Slightly unified C example's logging

Signed-off-by: Toni Uhlig <matzeton@googlemail.com>
This commit is contained in:
Toni Uhlig
2024-11-04 12:48:36 +01:00
parent d5a84ce630
commit f7933d0fdb
6 changed files with 95 additions and 99 deletions

View File

@@ -512,6 +512,7 @@ if(BUILD_EXAMPLES)
if(BUILD_NDPI)
add_dependencies(nDPIsrvd-notifyd libnDPI)
endif()
target_compile_definitions(nDPIsrvd-notifyd PRIVATE ${NDPID_DEFS})
target_include_directories(nDPIsrvd-notifyd PRIVATE
"${STATIC_LIBNDPI_INC}" "${DEFAULT_NDPI_INCLUDE}" "${CMAKE_SOURCE_DIR}" "${NDPID_DEPS_INC}"
"${DBUS_INCLUDE_DIRS}")
@@ -524,6 +525,7 @@ if(BUILD_EXAMPLES)
if(BUILD_NDPI)
add_dependencies(nDPIsrvd-influxd libnDPI)
endif()
target_compile_definitions(nDPIsrvd-influxd PRIVATE ${NDPID_DEFS})
target_include_directories(nDPIsrvd-influxd PRIVATE
"${STATIC_LIBNDPI_INC}" "${DEFAULT_NDPI_INCLUDE}" "${CMAKE_SOURCE_DIR}" "${NDPID_DEPS_INC}"
"${CURL_INCLUDE_DIRS}")

View File

@@ -367,9 +367,8 @@ void nDPIsrvd_memprof_log(char const * const format, ...)
va_list ap;
va_start(ap, format);
fprintf(stderr, "%s", "nDPIsrvd MemoryProfiler: ");
vfprintf(stderr, format, ap);
fprintf(stderr, "%s\n", "");
logger(0, "%s", "nDPIsrvd MemoryProfiler: ");
vlogger(0, format, ap);
va_end(ap);
}
#endif
@@ -386,30 +385,30 @@ static void nDPIsrvd_write_flow_info_cb(struct nDPIsrvd_socket const * sock,
if (flow == NULL || thread_data == NULL)
{
fprintf(stderr, "%s\n", "[WriteFlowInfoCallback] BUG: Internal error.");
logger(0, "%s", "[WriteFlowInfoCallback] BUG: Internal error.");
return;
}
fprintf(stderr,
"[Thread %2d][Flow %5llu][ptr: "
logger(0,
"[Thread %2d][Flow %5llu][ptr: "
#ifdef __LP64__
"0x%016llx"
"0x%016llx"
#else
"0x%08lx"
"0x%08lx"
#endif
"][last-seen: %13llu][idle-time: %7llu][time-until-timeout: %7llu]\n",
flow->thread_id,
flow->id_as_ull,
"][last-seen: %13llu][idle-time: %7llu][time-until-timeout: %7llu]",
flow->thread_id,
flow->id_as_ull,
#ifdef __LP64__
(unsigned long long int)flow,
(unsigned long long int)flow,
#else
(unsigned long int)flow,
(unsigned long int)flow,
#endif
flow->last_seen,
flow->idle_time,
(flow->last_seen + flow->idle_time >= thread_data->most_recent_flow_time
? flow->last_seen + flow->idle_time - thread_data->most_recent_flow_time
: 0));
flow->last_seen,
flow->idle_time,
(flow->last_seen + flow->idle_time >= thread_data->most_recent_flow_time
? flow->last_seen + flow->idle_time - thread_data->most_recent_flow_time
: 0));
}
static void nDPIsrvd_verify_flows_cb(struct nDPIsrvd_thread_data const * const thread_data,
@@ -422,25 +421,25 @@ static void nDPIsrvd_verify_flows_cb(struct nDPIsrvd_thread_data const * const t
{
if (flow->last_seen + flow->idle_time >= thread_data->most_recent_flow_time)
{
fprintf(stderr,
"Thread %d / %d, Flow %llu verification failed\n",
thread_data->thread_key,
flow->thread_id,
flow->id_as_ull);
logger(1,
"Thread %d / %d, Flow %llu verification failed",
thread_data->thread_key,
flow->thread_id,
flow->id_as_ull);
}
else
{
fprintf(stderr,
"Thread %d / %d, Flow %llu verification failed, diff: %llu\n",
thread_data->thread_key,
flow->thread_id,
flow->id_as_ull,
thread_data->most_recent_flow_time - flow->last_seen + flow->idle_time);
logger(1,
"Thread %d / %d, Flow %llu verification failed, diff: %llu",
thread_data->thread_key,
flow->thread_id,
flow->id_as_ull,
thread_data->most_recent_flow_time - flow->last_seen + flow->idle_time);
}
}
else
{
fprintf(stderr, "Thread [UNKNOWN], Flow %llu verification failed\n", flow->id_as_ull);
logger(1, "Thread [UNKNOWN], Flow %llu verification failed", flow->id_as_ull);
}
}
@@ -458,13 +457,13 @@ static void sighandler(int signum)
{
if (nDPIsrvd_verify_flows(current_instance, nDPIsrvd_verify_flows_cb, NULL) != 0)
{
fprintf(stderr, "Flow verification failed for instance %d\n", current_instance->alias_source_key);
logger(1, "Flow verification failed for instance %d", current_instance->alias_source_key);
verification_failed = 1;
}
}
if (verification_failed == 0)
{
fprintf(stderr, "%s\n", "Flow verification succeeded.");
logger(1, "%s", "Flow verification succeeded.");
}
else
{
@@ -1351,8 +1350,9 @@ static void print_usage(char const * const arg0)
{
static char const usage[] =
"Usage: %s "
"[-d] [-p pidfile] [-s host]\n"
"[-l] [-d] [-p pidfile] [-s host]\n"
"\t \t[-u user] [-g group] [-o csv-outfile] [-O csv-outfile]\n\n"
"\t-l\tLog to console instead of syslog.\n"
"\t-d\tForking into background after initialization.\n"
"\t-p\tWrite the daemon PID to the given file path.\n"
"\t-s\tDestination where nDPIsrvd is listening on.\n"
@@ -1370,10 +1370,13 @@ static int parse_options(int argc, char ** argv)
{
int opt;
while ((opt = getopt(argc, argv, "hdp:s:u:g:o:O:t:")) != -1)
while ((opt = getopt(argc, argv, "hldp:s:u:g:o:O:t:")) != -1)
{
switch (opt)
{
case 'l':
enable_console_logger();
break;
case 'd':
daemonize_enable();
break;
@@ -1413,9 +1416,9 @@ static int parse_options(int argc, char ** argv)
if (csv_outfile == NULL && stats_csv_outfile == NULL)
{
fprintf(stderr,
"%s: Missing either analyse CSV output file (`-o') or global stats CSV output file (`-O')\n",
argv[0]);
logger_early(1,
"%s: Missing either analyse CSV output file (`-o') or global stats CSV output file (`-O')",
argv[0]);
return 1;
}
@@ -1430,7 +1433,7 @@ static int parse_options(int argc, char ** argv)
csv_fp = fopen(csv_outfile, "a+");
if (csv_fp == NULL)
{
fprintf(stderr, "%s: Could not open file `%s' for appending: %s\n", argv[0], csv_outfile, strerror(errno));
logger_early(1, "%s: Could not open file `%s' for appending: %s", argv[0], csv_outfile, strerror(errno));
return 1;
}
@@ -1468,11 +1471,8 @@ static int parse_options(int argc, char ** argv)
stats_csv_fp = fopen(stats_csv_outfile, "a+");
if (stats_csv_fp == NULL)
{
fprintf(stderr,
"%s: Could not open file `%s' for appending: %s\n",
argv[0],
stats_csv_outfile,
strerror(errno));
logger_early(
1, "%s: Could not open file `%s' for appending: %s", argv[0], stats_csv_outfile, strerror(errno));
return 1;
}
@@ -1537,7 +1537,7 @@ static int parse_options(int argc, char ** argv)
if (optind < argc)
{
fprintf(stderr, "Unexpected argument after options\n\n");
logger_early(1, "%s", "Unexpected argument after options");
print_usage(argv[0]);
return 1;
}
@@ -1988,12 +1988,12 @@ int main(int argc, char ** argv)
if (nDPIsrvd_setup_address(&distributor->address, serv_optarg) != 0)
{
fprintf(stderr, "%s: Could not parse address `%s'\n", argv[0], serv_optarg);
logger_early(1, "%s: Could not parse address `%s'\n", argv[0], serv_optarg);
goto failure;
}
printf("Recv buffer size: %u\n", NETWORK_BUFFER_MAX_SIZE);
printf("Connecting to `%s'..\n", serv_optarg);
logger(0, "Recv buffer size: %u", NETWORK_BUFFER_MAX_SIZE);
logger(0, "Connecting to `%s'..", serv_optarg);
if (nDPIsrvd_connect(distributor) != CONNECT_OK)
{

View File

@@ -1503,8 +1503,8 @@ int main(int argc, char ** argv)
if (getenv("COLLECTD_HOSTNAME") == NULL && getenv("COLLECTD_INTERVAL") == NULL)
{
LOGGER_EARLY(0, "Recv buffer size: %u", NETWORK_BUFFER_MAX_SIZE);
LOGGER_EARLY(0, "Connecting to `%s'..", serv_optarg);
logger(0, "Recv buffer size: %u", NETWORK_BUFFER_MAX_SIZE);
logger(0, "Connecting to `%s'..", serv_optarg);
}
else
{

View File

@@ -366,9 +366,8 @@ void nDPIsrvd_memprof_log(char const * const format, ...)
va_list ap;
va_start(ap, format);
fprintf(stderr, "%s", "nDPIsrvd MemoryProfiler: ");
vfprintf(stderr, format, ap);
fprintf(stderr, "%s\n", "");
logger(0, "%s", "nDPIsrvd MemoryProfiler: ");
vlogger(0, format, ap);
va_end(ap);
}
#endif
@@ -1549,7 +1548,7 @@ static int parse_options(int argc, char ** argv, struct nDPIsrvd_socket * const
if (test_mode != 0)
{
logger_early(1, "%s", "Test mode enabled: ignoring `-U' / `-T' command line parameters");
logger(1, "%s", "Test mode enabled: ignoring `-U' / `-T' command line parameters");
free(influxdb_url);
free(influxdb_token);
influxdb_url = NULL;
@@ -1600,8 +1599,7 @@ static int parse_options(int argc, char ** argv, struct nDPIsrvd_socket * const
if (optind < argc)
{
logger_early(1, "%s", "Unexpected argument after options");
logger_early(1, "%s", "");
logger_early(1, usage, argv[0]);
fprintf(stderr, usage, argv[0]);
return 1;
}
@@ -1638,26 +1636,29 @@ int main(int argc, char ** argv)
goto failure;
}
logger_early(0, "Recv buffer size: %u", NETWORK_BUFFER_MAX_SIZE);
logger_early(0, "Connecting to `%s'..", serv_optarg);
logger_early(0, "InfluxDB push URL: %s", influxdb_url);
if (test_mode == 0)
{
logger(0, "Recv buffer size: %u", NETWORK_BUFFER_MAX_SIZE);
logger(0, "Connecting to `%s'..", serv_optarg);
logger(0, "InfluxDB push URL: %s", influxdb_url);
}
if (setvbuf(stdout, NULL, _IONBF, 0) != 0)
{
logger_early(1,
"Could not set stdout unbuffered: %s. Collectd may receive too old PUTVALs and complain.",
strerror(errno));
logger(1,
"Could not set stdout unbuffered: %s. Collectd may receive too old PUTVALs and complain.",
strerror(errno));
}
if (nDPIsrvd_connect(sock) != CONNECT_OK)
{
logger_early(1, "nDPIsrvd socket connect to %s failed!", serv_optarg);
logger(1, "nDPIsrvd socket connect to %s failed!", serv_optarg);
goto failure;
}
if (nDPIsrvd_set_nonblock(sock) != 0)
{
logger_early(1, "nDPIsrvd set nonblock failed: %s", strerror(errno));
logger(1, "nDPIsrvd set nonblock failed: %s", strerror(errno));
goto failure;
}
@@ -1675,11 +1676,11 @@ int main(int argc, char ** argv)
{
if (errno != 0)
{
logger_early(1, "Change user/group failed: %s", strerror(errno));
logger(1, "Change user/group failed: %s", strerror(errno));
}
else
{
logger_early(1, "%s", "Change user/group failed.");
logger(1, "%s", "Change user/group failed.");
}
goto failure;
}
@@ -1687,13 +1688,13 @@ int main(int argc, char ** argv)
epollfd = epoll_create1(0);
if (epollfd < 0)
{
logger_early(1, "Error creating epoll: %s", strerror(errno));
logger(1, "Error creating epoll: %s", strerror(errno));
goto failure;
}
if (create_influxd_timer() != 0)
{
logger_early(1, "Error creating timer: %s", strerror(errno));
logger(1, "Error creating timer: %s", strerror(errno));
goto failure;
}
@@ -1701,7 +1702,7 @@ int main(int argc, char ** argv)
struct epoll_event timer_event = {.data.fd = influxd_timerfd, .events = EPOLLIN};
if (epoll_ctl(epollfd, EPOLL_CTL_ADD, influxd_timerfd, &timer_event) < 0)
{
logger_early(1, "Error adding JSON fd to epoll: %s", strerror(errno));
logger(1, "Error adding JSON fd to epoll: %s", strerror(errno));
goto failure;
}
}
@@ -1710,7 +1711,7 @@ int main(int argc, char ** argv)
struct epoll_event socket_event = {.data.fd = sock->fd, .events = EPOLLIN};
if (epoll_ctl(epollfd, EPOLL_CTL_ADD, sock->fd, &socket_event) < 0)
{
logger_early(1, "Error adding nDPIsrvd socket fd to epoll: %s", strerror(errno));
logger(1, "Error adding nDPIsrvd socket fd to epoll: %s", strerror(errno));
goto failure;
}
}
@@ -1719,10 +1720,9 @@ int main(int argc, char ** argv)
{
curl_global_init(CURL_GLOBAL_ALL);
}
logger_early(0, "%s", "Initialization succeeded.");
logger(0, "%s", "Initialization succeeded.");
retval = mainloop(epollfd, sock);
logger_early(0, "%s", "Bye.");
logger(0, "%s", "Bye.");
if (test_mode == 0)
{

View File

@@ -1,7 +1,6 @@
#include <dbus-1.0/dbus/dbus.h>
#include <signal.h>
#include <stdint.h>
#include <syslog.h>
#include "nDPIsrvd.h"
#include "utstring.h"
@@ -185,8 +184,7 @@ static void check_value(char const * const possible_values[],
{
if (get_value_index(possible_values, possible_values_size, needle, needle_len) == -1)
{
syslog(LOG_DAEMON | LOG_ERR, "BUG: Unknown value: %.*s", (int)needle_len, needle);
notifyf(DBUS_CRITICAL, "BUG", 5000, "Unknown value: %.*s", (int)needle_len, needle);
notifyf(DBUS_CRITICAL, "nDPIsrvd-notifyd", 5000, "BUG: Unknown value: %.*s", (int)needle_len, needle);
}
}
@@ -451,7 +449,7 @@ static int parse_options(int argc, char ** argv, struct nDPIsrvd_socket * const
{
int opt, force_defaults = 1;
while ((opt = getopt(argc, argv, "hdp:s:C:B:S:")) != -1)
while ((opt = getopt(argc, argv, "hldp:s:C:B:S:")) != -1)
{
switch (opt)
{
@@ -522,8 +520,7 @@ static int parse_options(int argc, char ** argv, struct nDPIsrvd_socket * const
if (force_defaults != 0 && set_defaults() != 0)
{
fprintf(stderr, "%s\n", "BUG: Could not set default values.");
syslog(LOG_DAEMON | LOG_ERR, "%s\n", "BUG: Could not set default values.");
notifyf(DBUS_CRITICAL, "nDPIsrvd-notifyd", 5000, "%s\n", "BUG: Could not set default values.");
return 1;
}
@@ -534,13 +531,13 @@ static int parse_options(int argc, char ** argv, struct nDPIsrvd_socket * const
if (nDPIsrvd_setup_address(&sock->address, serv_optarg) != 0)
{
syslog(LOG_DAEMON | LOG_ERR, "Could not parse address `%s'", serv_optarg);
notifyf(DBUS_CRITICAL, "nDPIsrvd-notifyd", 3000, "Could not parse address `%s'\n", serv_optarg);
return 1;
}
if (optind < argc)
{
syslog(LOG_DAEMON | LOG_ERR, "%s", "Unexpected argument after options");
notifyf(DBUS_CRITICAL, "nDPIsrvd-notifyd", 3000, "%s\n", "Unexpected argument after options");
return 1;
}
@@ -571,13 +568,11 @@ int main(int argc, char ** argv)
signal(SIGTERM, sighandler);
signal(SIGPIPE, SIG_IGN);
openlog("nDPIsrvd-notifyd", LOG_CONS, LOG_DAEMON);
struct nDPIsrvd_socket * sock =
nDPIsrvd_socket_init(0, 0, 0, sizeof(struct flow_user_data), notifyd_json_callback, NULL, NULL);
if (sock == NULL)
{
syslog(LOG_DAEMON | LOG_ERR, "%s", "nDPIsrvd socket memory allocation failed!");
notifyf(DBUS_CRITICAL, "nDPIsrvd-notifyd", 5000, "%s\n", "BUG: nDPIsrvd socket memory allocation failed!");
return 1;
}
@@ -602,8 +597,8 @@ int main(int argc, char ** argv)
}
if (previous_connect_succeeded != 0)
{
notifyf(DBUS_CRITICAL, "nDPIsrvd-notifyd", 3000, "nDPIsrvd socket connect to %s failed!", serv_optarg);
syslog(LOG_DAEMON | LOG_ERR, "nDPIsrvd socket connect to %s failed!", serv_optarg);
notifyf(
DBUS_CRITICAL, "nDPIsrvd-notifyd", 3000, "nDPIsrvd socket connect to %s failed!\n", serv_optarg);
previous_connect_succeeded = 0;
}
nDPIsrvd_socket_close(sock);
@@ -614,12 +609,11 @@ int main(int argc, char ** argv)
if (nDPIsrvd_set_read_timeout(sock, 3, 0) != 0)
{
syslog(LOG_DAEMON | LOG_ERR, "nDPIsrvd set read timeout failed: %s", strerror(errno));
notifyf(DBUS_CRITICAL, "nDPIsrvd-notifyd", 3000, "nDPIsrvd set read timeout failed: %s\n", strerror(errno));
goto failure;
}
notifyf(DBUS_NORMAL, "nDPIsrvd-notifyd", 3000, "Connected to '%s'", serv_optarg);
syslog(LOG_DAEMON | LOG_NOTICE, "%s", "Initialization succeeded.");
notifyf(DBUS_NORMAL, "nDPIsrvd-notifyd", 3000, "Connected to '%s'\n", serv_optarg);
while (main_thread_shutdown == 0)
{
@@ -634,25 +628,26 @@ int main(int argc, char ** argv)
}
if (read_ret != READ_OK)
{
notifyf(DBUS_CRITICAL, "nDPIsrvd-notifyd", 3000, "nDPIsrvd socket read from %s failed!", serv_optarg);
syslog(LOG_DAEMON | LOG_ERR, "nDPIsrvd socket read from %s failed!", serv_optarg);
notifyf(DBUS_CRITICAL, "nDPIsrvd-notifyd", 3000, "nDPIsrvd socket read from %s failed!\n", serv_optarg);
break;
}
enum nDPIsrvd_parse_return parse_ret = nDPIsrvd_parse_all(sock);
if (parse_ret != PARSE_NEED_MORE_DATA)
{
syslog(LOG_DAEMON | LOG_ERR,
"Could not parse JSON message %s: %.*s\n",
nDPIsrvd_enum_to_string(parse_ret),
nDPIsrvd_json_buffer_length(sock),
nDPIsrvd_json_buffer_string(sock));
notifyf(DBUS_CRITICAL,
"nDPIsrvd-notifyd",
3000,
"Could not parse JSON message %s: %.*s\n",
nDPIsrvd_enum_to_string(parse_ret),
nDPIsrvd_json_buffer_length(sock),
nDPIsrvd_json_buffer_string(sock));
break;
}
}
nDPIsrvd_socket_close(sock);
notifyf(DBUS_NORMAL, "nDPIsrvd-notifyd", 3000, "Disconnected from '%s'.", serv_optarg);
notifyf(DBUS_NORMAL, "nDPIsrvd-notifyd", 3000, "Disconnected from '%s'.\n", serv_optarg);
if (main_thread_shutdown == 0)
{
sleep(SLEEP_TIME_IN_S);
@@ -662,7 +657,6 @@ int main(int argc, char ** argv)
failure:
nDPIsrvd_socket_free(&sock);
daemonize_shutdown(pidfile);
closelog();
return 0;
}

View File

@@ -321,7 +321,7 @@ if [ -x "${NDPISRVD_ANALYSED}" ]; then
cat "${out_file}" | grep -vE '^~~.*$' | ${NETCAT_EXEC} &
nc_pid=$!
while ! ss -x -t -n -l | grep -q "${NETCAT_SOCK}"; do sleep 0.1; printf '%s\n' "Waiting until socket ${NETCAT_SOCK} is available.." >>"${stderr_file}"; done
${NDPISRVD_ANALYSED} -s "${NETCAT_SOCK}" -o "${stdout_file}" 2>>"${stderr_file}" 1>&2
${NDPISRVD_ANALYSED} -l -s "${NETCAT_SOCK}" -o "${stdout_file}" 2>>"${stderr_file}" 1>&2
kill -SIGTERM ${nc_pid} 2>/dev/null
wait ${nc_pid} 2>/dev/null
while ss -x -t -n -l | grep -q "${NETCAT_SOCK}"; do sleep 0.1; printf '%s\n' "Waiting until socket ${NETCAT_SOCK} is not available anymore.." >>"${stderr_file}"; done
@@ -450,7 +450,7 @@ if [ -x "${NDPISRVD_COLLECTD}" ]; then
cat "${out_file}" | grep -vE '^~~.*$' | ${NETCAT_EXEC} &
nc_pid=$!
while ! ss -x -t -n -l | grep -q "${NETCAT_SOCK}"; do sleep 0.1; printf '%s\n' "Waiting until socket ${NETCAT_SOCK} is available.." >>"${stderr_file}"; done
${NDPISRVD_COLLECTD} -s "${NETCAT_SOCK}" 2>>"${stderr_file}" 1>"${stdout_file}"
${NDPISRVD_COLLECTD} -l -s "${NETCAT_SOCK}" 2>>"${stderr_file}" 1>"${stdout_file}"
kill -SIGTERM ${nc_pid} 2>/dev/null
wait ${nc_pid} 2>/dev/null
while ss -x -t -n -l | grep -q "${NETCAT_SOCK}"; do sleep 0.1; printf '%s\n' "Waiting until socket ${NETCAT_SOCK} is not available anymore.." >>"${stderr_file}"; done