Re: [chrony-dev] Issue with version 1.25 and GPRS/GSM connections

[ Thread Index | Date Index | More chrony.tuxfamily.org/chrony-dev Archives ]


On Fri, 12 Aug 2011 21:46:56 +0200, Harald Krammer <Harald.Krammer@xxxxxx>
wrote:
> On Fri, 12 Aug 2011 13:06:33 +0200, Miroslav Lichvar
<mlichvar@xxxxxxxxxx>
> wrote:
>> On Fri, Aug 12, 2011 at 09:31:32AM +0200, Harald Krammer wrote:
> 
>>> > But you said it can happen after few hours, that would probably be a
>>> > different problem. Is it possible that you only noticed it after few
>>> > hours?
>>> > 
>>> 
>>> I don't think so. I monitor the time with the command 
>>> "chronyc tracking" in my application. So it happens that the time will
>>> not be synchronized any more after hours or days. It seems for me 
>>> chrony remains in this unknown case. A reboot of chrony helps.
>>> But I can not exclude an error in my application.
>>> 
>>> The problem is is not reproducible for me, so I will create a network 
>>> simulation with a similar behaviour and hope to get more
information's.
> 
>> 
>> Ok, please let us know if you can reproduce it without iburst or if it
>> happens not during or immediately after iburst.
>> 
> 
> Yes, I will do that. End of next the results should be available.
> I test the following constellations:
>  - Chrony 1.25 with iburst 
>  - Chrony 1.25 without iburst 
>  - Chrony latest version from git with iburst 
> 

So I made few tests and here are my results:

Result 1:
#########

Version: Chrony 1.26-git (without test6, without iburst) 
It's working fine
Log: http://hkr.at/chronylog_3days.tar.bz2
Maybe a interesting log with high jitter.  (GPRS Connection)

Result 2:
#########
Version: Chrony 1.26-git (without test6, with iburst)
It's working fine. I can not reproduce the problem. :)

Result 3:
#########
Version: Chrony 1.26-git (without test6, with iburst) 

It looks interesting. The offset is 6651.414062500s. 
Normally my application monitors the offet with the
tracking command and if the offset gets to high, 
chrony will be restarted.
Why 'command sources' shows so a "strange" result? 

210 Number of sources = 1
MS Name/IP address Stratum Poll LastRx Last sample
========================================================
^* 10.126.3.70      2    8  253  -28us[-43us] +/- 509us

Reference ID    : 10.126.3.70 (10.126.3.70)
Stratum         : 3
Ref time (UTC)  : Mon Aug 22 06:58:16 2011
System time     : 6651.414062500 seconds fast of NTP time
Frequency       : 73.729 ppm fast
Residual freq   : -0.001 ppm
Skew            : 0.097 ppm
Root delay      : 0.001012 seconds
Root dispersion : 0.000311 seconds

Tracking Log:
2011-08-22 06:13:38 10.126.3.70      3     73.779      0.184  1.226e-05
2011-08-22 06:15:58 10.126.3.70      3     73.780      0.151 -1.333e-06
2011-08-22 06:18:18 10.126.3.70      3     73.787      0.133  8.869e-06
2011-08-22 06:20:39 10.126.3.70      3     73.784      0.111 -5.910e-06
2011-08-22 06:30:07 10.126.3.70      3     73.795      0.110  2.308e-05
2011-08-22 06:39:28 10.126.3.70      3     73.790      0.071 -1.655e-05
2011-08-22 06:44:08 10.126.3.70      3     73.782      0.085 -2.212e-05
2011-08-22 06:48:48 10.126.3.70      3     73.754      0.123 -8.344e-05
2011-08-22 06:53:32 10.126.3.70      3     73.737      0.126 -1.749e-05
=======================================================================
   Date (UTC) Time     IP Address   St   Freq ppm   Skew ppm     Offset
=======================================================================
2011-08-22 06:58:16 10.126.3.70      3     73.729      0.097 -1.499e-05
2011-08-22 07:03:00 10.126.3.70      3     73.721      0.106 -2.677e-05

measurements.log:
2011-08-22 06:13:38 10.126.3.70     N  2 1111 111 1111  7  6 0.20
-3.800e-05  9.150e-04  3.001e-06  0.000e+00  0.000e+00
2011-08-22 06:15:58 10.126.3.70     N  2 1111 111 1111  7  7 0.45 
7.000e-06  9.820e-04  3.001e-06  0.000e+00  0.000e+00
2011-08-22 06:18:18 10.126.3.70     N  2 1111 111 1111  7  7 0.73
-3.900e-05  9.930e-04  3.001e-06  0.000e+00  0.000e+00
2011-08-22 06:20:39 10.126.3.70     N  2 1111 111 1111  8  7 0.03 
2.300e-05  9.670e-04  3.000e-06  0.000e+00  0.000e+00
2011-08-22 06:25:23 10.126.3.70     N  2 1111 110 1111  8  8 0.13 
7.510e-04  2.337e-03  3.001e-06  0.000e+00  0.000e+00
2011-08-22 06:30:07 10.126.3.70     N  2 1111 111 1111  8  8 0.47
-1.660e-04  1.272e-03  3.000e-06  0.000e+00  0.000e+00
2011-08-22 06:34:48 10.126.3.70     N  2 1111 110 1111  8  8 0.57 
6.940e-04  2.613e-03  3.001e-06  0.000e+00  0.000e+00
2011-08-22 06:39:28 10.126.3.70     N  2 1111 111 1111  8  8 0.93 
2.900e-05  9.230e-04  3.000e-06  0.000e+00  0.000e+00
2011-08-22 06:44:08 10.126.3.70     N  2 1111 111 1111  8  8 1.00 
7.230e-04  2.104e-03  3.000e-06  0.000e+00  0.000e+00
2011-08-22 06:48:48 10.126.3.70     N  2 1111 111 1111  8  8 1.00 
1.460e-04  9.410e-04  3.000e-06  0.000e+00  0.000e+00
2011-08-22 06:53:32 10.126.3.70     N  2 1111 111 1111  8  8 1.00 
8.250e-04  2.374e-03  3.001e-06  0.000e+00  0.000e+00
========================================================================================================================
   Date (UTC) Time     IP Address   L St 1234 abc 5678 LP RP Score Offset 
  Peer del. Peer disp. Root del.  Root disp.
========================================================================================================================
2011-08-22 06:58:16 10.126.3.70     N  2 1111 111 1111  8  8 1.00 
4.300e-05  1.012e-03  3.000e-06  0.000e+00  0.000e+00
2011-08-22 07:03:00 10.126.3.70     N  2 1111 111 1111  8  8 1.00 
7.160e-04  2.482e-03  3.001e-06  0.000e+00  0.000e+00


statistics.log:
2011-08-22 06:13:38 10.126.3.70      4.661e-05  1.226e-05  2.418e-05 
1.743e-08  1.697e-07 8.5e-02  14   0   6
2011-08-22 06:15:58 10.126.3.70      4.511e-05 -1.333e-06  2.450e-05 
8.929e-10  1.437e-07 1.2e-02  15   0   7
2011-08-22 06:18:18 10.126.3.70      4.452e-05  8.869e-06  2.477e-05 
9.758e-09  1.241e-07 6.7e-02  16   0   8
2011-08-22 06:20:39 10.126.3.70      4.338e-05 -5.910e-06  2.384e-05
-4.023e-09  1.045e-07 4.7e-02  17   0   9
2011-08-22 06:30:07 10.126.3.70      4.733e-05  2.308e-05  3.677e-05 
1.411e-08  1.019e-07 1.4e-01  18   0  10
2011-08-22 06:39:28 10.126.3.70      4.569e-05 -1.655e-05  3.149e-05
-5.715e-09  6.485e-08 8.6e-02  19   0  11
2011-08-22 06:44:08 10.126.3.70      6.262e-05 -2.212e-05  4.664e-05
-1.147e-08  8.392e-08 1.7e-01  20   0  11
2011-08-22 06:48:48 10.126.3.70      7.351e-05 -8.344e-05  4.844e-05
-4.473e-08  1.109e-07 4.9e-01  21   8  13
2011-08-22 06:53:32 10.126.3.70      8.207e-05 -1.749e-05  5.841e-05
-2.121e-08  1.148e-07 4.6e-02  14   0   9
2011-08-22 06:58:16 10.126.3.70      7.820e-05 -1.499e-05  4.989e-05
-9.923e-09  8.813e-08 4.5e-02  15   0   7
2011-08-22 07:03:00 10.126.3.70      9.785e-05 -2.677e-05  6.578e-05
-1.107e-08  1.032e-07 1.1e-01  16   0   7
==============================================================================================================
   Date (UTC) Time     IP Address    Std dev'n Est offset  Offset sd  Diff
freq   Est skew  Stress  Ns  Bs  Nr
==============================================================================================================
2011-08-22 07:07:40 10.126.3.70      9.571e-05 -1.302e-05  6.142e-05
-6.983e-09  8.762e-08 3.8e-02  17   0   9


Result 4:
#########
My "Chrony hang problem" looks to me, that the time server gets 
into state non-synchronizes. 
In 'command sources' a non-synchronizes server entry looks like 
an entry with '?', but all other fields are shown with valid
entries.  Detection of 'timer source unsynchronized' may help.
What do you think? 


Nice greetings,
Harald

---
To unsubscribe email chrony-dev-request@xxxxxxxxxxxxxxxxxxxx with "unsubscribe" in the subject.
For help email chrony-dev-request@xxxxxxxxxxxxxxxxxxxx with "help" in the subject.
Trouble?  Email listmaster@xxxxxxxxxxxxxxxxxxxx.


Mail converted by MHonArc 2.6.19+ http://listengine.tuxfamily.org/