Re: [PATCH] libselinux: Drop '\n' from avc_log() messages

[Daniel Burgener <dburgener@xxxxxxxxxxxxxxxxxxx>]

On 10/25/2022 7:24 AM, Petr Lautrbach wrote:
> The main set_selinux_callback() consumers, such as systemd, dbus-broker,
> and shadow-utils, expect messages to end without a newline. The default
> log handler in libselinux has been updated to add a newline to messages
> printed to stderr.
>
> Signed-off-by: Petr Lautrbach <plautrba@xxxxxxxxxx>
> ---
>   libselinux/man/man3/selinux_set_callback.3 |  3 +++
>   libselinux/src/avc.c                       | 16 ++++++-------
>   libselinux/src/avc_internal.c              | 26 +++++++++++-----------
>   libselinux/src/callbacks.c                 |  6 +++++
>   4 files changed, 30 insertions(+), 21 deletions(-)
It looks like the newline removal in this patch targetted avc_log(), but 
the newline addition is in selinux_log.

The problem is that there are numerous places where selinux_log() is 
called directly, typically with a newline.  For example 
selinux_restorecon.c has a lot of selinux_log() callers, which all(?) 
include a newline.  With a result that calling selinux_restorecon(3) 
directly appends 2 newlines after this patch.

Of course, setfiles defines its own log callback, so I don't think this 
would cause a problem there.  But any external callers without a custom 
callback would get double newlines.

Looking at setfiles log_callback.  I suspect that if we wanted to remove 
newlines to all selinux_log() callers, we would need to modify setfiles 
to append one, and the same would hold true for all internal users.

I haven't particularly inspected other selinux_log() callers, although 
it appears there are a few, and they seem to typically include a newline.

An alternative might be to add the newline in avc_log() rather than 
selinux_log(), but I haven't really thought through the implications of 
that.

-Daniel

> diff --git a/libselinux/man/man3/selinux_set_callback.3 b/libselinux/man/man3/selinux_set_callback.3
> index 75f49b06d836..124754a1854b 100644
> --- a/libselinux/man/man3/selinux_set_callback.3
> +++ b/libselinux/man/man3/selinux_set_callback.3
> @@ -122,6 +122,9 @@ None.
>   .SH "ERRORS"
>   None.
>   .
> +.SH "NOTES"
> +Log messages don't end with a newline.
> +.
>   .SH "AUTHOR"
>   Eamon Walsh <ewalsh@xxxxxxxxxxxxx>
>   .
> diff --git a/libselinux/src/avc.c b/libselinux/src/avc.c
> index 8d5983a2fe0c..e4f7f64fa913 100644
> --- a/libselinux/src/avc.c
> +++ b/libselinux/src/avc.c
> @@ -175,7 +175,7 @@ static int avc_init_internal(const char *prefix,
>   	rc = sidtab_init(&avc_sidtab);
>   	if (rc) {
>   		avc_log(SELINUX_ERROR,
> -			"%s:  unable to initialize SID table\n",
> +			"%s:  unable to initialize SID table",
>   			avc_prefix);
>   		goto out;
>   	}
> @@ -183,7 +183,7 @@ static int avc_init_internal(const char *prefix,
>   	avc_audit_buf = (char *)avc_malloc(AVC_AUDIT_BUFSIZE);
>   	if (!avc_audit_buf) {
>   		avc_log(SELINUX_ERROR,
> -			"%s:  unable to allocate audit buffer\n",
> +			"%s:  unable to allocate audit buffer",
>   			avc_prefix);
>   		rc = -1;
>   		goto out;
> @@ -193,7 +193,7 @@ static int avc_init_internal(const char *prefix,
>   		new = avc_malloc(sizeof(*new));
>   		if (!new) {
>   			avc_log(SELINUX_WARNING,
> -				"%s:  warning: only got %d av entries\n",
> +				"%s:  warning: only got %d av entries",
>   				avc_prefix, i);
>   			break;
>   		}
> @@ -206,7 +206,7 @@ static int avc_init_internal(const char *prefix,
>   		rc = security_getenforce();
>   		if (rc < 0) {
>   			avc_log(SELINUX_ERROR,
> -				"%s:  could not determine enforcing mode: %m\n",
> +				"%s:  could not determine enforcing mode: %m",
>   				avc_prefix);
>   			goto out;
>   		}
> @@ -216,7 +216,7 @@ static int avc_init_internal(const char *prefix,
>   	rc = selinux_status_open(0);
>   	if (rc < 0) {
>   		avc_log(SELINUX_ERROR,
> -			"%s: could not open selinux status page: %d (%m)\n",
> +			"%s: could not open selinux status page: %d (%m)",
>   			avc_prefix, errno);
>   		goto out;
>   	}
> @@ -292,7 +292,7 @@ void avc_av_stats(void)
>   	avc_release_lock(avc_lock);
>   
>   	avc_log(SELINUX_INFO, "%s:  %u AV entries and %d/%d buckets used, "
> -		"longest chain length %d\n", avc_prefix,
> +		"longest chain length %d", avc_prefix,
>   		avc_cache.active_nodes,
>   		slots_used, AVC_CACHE_SLOTS, max_chain_len);
>   }
> @@ -473,7 +473,7 @@ static int avc_insert(security_id_t ssid, security_id_t tsid,
>   
>   	if (ae->avd.seqno < avc_cache.latest_notif) {
>   		avc_log(SELINUX_WARNING,
> -			"%s:  seqno %u < latest_notif %u\n", avc_prefix,
> +			"%s:  seqno %u < latest_notif %u", avc_prefix,
>   			ae->avd.seqno, avc_cache.latest_notif);
>   		errno = EAGAIN;
>   		rc = -1;
> @@ -613,7 +613,7 @@ static int avc_ratelimit(void)
>   		avc_release_lock(ratelimit_lock);
>   		if (lost) {
>   			avc_log(SELINUX_WARNING,
> -				"%s:  %d messages suppressed.\n", avc_prefix,
> +				"%s:  %d messages suppressed.", avc_prefix,
>   				lost);
>   		}
>   		rc = 1;
> diff --git a/libselinux/src/avc_internal.c b/libselinux/src/avc_internal.c
> index 71a1357bc564..a5d24b16d063 100644
> --- a/libselinux/src/avc_internal.c
> +++ b/libselinux/src/avc_internal.c
> @@ -66,7 +66,7 @@ int avc_process_setenforce(int enforcing)
>   	avc_enforcing = enforcing;
>   	if (avc_enforcing && (rc = avc_ss_reset(0)) < 0) {
>   		avc_log(SELINUX_ERROR,
> -			"%s:  cache reset returned %d (errno %d)\n",
> +			"%s:  cache reset returned %d (errno %d)",
>   			avc_prefix, rc, errno);
>   		return rc;
>   	}
> @@ -86,7 +86,7 @@ int avc_process_policyload(uint32_t seqno)
>   	rc = avc_ss_reset(seqno);
>   	if (rc < 0) {
>   		avc_log(SELINUX_ERROR,
> -			"%s:  cache reset returned %d (errno %d)\n",
> +			"%s:  cache reset returned %d (errno %d)",
>   			avc_prefix, rc, errno);
>   		return rc;
>   	}
> @@ -157,7 +157,7 @@ static int avc_netlink_receive(void *buf, unsigned buflen, int blocking)
>   		return -1;
>   	}
>   	else if (rc < 1) {
> -		avc_log(SELINUX_ERROR, "%s:  netlink poll: error %d\n",
> +		avc_log(SELINUX_ERROR, "%s:  netlink poll: error %d",
>   			avc_prefix, errno);
>   		return rc;
>   	}
> @@ -169,21 +169,21 @@ static int avc_netlink_receive(void *buf, unsigned buflen, int blocking)
>   
>   	if (nladdrlen != sizeof nladdr) {
>   		avc_log(SELINUX_WARNING,
> -			"%s:  warning: netlink address truncated, len %u?\n",
> +			"%s:  warning: netlink address truncated, len %u?",
>   			avc_prefix, nladdrlen);
>   		return -1;
>   	}
>   
>   	if (nladdr.nl_pid) {
>   		avc_log(SELINUX_WARNING,
> -			"%s:  warning: received spoofed netlink packet from: %u\n",
> +			"%s:  warning: received spoofed netlink packet from: %u",
>   			avc_prefix, nladdr.nl_pid);
>   		return -1;
>   	}
>   
>   	if (rc == 0) {
>   		avc_log(SELINUX_WARNING,
> -			"%s:  warning: received EOF on netlink socket\n",
> +			"%s:  warning: received EOF on netlink socket",
>   			avc_prefix);
>   		errno = EBADFD;
>   		return -1;
> @@ -191,7 +191,7 @@ static int avc_netlink_receive(void *buf, unsigned buflen, int blocking)
>   
>   	if (nlh->nlmsg_flags & MSG_TRUNC || nlh->nlmsg_len > (unsigned)rc) {
>   		avc_log(SELINUX_WARNING,
> -			"%s:  warning: incomplete netlink message\n",
> +			"%s:  warning: incomplete netlink message",
>   			avc_prefix);
>   		return -1;
>   	}
> @@ -214,7 +214,7 @@ static int avc_netlink_process(void *buf)
>   
>   		errno = -err->error;
>   		avc_log(SELINUX_ERROR,
> -			"%s:  netlink error: %d\n", avc_prefix, errno);
> +			"%s:  netlink error: %d", avc_prefix, errno);
>   		return -1;
>   	}
>   
> @@ -236,7 +236,7 @@ static int avc_netlink_process(void *buf)
>   
>   	default:
>   		avc_log(SELINUX_WARNING,
> -			"%s:  warning: unknown netlink message %d\n",
> +			"%s:  warning: unknown netlink message %d",
>   			avc_prefix, nlh->nlmsg_type);
>   	}
>   	return 0;
> @@ -257,7 +257,7 @@ int avc_netlink_check_nb(void)
>   				continue;
>   			else {
>   				avc_log(SELINUX_ERROR,
> -					"%s:  netlink recvfrom: error %d\n",
> +					"%s:  netlink recvfrom: error %d",
>   					avc_prefix, errno);
>   				return rc;
>   			}
> @@ -282,7 +282,7 @@ void avc_netlink_loop(void)
>   				continue;
>   			else {
>   				avc_log(SELINUX_ERROR,
> -					"%s:  netlink recvfrom: error %d\n",
> +					"%s:  netlink recvfrom: error %d",
>   					avc_prefix, errno);
>   				break;
>   			}
> @@ -297,7 +297,7 @@ void avc_netlink_loop(void)
>   	fd = -1;
>   	avc_netlink_trouble = 1;
>   	avc_log(SELINUX_ERROR,
> -		"%s:  netlink thread: errors encountered, terminating\n",
> +		"%s:  netlink thread: errors encountered, terminating",
>   		avc_prefix);
>   }
>   
> @@ -308,7 +308,7 @@ int avc_netlink_acquire_fd(void)
>   		rc = avc_netlink_open(0);
>   		if (rc < 0) {
>   			avc_log(SELINUX_ERROR,
> -				"%s: could not open netlink socket: %d (%m)\n",
> +				"%s: could not open netlink socket: %d (%m)",
>   				avc_prefix, errno);
>   			return rc;
>   		}
> diff --git a/libselinux/src/callbacks.c b/libselinux/src/callbacks.c
> index 469c4055f4d7..6850df5fdfe0 100644
> --- a/libselinux/src/callbacks.c
> +++ b/libselinux/src/callbacks.c
> @@ -21,6 +21,12 @@ default_selinux_log(int type __attribute__((unused)), const char *fmt, ...)
>   	va_start(ap, fmt);
>   	rc = vfprintf(stderr, fmt, ap);
>   	va_end(ap);
> +	if (rc > 0) {
> +		if (fputc('\n', stderr) != EOF)
> +			rc++;
> +		else
> +			rc = EOF;
> +	}
>   	return rc;
>   }
>