Re: SCP doesn't complete transfers of large files

[Dirk Sondermann <Dirk dot Sondermann at dynaware dot de>]

Igor Pechtchanski wrote:
> 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 attachment is the output of strace which was produced after
the state of the scp process had changed to 'stalled'.

At that time, 280,743,936 of a total of 280,751,683 bytes had been
transferred from a remote host to the local host.

Dirk

    4       4 [win] scp 156 wndproc 275 WM_TIMER 1 0
  200     204 [win] scp 156 kill: kill (156, 14)
   53     257 [win] scp 156 sig_send: pid 156, signal 14, its_me 1
   52     309 [win] scp 156 sig_send: Waiting for pack.wakeup 0x75C
   62     371 [sig] scp 156 sig_handle: signal 14 processing
   41     412 [sig] scp 156 sig_handle: signal 14, about to call 0x404F10
   41     453 [sig] scp 156 proc_subproc: args: 3, 1
   49     502 [sig] scp 156 proc_subproc: clear waiting threads
   36     538 [sig] scp 156 proc_subproc: finished clearing
   35     573 [sig] scp 156 proc_subproc: returning 1
   53     626 [sig] scp 156 _threadinfo::interrupt_setup: armed signal_arrived 0x768, sig 14, res 1
   36     662 [sig] scp 156 setup_handler: interrupted known cygwin routine
  114     776 [sig] scp 156 setup_handler: signal 14 delivered
   29     805 [sig] scp 156 sig_handle: returning 1
   39     844 [win] scp 156 sig_send: returning 0x0 from sending signal 14
   29     873 [win] scp 156 kill_worker: 0 = kill_worker (156, 14), process_state 0x4C9
  181    1054 [main] scp 156 reset_signal_arrived: reset signal_arrived
   32    1086 [main] scp 156 set_signal_mask: oldmask 0x0, newmask 0x2000, mask_bits 0x0
   28    1114 [main] scp 156 set_signal_mask: not calling sig_dispatch_pending
   34    1148 [main] scp 156 tcgetpgrp: 156 = tcgetpgrp (1)
   35    1183 [main] scp 156 time: 1075369195 = time (0)
   55    1238 [main] scp 156 writev: writev (1, 0x22E200, 1)
   29    1267 [main] scp 156 fhandler_console::write: 22E280, 161
   29    1296 [main] scp 156 fhandler_console::write: at 13(0x20) state is 0
   77    1373 [main] scp 156 fhandler_console::write: at 109(m) state is 0
  171    1544 [main] scp 156 fhandler_console::write: 161 = write_console (,..161)
   36    1580 [main] scp 156 writev: 161 = write (1, 0x22E200, 1), errno 4
   31    1611 [main] scp 156 sigaction: signal 14, newact 0x0, oldact 0x22E470
   52    1663 [main] scp 156 set_signal_mask: oldmask 0x2000, newmask 0x0, mask_bits 0x2000
   29    1692 [main] scp 156 readv: -1 = readv (7, 0x22E570, 1), errno 4
   33    1725 [main] scp 156 readv: readv (7, 0x22E570, 1) blocking, sigcatchers 5
1003460 1005185 [win] scp 156 wndproc 275 WM_TIMER 1 0
   89 1005274 [win] scp 156 kill: kill (156, 14)
   33 1005307 [win] scp 156 sig_send: pid 156, signal 14, its_me 1
   39 1005346 [win] scp 156 sig_send: Waiting for pack.wakeup 0x75C
   35 1005381 [sig] scp 156 sig_handle: signal 14 processing
   27 1005408 [sig] scp 156 sig_handle: signal 14, about to call 0x404F10
   29 1005437 [sig] scp 156 proc_subproc: args: 3, 1
   27 1005464 [sig] scp 156 proc_subproc: clear waiting threads
   24 1005488 [sig] scp 156 proc_subproc: finished clearing
   25 1005513 [sig] scp 156 proc_subproc: returning 1
   25 1005538 [sig] scp 156 _threadinfo::interrupt_setup: armed signal_arrived 0x768, sig 14, res 1
   25 1005563 [sig] scp 156 setup_handler: interrupted known cygwin routine
   25 1005588 [sig] scp 156 setup_handler: signal 14 delivered
   24 1005612 [sig] scp 156 sig_handle: returning 1
   37 1005649 [win] scp 156 sig_send: returning 0x0 from sending signal 14
   28 1005677 [win] scp 156 kill_worker: 0 = kill_worker (156, 14), process_state 0x4C9
  185 1005862 [main] scp 156 reset_signal_arrived: reset signal_arrived
   33 1005895 [main] scp 156 set_signal_mask: oldmask 0x0, newmask 0x2000, mask_bits 0x0
   28 1005923 [main] scp 156 set_signal_mask: not calling sig_dispatch_pending
   33 1005956 [main] scp 156 tcgetpgrp: 156 = tcgetpgrp (1)
   34 1005990 [main] scp 156 time: 1075369196 = time (0)
   54 1006044 [main] scp 156 writev: writev (1, 0x22E200, 1)
   30 1006074 [main] scp 156 fhandler_console::write: 22E280, 161
   29 1006103 [main] scp 156 fhandler_console::write: at 13(0x20) state is 0
   82 1006185 [main] scp 156 fhandler_console::write: at 109(m) state is 0
  166 1006351 [main] scp 156 fhandler_console::write: 161 = write_console (,..161)
   35 1006386 [main] scp 156 writev: 161 = write (1, 0x22E200, 1), errno 4
   30 1006416 [main] scp 156 sigaction: signal 14, newact 0x0, oldact 0x22E470
  158 1006574 [main] scp 156 set_signal_mask: oldmask 0x2000, newmask 0x0, mask_bits 0x2000
   35 1006609 [main] scp 156 readv: -1 = readv (7, 0x22E570, 1), errno 4
   33 1006642 [main] scp 156 readv: readv (7, 0x22E570, 1) blocking, sigcatchers 5
997727 2004369 [win] scp 156 wndproc 275 WM_TIMER 1 0
   98 2004467 [win] scp 156 kill: kill (156, 14)
   29 2004496 [win] scp 156 sig_send: pid 156, signal 14, its_me 1
   39 2004535 [win] scp 156 sig_send: Waiting for pack.wakeup 0x75C
   34 2004569 [sig] scp 156 sig_handle: signal 14 processing
   27 2004596 [sig] scp 156 sig_handle: signal 14, about to call 0x404F10
   30 2004626 [sig] scp 156 proc_subproc: args: 3, 1
   26 2004652 [sig] scp 156 proc_subproc: clear waiting threads
   25 2004677 [sig] scp 156 proc_subproc: finished clearing
   25 2004702 [sig] scp 156 proc_subproc: returning 1
   25 2004727 [sig] scp 156 _threadinfo::interrupt_setup: armed signal_arrived 0x768, sig 14, res 1
   26 2004753 [sig] scp 156 setup_handler: interrupted known cygwin routine
   25 2004778 [sig] scp 156 setup_handler: signal 14 delivered
   24 2004802 [sig] scp 156 sig_handle: returning 1
   37 2004839 [win] scp 156 sig_send: returning 0x0 from sending signal 14
   28 2004867 [win] scp 156 kill_worker: 0 = kill_worker (156, 14), process_state 0x4C9
  173 2005040 [main] scp 156 reset_signal_arrived: reset signal_arrived
   31 2005071 [main] scp 156 set_signal_mask: oldmask 0x0, newmask 0x2000, mask_bits 0x0
   28 2005099 [main] scp 156 set_signal_mask: not calling sig_dispatch_pending
   33 2005132 [main] scp 156 tcgetpgrp: 156 = tcgetpgrp (1)
   35 2005167 [main] scp 156 time: 1075369197 = time (0)
   53 2005220 [main] scp 156 writev: writev (1, 0x22E200, 1)
   31 2005251 [main] scp 156 fhandler_console::write: 22E280, 161
   28 2005279 [main] scp 156 fhandler_console::write: at 13(0x20) state is 0
   83 2005362 [main] scp 156 fhandler_console::write: at 109(m) state is 0
  163 2005525 [main] scp 156 fhandler_console::write: 161 = write_console (,..161)
   37 2005562 [main] scp 156 writev: 161 = write (1, 0x22E200, 1), errno 4
   31 2005593 [main] scp 156 sigaction: signal 14, newact 0x0, oldact 0x22E470
   51 2005644 [main] scp 156 set_signal_mask: oldmask 0x2000, newmask 0x0, mask_bits 0x2000
   29 2005673 [main] scp 156 readv: -1 = readv (7, 0x22E570, 1), errno 4
   32 2005705 [main] scp 156 readv: readv (7, 0x22E570, 1) blocking, sigcatchers 5
998858 3004563 [win] scp 156 wndproc 275 WM_TIMER 1 0
  102 3004665 [win] scp 156 kill: kill (156, 14)
   30 3004695 [win] scp 156 sig_send: pid 156, signal 14, its_me 1
   40 3004735 [win] scp 156 sig_send: Waiting for pack.wakeup 0x75C
   34 3004769 [sig] scp 156 sig_handle: signal 14 processing
   28 3004797 [sig] scp 156 sig_handle: signal 14, about to call 0x404F10
   29 3004826 [sig] scp 156 proc_subproc: args: 3, 1
   27 3004853 [sig] scp 156 proc_subproc: clear waiting threads
   25 3004878 [sig] scp 156 proc_subproc: finished clearing
   25 3004903 [sig] scp 156 proc_subproc: returning 1
   25 3004928 [sig] scp 156 _threadinfo::interrupt_setup: armed signal_arrived 0x768, sig 14, res 1
   26 3004954 [sig] scp 156 setup_handler: interrupted known cygwin routine
   24 3004978 [sig] scp 156 setup_handler: signal 14 delivered
   25 3005003 [sig] scp 156 sig_handle: returning 1
   37 3005040 [win] scp 156 sig_send: returning 0x0 from sending signal 14
   29 3005069 [win] scp 156 kill_worker: 0 = kill_worker (156, 14), process_state 0x4C9
  171 3005240 [main] scp 156 reset_signal_arrived: reset signal_arrived
   32 3005272 [main] scp 156 set_signal_mask: oldmask 0x0, newmask 0x2000, mask_bits 0x0
   28 3005300 [main] scp 156 set_signal_mask: not calling sig_dispatch_pending
   33 3005333 [main] scp 156 tcgetpgrp: 156 = tcgetpgrp (1)
   34 3005367 [main] scp 156 time: 1075369198 = time (0)
   52 3005419 [main] scp 156 writev: writev (1, 0x22E200, 1)
   30 3005449 [main] scp 156 fhandler_console::write: 22E280, 161
  145 3005594 [main] scp 156 fhandler_console::write: at 13(0x20) state is 0
   83 3005677 [main] scp 156 fhandler_console::write: at 109(m) state is 0
  171 3005848 [main] scp 156 fhandler_console::write: 161 = write_console (,..161)
   36 3005884 [main] scp 156 writev: 161 = write (1, 0x22E200, 1), errno 4
   32 3005916 [main] scp 156 sigaction: signal 14, newact 0x0, oldact 0x22E470
   53 3005969 [main] scp 156 set_signal_mask: oldmask 0x2000, newmask 0x0, mask_bits 0x2000
   30 3005999 [main] scp 156 readv: -1 = readv (7, 0x22E570, 1), errno 4
   32 3006031 [main] scp 156 readv: readv (7, 0x22E570, 1) blocking, sigcatchers 5
1004737 4010768 [win] scp 156 wndproc 275 WM_TIMER 1 0
   84 4010852 [win] scp 156 kill: kill (156, 14)
   33 4010885 [win] scp 156 sig_send: pid 156, signal 14, its_me 1
   38 4010923 [win] scp 156 sig_send: Waiting for pack.wakeup 0x75C
   34 4010957 [sig] scp 156 sig_handle: signal 14 processing
   27 4010984 [sig] scp 156 sig_handle: signal 14, about to call 0x404F10
   29 4011013 [sig] scp 156 proc_subproc: args: 3, 1
   27 4011040 [sig] scp 156 proc_subproc: clear waiting threads
   25 4011065 [sig] scp 156 proc_subproc: finished clearing
   26 4011091 [sig] scp 156 proc_subproc: returning 1
   25 4011116 [sig] scp 156 _threadinfo::interrupt_setup: armed signal_arrived 0x768, sig 14, res 1
   26 4011142 [sig] scp 156 setup_handler: interrupted known cygwin routine
   24 4011166 [sig] scp 156 setup_handler: signal 14 delivered
   25 4011191 [sig] scp 156 sig_handle: returning 1
   37 4011228 [win] scp 156 sig_send: returning 0x0 from sending signal 14
   28 4011256 [win] scp 156 kill_worker: 0 = kill_worker (156, 14), process_state 0x4C9
  167 4011423 [main] scp 156 reset_signal_arrived: reset signal_arrived
   31 4011454 [main] scp 156 set_signal_mask: oldmask 0x0, newmask 0x2000, mask_bits 0x0
   29 4011483 [main] scp 156 set_signal_mask: not calling sig_dispatch_pending
   33 4011516 [main] scp 156 tcgetpgrp: 156 = tcgetpgrp (1)
   35 4011551 [main] scp 156 time: 1075369199 = time (0)
   54 4011605 [main] scp 156 writev: writev (1, 0x22E200, 1)
   29 4011634 [main] scp 156 fhandler_console::write: 22E280, 161
   28 4011662 [main] scp 156 fhandler_console::write: at 13(0x20) state is 0
   82 4011744 [main] scp 156 fhandler_console::write: at 109(m) state is 0
  166 4011910 [main] scp 156 fhandler_console::write: 161 = write_console (,..161)
   36 4011946 [main] scp 156 writev: 161 = write (1, 0x22E200, 1), errno 4
   30 4011976 [main] scp 156 sigaction: signal 14, newact 0x0, oldact 0x22E470
   51 4012027 [main] scp 156 set_signal_mask: oldmask 0x2000, newmask 0x0, mask_bits 0x2000
   29 4012056 [main] scp 156 readv: -1 = readv (7, 0x22E570, 1), errno 4
   32 4012088 [main] scp 156 readv: readv (7, 0x22E570, 1) blocking, sigcatchers 5
1000877 5012965 [win] scp 156 wndproc 275 WM_TIMER 1 0
   90 5013055 [win] scp 156 kill: kill (156, 14)
   33 5013088 [win] scp 156 sig_send: pid 156, signal 14, its_me 1
   40 5013128 [win] scp 156 sig_send: Waiting for pack.wakeup 0x75C
   35 5013163 [sig] scp 156 sig_handle: signal 14 processing
   28 5013191 [sig] scp 156 sig_handle: signal 14, about to call 0x404F10
   30 5013221 [sig] scp 156 proc_subproc: args: 3, 1
   27 5013248 [sig] scp 156 proc_subproc: clear waiting threads
   25 5013273 [sig] scp 156 proc_subproc: finished clearing
   25 5013298 [sig] scp 156 proc_subproc: returning 1
   25 5013323 [sig] scp 156 _threadinfo::interrupt_setup: armed signal_arrived 0x768, sig 14, res 1
   26 5013349 [sig] scp 156 setup_handler: interrupted known cygwin routine
   25 5013374 [sig] scp 156 setup_handler: signal 14 delivered
   24 5013398 [sig] scp 156 sig_handle: returning 1
   38 5013436 [win] scp 156 sig_send: returning 0x0 from sending signal 14
   28 5013464 [win] scp 156 kill_worker: 0 = kill_worker (156, 14), process_state 0x4C9
  161 5013625 [main] scp 156 reset_signal_arrived: reset signal_arrived
   30 5013655 [main] scp 156 set_signal_mask: oldmask 0x0, newmask 0x2000, mask_bits 0x0
   44 5013699 [main] scp 156 set_signal_mask: not calling sig_dispatch_pending
   35 5013734 [main] scp 156 tcgetpgrp: 156 = tcgetpgrp (1)
   35 5013769 [main] scp 156 time: 1075369200 = time (0)
   55 5013824 [main] scp 156 writev: writev (1, 0x22E200, 1)
   29 5013853 [main] scp 156 fhandler_console::write: 22E280, 161
   29 5013882 [main] scp 156 fhandler_console::write: at 13(0x20) state is 0
   88 5013970 [main] scp 156 fhandler_console::write: at 109(m) state is 0
  165 5014135 [main] scp 156 fhandler_console::write: 161 = write_console (,..161)
   36 5014171 [main] scp 156 writev: 161 = write (1, 0x22E200, 1), errno 4
   30 5014201 [main] scp 156 sigaction: signal 14, newact 0x0, oldact 0x22E470
   52 5014253 [main] scp 156 set_signal_mask: oldmask 0x2000, newmask 0x0, mask_bits 0x2000
   31 5014284 [main] scp 156 readv: -1 = readv (7, 0x22E570, 1), errno 4
   32 5014316 [main] scp 156 readv: readv (7, 0x22E570, 1) blocking, sigcatchers 5
993823 6008139 [win] scp 156 wndproc 275 WM_TIMER 1 0
   90 6008229 [win] scp 156 kill: kill (156, 14)
   29 6008258 [win] scp 156 sig_send: pid 156, signal 14, its_me 1
   38 6008296 [win] scp 156 sig_send: Waiting for pack.wakeup 0x75C
   34 6008330 [sig] scp 156 sig_handle: signal 14 processing
   28 6008358 [sig] scp 156 sig_handle: signal 14, about to call 0x404F10
   29 6008387 [sig] scp 156 proc_subproc: args: 3, 1
   26 6008413 [sig] scp 156 proc_subproc: clear waiting threads
   25 6008438 [sig] scp 156 proc_subproc: finished clearing
   25 6008463 [sig] scp 156 proc_subproc: returning 1
   26 6008489 [sig] scp 156 _threadinfo::interrupt_setup: armed signal_arrived 0x768, sig 14, res 1
   25 6008514 [sig] scp 156 setup_handler: interrupted known cygwin routine
   25 6008539 [sig] scp 156 setup_handler: signal 14 delivered
   24 6008563 [sig] scp 156 sig_handle: returning 1
   37 6008600 [win] scp 156 sig_send: returning 0x0 from sending signal 14
   29 6008629 [win] scp 156 kill_worker: 0 = kill_worker (156, 14), process_state 0x4C9
  171 6008800 [main] scp 156 reset_signal_arrived: reset signal_arrived
   30 6008830 [main] scp 156 set_signal_mask: oldmask 0x0, newmask 0x2000, mask_bits 0x0
   28 6008858 [main] scp 156 set_signal_mask: not calling sig_dispatch_pending
   33 6008891 [main] scp 156 tcgetpgrp: 156 = tcgetpgrp (1)
   35 6008926 [main] scp 156 time: 1075369201 = time (0)
   52 6008978 [main] scp 156 writev: writev (1, 0x22E200, 1)
   30 6009008 [main] scp 156 fhandler_console::write: 22E280, 161
   28 6009036 [main] scp 156 fhandler_console::write: at 13(0x20) state is 0
   85 6009121 [main] scp 156 fhandler_console::write: at 109(m) state is 0
  165 6009286 [main] scp 156 fhandler_console::write: 161 = write_console (,..161)
   36 6009322 [main] scp 156 writev: 161 = write (1, 0x22E200, 1), errno 4
   30 6009352 [main] scp 156 sigaction: signal 14, newact 0x0, oldact 0x22E470
   50 6009402 [main] scp 156 set_signal_mask: oldmask 0x2000, newmask 0x0, mask_bits 0x2000
   29 6009431 [main] scp 156 readv: -1 = readv (7, 0x22E570, 1), errno 4
   33 6009464 [main] scp 156 readv: readv (7, 0x22E570, 1) blocking, sigcatchers 5
997864 7007328 [win] scp 156 wndproc 275 WM_TIMER 1 0
   93 7007421 [win] scp 156 kill: kill (156, 14)
   29 7007450 [win] scp 156 sig_send: pid 156, signal 14, its_me 1
   40 7007490 [win] scp 156 sig_send: Waiting for pack.wakeup 0x75C
   34 7007524 [sig] scp 156 sig_handle: signal 14 processing
   28 7007552 [sig] scp 156 sig_handle: signal 14, about to call 0x404F10
   29 7007581 [sig] scp 156 proc_subproc: args: 3, 1
   27 7007608 [sig] scp 156 proc_subproc: clear waiting threads
   25 7007633 [sig] scp 156 proc_subproc: finished clearing
   25 7007658 [sig] scp 156 proc_subproc: returning 1
   25 7007683 [sig] scp 156 _threadinfo::interrupt_setup: armed signal_arrived 0x768, sig 14, res 1
   26 7007709 [sig] scp 156 setup_handler: interrupted known cygwin routine
   24 7007733 [sig] scp 156 setup_handler: signal 14 delivered
   25 7007758 [sig] scp 156 sig_handle: returning 1
   37 7007795 [win] scp 156 sig_send: returning 0x0 from sending signal 14
  127 7007922 [win] scp 156 kill_worker: 0 = kill_worker (156, 14), process_state 0x4C9
  178 7008100 [main] scp 156 reset_signal_arrived: reset signal_arrived
   31 7008131 [main] scp 156 set_signal_mask: oldmask 0x0, newmask 0x2000, mask_bits 0x0
   29 7008160 [main] scp 156 set_signal_mask: not calling sig_dispatch_pending
   33 7008193 [main] scp 156 tcgetpgrp: 156 = tcgetpgrp (1)
   34 7008227 [main] scp 156 time: 1075369202 = time (0)
   53 7008280 [main] scp 156 writev: writev (1, 0x22E200, 1)
   37 7008317 [main] scp 156 fhandler_console::write: 22E280, 161
   29 7008346 [main] scp 156 fhandler_console::write: at 13(0x20) state is 0
   75 7008421 [main] scp 156 fhandler_console::write: at 109(m) state is 0
  168 7008589 [main] scp 156 fhandler_console::write: 161 = write_console (,..161)
   35 7008624 [main] scp 156 writev: 161 = write (1, 0x22E200, 1), errno 4
   31 7008655 [main] scp 156 sigaction: signal 14, newact 0x0, oldact 0x22E470
   52 7008707 [main] scp 156 set_signal_mask: oldmask 0x2000, newmask 0x0, mask_bits 0x2000
   30 7008737 [main] scp 156 readv: -1 = readv (7, 0x22E570, 1), errno 4
   32 7008769 [main] scp 156 readv: readv (7, 0x22E570, 1) blocking, sigcatchers 5

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