[1.7] regression wrt scp?

[1.7] regression wrt scp?

[Charles Wilson]

With cygwin-1.7.36:

$ scp gcc-tools-autoconf-2.59-10-src.tar.bz2 sources.redhat.com:
gcc-tools-autoconf-2.59-10-src.tar.bz2 100%  911KB  60.8KB/s   00:15

With cygwin-1.7.37:

$ scp gcc-tools-autoconf-2.59-10-src.tar.bz2 sources.redhat.com:
gcc-tools-autoconf-2.59-10-src.tar.bz2  21%  192KB  91.8KB/s - stalled -
gcc-tools-autoconf-2.59-10-src.tar.bz2: Broken pipe

and has to be killed with CTRL-C. ssh works fine in both cases.

Is anybody else seeing this?

--
Chuck

--
Unsubscribe info:      http://cygwin.com/ml/#unsubscribe-simple
Problem reports:       http://cygwin.com/problems.html
Documentation:         http://cygwin.com/docs.html
FAQ:                   http://cygwin.com/faq/

Re: [1.7] regression wrt scp?

[Corinna Vinschen]

On Jan  7 00:52, Charles Wilson wrote:
> With cygwin-1.7.36:
> 
> $ scp gcc-tools-autoconf-2.59-10-src.tar.bz2 sources.redhat.com:
> gcc-tools-autoconf-2.59-10-src.tar.bz2 100%  911KB  60.8KB/s   00:15
> 
> With cygwin-1.7.37:
> 
> $ scp gcc-tools-autoconf-2.59-10-src.tar.bz2 sources.redhat.com:
> gcc-tools-autoconf-2.59-10-src.tar.bz2  21%  192KB  91.8KB/s - stalled -
> gcc-tools-autoconf-2.59-10-src.tar.bz2: Broken pipe
> 
> and has to be killed with CTRL-C. ssh works fine in both cases.
> 
> Is anybody else seeing this?

I could reproduce it with Cygwin from CVS as well.  It did not occur
over a fast LAN connection, but it occurs reliably over my much slower
ADSL connection when trying to upload to sourceware.  The strace didn't
exactly enlighten me yet.  That's Chris' code and I'm not very familar
with it.


Corinna

-- 
Corinna Vinschen                  Please, send mails regarding Cygwin to
Cygwin Project Co-Leader          cygwin AT cygwin DOT com
Red Hat

--
Unsubscribe info:      http://cygwin.com/ml/#unsubscribe-simple
Problem reports:       http://cygwin.com/problems.html
Documentation:         http://cygwin.com/docs.html
FAQ:                   http://cygwin.com/faq/

Re: [1.7] regression wrt scp?

[Christopher Faylor]

On Thu, Jan 08, 2009 at 11:33:49AM +0100, Corinna Vinschen wrote:
>On Jan  7 00:52, Charles Wilson wrote:
>> With cygwin-1.7.36:
>> 
>> $ scp gcc-tools-autoconf-2.59-10-src.tar.bz2 sources.redhat.com:
>> gcc-tools-autoconf-2.59-10-src.tar.bz2 100%  911KB  60.8KB/s   00:15
>> 
>> With cygwin-1.7.37:
>> 
>> $ scp gcc-tools-autoconf-2.59-10-src.tar.bz2 sources.redhat.com:
>> gcc-tools-autoconf-2.59-10-src.tar.bz2  21%  192KB  91.8KB/s - stalled -
>> gcc-tools-autoconf-2.59-10-src.tar.bz2: Broken pipe
>> 
>> and has to be killed with CTRL-C. ssh works fine in both cases.
>> 
>> Is anybody else seeing this?
>
>I could reproduce it with Cygwin from CVS as well.  It did not occur
>over a fast LAN connection, but it occurs reliably over my much slower
>ADSL connection when trying to upload to sourceware.  The strace didn't
>exactly enlighten me yet.  That's Chris' code and I'm not very familar
>with it.

It's already on my list to investigate.  When I saw "broken pipe" I
thought it could be something in the new pipe code.

cgf

--
Unsubscribe info:      http://cygwin.com/ml/#unsubscribe-simple
Problem reports:       http://cygwin.com/problems.html
Documentation:         http://cygwin.com/docs.html
FAQ:                   http://cygwin.com/faq/

Re: [1.7] regression wrt scp?

[Corinna Vinschen]

On Jan  8 11:15, Christopher Faylor wrote:
> On Thu, Jan 08, 2009 at 11:33:49AM +0100, Corinna Vinschen wrote:
> >On Jan  7 00:52, Charles Wilson wrote:
> >> With cygwin-1.7.36:
> >> 
> >> $ scp gcc-tools-autoconf-2.59-10-src.tar.bz2 sources.redhat.com:
> >> gcc-tools-autoconf-2.59-10-src.tar.bz2 100%  911KB  60.8KB/s   00:15
> >> 
> >> With cygwin-1.7.37:
> >> 
> >> $ scp gcc-tools-autoconf-2.59-10-src.tar.bz2 sources.redhat.com:
> >> gcc-tools-autoconf-2.59-10-src.tar.bz2  21%  192KB  91.8KB/s - stalled -
> >> gcc-tools-autoconf-2.59-10-src.tar.bz2: Broken pipe
> >> 
> >> and has to be killed with CTRL-C. ssh works fine in both cases.
> >> 
> >> Is anybody else seeing this?
> >
> >I could reproduce it with Cygwin from CVS as well.  It did not occur
> >over a fast LAN connection, but it occurs reliably over my much slower
> >ADSL connection when trying to upload to sourceware.  The strace didn't
> >exactly enlighten me yet.  That's Chris' code and I'm not very familar
> >with it.
> 
> It's already on my list to investigate.  When I saw "broken pipe" I
> thought it could be something in the new pipe code.

Yeah, I thought so.  I just figured it might be interesting to know
that it seems to depend on the connection speed, as if one of the pipes
between ssh and scp starves for some reason.


Corinna

-- 
Corinna Vinschen                  Please, send mails regarding Cygwin to
Cygwin Project Co-Leader          cygwin AT cygwin DOT com
Red Hat

--
Unsubscribe info:      http://cygwin.com/ml/#unsubscribe-simple
Problem reports:       http://cygwin.com/problems.html
Documentation:         http://cygwin.com/docs.html
FAQ:                   http://cygwin.com/faq/

Re: [1.7] regression wrt scp?

[Christopher Faylor]

I finally managed to duplicate this.

On Thu, Jan 08, 2009 at 11:15:13AM -0500, Christopher Faylor wrote:
>On Thu, Jan 08, 2009 at 11:33:49AM +0100, Corinna Vinschen wrote:
>>On Jan  7 00:52, Charles Wilson wrote:
>>> With cygwin-1.7.36:
>>> 
>>> $ scp gcc-tools-autoconf-2.59-10-src.tar.bz2 sources.redhat.com:
>>> gcc-tools-autoconf-2.59-10-src.tar.bz2 100%  911KB  60.8KB/s   00:15
>>> 
>>> With cygwin-1.7.37:
>>> 
>>> $ scp gcc-tools-autoconf-2.59-10-src.tar.bz2 sources.redhat.com:
>>> gcc-tools-autoconf-2.59-10-src.tar.bz2  21%  192KB  91.8KB/s - stalled -
>>> gcc-tools-autoconf-2.59-10-src.tar.bz2: Broken pipe
>>> 
>>> and has to be killed with CTRL-C. ssh works fine in both cases.
>>> 
>>> Is anybody else seeing this?
>>
>>I could reproduce it with Cygwin from CVS as well.  It did not occur
>>over a fast LAN connection, but it occurs reliably over my much slower
>>ADSL connection when trying to upload to sourceware.  The strace didn't
>>exactly enlighten me yet.  That's Chris' code and I'm not very familar
>>with it.
>
>It's already on my list to investigate.  When I saw "broken pipe" I
>thought it could be something in the new pipe code.

But, if it is, I can't see it yet.

The strace snippet below seems to show that the ssh process which scp
forks is expecting for the socket to become writable but that never happens.

At time 10048910 you can see 16384 bytes received.  Then select() is
called to inspect the socket handler for readability/writability.  But
select claims that the socket handle is never ready.

cgf


 1047 10039981 [main] ssh 2308 readv: readv (4, 0x221CC0, 1) nonblocking, sigcatchers 6
  386 10040367 [main] ssh 2308 peek_pipe: , ready for read: avail 81920
  360 10040727 [main] ssh 2308 fhandler_base::ready_for_read: read_ready 1, avail 1
 4233 10044960 [main] ssh 2308 fhandler_base::wait_overlapped: normal read, 16384 bytes
 1029 10045989 [main] ssh 2308 __set_errno: int fhandler_base::wait_overlapped(bool, bool, DWORD*):1742 val 0
  359 10046348 [main] ssh 2308 fhandler_base::read: returning 16384, binary mode
 2562 10048910 [main] ssh 2308 readv: 16384 = readv (4, 0x221CC0, 1), errno 0
 1071 10049981 [main] ssh 2308 cygwin_select: 7, 0x6E9030, 0x6E9040, 0x0, 0x0
  713 10050694 [main] ssh 2308 dtable::select_read:  fd 3
  345 10051039 [main] ssh 2308 dtable::select_write:  fd 3
  433 10051472 [main] ssh 2308 cygwin_select: to NULL, ms FFFFFFFF
  344 10051816 [main] ssh 2308 cygwin_select: sel.always_ready 0
 1473 10053289 [main] ssh 2308 start_thread_socket: stuff_start 0x229C44
 1115 10054404 [main] ssh 2308 select_stuff::wait: m 2, ms 4294967295
  367 10054771 [select_socket] ssh 2308 thread_socket: stuff_start 0x229C44
  390 10055161 [select_socket] ssh 2308 peek_socket: read_ready: 0, write_ready: 0, except_ready: 0
61530 10116691 [select_socket] ssh 2308 peek_socket: read_ready: 0, write_ready: 0, except_ready: 0
71665 10188356 [select_socket] ssh 2308 peek_socket: read_ready: 0, write_ready: 0, except_ready: 0
68540 10256896 [select_socket] ssh 2308 peek_socket: read_ready: 0, write_ready: 0, except_ready: 0
70495 10327391 [select_socket] ssh 2308 peek_socket: read_ready: 0, write_ready: 0, except_ready: 0
71157 10398548 [select_socket] ssh 2308 peek_socket: read_ready: 0, write_ready: 0, except_ready: 0
68720 10467268 [select_socket] ssh 2308 peek_socket: read_ready: 0, write_ready: 0, except_ready: 0

etc.

--
Unsubscribe info:      http://cygwin.com/ml/#unsubscribe-simple
Problem reports:       http://cygwin.com/problems.html
Documentation:         http://cygwin.com/docs.html
FAQ:                   http://cygwin.com/faq/

Re: [1.7] regression wrt scp?

[Corinna Vinschen]

On Jan 26 02:43, Christopher Faylor wrote:
> I finally managed to duplicate this.
> [...]
> >It's already on my list to investigate.  When I saw "broken pipe" I
> >thought it could be something in the new pipe code.
> 
> But, if it is, I can't see it yet.
> 
> The strace snippet below seems to show that the ssh process which scp
> forks is expecting for the socket to become writable but that never happens.
> 
> At time 10048910 you can see 16384 bytes received.  Then select() is
> called to inspect the socket handler for readability/writability.  But
> select claims that the socket handle is never ready.

It's probably right about that.  The peek_socket function is called in a
loop by the thread_socket function (via select) with a non INFINITE
timeout.  The "Broken pipe" message already occured at the time the
peek_socket function is repeated ad infinitum.  This message in the
strace does not mean that SSH hangs for that reason, it just doesn't get
any data from the remote side.  SSH maintains a select loop over all
open descriptors and every poll from the thread_socket function
generates this debug message.  SSH seems to be waiting for data from the
local pipe to the local scp actually.

What strucks me as weird is, why does SSH hang in select() at all?  The
"Broken pipe" message should have resulted in exiting the application
but for some reason only scp noticed the broken pipe, not SSH.  That's
the only reason I can think of that the select loop in SSH didn't finish.

FWIW, I reverted the pipe-related changes from 2008-12-20 and 2008-12-23
for testing and the problem goes away for me.


Corinna

-- 
Corinna Vinschen                  Please, send mails regarding Cygwin to
Cygwin Project Co-Leader          cygwin AT cygwin DOT com
Red Hat

--
Unsubscribe info:      http://cygwin.com/ml/#unsubscribe-simple
Problem reports:       http://cygwin.com/problems.html
Documentation:         http://cygwin.com/docs.html
FAQ:                   http://cygwin.com/faq/

Re: [1.7] regression wrt scp?

[Christopher Faylor]

On Mon, Jan 26, 2009 at 03:28:15PM +0100, Corinna Vinschen wrote:
>On Jan 26 02:43, Christopher Faylor wrote:
>> I finally managed to duplicate this.
>> [...]
>> >It's already on my list to investigate.  When I saw "broken pipe" I
>> >thought it could be something in the new pipe code.
>> 
>> But, if it is, I can't see it yet.
>> 
>> The strace snippet below seems to show that the ssh process which scp
>> forks is expecting for the socket to become writable but that never happens.
>> 
>> At time 10048910 you can see 16384 bytes received.  Then select() is
>> called to inspect the socket handler for readability/writability.  But
>> select claims that the socket handle is never ready.
>
>It's probably right about that.  The peek_socket function is called in a
>loop by the thread_socket function (via select) with a non INFINITE
>timeout.  The "Broken pipe" message already occured at the time the
>peek_socket function is repeated ad infinitum.  This message in the
>strace does not mean that SSH hangs for that reason, it just doesn't get
>any data from the remote side.  SSH maintains a select loop over all
>open descriptors and every poll from the thread_socket function
>generates this debug message.  SSH seems to be waiting for data from the
>local pipe to the local scp actually.

Ok.  I was pretty sure that I hadn't seen a broken pipe message at this
point but I could be mistaken.

Btw, in an unrelated problem, the reason that I didn't look into this
earlier was because my normal system for debugging this problem can no
longer connect to sourceware.org.  I am not running a firewall or any
BLODA but it seems to hang in the initial connect and never recover.
1.5.25 works fine.  It is just sourceware.org which seems to have
this problem, which is weird.

I assume that if 1.7 goes live I won't be the only one with this problem.
I guess I should start a new thread to discuss it.

cgf

--
Unsubscribe info:      http://cygwin.com/ml/#unsubscribe-simple
Problem reports:       http://cygwin.com/problems.html
Documentation:         http://cygwin.com/docs.html
FAQ:                   http://cygwin.com/faq/

Re: [1.7] regression wrt scp?

[Corinna Vinschen]

On Jan 26 11:29, Christopher Faylor wrote:
> On Mon, Jan 26, 2009 at 03:28:15PM +0100, Corinna Vinschen wrote:
> >On Jan 26 02:43, Christopher Faylor wrote:
> >> I finally managed to duplicate this.
> >> [...]
> >> >It's already on my list to investigate.  When I saw "broken pipe" I
> >> >thought it could be something in the new pipe code.
> >> 
> >> But, if it is, I can't see it yet.
> >> 
> >> The strace snippet below seems to show that the ssh process which scp
> >> forks is expecting for the socket to become writable but that never happens.
> >> 
> >> At time 10048910 you can see 16384 bytes received.  Then select() is
> >> called to inspect the socket handler for readability/writability.  But
> >> select claims that the socket handle is never ready.
> >
> >It's probably right about that.  The peek_socket function is called in a
> >loop by the thread_socket function (via select) with a non INFINITE
> >timeout.  The "Broken pipe" message already occured at the time the
> >peek_socket function is repeated ad infinitum.  This message in the
> >strace does not mean that SSH hangs for that reason, it just doesn't get
> >any data from the remote side.  SSH maintains a select loop over all
> >open descriptors and every poll from the thread_socket function
> >generates this debug message.  SSH seems to be waiting for data from the
> >local pipe to the local scp actually.
> 
> Ok.  I was pretty sure that I hadn't seen a broken pipe message at this
> point but I could be mistaken.
> 
> Btw, in an unrelated problem, the reason that I didn't look into this
> earlier was because my normal system for debugging this problem can no
> longer connect to sourceware.org.  I am not running a firewall or any
> BLODA but it seems to hang in the initial connect and never recover.
> 1.5.25 works fine.  It is just sourceware.org which seems to have
> this problem, which is weird.

WJFFM from XP as well as from 2K8.


Corinna

-- 
Corinna Vinschen                  Please, send mails regarding Cygwin to
Cygwin Project Co-Leader          cygwin AT cygwin DOT com
Red Hat

--
Unsubscribe info:      http://cygwin.com/ml/#unsubscribe-simple
Problem reports:       http://cygwin.com/problems.html
Documentation:         http://cygwin.com/docs.html
FAQ:                   http://cygwin.com/faq/

Re: [1.7] regression wrt scp?

[Christopher Faylor]

On Mon, Jan 26, 2009 at 05:58:48PM +0100, Corinna Vinschen wrote:
>WJFFM from XP as well as from 2K8.

Yes, it works for me from every machine in my house except for the one
that I normally do development on.  I spent a few hours trying to figure
out what was different with that machine.  At first I thought it was an
MTU issue since I use PPPOE.  Making recommended changes there did not
have any effect.  There were some strange issues with the network card
on that system since it has gone through numerous changes but clearing
those did not change anything.

I rebuilt openssh to see if it was the 1.7 version that was the problem
but the 1.5 version has the same problem.

I can ping sourceware and access the sourceware web site.  I just can't
ssh to it.

I'll provide more details soon.

cgf

--
Unsubscribe info:      http://cygwin.com/ml/#unsubscribe-simple
Problem reports:       http://cygwin.com/problems.html
Documentation:         http://cygwin.com/docs.html
FAQ:                   http://cygwin.com/faq/

Re: [1.7] regression wrt scp?

[Corinna Vinschen]

On Jan 26 11:29, Christopher Faylor wrote:
> Btw, in an unrelated problem, the reason that I didn't look into this
> earlier was because my normal system for debugging this problem can no
> longer connect to sourceware.org.

Btw., you can also reproduce this problem locally if the file to copy is
just big enough.  A file of about 5 Megs is sufficient to reproduce it
on my local net reliably.


Corinna

-- 
Corinna Vinschen                  Please, send mails regarding Cygwin to
Cygwin Project Co-Leader          cygwin AT cygwin DOT com
Red Hat

--
Unsubscribe info:      http://cygwin.com/ml/#unsubscribe-simple
Problem reports:       http://cygwin.com/problems.html
Documentation:         http://cygwin.com/docs.html
FAQ:                   http://cygwin.com/faq/

Re: [1.7] regression wrt scp?

[Christopher Faylor]

On Mon, Jan 26, 2009 at 11:29:23AM -0500, Christopher Faylor wrote:
>Ok.  I was pretty sure that I hadn't seen a broken pipe message at this
>point but I could be mistaken.

That was because there wasn't really a broken pipe.  I wasn't reporting
EINTR correctly.

This should be fixed in CVS and is in the latest snapshot.

cgf

--
Unsubscribe info:      http://cygwin.com/ml/#unsubscribe-simple
Problem reports:       http://cygwin.com/problems.html
Documentation:         http://cygwin.com/docs.html
FAQ:                   http://cygwin.com/faq/

Re: [1.7] regression wrt scp?

[Charles Wilson]

Christopher Faylor wrote:
> This should be fixed in CVS and is in the latest snapshot.

Confirmed that CVS fixes this problem for me. Thanks!

--
Chuck


--
Unsubscribe info:      http://cygwin.com/ml/#unsubscribe-simple
Problem reports:       http://cygwin.com/problems.html
Documentation:         http://cygwin.com/docs.html
FAQ:                   http://cygwin.com/faq/