confusing log-entry combined with "bad time 1371893371 0"

[htabbs]

Hi!

I checked this twice before I posted, it is still to strange to be real:

me@myRaspberry:/home/me/.sync# date && tail sync.log

Sat Jun 22 14:45:24 CEST 2013

[20130522 14:44:44.609] SyncFileEntry: got dictionary with bad time 1371893371 0

[20130522 14:44:44.610] Merge: failed to construct file entry received from remote, aborting

[20130522 14:44:54.447] SyncFileEntry: got dictionary with bad time 1371893371 0

[20130522 14:44:54.447] Merge: failed to construct file entry received from remote, aborting

[20130522 14:45:04.667] SyncFileEntry: got dictionary with bad time 1371893371 0

[20130522 14:45:04.668] Merge: failed to construct file entry received from remote, aborting

So what? Well, obviously we have the 22nd of june.

And as we can see btsync is up and running, doing as well as it can.

But it reports strange problems with a "bad time"- well, indeed it reports those problems one month in the past, that is the 22nd of _MAY_..

Raspi has no RTC, that COULD be related to this, but as you see it IS in sync and it WAS in sync 2 minutes earlier to the occurence of the last log lines

Might or might not be related. I don't even care to much about the wrong log-date (sure you'll fix it in coming releases) but I DO care about the bad time, as it seems to prevent my share to sync.

As far as I can tell no strange data (datetime) occurs in the source- directory, even more sure it doesn't in the destination- so called since it is readOnly and used for backup only..

Oh, I forgot: Raspi is ARM, Version is 1.1.15.

Any feedback is appreciated,

Rudi

[GreatMarko]

Hmmm... yes, looks like a system time issue with your Pi

A timestamp of "1371893371" equates to 22nd June 2013 09:29 UTC... so the "bad time" error is basically being thrown because Sync has encountered a folder that it believes has been created in the future (as your Pi, and therefore by association Sync, believes incorrectly that the current date is currently 22nd May.. so anything with a timestamp after this date will be considered invalid)

Whilst I'm no expert on the Pi, my understanding is that in order to keep time, the Pi updates the date and time automatically over the internet via Ethernet or WiFi, but that if the network connection is removed, it reverts back to the standard date and time settings (usually 30 November 1999).

So, perhaps your Pi got a bad update when last updating its date/time, which may be resolved the next time it updates?

I suspect once your Pi knows what date it actually is (i.e. 22nd June, not 22nd May), this "bad time" problem with Sync will be resolved and your files will resume syncing.

[htabbs]

Thanks, but I don't think so..

See the exact command I gave for the log:

To ensure it is with no doubt clear i had the current date print out AND (&&) immediatly after show the most recent lines in the log.

AND, i checked my logs on an other computer as well- also there the log shows 05.. That one does have an RTC and all files it produces are - by default - dated 22nd of june..

Antother Detail: My timezone is (currently) CEST. But I do not sync between any time-zones (so far..)

[htabbs]

I have now checked all three Computers I am using BTsync with:

All of them (Raspi with ARCH, Thinkpad430 witch Arch_x64 and Workstation with Ubuntu12.04_i386 are configured in timezone CEST, all of them use NTP, all have correct date (and time).

But all have log-entries suggesting it was May.

I guess this is in fact related to my real problem (not syncing)

My guess is testing btsync on any computer with linux and CEST will show the same, wrong date in logs.

(Any feedback from Users with that setup would be helpful here.)

[sergey@bt]

The problem is in second timestamp (0), which is file modification date. Please find files with modification time set to 0 and fix them (touch), it should resolve the issue.

The date in log is correct, month is numerated from 0 to 11, we will fix it to avoid confusion.

[htabbs]

Perfect! That solved the problem!

I agree it's better to change the output to 1..12

Just finding those itchy files was a bit of work..

Especially since the reference- File i created for that purpose blocked BTsync - well, it's mod-date was 0..

Just in case someone needs the procedure (linux shell):

touch cmp -d @0

find /.../yoursyncfolder -not -newer cmp #see what we have

find /.../yoursyncfolder -not -newer cmp -exec touch -d @631148401 {} \; #touch every of them- the number stands for 1.1.1990

#IMPORTANT:

rm cmp #otherwise this very file might cause exactly the problem you try to solve

#Personaly I didn't want to wait for the next reindexing, so i killed/restarted BTsync- but I assume it would work without that either..

[rdebath]

Um, zero is NOT a "bad time". A time_t is normally a signed int on a 64 bit system. It is also usually signed on a 32bit system but it can also (becoming less rare) be a signed 64bit int on a 32bit system.

# uname -mrso
Linux 2.6.32-5-amd64 x86_64 GNU/Linux
# date -d '23 jan 1966' +%s
-124329600
# date -d '23 jan 2066' +%s
3031430400
# date -d '23 jan 1801' +%s
-5331225525
# date -d '23 jan 2266' +%s
9342777600
# TZ=UTC date -d '1 jan 1970' +%s
0
# TZ=UTC date -d 1970-01-01+2147483648sec
Tue Jan 19 03:14:08 UTC 2038
#