networkd: use structured logging for links and bridges

This commit is contained in:
Zbigniew Jędrzejewski-Szmek 2014-01-08 20:42:38 -05:00
parent 2ad8416dd0
commit 3333d748fa
4 changed files with 143 additions and 75 deletions

2
TODO
View File

@ -32,6 +32,8 @@ External:
Features:
* machinectl bash completion is missing
* Introduce PrivateDevices=yes/no which works like PrivateTmp= but for /dev setting up a tmpfs for it that only includes /dev/null, /dev/zero, /dev/random, /dev/urandom, but nothing else.
* libsystemd-journal returns the object created as first param in sd_journal_new(), sd_bus_new() and suchlike as last...

View File

@ -86,21 +86,25 @@ static int bridge_join_ready(Bridge *bridge, Link* link, sd_rtnl_message_handler
r = sd_rtnl_message_link_new(RTM_SETLINK, link->ifindex, &req);
if (r < 0) {
log_error("Could not allocate RTM_SETLINK message: %s",
strerror(-r));
log_error_bridge(bridge,
"Could not allocate RTM_SETLINK message: %s",
strerror(-r));
return r;
}
r = sd_rtnl_message_append_u32(req, IFLA_MASTER, bridge->link->ifindex);
if (r < 0) {
log_error("Could not append IFLA_MASTER attribute: %s",
strerror(-r));
log_error_bridge(bridge,
"Could not append IFLA_MASTER attribute: %s",
strerror(-r));
return r;
}
r = sd_rtnl_call_async(bridge->manager->rtnl, req, callback, link, 0, NULL);
if (r < 0) {
log_error("Could not send rtnetlink message: %s", strerror(-r));
log_error_bridge(bridge,
"Could not send rtnetlink message: %s",
strerror(-r));
return r;
}
@ -112,7 +116,7 @@ static int bridge_enter_ready(Bridge *bridge) {
bridge->state = BRIDGE_STATE_READY;
log_info("%s: bridge ready", bridge->name);
log_bridge_info(bridge, "bridge ready");
LIST_FOREACH(callbacks, callback, bridge->callbacks) {
/* join the links that were attempted to be joined befor the
@ -131,7 +135,7 @@ static int bridge_create_handler(sd_rtnl *rtnl, sd_rtnl_message *m, void *userda
r = sd_rtnl_message_get_errno(m);
if (r < 0) {
log_warning("%s: bridge failed: %s", bridge->name, strerror(-r));
log_warning_bridge(bridge, "bridge failed: %s", strerror(-r));
bridge_enter_failed(bridge);
return 1;
@ -157,46 +161,52 @@ static int bridge_create(Bridge *bridge) {
r = sd_rtnl_message_link_new(RTM_NEWLINK, 0, &req);
if (r < 0) {
log_error("Could not allocate RTM_NEWLINK message: %s",
strerror(-r));
log_error_bridge(bridge,
"Could not allocate RTM_NEWLINK message: %s",
strerror(-r));
return r;
}
r = sd_rtnl_message_append_string(req, IFLA_IFNAME, bridge->name);
if (r < 0) {
log_error("Could not append IFLA_IFNAME attribute: %s",
strerror(-r));
log_error_bridge(bridge,
"Could not append IFLA_IFNAME attribute: %s",
strerror(-r));
return r;
}
r = sd_rtnl_message_open_container(req, IFLA_LINKINFO);
if (r < 0) {
log_error("Colud not open IFLA_LINKINFO container: %s",
strerror(-r));
log_error_bridge(bridge,
"Could not open IFLA_LINKINFO container: %s",
strerror(-r));
return r;
}
r = sd_rtnl_message_append_string(req, IFLA_INFO_KIND, "bridge");
if (r < 0) {
log_error("Could not append IFLA_INFO_KIND attribute: %s",
strerror(-r));
log_error_bridge(bridge,
"Could not append IFLA_INFO_KIND attribute: %s",
strerror(-r));
return r;
}
r = sd_rtnl_message_close_container(req);
if (r < 0) {
log_error("Could not close IFLA_LINKINFO container %s",
strerror(-r));
log_error_bridge(bridge,
"Could not close IFLA_LINKINFO container %s",
strerror(-r));
return r;
}
r = sd_rtnl_call_async(bridge->manager->rtnl, req, &bridge_create_handler, bridge, 0, NULL);
if (r < 0) {
log_error("Could not send rtnetlink message: %s", strerror(-r));
log_error_bridge(bridge,
"Could not send rtnetlink message: %s", strerror(-r));
return r;
}
log_debug("%s: creating bridge", bridge->name);
log_bridge_debug(bridge, "creating bridge");
bridge->state = BRIDGE_STATE_CREATING;

View File

@ -134,7 +134,7 @@ static int link_enter_configured(Link *link) {
assert(link);
assert(link->state == LINK_STATE_SETTING_ROUTES);
log_info("%s: link configured", link->ifname);
log_link_info(link, "link configured");
link->state = LINK_STATE_CONFIGURED;
@ -144,7 +144,7 @@ static int link_enter_configured(Link *link) {
static void link_enter_failed(Link *link) {
assert(link);
log_warning("%s: failed", link->ifname);
log_link_warning(link, "failed");
link->state = LINK_STATE_FAILED;
}
@ -165,13 +165,12 @@ static int route_handler(sd_rtnl *rtnl, sd_rtnl_message *m, void *userdata) {
r = sd_rtnl_message_get_errno(m);
if (r < 0 && r != -EEXIST)
log_warning("%s: could not set route: %s",
link->ifname, strerror(-r));
log_warning_link(link, "could not set route: %s", strerror(-r));
/* we might have received an old reply after moving back to SETTING_ADDRESSES,
* ignore it */
if (link->route_messages == 0 && link->state == LINK_STATE_SETTING_ROUTES) {
log_debug("%s: routes set", link->ifname);
log_link_debug(link, "routes set");
link_enter_configured(link);
}
@ -191,12 +190,13 @@ static int link_enter_set_routes(Link *link) {
if (!link->network->static_routes && !link->dhcp_route)
return link_enter_configured(link);
log_debug("%s: setting routes", link->ifname);
log_link_debug(link, "setting routes");
LIST_FOREACH(static_routes, route, link->network->static_routes) {
r = route_configure(route, link, &route_handler);
if (r < 0) {
log_warning("%s: could not set routes", link->ifname);
log_warning_link(link,
"could not set routes: %s", strerror(-r));
link_enter_failed(link);
return r;
}
@ -207,7 +207,8 @@ static int link_enter_set_routes(Link *link) {
if (link->dhcp_route) {
r = route_configure(link->dhcp_route, link, &route_handler);
if (r < 0) {
log_warning("%s: could not set routes", link->ifname);
log_warning_link(link,
"could not set routes: %s", strerror(-r));
link_enter_failed(link);
return r;
}
@ -235,11 +236,14 @@ static int address_handler(sd_rtnl *rtnl, sd_rtnl_message *m, void *userdata) {
r = sd_rtnl_message_get_errno(m);
if (r < 0 && r != -EEXIST)
log_warning("%s: could not set address: %s",
link->ifname, strerror(-r));
log_struct_link(LOG_ERR, link,
"MESSAGE=%s: could not set address: %s",
link->ifname, strerror(-r),
"ERRNO=%d", -r,
NULL);
if (link->addr_messages == 0) {
log_debug("%s: addresses set", link->ifname);
log_link_debug(link, "addresses set");
link_enter_set_routes(link);
}
@ -259,12 +263,13 @@ static int link_enter_set_addresses(Link *link) {
if (!link->network->static_addresses && !link->dhcp_address)
return link_enter_set_routes(link);
log_debug("%s: setting addresses", link->ifname);
log_link_debug(link, "setting addresses");
LIST_FOREACH(static_addresses, address, link->network->static_addresses) {
r = address_configure(address, link, &address_handler);
if (r < 0) {
log_warning("%s: could not set addresses", link->ifname);
log_warning_link(link,
"could not set addresses: %s", strerror(-r));
link_enter_failed(link);
return r;
}
@ -275,7 +280,8 @@ static int link_enter_set_addresses(Link *link) {
if (link->dhcp_address) {
r = address_configure(link->dhcp_address, link, &address_handler);
if (r < 0) {
log_warning("%s: could not set addresses", link->ifname);
log_warning_link(link,
"could not set addresses: %s", strerror(-r));
link_enter_failed(link);
return r;
}
@ -299,8 +305,7 @@ static int address_drop_handler(sd_rtnl *rtnl, sd_rtnl_message *m, void *userdat
r = sd_rtnl_message_get_errno(m);
if (r < 0 && r != -EEXIST)
log_warning("%s: could not drop address: %s",
link->ifname, strerror(-r));
log_warning_link(link, "could not drop address: %s", strerror(-r));
return 1;
}
@ -319,13 +324,13 @@ static void dhcp_handler(sd_dhcp_client *client, int event, void *userdata) {
return;
if (event < 0) {
log_warning("%s: DHCP error: %s", link->ifname, strerror(-event));
log_warning_link(link, "DHCP error: %s", strerror(-event));
link_enter_failed(link);
return;
}
if (event == DHCP_EVENT_NO_LEASE)
log_debug("%s: IP address in use.", link->ifname);
log_link_debug(link, "IP address in use.");
if (event == DHCP_EVENT_IP_CHANGE || event == DHCP_EVENT_EXPIRED ||
event == DHCP_EVENT_STOP) {
@ -344,28 +349,28 @@ static void dhcp_handler(sd_dhcp_client *client, int event, void *userdata) {
r = sd_dhcp_client_get_address(client, &address);
if (r < 0) {
log_warning("%s: DHCP error: no address", link->ifname);
log_link_warning(link, "DHCP error: no address");
link_enter_failed(link);
return;
}
r = sd_dhcp_client_get_netmask(client, &netmask);
if (r < 0) {
log_warning("%s: DHCP error: no netmask", link->ifname);
log_link_warning(link, "DHCP error: no netmask");
link_enter_failed(link);
return;
}
prefixlen = sd_dhcp_client_prefixlen(&netmask);
if (prefixlen < 0) {
log_warning("%s: DHCP error: no prefixlen", link->ifname);
log_link_warning(link, "DHCP error: no prefixlen");
link_enter_failed(link);
return;
}
r = sd_dhcp_client_get_router(client, &gateway);
if (r < 0) {
log_warning("%s: DHCP error: no router", link->ifname);
log_link_warning(link, "DHCP error: no router");
link_enter_failed(link);
return;
}
@ -374,11 +379,11 @@ static void dhcp_handler(sd_dhcp_client *client, int event, void *userdata) {
_cleanup_address_free_ Address *addr = NULL;
_cleanup_route_free_ Route *rt = NULL;
log_info("%s: received config over DHCPv4", link->ifname);
log_link_info(link, "received config over DHCPv4");
r = address_new_dynamic(&addr);
if (r < 0) {
log_error("Could not allocate address");
log_link_error(link, "Could not allocate address");
link_enter_failed(link);
return;
}
@ -390,7 +395,7 @@ static void dhcp_handler(sd_dhcp_client *client, int event, void *userdata) {
r = route_new_dynamic(&rt);
if (r < 0) {
log_error("Could not allocate route");
log_link_error(link, "Could not allocate route");
link_enter_failed(link);
return;
}
@ -453,20 +458,17 @@ static int link_update_flags(Link *link, unsigned flags) {
return 0;
if (link->flags == flags) {
log_debug("%s: link status unchanged: %#x", link->ifname, flags);
log_debug_link(link, "link status unchanged: %#x", flags);
return 0;
}
if ((link->flags & IFF_UP) != (flags & IFF_UP)) {
if (flags & IFF_UP)
log_info("%s: power on", link->ifname);
else
log_info("%s: power off", link->ifname);
}
if ((link->flags & IFF_UP) != (flags & IFF_UP))
log_info_link(link,
"power %s", flags & IFF_UP ? "on": "off");
if ((link->flags & IFF_LOWER_UP) != (flags & IFF_LOWER_UP)) {
if (flags & IFF_LOWER_UP) {
log_info("%s: carrier on", link->ifname);
log_link_info(link, "carrier on");
if (link->network->dhcp) {
r = link_acquire_conf(link);
@ -476,7 +478,7 @@ static int link_update_flags(Link *link, unsigned flags) {
}
}
} else {
log_info("%s: carrier off", link->ifname);
log_link_info(link, "carrier off");
if (link->network->dhcp) {
r = sd_dhcp_client_stop(link->dhcp);
@ -488,7 +490,8 @@ static int link_update_flags(Link *link, unsigned flags) {
}
}
log_debug("%s: link status updated: %#x -> %#x", link->ifname, link->flags, flags);
log_debug_link(link,
"link status updated: %#x -> %#x", link->flags, flags);
link->flags = flags;
@ -506,8 +509,8 @@ static int link_up_handler(sd_rtnl *rtnl, sd_rtnl_message *m, void *userdata) {
r = sd_rtnl_message_get_errno(m);
if (r < 0) {
log_warning("%s: could not bring up interface: %s",
link->ifname, strerror(-r));
log_warning_link(link,
"could not bring up interface: %s", strerror(-r));
link_enter_failed(link);
}
@ -524,23 +527,24 @@ static int link_up(Link *link) {
assert(link->manager);
assert(link->manager->rtnl);
log_debug("%s: bringing up link", link->ifname);
log_link_debug(link, "bringing link up");
r = sd_rtnl_message_link_new(RTM_SETLINK, link->ifindex, &req);
if (r < 0) {
log_error("Could not allocate RTM_SETLINK message");
log_link_error(link, "Could not allocate RTM_SETLINK message");
return r;
}
r = sd_rtnl_message_link_set_flags(req, IFF_UP);
if (r < 0) {
log_error("Could not set link flags");
log_error_link(link, "Could not set link flags: %s", strerror(-r));
return r;
}
r = sd_rtnl_call_async(link->manager->rtnl, req, link_up_handler, link, 0, NULL);
if (r < 0) {
log_error("Could not send rtnetlink message: %s", strerror(-r));
log_error_link(link,
"Could not send rtnetlink message: %s", strerror(-r));
return r;
}
@ -579,14 +583,20 @@ static int bridge_handler(sd_rtnl *rtnl, sd_rtnl_message *m, void *userdata) {
r = sd_rtnl_message_get_errno(m);
if (r < 0) {
log_warning("%s: could not join bridge '%s': %s",
link->ifname, link->network->bridge->name, strerror(-r));
log_struct_link(LOG_ERR, link,
"MESSAGE=%s: could not join bridge '%s': %s",
link->ifname, link->network->bridge->name, strerror(-r),
BRIDGE(link->network->bridge),
NULL);
link_enter_failed(link);
return 1;
} else
log_debug("%s: joined bridge '%s'",
link->ifname, link->network->bridge->name);
}
log_struct_link(LOG_DEBUG, link,
"MESSAGE=%s: joined bridge '%s'",
link->network->bridge->name,
BRIDGE(link->network->bridge),
NULL);
link_bridge_joined(link);
return 1;
@ -604,12 +614,20 @@ static int link_enter_join_bridge(Link *link) {
if (!link->network->bridge)
return link_bridge_joined(link);
log_debug("%s: joining bridge", link->ifname);
log_struct_link(LOG_DEBUG, link,
"MESSAGE=%s: joining bridge '%s'",
link->network->bridge->name,
BRIDGE(link->network->bridge),
NULL);
log_link_debug(link, "joining bridge");
r = bridge_join(link->network->bridge, link, &bridge_handler);
if (r < 0) {
log_warning("%s: could not join bridge '%s'", link->ifname,
link->network->bridge->name);
log_struct_link(LOG_WARNING, link,
"MESSAGE=%s: could not join bridge '%s': %s",
link->network->bridge->name, strerror(-r),
BRIDGE(link->network->bridge),
NULL);
link_enter_failed(link);
return r;
}
@ -628,12 +646,11 @@ static int link_get_handler(sd_rtnl *rtnl, sd_rtnl_message *m, void *userdata) {
r = sd_rtnl_message_get_errno(m);
if (r < 0) {
log_warning("%s: could not get state: %s",
link->ifname, strerror(-r));
log_warning_link(link, "could not get state: %s", strerror(-r));
link_enter_failed(link);
}
log_debug("%s: got link state", link->ifname);
log_link_debug(link, "got link state");
link_update(link, m);
@ -648,17 +665,18 @@ static int link_get(Link *link) {
assert(link->manager);
assert(link->manager->rtnl);
log_debug("%s: requesting link status", link->ifname);
log_link_debug(link, "requesting link status");
r = sd_rtnl_message_link_new(RTM_GETLINK, link->ifindex, &req);
if (r < 0) {
log_error("Could not allocate RTM_GETLINK message");
log_link_error(link, "Could not allocate RTM_GETLINK message");
return r;
}
r = sd_rtnl_call_async(link->manager->rtnl, req, link_get_handler, link, 0, NULL);
if (r < 0) {
log_error("Could not send rtnetlink message: %s", strerror(-r));
log_error_link(link,
"Could not send rtnetlink message: %s", strerror(-r));
return r;
}
@ -693,7 +711,7 @@ int link_update(Link *link, sd_rtnl_message *m) {
r = sd_rtnl_message_link_get_flags(m, &flags);
if (r < 0) {
log_warning("%s: could not get link flags", link->ifname);
log_link_warning(link, "could not get link flags");
return r;
}

View File

@ -278,3 +278,41 @@ int link_update(Link *link, sd_rtnl_message *message);
DEFINE_TRIVIAL_CLEANUP_FUNC(Link*, link_free);
#define _cleanup_link_free_ _cleanup_(link_freep)
/* Macros which append INTERFACE= to the message */
#define log_full_link(level, link, fmt, ...) log_meta_object(level, __FILE__, __LINE__, __func__, "INTERFACE=", link->ifname, "%s: " fmt, link->ifname, __VA_ARGS__)
#define log_debug_link(link, ...) log_full_link(LOG_DEBUG, link, __VA_ARGS__)
#define log_info_link(link, ...) log_full_link(LOG_INFO, link, __VA_ARGS__)
#define log_notice_link(link, ...) log_full_link(LOG_NOTICE, link, __VA_ARGS__)
#define log_warning_link(link, ...) log_full_link(LOG_WARNING, link, __VA_ARGS__)
#define log_error_link(link, ...) log_full_link(LOG_ERR, link, __VA_ARGS__)
#define log_link_full(level, link, message) log_meta_object(level, __FILE__, __LINE__, __func__, "INTERFACE=", link->ifname, "%s: " message, link->ifname)
#define log_link_debug(link, ...) log_link_full(LOG_DEBUG, link, __VA_ARGS__)
#define log_link_info(link, ...) log_link_full(LOG_INFO, link, __VA_ARGS__)
#define log_link_notice(link, ...) log_link_full(LOG_NOTICE, link, __VA_ARGS__)
#define log_link_warning(link, ...) log_link_full(LOG_WARNING, link, __VA_ARGS__)
#define log_link_error(link, ...) log_link_full(LOG_ERR, link, __VA_ARGS__)
#define log_struct_link(level, link, ...) log_struct(level, "INTERFACE=%s", link->ifname, __VA_ARGS__)
/* More macros which append INTERFACE= to the message */
#define log_full_bridge(level, bridge, fmt, ...) log_meta_object(level, __FILE__, __LINE__, __func__, "INTERFACE=", bridge->name, "%s: " fmt, bridge->name, __VA_ARGS__)
#define log_debug_bridge(bridge, ...) log_full_bridge(LOG_DEBUG, bridge, __VA_ARGS__)
#define log_info_bridge(bridge, ...) log_full_bridge(LOG_INFO, bridge, __VA_ARGS__)
#define log_notice_bridge(bridge, ...) log_full_bridge(LOG_NOTICE, bridge, __VA_ARGS__)
#define log_warning_bridge(bridge, ...) log_full_bridge(LOG_WARNING, bridge, __VA_ARGS__)
#define log_error_bridge(bridge, ...) log_full_bridge(LOG_ERR, bridge, __VA_ARGS__)
#define log_bridge_full(level, bridge, message) log_meta_object(level, __FILE__, __LINE__, __func__, "INTERFACE=", bridge->name, "%s: " message, bridge->name)
#define log_bridge_debug(bridge, ...) log_bridge_full(LOG_DEBUG, bridge, __VA_ARGS__)
#define log_bridge_info(bridge, ...) log_bridge_full(LOG_INFO, bridge, __VA_ARGS__)
#define log_bridge_notice(bridge, ...) log_bridge_full(LOG_NOTICE, bridge, __VA_ARGS__)
#define log_bridge_warning(bridge, ...) log_bridge_full(LOG_WARNING, bridge, __VA_ARGS__)
#define log_bridge_error(bridge, ...) log_bridge_full(LOG_ERR, bridge, __VA_ARGS__)
#define log_struct_bridge(level, bridge, ...) log_struct(level, "INTERFACE=%s", bridge->name, __VA_ARGS__)
#define BRIDGE(bridge) "INTERFACE=%s", bridge->name