chiark / gitweb /
networkd: use structured logging for links and bridges
[elogind.git] / src / network / networkd-link.c
index 9d942f436b3ad0e0307ad461cdd87c4e98c6e2e2..2ed5e6b63f21a438fddf3f72a77cb861edde07eb 100644 (file)
@@ -89,7 +89,7 @@ void link_free(Link *link) {
         free(link);
 }
 
-int link_add(Manager *m, struct udev_device *device) {
+int link_add(Manager *m, struct udev_device *device, Link **ret) {
         Link *link;
         Network *network;
         int r;
@@ -101,20 +101,22 @@ int link_add(Manager *m, struct udev_device *device) {
 
         ifindex = udev_device_get_ifindex(device);
         link = hashmap_get(m->links, &ifindex);
-        if (link)
-                return 0;
+        if (link) {
+                *ret = link;
+                return -EEXIST;
+        }
 
         r = link_new(m, device, &link);
-        if (r < 0) {
-                log_error("Could not create link: %s", strerror(-r));
+        if (r < 0)
                 return r;
-        }
+
+        *ret = link;
 
         devtype = udev_device_get_devtype(device);
         if (streq_ptr(devtype, "bridge")) {
                 r = bridge_set_link(m, link);
-                if (r < 0)
-                        return r == -ENOENT ? 0 : r;
+                if (r < 0 && r != -ENOENT)
+                        return r;
         }
 
         r = network_get(m, device, &network);
@@ -132,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;
 
@@ -142,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;
 }
@@ -163,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);
         }
 
@@ -189,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;
                 }
@@ -205,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;
                 }
@@ -233,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);
         }
 
@@ -257,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;
                 }
@@ -273,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;
                 }
@@ -284,17 +292,230 @@ static int link_enter_set_addresses(Link *link) {
         return 0;
 }
 
+static int address_drop_handler(sd_rtnl *rtnl, sd_rtnl_message *m, void *userdata) {
+        Link *link = userdata;
+        int r;
+
+        assert(m);
+        assert(link);
+        assert(link->ifname);
+
+        if (link->state == LINK_STATE_FAILED)
+                return 1;
+
+        r = sd_rtnl_message_get_errno(m);
+        if (r < 0 && r != -EEXIST)
+                log_warning_link(link, "could not drop address: %s", strerror(-r));
+
+        return 1;
+}
+
+static void dhcp_handler(sd_dhcp_client *client, int event, void *userdata) {
+        Link *link = userdata;
+        struct in_addr address;
+        struct in_addr netmask;
+        struct in_addr gateway;
+        int prefixlen;
+        int r;
+
+        assert(link);
+
+        if (link->state == LINK_STATE_FAILED)
+                return;
+
+        if (event < 0) {
+                log_warning_link(link, "DHCP error: %s", strerror(-event));
+                link_enter_failed(link);
+                return;
+        }
+
+        if (event == DHCP_EVENT_NO_LEASE)
+                log_link_debug(link, "IP address in use.");
+
+        if (event == DHCP_EVENT_IP_CHANGE || event == DHCP_EVENT_EXPIRED ||
+            event == DHCP_EVENT_STOP) {
+                if (link->dhcp_address) {
+                        address_drop(link->dhcp_address, link, address_drop_handler);
+
+                        address_free(link->dhcp_address);
+                        link->dhcp_address = NULL;
+                }
+
+                if (link->dhcp_route) {
+                        route_free(link->dhcp_route);
+                        link->dhcp_route = NULL;
+                }
+        }
+
+        r = sd_dhcp_client_get_address(client, &address);
+        if (r < 0) {
+                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_link_warning(link, "DHCP error: no netmask");
+                link_enter_failed(link);
+                return;
+        }
+
+        prefixlen = sd_dhcp_client_prefixlen(&netmask);
+        if (prefixlen < 0) {
+                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_link_warning(link, "DHCP error: no router");
+                link_enter_failed(link);
+                return;
+        }
+
+        if (event == DHCP_EVENT_IP_CHANGE || event == DHCP_EVENT_IP_ACQUIRE) {
+                _cleanup_address_free_ Address *addr = NULL;
+                _cleanup_route_free_ Route *rt = NULL;
+
+                log_link_info(link, "received config over DHCPv4");
+
+                r = address_new_dynamic(&addr);
+                if (r < 0) {
+                        log_link_error(link, "Could not allocate address");
+                        link_enter_failed(link);
+                        return;
+                }
+
+                addr->family = AF_INET;
+                addr->in_addr.in = address;
+                addr->prefixlen = prefixlen;
+                addr->netmask = netmask;
+
+                r = route_new_dynamic(&rt);
+                if (r < 0) {
+                        log_link_error(link, "Could not allocate route");
+                        link_enter_failed(link);
+                        return;
+                }
+
+                rt->family = AF_INET;
+                rt->in_addr.in = gateway;
+
+                link->dhcp_address = addr;
+                link->dhcp_route = rt;
+                addr = NULL;
+                rt = NULL;
+
+                link_enter_set_addresses(link);
+        }
+
+        return;
+}
+
+static int link_acquire_conf(Link *link) {
+        int r;
+
+        assert(link);
+        assert(link->network);
+        assert(link->network->dhcp);
+        assert(link->manager);
+        assert(link->manager->event);
+
+        if (!link->dhcp) {
+                link->dhcp = sd_dhcp_client_new(link->manager->event);
+                if (!link->dhcp)
+                        return -ENOMEM;
+
+                r = sd_dhcp_client_set_index(link->dhcp, link->ifindex);
+                if (r < 0)
+                        return r;
+
+                r = sd_dhcp_client_set_mac(link->dhcp, &link->mac);
+                if (r < 0)
+                        return r;
+
+                r = sd_dhcp_client_set_callback(link->dhcp, dhcp_handler, link);
+                if (r < 0)
+                        return r;
+        }
+
+        r = sd_dhcp_client_start(link->dhcp);
+        if (r < 0)
+                return r;
+
+        return 0;
+}
+
+static int link_update_flags(Link *link, unsigned flags) {
+        int r;
+
+        assert(link);
+        assert(link->network);
+
+        if (link->state == LINK_STATE_FAILED)
+                return 0;
+
+        if (link->flags == flags) {
+                log_debug_link(link, "link status unchanged: %#x", flags);
+                return 0;
+        }
+
+        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_link_info(link, "carrier on");
+
+                        if (link->network->dhcp) {
+                                r = link_acquire_conf(link);
+                                if (r < 0) {
+                                        link_enter_failed(link);
+                                        return r;
+                                }
+                        }
+                } else {
+                        log_link_info(link, "carrier off");
+
+                        if (link->network->dhcp) {
+                                r = sd_dhcp_client_stop(link->dhcp);
+                                if (r < 0) {
+                                        link_enter_failed(link);
+                                        return r;
+                                }
+                        }
+                }
+        }
+
+        log_debug_link(link,
+                       "link status updated: %#x -> %#x", link->flags, flags);
+
+        link->flags = flags;
+
+        return 0;
+}
+
 static int link_up_handler(sd_rtnl *rtnl, sd_rtnl_message *m, void *userdata) {
         Link *link = userdata;
         int r;
 
+        assert(link);
+
+        if (link->state == LINK_STATE_FAILED)
+                return 1;
+
         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);
         }
 
+        link_update_flags(link, link->flags | IFF_UP);
+
         return 1;
 }
 
@@ -306,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;
         }
 
@@ -342,12 +564,8 @@ static int link_bridge_joined(Link *link) {
                 return r;
         }
 
-        if (!link->network->dhcp) {
-                r = link_enter_set_addresses(link);
-                if (r < 0)
-                        link_enter_failed(link);
-                        return r;
-        }
+        if (!link->network->dhcp)
+                return link_enter_set_addresses(link);
 
         return 0;
 }
@@ -356,6 +574,7 @@ static int bridge_handler(sd_rtnl *rtnl, sd_rtnl_message *m, void *userdata) {
         Link *link = userdata;
         int r;
 
+        assert(link);
         assert(link->state == LINK_STATE_JOINING_BRIDGE || link->state == LINK_STATE_FAILED);
         assert(link->network);
 
@@ -364,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;
@@ -389,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;
         }
@@ -406,13 +639,19 @@ static int link_get_handler(sd_rtnl *rtnl, sd_rtnl_message *m, void *userdata) {
         Link *link = userdata;
         int r;
 
+        assert(link);
+
+        if (link->state == LINK_STATE_FAILED)
+                return 1;
+
         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_link_debug(link, "got link state");
+
         link_update(link, m);
 
         return 1;
@@ -426,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;
         }
 
@@ -456,162 +696,7 @@ int link_configure(Link *link) {
                 return r;
         }
 
-        r = link_enter_join_bridge(link);
-        if (r < 0)
-                return r;
-
-        return 0;
-}
-
-static int address_drop_handler(sd_rtnl *rtnl, sd_rtnl_message *m, void *userdata) {
-        Link *link = userdata;
-        int r;
-
-        assert(m);
-        assert(link);
-        assert(link->ifname);
-
-        if (link->state == LINK_STATE_FAILED)
-                return 1;
-
-        r = sd_rtnl_message_get_errno(m);
-        if (r < 0 && r != -EEXIST)
-                log_warning("%s: could not drop address: %s",
-                            link->ifname, strerror(-r));
-
-        return 1;
-}
-
-static void dhcp_handler(sd_dhcp_client *client, int event, void *userdata) {
-        Link *link = userdata;
-        struct in_addr address;
-        struct in_addr netmask;
-        struct in_addr gateway;
-        int prefixlen;
-        int r;
-
-        if (link->state == LINK_STATE_FAILED)
-                return;
-
-        if (event < 0) {
-                log_warning("%s: DHCP error: %s", link->ifname, strerror(-event));
-                link_enter_failed(link);
-                return;
-        }
-
-        if (event == DHCP_EVENT_NO_LEASE)
-                log_debug("%s: IP address in use.", link->ifname);
-
-        if (event == DHCP_EVENT_IP_CHANGE || event == DHCP_EVENT_EXPIRED ||
-            event == DHCP_EVENT_STOP) {
-                address_drop(link->dhcp_address, link, address_drop_handler);
-
-                address_free(link->dhcp_address);
-                link->dhcp_address = NULL;
-
-                route_free(link->dhcp_route);
-                link->dhcp_route = NULL;
-        }
-
-        r = sd_dhcp_client_get_address(client, &address);
-        if (r < 0) {
-                log_warning("%s: DHCP error: no address", link->ifname);
-                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);
-                link_enter_failed(link);
-                return;
-        }
-
-        prefixlen = sd_dhcp_client_prefixlen(&netmask);
-        if (prefixlen < 0) {
-                log_warning("%s: DHCP error: no prefixlen", link->ifname);
-                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);
-                link_enter_failed(link);
-                return;
-        }
-
-        if (event == DHCP_EVENT_IP_CHANGE || event == DHCP_EVENT_IP_ACQUIRE) {
-                _cleanup_address_free_ Address *addr = NULL;
-                _cleanup_route_free_ Route *rt = NULL;
-
-                log_info("%s: received config over DHCPv4", link->ifname);
-
-                r = address_new_dynamic(&addr);
-                if (r < 0) {
-                        log_error("Could not allocate address");
-                        link_enter_failed(link);
-                        return;
-                }
-
-                addr->family = AF_INET;
-                addr->in_addr.in = address;
-                addr->prefixlen = prefixlen;
-                addr->netmask = netmask;
-
-                r = route_new_dynamic(&rt);
-                if (r < 0) {
-                        log_error("Could not allocate route");
-                        link_enter_failed(link);
-                        return;
-                }
-
-                rt->family = AF_INET;
-                rt->in_addr.in = gateway;
-
-                link->dhcp_address = addr;
-                link->dhcp_route = rt;
-                addr = NULL;
-                rt = NULL;
-
-                link_enter_set_addresses(link);
-        }
-
-        return;
-}
-
-static int link_acquire_conf(Link *link) {
-        int r;
-
-        assert(link);
-        assert(link->network);
-        assert(link->network->dhcp);
-        assert(link->manager);
-        assert(link->manager->event);
-
-        if (!link->dhcp) {
-                link->dhcp = sd_dhcp_client_new(link->manager->event);
-                if (!link->dhcp)
-                        return -ENOMEM;
-
-                r = sd_dhcp_client_set_index(link->dhcp, link->ifindex);
-                if (r < 0)
-                        return r;
-
-                r = sd_dhcp_client_set_mac(link->dhcp, &link->mac);
-                if (r < 0)
-                        return r;
-
-                r = sd_dhcp_client_set_callback(link->dhcp, dhcp_handler, link);
-                if (r < 0)
-                        return r;
-        }
-
-        r = sd_dhcp_client_start(link->dhcp);
-        if (r < 0)
-                return r;
-
-        return 0;
+        return link_enter_join_bridge(link);
 }
 
 int link_update(Link *link, sd_rtnl_message *m) {
@@ -621,42 +706,14 @@ int link_update(Link *link, sd_rtnl_message *m) {
         assert(link);
         assert(m);
 
+        if (link->state == LINK_STATE_FAILED)
+                return 0;
+
         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;
         }
 
-        if (link->flags & IFF_UP && !(flags & IFF_UP))
-                log_info("%s: interface is down", link->ifname);
-        else if (!(link->flags & IFF_UP) && flags & IFF_UP)
-                log_info("%s: interface is up", link->ifname);
-
-        if (link->flags & IFF_LOWER_UP && !(flags & IFF_LOWER_UP)) {
-                log_info("%s: disconnected", link->ifname);
-
-                if (link->network->dhcp) {
-                        r = sd_dhcp_client_stop(link->dhcp);
-                        if (r < 0) {
-                                link_enter_failed(link);
-                                return r;
-                        }
-                }
-        } else if (!(link->flags & IFF_LOWER_UP) && flags & IFF_LOWER_UP) {
-                log_info("%s: connected", link->ifname);
-
-                if (link->network && link->network->dhcp) {
-                        r = link_acquire_conf(link);
-                        if (r < 0) {
-                                link_enter_failed(link);
-                                return r;
-                        }
-                }
-        }
-
-        link->flags = flags;
-
-        log_debug("%s: updated state", link->ifname);
-
-        return 0;
+        return link_update_flags(link, flags);
 }