71962 - file uploads don't finish

Status: VERIFIED FIXED

(Core :: Networking: HTTP, defect)

Description

[Christopher Blizzard (:blizzard)]

When posting a screenshot to bugzilla my file upload never finished and the
resulting image in bugzilla is damaged.  Have a look in bug 71958 to see the
uploaded images.  When you upload the file the spinner keeps going until you get
a complaint that "the operation timed out."

My build is from a pull at about 6 AM pacific time on March 14th.

Comment 1

[Doron Rosenberg (IBM)]

cc: pollman, who fixed yesterday's file submission blocker (bug 71834).

Perhaps this is form submission

Comment 2

[Christopher Blizzard (:blizzard)]

marking as a blocker

Comment 3

[Darin Fisher]

Investigating...

Comment 4

[Darin Fisher]

Attachment: test image (111k)

Comment 5

[Darin Fisher]

The image I just posted (attachment 27726 [details]) seemed to go through without any
problems.  Perhaps the image size matters.  I'm going to try posting a smaller
image...

Comment 6

[Darin Fisher]

Attachment: test upload (19k)

Comment 7

[Darin Fisher]

Attachment: test upload (12k)

Comment 8

[Darin Fisher]

Attachment: test upload (37k)

Comment 9

[Darin Fisher]

I've successfully uploaded 4 different images with a variety of sizes, and none
of them got corrupted.  Sounds like this could be heavily dependant on your
network configuration... perhaps the timeout was a fluke??  But, then it seems
you were able to duplicate the problem, so I think I'm a little bit stuck.

Can someone help me generate a test case for this?  Thanks!

Comment 10

[Darin Fisher]

blizzard: what is your network configuration btw?  are you connecting through
a proxy?

Comment 11

[Christopher Blizzard (:blizzard)]

I'm not using a proxy and I have a reasonably fast connection to the net.  2.2 DSL.

Comment 12

[Christopher Blizzard (:blizzard)]

Attachment: test image 41k

Comment 13

[Darin Fisher]

Ok.. let me see what happens when I upload a 41k file.

Comment 14

[Darin Fisher]

Attachment: test upload (41k)

Comment 15

[Darin Fisher]

OK.. I'm still not seeing the problem.  Blizzard: can you try uploading your
41k file using a version of the browser (or some other browser) that doesn't
exhibit this problem.  I'd like to be able to send the exact same number of 
bytes.  Thanks! 

Comment 16

[Darin Fisher]

Blizzard: what version of Linux are you running?  My tests are on a pretty
box-stock redhat 6.2 machine (dual processor machine).  Perhaps this has
something to do with it.  On that note, is anyone seeing this on other
platforms?

Comment 17

[Christopher Blizzard (:blizzard)]

Attachment: test 41k

Comment 18

[Christopher Blizzard (:blizzard)]

Attachment: test 41k ( Netscape 4.7 )

Comment 19

[Christopher Blizzard (:blizzard)]

I uploaded the same file with my build and Netscape 4.7.  My build fails but the
Netscape 4.7 works fine.

I'm using RH 7.<mumble> here.  Let me respin to see if maybe I missed a file or
something.

Comment 20

[Doron Rosenberg (IBM)]

Attachment: test (new build)

Comment 21

[Christopher Blizzard (:blizzard)]

Attachment: test 41k ( debug moz build )

Comment 22

[Christopher Blizzard (:blizzard)]

Attachment: test binary file

Comment 23

[Christopher Blizzard (:blizzard)]

Attachment: test binary file ( 1000 bytes )

Comment 24

[Christopher Blizzard (:blizzard)]

Attachment: test binary file ( 10,000 bytes )

Comment 25

[Christopher Blizzard (:blizzard)]

Strange.  I can upload that 10,000 byte type without problems.  Maybe it's
related to the content of the file itself.

Comment 26

[Christopher Blizzard (:blizzard)]

Attachment: test this image file again to make sure I'm not on crack

Comment 27

[Christopher Blizzard (:blizzard)]

Attachment: test this image file again to make sure I'm not on crack

Comment 28

[Christopher Blizzard (:blizzard)]

Attachment: 1x1 test gif

Comment 29

[Christopher Blizzard (:blizzard)]

Attachment: test 1x1 jpg

Comment 30

[Christopher Blizzard (:blizzard)]

OK, those work fine.  Darin, can you try downloading the good image that I
uploaded with Netscape 4.7 and uploading it yourself?

Comment 31

[Darin Fisher]

Attachment: uploading blizzard's 41k test image

Comment 32

[Darin Fisher]

blizzard: your 41k image uploaded perfectly from my 0.8.1 build on my rh7
machine!!  What the f*&#!!

Comment 33

[chris hofmann]

ok, to move this off the 0.8.1 list???
looks like things working ok now???

Comment 34

[Christopher Blizzard (:blizzard)]

Darin, you're right next to bugzilla.  Try uploading to the silophone or something.

Comment 35

[Darin Fisher]

I'm not sure what to do about this.  It works for me but it doesn't seem to
work for Blizzard.  And, we are apparently testing identical builds... the
only variable seems to be in our OS's.

Can we get some more QA testing this?

Comment 36

[Darin Fisher]

OK, but my test upload of your 41k file was from home over an ISDN line... not
from mountain view!  All the same, I will try uploading to a remote system.

Perhaps the combination of a faster connection to a remote host will demonstrate
the problem?!?

Comment 37

[Darin Fisher]

I'm going to be out of town for the next two days, so if this is REALLY
important for moz 0.8.1, then someone else needs to own it.

Comment 38

[Zach Lipton [:zach]]

I think that this is REALLY important for release. Lets see how long this might
take to fix before we commit to holding the release though.

Comment 39

[Asko Tontti]

Attachment: test 41k (Mozilla PC Linux 2001031611)

Comment 40

[Asko Tontti]

Attachment: retrying: blizzard's test 41k (Mozilla PC Linux 2001031611)

Comment 41

[Asko Tontti]

Seeing also with Mozilla PC Linux 2001031611 and Redhat Linux 7

Comment 42

[John Dobbins]

I ran into this bug yesterday with Win NT sp6a nightly build 2001031604.
While attempting to upload a screenshot to Mozdev's bugzilla at
http://mozdev.org/bugs/show_bug.cgi?id=219

Network Configuration is Win NT connected to a e-smith 4.1 gateway (based on RH
7.0) with a ADSL line that tests at 380 K upload time.

Three attempts to upload with Mozilla timed out and resulted in damaged images,
Netscape 4.76 uploaded the file with no problem.

Comment 43

[Asko Tontti]

I tested it with ISDN upload so it don't seem to be related to speed?

Comment 44

[Darin Fisher]

Attachment: retrying blizzard's 41k test image

Comment 45

[Darin Fisher]

Blizzard: could you (or anyone else who's seeing this bug) please attach a
socket transport log (NSPR_LOG_MODULES=nsSocketTransport:5)... thanks!!

Comment 46

[Christopher Blizzard (:blizzard)]

Attachment: test upload

Comment 47

[Christopher Blizzard (:blizzard)]

Attachment: socket trace

Comment 48

[Christopher Blizzard (:blizzard)]

Attachment: test upload again

Comment 49

[Christopher Blizzard (:blizzard)]

Attachment: log with http logging and socket logging

Comment 50

[Darin Fisher]

Blizzard: the logs look very interesting... especially the socket TIMED OUT 
error during the AsyncRead (though not sure if this could explain the
corruption)... still looking.

Comment 51

[Darin Fisher]

From the logs it appears that only 37624 bytes were actually written.  However,
I don't see anything in the logs that would explain this.

Comment 52

[Brendan Eich [:brendan]]

Is the log enough to show that (however impossible it might seem) some very
constrained bad thing is happening?  Or could a million bad things be going
wrong, and more tracing info is needed?

/be

Comment 53

[Darin Fisher]

Brendan: not sure exactly what could be wrong... necko is not complaining about
anything, but that hardly means that it's off the hook.

Blizzard: can you check the size of your /tmp/formpost-XX file corresponding
to the corrupted upload?  thanks!

Comment 54

[Christopher Blizzard (:blizzard)]

Attachment: test

Comment 55

[Christopher Blizzard (:blizzard)]

Attachment: test

Comment 56

[Darin Fisher]

Blizzard: can you check the /tmp/formpost-xx file?  what is it's size?  thankx!

Comment 57

[Christopher Blizzard (:blizzard)]

Attachment: test

Comment 58

[Christopher Blizzard (:blizzard)]

Attachment: test

Comment 59

[Christopher Blizzard (:blizzard)]

Attachment: test

Comment 60

[Christopher Blizzard (:blizzard)]

Attachment: test

Comment 61

[Christopher Blizzard (:blizzard)]

Attachment: test

Comment 62

[Christopher Blizzard (:blizzard)]

Attachment: test

Comment 63

[Christopher Blizzard (:blizzard)]

Attachment: test

Comment 64

[Christopher Blizzard (:blizzard)]

Attachment: test

Comment 65

[Christopher Blizzard (:blizzard)]

Attachment: test

Comment 66

[Christopher Blizzard (:blizzard)]

Attachment: test

Comment 67

[Darin Fisher]

Attachment: Should fix the problem.

Comment 68

[Christopher Blizzard (:blizzard)]

Comments:

When you are doing the translation in nsHTTPEncodeStream::Read() to the passed
in buffer what's to prevent you from overwriting the end of the buffer?  You are
adding characters.

rv = writer(this, closure, mBuf + mBufCursor, offset, amt, &amt);
            if (rv == NS_BASE_STREAM_WOULD_BLOCK)
                return NS_OK; // mask this error

You aren't updating the amt from the return of that which will probably cause
some badness down the road.

Now to do some testing...

Comment 69

[Christopher Blizzard (:blizzard)]

Attachment: test

Comment 70

[Darin Fisher]

Blizzard:

1) ReadNext() ensures that the buffer will not be overrun.

2) amt is reset/computed at the top of the loop, but offset should be
   updated as well.  Attaching new patch.

Comment 71

[Christopher Blizzard (:blizzard)]

This patch didn't fix the problem.  In fact it seems to have caused another more
serious problem.  Now the file uploads and it's apparently successful but the
http thread gets stuck in:

1026[81399a0]: nsSocketTransport: PR_Write(count=1007) returned 1007

and has the CPU pegged.  Hitting cancel will make the browser hang, probably
trying to cancel the request.

Comment 72

[Darin Fisher]

Attachment: New patch (updates offset)

Comment 73

[Christopher Blizzard (:blizzard)]

Attachment: test

Comment 74

[Darin Fisher]

Attachment: test

Comment 75

[Christopher Blizzard (:blizzard)]

Attachment: test

Comment 76

[Christopher Blizzard (:blizzard)]

Attachment: test

Comment 77

[Darin Fisher]

Attachment: test (should work)

Comment 78

[Darin Fisher]

Attachment: Fixes endless loop problem

Comment 79

[Christopher Blizzard (:blizzard)]

Attachment: test

Comment 80

[Darin Fisher]

Attachment: New patch (removes cruft from ReadNext)

Comment 81

[Brendan Eich [:brendan]]

I was IRC'ing with darin as the last patch developed, focused on crucial stuff. 
Nit comments only below, take 'em or leave 'em -- sr=[e-mail] either
way, we need the crucial fixes for 0.8.1:

+    char                       *mBuf;       // ReadSegments buffer
+    PRUint32                    mBufCursor; // index into mBuf of unread data
+    PRUint32                    mBufSize;   // amount of unread data in buffer

mBufSize is a misleading name next to mBuf (it's not the size in bytes of the
allocation at mBuf).  How about mBufUnread or mBufLength (vaguer, mBufUnread
says it all)?

From ReadNext:

         if (NS_FAILED(rv)) return rv;
+        *result += amt;
         if (rv == NS_BASE_STREAM_WOULD_BLOCK || amt == 0)
             return rv;

Isn't NS_BASE_STREAM_WOULD_BLOCK a failure code?  Maybe the first clause of that
|| is useless and you just want

         if (amt == 0) return rv;

?  If so, save a useless += 0 and put the *result += amt; after that if-then.

+    NS_ENSURE_ARG_POINTER(buf);
+    NS_ENSURE_ARG_POINTER(countRead);

These are just cycle-wasting worry-beads, no?  Read is called only within this
module or by other code in Necko, and Necko is a sufficiently closed system that
you need assertions (at most), not runtime checks, that no one was insane enough
to pass null for a in string or out int param.  Or it had better be, else I will
look for CVS vouchers to chastise!

+            if (rv == NS_BASE_STREAM_WOULD_BLOCK)
+                return NS_OK; // mask this error
+            else if (NS_FAILED(rv))
+                return rv;
+            else if (amt == 0)
+                return NS_OK;

else after return twice here, non-sequitur alert!  But this confirms that rv ==
NS_BASE_STREAM_WOULD_BLOCK needs to be checked before NS_FAILED(rv).

More nits in that other bug darin's filing about gratuitous string copying in
ReadNext -- darin, what's that bug #?  Thanks.

/be

Comment 82

[Asa Dotzler [:asa]]

a=asa for checkin to the branch (on behalf of drivers).  Do we still need an r= ?

Comment 83

[Darin Fisher]

Attachment: New patch (revised per brendan's comments)

Comment 84

[Darin Fisher]

r=blizzard, sr=brendan (as i understand it)

Comment 85

[Asa Dotzler [:asa]]

Great!

Comment 86

[Darin Fisher]

brendan: i've opened bug 72738 to track removing the extra buffer copies from
nsHTTPEncodeStream::ReadNext().

Comment 87

[Eric Pollmann]

*** Bug 72680 has been marked as a duplicate of this bug. ***

Comment 88

[Darin Fisher]

Ok, I've checked in the fix on both the trunk and the 0.8.1 branch.

Comment 89

[Tom Everingham]

Attachment: test upload

Comment 90

[Tom Everingham]

verified:

Linux rh6 2001050108