Merge 6d72cd9e88 into 4dca06cba9

We already have LOG_CONTEXT_PUSH_EXEC() which with two additions
does exactly the same as the custom logging macros, so let's get rid
of the custom logging macros and use LOG_CONTEXT_PUSH_EXEC() instead.

man/systemd.exec.xml

@@ -3268,23 +3268,30 @@ StandardInputData=V2XigLJyZSBubyBzdHJhbmdlcnMgdG8gbG92ZQpZb3Uga25vdyB0aGUgcnVsZX
       <varlistentry>
         <term><varname>LogLevelMax=</varname></term>
 
-        <listitem><para>Configures filtering by log level of log messages generated by this unit. Takes a
+        <listitem><para>Overrides the maximum log level of log messages generated by this unit. Takes a
-        <command>syslog</command> log level, one of <option>emerg</option> (lowest log level, only highest priority
+        <command>syslog</command> log level, one of <option>emerg</option> (lowest log level, only highest
-        messages), <option>alert</option>, <option>crit</option>, <option>err</option>, <option>warning</option>,
+        priority messages), <option>alert</option>, <option>crit</option>, <option>err</option>,
-        <option>notice</option>, <option>info</option>, <option>debug</option> (highest log level, also lowest priority
+        <option>warning</option>, <option>notice</option>, <option>info</option>, <option>debug</option>
-        messages). See <citerefentry
+        (highest log level, also lowest priority messages). See <citerefentry
         project='man-pages'><refentrytitle>syslog</refentrytitle><manvolnum>3</manvolnum></citerefentry> for
-        details. By default, no filtering is applied (i.e. the default maximum log level is <option>debug</option>). Use
+        details. By default, no per unit filtering is applied.</para>
-        this option to configure the logging system to drop log messages of a specific service above the specified
+
-        level. For example, set <varname>LogLevelMax=</varname><option>info</option> in order to turn off debug logging
+        <para>This option can be used to configure the logging system to drop log messages of a specific
-        of a particularly chatty unit. Note that the configured level is applied to any log messages written by any
+        service above the specified level. For example, set
-        of the processes belonging to this unit, as well as any log messages written by the system manager process
+        <varname>LogLevelMax=</varname><option>info</option> in order to turn off debug logging of a
-        (PID 1) in reference to this unit, sent via any supported logging protocol. The filtering is applied
+        particularly chatty unit. Alternatively, this option can be used to enable extra logging about a
-        early in the logging pipeline, before any kind of further processing is done. Moreover, messages which pass
+        specific unit by the system or user manager processes without changing the global log level for the
-        through this filter successfully might still be dropped by filters applied at a later stage in the logging
+        system or user manager processes by setting <varname>LogLevelMax=</varname><option>debug</option>.
-        subsystem. For example, <varname>MaxLevelStore=</varname> configured in
+        </para>
-        <citerefentry><refentrytitle>journald.conf</refentrytitle><manvolnum>5</manvolnum></citerefentry> might
+
-        prohibit messages of higher log levels to be stored on disk, even though the per-unit
+        <para>Note that the configured level is applied to any log messages written by any of the processes
+        belonging to this unit, as well as any log messages written by the system or user manager processes
+        in reference to this unit, sent via any supported logging protocol. The filtering is applied early in
+        the logging pipeline, before any kind of further processing is done. Moreover, messages which pass
+        through this filter successfully might still be dropped by filters applied at a later stage in the
+        logging subsystem. For example, <varname>MaxLevelStore=</varname> configured in
+        <citerefentry><refentrytitle>journald.conf</refentrytitle><manvolnum>5</manvolnum></citerefentry>
+        might prohibit messages of higher log levels to be stored on disk, even though the per-unit
         <varname>LogLevelMax=</varname> permitted it to be processed.</para>
 
         <xi:include href="version-info.xml" xpointer="v236"/></listitem>

src/basic/log.h

@@ -521,8 +521,11 @@ static inline void _reset_log_level(int *saved_log_level) {
         log_set_max_level(*saved_log_level);
 }
 
+#define _LOG_CONTEXT_SET_LOG_LEVEL(level, l) \
+        _cleanup_(_reset_log_level) _unused_ int l = log_set_max_level(level);
+
 #define LOG_CONTEXT_SET_LOG_LEVEL(level) \
-        _cleanup_(_reset_log_level) _unused_ int _saved_log_level_ = log_set_max_level(level);
+        _LOG_CONTEXT_SET_LOG_LEVEL(level, UNIQ_T(l, UNIQ))
 
 #define LOG_CONTEXT_PUSH(...) \
         LOG_CONTEXT_PUSH_STRV(STRV_MAKE(__VA_ARGS__))

src/core/execute.h

@@ -638,6 +638,16 @@ bool exec_is_cgroup_mount_read_only(const ExecContext *context);
 
 const char* exec_get_private_notify_socket_path(const ExecContext *context, const ExecParameters *params, bool needs_sandboxing);
 
+static inline int exec_log_level_max(const ExecContext *context, const ExecParameters *params) {
+        assert(context);
+        assert(params);
+
+        if (params->debug_invocation)
+                return LOG_DEBUG;
+
+        return context->log_level_max < 0 ? log_get_max_level() : context->log_level_max;
+}
+
 /* These logging macros do the same logging as those in unit.h, but using ExecContext and ExecParameters
  * instead of the unit object, so that it can be used in the sd-executor context (where the unit object is
  * not available). */
@@ -647,77 +657,19 @@ const char* exec_get_private_notify_socket_path(const ExecContext *context, cons
 #define LOG_EXEC_INVOCATION_ID_FIELD(ep) \
         ((ep)->runtime_scope == RUNTIME_SCOPE_USER ? "USER_INVOCATION_ID=" : "INVOCATION_ID=")
 
-#define log_exec_full_errno_zerook(ec, ep, level, error, ...)                     \
-        ({                                                                        \
-                const ExecContext *_c = (ec);                                     \
-                const ExecParameters *_p = (ep);                                  \
-                const int _l = (level);                                           \
-                bool _do_log = _p->debug_invocation ||                            \
-                               _c->log_level_max < 0 ||                           \
-                               _c->log_level_max >= LOG_PRI(_l);                  \
-                LOG_CONTEXT_PUSH_IOV(_c->log_extra_fields,                        \
-                                     _c->n_log_extra_fields);                     \
-                !_do_log ? -ERRNO_VALUE(error) :                                  \
-                        log_object_internal(_l, error,                            \
-                                            PROJECT_FILE, __LINE__, __func__,     \
-                                            LOG_EXEC_ID_FIELD(_p),                \
-                                            _p->unit_id,                          \
-                                            LOG_EXEC_INVOCATION_ID_FIELD(_p),     \
-                                            _p->invocation_id_string,             \
-                                            ##__VA_ARGS__);                       \
-        })
-
-#define log_exec_full_errno(ec, ep, level, error, ...)                            \
-        ({                                                                        \
-                int _error = (error);                                             \
-                ASSERT_NON_ZERO(_error);                                          \
-                log_exec_full_errno_zerook(ec, ep, level, _error, ##__VA_ARGS__); \
-        })
-
-#define log_exec_full(ec, ep, level, ...) (void) log_exec_full_errno_zerook(ec, ep, level, 0, __VA_ARGS__)
-
-#define log_exec_debug(ec, ep, ...)   log_exec_full(ec, ep, LOG_DEBUG, __VA_ARGS__)
-#define log_exec_info(ec, ep, ...)    log_exec_full(ec, ep, LOG_INFO, __VA_ARGS__)
-#define log_exec_notice(ec, ep, ...)  log_exec_full(ec, ep, LOG_NOTICE, __VA_ARGS__)
-#define log_exec_warning(ec, ep, ...) log_exec_full(ec, ep, LOG_WARNING, __VA_ARGS__)
-#define log_exec_error(ec, ep, ...)   log_exec_full(ec, ep, LOG_ERR, __VA_ARGS__)
-
-#define log_exec_debug_errno(ec, ep, error, ...)   log_exec_full_errno(ec, ep, LOG_DEBUG, error, __VA_ARGS__)
-#define log_exec_info_errno(ec, ep, error, ...)    log_exec_full_errno(ec, ep, LOG_INFO, error, __VA_ARGS__)
-#define log_exec_notice_errno(ec, ep, error, ...)  log_exec_full_errno(ec, ep, LOG_NOTICE, error, __VA_ARGS__)
-#define log_exec_warning_errno(ec, ep, error, ...) log_exec_full_errno(ec, ep, LOG_WARNING, error, __VA_ARGS__)
-#define log_exec_error_errno(ec, ep, error, ...)   log_exec_full_errno(ec, ep, LOG_ERR, error, __VA_ARGS__)
-
 /* Like LOG_MESSAGE(), but with the unit name prefixed. */
 #define LOG_EXEC_MESSAGE(ep, fmt, ...) LOG_MESSAGE("%s: " fmt, (ep)->unit_id, ##__VA_ARGS__)
 #define LOG_EXEC_ID(ep) LOG_ITEM("%s%s", LOG_EXEC_ID_FIELD(ep), (ep)->unit_id)
 #define LOG_EXEC_INVOCATION_ID(ep) LOG_ITEM("%s%s", LOG_EXEC_INVOCATION_ID_FIELD(ep), (ep)->invocation_id_string)
 
-#define log_exec_struct_errno(ec, ep, level, error, ...)                          \
-        ({                                                                        \
-                const ExecContext *_c = (ec);                                     \
-                const ExecParameters *_p = (ep);                                  \
-                const int _l = (level);                                           \
-                bool _do_log = _p->debug_invocation ||                            \
-                               _c->log_level_max < 0 ||                           \
-                               _c->log_level_max >= LOG_PRI(_l);                  \
-                LOG_CONTEXT_PUSH_IOV(_c->log_extra_fields,                        \
-                                     _c->n_log_extra_fields);                     \
-                !_do_log ? -ERRNO_VALUE(error) :                                  \
-                        log_struct_errno(_l, error,                               \
-                                         LOG_EXEC_ID(_p),                         \
-                                         LOG_EXEC_INVOCATION_ID(_p),              \
-                                         __VA_ARGS__);                            \
-        })
-
-#define log_exec_struct(ec, ep, level, ...) log_exec_struct_errno(ec, ep, level, 0, __VA_ARGS__)
-
 #define _LOG_CONTEXT_PUSH_EXEC(ec, ep, p, c)                                                       \
         const ExecContext *c = (ec);                                                               \
         const ExecParameters *p = (ep);                                                            \
         LOG_CONTEXT_PUSH_KEY_VALUE(LOG_EXEC_ID_FIELD(p), p->unit_id);                              \
         LOG_CONTEXT_PUSH_KEY_VALUE(LOG_EXEC_INVOCATION_ID_FIELD(p), p->invocation_id_string);      \
-        LOG_CONTEXT_PUSH_IOV(c->log_extra_fields, c->n_log_extra_fields)
+        LOG_CONTEXT_PUSH_IOV(c->log_extra_fields, c->n_log_extra_fields)                           \
+        LOG_CONTEXT_SET_LOG_LEVEL(exec_log_level_max(c, p))                                        \
+        LOG_SET_PREFIX(p->unit_id);
 
 #define LOG_CONTEXT_PUSH_EXEC(ec, ep) \
         _LOG_CONTEXT_PUSH_EXEC(ec, ep, UNIQ_T(p, UNIQ), UNIQ_T(c, UNIQ))

src/core/executor.c

@@ -238,6 +238,8 @@ static int run(int argc, char *argv[]) {
         if (r < 0)
                 return log_error_errno(r, "Failed to deserialize: %m");
 
+        LOG_CONTEXT_PUSH_EXEC(&context, &params);
+
         arg_serialization = safe_fclose(arg_serialization);
         fdset = fdset_free(fdset);
 
@@ -251,7 +253,7 @@ static int run(int argc, char *argv[]) {
                 const char *status = ASSERT_PTR(
                                 exit_status_to_string(exit_status, EXIT_STATUS_LIBC | EXIT_STATUS_SYSTEMD));
 
-                log_exec_struct_errno(&context, &params, LOG_ERR, r,
+                log_struct_errno(LOG_ERR, r,
                                  LOG_MESSAGE_ID(SD_MESSAGE_SPAWN_FAILED_STR),
                                  LOG_EXEC_MESSAGE(&params, "Failed at step %s spawning %s: %m",
                                                   status, command.path),

src/core/unit.h

@@ -1009,10 +1009,20 @@ static inline bool unit_has_job_type(Unit *u, JobType type) {
         return u && u->job && u->job->type == type;
 }
 
+static inline int unit_get_log_level_max(const Unit *u) {
+        if (!u)
+                return log_get_max_level();
+
+        if (u->debug_invocation)
+                return LOG_DEBUG;
+
+        ExecContext *ec = unit_get_exec_context(u);
+        return ec && ec->log_level_max >= 0 ? ec->log_level_max : log_get_max_level();
+}
+
 static inline bool unit_log_level_test(const Unit *u, int level) {
         assert(u);
-        ExecContext *ec = unit_get_exec_context(u);
+        return LOG_PRI(level) <= unit_get_log_level_max(u);
-        return !ec || ec->log_level_max < 0 || ec->log_level_max >= LOG_PRI(level) || u->debug_invocation;
 }
 
 /* unit_log_skip is for cases like ExecCondition= where a unit is considered "done"
@@ -1070,13 +1080,10 @@ UnitDependency unit_mount_dependency_type_to_dependency_type(UnitMountDependency
         ({                                                              \
                 const Unit *_u = (unit);                                \
                 const int _l = (level);                                 \
-                bool _do_log = !(log_get_max_level() < LOG_PRI(_l) ||   \
+                LOG_CONTEXT_SET_LOG_LEVEL(unit_get_log_level_max(_u));  \
-                        (_u && !unit_log_level_test(_u, _l)));          \
+                const ExecContext *_c = _u ? unit_get_exec_context(_u) : NULL; \
-                const ExecContext *_c = _do_log && _u ?                 \
-                        unit_get_exec_context(_u) : NULL;               \
                 LOG_CONTEXT_PUSH_IOV(_c ? _c->log_extra_fields : NULL,  \
                                      _c ? _c->n_log_extra_fields : 0);  \
-                !_do_log ? -ERRNO_VALUE(error) :                        \
                 _u ? log_object_internal(_l, error, PROJECT_FILE, __LINE__, __func__, _u->manager->unit_log_field, _u->id, _u->manager->invocation_log_field, _u->invocation_id_string, ##__VA_ARGS__) : \
                      log_internal(_l, error, PROJECT_FILE, __LINE__, __func__, ##__VA_ARGS__); \
         })
@@ -1114,14 +1121,11 @@ UnitDependency unit_mount_dependency_type_to_dependency_type(UnitMountDependency
         ({                                                              \
                 const Unit *_u = (unit);                                \
                 const int _l = (level);                                 \
-                bool _do_log = unit_log_level_test(_u, _l);             \
+                LOG_CONTEXT_SET_LOG_LEVEL(unit_get_log_level_max(_u));  \
-                const ExecContext *_c = _do_log && _u ?                 \
+                const ExecContext *_c = _u ? unit_get_exec_context(_u) : NULL; \
-                        unit_get_exec_context(_u) : NULL;               \
                 LOG_CONTEXT_PUSH_IOV(_c ? _c->log_extra_fields : NULL,  \
                                      _c ? _c->n_log_extra_fields : 0);  \
-                _do_log ?                                               \
+                log_struct_errno(_l, error, __VA_ARGS__, LOG_UNIT_ID(_u)); \
-                        log_struct_errno(_l, error, __VA_ARGS__, LOG_UNIT_ID(_u)) : \
-                        -ERRNO_VALUE(error);                            \
         })
 
 #define log_unit_struct(unit, level, ...) log_unit_struct_errno(unit, level, 0, __VA_ARGS__)
@@ -1130,14 +1134,11 @@ UnitDependency unit_mount_dependency_type_to_dependency_type(UnitMountDependency
         ({                                                              \
                 const Unit *_u = (unit);                                \
                 const int _l = (level);                                 \
-                bool _do_log = unit_log_level_test(_u, _l);             \
+                LOG_CONTEXT_SET_LOG_LEVEL(unit_get_log_level_max(_u));  \
-                const ExecContext *_c = _do_log && _u ?                 \
+                const ExecContext *_c = _u ? unit_get_exec_context(_u) : NULL; \
-                        unit_get_exec_context(_u) : NULL;               \
                 LOG_CONTEXT_PUSH_IOV(_c ? _c->log_extra_fields : NULL,  \
                                      _c ? _c->n_log_extra_fields : 0);  \
-                _do_log ?                                               \
+                log_struct_iovec_errno(_l, error, iovec, n_iovec);      \
-                        log_struct_iovec_errno(_l, error, iovec, n_iovec) : \
-                        -ERRNO_VALUE(error);                            \
         })
 
 #define log_unit_struct_iovec(unit, level, iovec, n_iovec) log_unit_struct_iovec_errno(unit, level, 0, iovec, n_iovec)
@@ -1207,7 +1208,7 @@ typedef struct UnitForEachDependencyData {
         LOG_CONTEXT_PUSH_KEY_VALUE(u->manager->unit_log_field, u->id);                                  \
         LOG_CONTEXT_PUSH_KEY_VALUE(u->manager->invocation_log_field, u->invocation_id_string);          \
         LOG_CONTEXT_PUSH_IOV(c ? c->log_extra_fields : NULL, c ? c->n_log_extra_fields : 0);            \
-        LOG_CONTEXT_SET_LOG_LEVEL(c->log_level_max >= 0 ? c->log_level_max : log_get_max_level())
+        LOG_CONTEXT_SET_LOG_LEVEL(unit_get_log_level_max(u))
 
 #define LOG_CONTEXT_PUSH_UNIT(unit) \
         _LOG_CONTEXT_PUSH_UNIT(unit, UNIQ_T(u, UNIQ), UNIQ_T(c, UNIQ))

src/timedate/timedated.c

@@ -70,33 +70,13 @@ typedef struct Context {
         LIST_HEAD(UnitStatusInfo, units);
 } Context;
 
-#define log_unit_full_errno_zerook(unit, level, error, ...)             \
+#define _LOG_CONTEXT_PUSH_UNIT(unit, u)               \
-        ({                                                              \
+        const UnitStatusInfo *u = (unit);             \
-                const UnitStatusInfo *_u = (unit);                      \
+        LOG_CONTEXT_PUSH_KEY_VALUE("UNIT=", u->name); \
-                _u ? log_object_internal(level, error, PROJECT_FILE, __LINE__, __func__, "UNIT=", _u->name, NULL, NULL, ##__VA_ARGS__) : \
+        LOG_SET_PREFIX(u->name)
-                        log_internal(level, error, PROJECT_FILE, __LINE__, __func__, ##__VA_ARGS__); \
-        })
 
-#define log_unit_full_errno(unit, level, error, ...) \
+#define LOG_CONTEXT_PUSH_UNIT(unit) \
-        ({                                                              \
+        _LOG_CONTEXT_PUSH_UNIT(unit, UNIQ_T(u, UNIQ))
-                int _error = (error);                                   \
-                ASSERT_NON_ZERO(_error);                                \
-                log_unit_full_errno_zerook(unit, level, _error, ##__VA_ARGS__); \
-        })
-
-#define log_unit_full(unit, level, ...) (void) log_unit_full_errno_zerook(unit, level, 0, ##__VA_ARGS__)
-
-#define log_unit_debug(unit, ...)   log_unit_full(unit, LOG_DEBUG, ##__VA_ARGS__)
-#define log_unit_info(unit, ...)    log_unit_full(unit, LOG_INFO, ##__VA_ARGS__)
-#define log_unit_notice(unit, ...)  log_unit_full(unit, LOG_NOTICE, ##__VA_ARGS__)
-#define log_unit_warning(unit, ...) log_unit_full(unit, LOG_WARNING, ##__VA_ARGS__)
-#define log_unit_error(unit, ...)   log_unit_full(unit, LOG_ERR, ##__VA_ARGS__)
-
-#define log_unit_debug_errno(unit, error, ...)   log_unit_full_errno(unit, LOG_DEBUG, error, ##__VA_ARGS__)
-#define log_unit_info_errno(unit, error, ...)    log_unit_full_errno(unit, LOG_INFO, error, ##__VA_ARGS__)
-#define log_unit_notice_errno(unit, error, ...)  log_unit_full_errno(unit, LOG_NOTICE, error, ##__VA_ARGS__)
-#define log_unit_warning_errno(unit, error, ...) log_unit_full_errno(unit, LOG_WARNING, error, ##__VA_ARGS__)
-#define log_unit_error_errno(unit, error, ...)   log_unit_full_errno(unit, LOG_ERR, error, ##__VA_ARGS__)
 
 static void unit_status_info_clear(UnitStatusInfo *p) {
         assert(p);
@@ -154,8 +134,10 @@ static int context_add_ntp_service(Context *c, const char *s, const char *source
         if (!unit->name)
                 return -ENOMEM;
 
+        LOG_CONTEXT_PUSH_UNIT(unit);
+
         LIST_APPEND(units, c->units, unit);
-        log_unit_debug(unit, "added from %s.", source);
+        log_debug("added from %s.", source);
         TAKE_PTR(unit);
 
         return 0;
@@ -422,6 +404,8 @@ static int context_update_ntp_status(Context *c, sd_bus *bus, sd_bus_message *m)
                 _cleanup_(sd_bus_error_free) sd_bus_error error = SD_BUS_ERROR_NULL;
                 _cleanup_free_ char *path = NULL;
 
+                LOG_CONTEXT_PUSH_UNIT(u);
+
                 unit_status_info_clear(u);
 
                 path = unit_dbus_path_from_name(u->name);
@@ -438,7 +422,7 @@ static int context_update_ntp_status(Context *c, sd_bus *bus, sd_bus_message *m)
                                 NULL,
                                 u);
                 if (r < 0)
-                        return log_unit_error_errno(u, r, "Failed to get properties: %s", bus_error_message(&error, r));
+                        return log_error_errno(r, "%s: Failed to get properties: %s", u->name, bus_error_message(&error, r));
         }
 
         return 0;
@@ -492,6 +476,8 @@ static int unit_start_or_stop(UnitStatusInfo *u, sd_bus *bus, sd_bus_error *erro
         assert(bus);
         assert(error);
 
+        LOG_CONTEXT_PUSH_UNIT(u);
+
         r = bus_call_method(
                 bus,
                 bus_systemd_mgr,
@@ -501,7 +487,7 @@ static int unit_start_or_stop(UnitStatusInfo *u, sd_bus *bus, sd_bus_error *erro
                 "ss",
                 u->name,
                 "replace");
-        log_unit_full_errno_zerook(u, r < 0 ? LOG_WARNING : LOG_DEBUG, r,
+        log_full_errno_zerook(r < 0 ? LOG_WARNING : LOG_DEBUG, r,
                               "%s unit: %m", start ? "Starting" : "Stopping");
         if (r < 0)
                 return r;
@@ -526,12 +512,14 @@ static int unit_enable_or_disable(UnitStatusInfo *u, sd_bus *bus, sd_bus_error *
 
         /* Call context_update_ntp_status() to update UnitStatusInfo before calling this. */
 
+        LOG_CONTEXT_PUSH_UNIT(u);
+
         if (streq(u->unit_file_state, "enabled") == enable) {
-                log_unit_debug(u, "already %sd.", enable_disable(enable));
+                log_debug("already %sd.", enable_disable(enable));
                 return 0;
         }
 
-        log_unit_info(u, "%s unit.", enable ? "Enabling" : "Disabling");
+        log_info("%s unit.", enable ? "Enabling" : "Disabling");
 
         if (enable)
                 r = bus_call_method(
@@ -997,6 +985,8 @@ static int method_set_ntp(sd_bus_message *m, void *userdata, sd_bus_error *error
                         if (!streq(u->load_state, "loaded"))
                                 continue;
 
+                        LOG_CONTEXT_PUSH_UNIT(u);
+
                         r = unit_enable_or_disable(u, bus, error, enable_this_one);
                         if (r < 0)
                                 /* If enablement failed, don't start this unit. */
@@ -1004,7 +994,7 @@ static int method_set_ntp(sd_bus_message *m, void *userdata, sd_bus_error *error
 
                         r = unit_start_or_stop(u, bus, error, enable_this_one);
                         if (r < 0)
-                                log_unit_warning_errno(u, r, "Failed to %s %sd NTP unit, ignoring: %m",
+                                log_warning_errno(r, "Failed to %s %sd NTP unit, ignoring: %m",
                                                   enable_this_one ? "start" : "stop",
                                                   enable_disable(enable_this_one));
                         if (enable_this_one)