SCP doesn't complete transfers of large files

Olaf Föllinger Olaf.Foellinger@sesa.de
Tue Jan 27 17:20:00 GMT 2004


On Tue, Jan 27, 2004 at 08:42:41AM -0500, Igor Pechtchanski wrote:
> On Tue, 27 Jan 2004, Olaf Föllinger wrote:
> 
> > On Tue, Jan 27, 2004 at 12:36:29PM +0100, Dirk Sondermann wrote:
> > > I have also noticed this problem when copying files ~1GB from
> > > a remote host to the local host.
> > >
> > > Strangely, if x is a big file and x0 has just a few bytes,
> > > scp remote:x . may hang while scp remote:x* . succeeds.
> >
> > Same observation here. Just to make clear that it's not a singular
> > problem.
> >
> > Gruss Olaf Follinger
> 
> Can anyone in this thread who can actually reproduce this problem attach
> to the hung scp process with gdb/strace and see where it hangs (and what
> it's doing)?

The process is 

$ scp news:SFU35SEL_EN.exe tmp/
SFU35SEL_EN.exe 99%  218MB   0.0KB/s - stalled -

and the output of strace is attached. I've used 'strace -p <PID>' while
the scp-process was stalled already. I think I've tested with the latest
snapshot:

$ uname -a
CYGWIN_NT-5.0 nbof 1.5.7s(0.109/3/2) 20040124 15:46:47 i686 unknown
unknown Cygwin

 
 
Gruss Olaf Föllinger

-- 
Olaf Föllinger
Berater 
S.E.S.A. Software und Systeme AG

Alt-Moabit 91a
D-10559 Berlin
Germany
Tel:   +49 30 390722 -291
Fax:   +49 30 390722 -222
Mobil: +49 173 6227080
http://www.sesa.de
mailto: Olaf.Foellinger@sesa.de
-------------- next part --------------
   20      20 [unknown (0x858)] scp 2424 _threadinfo::remove: wait 0x0
  430     450 [unknown (0x858)] scp 2424 _threadinfo::remove: removed 0x10DF014 element 1
87576   88026 [win] scp 2424 wndproc 275 WM_TIMER 1 0
  465   88491 [win] scp 2424 kill: kill (2424, 14)
  188   88679 [win] scp 2424 sig_send: sendsig 0x354, pid 2424, signal 14, its_me 1
  188   88867 [win] scp 2424 sig_send: wakeup 0x2D4
  257   89124 [sig] scp 2424 sig_handle: signal 14 processing
  173   89297 [sig] scp 2424 sig_handle: signal 14, about to call 0x404F10
  176   89473 [sig] scp 2424 proc_subproc: args: 3, 1
  168   89641 [sig] scp 2424 proc_subproc: clear waiting threads
  162   89803 [sig] scp 2424 proc_subproc: finished clearing
  374   90177 [sig] scp 2424 proc_subproc: returning 1
 1137   91314 [sig] scp 2424 _threadinfo::interrupt_setup: armed signal_arrived 0x35C, sig 14, res 1
  206   91520 [sig] scp 2424 setup_handler: interrupted known cygwin routine
  274   91794 [win] scp 2424 sig_send: Waiting for pack.wakeup 0x2D4
  980   92774 [main] scp 2424 reset_signal_arrived: reset signal_arrived
  144   92918 [main] scp 2424 set_signal_mask: oldmask 0x0, newmask 0x2000, mask_bits 0x0
  125   93043 [main] scp 2424 set_signal_mask: not calling sig_dispatch_pending
  121   93164 [main] scp 2424 tcgetpgrp: 2424 = tcgetpgrp (1)
  154   93318 [main] scp 2424 time: 1075220980 = time (0)
  170   93488 [main] scp 2424 writev: writev (1, 0x22E200, 1)
  116   93604 [main] scp 2424 fhandler_tty_slave::write: tty3, write(22E280, 126)
  367   93971 [main] scp 2424 fhandler_tty_slave::write: (681): tty output_mutex: waiting -1 ms
  121   94092 [main] scp 2424 fhandler_tty_slave::write: (681): tty output_mutex: acquired
  145   94237 [main] scp 2424 fhandler_tty_slave::write: (724): tty output_mutex released
  112   94349 [main] scp 2424 writev: 126 = write (1, 0x22E200, 1), errno 4
  114   94463 [main] scp 2424 sigaction: signal 14, newact 0x0, oldact 0x22E470
  160   94623 [main] scp 2424 set_signal_mask: oldmask 0x2000, newmask 0x0, mask_bits 0x2000
  113   94736 [main] scp 2424 readv: -1 = readv (7, 0x22E570, 1), errno 4
  116   94852 [main] scp 2424 readv: readv (7, 0x22E570, 1) blocking, sigcatchers 5
-3205   91647 [sig] scp 2424 setup_handler: signal 14 delivered
101948  193595 [sig] scp 2424 sig_handle: returning 1
  134  193729 [sig] scp 2424 wait_sig: signalled 0x2D4
  180  193909 [win] scp 2424 sig_send: returning 0x0 from sending signal 14
  135  194044 [win] scp 2424 kill_worker: 0 = kill_worker (2424, 14), process_state 0x10C9
899191 1093235 [win] scp 2424 wndproc 275 WM_TIMER 1 0
  568 1093803 [win] scp 2424 kill: kill (2424, 14)
  151 1093954 [win] scp 2424 sig_send: sendsig 0x354, pid 2424, signal 14, its_me 1
  147 1094101 [win] scp 2424 sig_send: wakeup 0x2D4
  177 1094278 [sig] scp 2424 sig_handle: signal 14 processing
  123 1094401 [sig] scp 2424 sig_handle: signal 14, about to call 0x404F10
  123 1094524 [sig] scp 2424 proc_subproc: args: 3, 1
  116 1094640 [sig] scp 2424 proc_subproc: clear waiting threads
  112 1094752 [sig] scp 2424 proc_subproc: finished clearing
  111 1094863 [sig] scp 2424 proc_subproc: returning 1
  110 1094973 [sig] scp 2424 _threadinfo::interrupt_setup: armed signal_arrived 0x35C, sig 14, res 1
  107 1095080 [sig] scp 2424 setup_handler: interrupted known cygwin routine
  403 1095483 [sig] scp 2424 setup_handler: signal 14 delivered
  117 1095600 [sig] scp 2424 sig_handle: returning 1
  118 1095718 [sig] scp 2424 wait_sig: signalled 0x2D4
  173 1095891 [win] scp 2424 sig_send: Waiting for pack.wakeup 0x2D4
  137 1096028 [win] scp 2424 sig_send: returning 0x0 from sending signal 14
  125 1096153 [win] scp 2424 kill_worker: 0 = kill_worker (2424, 14), process_state 0x10C9
  581 1096734 [main] scp 2424 reset_signal_arrived: reset signal_arrived
  126 1096860 [main] scp 2424 set_signal_mask: oldmask 0x0, newmask 0x2000, mask_bits 0x0
  121 1096981 [main] scp 2424 set_signal_mask: not calling sig_dispatch_pending
  127 1097108 [main] scp 2424 tcgetpgrp: 2424 = tcgetpgrp (1)
  859 1097967 [main] scp 2424 time: 1075220981 = time (0)
  243 1098210 [main] scp 2424 writev: writev (1, 0x22E200, 1)
  129 1098339 [main] scp 2424 fhandler_tty_slave::write: tty3, write(22E280, 126)
  144 1098483 [main] scp 2424 fhandler_tty_slave::write: (681): tty output_mutex: waiting -1 ms
  127 1098610 [main] scp 2424 fhandler_tty_slave::write: (681): tty output_mutex: acquired
  143 1098753 [main] scp 2424 fhandler_tty_slave::write: (724): tty output_mutex released
  114 1098867 [main] scp 2424 writev: 126 = write (1, 0x22E200, 1), errno 4
  119 1098986 [main] scp 2424 sigaction: signal 14, newact 0x0, oldact 0x22E470
  174 1099160 [main] scp 2424 set_signal_mask: oldmask 0x2000, newmask 0x0, mask_bits 0x2000
  129 1099289 [main] scp 2424 readv: -1 = readv (7, 0x22E570, 1), errno 4
  123 1099412 [main] scp 2424 readv: readv (7, 0x22E570, 1) blocking, sigcatchers 5
995013 2094425 [win] scp 2424 wndproc 275 WM_TIMER 1 0
  332 2094757 [win] scp 2424 kill: kill (2424, 14)
  141 2094898 [win] scp 2424 sig_send: sendsig 0x354, pid 2424, signal 14, its_me 1
  143 2095041 [win] scp 2424 sig_send: wakeup 0x2D4
  164 2095205 [sig] scp 2424 sig_handle: signal 14 processing
  130 2095335 [sig] scp 2424 sig_handle: signal 14, about to call 0x404F10
  124 2095459 [sig] scp 2424 proc_subproc: args: 3, 1
  117 2095576 [sig] scp 2424 proc_subproc: clear waiting threads
  112 2095688 [sig] scp 2424 proc_subproc: finished clearing
  112 2095800 [sig] scp 2424 proc_subproc: returning 1
  111 2095911 [sig] scp 2424 _threadinfo::interrupt_setup: armed signal_arrived 0x35C, sig 14, res 1
  134 2096045 [sig] scp 2424 setup_handler: interrupted known cygwin routine
  113 2096158 [sig] scp 2424 setup_handler: signal 14 delivered
  105 2096263 [sig] scp 2424 sig_handle: returning 1
  124 2096387 [sig] scp 2424 wait_sig: signalled 0x2D4
  155 2096542 [win] scp 2424 sig_send: Waiting for pack.wakeup 0x2D4
  135 2096677 [win] scp 2424 sig_send: returning 0x0 from sending signal 14
  118 2096795 [win] scp 2424 kill_worker: 0 = kill_worker (2424, 14), process_state 0x10C9
  750 2097545 [main] scp 2424 reset_signal_arrived: reset signal_arrived
  139 2097684 [main] scp 2424 set_signal_mask: oldmask 0x0, newmask 0x2000, mask_bits 0x0
  122 2097806 [main] scp 2424 set_signal_mask: not calling sig_dispatch_pending
  125 2097931 [main] scp 2424 tcgetpgrp: 2424 = tcgetpgrp (1)
  128 2098059 [main] scp 2424 time: 1075220982 = time (0)
  171 2098230 [main] scp 2424 writev: writev (1, 0x22E200, 1)
  239 2098469 [main] scp 2424 fhandler_tty_slave::write: tty3, write(22E280, 126)
  133 2098602 [main] scp 2424 fhandler_tty_slave::write: (681): tty output_mutex: waiting -1 ms
  130 2098732 [main] scp 2424 fhandler_tty_slave::write: (681): tty output_mutex: acquired
  139 2098871 [main] scp 2424 fhandler_tty_slave::write: (724): tty output_mutex released
  118 2098989 [main] scp 2424 writev: 126 = write (1, 0x22E200, 1), errno 4
  121 2099110 [main] scp 2424 sigaction: signal 14, newact 0x0, oldact 0x22E470
  162 2099272 [main] scp 2424 set_signal_mask: oldmask 0x2000, newmask 0x0, mask_bits 0x2000
  137 2099409 [main] scp 2424 readv: -1 = readv (7, 0x22E570, 1), errno 4
  127 2099536 [main] scp 2424 readv: readv (7, 0x22E570, 1) blocking, sigcatchers 5
999083 3098619 [win] scp 2424 wndproc 275 WM_TIMER 1 0
  324 3098943 [win] scp 2424 kill: kill (2424, 14)
  666 3099609 [win] scp 2424 sig_send: sendsig 0x354, pid 2424, signal 14, its_me 1
  157 3099766 [win] scp 2424 sig_send: wakeup 0x2D4
  164 3099930 [sig] scp 2424 sig_handle: signal 14 processing
  122 3100052 [sig] scp 2424 sig_handle: signal 14, about to call 0x404F10
  121 3100173 [sig] scp 2424 proc_subproc: args: 3, 1
  110 3100283 [sig] scp 2424 proc_subproc: clear waiting threads
  112 3100395 [sig] scp 2424 proc_subproc: finished clearing
  105 3100500 [sig] scp 2424 proc_subproc: returning 1
  126 3100626 [sig] scp 2424 _threadinfo::interrupt_setup: armed signal_arrived 0x35C, sig 14, res 1
  106 3100732 [sig] scp 2424 setup_handler: interrupted known cygwin routine
  132 3100864 [sig] scp 2424 setup_handler: signal 14 delivered
  104 3100968 [sig] scp 2424 sig_handle: returning 1
  129 3101097 [sig] scp 2424 wait_sig: signalled 0x2D4
  154 3101251 [win] scp 2424 sig_send: Waiting for pack.wakeup 0x2D4
  133 3101384 [win] scp 2424 sig_send: returning 0x0 from sending signal 14
  115 3101499 [win] scp 2424 kill_worker: 0 = kill_worker (2424, 14), process_state 0x10C9
  782 3102281 [main] scp 2424 reset_signal_arrived: reset signal_arrived
  133 3102414 [main] scp 2424 set_signal_mask: oldmask 0x0, newmask 0x2000, mask_bits 0x0
  131 3102545 [main] scp 2424 set_signal_mask: not calling sig_dispatch_pending
  121 3102666 [main] scp 2424 tcgetpgrp: 2424 = tcgetpgrp (1)
  125 3102791 [main] scp 2424 time: 1075220983 = time (0)
  166 3102957 [main] scp 2424 writev: writev (1, 0x22E200, 1)
  120 3103077 [main] scp 2424 fhandler_tty_slave::write: tty3, write(22E280, 126)
  117 3103194 [main] scp 2424 fhandler_tty_slave::write: (681): tty output_mutex: waiting -1 ms
  123 3103317 [main] scp 2424 fhandler_tty_slave::write: (681): tty output_mutex: acquired
  137 3103454 [main] scp 2424 fhandler_tty_slave::write: (724): tty output_mutex released
  326 3103780 [main] scp 2424 writev: 126 = write (1, 0x22E200, 1), errno 4
  139 3103919 [main] scp 2424 sigaction: signal 14, newact 0x0, oldact 0x22E470
  158 3104077 [main] scp 2424 set_signal_mask: oldmask 0x2000, newmask 0x0, mask_bits 0x2000
  128 3104205 [main] scp 2424 readv: -1 = readv (7, 0x22E570, 1), errno 4
  121 3104326 [main] scp 2424 readv: readv (7, 0x22E570, 1) blocking, sigcatchers 5
996463 4100789 [win] scp 2424 wndproc 275 WM_TIMER 1 0
  304 4101093 [win] scp 2424 kill: kill (2424, 14)
  148 4101241 [win] scp 2424 sig_send: sendsig 0x354, pid 2424, signal 14, its_me 1
  136 4101377 [win] scp 2424 sig_send: wakeup 0x2D4
  152 4101529 [sig] scp 2424 sig_handle: signal 14 processing
  120 4101649 [sig] scp 2424 sig_handle: signal 14, about to call 0x404F10
  150 4101799 [sig] scp 2424 proc_subproc: args: 3, 1
  118 4101917 [sig] scp 2424 proc_subproc: clear waiting threads
  113 4102030 [sig] scp 2424 proc_subproc: finished clearing
  113 4102143 [sig] scp 2424 proc_subproc: returning 1
  109 4102252 [sig] scp 2424 _threadinfo::interrupt_setup: armed signal_arrived 0x35C, sig 14, res 1
  106 4102358 [sig] scp 2424 setup_handler: interrupted known cygwin routine
  111 4102469 [sig] scp 2424 setup_handler: signal 14 delivered
  103 4102572 [sig] scp 2424 sig_handle: returning 1
  114 4102686 [sig] scp 2424 wait_sig: signalled 0x2D4
  158 4102844 [win] scp 2424 sig_send: Waiting for pack.wakeup 0x2D4
  130 4102974 [win] scp 2424 sig_send: returning 0x0 from sending signal 14
  118 4103092 [win] scp 2424 kill_worker: 0 = kill_worker (2424, 14), process_state 0x10C9
  664 4103756 [main] scp 2424 reset_signal_arrived: reset signal_arrived
  138 4103894 [main] scp 2424 set_signal_mask: oldmask 0x0, newmask 0x2000, mask_bits 0x0
  123 4104017 [main] scp 2424 set_signal_mask: not calling sig_dispatch_pending
  126 4104143 [main] scp 2424 tcgetpgrp: 2424 = tcgetpgrp (1)
  127 4104270 [main] scp 2424 time: 1075220984 = time (0)
  169 4104439 [main] scp 2424 writev: writev (1, 0x22E200, 1)
  125 4104564 [main] scp 2424 fhandler_tty_slave::write: tty3, write(22E280, 126)
  119 4104683 [main] scp 2424 fhandler_tty_slave::write: (681): tty output_mutex: waiting -1 ms
  311 4104994 [main] scp 2424 fhandler_tty_slave::write: (681): tty output_mutex: acquired
  159 4105153 [main] scp 2424 fhandler_tty_slave::write: (724): tty output_mutex released
  126 4105279 [main] scp 2424 writev: 126 = write (1, 0x22E200, 1), errno 4
  182 4105461 [main] scp 2424 sigaction: signal 14, newact 0x0, oldact 0x22E470
  164 4105625 [main] scp 2424 set_signal_mask: oldmask 0x2000, newmask 0x0, mask_bits 0x2000
  140 4105765 [main] scp 2424 readv: -1 = readv (7, 0x22E570, 1), errno 4
  126 4105891 [main] scp 2424 readv: readv (7, 0x22E570, 1) blocking, sigcatchers 5
998113 5104004 [win] scp 2424 wndproc 275 WM_TIMER 1 0
110968 5214972 [win] scp 2424 kill: kill (2424, 14)
  224 5215196 [win] scp 2424 sig_send: sendsig 0x354, pid 2424, signal 14, its_me 1
  160 5215356 [win] scp 2424 sig_send: wakeup 0x2D4
  167 5215523 [sig] scp 2424 sig_handle: signal 14 processing
  122 5215645 [sig] scp 2424 sig_handle: signal 14, about to call 0x404F10
  125 5215770 [sig] scp 2424 proc_subproc: args: 3, 1
  111 5215881 [sig] scp 2424 proc_subproc: clear waiting threads
  111 5215992 [sig] scp 2424 proc_subproc: finished clearing
  105 5216097 [sig] scp 2424 proc_subproc: returning 1
  110 5216207 [sig] scp 2424 _threadinfo::interrupt_setup: armed signal_arrived 0x35C, sig 14, res 1
  133 5216340 [sig] scp 2424 setup_handler: interrupted known cygwin routine
  114 5216454 [sig] scp 2424 setup_handler: signal 14 delivered
  102 5216556 [sig] scp 2424 sig_handle: returning 1
  115 5216671 [sig] scp 2424 wait_sig: signalled 0x2D4
  156 5216827 [win] scp 2424 sig_send: Waiting for pack.wakeup 0x2D4
  135 5216962 [win] scp 2424 sig_send: returning 0x0 from sending signal 14
  117 5217079 [win] scp 2424 kill_worker: 0 = kill_worker (2424, 14), process_state 0x10C9
  633 5217712 [main] scp 2424 reset_signal_arrived: reset signal_arrived
  132 5217844 [main] scp 2424 set_signal_mask: oldmask 0x0, newmask 0x2000, mask_bits 0x0
  117 5217961 [main] scp 2424 set_signal_mask: not calling sig_dispatch_pending
  126 5218087 [main] scp 2424 tcgetpgrp: 2424 = tcgetpgrp (1)
  126 5218213 [main] scp 2424 time: 1075220985 = time (0)
  523 5218736 [main] scp 2424 writev: writev (1, 0x22E200, 1)
  170 5218906 [main] scp 2424 fhandler_tty_slave::write: tty3, write(22E280, 126)
  131 5219037 [main] scp 2424 fhandler_tty_slave::write: (681): tty output_mutex: waiting -1 ms
  121 5219158 [main] scp 2424 fhandler_tty_slave::write: (681): tty output_mutex: acquired
  157 5219315 [main] scp 2424 fhandler_tty_slave::write: (724): tty output_mutex released
  120 5219435 [main] scp 2424 writev: 126 = write (1, 0x22E200, 1), errno 4
  120 5219555 [main] scp 2424 sigaction: signal 14, newact 0x0, oldact 0x22E470
  561 5220116 [main] scp 2424 set_signal_mask: oldmask 0x2000, newmask 0x0, mask_bits 0x2000
  162 5220278 [main] scp 2424 readv: -1 = readv (7, 0x22E570, 1), errno 4
  629 5220907 [main] scp 2424 readv: readv (7, 0x22E570, 1) blocking, sigcatchers 5

-------------- next part --------------
--
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/


More information about the Cygwin mailing list