I’m experiencing weird problem with time on ConnectPort X4 with time feature.
My software is using Xbee DIO module and I have modified xbeedio.py device driver. The DIO module is configured to periodically send sample of inputs to the gateway. I have configured sample time to 500ms. In callback function (sample_indication()) I process sample and if the input didn’t change the processing is skipped and we are waiting for another one.
But here I have notified weird behavior. It seems that time.time() is jumping ahead time.clock(). Once in a while I experience that time.time() jumps ahead the clock() for more then 1 minute.
what is your NTP update rate (I hope not 60 seconds)
The time.time() and time.clock are not directly related to each other in an X4 with hardware RTC, so you will see differences if NTP forces time.time() to change because time.clock() will NOT change.
time.time() is from a hardware real-time clock chip and is affected by NTP responses. I have observed that calling time.time() can cause your code to block for over 50msec since it requires external access to shared hardware buses.
time.clock is a pure RTOS software ticker and will never be affected or changed by NTP. Calling time.clock() is very fast since it just returns a free-running counter. Be aware that time.clock() will ‘roll-over’ in about 47 days.
1.) Firmware Version: 2.12.0.6 (Version 82001536_H1 10/15/2010)
2.) I configured server time.windows.com, because it is SNTP server. It was easiest to copy from Windows machine.
3.) Update rate is 60. I was not careful and didn’t pay attention on number. Number 60 is not explained only in help. Maybe it would be appropriate that value should be in minutes rather then seconds.
I also suspected that problem is in SNTP server I setup time manually. After that I didn’t had any problems. Thanks for the explanation on time(). I would be now more careful with that.
Can you tell me about the code block. Is code blocked only inside thread or the whole code is blocked? I have to remember the arrival time, but it is no so important if it is in Xbee driver thread or inside presentation thread. Would it be wiser to record arrival time() inside presentation and not block driver?
I would also make correction about roll-over for clock(). What is the max value for clock()?
You could also use app.idigi.com, as some consider it bad form to add congestion to ‘other’ companies (a ubuntu.com or windows.com), plus the nist.gov is so overloaded it has huge jittery & response issues.
I tend to set SNTP to 24 hours, so 86400. There is a hardware realtime clock (RTC) within the X4 which was spec’d at having no more than 1 minute of drift per month, and tests show actual drift is closer to 15-25 seconds per month. So in truth there is no reason to risk a time.time() hiccup/jump more than once per day.
Yet if you put 2 and 2 togather, you should realize that your time bump of 78 seconds is ‘unexplianable’ - you should never see an SNTP caused bump greater than 1 or 2 seconds assuming the X4’s RTC will not drift more than 2 second per day.
So there is something flakey in how Digi is handling SNTP and Python time.time(). I would turn SNTP off until they fix that (H1 is the latest release, who knows when this will be fixed).
Reading I/O would block at least your thread, but might block the entire Python engine as it runs as a shared memory image. It does not ALWAYS block, because there is some minor caching of RTC data, which is then fudged with time.clock() additions for some seconds. Plus if nothing else is using the hardware, the RTC read is faster (maybe a few msec).
I will move time() function to presentation layer to avoid blocking of DIO driver. It is important for me not to lose any sample.
Currently there is no other activity on CPX8 and there should not be any problem reading time(). Probably there was problem with SNTP and sample collection. I would pay special attention to timing and try to monitor if such event will happen again.
I would also set SNTP back in work but would set update to 24h or even more. For now it is not problem of drift for 1-2 seconds in a day.
Finally I have to correct roll-over situation with clock(). The clock() is very important for me because I measure time between two samples.
I avoid the time.clock() roll-over problem by converting the float returned into an integer representing 10ths of a second, then masking down to do 24-bit unsigned math.
I use this to (for example) manage defragmentation of serial messages and aging of data in buffers. time.time() with seconds is too coarse a measure, while pure time.clock() has an ugly roll-over problem (how to predict and compensate when a float rolls over?)
Even if your Python blocks for I/O, you should not lose XBee packets as those are being buffered by the underlying RTOS.
I encountered issues similar to those Boris had.
My Dia samples’ automatic timestamps were set in the future, by as much as 2 hours, then they got back on time after a while. My CPX4 is set to be UTC, with no timezone defined anywhere.
Note : my CPX4 was also (:-<) set to ‘SNTP’ every 60 seconds and I was using a stratum-2 server (ntp.jussieu.fr).
Reading note from Lynn I changed to 43200 and 0.fr.pool.ntp.org
Apparently the SNTP works, but breaks something in the way Python fetches time from the RTC. (Was something to do with trying to ‘spread out change’, so if SNTP says your time needs to jump 5 minutes, an over ambitious design tried to spread that 5 minutes out over say an hour, but instead causes time to keep running weird forever.)
If you ever needed an evidence that Dia 1.4.6 has not fixed the issue: below are logs from an NTP-synchronized server after I synchronized my CPX4 to an NTP source. It’s running ahead at twice the speed limit
[Sun Aug 21 10:44:50 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:01:30 from 82.xx.xx.xx
[Sun Aug 21 10:45:50 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:01:57 from 82.xx.xx.xx
[Sun Aug 21 10:46:51 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:02:25 from 82.xx.xx.xx
[Sun Aug 21 10:47:52 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:02:52 from 82.xx.xx.xx
[Sun Aug 21 10:48:53 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:03:18 from 82.xx.xx.xx
[Sun Aug 21 10:49:53 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:03:47 from 82.xx.xx.xx
[Sun Aug 21 10:50:54 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:04:14 from 82.xx.xx.xx
[Sun Aug 21 10:51:55 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:04:42 from 82.xx.xx.xx
[Sun Aug 21 10:52:56 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:05:09 from 82.xx.xx.xx
[Sun Aug 21 10:53:57 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:05:35 from 82.xx.xx.xx
[Sun Aug 21 10:54:57 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:06:04 from 82.xx.xx.xx
[Sun Aug 21 10:55:58 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:06:31 from 82.xx.xx.xx
[Sun Aug 21 10:56:59 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:06:59 from 82.xx.xx.xx
[Sun Aug 21 10:58:00 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:07:25 from 82.xx.xx.xx
[Sun Aug 21 10:59:01 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:07:52 from 82.xx.xx.xx
[Sun Aug 21 11:00:01 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:08:21 from 82.xx.xx.xx
[Sun Aug 21 11:01:02 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:08:48 from 82.xx.xx.xx
[Sun Aug 21 11:02:03 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:09:16 from 82.xx.xx.xx
[Sun Aug 21 11:03:04 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:09:42 from 82.xx.xx.xx
[Sun Aug 21 11:04:05 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:10:09 from 82.xx.xx.xx
[Sun Aug 21 11:05:05 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:10:38 from 82.xx.xx.xx
[Sun Aug 21 11:06:06 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:11:05 from 82.xx.xx.xx
[Sun Aug 21 11:07:07 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:11:31 from 82.xx.xx.xx
[Sun Aug 21 11:08:08 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:11:59 from 82.xx.xx.xx
[Sun Aug 21 11:09:09 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:12:26 from 82.xx.xx.xx
[Sun Aug 21 11:10:09 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:12:55 from 82.xx.xx.xx
[Sun Aug 21 11:11:10 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:13:22 from 82.xx.xx.xx
[Sun Aug 21 11:12:11 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:13:49 from 82.xx.xx.xx
[Sun Aug 21 11:13:12 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:14:16 from 82.xx.xx.xx
[Sun Aug 21 11:14:13 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:14:44 from 82.xx.xx.xx
[Sun Aug 21 11:15:13 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:15:11 from 82.xx.xx.xx
[Sun Aug 21 11:16:13 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:15:39 from 82.xx.xx.xx
[Sun Aug 21 11:17:14 2011] [error] [client 82.xx.xx.xx] feed_db_ts: Detected time difference of +00-00-00 00:16:05 from 82.xx.xx.xx
