From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from cross.elm.relay.mailchannels.net (cross.elm.relay.mailchannels.net [23.83.212.46]) by sourceware.org (Postfix) with ESMTPS id D7E5D3857016 for ; Mon, 29 Aug 2022 20:16:35 +0000 (GMT) DMARC-Filter: OpenDMARC Filter v1.4.1 sourceware.org D7E5D3857016 Authentication-Results: sourceware.org; dmarc=none (p=none dis=none) header.from=gotplt.org Authentication-Results: sourceware.org; spf=pass smtp.mailfrom=gotplt.org X-Sender-Id: dreamhost|x-authsender|siddhesh@gotplt.org Received: from relay.mailchannels.net (localhost [127.0.0.1]) by relay.mailchannels.net (Postfix) with ESMTP id 57CBF122689; Mon, 29 Aug 2022 20:16:33 +0000 (UTC) Received: from pdx1-sub0-mail-a305 (unknown [127.0.0.6]) (Authenticated sender: dreamhost) by relay.mailchannels.net (Postfix) with ESMTPA id D402C122A3C; Mon, 29 Aug 2022 20:16:32 +0000 (UTC) ARC-Seal: i=1; s=arc-2022; d=mailchannels.net; t=1661804192; a=rsa-sha256; cv=none; b=3FNVwzkIYkUUxweXAC0k+DHoFYSQaOKqBsS7WdNqfvJvrm6Wr+6POeuJD2oMZVN41Dj+sF GYP0YuKnWqr+zHBiohc0JBYG5+o04+jdv5Uzy/Wi8seeeYvh00KLOd8qggq6uP4hCwuqJi vIC3nlIHBLfZDlV3f+xJXmPJQ8l4VNizgQqadbZo3EvBStbg0anj3//c0Mg4z6afFSlbti crVsjo++Nr0du5eQ/NmaGCQ6aGgc4dKR/k4UrZSH1QGCM4YKOFmlwH/8MGAueG65QXcOFp xJ4sHlYQ9SDEbIlHMjwZBMQEt7B0K3cliyTFNnlC9JfjnL7AKZ0b4k1WG/vZfg== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=mailchannels.net; s=arc-2022; t=1661804192; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding: in-reply-to:in-reply-to:references:references:dkim-signature; bh=eT9rO8d//BSzDvkL7wYuUkoULAxZD5rRlUKiJNpsZ/g=; b=j7OqjnFBeq716Z5kgi7JgyS6Rl/b8f2N7DBl3CWSytpByhGvkdNyN6kDFzSUDKGbWrRl3z MoXAhsDcrx43ATh6E1JWCDEHv6e8ei0OJhmqLSzvYS6iTiGXTVhALufhktY8GQLWe1hZYJ zJI8F+8UPDKssGD/XbZdDX94CDNYKDkcF8G0xKDA4+ZpBB0bTltnZdV9FnGtdzVMtSG+SJ jw5zlGDBSGQ8fzzGNCmGkwnrhmr6ZYfOKoK1fTeG45ruBVQ2Ncj2LJALsYxGJSmPHwZSuj IXJ3qghoXc3gDJaRJvBRz5m1fm3csnX2tNIEAgPWOAELTD8hgvavU8yRYTbZ2g== ARC-Authentication-Results: i=1; rspamd-64cc6f7466-q4ltg; auth=pass smtp.auth=dreamhost smtp.mailfrom=siddhesh@gotplt.org X-Sender-Id: dreamhost|x-authsender|siddhesh@gotplt.org X-MC-Relay: Neutral X-MailChannels-SenderId: dreamhost|x-authsender|siddhesh@gotplt.org X-MailChannels-Auth-Id: dreamhost X-Vacuous-Army: 624a344a26ca393c_1661804193121_1180997929 X-MC-Loop-Signature: 1661804193121:3858673351 X-MC-Ingress-Time: 1661804193120 Received: from pdx1-sub0-mail-a305 (pop.dreamhost.com [64.90.62.162]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384) by 100.108.161.89 (trex/6.7.1); Mon, 29 Aug 2022 20:16:33 +0000 Received: from [192.168.0.182] (bras-vprn-toroon4834w-lp130-16-184-147-84-238.dsl.bell.ca [184.147.84.238]) (using TLSv1.3 with cipher TLS_AES_128_GCM_SHA256 (128/128 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits)) (No client certificate requested) (Authenticated sender: siddhesh@gotplt.org) by pdx1-sub0-mail-a305 (Postfix) with ESMTPSA id 4MGhXw0qqxzVw; Mon, 29 Aug 2022 13:16:31 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gotplt.org; s=dreamhost; t=1661804192; bh=eT9rO8d//BSzDvkL7wYuUkoULAxZD5rRlUKiJNpsZ/g=; h=Date:Subject:To:From:Content-Type:Content-Transfer-Encoding; b=sDdYMRSh5Wm3ckBvTsQP84B8gh32e0s34ySaVWq6EJDOq+6PCRdRyYiWZWXnni0PI gu0o4+TmmkU33ld54LTiolZLt/EUQ4GpQdmSoon/Dd2js/m8vukzqA0rIYZY5+/0VG gGUaMXWDdKeQBD7MywjN0TawoCESPYqHxzPVvAreeK8LaDCKrL7tvbNw9sgjY4hzca eZLbooGKokJd1P+rfh4RipUPU1NVG1UQcFBJPXaBLRcGBffqOCeUOuNX6BHe2pUb1H 8mbfpI2D0FN5lKEb+FL6F2iciIyedyo1TMjKWifKLWNvIOxv7aDPnIlozgTgTs1bWf UVp5sIPgklxhw== Message-ID: <562fe7a8-a1b1-a355-3250-bb726b33f2bf@gotplt.org> Date: Mon, 29 Aug 2022 16:16:30 -0400 MIME-Version: 1.0 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:91.0) Gecko/20100101 Thunderbird/91.12.0 Subject: Re: [PATCH] syslog: Fix large messages (BZ#29536) Content-Language: en-US To: Adhemerval Zanella , libc-alpha@sourceware.org References: <20220829123751.89906-1-adhemerval.zanella@linaro.org> From: Siddhesh Poyarekar In-Reply-To: <20220829123751.89906-1-adhemerval.zanella@linaro.org> Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: 7bit X-Spam-Status: No, score=-3038.1 required=5.0 tests=BAYES_00,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DKIM_VALID_EF,GIT_PATCH_0,NICE_REPLY_A,RCVD_IN_DNSWL_NONE,RCVD_IN_MSPIKE_H2,SPF_HELO_NONE,SPF_PASS,TXREP,T_SCC_BODY_TEXT_LINE autolearn=ham autolearn_force=no version=3.4.6 X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on server2.sourceware.org List-Id: On 2022-08-29 08:37, Adhemerval Zanella via Libc-alpha wrote: > The a583b6add407c17cd change did not handle large messages that > would require a heap allocation correctly, where the message itself > is not take in consideration. > > This patch fixes it and extend the tst-syslog to check for large > messages as well. > > Checked on x86_64-linux-gnu. The change itself looks good. For the test, could it cover both large as well as small strings? e.g., 64, 1024 and 1280 byte messages. That'll ensure all code paths are covered. Thanks, Siddhesh > --- > misc/syslog.c | 18 +++--- > misc/tst-syslog.c | 152 +++++++++++++++++++++++++++++++++++++++------- > 2 files changed, 142 insertions(+), 28 deletions(-) > > diff --git a/misc/syslog.c b/misc/syslog.c > index 554089bfc4..b88f66c835 100644 > --- a/misc/syslog.c > +++ b/misc/syslog.c > @@ -193,28 +193,32 @@ __vsyslog_internal (int pri, const char *fmt, va_list ap, > int vl = __vsnprintf_internal (bufs + l, sizeof bufs - l, fmt, apc, > mode_flags); > if (0 <= vl && vl < sizeof bufs - l) > - { > - buf = bufs; > - bufsize = l + vl; > - } > + buf = bufs; > + bufsize = l + vl; > > va_end (apc); > } > > if (buf == NULL) > { > - buf = malloc (l * sizeof (char)); > + buf = malloc ((bufsize + 1) * sizeof (char)); > if (buf != NULL) > { > /* Tell the cancellation handler to free this buffer. */ > clarg.buf = buf; > > if (has_ts) > - __snprintf (bufs, sizeof bufs, > + __snprintf (buf, l + 1, > SYSLOG_HEADER (pri, timestamp, &msgoff, pid)); > else > - __snprintf (bufs, sizeof bufs, > + __snprintf (buf, l + 1, > SYSLOG_HEADER_WITHOUT_TS (pri, &msgoff)); > + > + va_list apc; > + va_copy (apc, ap); > + __vsnprintf_internal (buf + l, bufsize - l + 1, fmt, apc, > + mode_flags); > + va_end (apc); > } > else > { > diff --git a/misc/tst-syslog.c b/misc/tst-syslog.c > index e550d15796..1d332ece53 100644 > --- a/misc/tst-syslog.c > +++ b/misc/tst-syslog.c > @@ -68,21 +68,19 @@ static const int priorities[] = > LOG_DEBUG > }; > > -enum > - { > - ident_length = 64, > - msg_length = 64 > - }; > +#define IDENT_LENGTH 64 > +#define MSG_LENGTH 1024 > > #define SYSLOG_MSG_BASE "syslog_message" > #define OPENLOG_IDENT "openlog_ident" > +static char large_message[MSG_LENGTH]; > > struct msg_t > { > int priority; > int facility; > - char ident[ident_length]; > - char msg[msg_length]; > + char ident[IDENT_LENGTH]; > + char msg[MSG_LENGTH]; > pid_t pid; > }; > > @@ -147,6 +145,37 @@ check_syslog_message (const struct msg_t *msg, int msgnum, int options, > return true; > } > > +static void > +send_syslog_large (int options) > +{ > + int facility = LOG_USER; > + int priority = LOG_INFO; > + > + syslog (facility | priority, "%s %d %d", large_message, facility, > + priority); > +} > + > +static void > +send_vsyslog_large (int options) > +{ > + int facility = LOG_USER; > + int priority = LOG_INFO; > + > + call_vsyslog (facility | priority, "%s %d %d", large_message, facility, > + priority); > +} > + > +static bool > +check_syslog_message_large (const struct msg_t *msg, int msgnum, int options, > + pid_t pid) > +{ > + TEST_COMPARE (msg->facility, LOG_USER); > + TEST_COMPARE (msg->priority, LOG_INFO); > + TEST_COMPARE_STRING (msg->msg, large_message); > + > + return false; > +} > + > static void > send_openlog (int options) > { > @@ -179,6 +208,17 @@ send_openlog (int options) > closelog (); > } > > +static void > +send_openlog_large (int options) > +{ > + /* Define a non-default IDENT and a not default facility. */ > + openlog (OPENLOG_IDENT, options, LOG_LOCAL0); > + > + syslog (LOG_INFO, "%s %d %d", large_message, LOG_LOCAL0, LOG_INFO); > + > + closelog (); > +} > + > static bool > check_openlog_message (const struct msg_t *msg, int msgnum, > int options, pid_t pid) > @@ -189,7 +229,7 @@ check_openlog_message (const struct msg_t *msg, int msgnum, > int expected_priority = priorities[msgnum % array_length (priorities)]; > TEST_COMPARE (msg->priority, expected_priority); > > - char expected_ident[ident_length]; > + char expected_ident[IDENT_LENGTH]; > snprintf (expected_ident, sizeof (expected_ident), "%s%s%.0d%s:", > OPENLOG_IDENT, > options & LOG_PID ? "[" : "", > @@ -211,15 +251,38 @@ check_openlog_message (const struct msg_t *msg, int msgnum, > return true; > } > > +static bool > +check_openlog_message_large (const struct msg_t *msg, int msgnum, > + int options, pid_t pid) > +{ > + char expected_ident[IDENT_LENGTH]; > + snprintf (expected_ident, sizeof (expected_ident), "%s%s%.0d%s:", > + OPENLOG_IDENT, > + options & LOG_PID ? "[" : "", > + options & LOG_PID ? pid : 0, > + options & LOG_PID ? "]" : ""); > + > + TEST_COMPARE_STRING (msg->ident, expected_ident); > + TEST_COMPARE_STRING (msg->msg, large_message); > + TEST_COMPARE (msg->priority, LOG_INFO); > + TEST_COMPARE (msg->facility, LOG_LOCAL0); > + > + return false; > +} > + > static struct msg_t > parse_syslog_msg (const char *msg) > { > struct msg_t r = { .pid = -1 }; > int number; > > +#define STRINPUT(size) XSTRINPUT(size) > +#define XSTRINPUT(size) "%" # size "s" > + > /* The message in the form: > - <179>Apr 8 14:51:19 tst-syslog: syslog message 176 3 */ > - int n = sscanf (msg, "<%3d>%*s %*d %*d:%*d:%*d %32s %64s %*d %*d", > + <179>Apr 8 14:51:19 tst-syslog: message 176 3 */ > + int n = sscanf (msg, "<%3d>%*s %*d %*d:%*d:%*d " STRINPUT(IDENT_LENGTH) > + " " STRINPUT(MSG_LENGTH) " %*d %*d", > &number, r.ident, r.msg); > TEST_COMPARE (n, 3); > > @@ -246,7 +309,7 @@ parse_syslog_console (const char *msg) > > /* The message in the form: > openlog_ident: syslog_message 128 0 */ > - int n = sscanf (msg, "%32s %64s %d %d", > + int n = sscanf (msg, STRINPUT(IDENT_LENGTH) " " STRINPUT(MSG_LENGTH) " %d %d", > r.ident, r.msg, &facility, &priority); > TEST_COMPARE (n, 4); > > @@ -281,7 +344,7 @@ check_syslog_udp (void (*syslog_send)(int), int options, > int msgnum = 0; > while (1) > { > - char buf[512]; > + char buf[2048]; > size_t l = xrecvfrom (server_udp, buf, sizeof (buf), 0, > (struct sockaddr *) &addr, &addrlen); > buf[l] = '\0'; > @@ -325,7 +388,7 @@ check_syslog_tcp (void (*syslog_send)(int), int options, > > int client_tcp = xaccept (server_tcp, NULL, NULL); > > - char buf[512], *rb = buf; > + char buf[2048], *rb = buf; > size_t rbl = sizeof (buf); > size_t prl = 0; /* Track the size of the partial record. */ > int msgnum = 0; > @@ -393,20 +456,34 @@ check_syslog_console_read (FILE *fp) > } > > static void > -check_syslog_console (void) > +check_syslog_console_read_large (FILE *fp) > +{ > + char buf[2048]; > + TEST_VERIFY (fgets (buf, sizeof (buf), fp) != NULL); > + struct msg_t msg = parse_syslog_console (buf); > + > + TEST_COMPARE_STRING (msg.ident, OPENLOG_IDENT ":"); > + TEST_COMPARE_STRING (msg.msg, large_message); > + TEST_COMPARE (msg.priority, LOG_INFO); > + TEST_COMPARE (msg.facility, LOG_LOCAL0); > +} > + > +static void > +check_syslog_console (void (*syslog_send)(int), > + void (*syslog_check)(FILE *fp)) > { > xmkfifo (_PATH_CONSOLE, 0666); > > pid_t sender_pid = xfork (); > if (sender_pid == 0) > { > - send_openlog (LOG_CONS); > + syslog_send (LOG_CONS); > _exit (0); > } > > { > FILE *fp = xfopen (_PATH_CONSOLE, "r+"); > - check_syslog_console_read (fp); > + syslog_check (fp); > xfclose (fp); > } > > @@ -425,16 +502,28 @@ send_openlog_callback (void *clousure) > } > > static void > -check_syslog_perror (void) > +send_openlog_callback_large (void *clousure) > +{ > + int options = *(int *) clousure; > + send_openlog_large (options); > +} > + > +static void > +check_syslog_perror (bool large) > { > struct support_capture_subprocess result; > - result = support_capture_subprocess (send_openlog_callback, > + result = support_capture_subprocess (large > + ? send_openlog_callback_large > + : send_openlog_callback, > &(int){LOG_PERROR}); > > FILE *mfp = fmemopen (result.err.buffer, result.err.length, "r"); > if (mfp == NULL) > FAIL_EXIT1 ("fmemopen: %m"); > - check_syslog_console_read (mfp); > + if (large) > + check_syslog_console_read_large (mfp); > + else > + check_syslog_console_read (mfp); > xfclose (mfp); > > support_capture_subprocess_check (&result, "tst-openlog-child", 0, > @@ -462,10 +551,31 @@ do_test (void) > check_syslog_tcp (send_openlog, LOG_PID, check_openlog_message); > > /* Check the LOG_CONS option. */ > - check_syslog_console (); > + check_syslog_console (send_openlog, check_syslog_console_read); > > /* Check the LOG_PERROR option. */ > - check_syslog_perror (); > + check_syslog_perror (false); > + > + /* Similar tests as before, but with a large message to trigger the > + syslog path that uses dynamically allocated memory. */ > + memset (large_message, 'a', sizeof large_message - 1); > + large_message[sizeof large_message - 1] = '\0'; > + > + check_syslog_udp (send_syslog_large, 0, check_syslog_message_large); > + check_syslog_tcp (send_syslog_large, 0, check_syslog_message_large); > + > + check_syslog_udp (send_vsyslog_large, 0, check_syslog_message_large); > + check_syslog_tcp (send_vsyslog_large, 0, check_syslog_message_large); > + > + check_syslog_udp (send_openlog_large, 0, check_openlog_message_large); > + check_syslog_tcp (send_openlog_large, 0, check_openlog_message_large); > + > + check_syslog_udp (send_openlog_large, LOG_PID, check_openlog_message_large); > + check_syslog_tcp (send_openlog_large, LOG_PID, check_openlog_message_large); > + > + check_syslog_console (send_openlog_large, check_syslog_console_read_large); > + > + check_syslog_perror (true); > > return 0; > }