[Bug 15163] rsync timeout non-effective and incorrect behaviour

[samba-bugs at samba.org]

https://bugzilla.samba.org/show_bug.cgi?id=15163

--- Comment #3 from roland <devzero at web.de> ---
ah, getting a clue

in io.c

static void check_timeout(BOOL allow_keepalive, int keepalive_flags)
{
        time_t t, chk;

        /* On the receiving side, the generator is now the one that decides
         * when a timeout has occurred.  When it is sifting through a lot of
         * files looking for work, it will be sending keep-alive messages to
         * the sender, and even though the receiver won't be sending/receiving
         * anything (not even keep-alive messages), the successful writes to
         * the sender will keep things going.  If the receiver is actively
         * receiving data, it will ensure that the generator knows that it is
         * not idle by sending the generator keep-alive messages (since the
         * generator might be blocked trying to send checksums, it needs to
         * know that the receiver is active).  Thus, as long as one or the
         * other is successfully doing work, the generator will not timeout. */
        if (!io_timeout)
                return;

        t = time(NULL);

        if (allow_keepalive) {
                /* This may put data into iobuf.msg w/o flushing. */
                maybe_send_keepalive(t, keepalive_flags);
        }

        if (!last_io_in)
                last_io_in = t;

        if (am_receiver)
                return;

        chk = MAX(last_io_out, last_io_in);
        if (t - chk >= io_timeout) {
                if (am_server)
                        msgs2stderr = 1;
                rprintf(FERROR, "[%s] io timeout after %d seconds --
exiting\n",
                        who_am_i(), (int)(t-chk));
                exit_cleanup(RERR_TIMEOUT);
        }
}


so , apparently when syncing "/" instead of "/iscsipool", keepalive messages
come into the play....

i see keepalive messages getting sent, but the are NOT replied by the remote
rsync machine, as strace shows. there is only sshd process actively processing
data.


 | 00000  00 00 00 07                                       ....             |
[pid 131555] 09:57:47.454101 select(14, [4 5 11 13], [], NULL, NULL) = 1 (in
[4])
[pid 131555] 09:57:50.455771 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 131555] 09:57:50.455887 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 131555] 09:57:50.455963 read(4, "\0\0\0
\v\10\372\371(\256V\16$\17\375Z5\252Km-\357\311~A\352\202\232\365\234\33>"...,
16384) = 44
[pid 131555] 09:57:50.456064 select(14, [4 5 11 13], [10], NULL, NULL) = 1 (out
[10])
[pid 131555] 09:57:50.456225 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 131555] 09:57:50.456745 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 131555] 09:57:50.456950 write(10, "\0\0\0\7", 4) = 4
 | 00000  00 00 00 07                                       ....             |
[pid 131555] 09:57:50.457163 select(14, [4 5 11 13], [], NULL, NULL) = 1 (in
[4])
[pid 131555] 09:57:53.459934 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 131555] 09:57:53.460391 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 131555] 09:57:53.460602 read(4, "\0\0\0
\303M\204S\275D\23r\225a\210\247Q\314\256\373]\\C\27\246\241\265\212\235\210\312o"...,
16384) = 44
[pid 131555] 09:57:53.460817 select(14, [4 5 11 13], [10], NULL, NULL) = 1 (out
[10])
[pid 131555] 09:57:53.461023 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 131555] 09:57:53.461221 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 131555] 09:57:53.461314 write(10, "\0\0\0\7", 4) = 4
 | 00000  00 00 00 07                                       ....             |
[pid 131555] 09:57:53.461526 select(14, [4 5 11 13], [], NULL, NULL) = 1 (in
[4])
[pid 131555] 09:57:56.463410 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 131555] 09:57:56.463858 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 131555] 09:57:56.464211 read(4, "\0\0\0
\367\270\356\21\304-u\200cQ\16\350UAo\264*\231B\303\275\250\221Nzo\33\231"...,
16384) = 44
[pid 131555] 09:57:56.464336 select(14, [4 5 11 13], [10], NULL, NULL) = 1 (out
[10])
[pid 131555] 09:57:56.464684 rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
[pid 131555] 09:57:56.464915 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid 131555] 09:57:56.465239 write(10, "\0\0\0\7", 4) = 4
 | 00000  00 00 00 07                                       ....             |
[pid 131555] 09:57:56.465354 select(14, [4 5 11 13], [], NULL, NULL^Z
[1]+  Angehalten              strace -f -p 131431 -tt -e write=all


root at debian:~# ps -ef|grep 131555
root      131555  131431  0 09:57 ?        00:00:00 sshd: root at notty
root      131562  131555  3 09:57 ?        00:00:02 rsync --server --sender
-vlogDtpre.iLsfxCIvu --timeout=5 . /
root      131565  131540  0 09:58 pts/1    00:00:00 grep 131555

-- 
You are receiving this mail because:
You are the QA Contact for the bug.