faraphel/chrony
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions

logging: remove facility parameter

Browse source 
It was never used for anything and messages in debug output already
include filenames, which can be easily grepped if there is a need
to see log messages only from a particular file.
This commit is contained in:
Miroslav Lichvar 2017-03-07 17:30:09 +01:00
parent 6db8ec1ba2
commit f282856c72
40 changed files with 448 additions and 522 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

102
client.c
View file

@ -81,8 +81,7 @@ int log_debug_enabled = 0;
void LOG_Message(LOG_Severity severity, void LOG_Message(LOG_Severity severity,
#if DEBUG > 0 #if DEBUG > 0
LOG_Facility facility, int line_number, int line_number, const char *filename, const char *function_name,
const char *filename, const char *function_name,
#endif #endif
const char *format, ...) const char *format, ...)
{ {
@ -168,18 +167,18 @@ get_sockaddrs(const char *hostnames, int port)
addr = (union sockaddr_all *)ARR_GetNewElement(addrs); addr = (union sockaddr_all *)ARR_GetNewElement(addrs);
if (snprintf(addr->un.sun_path, sizeof (addr->un.sun_path), "%s", hostname) >= if (snprintf(addr->un.sun_path, sizeof (addr->un.sun_path), "%s", hostname) >=
sizeof (addr->un.sun_path)) sizeof (addr->un.sun_path))
LOG_FATAL(LOGF_Client, "Unix socket path too long"); LOG_FATAL("Unix socket path too long");
addr->un.sun_family = AF_UNIX; addr->un.sun_family = AF_UNIX;
} else { } else {
if (DNS_Name2IPAddress(hostname, ip_addrs, DNS_MAX_ADDRESSES) != DNS_Success) { if (DNS_Name2IPAddress(hostname, ip_addrs, DNS_MAX_ADDRESSES) != DNS_Success) {
DEBUG_LOG(LOGF_Client, "Could not get IP address for %s", hostname); DEBUG_LOG("Could not get IP address for %s", hostname);
break; break;
} }
for (i = 0; i < DNS_MAX_ADDRESSES && ip_addrs[i].family != IPADDR_UNSPEC; i++) { for (i = 0; i < DNS_MAX_ADDRESSES && ip_addrs[i].family != IPADDR_UNSPEC; i++) {
addr = (union sockaddr_all *)ARR_GetNewElement(addrs); addr = (union sockaddr_all *)ARR_GetNewElement(addrs);
UTI_IPAndPortToSockaddr(&ip_addrs[i], port, (struct sockaddr *)addr); UTI_IPAndPortToSockaddr(&ip_addrs[i], port, (struct sockaddr *)addr);
DEBUG_LOG(LOGF_Client, "Resolved %s to %s", hostname, UTI_IPToString(&ip_addrs[i])); DEBUG_LOG("Resolved %s to %s", hostname, UTI_IPToString(&ip_addrs[i]));
} }
} }
} }
@ -216,7 +215,7 @@ prepare_socket(union sockaddr_all *addr)
sock_fd = socket(addr->sa.sa_family, SOCK_DGRAM, 0); sock_fd = socket(addr->sa.sa_family, SOCK_DGRAM, 0);
if (sock_fd < 0) { if (sock_fd < 0) {
DEBUG_LOG(LOGF_Client, "Could not create socket : %s", strerror(errno)); DEBUG_LOG("Could not create socket : %s", strerror(errno));
return 0; return 0;
} }
@ -229,7 +228,7 @@ prepare_socket(union sockaddr_all *addr)
dir = UTI_PathToDir(addr->un.sun_path); dir = UTI_PathToDir(addr->un.sun_path);
if (snprintf(sa_un.sun_path, sizeof (sa_un.sun_path), if (snprintf(sa_un.sun_path, sizeof (sa_un.sun_path),
"%s/chronyc.%d.sock", dir, (int)getpid()) >= sizeof (sa_un.sun_path)) "%s/chronyc.%d.sock", dir, (int)getpid()) >= sizeof (sa_un.sun_path))
LOG_FATAL(LOGF_Client, "Unix socket path too long"); LOG_FATAL("Unix socket path too long");
Free(dir); Free(dir);
sa_un.sun_family = AF_UNIX; sa_un.sun_family = AF_UNIX;
@ -237,19 +236,19 @@ prepare_socket(union sockaddr_all *addr)
/* Bind the socket to the path */ /* Bind the socket to the path */
if (bind(sock_fd, (struct sockaddr *)&sa_un, sizeof (sa_un)) < 0) { if (bind(sock_fd, (struct sockaddr *)&sa_un, sizeof (sa_un)) < 0) {
DEBUG_LOG(LOGF_Client, "Could not bind socket : %s", strerror(errno)); DEBUG_LOG("Could not bind socket : %s", strerror(errno));
return 0; return 0;
} }
/* Allow server without root privileges to send replies to our socket */ /* Allow server without root privileges to send replies to our socket */
if (chmod(sa_un.sun_path, 0666) < 0) { if (chmod(sa_un.sun_path, 0666) < 0) {
DEBUG_LOG(LOGF_Client, "Could not change socket permissions : %s", strerror(errno)); DEBUG_LOG("Could not change socket permissions : %s", strerror(errno));
return 0; return 0;
} }
} }
if (connect(sock_fd, &addr->sa, addr_len) < 0) { if (connect(sock_fd, &addr->sa, addr_len) < 0) {
DEBUG_LOG(LOGF_Client, "Could not connect socket : %s", strerror(errno)); DEBUG_LOG("Could not connect socket : %s", strerror(errno));
return 0; return 0;
} }
@ -269,7 +268,7 @@ close_io(void)
/* Remove our Unix domain socket */ /* Remove our Unix domain socket */
if (getsockname(sock_fd, &addr.sa, &addr_len) < 0) if (getsockname(sock_fd, &addr.sa, &addr_len) < 0)
LOG_FATAL(LOGF_Client, "getsockname() failed : %s", strerror(errno)); LOG_FATAL("getsockname() failed : %s", strerror(errno));
if (addr_len <= sizeof (addr) && addr_len > sizeof (addr.sa.sa_family) && if (addr_len <= sizeof (addr) && addr_len > sizeof (addr.sa.sa_family) &&
addr.sa.sa_family == AF_UNIX) addr.sa.sa_family == AF_UNIX)
unlink(addr.un.sun_path); unlink(addr.un.sun_path);
@ -295,8 +294,7 @@ open_io(void)
/* Find an address for which a socket can be opened and connected */ /* Find an address for which a socket can be opened and connected */
for (; address_index < ARR_GetSize(sockaddrs); address_index++) { for (; address_index < ARR_GetSize(sockaddrs); address_index++) {
addr = (union sockaddr_all *)ARR_GetElement(sockaddrs, address_index); addr = (union sockaddr_all *)ARR_GetElement(sockaddrs, address_index);
DEBUG_LOG(LOGF_Client, "Opening connection to %s", DEBUG_LOG("Opening connection to %s", UTI_SockaddrToString(&addr->sa));
UTI_SockaddrToString(&addr->sa));
if (prepare_socket(addr)) if (prepare_socket(addr))
return 1; return 1;
@ -373,13 +371,13 @@ read_mask_address(char *line, IPAddr *mask, IPAddr *address)
bits_to_mask(-1, address->family, mask); bits_to_mask(-1, address->family, mask);
return 1; return 1;
} else { } else {
LOG(LOGS_ERR, LOGF_Client, "Could not get address for hostname"); LOG(LOGS_ERR, "Could not get address for hostname");
return 0; return 0;
} }
} }
} }
LOG(LOGS_ERR, LOGF_Client, "Invalid syntax for mask/address"); LOG(LOGS_ERR, "Invalid syntax for mask/address");
return 0; return 0;
} }
@ -438,11 +436,11 @@ read_address_integer(char *line, IPAddr *address, int *value)
line = CPS_SplitWord(line); line = CPS_SplitWord(line);
if (sscanf(line, "%d", value) != 1) { if (sscanf(line, "%d", value) != 1) {
LOG(LOGS_ERR, LOGF_Client, "Invalid syntax for address value"); LOG(LOGS_ERR, "Invalid syntax for address value");
ok = 0; ok = 0;
} else { } else {
if (DNS_Name2IPAddress(hostname, address, 1) != DNS_Success) { if (DNS_Name2IPAddress(hostname, address, 1) != DNS_Success) {
LOG(LOGS_ERR, LOGF_Client, "Could not get address for hostname"); LOG(LOGS_ERR, "Could not get address for hostname");
ok = 0; ok = 0;
} else { } else {
ok = 1; ok = 1;
@ -466,11 +464,11 @@ read_address_double(char *line, IPAddr *address, double *value)
line = CPS_SplitWord(line); line = CPS_SplitWord(line);
if (sscanf(line, "%lf", value) != 1) { if (sscanf(line, "%lf", value) != 1) {
LOG(LOGS_ERR, LOGF_Client, "Invalid syntax for address value"); LOG(LOGS_ERR, "Invalid syntax for address value");
ok = 0; ok = 0;
} else { } else {
if (DNS_Name2IPAddress(hostname, address, 1) != DNS_Success) { if (DNS_Name2IPAddress(hostname, address, 1) != DNS_Success) {
LOG(LOGS_ERR, LOGF_Client, "Could not get address for hostname"); LOG(LOGS_ERR, "Could not get address for hostname");
ok = 0; ok = 0;
} else { } else {
ok = 1; ok = 1;
@ -703,7 +701,7 @@ process_cmd_burst(CMD_Request *msg, char *line)
CPS_SplitWord(s2); CPS_SplitWord(s2);
if (sscanf(s1, "%d/%d", &n_good_samples, &n_total_samples) != 2) { if (sscanf(s1, "%d/%d", &n_good_samples, &n_total_samples) != 2) {
LOG(LOGS_ERR, LOGF_Client, "Invalid syntax for burst command"); LOG(LOGS_ERR, "Invalid syntax for burst command");
return 0; return 0;
} }
@ -735,7 +733,7 @@ process_cmd_local(CMD_Request *msg, char *line)
} else if (CPS_ParseLocal(line, &stratum, &orphan, &distance)) { } else if (CPS_ParseLocal(line, &stratum, &orphan, &distance)) {
on_off = 1; on_off = 1;
} else { } else {
LOG(LOGS_ERR, LOGF_Client, "Invalid syntax for local command"); LOG(LOGS_ERR, "Invalid syntax for local command");
return 0; return 0;
} }
@ -764,7 +762,7 @@ process_cmd_manual(CMD_Request *msg, const char *line)
} else if (!strcmp(p, "reset")) { } else if (!strcmp(p, "reset")) {
msg->data.manual.option = htonl(2); msg->data.manual.option = htonl(2);
} else { } else {
LOG(LOGS_ERR, LOGF_Client, "Invalid syntax for manual command"); LOG(LOGS_ERR, "Invalid syntax for manual command");
return 0; return 0;
} }
msg->command = htons(REQ_MANUAL); msg->command = htons(REQ_MANUAL);
@ -799,7 +797,7 @@ parse_allow_deny(CMD_Request *msg, char *line)
/* Try to parse as the name of a machine */ /* Try to parse as the name of a machine */
if (DNS_Name2IPAddress(p, &ip, 1) != DNS_Success) { if (DNS_Name2IPAddress(p, &ip, 1) != DNS_Success) {
LOG(LOGS_ERR, LOGF_Client, "Could not read address"); LOG(LOGS_ERR, "Could not read address");
return 0; return 0;
} else { } else {
UTI_IPHostToNetwork(&ip, &msg->data.allow_deny.ip); UTI_IPHostToNetwork(&ip, &msg->data.allow_deny.ip);
@ -852,7 +850,7 @@ parse_allow_deny(CMD_Request *msg, char *line)
if (n == 1) { if (n == 1) {
msg->data.allow_deny.subnet_bits = htonl(specified_subnet_bits); msg->data.allow_deny.subnet_bits = htonl(specified_subnet_bits);
} else { } else {
LOG(LOGS_WARN, LOGF_Client, "Warning: badly formatted subnet size, using %d", LOG(LOGS_WARN, "Warning: badly formatted subnet size, using %d",
(int)ntohl(msg->data.allow_deny.subnet_bits)); (int)ntohl(msg->data.allow_deny.subnet_bits));
} }
} }
@ -987,7 +985,7 @@ process_cmd_accheck(CMD_Request *msg, char *line)
UTI_IPHostToNetwork(&ip, &msg->data.ac_check.ip); UTI_IPHostToNetwork(&ip, &msg->data.ac_check.ip);
return 1; return 1;
} else { } else {
LOG(LOGS_ERR, LOGF_Client, "Could not read address"); LOG(LOGS_ERR, "Could not read address");
return 0; return 0;
} }
} }
@ -1003,7 +1001,7 @@ process_cmd_cmdaccheck(CMD_Request *msg, char *line)
UTI_IPHostToNetwork(&ip, &msg->data.ac_check.ip); UTI_IPHostToNetwork(&ip, &msg->data.ac_check.ip);
return 1; return 1;
} else { } else {
LOG(LOGS_ERR, LOGF_Client, "Could not read address"); LOG(LOGS_ERR, "Could not read address");
return 0; return 0;
} }
} }
@ -1073,17 +1071,17 @@ process_cmd_add_server_or_peer(CMD_Request *msg, char *line)
status = CPS_ParseNTPSourceAdd(line, &data); status = CPS_ParseNTPSourceAdd(line, &data);
switch (status) { switch (status) {
case 0: case 0:
LOG(LOGS_ERR, LOGF_Client, "Invalid syntax for add command"); LOG(LOGS_ERR, "Invalid syntax for add command");
break; break;
default: default:
if (DNS_Name2IPAddress(data.name, &ip_addr, 1) != DNS_Success) { if (DNS_Name2IPAddress(data.name, &ip_addr, 1) != DNS_Success) {
LOG(LOGS_ERR, LOGF_Client, "Invalid host/IP address"); LOG(LOGS_ERR, "Invalid host/IP address");
break; break;
} }
opt_name = NULL; opt_name = NULL;
if (opt_name) { if (opt_name) {
LOG(LOGS_ERR, LOGF_Client, "%s can't be set in chronyc", opt_name); LOG(LOGS_ERR, "%s can't be set in chronyc", opt_name);
break; break;
} }
@ -1153,11 +1151,11 @@ process_cmd_delete(CMD_Request *msg, char *line)
CPS_SplitWord(line); CPS_SplitWord(line);
if (!*hostname) { if (!*hostname) {
LOG(LOGS_ERR, LOGF_Client, "Invalid syntax for address"); LOG(LOGS_ERR, "Invalid syntax for address");
ok = 0; ok = 0;
} else { } else {
if (DNS_Name2IPAddress(hostname, &address, 1) != DNS_Success) { if (DNS_Name2IPAddress(hostname, &address, 1) != DNS_Success) {
LOG(LOGS_ERR, LOGF_Client, "Could not get address for hostname"); LOG(LOGS_ERR, "Could not get address for hostname");
ok = 0; ok = 0;
} else { } else {
UTI_IPHostToNetwork(&address, &msg->data.del_source.ip_addr); UTI_IPHostToNetwork(&address, &msg->data.del_source.ip_addr);
@ -1369,17 +1367,16 @@ submit_request(CMD_Request *request, CMD_Reply *reply)
memset(((char *)request) + command_length - padding_length, 0, padding_length); memset(((char *)request) + command_length - padding_length, 0, padding_length);
if (sock_fd < 0) { if (sock_fd < 0) {
DEBUG_LOG(LOGF_Client, "No socket to send request"); DEBUG_LOG("No socket to send request");
return 0; return 0;
} }
if (send(sock_fd, (void *)request, command_length, 0) < 0) { if (send(sock_fd, (void *)request, command_length, 0) < 0) {
DEBUG_LOG(LOGF_Client, "Could not send %d bytes : %s", DEBUG_LOG("Could not send %d bytes : %s", command_length, strerror(errno));
command_length, strerror(errno));
return 0; return 0;
} }
DEBUG_LOG(LOGF_Client, "Sent %d bytes", command_length); DEBUG_LOG("Sent %d bytes", command_length);
} }
if (gettimeofday(&tv, NULL)) if (gettimeofday(&tv, NULL))
@ -1394,7 +1391,7 @@ submit_request(CMD_Request *request, CMD_Reply *reply)
timeout = initial_timeout / 1000.0 * (1U << (n_attempts - 1)) - timeout = initial_timeout / 1000.0 * (1U << (n_attempts - 1)) -
UTI_DiffTimespecsToDouble(&ts_now, &ts_start); UTI_DiffTimespecsToDouble(&ts_now, &ts_start);
UTI_DoubleToTimeval(timeout, &tv); UTI_DoubleToTimeval(timeout, &tv);
DEBUG_LOG(LOGF_Client, "Timeout %f seconds", timeout); DEBUG_LOG("Timeout %f seconds", timeout);
FD_ZERO(&rdfd); FD_ZERO(&rdfd);
FD_ZERO(&wrfd); FD_ZERO(&wrfd);
@ -1408,7 +1405,7 @@ submit_request(CMD_Request *request, CMD_Reply *reply)
select_status = select(sock_fd + 1, &rdfd, &wrfd, &exfd, &tv); select_status = select(sock_fd + 1, &rdfd, &wrfd, &exfd, &tv);
if (select_status < 0) { if (select_status < 0) {
DEBUG_LOG(LOGF_Client, "select failed : %s", strerror(errno)); DEBUG_LOG("select failed : %s", strerror(errno));
} else if (select_status == 0) { } else if (select_status == 0) {
/* Timeout must have elapsed, try a resend? */ /* Timeout must have elapsed, try a resend? */
new_attempt = 1; new_attempt = 1;
@ -1418,10 +1415,10 @@ submit_request(CMD_Request *request, CMD_Reply *reply)
if (recv_status < 0) { if (recv_status < 0) {
/* If we get connrefused here, it suggests the sendto is /* If we get connrefused here, it suggests the sendto is
going to a dead port */ going to a dead port */
DEBUG_LOG(LOGF_Client, "Could not receive : %s", strerror(errno)); DEBUG_LOG("Could not receive : %s", strerror(errno));
new_attempt = 1; new_attempt = 1;
} else { } else {
DEBUG_LOG(LOGF_Client, "Received %d bytes", recv_status); DEBUG_LOG("Received %d bytes", recv_status);
read_length = recv_status; read_length = recv_status;
if (read_length >= offsetof(CMD_Reply, data)) { if (read_length >= offsetof(CMD_Reply, data)) {
@ -1471,7 +1468,7 @@ submit_request(CMD_Request *request, CMD_Reply *reply)
#endif #endif
/* Good packet received, print out results */ /* Good packet received, print out results */
DEBUG_LOG(LOGF_Client, "Reply cmd=%d reply=%d stat=%d", DEBUG_LOG("Reply cmd=%d reply=%d stat=%d",
ntohs(reply->command), ntohs(reply->reply), ntohs(reply->status)); ntohs(reply->command), ntohs(reply->reply), ntohs(reply->status));
break; break;
} }
@ -2264,7 +2261,7 @@ process_cmd_ntpdata(char *line)
for (i = 0; i < n_sources; i++) { for (i = 0; i < n_sources; i++) {
if (specified_addr) { if (specified_addr) {
if (DNS_Name2IPAddress(line, &remote_addr, 1) != DNS_Success) { if (DNS_Name2IPAddress(line, &remote_addr, 1) != DNS_Success) {
LOG(LOGS_ERR, LOGF_Client, "Could not get address for hostname"); LOG(LOGS_ERR, "Could not get address for hostname");
return 0; return 0;
} }
} else { } else {
@ -2421,7 +2418,7 @@ process_cmd_smoothtime(CMD_Request *msg, const char *line)
} else if (!strcmp(line, "activate")) { } else if (!strcmp(line, "activate")) {
msg->data.smoothtime.option = htonl(REQ_SMOOTHTIME_ACTIVATE); msg->data.smoothtime.option = htonl(REQ_SMOOTHTIME_ACTIVATE);
} else { } else {
LOG(LOGS_ERR, LOGF_Client, "Invalid syntax for smoothtime command"); LOG(LOGS_ERR, "Invalid syntax for smoothtime command");
return 0; return 0;
} }
@ -2569,7 +2566,7 @@ process_cmd_manual_delete(CMD_Request *msg, const char *line)
int index; int index;
if (sscanf(line, "%d", &index) != 1) { if (sscanf(line, "%d", &index) != 1) {
LOG(LOGS_ERR, LOGF_Client, "Bad syntax for manual delete command"); LOG(LOGS_ERR, "Bad syntax for manual delete command");
return 0; return 0;
} }
@ -2632,7 +2629,7 @@ process_cmd_makestep(CMD_Request *msg, char *line)
if (*line) { if (*line) {
if (sscanf(line, "%lf %d", &threshold, &limit) != 2) { if (sscanf(line, "%lf %d", &threshold, &limit) != 2) {
LOG(LOGS_ERR, LOGF_Client, "Bad syntax for makestep command"); LOG(LOGS_ERR, "Bad syntax for makestep command");
return 0; return 0;
} }
msg->command = htons(REQ_MODIFY_MAKESTEP); msg->command = htons(REQ_MODIFY_MAKESTEP);
@ -2781,7 +2778,7 @@ process_cmd_dns(const char *line)
} else if (!strcmp(line, "+n")) { } else if (!strcmp(line, "+n")) {
no_dns = 0; no_dns = 0;
} else { } else {
LOG(LOGS_ERR, LOGF_Client, "Unrecognized dns command"); LOG(LOGS_ERR, "Unrecognized dns command");
return 0; return 0;
} }
return 1; return 1;
@ -2796,7 +2793,7 @@ process_cmd_timeout(const char *line)
timeout = atoi(line); timeout = atoi(line);
if (timeout < 100) { if (timeout < 100) {
LOG(LOGS_ERR, LOGF_Client, "Timeout %d is too short", timeout); LOG(LOGS_ERR, "Timeout %d is too short", timeout);
return 0; return 0;
} }
initial_timeout = timeout; initial_timeout = timeout;
@ -2812,7 +2809,7 @@ process_cmd_retries(const char *line)
retries = atoi(line); retries = atoi(line);
if (retries < 0) { if (retries < 0) {
LOG(LOGS_ERR, LOGF_Client, "Invalid maximum number of retries"); LOG(LOGS_ERR, "Invalid maximum number of retries");
return 0; return 0;
} }
max_retries = retries; max_retries = retries;
@ -2839,7 +2836,7 @@ process_cmd_keygen(char *line)
length = CLAMP(10, (bits + 7) / 8, sizeof (key)); length = CLAMP(10, (bits + 7) / 8, sizeof (key));
if (HSH_GetHashId(hash_name) < 0) { if (HSH_GetHashId(hash_name) < 0) {
LOG(LOGS_ERR, LOGF_Client, "Unknown hash function %s", hash_name); LOG(LOGS_ERR, "Unknown hash function %s", hash_name);
return 0; return 0;
} }
@ -3031,11 +3028,11 @@ process_line(char *line)
} else if (!strcmp(command, "authhash") || } else if (!strcmp(command, "authhash") ||
!strcmp(command, "password")) { !strcmp(command, "password")) {
/* Warn, but don't return error to not break scripts */ /* Warn, but don't return error to not break scripts */
LOG(LOGS_WARN, LOGF_Client, "Authentication is no longer supported"); LOG(LOGS_WARN, "Authentication is no longer supported");
do_normal_submit = 0; do_normal_submit = 0;
ret = 1; ret = 1;
} else { } else {
LOG(LOGS_ERR, LOGF_Client, "Unrecognized command"); LOG(LOGS_ERR, "Unrecognized command");
do_normal_submit = 0; do_normal_submit = 0;
} }
@ -3149,8 +3146,7 @@ main(int argc, char **argv)
printf("chronyc (chrony) version %s (%s)\n", CHRONY_VERSION, CHRONYC_FEATURES); printf("chronyc (chrony) version %s (%s)\n", CHRONY_VERSION, CHRONYC_FEATURES);
return 0; return 0;
} else if (!strncmp(*argv, "-", 1)) { } else if (!strncmp(*argv, "-", 1)) {
LOG(LOGS_ERR, LOGF_Client, LOG(LOGS_ERR, "Usage: %s [-h HOST] [-p PORT] [-n] [-c] [-d] [-4|-6] [-m] [COMMAND]",
"Usage: %s [-h HOST] [-p PORT] [-n] [-c] [-d] [-4|-6] [-m] [COMMAND]",
progname); progname);
return 1; return 1;
} else { } else {
@ -3177,7 +3173,7 @@ main(int argc, char **argv)
sockaddrs = get_sockaddrs(hostnames, port); sockaddrs = get_sockaddrs(hostnames, port);
if (!open_io()) if (!open_io())
LOG_FATAL(LOGF_Client, "Could not open connection to daemon"); LOG_FATAL("Could not open connection to daemon");
if (argc > 0) { if (argc > 0) {
ret = process_args(argc, argv, multi); ret = process_args(argc, argv, multi);

8
clientlog.c
View file

@ -294,7 +294,7 @@ set_bucket_params(int interval, int burst, uint16_t *max_tokens,
*tokens_per_packet = 1U << (TS_FRAC + interval - *token_shift); *tokens_per_packet = 1U << (TS_FRAC + interval - *token_shift);
*max_tokens = *tokens_per_packet * burst; *max_tokens = *tokens_per_packet * burst;
DEBUG_LOG(LOGF_ClientLog, "Tokens max %d packet %d shift %d", DEBUG_LOG("Tokens max %d packet %d shift %d",
*max_tokens, *tokens_per_packet, *token_shift); *max_tokens, *tokens_per_packet, *token_shift);
} }
@ -325,7 +325,7 @@ CLG_Initialise(void)
active = !CNF_GetNoClientLog(); active = !CNF_GetNoClientLog();
if (!active) { if (!active) {
if (ntp_leak_rate || cmd_leak_rate) if (ntp_leak_rate || cmd_leak_rate)
LOG_FATAL(LOGF_ClientLog, "ratelimit cannot be used with noclientlog"); LOG_FATAL("ratelimit cannot be used with noclientlog");
return; return;
} }
@ -470,7 +470,7 @@ CLG_LogNTPAccess(IPAddr *client, struct timespec *now)
record->flags & FLAG_NTP_DROPPED ? record->flags & FLAG_NTP_DROPPED ?
&record->ntp_timeout_rate : &record->ntp_rate); &record->ntp_timeout_rate : &record->ntp_rate);
DEBUG_LOG(LOGF_ClientLog, "NTP hits %"PRIu32" rate %d trate %d tokens %d", DEBUG_LOG("NTP hits %"PRIu32" rate %d trate %d tokens %d",
record->ntp_hits, record->ntp_rate, record->ntp_timeout_rate, record->ntp_hits, record->ntp_rate, record->ntp_timeout_rate,
record->ntp_tokens); record->ntp_tokens);
@ -494,7 +494,7 @@ CLG_LogCommandAccess(IPAddr *client, struct timespec *now)
&record->cmd_tokens, max_cmd_tokens, cmd_token_shift, &record->cmd_tokens, max_cmd_tokens, cmd_token_shift,
&record->cmd_rate); &record->cmd_rate);
DEBUG_LOG(LOGF_ClientLog, "Cmd hits %"PRIu32" rate %d tokens %d", DEBUG_LOG("Cmd hits %"PRIu32" rate %d tokens %d",
record->cmd_hits, record->cmd_rate, record->cmd_tokens); record->cmd_hits, record->cmd_rate, record->cmd_tokens);
return get_index(record); return get_index(record);

40
cmdmon.c
View file

@ -161,7 +161,7 @@ prepare_socket(int family, int port_number)
sock_fd = socket(family, SOCK_DGRAM, 0); sock_fd = socket(family, SOCK_DGRAM, 0);
if (sock_fd < 0) { if (sock_fd < 0) {
LOG(LOGS_ERR, LOGF_CmdMon, "Could not open %s command socket : %s", LOG(LOGS_ERR, "Could not open %s command socket : %s",
UTI_SockaddrFamilyToString(family), strerror(errno)); UTI_SockaddrFamilyToString(family), strerror(errno));
return -1; return -1;
} }
@ -172,14 +172,14 @@ prepare_socket(int family, int port_number)
if (family != AF_UNIX) { if (family != AF_UNIX) {
/* Allow reuse of port number */ /* Allow reuse of port number */
if (setsockopt(sock_fd, SOL_SOCKET, SO_REUSEADDR, (char *) &on_off, sizeof(on_off)) < 0) { if (setsockopt(sock_fd, SOL_SOCKET, SO_REUSEADDR, (char *) &on_off, sizeof(on_off)) < 0) {
LOG(LOGS_ERR, LOGF_CmdMon, "Could not set reuseaddr socket options"); LOG(LOGS_ERR, "Could not set reuseaddr socket options");
/* Don't quit - we might survive anyway */ /* Don't quit - we might survive anyway */
} }
#ifdef IP_FREEBIND #ifdef IP_FREEBIND
/* Allow binding to address that doesn't exist yet */ /* Allow binding to address that doesn't exist yet */
if (setsockopt(sock_fd, IPPROTO_IP, IP_FREEBIND, (char *)&on_off, sizeof(on_off)) < 0) { if (setsockopt(sock_fd, IPPROTO_IP, IP_FREEBIND, (char *)&on_off, sizeof(on_off)) < 0) {
LOG(LOGS_ERR, LOGF_CmdMon, "Could not set free bind socket option"); LOG(LOGS_ERR, "Could not set free bind socket option");
} }
#endif #endif
@ -188,7 +188,7 @@ prepare_socket(int family, int port_number)
#ifdef IPV6_V6ONLY #ifdef IPV6_V6ONLY
/* Receive IPv6 packets only */ /* Receive IPv6 packets only */
if (setsockopt(sock_fd, IPPROTO_IPV6, IPV6_V6ONLY, (char *)&on_off, sizeof(on_off)) < 0) { if (setsockopt(sock_fd, IPPROTO_IPV6, IPV6_V6ONLY, (char *)&on_off, sizeof(on_off)) < 0) {
LOG(LOGS_ERR, LOGF_CmdMon, "Could not request IPV6_V6ONLY socket option"); LOG(LOGS_ERR, "Could not request IPV6_V6ONLY socket option");
} }
#endif #endif
} }
@ -230,7 +230,7 @@ prepare_socket(int family, int port_number)
my_addr.un.sun_family = family; my_addr.un.sun_family = family;
if (snprintf(my_addr.un.sun_path, sizeof (my_addr.un.sun_path), "%s", if (snprintf(my_addr.un.sun_path, sizeof (my_addr.un.sun_path), "%s",
CNF_GetBindCommandPath()) >= sizeof (my_addr.un.sun_path)) CNF_GetBindCommandPath()) >= sizeof (my_addr.un.sun_path))
LOG_FATAL(LOGF_CmdMon, "Unix socket path too long"); LOG_FATAL("Unix socket path too long");
unlink(my_addr.un.sun_path); unlink(my_addr.un.sun_path);
break; break;
default: default:
@ -238,7 +238,7 @@ prepare_socket(int family, int port_number)
} }
if (bind(sock_fd, &my_addr.sa, my_addr_len) < 0) { if (bind(sock_fd, &my_addr.sa, my_addr_len) < 0) {
LOG(LOGS_ERR, LOGF_CmdMon, "Could not bind %s command socket : %s", LOG(LOGS_ERR, "Could not bind %s command socket : %s",
UTI_SockaddrFamilyToString(family), strerror(errno)); UTI_SockaddrFamilyToString(family), strerror(errno));
close(sock_fd); close(sock_fd);
return -1; return -1;
@ -315,7 +315,7 @@ CAM_Initialise(int family)
&& sock_fd6 < 0 && sock_fd6 < 0
#endif #endif
) { ) {
LOG_FATAL(LOGF_CmdMon, "Could not open any command socket"); LOG_FATAL("Could not open any command socket");
} }
access_auth_table = ADF_CreateTable(); access_auth_table = ADF_CreateTable();
@ -396,12 +396,12 @@ transmit_reply(CMD_Reply *msg, union sockaddr_all *where_to)
&where_to->sa, addrlen); &where_to->sa, addrlen);
if (status < 0) { if (status < 0) {
DEBUG_LOG(LOGF_CmdMon, "Could not send to %s fd %d : %s", DEBUG_LOG("Could not send to %s fd %d : %s",
UTI_SockaddrToString(&where_to->sa), sock_fd, strerror(errno)); UTI_SockaddrToString(&where_to->sa), sock_fd, strerror(errno));
return; return;
} }
DEBUG_LOG(LOGF_CmdMon, "Sent %d bytes to %s fd %d", status, DEBUG_LOG("Sent %d bytes to %s fd %d", status,
UTI_SockaddrToString(&where_to->sa), sock_fd); UTI_SockaddrToString(&where_to->sa), sock_fd);
} }
@ -874,7 +874,7 @@ handle_dfreq(CMD_Request *rx_message, CMD_Reply *tx_message)
double dfreq; double dfreq;
dfreq = UTI_FloatNetworkToHost(rx_message->data.dfreq.dfreq); dfreq = UTI_FloatNetworkToHost(rx_message->data.dfreq.dfreq);
LCL_AccumulateDeltaFrequency(dfreq * 1.0e-6); LCL_AccumulateDeltaFrequency(dfreq * 1.0e-6);
LOG(LOGS_INFO, LOGF_CmdMon, "Accumulated delta freq of %.3fppm", dfreq); LOG(LOGS_INFO, "Accumulated delta freq of %.3fppm", dfreq);
} }
/* ================================================== */ /* ================================================== */
@ -887,7 +887,7 @@ handle_doffset(CMD_Request *rx_message, CMD_Reply *tx_message)
sec = (int32_t)ntohl(rx_message->data.doffset.sec); sec = (int32_t)ntohl(rx_message->data.doffset.sec);
usec = (int32_t)ntohl(rx_message->data.doffset.usec); usec = (int32_t)ntohl(rx_message->data.doffset.usec);
doffset = (double) sec + 1.0e-6 * (double) usec; doffset = (double) sec + 1.0e-6 * (double) usec;
LOG(LOGS_INFO, LOGF_CmdMon, "Accumulated delta offset of %.6f seconds", doffset); LOG(LOGS_INFO, "Accumulated delta offset of %.6f seconds", doffset);
LCL_AccumulateOffset(doffset, 0.0); LCL_AccumulateOffset(doffset, 0.0);
} }
@ -1258,14 +1258,14 @@ read_from_cmd_socket(int sock_fd, int event, void *anything)
&where_from.sa, &from_length); &where_from.sa, &from_length);
if (status < 0) { if (status < 0) {
LOG(LOGS_WARN, LOGF_CmdMon, "Error [%s] reading from control socket %d", LOG(LOGS_WARN, "Error [%s] reading from control socket %d",
strerror(errno), sock_fd); strerror(errno), sock_fd);
return; return;
} }
if (from_length > sizeof (where_from) || if (from_length > sizeof (where_from) ||
from_length <= sizeof (where_from.sa.sa_family)) { from_length <= sizeof (where_from.sa.sa_family)) {
DEBUG_LOG(LOGF_CmdMon, "Read command packet without source address"); DEBUG_LOG("Read command packet without source address");
return; return;
} }
@ -1300,7 +1300,7 @@ read_from_cmd_socket(int sock_fd, int event, void *anything)
assert(0); assert(0);
} }
DEBUG_LOG(LOGF_CmdMon, "Received %d bytes from %s fd %d", DEBUG_LOG("Received %d bytes from %s fd %d",
status, UTI_SockaddrToString(&where_from.sa), sock_fd); status, UTI_SockaddrToString(&where_from.sa), sock_fd);
if (!(localhost || ADF_IsAllowed(access_auth_table, &remote_ip))) { if (!(localhost || ADF_IsAllowed(access_auth_table, &remote_ip))) {
@ -1319,7 +1319,7 @@ read_from_cmd_socket(int sock_fd, int event, void *anything)
/* We don't know how to process anything like this or an error reply /* We don't know how to process anything like this or an error reply
would be larger than the request */ would be larger than the request */
DEBUG_LOG(LOGF_CmdMon, "Command packet dropped"); DEBUG_LOG("Command packet dropped");
return; return;
} }
@ -1341,7 +1341,7 @@ read_from_cmd_socket(int sock_fd, int event, void *anything)
tx_message.pad5 = 0; tx_message.pad5 = 0;
if (rx_message.version != PROTO_VERSION_NUMBER) { if (rx_message.version != PROTO_VERSION_NUMBER) {
DEBUG_LOG(LOGF_CmdMon, "Command packet has invalid version (%d != %d)", DEBUG_LOG("Command packet has invalid version (%d != %d)",
rx_message.version, PROTO_VERSION_NUMBER); rx_message.version, PROTO_VERSION_NUMBER);
if (rx_message.version >= PROTO_VERSION_MISMATCH_COMPAT_SERVER) { if (rx_message.version >= PROTO_VERSION_MISMATCH_COMPAT_SERVER) {
@ -1353,7 +1353,7 @@ read_from_cmd_socket(int sock_fd, int event, void *anything)
if (rx_command >= N_REQUEST_TYPES || if (rx_command >= N_REQUEST_TYPES ||
expected_length < (int)offsetof(CMD_Request, data)) { expected_length < (int)offsetof(CMD_Request, data)) {
DEBUG_LOG(LOGF_CmdMon, "Command packet has invalid command %d", rx_command); DEBUG_LOG("Command packet has invalid command %d", rx_command);
tx_message.status = htons(STT_INVALID); tx_message.status = htons(STT_INVALID);
transmit_reply(&tx_message, &where_from); transmit_reply(&tx_message, &where_from);
@ -1361,7 +1361,7 @@ read_from_cmd_socket(int sock_fd, int event, void *anything)
} }
if (read_length < expected_length) { if (read_length < expected_length) {
DEBUG_LOG(LOGF_CmdMon, "Command packet is too short (%d < %d)", read_length, DEBUG_LOG("Command packet is too short (%d < %d)", read_length,
expected_length); expected_length);
tx_message.status = htons(STT_BADPKTLENGTH); tx_message.status = htons(STT_BADPKTLENGTH);
@ -1376,7 +1376,7 @@ read_from_cmd_socket(int sock_fd, int event, void *anything)
/* Don't reply to all requests from hosts other than localhost if the rate /* Don't reply to all requests from hosts other than localhost if the rate
is excessive */ is excessive */
if (!localhost && log_index >= 0 && CLG_LimitCommandResponseRate(log_index)) { if (!localhost && log_index >= 0 && CLG_LimitCommandResponseRate(log_index)) {
DEBUG_LOG(LOGF_CmdMon, "Command packet discarded to limit response rate"); DEBUG_LOG("Command packet discarded to limit response rate");
return; return;
} }
@ -1627,7 +1627,7 @@ read_from_cmd_socket(int sock_fd, int event, void *anything)
break; break;
default: default:
DEBUG_LOG(LOGF_CmdMon, "Unhandled command %d", rx_command); DEBUG_LOG("Unhandled command %d", rx_command);
tx_message.status = htons(STT_FAILED); tx_message.status = htons(STT_FAILED);
break; break;
} }

22
conf.c
View file

@ -271,7 +271,7 @@ static const char *processed_command;
static void static void
command_parse_error(void) command_parse_error(void)
{ {
LOG_FATAL(LOGF_Configure, "Could not parse %s directive at line %d%s%s", LOG_FATAL("Could not parse %s directive at line %d%s%s",
processed_command, line_number, processed_file ? " in file " : "", processed_command, line_number, processed_file ? " in file " : "",
processed_file ? processed_file : ""); processed_file ? processed_file : "");
} }
@ -281,7 +281,7 @@ command_parse_error(void)
static void static void
other_parse_error(const char *message) other_parse_error(const char *message)
{ {
LOG_FATAL(LOGF_Configure, "%s at line %d%s%s", LOG_FATAL("%s at line %d%s%s",
message, line_number, processed_file ? " in file " : "", message, line_number, processed_file ? " in file " : "",
processed_file ? processed_file : ""); processed_file ? processed_file : "");
} }
@ -314,7 +314,7 @@ check_number_of_args(char *line, int num)
num -= get_number_of_args(line); num -= get_number_of_args(line);
if (num) { if (num) {
LOG_FATAL(LOGF_Configure, "%s arguments for %s directive at line %d%s%s", LOG_FATAL("%s arguments for %s directive at line %d%s%s",
num > 0 ? "Missing" : "Too many", num > 0 ? "Missing" : "Too many",
processed_command, line_number, processed_file ? " in file " : "", processed_command, line_number, processed_file ? " in file " : "",
processed_file ? processed_file : ""); processed_file ? processed_file : "");
@ -398,12 +398,12 @@ CNF_ReadFile(const char *filename)
in = fopen(filename, "r"); in = fopen(filename, "r");
if (!in) { if (!in) {
LOG_FATAL(LOGF_Configure, "Could not open configuration file %s : %s", LOG_FATAL("Could not open configuration file %s : %s",
filename, strerror(errno)); filename, strerror(errno));
return; return;
} }
DEBUG_LOG(LOGF_Configure, "Reading %s", filename); DEBUG_LOG("Reading %s", filename);
for (i = 1; fgets(line, sizeof(line), in); i++) { for (i = 1; fgets(line, sizeof(line), in); i++) {
CNF_ParseLine(filename, i, line); CNF_ParseLine(filename, i, line);
@ -569,7 +569,7 @@ CNF_ParseLine(const char *filename, int number, char *line)
!strcasecmp(command, "generatecommandkey") || !strcasecmp(command, "generatecommandkey") ||
!strcasecmp(command, "linux_freq_scale") || !strcasecmp(command, "linux_freq_scale") ||
!strcasecmp(command, "linux_hz")) { !strcasecmp(command, "linux_hz")) {
LOG(LOGS_WARN, LOGF_Configure, "%s directive is no longer supported", command); LOG(LOGS_WARN, "%s directive is no longer supported", command);
} else { } else {
other_parse_error("Invalid command"); other_parse_error("Invalid command");
} }
@ -878,7 +878,7 @@ parse_initstepslew(char *line)
if (DNS_Name2IPAddress(hostname, &ip_addr, 1) == DNS_Success) { if (DNS_Name2IPAddress(hostname, &ip_addr, 1) == DNS_Success) {
ARR_AppendElement(init_sources, &ip_addr); ARR_AppendElement(init_sources, &ip_addr);
} else { } else {
LOG(LOGS_WARN, LOGF_Configure, "Could not resolve address of initstepslew server %s", hostname); LOG(LOGS_WARN, "Could not resolve address of initstepslew server %s", hostname);
} }
} }
} }
@ -1307,7 +1307,7 @@ parse_include(char *line)
check_number_of_args(line, 1); check_number_of_args(line, 1);
if (glob(line, 0, NULL, &gl)) { if (glob(line, 0, NULL, &gl)) {
DEBUG_LOG(LOGF_Configure, "glob of %s failed", line); DEBUG_LOG("glob of %s failed", line);
return; return;
} }
@ -1333,7 +1333,7 @@ CNF_CreateDirs(uid_t uid, gid_t gid)
existed. It MUST NOT be accessible by others as permissions on Unix existed. It MUST NOT be accessible by others as permissions on Unix
domain sockets are ignored on some systems (e.g. Solaris). */ domain sockets are ignored on some systems (e.g. Solaris). */
if (!UTI_CheckDirPermissions(dir, 0770, uid, gid)) { if (!UTI_CheckDirPermissions(dir, 0770, uid, gid)) {
LOG(LOGS_WARN, LOGF_Configure, "Disabled command socket %s", bind_cmd_path); LOG(LOGS_WARN, "Disabled command socket %s", bind_cmd_path);
bind_cmd_path[0] = '\0'; bind_cmd_path[0] = '\0';
} }
@ -1740,7 +1740,7 @@ CNF_SetupAccessRestrictions(void)
node = ARR_GetElement(ntp_restrictions, i); node = ARR_GetElement(ntp_restrictions, i);
status = NCR_AddAccessRestriction(&node->ip, node->subnet_bits, node->allow, node->all); status = NCR_AddAccessRestriction(&node->ip, node->subnet_bits, node->allow, node->all);
if (!status) { if (!status) {
LOG_FATAL(LOGF_Configure, "Bad subnet in %s/%d", UTI_IPToString(&node->ip), node->subnet_bits); LOG_FATAL("Bad subnet in %s/%d", UTI_IPToString(&node->ip), node->subnet_bits);
} }
} }
@ -1748,7 +1748,7 @@ CNF_SetupAccessRestrictions(void)
node = ARR_GetElement(cmd_restrictions, i); node = ARR_GetElement(cmd_restrictions, i);
status = CAM_AddAccessRestriction(&node->ip, node->subnet_bits, node->allow, node->all); status = CAM_AddAccessRestriction(&node->ip, node->subnet_bits, node->allow, node->all);
if (!status) { if (!status) {
LOG_FATAL(LOGF_Configure, "Bad subnet in %s/%d", UTI_IPToString(&node->ip), node->subnet_bits); LOG_FATAL("Bad subnet in %s/%d", UTI_IPToString(&node->ip), node->subnet_bits);
} }
} }

8
hwclock.c
View file

@ -143,7 +143,7 @@ HCL_AccumulateSample(HCL_Instance clock, struct timespec *hw_ts,
if (hw_delta <= 0.0 || local_delta < clock->min_separation / 2.0) { if (hw_delta <= 0.0 || local_delta < clock->min_separation / 2.0) {
clock->n_samples = 0; clock->n_samples = 0;
DEBUG_LOG(LOGF_HwClocks, "HW clock reset interval=%f", local_delta); DEBUG_LOG("HW clock reset interval=%f", local_delta);
} }
for (i = MAX_SAMPLES - clock->n_samples; i < MAX_SAMPLES; i++) { for (i = MAX_SAMPLES - clock->n_samples; i < MAX_SAMPLES; i++) {
@ -165,7 +165,7 @@ HCL_AccumulateSample(HCL_Instance clock, struct timespec *hw_ts,
&n_runs, &best_start); &n_runs, &best_start);
if (!clock->valid_coefs) { if (!clock->valid_coefs) {
DEBUG_LOG(LOGF_HwClocks, "HW clock needs more samples"); DEBUG_LOG("HW clock needs more samples");
return; return;
} }
@ -177,12 +177,12 @@ HCL_AccumulateSample(HCL_Instance clock, struct timespec *hw_ts,
/* If the fit doesn't cross the error interval of the last sample, throw away /* If the fit doesn't cross the error interval of the last sample, throw away
all previous samples and keep only the frequency estimate */ all previous samples and keep only the frequency estimate */
if (fabs(clock->offset) > err) { if (fabs(clock->offset) > err) {
DEBUG_LOG(LOGF_HwClocks, "HW clock reset offset=%e", clock->offset); DEBUG_LOG("HW clock reset offset=%e", clock->offset);
clock->offset = 0.0; clock->offset = 0.0;
clock->n_samples = 1; clock->n_samples = 1;
} }
DEBUG_LOG(LOGF_HwClocks, "HW clock samples=%d offset=%e freq=%.9e raw_freq=%.9e err=%e ref_diff=%e", DEBUG_LOG("HW clock samples=%d offset=%e freq=%.9e raw_freq=%.9e err=%e ref_diff=%e",
clock->n_samples, clock->offset, clock->frequency, raw_freq, err, clock->n_samples, clock->offset, clock->frequency, raw_freq, err,
UTI_DiffTimespecsToDouble(&clock->hw_ref, &clock->local_ref)); UTI_DiffTimespecsToDouble(&clock->hw_ref, &clock->local_ref));
} }

12
keys.c
View file

@ -122,7 +122,7 @@ determine_hash_delay(uint32_t key_id)
/* Add on a bit extra to allow for copying, conversions etc */ /* Add on a bit extra to allow for copying, conversions etc */
nsecs = 1.0625e9 * min_diff; nsecs = 1.0625e9 * min_diff;
DEBUG_LOG(LOGF_Keys, "authentication delay for key %"PRIu32": %d nsecs", key_id, nsecs); DEBUG_LOG("authentication delay for key %"PRIu32": %d nsecs", key_id, nsecs);
return nsecs; return nsecs;
} }
@ -200,7 +200,7 @@ KEY_Reload(void)
in = fopen(key_file, "r"); in = fopen(key_file, "r");
if (!in) { if (!in) {
LOG(LOGS_WARN, LOGF_Keys, "Could not open keyfile %s", key_file); LOG(LOGS_WARN, "Could not open keyfile %s", key_file);
return; return;
} }
@ -212,19 +212,19 @@ KEY_Reload(void)
continue; continue;
if (!CPS_ParseKey(line, &key_id, &hashname, &keyval)) { if (!CPS_ParseKey(line, &key_id, &hashname, &keyval)) {
LOG(LOGS_WARN, LOGF_Keys, "Could not parse key at line %d in file %s", line_number, key_file); LOG(LOGS_WARN, "Could not parse key at line %d in file %s", line_number, key_file);
continue; continue;
} }
key.hash_id = HSH_GetHashId(hashname); key.hash_id = HSH_GetHashId(hashname);
if (key.hash_id < 0) { if (key.hash_id < 0) {
LOG(LOGS_WARN, LOGF_Keys, "Unknown hash function in key %"PRIu32, key_id); LOG(LOGS_WARN, "Unknown hash function in key %"PRIu32, key_id);
continue; continue;
} }
key.len = decode_password(keyval); key.len = decode_password(keyval);
if (!key.len) { if (!key.len) {
LOG(LOGS_WARN, LOGF_Keys, "Could not decode password in key %"PRIu32, key_id); LOG(LOGS_WARN, "Could not decode password in key %"PRIu32, key_id);
continue; continue;
} }
@ -244,7 +244,7 @@ KEY_Reload(void)
/* Check for duplicates */ /* Check for duplicates */
for (i = 1; i < ARR_GetSize(keys); i++) { for (i = 1; i < ARR_GetSize(keys); i++) {
if (get_key(i - 1)->id == get_key(i)->id) if (get_key(i - 1)->id == get_key(i)->id)
LOG(LOGS_WARN, LOGF_Keys, "Detected duplicate key %"PRIu32, get_key(i - 1)->id); LOG(LOGS_WARN, "Detected duplicate key %"PRIu32, get_key(i - 1)->id);
} }
/* Erase any passwords from stack */ /* Erase any passwords from stack */

18
local.c
View file

@ -146,7 +146,7 @@ calculate_sys_precision(void)
assert(precision_log >= -30); assert(precision_log >= -30);
DEBUG_LOG(LOGF_Local, "Clock precision %.9f (%d)", precision_quantum, precision_log); DEBUG_LOG("Clock precision %.9f (%d)", precision_quantum, precision_log);
} }
/* ================================================== */ /* ================================================== */
@ -358,12 +358,12 @@ LCL_ReadRawTime(struct timespec *ts)
{ {
#if HAVE_CLOCK_GETTIME #if HAVE_CLOCK_GETTIME
if (clock_gettime(CLOCK_REALTIME, ts) < 0) if (clock_gettime(CLOCK_REALTIME, ts) < 0)
LOG_FATAL(LOGF_Local, "clock_gettime() failed : %s", strerror(errno)); LOG_FATAL("clock_gettime() failed : %s", strerror(errno));
#else #else
struct timeval tv; struct timeval tv;
if (gettimeofday(&tv, NULL) < 0) if (gettimeofday(&tv, NULL) < 0)
LOG_FATAL(LOGF_Local, "gettimeofday() failed : %s", strerror(errno)); LOG_FATAL("gettimeofday() failed : %s", strerror(errno));
UTI_TimevalToTimespec(&tv, ts); UTI_TimevalToTimespec(&tv, ts);
#endif #endif
@ -426,7 +426,7 @@ clamp_freq(double freq)
if (freq <= max_freq_ppm && freq >= -max_freq_ppm) if (freq <= max_freq_ppm && freq >= -max_freq_ppm)
return freq; return freq;
LOG(LOGS_WARN, LOGF_Local, "Frequency %.1f ppm exceeds allowed maximum", freq); LOG(LOGS_WARN, "Frequency %.1f ppm exceeds allowed maximum", freq);
return CLAMP(-max_freq_ppm, freq, max_freq_ppm); return CLAMP(-max_freq_ppm, freq, max_freq_ppm);
} }
@ -440,7 +440,7 @@ check_offset(struct timespec *now, double offset)
if (UTI_IsTimeOffsetSane(now, -offset)) if (UTI_IsTimeOffsetSane(now, -offset))
return 1; return 1;
LOG(LOGS_WARN, LOGF_Local, "Adjustment of %.1f seconds is invalid", -offset); LOG(LOGS_WARN, "Adjustment of %.1f seconds is invalid", -offset);
return 0; return 0;
} }
@ -546,7 +546,7 @@ LCL_ApplyStepOffset(double offset)
return 0; return 0;
if (!(*drv_apply_step_offset)(offset)) { if (!(*drv_apply_step_offset)(offset)) {
LOG(LOGS_ERR, LOGF_Local, "Could not step clock"); LOG(LOGS_ERR, "Could not step clock");
return 0; return 0;
} }
@ -613,7 +613,7 @@ LCL_AccumulateFrequencyAndOffset(double dfreq, double doffset, double corr_rate)
current_freq_ppm = clamp_freq(current_freq_ppm); current_freq_ppm = clamp_freq(current_freq_ppm);
DEBUG_LOG(LOGF_Local, "old_freq=%.3fppm new_freq=%.3fppm offset=%.6fsec", DEBUG_LOG("old_freq=%.3fppm new_freq=%.3fppm offset=%.6fsec",
old_freq_ppm, current_freq_ppm, doffset); old_freq_ppm, current_freq_ppm, doffset);
/* Call the system-specific driver for setting the frequency */ /* Call the system-specific driver for setting the frequency */
@ -660,7 +660,7 @@ lcl_RegisterSystemDrivers(lcl_ReadFrequencyDriver read_freq,
current_freq_ppm = (*drv_read_freq)(); current_freq_ppm = (*drv_read_freq)();
DEBUG_LOG(LOGF_Local, "Local freq=%.3fppm", current_freq_ppm); DEBUG_LOG("Local freq=%.3fppm", current_freq_ppm);
} }
/* ================================================== */ /* ================================================== */
@ -684,7 +684,7 @@ LCL_MakeStep(void)
if (!LCL_ApplyStepOffset(-correction)) if (!LCL_ApplyStepOffset(-correction))
return 0; return 0;
LOG(LOGS_WARN, LOGF_Local, "System clock was stepped by %.6f seconds", correction); LOG(LOGS_WARN, "System clock was stepped by %.6f seconds", correction);
return 1; return 1;
} }

7
logging.c
View file

@ -121,8 +121,7 @@ static void log_message(int fatal, LOG_Severity severity, const char *message)
void LOG_Message(LOG_Severity severity, void LOG_Message(LOG_Severity severity,
#if DEBUG > 0 #if DEBUG > 0
LOG_Facility facility, int line_number, int line_number, const char *filename, const char *function_name,
const char *filename, const char *function_name,
#endif #endif
const char *format, ...) const char *format, ...)
{ {
@ -241,7 +240,7 @@ LOG_FileWrite(LOG_FileID id, const char *format, ...)
char filename[512], *logdir = CNF_GetLogDir(); char filename[512], *logdir = CNF_GetLogDir();
if (logdir[0] == '\0') { if (logdir[0] == '\0') {
LOG(LOGS_WARN, LOGF_Logging, "logdir not specified"); LOG(LOGS_WARN, "logdir not specified");
logfiles[id].name = NULL; logfiles[id].name = NULL;
return; return;
} }
@ -249,7 +248,7 @@ LOG_FileWrite(LOG_FileID id, const char *format, ...)
if (snprintf(filename, sizeof(filename), "%s/%s.log", if (snprintf(filename, sizeof(filename), "%s/%s.log",
logdir, logfiles[id].name) >= sizeof (filename) || logdir, logfiles[id].name) >= sizeof (filename) ||
!(logfiles[id].file = fopen(filename, "a"))) { !(logfiles[id].file = fopen(filename, "a"))) {
LOG(LOGS_WARN, LOGF_Logging, "Could not open log file %s", filename); LOG(LOGS_WARN, "Could not open log file %s", filename);
logfiles[id].name = NULL; logfiles[id].name = NULL;
return; return;
} }

65
logging.h
View file

@ -46,26 +46,26 @@ extern int log_debug_enabled;
#endif #endif
#if DEBUG > 0 #if DEBUG > 0
#define LOG_MESSAGE(severity, facility, ...) \ #define LOG_MESSAGE(severity, ...) \
LOG_Message(severity, facility, __LINE__, __FILE__, FUNCTION_NAME, __VA_ARGS__) LOG_Message(severity, __LINE__, __FILE__, FUNCTION_NAME, __VA_ARGS__)
#else #else
#define LOG_MESSAGE(severity, facility, ...) \ #define LOG_MESSAGE(severity, ...) \
LOG_Message(severity, __VA_ARGS__) LOG_Message(severity, __VA_ARGS__)
#endif #endif
#define DEBUG_LOG(facility, ...) \ #define DEBUG_LOG(...) \
do { \ do { \
if (DEBUG && log_debug_enabled) \ if (DEBUG && log_debug_enabled) \
LOG_MESSAGE(LOGS_DEBUG, facility, __VA_ARGS__); \ LOG_MESSAGE(LOGS_DEBUG, __VA_ARGS__); \
} while (0) } while (0)
#define LOG_FATAL(facility, ...) \ #define LOG_FATAL(...) \
do { \ do { \
LOG_MESSAGE(LOGS_FATAL, facility, __VA_ARGS__); \ LOG_MESSAGE(LOGS_FATAL, __VA_ARGS__); \
exit(1); \ exit(1); \
} while (0) } while (0)
#define LOG(severity, facility, ...) LOG_MESSAGE(severity, facility, __VA_ARGS__) #define LOG(severity, ...) LOG_MESSAGE(severity, __VA_ARGS__)
/* Definition of severity */ /* Definition of severity */
typedef enum { typedef enum {
@ -76,50 +76,6 @@ typedef enum {
LOGS_DEBUG LOGS_DEBUG
} LOG_Severity; } LOG_Severity;
/* Definition of facility. Each message is tagged with who generated
it, so that the user can customise what level of reporting he gets
for each area of the software */
typedef enum {
LOGF_Reference,
LOGF_NtpIO,
LOGF_NtpIOLinux,
LOGF_NtpCore,
LOGF_NtpSignd,
LOGF_NtpSources,
LOGF_Scheduler,
LOGF_SourceStats,
LOGF_Sources,
LOGF_Local,
LOGF_Util,
LOGF_Main,
LOGF_Memory,
LOGF_Client,
LOGF_ClientLog,
LOGF_Configure,
LOGF_CmdMon,
LOGF_Acquire,
LOGF_Manual,
LOGF_Keys,
LOGF_Logging,
LOGF_Nameserv,
LOGF_PrivOps,
LOGF_Rtc,
LOGF_Regress,
LOGF_Sys,
LOGF_SysGeneric,
LOGF_SysLinux,
LOGF_SysMacOSX,
LOGF_SysNetBSD,
LOGF_SysSolaris,
LOGF_SysTimex,
LOGF_SysWinnt,
LOGF_TempComp,
LOGF_RtcLinux,
LOGF_Refclock,
LOGF_HwClocks,
LOGF_Smooth,
} LOG_Facility;
/* Init function */ /* Init function */
extern void LOG_Initialise(void); extern void LOG_Initialise(void);
@ -128,9 +84,8 @@ extern void LOG_Finalise(void);
/* Line logging function */ /* Line logging function */
#if DEBUG > 0 #if DEBUG > 0
FORMAT_ATTRIBUTE_PRINTF(6, 7) FORMAT_ATTRIBUTE_PRINTF(5, 6)
extern void LOG_Message(LOG_Severity severity, LOG_Facility facility, extern void LOG_Message(LOG_Severity severity, int line_number, const char *filename,
int line_number, const char *filename,
const char *function_name, const char *format, ...); const char *function_name, const char *format, ...);
#else #else
FORMAT_ATTRIBUTE_PRINTF(2, 3) FORMAT_ATTRIBUTE_PRINTF(2, 3)

29
main.c
View file

@ -290,7 +290,7 @@ write_lockfile(void)
out = fopen(pidfile, "w"); out = fopen(pidfile, "w");
if (!out) { if (!out) {
LOG_FATAL(LOGF_Main, "could not open lockfile %s for writing", pidfile); LOG_FATAL("could not open lockfile %s for writing", pidfile);
} else { } else {
fprintf(out, "%d\n", (int)getpid()); fprintf(out, "%d\n", (int)getpid());
fclose(out); fclose(out);
@ -307,14 +307,14 @@ go_daemon(void)
/* Create pipe which will the daemon use to notify the grandparent /* Create pipe which will the daemon use to notify the grandparent
when it's initialised or send an error message */ when it's initialised or send an error message */
if (pipe(pipefd)) { if (pipe(pipefd)) {
LOG_FATAL(LOGF_Main, "Could not detach, pipe failed : %s", strerror(errno)); LOG_FATAL("Could not detach, pipe failed : %s", strerror(errno));
} }
/* Does this preserve existing signal handlers? */ /* Does this preserve existing signal handlers? */
pid = fork(); pid = fork();
if (pid < 0) { if (pid < 0) {
LOG_FATAL(LOGF_Main, "Could not detach, fork failed : %s", strerror(errno)); LOG_FATAL("Could not detach, fork failed : %s", strerror(errno));
} else if (pid > 0) { } else if (pid > 0) {
/* In the 'grandparent' */ /* In the 'grandparent' */
char message[1024]; char message[1024];
@ -340,7 +340,7 @@ go_daemon(void)
pid = fork(); pid = fork();
if (pid < 0) { if (pid < 0) {
LOG_FATAL(LOGF_Main, "Could not detach, fork failed : %s", strerror(errno)); LOG_FATAL("Could not detach, fork failed : %s", strerror(errno));
} else if (pid > 0) { } else if (pid > 0) {
exit(0); /* In the 'parent' */ exit(0); /* In the 'parent' */
} else { } else {
@ -348,7 +348,7 @@ go_daemon(void)
/* Change current directory to / */ /* Change current directory to / */
if (chdir("/") < 0) { if (chdir("/") < 0) {
LOG_FATAL(LOGF_Main, "Could not chdir to / : %s", strerror(errno)); LOG_FATAL("Could not chdir to / : %s", strerror(errno));
} }
/* Don't keep stdin/out/err from before. But don't close /* Don't keep stdin/out/err from before. But don't close
@ -392,7 +392,7 @@ int main
} else if (!strcmp("-P", *argv)) { } else if (!strcmp("-P", *argv)) {
++argv, --argc; ++argv, --argc;
if (argc == 0 || sscanf(*argv, "%d", &sched_priority) != 1) { if (argc == 0 || sscanf(*argv, "%d", &sched_priority) != 1) {
LOG_FATAL(LOGF_Main, "Bad scheduler priority"); LOG_FATAL("Bad scheduler priority");
} }
} else if (!strcmp("-m", *argv)) { } else if (!strcmp("-m", *argv)) {
lock_memory = 1; lock_memory = 1;
@ -403,14 +403,14 @@ int main
} else if (!strcmp("-u", *argv)) { } else if (!strcmp("-u", *argv)) {
++argv, --argc; ++argv, --argc;
if (argc == 0) { if (argc == 0) {
LOG_FATAL(LOGF_Main, "Missing user name"); LOG_FATAL("Missing user name");
} else { } else {
user = *argv; user = *argv;
} }
} else if (!strcmp("-F", *argv)) { } else if (!strcmp("-F", *argv)) {
++argv, --argc; ++argv, --argc;
if (argc == 0 || sscanf(*argv, "%d", &scfilter_level) != 1) if (argc == 0 || sscanf(*argv, "%d", &scfilter_level) != 1)
LOG_FATAL(LOGF_Main, "Bad syscall filter level"); LOG_FATAL("Bad syscall filter level");
} else if (!strcmp("-s", *argv)) { } else if (!strcmp("-s", *argv)) {
do_init_rtc = 1; do_init_rtc = 1;
} else if (!strcmp("-v", *argv) || !strcmp("--version",*argv)) { } else if (!strcmp("-v", *argv) || !strcmp("--version",*argv)) {
@ -434,7 +434,7 @@ int main
} else if (!strcmp("-t", *argv)) { } else if (!strcmp("-t", *argv)) {
++argv, --argc; ++argv, --argc;
if (argc == 0 || sscanf(*argv, "%d", &timeout) != 1 || timeout <= 0) if (argc == 0 || sscanf(*argv, "%d", &timeout) != 1 || timeout <= 0)
LOG_FATAL(LOGF_Main, "Bad timeout"); LOG_FATAL("Bad timeout");
} else if (!strcmp("-4", *argv)) { } else if (!strcmp("-4", *argv)) {
address_family = IPADDR_INET4; address_family = IPADDR_INET4;
} else if (!strcmp("-6", *argv)) { } else if (!strcmp("-6", *argv)) {
@ -444,7 +444,7 @@ int main
progname); progname);
return 0; return 0;
} else if (*argv[0] == '-') { } else if (*argv[0] == '-') {
LOG_FATAL(LOGF_Main, "Unrecognized command line option [%s]", *argv); LOG_FATAL("Unrecognized command line option [%s]", *argv);
} else { } else {
/* Process remaining arguments and configuration lines */ /* Process remaining arguments and configuration lines */
config_args = argc; config_args = argc;
@ -469,8 +469,7 @@ int main
LOG_SetDebugLevel(debug); LOG_SetDebugLevel(debug);
LOG(LOGS_INFO, LOGF_Main, "chronyd version %s starting (%s)", LOG(LOGS_INFO, "chronyd version %s starting (%s)", CHRONY_VERSION, CHRONYD_FEATURES);
CHRONY_VERSION, CHRONYD_FEATURES);
DNS_SetAddressFamily(address_family); DNS_SetAddressFamily(address_family);
@ -489,7 +488,7 @@ int main
* forking, so that message logging goes to the right place (i.e. syslog), in * forking, so that message logging goes to the right place (i.e. syslog), in
* case this chronyd is being run from a boot script. */ * case this chronyd is being run from a boot script. */
if (maybe_another_chronyd_running(&other_pid)) { if (maybe_another_chronyd_running(&other_pid)) {
LOG_FATAL(LOGF_Main, "Another chronyd may already be running (pid=%d), check lockfile (%s)", LOG_FATAL("Another chronyd may already be running (pid=%d), check lockfile (%s)",
other_pid, CNF_GetPidFile()); other_pid, CNF_GetPidFile());
} }
@ -529,7 +528,7 @@ int main
} }
if ((pw = getpwnam(user)) == NULL) if ((pw = getpwnam(user)) == NULL)
LOG_FATAL(LOGF_Main, "Could not get %s uid/gid", user); LOG_FATAL("Could not get %s uid/gid", user);
/* Create all directories before dropping root */ /* Create all directories before dropping root */
CNF_CreateDirs(pw->pw_uid, pw->pw_gid); CNF_CreateDirs(pw->pw_uid, pw->pw_gid);
@ -577,7 +576,7 @@ int main
the scheduler. */ the scheduler. */
SCH_MainLoop(); SCH_MainLoop();
LOG(LOGS_INFO, LOGF_Main, "chronyd exiting"); LOG(LOGS_INFO, "chronyd exiting");
MAI_CleanupAndExit(); MAI_CleanupAndExit();

5
manual.c
View file

@ -145,15 +145,14 @@ estimate_and_set_system(struct timespec *now, int offset_provided, double offset
} }
if (found_freq) { if (found_freq) {
LOG(LOGS_INFO, LOGF_Manual, LOG(LOGS_INFO, "Making a frequency change of %.3f ppm and a slew of %.6f",
"Making a frequency change of %.3f ppm and a slew of %.6f",
1.0e6 * freq, slew_by); 1.0e6 * freq, slew_by);
REF_SetManualReference(now, REF_SetManualReference(now,
slew_by, slew_by,
freq, skew); freq, skew);
} else { } else {
LOG(LOGS_INFO, LOGF_Manual, "Making a slew of %.6f", slew_by); LOG(LOGS_INFO, "Making a slew of %.6f", slew_by);
REF_SetManualReference(now, REF_SetManualReference(now,
slew_by, slew_by,
0.0, skew); 0.0, skew);

6
memory.c
View file

@ -37,7 +37,7 @@ Malloc(size_t size)
r = malloc(size); r = malloc(size);
if (!r && size) if (!r && size)
LOG_FATAL(LOGF_Memory, "Could not allocate memory"); LOG_FATAL("Could not allocate memory");
return r; return r;
} }
@ -49,7 +49,7 @@ Realloc(void *ptr, size_t size)
r = realloc(ptr, size); r = realloc(ptr, size);
if (!r && size) if (!r && size)
LOG_FATAL(LOGF_Memory, "Could not allocate memory"); LOG_FATAL("Could not allocate memory");
return r; return r;
} }
@ -61,7 +61,7 @@ Strdup(const char *s)
r = strdup(s); r = strdup(s);
if (!r) if (!r)
LOG_FATAL(LOGF_Memory, "Could not allocate memory"); LOG_FATAL("Could not allocate memory");
return r; return r;
} }

6
nameserv_async.c
View file

@ -78,7 +78,7 @@ end_resolving(int fd, int event, void *anything)
int i; int i;
if (pthread_join(inst->thread, NULL)) { if (pthread_join(inst->thread, NULL)) {
LOG_FATAL(LOGF_Nameserv, "pthread_join() failed"); LOG_FATAL("pthread_join() failed");
} }
resolving_threads--; resolving_threads--;
@ -110,7 +110,7 @@ DNS_Name2IPAddressAsync(const char *name, DNS_NameResolveHandler handler, void *
inst->status = DNS_Failure; inst->status = DNS_Failure;
if (pipe(inst->pipe)) { if (pipe(inst->pipe)) {
LOG_FATAL(LOGF_Nameserv, "pipe() failed"); LOG_FATAL("pipe() failed");
} }
UTI_FdSetCloexec(inst->pipe[0]); UTI_FdSetCloexec(inst->pipe[0]);
@ -120,7 +120,7 @@ DNS_Name2IPAddressAsync(const char *name, DNS_NameResolveHandler handler, void *
assert(resolving_threads <= 1); assert(resolving_threads <= 1);
if (pthread_create(&inst->thread, NULL, start_resolving, inst)) { if (pthread_create(&inst->thread, NULL, start_resolving, inst)) {
LOG_FATAL(LOGF_Nameserv, "pthread_create() failed"); LOG_FATAL("pthread_create() failed");
} }
SCH_AddFileHandler(inst->pipe[0], SCH_FILE_INPUT, end_resolving, inst); SCH_AddFileHandler(inst->pipe[0], SCH_FILE_INPUT, end_resolving, inst);

81
ntp_core.c
View file

@ -336,13 +336,11 @@ do_time_checks(void)
LCL_ReadRawTime(&now); LCL_ReadRawTime(&now);
if (ts2.tv_sec - now.tv_sec < warning_advance) if (ts2.tv_sec - now.tv_sec < warning_advance)
LOG(LOGS_WARN, LOGF_NtpCore, "Assumed NTP time ends at %s!", LOG(LOGS_WARN, "Assumed NTP time ends at %s!", UTI_TimeToLogForm(ts2.tv_sec));
UTI_TimeToLogForm(ts2.tv_sec));
#else #else
LCL_ReadRawTime(&now); LCL_ReadRawTime(&now);
if (now.tv_sec > 0x7fffffff - warning_advance) if (now.tv_sec > 0x7fffffff - warning_advance)
LOG(LOGS_WARN, LOGF_NtpCore, "System time ends at %s!", LOG(LOGS_WARN, "System time ends at %s!", UTI_TimeToLogForm(0x7fffffff));
UTI_TimeToLogForm(0x7fffffff));
#endif #endif
} }
@ -539,11 +537,11 @@ NCR_GetInstance(NTP_Remote_Address *remote_addr, NTP_Source_Type type, SourcePar
result->auth_mode = AUTH_SYMMETRIC; result->auth_mode = AUTH_SYMMETRIC;
result->auth_key_id = params->authkey; result->auth_key_id = params->authkey;
if (!KEY_KeyKnown(result->auth_key_id)) { if (!KEY_KeyKnown(result->auth_key_id)) {
LOG(LOGS_WARN, LOGF_NtpCore, "Key %"PRIu32" used by source %s is %s", LOG(LOGS_WARN, "Key %"PRIu32" used by source %s is %s",
result->auth_key_id, UTI_IPToString(&result->remote_addr.ip_addr), result->auth_key_id, UTI_IPToString(&result->remote_addr.ip_addr),
"missing"); "missing");
} else if (!KEY_CheckKeyLength(result->auth_key_id)) { } else if (!KEY_CheckKeyLength(result->auth_key_id)) {
LOG(LOGS_WARN, LOGF_NtpCore, "Key %"PRIu32" used by source %s is %s", LOG(LOGS_WARN, "Key %"PRIu32" used by source %s is %s",
result->auth_key_id, UTI_IPToString(&result->remote_addr.ip_addr), result->auth_key_id, UTI_IPToString(&result->remote_addr.ip_addr),
"too short"); "too short");
} }
@ -852,7 +850,7 @@ receive_timeout(void *arg)
{ {
NCR_Instance inst = (NCR_Instance)arg; NCR_Instance inst = (NCR_Instance)arg;
DEBUG_LOG(LOGF_NtpCore, "Receive timeout for [%s:%d]", DEBUG_LOG("Receive timeout for [%s:%d]",
UTI_IPToString(&inst->remote_addr.ip_addr), inst->remote_addr.port); UTI_IPToString(&inst->remote_addr.ip_addr), inst->remote_addr.port);
inst->rx_timeout_id = 0; inst->rx_timeout_id = 0;
@ -1009,7 +1007,7 @@ transmit_packet(NTP_Mode my_mode, /* The mode this machine wants to be */
(unsigned char *)&message.auth_data, (unsigned char *)&message.auth_data,
sizeof (message.auth_data)); sizeof (message.auth_data));
if (!auth_len) { if (!auth_len) {
DEBUG_LOG(LOGF_NtpCore, "Could not generate auth data with key %"PRIu32, key_id); DEBUG_LOG("Could not generate auth data with key %"PRIu32, key_id);
return 0; return 0;
} }
@ -1085,7 +1083,7 @@ transmit_timeout(void *arg)
return; return;
} }
DEBUG_LOG(LOGF_NtpCore, "Transmit timeout for [%s:%d]", DEBUG_LOG("Transmit timeout for [%s:%d]",
UTI_IPToString(&inst->remote_addr.ip_addr), inst->remote_addr.port); UTI_IPToString(&inst->remote_addr.ip_addr), inst->remote_addr.port);
/* Open new client socket */ /* Open new client socket */
@ -1175,12 +1173,12 @@ check_packet_format(NTP_Packet *message, int length)
version = NTP_LVM_TO_VERSION(message->lvm); version = NTP_LVM_TO_VERSION(message->lvm);
if (version < NTP_MIN_COMPAT_VERSION || version > NTP_MAX_COMPAT_VERSION) { if (version < NTP_MIN_COMPAT_VERSION || version > NTP_MAX_COMPAT_VERSION) {
DEBUG_LOG(LOGF_NtpCore, "NTP packet has invalid version %d", version); DEBUG_LOG("NTP packet has invalid version %d", version);
return 0; return 0;
} }
if (length < NTP_NORMAL_PACKET_LENGTH || (unsigned int)length % 4) { if (length < NTP_NORMAL_PACKET_LENGTH || (unsigned int)length % 4) {
DEBUG_LOG(LOGF_NtpCore, "NTP packet has invalid length %d", length); DEBUG_LOG("NTP packet has invalid length %d", length);
return 0; return 0;
} }
@ -1557,21 +1555,21 @@ receive_packet(NCR_Instance inst, NTP_Local_Address *local_addr,
(int)inst->local_tx.source < 0 || inst->local_tx.source >= sizeof (tss_chars)) (int)inst->local_tx.source < 0 || inst->local_tx.source >= sizeof (tss_chars))
assert(0); assert(0);
DEBUG_LOG(LOGF_NtpCore, "NTP packet lvm=%o stratum=%d poll=%d prec=%d root_delay=%f root_disp=%f refid=%"PRIx32" [%s]", DEBUG_LOG("NTP packet lvm=%o stratum=%d poll=%d prec=%d root_delay=%f root_disp=%f refid=%"PRIx32" [%s]",
message->lvm, message->stratum, message->poll, message->precision, message->lvm, message->stratum, message->poll, message->precision,
pkt_root_delay, pkt_root_dispersion, pkt_refid, pkt_root_delay, pkt_root_dispersion, pkt_refid,
message->stratum == NTP_INVALID_STRATUM ? UTI_RefidToString(pkt_refid) : ""); message->stratum == NTP_INVALID_STRATUM ? UTI_RefidToString(pkt_refid) : "");
DEBUG_LOG(LOGF_NtpCore, "reference=%s origin=%s receive=%s transmit=%s", DEBUG_LOG("reference=%s origin=%s receive=%s transmit=%s",
UTI_Ntp64ToString(&message->reference_ts), UTI_Ntp64ToString(&message->reference_ts),
UTI_Ntp64ToString(&message->originate_ts), UTI_Ntp64ToString(&message->originate_ts),
UTI_Ntp64ToString(&message->receive_ts), UTI_Ntp64ToString(&message->receive_ts),
UTI_Ntp64ToString(&message->transmit_ts)); UTI_Ntp64ToString(&message->transmit_ts));
DEBUG_LOG(LOGF_NtpCore, "offset=%.9f delay=%.9f dispersion=%f root_delay=%f root_dispersion=%f", DEBUG_LOG("offset=%.9f delay=%.9f dispersion=%f root_delay=%f root_dispersion=%f",
offset, delay, dispersion, root_delay, root_dispersion); offset, delay, dispersion, root_delay, root_dispersion);
DEBUG_LOG(LOGF_NtpCore, "remote_interval=%.9f local_interval=%.9f server_interval=%.9f txs=%c rxs=%c", DEBUG_LOG("remote_interval=%.9f local_interval=%.9f server_interval=%.9f txs=%c rxs=%c",
remote_interval, local_interval, server_interval, remote_interval, local_interval, server_interval,
tss_chars[inst->local_tx.source], tss_chars[sample_rx_tss]); tss_chars[inst->local_tx.source], tss_chars[sample_rx_tss]);
DEBUG_LOG(LOGF_NtpCore, "test123=%d%d%d test567=%d%d%d testABCD=%d%d%d%d kod_rate=%d interleaved=%d presend=%d valid=%d good=%d updated=%d", DEBUG_LOG("test123=%d%d%d test567=%d%d%d testABCD=%d%d%d%d kod_rate=%d interleaved=%d presend=%d valid=%d good=%d updated=%d",
test1, test2, test3, test5, test6, test7, testA, testB, testC, testD, test1, test2, test3, test5, test6, test7, testA, testB, testC, testD,
kod_rate, interleaved_packet, inst->presend_done, valid_packet, good_packet, kod_rate, interleaved_packet, inst->presend_done, valid_packet, good_packet,
!UTI_CompareTimespecs(&inst->local_rx.ts, &rx_ts->ts)); !UTI_CompareTimespecs(&inst->local_rx.ts, &rx_ts->ts));
@ -1641,7 +1639,7 @@ receive_packet(NCR_Instance inst, NTP_Local_Address *local_addr,
UTI_DiffTimespecsToDouble(&inst->local_rx.ts, &inst->local_tx.ts)); UTI_DiffTimespecsToDouble(&inst->local_rx.ts, &inst->local_tx.ts));
if (kod_rate) { if (kod_rate) {
LOG(LOGS_WARN, LOGF_NtpCore, "Received KoD RATE from %s", LOG(LOGS_WARN, "Received KoD RATE from %s",
UTI_IPToString(&inst->remote_addr.ip_addr)); UTI_IPToString(&inst->remote_addr.ip_addr));
/* Back off for a while and stop ongoing burst */ /* Back off for a while and stop ongoing burst */
@ -1829,15 +1827,14 @@ NCR_ProcessRxKnown(NCR_Instance inst, NTP_Local_Address *local_addr,
if (proc_packet) { if (proc_packet) {
/* Check if the reply was received by the socket that sent the request */ /* Check if the reply was received by the socket that sent the request */
if (local_addr->sock_fd != inst->local_addr.sock_fd) { if (local_addr->sock_fd != inst->local_addr.sock_fd) {
DEBUG_LOG(LOGF_NtpCore, DEBUG_LOG("Packet received by wrong socket %d (expected %d)",
"Packet received by wrong socket %d (expected %d)",
local_addr->sock_fd, inst->local_addr.sock_fd); local_addr->sock_fd, inst->local_addr.sock_fd);
return 0; return 0;
} }
/* Ignore packets from offline sources */ /* Ignore packets from offline sources */
if (inst->opmode == MD_OFFLINE || inst->tx_suspended) { if (inst->opmode == MD_OFFLINE || inst->tx_suspended) {
DEBUG_LOG(LOGF_NtpCore, "Packet from offline source"); DEBUG_LOG("Packet from offline source");
return 0; return 0;
} }
@ -1847,8 +1844,7 @@ NCR_ProcessRxKnown(NCR_Instance inst, NTP_Local_Address *local_addr,
/* It's not a reply to our request, don't return success */ /* It's not a reply to our request, don't return success */
return 0; return 0;
} else { } else {
DEBUG_LOG(LOGF_NtpCore, "NTP packet discarded pkt_mode=%d our_mode=%d", DEBUG_LOG("NTP packet discarded pkt_mode=%d our_mode=%d", pkt_mode, inst->mode);
pkt_mode, inst->mode);
return 0; return 0;
} }
} }
@ -1870,8 +1866,7 @@ NCR_ProcessRxUnknown(NTP_Remote_Address *remote_addr, NTP_Local_Address *local_a
/* Ignore the packet if it wasn't received by server socket */ /* Ignore the packet if it wasn't received by server socket */
if (!NIO_IsServerSocket(local_addr->sock_fd)) { if (!NIO_IsServerSocket(local_addr->sock_fd)) {
DEBUG_LOG(LOGF_NtpCore, "NTP request packet received by client socket %d", DEBUG_LOG("NTP request packet received by client socket %d", local_addr->sock_fd);
local_addr->sock_fd);
return; return;
} }
@ -1879,7 +1874,7 @@ NCR_ProcessRxUnknown(NTP_Remote_Address *remote_addr, NTP_Local_Address *local_a
return; return;
if (!ADF_IsAllowed(access_auth_table, &remote_addr->ip_addr)) { if (!ADF_IsAllowed(access_auth_table, &remote_addr->ip_addr)) {
DEBUG_LOG(LOGF_NtpCore, "NTP packet received from unauthorised host %s port %d", DEBUG_LOG("NTP packet received from unauthorised host %s port %d",
UTI_IPToString(&remote_addr->ip_addr), UTI_IPToString(&remote_addr->ip_addr),
remote_addr->port); remote_addr->port);
return; return;
@ -1898,7 +1893,7 @@ NCR_ProcessRxUnknown(NTP_Remote_Address *remote_addr, NTP_Local_Address *local_a
break; break;
default: default:
/* Discard */ /* Discard */
DEBUG_LOG(LOGF_NtpCore, "NTP packet discarded pkt_mode=%d", pkt_mode); DEBUG_LOG("NTP packet discarded pkt_mode=%d", pkt_mode);
return; return;
} }
@ -1906,7 +1901,7 @@ NCR_ProcessRxUnknown(NTP_Remote_Address *remote_addr, NTP_Local_Address *local_a
/* Don't reply to all requests if the rate is excessive */ /* Don't reply to all requests if the rate is excessive */
if (log_index >= 0 && CLG_LimitNTPResponseRate(log_index)) { if (log_index >= 0 && CLG_LimitNTPResponseRate(log_index)) {
DEBUG_LOG(LOGF_NtpCore, "NTP packet discarded to limit response rate"); DEBUG_LOG("NTP packet discarded to limit response rate");
return; return;
} }
@ -1924,7 +1919,7 @@ NCR_ProcessRxUnknown(NTP_Remote_Address *remote_addr, NTP_Local_Address *local_a
break; break;
default: default:
/* Discard packets in other modes */ /* Discard packets in other modes */
DEBUG_LOG(LOGF_NtpCore, "NTP packet discarded auth_mode=%d", auth_mode); DEBUG_LOG("NTP packet discarded auth_mode=%d", auth_mode);
return; return;
} }
} }
@ -1971,27 +1966,27 @@ update_tx_timestamp(NTP_Local_Timestamp *tx_ts, NTP_Local_Timestamp *new_tx_ts,
double delay; double delay;
if (UTI_IsZeroTimespec(&tx_ts->ts)) { if (UTI_IsZeroTimespec(&tx_ts->ts)) {
DEBUG_LOG(LOGF_NtpCore, "Unexpected TX update"); DEBUG_LOG("Unexpected TX update");
return; return;
} }
/* Check if this is the last packet that was sent */ /* Check if this is the last packet that was sent */
if ((local_ntp_rx && UTI_CompareNtp64(&message->receive_ts, local_ntp_rx)) || if ((local_ntp_rx && UTI_CompareNtp64(&message->receive_ts, local_ntp_rx)) ||
(local_ntp_tx && UTI_CompareNtp64(&message->transmit_ts, local_ntp_tx))) { (local_ntp_tx && UTI_CompareNtp64(&message->transmit_ts, local_ntp_tx))) {
DEBUG_LOG(LOGF_NtpCore, "RX/TX timestamp mismatch"); DEBUG_LOG("RX/TX timestamp mismatch");
return; return;
} }
delay = UTI_DiffTimespecsToDouble(&new_tx_ts->ts, &tx_ts->ts); delay = UTI_DiffTimespecsToDouble(&new_tx_ts->ts, &tx_ts->ts);
if (delay < 0.0 || delay > MAX_TX_DELAY) { if (delay < 0.0 || delay > MAX_TX_DELAY) {
DEBUG_LOG(LOGF_NtpCore, "Unacceptable TX delay %.9f", delay); DEBUG_LOG("Unacceptable TX delay %.9f", delay);
return; return;
} }
*tx_ts = *new_tx_ts; *tx_ts = *new_tx_ts;
DEBUG_LOG(LOGF_NtpCore, "Updated TX timestamp delay=%.9f", delay); DEBUG_LOG("Updated TX timestamp delay=%.9f", delay);
} }
/* ================================================== */ /* ================================================== */
@ -2070,7 +2065,7 @@ NCR_TakeSourceOnline(NCR_Instance inst)
/* Nothing to do */ /* Nothing to do */
break; break;
case MD_OFFLINE: case MD_OFFLINE:
LOG(LOGS_INFO, LOGF_NtpCore, "Source %s online", UTI_IPToString(&inst->remote_addr.ip_addr)); LOG(LOGS_INFO, "Source %s online", UTI_IPToString(&inst->remote_addr.ip_addr));
inst->opmode = MD_ONLINE; inst->opmode = MD_ONLINE;
NCR_ResetInstance(inst); NCR_ResetInstance(inst);
start_initial_timeout(inst); start_initial_timeout(inst);
@ -2080,7 +2075,7 @@ NCR_TakeSourceOnline(NCR_Instance inst)
break; break;
case MD_BURST_WAS_OFFLINE: case MD_BURST_WAS_OFFLINE:
inst->opmode = MD_BURST_WAS_ONLINE; inst->opmode = MD_BURST_WAS_ONLINE;
LOG(LOGS_INFO, LOGF_NtpCore, "Source %s online", UTI_IPToString(&inst->remote_addr.ip_addr)); LOG(LOGS_INFO, "Source %s online", UTI_IPToString(&inst->remote_addr.ip_addr));
break; break;
} }
} }
@ -2092,14 +2087,14 @@ NCR_TakeSourceOffline(NCR_Instance inst)
{ {
switch (inst->opmode) { switch (inst->opmode) {
case MD_ONLINE: case MD_ONLINE:
LOG(LOGS_INFO, LOGF_NtpCore, "Source %s offline", UTI_IPToString(&inst->remote_addr.ip_addr)); LOG(LOGS_INFO, "Source %s offline", UTI_IPToString(&inst->remote_addr.ip_addr));
take_offline(inst); take_offline(inst);
break; break;
case MD_OFFLINE: case MD_OFFLINE:
break; break;
case MD_BURST_WAS_ONLINE: case MD_BURST_WAS_ONLINE:
inst->opmode = MD_BURST_WAS_OFFLINE; inst->opmode = MD_BURST_WAS_OFFLINE;
LOG(LOGS_INFO, LOGF_NtpCore, "Source %s offline", UTI_IPToString(&inst->remote_addr.ip_addr)); LOG(LOGS_INFO, "Source %s offline", UTI_IPToString(&inst->remote_addr.ip_addr));
break; break;
case MD_BURST_WAS_OFFLINE: case MD_BURST_WAS_OFFLINE:
break; break;
@ -2115,7 +2110,7 @@ NCR_ModifyMinpoll(NCR_Instance inst, int new_minpoll)
if (new_minpoll < MIN_MINPOLL || new_minpoll > MAX_POLL) if (new_minpoll < MIN_MINPOLL || new_minpoll > MAX_POLL)
return; return;
inst->minpoll = new_minpoll; inst->minpoll = new_minpoll;
LOG(LOGS_INFO, LOGF_NtpCore, "Source %s new minpoll %d", UTI_IPToString(&inst->remote_addr.ip_addr), new_minpoll); LOG(LOGS_INFO, "Source %s new minpoll %d", UTI_IPToString(&inst->remote_addr.ip_addr), new_minpoll);
if (inst->maxpoll < inst->minpoll) if (inst->maxpoll < inst->minpoll)
NCR_ModifyMaxpoll(inst, inst->minpoll); NCR_ModifyMaxpoll(inst, inst->minpoll);
} }
@ -2128,7 +2123,7 @@ NCR_ModifyMaxpoll(NCR_Instance inst, int new_maxpoll)
if (new_maxpoll < MIN_MAXPOLL || new_maxpoll > MAX_POLL) if (new_maxpoll < MIN_MAXPOLL || new_maxpoll > MAX_POLL)
return; return;
inst->maxpoll = new_maxpoll; inst->maxpoll = new_maxpoll;
LOG(LOGS_INFO, LOGF_NtpCore, "Source %s new maxpoll %d", UTI_IPToString(&inst->remote_addr.ip_addr), new_maxpoll); LOG(LOGS_INFO, "Source %s new maxpoll %d", UTI_IPToString(&inst->remote_addr.ip_addr), new_maxpoll);
if (inst->minpoll > inst->maxpoll) if (inst->minpoll > inst->maxpoll)
NCR_ModifyMinpoll(inst, inst->maxpoll); NCR_ModifyMinpoll(inst, inst->maxpoll);
} }
@ -2139,7 +2134,7 @@ void
NCR_ModifyMaxdelay(NCR_Instance inst, double new_max_delay) NCR_ModifyMaxdelay(NCR_Instance inst, double new_max_delay)
{ {
inst->max_delay = CLAMP(0.0, new_max_delay, MAX_MAXDELAY); inst->max_delay = CLAMP(0.0, new_max_delay, MAX_MAXDELAY);
LOG(LOGS_INFO, LOGF_NtpCore, "Source %s new max delay %f", LOG(LOGS_INFO, "Source %s new max delay %f",
UTI_IPToString(&inst->remote_addr.ip_addr), inst->max_delay); UTI_IPToString(&inst->remote_addr.ip_addr), inst->max_delay);
} }
@ -2149,7 +2144,7 @@ void
NCR_ModifyMaxdelayratio(NCR_Instance inst, double new_max_delay_ratio) NCR_ModifyMaxdelayratio(NCR_Instance inst, double new_max_delay_ratio)
{ {
inst->max_delay_ratio = CLAMP(0.0, new_max_delay_ratio, MAX_MAXDELAYRATIO); inst->max_delay_ratio = CLAMP(0.0, new_max_delay_ratio, MAX_MAXDELAYRATIO);
LOG(LOGS_INFO, LOGF_NtpCore, "Source %s new max delay ratio %f", LOG(LOGS_INFO, "Source %s new max delay ratio %f",
UTI_IPToString(&inst->remote_addr.ip_addr), inst->max_delay_ratio); UTI_IPToString(&inst->remote_addr.ip_addr), inst->max_delay_ratio);
} }
@ -2159,7 +2154,7 @@ void
NCR_ModifyMaxdelaydevratio(NCR_Instance inst, double new_max_delay_dev_ratio) NCR_ModifyMaxdelaydevratio(NCR_Instance inst, double new_max_delay_dev_ratio)
{ {
inst->max_delay_dev_ratio = CLAMP(0.0, new_max_delay_dev_ratio, MAX_MAXDELAYDEVRATIO); inst->max_delay_dev_ratio = CLAMP(0.0, new_max_delay_dev_ratio, MAX_MAXDELAYDEVRATIO);
LOG(LOGS_INFO, LOGF_NtpCore, "Source %s new max delay dev ratio %f", LOG(LOGS_INFO, "Source %s new max delay dev ratio %f",
UTI_IPToString(&inst->remote_addr.ip_addr), inst->max_delay_dev_ratio); UTI_IPToString(&inst->remote_addr.ip_addr), inst->max_delay_dev_ratio);
} }
@ -2169,7 +2164,7 @@ void
NCR_ModifyMinstratum(NCR_Instance inst, int new_min_stratum) NCR_ModifyMinstratum(NCR_Instance inst, int new_min_stratum)
{ {
inst->min_stratum = new_min_stratum; inst->min_stratum = new_min_stratum;
LOG(LOGS_INFO, LOGF_NtpCore, "Source %s new minstratum %d", LOG(LOGS_INFO, "Source %s new minstratum %d",
UTI_IPToString(&inst->remote_addr.ip_addr), new_min_stratum); UTI_IPToString(&inst->remote_addr.ip_addr), new_min_stratum);
} }
@ -2179,7 +2174,7 @@ void
NCR_ModifyPolltarget(NCR_Instance inst, int new_poll_target) NCR_ModifyPolltarget(NCR_Instance inst, int new_poll_target)
{ {
inst->poll_target = new_poll_target; inst->poll_target = new_poll_target;
LOG(LOGS_INFO, LOGF_NtpCore, "Source %s new polltarget %d", LOG(LOGS_INFO, "Source %s new polltarget %d",
UTI_IPToString(&inst->remote_addr.ip_addr), new_poll_target); UTI_IPToString(&inst->remote_addr.ip_addr), new_poll_target);
} }

44
ntp_io.c
View file

@ -130,10 +130,10 @@ prepare_socket(int family, int port_number, int client_only)
if (sock_fd < 0) { if (sock_fd < 0) {
if (!client_only) { if (!client_only) {
LOG(LOGS_ERR, LOGF_NtpIO, "Could not open %s NTP socket : %s", LOG(LOGS_ERR, "Could not open %s NTP socket : %s",
UTI_SockaddrFamilyToString(family), strerror(errno)); UTI_SockaddrFamilyToString(family), strerror(errno));
} else { } else {
DEBUG_LOG(LOGF_NtpIO, "Could not open %s NTP socket : %s", DEBUG_LOG("Could not open %s NTP socket : %s",
UTI_SockaddrFamilyToString(family), strerror(errno)); UTI_SockaddrFamilyToString(family), strerror(errno));
} }
return INVALID_SOCK_FD; return INVALID_SOCK_FD;
@ -193,14 +193,14 @@ prepare_socket(int family, int port_number, int client_only)
/* Make the socket capable of re-using an old address if binding to a specific port */ /* Make the socket capable of re-using an old address if binding to a specific port */
if (port_number && if (port_number &&
setsockopt(sock_fd, SOL_SOCKET, SO_REUSEADDR, (char *)&on_off, sizeof(on_off)) < 0) { setsockopt(sock_fd, SOL_SOCKET, SO_REUSEADDR, (char *)&on_off, sizeof(on_off)) < 0) {
LOG(LOGS_ERR, LOGF_NtpIO, "Could not set %s socket option", "SO_REUSEADDR"); LOG(LOGS_ERR, "Could not set %s socket option", "SO_REUSEADDR");
/* Don't quit - we might survive anyway */ /* Don't quit - we might survive anyway */
} }
/* Make the socket capable of sending broadcast pkts - needed for NTP broadcast mode */ /* Make the socket capable of sending broadcast pkts - needed for NTP broadcast mode */
if (!client_only && if (!client_only &&
setsockopt(sock_fd, SOL_SOCKET, SO_BROADCAST, (char *)&on_off, sizeof(on_off)) < 0) { setsockopt(sock_fd, SOL_SOCKET, SO_BROADCAST, (char *)&on_off, sizeof(on_off)) < 0) {
LOG(LOGS_ERR, LOGF_NtpIO, "Could not set %s socket option", "SO_BROADCAST"); LOG(LOGS_ERR, "Could not set %s socket option", "SO_BROADCAST");
/* Don't quit - we might survive anyway */ /* Don't quit - we might survive anyway */
} }
@ -211,7 +211,7 @@ prepare_socket(int family, int port_number, int client_only)
if (setsockopt(sock_fd, SOL_SOCKET, SO_TIMESTAMPNS, (char *)&on_off, sizeof(on_off)) < 0) if (setsockopt(sock_fd, SOL_SOCKET, SO_TIMESTAMPNS, (char *)&on_off, sizeof(on_off)) < 0)
#endif #endif
if (setsockopt(sock_fd, SOL_SOCKET, SO_TIMESTAMP, (char *)&on_off, sizeof(on_off)) < 0) { if (setsockopt(sock_fd, SOL_SOCKET, SO_TIMESTAMP, (char *)&on_off, sizeof(on_off)) < 0) {
LOG(LOGS_ERR, LOGF_NtpIO, "Could not set %s socket option", "SO_TIMESTAMP"); LOG(LOGS_ERR, "Could not set %s socket option", "SO_TIMESTAMP");
/* Don't quit - we might survive anyway */ /* Don't quit - we might survive anyway */
} }
#endif #endif
@ -224,7 +224,7 @@ prepare_socket(int family, int port_number, int client_only)
/* Allow binding to address that doesn't exist yet */ /* Allow binding to address that doesn't exist yet */
if (my_addr_len > 0 && if (my_addr_len > 0 &&
setsockopt(sock_fd, IPPROTO_IP, IP_FREEBIND, (char *)&on_off, sizeof(on_off)) < 0) { setsockopt(sock_fd, IPPROTO_IP, IP_FREEBIND, (char *)&on_off, sizeof(on_off)) < 0) {
LOG(LOGS_ERR, LOGF_NtpIO, "Could not set %s socket option", "IP_FREEBIND"); LOG(LOGS_ERR, "Could not set %s socket option", "IP_FREEBIND");
} }
#endif #endif
@ -232,7 +232,7 @@ prepare_socket(int family, int port_number, int client_only)
#ifdef HAVE_IN_PKTINFO #ifdef HAVE_IN_PKTINFO
/* We want the local IP info on server sockets */ /* We want the local IP info on server sockets */
if (setsockopt(sock_fd, IPPROTO_IP, IP_PKTINFO, (char *)&on_off, sizeof(on_off)) < 0) { if (setsockopt(sock_fd, IPPROTO_IP, IP_PKTINFO, (char *)&on_off, sizeof(on_off)) < 0) {
LOG(LOGS_ERR, LOGF_NtpIO, "Could not set %s socket option", "IP_PKTINFO"); LOG(LOGS_ERR, "Could not set %s socket option", "IP_PKTINFO");
/* Don't quit - we might survive anyway */ /* Don't quit - we might survive anyway */
} }
#endif #endif
@ -242,18 +242,18 @@ prepare_socket(int family, int port_number, int client_only)
#ifdef IPV6_V6ONLY #ifdef IPV6_V6ONLY
/* Receive IPv6 packets only */ /* Receive IPv6 packets only */
if (setsockopt(sock_fd, IPPROTO_IPV6, IPV6_V6ONLY, (char *)&on_off, sizeof(on_off)) < 0) { if (setsockopt(sock_fd, IPPROTO_IPV6, IPV6_V6ONLY, (char *)&on_off, sizeof(on_off)) < 0) {
LOG(LOGS_ERR, LOGF_NtpIO, "Could not set %s socket option", "IPV6_V6ONLY"); LOG(LOGS_ERR, "Could not set %s socket option", "IPV6_V6ONLY");
} }
#endif #endif
#ifdef HAVE_IN6_PKTINFO #ifdef HAVE_IN6_PKTINFO
#ifdef IPV6_RECVPKTINFO #ifdef IPV6_RECVPKTINFO
if (setsockopt(sock_fd, IPPROTO_IPV6, IPV6_RECVPKTINFO, (char *)&on_off, sizeof(on_off)) < 0) { if (setsockopt(sock_fd, IPPROTO_IPV6, IPV6_RECVPKTINFO, (char *)&on_off, sizeof(on_off)) < 0) {
LOG(LOGS_ERR, LOGF_NtpIO, "Could not set %s socket option", "IPV6_RECVPKTINFO"); LOG(LOGS_ERR, "Could not set %s socket option", "IPV6_RECVPKTINFO");
} }
#else #else
if (setsockopt(sock_fd, IPPROTO_IPV6, IPV6_PKTINFO, (char *)&on_off, sizeof(on_off)) < 0) { if (setsockopt(sock_fd, IPPROTO_IPV6, IPV6_PKTINFO, (char *)&on_off, sizeof(on_off)) < 0) {
LOG(LOGS_ERR, LOGF_NtpIO, "Could not set %s socket option", "IPV6_PKTINFO"); LOG(LOGS_ERR, "Could not set %s socket option", "IPV6_PKTINFO");
} }
#endif #endif
#endif #endif
@ -262,7 +262,7 @@ prepare_socket(int family, int port_number, int client_only)
/* Bind the socket if a port or address was specified */ /* Bind the socket if a port or address was specified */
if (my_addr_len > 0 && PRV_BindSocket(sock_fd, &my_addr.u, my_addr_len) < 0) { if (my_addr_len > 0 && PRV_BindSocket(sock_fd, &my_addr.u, my_addr_len) < 0) {
LOG(LOGS_ERR, LOGF_NtpIO, "Could not bind %s NTP socket : %s", LOG(LOGS_ERR, "Could not bind %s NTP socket : %s",
UTI_SockaddrFamilyToString(family), strerror(errno)); UTI_SockaddrFamilyToString(family), strerror(errno));
close(sock_fd); close(sock_fd);
return INVALID_SOCK_FD; return INVALID_SOCK_FD;
@ -304,7 +304,7 @@ connect_socket(int sock_fd, NTP_Remote_Address *remote_addr)
assert(addr_len); assert(addr_len);
if (connect(sock_fd, &addr.u, addr_len) < 0) { if (connect(sock_fd, &addr.u, addr_len) < 0) {
DEBUG_LOG(LOGF_NtpIO, "Could not connect NTP socket to %s:%d : %s", DEBUG_LOG("Could not connect NTP socket to %s:%d : %s",
UTI_IPToString(&remote_addr->ip_addr), remote_addr->port, UTI_IPToString(&remote_addr->ip_addr), remote_addr->port,
strerror(errno)); strerror(errno));
return 0; return 0;
@ -367,7 +367,7 @@ NIO_Initialise(int family)
if (1) { if (1) {
CNF_HwTsInterface *conf_iface; CNF_HwTsInterface *conf_iface;
if (CNF_GetHwTsInterface(0, &conf_iface)) if (CNF_GetHwTsInterface(0, &conf_iface))
LOG_FATAL(LOGF_NtpIO, "HW timestamping not supported"); LOG_FATAL("HW timestamping not supported");
} }
#endif #endif
@ -430,7 +430,7 @@ NIO_Initialise(int family)
&& client_sock_fd6 == INVALID_SOCK_FD && client_sock_fd6 == INVALID_SOCK_FD
#endif #endif
)) { )) {
LOG_FATAL(LOGF_NtpIO, "Could not open NTP sockets"); LOG_FATAL("Could not open NTP sockets");
} }
} }
@ -584,7 +584,7 @@ process_message(struct msghdr *hdr, int length, int sock_fd)
sched_ts = local_ts.ts; sched_ts = local_ts.ts;
if (hdr->msg_namelen > sizeof (union sockaddr_in46)) { if (hdr->msg_namelen > sizeof (union sockaddr_in46)) {
DEBUG_LOG(LOGF_NtpIO, "Truncated source address"); DEBUG_LOG("Truncated source address");
return; return;
} }
@ -601,13 +601,13 @@ process_message(struct msghdr *hdr, int length, int sock_fd)
local_addr.sock_fd = sock_fd; local_addr.sock_fd = sock_fd;
if (hdr->msg_flags & MSG_TRUNC) { if (hdr->msg_flags & MSG_TRUNC) {
DEBUG_LOG(LOGF_NtpIO, "Received truncated message from %s:%d", DEBUG_LOG("Received truncated message from %s:%d",
UTI_IPToString(&remote_addr.ip_addr), remote_addr.port); UTI_IPToString(&remote_addr.ip_addr), remote_addr.port);
return; return;
} }
if (hdr->msg_flags & MSG_CTRUNC) { if (hdr->msg_flags & MSG_CTRUNC) {
DEBUG_LOG(LOGF_NtpIO, "Truncated control message"); DEBUG_LOG("Truncated control message");
/* Continue */ /* Continue */
} }
@ -663,7 +663,7 @@ process_message(struct msghdr *hdr, int length, int sock_fd)
return; return;
#endif #endif
DEBUG_LOG(LOGF_NtpIO, "Received %d bytes from %s:%d to %s fd=%d if=%d tss=%d delay=%.9f", DEBUG_LOG("Received %d bytes from %s:%d to %s fd=%d if=%d tss=%d delay=%.9f",
length, UTI_IPToString(&remote_addr.ip_addr), remote_addr.port, length, UTI_IPToString(&remote_addr.ip_addr), remote_addr.port,
UTI_IPToString(&local_addr.ip_addr), local_addr.sock_fd, local_addr.if_index, UTI_IPToString(&local_addr.ip_addr), local_addr.sock_fd, local_addr.if_index,
local_ts.source, UTI_DiffTimespecsToDouble(&sched_ts, &local_ts.ts)); local_ts.source, UTI_DiffTimespecsToDouble(&sched_ts, &local_ts.ts));
@ -712,7 +712,7 @@ read_from_socket(int sock_fd, int event, void *anything)
#endif #endif
if (status < 0) { if (status < 0) {
DEBUG_LOG(LOGF_NtpIO, "Could not receive from fd %d : %s", sock_fd, DEBUG_LOG("Could not receive from fd %d : %s", sock_fd,
strerror(errno)); strerror(errno));
return; return;
} }
@ -743,7 +743,7 @@ NIO_SendPacket(NTP_Packet *packet, NTP_Remote_Address *remote_addr,
assert(initialised); assert(initialised);
if (local_addr->sock_fd == INVALID_SOCK_FD) { if (local_addr->sock_fd == INVALID_SOCK_FD) {
DEBUG_LOG(LOGF_NtpIO, "No socket to send to %s:%d", DEBUG_LOG("No socket to send to %s:%d",
UTI_IPToString(&remote_addr->ip_addr), remote_addr->port); UTI_IPToString(&remote_addr->ip_addr), remote_addr->port);
return 0; return 0;
} }
@ -819,14 +819,14 @@ NIO_SendPacket(NTP_Packet *packet, NTP_Remote_Address *remote_addr,
msg.msg_control = NULL; msg.msg_control = NULL;
if (sendmsg(local_addr->sock_fd, &msg, 0) < 0) { if (sendmsg(local_addr->sock_fd, &msg, 0) < 0) {
DEBUG_LOG(LOGF_NtpIO, "Could not send to %s:%d from %s fd %d : %s", DEBUG_LOG("Could not send to %s:%d from %s fd %d : %s",
UTI_IPToString(&remote_addr->ip_addr), remote_addr->port, UTI_IPToString(&remote_addr->ip_addr), remote_addr->port,
UTI_IPToString(&local_addr->ip_addr), local_addr->sock_fd, UTI_IPToString(&local_addr->ip_addr), local_addr->sock_fd,
strerror(errno)); strerror(errno));
return 0; return 0;
} }
DEBUG_LOG(LOGF_NtpIO, "Sent %d bytes to %s:%d from %s fd %d", length, DEBUG_LOG("Sent %d bytes to %s:%d from %s fd %d", length,
UTI_IPToString(&remote_addr->ip_addr), remote_addr->port, UTI_IPToString(&remote_addr->ip_addr), remote_addr->port,
UTI_IPToString(&local_addr->ip_addr), local_addr->sock_fd); UTI_IPToString(&local_addr->ip_addr), local_addr->sock_fd);

31
ntp_io_linux.c
View file

@ -127,7 +127,7 @@ add_interface(CNF_HwTsInterface *conf_iface)
} }
if (ioctl(sock_fd, SIOCGIFINDEX, &req)) { if (ioctl(sock_fd, SIOCGIFINDEX, &req)) {
DEBUG_LOG(LOGF_NtpIOLinux, "ioctl(%s) failed : %s", "SIOCGIFINDEX", strerror(errno)); DEBUG_LOG("ioctl(%s) failed : %s", "SIOCGIFINDEX", strerror(errno));
close(sock_fd); close(sock_fd);
return 0; return 0;
} }
@ -138,7 +138,7 @@ add_interface(CNF_HwTsInterface *conf_iface)
req.ifr_data = (char *)&ts_info; req.ifr_data = (char *)&ts_info;
if (ioctl(sock_fd, SIOCETHTOOL, &req)) { if (ioctl(sock_fd, SIOCETHTOOL, &req)) {
DEBUG_LOG(LOGF_NtpIOLinux, "ioctl(%s) failed : %s", "SIOCETHTOOL", strerror(errno)); DEBUG_LOG("ioctl(%s) failed : %s", "SIOCETHTOOL", strerror(errno));
close(sock_fd); close(sock_fd);
return 0; return 0;
} }
@ -146,7 +146,7 @@ add_interface(CNF_HwTsInterface *conf_iface)
req_hwts_flags = SOF_TIMESTAMPING_RX_HARDWARE | SOF_TIMESTAMPING_TX_HARDWARE | req_hwts_flags = SOF_TIMESTAMPING_RX_HARDWARE | SOF_TIMESTAMPING_TX_HARDWARE |
SOF_TIMESTAMPING_RAW_HARDWARE; SOF_TIMESTAMPING_RAW_HARDWARE;
if ((ts_info.so_timestamping & req_hwts_flags) != req_hwts_flags) { if ((ts_info.so_timestamping & req_hwts_flags) != req_hwts_flags) {
DEBUG_LOG(LOGF_NtpIOLinux, "HW timestamping not supported on %s", req.ifr_name); DEBUG_LOG("HW timestamping not supported on %s", req.ifr_name);
close(sock_fd); close(sock_fd);
return 0; return 0;
} }
@ -157,7 +157,7 @@ add_interface(CNF_HwTsInterface *conf_iface)
req.ifr_data = (char *)&ts_config; req.ifr_data = (char *)&ts_config;
if (ioctl(sock_fd, SIOCSHWTSTAMP, &req)) { if (ioctl(sock_fd, SIOCSHWTSTAMP, &req)) {
DEBUG_LOG(LOGF_NtpIOLinux, "ioctl(%s) failed : %s", "SIOCSHWTSTAMP", strerror(errno)); DEBUG_LOG("ioctl(%s) failed : %s", "SIOCSHWTSTAMP", strerror(errno));
close(sock_fd); close(sock_fd);
return 0; return 0;
} }
@ -187,7 +187,7 @@ add_interface(CNF_HwTsInterface *conf_iface)
iface->clock = HCL_CreateInstance(UTI_Log2ToDouble(MAX(conf_iface->minpoll, MIN_PHC_POLL))); iface->clock = HCL_CreateInstance(UTI_Log2ToDouble(MAX(conf_iface->minpoll, MIN_PHC_POLL)));
LOG(LOGS_INFO, LOGF_NtpIOLinux, "Enabled HW timestamping on %s", iface->name); LOG(LOGS_INFO, "Enabled HW timestamping on %s", iface->name);
return 1; return 1;
} }
@ -204,7 +204,7 @@ add_all_interfaces(CNF_HwTsInterface *conf_iface_all)
conf_iface = *conf_iface_all; conf_iface = *conf_iface_all;
if (getifaddrs(&ifaddr)) { if (getifaddrs(&ifaddr)) {
DEBUG_LOG(LOGF_NtpIOLinux, "getifaddrs() failed : %s", strerror(errno)); DEBUG_LOG("getifaddrs() failed : %s", strerror(errno));
return 0; return 0;
} }
@ -241,7 +241,7 @@ update_interface_speed(struct Interface *iface)
req.ifr_data = (char *)&cmd; req.ifr_data = (char *)&cmd;
if (ioctl(sock_fd, SIOCETHTOOL, &req)) { if (ioctl(sock_fd, SIOCETHTOOL, &req)) {
DEBUG_LOG(LOGF_NtpIOLinux, "ioctl(%s) failed : %s", "SIOCETHTOOL", strerror(errno)); DEBUG_LOG("ioctl(%s) failed : %s", "SIOCETHTOOL", strerror(errno));
close(sock_fd); close(sock_fd);
return; return;
} }
@ -269,7 +269,7 @@ NIO_Linux_Initialise(void)
if (!strcmp("*", conf_iface->name)) if (!strcmp("*", conf_iface->name))
continue; continue;
if (!add_interface(conf_iface)) if (!add_interface(conf_iface))
LOG_FATAL(LOGF_NtpIO, "Could not enable HW timestamping on %s", conf_iface->name); LOG_FATAL("Could not enable HW timestamping on %s", conf_iface->name);
hwts = 1; hwts = 1;
} }
@ -333,13 +333,13 @@ NIO_Linux_SetTimestampSocketOptions(int sock_fd, int client_only, int *events)
flags |= ts_tx_flags; flags |= ts_tx_flags;
if (setsockopt(sock_fd, SOL_SOCKET, SO_SELECT_ERR_QUEUE, &val, sizeof (val)) < 0) { if (setsockopt(sock_fd, SOL_SOCKET, SO_SELECT_ERR_QUEUE, &val, sizeof (val)) < 0) {
LOG(LOGS_ERR, LOGF_NtpIOLinux, "Could not set %s socket option", "SO_SELECT_ERR_QUEUE"); LOG(LOGS_ERR, "Could not set %s socket option", "SO_SELECT_ERR_QUEUE");
ts_flags = 0; ts_flags = 0;
return 0; return 0;
} }
if (setsockopt(sock_fd, SOL_SOCKET, SO_TIMESTAMPING, &flags, sizeof (flags)) < 0) { if (setsockopt(sock_fd, SOL_SOCKET, SO_TIMESTAMPING, &flags, sizeof (flags)) < 0) {
LOG(LOGS_ERR, LOGF_NtpIOLinux, "Could not set %s socket option", "SO_TIMESTAMPING"); LOG(LOGS_ERR, "Could not set %s socket option", "SO_TIMESTAMPING");
ts_flags = 0; ts_flags = 0;
return 0; return 0;
} }
@ -412,7 +412,7 @@ process_hw_timestamp(struct Interface *iface, struct timespec *hw_ts,
ts_delay = UTI_DiffTimespecsToDouble(&local_ts->ts, &ts); ts_delay = UTI_DiffTimespecsToDouble(&local_ts->ts, &ts);
if (fabs(ts_delay) > MAX_TS_DELAY) { if (fabs(ts_delay) > MAX_TS_DELAY) {
DEBUG_LOG(LOGF_NtpIOLinux, "Unacceptable timestamp delay %.9f", ts_delay); DEBUG_LOG("Unacceptable timestamp delay %.9f", ts_delay);
return; return;
} }
@ -512,8 +512,7 @@ NIO_Linux_ProcessMessage(NTP_Remote_Address *remote_addr, NTP_Local_Address *loc
process_hw_timestamp(iface, &ts3.ts[2], local_ts, !is_tx ? length : 0, process_hw_timestamp(iface, &ts3.ts[2], local_ts, !is_tx ? length : 0,
remote_addr->ip_addr.family); remote_addr->ip_addr.family);
} else { } else {
DEBUG_LOG(LOGF_NtpIOLinux, "HW clock not found for interface %d", DEBUG_LOG("HW clock not found for interface %d", local_addr->if_index);
local_addr->if_index);
} }
} }
} }
@ -526,7 +525,7 @@ NIO_Linux_ProcessMessage(NTP_Remote_Address *remote_addr, NTP_Local_Address *loc
if (err.ee_errno != ENOMSG || err.ee_info != SCM_TSTAMP_SND || if (err.ee_errno != ENOMSG || err.ee_info != SCM_TSTAMP_SND ||
err.ee_origin != SO_EE_ORIGIN_TIMESTAMPING) { err.ee_origin != SO_EE_ORIGIN_TIMESTAMPING) {
DEBUG_LOG(LOGF_NtpIOLinux, "Unknown extended error"); DEBUG_LOG("Unknown extended error");
/* Drop the message */ /* Drop the message */
return 1; return 1;
} }
@ -543,7 +542,7 @@ NIO_Linux_ProcessMessage(NTP_Remote_Address *remote_addr, NTP_Local_Address *loc
l2_length = length; l2_length = length;
length = extract_udp_data(hdr->msg_iov[0].iov_base, remote_addr, length); length = extract_udp_data(hdr->msg_iov[0].iov_base, remote_addr, length);
DEBUG_LOG(LOGF_NtpIOLinux, "Received %d (%d) bytes from error queue for %s:%d fd=%d if=%d tss=%d", DEBUG_LOG("Received %d (%d) bytes from error queue for %s:%d fd=%d if=%d tss=%d",
l2_length, length, UTI_IPToString(&remote_addr->ip_addr), remote_addr->port, l2_length, length, UTI_IPToString(&remote_addr->ip_addr), remote_addr->port,
local_addr->sock_fd, local_addr->if_index, local_ts->source); local_addr->sock_fd, local_addr->if_index, local_ts->source);
@ -557,7 +556,7 @@ NIO_Linux_ProcessMessage(NTP_Remote_Address *remote_addr, NTP_Local_Address *loc
/* Drop the message if HW timestamp is missing or its processing failed */ /* Drop the message if HW timestamp is missing or its processing failed */
if ((ts_flags & SOF_TIMESTAMPING_RAW_HARDWARE) && local_ts->source != NTP_TS_HARDWARE) { if ((ts_flags & SOF_TIMESTAMPING_RAW_HARDWARE) && local_ts->source != NTP_TS_HARDWARE) {
DEBUG_LOG(LOGF_NtpIOLinux, "Missing HW timestamp"); DEBUG_LOG("Missing HW timestamp");
return 1; return 1;
} }

41
ntp_signd.c
View file

@ -135,7 +135,7 @@ open_socket(void)
sock_fd = socket(AF_UNIX, SOCK_STREAM, 0); sock_fd = socket(AF_UNIX, SOCK_STREAM, 0);
if (sock_fd < 0) { if (sock_fd < 0) {
DEBUG_LOG(LOGF_NtpSignd, "Could not open signd socket : %s", strerror(errno)); DEBUG_LOG("Could not open signd socket : %s", strerror(errno));
return 0; return 0;
} }
@ -145,18 +145,18 @@ open_socket(void)
s.sun_family = AF_UNIX; s.sun_family = AF_UNIX;
if (snprintf(s.sun_path, sizeof (s.sun_path), "%s/socket", if (snprintf(s.sun_path, sizeof (s.sun_path), "%s/socket",
CNF_GetNtpSigndSocket()) >= sizeof (s.sun_path)) { CNF_GetNtpSigndSocket()) >= sizeof (s.sun_path)) {
DEBUG_LOG(LOGF_NtpSignd, "signd socket path too long"); DEBUG_LOG("signd socket path too long");
close_socket(); close_socket();
return 0; return 0;
} }
if (connect(sock_fd, (struct sockaddr *)&s, sizeof (s)) < 0) { if (connect(sock_fd, (struct sockaddr *)&s, sizeof (s)) < 0) {
DEBUG_LOG(LOGF_NtpSignd, "Could not connect to signd : %s", strerror(errno)); DEBUG_LOG("Could not connect to signd : %s", strerror(errno));
close_socket(); close_socket();
return 0; return 0;
} }
DEBUG_LOG(LOGF_NtpSignd, "Connected to signd"); DEBUG_LOG("Connected to signd");
return 1; return 1;
} }
@ -170,25 +170,25 @@ process_response(SignInstance *inst)
double delay; double delay;
if (ntohs(inst->request.packet_id) != ntohl(inst->response.packet_id)) { if (ntohs(inst->request.packet_id) != ntohl(inst->response.packet_id)) {
DEBUG_LOG(LOGF_NtpSignd, "Invalid response ID"); DEBUG_LOG("Invalid response ID");
return; return;
} }
if (ntohl(inst->response.op) != SIGNING_SUCCESS) { if (ntohl(inst->response.op) != SIGNING_SUCCESS) {
DEBUG_LOG(LOGF_NtpSignd, "Signing failed"); DEBUG_LOG("Signing failed");
return; return;
} }
/* Check if the file descriptor is still valid */ /* Check if the file descriptor is still valid */
if (!NIO_IsServerSocket(inst->local_addr.sock_fd)) { if (!NIO_IsServerSocket(inst->local_addr.sock_fd)) {
DEBUG_LOG(LOGF_NtpSignd, "Invalid NTP socket"); DEBUG_LOG("Invalid NTP socket");
return; return;
} }
SCH_GetLastEventTime(NULL, NULL, &ts); SCH_GetLastEventTime(NULL, NULL, &ts);
delay = UTI_DiffTimespecsToDouble(&ts, &inst->request_ts); delay = UTI_DiffTimespecsToDouble(&ts, &inst->request_ts);
DEBUG_LOG(LOGF_NtpSignd, "Signing succeeded (delay %f)", delay); DEBUG_LOG("Signing succeeded (delay %f)", delay);
/* Send the signed NTP packet */ /* Send the signed NTP packet */
NIO_SendPacket(&inst->response.signed_packet, &inst->remote_addr, &inst->local_addr, NIO_SendPacket(&inst->response.signed_packet, &inst->remote_addr, &inst->local_addr,
@ -222,12 +222,12 @@ read_write_socket(int sock_fd, int event, void *anything)
inst->request_length - inst->sent, 0); inst->request_length - inst->sent, 0);
if (s < 0) { if (s < 0) {
DEBUG_LOG(LOGF_NtpSignd, "signd socket error: %s", strerror(errno)); DEBUG_LOG("signd socket error: %s", strerror(errno));
close_socket(); close_socket();
return; return;
} }
DEBUG_LOG(LOGF_NtpSignd, "Sent %d bytes to signd", s); DEBUG_LOG("Sent %d bytes to signd", s);
inst->sent += s; inst->sent += s;
/* Try again later if the request is not complete yet */ /* Try again later if the request is not complete yet */
@ -240,7 +240,7 @@ read_write_socket(int sock_fd, int event, void *anything)
if (event == SCH_FILE_INPUT) { if (event == SCH_FILE_INPUT) {
if (IS_QUEUE_EMPTY()) { if (IS_QUEUE_EMPTY()) {
DEBUG_LOG(LOGF_NtpSignd, "Unexpected signd response"); DEBUG_LOG("Unexpected signd response");
close_socket(); close_socket();
return; return;
} }
@ -251,15 +251,15 @@ read_write_socket(int sock_fd, int event, void *anything)
if (s <= 0) { if (s <= 0) {
if (s < 0) if (s < 0)
DEBUG_LOG(LOGF_NtpSignd, "signd socket error: %s", strerror(errno)); DEBUG_LOG("signd socket error: %s", strerror(errno));
else else
DEBUG_LOG(LOGF_NtpSignd, "signd socket closed"); DEBUG_LOG("signd socket closed");
close_socket(); close_socket();
return; return;
} }
DEBUG_LOG(LOGF_NtpSignd, "Received %d bytes from signd", s); DEBUG_LOG("Received %d bytes from signd", s);
inst->received += s; inst->received += s;
if (inst->received < sizeof (inst->response.length)) if (inst->received < sizeof (inst->response.length))
@ -269,7 +269,7 @@ read_write_socket(int sock_fd, int event, void *anything)
if (response_length < offsetof(SigndResponse, signed_packet) || if (response_length < offsetof(SigndResponse, signed_packet) ||
response_length > sizeof (SigndResponse)) { response_length > sizeof (SigndResponse)) {
DEBUG_LOG(LOGF_NtpSignd, "Invalid response length"); DEBUG_LOG("Invalid response length");
close_socket(); close_socket();
return; return;
} }
@ -303,7 +303,7 @@ NSD_Initialise()
ARR_SetSize(queue, MAX_QUEUE_LENGTH); ARR_SetSize(queue, MAX_QUEUE_LENGTH);
queue_head = queue_tail = 0; queue_head = queue_tail = 0;
LOG(LOGS_INFO, LOGF_NtpSignd, "MS-SNTP authentication enabled"); LOG(LOGS_INFO, "MS-SNTP authentication enabled");
} }
/* ================================================== */ /* ================================================== */
@ -333,17 +333,17 @@ NSD_SignAndSendPacket(uint32_t key_id, NTP_Packet *packet, NTP_Remote_Address *r
SignInstance *inst; SignInstance *inst;
if (!enabled) { if (!enabled) {
DEBUG_LOG(LOGF_NtpSignd, "signd disabled"); DEBUG_LOG("signd disabled");
return 0; return 0;
} }
if (queue_head == NEXT_QUEUE_INDEX(queue_tail)) { if (queue_head == NEXT_QUEUE_INDEX(queue_tail)) {
DEBUG_LOG(LOGF_NtpSignd, "signd queue full"); DEBUG_LOG("signd queue full");
return 0; return 0;
} }
if (length != NTP_NORMAL_PACKET_LENGTH) { if (length != NTP_NORMAL_PACKET_LENGTH) {
DEBUG_LOG(LOGF_NtpSignd, "Invalid packet length"); DEBUG_LOG("Invalid packet length");
return 0; return 0;
} }
@ -373,8 +373,7 @@ NSD_SignAndSendPacket(uint32_t key_id, NTP_Packet *packet, NTP_Remote_Address *r
queue_tail = NEXT_QUEUE_INDEX(queue_tail); queue_tail = NEXT_QUEUE_INDEX(queue_tail);
DEBUG_LOG(LOGF_NtpSignd, "Packet added to signd queue (%u:%u)", DEBUG_LOG("Packet added to signd queue (%u:%u)", queue_head, queue_tail);
queue_head, queue_tail);
return 1; return 1;
} }

22
ntp_sources.c
View file

@ -355,7 +355,7 @@ replace_source(NTP_Remote_Address *old_addr, NTP_Remote_Address *new_addr)
/* The hash table must be rebuilt for the new address */ /* The hash table must be rebuilt for the new address */
rehash_records(); rehash_records();
LOG(LOGS_INFO, LOGF_NtpSources, "Source %s replaced with %s", LOG(LOGS_INFO, "Source %s replaced with %s",
UTI_IPToString(&old_addr->ip_addr), UTI_IPToString(&old_addr->ip_addr),
UTI_IPToString(&new_addr->ip_addr)); UTI_IPToString(&new_addr->ip_addr));
@ -378,7 +378,7 @@ process_resolved_name(struct UnresolvedSource *us, IPAddr *ip_addrs, int n_addrs
address.ip_addr = ip_addrs[((unsigned int)i + first) % n_addrs]; address.ip_addr = ip_addrs[((unsigned int)i + first) % n_addrs];
address.port = us->port; address.port = us->port;
DEBUG_LOG(LOGF_NtpSources, "(%d) %s", i + 1, UTI_IPToString(&address.ip_addr)); DEBUG_LOG("(%d) %s", i + 1, UTI_IPToString(&address.ip_addr));
if (us->replacement) { if (us->replacement) {
if (replace_source(&us->replace_source, &address) != NSR_AlreadyInUse) if (replace_source(&us->replace_source, &address) != NSR_AlreadyInUse)
@ -405,7 +405,7 @@ name_resolve_handler(DNS_Status status, int n_addrs, IPAddr *ip_addrs, void *any
assert(us == resolving_source); assert(us == resolving_source);
DEBUG_LOG(LOGF_NtpSources, "%s resolved to %d addrs", us->name, n_addrs); DEBUG_LOG("%s resolved to %d addrs", us->name, n_addrs);
switch (status) { switch (status) {
case DNS_TryAgain: case DNS_TryAgain:
@ -414,7 +414,7 @@ name_resolve_handler(DNS_Status status, int n_addrs, IPAddr *ip_addrs, void *any
process_resolved_name(us, ip_addrs, n_addrs); process_resolved_name(us, ip_addrs, n_addrs);
break; break;
case DNS_Failure: case DNS_Failure:
LOG(LOGS_WARN, LOGF_NtpSources, "Invalid host %s", us->name); LOG(LOGS_WARN, "Invalid host %s", us->name);
break; break;
default: default:
assert(0); assert(0);
@ -439,7 +439,7 @@ name_resolve_handler(DNS_Status status, int n_addrs, IPAddr *ip_addrs, void *any
if (next) { if (next) {
/* Continue with the next source in the list */ /* Continue with the next source in the list */
DEBUG_LOG(LOGF_NtpSources, "resolving %s", next->name); DEBUG_LOG("resolving %s", next->name);
DNS_Name2IPAddressAsync(next->name, name_resolve_handler, next); DNS_Name2IPAddressAsync(next->name, name_resolve_handler, next);
} else { } else {
/* This was the last source in the list. If some sources couldn't /* This was the last source in the list. If some sources couldn't
@ -477,7 +477,7 @@ resolve_sources(void *arg)
us = unresolved_sources; us = unresolved_sources;
resolving_source = us; resolving_source = us;
DEBUG_LOG(LOGF_NtpSources, "resolving %s", us->name); DEBUG_LOG("resolving %s", us->name);
DNS_Name2IPAddressAsync(us->name, name_resolve_handler, us); DNS_Name2IPAddressAsync(us->name, name_resolve_handler, us);
} }
@ -658,8 +658,7 @@ resolve_source_replacement(SourceRecord *record)
{ {
struct UnresolvedSource *us; struct UnresolvedSource *us;
DEBUG_LOG(LOGF_NtpSources, "trying to replace %s", DEBUG_LOG("trying to replace %s", UTI_IPToString(&record->remote_addr->ip_addr));
UTI_IPToString(&record->remote_addr->ip_addr));
us = MallocNew(struct UnresolvedSource); us = MallocNew(struct UnresolvedSource);
us->name = Strdup(record->name); us->name = Strdup(record->name);
@ -705,7 +704,7 @@ NSR_HandleBadSource(IPAddr *address)
SCH_GetLastEventTime(NULL, NULL, &now); SCH_GetLastEventTime(NULL, NULL, &now);
diff = UTI_DiffTimespecsToDouble(&now, &last_replacement); diff = UTI_DiffTimespecsToDouble(&now, &last_replacement);
if (fabs(diff) < RESOLVE_INTERVAL_UNIT * (1 << MIN_REPLACEMENT_INTERVAL)) { if (fabs(diff) < RESOLVE_INTERVAL_UNIT * (1 << MIN_REPLACEMENT_INTERVAL)) {
DEBUG_LOG(LOGF_NtpSources, "replacement postponed"); DEBUG_LOG("replacement postponed");
return; return;
} }
last_replacement = now; last_replacement = now;
@ -743,7 +742,7 @@ static void remove_tentative_pool_sources(int pool)
if (!record->remote_addr || record->pool != pool || !record->tentative) if (!record->remote_addr || record->pool != pool || !record->tentative)
continue; continue;
DEBUG_LOG(LOGF_NtpSources, "removing tentative source %s", DEBUG_LOG("removing tentative source %s",
UTI_IPToString(&record->remote_addr->ip_addr)); UTI_IPToString(&record->remote_addr->ip_addr));
clean_source_record(record); clean_source_record(record);
@ -801,8 +800,7 @@ NSR_ProcessRx(NTP_Remote_Address *remote_addr, NTP_Local_Address *local_addr,
pool = ARR_GetElement(pools, record->pool); pool = ARR_GetElement(pools, record->pool);
pool->sources++; pool->sources++;
DEBUG_LOG(LOGF_NtpSources, "pool %s has %d confirmed sources", DEBUG_LOG("pool %s has %d confirmed sources", record->name, pool->sources);
record->name, pool->sources);
/* If the number of sources from the pool reached the configured /* If the number of sources from the pool reached the configured
maximum, remove the remaining tentative sources */ maximum, remove the remaining tentative sources */

20
privops.c
View file

@ -388,14 +388,14 @@ receive_response(PrvResponse *res)
resp_len = recv(helper_fd, res, sizeof (*res), 0); resp_len = recv(helper_fd, res, sizeof (*res), 0);
if (resp_len < 0) if (resp_len < 0)
LOG_FATAL(LOGF_PrivOps, "Could not read from helper : %s", strerror(errno)); LOG_FATAL("Could not read from helper : %s", strerror(errno));
if (resp_len != sizeof (*res)) if (resp_len != sizeof (*res))
LOG_FATAL(LOGF_PrivOps, "Invalid helper response"); LOG_FATAL("Invalid helper response");
if (res->fatal_error) if (res->fatal_error)
LOG_FATAL(LOGF_PrivOps, "Error in helper : %s", res->data.fatal_msg.msg); LOG_FATAL("Error in helper : %s", res->data.fatal_msg.msg);
DEBUG_LOG(LOGF_PrivOps, "Received response rc=%d", res->rc); DEBUG_LOG("Received response rc=%d", res->rc);
/* if operation failed in the helper, set errno so daemon can print log message */ /* if operation failed in the helper, set errno so daemon can print log message */
if (res->res_errno) if (res->res_errno)
@ -446,10 +446,10 @@ send_request(PrvRequest *req)
if (sendmsg(helper_fd, &msg, 0) < 0) { if (sendmsg(helper_fd, &msg, 0) < 0) {
/* don't try to send another request from exit() */ /* don't try to send another request from exit() */
helper_fd = -1; helper_fd = -1;
LOG_FATAL(LOGF_PrivOps, "Could not send to helper : %s", strerror(errno)); LOG_FATAL("Could not send to helper : %s", strerror(errno));
} }
DEBUG_LOG(LOGF_PrivOps, "Sent request op=%d", req->op); DEBUG_LOG("Sent request op=%d", req->op);
} }
/* ======================================================================= */ /* ======================================================================= */
@ -615,7 +615,7 @@ PRV_Name2IPAddress(const char *name, IPAddr *ip_addrs, int max_addrs)
req.op = OP_NAME2IPADDRESS; req.op = OP_NAME2IPADDRESS;
if (snprintf(req.data.name_to_ipaddress.name, sizeof (req.data.name_to_ipaddress.name), if (snprintf(req.data.name_to_ipaddress.name, sizeof (req.data.name_to_ipaddress.name),
"%s", name) >= sizeof (req.data.name_to_ipaddress.name)) { "%s", name) >= sizeof (req.data.name_to_ipaddress.name)) {
DEBUG_LOG(LOGF_PrivOps, "Name too long"); DEBUG_LOG("Name too long");
return DNS_Failure; return DNS_Failure;
} }
@ -672,21 +672,21 @@ PRV_StartHelper(void)
int fd, sock_pair[2]; int fd, sock_pair[2];
if (have_helper()) if (have_helper())
LOG_FATAL(LOGF_PrivOps, "Helper already running"); LOG_FATAL("Helper already running");
if ( if (
#ifdef SOCK_SEQPACKET #ifdef SOCK_SEQPACKET
socketpair(AF_UNIX, SOCK_SEQPACKET, 0, sock_pair) && socketpair(AF_UNIX, SOCK_SEQPACKET, 0, sock_pair) &&
#endif #endif
socketpair(AF_UNIX, SOCK_DGRAM, 0, sock_pair)) socketpair(AF_UNIX, SOCK_DGRAM, 0, sock_pair))
LOG_FATAL(LOGF_PrivOps, "socketpair() failed : %s", strerror(errno)); LOG_FATAL("socketpair() failed : %s", strerror(errno));
UTI_FdSetCloexec(sock_pair[0]); UTI_FdSetCloexec(sock_pair[0]);
UTI_FdSetCloexec(sock_pair[1]); UTI_FdSetCloexec(sock_pair[1]);
pid = fork(); pid = fork();
if (pid < 0) if (pid < 0)
LOG_FATAL(LOGF_PrivOps, "fork() failed : %s", strerror(errno)); LOG_FATAL("fork() failed : %s", strerror(errno));
if (pid == 0) { if (pid == 0) {
/* child process */ /* child process */

28
refclock.c
View file

@ -185,12 +185,12 @@ RCL_AddRefclock(RefclockParameters *params)
inst->driver = &RCL_PHC_driver; inst->driver = &RCL_PHC_driver;
inst->precision = 1e-9; inst->precision = 1e-9;
} else { } else {
LOG_FATAL(LOGF_Refclock, "unknown refclock driver %s", params->driver_name); LOG_FATAL("unknown refclock driver %s", params->driver_name);
return 0; return 0;
} }
if (!inst->driver->init && !inst->driver->poll) { if (!inst->driver->init && !inst->driver->poll) {
LOG_FATAL(LOGF_Refclock, "refclock driver %s is not compiled in", params->driver_name); LOG_FATAL("refclock driver %s is not compiled in", params->driver_name);
return 0; return 0;
} }
@ -251,7 +251,7 @@ RCL_AddRefclock(RefclockParameters *params)
max_samples = 1 << (inst->poll - inst->driver_poll); max_samples = 1 << (inst->poll - inst->driver_poll);
if (max_samples < params->filter_length) { if (max_samples < params->filter_length) {
if (max_samples < 4) { if (max_samples < 4) {
LOG(LOGS_WARN, LOGF_Refclock, "Setting filter length for %s to %d", LOG(LOGS_WARN, "Setting filter length for %s to %d",
UTI_RefidToString(inst->ref_id), max_samples); UTI_RefidToString(inst->ref_id), max_samples);
} }
params->filter_length = max_samples; params->filter_length = max_samples;
@ -260,7 +260,7 @@ RCL_AddRefclock(RefclockParameters *params)
if (inst->driver->init) if (inst->driver->init)
if (!inst->driver->init(inst)) { if (!inst->driver->init(inst)) {
LOG_FATAL(LOGF_Refclock, "refclock %s initialisation failed", params->driver_name); LOG_FATAL("refclock %s initialisation failed", params->driver_name);
return 0; return 0;
} }
@ -269,7 +269,7 @@ RCL_AddRefclock(RefclockParameters *params)
inst->source = SRC_CreateNewInstance(inst->ref_id, SRC_REFCLOCK, params->sel_options, NULL, inst->source = SRC_CreateNewInstance(inst->ref_id, SRC_REFCLOCK, params->sel_options, NULL,
params->min_samples, params->max_samples); params->min_samples, params->max_samples);
DEBUG_LOG(LOGF_Refclock, "refclock %s refid=%s poll=%d dpoll=%d filter=%d", DEBUG_LOG("refclock %s refid=%s poll=%d dpoll=%d filter=%d",
params->driver_name, UTI_RefidToString(inst->ref_id), params->driver_name, UTI_RefidToString(inst->ref_id),
inst->poll, inst->driver_poll, params->filter_length); inst->poll, inst->driver_poll, params->filter_length);
@ -385,7 +385,7 @@ RCL_AddSample(RCL_Instance instance, struct timespec *sample_time, double offset
instance->leap_status = leap; instance->leap_status = leap;
break; break;
default: default:
DEBUG_LOG(LOGF_Refclock, "refclock sample ignored bad leap %d", leap); DEBUG_LOG("refclock sample ignored bad leap %d", leap);
return 0; return 0;
} }
@ -439,7 +439,7 @@ RCL_AddPulse(RCL_Instance instance, struct timespec *pulse_time, double second)
if (!filter_get_last_sample(&lock_refclock->filter, if (!filter_get_last_sample(&lock_refclock->filter,
&ref_sample_time, &ref_offset, &ref_dispersion)) { &ref_sample_time, &ref_offset, &ref_dispersion)) {
DEBUG_LOG(LOGF_Refclock, "refclock pulse ignored no ref sample"); DEBUG_LOG("refclock pulse ignored no ref sample");
return 0; return 0;
} }
@ -447,7 +447,7 @@ RCL_AddPulse(RCL_Instance instance, struct timespec *pulse_time, double second)
sample_diff = UTI_DiffTimespecsToDouble(&cooked_time, &ref_sample_time); sample_diff = UTI_DiffTimespecsToDouble(&cooked_time, &ref_sample_time);
if (fabs(sample_diff) >= (double)instance->max_lock_age / rate) { if (fabs(sample_diff) >= (double)instance->max_lock_age / rate) {
DEBUG_LOG(LOGF_Refclock, "refclock pulse ignored samplediff=%.9f", DEBUG_LOG("refclock pulse ignored samplediff=%.9f",
sample_diff); sample_diff);
return 0; return 0;
} }
@ -461,14 +461,14 @@ RCL_AddPulse(RCL_Instance instance, struct timespec *pulse_time, double second)
offset += shift; offset += shift;
if (fabs(ref_offset - offset) + ref_dispersion + dispersion >= 0.2 / rate) { if (fabs(ref_offset - offset) + ref_dispersion + dispersion >= 0.2 / rate) {
DEBUG_LOG(LOGF_Refclock, "refclock pulse ignored offdiff=%.9f refdisp=%.9f disp=%.9f", DEBUG_LOG("refclock pulse ignored offdiff=%.9f refdisp=%.9f disp=%.9f",
ref_offset - offset, ref_dispersion, dispersion); ref_offset - offset, ref_dispersion, dispersion);
return 0; return 0;
} }
leap = lock_refclock->leap_status; leap = lock_refclock->leap_status;
DEBUG_LOG(LOGF_Refclock, "refclock pulse second=%.9f offset=%.9f offdiff=%.9f samplediff=%.9f", DEBUG_LOG("refclock pulse second=%.9f offset=%.9f offdiff=%.9f samplediff=%.9f",
second, offset, ref_offset - offset, sample_diff); second, offset, ref_offset - offset, sample_diff);
} else { } else {
struct timespec ref_time; struct timespec ref_time;
@ -484,7 +484,7 @@ RCL_AddPulse(RCL_Instance instance, struct timespec *pulse_time, double second)
distance = fabs(root_delay) / 2 + root_dispersion; distance = fabs(root_delay) / 2 + root_dispersion;
if (leap == LEAP_Unsynchronised || distance >= 0.5 / rate) { if (leap == LEAP_Unsynchronised || distance >= 0.5 / rate) {
DEBUG_LOG(LOGF_Refclock, "refclock pulse ignored second=%.9f sync=%d dist=%.9f", DEBUG_LOG("refclock pulse ignored second=%.9f sync=%d dist=%.9f",
second, leap != LEAP_Unsynchronised, distance); second, leap != LEAP_Unsynchronised, distance);
/* Drop also all stored samples */ /* Drop also all stored samples */
filter_reset(&instance->filter); filter_reset(&instance->filter);
@ -525,7 +525,7 @@ valid_sample_time(RCL_Instance instance, struct timespec *raw, struct timespec *
filter_get_last_sample(&instance->filter, &last_sample_time, filter_get_last_sample(&instance->filter, &last_sample_time,
&last_offset, &last_dispersion) && &last_offset, &last_dispersion) &&
UTI_CompareTimespecs(&last_sample_time, cooked) >= 0)) { UTI_CompareTimespecs(&last_sample_time, cooked) >= 0)) {
DEBUG_LOG(LOGF_Refclock, "%s refclock sample not valid age=%.6f raw=%s cooked=%s", DEBUG_LOG("%s refclock sample not valid age=%.6f raw=%s cooked=%s",
UTI_RefidToString(instance->ref_id), diff, UTI_RefidToString(instance->ref_id), diff,
UTI_TimespecToString(raw), UTI_TimespecToString(cooked)); UTI_TimespecToString(raw), UTI_TimespecToString(cooked));
return 0; return 0;
@ -719,7 +719,7 @@ filter_add_sample(struct MedianFilter *filter, struct timespec *sample_time, dou
filter->samples[filter->index].offset = offset; filter->samples[filter->index].offset = offset;
filter->samples[filter->index].dispersion = dispersion; filter->samples[filter->index].dispersion = dispersion;
DEBUG_LOG(LOGF_Refclock, "filter sample %d t=%s offset=%.9f dispersion=%.9f", DEBUG_LOG("filter sample %d t=%s offset=%.9f dispersion=%.9f",
filter->index, UTI_TimespecToString(sample_time), offset, dispersion); filter->index, UTI_TimespecToString(sample_time), offset, dispersion);
} }
@ -909,7 +909,7 @@ filter_get_sample(struct MedianFilter *filter, struct timespec *sample_time, dou
/* drop the sample if variance is larger than allowed maximum */ /* drop the sample if variance is larger than allowed maximum */
if (filter->max_var > 0.0 && var > filter->max_var) { if (filter->max_var > 0.0 && var > filter->max_var) {
DEBUG_LOG(LOGF_Refclock, "filter dispersion too large disp=%.9f max=%.9f", DEBUG_LOG("filter dispersion too large disp=%.9f max=%.9f",
sqrt(var), sqrt(filter->max_var)); sqrt(var), sqrt(filter->max_var));
return 0; return 0;
} }

4
refclock_phc.c
View file

@ -55,7 +55,7 @@ static int phc_initialise(RCL_Instance instance)
phc_fd = SYS_Linux_OpenPHC(path, 0); phc_fd = SYS_Linux_OpenPHC(path, 0);
if (phc_fd < 0) { if (phc_fd < 0) {
LOG_FATAL(LOGF_Refclock, "Could not open PHC"); LOG_FATAL("Could not open PHC");
return 0; return 0;
} }
@ -91,7 +91,7 @@ static int phc_poll(RCL_Instance instance)
offset = UTI_DiffTimespecsToDouble(&phc_ts, &sys_ts); offset = UTI_DiffTimespecsToDouble(&phc_ts, &sys_ts);
DEBUG_LOG(LOGF_Refclock, "PHC offset: %+.9f err: %.9f", offset, err); DEBUG_LOG("PHC offset: %+.9f err: %.9f", offset, err);
return RCL_AddSample(instance, &sys_ts, offset, LEAP_Normal); return RCL_AddSample(instance, &sys_ts, offset, LEAP_Normal);
} }

18
refclock_pps.c
View file

@ -59,37 +59,37 @@ static int pps_initialise(RCL_Instance instance) {
fd = open(path, O_RDWR); fd = open(path, O_RDWR);
if (fd < 0) { if (fd < 0) {
LOG_FATAL(LOGF_Refclock, "open() failed on %s", path); LOG_FATAL("open() failed on %s", path);
return 0; return 0;
} }
UTI_FdSetCloexec(fd); UTI_FdSetCloexec(fd);
if (time_pps_create(fd, &handle) < 0) { if (time_pps_create(fd, &handle) < 0) {
LOG_FATAL(LOGF_Refclock, "time_pps_create() failed on %s", path); LOG_FATAL("time_pps_create() failed on %s", path);
return 0; return 0;
} }
if (time_pps_getcap(handle, &mode) < 0) { if (time_pps_getcap(handle, &mode) < 0) {
LOG_FATAL(LOGF_Refclock, "time_pps_getcap() failed on %s", path); LOG_FATAL("time_pps_getcap() failed on %s", path);
return 0; return 0;
} }
if (time_pps_getparams(handle, &params) < 0) { if (time_pps_getparams(handle, &params) < 0) {
LOG_FATAL(LOGF_Refclock, "time_pps_getparams() failed on %s", path); LOG_FATAL("time_pps_getparams() failed on %s", path);
return 0; return 0;
} }
if (!edge_clear) { if (!edge_clear) {
if (!(mode & PPS_CAPTUREASSERT)) { if (!(mode & PPS_CAPTUREASSERT)) {
LOG_FATAL(LOGF_Refclock, "CAPTUREASSERT not supported on %s", path); LOG_FATAL("CAPTUREASSERT not supported on %s", path);
return 0; return 0;
} }
params.mode |= PPS_CAPTUREASSERT; params.mode |= PPS_CAPTUREASSERT;
params.mode &= ~PPS_CAPTURECLEAR; params.mode &= ~PPS_CAPTURECLEAR;
} else { } else {
if (!(mode & PPS_CAPTURECLEAR)) { if (!(mode & PPS_CAPTURECLEAR)) {
LOG_FATAL(LOGF_Refclock, "CAPTURECLEAR not supported on %s", path); LOG_FATAL("CAPTURECLEAR not supported on %s", path);
return 0; return 0;
} }
params.mode |= PPS_CAPTURECLEAR; params.mode |= PPS_CAPTURECLEAR;
@ -97,7 +97,7 @@ static int pps_initialise(RCL_Instance instance) {
} }
if (time_pps_setparams(handle, &params) < 0) { if (time_pps_setparams(handle, &params) < 0) {
LOG_FATAL(LOGF_Refclock, "time_pps_setparams() failed on %s", path); LOG_FATAL("time_pps_setparams() failed on %s", path);
return 0; return 0;
} }
@ -133,7 +133,7 @@ static int pps_poll(RCL_Instance instance)
ts.tv_nsec = 0; ts.tv_nsec = 0;
if (time_pps_fetch(pps->handle, PPS_TSFMT_TSPEC, &pps_info, &ts) < 0) { if (time_pps_fetch(pps->handle, PPS_TSFMT_TSPEC, &pps_info, &ts) < 0) {
LOG(LOGS_ERR, LOGF_Refclock, "time_pps_fetch() failed : %s", strerror(errno)); LOG(LOGS_ERR, "time_pps_fetch() failed : %s", strerror(errno));
return 0; return 0;
} }
@ -146,7 +146,7 @@ static int pps_poll(RCL_Instance instance)
} }
if (seq == pps->last_seq || UTI_IsZeroTimespec(&ts)) { if (seq == pps->last_seq || UTI_IsZeroTimespec(&ts)) {
DEBUG_LOG(LOGF_Refclock, "PPS sample ignored seq=%lu ts=%s", DEBUG_LOG("PPS sample ignored seq=%lu ts=%s",
seq, UTI_TimespecToString(&ts)); seq, UTI_TimespecToString(&ts));
return 0; return 0;
} }

6
refclock_shm.c
View file

@ -69,13 +69,13 @@ static int shm_initialise(RCL_Instance instance) {
id = shmget(SHMKEY + param, sizeof (struct shmTime), IPC_CREAT | perm); id = shmget(SHMKEY + param, sizeof (struct shmTime), IPC_CREAT | perm);
if (id == -1) { if (id == -1) {
LOG_FATAL(LOGF_Refclock, "shmget() failed"); LOG_FATAL("shmget() failed");
return 0; return 0;
} }
shm = (struct shmTime *)shmat(id, 0, 0); shm = (struct shmTime *)shmat(id, 0, 0);
if ((long)shm == -1) { if ((long)shm == -1) {
LOG_FATAL(LOGF_Refclock, "shmat() failed"); LOG_FATAL("shmat() failed");
return 0; return 0;
} }
@ -100,7 +100,7 @@ static int shm_poll(RCL_Instance instance)
if ((t.mode == 1 && t.count != shm->count) || if ((t.mode == 1 && t.count != shm->count) ||
!(t.mode == 0 || t.mode == 1) || !t.valid) { !(t.mode == 0 || t.mode == 1) || !t.valid) {
DEBUG_LOG(LOGF_Refclock, "SHM sample ignored mode=%d count=%d valid=%d", DEBUG_LOG("SHM sample ignored mode=%d count=%d valid=%d",
t.mode, t.count, t.valid); t.mode, t.count, t.valid);
return 0; return 0;
} }

12
refclock_sock.c
View file

@ -69,19 +69,19 @@ static void read_sample(int sockfd, int event, void *anything)
s = recv(sockfd, &sample, sizeof (sample), 0); s = recv(sockfd, &sample, sizeof (sample), 0);
if (s < 0) { if (s < 0) {
LOG(LOGS_ERR, LOGF_Refclock, "Could not read SOCK sample : %s", LOG(LOGS_ERR, "Could not read SOCK sample : %s",
strerror(errno)); strerror(errno));
return; return;
} }
if (s != sizeof (sample)) { if (s != sizeof (sample)) {
LOG(LOGS_WARN, LOGF_Refclock, "Unexpected length of SOCK sample : %d != %ld", LOG(LOGS_WARN, "Unexpected length of SOCK sample : %d != %ld",
s, (long)sizeof (sample)); s, (long)sizeof (sample));
return; return;
} }
if (sample.magic != SOCK_MAGIC) { if (sample.magic != SOCK_MAGIC) {
LOG(LOGS_WARN, LOGF_Refclock, "Unexpected magic number in SOCK sample : %x != %x", LOG(LOGS_WARN, "Unexpected magic number in SOCK sample : %x != %x",
sample.magic, SOCK_MAGIC); sample.magic, SOCK_MAGIC);
return; return;
} }
@ -106,13 +106,13 @@ static int sock_initialise(RCL_Instance instance)
s.sun_family = AF_UNIX; s.sun_family = AF_UNIX;
if (snprintf(s.sun_path, sizeof (s.sun_path), "%s", path) >= sizeof (s.sun_path)) { if (snprintf(s.sun_path, sizeof (s.sun_path), "%s", path) >= sizeof (s.sun_path)) {
LOG_FATAL(LOGF_Refclock, "path %s is too long", path); LOG_FATAL("path %s is too long", path);
return 0; return 0;
} }
sockfd = socket(AF_UNIX, SOCK_DGRAM, 0); sockfd = socket(AF_UNIX, SOCK_DGRAM, 0);
if (sockfd < 0) { if (sockfd < 0) {
LOG_FATAL(LOGF_Refclock, "socket() failed"); LOG_FATAL("socket() failed");
return 0; return 0;
} }
@ -120,7 +120,7 @@ static int sock_initialise(RCL_Instance instance)
unlink(path); unlink(path);
if (bind(sockfd, (struct sockaddr *)&s, sizeof (s)) < 0) { if (bind(sockfd, (struct sockaddr *)&s, sizeof (s)) < 0) {
LOG_FATAL(LOGF_Refclock, "bind() failed"); LOG_FATAL("bind() failed");
return 0; return 0;
} }

60
reference.c
View file

@ -205,11 +205,11 @@ REF_Initialise(void)
our_skew = 1.0e-6 * file_skew_ppm; our_skew = 1.0e-6 * file_skew_ppm;
if (our_skew < MIN_SKEW) if (our_skew < MIN_SKEW)
our_skew = MIN_SKEW; our_skew = MIN_SKEW;
LOG(LOGS_INFO, LOGF_Reference, "Frequency %.3f +/- %.3f ppm read from %s", LOG(LOGS_INFO, "Frequency %.3f +/- %.3f ppm read from %s",
file_freq_ppm, file_skew_ppm, drift_file); file_freq_ppm, file_skew_ppm, drift_file);
LCL_SetAbsoluteFrequency(our_frequency_ppm); LCL_SetAbsoluteFrequency(our_frequency_ppm);
} else { } else {
LOG(LOGS_WARN, LOGF_Reference, "Could not read valid frequency and skew from driftfile %s", LOG(LOGS_WARN, "Could not read valid frequency and skew from driftfile %s",
drift_file); drift_file);
} }
fclose(in); fclose(in);
@ -219,7 +219,7 @@ REF_Initialise(void)
if (our_frequency_ppm == 0.0) { if (our_frequency_ppm == 0.0) {
our_frequency_ppm = LCL_ReadAbsoluteFrequency(); our_frequency_ppm = LCL_ReadAbsoluteFrequency();
if (our_frequency_ppm != 0.0) { if (our_frequency_ppm != 0.0) {
LOG(LOGS_INFO, LOGF_Reference, "Initial frequency %.3f ppm", our_frequency_ppm); LOG(LOGS_INFO, "Initial frequency %.3f ppm", our_frequency_ppm);
} }
} }
@ -245,9 +245,9 @@ REF_Initialise(void)
/* Check that the timezone has good data for Jun 30 2012 and Dec 31 2012 */ /* Check that the timezone has good data for Jun 30 2012 and Dec 31 2012 */
if (get_tz_leap(1341014400) == LEAP_InsertSecond && if (get_tz_leap(1341014400) == LEAP_InsertSecond &&
get_tz_leap(1356912000) == LEAP_Normal) { get_tz_leap(1356912000) == LEAP_Normal) {
LOG(LOGS_INFO, LOGF_Reference, "Using %s timezone to obtain leap second data", leap_tzname); LOG(LOGS_INFO, "Using %s timezone to obtain leap second data", leap_tzname);
} else { } else {
LOG(LOGS_WARN, LOGF_Reference, "Timezone %s failed leap second check, ignoring", leap_tzname); LOG(LOGS_WARN, "Timezone %s failed leap second check, ignoring", leap_tzname);
leap_tzname = NULL; leap_tzname = NULL;
} }
} }
@ -364,7 +364,7 @@ update_drift_file(double freq_ppm, double skew)
out = fopen(temp_drift_file, "w"); out = fopen(temp_drift_file, "w");
if (!out) { if (!out) {
Free(temp_drift_file); Free(temp_drift_file);
LOG(LOGS_WARN, LOGF_Reference, "Could not open temporary driftfile %s.tmp for writing", LOG(LOGS_WARN, "Could not open temporary driftfile %s.tmp for writing",
drift_file); drift_file);
return; return;
} }
@ -374,7 +374,7 @@ update_drift_file(double freq_ppm, double skew)
r2 = fclose(out); r2 = fclose(out);
if (r1 < 0 || r2) { if (r1 < 0 || r2) {
Free(temp_drift_file); Free(temp_drift_file);
LOG(LOGS_WARN, LOGF_Reference, "Could not write to temporary driftfile %s.tmp", LOG(LOGS_WARN, "Could not write to temporary driftfile %s.tmp",
drift_file); drift_file);
return; return;
} }
@ -384,8 +384,7 @@ update_drift_file(double freq_ppm, double skew)
if (!stat(drift_file,&buf)) { if (!stat(drift_file,&buf)) {
if (chown(temp_drift_file,buf.st_uid,buf.st_gid) || if (chown(temp_drift_file,buf.st_uid,buf.st_gid) ||
chmod(temp_drift_file,buf.st_mode & 0777)) { chmod(temp_drift_file,buf.st_mode & 0777)) {
LOG(LOGS_WARN, LOGF_Reference, LOG(LOGS_WARN, "Could not change ownership or permissions of temporary driftfile %s.tmp",
"Could not change ownership or permissions of temporary driftfile %s.tmp",
drift_file); drift_file);
} }
} }
@ -395,7 +394,7 @@ update_drift_file(double freq_ppm, double skew)
if (rename(temp_drift_file,drift_file)) { if (rename(temp_drift_file,drift_file)) {
unlink(temp_drift_file); unlink(temp_drift_file);
Free(temp_drift_file); Free(temp_drift_file);
LOG(LOGS_WARN, LOGF_Reference, "Could not replace old driftfile %s with new one %s.tmp", LOG(LOGS_WARN, "Could not replace old driftfile %s with new one %s.tmp",
drift_file,drift_file); drift_file,drift_file);
return; return;
} }
@ -443,8 +442,8 @@ update_fb_drifts(double freq_ppm, double update_interval)
(freq_ppm - fb_drifts[i].freq); (freq_ppm - fb_drifts[i].freq);
} }
DEBUG_LOG(LOGF_Reference, "Fallback drift %d updated: %f ppm %f seconds", DEBUG_LOG("Fallback drift %d updated: %f ppm %f seconds",
i + fb_drift_min, fb_drifts[i].freq, fb_drifts[i].secs); i + fb_drift_min, fb_drifts[i].freq, fb_drifts[i].secs);
} }
} }
@ -457,7 +456,7 @@ fb_drift_timeout(void *arg)
fb_drift_timeout_id = 0; fb_drift_timeout_id = 0;
DEBUG_LOG(LOGF_Reference, "Fallback drift %d active: %f ppm", DEBUG_LOG("Fallback drift %d active: %f ppm",
next_fb_drift, fb_drifts[next_fb_drift - fb_drift_min].freq); next_fb_drift, fb_drifts[next_fb_drift - fb_drift_min].freq);
LCL_SetAbsoluteFrequency(fb_drifts[next_fb_drift - fb_drift_min].freq); LCL_SetAbsoluteFrequency(fb_drifts[next_fb_drift - fb_drift_min].freq);
REF_SetUnsynchronised(); REF_SetUnsynchronised();
@ -492,14 +491,14 @@ schedule_fb_drift(struct timespec *now)
if (c > next_fb_drift) { if (c > next_fb_drift) {
LCL_SetAbsoluteFrequency(fb_drifts[c - fb_drift_min].freq); LCL_SetAbsoluteFrequency(fb_drifts[c - fb_drift_min].freq);
next_fb_drift = c; next_fb_drift = c;
DEBUG_LOG(LOGF_Reference, "Fallback drift %d set", c); DEBUG_LOG("Fallback drift %d set", c);
} }
if (i <= fb_drift_max) { if (i <= fb_drift_max) {
next_fb_drift = i; next_fb_drift = i;
UTI_AddDoubleToTimespec(now, secs - unsynchronised, &when); UTI_AddDoubleToTimespec(now, secs - unsynchronised, &when);
fb_drift_timeout_id = SCH_AddTimeout(&when, fb_drift_timeout, NULL); fb_drift_timeout_id = SCH_AddTimeout(&when, fb_drift_timeout, NULL);
DEBUG_LOG(LOGF_Reference, "Fallback drift %d scheduled", i); DEBUG_LOG("Fallback drift %d scheduled", i);
} }
} }
@ -531,8 +530,7 @@ maybe_log_offset(double offset, time_t now)
abs_offset = fabs(offset); abs_offset = fabs(offset);
if (abs_offset > log_change_threshold) { if (abs_offset > log_change_threshold) {
LOG(LOGS_WARN, LOGF_Reference, LOG(LOGS_WARN, "System clock wrong by %.6f seconds, adjustment started",
"System clock wrong by %.6f seconds, adjustment started",
-offset); -offset);
} }
@ -558,8 +556,7 @@ maybe_log_offset(double offset, time_t now)
-offset, mail_change_threshold); -offset, mail_change_threshold);
pclose(p); pclose(p);
} else { } else {
LOG(LOGS_ERR, LOGF_Reference, LOG(LOGS_ERR, "Could not send mail notification to user %s\n",
"Could not send mail notification to user %s\n",
mail_change_user); mail_change_user);
} }
} }
@ -594,7 +591,7 @@ is_offset_ok(double offset)
offset = fabs(offset); offset = fabs(offset);
if (offset > max_offset) { if (offset > max_offset) {
LOG(LOGS_WARN, LOGF_Reference, LOG(LOGS_WARN,
"Adjustment of %.3f seconds exceeds the allowed maximum of %.3f seconds (%s) ", "Adjustment of %.3f seconds exceeds the allowed maximum of %.3f seconds (%s) ",
-offset, max_offset, !max_offset_ignore ? "exiting" : "ignored"); -offset, max_offset, !max_offset_ignore ? "exiting" : "ignored");
if (!max_offset_ignore) if (!max_offset_ignore)
@ -697,20 +694,20 @@ leap_start_timeout(void *arg)
switch (leap_mode) { switch (leap_mode) {
case REF_LeapModeSystem: case REF_LeapModeSystem:
DEBUG_LOG(LOGF_Reference, "Waiting for system clock leap second correction"); DEBUG_LOG("Waiting for system clock leap second correction");
break; break;
case REF_LeapModeSlew: case REF_LeapModeSlew:
LCL_NotifyLeap(our_leap_sec); LCL_NotifyLeap(our_leap_sec);
LCL_AccumulateOffset(our_leap_sec, 0.0); LCL_AccumulateOffset(our_leap_sec, 0.0);
LOG(LOGS_WARN, LOGF_Reference, "Adjusting system clock for leap second"); LOG(LOGS_WARN, "Adjusting system clock for leap second");
break; break;
case REF_LeapModeStep: case REF_LeapModeStep:
LCL_NotifyLeap(our_leap_sec); LCL_NotifyLeap(our_leap_sec);
LCL_ApplyStepOffset(our_leap_sec); LCL_ApplyStepOffset(our_leap_sec);
LOG(LOGS_WARN, LOGF_Reference, "System clock was stepped for leap second"); LOG(LOGS_WARN, "System clock was stepped for leap second");
break; break;
case REF_LeapModeIgnore: case REF_LeapModeIgnore:
LOG(LOGS_WARN, LOGF_Reference, "Ignoring leap second"); LOG(LOGS_WARN, "Ignoring leap second");
break; break;
default: default:
break; break;
@ -825,15 +822,14 @@ special_mode_sync(int valid, double offset)
switch (mode) { switch (mode) {
case REF_ModeInitStepSlew: case REF_ModeInitStepSlew:
if (!valid) { if (!valid) {
LOG(LOGS_WARN, LOGF_Reference, "No suitable source for initstepslew"); LOG(LOGS_WARN, "No suitable source for initstepslew");
end_ref_mode(0); end_ref_mode(0);
break; break;
} }
step = fabs(offset) >= CNF_GetInitStepThreshold(); step = fabs(offset) >= CNF_GetInitStepThreshold();
LOG(LOGS_INFO, LOGF_Reference, LOG(LOGS_INFO, "System's initial offset : %.6f seconds %s of true (%s)",
"System's initial offset : %.6f seconds %s of true (%s)",
fabs(offset), offset >= 0 ? "fast" : "slow", step ? "step" : "slew"); fabs(offset), offset >= 0 ? "fast" : "slow", step ? "step" : "slew");
if (step) if (step)
@ -847,14 +843,14 @@ special_mode_sync(int valid, double offset)
case REF_ModeUpdateOnce: case REF_ModeUpdateOnce:
case REF_ModePrintOnce: case REF_ModePrintOnce:
if (!valid) { if (!valid) {
LOG(LOGS_WARN, LOGF_Reference, "No suitable source for synchronisation"); LOG(LOGS_WARN, "No suitable source for synchronisation");
end_ref_mode(0); end_ref_mode(0);
break; break;
} }
step = mode == REF_ModeUpdateOnce; step = mode == REF_ModeUpdateOnce;
LOG(LOGS_INFO, LOGF_Reference, "System clock wrong by %.6f seconds (%s)", LOG(LOGS_INFO, "System clock wrong by %.6f seconds (%s)",
-offset, step ? "step" : "ignored"); -offset, step ? "step" : "ignored");
if (step) if (step)
@ -928,7 +924,7 @@ REF_SetReference(int stratum,
double t; double t;
t = (skew + skew) / skew; /* Skew shouldn't be zero either */ t = (skew + skew) / skew; /* Skew shouldn't be zero either */
if ((t < 1.9) || (t > 2.1)) { if ((t < 1.9) || (t > 2.1)) {
LOG(LOGS_WARN, LOGF_Reference, "Bogus skew value encountered"); LOG(LOGS_WARN, "Bogus skew value encountered");
return; return;
} }
} }
@ -1025,7 +1021,7 @@ REF_SetReference(int stratum,
LCL_AccumulateFrequencyAndOffset(our_frequency, accumulate_offset, correction_rate); LCL_AccumulateFrequencyAndOffset(our_frequency, accumulate_offset, correction_rate);
} else { } else {
DEBUG_LOG(LOGF_Reference, "Skew %f too large to track, offset=%f", skew, accumulate_offset); DEBUG_LOG("Skew %f too large to track, offset=%f", skew, accumulate_offset);
LCL_AccumulateOffset(accumulate_offset, correction_rate); LCL_AccumulateOffset(accumulate_offset, correction_rate);
@ -1037,7 +1033,7 @@ REF_SetReference(int stratum,
if (step_offset != 0.0) { if (step_offset != 0.0) {
if (LCL_ApplyStepOffset(step_offset)) if (LCL_ApplyStepOffset(step_offset))
LOG(LOGS_WARN, LOGF_Reference, "System clock was stepped by %.6f seconds", -step_offset); LOG(LOGS_WARN, "System clock was stepped by %.6f seconds", -step_offset);
} }
LCL_SetSyncStatus(are_we_synchronised, offset_sd, offset_sd + root_delay / 2.0 + root_dispersion); LCL_SetSyncStatus(are_we_synchronised, offset_sd, offset_sd + root_delay / 2.0 + root_dispersion);

6
rtc.c
View file

@ -104,7 +104,7 @@ apply_driftfile_time(time_t t)
if (now.tv_sec < t) { if (now.tv_sec < t) {
if (LCL_ApplyStepOffset(now.tv_sec - t)) if (LCL_ApplyStepOffset(now.tv_sec - t))
LOG(LOGS_INFO, LOGF_Rtc, "System time restored from driftfile"); LOG(LOGS_INFO, "System time restored from driftfile");
} }
} }
@ -142,7 +142,7 @@ RTC_Initialise(int initial_set)
if (file_name) { if (file_name) {
if (CNF_GetRtcSync()) { if (CNF_GetRtcSync()) {
LOG_FATAL(LOGF_Rtc, "rtcfile directive cannot be used with rtcsync"); LOG_FATAL("rtcfile directive cannot be used with rtcsync");
} }
if (driver.init) { if (driver.init) {
@ -150,7 +150,7 @@ RTC_Initialise(int initial_set)
driver_initialised = 1; driver_initialised = 1;
} }
} else { } else {
LOG(LOGS_ERR, LOGF_Rtc, "RTC not supported on this operating system"); LOG(LOGS_ERR, "RTC not supported on this operating system");
} }
} }
} }

52
rtc_linux.c
View file

@ -189,7 +189,7 @@ accumulate_sample(time_t rtc, struct timespec *sys)
/* Discard all samples if the RTC was stepped back (not our trim) */ /* Discard all samples if the RTC was stepped back (not our trim) */
if (n_samples > 0 && rtc_sec[n_samples - 1] - rtc >= rtc_trim[n_samples - 1]) { if (n_samples > 0 && rtc_sec[n_samples - 1] - rtc >= rtc_trim[n_samples - 1]) {
DEBUG_LOG(LOGF_RtcLinux, "RTC samples discarded"); DEBUG_LOG("RTC samples discarded");
n_samples = 0; n_samples = 0;
} }
@ -294,7 +294,7 @@ slew_samples
coef_gain_rate += dfreq * (1.0 - coef_gain_rate); coef_gain_rate += dfreq * (1.0 - coef_gain_rate);
} }
DEBUG_LOG(LOGF_RtcLinux, "dfreq=%.8f doffset=%.6f old_fast=%.6f old_rate=%.3f new_fast=%.6f new_rate=%.3f", DEBUG_LOG("dfreq=%.8f doffset=%.6f old_fast=%.6f old_rate=%.3f new_fast=%.6f new_rate=%.3f",
dfreq, doffset, dfreq, doffset,
old_seconds_fast, 1.0e6 * old_gain_rate, old_seconds_fast, 1.0e6 * old_gain_rate,
coef_seconds_fast, 1.0e6 * coef_gain_rate); coef_seconds_fast, 1.0e6 * coef_gain_rate);
@ -371,7 +371,7 @@ t_from_rtc(struct tm *stm) {
diff = t2 - t1; diff = t2 - t1;
if (t1 - diff == -1) if (t1 - diff == -1)
DEBUG_LOG(LOGF_RtcLinux, "Could not convert RTC time"); DEBUG_LOG("Could not convert RTC time");
return t1 - diff; return t1 - diff;
} }
@ -390,7 +390,7 @@ read_hwclock_file(const char *hwclock_file)
in = fopen(hwclock_file, "r"); in = fopen(hwclock_file, "r");
if (!in) { if (!in) {
LOG(LOGS_WARN, LOGF_RtcLinux, "Could not open %s : %s", LOG(LOGS_WARN, "Could not open %s : %s",
hwclock_file, strerror(errno)); hwclock_file, strerror(errno));
return; return;
} }
@ -408,8 +408,7 @@ read_hwclock_file(const char *hwclock_file)
} else if (i == 3 && !strncmp(line, "UTC", 3)) { } else if (i == 3 && !strncmp(line, "UTC", 3)) {
rtc_on_utc = 1; rtc_on_utc = 1;
} else { } else {
LOG(LOGS_WARN, LOGF_RtcLinux, "Could not read RTC LOCAL/UTC setting from %s", LOG(LOGS_WARN, "Could not read RTC LOCAL/UTC setting from %s", hwclock_file);
hwclock_file);
} }
} }
@ -451,8 +450,7 @@ read_coefs_from_file(void)
&file_ref_offset, &file_ref_offset,
&file_rate_ppm) == 4) { &file_rate_ppm) == 4) {
} else { } else {
LOG(LOGS_WARN, LOGF_RtcLinux, "Could not read coefficients from %s", LOG(LOGS_WARN, "Could not read coefficients from %s", coefs_file_name);
coefs_file_name);
} }
fclose(in); fclose(in);
} }
@ -485,7 +483,7 @@ write_coefs_to_file(int valid,time_t ref_time,double offset,double rate)
out = fopen(temp_coefs_file_name, "w"); out = fopen(temp_coefs_file_name, "w");
if (!out) { if (!out) {
Free(temp_coefs_file_name); Free(temp_coefs_file_name);
LOG(LOGS_WARN, LOGF_RtcLinux, "Could not open temporary RTC file %s.tmp for writing", LOG(LOGS_WARN, "Could not open temporary RTC file %s.tmp for writing",
coefs_file_name); coefs_file_name);
return RTC_ST_BADFILE; return RTC_ST_BADFILE;
} }
@ -496,7 +494,7 @@ write_coefs_to_file(int valid,time_t ref_time,double offset,double rate)
r2 = fclose(out); r2 = fclose(out);
if (r1 < 0 || r2) { if (r1 < 0 || r2) {
Free(temp_coefs_file_name); Free(temp_coefs_file_name);
LOG(LOGS_WARN, LOGF_RtcLinux, "Could not write to temporary RTC file %s.tmp", LOG(LOGS_WARN, "Could not write to temporary RTC file %s.tmp",
coefs_file_name); coefs_file_name);
return RTC_ST_BADFILE; return RTC_ST_BADFILE;
} }
@ -506,7 +504,7 @@ write_coefs_to_file(int valid,time_t ref_time,double offset,double rate)
if (!stat(coefs_file_name,&buf)) { if (!stat(coefs_file_name,&buf)) {
if (chown(temp_coefs_file_name,buf.st_uid,buf.st_gid) || if (chown(temp_coefs_file_name,buf.st_uid,buf.st_gid) ||
chmod(temp_coefs_file_name,buf.st_mode & 0777)) { chmod(temp_coefs_file_name,buf.st_mode & 0777)) {
LOG(LOGS_WARN, LOGF_RtcLinux, LOG(LOGS_WARN,
"Could not change ownership or permissions of temporary RTC file %s.tmp", "Could not change ownership or permissions of temporary RTC file %s.tmp",
coefs_file_name); coefs_file_name);
} }
@ -517,7 +515,7 @@ write_coefs_to_file(int valid,time_t ref_time,double offset,double rate)
if (rename(temp_coefs_file_name,coefs_file_name)) { if (rename(temp_coefs_file_name,coefs_file_name)) {
unlink(temp_coefs_file_name); unlink(temp_coefs_file_name);
Free(temp_coefs_file_name); Free(temp_coefs_file_name);
LOG(LOGS_WARN, LOGF_RtcLinux, "Could not replace old RTC file %s.tmp with new one %s", LOG(LOGS_WARN, "Could not replace old RTC file %s.tmp with new one %s",
coefs_file_name, coefs_file_name); coefs_file_name, coefs_file_name);
return RTC_ST_BADFILE; return RTC_ST_BADFILE;
} }
@ -550,7 +548,7 @@ RTC_Linux_Initialise(void)
fd = open (CNF_GetRtcDevice(), O_RDWR); fd = open (CNF_GetRtcDevice(), O_RDWR);
if (fd < 0) { if (fd < 0) {
LOG(LOGS_ERR, LOGF_RtcLinux, "Could not open RTC device %s : %s", LOG(LOGS_ERR, "Could not open RTC device %s : %s",
CNF_GetRtcDevice(), strerror(errno)); CNF_GetRtcDevice(), strerror(errno));
return 0; return 0;
} }
@ -611,16 +609,14 @@ switch_interrupts(int onoff)
if (onoff) { if (onoff) {
status = ioctl(fd, RTC_UIE_ON, 0); status = ioctl(fd, RTC_UIE_ON, 0);
if (status < 0) { if (status < 0) {
LOG(LOGS_ERR, LOGF_RtcLinux, "Could not %s RTC interrupt : %s", LOG(LOGS_ERR, "Could not %s RTC interrupt : %s", "enable", strerror(errno));
"enable", strerror(errno));
return; return;
} }
skip_interrupts = 1; skip_interrupts = 1;
} else { } else {
status = ioctl(fd, RTC_UIE_OFF, 0); status = ioctl(fd, RTC_UIE_OFF, 0);
if (status < 0) { if (status < 0) {
LOG(LOGS_ERR, LOGF_RtcLinux, "Could not %s RTC interrupt : %s", LOG(LOGS_ERR, "Could not %s RTC interrupt : %s", "disable", strerror(errno));
"disable", strerror(errno));
return; return;
} }
} }
@ -658,7 +654,7 @@ set_rtc(time_t new_rtc_time)
status = ioctl(fd, RTC_SET_TIME, &rtc_raw); status = ioctl(fd, RTC_SET_TIME, &rtc_raw);
if (status < 0) { if (status < 0) {
LOG(LOGS_ERR, LOGF_RtcLinux, "Could not set RTC time"); LOG(LOGS_ERR, "Could not set RTC time");
} }
} }
@ -701,10 +697,10 @@ handle_initial_trim(void)
sys_error_now = rtc_error_now - coef_seconds_fast; sys_error_now = rtc_error_now - coef_seconds_fast;
LCL_AccumulateOffset(sys_error_now, 0.0); LCL_AccumulateOffset(sys_error_now, 0.0);
LOG(LOGS_INFO, LOGF_RtcLinux, "System clock off from RTC by %f seconds (slew)", LOG(LOGS_INFO, "System clock off from RTC by %f seconds (slew)",
sys_error_now); sys_error_now);
} else { } else {
LOG(LOGS_WARN, LOGF_RtcLinux, "No valid rtcfile coefficients"); LOG(LOGS_WARN, "No valid rtcfile coefficients");
} }
coefs_valid = 0; coefs_valid = 0;
@ -729,7 +725,7 @@ handle_relock_after_trim(void)
if (valid) { if (valid) {
write_coefs_to_file(1,ref,fast,saved_coef_gain_rate); write_coefs_to_file(1,ref,fast,saved_coef_gain_rate);
} else { } else {
DEBUG_LOG(LOGF_RtcLinux, "Could not do regression after trim"); DEBUG_LOG("Could not do regression after trim");
} }
coefs_valid = 0; coefs_valid = 0;
@ -824,7 +820,7 @@ read_from_device(int fd_, int event, void *any)
if (status < 0) { if (status < 0) {
/* This looks like a bad error : the file descriptor was indicating it was /* This looks like a bad error : the file descriptor was indicating it was
* ready to read but we couldn't read anything. Give up. */ * ready to read but we couldn't read anything. Give up. */
LOG(LOGS_ERR, LOGF_RtcLinux, "Could not read flags %s : %s", CNF_GetRtcDevice(), strerror(errno)); LOG(LOGS_ERR, "Could not read flags %s : %s", CNF_GetRtcDevice(), strerror(errno));
SCH_RemoveFileHandler(fd); SCH_RemoveFileHandler(fd);
switch_interrupts(0); /* Likely to raise error too, but just to be sure... */ switch_interrupts(0); /* Likely to raise error too, but just to be sure... */
close(fd); close(fd);
@ -848,7 +844,7 @@ read_from_device(int fd_, int event, void *any)
status = ioctl(fd, RTC_RD_TIME, &rtc_raw); status = ioctl(fd, RTC_RD_TIME, &rtc_raw);
if (status < 0) { if (status < 0) {
LOG(LOGS_ERR, LOGF_RtcLinux, "Could not read time from %s : %s", CNF_GetRtcDevice(), strerror(errno)); LOG(LOGS_ERR, "Could not read time from %s : %s", CNF_GetRtcDevice(), strerror(errno));
error = 1; error = 1;
goto turn_off_interrupt; goto turn_off_interrupt;
} }
@ -889,7 +885,7 @@ turn_off_interrupt:
switch (operating_mode) { switch (operating_mode) {
case OM_INITIAL: case OM_INITIAL:
if (error) { if (error) {
DEBUG_LOG(LOGF_RtcLinux, "Could not complete initial step due to errors"); DEBUG_LOG("Could not complete initial step due to errors");
operating_mode = OM_NORMAL; operating_mode = OM_NORMAL;
(after_init_hook)(after_init_hook_arg); (after_init_hook)(after_init_hook_arg);
@ -902,7 +898,7 @@ turn_off_interrupt:
case OM_AFTERTRIM: case OM_AFTERTRIM:
if (error) { if (error) {
DEBUG_LOG(LOGF_RtcLinux, "Could not complete after trim relock due to errors"); DEBUG_LOG("Could not complete after trim relock due to errors");
operating_mode = OM_NORMAL; operating_mode = OM_NORMAL;
switch_interrupts(0); switch_interrupts(0);
@ -1041,7 +1037,7 @@ RTC_Linux_TimePreInit(time_t driftfile_time)
UTI_AddDoubleToTimespec(&new_sys_time, -accumulated_error, &new_sys_time); UTI_AddDoubleToTimespec(&new_sys_time, -accumulated_error, &new_sys_time);
if (new_sys_time.tv_sec < driftfile_time) { if (new_sys_time.tv_sec < driftfile_time) {
LOG(LOGS_WARN, LOGF_RtcLinux, "RTC time before last driftfile modification (ignored)"); LOG(LOGS_WARN, "RTC time before last driftfile modification (ignored)");
return 0; return 0;
} }
@ -1050,7 +1046,7 @@ RTC_Linux_TimePreInit(time_t driftfile_time)
/* Set system time only if the step is larger than 1 second */ /* Set system time only if the step is larger than 1 second */
if (fabs(sys_offset) >= 1.0) { if (fabs(sys_offset) >= 1.0) {
if (LCL_ApplyStepOffset(sys_offset)) if (LCL_ApplyStepOffset(sys_offset))
LOG(LOGS_INFO, LOGF_RtcLinux, "System time set from RTC"); LOG(LOGS_INFO, "System time set from RTC");
} }
} else { } else {
return 0; return 0;
@ -1095,7 +1091,7 @@ RTC_Linux_Trim(void)
if (fabs(coef_seconds_fast) > 1.0) { if (fabs(coef_seconds_fast) > 1.0) {
LOG(LOGS_INFO, LOGF_RtcLinux, "RTC wrong by %.3f seconds (step)", LOG(LOGS_INFO, "RTC wrong by %.3f seconds (step)",
coef_seconds_fast); coef_seconds_fast);
/* Do processing to set clock. Let R be the value we set the /* Do processing to set clock. Let R be the value we set the

14
sched.c
View file

@ -163,7 +163,7 @@ SCH_AddFileHandler
assert(fd >= 0); assert(fd >= 0);
if (fd >= FD_SETSIZE) if (fd >= FD_SETSIZE)
LOG_FATAL(LOGF_Scheduler, "Too many file descriptors"); LOG_FATAL("Too many file descriptors");
/* Resize the array if the descriptor is highest so far */ /* Resize the array if the descriptor is highest so far */
while (ARR_GetSize(file_handlers) <= fd) { while (ARR_GetSize(file_handlers) <= fd) {
@ -350,7 +350,7 @@ SCH_AddTimeoutByDelay(double delay, SCH_TimeoutHandler handler, SCH_ArbitraryArg
LCL_ReadRawTime(&now); LCL_ReadRawTime(&now);
UTI_AddDoubleToTimespec(&now, delay, &then); UTI_AddDoubleToTimespec(&now, delay, &then);
if (UTI_CompareTimespecs(&now, &then) > 0) { if (UTI_CompareTimespecs(&now, &then) > 0) {
LOG_FATAL(LOGF_Scheduler, "Timeout overflow"); LOG_FATAL("Timeout overflow");
} }
return SCH_AddTimeout(&then, handler, arg); return SCH_AddTimeout(&then, handler, arg);
@ -512,7 +512,7 @@ dispatch_timeouts(struct timespec *now) {
more time than was delay of a scheduled timeout. */ more time than was delay of a scheduled timeout. */
if (n_done > n_timer_queue_entries * 4 && if (n_done > n_timer_queue_entries * 4 &&
n_done > n_entries_on_start * 4) { n_done > n_entries_on_start * 4) {
LOG_FATAL(LOGF_Scheduler, "Possible infinite loop in scheduling"); LOG_FATAL("Possible infinite loop in scheduling");
} }
} }
} }
@ -680,10 +680,10 @@ check_current_time(struct timespec *prev_raw, struct timespec *raw, int timeout,
if (last_select_ts_raw.tv_sec + elapsed_min.tv_sec > if (last_select_ts_raw.tv_sec + elapsed_min.tv_sec >
raw->tv_sec + JUMP_DETECT_THRESHOLD) { raw->tv_sec + JUMP_DETECT_THRESHOLD) {
LOG(LOGS_WARN, LOGF_Scheduler, "Backward time jump detected!"); LOG(LOGS_WARN, "Backward time jump detected!");
} else if (prev_raw->tv_sec + elapsed_max.tv_sec + JUMP_DETECT_THRESHOLD < } else if (prev_raw->tv_sec + elapsed_max.tv_sec + JUMP_DETECT_THRESHOLD <
raw->tv_sec) { raw->tv_sec) {
LOG(LOGS_WARN, LOGF_Scheduler, "Forward time jump detected!"); LOG(LOGS_WARN, "Forward time jump detected!");
} else { } else {
return 1; return 1;
} }
@ -742,7 +742,7 @@ SCH_MainLoop(void)
/* if there are no file descriptors being waited on and no /* if there are no file descriptors being waited on and no
timeout set, this is clearly ridiculous, so stop the run */ timeout set, this is clearly ridiculous, so stop the run */
if (!ptv && !p_read_fds && !p_write_fds) if (!ptv && !p_read_fds && !p_write_fds)
LOG_FATAL(LOGF_Scheduler, "Nothing to do"); LOG_FATAL("Nothing to do");
status = select(one_highest_fd, p_read_fds, p_write_fds, p_except_fds, ptv); status = select(one_highest_fd, p_read_fds, p_write_fds, p_except_fds, ptv);
errsv = errno; errsv = errno;
@ -762,7 +762,7 @@ SCH_MainLoop(void)
if (status < 0) { if (status < 0) {
if (!need_to_exit && errsv != EINTR) { if (!need_to_exit && errsv != EINTR) {
LOG_FATAL(LOGF_Scheduler, "select() failed : %s", strerror(errsv)); LOG_FATAL("select() failed : %s", strerror(errsv));
} }
} else if (status > 0) { } else if (status > 0) {
/* A file descriptor is ready for input or output */ /* A file descriptor is ready for input or output */

6
smooth.c
View file

@ -208,7 +208,7 @@ update_stages(void)
stages[2].length = l3; stages[2].length = l3;
for (i = 0; i < NUM_STAGES; i++) { for (i = 0; i < NUM_STAGES; i++) {
DEBUG_LOG(LOGF_Smooth, "Smooth stage %d wander %e length %f", DEBUG_LOG("Smooth stage %d wander %e length %f",
i + 1, stages[i].wander, stages[i].length); i + 1, stages[i].wander, stages[i].length);
} }
} }
@ -230,7 +230,7 @@ update_smoothing(struct timespec *now, double offset, double freq)
update_stages(); update_stages();
DEBUG_LOG(LOGF_Smooth, "Smooth offset %e freq %e", smooth_offset, smooth_freq); DEBUG_LOG("Smooth offset %e freq %e", smooth_offset, smooth_freq);
} }
static void static void
@ -295,7 +295,7 @@ SMT_Activate(struct timespec *now)
if (!enabled || !locked) if (!enabled || !locked)
return; return;
LOG(LOGS_INFO, LOGF_Smooth, "Time smoothing activated%s", leap_only_mode ? LOG(LOGS_INFO, "Time smoothing activated%s", leap_only_mode ?
" (leap seconds only)" : ""); " (leap seconds only)" : "");
locked = 0; locked = 0;
last_update = *now; last_update = *now;

35
sources.c
View file

@ -348,12 +348,12 @@ void SRC_AccumulateSample
inst->leap_status = leap_status; inst->leap_status = leap_status;
DEBUG_LOG(LOGF_Sources, "ip=[%s] t=%s ofs=%f del=%f disp=%f str=%d", DEBUG_LOG("ip=[%s] t=%s ofs=%f del=%f disp=%f str=%d",
source_to_string(inst), UTI_TimespecToString(sample_time), -offset, source_to_string(inst), UTI_TimespecToString(sample_time), -offset,
root_delay, root_dispersion, stratum); root_delay, root_dispersion, stratum);
if (REF_IsLeapSecondClose()) { if (REF_IsLeapSecondClose()) {
LOG(LOGS_INFO, LOGF_Sources, "Dropping sample around leap second"); LOG(LOGS_INFO, "Dropping sample around leap second");
return; return;
} }
@ -451,7 +451,7 @@ log_selection_message(char *format, char *arg)
{ {
if (REF_GetMode() != REF_ModeNormal) if (REF_GetMode() != REF_ModeNormal)
return; return;
LOG(LOGS_INFO, LOGF_Sources, format, arg); LOG(LOGS_INFO, format, arg);
} }
/* ================================================== */ /* ================================================== */
@ -563,7 +563,7 @@ combine_sources(int n_sel_sources, struct timespec *ref_time, double *offset,
offset_weight = 1.0 / sources[index]->sel_info.root_distance; offset_weight = 1.0 / sources[index]->sel_info.root_distance;
frequency_weight = 1.0 / src_skew; frequency_weight = 1.0 / src_skew;
DEBUG_LOG(LOGF_Sources, "combining index=%d oweight=%e offset=%e sd=%e fweight=%e freq=%e skew=%e", DEBUG_LOG("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); index, offset_weight, src_offset, src_offset_sd, frequency_weight, src_frequency, src_skew);
sum_offset_weight += offset_weight; sum_offset_weight += offset_weight;
@ -584,7 +584,7 @@ combine_sources(int n_sel_sources, struct timespec *ref_time, double *offset,
*frequency = sum_frequency / sum_frequency_weight; *frequency = sum_frequency / sum_frequency_weight;
*skew = 1.0 / sqrt(inv_sum2_skew); *skew = 1.0 / sqrt(inv_sum2_skew);
DEBUG_LOG(LOGF_Sources, "combined result offset=%e sd=%e freq=%e skew=%e", DEBUG_LOG("combined result offset=%e sd=%e freq=%e skew=%e",
*offset, *offset_sd, *frequency, *skew); *offset, *offset_sd, *frequency, *skew);
return combined; return combined;
@ -736,12 +736,11 @@ SRC_SelectSource(SRC_Instance updated_inst)
uint32_t local_ref_id = NSR_GetLocalRefid(sources[orphan_source]->ip_addr); uint32_t local_ref_id = NSR_GetLocalRefid(sources[orphan_source]->ip_addr);
if (!local_ref_id) { if (!local_ref_id) {
LOG(LOGS_ERR, LOGF_Sources, "Unknown local refid in orphan mode"); LOG(LOGS_ERR, "Unknown local refid in orphan mode");
} else if (sources[orphan_source]->ref_id < local_ref_id) { } else if (sources[orphan_source]->ref_id < local_ref_id) {
sources[orphan_source]->status = SRC_OK; sources[orphan_source]->status = SRC_OK;
n_sel_sources = 1; n_sel_sources = 1;
DEBUG_LOG(LOGF_Sources, "selecting orphan refid=%"PRIx32, DEBUG_LOG("selecting orphan refid=%"PRIx32, sources[orphan_source]->ref_id);
sources[orphan_source]->ref_id);
} }
} }
@ -765,7 +764,7 @@ SRC_SelectSource(SRC_Instance updated_inst)
n_endpoints += 2; n_endpoints += 2;
} }
DEBUG_LOG(LOGF_Sources, "badstat=%d sel=%d badstat_reach=%x sel_reach=%x max_reach_ago=%f", DEBUG_LOG("badstat=%d sel=%d badstat_reach=%x sel_reach=%x max_reach_ago=%f",
n_badstats_sources, n_sel_sources, max_badstat_reach, n_badstats_sources, n_sel_sources, max_badstat_reach,
max_sel_reach, max_reach_sample_ago); max_sel_reach, max_reach_sample_ago);
@ -1003,7 +1002,7 @@ SRC_SelectSource(SRC_Instance updated_inst)
sources[i]->sel_score = 1.0 / distance; sources[i]->sel_score = 1.0 / distance;
} }
DEBUG_LOG(LOGF_Sources, "select score=%f refid=%"PRIx32" match_refid=%"PRIx32" status=%d dist=%f", DEBUG_LOG("select score=%f refid=%"PRIx32" match_refid=%"PRIx32" status=%d dist=%f",
sources[i]->sel_score, sources[i]->ref_id, sources[i]->sel_score, sources[i]->ref_id,
updated_inst ? updated_inst->ref_id : 0, updated_inst ? updated_inst->ref_id : 0,
sources[i]->status, distance); sources[i]->status, distance);
@ -1027,7 +1026,7 @@ SRC_SelectSource(SRC_Instance updated_inst)
if (sources[max_score_index]->updates == 0) { if (sources[max_score_index]->updates == 0) {
selected_source_index = INVALID_SOURCE; selected_source_index = INVALID_SOURCE;
mark_ok_sources(SRC_WAITS_UPDATE); mark_ok_sources(SRC_WAITS_UPDATE);
DEBUG_LOG(LOGF_Sources, "best source has no updates"); DEBUG_LOG("best source has no updates");
return; return;
} }
@ -1098,7 +1097,7 @@ SRC_SetReselectDistance(double distance)
{ {
if (reselect_distance != distance) { if (reselect_distance != distance) {
reselect_distance = distance; reselect_distance = distance;
LOG(LOGS_INFO, LOGF_Sources, "New reselect distance %f", distance); LOG(LOGS_INFO, "New reselect distance %f", distance);
} }
} }
@ -1153,7 +1152,7 @@ FILE *open_dumpfile(SRC_Instance inst, const char *mode)
dumpdir = CNF_GetDumpDir(); dumpdir = CNF_GetDumpDir();
if (dumpdir[0] == '\0') { if (dumpdir[0] == '\0') {
LOG(LOGS_WARN, LOGF_Sources, "dumpdir not specified"); LOG(LOGS_WARN, "dumpdir not specified");
return NULL; return NULL;
} }
@ -1164,13 +1163,13 @@ FILE *open_dumpfile(SRC_Instance inst, const char *mode)
(inst->type != SRC_NTP && (inst->type != SRC_NTP &&
snprintf(filename, sizeof (filename), "%s/refid:%08"PRIx32".dat", snprintf(filename, sizeof (filename), "%s/refid:%08"PRIx32".dat",
dumpdir, inst->ref_id) >= sizeof (filename))) { dumpdir, inst->ref_id) >= sizeof (filename))) {
LOG(LOGS_WARN, LOGF_Sources, "dumpdir too long"); LOG(LOGS_WARN, "dumpdir too long");
return NULL; return NULL;
} }
f = fopen(filename, mode); f = fopen(filename, mode);
if (!f && mode[0] != 'r') if (!f && mode[0] != 'r')
LOG(LOGS_WARN, LOGF_Sources, "Could not open dump file for %s", LOG(LOGS_WARN, "Could not open dump file for %s",
source_to_string(inst)); source_to_string(inst));
return f; return f;
@ -1207,10 +1206,10 @@ SRC_ReloadSources(void)
if (!in) if (!in)
continue; continue;
if (!SST_LoadFromFile(sources[i]->stats, in)) if (!SST_LoadFromFile(sources[i]->stats, in))
LOG(LOGS_WARN, LOGF_Sources, "Could not load dump file for %s", LOG(LOGS_WARN, "Could not load dump file for %s",
source_to_string(sources[i])); source_to_string(sources[i]));
else else
LOG(LOGS_INFO, LOGF_Sources, "Loaded dump file for %s", LOG(LOGS_INFO, "Loaded dump file for %s",
source_to_string(sources[i])); source_to_string(sources[i]));
fclose(in); fclose(in);
} }
@ -1248,7 +1247,7 @@ SRC_RemoveDumpFiles(void)
if (strncmp(name, "refid:", 6) && !UTI_StringToIP(name, &ip_addr)) if (strncmp(name, "refid:", 6) && !UTI_StringToIP(name, &ip_addr))
continue; continue;
DEBUG_LOG(LOGF_Sources, "Removing %s", gl.gl_pathv[i]); DEBUG_LOG("Removing %s", gl.gl_pathv[i]);
unlink(gl.gl_pathv[i]); unlink(gl.gl_pathv[i]);
} }

15
sourcestats.c
View file

@ -295,7 +295,7 @@ SST_AccumulateSample(SST_Stats inst, struct timespec *sample_time,
/* Make sure it's newer than the last sample */ /* Make sure it's newer than the last sample */
if (inst->n_samples && if (inst->n_samples &&
UTI_CompareTimespecs(&inst->sample_times[inst->last_sample], sample_time) >= 0) { UTI_CompareTimespecs(&inst->sample_times[inst->last_sample], sample_time) >= 0) {
LOG(LOGS_WARN, LOGF_SourceStats, "Out of order sample detected, discarding history for %s", LOG(LOGS_WARN, "Out of order sample detected, discarding history for %s",
inst->ip_addr ? UTI_IPToString(inst->ip_addr) : UTI_RefidToString(inst->refid)); inst->ip_addr ? UTI_IPToString(inst->ip_addr) : UTI_RefidToString(inst->refid));
SST_ResetInstance(inst); SST_ResetInstance(inst);
} }
@ -545,7 +545,7 @@ SST_DoNewRegression(SST_Stats inst)
inst->skew = CLAMP(MIN_SKEW, inst->skew, MAX_SKEW); inst->skew = CLAMP(MIN_SKEW, inst->skew, MAX_SKEW);
stress = fabs(old_freq - inst->estimated_frequency) / old_skew; stress = fabs(old_freq - inst->estimated_frequency) / old_skew;
DEBUG_LOG(LOGF_SourceStats, "off=%e freq=%e skew=%e n=%d bs=%d runs=%d asym=%f arun=%d", DEBUG_LOG("off=%e freq=%e skew=%e n=%d bs=%d runs=%d asym=%f arun=%d",
inst->estimated_offset, inst->estimated_frequency, inst->skew, inst->estimated_offset, inst->estimated_frequency, inst->skew,
inst->n_samples, best_start, inst->nruns, inst->n_samples, best_start, inst->nruns,
inst->asymmetry, inst->asymmetry_run); inst->asymmetry, inst->asymmetry_run);
@ -653,7 +653,7 @@ SST_GetSelectionData(SST_Stats inst, struct timespec *now,
*select_ok = inst->regression_ok; *select_ok = inst->regression_ok;
DEBUG_LOG(LOGF_SourceStats, "n=%d off=%f dist=%f sd=%f first_ago=%f last_ago=%f selok=%d", DEBUG_LOG("n=%d off=%f dist=%f sd=%f first_ago=%f last_ago=%f selok=%d",
inst->n_samples, offset, *root_distance, *std_dev, inst->n_samples, offset, *root_distance, *std_dev,
*first_sample_ago, *last_sample_ago, *select_ok); *first_sample_ago, *last_sample_ago, *select_ok);
} }
@ -684,8 +684,9 @@ SST_GetTrackingData(SST_Stats inst, struct timespec *ref_time,
elapsed_sample = UTI_DiffTimespecsToDouble(&inst->offset_time, &inst->sample_times[i]); elapsed_sample = UTI_DiffTimespecsToDouble(&inst->offset_time, &inst->sample_times[i]);
*root_dispersion = inst->root_dispersions[j] + inst->skew * elapsed_sample; *root_dispersion = inst->root_dispersions[j] + inst->skew * elapsed_sample;
DEBUG_LOG(LOGF_SourceStats, "n=%d freq=%f (%.3fppm) skew=%f (%.3fppm) avoff=%f offsd=%f disp=%f", DEBUG_LOG("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); inst->n_samples, *frequency, 1.0e6* *frequency, *skew, 1.0e6* *skew,
*average_offset, *offset_sd, *root_dispersion);
} }
@ -719,7 +720,7 @@ SST_SlewSamples(SST_Stats inst, struct timespec *when, double dfreq, double doff
inst->estimated_offset += delta_time; inst->estimated_offset += delta_time;
inst->estimated_frequency = (inst->estimated_frequency - dfreq) / (1.0 - dfreq); inst->estimated_frequency = (inst->estimated_frequency - dfreq) / (1.0 - dfreq);
DEBUG_LOG(LOGF_SourceStats, "n=%d m=%d old_off_time=%s new=%s old_off=%f new_off=%f old_freq=%.3f new_freq=%.3f", DEBUG_LOG("n=%d m=%d old_off_time=%s new=%s old_off=%f new_off=%f old_freq=%.3f new_freq=%.3f",
inst->n_samples, inst->runs_samples, inst->n_samples, inst->runs_samples,
UTI_TimespecToString(&prev), UTI_TimespecToString(&inst->offset_time), UTI_TimespecToString(&prev), UTI_TimespecToString(&inst->offset_time),
prev_offset, inst->estimated_offset, prev_offset, inst->estimated_offset,
@ -805,7 +806,7 @@ SST_IsGoodSample(SST_Stats inst, double offset, double delay,
if (fabs(offset) - delay_increase > allowed_increase) if (fabs(offset) - delay_increase > allowed_increase)
return 1; return 1;
DEBUG_LOG(LOGF_SourceStats, "Bad sample: offset=%f delay=%f incr_delay=%f allowed=%f", DEBUG_LOG("Bad sample: offset=%f delay=%f incr_delay=%f allowed=%f",
offset, delay, allowed_increase, delay_increase); offset, delay, allowed_increase, delay_increase);
return 0; return 0;

2
stubs.c
View file

@ -91,7 +91,7 @@ DNS_Name2IPAddressAsync(const char *name, DNS_NameResolveHandler handler, void *
inst->arg = anything; inst->arg = anything;
if (pipe(inst->pipe)) if (pipe(inst->pipe))
LOG_FATAL(LOGF_Nameserv, "pipe() failed"); LOG_FATAL("pipe() failed");
UTI_FdSetCloexec(inst->pipe[0]); UTI_FdSetCloexec(inst->pipe[0]);
UTI_FdSetCloexec(inst->pipe[1]); UTI_FdSetCloexec(inst->pipe[1]);

8
sys.c
View file

@ -91,7 +91,7 @@ void SYS_DropRoot(uid_t uid, gid_t gid)
#elif defined(MACOSX) && defined(FEAT_PRIVDROP) #elif defined(MACOSX) && defined(FEAT_PRIVDROP)
SYS_MacOSX_DropRoot(uid, gid); SYS_MacOSX_DropRoot(uid, gid);
#else #else
LOG_FATAL(LOGF_Sys, "dropping root privileges not supported"); LOG_FATAL("dropping root privileges not supported");
#endif #endif
} }
@ -102,7 +102,7 @@ void SYS_EnableSystemCallFilter(int level)
#if defined(LINUX) && defined(FEAT_SCFILTER) #if defined(LINUX) && defined(FEAT_SCFILTER)
SYS_Linux_EnableSystemCallFilter(level); SYS_Linux_EnableSystemCallFilter(level);
#else #else
LOG_FATAL(LOGF_Sys, "system call filter not supported"); LOG_FATAL("system call filter not supported");
#endif #endif
} }
@ -115,7 +115,7 @@ void SYS_SetScheduler(int SchedPriority)
#elif defined(MACOSX) #elif defined(MACOSX)
SYS_MacOSX_SetScheduler(SchedPriority); SYS_MacOSX_SetScheduler(SchedPriority);
#else #else
LOG_FATAL(LOGF_Sys, "scheduler priority setting not supported"); LOG_FATAL("scheduler priority setting not supported");
#endif #endif
} }
@ -126,7 +126,7 @@ void SYS_LockMemory(void)
#if defined(LINUX) && defined(HAVE_MLOCKALL) #if defined(LINUX) && defined(HAVE_MLOCKALL)
SYS_Linux_MemLockAll(1); SYS_Linux_MemLockAll(1);
#else #else
LOG_FATAL(LOGF_Sys, "memory locking not supported"); LOG_FATAL("memory locking not supported");
#endif #endif
} }

6
sys_generic.c
View file

@ -129,7 +129,7 @@ start_fastslew(void)
drv_accrue_offset(offset_register, 0.0); drv_accrue_offset(offset_register, 0.0);
DEBUG_LOG(LOGF_SysGeneric, "fastslew offset=%e", offset_register); DEBUG_LOG("fastslew offset=%e", offset_register);
offset_register = 0.0; offset_register = 0.0;
fastslew_active = 1; fastslew_active = 1;
@ -246,7 +246,7 @@ update_slew(void)
slew_timeout_id = SCH_AddTimeout(&end_of_slew, handle_end_of_slew, NULL); slew_timeout_id = SCH_AddTimeout(&end_of_slew, handle_end_of_slew, NULL);
slew_start = now; slew_start = now;
DEBUG_LOG(LOGF_SysGeneric, "slew offset=%e corr_rate=%e base_freq=%f total_freq=%f slew_freq=%e duration=%f slew_error=%e", DEBUG_LOG("slew offset=%e corr_rate=%e base_freq=%f total_freq=%f slew_freq=%e duration=%f slew_error=%e",
offset_register, correction_rate, base_freq, total_freq, slew_freq, offset_register, correction_rate, base_freq, total_freq, slew_freq,
duration, slew_error); duration, slew_error);
} }
@ -333,7 +333,7 @@ apply_step_offset(double offset)
UTI_TimespecToTimeval(&new_time, &new_time_tv); UTI_TimespecToTimeval(&new_time, &new_time_tv);
if (PRV_SetTime(&new_time_tv, NULL) < 0) { if (PRV_SetTime(&new_time_tv, NULL) < 0) {
DEBUG_LOG(LOGF_SysGeneric, "settimeofday() failed"); DEBUG_LOG("settimeofday() failed");
return 0; return 0;
} }

50
sys_linux.c
View file

@ -240,7 +240,7 @@ guess_hz(void)
} }
/* oh dear. doomed. */ /* oh dear. doomed. */
LOG_FATAL(LOGF_SysLinux, "Can't determine hz from tick %d", tick); LOG_FATAL("Can't determine hz from tick %d", tick);
return 0; return 0;
} }
@ -283,11 +283,11 @@ get_kernel_version(int *major, int *minor, int *patch)
struct utsname uts; struct utsname uts;
if (uname(&uts) < 0) if (uname(&uts) < 0)
LOG_FATAL(LOGF_SysLinux, "uname() failed"); LOG_FATAL("uname() failed");
*patch = 0; *patch = 0;
if (sscanf(uts.release, "%d.%d.%d", major, minor, patch) < 2) if (sscanf(uts.release, "%d.%d.%d", major, minor, patch) < 2)
LOG_FATAL(LOGF_SysLinux, "Could not parse kernel version"); LOG_FATAL("Could not parse kernel version");
} }
/* ================================================== */ /* ================================================== */
@ -314,10 +314,10 @@ get_version_specific_details(void)
tick_update_hz = 100; tick_update_hz = 100;
get_kernel_version(&major, &minor, &patch); get_kernel_version(&major, &minor, &patch);
DEBUG_LOG(LOGF_SysLinux, "Linux kernel major=%d minor=%d patch=%d", major, minor, patch); DEBUG_LOG("Linux kernel major=%d minor=%d patch=%d", major, minor, patch);
if (kernelvercmp(major, minor, patch, 2, 2, 0) < 0) { if (kernelvercmp(major, minor, patch, 2, 2, 0) < 0) {
LOG_FATAL(LOGF_SysLinux, "Kernel version not supported, sorry."); LOG_FATAL("Kernel version not supported, sorry.");
} }
if (kernelvercmp(major, minor, patch, 2, 6, 27) >= 0 && if (kernelvercmp(major, minor, patch, 2, 6, 27) >= 0 &&
@ -334,7 +334,7 @@ get_version_specific_details(void)
have_setoffset = 1; have_setoffset = 1;
} }
DEBUG_LOG(LOGF_SysLinux, "hz=%d nominal_tick=%d max_tick_bias=%d", DEBUG_LOG("hz=%d nominal_tick=%d max_tick_bias=%d",
hz, nominal_tick, max_tick_bias); hz, nominal_tick, max_tick_bias);
} }
@ -391,7 +391,7 @@ SYS_Linux_Initialise(void)
reset_adjtime_offset(); reset_adjtime_offset();
if (have_setoffset && !test_step_offset()) { if (have_setoffset && !test_step_offset()) {
LOG(LOGS_INFO, LOGF_SysLinux, "adjtimex() doesn't support ADJ_SETOFFSET"); LOG(LOGS_INFO, "adjtimex() doesn't support ADJ_SETOFFSET");
have_setoffset = 0; have_setoffset = 0;
} }
@ -421,7 +421,7 @@ SYS_Linux_DropRoot(uid_t uid, gid_t gid)
cap_t cap; cap_t cap;
if (prctl(PR_SET_KEEPCAPS, 1)) { if (prctl(PR_SET_KEEPCAPS, 1)) {
LOG_FATAL(LOGF_SysLinux, "prctl() failed"); LOG_FATAL("prctl() failed");
} }
UTI_DropRoot(uid, gid); UTI_DropRoot(uid, gid);
@ -431,11 +431,11 @@ SYS_Linux_DropRoot(uid_t uid, gid_t gid)
"cap_net_bind_service,cap_sys_time=ep" : "cap_sys_time=ep"; "cap_net_bind_service,cap_sys_time=ep" : "cap_sys_time=ep";
if ((cap = cap_from_text(cap_text)) == NULL) { if ((cap = cap_from_text(cap_text)) == NULL) {
LOG_FATAL(LOGF_SysLinux, "cap_from_text() failed"); LOG_FATAL("cap_from_text() failed");
} }
if (cap_set_proc(cap)) { if (cap_set_proc(cap)) {
LOG_FATAL(LOGF_SysLinux, "cap_set_proc() failed"); LOG_FATAL("cap_set_proc() failed");
} }
cap_free(cap); cap_free(cap);
@ -454,7 +454,7 @@ void check_seccomp_applicability(void)
CNF_GetMailOnChange(&mail_enabled, &mail_threshold, &mail_user); CNF_GetMailOnChange(&mail_enabled, &mail_threshold, &mail_user);
if (mail_enabled) if (mail_enabled)
LOG_FATAL(LOGF_SysLinux, "mailonchange directive cannot be used with -F enabled"); LOG_FATAL("mailonchange directive cannot be used with -F enabled");
} }
/* ================================================== */ /* ================================================== */
@ -546,7 +546,7 @@ SYS_Linux_EnableSystemCallFilter(int level)
ctx = seccomp_init(level > 0 ? SCMP_ACT_KILL : SCMP_ACT_TRAP); ctx = seccomp_init(level > 0 ? SCMP_ACT_KILL : SCMP_ACT_TRAP);
if (ctx == NULL) if (ctx == NULL)
LOG_FATAL(LOGF_SysLinux, "Failed to initialize seccomp"); LOG_FATAL("Failed to initialize seccomp");
/* Add system calls that are always allowed */ /* Add system calls that are always allowed */
for (i = 0; i < (sizeof (syscalls) / sizeof (*syscalls)); i++) { for (i = 0; i < (sizeof (syscalls) / sizeof (*syscalls)); i++) {
@ -587,14 +587,14 @@ SYS_Linux_EnableSystemCallFilter(int level)
} }
if (seccomp_load(ctx) < 0) if (seccomp_load(ctx) < 0)
LOG_FATAL(LOGF_SysLinux, "Failed to load seccomp rules"); LOG_FATAL("Failed to load seccomp rules");
LOG(LOGS_INFO, LOGF_SysLinux, "Loaded seccomp filter"); LOG(LOGS_INFO, "Loaded seccomp filter");
seccomp_release(ctx); seccomp_release(ctx);
return; return;
add_failed: add_failed:
LOG_FATAL(LOGF_SysLinux, "Failed to add seccomp rules"); LOG_FATAL("Failed to add seccomp rules");
} }
#endif #endif
@ -608,7 +608,7 @@ void SYS_Linux_SetScheduler(int SchedPriority)
struct sched_param sched; struct sched_param sched;
if (SchedPriority < 1 || SchedPriority > 99) { if (SchedPriority < 1 || SchedPriority > 99) {
LOG_FATAL(LOGF_SysLinux, "Bad scheduler priority: %d", SchedPriority); LOG_FATAL("Bad scheduler priority: %d", SchedPriority);
} else { } else {
sched.sched_priority = SchedPriority; sched.sched_priority = SchedPriority;
pmax = sched_get_priority_max(SCHED_FIFO); pmax = sched_get_priority_max(SCHED_FIFO);
@ -620,10 +620,10 @@ void SYS_Linux_SetScheduler(int SchedPriority)
sched.sched_priority = pmin; sched.sched_priority = pmin;
} }
if ( sched_setscheduler(0, SCHED_FIFO, &sched) == -1 ) { if ( sched_setscheduler(0, SCHED_FIFO, &sched) == -1 ) {
LOG(LOGS_ERR, LOGF_SysLinux, "sched_setscheduler() failed"); LOG(LOGS_ERR, "sched_setscheduler() failed");
} }
else { else {
DEBUG_LOG(LOGF_SysLinux, "Enabled SCHED_FIFO with priority %d", DEBUG_LOG("Enabled SCHED_FIFO with priority %d",
sched.sched_priority); sched.sched_priority);
} }
} }
@ -641,14 +641,14 @@ void SYS_Linux_MemLockAll(int LockAll)
rlim.rlim_max = RLIM_INFINITY; rlim.rlim_max = RLIM_INFINITY;
rlim.rlim_cur = RLIM_INFINITY; rlim.rlim_cur = RLIM_INFINITY;
if (setrlimit(RLIMIT_MEMLOCK, &rlim) < 0) { if (setrlimit(RLIMIT_MEMLOCK, &rlim) < 0) {
LOG(LOGS_ERR, LOGF_SysLinux, "setrlimit() failed: not locking into RAM"); LOG(LOGS_ERR, "setrlimit() failed: not locking into RAM");
} }
else { else {
if (mlockall(MCL_CURRENT|MCL_FUTURE) < 0) { if (mlockall(MCL_CURRENT|MCL_FUTURE) < 0) {
LOG(LOGS_ERR, LOGF_SysLinux, "mlockall() failed"); LOG(LOGS_ERR, "mlockall() failed");
} }
else { else {
DEBUG_LOG(LOGF_SysLinux, "Successfully locked into RAM"); DEBUG_LOG("Successfully locked into RAM");
} }
} }
} }
@ -688,7 +688,7 @@ get_phc_sample(int phc_fd, double precision, struct timespec *phc_ts,
sys_off.n_samples = PHC_READINGS; sys_off.n_samples = PHC_READINGS;
if (ioctl(phc_fd, PTP_SYS_OFFSET, &sys_off)) { if (ioctl(phc_fd, PTP_SYS_OFFSET, &sys_off)) {
DEBUG_LOG(LOGF_SysLinux, "ioctl(%s) failed : %s", "PTP_SYS_OFFSET", strerror(errno)); DEBUG_LOG("ioctl(%s) failed : %s", "PTP_SYS_OFFSET", strerror(errno));
return 0; return 0;
} }
@ -745,7 +745,7 @@ get_precise_phc_sample(int phc_fd, double precision, struct timespec *phc_ts,
memset(&sys_off, 0, sizeof (sys_off)); memset(&sys_off, 0, sizeof (sys_off));
if (ioctl(phc_fd, PTP_SYS_OFFSET_PRECISE, &sys_off)) { if (ioctl(phc_fd, PTP_SYS_OFFSET_PRECISE, &sys_off)) {
DEBUG_LOG(LOGF_SysLinux, "ioctl(%s) failed : %s", "PTP_SYS_OFFSET_PRECISE", DEBUG_LOG("ioctl(%s) failed : %s", "PTP_SYS_OFFSET_PRECISE",
strerror(errno)); strerror(errno));
return 0; return 0;
} }
@ -779,13 +779,13 @@ SYS_Linux_OpenPHC(const char *path, int phc_index)
phc_fd = open(path, O_RDONLY); phc_fd = open(path, O_RDONLY);
if (phc_fd < 0) { if (phc_fd < 0) {
LOG(LOGS_ERR, LOGF_SysLinux, "Could not open %s : %s", path, strerror(errno)); LOG(LOGS_ERR, "Could not open %s : %s", path, strerror(errno));
return -1; return -1;
} }
/* Make sure it is a PHC */ /* Make sure it is a PHC */
if (ioctl(phc_fd, PTP_CLOCK_GETCAPS, &caps)) { if (ioctl(phc_fd, PTP_CLOCK_GETCAPS, &caps)) {
LOG(LOGS_ERR, LOGF_SysLinux, "ioctl(%s) failed : %s", "PTP_CLOCK_GETCAPS", strerror(errno)); LOG(LOGS_ERR, "ioctl(%s) failed : %s", "PTP_CLOCK_GETCAPS", strerror(errno));
close(phc_fd); close(phc_fd);
return -1; return -1;
} }

21
sys_macosx.c
View file

@ -116,7 +116,7 @@ clock_initialise(void)
newadj.tv_usec = 0; newadj.tv_usec = 0;
if (PRV_AdjustTime(&newadj, &oldadj) < 0) { if (PRV_AdjustTime(&newadj, &oldadj) < 0) {
LOG_FATAL(LOGF_SysMacOSX, "adjtime() failed"); LOG_FATAL("adjtime() failed");
} }
} }
@ -154,10 +154,9 @@ start_adjust(void)
predicted_error = (current_drift_removal_interval - drift_removal_elapsed) / 2.0 * current_freq; predicted_error = (current_drift_removal_interval - drift_removal_elapsed) / 2.0 * current_freq;
DEBUG_LOG(LOGF_SysMacOSX, "drift_removal_elapsed: %.3f current_drift_removal_interval: %.3f predicted_error: %.3f", DEBUG_LOG("drift_removal_elapsed: %.3f current_drift_removal_interval: %.3f predicted_error: %.3f",
1.0e6 * drift_removal_elapsed, 1.0e6 * drift_removal_elapsed, 1.0e6 * current_drift_removal_interval,
1.0e6 * current_drift_removal_interval, 1.0e6 * predicted_error);
1.0e6 * predicted_error);
adjust_required = - (accrued_error + offset_register + predicted_error); adjust_required = - (accrued_error + offset_register + predicted_error);
@ -166,7 +165,7 @@ start_adjust(void)
rounding_error = adjust_required - adjustment_requested; rounding_error = adjust_required - adjustment_requested;
if (PRV_AdjustTime(&newadj, &oldadj) < 0) { if (PRV_AdjustTime(&newadj, &oldadj) < 0) {
LOG_FATAL(LOGF_SysMacOSX, "adjtime() failed"); LOG_FATAL("adjtime() failed");
} }
old_adjust_remaining = UTI_TimevalToDouble(&oldadj); old_adjust_remaining = UTI_TimevalToDouble(&oldadj);
@ -190,7 +189,7 @@ stop_adjust(void)
zeroadj.tv_usec = 0; zeroadj.tv_usec = 0;
if (PRV_AdjustTime(&zeroadj, &remadj) < 0) { if (PRV_AdjustTime(&zeroadj, &remadj) < 0) {
LOG_FATAL(LOGF_SysMacOSX, "adjtime() failed"); LOG_FATAL("adjtime() failed");
} }
LCL_ReadRawTime(&T1); LCL_ReadRawTime(&T1);
@ -239,7 +238,7 @@ apply_step_offset(double offset)
UTI_TimespecToTimeval(&new_time, &new_time_tv); UTI_TimespecToTimeval(&new_time, &new_time_tv);
if (PRV_SetTime(&new_time_tv, NULL) < 0) { if (PRV_SetTime(&new_time_tv, NULL) < 0) {
DEBUG_LOG(LOGF_SysMacOSX, "settimeofday() failed"); DEBUG_LOG("settimeofday() failed");
return 0; return 0;
} }
@ -338,14 +337,14 @@ set_sync_status(int synchronised, double est_error, double max_error)
/* update the RTC by applying a step of 0.0 secs */ /* update the RTC by applying a step of 0.0 secs */
apply_step_offset(0.0); apply_step_offset(0.0);
last_rtc_sync = now; last_rtc_sync = now;
DEBUG_LOG(LOGF_SysMacOSX, "rtc synchronised"); DEBUG_LOG("rtc synchronised");
} }
} }
interval = ERROR_WEIGHT * est_error / (fabs(current_freq) + FREQUENCY_RES); interval = ERROR_WEIGHT * est_error / (fabs(current_freq) + FREQUENCY_RES);
drift_removal_interval = MAX(interval, DRIFT_REMOVAL_INTERVAL_MIN); drift_removal_interval = MAX(interval, DRIFT_REMOVAL_INTERVAL_MIN);
DEBUG_LOG(LOGF_SysMacOSX, "est_error: %.3f current_freq: %.3f est drift_removal_interval: %.3f act drift_removal_interval: %.3f", DEBUG_LOG("est_error: %.3f current_freq: %.3f est drift_removal_interval: %.3f act drift_removal_interval: %.3f",
est_error * 1.0e6, current_freq * 1.0e6, interval, drift_removal_interval); est_error * 1.0e6, current_freq * 1.0e6, interval, drift_removal_interval);
} }
@ -389,7 +388,7 @@ set_realtime(void)
THREAD_TIME_CONSTRAINT_POLICY_COUNT); THREAD_TIME_CONSTRAINT_POLICY_COUNT);
if (kr != KERN_SUCCESS) { if (kr != KERN_SUCCESS) {
LOG(LOGS_WARN, LOGF_SysMacOSX, "Cannot set real-time priority: %d", kr); LOG(LOGS_WARN, "Cannot set real-time priority: %d", kr);
return -1; return -1;
} }
return 0; return 0;

8
sys_netbsd.c
View file

@ -65,14 +65,14 @@ accrue_offset(double offset, double corr_rate)
UTI_DoubleToTimeval(-offset, &newadj); UTI_DoubleToTimeval(-offset, &newadj);
if (PRV_AdjustTime(&newadj, &oldadj) < 0) if (PRV_AdjustTime(&newadj, &oldadj) < 0)
LOG_FATAL(LOGF_SysNetBSD, "adjtime() failed"); LOG_FATAL("adjtime() failed");
/* Add the old remaining adjustment if not zero */ /* Add the old remaining adjustment if not zero */
doldadj = UTI_TimevalToDouble(&oldadj); doldadj = UTI_TimevalToDouble(&oldadj);
if (doldadj != 0.0) { if (doldadj != 0.0) {
UTI_DoubleToTimeval(-offset + doldadj, &newadj); UTI_DoubleToTimeval(-offset + doldadj, &newadj);
if (PRV_AdjustTime(&newadj, NULL) < 0) if (PRV_AdjustTime(&newadj, NULL) < 0)
LOG_FATAL(LOGF_SysNetBSD, "adjtime() failed"); LOG_FATAL("adjtime() failed");
} }
} }
@ -86,7 +86,7 @@ get_offset_correction(struct timespec *raw,
double adjustment_remaining; double adjustment_remaining;
if (PRV_AdjustTime(NULL, &remadj) < 0) if (PRV_AdjustTime(NULL, &remadj) < 0)
LOG_FATAL(LOGF_SysNetBSD, "adjtime() failed"); LOG_FATAL("adjtime() failed");
adjustment_remaining = UTI_TimevalToDouble(&remadj); adjustment_remaining = UTI_TimevalToDouble(&remadj);
@ -138,7 +138,7 @@ SYS_NetBSD_DropRoot(uid_t uid, gid_t gid)
/* Check if we have write access to /dev/clockctl */ /* Check if we have write access to /dev/clockctl */
fd = open("/dev/clockctl", O_WRONLY); fd = open("/dev/clockctl", O_WRONLY);
if (fd < 0) if (fd < 0)
LOG_FATAL(LOGF_SysNetBSD, "Can't write to /dev/clockctl"); LOG_FATAL("Can't write to /dev/clockctl");
close(fd); close(fd);
#endif #endif
} }

8
sys_timex.c
View file

@ -119,7 +119,7 @@ set_leap(int leap)
SYS_Timex_Adjust(&txc, 0); SYS_Timex_Adjust(&txc, 0);
LOG(LOGS_INFO, LOGF_SysTimex, "System clock status %s leap second", LOG(LOGS_INFO, "System clock status %s leap second",
leap ? (leap > 0 ? "set to insert" : "set to delete") : leap ? (leap > 0 ? "set to insert" : "set to delete") :
(applied ? "reset after" : "set to not insert/delete")); (applied ? "reset after" : "set to not insert/delete"));
} }
@ -239,11 +239,9 @@ SYS_Timex_Adjust(struct timex *txc, int ignore_error)
if (state < 0) { if (state < 0) {
if (!ignore_error) if (!ignore_error)
LOG_FATAL(LOGF_SysTimex, NTP_ADJTIME_NAME"(0x%x) failed : %s", LOG_FATAL(NTP_ADJTIME_NAME"(0x%x) failed : %s", txc->modes, strerror(errno));
txc->modes, strerror(errno));
else else
DEBUG_LOG(LOGF_SysTimex, NTP_ADJTIME_NAME"(0x%x) failed : %s", DEBUG_LOG(NTP_ADJTIME_NAME"(0x%x) failed : %s", txc->modes, strerror(errno));
txc->modes, strerror(errno));
} }
return state; return state;

14
tempcomp.c
View file

@ -92,7 +92,7 @@ read_timeout(void *arg)
if (fabs(comp) <= MAX_COMP) { if (fabs(comp) <= MAX_COMP) {
comp = LCL_SetTempComp(comp); comp = LCL_SetTempComp(comp);
DEBUG_LOG(LOGF_TempComp, "tempcomp updated to %f for %f", comp, temp); DEBUG_LOG("tempcomp updated to %f for %f", comp, temp);
if (logfileid != -1) { if (logfileid != -1) {
struct timespec now; struct timespec now;
@ -102,13 +102,11 @@ read_timeout(void *arg)
UTI_TimeToLogForm(now.tv_sec), temp, comp); UTI_TimeToLogForm(now.tv_sec), temp, comp);
} }
} else { } else {
LOG(LOGS_WARN, LOGF_TempComp, LOG(LOGS_WARN, "Temperature compensation of %.3f ppm exceeds sanity limit of %.1f",
"Temperature compensation of %.3f ppm exceeds sanity limit of %.1f",
comp, MAX_COMP); comp, MAX_COMP);
} }
} else { } else {
LOG(LOGS_WARN, LOGF_TempComp, "Could not read temperature from %s", LOG(LOGS_WARN, "Could not read temperature from %s", filename);
filename);
} }
if (f) if (f)
@ -126,7 +124,7 @@ read_points(const char *filename)
f = fopen(filename, "r"); f = fopen(filename, "r");
if (!f) { if (!f) {
LOG_FATAL(LOGF_TempComp, "Could not open tempcomp point file %s", filename); LOG_FATAL("Could not open tempcomp point file %s", filename);
return; return;
} }
@ -135,7 +133,7 @@ read_points(const char *filename)
while (fgets(line, sizeof (line), f)) { while (fgets(line, sizeof (line), f)) {
p = (struct Point *)ARR_GetNewElement(points); p = (struct Point *)ARR_GetNewElement(points);
if (sscanf(line, "%lf %lf", &p->temp, &p->comp) != 2) { if (sscanf(line, "%lf %lf", &p->temp, &p->comp) != 2) {
LOG_FATAL(LOGF_TempComp, "Could not read tempcomp point from %s", filename); LOG_FATAL("Could not read tempcomp point from %s", filename);
break; break;
} }
} }
@ -143,7 +141,7 @@ read_points(const char *filename)
fclose(f); fclose(f);
if (ARR_GetSize(points) < 2) if (ARR_GetSize(points) < 2)
LOG_FATAL(LOGF_TempComp, "Not enough points in %s", filename); LOG_FATAL("Not enough points in %s", filename);
} }
void void

30
util.c
View file

@ -1038,25 +1038,25 @@ create_dir(char *p, mode_t mode, uid_t uid, gid_t gid)
if (status < 0) { if (status < 0) {
if (errno != ENOENT) { if (errno != ENOENT) {
LOG(LOGS_ERR, LOGF_Util, "Could not access %s : %s", p, strerror(errno)); LOG(LOGS_ERR, "Could not access %s : %s", p, strerror(errno));
return 0; return 0;
} }
} else { } else {
if (S_ISDIR(buf.st_mode)) if (S_ISDIR(buf.st_mode))
return 1; return 1;
LOG(LOGS_ERR, LOGF_Util, "%s is not directory", p); LOG(LOGS_ERR, "%s is not directory", p);
return 0; return 0;
} }
/* Create the directory */ /* Create the directory */
if (mkdir(p, mode) < 0) { if (mkdir(p, mode) < 0) {
LOG(LOGS_ERR, LOGF_Util, "Could not create directory %s : %s", p, strerror(errno)); LOG(LOGS_ERR, "Could not create directory %s : %s", p, strerror(errno));
return 0; return 0;
} }
/* Set its owner */ /* Set its owner */
if (chown(p, uid, gid) < 0) { if (chown(p, uid, gid) < 0) {
LOG(LOGS_ERR, LOGF_Util, "Could not change ownership of %s : %s", p, strerror(errno)); LOG(LOGS_ERR, "Could not change ownership of %s : %s", p, strerror(errno));
/* Don't leave it there with incorrect ownership */ /* Don't leave it there with incorrect ownership */
rmdir(p); rmdir(p);
return 0; return 0;
@ -1125,27 +1125,27 @@ UTI_CheckDirPermissions(const char *path, mode_t perm, uid_t uid, gid_t gid)
struct stat buf; struct stat buf;
if (stat(path, &buf)) { if (stat(path, &buf)) {
LOG(LOGS_ERR, LOGF_Util, "Could not access %s : %s", path, strerror(errno)); LOG(LOGS_ERR, "Could not access %s : %s", path, strerror(errno));
return 0; return 0;
} }
if (!S_ISDIR(buf.st_mode)) { if (!S_ISDIR(buf.st_mode)) {
LOG(LOGS_ERR, LOGF_Util, "%s is not directory", path); LOG(LOGS_ERR, "%s is not directory", path);
return 0; return 0;
} }
if ((buf.st_mode & 0777) & ~perm) { if ((buf.st_mode & 0777) & ~perm) {
LOG(LOGS_ERR, LOGF_Util, "Wrong permissions on %s", path); LOG(LOGS_ERR, "Wrong permissions on %s", path);
return 0; return 0;
} }
if (buf.st_uid != uid) { if (buf.st_uid != uid) {
LOG(LOGS_ERR, LOGF_Util, "Wrong owner of %s (%s != %d)", path, "UID", uid); LOG(LOGS_ERR, "Wrong owner of %s (%s != %d)", path, "UID", uid);
return 0; return 0;
} }
if (buf.st_gid != gid) { if (buf.st_gid != gid) {
LOG(LOGS_ERR, LOGF_Util, "Wrong owner of %s (%s != %d)", path, "GID", gid); LOG(LOGS_ERR, "Wrong owner of %s (%s != %d)", path, "GID", gid);
return 0; return 0;
} }
@ -1159,17 +1159,17 @@ UTI_DropRoot(uid_t uid, gid_t gid)
{ {
/* Drop supplementary groups */ /* Drop supplementary groups */
if (setgroups(0, NULL)) if (setgroups(0, NULL))
LOG_FATAL(LOGF_Util, "setgroups() failed : %s", strerror(errno)); LOG_FATAL("setgroups() failed : %s", strerror(errno));
/* Set effective, saved and real group ID */ /* Set effective, saved and real group ID */
if (setgid(gid)) if (setgid(gid))
LOG_FATAL(LOGF_Util, "setgid(%d) failed : %s", gid, strerror(errno)); LOG_FATAL("setgid(%d) failed : %s", gid, strerror(errno));
/* Set effective, saved and real user ID */ /* Set effective, saved and real user ID */
if (setuid(uid)) if (setuid(uid))
LOG_FATAL(LOGF_Util, "setuid(%d) failed : %s", uid, strerror(errno)); LOG_FATAL("setuid(%d) failed : %s", uid, strerror(errno));
DEBUG_LOG(LOGF_Util, "Dropped root privileges: UID %d GID %d", uid, gid); DEBUG_LOG("Dropped root privileges: UID %d GID %d", uid, gid);
} }
/* ================================================== */ /* ================================================== */
@ -1184,9 +1184,9 @@ UTI_GetRandomBytesUrandom(void *buf, unsigned int len)
if (!f) if (!f)
f = fopen(DEV_URANDOM, "r"); f = fopen(DEV_URANDOM, "r");
if (!f) if (!f)
LOG_FATAL(LOGF_Util, "Can't open %s : %s", DEV_URANDOM, strerror(errno)); LOG_FATAL("Can't open %s : %s", DEV_URANDOM, strerror(errno));
if (fread(buf, 1, len, f) != len) if (fread(buf, 1, len, f) != len)
LOG_FATAL(LOGF_Util, "Can't read from %s", DEV_URANDOM); LOG_FATAL("Can't read from %s", DEV_URANDOM);
} }
/* ================================================== */ /* ================================================== */