From 1c3aff37deda95ae5461d1b9e930117da294cbd0 Mon Sep 17 00:00:00 2001 From: Miroslav Lichvar Date: Tue, 26 Nov 2013 18:53:24 +0100 Subject: [PATCH] Convert TRACEON LOG messages to DEBUG_LOG --- configure | 4 ---- local.c | 8 ++------ ntp_core.c | 38 +++++++++++++------------------------- refclock.c | 32 ++++++++------------------------ refclock_phc.c | 4 +--- refclock_pps.c | 4 +--- refclock_shm.c | 4 +--- sources.c | 20 +++++--------------- sourcestats.c | 21 +++++---------------- 9 files changed, 36 insertions(+), 99 deletions(-) diff --git a/configure b/configure index 4216997..3a09758 100755 --- a/configure +++ b/configure @@ -114,7 +114,6 @@ For better control, use the options below. --disable-linuxcaps Disable Linux capabilities support --disable-forcednsretry Don't retry on permanent DNS error --with-sendmail=PATH Path to sendmail binary [/usr/lib/sendmail] - --enable-trace Enable tracing --enable-debug Enable debugging support Fine tuning of the installation directories: @@ -197,9 +196,6 @@ mail_program="/usr/lib/sendmail" for option do case "$option" in - --enable-trace ) - add_def TRACEON - ;; --enable-debug ) debug=1 ;; diff --git a/local.c b/local.c index cbe8518..8de198e 100644 --- a/local.c +++ b/local.c @@ -510,10 +510,8 @@ LCL_AccumulateFrequencyAndOffset(double dfreq, double doffset, double corr_rate) terms of the gradient of the (offset) v (local time) function. */ current_freq_ppm = (1.0 + dfreq) * old_freq_ppm + 1.0e6 * dfreq; -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_Local, "old_freq=%.3fppm new_freq=%.3fppm offset=%.6fsec", + DEBUG_LOG(LOGF_Local, "old_freq=%.3fppm new_freq=%.3fppm offset=%.6fsec", old_freq_ppm, current_freq_ppm, doffset); -#endif /* Call the system-specific driver for setting the frequency */ current_freq_ppm = (*drv_set_freq)(current_freq_ppm); @@ -561,9 +559,7 @@ lcl_RegisterSystemDrivers(lcl_ReadFrequencyDriver read_freq, current_freq_ppm = (*drv_read_freq)(); -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_Local, "Local freq=%.3fppm", current_freq_ppm); -#endif + DEBUG_LOG(LOGF_Local, "Local freq=%.3fppm", current_freq_ppm); } /* ================================================== */ diff --git a/ntp_core.c b/ntp_core.c index f17584e..7910d23 100644 --- a/ntp_core.c +++ b/ntp_core.c @@ -686,10 +686,8 @@ transmit_timeout(void *arg) return; } -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_NtpCore, "Transmit timeout for [%s:%d]", + DEBUG_LOG(LOGF_NtpCore, "Transmit timeout for [%s:%d]", UTI_IPToString(&inst->remote_addr.ip_addr), inst->remote_addr.port); -#endif /* Check whether we need to 'warm up' the link to the other end by sending an echo exchange to ensure both ends' ARP caches are @@ -1080,37 +1078,35 @@ receive_packet(NTP_Packet *message, struct timeval *now, double now_err, NCR_Ins root_delay = pkt_root_delay + fabs(delta); root_dispersion = pkt_root_dispersion + epsilon; -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_NtpCore, "lvm=%o stratum=%d poll=%d prec=%d", + DEBUG_LOG(LOGF_NtpCore, "lvm=%o stratum=%d poll=%d prec=%d", message->lvm, message->stratum, message->poll, message->precision); - LOG(LOGS_INFO, LOGF_NtpCore, "Root delay=%08x (%f), dispersion=%08x (%f)", + DEBUG_LOG(LOGF_NtpCore, "Root delay=%08x (%f), dispersion=%08x (%f)", message->root_delay, pkt_root_delay, message->root_dispersion, pkt_root_dispersion); - LOG(LOGS_INFO, LOGF_NtpCore, "Ref id=[%x], ref_time=%08x.%08x [%s]", + DEBUG_LOG(LOGF_NtpCore, "Ref id=[%x], ref_time=%08x.%08x [%s]", ntohl(message->reference_id), message->reference_ts.hi, message->reference_ts.lo, UTI_TimestampToString(&message->reference_ts)); - LOG(LOGS_INFO, LOGF_NtpCore, "Originate=%08x.%08x [%s]", + DEBUG_LOG(LOGF_NtpCore, "Originate=%08x.%08x [%s]", message->originate_ts.hi, message->originate_ts.lo, UTI_TimestampToString(&message->originate_ts)); - LOG(LOGS_INFO, LOGF_NtpCore, "Message receive=%08x.%08x [%s]", + DEBUG_LOG(LOGF_NtpCore, "Message receive=%08x.%08x [%s]", message->receive_ts.hi, message->receive_ts.lo, UTI_TimestampToString(&message->receive_ts)); - LOG(LOGS_INFO, LOGF_NtpCore, "Transmit=%08x.%08x [%s]", + DEBUG_LOG(LOGF_NtpCore, "Transmit=%08x.%08x [%s]", message->transmit_ts.hi, message->transmit_ts.lo, UTI_TimestampToString(&message->transmit_ts)); - LOG(LOGS_INFO, LOGF_NtpCore, "theta=%f delta=%f epsilon=%f root_delay=%f root_dispersion=%f", + DEBUG_LOG(LOGF_NtpCore, "theta=%f delta=%f epsilon=%f root_delay=%f root_dispersion=%f", theta, delta, epsilon, root_delay, root_dispersion); - LOG(LOGS_INFO, LOGF_NtpCore, "test1=%d test2=%d test3=%d test4=%d valid_data=%d good_data=%d", + DEBUG_LOG(LOGF_NtpCore, "test1=%d test2=%d test3=%d test4=%d valid_data=%d good_data=%d", test1, test2, test3, test4, valid_data, good_data); - LOG(LOGS_INFO, LOGF_NtpCore, "test5=%d test6=%d test7=%d test8=%d valid_header=%d good_header=%d", + DEBUG_LOG(LOGF_NtpCore, "test5=%d test6=%d test7=%d test8=%d valid_header=%d good_header=%d", test5, test6, test7, test8, valid_header, good_header); - LOG(LOGS_INFO, LOGF_NtpCore, "kod_rate=%d valid_kod=%d", kod_rate, valid_kod); -#endif + DEBUG_LOG(LOGF_NtpCore, "kod_rate=%d valid_kod=%d", kod_rate, valid_kod); /* Reduce polling rate if KoD RATE was received */ if (kod_rate && valid_kod) { @@ -1545,21 +1541,13 @@ NCR_SlewTimes(NCR_Instance inst, struct timeval *when, double dfreq, double doff prev = inst->local_rx; if (inst->local_rx.tv_sec || inst->local_rx.tv_usec) UTI_AdjustTimeval(&inst->local_rx, when, &inst->local_rx, &delta, dfreq, doffset); -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_NtpCore, "rx prev=[%s] new=[%s]", + DEBUG_LOG(LOGF_NtpCore, "rx prev=[%s] new=[%s]", UTI_TimevalToString(&prev), UTI_TimevalToString(&inst->local_rx)); -#else - (void)prev; -#endif prev = inst->local_tx; if (inst->local_tx.tv_sec || inst->local_tx.tv_usec) UTI_AdjustTimeval(&inst->local_tx, when, &inst->local_tx, &delta, dfreq, doffset); -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_NtpCore, "tx prev=[%s] new=[%s]", + DEBUG_LOG(LOGF_NtpCore, "tx prev=[%s] new=[%s]", UTI_TimevalToString(&prev), UTI_TimevalToString(&inst->local_tx)); -#else - (void)prev; -#endif } /* ================================================== */ diff --git a/refclock.c b/refclock.c index c375445..15fe9d6 100644 --- a/refclock.c +++ b/refclock.c @@ -249,10 +249,8 @@ RCL_AddRefclock(RefclockParameters *params) inst->source = SRC_CreateNewInstance(inst->ref_id, SRC_REFCLOCK, params->sel_option, NULL); -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_Refclock, "refclock %s added poll=%d dpoll=%d filter=%d", + DEBUG_LOG(LOGF_Refclock, "refclock %s added poll=%d dpoll=%d filter=%d", params->driver_name, inst->poll, inst->driver_poll, params->filter_length); -#endif n_sources++; Free(params->driver_name); @@ -412,18 +410,14 @@ RCL_AddPulse(RCL_Instance instance, struct timeval *pulse_time, double second) if (!filter_get_last_sample(&refclocks[instance->lock_ref].filter, &ref_sample_time, &ref_offset, &ref_dispersion)) { -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_Refclock, "refclock pulse ignored no ref sample"); -#endif + DEBUG_LOG(LOGF_Refclock, "refclock pulse ignored no ref sample"); return 0; } UTI_DiffTimevalsToDouble(&sample_diff, &cooked_time, &ref_sample_time); if (fabs(sample_diff) >= 2.0 / rate) { -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_Refclock, "refclock pulse ignored samplediff=%.9f", + DEBUG_LOG(LOGF_Refclock, "refclock pulse ignored samplediff=%.9f", sample_diff); -#endif return 0; } @@ -436,17 +430,13 @@ RCL_AddPulse(RCL_Instance instance, struct timeval *pulse_time, double second) offset += shift; if (fabs(ref_offset - offset) + ref_dispersion + dispersion >= 0.2 / rate) { -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_Refclock, "refclock pulse ignored offdiff=%.9f refdisp=%.9f disp=%.9f", + DEBUG_LOG(LOGF_Refclock, "refclock pulse ignored offdiff=%.9f refdisp=%.9f disp=%.9f", ref_offset - offset, ref_dispersion, dispersion); -#endif return 0; } -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_Refclock, "refclock pulse second=%.9f offset=%.9f offdiff=%.9f samplediff=%.9f", + DEBUG_LOG(LOGF_Refclock, "refclock pulse second=%.9f offset=%.9f offdiff=%.9f samplediff=%.9f", second, offset, ref_offset - offset, sample_diff); -#endif } else { struct timeval ref_time; int is_synchronised, stratum; @@ -461,10 +451,8 @@ RCL_AddPulse(RCL_Instance instance, struct timeval *pulse_time, double second) distance = fabs(root_delay) / 2 + root_dispersion; if (!is_synchronised || distance >= 0.5 / rate) { -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_Refclock, "refclock pulse ignored second=%.9f sync=%d dist=%.9f", + DEBUG_LOG(LOGF_Refclock, "refclock pulse ignored second=%.9f sync=%d dist=%.9f", second, is_synchronised, distance); -#endif /* Drop also all stored samples */ filter_reset(&instance->filter); return 0; @@ -493,10 +481,8 @@ valid_sample_time(RCL_Instance instance, struct timeval *tv) LCL_ReadRawTime(&raw_time); UTI_DiffTimevalsToDouble(&diff, &raw_time, tv); if (diff < 0.0 || diff > 1 << (instance->poll + 1)) { -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_Refclock, "refclock sample not valid age=%.f tv=%s", + DEBUG_LOG(LOGF_Refclock, "refclock sample not valid age=%.f tv=%s", diff, UTI_TimevalToString(tv)); -#endif return 0; } return 1; @@ -683,10 +669,8 @@ filter_add_sample(struct MedianFilter *filter, struct timeval *sample_time, doub filter->samples[filter->index].offset = offset; filter->samples[filter->index].dispersion = dispersion; -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_Refclock, "filter sample %d t=%s offset=%.9f dispersion=%.9f", + DEBUG_LOG(LOGF_Refclock, "filter sample %d t=%s offset=%.9f dispersion=%.9f", filter->index, UTI_TimevalToString(sample_time), offset, dispersion); -#endif } static int diff --git a/refclock_phc.c b/refclock_phc.c index 195c501..deaec25 100644 --- a/refclock_phc.c +++ b/refclock_phc.c @@ -175,9 +175,7 @@ static int phc_poll(RCL_Instance instance) tv.tv_sec = readings[best].sys_ts2.tv_sec; tv.tv_usec = readings[best].sys_ts2.tv_nsec / 1000; -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_Refclock, "PHC offset: %+.9f delay: %.9f", offset, best_delay); -#endif + DEBUG_LOG(LOGF_Refclock, "PHC offset: %+.9f delay: %.9f", offset, best_delay); return RCL_AddSample(instance, &tv, offset, LEAP_Normal); } diff --git a/refclock_pps.c b/refclock_pps.c index e400096..b17f496 100644 --- a/refclock_pps.c +++ b/refclock_pps.c @@ -147,10 +147,8 @@ static int pps_poll(RCL_Instance instance) } if (seq == pps->last_seq || (ts.tv_sec == 0 && ts.tv_nsec == 0)) { -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_Refclock, "PPS sample ignored seq=%lu ts=%lu.%09lu", + DEBUG_LOG(LOGF_Refclock, "PPS sample ignored seq=%lu ts=%lu.%09lu", seq, ts.tv_sec, ts.tv_nsec); -#endif return 0; } diff --git a/refclock_shm.c b/refclock_shm.c index 4925d97..3ad0a6a 100644 --- a/refclock_shm.c +++ b/refclock_shm.c @@ -100,10 +100,8 @@ static int shm_poll(RCL_Instance instance) if ((t.mode == 1 && t.count != shm->count) || !(t.mode == 0 || t.mode == 1) || !t.valid) { -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_Refclock, "SHM sample ignored mode=%d count=%d valid=%d", + DEBUG_LOG(LOGF_Refclock, "SHM sample ignored mode=%d count=%d valid=%d", t.mode, t.count, t.valid); -#endif return 0; } diff --git a/sources.c b/sources.c index 5be28ef..6098d78 100644 --- a/sources.c +++ b/sources.c @@ -307,10 +307,8 @@ void SRC_AccumulateSample inst->leap_status = leap_status; -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_Sources, "ip=[%s] t=%s ofs=%f del=%f disp=%f str=%d", + DEBUG_LOG(LOGF_Sources, "ip=[%s] t=%s ofs=%f del=%f disp=%f str=%d", source_to_string(inst), UTI_TimevalToString(sample_time), -offset, root_delay, root_dispersion, stratum); -#endif /* WE HAVE TO NEGATE OFFSET IN THIS CALL, IT IS HERE THAT THE SENSE OF OFFSET IS FLIPPED */ @@ -327,9 +325,7 @@ SRC_SetSelectable(SRC_Instance inst) { inst->selectable = 1; -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_Sources, "%s", source_to_string(inst)); -#endif + DEBUG_LOG(LOGF_Sources, "%s", source_to_string(inst)); /* Don't do selection at this point, though - that will come about in due course when we get some useful data from the source */ @@ -342,10 +338,8 @@ SRC_UnsetSelectable(SRC_Instance inst) { inst->selectable = 0; -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_Sources, "%s%s", source_to_string(inst), + DEBUG_LOG(LOGF_Sources, "%s%s", source_to_string(inst), (inst->index == selected_source_index) ? "(REF)":""); -#endif /* If this was the previous reference source, we have to reselect! */ @@ -472,10 +466,8 @@ combine_sources(int n_sel_sources, struct timeval *ref_time, double *offset, offset_weight = 1.0 / sources[index]->sel_info.root_distance; frequency_weight = 1.0 / src_skew; -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_Sources, "combining index=%d oweight=%e offset=%e sd=%e fweight=%e freq=%e skew=%e", + DEBUG_LOG(LOGF_Sources, "combining index=%d oweight=%e offset=%e sd=%e fweight=%e freq=%e skew=%e", index, offset_weight, src_offset, src_offset_sd, frequency_weight, src_frequency, src_skew); -#endif sum_offset_weight += offset_weight; sum_offset += offset_weight * src_offset; @@ -495,10 +487,8 @@ combine_sources(int n_sel_sources, struct timeval *ref_time, double *offset, *frequency = sum_frequency / sum_frequency_weight; *skew = 1.0 / sqrt(inv_sum2_skew); -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_Sources, "combined result offset=%e sd=%e freq=%e skew=%e", + DEBUG_LOG(LOGF_Sources, "combined result offset=%e sd=%e freq=%e skew=%e", *offset, *offset_sd, *frequency, *skew); -#endif return combined; } diff --git a/sourcestats.c b/sourcestats.c index bde1261..643fe28 100644 --- a/sourcestats.c +++ b/sourcestats.c @@ -569,10 +569,8 @@ SST_GetSelectionData(SST_Stats inst, struct timeval *now, *select_ok = inst->regression_ok; -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_SourceStats, "n=%d off=%f dist=%f var=%f selok=%d", + DEBUG_LOG(LOGF_SourceStats, "n=%d off=%f dist=%f var=%f selok=%d", inst->n_samples, offset, *root_distance, *variance, *select_ok); -#endif } /* ================================================== */ @@ -599,10 +597,8 @@ SST_GetTrackingData(SST_Stats inst, struct timeval *ref_time, UTI_DiffTimevalsToDouble(&elapsed_sample, &inst->offset_time, &inst->sample_times[i]); *root_dispersion = inst->root_dispersions[j] + inst->skew * elapsed_sample; -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_SourceStats, "n=%d freq=%f (%.3fppm) skew=%f (%.3fppm) avoff=%f offsd=%f disp=%f", + DEBUG_LOG(LOGF_SourceStats, "n=%d freq=%f (%.3fppm) skew=%f (%.3fppm) avoff=%f offsd=%f disp=%f", inst->n_samples, *frequency, 1.0e6* *frequency, *skew, 1.0e6* *skew, *average_offset, *offset_sd, *root_dispersion); -#endif } @@ -626,13 +622,10 @@ SST_SlewSamples(SST_Stats inst, struct timeval *when, double dfreq, double doffs UTI_AdjustTimeval(sample, when, sample, &delta_time, dfreq, doffset); prev_offset = inst->offsets[i]; inst->offsets[i] += delta_time; -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_SourceStats, "i=%d old_st=[%s] new_st=[%s] old_off=%f new_off=%f", + + DEBUG_LOG(LOGF_SourceStats, "i=%d old_st=[%s] new_st=[%s] old_off=%f new_off=%f", i, UTI_TimevalToString(&prev), UTI_TimevalToString(sample), prev_offset, inst->offsets[i]); -#else - (void)prev; (void)prev_offset; -#endif } /* Do a half-baked update to the regression estimates */ @@ -644,14 +637,10 @@ SST_SlewSamples(SST_Stats inst, struct timeval *when, double dfreq, double doffs inst->estimated_offset += delta_time; inst->estimated_frequency -= dfreq; -#ifdef TRACEON - LOG(LOGS_INFO, LOGF_SourceStats, "old_off_time=[%s] new=[%s] old_off=%f new_off=%f old_freq=%.3fppm new_freq=%.3fppm", + DEBUG_LOG(LOGF_SourceStats, "old_off_time=[%s] new=[%s] old_off=%f new_off=%f old_freq=%.3fppm new_freq=%.3fppm", UTI_TimevalToString(&prev), UTI_TimevalToString(&(inst->offset_time)), prev_offset, inst->estimated_offset, 1.0e6*prev_freq, 1.0e6*inst->estimated_frequency); -#else - (void)prev; (void)prev_offset; (void)prev_freq; -#endif } /* ================================================== */