From fd123315e548cb4879bf4b3820d8a9d91d06674e Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Mon, 3 Apr 2023 19:11:54 +0200 Subject: [PATCH 01/16] core: fix setting non-blocking FD in nm_utils_spawn_helper() Fixes: 6ac21ba916b3 ('core: add infrastructure for spawning a helper process') --- src/core/nm-core-utils.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/core/nm-core-utils.c b/src/core/nm-core-utils.c index 7482292034..410fb2bc29 100644 --- a/src/core/nm-core-utils.c +++ b/src/core/nm-core-utils.c @@ -5163,9 +5163,9 @@ nm_utils_spawn_helper(const char *const *args, g_source_attach(info->timeout_source, context); /* Set file descriptors as non-blocking */ - fd_flags = fcntl(info->child_stdin, F_GETFD, 0); + fd_flags = fcntl(info->child_stdin, F_GETFL, 0); fcntl(info->child_stdin, F_SETFL, fd_flags | O_NONBLOCK); - fd_flags = fcntl(info->child_stdout, F_GETFD, 0); + fd_flags = fcntl(info->child_stdout, F_GETFL, 0); fcntl(info->child_stdout, F_SETFL, fd_flags | O_NONBLOCK); fd_flags = fcntl(info->child_stderr, F_GETFD, 0); fcntl(info->child_stderr, F_SETFL, fd_flags | O_NONBLOCK); From d1f7e439c6103f3e635beb221718eb09241c6fdb Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Mon, 3 Apr 2023 19:11:54 +0200 Subject: [PATCH 02/16] core: fix setting non-blocking stderr in nm_utils_spawn_helper() Fixes: d65702803cb0 ('core: print stderr from nm-daemon-helper') --- src/core/nm-core-utils.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/core/nm-core-utils.c b/src/core/nm-core-utils.c index 410fb2bc29..175a1652e2 100644 --- a/src/core/nm-core-utils.c +++ b/src/core/nm-core-utils.c @@ -5167,7 +5167,7 @@ nm_utils_spawn_helper(const char *const *args, fcntl(info->child_stdin, F_SETFL, fd_flags | O_NONBLOCK); fd_flags = fcntl(info->child_stdout, F_GETFL, 0); fcntl(info->child_stdout, F_SETFL, fd_flags | O_NONBLOCK); - fd_flags = fcntl(info->child_stderr, F_GETFD, 0); + fd_flags = fcntl(info->child_stderr, F_GETFL, 0); fcntl(info->child_stderr, F_SETFL, fd_flags | O_NONBLOCK); /* Watch process stdin */ From 62a85fa84560dc296796c3a63f698f8c15794b99 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Mon, 3 Apr 2023 19:18:15 +0200 Subject: [PATCH 03/16] core: fix setting FD flags in _rfkill_update_system() F_SETFL will reset the flags. That is wrong, as we only want to add O_NONBLOCK flag and leaving the other flags alone. Usually, we would need to call F_GETFL first. Note that on Linux, F_SETFL can only set certain flags, so the O_RDWR|O_CLOEXEC flags were unaffected by this. That means, most likely there are no other flags that our use of F_SETFL would wrongly clear. Still, it's ugly, because it's not obvious whether there might be other flags. Avoid that altogether, by setting the flag already during open(). Fixes: 67e092abcbde ('core: better handling of rfkill for WiMAX and WiFi (bgo #629589) (rh #599002)') --- src/core/nm-manager.c | 10 +--------- 1 file changed, 1 insertion(+), 9 deletions(-) diff --git a/src/core/nm-manager.c b/src/core/nm-manager.c index b10e78bee3..f6902b9786 100644 --- a/src/core/nm-manager.c +++ b/src/core/nm-manager.c @@ -3021,7 +3021,7 @@ _rfkill_update_system(NMManager *self, NMRfkillType rtype, gboolean enabled) nm_assert(NM_IN_SET(rtype, NM_RFKILL_TYPE_WLAN, NM_RFKILL_TYPE_WWAN)); - fd = open("/dev/rfkill", O_RDWR | O_CLOEXEC); + fd = open("/dev/rfkill", O_RDWR | O_NONBLOCK | O_CLOEXEC); if (fd < 0) { if (errno == EACCES) _LOGW(LOGD_RFKILL, @@ -3030,14 +3030,6 @@ _rfkill_update_system(NMManager *self, NMRfkillType rtype, gboolean enabled) return; } - if (fcntl(fd, F_SETFL, O_NONBLOCK) < 0) { - _LOGW(LOGD_RFKILL, - "rfkill: (%s): failed to set killswitch device for " - "non-blocking operation", - nm_rfkill_type_to_string(rtype)); - return; - } - memset(&event, 0, sizeof(event)); event.op = KERN_RFKILL_OP_CHANGE_ALL; switch (rtype) { From 20bd6b68036b9696d39c96cb0c1600c42d8d4255 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Mon, 3 Apr 2023 19:24:05 +0200 Subject: [PATCH 04/16] core: fix setting non-blocking FD in nm_utils_spawn_helper() Fixes: df1d214b2ea7 ('clients: polkit-agent: implement polkit agent without using libpolkit') --- src/libnmc-base/nm-polkit-listener.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/libnmc-base/nm-polkit-listener.c b/src/libnmc-base/nm-polkit-listener.c index e7972faa48..fbc2c7046d 100644 --- a/src/libnmc-base/nm-polkit-listener.c +++ b/src/libnmc-base/nm-polkit-listener.c @@ -534,10 +534,10 @@ begin_authentication(AuthRequest *request) return; } - fd_flags = fcntl(request->child_stdin, F_GETFD, 0); + fd_flags = fcntl(request->child_stdin, F_GETFL, 0); fcntl(request->child_stdin, F_SETFL, fd_flags | O_NONBLOCK); - fd_flags = fcntl(request->child_stdout, F_GETFD, 0); + fd_flags = fcntl(request->child_stdout, F_GETFL, 0); fcntl(request->child_stdout, F_SETFL, fd_flags | O_NONBLOCK); request->child_stdout_watch_source = nm_g_unix_fd_source_new(request->child_stdout, From 17ae6a4413a886d95a74abd972cd5b0c4744a9b7 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Mon, 3 Apr 2023 19:22:07 +0200 Subject: [PATCH 05/16] platform: drop unused nl_socket_set_nonblocking() function It's not used. It's better to use SOCK_NONBLOCK flag for socket(), as we do. Also, the implementation that blindly calls F_SETFL without merging the existing flags from F_GETFL is just wrong. Drop it altogether. --- src/libnm-platform/nm-netlink.c | 11 ----------- src/libnm-platform/nm-netlink.h | 2 -- src/libnm-platform/tests/test-nm-platform.c | 1 - 3 files changed, 14 deletions(-) diff --git a/src/libnm-platform/nm-netlink.c b/src/libnm-platform/nm-netlink.c index 00b6880abb..5684b8cda5 100644 --- a/src/libnm-platform/nm-netlink.c +++ b/src/libnm-platform/nm-netlink.c @@ -1036,17 +1036,6 @@ nlmsg_get_dst(struct nl_msg *msg) return &msg->nm_dst; } -int -nl_socket_set_nonblocking(const struct nl_sock *sk) -{ - nm_assert_sk(sk); - - if (fcntl(sk->s_fd, F_SETFL, O_NONBLOCK) < 0) - return -nm_errno_from_native(errno); - - return 0; -} - int nl_socket_set_buffer_size(struct nl_sock *sk, int rxbuf, int txbuf) { diff --git a/src/libnm-platform/nm-netlink.h b/src/libnm-platform/nm-netlink.h index 6fed8189b7..35e2962984 100644 --- a/src/libnm-platform/nm-netlink.h +++ b/src/libnm-platform/nm-netlink.h @@ -605,8 +605,6 @@ int nl_socket_set_passcred(struct nl_sock *sk, int state); int nl_socket_set_pktinfo(struct nl_sock *sk, int state); -int nl_socket_set_nonblocking(const struct nl_sock *sk); - uint32_t nl_socket_get_local_port(const struct nl_sock *sk); int nl_socket_add_memberships(struct nl_sock *sk, int group, ...); diff --git a/src/libnm-platform/tests/test-nm-platform.c b/src/libnm-platform/tests/test-nm-platform.c index 90a2904599..5fc8a5dded 100644 --- a/src/libnm-platform/tests/test-nm-platform.c +++ b/src/libnm-platform/tests/test-nm-platform.c @@ -117,7 +117,6 @@ test_use_symbols(void) (void (*)(void)) nl_socket_set_passcred, (void (*)(void)) nl_socket_set_msg_buf_size, (void (*)(void)) nlmsg_get_dst, - (void (*)(void)) nl_socket_set_nonblocking, (void (*)(void)) nl_socket_set_buffer_size, (void (*)(void)) nl_socket_add_memberships, (void (*)(void)) nl_wait_for_ack, From 31fd8f60cf21ab8fca232ef0d2dcd65f71b1c03e Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Mon, 3 Apr 2023 19:38:00 +0200 Subject: [PATCH 06/16] all: use G_SPAWN_CLOEXEC_PIPES with g_spawn_async_with_pipes() G_SPAWN_CLOEXEC_PIPES is supported since glib 2.40, which we already depend on. --- src/core/dns/nm-dns-manager.c | 2 +- src/core/nm-core-utils.c | 2 +- src/libnm-client-test/nm-test-utils-impl.c | 3 ++- src/libnmc-base/nm-polkit-listener.c | 2 +- src/libnmc-base/nm-secret-agent-simple.c | 2 +- 5 files changed, 6 insertions(+), 5 deletions(-) diff --git a/src/core/dns/nm-dns-manager.c b/src/core/dns/nm-dns-manager.c index 6ee2e816a0..fb65afcadc 100644 --- a/src/core/dns/nm-dns-manager.c +++ b/src/core/dns/nm-dns-manager.c @@ -647,7 +647,7 @@ run_netconfig(NMDnsManager *self, GError **error, int *stdin_fd) if (!g_spawn_async_with_pipes(NULL, argv, NULL, - G_SPAWN_DO_NOT_REAP_CHILD, + G_SPAWN_CLOEXEC_PIPES | G_SPAWN_DO_NOT_REAP_CHILD, NULL, NULL, &pid, diff --git a/src/core/nm-core-utils.c b/src/core/nm-core-utils.c index 175a1652e2..4a028e8be2 100644 --- a/src/core/nm-core-utils.c +++ b/src/core/nm-core-utils.c @@ -5108,7 +5108,7 @@ nm_utils_spawn_helper(const char *const *args, if (!g_spawn_async_with_pipes("/", (char **) NM_MAKE_STRV(LIBEXECDIR "/nm-daemon-helper"), (char **) NM_MAKE_STRV(), - G_SPAWN_DO_NOT_REAP_CHILD, + G_SPAWN_CLOEXEC_PIPES | G_SPAWN_DO_NOT_REAP_CHILD, NULL, NULL, &info->pid, diff --git a/src/libnm-client-test/nm-test-utils-impl.c b/src/libnm-client-test/nm-test-utils-impl.c index ad642d2530..ba541ad83a 100644 --- a/src/libnm-client-test/nm-test-utils-impl.c +++ b/src/libnm-client-test/nm-test-utils-impl.c @@ -107,7 +107,8 @@ nmtstc_service_init(void) g_spawn_async_with_pipes(NULL, (char **) args, NULL, - G_SPAWN_SEARCH_PATH | G_SPAWN_DO_NOT_REAP_CHILD, + G_SPAWN_CLOEXEC_PIPES | G_SPAWN_SEARCH_PATH + | G_SPAWN_DO_NOT_REAP_CHILD, NULL, NULL, &info->pid, diff --git a/src/libnmc-base/nm-polkit-listener.c b/src/libnmc-base/nm-polkit-listener.c index fbc2c7046d..7b0de39bcb 100644 --- a/src/libnmc-base/nm-polkit-listener.c +++ b/src/libnmc-base/nm-polkit-listener.c @@ -514,7 +514,7 @@ begin_authentication(AuthRequest *request) if (!g_spawn_async_with_pipes(NULL, (char **) helper_argv, NULL, - G_SPAWN_STDERR_TO_DEV_NULL, + G_SPAWN_CLOEXEC_PIPES | G_SPAWN_STDERR_TO_DEV_NULL, NULL, NULL, NULL, diff --git a/src/libnmc-base/nm-secret-agent-simple.c b/src/libnmc-base/nm-secret-agent-simple.c index d35ffd7975..1b9aa57142 100644 --- a/src/libnmc-base/nm-secret-agent-simple.c +++ b/src/libnmc-base/nm-secret-agent-simple.c @@ -787,7 +787,7 @@ try_spawn_vpn_auth_helper(RequestData *request, GPtrArray *secrets) if (!g_spawn_async_with_pipes(NULL, (char **) auth_dialog_argv->pdata, NULL, - G_SPAWN_DO_NOT_REAP_CHILD, + G_SPAWN_CLOEXEC_PIPES | G_SPAWN_DO_NOT_REAP_CHILD, NULL, NULL, &auth_dialog_pid, From f4943e07f1ae89c97c1fca8469b846831cab4ef8 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Mon, 3 Apr 2023 17:49:33 +0200 Subject: [PATCH 07/16] glib-aux: add nm_io_fcntl_setfl_update_nonblock() helper --- src/libnm-glib-aux/nm-io-utils.c | 80 ++++++++++++++++++++++++++++++++ src/libnm-glib-aux/nm-io-utils.h | 10 ++++ 2 files changed, 90 insertions(+) diff --git a/src/libnm-glib-aux/nm-io-utils.c b/src/libnm-glib-aux/nm-io-utils.c index 1340e1b45f..ec016ed8a3 100644 --- a/src/libnm-glib-aux/nm-io-utils.c +++ b/src/libnm-glib-aux/nm-io-utils.c @@ -21,6 +21,86 @@ /*****************************************************************************/ +int +nm_io_fcntl_getfl(int fd) +{ + int f; + + nm_assert(fd >= 0); + + f = fcntl(fd, F_GETFL, 0); + + /* The caller really must provide a valid FD. For a valid FD, there is not + * reason why this call could fail (or how we could handle the failure). + * + * Unlike plain fcntl(), nm_io_fcntl_getfl() cannot fail. */ + nm_assert(f != -1); + + /* We not only assert that the return value is "!= -1", but that it's not + * negative. Negative flags would be very odd, and not something we would + * expect for a successful call. */ + nm_assert(f >= 0); + + return f; +} + +int +nm_io_fcntl_setfl(int fd, int flags) +{ + int f; + int errsv; + + nm_assert(fd >= 0); + nm_assert(flags >= 0); + + f = fcntl(fd, F_SETFL, flags); + if (f != 0) { + errsv = errno; + + nm_assert(errsv != EBADF); + + return -NM_ERRNO_NATIVE(errsv); + } + + return 0; +} + +int +nm_io_fcntl_setfl_update(int fd, int flags_mask, int flags_value) +{ + int flags_current; + + nm_assert(fd >= 0); + nm_assert(flags_mask > 0); + nm_assert(flags_value >= 0); + nm_assert(((~flags_mask) & flags_value) == 0); + + flags_current = nm_io_fcntl_getfl(fd); + return nm_io_fcntl_setfl(fd, (flags_current & ~flags_mask) | (flags_mask & flags_value)); +} + +void +nm_io_fcntl_setfl_update_nonblock(int fd) +{ + int r; + + nm_assert(fd >= 0); + + r = nm_io_fcntl_setfl_update(fd, O_NONBLOCK, O_NONBLOCK); + + /* nm_io_fcntl_setfl_update() already asserts that it cannot fail with + * EBADF. + * + * In nm_io_fcntl_setfl_update_nonblock() only sts O_NONBLOCK, where we + * don't expect any other error. Kernel should never reject setting this + * flags, and if it did, we have to find out how to handle that. Currently + * we don't handle it and assert against failure. */ + + nm_assert(r == 0); +} + +/*****************************************************************************/ + _nm_printf(4, 5) static int _get_contents_error(GError **error, int errsv, int *out_errsv, diff --git a/src/libnm-glib-aux/nm-io-utils.h b/src/libnm-glib-aux/nm-io-utils.h index 5401814018..0021138f46 100644 --- a/src/libnm-glib-aux/nm-io-utils.h +++ b/src/libnm-glib-aux/nm-io-utils.h @@ -10,6 +10,16 @@ /*****************************************************************************/ +int nm_io_fcntl_getfl(int fd); + +int nm_io_fcntl_setfl(int fd, int flags); + +int nm_io_fcntl_setfl_update(int fd, int flags_mask, int flags_value); + +void nm_io_fcntl_setfl_update_nonblock(int fd); + +/*****************************************************************************/ + /** * NMUtilsFileGetContentsFlags: * @NM_UTILS_FILE_GET_CONTENTS_FLAG_NONE: no flag From ce414933a7bf8b52de4cf1990c96bc32af77b5d6 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Mon, 3 Apr 2023 17:52:37 +0200 Subject: [PATCH 08/16] core: use nm_io_fcntl_setfl_update_nonblock() helper --- src/core/nm-core-utils.c | 11 +++-------- src/libnmc-base/nm-polkit-listener.c | 8 ++------ 2 files changed, 5 insertions(+), 14 deletions(-) diff --git a/src/core/nm-core-utils.c b/src/core/nm-core-utils.c index 4a028e8be2..6417cfc43f 100644 --- a/src/core/nm-core-utils.c +++ b/src/core/nm-core-utils.c @@ -5090,7 +5090,6 @@ nm_utils_spawn_helper(const char *const *args, gs_free_error GError *error = NULL; gs_free char *commands = NULL; HelperInfo *info; - int fd_flags; const char *const *arg; GMainContext *context; gsize n; @@ -5162,13 +5161,9 @@ nm_utils_spawn_helper(const char *const *args, nm_g_timeout_source_new_seconds(20, G_PRIORITY_DEFAULT, helper_timeout, info, NULL); g_source_attach(info->timeout_source, context); - /* Set file descriptors as non-blocking */ - fd_flags = fcntl(info->child_stdin, F_GETFL, 0); - fcntl(info->child_stdin, F_SETFL, fd_flags | O_NONBLOCK); - fd_flags = fcntl(info->child_stdout, F_GETFL, 0); - fcntl(info->child_stdout, F_SETFL, fd_flags | O_NONBLOCK); - fd_flags = fcntl(info->child_stderr, F_GETFL, 0); - fcntl(info->child_stderr, F_SETFL, fd_flags | O_NONBLOCK); + nm_io_fcntl_setfl_update_nonblock(info->child_stdin); + nm_io_fcntl_setfl_update_nonblock(info->child_stdout); + nm_io_fcntl_setfl_update_nonblock(info->child_stderr); /* Watch process stdin */ for (n = 1, arg = args; *arg; arg++) diff --git a/src/libnmc-base/nm-polkit-listener.c b/src/libnmc-base/nm-polkit-listener.c index 7b0de39bcb..c715b0494a 100644 --- a/src/libnmc-base/nm-polkit-listener.c +++ b/src/libnmc-base/nm-polkit-listener.c @@ -499,7 +499,6 @@ out: static void begin_authentication(AuthRequest *request) { - int fd_flags; const char *helper_argv[] = { POLKIT_AGENT_HELPER_1_PATH, request->username, @@ -534,11 +533,8 @@ begin_authentication(AuthRequest *request) return; } - fd_flags = fcntl(request->child_stdin, F_GETFL, 0); - fcntl(request->child_stdin, F_SETFL, fd_flags | O_NONBLOCK); - - fd_flags = fcntl(request->child_stdout, F_GETFL, 0); - fcntl(request->child_stdout, F_SETFL, fd_flags | O_NONBLOCK); + nm_io_fcntl_setfl_update_nonblock(request->child_stdin); + nm_io_fcntl_setfl_update_nonblock(request->child_stdout); request->child_stdout_watch_source = nm_g_unix_fd_source_new(request->child_stdout, G_IO_IN | G_IO_ERR | G_IO_HUP, From 1378ed7d963bf10cdeb28b7999ad490ca8963509 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Mon, 3 Apr 2023 19:45:36 +0200 Subject: [PATCH 09/16] core: drop unnecessary initialization in nm_utils_spawn_helper() We did not initialize "child_stderr". If that were necessary, we would need to add it too. However, it is clearly not necessary to initialize those fields. --- src/core/nm-core-utils.c | 5 +---- 1 file changed, 1 insertion(+), 4 deletions(-) diff --git a/src/core/nm-core-utils.c b/src/core/nm-core-utils.c index 6417cfc43f..628947a969 100644 --- a/src/core/nm-core-utils.c +++ b/src/core/nm-core-utils.c @@ -5098,10 +5098,7 @@ nm_utils_spawn_helper(const char *const *args, info = g_new(HelperInfo, 1); *info = (HelperInfo){ - .task = nm_g_task_new(NULL, cancellable, nm_utils_spawn_helper, callback, cb_data), - .child_stdin = -1, - .child_stdout = -1, - .pid = -1, + .task = nm_g_task_new(NULL, cancellable, nm_utils_spawn_helper, callback, cb_data), }; if (!g_spawn_async_with_pipes("/", From 64825b4f58489f64c6cde82c76c373264985b448 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 30 Mar 2023 18:49:00 +0200 Subject: [PATCH 10/16] ovsdb: don't track buffer offset in NMOvsdb data and refactor parsing JSON messages The "priv->bufp" offset is only used while parsing a message at a time. It's unnecessary to track it in NMOvsdbPrivate and keep it between parsing messages. Tracking the state in NMOvsdbPrivate makes it more complicated to understand, because one needs to reason at which times the state is used (when it really is not used). Also, move the parsing to a separate function. --- src/core/devices/ovs/nm-ovsdb.c | 71 +++++++++++++++++++++------------ 1 file changed, 46 insertions(+), 25 deletions(-) diff --git a/src/core/devices/ovs/nm-ovsdb.c b/src/core/devices/ovs/nm-ovsdb.c index 85b7953f7e..50239be6c7 100644 --- a/src/core/devices/ovs/nm-ovsdb.c +++ b/src/core/devices/ovs/nm-ovsdb.c @@ -138,7 +138,6 @@ typedef struct { GSocketConnection *conn; GCancellable *conn_cancellable; char buf[4096]; /* Input buffer */ - size_t bufp; /* Last decoded byte in the input buffer. */ GString *input; /* JSON stream waiting for decoding. */ GString *output; /* JSON stream to be sent. */ guint64 call_id_counter; @@ -2320,25 +2319,55 @@ ovsdb_got_msg(NMOvsdb *self, json_t *msg) /*****************************************************************************/ +typedef struct { + gsize bufp; + GString *input; +} JsonReadMsgData; + /* Lower level marshalling and demarshalling of the JSON-RPC traffic on the * ovsdb socket. */ static size_t -_json_callback(void *buffer, size_t buflen, void *user_data) +_json_read_msg_cb(void *buffer, size_t buflen, void *user_data) { - NMOvsdb *self = NM_OVSDB(user_data); - NMOvsdbPrivate *priv = NM_OVSDB_GET_PRIVATE(self); + JsonReadMsgData *data = user_data; - if (priv->bufp == priv->input->len) { + nm_assert(buffer); + nm_assert(buflen > 0); + + if (data->bufp == data->input->len) { /* No more bytes buffered for decoding. */ return 0; } /* Pass one more byte to the JSON decoder. */ - *(char *) buffer = priv->input->str[priv->bufp]; - priv->bufp++; + *(char *) buffer = data->input->str[data->bufp]; + data->bufp++; + return 1; +} - return (size_t) 1; +static json_t * +_json_read_msg(GString *input) +{ + JsonReadMsgData data = { + .bufp = 0, + .input = input, + }; + json_error_t json_error = { + 0, + }; + json_t *msg; + + /* The callback always eats up only up to a single byte. This makes it + * possible for us to identify complete JSON objects in spite of us not + * knowing the length in advance. */ + msg = json_load_callback(_json_read_msg_cb, &data, JSON_DISABLE_EOF_CHECK, &json_error); + if (!msg) + return NULL; + + nm_assert(data.bufp > 0); + g_string_erase(input, 0, data.bufp); + return msg; } /** @@ -2355,10 +2384,6 @@ ovsdb_read_cb(GObject *source_object, GAsyncResult *res, gpointer user_data) GInputStream *stream = G_INPUT_STREAM(source_object); GError *error = NULL; gssize size; - json_t *msg; - json_error_t json_error = { - 0, - }; size = g_input_stream_read_finish(stream, res, &error); if (size == -1) { @@ -2371,18 +2396,15 @@ ovsdb_read_cb(GObject *source_object, GAsyncResult *res, gpointer user_data) } g_string_append_len(priv->input, priv->buf, size); - do { - priv->bufp = 0; - /* The callback always eats up only up to a single byte. This makes - * it possible for us to identify complete JSON objects in spite of - * us not knowing the length in advance. */ - msg = json_load_callback(_json_callback, self, JSON_DISABLE_EOF_CHECK, &json_error); - if (msg) { - ovsdb_got_msg(self, msg); - g_string_erase(priv->input, 0, priv->bufp); - } - json_decref(msg); - } while (msg); + while (TRUE) { + nm_auto_decref_json json_t *msg = NULL; + + msg = _json_read_msg(priv->input); + if (!msg) + break; + + ovsdb_got_msg(self, msg); + } if (!priv->conn) return; @@ -2498,7 +2520,6 @@ ovsdb_disconnect(NMOvsdb *self, gboolean retry, gboolean is_disposing) _call_complete(call, NULL, error); } - priv->bufp = 0; g_string_truncate(priv->input, 0); g_string_truncate(priv->output, 0); g_clear_object(&priv->conn); From f862d4bbcef704e539fa98d98eacd398e8c6c57a Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 30 Mar 2023 20:12:50 +0200 Subject: [PATCH 11/16] ovsdb: use nm_auto_free cleanup attribute in "nm-ovsdb.c" --- src/core/devices/ovs/nm-ovsdb.c | 10 ++++------ 1 file changed, 4 insertions(+), 6 deletions(-) diff --git a/src/core/devices/ovs/nm-ovsdb.c b/src/core/devices/ovs/nm-ovsdb.c index 50239be6c7..bac6235429 100644 --- a/src/core/devices/ovs/nm-ovsdb.c +++ b/src/core/devices/ovs/nm-ovsdb.c @@ -1445,7 +1445,7 @@ ovsdb_next_command(NMOvsdb *self) { NMOvsdbPrivate *priv = NM_OVSDB_GET_PRIVATE(self); OvsdbMethodCall *call; - char *cmd; + nm_auto_free char *cmd = NULL; nm_auto_decref_json json_t *msg = NULL; if (!priv->conn) @@ -1586,7 +1586,6 @@ ovsdb_next_command(NMOvsdb *self) cmd = json_dumps(msg, 0); _LOGT_call(call, "send: call-id=%" G_GUINT64_FORMAT ", %s", call->call_id, cmd); g_string_append(priv->output, cmd); - free(cmd); ovsdb_write(self); } @@ -2187,9 +2186,9 @@ ovsdb_got_update(NMOvsdb *self, json_t *msg) static void ovsdb_got_echo(NMOvsdb *self, json_int_t id, json_t *data) { - NMOvsdbPrivate *priv = NM_OVSDB_GET_PRIVATE(self); - nm_auto_decref_json json_t *msg = NULL; - char *reply; + NMOvsdbPrivate *priv = NM_OVSDB_GET_PRIVATE(self); + nm_auto_decref_json json_t *msg = NULL; + nm_auto_free char *reply = NULL; gboolean output_was_empty; output_was_empty = priv->output->len == 0; @@ -2197,7 +2196,6 @@ ovsdb_got_echo(NMOvsdb *self, json_int_t id, json_t *data) msg = json_pack("{s:I, s:O}", "id", id, "result", data); reply = json_dumps(msg, 0); g_string_append(priv->output, reply); - free(reply); if (output_was_empty) ovsdb_write(self); From 7e12d437fe6302acdc4816d0dcf0c7a4ac778c45 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 30 Mar 2023 20:09:35 +0200 Subject: [PATCH 12/16] ovsdb: use the FD directly instead of GSocketConnection/GOutputStream GSocketConnection/GOutputStream/GInputStream seems rather unnecessary. Maybe they make sense when you want to write portable code (for Windows). Otherwise, watching a file descriptor and reading/writing it directly is simpler (and also more efficient). For example, we passed no GCancellable to g_input_stream_read_async(). What does that mean w.r.t. destroying the NMOvsdb instance? I suspect it's wrong, but it's hard to say, because there are so many layers of code. Note that we anyway keep state in NMOvsdb, namely the data we want to send (output_buf) and the data we partially received (input_buf). All we need, are poll notifications when the file descriptor is ready. To those, we hook up the read/write callbacks. Also before was the code async, and there were callbacks when when read/write was done. That does not simplify the code in any way. - we no longer use separate NMOvsdbPrivate.buf and NMOvsdbPrivate.input buffers. There is just a NMOvsdbPrivate.input_buf that can we can fill directly. --- src/core/devices/ovs/nm-ovsdb.c | 256 ++++++++++++++++---------------- 1 file changed, 126 insertions(+), 130 deletions(-) diff --git a/src/core/devices/ovs/nm-ovsdb.c b/src/core/devices/ovs/nm-ovsdb.c index bac6235429..2d080b3313 100644 --- a/src/core/devices/ovs/nm-ovsdb.c +++ b/src/core/devices/ovs/nm-ovsdb.c @@ -12,6 +12,7 @@ #include "libnm-glib-aux/nm-jansson.h" #include "libnm-glib-aux/nm-str-buf.h" +#include "libnm-glib-aux/nm-io-utils.h" #include "nm-core-utils.h" #include "libnm-core-intern/nm-core-internal.h" #include "devices/nm-device.h" @@ -134,13 +135,16 @@ enum { static guint signals[LAST_SIGNAL] = {0}; typedef struct { - NMPlatform *platform; - GSocketConnection *conn; - GCancellable *conn_cancellable; - char buf[4096]; /* Input buffer */ - GString *input; /* JSON stream waiting for decoding. */ - GString *output; /* JSON stream to be sent. */ - guint64 call_id_counter; + NMPlatform *platform; + int conn_fd; + GSource *conn_fd_in_source; + GSource *conn_fd_out_source; + GCancellable *conn_cancellable; + + NMStrBuf input_buf; + NMStrBuf output_buf; + + guint64 call_id_counter; CList calls_lst_head; @@ -176,12 +180,13 @@ NM_DEFINE_SINGLETON_GETTER(NMOvsdb, nm_ovsdb_get, NM_TYPE_OVSDB); /*****************************************************************************/ -static void ovsdb_try_connect(NMOvsdb *self); -static void ovsdb_disconnect(NMOvsdb *self, gboolean retry, gboolean is_disposing); -static void ovsdb_read(NMOvsdb *self); -static void ovsdb_write(NMOvsdb *self); -static void ovsdb_next_command(NMOvsdb *self); -static void cleanup_check_ready(NMOvsdb *self); +static void ovsdb_try_connect(NMOvsdb *self); +static void ovsdb_disconnect(NMOvsdb *self, gboolean retry, gboolean is_disposing); +static void ovsdb_read(NMOvsdb *self); +static void ovsdb_write_try(NMOvsdb *self); +static gboolean ovsdb_write_cb(int fd, GIOCondition condition, gpointer user_data); +static void ovsdb_next_command(NMOvsdb *self); +static void cleanup_check_ready(NMOvsdb *self); /*****************************************************************************/ @@ -1448,7 +1453,7 @@ ovsdb_next_command(NMOvsdb *self) nm_auto_free char *cmd = NULL; nm_auto_decref_json json_t *msg = NULL; - if (!priv->conn) + if (priv->conn_fd < 0) return; if (c_list_is_empty(&priv->calls_lst_head)) @@ -1585,9 +1590,9 @@ ovsdb_next_command(NMOvsdb *self) cmd = json_dumps(msg, 0); _LOGT_call(call, "send: call-id=%" G_GUINT64_FORMAT ", %s", call->call_id, cmd); - g_string_append(priv->output, cmd); + nm_str_buf_append(&priv->output_buf, cmd); - ovsdb_write(self); + ovsdb_write_try(self); } /** @@ -2189,16 +2194,12 @@ ovsdb_got_echo(NMOvsdb *self, json_int_t id, json_t *data) NMOvsdbPrivate *priv = NM_OVSDB_GET_PRIVATE(self); nm_auto_decref_json json_t *msg = NULL; nm_auto_free char *reply = NULL; - gboolean output_was_empty; - - output_was_empty = priv->output->len == 0; msg = json_pack("{s:I, s:O}", "id", id, "result", data); reply = json_dumps(msg, 0); - g_string_append(priv->output, reply); + nm_str_buf_append(&priv->output_buf, reply); - if (output_was_empty) - ovsdb_write(self); + ovsdb_write_try(self); } /** @@ -2302,7 +2303,7 @@ ovsdb_got_msg(NMOvsdb *self, json_t *msg) /* Don't progress further commands in case the callback hit an error * and disconnected us. */ - if (!priv->conn) + if (priv->conn_fd < 0) return; /* Now we're free to serialize and send the next command, if any. */ @@ -2318,8 +2319,8 @@ ovsdb_got_msg(NMOvsdb *self, json_t *msg) /*****************************************************************************/ typedef struct { - gsize bufp; - GString *input; + gsize bufp; + NMStrBuf *input; } JsonReadMsgData; /* Lower level marshalling and demarshalling of the JSON-RPC traffic on the @@ -2339,13 +2340,13 @@ _json_read_msg_cb(void *buffer, size_t buflen, void *user_data) } /* Pass one more byte to the JSON decoder. */ - *(char *) buffer = data->input->str[data->bufp]; + *(char *) buffer = nm_str_buf_get_char(data->input, data->bufp); data->bufp++; return 1; } static json_t * -_json_read_msg(GString *input) +_json_read_msg(NMStrBuf *input) { JsonReadMsgData data = { .bufp = 0, @@ -2364,114 +2365,112 @@ _json_read_msg(GString *input) return NULL; nm_assert(data.bufp > 0); - g_string_erase(input, 0, data.bufp); + nm_str_buf_erase(input, 0, data.bufp, FALSE); return msg; } -/** - * ovsdb_read_cb: - * - * Read out the data available from the ovsdb socket and try to deserialize - * the JSON. If we see a complete object, pass it upwards to ovsdb_got_msg(). - */ -static void -ovsdb_read_cb(GObject *source_object, GAsyncResult *res, gpointer user_data) -{ - NMOvsdb *self = NM_OVSDB(user_data); - NMOvsdbPrivate *priv = NM_OVSDB_GET_PRIVATE(self); - GInputStream *stream = G_INPUT_STREAM(source_object); - GError *error = NULL; - gssize size; - - size = g_input_stream_read_finish(stream, res, &error); - if (size == -1) { - /* ovsdb-server was possibly restarted */ - _LOGW("short read from ovsdb: %s", error->message); - priv->num_failures++; - g_clear_error(&error); - ovsdb_disconnect(self, priv->num_failures <= OVSDB_MAX_FAILURES, FALSE); - return; - } - - g_string_append_len(priv->input, priv->buf, size); - while (TRUE) { - nm_auto_decref_json json_t *msg = NULL; - - msg = _json_read_msg(priv->input); - if (!msg) - break; - - ovsdb_got_msg(self, msg); - } - - if (!priv->conn) - return; - - if (size) - ovsdb_read(self); -} - static void ovsdb_read(NMOvsdb *self) { NMOvsdbPrivate *priv = NM_OVSDB_GET_PRIVATE(self); - - g_input_stream_read_async(g_io_stream_get_input_stream(G_IO_STREAM(priv->conn)), - priv->buf, - sizeof(priv->buf), - G_PRIORITY_DEFAULT, - NULL, - ovsdb_read_cb, - self); -} - -static void -ovsdb_write_cb(GObject *source_object, GAsyncResult *res, gpointer user_data) -{ - GOutputStream *stream = G_OUTPUT_STREAM(source_object); - NMOvsdb *self = NM_OVSDB(user_data); - NMOvsdbPrivate *priv = NM_OVSDB_GET_PRIVATE(self); - GError *error = NULL; gssize size; - size = g_output_stream_write_finish(stream, res, &error); - if (size == -1) { +again: + size = nm_utils_fd_read(priv->conn_fd, &priv->input_buf); + + if (size <= 0) { + if (size == -EAGAIN) + return; + /* ovsdb-server was possibly restarted */ - _LOGW("short write to ovsdb: %s", error->message); + _LOGW("short read from ovsdb: %s", nm_strerror_native(-size)); priv->num_failures++; - g_clear_error(&error); ovsdb_disconnect(self, priv->num_failures <= OVSDB_MAX_FAILURES, FALSE); return; } - if (!priv->conn) - return; + nm_assert(priv->input_buf.len > 0); - g_string_erase(priv->output, 0, size); + while (TRUE) { + nm_auto_decref_json json_t *msg = NULL; - ovsdb_write(self); + msg = _json_read_msg(&priv->input_buf); + if (!msg) + break; + + ovsdb_got_msg(self, msg); + + if (priv->input_buf.len == 0) + break; + } + + if (priv->input_buf.len > 0) { + /* We have an incomplete message in the message buffer. Don't wait for another round + * of "poll", instead try to read it again. */ + goto again; + } +} + +static gboolean +ovsdb_read_cb(int fd, GIOCondition condition, gpointer user_data) +{ + ovsdb_read(user_data); + return G_SOURCE_CONTINUE; } static void ovsdb_write(NMOvsdb *self) { NMOvsdbPrivate *priv = NM_OVSDB_GET_PRIVATE(self); - GOutputStream *stream; + gssize n; - if (!priv->output->len) +again: + if (priv->output_buf.len == 0) { + nm_clear_g_source_inst(&priv->conn_fd_out_source); return; + } - stream = g_io_stream_get_output_stream(G_IO_STREAM(priv->conn)); - if (g_output_stream_has_pending(stream)) + n = write(priv->conn_fd, + nm_str_buf_get_str_at_unsafe(&priv->output_buf, 0), + priv->output_buf.len); + + if (n < 0) + n = -NM_ERRNO_NATIVE(errno); + + if (n == -EAGAIN) { + if (!priv->conn_fd_out_source) { + priv->conn_fd_out_source = + nm_g_unix_fd_add_source(priv->conn_fd, G_IO_OUT, ovsdb_write_cb, self); + } return; + } - g_output_stream_write_async(stream, - priv->output->str, - priv->output->len, - G_PRIORITY_DEFAULT, - NULL, - ovsdb_write_cb, - self); + if (n <= 0) { + /* ovsdb-server was possibly restarted */ + _LOGW("short write to ovsdb: %s", nm_strerror_native(-n)); + priv->num_failures++; + ovsdb_disconnect(self, priv->num_failures <= OVSDB_MAX_FAILURES, FALSE); + return; + } + + nm_str_buf_erase(&priv->output_buf, 0, n, FALSE); + goto again; +} + +static void +ovsdb_write_try(NMOvsdb *self) +{ + NMOvsdbPrivate *priv = NM_OVSDB_GET_PRIVATE(self); + + if (priv->conn_fd >= 0 && !priv->conn_fd_out_source) + ovsdb_write(self); +} + +static gboolean +ovsdb_write_cb(int fd, GIOCondition condition, gpointer user_data) +{ + ovsdb_write(user_data); + return G_SOURCE_CONTINUE; } /*****************************************************************************/ @@ -2494,7 +2493,7 @@ ovsdb_disconnect(NMOvsdb *self, gboolean retry, gboolean is_disposing) nm_assert(!retry || !is_disposing); - if (!priv->conn && !priv->conn_cancellable) + if (priv->conn_fd < 0 && !priv->conn_cancellable) return; _LOGD("disconnecting from ovsdb, retry %d", retry); @@ -2518,9 +2517,11 @@ ovsdb_disconnect(NMOvsdb *self, gboolean retry, gboolean is_disposing) _call_complete(call, NULL, error); } - g_string_truncate(priv->input, 0); - g_string_truncate(priv->output, 0); - g_clear_object(&priv->conn); + nm_str_buf_reset(&priv->input_buf); + nm_str_buf_reset(&priv->output_buf); + nm_clear_fd(&priv->conn_fd); + nm_clear_g_source_inst(&priv->conn_fd_in_source); + nm_clear_g_source_inst(&priv->conn_fd_out_source); nm_clear_g_free(&priv->db_uuid); nm_clear_g_cancellable(&priv->conn_cancellable); @@ -2721,15 +2722,12 @@ _ovsdb_connect_complete_with_fd(NMOvsdb *self, int fd_take) gs_unref_object GSocket *socket = NULL; gs_free_error GError *error = NULL; - socket = g_socket_new_from_fd(nm_steal_fd(&fd_take), &error); - if (!socket) { - _LOGT("connect: failure to open socket for new FD: %s", error->message); - ovsdb_disconnect(self, FALSE, FALSE); - return; - } + nm_clear_g_cancellable(&priv->conn_cancellable); - priv->conn = g_socket_connection_factory_create_connection(socket); - g_clear_object(&priv->conn_cancellable); + nm_io_fcntl_setfl_update_nonblock(fd_take); + + priv->conn_fd = nm_steal_fd(&fd_take); + priv->conn_fd_in_source = nm_g_unix_fd_add_source(priv->conn_fd, G_IO_IN, ovsdb_read_cb, self); ovsdb_read(self); ovsdb_next_command(self); @@ -2803,7 +2801,7 @@ ovsdb_try_connect(NMOvsdb *self) { NMOvsdbPrivate *priv = NM_OVSDB_GET_PRIVATE(self); - if (priv->conn || priv->conn_cancellable) + if (priv->conn_fd >= 0 || priv->conn_cancellable) return; _LOGT("connect: start connecting socket %s on idle", NM_OVSDB_SOCKET); @@ -2983,11 +2981,15 @@ nm_ovsdb_init(NMOvsdb *self) { NMOvsdbPrivate *priv = NM_OVSDB_GET_PRIVATE(self); + priv->conn_fd = -1; + + priv->input_buf = NM_STR_BUF_INIT(0, FALSE); + priv->output_buf = NM_STR_BUF_INIT(0, FALSE); + c_list_init(&priv->calls_lst_head); priv->platform = g_object_ref(NM_PLATFORM_GET); - priv->input = g_string_new(NULL); - priv->output = g_string_new(NULL); + priv->bridges = g_hash_table_new_full(nm_pstr_hash, nm_pstr_equal, (GDestroyNotify) _free_bridge, NULL); priv->ports = @@ -3008,14 +3010,8 @@ dispose(GObject *object) nm_assert(c_list_is_empty(&priv->calls_lst_head)); - if (priv->input) { - g_string_free(priv->input, TRUE); - priv->input = NULL; - } - if (priv->output) { - g_string_free(priv->output, TRUE); - priv->output = NULL; - } + nm_str_buf_destroy(&priv->input_buf); + nm_str_buf_destroy(&priv->output_buf); g_clear_object(&priv->platform); nm_clear_pointer(&priv->bridges, g_hash_table_destroy); From f7d321c6d6ab0eba1052163b114a5139b72c1889 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 30 Mar 2023 20:28:31 +0200 Subject: [PATCH 13/16] ovsdb: add watchdog for unparsable JSON data in socket --- src/core/devices/ovs/nm-ovsdb.c | 31 ++++++++++++++++++++++++++++++- 1 file changed, 30 insertions(+), 1 deletion(-) diff --git a/src/core/devices/ovs/nm-ovsdb.c b/src/core/devices/ovs/nm-ovsdb.c index 2d080b3313..0e10aa2f0d 100644 --- a/src/core/devices/ovs/nm-ovsdb.c +++ b/src/core/devices/ovs/nm-ovsdb.c @@ -144,6 +144,8 @@ typedef struct { NMStrBuf input_buf; NMStrBuf output_buf; + GSource *input_timeout_source; + guint64 call_id_counter; CList calls_lst_head; @@ -2369,6 +2371,18 @@ _json_read_msg(NMStrBuf *input) return msg; } +static gboolean +_ovsdb_read_input_timeout_cb(gpointer user_data) +{ + NMOvsdb *self = user_data; + NMOvsdbPrivate *priv = NM_OVSDB_GET_PRIVATE(self); + + _LOGW("invalid/incomplete data in receive buffer. Reset"); + priv->num_failures++; + ovsdb_disconnect(self, priv->num_failures <= OVSDB_MAX_FAILURES, FALSE); + return G_SOURCE_CONTINUE; +} + static void ovsdb_read(NMOvsdb *self) { @@ -2379,8 +2393,19 @@ again: size = nm_utils_fd_read(priv->conn_fd, &priv->input_buf); if (size <= 0) { - if (size == -EAGAIN) + if (size == -EAGAIN) { + if (priv->input_buf.len == 0) + nm_clear_g_source_inst(&priv->input_timeout_source); + else if (!priv->input_timeout_source) { + /* We have data in the buffer but nothing further to read. Schedule a timer, + * if we don't get the rest within timeout, it means that the buffer + * content is broken (_json_read_msg() cannot extract any data) and + * we disconnect. */ + priv->input_timeout_source = + nm_g_timeout_add_seconds_source(5, _ovsdb_read_input_timeout_cb, NULL); + } return; + } /* ovsdb-server was possibly restarted */ _LOGW("short read from ovsdb: %s", nm_strerror_native(-size)); @@ -2398,6 +2423,7 @@ again: if (!msg) break; + nm_clear_g_source_inst(&priv->input_timeout_source); ovsdb_got_msg(self, msg); if (priv->input_buf.len == 0) @@ -2409,6 +2435,8 @@ again: * of "poll", instead try to read it again. */ goto again; } + + nm_clear_g_source_inst(&priv->input_timeout_source); } static gboolean @@ -2522,6 +2550,7 @@ ovsdb_disconnect(NMOvsdb *self, gboolean retry, gboolean is_disposing) nm_clear_fd(&priv->conn_fd); nm_clear_g_source_inst(&priv->conn_fd_in_source); nm_clear_g_source_inst(&priv->conn_fd_out_source); + nm_clear_g_source_inst(&priv->input_timeout_source); nm_clear_g_free(&priv->db_uuid); nm_clear_g_cancellable(&priv->conn_cancellable); From 25c97817d2ff4c62bacd46eade061d408eb50b20 Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 30 Mar 2023 20:44:42 +0200 Subject: [PATCH 14/16] ovsdb: limit maxiumum data size for receive buffer from ovsdb --- src/core/devices/ovs/nm-ovsdb.c | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/src/core/devices/ovs/nm-ovsdb.c b/src/core/devices/ovs/nm-ovsdb.c index 0e10aa2f0d..dc8bf289fe 100644 --- a/src/core/devices/ovs/nm-ovsdb.c +++ b/src/core/devices/ovs/nm-ovsdb.c @@ -2431,6 +2431,12 @@ again: } if (priv->input_buf.len > 0) { + if (priv->input_buf.len > 50 * 1024 * 1024) { + _LOGW("received too much data from ovsdb that is not valid JSON"); + priv->num_failures++; + ovsdb_disconnect(self, priv->num_failures <= OVSDB_MAX_FAILURES, FALSE); + return; + } /* We have an incomplete message in the message buffer. Don't wait for another round * of "poll", instead try to read it again. */ goto again; From 0ee60b943d07dcbbc8507e346175bac9bb49bd6d Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Thu, 30 Mar 2023 20:50:29 +0200 Subject: [PATCH 15/16] ovsdb: downgrade error logging to warnings is mostly about "really should not happen" scenarios. It's closer to an assertion failure, and something that NetworkManager should not happen. Of course, things can go wrong, but is a sufficient. When ovsdb gives unexpected communication, it's just a warning. At least, that's also what all the similar cases in "nm-ovsdb.c" already do --- src/core/devices/ovs/nm-ovsdb.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/core/devices/ovs/nm-ovsdb.c b/src/core/devices/ovs/nm-ovsdb.c index dc8bf289fe..8c463106fd 100644 --- a/src/core/devices/ovs/nm-ovsdb.c +++ b/src/core/devices/ovs/nm-ovsdb.c @@ -2274,13 +2274,13 @@ ovsdb_got_msg(NMOvsdb *self, json_t *msg) /* This is a response to a method call. */ if (c_list_is_empty(&priv->calls_lst_head)) { - _LOGE("there are no queued calls expecting response %" G_GUINT64_FORMAT, (guint64) id); + _LOGW("there are no queued calls expecting response %" G_GUINT64_FORMAT, (guint64) id); ovsdb_disconnect(self, FALSE, FALSE); return; } call = c_list_first_entry(&priv->calls_lst_head, OvsdbMethodCall, calls_lst); if (call->call_id != id) { - _LOGE("expected a response to call %" G_GUINT64_FORMAT ", not %" G_GUINT64_FORMAT, + _LOGW("expected a response to call %" G_GUINT64_FORMAT ", not %" G_GUINT64_FORMAT, call->call_id, (guint64) id); ovsdb_disconnect(self, FALSE, FALSE); From 3a76d717dab30e525ff7e451bd8418ebba9c7afc Mon Sep 17 00:00:00 2001 From: Thomas Haller Date: Tue, 4 Apr 2023 08:56:12 +0200 Subject: [PATCH 16/16] ovsdb: debug log all messages of socket buffer --- src/core/devices/ovs/nm-ovsdb.c | 13 +++++++++++-- 1 file changed, 11 insertions(+), 2 deletions(-) diff --git a/src/core/devices/ovs/nm-ovsdb.c b/src/core/devices/ovs/nm-ovsdb.c index 8c463106fd..68366f7398 100644 --- a/src/core/devices/ovs/nm-ovsdb.c +++ b/src/core/devices/ovs/nm-ovsdb.c @@ -2199,6 +2199,9 @@ ovsdb_got_echo(NMOvsdb *self, json_int_t id, json_t *data) msg = json_pack("{s:I, s:O}", "id", id, "result", data); reply = json_dumps(msg, 0); + + _LOGT("send: echo: %s", reply); + nm_str_buf_append(&priv->output_buf, reply); ovsdb_write_try(self); @@ -2348,8 +2351,9 @@ _json_read_msg_cb(void *buffer, size_t buflen, void *user_data) } static json_t * -_json_read_msg(NMStrBuf *input) +_json_read_msg(NMOvsdb *self, NMStrBuf *input) { + gs_free char *ss = NULL; JsonReadMsgData data = { .bufp = 0, .input = input, @@ -2367,6 +2371,11 @@ _json_read_msg(NMStrBuf *input) return NULL; nm_assert(data.bufp > 0); + + _LOGT("json: parse %zu bytes: \"%s\"", + data.bufp, + (ss = g_strndup(nm_str_buf_get_str_at_unsafe(input, 0), data.bufp))); + nm_str_buf_erase(input, 0, data.bufp, FALSE); return msg; } @@ -2419,7 +2428,7 @@ again: while (TRUE) { nm_auto_decref_json json_t *msg = NULL; - msg = _json_read_msg(&priv->input_buf); + msg = _json_read_msg(self, &priv->input_buf); if (!msg) break;