Refactor our logging and extend the wslog API

Experience has shown that:

  1. The current logging methods are not very reliable or practical.
A logging bitmask makes little sense as the user-facing interface (who
would want debug but not crtical messages for example?); it's
computer-friendly and user-unfriendly. More importantly the console
log level preference is initialized too late in the startup process
to be used for the logging subsystem and that fact raises a number
of annoying and hard-to-fix usability issues.

  2. Coding around G_MESSAGES_DEBUG to comply with our log level mask
and not clobber the user's settings or not create unexpected log misses
is unworkable and generally follows the principle of most surprise.
The fact that G_MESSAGES_DEBUG="all" can leak to other programs using
GLib is also annoying.

  3. The non-structured GLib logging API is very opinionated and lacks
configurability beyond replacing the log handler.

  4. Windows GUI has some special code to attach to a console,
but it would be nice to abstract away the rest under a single
interface.

  5. Using this logger seems to be noticeably faster.

Deprecate the console log level preference and extend our API to
implement a log handler in wsutil/wslog.h to provide easy-to-use,
flexible and dependable logging during all execution phases.

Log levels have a hierarchy, from most verbose to least verbose
(debug to error). When a given level is set everything above that
is also enabled.

The log level can be set with an environment variable or a command
line option (parsed as soon as possible but still later than the
environment). The default log level is "message".

Dissector logging is not included because it is not clear what log
domain they should use. An explosion to thousands of domains is
not desirable and putting everything in a single domain is probably
too coarse and noisy. For now I think it makes sense to let them do
their own thing using g_log_default_handler() and continue using the
G_MESSAGES_DEBUG mechanism with specific domains for each individual
dissector.

In the future a mechanism may be added to selectively enable these
domains at runtime while trying to avoid the problems introduced
by G_MESSAGES_DEBUG.
pespin/rlcmac
João Valverde 2021-06-08 02:46:52 +01:00 committed by Wireshark GitLab Utility
parent c0f8812c31
commit dc7f0b88bb
57 changed files with 1118 additions and 1003 deletions

View File

@ -3374,10 +3374,10 @@ set(SHARK_PUBLIC_HEADERS
cli_main.h
file.h
globals.h
log.h
ws_attributes.h
ws_compiler_tests.h
ws_diag_control.h
ws_log_domains.h
ws_symbol_export.h
version_info.h
${CMAKE_BINARY_DIR}/ws_version.h

View File

@ -9,6 +9,7 @@
*/
#include "config.h"
#define WS_LOG_DOMAIN LOG_DOMAIN_CAPCHILD
#ifdef HAVE_LIBPCAP
@ -68,10 +69,9 @@
#include "capture/capture-pcap-util.h"
#include "capture/capture-pcap-util-int.h"
#include "log.h"
#include <wsutil/file_util.h>
#include <wsutil/please_report_bug.h>
#include <wsutil/wslog.h>
#ifndef _WIN32
#include <netinet/in.h>
@ -1275,23 +1275,19 @@ open_capture_device_pcap_create(
pcap_t *pcap_h;
int status;
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG,
"Calling pcap_create() using %s.", interface_opts->name);
ws_debug("Calling pcap_create() using %s.", interface_opts->name);
pcap_h = pcap_create(interface_opts->name, *open_err_str);
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG,
"pcap_create() returned %p.", (void *)pcap_h);
ws_debug("pcap_create() returned %p.", (void *)pcap_h);
if (pcap_h == NULL) {
*open_err = CAP_DEVICE_OPEN_ERR_NOT_PERMISSIONS;
return NULL;
}
if (interface_opts->has_snaplen) {
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG,
"Calling pcap_set_snaplen() with snaplen %d.",
ws_debug("Calling pcap_set_snaplen() with snaplen %d.",
interface_opts->snaplen);
pcap_set_snaplen(pcap_h, interface_opts->snaplen);
}
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG,
"Calling pcap_set_promisc() with promisc_mode %d.",
ws_debug("Calling pcap_set_promisc() with promisc_mode %d.",
interface_opts->promisc_mode);
pcap_set_promisc(pcap_h, interface_opts->promisc_mode);
pcap_set_timeout(pcap_h, timeout);
@ -1337,18 +1333,15 @@ open_capture_device_pcap_create(
}
#endif /* HAVE_PCAP_SET_TSTAMP_PRECISION */
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG,
"buffersize %d.", interface_opts->buffer_size);
ws_debug("buffersize %d.", interface_opts->buffer_size);
if (interface_opts->buffer_size != 0)
pcap_set_buffer_size(pcap_h,
interface_opts->buffer_size * 1024 * 1024);
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG,
"monitor_mode %d.", interface_opts->monitor_mode);
ws_debug("monitor_mode %d.", interface_opts->monitor_mode);
if (interface_opts->monitor_mode)
pcap_set_rfmon(pcap_h, 1);
status = pcap_activate(pcap_h);
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG,
"pcap_activate() returned %d.", status);
ws_debug("pcap_activate() returned %d.", status);
if (status < 0) {
/* Failed to activate, set to NULL */
if (status == PCAP_ERROR) {
@ -1424,13 +1417,11 @@ open_capture_device_pcap_open_live(interface_options *interface_opts,
*/
snaplen = 256*1024;
}
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG,
"pcap_open_live() calling using name %s, snaplen %d, promisc_mode %d.",
ws_debug("pcap_open_live() calling using name %s, snaplen %d, promisc_mode %d.",
interface_opts->name, snaplen, interface_opts->promisc_mode);
pcap_h = pcap_open_live(interface_opts->name, snaplen,
interface_opts->promisc_mode, timeout, *open_err_str);
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG,
"pcap_open_live() returned %p.", (void *)pcap_h);
ws_debug("pcap_open_live() returned %p.", (void *)pcap_h);
if (pcap_h == NULL) {
*open_err = CAP_DEVICE_OPEN_ERR_GENERIC;
return NULL;
@ -1538,7 +1529,7 @@ open_capture_device(capture_options *capture_opts,
Some versions of libpcap may put warnings into the error buffer
if they succeed; to tell if that's happened, we have to clear
the error buffer, and check if it's still a null string. */
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "Entering open_capture_device().");
ws_debug("Entering open_capture_device().");
*open_err = CAP_DEVICE_OPEN_NO_ERR;
(*open_err_str)[0] = '\0';
#if defined(HAVE_PCAP_OPEN) && defined(HAVE_PCAP_REMOTE)
@ -1563,8 +1554,7 @@ open_capture_device(capture_options *capture_opts,
*/
snaplen = 256*1024;
}
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG,
"Calling pcap_open() using name %s, snaplen %d, promisc_mode %d, datatx_udp %d, nocap_rpcap %d.",
ws_debug("Calling pcap_open() using name %s, snaplen %d, promisc_mode %d, datatx_udp %d, nocap_rpcap %d.",
interface_opts->name, snaplen,
interface_opts->promisc_mode, interface_opts->datatx_udp,
interface_opts->nocap_rpcap);
@ -1597,16 +1587,15 @@ open_capture_device(capture_options *capture_opts,
sizeof *open_err_str);
}
}
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG,
"pcap_open() returned %p.", (void *)pcap_h);
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "open_capture_device %s : %s", pcap_h ? "SUCCESS" : "FAILURE", interface_opts->name);
ws_debug("pcap_open() returned %p.", (void *)pcap_h);
ws_debug("open_capture_device %s : %s", pcap_h ? "SUCCESS" : "FAILURE", interface_opts->name);
return pcap_h;
}
#endif
pcap_h = open_capture_device_local(capture_opts, interface_opts,
timeout, open_err, open_err_str);
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "open_capture_device %s : %s", pcap_h ? "SUCCESS" : "FAILURE", interface_opts->name);
ws_debug("open_capture_device %s : %s", pcap_h ? "SUCCESS" : "FAILURE", interface_opts->name);
return pcap_h;
}

View File

@ -9,6 +9,7 @@
*/
#include "config.h"
#define WS_LOG_DOMAIN LOG_DOMAIN_CAPTURE
#ifdef HAVE_LIBPCAP
@ -23,7 +24,6 @@
#include "capture/capture_session.h"
#include "capture/capture_sync.h"
#include "extcap.h"
#include "log.h"
#include <capture/capture_ifinfo.h>
#include <wsutil/inet_addr.h>
@ -90,8 +90,6 @@ capture_interface_list(int *err, char **err_str, void (*update_cb)(void))
if_info_t *if_info;
if_addr_t *if_addr;
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_MESSAGE, "Capture Interface List ...");
*err = 0;
if (err_str) {
*err_str = NULL;
@ -101,12 +99,12 @@ capture_interface_list(int *err, char **err_str, void (*update_cb)(void))
ret = sync_interface_list_open(&data, &primary_msg, &secondary_msg, update_cb);
if (ret != 0) {
/* Add the extcap interfaces that can exist, even if no native interfaces have been found */
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_MESSAGE, "Loading External Capture Interface List ...");
ws_message("Loading External Capture Interface List ...");
if_list = append_extcap_interface_list(if_list, err_str);
/* err_str is ignored, as the error for the interface loading list will take precedence */
if ( g_list_length(if_list) == 0 ) {
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_MESSAGE, "Capture Interface List failed. Error %d, %s (%s)",
ws_message("Capture Interface List failed. Error %d, %s (%s)",
*err, primary_msg ? primary_msg : "no message",
secondary_msg ? secondary_msg : "no secondary message");
if (err_str) {
@ -185,7 +183,7 @@ capture_interface_list(int *err, char **err_str, void (*update_cb)(void))
#endif
/* Add the extcap interfaces after the native and remote interfaces */
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_MESSAGE, "Loading External Capture Interface List ...");
ws_message("Loading External Capture Interface List ...");
if_list = append_extcap_interface_list(if_list, err_str);
return if_list;
@ -205,8 +203,6 @@ capture_get_if_capabilities(const gchar *ifname, gboolean monitor_mode,
gchar *data, *primary_msg, *secondary_msg;
gchar **raw_list;
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_MESSAGE, "Capture Interface Capabilities ...");
/* see if the interface is from extcap */
caps = extcap_get_if_dlts(ifname, err_primary_msg);
if (caps != NULL)
@ -220,7 +216,7 @@ capture_get_if_capabilities(const gchar *ifname, gboolean monitor_mode,
err = sync_if_capabilities_open(ifname, monitor_mode, auth_string, &data,
&primary_msg, &secondary_msg, update_cb);
if (err != 0) {
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_MESSAGE, "Capture Interface Capabilities failed. Error %d, %s",
ws_message("Capture Interface Capabilities failed. Error %d, %s",
err, primary_msg ? primary_msg : "no message");
if (err_primary_msg)
*err_primary_msg = primary_msg;
@ -245,7 +241,7 @@ capture_get_if_capabilities(const gchar *ifname, gboolean monitor_mode,
* First line is 0 if monitor mode isn't supported, 1 if it is.
*/
if (raw_list[0] == NULL || *raw_list[0] == '\0') {
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_MESSAGE, "Capture Interface Capabilities returned no information.");
ws_message("Capture Interface Capabilities returned no information.");
if (err_primary_msg) {
*err_primary_msg = g_strdup("Dumpcap returned no interface capability information");
}
@ -268,7 +264,7 @@ capture_get_if_capabilities(const gchar *ifname, gboolean monitor_mode,
break;
default:
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_MESSAGE, "Capture Interface Capabilities returned bad information.");
ws_message("Capture Interface Capabilities returned bad information.");
if (err_primary_msg) {
*err_primary_msg = g_strdup_printf("Dumpcap returned \"%s\" for monitor-mode capability",
raw_list[0]);

View File

@ -9,6 +9,7 @@
*/
#include "config.h"
#define WS_LOG_DOMAIN LOG_DOMAIN_CAPTURE
#ifdef HAVE_LIBPCAP
@ -20,6 +21,7 @@
#include <signal.h>
#include <wsutil/strtoi.h>
#include <wsutil/wslog.h>
#ifdef _WIN32
#include <wsutil/unicode-utils.h>
@ -81,7 +83,6 @@
#include <wsutil/file_util.h>
#include <wsutil/report_message.h>
#include "extcap.h"
#include "log.h"
#ifdef _WIN32
#include <process.h> /* For spawning child process */
@ -230,8 +231,8 @@ sync_pipe_start(capture_options *capture_opts, capture_session *cap_session, inf
if (capture_opts->ifaces->len > 1)
capture_opts->use_pcapng = TRUE;
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG, "sync_pipe_start");
capture_opts_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG, capture_opts);
ws_debug("sync_pipe_start");
capture_opts_log(LOG_DOMAIN_CAPTURE, LOG_LEVEL_DEBUG, capture_opts);
cap_session->fork_child = WS_INVALID_PID;
@ -447,7 +448,7 @@ sync_pipe_start(capture_options *capture_opts, capture_session *cap_session, inf
argv = sync_pipe_add_arg(argv, &argc, capture_opts->save_file);
}
for (i = 0; i < argc; i++) {
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG, "argv[%d]: %s", i, argv[i]);
ws_debug("argv[%d]: %s", i, argv[i]);
}
if (capture_opts->compress_type) {
argv = sync_pipe_add_arg(argv, &argc, "--compress-type");
@ -682,7 +683,7 @@ sync_pipe_open_command(char* const argv[], int *data_read_fd,
*fork_child = WS_INVALID_PID;
*data_read_fd = -1;
*message_read_fd = -1;
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG, "sync_pipe_open_command");
ws_debug("sync_pipe_open_command");
if (!msg) {
/* We can't return anything */
@ -1096,21 +1097,21 @@ sync_pipe_run_command(char* const argv[], gchar **data, gchar **primary_msg,
int logging_enabled;
/* check if logging is actually enabled, otherwise don't expend the CPU generating logging */
logging_enabled=( (G_LOG_LEVEL_DEBUG | G_LOG_LEVEL_INFO) & G_LOG_LEVEL_MASK & prefs.console_log_level);
if(logging_enabled){
logging_enabled = ws_log_level_is_active(LOG_LEVEL_INFO);
if (logging_enabled) {
start_time = g_get_monotonic_time();
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_INFO, "sync_pipe_run_command() starts");
for(i=0; argv[i] != 0; i++) {
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG, " argv[%d]: %s", i, argv[i]);
ws_info("sync_pipe_run_command() starts");
for (i=0; argv[i] != 0; i++) {
ws_debug(" argv[%d]: %s", i, argv[i]);
}
}
/* do the actual sync pipe run command */
ret=sync_pipe_run_command_actual(argv, data, primary_msg, secondary_msg, update_cb);
ret = sync_pipe_run_command_actual(argv, data, primary_msg, secondary_msg, update_cb);
if(logging_enabled){
if (logging_enabled) {
elapsed = (g_get_monotonic_time() - start_time) / 1e6;
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_INFO, "sync_pipe_run_command() ends, taking %.3fs, result=%d", elapsed, ret);
ws_info("sync_pipe_run_command() ends, taking %.3fs, result=%d", elapsed, ret);
}
return ret;
@ -1191,7 +1192,7 @@ sync_interface_list_open(gchar **data, gchar **primary_msg,
char **argv;
int ret;
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG, "sync_interface_list_open");
ws_debug("sync_interface_list_open");
argv = init_pipe_args(&argc);
@ -1236,7 +1237,7 @@ sync_if_capabilities_open(const gchar *ifname, gboolean monitor_mode, const gcha
char **argv;
int ret;
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG, "sync_if_capabilities_open");
ws_debug("sync_if_capabilities_open");
argv = init_pipe_args(&argc);
@ -1291,7 +1292,7 @@ sync_interface_stats_open(int *data_read_fd, ws_process_id *fork_child, gchar **
/*char *secondary_msg_text;*/
char *combined_msg;
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG, "sync_interface_stats_open");
ws_debug("sync_interface_stats_open");
argv = init_pipe_args(&argc);
@ -1456,17 +1457,14 @@ pipe_read_bytes(int pipe_fd, char *bytes, int required, char **msg)
newly = ws_read(pipe_fd, &bytes[offset], required);
if (newly == 0) {
/* EOF */
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG,
"read from pipe %d: EOF (capture closed?)", pipe_fd);
ws_debug("read from pipe %d: EOF (capture closed?)", pipe_fd);
*msg = 0;
return offset;
}
if (newly < 0) {
/* error */
error = errno;
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG,
"read from pipe %d: error(%u): %s", pipe_fd, error,
g_strerror(error));
ws_debug("read from pipe %d: error(%u): %s", pipe_fd, error, g_strerror(error));
*msg = g_strdup_printf("Error reading from sync pipe: %s",
g_strerror(error));
return newly;
@ -1501,8 +1499,7 @@ sync_pipe_gets_nonblock(int pipe_fd, char *bytes, int max) {
break;
} else if (newly == -1) {
/* error */
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG,
"read from pipe %d: error(%u): %s", pipe_fd, errno, g_strerror(errno));
ws_debug("read from pipe %d: error(%u): %s", pipe_fd, errno, g_strerror(errno));
return -1;
} else if (bytes[offset] == '\n') {
break;
@ -1547,12 +1544,10 @@ pipe_read_block(int pipe_fd, char *indicator, int len, char *msg,
* is an "I'm done" indication, so don't report it as an
* error.
*/
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG,
"read %d got an EOF", pipe_fd);
ws_debug("read %d got an EOF", pipe_fd);
return 0;
}
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG,
"read %d failed to read header: %lu", pipe_fd, (long)newly);
ws_debug("read %d failed to read header: %lu", pipe_fd, (long)newly);
if (newly != -1) {
/*
* Short read, but not an immediate EOF.
@ -1568,15 +1563,13 @@ pipe_read_block(int pipe_fd, char *indicator, int len, char *msg,
/* only indicator with no value? */
if(required == 0) {
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG,
"read %d indicator: %c empty value", pipe_fd, *indicator);
ws_debug("read %d indicator: %c empty value", pipe_fd, *indicator);
return 4;
}
/* does the data fit into the given buffer? */
if(required > len) {
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG,
"read %d length error, required %d > len %d, header: 0x%02x 0x%02x 0x%02x 0x%02x",
ws_debug("read %d length error, required %d > len %d, header: 0x%02x 0x%02x 0x%02x 0x%02x",
pipe_fd, required, len,
header[0], header[1], header[2], header[3]);
@ -1584,8 +1577,7 @@ pipe_read_block(int pipe_fd, char *indicator, int len, char *msg,
memcpy(msg, header, sizeof(header));
newly = ws_read(pipe_fd, &msg[sizeof(header)], len-sizeof(header));
if (newly < 0) { /* error */
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG,
"read from pipe %d: error(%u): %s", pipe_fd, errno, g_strerror(errno));
ws_debug("read from pipe %d: error(%u): %s", pipe_fd, errno, g_strerror(errno));
}
*err_msg = g_strdup_printf("Unknown message from dumpcap reading header, try to show it as a string: %s",
msg);
@ -1604,9 +1596,7 @@ pipe_read_block(int pipe_fd, char *indicator, int len, char *msg,
}
/* XXX If message is "2part", the msg probably won't be sent to debug log correctly */
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG,
"read %d ok indicator: %c len: %u msg: %s", pipe_fd, *indicator,
len, msg);
ws_debug("read %d ok indicator: %c len: %u msg: %s", pipe_fd, *indicator, len, msg);
*err_msg = NULL;
return newly + 4;
}
@ -1672,7 +1662,7 @@ sync_pipe_input_cb(gint source, gpointer user_data)
#ifdef _WIN32
ws_close(cap_session->signal_pipe_write_fd);
#endif
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG, "sync_pipe_input_cb: cleaning extcap pipe");
ws_debug("cleaning extcap pipe");
extcap_if_cleanup(cap_session->capture_opts, &primary_msg);
cap_session->closed(cap_session, primary_msg);
g_free(primary_msg);
@ -1683,7 +1673,7 @@ sync_pipe_input_cb(gint source, gpointer user_data)
switch(indicator) {
case SP_FILE:
if(!cap_session->new_file(cap_session, buffer)) {
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG, "sync_pipe_input_cb: file failed, closing capture");
ws_debug("file failed, closing capture");
/* We weren't able to open the new capture file; user has been
alerted. Close the sync pipe. */
@ -1708,9 +1698,9 @@ sync_pipe_input_cb(gint source, gpointer user_data)
break;
case SP_PACKET_COUNT:
if (!ws_strtou32(buffer, NULL, &npackets)) {
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_WARNING, "Invalid packets number: %s", buffer);
ws_warning("Invalid packets number: %s", buffer);
}
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG, "sync_pipe_input_cb: new packets %u", npackets);
ws_debug("new packets %u", npackets);
cap_session->count += npackets;
cap_session->new_packets(cap_session, npackets);
break;
@ -1781,7 +1771,7 @@ sync_pipe_wait_for_child(ws_process_id fork_child, gchar **msgp)
start_time = g_get_monotonic_time();
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG, "sync_pipe_wait_for_child: wait till child closed");
ws_debug("wait till child closed");
g_assert(fork_child != WS_INVALID_PID);
*msgp = NULL; /* assume no error */
@ -1849,7 +1839,7 @@ sync_pipe_wait_for_child(ws_process_id fork_child, gchar **msgp)
* kills dumpcap, so we should eventually see that and
* clean up and terminate.
*/
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_WARNING, "sync_pipe_wait_for_child: waitpid returned EINTR. retrying.");
ws_warning("waitpid returned EINTR. retrying.");
continue;
} else if (errno == ECHILD) {
/*
@ -1870,7 +1860,7 @@ sync_pipe_wait_for_child(ws_process_id fork_child, gchar **msgp)
#endif
elapsed = (g_get_monotonic_time() - start_time) / 1e6;
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG, "sync_pipe_wait_for_child: capture child closed after %.3fs", elapsed);
ws_debug("capture child closed after %.3fs", elapsed);
return ret;
}
@ -1997,15 +1987,14 @@ signal_pipe_capquit_to_child(capture_session *cap_session)
const char quit_msg[] = "QUIT";
int ret;
g_log(LOG_DOMAIN_CAPTURE, G_LOG_LEVEL_DEBUG, "signal_pipe_capquit_to_child");
ws_debug("signal_pipe_capquit_to_child");
/* it doesn't matter *what* we send here, the first byte will stop the capture */
/* simply sending a "QUIT" string */
/*pipe_write_block(cap_session->signal_pipe_write_fd, SP_QUIT, quit_msg);*/
ret = ws_write(cap_session->signal_pipe_write_fd, quit_msg, sizeof quit_msg);
if(ret == -1) {
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_WARNING,
"signal_pipe_capquit_to_child: %d header: error %s", cap_session->signal_pipe_write_fd, g_strerror(errno));
ws_warning("%d header: error %s", cap_session->signal_pipe_write_fd, g_strerror(errno));
}
}
#endif
@ -2025,8 +2014,7 @@ sync_pipe_stop(capture_session *cap_session)
/* send the SIGINT signal to close the capture child gracefully. */
int sts = kill(cap_session->fork_child, SIGINT);
if (sts != 0) {
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_WARNING,
"Sending SIGINT to child failed: %s\n", g_strerror(errno));
ws_warning("Sending SIGINT to child failed: %s\n", g_strerror(errno));
}
#else
#define STOP_SLEEP_TIME 500 /* ms */
@ -2048,8 +2036,7 @@ sync_pipe_stop(capture_session *cap_session)
/* Force the issue. */
if (terminate) {
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_WARNING,
"sync_pipe_stop: forcing child to exit");
ws_warning("sync_pipe_stop: forcing child to exit");
sync_pipe_kill(cap_session->fork_child);
}
#endif
@ -2065,8 +2052,7 @@ sync_pipe_kill(ws_process_id fork_child)
#ifndef _WIN32
int sts = kill(fork_child, SIGTERM); /* SIGTERM so it can clean up if necessary */
if (sts != 0) {
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_WARNING,
"Sending SIGTERM to child failed: %s\n", g_strerror(errno));
ws_warning("Sending SIGTERM to child failed: %s\n", g_strerror(errno));
}
#else
/* Remark: This is not the preferred method of closing a process!

View File

@ -31,8 +31,6 @@
#define NETIO_STATUS DWORD
#endif
#include "log.h"
#include "capture/capture_ifinfo.h"
#include "capture/capture_win_ifnames.h"

View File

@ -150,115 +150,115 @@ capture_opts_cleanup(capture_options *capture_opts)
/* log content of capture_opts */
void
capture_opts_log(const char *log_domain, GLogLevelFlags log_level, capture_options *capture_opts) {
capture_opts_log(enum ws_log_domain log_domain, enum ws_log_level log_level, capture_options *capture_opts) {
guint i;
g_log(log_domain, log_level, "CAPTURE OPTIONS :");
ws_log(log_domain, log_level, "CAPTURE OPTIONS :");
for (i = 0; i < capture_opts->ifaces->len; i++) {
interface_options *interface_opts;
interface_opts = &g_array_index(capture_opts->ifaces, interface_options, i);
g_log(log_domain, log_level, "Interface name[%02d] : %s", i, interface_opts->name ? interface_opts->name : "(unspecified)");
g_log(log_domain, log_level, "Interface description[%02d] : %s", i, interface_opts->descr ? interface_opts->descr : "(unspecified)");
g_log(log_domain, log_level, "Interface vendor description[%02d] : %s", i, interface_opts->hardware ? interface_opts->hardware : "(unspecified)");
g_log(log_domain, log_level, "Display name[%02d]: %s", i, interface_opts->display_name ? interface_opts->display_name : "(unspecified)");
g_log(log_domain, log_level, "Capture filter[%02d] : %s", i, interface_opts->cfilter ? interface_opts->cfilter : "(unspecified)");
g_log(log_domain, log_level, "Snap length[%02d] (%u) : %d", i, interface_opts->has_snaplen, interface_opts->snaplen);
g_log(log_domain, log_level, "Link Type[%02d] : %d", i, interface_opts->linktype);
g_log(log_domain, log_level, "Promiscuous Mode[%02d]: %s", i, interface_opts->promisc_mode?"TRUE":"FALSE");
g_log(log_domain, log_level, "Extcap[%02d] : %s", i, interface_opts->extcap ? interface_opts->extcap : "(unspecified)");
g_log(log_domain, log_level, "Extcap FIFO[%02d] : %s", i, interface_opts->extcap_fifo ? interface_opts->extcap_fifo : "(unspecified)");
g_log(log_domain, log_level, "Extcap PID[%02d] : %d", i, interface_opts->extcap_pid);
ws_log(log_domain, log_level, "Interface name[%02d] : %s", i, interface_opts->name ? interface_opts->name : "(unspecified)");
ws_log(log_domain, log_level, "Interface description[%02d] : %s", i, interface_opts->descr ? interface_opts->descr : "(unspecified)");
ws_log(log_domain, log_level, "Interface vendor description[%02d] : %s", i, interface_opts->hardware ? interface_opts->hardware : "(unspecified)");
ws_log(log_domain, log_level, "Display name[%02d]: %s", i, interface_opts->display_name ? interface_opts->display_name : "(unspecified)");
ws_log(log_domain, log_level, "Capture filter[%02d] : %s", i, interface_opts->cfilter ? interface_opts->cfilter : "(unspecified)");
ws_log(log_domain, log_level, "Snap length[%02d] (%u) : %d", i, interface_opts->has_snaplen, interface_opts->snaplen);
ws_log(log_domain, log_level, "Link Type[%02d] : %d", i, interface_opts->linktype);
ws_log(log_domain, log_level, "Promiscuous Mode[%02d]: %s", i, interface_opts->promisc_mode?"TRUE":"FALSE");
ws_log(log_domain, log_level, "Extcap[%02d] : %s", i, interface_opts->extcap ? interface_opts->extcap : "(unspecified)");
ws_log(log_domain, log_level, "Extcap FIFO[%02d] : %s", i, interface_opts->extcap_fifo ? interface_opts->extcap_fifo : "(unspecified)");
ws_log(log_domain, log_level, "Extcap PID[%02d] : %d", i, interface_opts->extcap_pid);
#ifdef CAN_SET_CAPTURE_BUFFER_SIZE
g_log(log_domain, log_level, "Buffer size[%02d] : %d (MB)", i, interface_opts->buffer_size);
ws_log(log_domain, log_level, "Buffer size[%02d] : %d (MB)", i, interface_opts->buffer_size);
#endif
g_log(log_domain, log_level, "Monitor Mode[%02d] : %s", i, interface_opts->monitor_mode?"TRUE":"FALSE");
ws_log(log_domain, log_level, "Monitor Mode[%02d] : %s", i, interface_opts->monitor_mode?"TRUE":"FALSE");
#ifdef HAVE_PCAP_REMOTE
g_log(log_domain, log_level, "Capture source[%02d] : %s", i,
ws_log(log_domain, log_level, "Capture source[%02d] : %s", i,
interface_opts->src_type == CAPTURE_IFLOCAL ? "Local interface" :
interface_opts->src_type == CAPTURE_IFREMOTE ? "Remote interface" :
"Unknown");
if (interface_opts->src_type == CAPTURE_IFREMOTE) {
g_log(log_domain, log_level, "Remote host[%02d] : %s", i, interface_opts->remote_host ? interface_opts->remote_host : "(unspecified)");
g_log(log_domain, log_level, "Remote port[%02d] : %s", i, interface_opts->remote_port ? interface_opts->remote_port : "(unspecified)");
ws_log(log_domain, log_level, "Remote host[%02d] : %s", i, interface_opts->remote_host ? interface_opts->remote_host : "(unspecified)");
ws_log(log_domain, log_level, "Remote port[%02d] : %s", i, interface_opts->remote_port ? interface_opts->remote_port : "(unspecified)");
}
g_log(log_domain, log_level, "Authentication[%02d] : %s", i,
ws_log(log_domain, log_level, "Authentication[%02d] : %s", i,
interface_opts->auth_type == CAPTURE_AUTH_NULL ? "Null" :
interface_opts->auth_type == CAPTURE_AUTH_PWD ? "By username/password" :
"Unknown");
if (interface_opts->auth_type == CAPTURE_AUTH_PWD) {
g_log(log_domain, log_level, "Auth username[%02d] : %s", i, interface_opts->auth_username ? interface_opts->auth_username : "(unspecified)");
g_log(log_domain, log_level, "Auth password[%02d] : <hidden>", i);
ws_log(log_domain, log_level, "Auth username[%02d] : %s", i, interface_opts->auth_username ? interface_opts->auth_username : "(unspecified)");
ws_log(log_domain, log_level, "Auth password[%02d] : <hidden>", i);
}
g_log(log_domain, log_level, "UDP data tfer[%02d] : %u", i, interface_opts->datatx_udp);
g_log(log_domain, log_level, "No cap. RPCAP[%02d] : %u", i, interface_opts->nocap_rpcap);
g_log(log_domain, log_level, "No cap. local[%02d] : %u", i, interface_opts->nocap_local);
ws_log(log_domain, log_level, "UDP data tfer[%02d] : %u", i, interface_opts->datatx_udp);
ws_log(log_domain, log_level, "No cap. RPCAP[%02d] : %u", i, interface_opts->nocap_rpcap);
ws_log(log_domain, log_level, "No cap. local[%02d] : %u", i, interface_opts->nocap_local);
#endif
#ifdef HAVE_PCAP_SETSAMPLING
g_log(log_domain, log_level, "Sampling meth.[%02d] : %d", i, interface_opts->sampling_method);
g_log(log_domain, log_level, "Sampling param.[%02d] : %d", i, interface_opts->sampling_param);
ws_log(log_domain, log_level, "Sampling meth.[%02d] : %d", i, interface_opts->sampling_method);
ws_log(log_domain, log_level, "Sampling param.[%02d] : %d", i, interface_opts->sampling_param);
#endif
g_log(log_domain, log_level, "Timestamp type [%02d] : %s", i, interface_opts->timestamp_type);
ws_log(log_domain, log_level, "Timestamp type [%02d] : %s", i, interface_opts->timestamp_type);
}
g_log(log_domain, log_level, "Interface name[df] : %s", capture_opts->default_options.name ? capture_opts->default_options.name : "(unspecified)");
g_log(log_domain, log_level, "Interface Descr[df] : %s", capture_opts->default_options.descr ? capture_opts->default_options.descr : "(unspecified)");
g_log(log_domain, log_level, "Interface Hardware Descr[df] : %s", capture_opts->default_options.hardware ? capture_opts->default_options.hardware : "(unspecified)");
g_log(log_domain, log_level, "Interface display name[df] : %s", capture_opts->default_options.display_name ? capture_opts->default_options.display_name : "(unspecified)");
g_log(log_domain, log_level, "Capture filter[df] : %s", capture_opts->default_options.cfilter ? capture_opts->default_options.cfilter : "(unspecified)");
g_log(log_domain, log_level, "Snap length[df] (%u) : %d", capture_opts->default_options.has_snaplen, capture_opts->default_options.snaplen);
g_log(log_domain, log_level, "Link Type[df] : %d", capture_opts->default_options.linktype);
g_log(log_domain, log_level, "Promiscuous Mode[df]: %s", capture_opts->default_options.promisc_mode?"TRUE":"FALSE");
g_log(log_domain, log_level, "Extcap[df] : %s", capture_opts->default_options.extcap ? capture_opts->default_options.extcap : "(unspecified)");
g_log(log_domain, log_level, "Extcap FIFO[df] : %s", capture_opts->default_options.extcap_fifo ? capture_opts->default_options.extcap_fifo : "(unspecified)");
ws_log(log_domain, log_level, "Interface name[df] : %s", capture_opts->default_options.name ? capture_opts->default_options.name : "(unspecified)");
ws_log(log_domain, log_level, "Interface Descr[df] : %s", capture_opts->default_options.descr ? capture_opts->default_options.descr : "(unspecified)");
ws_log(log_domain, log_level, "Interface Hardware Descr[df] : %s", capture_opts->default_options.hardware ? capture_opts->default_options.hardware : "(unspecified)");
ws_log(log_domain, log_level, "Interface display name[df] : %s", capture_opts->default_options.display_name ? capture_opts->default_options.display_name : "(unspecified)");
ws_log(log_domain, log_level, "Capture filter[df] : %s", capture_opts->default_options.cfilter ? capture_opts->default_options.cfilter : "(unspecified)");
ws_log(log_domain, log_level, "Snap length[df] (%u) : %d", capture_opts->default_options.has_snaplen, capture_opts->default_options.snaplen);
ws_log(log_domain, log_level, "Link Type[df] : %d", capture_opts->default_options.linktype);
ws_log(log_domain, log_level, "Promiscuous Mode[df]: %s", capture_opts->default_options.promisc_mode?"TRUE":"FALSE");
ws_log(log_domain, log_level, "Extcap[df] : %s", capture_opts->default_options.extcap ? capture_opts->default_options.extcap : "(unspecified)");
ws_log(log_domain, log_level, "Extcap FIFO[df] : %s", capture_opts->default_options.extcap_fifo ? capture_opts->default_options.extcap_fifo : "(unspecified)");
#ifdef CAN_SET_CAPTURE_BUFFER_SIZE
g_log(log_domain, log_level, "Buffer size[df] : %d (MB)", capture_opts->default_options.buffer_size);
ws_log(log_domain, log_level, "Buffer size[df] : %d (MB)", capture_opts->default_options.buffer_size);
#endif
g_log(log_domain, log_level, "Monitor Mode[df] : %s", capture_opts->default_options.monitor_mode?"TRUE":"FALSE");
ws_log(log_domain, log_level, "Monitor Mode[df] : %s", capture_opts->default_options.monitor_mode?"TRUE":"FALSE");
#ifdef HAVE_PCAP_REMOTE
g_log(log_domain, log_level, "Capture source[df] : %s",
ws_log(log_domain, log_level, "Capture source[df] : %s",
capture_opts->default_options.src_type == CAPTURE_IFLOCAL ? "Local interface" :
capture_opts->default_options.src_type == CAPTURE_IFREMOTE ? "Remote interface" :
"Unknown");
if (capture_opts->default_options.src_type == CAPTURE_IFREMOTE) {
g_log(log_domain, log_level, "Remote host[df] : %s", capture_opts->default_options.remote_host ? capture_opts->default_options.remote_host : "(unspecified)");
g_log(log_domain, log_level, "Remote port[df] : %s", capture_opts->default_options.remote_port ? capture_opts->default_options.remote_port : "(unspecified)");
ws_log(log_domain, log_level, "Remote host[df] : %s", capture_opts->default_options.remote_host ? capture_opts->default_options.remote_host : "(unspecified)");
ws_log(log_domain, log_level, "Remote port[df] : %s", capture_opts->default_options.remote_port ? capture_opts->default_options.remote_port : "(unspecified)");
}
g_log(log_domain, log_level, "Authentication[df] : %s",
ws_log(log_domain, log_level, "Authentication[df] : %s",
capture_opts->default_options.auth_type == CAPTURE_AUTH_NULL ? "Null" :
capture_opts->default_options.auth_type == CAPTURE_AUTH_PWD ? "By username/password" :
"Unknown");
if (capture_opts->default_options.auth_type == CAPTURE_AUTH_PWD) {
g_log(log_domain, log_level, "Auth username[df] : %s", capture_opts->default_options.auth_username ? capture_opts->default_options.auth_username : "(unspecified)");
g_log(log_domain, log_level, "Auth password[df] : <hidden>");
ws_log(log_domain, log_level, "Auth username[df] : %s", capture_opts->default_options.auth_username ? capture_opts->default_options.auth_username : "(unspecified)");
ws_log(log_domain, log_level, "Auth password[df] : <hidden>");
}
g_log(log_domain, log_level, "UDP data tfer[df] : %u", capture_opts->default_options.datatx_udp);
g_log(log_domain, log_level, "No cap. RPCAP[df] : %u", capture_opts->default_options.nocap_rpcap);
g_log(log_domain, log_level, "No cap. local[df] : %u", capture_opts->default_options.nocap_local);
ws_log(log_domain, log_level, "UDP data tfer[df] : %u", capture_opts->default_options.datatx_udp);
ws_log(log_domain, log_level, "No cap. RPCAP[df] : %u", capture_opts->default_options.nocap_rpcap);
ws_log(log_domain, log_level, "No cap. local[df] : %u", capture_opts->default_options.nocap_local);
#endif
#ifdef HAVE_PCAP_SETSAMPLING
g_log(log_domain, log_level, "Sampling meth. [df] : %d", capture_opts->default_options.sampling_method);
g_log(log_domain, log_level, "Sampling param.[df] : %d", capture_opts->default_options.sampling_param);
ws_log(log_domain, log_level, "Sampling meth. [df] : %d", capture_opts->default_options.sampling_method);
ws_log(log_domain, log_level, "Sampling param.[df] : %d", capture_opts->default_options.sampling_param);
#endif
g_log(log_domain, log_level, "Timestamp type [df] : %s", capture_opts->default_options.timestamp_type ? capture_opts->default_options.timestamp_type : "(unspecified)");
g_log(log_domain, log_level, "SavingToFile : %u", capture_opts->saving_to_file);
g_log(log_domain, log_level, "SaveFile : %s", (capture_opts->save_file) ? capture_opts->save_file : "");
g_log(log_domain, log_level, "GroupReadAccess : %u", capture_opts->group_read_access);
g_log(log_domain, log_level, "Fileformat : %s", (capture_opts->use_pcapng) ? "PCAPNG" : "PCAP");
g_log(log_domain, log_level, "RealTimeMode : %u", capture_opts->real_time_mode);
g_log(log_domain, log_level, "ShowInfo : %u", capture_opts->show_info);
ws_log(log_domain, log_level, "Timestamp type [df] : %s", capture_opts->default_options.timestamp_type ? capture_opts->default_options.timestamp_type : "(unspecified)");
ws_log(log_domain, log_level, "SavingToFile : %u", capture_opts->saving_to_file);
ws_log(log_domain, log_level, "SaveFile : %s", (capture_opts->save_file) ? capture_opts->save_file : "");
ws_log(log_domain, log_level, "GroupReadAccess : %u", capture_opts->group_read_access);
ws_log(log_domain, log_level, "Fileformat : %s", (capture_opts->use_pcapng) ? "PCAPNG" : "PCAP");
ws_log(log_domain, log_level, "RealTimeMode : %u", capture_opts->real_time_mode);
ws_log(log_domain, log_level, "ShowInfo : %u", capture_opts->show_info);
g_log(log_domain, log_level, "MultiFilesOn : %u", capture_opts->multi_files_on);
g_log(log_domain, log_level, "FileDuration (%u) : %.3f", capture_opts->has_file_duration, capture_opts->file_duration);
g_log(log_domain, log_level, "FileInterval (%u) : %u", capture_opts->has_file_interval, capture_opts->file_interval);
g_log(log_domain, log_level, "FilePackets (%u) : %u", capture_opts->has_file_packets, capture_opts->file_packets);
g_log(log_domain, log_level, "RingNumFiles (%u) : %u", capture_opts->has_ring_num_files, capture_opts->ring_num_files);
g_log(log_domain, log_level, "RingPrintFiles (%u) : %s", capture_opts->print_file_names, (capture_opts->print_file_names ? capture_opts->print_name_to : ""));
ws_log(log_domain, log_level, "MultiFilesOn : %u", capture_opts->multi_files_on);
ws_log(log_domain, log_level, "FileDuration (%u) : %.3f", capture_opts->has_file_duration, capture_opts->file_duration);
ws_log(log_domain, log_level, "FileInterval (%u) : %u", capture_opts->has_file_interval, capture_opts->file_interval);
ws_log(log_domain, log_level, "FilePackets (%u) : %u", capture_opts->has_file_packets, capture_opts->file_packets);
ws_log(log_domain, log_level, "RingNumFiles (%u) : %u", capture_opts->has_ring_num_files, capture_opts->ring_num_files);
ws_log(log_domain, log_level, "RingPrintFiles (%u) : %s", capture_opts->print_file_names, (capture_opts->print_file_names ? capture_opts->print_name_to : ""));
g_log(log_domain, log_level, "AutostopFiles (%u) : %u", capture_opts->has_autostop_files, capture_opts->autostop_files);
g_log(log_domain, log_level, "AutostopPackets (%u) : %u", capture_opts->has_autostop_packets, capture_opts->autostop_packets);
g_log(log_domain, log_level, "AutostopFilesize(%u) : %u (KB)", capture_opts->has_autostop_filesize, capture_opts->autostop_filesize);
g_log(log_domain, log_level, "AutostopDuration(%u) : %.3f", capture_opts->has_autostop_duration, capture_opts->autostop_duration);
ws_log(log_domain, log_level, "AutostopFiles (%u) : %u", capture_opts->has_autostop_files, capture_opts->autostop_files);
ws_log(log_domain, log_level, "AutostopPackets (%u) : %u", capture_opts->has_autostop_packets, capture_opts->autostop_packets);
ws_log(log_domain, log_level, "AutostopFilesize(%u) : %u (KB)", capture_opts->has_autostop_filesize, capture_opts->autostop_filesize);
ws_log(log_domain, log_level, "AutostopDuration(%u) : %.3f", capture_opts->has_autostop_duration, capture_opts->autostop_duration);
}
/*

View File

@ -22,6 +22,7 @@
#include <capture/capture_ifinfo.h>
#include "ringbuffer.h"
#include <wsutil/wslog.h>
#ifdef _WIN32
#include <windows.h>
@ -338,7 +339,7 @@ capture_opts_add_opt(capture_options *capture_opts, int opt, const char *optarg)
/* log content of capture_opts */
extern void
capture_opts_log(const char *log_domain, GLogLevelFlags log_level, capture_options *capture_opts);
capture_opts_log(enum ws_log_domain domain, enum ws_log_level level, capture_options *capture_opts);
enum caps_query {
CAPS_QUERY_LINK_TYPES = 0x1,

View File

@ -380,5 +380,6 @@
#endif
#include <ws_diag_control.h>
#include <ws_log_domains.h>
#endif /* __CONFIG_H__ */

View File

@ -225,7 +225,20 @@ libwsutil.so.0 libwsutil0 #MINVER#
ws_inet_pton4@Base 2.1.2
ws_inet_pton6@Base 2.1.2
ws_init_sockets@Base 3.1.0
ws_log@Base 3.5.0
ws_log_add_custom_file@Base 3.5.0
ws_log_default_writer@Base 3.5.0
ws_log_domain_to_string@Base 3.5.0
ws_log_full@Base 3.5.0
ws_log_get_level@Base 3.5.0
ws_log_init@Base 3.5.0
ws_log_init_with_data@Base 3.5.0
ws_log_level_is_active@Base 3.5.0
ws_log_level_to_string@Base 3.5.0
ws_log_set_level@Base 3.5.0
ws_log_set_level_args@Base 3.5.0
ws_log_set_level_str@Base 3.5.0
ws_logv@Base 3.5.0
ws_mempbrk_compile@Base 1.99.4
ws_mempbrk_exec@Base 1.99.4
ws_pipe_close@Base 2.6.5

321
dumpcap.c
View File

@ -8,6 +8,7 @@
*/
#include <config.h>
#define WS_LOG_DOMAIN LOG_DOMAIN_CAPCHILD
#include <stdio.h>
#include <stdlib.h> /* for exit() */
@ -47,6 +48,7 @@
#include <version_info.h>
#include <wsutil/socket.h>
#include <wsutil/wslog.h>
#ifdef HAVE_LIBCAP
# include <sys/prctl.h>
@ -78,7 +80,6 @@
#include <capture/capture_sync.h>
#include "wsutil/tempfile.h"
#include "log.h"
#include "wsutil/file_util.h"
#include "wsutil/cpu_info.h"
#include "wsutil/os_version_info.h"
@ -326,8 +327,8 @@ static gboolean need_timeout_workaround;
#define WRITER_THREAD_TIMEOUT 100000 /* usecs */
static void
console_log_handler(const char *log_domain, GLogLevelFlags log_level,
const char *message, gpointer user_data _U_);
dumpcap_log_writer(const char *message, enum ws_log_domain domain,
enum ws_log_level level, void *ptr);
/* capture related options */
static capture_options global_capture_opts;
@ -510,9 +511,7 @@ static void
/* .... */
print_caps(const char *pfx) {
cap_t caps = cap_get_proc();
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG,
"%s: EUID: %d Capabilities: %s", pfx,
geteuid(), cap_to_text(caps, NULL));
ws_debug("%s: EUID: %d Capabilities: %s", pfx, geteuid(), cap_to_text(caps, NULL));
cap_free(caps);
}
#else
@ -931,8 +930,7 @@ print_statistics_loop(gboolean machine_readable)
* connections. We avoid collecting stats on them.
*/
if (!strncmp(if_info->name, "nf", 2)) {
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "Skipping interface %s for stats",
if_info->name);
ws_debug("Skipping interface %s for stats", if_info->name);
continue;
}
#endif
@ -1025,10 +1023,8 @@ capture_cleanup_handler(DWORD dwCtrlType)
user logs out. (XXX - can we explicitly check whether we're
running as a service?) */
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_INFO,
"Console: Control signal");
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG,
"Console: Control signal, CtrlType: %lu", dwCtrlType);
ws_info("Console: Control signal");
ws_debug("Console: Control signal, CtrlType: %lu", dwCtrlType);
/* Keep capture running if we're a service and a user logs off */
if (capture_child || (dwCtrlType != CTRL_LOGOFF_EVENT)) {
@ -1046,11 +1042,6 @@ capture_cleanup_handler(int signum _U_)
SIGTERM. We assume that if the user wanted it to keep running
after they logged out, they'd have nohupped it. */
/* Note: don't call g_log() in the signal handler: if we happened to be in
* g_log() in process context when the signal came in, g_log will detect
* the "recursion" and abort.
*/
capture_loop_stop();
}
#endif
@ -1452,7 +1443,7 @@ cap_pipe_read_data_bytes(capture_src *pcap_src, char *errmsg, size_t errmsgl)
ssize_t b;
#ifdef LOG_CAPTURE_VERBOSE
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "cap_pipe_read_data_bytes read %lu of %lu",
ws_debug("cap_pipe_read_data_bytes read %lu of %lu",
pcap_src->cap_pipe_bytes_read, pcap_src->cap_pipe_bytes_to_read);
#endif
sz = pcap_src->cap_pipe_bytes_to_read - pcap_src->cap_pipe_bytes_read;
@ -1501,7 +1492,7 @@ cap_pipe_read_data_bytes(capture_src *pcap_src, char *errmsg, size_t errmsgl)
}
pcap_src->cap_pipe_bytes_read += bytes_read;
#ifdef LOG_CAPTURE_VERBOSE
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "cap_pipe_read_data_bytes read %lu of %lu",
ws_debug("cap_pipe_read_data_bytes read %lu of %lu",
pcap_src->cap_pipe_bytes_read, pcap_src->cap_pipe_bytes_to_read);
#endif
return bytes_read;
@ -1552,7 +1543,7 @@ cap_pipe_open_live(char *pipename,
pcap_src->cap_pipe_h = INVALID_HANDLE_VALUE;
#endif
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "cap_pipe_open_live: %s", pipename);
ws_debug("cap_pipe_open_live: %s", pipename);
/*
* XXX - this blocks until a pcap per-file header has been written to
@ -1868,7 +1859,7 @@ cap_pipe_open_live(char *pipename,
return;
error:
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "cap_pipe_open_live: error %s", errmsg);
ws_debug("cap_pipe_open_live: error %s", errmsg);
pcap_src->cap_pipe_err = PIPERR;
cap_pipe_close(fd, pcap_src->from_cap_socket);
pcap_src->cap_pipe_fd = -1;
@ -1992,7 +1983,7 @@ pcap_pipe_open_live(int fd,
return;
error:
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "pcap_pipe_open_live: error %s", errmsg);
ws_debug("pcap_pipe_open_live: error %s", errmsg);
pcap_src->cap_pipe_err = PIPERR;
cap_pipe_close(fd, pcap_src->from_cap_socket);
pcap_src->cap_pipe_fd = -1;
@ -2043,10 +2034,10 @@ pcapng_read_shb(capture_src *pcap_src,
switch (shb.magic)
{
case PCAPNG_MAGIC:
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "pcapng SHB MAGIC");
ws_debug("pcapng SHB MAGIC");
break;
case PCAPNG_SWAPPED_MAGIC:
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "pcapng SHB SWAPPED MAGIC");
ws_debug("pcapng SHB SWAPPED MAGIC");
/*
* pcapng sources can contain all sorts of block types.
* Rather than add a bunch of complexity to this code (which is
@ -2141,7 +2132,7 @@ pcapng_adjust_block(capture_src *pcap_src, const pcapng_block_header_t *bh, u_ch
g_free(idb_source->idb);
memset(idb_source, 0, sizeof(saved_idb_t));
idb_source->deleted = TRUE;
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "%s: deleted pcapng IDB %u", G_STRFUNC, iface_id);
ws_debug("%s: deleted pcapng IDB %u", G_STRFUNC, iface_id);
}
}
g_array_set_size(pcap_src->cap_pipe_info.pcapng.src_iface_to_global, 0);
@ -2160,7 +2151,7 @@ pcapng_adjust_block(capture_src *pcap_src, const pcapng_block_header_t *bh, u_ch
g_array_append_val(global_ld.saved_idbs, idb_source);
guint32 iface_id = global_ld.saved_idbs->len - 1;
g_array_append_val(pcap_src->cap_pipe_info.pcapng.src_iface_to_global, iface_id);
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "%s: mapped pcapng IDB %u -> %u from source %u",
ws_debug("%s: mapped pcapng IDB %u -> %u from source %u",
G_STRFUNC, pcap_src->cap_pipe_info.pcapng.src_iface_to_global->len - 1, iface_id, pcap_src->interface_id);
}
break;
@ -2178,7 +2169,7 @@ pcapng_adjust_block(capture_src *pcap_src, const pcapng_block_header_t *bh, u_ch
memcpy(pd + sizeof(pcapng_block_header_t),
&g_array_index(pcap_src->cap_pipe_info.pcapng.src_iface_to_global, guint32, iface_id), 4);
} else {
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "%s: pcapng EPB or ISB interface id %u > max %u", G_STRFUNC, iface_id, pcap_src->cap_pipe_info.pcapng.src_iface_to_global->len);
ws_debug("%s: pcapng EPB or ISB interface id %u > max %u", G_STRFUNC, iface_id, pcap_src->cap_pipe_info.pcapng.src_iface_to_global->len);
return FALSE;
}
}
@ -2203,7 +2194,7 @@ pcapng_pipe_open_live(int fd,
guint32 type = BLOCK_TYPE_SHB;
pcapng_block_header_t *bh = &pcap_src->cap_pipe_info.pcapng.bh;
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "pcapng_pipe_open_live: fd %d", fd);
ws_debug("pcapng_pipe_open_live: fd %d", fd);
/*
* A pcapng block begins with the block type followed by the block
@ -2266,7 +2257,7 @@ pcapng_pipe_open_live(int fd,
return;
error:
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "pcapng_pipe_open_live: error %s", errmsg);
ws_debug("pcapng_pipe_open_live: error %s", errmsg);
pcap_src->cap_pipe_err = PIPERR;
cap_pipe_close(fd, pcap_src->from_cap_socket);
pcap_src->cap_pipe_fd = -1;
@ -2291,7 +2282,7 @@ pcap_pipe_dispatch(loop_data *ld, capture_src *pcap_src, char *errmsg, size_t er
pcap_pipe_info_t *pcap_info = &pcap_src->cap_pipe_info.pcap;
#ifdef LOG_CAPTURE_VERBOSE
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "pcap_pipe_dispatch");
ws_debug("pcap_pipe_dispatch");
#endif
switch (pcap_src->cap_pipe_state) {
@ -2531,14 +2522,14 @@ pcapng_pipe_dispatch(loop_data *ld, capture_src *pcap_src, char *errmsg, size_t
pcapng_block_header_t *bh = &pcap_src->cap_pipe_info.pcapng.bh;
#ifdef LOG_CAPTURE_VERBOSE
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "pcapng_pipe_dispatch");
ws_debug("pcapng_pipe_dispatch");
#endif
switch (pcap_src->cap_pipe_state) {
case STATE_EXPECT_REC_HDR:
#ifdef LOG_CAPTURE_VERBOSE
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "pcapng_pipe_dispatch STATE_EXPECT_REC_HDR");
ws_debug("pcapng_pipe_dispatch STATE_EXPECT_REC_HDR");
#endif
#ifdef _WIN32
if (g_mutex_trylock(pcap_src->cap_pipe_read_mtx)) {
@ -2560,7 +2551,7 @@ pcapng_pipe_dispatch(loop_data *ld, capture_src *pcap_src, char *errmsg, size_t
case STATE_READ_REC_HDR:
#ifdef LOG_CAPTURE_VERBOSE
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "pcapng_pipe_dispatch STATE_READ_REC_HDR");
ws_debug("pcapng_pipe_dispatch STATE_READ_REC_HDR");
#endif
#ifdef _WIN32
if (pcap_src->from_cap_socket) {
@ -2593,7 +2584,7 @@ pcapng_pipe_dispatch(loop_data *ld, capture_src *pcap_src, char *errmsg, size_t
case STATE_EXPECT_DATA:
#ifdef LOG_CAPTURE_VERBOSE
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "pcapng_pipe_dispatch STATE_EXPECT_DATA");
ws_debug("pcapng_pipe_dispatch STATE_EXPECT_DATA");
#endif
#ifdef _WIN32
if (g_mutex_trylock(pcap_src->cap_pipe_read_mtx)) {
@ -2615,7 +2606,7 @@ pcapng_pipe_dispatch(loop_data *ld, capture_src *pcap_src, char *errmsg, size_t
case STATE_READ_DATA:
#ifdef LOG_CAPTURE_VERBOSE
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "pcapng_pipe_dispatch STATE_READ_DATA");
ws_debug("pcapng_pipe_dispatch STATE_READ_DATA");
#endif
#ifdef _WIN32
if (pcap_src->from_cap_socket) {
@ -2808,7 +2799,7 @@ capture_loop_open_input(capture_options *capture_opts, loop_data *ld,
g_rw_lock_writer_lock (&ld->saved_shb_idb_lock);
g_array_append_val(global_ld.saved_idbs, idb_source);
g_rw_lock_writer_unlock (&ld->saved_shb_idb_lock);
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "%s: saved capture_opts IDB %u",
ws_debug("%s: saved capture_opts IDB %u",
G_STRFUNC, i);
#ifdef MUST_DO_SELECT
@ -2831,7 +2822,7 @@ capture_loop_open_input(capture_options *capture_opts, loop_data *ld,
#endif
g_array_append_val(ld->pcaps, pcap_src);
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "capture_loop_open_input : %s", interface_opts->name);
ws_debug("capture_loop_open_input : %s", interface_opts->name);
pcap_src->pcap_h = open_capture_device(capture_opts, interface_opts,
CAP_READ_TIMEOUT, &open_err, &open_err_str);
@ -2963,7 +2954,7 @@ capture_loop_open_input(capture_options *capture_opts, loop_data *ld,
*/
ld->pcapng_passthrough = TRUE;
g_rw_lock_writer_lock (&ld->saved_shb_idb_lock);
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "%s: Clearing %u interfaces for passthrough",
ws_debug("%s: Clearing %u interfaces for passthrough",
G_STRFUNC, global_ld.saved_idbs->len);
g_array_set_size(global_ld.saved_idbs, 0);
g_rw_lock_writer_unlock (&ld->saved_shb_idb_lock);
@ -2988,7 +2979,7 @@ static void capture_loop_close_input(loop_data *ld)
guint i;
capture_src *pcap_src;
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "capture_loop_close_input");
ws_debug("capture_loop_close_input");
for (i = 0; i < ld->pcaps->len; i++) {
pcap_src = g_array_index(ld->pcaps, capture_src *, i);
@ -3017,7 +3008,7 @@ static void capture_loop_close_input(loop_data *ld)
} else {
/* Capture device. If open, close the pcap_t. */
if (pcap_src->pcap_h != NULL) {
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "capture_loop_close_input: closing %p", (void *)pcap_src->pcap_h);
ws_debug("capture_loop_close_input: closing %p", (void *)pcap_src->pcap_h);
pcap_close(pcap_src->pcap_h);
pcap_src->pcap_h = NULL;
}
@ -3035,7 +3026,7 @@ capture_loop_init_filter(pcap_t *pcap_h, gboolean from_cap_pipe,
{
struct bpf_program fcode;
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "capture_loop_init_filter: %s", cfilter);
ws_debug("capture_loop_init_filter: %s", cfilter);
/* capture filters only work on real interfaces */
if (cfilter && !from_cap_pipe) {
@ -3072,7 +3063,7 @@ capture_loop_init_pcapng_output(capture_options *capture_opts, loop_data *ld,
if (ld->pcapng_passthrough && !ld->saved_shb) {
/* We have a single pcapng capture interface and this is the first or only output file. */
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "%s: skipping dumpcap SHB and IDBs in favor of source", G_STRFUNC);
ws_debug("%s: skipping dumpcap SHB and IDBs in favor of source", G_STRFUNC);
g_rw_lock_reader_unlock (&ld->saved_shb_idb_lock);
return TRUE;
}
@ -3092,7 +3083,7 @@ capture_loop_init_pcapng_output(capture_options *capture_opts, loop_data *ld,
successful = pcapng_write_block(ld->pdh, ld->saved_shb, bh.block_total_length, &ld->bytes_written, err);
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "%s: wrote saved passthrough SHB %d", G_STRFUNC, successful);
ws_debug("%s: wrote saved passthrough SHB %d", G_STRFUNC, successful);
} else {
GString *cpu_info_str = g_string_new("");
get_cpu_info(cpu_info_str);
@ -3105,7 +3096,7 @@ capture_loop_init_pcapng_output(capture_options *capture_opts, loop_data *ld,
-1, /* section_length */
&ld->bytes_written,
err);
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "%s: wrote dumpcap SHB %d", G_STRFUNC, successful);
ws_debug("%s: wrote dumpcap SHB %d", G_STRFUNC, successful);
g_string_free(cpu_info_str, TRUE);
}
@ -3138,10 +3129,10 @@ capture_loop_init_pcapng_output(capture_options *capture_opts, loop_data *ld,
0, /* IDB_IF_SPEED 8 */
6, /* IDB_TSRESOL 9 */
&global_ld.err);
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "%s: skipping deleted pcapng IDB %u", G_STRFUNC, i);
ws_debug("%s: skipping deleted pcapng IDB %u", G_STRFUNC, i);
} else if (idb_source.idb && idb_source.idb_len) {
successful = pcapng_write_block(global_ld.pdh, idb_source.idb, idb_source.idb_len, &ld->bytes_written, err);
g_log(LOG_DOMAIN_CAPTURE_CHILD, G_LOG_LEVEL_DEBUG, "%s: wrote pcapng IDB %d", G_STRFUNC, successful);
ws_debug("%s: wrote pcapng IDB %d", G_STRFUNC, successful);
} else if (idb_source.interface_id < capture_opts->ifaces->len) {
unsigned if_id = idb_source.interface_id;
interface_options *interface_opts = &g_array_index(capture_opts->ifaces, interface_options, if_id);
@ -3164,7 +3155,7 @@ capture_loop_init_pcapng_output(capture_options *capture_opts, loop_data *ld,
0, /* IDB_IF_SPEED 8 */
pcap_src->ts_nsec ? 9 : 6, /* IDB_TSRESOL 9 */