core,network: major per-object logging rework

This changes log_unit_info() (and friends) to take a real Unit* object
insted of just a unit name as parameter. The call will now prefix all
logged messages with the unit name, thus allowing the unit name to be
dropped from the various passed romat strings, simplifying invocations
drastically, and unifying log output across messages. Also, UNIT= vs.
USER_UNIT= is now derived from the Manager object attached to the Unit
object, instead of getpid(). This has the benefit of correcting the
field for --test runs.

Also contains a couple of other logging improvements:

- Drops a couple of strerror() invocations in favour of using %m.

- Not only .mount units now warn if a symlinks exist for the mount
  point already, .automount units do that too, now.

- A few invocations of log_struct() that didn't actually pass any
  additional structured data have been replaced by simpler invocations
  of log_unit_info() and friends.

- For structured data a new LOG_UNIT_MESSAGE() macro has been added,
  that works like LOG_MESSAGE() but prefixes the message with the unit
  name. Similar, there's now LOG_LINK_MESSAGE() and
  LOG_NETDEV_MESSAGE().

- For structured data new LOG_UNIT_ID(), LOG_LINK_INTERFACE(),
  LOG_NETDEV_INTERFACE() macros have been added that generate the
  necessary per object fields. The old log_unit_struct() call has been
  removed in favour of these new macros used in raw log_struct()
  invocations. In addition to removing one more function call this
  allows generated structured log messages that contain two object
  fields, as necessary for example for network interfaces that are
  joined into another network interface, and whose messages shall be
  indexed by both.

- The LOG_ERRNO() macro has been removed, in favour of
  log_struct_errno(). The latter has the benefit of ensuring that %m in
  format strings is properly resolved to the specified error number.

- A number of logging messages have been converted to use
  log_unit_info() instead of log_info()

- The client code in sysv-generator no longer #includes core code from
  src/core/.

- log_unit_full_errno() has been removed, log_unit_full() instead takes
  an errno now, too.

- log_unit_info(), log_link_info(), log_netdev_info() and friends, now
  avoid double evaluation of their parameters

5 files changed, 101 insertions, 139 deletions

diff --git a/src/network/networkd-dhcp4.c b/src/network/networkd-dhcp4.c
index 38321905e6..c99e92f56d 100644
--- a/src/network/networkd-dhcp4.c
+++ b/src/network/networkd-dhcp4.c
@@ -409,62 +409,43 @@ static int dhcp_lease_acquired(sd_dhcp_client *client, Link *link) {
         assert(link);
 
         r = sd_dhcp_client_get_lease(client, &lease);
-        if (r < 0) {
-                log_link_warning(link, "DHCP error: no lease: %s",
-                                 strerror(-r));
-                return r;
-        }
+        if (r < 0)
+                return log_link_error_errno(link, r, "DHCP error: no lease: %m");
 
         r = sd_dhcp_lease_get_address(lease, &address);
-        if (r < 0) {
-                log_link_warning(link, "DHCP error: no address: %s",
-                                 strerror(-r));
-                return r;
-        }
+        if (r < 0)
+                return log_link_error_errno(link, r, "DHCP error: no address: %m");
 
         r = sd_dhcp_lease_get_netmask(lease, &netmask);
-        if (r < 0) {
-                log_link_warning(link, "DHCP error: no netmask: %s",
-                                 strerror(-r));
-                return r;
-        }
+        if (r < 0)
+                return log_link_error_errno(link, r, "DHCP error: no netmask: %m");
 
         prefixlen = in_addr_netmask_to_prefixlen(&netmask);
 
         r = sd_dhcp_lease_get_router(lease, &gateway);
-        if (r < 0 && r != -ENOENT) {
-                log_link_warning(link, "DHCP error: could not get gateway: %s",
-                                 strerror(-r));
-                return r;
-        }
+        if (r < 0 && r != -ENOENT)
+                return log_link_error_errno(link, r, "DHCP error: could not get gateway: %m");
 
         if (r >= 0)
-                log_link_struct(link, LOG_INFO,
-                                "MESSAGE=%-*s: DHCPv4 address %u.%u.%u.%u/%u via %u.%u.%u.%u",
-                                 IFNAMSIZ,
-                                 link->ifname,
-                                 ADDRESS_FMT_VAL(address),
-                                 prefixlen,
-                                 ADDRESS_FMT_VAL(gateway),
-                                 "ADDRESS=%u.%u.%u.%u",
-                                 ADDRESS_FMT_VAL(address),
-                                 "PREFIXLEN=%u",
-                                 prefixlen,
-                                 "GATEWAY=%u.%u.%u.%u",
-                                 ADDRESS_FMT_VAL(gateway),
-                                 NULL);
+                log_struct(LOG_INFO,
+                           LOG_LINK_INTERFACE(link),
+                           LOG_LINK_MESSAGE(link, "DHCPv4 address %u.%u.%u.%u/%u via %u.%u.%u.%u",
+                                            ADDRESS_FMT_VAL(address),
+                                            prefixlen,
+                                            ADDRESS_FMT_VAL(gateway)),
+                           "ADDRESS=%u.%u.%u.%u", ADDRESS_FMT_VAL(address),
+                           "PREFIXLEN=%u", prefixlen,
+                           "GATEWAY=%u.%u.%u.%u", ADDRESS_FMT_VAL(gateway),
+                           NULL);
         else
-                log_link_struct(link, LOG_INFO,
-                                "MESSAGE=%-*s: DHCPv4 address %u.%u.%u.%u/%u",
-                                 IFNAMSIZ,
-                                 link->ifname,
-                                 ADDRESS_FMT_VAL(address),
-                                 prefixlen,
-                                 "ADDRESS=%u.%u.%u.%u",
-                                 ADDRESS_FMT_VAL(address),
-                                 "PREFIXLEN=%u",
-                                 prefixlen,
-                                 NULL);
+                log_struct(LOG_INFO,
+                           LOG_LINK_INTERFACE(link),
+                           LOG_LINK_MESSAGE(link, "DHCPv4 address %u.%u.%u.%u/%u",
+                                            ADDRESS_FMT_VAL(address),
+                                            prefixlen),
+                           "ADDRESS=%u.%u.%u.%u", ADDRESS_FMT_VAL(address),
+                           "PREFIXLEN=%u", prefixlen,
+                           NULL);
 
         link->dhcp_lease = lease;
 
@@ -475,8 +456,7 @@ static int dhcp_lease_acquired(sd_dhcp_client *client, Link *link) {
                 if (r >= 0) {
                         r = link_set_mtu(link, mtu);
                         if (r < 0)
-                                log_link_error(link, "Failed to set MTU "
-                                               "to %" PRIu16, mtu);
+                                log_link_error_errno(link, r, "Failed to set MTU to %" PRIu16 ": %m", mtu);
                 }
         }
 
@@ -487,27 +467,21 @@ static int dhcp_lease_acquired(sd_dhcp_client *client, Link *link) {
                 if (r >= 0) {
                         r = link_set_hostname(link, hostname);
                         if (r < 0)
-                                log_link_error(link,
-                                               "Failed to set transient hostname to '%s'",
-                                               hostname);
+                                log_link_error_errno(link, r, "Failed to set transient hostname to '%s': %m", hostname);
                 }
         }
 
         if (!link->network->dhcp_critical) {
-                r = sd_dhcp_lease_get_lifetime(link->dhcp_lease,
-                                               &lifetime);
+                r = sd_dhcp_lease_get_lifetime(link->dhcp_lease, &lifetime);
                 if (r < 0) {
-                        log_link_warning(link,
-                                         "DHCP error: no lifetime: %s",
-                                         strerror(-r));
+                        log_link_warning_errno(link, r, "DHCP error: no lifetime: %m");
                         return r;
                 }
         }
 
         r = dhcp4_update_address(link, &address, &netmask, lifetime);
         if (r < 0) {
-                log_link_warning(link, "could not update IP address: %s",
-                                 strerror(-r));
+                log_link_warning_errno(link, r, "Could not update IP address: %m");
                 link_enter_failed(link);
                 return r;
         }
diff --git a/src/network/networkd-dhcp6.c b/src/network/networkd-dhcp6.c
index 5668fdf16c..33e18137d2 100644
--- a/src/network/networkd-dhcp6.c
+++ b/src/network/networkd-dhcp6.c
@@ -83,16 +83,14 @@ static int dhcp6_address_update(Link *link, struct in6_addr *ip6_addr,
         addr->cinfo.ifa_prefered = lifetime_preferred;
         addr->cinfo.ifa_valid = lifetime_valid;
 
-        log_link_struct(link, LOG_INFO, "MESSAGE=%-*s: DHCPv6 address "SD_ICMP6_ADDRESS_FORMAT_STR"/%d timeout preferred %d valid %d",
-                        IFNAMSIZ,
-                        link->ifname, SD_ICMP6_ADDRESS_FORMAT_VAL(addr->in_addr.in6),
-                        addr->prefixlen, lifetime_preferred, lifetime_valid,
-                        NULL);
+        log_link_info(link,
+                      "DHCPv6 address "SD_ICMP6_ADDRESS_FORMAT_STR"/%d timeout preferred %d valid %d",
+                      SD_ICMP6_ADDRESS_FORMAT_VAL(addr->in_addr.in6),
+                      addr->prefixlen, lifetime_preferred, lifetime_valid);
 
         r = address_update(addr, link, dhcp6_address_handler);
         if (r < 0)
-                log_link_warning(link, "Could not assign DHCPv6 address: %s",
-                                strerror(-r));
+                log_link_warning_errno(link, r, "Could not assign DHCPv6 address: %m");
 
         return r;
 }
@@ -289,11 +287,9 @@ static int dhcp6_prefix_expired(Link *link) {
         if (r < 0)
                 return r;
 
-        log_link_struct(link, LOG_INFO,
-                        "MESSAGE=%-*s: IPv6 prefix "SD_ICMP6_ADDRESS_FORMAT_STR"/%d expired",
-                        IFNAMSIZ, link->ifname,
-                        SD_ICMP6_ADDRESS_FORMAT_VAL(*expired_prefix),
-                        expired_prefixlen, NULL);
+        log_link_info(link, "IPv6 prefix "SD_ICMP6_ADDRESS_FORMAT_STR"/%d expired",
+                      SD_ICMP6_ADDRESS_FORMAT_VAL(*expired_prefix),
+                      expired_prefixlen);
 
         sd_dhcp6_lease_reset_address_iter(lease);
 
@@ -306,14 +302,9 @@ static int dhcp6_prefix_expired(Link *link) {
                 if (r < 0)
                         continue;
 
-                log_link_struct(link, LOG_INFO,
-                                "MESSAGE=%-*s: IPv6 prefix length updated "SD_ICMP6_ADDRESS_FORMAT_STR"/%d",
-                                IFNAMSIZ, link->ifname,
-                                SD_ICMP6_ADDRESS_FORMAT_VAL(ip6_addr), 128,
-                                NULL);
+                log_link_info(link, "IPv6 prefix length updated "SD_ICMP6_ADDRESS_FORMAT_STR"/%d", SD_ICMP6_ADDRESS_FORMAT_VAL(ip6_addr), 128);
 
-                dhcp6_address_update(link, &ip6_addr, 128, lifetime_preferred,
-                                     lifetime_valid);
+                dhcp6_address_update(link, &ip6_addr, 128, lifetime_preferred, lifetime_valid);
         }
 
         return 0;
diff --git a/src/network/networkd-link.c b/src/network/networkd-link.c
index 0c6bb658e6..5628ed92bf 100644
--- a/src/network/networkd-link.c
+++ b/src/network/networkd-link.c
@@ -722,12 +722,7 @@ static int link_set_handler(sd_rtnl *rtnl, sd_rtnl_message *m, void *userdata) {
 
         r = sd_rtnl_message_get_errno(m);
         if (r < 0 && r != -EEXIST) {
-                log_link_struct(link, LOG_ERR,
-                                "MESSAGE=%-*s: could not join netdev: %s",
-                                IFNAMSIZ, link->ifname,
-                                strerror(-r),
-                                "ERRNO=%d", -r,
-                                NULL);
+                log_link_error_errno(link, r, "Could not join netdev: %m");
                 link_enter_failed(link);
                 return 1;
         }
@@ -1411,22 +1406,20 @@ static int link_enter_join_netdev(Link *link) {
                 return link_joined(link);
 
         if (link->network->bond) {
-                log_link_struct(link, LOG_DEBUG,
-                                "MESSAGE=%-*s: enslaving by '%s'",
-                                IFNAMSIZ, link->ifname,
-                                link->network->bond->ifname,
-                                NETDEVIF(link->network->bond),
-                                NULL);
-
-                r = netdev_join(link->network->bond, link, &netdev_join_handler);
+                log_struct(LOG_DEBUG,
+                           LOG_LINK_INTERFACE(link),
+                           LOG_NETDEV_INTERFACE(link->network->bond),
+                           LOG_LINK_MESSAGE(link, "Enslaving by '%s'", link->network->bond->ifname),
+                           NULL);
+
+                r = netdev_join(link->network->bond, link, netdev_join_handler);
                 if (r < 0) {
-                        log_link_struct(link, LOG_WARNING,
-                                        "MESSAGE=%-*s: could not join netdev '%s': %s",
-                                        IFNAMSIZ, link->ifname,
-                                        link->network->bond->ifname,
-                                        strerror(-r),
-                                        NETDEVIF(link->network->bond),
-                                        NULL);
+                        log_struct_errno(LOG_WARNING, r,
+                                         LOG_LINK_INTERFACE(link),
+                                         LOG_NETDEV_INTERFACE(link->network->bond),
+                                         LOG_LINK_MESSAGE(link, "Could not join netdev '%s': %m", link->network->bond->ifname),
+                                         NULL);
+
                         link_enter_failed(link);
                         return r;
                 }
@@ -1435,23 +1428,19 @@ static int link_enter_join_netdev(Link *link) {
         }
 
         if (link->network->bridge) {
-                log_link_struct(link, LOG_DEBUG,
-                                "MESSAGE=%-*s: enslaving by '%s'",
-                                IFNAMSIZ, link->ifname,
-                                link->network->bridge->ifname,
-                                NETDEVIF(link->network->bridge),
-                                NULL);
-
-                r = netdev_join(link->network->bridge, link,
-                                &netdev_join_handler);
+                log_struct(LOG_DEBUG,
+                           LOG_LINK_INTERFACE(link),
+                           LOG_NETDEV_INTERFACE(link->network->bridge),
+                           LOG_LINK_MESSAGE(link, "Enslaving by '%s'", link->network->bridge->ifname),
+                           NULL);
+
+                r = netdev_join(link->network->bridge, link, netdev_join_handler);
                 if (r < 0) {
-                        log_link_struct(link, LOG_WARNING,
-                                        "MESSAGE=%-*s: could not join netdev '%s': %s",
-                                        IFNAMSIZ, link->ifname,
-                                        link->network->bridge->ifname,
-                                        strerror(-r),
-                                        NETDEVIF(link->network->bridge),
-                                        NULL);
+                        log_struct_errno(LOG_WARNING, r,
+                                         LOG_LINK_INTERFACE(link),
+                                         LOG_NETDEV_INTERFACE(link->network->bridge),
+                                         LOG_LINK_MESSAGE(link, "Could not join netdev '%s': %m", link->network->bridge->ifname),
+                                         NULL),
                         link_enter_failed(link);
                         return r;
                 }
@@ -1460,20 +1449,20 @@ static int link_enter_join_netdev(Link *link) {
         }
 
         HASHMAP_FOREACH(netdev, link->network->stacked_netdevs, i) {
-                log_link_struct(link, LOG_DEBUG,
-                                "MESSAGE=%-*s: enslaving by '%s'",
-                                IFNAMSIZ, link->ifname,
-                                netdev->ifname, NETDEVIF(netdev),
-                                NULL);
 
-                r = netdev_join(netdev, link, &netdev_join_handler);
+                log_struct(LOG_DEBUG,
+                           LOG_LINK_INTERFACE(link),
+                           LOG_NETDEV_INTERFACE(netdev),
+                           LOG_LINK_MESSAGE(link, "Enslaving by '%s'", netdev->ifname),
+                           NULL);
+
+                r = netdev_join(netdev, link, netdev_join_handler);
                 if (r < 0) {
-                        log_link_struct(link, LOG_WARNING,
-                                        "MESSAGE=%-*s: could not join netdev '%s': %s",
-                                        IFNAMSIZ, link->ifname,
-                                        netdev->ifname,
-                                        strerror(-r),
-                                        NETDEVIF(netdev), NULL);
+                        log_struct_errno(LOG_WARNING, r,
+                                         LOG_LINK_INTERFACE(link),
+                                         LOG_NETDEV_INTERFACE(netdev),
+                                         LOG_LINK_MESSAGE(link, "Could not join netdev '%s': %m", netdev->ifname),
+                                         NULL);
                         link_enter_failed(link);
                         return r;
                 }
diff --git a/src/network/networkd-link.h b/src/network/networkd-link.h
index c3bc1b907b..c599952c45 100644
--- a/src/network/networkd-link.h
+++ b/src/network/networkd-link.h
@@ -141,14 +141,18 @@ DEFINE_TRIVIAL_CLEANUP_FUNC(Link*, link_unref);
 
 /* Macros which append INTERFACE= to the message */
 
-#define log_link_full(link, level, error, fmt, ...) \
-        log_object_internal(level, error, __FILE__, __LINE__, __func__, "INTERFACE=", link->ifname, "%-*s: " fmt, IFNAMSIZ, link->ifname, ##__VA_ARGS__)
-
-#define log_link_debug(link, ...)       log_link_full(link, LOG_DEBUG, 0, ##__VA_ARGS__)
-#define log_link_info(link, ...)        log_link_full(link, LOG_INFO, 0, ##__VA_ARGS__)
-#define log_link_notice(link, ...)      log_link_full(link, LOG_NOTICE, 0, ##__VA_ARGS__)
-#define log_link_warning(link, ...)     log_link_full(link, LOG_WARNING, 0, ##__VA_ARGS__)
-#define log_link_error(link, ...)       log_link_full(link, LOG_ERR, 0, ##__VA_ARGS__)
+#define log_link_full(link, level, error, ...)                          \
+        ({                                                              \
+                Link *_l = (link);                                      \
+                _l ? log_object_internal(level, error, __FILE__, __LINE__, __func__, "INTERFACE=", _l->ifname, ##__VA_ARGS__) : \
+                        log_internal(level, error, __FILE__, __LINE__, __func__, ##__VA_ARGS__); \
+        })                                                              \
+
+#define log_link_debug(link, ...)   log_link_full(link, LOG_DEBUG, 0, ##__VA_ARGS__)
+#define log_link_info(link, ...)    log_link_full(link, LOG_INFO, 0, ##__VA_ARGS__)
+#define log_link_notice(link, ...)  log_link_full(link, LOG_NOTICE, 0, ##__VA_ARGS__)
+#define log_link_warning(link, ...) log_link_full(link, LOG_WARNING, 0, ##__VA_ARGS__)
+#define log_link_error(link, ...)   log_link_full(link, LOG_ERR, 0, ##__VA_ARGS__)
 
 #define log_link_debug_errno(link, error, ...)   log_link_full(link, LOG_DEBUG, error, ##__VA_ARGS__)
 #define log_link_info_errno(link, error, ...)    log_link_full(link, LOG_INFO, error, ##__VA_ARGS__)
@@ -156,7 +160,8 @@ DEFINE_TRIVIAL_CLEANUP_FUNC(Link*, link_unref);
 #define log_link_warning_errno(link, error, ...) log_link_full(link, LOG_WARNING, error, ##__VA_ARGS__)
 #define log_link_error_errno(link, error, ...)   log_link_full(link, LOG_ERR, error, ##__VA_ARGS__)
 
-#define log_link_struct(link, level, ...) log_struct(level, "INTERFACE=%s", link->ifname, __VA_ARGS__)
+#define LOG_LINK_MESSAGE(link, fmt, ...) "MESSAGE=%s: " fmt, (link)->ifname, ##__VA_ARGS__
+#define LOG_LINK_INTERFACE(link) "INTERFACE=%s", (link)->ifname
 
 #define ADDRESS_FMT_VAL(address)                   \
         be32toh((address).s_addr) >> 24,           \
diff --git a/src/network/networkd-netdev.h b/src/network/networkd-netdev.h
index 8382606f1c..1ded495e4a 100644
--- a/src/network/networkd-netdev.h
+++ b/src/network/networkd-netdev.h
@@ -202,8 +202,12 @@ const struct ConfigPerfItem* network_netdev_gperf_lookup(const char *key, unsign
 
 /* Macros which append INTERFACE= to the message */
 
-#define log_netdev_full(netdev, level, error, fmt, ...)                  \
-        log_object_internal(level, error, __FILE__, __LINE__, __func__, "INTERFACE=", netdev->ifname, "%-*s: " fmt, IFNAMSIZ, netdev->ifname, ##__VA_ARGS__)
+#define log_netdev_full(netdev, level, error, ...)                      \
+        ({                                                              \
+                NetDev *_n = (netdev);                                  \
+                _n ? log_object_internal(level, error, __FILE__, __LINE__, __func__, "INTERFACE=", _n->ifname, ##__VA_ARGS__) : \
+                        log_internal(level, error, __FILE__, __LINE__, __func__, ##__VA_ARGS__); \
+        })
 
 #define log_netdev_debug(netdev, ...)       log_netdev_full(netdev, LOG_DEBUG, 0, ##__VA_ARGS__)
 #define log_netdev_info(netdev, ...)        log_netdev_full(netdev, LOG_INFO, 0, ##__VA_ARGS__)
@@ -217,6 +221,5 @@ const struct ConfigPerfItem* network_netdev_gperf_lookup(const char *key, unsign
 #define log_netdev_warning_errno(netdev, error, ...) log_netdev_full(netdev, LOG_WARNING, error, ##__VA_ARGS__)
 #define log_netdev_error_errno(netdev, error, ...)   log_netdev_full(netdev, LOG_ERR, error, ##__VA_ARGS__)
 
-#define log_netdev_struct(level, netdev, ...) log_struct(level, "INTERFACE=%s", netdev->ifname, __VA_ARGS__)
-
-#define NETDEVIF(netdev) "INTERFACE=%s", netdev->ifname
+#define LOG_NETDEV_MESSAGE(netdev, fmt, ...) "MESSAGE=%s: " fmt, (netdev)->ifname, ##__VA_ARGS__
+#define LOG_NETDEV_INTERFACE(netdev) "INTERFACE=%s", (netdev)->ifname