--timeout not honoured

Fabian Cenedese Cenedese at indel.ch
Fri Dec 18 05:29:16 MST 2009


At 14:19 16.12.2009 -0800, Wayne Davison wrote:
>On Tue, Dec 15, 2009 at 11:41 PM, Fabian Cenedese <<mailto:Cenedese at indel.ch>Cenedese at indel.ch> wrote:
>I think I know now where my confusion comes from. The reported time is not
>the actual time without action but the time since the start of the rsync command.
>
>
>It shouldn't be, since it is reporting the time elapsed since the last input was received. Â  I'd suggest running an strace on the rsync and seeing what it is doing. Â I'd imagine that some system call does not return for an extended amount of time, and then, when rsync finally gets control back and checks for the elapsed time since the last received input, it is a really long amount.

I now have a trace with a timeout case (almost 300MB). What do I need to look
for? I don't see immediately what part lead to the timeout. A short snippet:

13:18:51 ioctl(1, TIOCGPGRP, [17723])   = 0
13:18:51 write(1, "   955908096  45%   44.22kB/s   "..., 41) = 41
13:18:51 select(5, NULL, [4], [4], {60, 0}) = 1 (out [4], left {60, 0})
13:18:51 write(4, "\374\17\0\7", 4)     = 4
...
13:18:52 select(5, NULL, [4], [4], {60, 0}) = 1 (out [4], left {60, 0})
13:18:52 write(4, "qo\223\16\352\240\31z`\374;\350\203\374\2551\252\354\335"..., 4092) = 4092
13:18:52 time(NULL)                     = 1261138732
13:18:52 select(5, NULL, [4], [4], {60, 0}) = 1 (out [4], left {60, 0})
13:18:52 write(4, "\374\17\0\7", 4)     = 4
13:18:52 time(NULL)                     = 1261138732
13:18:52 select(5, NULL, [4], [4], {60, 0}) = 1 (out [4], left {60, 0})
13:18:52 write(4, "\367\344\356\325UUM3\273*<17\7\256D\255\225x0\345^{\203"..., 4092) = 4092
13:18:52 time(NULL)                     = 1261138732
13:18:52 select(5, NULL, [4], [4], {60, 0}) = 0 (Timeout)
13:19:52 time(NULL)                     = 1261138792
13:19:52 write(2, "io timeout after 9720 seconds --"..., 40) = 40
13:19:52 write(2, "\n", 1)              = 1
13:19:52 rt_sigaction(SIGUSR1, {SIG_IGN}, NULL, 8) = 0
13:19:52 rt_sigaction(SIGUSR2, {SIG_IGN}, NULL, 8) = 0

Should I trace with different flags?

Thanks

bye  Fabi

PS: I'll be away for two weeks so I can only give more info in the new year.



More information about the rsync mailing list