GNOME Bugzilla – Bug 779536
[review] lr/log-hints: tag device & connection for the log messages
Last modified: 2020-11-12 14:33:11 UTC
...and show user how to filter relevant logs on activation failure. https://cgit.freedesktop.org/NetworkManager/NetworkManager/log/?h=lr/log-hints
Created attachment 347200 [details] [review] Patch with suggestion of using NMLOGSTRUCT_*() macro > logging: respect choice of journal/syslog even with --debug could you explain in the commit message why this is useful? That is unclear to me, maybe it isn't?? + NM_CONFIG_GET_VALUE_STRIP | NM_CONFIG_GET_VALUE_NO_EMPTY), + nm_config_get_is_debug (config)); indention + (self) ? nm_device_get_iface (_nm_device_log_self_to_device (self)) : NULL, \ + NULL, (self), "device", \ indention Pushed one fixup. Rest lgtm. (but I would do a central part about this differently. See attached suggestion for what I mean)
> active-connection: log the connection context I think @device can be NULL here when the log macro is used before nm_active_connection_set_device() was called. > cli: advise the user to consult logs when a connection fails to activate: There are other places where nmcli reports an activation failure, for example: static void active_connection_state_cb (NMActiveConnection *active, GParamSpec *pspec, ActivateConnectionInfo *info) { [...] } else if (state == NM_ACTIVE_CONNECTION_STATE_DEACTIVATED) { g_string_printf (nmc->return_text, _("Error: Connection activation failed.")); nmc->return_value = NMC_RESULT_ERROR_CON_ACTIVATION; activate_connection_info_finish (info); or: static void activate_connection_cb (GObject *client, GAsyncResult *result, gpointer user_data) { [...] info->active = active = nm_client_activate_connection_finish (NM_CLIENT (client), result, &error); if (error) { g_string_printf (nmc->return_text, _("Error: Connection activation failed: %s"), error->message); g_error_free (error); nmc->return_value = NMC_RESULT_ERROR_CON_ACTIVATION; activate_connection_info_finish (info); Do we need to print the hint there too?
regarding the NMLOGSTRUCT_*() macros... in the patch attachment 347200 [details] [review], the _NMLogStruct is an implemenetation detail. The same effect could be achived via #define NMLOGSTRUCT_NONE() NULL, NULL #define NMLOGSTRUCT_DEV(dev) (dev), NULL #define NMLOGSTRUCT_DEV_CON(dev, con) (dev), (con) I care more about the usage of the NMLOGSTRUCT_*() macros, then about the _NMLogStruct structure. The NMLOGSTRUCT_*() macros, allow us to later add more fields without having to change all call sites. (but I still think the _NMLogStruct macro is slightly nicer then multiple arguments).
(In reply to Thomas Haller from comment #1) > Created attachment 347200 [details] [review] [review] > Patch with suggestion of using NMLOGSTRUCT_*() macro > > > > logging: respect choice of journal/syslog even with --debug > > could you explain in the commit message why this is useful? That is unclear > to me, maybe it isn't?? Right, it was not too clear. Amended the message, hopefully a bit better now. > NM_CONFIG_GET_VALUE_STRIP | NM_CONFIG_GET_VALUE_NO_EMPTY), > + nm_config_get_is_debug (config)); > > indention > > > > + (self) ? nm_device_get_iface (_nm_device_log_self_to_device > (self)) : NULL, \ > + NULL, (self), "device", \ > > > indention Fixed. > Pushed one fixup. Applied. > (but I would do a central part about this differently. See attached > suggestion for what I mean) I would prefer to leave it this way; it's really a simple thing, IMHO doesn't justify the extra complexity the NMLOGSTRUCT would involve. "NULL, NULL" doesn't look to me like something that would be of too much hassle. (In reply to Beniamino Galvani from comment #2) > > active-connection: log the connection context > > I think @device can be NULL here when the log macro is used before > nm_active_connection_set_device() was called. Fixed. > > cli: advise the user to consult logs when a connection fails to activate: > > There are other places where nmcli reports an activation failure, for > example: > > static void > active_connection_state_cb (NMActiveConnection *active, GParamSpec *pspec, > ActivateConnectionInfo *info) > { > [...] > } else if (state == NM_ACTIVE_CONNECTION_STATE_DEACTIVATED) { > g_string_printf (nmc->return_text, _("Error: Connection > activation failed.")); > nmc->return_value = NMC_RESULT_ERROR_CON_ACTIVATION; > activate_connection_info_finish (info); This one is from the editor; there I don't think it makes too much sense. > or: > > static void > activate_connection_cb (GObject *client, GAsyncResult *result, gpointer > user_data) > { > [...] > info->active = active = nm_client_activate_connection_finish > (NM_CLIENT (client), result, &error); > > if (error) { > g_string_printf (nmc->return_text, _("Error: Connection > activation failed: %s"), > error->message); > g_error_free (error); > nmc->return_value = NMC_RESULT_ERROR_CON_ACTIVATION; > activate_connection_info_finish (info); > > Do we need to print the hint there too? This one already has an error message directly from Activate() call and very likely no active connection instance. Pushed an updated branch.
> active-connection: log the connection context G_STMT_START { \ char _sbuf[64]; \ + NMDevice *_device = (self) ? NM_ACTIVE_CONNECTION_GET_PRIVATE (self)->device : NULL; Missing backslash at end of line. Also, during object construction nm_active_connection_set_device() calls _LOGD() with a possibly NULL priv->applied_connection; we should check it before calling nm_connection_get_uuid(). > cli: advise the user to consult logs when a connection fails to activate If I try to activate a DHCP connection and it times out, nmcli reports: Hint: use 'journalctl -xe NM_CONNECTION=8fac1606-754f-43f8-b471-5e554b160429' to get more details. The command gives: [..]: <debug> [1489583160.8482] settings-connection[0xc89dd0,8fac1606-754f-43f8-b471-5e554b160429]: replace settings from connection 0xc90f20 (host-dhcp+) [..]: <debug> [1489583169.9733] active-connection[0xd867e0]: constructed (NMActRequest, version-id 6) [..]: <debug> [1489583170.2381] active-connection[0xd867e0]: set state activating (was unknown) [..]: <debug> [1489583170.2381] active-connection[0xd867e0]: check-master-ready: not signalling (state activating, no master) [..]: <debug> [1489583185.6616] active-connection[0xd867e0]: set state deactivated (was activating) [..]: <debug> [1489583185.6616] active-connection[0xd867e0]: check-master-ready: not signalling (state deactivated, no master) [..]: <trace> [1489583185.6617] settings-connection[0xc89dd0,8fac1606-754f-43f8-b471-5e554b160429]: autoconnect-retries: set 3 [..]: <trace> [1489583185.6641] settings-connection[0xc89dd0,8fac1606-754f-43f8-b471-5e554b160429]: autoconnect-retries: set -2 [..]: <debug> [1489583185.6665] active-connection[0xd867e0]: disposing [..]: <debug> [1489583330.2793] active-connection[0xd86920]: constructed (NMActRequest, version-id 7) [..]: <debug> [1489583330.2802] active-connection[0xd86920]: set state activating (was unknown) [..]: <debug> [1489583330.2802] active-connection[0xd86920]: check-master-ready: not signalling (state activating, no master) [..]: <debug> [1489583345.6666] active-connection[0xd86920]: set state deactivated (was activating) [..]: <debug> [1489583345.6666] active-connection[0xd86920]: check-master-ready: not signalling (state deactivated, no master) [..]: <trace> [1489583345.6667] settings-connection[0xc89dd0,8fac1606-754f-43f8-b471-5e554b160429]: autoconnect-retries: set 3 [..]: <trace> [1489583345.6686] settings-connection[0xc89dd0,8fac1606-754f-43f8-b471-5e554b160429]: autoconnect-retries: set -2 [..]: <debug> [1489583345.6698] active-connection[0xd86920]: disposing which seems not so useful, as all the device logging is missing. In active_connection_hint() apparently nm_active_connection_get_devices() does not return the device; maybe active_connection_removed_cb() and other callers should pass in the device from info->device. The rest LGTM.
part 1 got merged: https://cgit.freedesktop.org/NetworkManager/NetworkManager/commit/?id=996e081af3ad00aadd0bd39a639a3fad00eb0525
bugzilla.gnome.org is being shut down in favor of a GitLab instance. We are closing all old bug reports and feature requests in GNOME Bugzilla which have not seen updates for a long time. If you still use NetworkManager and if you still see this bug / want this feature in a recent and supported version of NetworkManager, then please feel free to report it at https://gitlab.freedesktop.org/NetworkManager/NetworkManager/-/issues/ Thank you for creating this report and we are sorry it could not be implemented (workforce and time is unfortunately limited).