Large amount of files and big file size sync problems

I’ve been using Syncthing for a couple of weeks now with the purpose of replacing btsync. The main goal is to have the Master server untouched and mirror it to 1 or more external servers. On my test environment, with no more than 100 Gb, everything works as it suppose to. But when I start using it on the real server, with about 17 Tb of data, the first scan gets stock randomly. sometimes takes one hour, sometimes a bit more… but same result… never ending the sync and no errors shown.

I did a STTRACE=scanner and I can see when it stops scanning: … [WFCO5] 2015/11/06 09:24:40.423531 walk.go:165: DEBUG: Walk /test/ [] current progress 1361337744206/8253257992257 (16%)

[WFCO5] 2015/11/06 09:24:42.423437 walk.go:165: DEBUG: Walk /test/ [] current progress 1361546279758/8253257992257 (16%)

[WFCO5] 2015/11/06 09:24:44.423412 walk.go:165: DEBUG: Walk /test/ [] current progress 1361756781390/8253257992257 (16%)

[WFCO5] 2015/11/06 09:24:46.423384 walk.go:165: DEBUG: Walk /test/ [] current progress 1361969380174/8253257992257 (16%)

[WFCO5] 2015/11/06 09:24:48.423430 walk.go:165: DEBUG: Walk /test/ [] current progress 1362184076110/8253257992257 (16%)

[WFCO5] 2015/11/06 09:24:50.423506 walk.go:165: DEBUG: Walk /test/ [] current progress 1362404670286/8253257992257 (16%)

[WFCO5] 2015/11/06 09:24:52.423551 walk.go:165: DEBUG: Walk /test/ [] current progress 1362623429454/8253257992257 (16%)

[WFCO5] 2015/11/06 09:24:54.423601 walk.go:165: DEBUG: Walk /test/ [] current progress 1362837207886/8253257992257 (16%)

[WFCO5] 2015/11/06 09:24:56.423476 walk.go:165: DEBUG: Walk /test/ [] current progress 1363050855246/8253257992257 (16%)

[WFCO5] 2015/11/06 09:24:58.423484 walk.go:165: DEBUG: Walk /test/ [] current progress 1363264240462/8253257992257 (16%)

[WFCO5] 2015/11/06 09:25:00.423679 walk.go:165: DEBUG: Walk /test/ [] current progress 1363345467856/8253257992257 (16%)

[WFCO5] 2015/11/06 09:25:02.423465 walk.go:165: DEBUG: Walk /test/ [] current progress 1363345467856/8253257992257 (16%)

[WFCO5] 2015/11/06 09:25:04.423483 walk.go:165: DEBUG: Walk /test/ [] current progress 1363345467856/8253257992257 (16%)

[WFCO5] 2015/11/06 09:25:06.423445 walk.go:165: DEBUG: Walk /test/ [] current progress 1363345467856/8253257992257 (16%)

[WFCO5] 2015/11/06 09:25:08.423444 walk.go:165: DEBUG: Walk /test/ [] current progress 1363345467856/8253257992257 (16%)

[WFCO5] 2015/11/06 09:25:10.423439 walk.go:165: DEBUG: Walk /test/ [] current progress 1363345467856/8253257992257 (16%)

[WFCO5] 2015/11/06 09:25:12.423447 walk.go:165: DEBUG: Walk /test/ [] current progress 1363345467856/8253257992257 (16%)

[WFCO5] 2015/11/06 09:25:14.423457 walk.go:165: DEBUG: Walk /test/ [] current progress 1363345467856/8253257992257 (16%)

[WFCO5] 2015/11/06 09:25:16.423451 walk.go:165: DEBUG: Walk /test/ [] current progress 1363345467856/8253257992257 (16%)

[WFCO5] 2015/11/06 09:25:18.423448 walk.go:165: DEBUG: Walk /test/ [] current progress 1363345467856/8253257992257 (16%)

Sending a rescan duplicates the log.

curl -X POST -H “X-API-Key: sasasasasasasas” http://localhost:8384/rest/db/scan?folder=test_test

[WFCO5] 2015/11/06 09:54:48.437103 walk.go:165: DEBUG: Walk /test/ [] current progress 1363345467856/8253257992257 (16%)

[WFCO5] 2015/11/06 09:54:49.577894 walk.go:165: DEBUG: Walk /test/ [] current progress 2627319172/8123991285608 (0%)

[WFCO5] 2015/11/06 09:54:50.424500 walk.go:165: DEBUG: Walk /test/ [] current progress 1363345467856/8253257992257 (16%)

[WFCO5] 2015/11/06 09:54:51.582824 walk.go:165: DEBUG: Walk /test/ [] current progress 4019565956/8123991285608 (0%)

[WFCO5] 2015/11/06 09:54:52.457541 walk.go:165: DEBUG: Walk /test/ [] current progress 1363345467856/8253257992257 (16%)

[WFCO5] 2015/11/06 09:54:53.577861 walk.go:165: DEBUG: Walk /test/ [] current progress 5482984836/8123991285608 (0%)

[WFCO5] 2015/11/06 09:54:54.423413 walk.go:165: DEBUG: Walk /test/ [] current progress 1363345467856/8253257992257 (16%)

[WFCO5] 2015/11/06 09:54:55.577834 walk.go:165: DEBUG: Walk /test/ [] current progress 6689895812/8123991285608 (0%)

[WFCO5] 2015/11/06 09:54:56.429127 walk.go:165: DEBUG: Walk /test/ [] current progress 1363345467856/8253257992257 (16%)

[WFCO5] 2015/11/06 09:54:57.577843 walk.go:165: DEBUG: Walk /test/ [] current progress 8203908484/8123991285608 (0%)

[WFCO5] 2015/11/06 09:54:58.435662 walk.go:165: DEBUG: Walk /test/ [] current progress 1363345467856/8253257992257 (16%)

[WFCO5] 2015/11/06 09:54:59.577833 walk.go:165: DEBUG: Walk /test/ [] current progress 9728144772/8123991285608 (0%)

[WFCO5] 2015/11/06 09:55:00.446908 walk.go:165: DEBUG: Walk /test/ [] current progress 1363345467856/8253257992257 (16%)

[WFCO5] 2015/11/06 09:55:01.579589 walk.go:165: DEBUG: Walk /test/ [] current progress 11251201412/8123991285608 (0%)

[WFCO5] 2015/11/06 09:55:02.423392 walk.go:165: DEBUG: Walk /test/ [] current progress 1363345467856/8253257992257 (16%)

[WFCO5] 2015/11/06 09:55:03.579176 walk.go:165: DEBUG: Walk /test/ [] current progress 12757611908/8123991285608 (0%)

The only way to keep scanning is by restarting either through CLI or the Web Interface.

Any help on this?

Does it use any CPU while stuck like this? What’s the last few lines of debug output before it’s gets stuck in this nonsense?

The CPU goes from 50% to 90% when it is scanning. But when it stays stock, show 0.0some%, so no cpu usage at all.

The lines I showed are the last lines. if you see the lines in bold, those are the lines showing the scan not growing any more and stays like that until I send the reset.

… [WFCO5] 2015/11/06 09:25:12.423447 walk.go:165: DEBUG: Walk /test/ [] current progress 1363345467856/8253257992257 (16%)

[WFCO5] 2015/11/06 09:25:14.423457 walk.go:165: DEBUG: Walk /test/ [] current progress 1363345467856/8253257992257 (16%)

[WFCO5] 2015/11/06 09:25:16.423451 walk.go:165: DEBUG: Walk /test/ [] current progress 1363345467856/8253257992257 (16%)

[WFCO5] 2015/11/06 09:25:18.423448 walk.go:165: DEBUG: Walk /test/ [] current progress 1363345467856/8253257992257 (16%) …

RAM is not an issue that I can notice. usage stays around 1 to 4 gb.

Last lines yes, but what are the last lines showing actual activity before we get stuck with no progress?

Before getting stock, on the LOG file:

15:56:20.723752 table[at]build created L2[at]107973 N ·146 S ·12MiB “\x00CH…ata,v155660701”:"\x00CH…mov,d155657126"

15:56:20.765542 table[at]compaction committed F-1 S-12MiB Ke ·0 D ·73 T ·590.077453ms

15:56:20.765814 table[at]compaction L0 ·4 -> L1 ·1 S ·14MiB Q ·155658949

15:56:20.875068 memdb[at]flush N ·2 S ·18MiB

15:56:21.041036 table[at]build created L1[at]107974 N ·39 S ·3MiB “\x00CH…ata,v155661367”:"\x00CH…mov,v155661443"

15:56:21.658012 memdb[at]flush created L0[at]107976 N ·2 S ·15MiB “\x00CH…mov,v155661664”:"\x01CH…mov,v155661665"

15:56:21.708118 memdb[at]flush committed F ·1 T ·666.939854ms

15:56:21.712609 journal[at]remove removed [at]107966

15:56:22.265092 table[at]build created L1[at]107977 N ·108 S ·6MiB “\x00CH…mov,v155661445”:"\x00CH…mov,v155661659"

15:56:22.458892 table[at]build created L1[at]107978 N ·1 S ·4MiB “\x00CH…mov,v155661662”:"\x00CH…mov,v155661662"

15:56:22.500799 table[at]build created L1[at]107979 N ·740 S ·26KiB “\x01CH…mov,v155660184”:"\x01CH…mov,v155661663"

15:56:22.542755 table[at]compaction committed F-1 S-1KiB Ke ·0 D ·0 T ·1.776873299s

15:56:22.544271 table[at]compaction L1 ·1 -> L2 ·1 S ·24MiB Q ·155658949

15:56:23.063212 memdb[at]flush N ·860 S ·443KiB

15:56:23.102652 table[at]build created L2[at]107980 N ·2 S ·12MiB “\x00CH…mov,v155660847”:"\x00CH…mov,d155657128"

15:56:23.144602 table[at]compaction committed F-1 S-12MiB Ke ·0 D ·1 T ·600.263535ms

15:56:23.195001 memdb[at]flush created L0[at]107982 N ·860 S ·170KiB “\x00CH…ata,v155661666”:"\x01CH…tif,v155662525"

15:56:23.236792 memdb[at]flush committed F ·1 T ·92.047571ms

15:56:23.237089 journal[at]remove removed [at]107975

15:56:23.238200 memdb[at]flush N ·144 S ·7MiB

15:56:23.503903 memdb[at]flush created L0[at]107984 N ·144 S ·6MiB “\x00CH…ata,v155662526”:"\x01CH…mov,v155662669"

15:56:23.545732 memdb[at]flush committed F ·1 T ·307.418022ms

15:56:23.548987 journal[at]remove removed [at]107981

15:56:25.564217 memdb[at]flush N ·216 S ·11MiB

15:56:25.959716 memdb[at]flush created L0[at]107986 N ·216 S ·9MiB “\x00CH…ata,v155662670”:"\x01CH…mov,v155662885"

15:56:26.001593 memdb[at]flush committed F ·1 T ·437.268711ms

15:56:26.004432 journal[at]remove removed [at]107983

15:56:26.004764 table[at]compaction L0 ·4 -> L1 ·1 S ·32MiB Q ·155658949

15:56:26.605062 table[at]build created L1[at]107987 N ·1 S ·15MiB “\x00CH…mov,v155661664”:"\x00CH…mov,v155661664"

15:56:26.902338 table[at]build created L1[at]107988 N ·502 S ·6MiB “\x00CH…ata,v155661666”:"\x00CH…mov,v155662668"

15:56:26.910754 memdb[at]flush N ·288 S ·10MiB

15:56:27.477860 table[at]build created L1[at]107989 N ·108 S ·9MiB “\x00CH…ata,v155662670”:"\x00CH…mov,v155662884"

15:56:27.861519 memdb[at]flush created L0[at]107991 N ·288 S ·8MiB “\x00CH…ata,v155662886”:"\x01CH…mov,v155663173"

15:56:27.914572 memdb[at]flush committed F ·1 T ·436.574447ms

15:56:27.916786 journal[at]remove removed [at]107985

15:56:27.917672 memdb[at]flush N ·362 S ·6MiB

15:56:27.964989 table[at]build created L1[at]107992 N ·1351 S ·47KiB “\x01CH…mov,v155660184”:"\x01CH…mov,v155662885"

15:56:28.006816 table[at]compaction committed F-1 S-352B Ke ·0 D ·0 T ·2.001970162s

15:56:28.265538 memdb[at]flush created L0[at]107994 N ·362 S ·5MiB “\x00CH…ata,v155663174”:"\x01CH…mov,v155663535"

15:56:28.332533 memdb[at]flush committed F ·1 T ·325.586511ms

15:56:28.335896 journal[at]remove removed [at]107990

15:56:28.337251 memdb[at]flush N ·2 S ·5MiB

15:56:28.338117 table[at]compaction L1 ·1 -> L2 ·1 S ·13MiB Q ·155658949

15:56:28.555060 memdb[at]flush created L0[at]107996 N ·2 S ·4MiB “\x00CH…mov,v155663536”:"\x01CH…mov,v155663537"

15:56:28.605913 memdb[at]flush committed F ·1 T ·267.014422ms

15:56:28.608387 journal[at]remove removed [at]107993

15:56:28.933686 table[at]build created L2[at]107997 N ·110 S ·6MiB “\x00CH…mov,v155660849”:"\x00CH…mov,v155661067"

15:56:29.000547 table[at]compaction committed F-1 S-6MiB Ke ·0 D ·220 T ·662.28756ms

15:56:29.003275 table[at]compaction L1 ·1 -> L2 ·1 S ·8MiB Q ·155658949

15:56:29.060529 memdb[at]flush N ·72 S ·5MiB

15:56:29.192773 table[at]build created L2[at]107998 N ·1 S ·4MiB “\x00CH…mov,v155661069”:"\x00CH…mov,v155661069"

15:56:29.234554 table[at]compaction committed F-1 S-4MiB Ke ·0 D ·2 T ·231.193322ms

15:56:29.459828 memdb[at]flush created L0[at]108000 N ·72 S ·4MiB “\x00CH…ata,v155663538”:"\x01CH…mov,v155663609"

15:56:29.501715 memdb[at]flush committed F ·1 T ·267.045712ms

15:56:29.504301 journal[at]remove removed [at]107995

15:56:29.505250 memdb[at]flush N ·362 S ·3MiB

15:56:29.507099 table[at]compaction L1 ·1 -> L2 ·1 S ·24MiB Q ·155658949

15:56:29.703440 memdb[at]flush created L0[at]108002 N ·362 S ·3MiB “\x00CH…ata,v155663610”:"\x01CH…mov,v155663971"

15:56:29.745245 memdb[at]flush committed F ·1 T ·182.931365ms

15:56:29.746173 journal[at]remove removed [at]107999

15:56:29.912099 memdb[at]flush N ·8 S ·3MiB

15:56:30.345701 table[at]build created L2[at]108003 N ·1 S ·12MiB “\x00CH…mov,v155661071”:"\x00CH…mov,v155661071"

15:56:30.384516 table[at]compaction committed F-1 S-12MiB Ke ·0 D ·2 T ·877.316102ms

15:56:30.546251 memdb[at]flush created L0[at]108005 N ·8 S ·2MiB “\x00CH…mov,v155663972”:"\x01CH…mov,v155663979"

15:56:30.588016 memdb[at]flush committed F ·1 T ·203.360978ms

15:56:30.588971 journal[at]remove removed [at]108001

15:56:30.589283 table[at]compaction L0 ·6 -> L1 ·1 S ·29MiB Q ·155658949

15:56:31.171833 table[at]build created L1[at]108006 N ·144 S ·8MiB “\x00CH…ata,v155662886”:"\x00CH…mov,v155663172"

15:56:31.422183 table[at]build created L1[at]108007 N ·181 S ·5MiB “\x00CH…ata,v155663174”:"\x00CH…mov,v155663534"

15:56:31.689142 table[at]build created L1[at]108008 N ·1 S ·4MiB “\x00CH…mov,v155663536”:"\x00CH…mov,v155663536"

15:56:31.919724 table[at]build created L1[at]108009 N ·36 S ·4MiB “\x00CH…ata,v155663538”:"\x00CH…mov,v155663608"

15:56:32.086762 table[at]build created L1[at]108010 N ·181 S ·3MiB “\x00CH…ata,v155663610”:"\x00CH…mov,v155663970"

15:56:32.228889 table[at]build created L1[at]108011 N ·2 S ·2MiB “\x00CH…mov,v155663972”:"\x00CH…mov,v155663974"

15:56:32.320719 table[at]build created L1[at]108012 N ·2 S ·850KiB “\x00CH…mov,v155663976”:"\x00CH…mov,v155663978"

15:56:32.518018 table[at]build created L1[at]108013 N ·1898 S ·66KiB “\x01CH…mov,v155660184”:"\x01CH…mov,v155663979"

15:56:32.579734 table[at]compaction committed F+1 S-238B Ke ·0 D ·0 T ·1.990377709s

15:56:32.581853 table[at]move L1[at]107955 -> L2

15:56:32.634051 table[at]move L1[at]107956 -> L2

15:56:32.698839 table[at]move L1[at]107959 -> L2

15:56:34.843160 table[at]compaction L2 ·1 -> L3 ·1 S ·6MiB Q ·155658949

15:56:34.887780 memdb[at]flush N ·4004 S ·3MiB

15:56:35.122105 table[at]build created L3[at]108014 N ·298 S ·4MiB “\x00CH…ata,v69230371”:"\x00CH…mov,v148914307"

15:56:35.250457 memdb[at]flush created L0[at]108016 N ·4004 S ·2MiB “\x00CH…mov,v155663980”:"\x01CH…gIt,v155667983"

15:56:35.297586 memdb[at]flush committed F ·1 T ·175.347838ms

15:56:35.298622 journal[at]remove removed [at]108004

15:56:35.492767 table[at]build created L3[at]108017 N ·28173 S ·1MiB “\x00CH…ata,v69230767”:"\x02CH…mov,v92469894"

15:56:35.534650 table[at]compaction committed F~ S-10KiB Ke ·0 D ·540 T ·691.354299ms

15:57:04.276463 table[at]compaction L0 ·1 -> L1 ·1 S ·2MiB Q ·155658949

15:57:04.449800 table[at]build created L1[at]108018 N ·2 S ·2MiB “\x00CH…mov,v155663980”:"\x00CH…mov,v155663982"

15:57:04.498344 table[at]build created L1[at]108019 N ·2000 S ·103KiB “\x00CH…ata,v155663984”:"\x00CH…gIt,v155667982"

15:57:04.550454 table[at]build created L1[at]108020 N ·3900 S ·125KiB “\x01CH…mov,v155660184”:"\x01CH…gIt,v155667983"

15:57:04.601954 table[at]compaction committed F+1 S+3KiB Ke ·0 D ·0 T ·325.371965ms

then nothing else shows.

This is the wrong log, this is the db log. Run with STTRACE=all and redirect output to file and get the last few hundred lines.

Also, try setting scanProgressInterval to 0 to disable scanning progress in hopes of resolving the deadlock.

You already had the right log output, I’m just asking for earlier messages as the ones you posted doesn’t tell us what happened to get it stuck in this state.

I tried with the scanProgressInterval to 0 but it still gets stock. With STTRACE=all, I get too much data (Gbytes of space on the log in just a few minutes). I runned it with STTRACE=db,events,scanner,stats and this is the last 600 lines before it fails:

[WR65A] 2015/11/06 16:24:56.176628 walk.go:176: DEBUG: real to hash: dr_001/4514/15bd/34ea/416e/8947/889b/868c/22ed/102618967-451415bd-34ea-416e-8947-889b868c22ed/data/logs/transfers/102618967-87c39463-2caf-4b0d-840b-70675ee1d234/logs/BagIt/bag-info.txt

[WR65A] 2015/11/06 16:24:56.198420 walk.go:176: DEBUG: real to hash: dr_001/4514/15bd/34ea/416e/8947/889b/868c/22ed/102618967-451415bd-34ea-416e-8947-889b868c22ed/data/logs/transfers/102618967-87c39463-2caf-4b0d-840b-70675ee1d234/logs/BagIt/bagit.txt

[WR65A] 2015/11/06 16:24:56.201442 walk.go:176: DEBUG: real to hash: dr_001/4514/15bd/34ea/416e/8947/889b/868c/22ed/102618967-451415bd-34ea-416e-8947-889b868c22ed/data/logs/transfers/102618967-87c39463-2caf-4b0d-840b-70675ee1d234/logs/BagIt/tagmanifest-md5.txt

[WR65A] 2015/11/06 16:24:56.242762 walk.go:176: DEBUG: real to hash: dr_001/4514/15bd/34ea/416e/8947/889b/868c/22ed/102618967-451415bd-34ea-416e-8947-889b868c22ed/data/logs/transfers/102618967-87c39463-2caf-4b0d-840b-70675ee1d234/logs/fileFormatIdentification.log

[WR65A] 2015/11/06 16:24:56.246904 walk.go:176: DEBUG: real to hash: dr_001/4514/15bd/34ea/416e/8947/889b/868c/22ed/102618967-451415bd-34ea-416e-8947-889b868c22ed/data/objects/102618967/dec_pdp-8.woman_at_pdp8.102618967.src.tif

[WR65A] 2015/11/06 16:24:56.247376 walk.go:176: DEBUG: real to hash: dr_001/4514/15bd/34ea/416e/8947/889b/868c/22ed/102618967-451415bd-34ea-416e-8947-889b868c22ed/data/objects/metadata/transfers/102618967-87c39463-2caf-4b0d-840b-70675ee1d234/manifest-md5.txt

[WR65A] 2015/11/06 16:24:57.675471 walk.go:165: DEBUG: Walk /test/ [] current progress 1026841854687/10594042121544 (9%)

[WR65A] 2015/11/06 16:24:57.675535 events.go:141: DEBUG: log 1188 FolderScanProgress map[folder:CHM_Main current:1026841854687 total:10594042121544]

[WR65A] 2015/11/06 16:24:57.675560 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:24:58.132381 walk.go:176: DEBUG: real to hash: dr_001/4514/15bd/34ea/416e/8947/889b/868c/22ed/102618967-451415bd-34ea-416e-8947-889b868c22ed/data/objects/metadata/transfers/102618967-87c39463-2caf-4b0d-840b-70675ee1d234/metadata.csv

[WR65A] 2015/11/06 16:24:58.134339 walk.go:176: DEBUG: real to hash: dr_001/4514/15bd/34ea/416e/8947/889b/868c/22ed/102618967-451415bd-34ea-416e-8947-889b868c22ed/data/objects/submissionDocumentation/transfer-102618967-87c39463-2caf-4b0d-840b-70675ee1d234/METS.xml

[WR65A] 2015/11/06 16:24:58.140776 walk.go:176: DEBUG: real to hash: dr_001/4514/15bd/34ea/416e/8947/889b/868c/22ed/102618967-451415bd-34ea-416e-8947-889b868c22ed/manifest-sha512.txt

[WR65A] 2015/11/06 16:24:58.148225 walk.go:176: DEBUG: real to hash: dr_001/4514/15bd/34ea/416e/8947/889b/868c/22ed/102618967-451415bd-34ea-416e-8947-889b868c22ed/tagmanifest-md5.txt

[WR65A] 2015/11/06 16:24:58.152186 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/bag-info.txt

[WR65A] 2015/11/06 16:24:58.161549 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/bagit.txt

[WR65A] 2015/11/06 16:24:58.223932 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/METS.45a39883-760e-44ab-9a85-08760bba7ff6.xml

[WR65A] 2015/11/06 16:24:58.260366 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/logs/fileFormatIdentification.log

[WR65A] 2015/11/06 16:24:58.561493 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/logs/transfers/102746421-20125535-fa0b-4e2d-b42b-1237ec5c6a24/logs/BagIt/bag-info.txt

[WR65A] 2015/11/06 16:24:58.563032 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/logs/transfers/102746421-20125535-fa0b-4e2d-b42b-1237ec5c6a24/logs/BagIt/bagit.txt

[WR65A] 2015/11/06 16:24:58.563052 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/logs/transfers/102746421-20125535-fa0b-4e2d-b42b-1237ec5c6a24/logs/BagIt/tagmanifest-md5.txt

[WR65A] 2015/11/06 16:24:58.567488 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/logs/transfers/102746421-20125535-fa0b-4e2d-b42b-1237ec5c6a24/logs/fileFormatIdentification.log

[WR65A] 2015/11/06 16:24:58.578981 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/logs/transfers/102746421-20125535-fa0b-4e2d-b42b-1237ec5c6a24/logs/filenameCleanup.log

[WR65A] 2015/11/06 16:24:58.581690 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/objects/102746421/Clip__1.mov

[WR65A] 2015/11/06 16:24:58.603732 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/objects/102746421/Clip__10.mov

[WR65A] 2015/11/06 16:24:59.684114 walk.go:165: DEBUG: Walk /test/ [] current progress 1027940097701/10594042121544 (9%)

[WR65A] 2015/11/06 16:24:59.684185 events.go:141: DEBUG: log 1189 FolderScanProgress map[folder:CHM_Main current:1027940097701 total:10594042121544]

[WR65A] 2015/11/06 16:24:59.684210 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:25:01.675790 walk.go:165: DEBUG: Walk /test/ [] current progress 1029247540901/10594042121544 (9%)

[WR65A] 2015/11/06 16:25:01.675857 events.go:141: DEBUG: log 1190 FolderScanProgress map[total:10594042121544 folder:CHM_Main current:1029247540901]

[WR65A] 2015/11/06 16:25:01.676019 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:25:01.995133 events.go:141: DEBUG: log 1191 FolderSummary map[folder:CHM_Main summary:map[globalBytes:2082241930648 localDeleted:0 needFiles:0 ignorePatterns:false invalid: globalFiles:9670 globalDeleted:0 localFiles:9670 inSyncBytes:2082241930648 inSyncFiles:9670 state:scanning stateChanged:2015-11-06 15:56:09.675227573 -0800 PST localBytes:2082241930648 needBytes:0 version:9675]]

[WR65A] 2015/11/06 16:25:01.995188 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:25:03.679902 walk.go:165: DEBUG: Walk /test/ [] current progress 1030354050725/10594042121544 (9%)

[WR65A] 2015/11/06 16:25:03.679964 events.go:141: DEBUG: log 1192 FolderScanProgress map[total:10594042121544 folder:CHM_Main current:1030354050725]

[WR65A] 2015/11/06 16:25:03.679987 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:25:05.675473 walk.go:165: DEBUG: Walk /test/ [] current progress 1031633837733/10594042121544 (9%)

[WR65A] 2015/11/06 16:25:05.675533 events.go:141: DEBUG: log 1193 FolderScanProgress map[folder:CHM_Main current:1031633837733 total:10594042121544]

[WR65A] 2015/11/06 16:25:05.675556 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:25:07.685586 walk.go:165: DEBUG: Walk /test/ [] current progress 1032909168293/10594042121544 (9%)

[WR65A] 2015/11/06 16:25:07.685661 events.go:141: DEBUG: log 1194 FolderScanProgress map[folder:CHM_Main current:1032909168293 total:10594042121544]

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

[WR65A] 2015/11/06 16:25:54.197535 events.go:141: DEBUG: log 1220 FolderSummary map[folder:CHM_Main summary:map[globalDeleted:0 localFiles:9699 needFiles:0 inSyncBytes:2089017902927 globalFiles:9699 globalBytes:2089017902927 localBytes:2089017902927 state:scanning version:9704 ignorePatterns:false invalid: localDeleted:0 inSyncFiles:9699 stateChanged:2015-11-06 15:56:09.675227573 -0800 PST needBytes:0]]

[WR65A] 2015/11/06 16:25:54.197796 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:25:55.675536 walk.go:165: DEBUG: Walk /test/ [] current progress 1063276083743/10594042121544 (10%)

[WR65A] 2015/11/06 16:25:55.675600 events.go:141: DEBUG: log 1221 FolderScanProgress map[folder:CHM_Main current:1063276083743 total:10594042121544]

[WR65A] 2015/11/06 16:25:55.675627 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:25:56.001191 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/objects/102746421/Clip__13.mov

[WR65A] 2015/11/06 16:25:57.613307 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/objects/102746421/Clip__14.mov

[WR65A] 2015/11/06 16:25:57.670138 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/objects/102746421/Clip__15.mov

[WR65A] 2015/11/06 16:25:57.675484 walk.go:165: DEBUG: Walk /test/ [] current progress 1064517944840/10594042121544 (10%)

[WR65A] 2015/11/06 16:25:57.675538 events.go:141: DEBUG: log 1222 FolderScanProgress map[folder:CHM_Main current:1064517944840 total:10594042121544]

[WR65A] 2015/11/06 16:25:57.675562 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:25:57.677830 events.go:141: DEBUG: log 1223 LocalIndexUpdated map[folder:CHM_Main items:3 version:9707]

[WR65A] 2015/11/06 16:25:57.677858 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:25:58.306111 events.go:141: DEBUG: log 1224 FolderSummary map[folder:CHM_Main summary:map[globalFiles:9702 globalBytes:2089343674161 localFiles:9702 inSyncFiles:9702 inSyncBytes:2089343674161 ignorePatterns:false invalid: needFiles:0 needBytes:0 state:scanning version:9707 localDeleted:0 localBytes:2089343674161 stateChanged:2015-11-06 15:56:09.675227573 -0800 PST globalDeleted:0]]

[WR65A] 2015/11/06 16:25:58.306204 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:25:59.205143 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/objects/102746421/Clip__2.mov

[WR65A] 2015/11/06 16:25:59.696299 walk.go:165: DEBUG: Walk /test/ [] current progress 1065526949652/10594042121544 (10%)

[WR65A] 2015/11/06 16:25:59.696536 events.go:141: DEBUG: log 1225 FolderScanProgress map[current:1065526949652 total:10594042121544 folder:CHM_Main]

[WR65A] 2015/11/06 16:25:59.696590 events.go:194: DEBUG: poll 1m0s

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

[WR65A] 2015/11/06 16:53:41.675514 walk.go:165: DEBUG: Walk /test/ [] current progress 1362187019449/10594042121544 (12%)

[WR65A] 2015/11/06 16:53:41.675578 events.go:141: DEBUG: log 2085 FolderScanProgress map[current:1362187019449 total:10594042121544 folder:CHM_Main]

[WR65A] 2015/11/06 16:53:43.675583 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:53:45.675542 walk.go:165: DEBUG: Walk /test/ [] current progress 1362589541561/10594042121544 (12%)

[WR65A] 2015/11/06 16:53:45.675630 events.go:141: DEBUG: log 2087 FolderScanProgress map[folder:CHM_Main current:1362589541561 total:10594042121544]

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

[WR65A] 2015/11/06 16:59:01.675526 walk.go:165: DEBUG: Walk /test/ [] current progress 1394495874233/10594042121544 (13%)

[WR65A] 2015/11/06 16:59:01.675591 events.go:141: DEBUG: log 2250 FolderScanProgress map[folder:CHM_Main current:1394495874233 total:10594042121544]

[WR65A] 2015/11/06 16:59:01.675617 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:59:03.675507 walk.go:165: DEBUG: Walk /test/ [] current progress 1394704671929/10594042121544 (13%)

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

[WR65A] 2015/11/06 17:00:39.675519 events.go:141: DEBUG: log 2301 FolderScanProgress map[folder:CHM_Main current:1404304909497 total:10594042121544]

[WR65A] 2015/11/06 17:00:39.675544 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:00:41.675569 walk.go:165: DEBUG: Walk /test/ [] current progress 1404509643961/10594042121544 (13%)

[WR65A] 2015/11/06 17:00:41.675688 events.go:141: DEBUG: log 2302 FolderScanProgress map[folder:CHM_Main current:1404509643961 total:10594042121544]

[WR65A] 2015/11/06 17:00:41.675715 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:00:43.675604 walk.go:165: DEBUG: Walk /test/ [] current progress 1404603884729/10594042121544 (13%)

[WR65A] 2015/11/06 17:00:43.675730 events.go:141: DEBUG: log 2303 FolderScanProgress map[total:10594042121544 folder:CHM_Main current:1404603884729]

[WR65A] 2015/11/06 17:00:43.675778 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:00:45.675623 walk.go:165: DEBUG: Walk /test/ [] current progress 1404696028345/10594042121544 (13%)

[WR65A] 2015/11/06 17:00:45.675701 events.go:141: DEBUG: log 2304 FolderScanProgress map[folder:CHM_Main current:1404696028345 total:10594042121544]

[WR65A] 2015/11/06 17:00:45.675728 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:00:47.675593 walk.go:165: DEBUG: Walk /test/ [] current progress 1404767593657/10594042121544 (13%)

[WR65A] 2015/11/06 17:00:47.675685 events.go:141: DEBUG: log 2305 FolderScanProgress map[folder:CHM_Main current:1404767593657 total:10594042121544]

[WR65A] 2015/11/06 17:00:47.675714 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:00:49.675562 walk.go:165: DEBUG: Walk /test/ [] current progress 1404936152249/10594042121544 (13%)

[WR65A] 2015/11/06 17:00:49.675681 events.go:141: DEBUG: log 2306 FolderScanProgress map[folder:CHM_Main current:1404936152249 total:10594042121544]

[WR65A] 2015/11/06 17:00:49.675718 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:00:51.675554 walk.go:165: DEBUG: Walk /test/ [] current progress 1405136430265/10594042121544 (13%)

[WR65A] 2015/11/06 17:00:51.675655 events.go:141: DEBUG: log 2307 FolderScanProgress map[folder:CHM_Main current:1405136430265 total:10594042121544]

[WR65A] 2015/11/06 17:00:51.675713 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:00:53.675525 walk.go:165: DEBUG: Walk /test/ [] current progress 1405339067577/10594042121544 (13%)

[WR65A] 2015/11/06 17:00:53.675597 events.go:141: DEBUG: log 2308 FolderScanProgress map[folder:CHM_Main current:1405339067577 total:10594042121544]

[WR65A] 2015/11/06 17:00:53.675624 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:00:55.675542 walk.go:165: DEBUG: Walk /test/ [] current progress 1405541311673/10594042121544 (13%)

[WR65A] 2015/11/06 17:00:55.675633 events.go:141: DEBUG: log 2309 FolderScanProgress map[folder:CHM_Main current:1405541311673 total:10594042121544]

[WR65A] 2015/11/06 17:00:55.675693 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:00:57.675491 walk.go:165: DEBUG: Walk /test/ [] current progress 1405745521849/10594042121544 (13%)

[WR65A] 2015/11/06 17:00:57.675561 events.go:141: DEBUG: log 2310 FolderScanProgress map[folder:CHM_Main current:1405745521849 total:10594042121544]

[WR65A] 2015/11/06 17:00:57.675590 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:00:59.675536 walk.go:165: DEBUG: Walk /test/ [] current progress 1405943964857/10594042121544 (13%)

[WR65A] 2015/11/06 17:00:59.675598 events.go:141: DEBUG: log 2311 FolderScanProgress map[folder:CHM_Main current:1405943964857 total:10594042121544]

[WR65A] 2015/11/06 17:00:59.675625 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:01.675560 walk.go:165: DEBUG: Walk /test/ [] current progress 1406141883577/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:01.675681 events.go:141: DEBUG: log 2312 FolderScanProgress map[folder:CHM_Main current:1406141883577 total:10594042121544]

[WR65A] 2015/11/06 17:01:01.675719 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:03.675618 walk.go:165: DEBUG: Walk /test/ [] current progress 1406306510009/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:03.675763 events.go:141: DEBUG: log 2313 FolderScanProgress map[folder:CHM_Main current:1406306510009 total:10594042121544]

[WR65A] 2015/11/06 17:01:03.675803 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:05.675601 walk.go:165: DEBUG: Walk /test/ [] current progress 1406379517113/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:05.675740 events.go:141: DEBUG: log 2314 FolderScanProgress map[current:1406379517113 total:10594042121544 folder:CHM_Main]

[WR65A] 2015/11/06 17:01:05.675791 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:07.675526 walk.go:165: DEBUG: Walk /test/ [] current progress 1406563804345/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:07.675601 events.go:141: DEBUG: log 2315 FolderScanProgress map[folder:CHM_Main current:1406563804345 total:10594042121544]

[WR65A] 2015/11/06 17:01:07.675632 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:09.675481 walk.go:165: DEBUG: Walk /test/ [] current progress 1406761198777/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:09.675557 events.go:141: DEBUG: log 2316 FolderScanProgress map[folder:CHM_Main current:1406761198777 total:10594042121544]

[WR65A] 2015/11/06 17:01:09.675584 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:10.278447 events.go:141: DEBUG: log 2317 Ping

[WR65A] 2015/11/06 17:01:10.278493 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:11.675626 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:11.675794 events.go:141: DEBUG: log 2318 FolderScanProgress map[folder:CHM_Main current:1406886990651 total:10594042121544]

[WR65A] 2015/11/06 17:01:11.675844 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:13.675601 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:13.675748 events.go:141: DEBUG: log 2319 FolderScanProgress map[folder:CHM_Main current:1406886990651 total:10594042121544]

[WR65A] 2015/11/06 17:01:13.675803 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:15.675554 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:15.675624 events.go:141: DEBUG: log 2320 FolderScanProgress map[folder:CHM_Main current:1406886990651 total:10594042121544]

[WR65A] 2015/11/06 17:01:15.675699 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:17.675578 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:17.675680 events.go:141: DEBUG: log 2321 FolderScanProgress map[folder:CHM_Main current:1406886990651 total:10594042121544]

[WR65A] 2015/11/06 17:01:17.675728 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:19.675575 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:19.675730 events.go:141: DEBUG: log 2322 FolderScanProgress map[folder:CHM_Main current:1406886990651 total:10594042121544]

[WR65A] 2015/11/06 17:01:19.675781 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:21.675567 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:21.675635 events.go:141: DEBUG: log 2323 FolderScanProgress map[current:1406886990651 total:10594042121544 folder:CHM_Main]

[WR65A] 2015/11/06 17:01:21.675979 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:23.675593 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:23.675956 events.go:141: DEBUG: log 2324 FolderScanProgress map[folder:CHM_Main current:1406886990651 total:10594042121544]

[WR65A] 2015/11/06 17:01:23.676079 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:25.675603 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:25.676168 events.go:141: DEBUG: log 2325 FolderScanProgress map[folder:CHM_Main current:1406886990651 total:10594042121544]

[WR65A] 2015/11/06 17:01:25.676231 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:27.675579 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:27.675899 events.go:141: DEBUG: log 2326 FolderScanProgress map[total:10594042121544 folder:CHM_Main current:1406886990651]

[WR65A] 2015/11/06 17:01:27.675953 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:29.675572 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:29.675805 events.go:141: DEBUG: log 2327 FolderScanProgress map[folder:CHM_Main current:1406886990651 total:10594042121544]

[WR65A] 2015/11/06 17:01:29.675872 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:31.675569 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:31.675677 events.go:141: DEBUG: log 2328 FolderScanProgress map[current:1406886990651 total:10594042121544 folder:CHM_Main]

[WR65A] 2015/11/06 17:01:31.675728 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:33.675567 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:33.675680 events.go:141: DEBUG: log 2329 FolderScanProgress map[folder:CHM_Main current:1406886990651 total:10594042121544]

[WR65A] 2015/11/06 17:01:33.675735 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:35.675591 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

Scan interval to 0 does not help. This is the most of a log I can put into the message:

[WR65A] 2015/11/06 16:24:56.176628 walk.go:176: DEBUG: real to hash: dr_001/4514/15bd/34ea/416e/8947/889b/868c/22ed/102618967-451415bd-34ea-416e-8947-889b868c22ed/data/logs/transfers/102618967-87c39463-2caf-4b0d-840b-70675ee1d234/logs/BagIt/bag-info.txt

[WR65A] 2015/11/06 16:24:56.198420 walk.go:176: DEBUG: real to hash: dr_001/4514/15bd/34ea/416e/8947/889b/868c/22ed/102618967-451415bd-34ea-416e-8947-889b868c22ed/data/logs/transfers/102618967-87c39463-2caf-4b0d-840b-70675ee1d234/logs/BagIt/bagit.txt

[WR65A] 2015/11/06 16:24:56.201442 walk.go:176: DEBUG: real to hash: dr_001/4514/15bd/34ea/416e/8947/889b/868c/22ed/102618967-451415bd-34ea-416e-8947-889b868c22ed/data/logs/transfers/102618967-87c39463-2caf-4b0d-840b-70675ee1d234/logs/BagIt/tagmanifest-md5.txt

[WR65A] 2015/11/06 16:24:56.242762 walk.go:176: DEBUG: real to hash: dr_001/4514/15bd/34ea/416e/8947/889b/868c/22ed/102618967-451415bd-34ea-416e-8947-889b868c22ed/data/logs/transfers/102618967-87c39463-2caf-4b0d-840b-70675ee1d234/logs/fileFormatIdentification.log

[WR65A] 2015/11/06 16:24:56.246904 walk.go:176: DEBUG: real to hash: dr_001/4514/15bd/34ea/416e/8947/889b/868c/22ed/102618967-451415bd-34ea-416e-8947-889b868c22ed/data/objects/102618967/dec_pdp-8.woman_at_pdp8.102618967.src.tif

[WR65A] 2015/11/06 16:24:56.247376 walk.go:176: DEBUG: real to hash: dr_001/4514/15bd/34ea/416e/8947/889b/868c/22ed/102618967-451415bd-34ea-416e-8947-889b868c22ed/data/objects/metadata/transfers/102618967-87c39463-2caf-4b0d-840b-70675ee1d234/manifest-md5.txt

[WR65A] 2015/11/06 16:24:57.675471 walk.go:165: DEBUG: Walk /test/ [] current progress 1026841854687/10594042121544 (9%)

[WR65A] 2015/11/06 16:24:57.675535 events.go:141: DEBUG: log 1188 FolderScanProgress map[folder:CHM_Main current:1026841854687 total:10594042121544]

[WR65A] 2015/11/06 16:24:57.675560 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:24:58.132381 walk.go:176: DEBUG: real to hash: dr_001/4514/15bd/34ea/416e/8947/889b/868c/22ed/102618967-451415bd-34ea-416e-8947-889b868c22ed/data/objects/metadata/transfers/102618967-87c39463-2caf-4b0d-840b-70675ee1d234/metadata.csv

[WR65A] 2015/11/06 16:24:58.134339 walk.go:176: DEBUG: real to hash: dr_001/4514/15bd/34ea/416e/8947/889b/868c/22ed/102618967-451415bd-34ea-416e-8947-889b868c22ed/data/objects/submissionDocumentation/transfer-102618967-87c39463-2caf-4b0d-840b-70675ee1d234/METS.xml

[WR65A] 2015/11/06 16:24:58.140776 walk.go:176: DEBUG: real to hash: dr_001/4514/15bd/34ea/416e/8947/889b/868c/22ed/102618967-451415bd-34ea-416e-8947-889b868c22ed/manifest-sha512.txt

[WR65A] 2015/11/06 16:24:58.148225 walk.go:176: DEBUG: real to hash: dr_001/4514/15bd/34ea/416e/8947/889b/868c/22ed/102618967-451415bd-34ea-416e-8947-889b868c22ed/tagmanifest-md5.txt

[WR65A] 2015/11/06 16:24:58.152186 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/bag-info.txt

[WR65A] 2015/11/06 16:24:58.161549 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/bagit.txt

[WR65A] 2015/11/06 16:24:58.223932 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/METS.45a39883-760e-44ab-9a85-08760bba7ff6.xml

[WR65A] 2015/11/06 16:24:58.260366 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/logs/fileFormatIdentification.log

[WR65A] 2015/11/06 16:24:58.561493 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/logs/transfers/102746421-20125535-fa0b-4e2d-b42b-1237ec5c6a24/logs/BagIt/bag-info.txt

[WR65A] 2015/11/06 16:24:58.563032 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/logs/transfers/102746421-20125535-fa0b-4e2d-b42b-1237ec5c6a24/logs/BagIt/bagit.txt

[WR65A] 2015/11/06 16:24:58.563052 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/logs/transfers/102746421-20125535-fa0b-4e2d-b42b-1237ec5c6a24/logs/BagIt/tagmanifest-md5.txt

[WR65A] 2015/11/06 16:24:58.567488 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/logs/transfers/102746421-20125535-fa0b-4e2d-b42b-1237ec5c6a24/logs/fileFormatIdentification.log

[WR65A] 2015/11/06 16:24:58.578981 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/logs/transfers/102746421-20125535-fa0b-4e2d-b42b-1237ec5c6a24/logs/filenameCleanup.log

[WR65A] 2015/11/06 16:24:58.581690 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/objects/102746421/Clip__1.mov

[WR65A] 2015/11/06 16:24:58.603732 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/objects/102746421/Clip__10.mov

[WR65A] 2015/11/06 16:24:59.684114 walk.go:165: DEBUG: Walk /test/ [] current progress 1027940097701/10594042121544 (9%)

[WR65A] 2015/11/06 16:24:59.684185 events.go:141: DEBUG: log 1189 FolderScanProgress map[folder:CHM_Main current:1027940097701 total:10594042121544]

[WR65A] 2015/11/06 16:24:59.684210 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:25:01.675790 walk.go:165: DEBUG: Walk /test/ [] current progress 1029247540901/10594042121544 (9%)

[WR65A] 2015/11/06 16:25:01.675857 events.go:141: DEBUG: log 1190 FolderScanProgress map[total:10594042121544 folder:CHM_Main current:1029247540901]

[WR65A] 2015/11/06 16:25:01.676019 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:25:01.995133 events.go:141: DEBUG: log 1191 FolderSummary map[folder:CHM_Main summary:map[globalBytes:2082241930648 localDeleted:0 needFiles:0 ignorePatterns:false invalid: globalFiles:9670 globalDeleted:0 localFiles:9670 inSyncBytes:2082241930648 inSyncFiles:9670 state:scanning stateChanged:2015-11-06 15:56:09.675227573 -0800 PST localBytes:2082241930648 needBytes:0 version:9675]]

[WR65A] 2015/11/06 16:25:01.995188 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:25:03.679902 walk.go:165: DEBUG: Walk /test/ [] current progress 1030354050725/10594042121544 (9%)

[WR65A] 2015/11/06 16:25:03.679964 events.go:141: DEBUG: log 1192 FolderScanProgress map[total:10594042121544 folder:CHM_Main current:1030354050725]

[WR65A] 2015/11/06 16:25:03.679987 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:25:05.675473 walk.go:165: DEBUG: Walk /test/ [] current progress 1031633837733/10594042121544 (9%)

[WR65A] 2015/11/06 16:25:05.675533 events.go:141: DEBUG: log 1193 FolderScanProgress map[folder:CHM_Main current:1031633837733 total:10594042121544]

[WR65A] 2015/11/06 16:25:05.675556 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:25:07.685586 walk.go:165: DEBUG: Walk /test/ [] current progress 1032909168293/10594042121544 (9%)

[WR65A] 2015/11/06 16:25:07.685661 events.go:141: DEBUG: log 1194 FolderScanProgress map[folder:CHM_Main current:1032909168293 total:10594042121544]

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

[WR65A] 2015/11/06 16:25:54.197535 events.go:141: DEBUG: log 1220 FolderSummary map[folder:CHM_Main summary:map[globalDeleted:0 localFiles:9699 needFiles:0 inSyncBytes:2089017902927 globalFiles:9699 globalBytes:2089017902927 localBytes:2089017902927 state:scanning version:9704 ignorePatterns:false invalid: localDeleted:0 inSyncFiles:9699 stateChanged:2015-11-06 15:56:09.675227573 -0800 PST needBytes:0]]

[WR65A] 2015/11/06 16:25:54.197796 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:25:55.675536 walk.go:165: DEBUG: Walk /test/ [] current progress 1063276083743/10594042121544 (10%)

[WR65A] 2015/11/06 16:25:55.675600 events.go:141: DEBUG: log 1221 FolderScanProgress map[folder:CHM_Main current:1063276083743 total:10594042121544]

[WR65A] 2015/11/06 16:25:55.675627 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:25:56.001191 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/objects/102746421/Clip__13.mov

[WR65A] 2015/11/06 16:25:57.613307 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/objects/102746421/Clip__14.mov

[WR65A] 2015/11/06 16:25:57.670138 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/objects/102746421/Clip__15.mov

[WR65A] 2015/11/06 16:25:57.675484 walk.go:165: DEBUG: Walk /test/ [] current progress 1064517944840/10594042121544 (10%)

[WR65A] 2015/11/06 16:25:57.675538 events.go:141: DEBUG: log 1222 FolderScanProgress map[folder:CHM_Main current:1064517944840 total:10594042121544]

[WR65A] 2015/11/06 16:25:57.675562 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:25:57.677830 events.go:141: DEBUG: log 1223 LocalIndexUpdated map[folder:CHM_Main items:3 version:9707]

[WR65A] 2015/11/06 16:25:57.677858 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:25:58.306111 events.go:141: DEBUG: log 1224 FolderSummary map[folder:CHM_Main summary:map[globalFiles:9702 globalBytes:2089343674161 localFiles:9702 inSyncFiles:9702 inSyncBytes:2089343674161 ignorePatterns:false invalid: needFiles:0 needBytes:0 state:scanning version:9707 localDeleted:0 localBytes:2089343674161 stateChanged:2015-11-06 15:56:09.675227573 -0800 PST globalDeleted:0]]

[WR65A] 2015/11/06 16:25:58.306204 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:25:59.205143 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/objects/102746421/Clip__2.mov

[WR65A] 2015/11/06 16:25:59.696299 walk.go:165: DEBUG: Walk /test/ [] current progress 1065526949652/10594042121544 (10%)

[WR65A] 2015/11/06 16:25:59.696536 events.go:141: DEBUG: log 1225 FolderScanProgress map[current:1065526949652 total:10594042121544 folder:CHM_Main]

[WR65A] 2015/11/06 16:25:59.696590 events.go:194: DEBUG: poll 1m0s

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

[WR65A] 2015/11/06 16:53:41.675514 walk.go:165: DEBUG: Walk /test/ [] current progress 1362187019449/10594042121544 (12%)

[WR65A] 2015/11/06 16:53:41.675578 events.go:141: DEBUG: log 2085 FolderScanProgress map[current:1362187019449 total:10594042121544 folder:CHM_Main]

[WR65A] 2015/11/06 16:53:43.675583 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:53:45.675542 walk.go:165: DEBUG: Walk /test/ [] current progress 1362589541561/10594042121544 (12%)

[WR65A] 2015/11/06 16:53:45.675630 events.go:141: DEBUG: log 2087 FolderScanProgress map[folder:CHM_Main current:1362589541561 total:10594042121544]

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

[WR65A] 2015/11/06 16:59:01.675526 walk.go:165: DEBUG: Walk /test/ [] current progress 1394495874233/10594042121544 (13%)

[WR65A] 2015/11/06 16:59:01.675591 events.go:141: DEBUG: log 2250 FolderScanProgress map[folder:CHM_Main current:1394495874233 total:10594042121544]

[WR65A] 2015/11/06 16:59:01.675617 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 16:59:03.675507 walk.go:165: DEBUG: Walk /test/ [] current progress 1394704671929/10594042121544 (13%)

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

… CUTTED LINES because they were showing same output than before and after lines

[WR65A] 2015/11/06 17:00:39.675519 events.go:141: DEBUG: log 2301 FolderScanProgress map[folder:CHM_Main current:1404304909497 total:10594042121544]

[WR65A] 2015/11/06 17:00:39.675544 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:00:41.675569 walk.go:165: DEBUG: Walk /test/ [] current progress 1404509643961/10594042121544 (13%)

[WR65A] 2015/11/06 17:00:41.675688 events.go:141: DEBUG: log 2302 FolderScanProgress map[folder:CHM_Main current:1404509643961 total:10594042121544]

[WR65A] 2015/11/06 17:00:41.675715 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:00:43.675604 walk.go:165: DEBUG: Walk /test/ [] current progress 1404603884729/10594042121544 (13%)

[WR65A] 2015/11/06 17:00:43.675730 events.go:141: DEBUG: log 2303 FolderScanProgress map[total:10594042121544 folder:CHM_Main current:1404603884729]

[WR65A] 2015/11/06 17:00:43.675778 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:00:45.675623 walk.go:165: DEBUG: Walk /test/ [] current progress 1404696028345/10594042121544 (13%)

[WR65A] 2015/11/06 17:00:45.675701 events.go:141: DEBUG: log 2304 FolderScanProgress map[folder:CHM_Main current:1404696028345 total:10594042121544]

[WR65A] 2015/11/06 17:00:45.675728 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:00:47.675593 walk.go:165: DEBUG: Walk /test/ [] current progress 1404767593657/10594042121544 (13%)

[WR65A] 2015/11/06 17:00:47.675685 events.go:141: DEBUG: log 2305 FolderScanProgress map[folder:CHM_Main current:1404767593657 total:10594042121544]

[WR65A] 2015/11/06 17:00:47.675714 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:00:49.675562 walk.go:165: DEBUG: Walk /test/ [] current progress 1404936152249/10594042121544 (13%)

[WR65A] 2015/11/06 17:00:49.675681 events.go:141: DEBUG: log 2306 FolderScanProgress map[folder:CHM_Main current:1404936152249 total:10594042121544]

[WR65A] 2015/11/06 17:00:49.675718 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:00:51.675554 walk.go:165: DEBUG: Walk /test/ [] current progress 1405136430265/10594042121544 (13%)

[WR65A] 2015/11/06 17:00:51.675655 events.go:141: DEBUG: log 2307 FolderScanProgress map[folder:CHM_Main current:1405136430265 total:10594042121544]

[WR65A] 2015/11/06 17:00:51.675713 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:00:53.675525 walk.go:165: DEBUG: Walk /test/ [] current progress 1405339067577/10594042121544 (13%)

[WR65A] 2015/11/06 17:00:53.675597 events.go:141: DEBUG: log 2308 FolderScanProgress map[folder:CHM_Main current:1405339067577 total:10594042121544]

[WR65A] 2015/11/06 17:00:53.675624 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:00:55.675542 walk.go:165: DEBUG: Walk /test/ [] current progress 1405541311673/10594042121544 (13%)

[WR65A] 2015/11/06 17:00:55.675633 events.go:141: DEBUG: log 2309 FolderScanProgress map[folder:CHM_Main current:1405541311673 total:10594042121544]

[WR65A] 2015/11/06 17:00:55.675693 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:00:57.675491 walk.go:165: DEBUG: Walk /test/ [] current progress 1405745521849/10594042121544 (13%)

[WR65A] 2015/11/06 17:00:57.675561 events.go:141: DEBUG: log 2310 FolderScanProgress map[folder:CHM_Main current:1405745521849 total:10594042121544]

[WR65A] 2015/11/06 17:00:57.675590 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:00:59.675536 walk.go:165: DEBUG: Walk /test/ [] current progress 1405943964857/10594042121544 (13%)

[WR65A] 2015/11/06 17:00:59.675598 events.go:141: DEBUG: log 2311 FolderScanProgress map[folder:CHM_Main current:1405943964857 total:10594042121544]

[WR65A] 2015/11/06 17:00:59.675625 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:01.675560 walk.go:165: DEBUG: Walk /test/ [] current progress 1406141883577/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:01.675681 events.go:141: DEBUG: log 2312 FolderScanProgress map[folder:CHM_Main current:1406141883577 total:10594042121544]

[WR65A] 2015/11/06 17:01:01.675719 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:03.675618 walk.go:165: DEBUG: Walk /test/ [] current progress 1406306510009/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:03.675763 events.go:141: DEBUG: log 2313 FolderScanProgress map[folder:CHM_Main current:1406306510009 total:10594042121544]

[WR65A] 2015/11/06 17:01:03.675803 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:05.675601 walk.go:165: DEBUG: Walk /test/ [] current progress 1406379517113/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:05.675740 events.go:141: DEBUG: log 2314 FolderScanProgress map[current:1406379517113 total:10594042121544 folder:CHM_Main]

[WR65A] 2015/11/06 17:01:05.675791 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:07.675526 walk.go:165: DEBUG: Walk /test/ [] current progress 1406563804345/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:07.675601 events.go:141: DEBUG: log 2315 FolderScanProgress map[folder:CHM_Main current:1406563804345 total:10594042121544]

[WR65A] 2015/11/06 17:01:07.675632 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:09.675481 walk.go:165: DEBUG: Walk /test/ [] current progress 1406761198777/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:09.675557 events.go:141: DEBUG: log 2316 FolderScanProgress map[folder:CHM_Main current:1406761198777 total:10594042121544]

[WR65A] 2015/11/06 17:01:09.675584 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:10.278447 events.go:141: DEBUG: log 2317 Ping

[WR65A] 2015/11/06 17:01:10.278493 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:11.675626 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:11.675794 events.go:141: DEBUG: log 2318 FolderScanProgress map[folder:CHM_Main current:1406886990651 total:10594042121544]

[WR65A] 2015/11/06 17:01:11.675844 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:13.675601 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:13.675748 events.go:141: DEBUG: log 2319 FolderScanProgress map[folder:CHM_Main current:1406886990651 total:10594042121544]

[WR65A] 2015/11/06 17:01:13.675803 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:15.675554 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:15.675624 events.go:141: DEBUG: log 2320 FolderScanProgress map[folder:CHM_Main current:1406886990651 total:10594042121544]

[WR65A] 2015/11/06 17:01:15.675699 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:17.675578 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:17.675680 events.go:141: DEBUG: log 2321 FolderScanProgress map[folder:CHM_Main current:1406886990651 total:10594042121544]

[WR65A] 2015/11/06 17:01:17.675728 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:19.675575 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:19.675730 events.go:141: DEBUG: log 2322 FolderScanProgress map[folder:CHM_Main current:1406886990651 total:10594042121544]

[WR65A] 2015/11/06 17:01:19.675781 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:21.675567 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:21.675635 events.go:141: DEBUG: log 2323 FolderScanProgress map[current:1406886990651 total:10594042121544 folder:CHM_Main]

[WR65A] 2015/11/06 17:01:21.675979 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:23.675593 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:23.675956 events.go:141: DEBUG: log 2324 FolderScanProgress map[folder:CHM_Main current:1406886990651 total:10594042121544]

[WR65A] 2015/11/06 17:01:23.676079 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:25.675603 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:25.676168 events.go:141: DEBUG: log 2325 FolderScanProgress map[folder:CHM_Main current:1406886990651 total:10594042121544]

[WR65A] 2015/11/06 17:01:25.676231 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:27.675579 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:27.675899 events.go:141: DEBUG: log 2326 FolderScanProgress map[total:10594042121544 folder:CHM_Main current:1406886990651]

[WR65A] 2015/11/06 17:01:27.675953 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:29.675572 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:29.675805 events.go:141: DEBUG: log 2327 FolderScanProgress map[folder:CHM_Main current:1406886990651 total:10594042121544]

[WR65A] 2015/11/06 17:01:29.675872 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:31.675569 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:31.675677 events.go:141: DEBUG: log 2328 FolderScanProgress map[current:1406886990651 total:10594042121544 folder:CHM_Main]

[WR65A] 2015/11/06 17:01:31.675728 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:33.675567 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

[WR65A] 2015/11/06 17:01:33.675680 events.go:141: DEBUG: log 2329 FolderScanProgress map[folder:CHM_Main current:1406886990651 total:10594042121544]

[WR65A] 2015/11/06 17:01:33.675735 events.go:194: DEBUG: poll 1m0s

[WR65A] 2015/11/06 17:01:35.675591 walk.go:165: DEBUG: Walk /test/ [] current progress 1406886990651/10594042121544 (13%)

What are the last 10 or so lines containing the words “real to hash” before it stops making progress?

here they are:

[WR65A] 2015/11/06 16:24:58.567488 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/logs/transfers/102746421-20125535-fa0b-4e2d-b42b-1237ec5c6a24/logs/fileFormatIdentification.log

[WR65A] 2015/11/06 16:24:58.578981 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/logs/transfers/102746421-20125535-fa0b-4e2d-b42b-1237ec5c6a24/logs/filenameCleanup.log

[WR65A] 2015/11/06 16:24:58.581690 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/objects/102746421/Clip__1.mov

[WR65A] 2015/11/06 16:24:58.603732 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/objects/102746421/Clip__10.mov

[WR65A] 2015/11/06 16:25:51.700108 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/objects/102746421/Clip__11.mov

[WR65A] 2015/11/06 16:25:53.654478 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/objects/102746421/Clip__12.mov

[WR65A] 2015/11/06 16:25:56.001191 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/objects/102746421/Clip__13.mov

[WR65A] 2015/11/06 16:25:57.613307 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/objects/102746421/Clip__14.mov

[WR65A] 2015/11/06 16:25:57.670138 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/objects/102746421/Clip__15.mov

[WR65A] 2015/11/06 16:25:59.205143 walk.go:176: DEBUG: real to hash: dr_001/45a3/9883/760e/44ab/9a85/0876/0bba/7ff6/102746421-45a39883-760e-44ab-9a85-08760bba7ff6/data/objects/102746421/Clip__2.mov

Can you try setting scanProgressInterval to -1?

Yeah so 0 sets it to the default value of 2. You need to set it to -1 to disable it.

Are you sure those are the last ones? Because from the logs it’s apparently still reading data half an hour later, so apparently those files are quite large in that case?

Otherwise I don’t know. Are the files Ok, can you read them yourself, i.e. copy them somewhere?

It does not allow that value: The rescan interval must be a non-negative number of seconds.

He probably meant the setting “scanProgressIntervalS” which can be found in advanced settings.

Setting this to -1 will prevent Syncthing from checking/calculating the scan progress every 2 seconds to display it in the WebUI.

scanProgressInterval is not rescan interval. AFAIK it’s how often info about scanning progress would be updated in GUI, and you can set it only manually in config file.

EDIT: And also from advance settings, I keep forgetting that option.

I am able to read the files and copy them with btsync or rsync. When it gets stock it does not look like it stops the scan or anything, but shows not progressing in numbers. If I reset the scan every hour or two (when it gets “stock”) then it continues where it left off, but I reached to a point where the amount of data being indexed is not progressing. out of 15 Tb, it got 8.6 Tb indexed. the largest file I have is about 300 Gb but most of the files are normal size.

You might have to set it to -1 by modifyinh config.xmlin syncthings home directory.

I just changed it. I will send an update with the results.