Something very strange is going on with two pieces of equipment in my condo.

The clocks on both my Cisco 7965G IP phone and Logitech Squeezebox are running very slowly (somewhere between 1/5 and 1/10 normal speed), and constantly reverting back to 01:45 or so on Jan. 27th, 2010.  Menus and animations on both devices run very slowly, too, like there is a hardware timer issue, or something.

I first thought this might be an NTP issue, so I did a few packet captures of the NTP traffic between the Cisco 7965G and my NTP server:

20:39:54.844785 IP (tos 0x0, ttl 64, id 38096, offset 0, flags [none], proto UDP (17), length 76)
    10.3.5.104.123 > 10.3.4.2.123: [no cksum] NTPv3, length 48
     Client, Leap indicator: clock unsynchronized (192), Stratum 15, poll 6s, precision -7
     Root Delay: 0.000000, Root dispersion: 2.009994, Reference-ID: 0.0.0.0
       Reference Timestamp:  0.000000000
       Originator Timestamp: 0.000000000
       Receive Timestamp:    0.000000000
       Transmit Timestamp:   3473567182.860354963 (2010/01/27 02:46:22)
         Originator - Receive Timestamp:  0.000000000
         Originator - Transmit Timestamp: 3473567182.860354963 (2010/01/27 02:46:22)
20:39:54.881551 IP (tos 0x0, ttl 63, id 0, offset 0, flags [DF], proto UDP (17), length 76)
    10.3.4.2.123 > 10.3.5.104.123: [udp sum ok] NTPv3, length 48
     Server, Leap indicator:  (0), Stratum 2, poll 6s, precision -20
     Root Delay: 0.043365, Root dispersion: 0.029220, Reference-ID: 209.51.161.238
       Reference Timestamp:  3473803857.861653736 (2010/01/29 20:30:57)
       Originator Timestamp: 3473567182.860354963 (2010/01/27 02:46:22)
       Receive Timestamp:    3473804394.862448562 (2010/01/29 20:39:54)
       Transmit Timestamp:   3473804394.862667697 (2010/01/29 20:39:54)
         Originator - Receive Timestamp:  +237212.002093598
         Originator - Transmit Timestamp: +237212.002312734

It kept doing that every couple of seconds, never setting the clock.  Okay, maybe being +237212 seconds off prevented synchronization due to a sanity check of some sorts, so I manually set the clock (I ended up being 90 seconds off, but whatever).  A few seconds later it reverted BACK to Jan. 27th!  See below:

20:54:50.889287 IP (tos 0x0, ttl 64, id 40796, offset 0, flags [none], proto UDP (17), length 76)
    10.3.5.104.123 > 10.3.4.2.123: [no cksum] NTPv3, length 48
     Client, Leap indicator: clock unsynchronized (192), Stratum 15, poll 6s, precision -7
     Root Delay: 0.000000, Root dispersion: 2.009994, Reference-ID: 0.0.0.0
       Reference Timestamp:  0.000000000
       Originator Timestamp: 0.000000000
       Receive Timestamp:    0.000000000
       Transmit Timestamp:   3473805201.860325451 (2010/01/29 20:53:21)
         Originator - Receive Timestamp:  0.000000000
         Originator - Transmit Timestamp: 3473805201.860325451 (2010/01/29 20:53:21)
20:54:50.924125 IP (tos 0x0, ttl 63, id 0, offset 0, flags [DF], proto UDP (17), length 76)
    10.3.4.2.123 > 10.3.5.104.123: [udp sum ok] NTPv3, length 48
     Server, Leap indicator:  (0), Stratum 2, poll 6s, precision -20
     Root Delay: 0.043579, Root dispersion: 0.030624, Reference-ID: 209.51.161.238
       Reference Timestamp:  3473804882.860819613 (2010/01/29 20:48:02)
       Originator Timestamp: 3473805201.860325451 (2010/01/29 20:53:21)
       Receive Timestamp:    3473805290.909316960 (2010/01/29 20:54:50)
       Transmit Timestamp:   3473805290.909515881 (2010/01/29 20:54:50)
         Originator - Receive Timestamp:  +89.048991509
         Originator - Transmit Timestamp: +89.049190430
20:55:58.959742 IP (tos 0x0, ttl 64, id 41080, offset 0, flags [none], proto UDP (17), length 76)
    10.3.5.104.123 > 10.3.4.2.123: [no cksum] NTPv3, length 48
     Client, Leap indicator: clock unsynchronized (192), Stratum 15, poll 6s, precision -7
     Root Delay: 0.000000, Root dispersion: 2.009994, Reference-ID: 0.0.0.0
       Reference Timestamp:  0.000000000
       Originator Timestamp: 0.000000000
       Receive Timestamp:    0.000000000
       Transmit Timestamp:   3473564203.900366698 (2010/01/27 01:56:43)
         Originator - Receive Timestamp:  0.000000000
         Originator - Transmit Timestamp: 3473564203.900366698 (2010/01/27 01:56:43)
20:55:58.996647 IP (tos 0x0, ttl 63, id 0, offset 0, flags [DF], proto UDP (17), length 76)
    10.3.4.2.123 > 10.3.5.104.123: [udp sum ok] NTPv3, length 48
     Server, Leap indicator:  (0), Stratum 2, poll 6s, precision -20
     Root Delay: 0.043579, Root dispersion: 0.031646, Reference-ID: 209.51.161.238
       Reference Timestamp:  3473804882.860819613 (2010/01/29 20:48:02)
       Originator Timestamp: 3473564203.900366698 (2010/01/27 01:56:43)
       Receive Timestamp:    3473805358.982955623 (2010/01/29 20:55:58)
       Transmit Timestamp:   3473805358.983155598 (2010/01/29 20:55:58)
         Originator - Receive Timestamp:  +241155.082588925
         Originator - Transmit Timestamp: +241155.082788900

That shows the originator timestamp going back to the 27th!

To make matters worse, the Squeezebox apparently doesn't use NTP, it grabs time from the mysqueezebox.com service over a proprietary protocol.  So, forget NTP being the issue.

Here's hh.mm.ss on the Squeezebox vs a normal clock:

Yes, the last two digits are seconds.

It blows my mind that two separate devices that don't share anything in common (they are even on different subnets) are experiencing the same problem.  Perhaps I should call Fox Mulder.

Any ideas?

Update:

Apparently the time and date was wrong on my server (atlantis) that runs the Squeezebox server and TFTP server.  The Squeezebox was getting the time from this server, not from mysqueezebox.com, and the Cisco 7965G was, for some odd reason, getting its time via TFTP, which overrode NTP!)

Actually, it looks like something is wrong with the hardware on my server:

(destiny:1:27)% time ssh atlantis time sleep 2
sleep 2  0.00s user 0.00s system 0% cpu 2.004 total
ssh atlantis time sleep 2  0.01s user 0.01s system 0% cpu 23.412 total

Time for a reboot, I guess.

New comments are currently disabled for this entry.