2017-09-21 14:37 GMT+02:00 Craig Barratt via BackupPC-users
<backuppc-users@lists.sourceforge.net>:
> I recommend running strace -p PID -T on the rsync_bpc process to see what it
> is up to, and how long various system calls take. I agree your backups
> should run much faster.
Here is an extract.
Some calls are really slow, more than 1 second.
They seems to be select, right ? Writes seems to be ok, less than 1/10 second
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3452] read(5, "75601860.M846377P28101.xx.gu"..., 8184) = 4081 <0.000035>
[pid 3452] select(6, [5], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3453] <... select resumed> ) = 1 (in [3], left {tv_sec=59,
tv_usec=220734}) <0.779284>
[pid 3453] read(3, "\374\17\0\7", 4) = 4 <0.000035>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0}) = 1 (in
[3], left {tv_sec=59, tv_usec=999998}) <0.000028>
[pid 3453] read(3, ".yy,S=1262266,W=1278715:2,"..., 4092) = 2896 <0.000034>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0}) = 1 (in
[3], left {tv_sec=59, tv_usec=999998}) <0.000029>
[pid 3453] read(3, "383235089.M974673P2358.xx.gu"..., 1196) = 1196 <0.000027>
[pid 3453] select(7, NULL, [6], [6], {tv_sec=60, tv_usec=0}) = 1 (out
[6], left {tv_sec=59, tv_usec=999998}) <0.000035>
[pid 3453] write(6, "381086351.M234084P17834.xx.g"..., 4087) = 4087 <0.000039>
[pid 3452] <... select resumed> ) = 1 (in [5], left {tv_sec=59,
tv_usec=220263}) <0.779785>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3452] read(5, "381086351.M234084P17834.xx.g"..., 8184) = 4087 <0.000040>
[pid 3452] select(6, [5], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3453] <... select resumed> ) = 1 (in [3], left {tv_sec=58,
tv_usec=683238}) <1.316780>
[pid 3453] read(3, "\374\17\0\7", 4) = 4 <0.000056>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0}) = 1 (in
[3], left {tv_sec=59, tv_usec=999998}) <0.000029>
[pid 3453] read(3,
"t,S=9113,W=9346:2,S\0\231#V\10\300,\270\215\21z\360\250"..., 4092) =
4092 <0.000028>
[pid 3453] select(7, NULL, [6], [6], {tv_sec=60, tv_usec=0}) = 1 (out
[6], left {tv_sec=59, tv_usec=999998}) <0.000047>
[pid 3453] write(6, "45773421.M45371P9859.xx.gues"..., 4091) = 4091 <0.000051>
[pid 3452] <... select resumed> ) = 1 (in [5], left {tv_sec=58,
tv_usec=682833}) <1.317230>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3452] read(5, "45773421.M45371P9859.xx.gues"..., 8184) = 4091 <0.000033>
[pid 3452] select(6, [5], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3453] <... select resumed> ) = 1 (in [3], left {tv_sec=58,
tv_usec=879335}) <1.120688>
[pid 3453] read(3, "\374\17\0\7", 4) = 4 <0.000057>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0}) = 1 (in
[3], left {tv_sec=59, tv_usec=999997}) <0.000029>
[pid 3453] read(3, ".it,S=17245,W=17685:2,S\0]CR\364\340\327Q\f"...,
4092) = 4092 <0.000026>
[pid 3453] select(7, NULL, [6], [6], {tv_sec=60, tv_usec=0}) = 1 (out
[6], left {tv_sec=59, tv_usec=999998}) <0.000064>
[pid 3453] write(6, "389990620.M619008P11470.xx.g"..., 4092) = 4092 <0.000051>
[pid 3452] <... select resumed> ) = 1 (in [5], left {tv_sec=58,
tv_usec=878920}) <1.121130>
[pid 3453] select(7, NULL, [6], [6], {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3452] read(5, <unfinished ...>
[pid 3453] <... select resumed> ) = 1 (out [6], left {tv_sec=59,
tv_usec=999998}) <0.000029>
[pid 3452] <... read resumed> "389990620.M619008P11470.xx.g"...,
8184) = 4092 <0.000032>
[pid 3453] write(6, "\333\32;^\26\252\321[:>8", 11 <unfinished ...>
[pid 3452] select(6, [5], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3453] <... write resumed> ) = 11 <0.000030>
[pid 3452] <... select resumed> ) = 1 (in [5], left {tv_sec=59,
tv_usec=999998}) <0.000026>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3452] read(5, "\333\32;^\26\252\321[:>8", 8184) = 11 <0.000011>
[pid 3452] select(6, [5], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3453] <... select resumed> ) = 1 (in [3], left {tv_sec=58,
tv_usec=696881}) <1.303136>
[pid 3453] read(3, "\374\17\0\7", 4) = 4 <0.000028>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0}) = 1 (in
[3], left {tv_sec=59, tv_usec=999998}) <0.000027>
[pid 3453] read(3, ".w4w.yy,S=1841,W=1902:2,S\0"..., 4092) = 2896 <0.000026>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0}) = 1 (in
[3], left {tv_sec=59, tv_usec=999866}) <0.000149>
[pid 3453] read(3, "s\311\34\344:>:74312186.M702139P19191.x3"...,
1196) = 1196 <0.000031>
[pid 3453] select(7, NULL, [6], [6], {tv_sec=60, tv_usec=0}) = 1 (out
[6], left {tv_sec=59, tv_usec=999998}) <0.000038>
[pid 3453] write(6, "14095904.M963616P21646.xx.gu"..., 4078) = 4078 <0.000048>
[pid 3452] <... select resumed> ) = 1 (in [5], left {tv_sec=58,
tv_usec=695988}) <1.304041>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3452] read(5, "14095904.M963616P21646.xx.gu"..., 8184) = 4078 <0.000017>
[pid 3452] select(6, [5], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3453] <... select resumed> ) = 1 (in [3], left {tv_sec=59,
tv_usec=48799}) <0.951218>
[pid 3453] read(3, "\374\17\0\7", 4) = 4 <0.000031>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0}) = 1 (in
[3], left {tv_sec=59, tv_usec=999998}) <0.000027>
[pid 3453] read(3,
"=7725,W=7949:2,S\0-\36W\374.2\206\231\353\206=\\lh\357"..., 4092) =
4092 <0.000030>
[pid 3453] select(7, NULL, [6], [6], {tv_sec=60, tv_usec=0}) = 1 (out
[6], left {tv_sec=59, tv_usec=999998}) <0.000066>
[pid 3453] write(6, "62907683.M495817P8522.xx.gue"..., 4087) = 4087 <0.000032>
[pid 3452] <... select resumed> ) = 1 (in [5], left {tv_sec=59,
tv_usec=48330}) <0.951701>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3452] read(5, "62907683.M495817P8522.xx.gue"..., 8184) = 4087 <0.000013>
[pid 3452] select(6, [5], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3453] <... select resumed> ) = 1 (in [3], left {tv_sec=59,
tv_usec=292969}) <0.707051>
[pid 3453] read(3, "\374\17\0\7", 4) = 4 <0.000051>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0}) = 1 (in
[3], left {tv_sec=59, tv_usec=999998}) <0.000027>
[pid 3453] read(3,
"36467,W=1759087:2,S\32\23\177R0\272\3020\370\225\231\307x"..., 4092)
= 2896 <0.000034>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0}) = 1 (in
[3], left {tv_sec=59, tv_usec=999998}) <0.000031>
[pid 3453] read(3,
"it,S=5228,W=5374:2,S\0l\24V\254\3057\351K<,\365"..., 1196) = 1196
<0.000024>
[pid 3453] select(7, NULL, [6], [6], {tv_sec=60, tv_usec=0}) = 1 (out
[6], left {tv_sec=59, tv_usec=999998}) <0.000046>
[pid 3453] write(6, "388521904.M589886P25714.xx.g"..., 4092) = 4092 <0.000020>
[pid 3452] <... select resumed> ) = 1 (in [5], left {tv_sec=59,
tv_usec=292313}) <0.707718>
[pid 3453] select(7, NULL, [6], [6], {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3452] read(5, <unfinished ...>
[pid 3453] <... select resumed> ) = 1 (out [6], left {tv_sec=59,
tv_usec=999998}) <0.000049>
[pid 3452] <... read resumed> "388521904.M589886P25714.xx.g"...,
8184) = 4092 <0.000076>
[pid 3453] write(6, ".xx.yy,S=15433,W=15784"..., 43 <unfinished ...>
[pid 3452] select(6, [5], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3453] <... write resumed> ) = 43 <0.000067>
[pid 3452] <... select resumed> ) = 1 (in [5], left {tv_sec=59,
tv_usec=999995}) <0.000093>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3452] read(5, ".xx.yy,S=15433,W=15784"..., 8184) = 43 <0.000010>
[pid 3452] select(6, [5], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3453] <... select resumed> ) = 1 (in [3], left {tv_sec=59,
tv_usec=422402}) <0.577631>
[pid 3453] read(3, "\374\17\0\7", 4) = 4 <0.000028>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0}) = 1 (in
[3], left {tv_sec=59, tv_usec=999997}) <0.000040>
[pid 3453] read(3,
"\273\327\360\323\254\7\31\266\361G\202k\257\27\252:?73238650.M93730"...,
4092) = 4092 <0.000061>
[pid 3453] select(7, NULL, [6], [6], {tv_sec=60, tv_usec=0}) = 1 (out
[6], left {tv_sec=59, tv_usec=999998}) <0.000048>
[pid 3453] write(6,
"\243\273\327\360\323\254\7\31\266\361G\202k\257\27\252:?73238650.M9373"...,
4092) = 4092 <0.000047>
[pid 3452] <... select resumed> ) = 1 (in [5], left {tv_sec=59,
tv_usec=421565}) <0.578463>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3452] read(5,
"\243\273\327\360\323\254\7\31\266\361G\202k\257\27\252:?73238650.M9373"...,
8184) = 4092 <0.000017>
[pid 3452] select(6, [5], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3453] <... select resumed> ) = 1 (in [3], left {tv_sec=59,
tv_usec=96783}) <0.903236>
[pid 3453] read(3, "\374\17\0\7", 4) = 4 <0.000036>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0}) = 1 (in
[3], left {tv_sec=59, tv_usec=999997}) <0.000042>
[pid 3453] read(3,
"8\27+:\32i\236Y\273zt%\276\220.\fRP):>803195573.M"..., 4092) = 4092
<0.000031>
[pid 3453] select(7, NULL, [6], [6], {tv_sec=60, tv_usec=0}) = 1 (out
[6], left {tv_sec=59, tv_usec=999997}) <0.000033>
[pid 3453] write(6,
"X8\27+:\32i\236Y\273zt%\276\220.\fRP):>803195573."..., 4081) = 4081
<0.000044>
[pid 3452] <... select resumed> ) = 1 (in [5], left {tv_sec=59,
tv_usec=96242}) <0.903793>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3452] read(5,
"X8\27+:\32i\236Y\273zt%\276\220.\fRP):>803195573."..., 8184) = 4081
<0.000012>
[pid 3452] select(6, [5], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3453] <... select resumed> ) = 1 (in [3], left {tv_sec=59,
tv_usec=122772}) <0.877256>
[pid 3453] read(3, "\374\17\0\7", 4) = 4 <0.000049>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0}) = 1 (in
[3], left {tv_sec=59, tv_usec=999998}) <0.000027>
[pid 3453] read(3, "w\256n&:>818677495.M413127P21674.x3"..., 4092) =
4092 <0.000029>
[pid 3453] select(7, NULL, [6], [6], {tv_sec=60, tv_usec=0}) = 1 (out
[6], left {tv_sec=59, tv_usec=999998}) <0.000032>
[pid 3453] write(6,
"\222\236c\214]0I\322l\337\332\225w\256n&:>818677495.M413"..., 4092) =
4092 <0.000030>
[pid 3452] <... select resumed> ) = 1 (in [5], left {tv_sec=59,
tv_usec=122191}) <0.877835>
[pid 3453] select(7, NULL, [6], [6], {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3452] read(5, <unfinished ...>
[pid 3453] <... select resumed> ) = 1 (out [6], left {tv_sec=59,
tv_usec=999998}) <0.000044>
[pid 3452] <... read resumed>
"\222\236c\214]0I\322l\337\332\225w\256n&:>818677495.M413"..., 8184) =
4092 <0.000076>
[pid 3453] write(6, ":>9", 3 <unfinished ...>
[pid 3452] select(6, [5], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3453] <... write resumed> ) = 3 <0.000063>
[pid 3452] <... select resumed> ) = 1 (in [5], left {tv_sec=59,
tv_usec=999998}) <0.000054>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3452] read(5, ":>9", 8184) = 3 <0.000010>
[pid 3452] select(6, [5], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3453] <... select resumed> ) = 1 (in [3], left {tv_sec=59,
tv_usec=183807}) <0.816216>
[pid 3453] read(3, "\374\17\0\7", 4) = 4 <0.000043>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0}) = 1 (in
[3], left {tv_sec=59, tv_usec=999998}) <0.000032>
[pid 3453] read(3, "M631163P4170.xx.yy,S=7"..., 4092) = 4092 <0.000038>
[pid 3453] select(7, NULL, [6], [6], {tv_sec=60, tv_usec=0}) = 1 (out
[6], left {tv_sec=59, tv_usec=999998}) <0.000057>
[pid 3453] write(6, "63990838.M631163P4170.xx.gue"..., 4076) = 4076 <0.000069>
[pid 3452] <... select resumed> ) = 1 (in [5], left {tv_sec=59,
tv_usec=183238}) <0.816799>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3452] read(5, "63990838.M631163P4170.xx.gue"..., 8184) = 4076 <0.000021>
[pid 3452] select(6, [5], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3453] <... select resumed> ) = 1 (in [3], left {tv_sec=58,
tv_usec=539207}) <1.460809>
[pid 3453] read(3, "\374\17\0\7", 4) = 4 <0.000043>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0}) = 1 (in
[3], left {tv_sec=59, tv_usec=999998}) <0.000026>
[pid 3453] read(3, ".w4w.yy,S=6494,W=6699:2,RS"..., 4092) = 2896 <0.000030>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0}) = 1 (in
[3], left {tv_sec=59, tv_usec=999998}) <0.000036>
[pid 3453] read(3, "k}\253X\2\363\31:=;473885307.M728931P3170"...,
1196) = 1196 <0.000025>
[pid 3453] select(7, NULL, [6], [6], {tv_sec=60, tv_usec=0}) = 1 (out
[6], left {tv_sec=59, tv_usec=999998}) <0.000042>
[pid 3453] write(6, "503951001.M607392P4777.xx.gu"..., 4090) = 4090 <0.000028>
[pid 3452] <... select resumed> ) = 1 (in [5], left {tv_sec=58,
tv_usec=538591}) <1.461439>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3452] read(5, "503951001.M607392P4777.xx.gu"..., 8184) = 4090 <0.000012>
[pid 3452] select(6, [5], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3453] <... select resumed> ) = 1 (in [3], left {tv_sec=58,
tv_usec=296355}) <1.703661>
[pid 3453] read(3, "\374\17\0\7", 4) = 4 <0.000037>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0}) = 1 (in
[3], left {tv_sec=59, tv_usec=999998}) <0.000026>
[pid 3453] read(3, "4w.yy,S=16037,W=16517:2,S\0"..., 4092) = 4092 <0.000026>
[pid 3453] select(7, NULL, [6], [6], {tv_sec=60, tv_usec=0}) = 1 (out
[6], left {tv_sec=59, tv_usec=999998}) <0.000046>
[pid 3453] write(6, "60039418.M312936P14203.xx.gu"..., 4086) = 4086 <0.000033>
[pid 3452] <... select resumed> ) = 1 (in [5], left {tv_sec=58,
tv_usec=295880}) <1.704151>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3452] read(5, "60039418.M312936P14203.xx.gu"..., 8184) = 4086 <0.000023>
[pid 3452] select(6, [5], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3453] <... select resumed> ) = 1 (in [3], left {tv_sec=59,
tv_usec=85648}) <0.914375>
[pid 3453] read(3, "\374\17\0\7", 4) = 4 <0.000031>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0}) = 1 (in
[3], left {tv_sec=59, tv_usec=999997}) <0.000033>
[pid 3453] read(3, "st.it,S=78663,W=79986:2,S\1G3Y@\354["..., 4092) =
4092 <0.000029>
[pid 3453] select(7, NULL, [6], [6], {tv_sec=60, tv_usec=0}) = 1 (out
[6], left {tv_sec=59, tv_usec=999998}) <0.000034>
[pid 3453] write(6, "99197968.M916400P16550.xx.gu"..., 4092) = 4092 <0.000033>
[pid 3452] <... select resumed> ) = 1 (in [5], left {tv_sec=59,
tv_usec=85128}) <0.914899>
[pid 3453] select(7, NULL, [6], [6], {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3452] read(5, <unfinished ...>
[pid 3453] <... select resumed> ) = 1 (out [6], left {tv_sec=59,
tv_usec=999998}) <0.000029>
[pid 3452] <... read resumed> "99197968.M916400P16550.xx.gu"...,
8184) = 4092 <0.000107>
[pid 3453] write(6, "\245\252:=7", 5 <unfinished ...>
[pid 3452] select(6, [5], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3453] <... write resumed> ) = 5 <0.000033>
[pid 3452] <... select resumed> ) = 1 (in [5], left {tv_sec=59,
tv_usec=999998}) <0.000058>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3452] read(5, "\245\252:=7", 8184) = 5 <0.000010>
[pid 3452] select(6, [5], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3453] <... select resumed> ) = 1 (in [3], left {tv_sec=58,
tv_usec=366327}) <1.633690>
[pid 3453] read(3, "\374\17\0\7", 4) = 4 <0.000041>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0}) = 1 (in
[3], left {tv_sec=59, tv_usec=999998}) <0.000031>
[pid 3453] read(3, ".yy,S=6026,W=6181:2,S\0\212\27W4"..., 4092) =
2896 <0.000024>
[pid 3453] select(4, [3], [], NULL, {tv_sec=60, tv_usec=0}) = 1 (in
[3], left {tv_sec=59, tv_usec=999912}) <0.000104>
[pid 3453] read(3, "795.M725315P7800.xx.yy"..., 1196) = 1196 <0.000030>
[pid 3453] select(7, NULL, [6], [6], {tv_sec=60, tv_usec=0}) = 1 (out
[6], left {tv_sec=59, tv_usec=999998}) <0.000033>
[pid 3453] write(6, "464813873.M17845P5815.xx.gue"..., 4092) = 4092 <0.000028>
[pid 3452] <... select resumed> ) = 1 (in [5], left {tv_sec=58,
tv_usec=365511}) <1.634515>
[pid 3453] select(7, NULL, [6], [6], {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3452] read(5, <unfinished ...>
[pid 3453] <... select resumed> ) = 1 (out [6], left {tv_sec=59,
tv_usec=999998}) <0.000054>
[pid 3452] <... read resumed> "464813873.M17845P5815.xx.gue"...,
8184) = 4092 <0.000069>
[pid 3453] write(6, ";C\215\371\320:>9", 8 <unfinished ...>
[pid 3452] select(6, [5], [], NULL, {tv_sec=60, tv_usec=0} <unfinished ...>
[pid 3453] <... write resumed> ) = 8 <0.000076>
------------------------------------------------------------------------------
Check out the vibrant tech community on one of the world's most
engaging tech sites, Slashdot.org! http://sdm.link/slashdot
_______________________________________________
BackupPC-users mailing list
BackupPC-users@lists.sourceforge.net
List: https://lists.sourceforge.net/lists/listinfo/backuppc-users
Wiki: http://backuppc.wiki.sourceforge.net
Project: http://backuppc.sourceforge.net/
