193017 - downloading via ftp doesn't proceed

Status: RESOLVED FIXED

(Core Graveyard :: Networking: FTP, defect, P2)

Description

[Max Alekseyev]

OS/2 build 2003021209

Often Mozilla is unable to download via ftp.

To reproduce:
1. Click on URL
2. New window is opened but and nothing happens anymore. No errors of any kind
appear. Throbber is throbbing forever in that window.

The same file is well downloaded by wget.

It's not 100% reproduciable - sometimes downloading works as expected.
And it's not ftp server dependent. I saw the bug with different ftp servers.

Comment 1

[Matthias Versen [:Matti]]

no blocker

Comment 2

[Doug Turner (:dougt)]

Max, can you try reproducing this problem with the 1.3b build?  I think that
this may be a duplicated of bug:

http://bugzilla.mozilla.org/show_bug.cgi?id=191739

Comment 3

[Max Alekseyev]

The reported trunk version is newer than 1.3b release.
Is there any sence to try the release?

Actually, I experienced bug 191739 on one system. And the browser didn't connect
at all to any site. This bug is about problems with connecting to ftp only. The
http works great, no complaints.

Comment 4

[Mike Kaply [:mkaply]]

Attachment: Log with nsFTPProtocol:5,nsPipe:5,nsSocketTransport:5,nsStreamPump:5

This log shows two succeeds and then a failure. I let the failure sit for about
10 minutes and it never did anything. I then closed the browser.

Comment 5

[Darin Fisher]

this snipet of the log file indicates something very unusual...

  0[2b50c8]: nsInputStreamPump::OnInputStreamReady [this=d1a750]
  0[2b50c8]:   OnStateTransfer [this=d1a750]
  0[2b50c8]:   Available returned [stream=c5535c rv=0 avail=512]
  0[2b50c8]:   calling OnDataAvailable [offset=640 count=512]
  0[2b50c8]: III ReadSegments [this=c5535c count=512]

  0[2b50c8]: III advancing read cursor by 128

  0[2b50c8]: III deleting first segment
  0[2b50c8]: nsSocketInputStream::AsyncWait [this=ce52c0]
  0[2b50c8]: nsSocketTransportService::PostEvent [handler=ce5254 type=3 u=0 v=0]
  0[2b50c8]: III advancing read cursor by 64
  0[2b50c8]: III deleting first segment
  0[2b50c8]: III advancing read cursor by 64
  0[2b50c8]: III deleting first segment
  0[2b50c8]: III advancing read cursor by 64
  0[2b50c8]: III deleting first segment
  0[2b50c8]: III advancing read cursor by 64
  0[2b50c8]: III deleting first segment
  0[2b50c8]: III advancing read cursor by 64
  0[2b50c8]: III deleting first segment
  0[2b50c8]: III advancing read cursor by 64
  0[2b50c8]: III deleting first segment

the read cursor, of a pipe with 64 byte segments, should never advance by more
than 64 bytes at a time!!  the fact that the cursor is being advanced by 128
bytes is really scary.  something is not right.  maybe there are some more clues
in the log file...

Comment 6

[Darin Fisher]

i don't see anything in the log file that could explain this state.

mkaply: can you set an assertion at that LOG statement in
nsPipe::AdvanceReadCursor... something like this:

  NS_ASSERTION(bytesRead <= mBuffer.GetSegmentSize(), "whoops");

and then if you hit that assertion, can you save a snapshot of |*this|,
including the values of the member variables of mInput and mOutput.  thanks!!

Comment 7

[Mike Kaply [:mkaply]]

A break point there gets hit a lot on bringup. Do I need to just do it for ftp? 

Comment 8

[Darin Fisher]

no, if you are hitting that assertion then something is seriously wacked.  would
be good to get info from any hit.

Comment 9

[Darin Fisher]

with a trunk windows build, i have never hit that assertion.

Comment 10

[Mike Kaply [:mkaply]]

Attachment: picture of the variables

OK, here's a picture of the variables when I hit the length.

Note I got my info wrong, and I don't hit it during bring up, only during this
FTP case.

Comment 11

[Darin Fisher]

mike: this is great, but can you include the address values for the pointers? 
mReadCursor, mReadLimit, mWriteCursor, mWriteLimit.  thanks!

Comment 12

[Mike Kaply [:mkaply]]

Attachment: Per darin

Comment 13

[Jan Vlug]

dupe of bug 192871 ?

Comment 14

[Max Alekseyev]

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

Comment 15

[Darin Fisher]

well, mReadCursor and mReadLimit are definitely out of wack.  i'm going to put
together a patch that adds a bunch of assertions in hopes of actually
determining where the pointers get out of sync.

Comment 16

[Darin Fisher]

Attachment: v1 patch

OK, actually i think i realize what is going on here.  mReadLimit can point
just beyond the segment being read, and if the allocation of the next segment
occurs immediately beyond the first segment, then mReadLimit would also point
to the beginning of the next segment!  as a result, we would see that
mReadLimit == mWriteCursor when advancing the write cursor in the second
segment.  the patch adds a check to ensure that we only compare mReadLimit to
mWriteCursor if mWriteSegment == 0 (we only read from the first segment).

Comment 17

[Darin Fisher]

-> me

Comment 18

[Mike Kaply [:mkaply]]

Just tried with this patch and I still see the problem. Sorry.

Comment 19

[Robert Accettura [:raccettura]]

I can also confirm this problem.  Thought it was just me.  Since I've been
running 1.3b and later it's been happening.  

I've been trying to find some sort of pattern before reporting it, though as of
yet I have failed to find anything.  

Also noticed quite a few downloads will start, but die at some point in the
download.  Can't find any pattern as to when they die.  Often I have to use IE
(yuck) to download the files.

Comment 20

[Mike Kaply [:mkaply]]

Attachment: New log

This log is with the patch applied.

It succeeded once and then failed the second time.

Comment 21

[Darin Fisher]

the server seems to be closing the connection.  first read from the control
connection returns 0, which means EOF.

<mkaply> from NS 4.61 - network error: broken pipe
<mkaply> wget fails as well.
<mkaply> error in server response

looks like the server is just misbehaving now.  going to try to get the patch in
now.

Comment 22

[Doug Turner (:dougt)]

Comment on attachment 114716 [details] [diff] [review]
v1 patch

r=dougt.

Comment 23

[Brendan Eich [:brendan]]

Comment on attachment 114716 [details] [diff] [review]
v1 patch

I was telling darin that I fixed a similar bug in jsarena.c the other year,
diagnosed by rogerl.  Big fun, and something I won't forget soon!

/be

Comment 24

[Darin Fisher]

Comment on attachment 114716 [details] [diff] [review]
v1 patch

requesting drivers approval for 1.3 final.  this is critical for 1.3 final on
OS/2 and may effect other platforms as well (though windows, linux, and mach-o
seem to be immune).

Comment 25

[Darin Fisher]

fixed-on-trunk