[ntp:questions] using ACTS modem time service

cipo cseplo_l at netlock.net
Thu Oct 28 21:07:28 UTC 2004


We have tried the ACTS modem time service with a standard ntp (ntp-4.2.0,linux-2.4.27,2xP3 and P4 system)
configuration, but experienced a very strange problem. 

After starting the ntp daemon the modem connects to the service, receives the
time signals (8-12 pieces), calculates the different ntp values (offset, jitter,
...) and hangs up the modem. Immediately after that we receive an error message
stating that all internal buffers are full ("too many recvbufs allocated (40)") and the ntp daemon consumes
100% processor time from that point on. We tried with 2 different modems, and 3
different modem services (ACTS in the US, PTB in Germany, METAS in Switzerland),
but the results were the same.

Has anyone experienced the same problem? We would appreciate any information
regarding this issue.

Thans in advance,
-cipo

Below is the piece of log from ntpd -dddd:
ntpd 4.2.0 at 1.1161-r Thu Oct 28 17:42:24 CEST 2004 (5)
addto_syslog: ntpd 4.2.0 at 1.1161-r Thu Oct 28 17:42:24 CEST 2004 (5)
addto_syslog: signal_no_reset: signal 13 had flags 4000000
addto_syslog: set_process_priority: Leave priority alone: priority_done is <2>
addto_syslog: precision = 1.000 usec
create_sockets(123)
addto_syslog: no IPv6 interfaces found
...
init_io: maxactivefd 0
local_clock: at 0 state 0
getaddrinfo 127.127.23.0
getnetnum given 127.127.23.0, got 127.127.23.0 
peer_clear: at 0 assoc ID 35812 refid INIT
refclock_open: fd 5 modem status 0x4126
refclock_ioctl: fd 5 flags 0x4
acts: state 0 send 20 ATB1&C1&D2E0L1M1Q0V1
newpeer: 127.0.0.1->127.127.23.0 mode 3 vers 4 poll 10 18 flags 0x21 0x1 ttl 0 key 00000000
addto_syslog: frequency initialized 111.654 PPM from /etc/ntp.drift
local_clock: at 0 state 1
authtrust: keyid 0000ffff life 1
report_event: system event 'event_restart' (0x01) status 'sync_alarm, sync_unspec, 1 event, event_unspec' (0xc010)
addto_syslog: input_handler: Processed a gob of fd's in 0.845000 msec
refclock_gtlin: fd 5 time 3307985312.205591
refclock_gtlin: fd 5 time 3307985312.205591
addto_syslog: input_handler: Processed a gob of fd's in 0.008000 msec
refclock_gtlin: fd 5 time 3307985312.235103 timecode 2 OK
acts: state 0 timecode 2 OK
addto_syslog: input_handler: Processed a gob of fd's in 0.008000 msec
refclock_gtlin: fd 5 time 3307985312.245105
addto_syslog: select(): nfound=-1, error: Interrupted system call
auth_agekeys: at 1 keys 1 expired 0
addto_syslog: select(): nfound=-1, error: Interrupted system call
refclock_transmit: at 2 127.127.23.0
acts: state 0 send 7 ATM0DS0
poll_update: at 2 127.127.23.0 flags 0021 poll 10 burst 0 last 2 next 1026
addto_syslog: select(): nfound=-1, error: Interrupted system call
addto_syslog: input_handler: Processed a gob of fd's in 0.013000 msec
refclock_gtlin: fd 5 time 3307985315.845510
addto_syslog: input_handler: Processed a gob of fd's in 0.008000 msec
refclock_gtlin: fd 5 time 3307985315.855509
addto_syslog: select(): nfound=-1, error: Interrupted system call
addto_syslog: input_handler: Processed a gob of fd's in 0.010000 msec
refclock_gtlin: fd 5 time 3307985316.025527 timecode 20 T00049531512038#5214
acts: state 1 timecode 20 T00049531512038#5214
addto_syslog: input_handler: Processed a gob of fd's in 0.007000 msec
refclock_gtlin: fd 5 time 3307985316.035529
addto_syslog: select(): nfound=-1, error: Interrupted system call
...
addto_syslog: input_handler: Processed a gob of fd's in 0.016000 msec
refclock_gtlin: fd 5 time 3307985349.209241
addto_syslog: input_handler: Processed a gob of fd's in 0.007000 msec
refclock_gtlin: fd 5 time 3307985349.219238
addto_syslog: input_handler: Processed a gob of fd's in 0.009000 msec
refclock_gtlin: fd 5 time 3307985349.329249 timecode 12 CONNECT 1200
acts: state 1 timecode 12 CONNECT 1200
addto_syslog: input_handler: Processed a gob of fd's in 0.007000 msec
refclock_gtlin: fd 5 time 3307985349.339252
addto_syslog: input_handler: Processed a gob of fd's in 0.018000 msec
refclock_gtlin: fd 5 time 3307985349.999328 timecode 78 2004-10-28 22:49:06 MESZ 44430210310320041028204953306-50000504MEZ=CET=UTC+1h*
acts: state 2 timecode 78 2004-10-28 22:49:06 MESZ 44430210310320041028204953306-50000504MEZ=CET=UTC+1h*
addto_syslog: input_handler: Processed a gob of fd's in 0.007000 msec
refclock_gtlin: fd 5 time 3307985350.009325
...
acts: state 3 timecode 78 2004-10-28 22:49:15 MESZ 44430210310320041028204953306-50000506 MESZ=UTC+2h  *
addto_syslog: input_handler: Processed a gob of fd's in 0.007000 msec
refclock_gtlin: fd 5 time 3307985355.989992
addto_syslog: select(): nfound=-1, error: Interrupted system call
addto_syslog: input_handler: Processed a gob of fd's in 0.023000 msec
refclock_gtlin: fd 5 time 3307985356.640072 timecode 78 2004-10-28 22:49:16 MESZ 44430210310320041028204953306-50000500PTB-Zeit ueber*
acts: state 3 timecode 78 2004-10-28 22:49:16 MESZ 44430210310320041028204953306-50000500PTB-Zeit ueber*
refclock_receive: at 44 127.127.23.0
peer ACTS_PTB(0) event 'event_reach' (0x84) status 'unreach, conf, 1 event, event_reach' (0x8014)
refclock_sample: n 10 offset -1.479881 disp 0.000000 jitter 1.679621
clock_filter: n 1 off -1.479881 del 0.000000 dsp 9.348552 jit 0.000001, age 44
opening filegen (type=2/id=3307910400) "/var/log/ntpstats/peerstats.20041028"
addto_syslog: input_handler: Processed a gob of fd's in 0.008000 msec
refclock_gtlin: fd 5 time 3307985356.650067
addto_syslog: too many recvbufs allocated (40)
addto_syslog: too many recvbufs allocated (40)
addto_syslog: too many recvbufs allocated (40)








More information about the questions mailing list