Community
Participate
Working Groups
Build ID: CDT 8.0 (Indigo) I happened to run Eclipse on a machine where the system clock was lagging (by little more than 1 hour). As a result, I got several errors logged like this: java.lang.Exception: Invalid slave info timestamp: 1309949737136 -> 2011-07-06 12:55:37.136 I see how a slave info timestamp in the future looks incorrect, but the way how this is logged doesn't help me understand or diagnose the problem. Questions: - What can really go wrong when TCF instances on a local network are not synced in time? Note that some end users may not have permission to change the system clock, and for some deployed/managed devices it may not even be possible to easily change/adjust the system clock. - Is there a way TCF could work properly without clocks synced? - If not, could the error logging be improved? Eg "slave info timestamp seems to be in the future, please check your system clock". For completeness, here's the stacktrace from the error in my log: at org.eclipse.tm.internal.tcf.services.local.LocatorService.handleSlavesInfoPacket(LocatorService.java:1098) at org.eclipse.tm.internal.tcf.services.local.LocatorService.handleDatagramPacket(LocatorService.java:985) at org.eclipse.tm.internal.tcf.services.local.LocatorService.access$7(LocatorService.java:956) at org.eclipse.tm.internal.tcf.services.local.LocatorService$3$1.run(LocatorService.java:287) at org.eclipse.tm.tcf.protocol.Protocol$3.run(Protocol.java:209) at org.eclipse.tm.tcf.EventQueue.run(EventQueue.java:99) at java.lang.Thread.run(Thread.java:619)
This looks like duplicate of Bug 333610, which is supposed to be fixed.
I double-checked I was using o.e.tm.tcf.core 0.4.0.201106081058 ... the message was logged once per session per peer only, but it was logged.
... though interestingly, I cannot reproduce this now with a system where I deliberately changed the clock.
The messages can be caused by an old agent running somewhere on your local network.
Hm... how could I diagnose that? For the log entry below, I'm 100% sure that the local tcf is current, and I'm 95% sure that the remote agent was current. As you see, this log entry is kind of "the other end" of the original log entry (comment #0 was from 193.81.18.166)... though I must confess it's confusing that the line number information in this log entry is different, so perhaps the remote agent was in fact old. !ENTRY org.eclipse.tm.tcf 4 0 2011-07-06 13:01:02.154 !MESSAGE Invalid datagram packet received from /193.81.18.166/1534 !STACK 0 java.lang.Exception: Invalid slave info timestamp: 1309946265446 -> 2011-07-06 11:57:45.446 at org.eclipse.tm.internal.tcf.services.local.LocatorService.handleSlavesInfoPacket(LocatorService.java:1075) at org.eclipse.tm.internal.tcf.services.local.LocatorService.handleDatagramPacket(LocatorService.java:954) at org.eclipse.tm.internal.tcf.services.local.LocatorService.access$7(LocatorService.java:929) at org.eclipse.tm.internal.tcf.services.local.LocatorService$3$1.run(LocatorService.java:287) at org.eclipse.tm.tcf.protocol.Protocol$3.run(Protocol.java:209) at org.eclipse.tm.tcf.EventQueue.run(EventQueue.java:99) at java.lang.Thread.run(Unknown Source)
I think I know what is causing the problem. I have found one place in Java version of Locator service code that correctly computes time-to-live, but then still erroneously sends absolute time stamp instead of just computed value. I will commit a fix.
Committed a fix into both trunk and 0.4.0 release branch.
