public inbox for libc-alpha@sourceware.org
 help / color / mirror / Atom feed
* [PATCH v2 0/7] Use RFC5424 for syslog
@ 2022-02-18 14:23 Adhemerval Zanella
  2022-02-18 14:23 ` [PATCH v2 1/7] support: Add xmkfifo Adhemerval Zanella
                   ` (6 more replies)
  0 siblings, 7 replies; 21+ messages in thread
From: Adhemerval Zanella @ 2022-02-18 14:23 UTC (permalink / raw)
  To: libc-alpha

This is an update of my previous patchset.  The main driver of this
change is to move away of using 32-bit timestamps and for syslog it
would require to use an ad-hoc format.  Instead, since RFC5424 does
define a better way to format the timestamp, it is used instead.

Along with the RFC5424 change, the patch simplifies the code to use
a static buffer on default case (so no dynamic allocation for
messages up to 1024) and add a proper syslog() testscase.

Adhemerval Zanella (7):
  support: Add xmkfifo
  misc: Add syslog test
  misc: syslog: Fix indentation and style
  misc: syslog: Simplify implementation
  misc: syslog: Use static buffer
  misc: syslog: Move SYSLOG_NAME to USE_MISC (BZ #16355)
  misc: syslog: Use RFC5424

 misc/Makefile     |   2 +
 misc/sys/syslog.h |   4 +-
 misc/syslog.c     | 497 +++++++++++++++++++++++-----------------------
 misc/tst-syslog.c | 475 ++++++++++++++++++++++++++++++++++++++++++++
 support/Makefile  |   1 +
 support/xmkfifo.c |  29 +++
 support/xunistd.h |   1 +
 7 files changed, 763 insertions(+), 246 deletions(-)
 create mode 100644 misc/tst-syslog.c
 create mode 100644 support/xmkfifo.c

-- 
2.32.0


^ permalink raw reply	[flat|nested] 21+ messages in thread

* [PATCH v2 1/7] support: Add xmkfifo
  2022-02-18 14:23 [PATCH v2 0/7] Use RFC5424 for syslog Adhemerval Zanella
@ 2022-02-18 14:23 ` Adhemerval Zanella
  2022-02-18 14:23 ` [PATCH v2 2/7] misc: Add syslog test Adhemerval Zanella
                   ` (5 subsequent siblings)
  6 siblings, 0 replies; 21+ messages in thread
From: Adhemerval Zanella @ 2022-02-18 14:23 UTC (permalink / raw)
  To: libc-alpha

Wrapper support mkfifo.
---
 support/Makefile  |  1 +
 support/xmkfifo.c | 29 +++++++++++++++++++++++++++++
 support/xunistd.h |  1 +
 3 files changed, 31 insertions(+)
 create mode 100644 support/xmkfifo.c

diff --git a/support/Makefile b/support/Makefile
index 5ddcb8d158..c3609e211b 100644
--- a/support/Makefile
+++ b/support/Makefile
@@ -133,6 +133,7 @@ libsupport-routines = \
   xmemstream \
   xmkdir \
   xmkdirp \
+  xmkfifo \
   xmmap \
   xmprotect \
   xmunmap \
diff --git a/support/xmkfifo.c b/support/xmkfifo.c
new file mode 100644
index 0000000000..a8e196dbc2
--- /dev/null
+++ b/support/xmkfifo.c
@@ -0,0 +1,29 @@
+/* mkfifo with error checking.
+   Copyright (C) 2022 Free Software Foundation, Inc.
+   This file is part of the GNU C Library.
+
+   The GNU C Library is free software; you can redistribute it and/or
+   modify it under the terms of the GNU Lesser General Public
+   License as published by the Free Software Foundation; either
+   version 2.1 of the License, or (at your option) any later version.
+
+   The GNU C Library is distributed in the hope that it will be useful,
+   but WITHOUT ANY WARRANTY; without even the implied warranty of
+   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
+   Lesser General Public License for more details.
+
+   You should have received a copy of the GNU Lesser General Public
+   License along with the GNU C Library; if not, see
+   <https://www.gnu.org/licenses/>.  */
+
+#include <support/check.h>
+#include <support/xunistd.h>
+#include <sys/stat.h>
+
+void
+xmkfifo (const char *pathname, mode_t mode)
+{
+  int r = mkfifo (pathname, mode);
+  if (r < 0)
+    FAIL_EXIT1 ("mkfifo (%s, 0%o): %m", pathname, mode);
+}
diff --git a/support/xunistd.h b/support/xunistd.h
index 0454d83cf1..960a62d412 100644
--- a/support/xunistd.h
+++ b/support/xunistd.h
@@ -61,6 +61,7 @@ void xsymlink (const char *target, const char *linkpath);
 void xchdir (const char *path);
 void xfchmod (int fd, mode_t mode);
 void xchmod (const char *pathname, mode_t mode);
+void xmkfifo (const char *pathname, mode_t mode);
 
 /* Equivalent of "mkdir -p".  */
 void xmkdirp (const char *, mode_t);
-- 
2.32.0


^ permalink raw reply	[flat|nested] 21+ messages in thread

* [PATCH v2 2/7] misc: Add syslog test
  2022-02-18 14:23 [PATCH v2 0/7] Use RFC5424 for syslog Adhemerval Zanella
  2022-02-18 14:23 ` [PATCH v2 1/7] support: Add xmkfifo Adhemerval Zanella
@ 2022-02-18 14:23 ` Adhemerval Zanella
  2022-02-18 14:23 ` [PATCH v2 3/7] misc: syslog: Fix indentation and style Adhemerval Zanella
                   ` (4 subsequent siblings)
  6 siblings, 0 replies; 21+ messages in thread
From: Adhemerval Zanella @ 2022-02-18 14:23 UTC (permalink / raw)
  To: libc-alpha

The test cover:

  - All possible priorities and facilities through TCP and UDP.
  - Same syslog tests for vsyslog.
  - Some openlog/syslog/close combinations.
  - openlog with LOG_CONS, LOG_PERROR, and LOG_PID.

Internally is done with a test-container where the main process mimics
the syslog server interface.

The test does not cover multithread and async-signal usage.

Checked on x86_64-linux-gnu.
---
 misc/Makefile     |   2 +
 misc/tst-syslog.c | 477 ++++++++++++++++++++++++++++++++++++++++++++++
 2 files changed, 479 insertions(+)
 create mode 100644 misc/tst-syslog.c

diff --git a/misc/Makefile b/misc/Makefile
index 3d8a569d06..ba8232a0e9 100644
--- a/misc/Makefile
+++ b/misc/Makefile
@@ -115,6 +115,8 @@ tests-special += $(objpfx)tst-error1-mem.out \
   $(objpfx)tst-allocate_once-mem.out
 endif
 
+tests-container := tst-syslog
+
 CFLAGS-select.c += -fexceptions -fasynchronous-unwind-tables
 CFLAGS-tsearch.c += $(uses-callbacks)
 CFLAGS-lsearch.c += $(uses-callbacks)
diff --git a/misc/tst-syslog.c b/misc/tst-syslog.c
new file mode 100644
index 0000000000..8505178616
--- /dev/null
+++ b/misc/tst-syslog.c
@@ -0,0 +1,477 @@
+/* Basic tests for syslog interfaces.
+   Copyright (C) 2022 Free Software Foundation, Inc.
+   This file is part of the GNU C Library.
+
+   The GNU C Library is free software; you can redistribute it and/or
+   modify it under the terms of the GNU Lesser General Public
+   License as published by the Free Software Foundation; either
+   version 2.1 of the License, or (at your option) any later version.
+
+   The GNU C Library is distributed in the hope that it will be useful,
+   but WITHOUT ANY WARRANTY; without even the implied warranty of
+   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
+   Lesser General Public License for more details.
+
+   You should have received a copy of the GNU Lesser General Public
+   License along with the GNU C Library; if not, see
+   <https://www.gnu.org/licenses/>.  */
+
+#include <array_length.h>
+#include <fcntl.h>
+#include <paths.h>
+#include <netinet/in.h>
+#include <support/capture_subprocess.h>
+#include <support/check.h>
+#include <support/temp_file.h>
+#include <support/xstdio.h>
+#include <support/xsocket.h>
+#include <support/xunistd.h>
+#include <stdarg.h>
+#include <stdbool.h>
+#include <stddef.h>
+#include <stdlib.h>
+#include <syslog.h>
+#include <sys/un.h>
+
+static const int facilities[] =
+  {
+    LOG_KERN,
+    LOG_USER,
+    LOG_MAIL,
+    LOG_DAEMON,
+    LOG_AUTH,
+    LOG_SYSLOG,
+    LOG_LPR,
+    LOG_NEWS,
+    LOG_UUCP,
+    LOG_CRON,
+    LOG_AUTHPRIV,
+    LOG_FTP,
+    LOG_LOCAL0,
+    LOG_LOCAL1,
+    LOG_LOCAL2,
+    LOG_LOCAL3,
+    LOG_LOCAL4,
+    LOG_LOCAL5,
+    LOG_LOCAL6,
+    LOG_LOCAL7,
+  };
+
+static const int priorities[] =
+  {
+    LOG_EMERG,
+    LOG_ALERT,
+    LOG_CRIT,
+    LOG_ERR,
+    LOG_WARNING,
+    LOG_NOTICE,
+    LOG_INFO,
+    LOG_DEBUG
+  };
+
+enum
+  {
+    ident_length = 64,
+    msg_length = 64
+  };
+
+#define SYSLOG_MSG_BASE "syslog_message"
+#define OPENLOG_IDENT   "openlog_ident"
+
+struct msg_t
+  {
+    int priority;
+    int facility;
+    char ident[ident_length];
+    char msg[msg_length];
+    pid_t pid;
+  };
+
+static void
+call_vsyslog (int priority, const char *format, ...)
+{
+  va_list ap;
+  va_start (ap, format);
+  vsyslog (priority, format, ap);
+  va_end (ap);
+}
+
+static void
+send_vsyslog (int options)
+{
+  for (size_t i = 0; i < array_length (facilities); i++)
+    {
+      for (size_t j = 0; j < array_length (priorities); j++)
+        {
+          int facility = facilities[i];
+          int priority = priorities[j];
+          call_vsyslog (facility | priority, "%s %d %d", SYSLOG_MSG_BASE,
+                        facility, priority);
+        }
+    }
+}
+
+static void
+send_syslog (int options)
+{
+  for (size_t i = 0; i < array_length (facilities); i++)
+    {
+      for (size_t j = 0; j < array_length (priorities); j++)
+        {
+          int facility = facilities[i];
+          int priority = priorities[j];
+          syslog (facility | priority, "%s %d %d", SYSLOG_MSG_BASE, facility,
+                  priority);
+        }
+    }
+}
+
+static bool
+check_syslog_message (const struct msg_t *msg, int msgnum, int options,
+                      pid_t pid)
+{
+  if (msgnum == array_length (facilities) * array_length (priorities) - 1)
+    return false;
+
+  int i = msgnum / array_length (priorities);
+  int j = msgnum % array_length (priorities);
+
+  int expected_facility = facilities[i];
+  /* With no preceding openlog, syslog default to LOG_USER.  */
+  if (expected_facility == LOG_KERN)
+      expected_facility = LOG_USER;
+  int expected_priority = priorities[j];
+
+  TEST_COMPARE (msg->facility, expected_facility);
+  TEST_COMPARE (msg->priority, expected_priority);
+
+  return true;
+}
+
+static void
+send_openlog (int options)
+{
+  /* Define a non-default IDENT and a not default facility.  */
+  openlog (OPENLOG_IDENT, options, LOG_LOCAL0);
+  for (size_t j = 0; j < array_length (priorities); j++)
+    {
+      int priority = priorities[j];
+      syslog (priority, "%s %d %d", SYSLOG_MSG_BASE, LOG_LOCAL0, priority);
+    }
+  closelog ();
+
+  /* Back to the default IDENT with a non default facility.  */
+  openlog (NULL, 0, LOG_LOCAL6);
+  for (size_t j = 0; j < array_length (priorities); j++)
+    {
+      int priority = priorities[j];
+      syslog (LOG_LOCAL7 | priority, "%s %d %d", SYSLOG_MSG_BASE, LOG_LOCAL7,
+        priority);
+    }
+  closelog ();
+
+  /* LOG_KERN does not change the internal default facility.  */
+  openlog (NULL, 0, LOG_KERN);
+  for (size_t j = 0; j < array_length (priorities); j++)
+    {
+      int priority = priorities[j];
+      syslog (priority, "%s %d %d", SYSLOG_MSG_BASE, LOG_KERN, priority);
+    }
+  closelog ();
+}
+
+static bool
+check_openlog_message (const struct msg_t *msg, int msgnum,
+                       int options, pid_t pid)
+{
+  if (msgnum == 3 * array_length (priorities) - 1)
+    return false;
+
+  int expected_priority = priorities[msgnum % array_length (priorities)];
+  TEST_COMPARE (msg->priority, expected_priority);
+
+  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 ? "]" : "");
+
+  if (msgnum < array_length (priorities))
+    {
+      if (options & LOG_PID)
+        TEST_COMPARE (msg->pid, pid);
+      TEST_COMPARE_STRING (msg->ident, expected_ident);
+      TEST_COMPARE (msg->facility, LOG_LOCAL0);
+    }
+  else if (msgnum < 2 * array_length (priorities))
+    TEST_COMPARE (msg->facility, LOG_LOCAL7);
+  else if (msgnum < 3 * array_length (priorities))
+    TEST_COMPARE (msg->facility, LOG_KERN);
+
+  return true;
+}
+
+static struct msg_t
+parse_syslog_msg (const char *msg)
+{
+  struct msg_t r = { .pid = -1 };
+  int number;
+
+  /* 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",
+                  &number, r.ident, r.msg);
+  TEST_COMPARE (n, 3);
+
+  r.facility = number & LOG_FACMASK;
+  r.priority = number & LOG_PRIMASK;
+
+  char *pid_start = strchr (r.ident, '[');
+  if (pid_start != NULL)
+    {
+       char *pid_end = strchr (r.ident, ']');
+       if (pid_end != NULL)
+         r.pid = strtoul (pid_start + 1, NULL, 10);
+    }
+
+  return r;
+}
+
+static struct msg_t
+parse_syslog_console (const char *msg)
+{
+  int priority;
+  int facility;
+  struct msg_t r;
+
+  /* The message in the form:
+     openlog_ident: syslog_message 128 0  */
+  int n = sscanf (msg, "%32s %64s %d %d",
+      r.ident, r.msg, &facility, &priority);
+  TEST_COMPARE (n, 4);
+
+  r.facility = facility;
+  r.priority = priority;
+
+  return r;
+}
+
+static void
+check_syslog_udp (void (*syslog_send)(int), int options,
+                  bool (*syslog_check)(const struct msg_t *, int, int,
+                                       pid_t))
+{
+  struct sockaddr_un addr =
+    {
+      .sun_family = AF_UNIX,
+      .sun_path = _PATH_LOG
+    };
+
+  socklen_t addrlen = sizeof (addr);
+  int server_udp = xsocket (AF_UNIX, SOCK_DGRAM | SOCK_CLOEXEC, 0);
+  xbind (server_udp, (struct sockaddr *) &addr, addrlen);
+
+  pid_t sender_pid = xfork ();
+  if (sender_pid == 0)
+    {
+      syslog_send (options);
+      _exit (0);
+    }
+
+  int msgnum = 0;
+  while (1)
+    {
+      char buf[512];
+      size_t l = xrecvfrom (server_udp, buf, sizeof (buf), 0,
+                            (struct sockaddr *) &addr, &addrlen);
+      buf[l] = '\0';
+
+      struct msg_t msg = parse_syslog_msg (buf);
+      if (!syslog_check (&msg, msgnum++, options, sender_pid))
+        break;
+     }
+
+  xclose (server_udp);
+
+  int status;
+  xwaitpid (sender_pid, &status, 0);
+  TEST_COMPARE (status, 0);
+
+  unlink (_PATH_LOG);
+}
+
+static void
+check_syslog_tcp (void (*syslog_send)(int), int options,
+                  bool (*syslog_check)(const struct msg_t *, int, int,
+                                       pid_t))
+{
+  struct sockaddr_un addr =
+    {
+      .sun_family = AF_UNIX,
+      .sun_path = _PATH_LOG
+    };
+  socklen_t addrlen = sizeof (addr);
+
+  int server_tcp = xsocket (AF_UNIX, SOCK_STREAM | SOCK_CLOEXEC, 0);
+  xbind (server_tcp, (struct sockaddr *) &addr, addrlen);
+  xlisten (server_tcp, 5);
+
+  pid_t sender_pid = xfork ();
+  if (sender_pid == 0)
+    {
+      syslog_send (options);
+      _exit (0);
+    }
+
+  int client_tcp = xaccept (server_tcp, NULL, NULL);
+
+  char buf[512], *rb = buf;
+  size_t rbl = sizeof (buf);
+  size_t prl = 0;  /* Track the size of the partial record.  */
+  int msgnum = 0;
+
+  while (1)
+    {
+      size_t rl = xrecvfrom (client_tcp, rb, rbl - prl, 0, NULL, NULL);
+      if (rl == 0)
+        break;
+
+      /* Iterate over the buffer to find and check the record.  */
+      size_t l = rl + prl;
+      char *b = buf;
+      while (1)
+	{
+          /* With TCP each record ends with a '\0'.  */
+          char *e = memchr (b, '\0', l);
+          if (e != NULL)
+            {
+              struct msg_t msg = parse_syslog_msg (b);
+              if (!syslog_check (&msg, msgnum++, options, sender_pid))
+                break;
+
+	      /* Advance to the next record.  */
+	      ptrdiff_t diff = e + 1 - b;
+	      b += diff;
+	      l -= diff;
+	    }
+	  else
+	    {
+              /* Move the partial record to the start of the buffer.  */
+	      memmove (buf, b, l);
+	      rb = buf + l;
+	      prl = l;
+	      break;
+            }
+        }
+    }
+
+  xclose (client_tcp);
+  xclose (server_tcp);
+
+  int status;
+  xwaitpid (sender_pid, &status, 0);
+  TEST_COMPARE (status, 0);
+
+  unlink (_PATH_LOG);
+}
+
+static void
+check_syslog_console_read (FILE *fp)
+{
+  char buf[512];
+  int msgnum = 0;
+  while (fgets (buf, sizeof (buf), fp) != NULL)
+    {
+      struct msg_t msg = parse_syslog_console (buf);
+      TEST_COMPARE_STRING (msg.ident, OPENLOG_IDENT ":");
+      TEST_COMPARE (msg.priority, priorities[msgnum]);
+      TEST_COMPARE (msg.facility, LOG_LOCAL0);
+
+      if (++msgnum == array_length (priorities))
+        break;
+    }
+}
+
+static void
+check_syslog_console (void)
+{
+  xmkfifo (_PATH_CONSOLE, 0666);
+
+  pid_t sender_pid = xfork ();
+  if (sender_pid == 0)
+    {
+      send_openlog (LOG_CONS);
+      _exit (0);
+    }
+
+  {
+    FILE *fp = xfopen (_PATH_CONSOLE, "r+");
+    check_syslog_console_read (fp);
+    xfclose (fp);
+  }
+
+  int status;
+  xwaitpid (sender_pid, &status, 0);
+  TEST_COMPARE (status, 0);
+
+  unlink (_PATH_CONSOLE);
+}
+
+static void
+send_openlog_callback (void *clousure)
+{
+  int options = *(int *) clousure;
+  send_openlog (options);
+}
+
+static void
+check_syslog_perror (void)
+{
+  struct support_capture_subprocess result;
+  result = support_capture_subprocess (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);
+  xfclose (mfp);
+
+  support_capture_subprocess_check (&result, "tst-openlog-child", 0,
+                                    sc_allow_stderr);
+  support_capture_subprocess_free (&result);
+}
+
+static int
+do_test (void)
+{
+  add_temp_file (_PATH_LOG);
+  add_temp_file (_PATH_CONSOLE);
+
+  /* Send every combination of facility/priority over UDP and TCP.  */
+  check_syslog_udp (send_syslog, 0, check_syslog_message);
+  check_syslog_tcp (send_syslog, 0, check_syslog_message);
+
+  /* Also check vsyslog.  */
+  check_syslog_udp (send_vsyslog, 0, check_syslog_message);
+  check_syslog_tcp (send_vsyslog, 0, check_syslog_message);
+
+  /* Run some openlog/syslog/closelog combinations.  */
+  check_syslog_udp (send_openlog, 0, check_openlog_message);
+  check_syslog_tcp (send_openlog, 0, check_openlog_message);
+
+  /* Check the LOG_PID option.  */
+  check_syslog_udp (send_openlog, LOG_PID, check_openlog_message);
+  check_syslog_tcp (send_openlog, LOG_PID, check_openlog_message);
+
+  /* Check the LOG_CONS option.  */
+  check_syslog_console ();
+
+  /* Check the LOG_PERROR option.  */
+  check_syslog_perror ();
+
+  return 0;
+}
+
+#include <support/test-driver.c>
-- 
2.32.0


^ permalink raw reply	[flat|nested] 21+ messages in thread

* [PATCH v2 3/7] misc: syslog: Fix indentation and style
  2022-02-18 14:23 [PATCH v2 0/7] Use RFC5424 for syslog Adhemerval Zanella
  2022-02-18 14:23 ` [PATCH v2 1/7] support: Add xmkfifo Adhemerval Zanella
  2022-02-18 14:23 ` [PATCH v2 2/7] misc: Add syslog test Adhemerval Zanella
@ 2022-02-18 14:23 ` Adhemerval Zanella
  2022-02-18 14:23 ` [PATCH v2 4/7] misc: syslog: Simplify implementation Adhemerval Zanella
                   ` (3 subsequent siblings)
  6 siblings, 0 replies; 21+ messages in thread
From: Adhemerval Zanella @ 2022-02-18 14:23 UTC (permalink / raw)
  To: libc-alpha

No semantic changes.
---
 misc/syslog.c | 441 +++++++++++++++++++++++++-------------------------
 1 file changed, 221 insertions(+), 220 deletions(-)

diff --git a/misc/syslog.c b/misc/syslog.c
index ee83b1bb76..07a6938bff 100644
--- a/misc/syslog.c
+++ b/misc/syslog.c
@@ -60,20 +60,20 @@ static char sccsid[] = "@(#)syslog.c	8.4 (Berkeley) 3/18/94";
 
 #define ftell(s) _IO_ftell (s)
 
-static int	LogType = SOCK_DGRAM;	/* type of socket connection */
-static int	LogFile = -1;		/* fd for log */
-static bool	connected;		/* have done connect */
-static int	LogStat;		/* status bits, set by openlog() */
+static int LogType = SOCK_DGRAM;	/* type of socket connection */
+static int LogFile = -1;		/* fd for log */
+static bool connected;		/* have done connect */
+static int LogStat;		/* status bits, set by openlog() */
 static const char *LogTag;		/* string to tag the entry with */
-static int	LogFacility = LOG_USER;	/* default facility code */
-static int	LogMask = 0xff;		/* mask of priorities to be logged */
-extern char	*__progname;		/* Program name, from crt0. */
+static int LogFacility = LOG_USER;	/* default facility code */
+static int LogMask = 0xff;		/* mask of priorities to be logged */
+extern char *__progname;		/* Program name, from crt0. */
 
 /* Define the lock.  */
 __libc_lock_define_initialized (static, syslog_lock)
 
-static void openlog_internal(const char *, int, int);
-static void closelog_internal(void);
+static void openlog_internal (const char *, int, int);
+static void closelog_internal (void);
 
 struct cleanup_arg
 {
@@ -101,205 +101,204 @@ cancel_handler (void *ptr)
  *	print message on log file; output is intended for syslogd(8).
  */
 void
-__syslog(int pri, const char *fmt, ...)
+__syslog (int pri, const char *fmt, ...)
 {
-	va_list ap;
+  va_list ap;
 
-	va_start(ap, fmt);
-	__vsyslog_internal(pri, fmt, ap, 0);
-	va_end(ap);
+  va_start (ap, fmt);
+  __vsyslog_internal (pri, fmt, ap, 0);
+  va_end (ap);
 }
 ldbl_hidden_def (__syslog, syslog)
 ldbl_strong_alias (__syslog, syslog)
 
 void
-__vsyslog(int pri, const char *fmt, va_list ap)
+__vsyslog (int pri, const char *fmt, va_list ap)
 {
-	__vsyslog_internal(pri, fmt, ap, 0);
+  __vsyslog_internal (pri, fmt, ap, 0);
 }
 ldbl_weak_alias (__vsyslog, vsyslog)
 
 void
-__syslog_chk(int pri, int flag, const char *fmt, ...)
+__syslog_chk (int pri, int flag, const char *fmt, ...)
 {
-	va_list ap;
+  va_list ap;
 
-	va_start(ap, fmt);
-	__vsyslog_internal(pri, fmt, ap, (flag > 0) ? PRINTF_FORTIFY : 0);
-	va_end(ap);
+  va_start (ap, fmt);
+  __vsyslog_internal (pri, fmt, ap, (flag > 0) ? PRINTF_FORTIFY : 0);
+  va_end (ap);
 }
 
 void
 __vsyslog_chk(int pri, int flag, const char *fmt, va_list ap)
 {
-	__vsyslog_internal(pri, fmt, ap, (flag > 0) ? PRINTF_FORTIFY : 0);
+  __vsyslog_internal (pri, fmt, ap, (flag > 0) ? PRINTF_FORTIFY : 0);
 }
 
 void
 __vsyslog_internal(int pri, const char *fmt, va_list ap,
 		   unsigned int mode_flags)
 {
-	struct tm now_tm;
-	time_t now;
-	int fd;
-	FILE *f;
-	char *buf = 0;
-	size_t bufsize = 0;
-	size_t msgoff;
-	int saved_errno = errno;
-	char failbuf[3 * sizeof (pid_t) + sizeof "out of memory []"];
-
-#define	INTERNALLOG	LOG_ERR|LOG_CONS|LOG_PERROR|LOG_PID
-	/* Check for invalid bits. */
-	if (pri & ~(LOG_PRIMASK|LOG_FACMASK)) {
-		syslog(INTERNALLOG,
-		    "syslog: unknown facility/priority: %x", pri);
-		pri &= LOG_PRIMASK|LOG_FACMASK;
+  struct tm now_tm;
+  time_t now;
+  int fd;
+  FILE *f;
+  char *buf = 0;
+  size_t bufsize = 0;
+  size_t msgoff;
+  int saved_errno = errno;
+  char failbuf[3 * sizeof (pid_t) + sizeof "out of memory []"];
+
+#define	INTERNALLOG LOG_ERR|LOG_CONS|LOG_PERROR|LOG_PID
+  /* Check for invalid bits. */
+  if (pri & ~(LOG_PRIMASK|LOG_FACMASK))
+    {
+      syslog (INTERNALLOG, "syslog: unknown facility/priority: %x", pri);
+      pri &= LOG_PRIMASK|LOG_FACMASK;
+    }
+
+  /* Prepare for multiple users.  We have to take care: most syscalls we are
+     using are cancellation points.  */
+  struct cleanup_arg clarg;
+  clarg.buf = NULL;
+  clarg.oldaction = NULL;
+  __libc_cleanup_push (cancel_handler, &clarg);
+  __libc_lock_lock (syslog_lock);
+
+  /* Check priority against setlogmask values. */
+  if ((LOG_MASK (LOG_PRI (pri)) & LogMask) == 0)
+    goto out;
+
+  /* Set default facility if none specified. */
+  if ((pri & LOG_FACMASK) == 0)
+    pri |= LogFacility;
+
+  /* Build the message in a memory-buffer stream.  */
+  f = __open_memstream (&buf, &bufsize);
+  if (f == NULL)
+    {
+      /* We cannot get a stream.  There is not much we can do but emitting an
+	 error messages.  */
+      char numbuf[3 * sizeof (pid_t)];
+      char *nump;
+      char *endp = __stpcpy (failbuf, "out of memory [");
+      pid_t pid = __getpid ();
+
+      nump = numbuf + sizeof (numbuf);
+      /* The PID can never be zero.  */
+      do
+	*--nump = '0' + pid % 10;
+      while ((pid /= 10) != 0);
+
+      endp = __mempcpy (endp, nump, (numbuf + sizeof (numbuf)) - nump);
+      *endp++ = ']';
+      *endp = '\0';
+      buf = failbuf;
+      bufsize = endp - failbuf;
+      msgoff = 0;
+    }
+  else
+    {
+      __fsetlocking (f, FSETLOCKING_BYCALLER);
+      fprintf (f, "<%d>", pri);
+      now = time_now ();
+      f->_IO_write_ptr += __strftime_l (f->_IO_write_ptr,
+					f->_IO_write_end - f->_IO_write_ptr,
+					"%h %e %T ",
+					__localtime_r (&now, &now_tm),
+					_nl_C_locobj_ptr);
+      msgoff = ftell (f);
+      if (LogTag == NULL)
+	LogTag = __progname;
+      if (LogTag != NULL)
+	__fputs_unlocked (LogTag, f);
+      if (LogStat & LOG_PID)
+	fprintf (f, "[%d]", (int) __getpid ());
+      if (LogTag != NULL)
+	{
+	  __putc_unlocked (':', f);
+	  __putc_unlocked (' ', f);
+	}
+
+      /* Restore errno for %m format.  */
+      __set_errno (saved_errno);
+
+      /* We have the header.  Print the user's format into the buffer.  */
+      __vfprintf_internal (f, fmt, ap, mode_flags);
+
+      /* Close the memory stream; this will finalize the data into a malloc'd
+	 buffer in BUF.  */
+      fclose (f);
+
+      /* Tell the cancellation handler to free this buffer.  */
+      clarg.buf = buf;
+    }
+
+  /* Output to stderr if requested. */
+  if (LogStat & LOG_PERROR)
+    {
+      struct iovec iov[2];
+      struct iovec *v = iov;
+
+      v->iov_base = buf + msgoff;
+      v->iov_len = bufsize - msgoff;
+      /* Append a newline if necessary.  */
+      if (buf[bufsize - 1] != '\n')
+	{
+	  ++v;
+	  v->iov_base = (char *) "\n";
+	  v->iov_len = 1;
 	}
 
-	/* Prepare for multiple users.  We have to take care: most
-	   syscalls we are using are cancellation points.  */
-	struct cleanup_arg clarg;
-	clarg.buf = NULL;
-	clarg.oldaction = NULL;
-	__libc_cleanup_push (cancel_handler, &clarg);
-	__libc_lock_lock (syslog_lock);
-
-	/* Check priority against setlogmask values. */
-	if ((LOG_MASK (LOG_PRI (pri)) & LogMask) == 0)
-		goto out;
-
-	/* Set default facility if none specified. */
-	if ((pri & LOG_FACMASK) == 0)
-		pri |= LogFacility;
-
-	/* Build the message in a memory-buffer stream.  */
-	f = __open_memstream (&buf, &bufsize);
-	if (f == NULL)
-	  {
-	    /* We cannot get a stream.  There is not much we can do but
-	       emitting an error messages.  */
-	    char numbuf[3 * sizeof (pid_t)];
-	    char *nump;
-	    char *endp = __stpcpy (failbuf, "out of memory [");
-	    pid_t pid = __getpid ();
-
-	    nump = numbuf + sizeof (numbuf);
-	    /* The PID can never be zero.  */
-	    do
-	      *--nump = '0' + pid % 10;
-	    while ((pid /= 10) != 0);
-
-	    endp = __mempcpy (endp, nump, (numbuf + sizeof (numbuf)) - nump);
-	    *endp++ = ']';
-	    *endp = '\0';
-	    buf = failbuf;
-	    bufsize = endp - failbuf;
-	    msgoff = 0;
-	  }
-	else
-	  {
-	    __fsetlocking (f, FSETLOCKING_BYCALLER);
-	    fprintf (f, "<%d>", pri);
-	    now = time_now ();
-	    f->_IO_write_ptr += __strftime_l (f->_IO_write_ptr,
-					      f->_IO_write_end
-					      - f->_IO_write_ptr,
-					      "%h %e %T ",
-					      __localtime_r (&now, &now_tm),
-					      _nl_C_locobj_ptr);
-	    msgoff = ftell (f);
-	    if (LogTag == NULL)
-	      LogTag = __progname;
-	    if (LogTag != NULL)
-	      __fputs_unlocked (LogTag, f);
-	    if (LogStat & LOG_PID)
-	      fprintf (f, "[%d]", (int) __getpid ());
-	    if (LogTag != NULL)
-	      {
-		__putc_unlocked (':', f);
-		__putc_unlocked (' ', f);
-	      }
-
-	    /* Restore errno for %m format.  */
-	    __set_errno (saved_errno);
-
-	    /* We have the header.  Print the user's format into the
-	       buffer.  */
-	    __vfprintf_internal (f, fmt, ap, mode_flags);
-
-	    /* Close the memory stream; this will finalize the data
-	       into a malloc'd buffer in BUF.  */
-	    fclose (f);
-
-	    /* Tell the cancellation handler to free this buffer.  */
-	    clarg.buf = buf;
-	  }
-
-	/* Output to stderr if requested. */
-	if (LogStat & LOG_PERROR) {
-		struct iovec iov[2];
-		struct iovec *v = iov;
-
-		v->iov_base = buf + msgoff;
-		v->iov_len = bufsize - msgoff;
-		/* Append a newline if necessary.  */
-		if (buf[bufsize - 1] != '\n')
-		  {
-		    ++v;
-		    v->iov_base = (char *) "\n";
-		    v->iov_len = 1;
-		  }
-
-		/* writev is a cancellation point.  */
-		(void)__writev(STDERR_FILENO, iov, v - iov + 1);
+      /* writev is a cancellation point.  */
+      __writev (STDERR_FILENO, iov, v - iov + 1);
+    }
+
+  /* Get connected, output the message to the local logger.  */
+  if (!connected)
+    openlog_internal (NULL, LogStat | LOG_NDELAY, LogFacility);
+
+  /* If we have a SOCK_STREAM connection, also send ASCII NUL as a record
+     terminator.  */
+  if (LogType == SOCK_STREAM)
+    ++bufsize;
+
+  if (!connected || __send(LogFile, buf, bufsize, MSG_NOSIGNAL) < 0)
+    {
+      if (connected)
+	{
+	  /* Try to reopen the syslog connection.  Maybe it went down.  */
+	  closelog_internal ();
+	  openlog_internal (NULL, LogStat | LOG_NDELAY, LogFacility);
 	}
 
-	/* Get connected, output the message to the local logger. */
-	if (!connected)
-		openlog_internal(NULL, LogStat | LOG_NDELAY, LogFacility);
-
-	/* If we have a SOCK_STREAM connection, also send ASCII NUL as
-	   a record terminator.  */
-	if (LogType == SOCK_STREAM)
-	  ++bufsize;
-
-	if (!connected || __send(LogFile, buf, bufsize, MSG_NOSIGNAL) < 0)
-	  {
-	    if (connected)
-	      {
-		/* Try to reopen the syslog connection.  Maybe it went
-		   down.  */
-		closelog_internal ();
-		openlog_internal(NULL, LogStat | LOG_NDELAY, LogFacility);
-	      }
-
-	    if (!connected || __send(LogFile, buf, bufsize, MSG_NOSIGNAL) < 0)
-	      {
-		closelog_internal ();	/* attempt re-open next time */
-		/*
-		 * Output the message to the console; don't worry
-		 * about blocking, if console blocks everything will.
-		 * Make sure the error reported is the one from the
-		 * syslogd failure.
-		 */
-		if (LogStat & LOG_CONS &&
-		    (fd = __open(_PATH_CONSOLE, O_WRONLY|O_NOCTTY|O_CLOEXEC,
-				 0)) >= 0)
-		  {
-		    __dprintf (fd, "%s\r\n", buf + msgoff);
-		    (void)__close(fd);
-		  }
-	      }
-	  }
+      if (!connected || __send(LogFile, buf, bufsize, MSG_NOSIGNAL) < 0)
+	{
+	  closelog_internal ();	/* attempt re-open next time */
+	  /*
+	   * Output the message to the console; don't worry
+	   * about blocking, if console blocks everything will.
+	   * Make sure the error reported is the one from the
+	   * syslogd failure.
+	   */
+	  if (LogStat & LOG_CONS &&
+	      (fd = __open (_PATH_CONSOLE, O_WRONLY | O_NOCTTY
+			    | O_CLOEXEC, 0))
+	      >= 0)
+	    {
+	      __dprintf (fd, "%s\r\n", buf + msgoff);
+	      __close(fd);
+	    }
+	}
+    }
 
  out:
-	/* End of critical section.  */
-	__libc_cleanup_pop (0);
-	__libc_lock_unlock (syslog_lock);
+  /* End of critical section.  */
+  __libc_cleanup_pop (0);
+  __libc_lock_unlock (syslog_lock);
 
-	if (buf != failbuf)
-		free (buf);
+  if (buf != failbuf)
+    free (buf);
 }
 
 /* AF_UNIX address of local logger  */
@@ -312,45 +311,47 @@ static const struct sockaddr_un SyslogAddr =
 static void
 openlog_internal(const char *ident, int logstat, int logfac)
 {
-	if (ident != NULL)
-		LogTag = ident;
-	LogStat = logstat;
-	if ((logfac &~ LOG_FACMASK) == 0)
-		LogFacility = logfac;
-
-	int retry = 0;
-	while (retry < 2) {
-		if (LogFile == -1) {
-			if (LogStat & LOG_NDELAY) {
-			  LogFile = __socket(AF_UNIX, LogType | SOCK_CLOEXEC, 0);
-			  if (LogFile == -1)
-			    return;
-			}
-		}
-		if (LogFile != -1 && !connected)
+  if (ident != NULL)
+    LogTag = ident;
+  LogStat = logstat;
+  if ((logfac &~ LOG_FACMASK) == 0)
+    LogFacility = logfac;
+
+  int retry = 0;
+  while (retry < 2)
+    {
+      if (LogFile == -1)
+	{
+	  if (LogStat & LOG_NDELAY)
+	    {
+	      LogFile = __socket (AF_UNIX, LogType | SOCK_CLOEXEC, 0);
+	      if (LogFile == -1)
+		return;
+	    }
+	}
+      if (LogFile != -1 && !connected)
+	{
+	  int old_errno = errno;
+	  if (__connect (LogFile, &SyslogAddr, sizeof(SyslogAddr)) == -1)
+	    {
+	      int saved_errno = errno;
+	      int fd = LogFile;
+	      LogFile = -1;
+	      __close(fd);
+	      __set_errno (old_errno);
+	      if (saved_errno == EPROTOTYPE)
 		{
-			int old_errno = errno;
-			if (__connect(LogFile, &SyslogAddr, sizeof(SyslogAddr))
-			    == -1)
-			{
-				int saved_errno = errno;
-				int fd = LogFile;
-				LogFile = -1;
-				(void)__close(fd);
-				__set_errno (old_errno);
-				if (saved_errno == EPROTOTYPE)
-				{
-					/* retry with the other type: */
-					LogType = (LogType == SOCK_DGRAM
-						   ? SOCK_STREAM : SOCK_DGRAM);
-					++retry;
-					continue;
-				}
-			} else
-				connected = true;
+		  /* retry with the other type: */
+		  LogType = LogType == SOCK_DGRAM ? SOCK_STREAM : SOCK_DGRAM;
+		  ++retry;
+		  continue;
 		}
-		break;
+	    }
+	  else
+	    connected = true;
 	}
+      break;
+    }
 }
 
 void
@@ -395,16 +396,16 @@ closelog (void)
 int
 setlogmask (int pmask)
 {
-	int omask;
+  int omask;
 
-	/* Protect against multiple users.  */
-	__libc_lock_lock (syslog_lock);
+  /* Protect against multiple users.  */
+  __libc_lock_lock (syslog_lock);
 
-	omask = LogMask;
-	if (pmask != 0)
-		LogMask = pmask;
+  omask = LogMask;
+  if (pmask != 0)
+    LogMask = pmask;
 
-	__libc_lock_unlock (syslog_lock);
+  __libc_lock_unlock (syslog_lock);
 
-	return (omask);
+  return (omask);
 }
-- 
2.32.0


^ permalink raw reply	[flat|nested] 21+ messages in thread

* [PATCH v2 4/7] misc: syslog: Simplify implementation
  2022-02-18 14:23 [PATCH v2 0/7] Use RFC5424 for syslog Adhemerval Zanella
                   ` (2 preceding siblings ...)
  2022-02-18 14:23 ` [PATCH v2 3/7] misc: syslog: Fix indentation and style Adhemerval Zanella
@ 2022-02-18 14:23 ` Adhemerval Zanella
  2022-02-19  3:15   ` Paul Eggert
  2022-02-18 14:23 ` [PATCH v2 5/7] misc: syslog: Use static buffer Adhemerval Zanella
                   ` (2 subsequent siblings)
  6 siblings, 1 reply; 21+ messages in thread
From: Adhemerval Zanella @ 2022-02-18 14:23 UTC (permalink / raw)
  To: libc-alpha

Remove unrequired includes, use a temporary buffer for strftime instead
of using internal libio members, simplify fprintf call on the memstream
and memory allocation, use dprintf instead of writev for LOG_PERROR.

Checked on x86_64-linux-gnu.
---
 misc/syslog.c | 126 ++++++++++++++------------------------------------
 1 file changed, 35 insertions(+), 91 deletions(-)

diff --git a/misc/syslog.c b/misc/syslog.c
index 07a6938bff..e46cf1103b 100644
--- a/misc/syslog.c
+++ b/misc/syslog.c
@@ -31,34 +31,16 @@
 static char sccsid[] = "@(#)syslog.c	8.4 (Berkeley) 3/18/94";
 #endif /* LIBC_SCCS and not lint */
 
-#include <sys/types.h>
+#include <libc-lock.h>
+#include <libio/libioP.h>
+#include <math_ldbl_opt.h>
+#include <paths.h>
+#include <stdarg.h>
 #include <sys/socket.h>
-#include <sys/syslog.h>
+#include <syslog.h>
 #include <sys/uio.h>
 #include <sys/un.h>
-#include <netdb.h>
-
-#include <errno.h>
-#include <fcntl.h>
-#include <paths.h>
-#include <stdio.h>
 #include <stdio_ext.h>
-#include <string.h>
-#include <time.h>
-#include <unistd.h>
-#include <stdlib.h>
-#include <libc-lock.h>
-#include <signal.h>
-#include <locale.h>
-
-#include <stdarg.h>
-
-#include <libio/libioP.h>
-#include <math_ldbl_opt.h>
-
-#include <kernel-features.h>
-
-#define ftell(s) _IO_ftell (s)
 
 static int LogType = SOCK_DGRAM;	/* type of socket connection */
 static int LogFile = -1;		/* fd for log */
@@ -139,13 +121,10 @@ void
 __vsyslog_internal(int pri, const char *fmt, va_list ap,
 		   unsigned int mode_flags)
 {
-  struct tm now_tm;
-  time_t now;
-  int fd;
   FILE *f;
   char *buf = 0;
   size_t bufsize = 0;
-  size_t msgoff;
+  int msgoff;
   int saved_errno = errno;
   char failbuf[3 * sizeof (pid_t) + sizeof "out of memory []"];
 
@@ -159,9 +138,7 @@ __vsyslog_internal(int pri, const char *fmt, va_list ap,
 
   /* Prepare for multiple users.  We have to take care: most syscalls we are
      using are cancellation points.  */
-  struct cleanup_arg clarg;
-  clarg.buf = NULL;
-  clarg.oldaction = NULL;
+  struct cleanup_arg clarg = { NULL, NULL };
   __libc_cleanup_push (cancel_handler, &clarg);
   __libc_lock_lock (syslog_lock);
 
@@ -175,51 +152,24 @@ __vsyslog_internal(int pri, const char *fmt, va_list ap,
 
   /* Build the message in a memory-buffer stream.  */
   f = __open_memstream (&buf, &bufsize);
-  if (f == NULL)
-    {
-      /* We cannot get a stream.  There is not much we can do but emitting an
-	 error messages.  */
-      char numbuf[3 * sizeof (pid_t)];
-      char *nump;
-      char *endp = __stpcpy (failbuf, "out of memory [");
-      pid_t pid = __getpid ();
-
-      nump = numbuf + sizeof (numbuf);
-      /* The PID can never be zero.  */
-      do
-	*--nump = '0' + pid % 10;
-      while ((pid /= 10) != 0);
-
-      endp = __mempcpy (endp, nump, (numbuf + sizeof (numbuf)) - nump);
-      *endp++ = ']';
-      *endp = '\0';
-      buf = failbuf;
-      bufsize = endp - failbuf;
-      msgoff = 0;
-    }
-  else
+  if (f != NULL)
     {
       __fsetlocking (f, FSETLOCKING_BYCALLER);
-      fprintf (f, "<%d>", pri);
-      now = time_now ();
-      f->_IO_write_ptr += __strftime_l (f->_IO_write_ptr,
-					f->_IO_write_end - f->_IO_write_ptr,
-					"%h %e %T ",
-					__localtime_r (&now, &now_tm),
-					_nl_C_locobj_ptr);
-      msgoff = ftell (f);
-      if (LogTag == NULL)
-	LogTag = __progname;
-      if (LogTag != NULL)
-	__fputs_unlocked (LogTag, f);
-      if (LogStat & LOG_PID)
-	fprintf (f, "[%d]", (int) __getpid ());
-      if (LogTag != NULL)
-	{
-	  __putc_unlocked (':', f);
-	  __putc_unlocked (' ', f);
-	}
-
+      /* "%h %e %H:%M:%S "  */
+      char timebuf[3+1                   /* "%h "  */
+                   + 2+1                 /* "%e "  */
+                   + 2+1 + 2+1 + 2+1 + 1 /* "%T "  */];
+      time_t now = time_now ();
+      struct tm now_tm;
+      __localtime_r (&now, &now_tm);
+      __strftime_l (timebuf, sizeof (timebuf), "%h %e %T ", &now_tm,
+		    _nl_C_locobj_ptr);
+
+      pid_t pid = LogStat & LOG_PID ? __getpid () : 0;
+
+      fprintf (f, "<%d>%s %n%s%s%.0d%s: ", pri, timebuf, &msgoff,
+               LogTag == NULL ? __progname : LogTag,
+               pid != 0 ? "[" : "", pid, pid != 0 ? "]" : "");
       /* Restore errno for %m format.  */
       __set_errno (saved_errno);
 
@@ -233,26 +183,19 @@ __vsyslog_internal(int pri, const char *fmt, va_list ap,
       /* Tell the cancellation handler to free this buffer.  */
       clarg.buf = buf;
     }
+  else
+    {
+      /* We cannot get a stream.  There is not much we can do but emitting an
+         error messages.  */
+      bufsize = __snprintf (failbuf, sizeof failbuf, "out of memory[%d]",
+                            __getpid ());
+      buf = failbuf;
+    }
 
   /* Output to stderr if requested. */
   if (LogStat & LOG_PERROR)
-    {
-      struct iovec iov[2];
-      struct iovec *v = iov;
-
-      v->iov_base = buf + msgoff;
-      v->iov_len = bufsize - msgoff;
-      /* Append a newline if necessary.  */
-      if (buf[bufsize - 1] != '\n')
-	{
-	  ++v;
-	  v->iov_base = (char *) "\n";
-	  v->iov_len = 1;
-	}
-
-      /* writev is a cancellation point.  */
-      __writev (STDERR_FILENO, iov, v - iov + 1);
-    }
+    __dprintf (STDERR_FILENO, "%s%s", buf + msgoff,
+               buf[bufsize - 1] != '\n' ? "\n" : "");
 
   /* Get connected, output the message to the local logger.  */
   if (!connected)
@@ -281,6 +224,7 @@ __vsyslog_internal(int pri, const char *fmt, va_list ap,
 	   * Make sure the error reported is the one from the
 	   * syslogd failure.
 	   */
+	  int fd;
 	  if (LogStat & LOG_CONS &&
 	      (fd = __open (_PATH_CONSOLE, O_WRONLY | O_NOCTTY
 			    | O_CLOEXEC, 0))
-- 
2.32.0


^ permalink raw reply	[flat|nested] 21+ messages in thread

* [PATCH v2 5/7] misc: syslog: Use static buffer
  2022-02-18 14:23 [PATCH v2 0/7] Use RFC5424 for syslog Adhemerval Zanella
                   ` (3 preceding siblings ...)
  2022-02-18 14:23 ` [PATCH v2 4/7] misc: syslog: Simplify implementation Adhemerval Zanella
@ 2022-02-18 14:23 ` Adhemerval Zanella
  2022-02-19  3:45   ` Paul Eggert
  2022-02-18 14:23 ` [PATCH v2 6/7] misc: syslog: Move SYSLOG_NAME to USE_MISC (BZ #16355) Adhemerval Zanella
  2022-02-18 14:23 ` [PATCH v2 7/7] misc: syslog: Use RFC5424 Adhemerval Zanella
  6 siblings, 1 reply; 21+ messages in thread
From: Adhemerval Zanella @ 2022-02-18 14:23 UTC (permalink / raw)
  To: libc-alpha

The static buffer is used instead of memstream for messages up to
1024 bytes to avoid the potential BUFSIZ (8K) malloc and free for
each syslog call.  The memstream is still used as fallback for
larger messages.

Checked on x86_64-linux-gnu.
---
 misc/syslog.c | 105 ++++++++++++++++++++++++++++++++------------------
 1 file changed, 68 insertions(+), 37 deletions(-)

diff --git a/misc/syslog.c b/misc/syslog.c
index e46cf1103b..088e3b5664 100644
--- a/misc/syslog.c
+++ b/misc/syslog.c
@@ -121,12 +121,11 @@ void
 __vsyslog_internal(int pri, const char *fmt, va_list ap,
 		   unsigned int mode_flags)
 {
-  FILE *f;
-  char *buf = 0;
+  char *buf = NULL;
   size_t bufsize = 0;
+  bool buf_malloced = false;
   int msgoff;
   int saved_errno = errno;
-  char failbuf[3 * sizeof (pid_t) + sizeof "out of memory []"];
 
 #define	INTERNALLOG LOG_ERR|LOG_CONS|LOG_PERROR|LOG_PID
   /* Check for invalid bits. */
@@ -150,46 +149,78 @@ __vsyslog_internal(int pri, const char *fmt, va_list ap,
   if ((pri & LOG_FACMASK) == 0)
     pri |= LogFacility;
 
-  /* Build the message in a memory-buffer stream.  */
-  f = __open_memstream (&buf, &bufsize);
-  if (f != NULL)
+  pid_t pid = LogStat & LOG_PID ? __getpid () : 0;
+
+  enum
+    {
+      timebuf_size = 3+1                     /* "%h "  */
+                     + 2+1                   /* "%e "  */
+                     + 2+1 + 2+1 + 2+1 + 1,  /* "%T "  */
+
+      bufs_size    = 1024
+    };
+
+  /* "%h %e %H:%M:%S "  */
+  char timestamp[timebuf_size];
+  time_t now = time_now ();
+  struct tm now_tm;
+  __localtime_r (&now, &now_tm);
+  __strftime_l (timestamp, sizeof (timestamp), "%h %e %T ", &now_tm,
+                _nl_C_locobj_ptr);
+
+#define SYSLOG_HEADER(__pri, __timestamp, __msgoff, pid) \
+  "<%d>%s %n%s%s%.0d%s: ",                               \
+  __pri, __timestamp, __msgoff,                          \
+  LogTag == NULL ? __progname : LogTag,                  \
+  pid != 0 ? "[" : "", pid, pid != 0 ? "]" : ""
+
+  /* Try to use a static buffer as an optimization.  */
+  char bufs[bufs_size];
+  int l = __snprintf (bufs, sizeof bufs,
+                      SYSLOG_HEADER (pri, timestamp, &msgoff, pid));
+  if (l < sizeof (bufs))
     {
-      __fsetlocking (f, FSETLOCKING_BYCALLER);
-      /* "%h %e %H:%M:%S "  */
-      char timebuf[3+1                   /* "%h "  */
-                   + 2+1                 /* "%e "  */
-                   + 2+1 + 2+1 + 2+1 + 1 /* "%T "  */];
-      time_t now = time_now ();
-      struct tm now_tm;
-      __localtime_r (&now, &now_tm);
-      __strftime_l (timebuf, sizeof (timebuf), "%h %e %T ", &now_tm,
-		    _nl_C_locobj_ptr);
-
-      pid_t pid = LogStat & LOG_PID ? __getpid () : 0;
-
-      fprintf (f, "<%d>%s %n%s%s%.0d%s: ", pri, timebuf, &msgoff,
-               LogTag == NULL ? __progname : LogTag,
-               pid != 0 ? "[" : "", pid, pid != 0 ? "]" : "");
+      va_list apc;
+      va_copy (apc, ap);
+
       /* Restore errno for %m format.  */
       __set_errno (saved_errno);
 
-      /* We have the header.  Print the user's format into the buffer.  */
-      __vfprintf_internal (f, fmt, ap, mode_flags);
+      int vl = __vsnprintf_internal (bufs + l, sizeof (bufs) - l, fmt, apc,
+                                     mode_flags);
+      if (l + vl < sizeof (bufs))
+        {
+          buf = bufs;
+          bufsize = l + vl;
+        }
 
-      /* Close the memory stream; this will finalize the data into a malloc'd
-	 buffer in BUF.  */
-      fclose (f);
-
-      /* Tell the cancellation handler to free this buffer.  */
-      clarg.buf = buf;
+      va_end (apc);
     }
-  else
+
+  /* If the required size is larger than buffer size fallbacks to
+     open_memstream.  */
+  if (buf == NULL)
     {
-      /* We cannot get a stream.  There is not much we can do but emitting an
-         error messages.  */
-      bufsize = __snprintf (failbuf, sizeof failbuf, "out of memory[%d]",
-                            __getpid ());
-      buf = failbuf;
+      FILE *f = __open_memstream (&buf, &bufsize);
+      if (f != NULL)
+        {
+          __fsetlocking (f, FSETLOCKING_BYCALLER);
+          fprintf (f, SYSLOG_HEADER (pri, timestamp, &msgoff, pid));
+          /* Restore errno for %m format.  */
+          __set_errno (saved_errno);
+          __vfprintf_internal (f, fmt, ap, mode_flags);
+          fclose (f);
+
+          /* Tell the cancellation handler to free this buffer.  */
+          buf_malloced = true;
+          clarg.buf = buf;
+        }
+      else
+        {
+          bufsize = __snprintf (bufs, sizeof bufs,
+                                "out of memory[%d]", __getpid ());
+          buf = bufs;
+        }
     }
 
   /* Output to stderr if requested. */
@@ -241,7 +272,7 @@ __vsyslog_internal(int pri, const char *fmt, va_list ap,
   __libc_cleanup_pop (0);
   __libc_lock_unlock (syslog_lock);
 
-  if (buf != failbuf)
+  if (buf_malloced)
     free (buf);
 }
 
-- 
2.32.0


^ permalink raw reply	[flat|nested] 21+ messages in thread

* [PATCH v2 6/7] misc: syslog: Move SYSLOG_NAME to USE_MISC (BZ #16355)
  2022-02-18 14:23 [PATCH v2 0/7] Use RFC5424 for syslog Adhemerval Zanella
                   ` (4 preceding siblings ...)
  2022-02-18 14:23 ` [PATCH v2 5/7] misc: syslog: Use static buffer Adhemerval Zanella
@ 2022-02-18 14:23 ` Adhemerval Zanella
  2022-02-18 14:23 ` [PATCH v2 7/7] misc: syslog: Use RFC5424 Adhemerval Zanella
  6 siblings, 0 replies; 21+ messages in thread
From: Adhemerval Zanella @ 2022-02-18 14:23 UTC (permalink / raw)
  To: libc-alpha

There is no easy solution as described on first comment in bug report,
and some code (like busybox) assumes facilitynames existance when
SYSLOG_NAMES is defined (so we can't just remove it as suggested in
comment #2).

So use the easier solution and guard it with __USE_MISC.
---
 misc/sys/syslog.h | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/misc/sys/syslog.h b/misc/sys/syslog.h
index dc3b0e7ef8..bf368d1b8d 100644
--- a/misc/sys/syslog.h
+++ b/misc/sys/syslog.h
@@ -62,7 +62,7 @@
 #define	LOG_PRI(p)	((p) & LOG_PRIMASK)
 #define	LOG_MAKEPRI(fac, pri)	((fac) | (pri))
 
-#ifdef SYSLOG_NAMES
+#if defined(SYSLOG_NAMES) && defined(__USE_MISC)
 #define	INTERNAL_NOPRI	0x10	/* the "no priority" priority */
 				/* mark "facility" */
 #define	INTERNAL_MARK	LOG_MAKEPRI(LOG_NFACILITIES << 3, 0)
@@ -118,7 +118,7 @@ CODE prioritynames[] =
 				/* facility of pri */
 #define	LOG_FAC(p)	(((p) & LOG_FACMASK) >> 3)
 
-#ifdef SYSLOG_NAMES
+#if defined(SYSLOG_NAMES) && defined(__USE_MISC)
 CODE facilitynames[] =
   {
     { "auth", LOG_AUTH },
-- 
2.32.0


^ permalink raw reply	[flat|nested] 21+ messages in thread

* [PATCH v2 7/7] misc: syslog: Use RFC5424
  2022-02-18 14:23 [PATCH v2 0/7] Use RFC5424 for syslog Adhemerval Zanella
                   ` (5 preceding siblings ...)
  2022-02-18 14:23 ` [PATCH v2 6/7] misc: syslog: Move SYSLOG_NAME to USE_MISC (BZ #16355) Adhemerval Zanella
@ 2022-02-18 14:23 ` Adhemerval Zanella
  2022-02-19  3:50   ` Paul Eggert
  2022-02-19 20:35   ` Dan Raymond
  6 siblings, 2 replies; 21+ messages in thread
From: Adhemerval Zanella @ 2022-02-18 14:23 UTC (permalink / raw)
  To: libc-alpha

Current syslog format provides limited timestamp information (not full
year information nor microsecond precision) and the timezone information
might incur in confusion [1] since there is no metadata information on
how it was generated.

So instead of using another ad-hoc syslog format, this patch adapts it
to follow RFC5424:

  - VERSION is set as 1.
  - TIMESTAMP is logged as described by RFC 3339 using UTC ('Z') with
    maximum allowed TIME-SECFRAC precision (microseconds).
  - HOSTNAME is obtained with gethostname (as allowed by the RFC).
  - PROCID is only set if LOG_PID is previously set by openlog.
  - MSGID and STRUCTURED-DATA are both set to NILVALUE.

Checked on x86_64-linux-gnu.

[1] https://sourceware.org/pipermail/libc-alpha/2021-March/123583.html
---
 misc/syslog.c     | 79 +++++++++++++++++++++++++++++++++--------------
 misc/tst-syslog.c | 28 ++++++++---------
 2 files changed, 69 insertions(+), 38 deletions(-)

diff --git a/misc/syslog.c b/misc/syslog.c
index 088e3b5664..f15a536dd7 100644
--- a/misc/syslog.c
+++ b/misc/syslog.c
@@ -31,6 +31,7 @@
 static char sccsid[] = "@(#)syslog.c	8.4 (Berkeley) 3/18/94";
 #endif /* LIBC_SCCS and not lint */
 
+#include <intprops.h>
 #include <libc-lock.h>
 #include <libio/libioP.h>
 #include <math_ldbl_opt.h>
@@ -42,6 +43,10 @@ static char sccsid[] = "@(#)syslog.c	8.4 (Berkeley) 3/18/94";
 #include <sys/un.h>
 #include <stdio_ext.h>
 
+#ifndef HOST_NAME_MAX
+# define HOST_NAME_MAX 64
+#endif
+
 static int LogType = SOCK_DGRAM;	/* type of socket connection */
 static int LogFile = -1;		/* fd for log */
 static bool connected;		/* have done connect */
@@ -117,6 +122,39 @@ __vsyslog_chk(int pri, int flag, const char *fmt, va_list ap)
   __vsyslog_internal (pri, fmt, ap, (flag > 0) ? PRINTF_FORTIFY : 0);
 }
 
+/* Defined by RFC5424.  */
+#define NILVALUE "-"
+
+struct timebuf
+{
+  /* Leave room for outlandish but possible years.
+     The "+ 1" is for strftime's adding 1900 to tm_year.  */
+  char b[INT_STRLEN_BOUND (int) + 1
+	 + sizeof "-MM-DDThh:mm:ss.nnnnnnZ"];
+};
+
+
+/* Fill TIMEBUF with a RFC3339 timestamp.  Use UTC time and maximum
+   TIME-SECFRAC accurancy allowed (6 digits for microseconds).  */
+static void
+syslog_rfc3339_timestamp (struct timebuf *timebuf)
+{
+  struct __timespec64 ts;
+  __clock_gettime64 (TIME_CLOCK_GETTIME_CLOCKID, &ts);
+  struct tm now_tm;
+  struct tm *gmtm = __gmtime64_r (&ts.tv_sec, &now_tm);
+  if (gmtm == NULL)
+    strcpy (timebuf->b, NILVALUE);
+  else
+    {
+      size_t datebytes = __strftime_l (timebuf->b, sizeof timebuf->b,
+				       "%FT%T", gmtm, _nl_C_locobj_ptr);
+      int usec = ts.tv_nsec / 1000;
+      __snprintf (timebuf->b + datebytes, sizeof timebuf->b - datebytes,
+		  ".%06dZ", usec);
+    }
+}
+
 void
 __vsyslog_internal(int pri, const char *fmt, va_list ap,
 		   unsigned int mode_flags)
@@ -149,35 +187,30 @@ __vsyslog_internal(int pri, const char *fmt, va_list ap,
   if ((pri & LOG_FACMASK) == 0)
     pri |= LogFacility;
 
-  pid_t pid = LogStat & LOG_PID ? __getpid () : 0;
+  struct timebuf timestamp;
+  syslog_rfc3339_timestamp (&timestamp);
 
-  enum
-    {
-      timebuf_size = 3+1                     /* "%h "  */
-                     + 2+1                   /* "%e "  */
-                     + 2+1 + 2+1 + 2+1 + 1,  /* "%T "  */
-
-      bufs_size    = 1024
-    };
+  char hostname[HOST_NAME_MAX];
+  if (__gethostname (hostname, sizeof (hostname)) == -1)
+    strcpy (hostname, NILVALUE);
 
-  /* "%h %e %H:%M:%S "  */
-  char timestamp[timebuf_size];
-  time_t now = time_now ();
-  struct tm now_tm;
-  __localtime_r (&now, &now_tm);
-  __strftime_l (timestamp, sizeof (timestamp), "%h %e %T ", &now_tm,
-                _nl_C_locobj_ptr);
+  pid_t pid = LogStat & LOG_PID ? __getpid () : 0;
 
-#define SYSLOG_HEADER(__pri, __timestamp, __msgoff, pid) \
-  "<%d>%s %n%s%s%.0d%s: ",                               \
-  __pri, __timestamp, __msgoff,                          \
-  LogTag == NULL ? __progname : LogTag,                  \
-  pid != 0 ? "[" : "", pid, pid != 0 ? "]" : ""
+#define SYSLOG_HEADER(__pri, __timestamp, __msgoff, __hostname, __pid) \
+  "<%d>1 %s %n%s %s %s%.0d %s %s ",                      \
+  __pri,                                /* PRI  */       \
+  __timestamp.b,                        /* TIMESTAMP  */ \
+  __msgoff, __hostname,                 /* HOSTNAME  */  \
+  LogTag == NULL ? __progname : LogTag, /* APP-NAME  */  \
+  NILVALUE + !!__pid, __pid,            /* PROCID  */    \
+  NILVALUE,                             /* MSGID  */     \
+  NILVALUE                              /* STRUCT-DATA */
 
   /* Try to use a static buffer as an optimization.  */
+  enum { bufs_size  = 1024 };
   char bufs[bufs_size];
   int l = __snprintf (bufs, sizeof bufs,
-                      SYSLOG_HEADER (pri, timestamp, &msgoff, pid));
+                      SYSLOG_HEADER (pri, timestamp, &msgoff, hostname, pid));
   if (l < sizeof (bufs))
     {
       va_list apc;
@@ -205,7 +238,7 @@ __vsyslog_internal(int pri, const char *fmt, va_list ap,
       if (f != NULL)
         {
           __fsetlocking (f, FSETLOCKING_BYCALLER);
-          fprintf (f, SYSLOG_HEADER (pri, timestamp, &msgoff, pid));
+          fprintf (f, SYSLOG_HEADER (pri, timestamp, &msgoff, hostname, pid));
           /* Restore errno for %m format.  */
           __set_errno (saved_errno);
           __vfprintf_internal (f, fmt, ap, mode_flags);
diff --git a/misc/tst-syslog.c b/misc/tst-syslog.c
index 8505178616..7b78b0c619 100644
--- a/misc/tst-syslog.c
+++ b/misc/tst-syslog.c
@@ -18,6 +18,7 @@
 
 #include <array_length.h>
 #include <fcntl.h>
+#include <intprops.h>
 #include <paths.h>
 #include <netinet/in.h>
 #include <support/capture_subprocess.h>
@@ -201,7 +202,7 @@ check_openlog_message (const struct msg_t *msg, int msgnum,
     {
       if (options & LOG_PID)
         TEST_COMPARE (msg->pid, pid);
-      TEST_COMPARE_STRING (msg->ident, expected_ident);
+      TEST_COMPARE_STRING (msg->ident, OPENLOG_IDENT);
       TEST_COMPARE (msg->facility, LOG_LOCAL0);
     }
   else if (msgnum < 2 * array_length (priorities))
@@ -212,28 +213,25 @@ check_openlog_message (const struct msg_t *msg, int msgnum,
   return true;
 }
 
+#define NILVALUE "-"
+
 static struct msg_t
 parse_syslog_msg (const char *msg)
 {
   struct msg_t r = { .pid = -1 };
   int number;
+  char procid[INT_BUFSIZE_BOUND (pid_t)];
 
   /* 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",
-                  &number, r.ident, r.msg);
-  TEST_COMPARE (n, 3);
+  int n = sscanf (msg, "<%6d>1 %*s %*s %32s %s - - %s",
+                  &number, r.ident, procid, r.msg);
+  TEST_COMPARE (n, 4);
 
   r.facility = number & LOG_FACMASK;
   r.priority = number & LOG_PRIMASK;
 
-  char *pid_start = strchr (r.ident, '[');
-  if (pid_start != NULL)
-    {
-       char *pid_end = strchr (r.ident, ']');
-       if (pid_end != NULL)
-         r.pid = strtoul (pid_start + 1, NULL, 10);
-    }
+  r.pid = strcmp (procid, NILVALUE) == 0 ? 0 : strtoul (procid, NULL, 10);
 
   return r;
 }
@@ -246,9 +244,9 @@ parse_syslog_console (const char *msg)
   struct msg_t r;
 
   /* The message in the form:
-     openlog_ident: syslog_message 128 0  */
-  int n = sscanf (msg, "%32s %64s %d %d",
-      r.ident, r.msg, &facility, &priority);
+     mymachine openlog_ident PID - syslog_message 128 0  */
+  int n = sscanf (msg, "%*s %32s %*s - - %s %d %d",
+		  r.ident, r.msg, &facility, &priority);
   TEST_COMPARE (n, 4);
 
   r.facility = facility;
@@ -384,7 +382,7 @@ check_syslog_console_read (FILE *fp)
   while (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.ident, OPENLOG_IDENT);
       TEST_COMPARE (msg.priority, priorities[msgnum]);
       TEST_COMPARE (msg.facility, LOG_LOCAL0);
 
-- 
2.32.0


^ permalink raw reply	[flat|nested] 21+ messages in thread

* Re: [PATCH v2 4/7] misc: syslog: Simplify implementation
  2022-02-18 14:23 ` [PATCH v2 4/7] misc: syslog: Simplify implementation Adhemerval Zanella
@ 2022-02-19  3:15   ` Paul Eggert
  2022-02-21 13:15     ` Adhemerval Zanella
  2022-02-21 14:06     ` Andreas Schwab
  0 siblings, 2 replies; 21+ messages in thread
From: Paul Eggert @ 2022-02-19  3:15 UTC (permalink / raw)
  To: Adhemerval Zanella; +Cc: libc-alpha

On 2/18/22 06:23, Adhemerval Zanella via Libc-alpha wrote:
> +      char timebuf[3+1                   /* "%h "  */
> +                   + 2+1                 /* "%e "  */
> +                   + 2+1 + 2+1 + 2+1 + 1 /* "%T "  */];
> +      time_t now = time_now ();
> +      struct tm now_tm;
> +      __localtime_r (&now, &now_tm);
> +      __strftime_l (timebuf, sizeof (timebuf), "%h %e %T ", &now_tm,
> +		    _nl_C_locobj_ptr);
> +
> +      pid_t pid = LogStat & LOG_PID ? __getpid () : 0;
> +
> +      fprintf (f, "<%d>%s %n%s%s%.0d%s: ", pri, timebuf, &msgoff,

Doesn't this output two spaces after the expansion of "%T"? The old code 
output just one.

Also, the old code crashed when __localtime_r returns NULL, whereas the 
new code logs garbage that might be truncated in 'timebuf'; is that 
change intended?

^ permalink raw reply	[flat|nested] 21+ messages in thread

* Re: [PATCH v2 5/7] misc: syslog: Use static buffer
  2022-02-18 14:23 ` [PATCH v2 5/7] misc: syslog: Use static buffer Adhemerval Zanella
@ 2022-02-19  3:45   ` Paul Eggert
  2022-02-21 13:31     ` Adhemerval Zanella
  0 siblings, 1 reply; 21+ messages in thread
From: Paul Eggert @ 2022-02-19  3:45 UTC (permalink / raw)
  To: Adhemerval Zanella; +Cc: libc-alpha

On 2/18/22 06:23, Adhemerval Zanella via Libc-alpha wrote:
> +  /* Try to use a static buffer as an optimization.  */
> +  char bufs[bufs_size];

This is not a static buffer; it's a buffer whose size is static. Perhaps 
change "static buffer" to "fixed-sized buffer" in the comment and commit 
message.

> +  int l = __snprintf (bufs, sizeof bufs,
> +                      SYSLOG_HEADER (pri, timestamp, &msgoff, pid));
> +  if (l < sizeof (bufs))

"sizeof (bufs)" -> "sizeof bufs" for consistency and simplicity, both 
here and elsewhere in the file.

^ permalink raw reply	[flat|nested] 21+ messages in thread

* Re: [PATCH v2 7/7] misc: syslog: Use RFC5424
  2022-02-18 14:23 ` [PATCH v2 7/7] misc: syslog: Use RFC5424 Adhemerval Zanella
@ 2022-02-19  3:50   ` Paul Eggert
  2022-02-21 14:01     ` Adhemerval Zanella
  2022-02-19 20:35   ` Dan Raymond
  1 sibling, 1 reply; 21+ messages in thread
From: Paul Eggert @ 2022-02-19  3:50 UTC (permalink / raw)
  To: Adhemerval Zanella; +Cc: libc-alpha

There should be documentation about the change, somewhere.

On 2/18/22 06:23, Adhemerval Zanella via Libc-alpha wrote:

> +  struct tm *gmtm = __gmtime64_r (&ts.tv_sec, &now_tm);
> +  if (gmtm == NULL)
> +    strcpy (timebuf->b, NILVALUE);

RFC 5424 requires unsigned four-digit years, so change "gmtm == NULL" to 
"gmtm == NULL || ! (-1900 <= gmtm->tm_year && gmtm->tm_year <= 9999 - 
1900)". Or, if the idea is to depart from RFC 5424 for out-of-range 
years (which might be better), document the departure.

> +  else
> +    {
> +      size_t datebytes = __strftime_l (timebuf->b, sizeof timebuf->b,
> +				       "%FT%T", gmtm, _nl_C_locobj_ptr);
RFC 5424 does not allow leap seconds, so something like this:

     if (gmtm->tv_sec == 60)
       {
          gmtm->tv_sec = 59;
          gmtm->tv_nsec = 999999999;
       }

before calling __strftime_l. (Or again, if the idea is to depart from 
RFC 5424, document the departure.)

> +      int usec = ts.tv_nsec / 1000;

Typically fewer instructions (and still correct) if you replace 1000 
with 1000ul (admittedly a microoptimization....).

^ permalink raw reply	[flat|nested] 21+ messages in thread

* Re: [PATCH v2 7/7] misc: syslog: Use RFC5424
  2022-02-18 14:23 ` [PATCH v2 7/7] misc: syslog: Use RFC5424 Adhemerval Zanella
  2022-02-19  3:50   ` Paul Eggert
@ 2022-02-19 20:35   ` Dan Raymond
  2022-02-19 22:23     ` Paul Eggert
  1 sibling, 1 reply; 21+ messages in thread
From: Dan Raymond @ 2022-02-19 20:35 UTC (permalink / raw)
  To: libc-alpha

On 3/9/2021 4:45 PM, Dan Raymond via Libc-alpha wrote:

> I noticed an issue with syslog() timestamps.  When a client generates a
> timestamp inside a call to syslog() it uses localtime_r().  When the
> server (syslogd) generates a timestamp it uses localtime().  The
> observable difference is that localtime() checks the timezone settings
> while localtime_r() does not.  Hence if you change the timezone settings
> while syslogd is running: server-generated timestamps will be correct
> while client-generated timestamps will be incorrect.
>
> Is this something that should be fixed?  There are various ways to
> mitigate the problem but none are ideal:
>
> 1) reboot or restart all processes using syslog() after changing the
> timezone (this may not be possible/practical)
>
> 2) call tzset() from all processes using syslog() after changing the
> timezone (not likely to be possible)
>
> 3) start syslogd with -t command line option to disable client-generated
> timestamps (timestamp accuracy is decreased)
>
> On the other hand, switching from localtime_r() to localtime() inside
> syslog() could adversely impact performance.  For instance it could
> incur an additional call to stat('/etc/localtime', ...) for each call to
> syslog().  This cost would be avoided if the calling process sets the TZ
> environment variable, however, since only changes to TZ would
> subsequently trigger a filesystem access.  Thoughts?
>   

Adhemerval, since you have been making changes in this area recently I 
wonder if you had any comments about the issue I raised last year 
(quoted above)?


^ permalink raw reply	[flat|nested] 21+ messages in thread

* Re: [PATCH v2 7/7] misc: syslog: Use RFC5424
  2022-02-19 20:35   ` Dan Raymond
@ 2022-02-19 22:23     ` Paul Eggert
  0 siblings, 0 replies; 21+ messages in thread
From: Paul Eggert @ 2022-02-19 22:23 UTC (permalink / raw)
  To: Dan Raymond; +Cc: libc-alpha

On 2/19/22 12:35, Dan Raymond wrote:
> Adhemerval, since you have been making changes in this area recently I 
> wonder if you had any comments about the issue I raised last year 
> (quoted above)?

Adhemerval's patches switch from localtime to gmtime, which should avoid 
many of the issues you raised.

If a process switches its TZ setting from a timezone that has leap 
seconds, to one that doesn't (or vice versa), there would be problems 
even with gmtime - but that would be a bad idea for so many other 
reasons that I don't think we need to worry too much about it.

^ permalink raw reply	[flat|nested] 21+ messages in thread

* Re: [PATCH v2 4/7] misc: syslog: Simplify implementation
  2022-02-19  3:15   ` Paul Eggert
@ 2022-02-21 13:15     ` Adhemerval Zanella
  2022-02-21 22:25       ` Paul Eggert
  2022-02-21 14:06     ` Andreas Schwab
  1 sibling, 1 reply; 21+ messages in thread
From: Adhemerval Zanella @ 2022-02-21 13:15 UTC (permalink / raw)
  To: Paul Eggert; +Cc: libc-alpha



On 19/02/2022 00:15, Paul Eggert wrote:
> On 2/18/22 06:23, Adhemerval Zanella via Libc-alpha wrote:
>> +      char timebuf[3+1                   /* "%h "  */
>> +                   + 2+1                 /* "%e "  */
>> +                   + 2+1 + 2+1 + 2+1 + 1 /* "%T "  */];
>> +      time_t now = time_now ();
>> +      struct tm now_tm;
>> +      __localtime_r (&now, &now_tm);
>> +      __strftime_l (timebuf, sizeof (timebuf), "%h %e %T ", &now_tm,
>> +            _nl_C_locobj_ptr);
>> +
>> +      pid_t pid = LogStat & LOG_PID ? __getpid () : 0;
>> +
>> +      fprintf (f, "<%d>%s %n%s%s%.0d%s: ", pri, timebuf, &msgoff,
> 
> Doesn't this output two spaces after the expansion of "%T"? The old code output just one.

You are right, I will fix it.

> 
> Also, the old code crashed when __localtime_r returns NULL, whereas the new code logs garbage that might be truncated in 'timebuf'; is that change intended?

Not really, but afaiu __localtime_r fails on if __offtime return EOVERFLOW
which is *highly* unlikely.  Also given this is a transitory patch (the
final version will use gmtime with a proper NULL tests), I can add check
but I am not sure what to print in such cases (the RFC5424 at least gives
us a way to express such error).  Should we care for this?

^ permalink raw reply	[flat|nested] 21+ messages in thread

* Re: [PATCH v2 5/7] misc: syslog: Use static buffer
  2022-02-19  3:45   ` Paul Eggert
@ 2022-02-21 13:31     ` Adhemerval Zanella
  0 siblings, 0 replies; 21+ messages in thread
From: Adhemerval Zanella @ 2022-02-21 13:31 UTC (permalink / raw)
  To: Paul Eggert; +Cc: libc-alpha



On 19/02/2022 00:45, Paul Eggert wrote:
> On 2/18/22 06:23, Adhemerval Zanella via Libc-alpha wrote:
>> +  /* Try to use a static buffer as an optimization.  */
>> +  char bufs[bufs_size];
> 
> This is not a static buffer; it's a buffer whose size is static. Perhaps change "static buffer" to "fixed-sized buffer" in the comment and commit message.

Ack.

> 
>> +  int l = __snprintf (bufs, sizeof bufs,
>> +                      SYSLOG_HEADER (pri, timestamp, &msgoff, pid));
>> +  if (l < sizeof (bufs))
> 
> "sizeof (bufs)" -> "sizeof bufs" for consistency and simplicity, both here and elsewhere in the file.

Ack.

^ permalink raw reply	[flat|nested] 21+ messages in thread

* Re: [PATCH v2 7/7] misc: syslog: Use RFC5424
  2022-02-19  3:50   ` Paul Eggert
@ 2022-02-21 14:01     ` Adhemerval Zanella
  2022-02-21 16:18       ` Adhemerval Zanella
  0 siblings, 1 reply; 21+ messages in thread
From: Adhemerval Zanella @ 2022-02-21 14:01 UTC (permalink / raw)
  To: Paul Eggert; +Cc: libc-alpha



On 19/02/2022 00:50, Paul Eggert wrote:
> There should be documentation about the change, somewhere.
> 
> On 2/18/22 06:23, Adhemerval Zanella via Libc-alpha wrote:
> 
>> +  struct tm *gmtm = __gmtime64_r (&ts.tv_sec, &now_tm);
>> +  if (gmtm == NULL)
>> +    strcpy (timebuf->b, NILVALUE);
> 
> RFC 5424 requires unsigned four-digit years, so change "gmtm == NULL" to "gmtm == NULL || ! (-1900 <= gmtm->tm_year && gmtm->tm_year <= 9999 - 1900)". Or, if the idea is to depart from RFC 5424 for out-of-range years (which might be better), document the departure.

Indeed I don't see why we can't support out-of-range years in such case.  I will add
a comment.

> 
>> +  else
>> +    {
>> +      size_t datebytes = __strftime_l (timebuf->b, sizeof timebuf->b,
>> +                       "%FT%T", gmtm, _nl_C_locobj_ptr);
> RFC 5424 does not allow leap seconds, so something like this:
> 
>     if (gmtm->tv_sec == 60)
>       {
>          gmtm->tv_sec = 59;
>          gmtm->tv_nsec = 999999999;
>       }
> 
> before calling __strftime_l. (Or again, if the idea is to depart from RFC 5424, document the departure.)

I think this is worth to support, I will add such test.

> 
>> +      int usec = ts.tv_nsec / 1000;
> 
> Typically fewer instructions (and still correct) if you replace 1000 with 1000ul (admittedly a microoptimization....).

Ack.

^ permalink raw reply	[flat|nested] 21+ messages in thread

* Re: [PATCH v2 4/7] misc: syslog: Simplify implementation
  2022-02-19  3:15   ` Paul Eggert
  2022-02-21 13:15     ` Adhemerval Zanella
@ 2022-02-21 14:06     ` Andreas Schwab
  2022-02-21 22:23       ` Paul Eggert
  1 sibling, 1 reply; 21+ messages in thread
From: Andreas Schwab @ 2022-02-21 14:06 UTC (permalink / raw)
  To: Paul Eggert; +Cc: Adhemerval Zanella, libc-alpha

On Feb 18 2022, Paul Eggert wrote:

> Also, the old code crashed when __localtime_r returns NULL

How can that happen?

-- 
Andreas Schwab, schwab@linux-m68k.org
GPG Key fingerprint = 7578 EB47 D4E5 4D69 2510  2552 DF73 E780 A9DA AEC1
"And now for something completely different."

^ permalink raw reply	[flat|nested] 21+ messages in thread

* Re: [PATCH v2 7/7] misc: syslog: Use RFC5424
  2022-02-21 14:01     ` Adhemerval Zanella
@ 2022-02-21 16:18       ` Adhemerval Zanella
  2022-02-21 22:25         ` Paul Eggert
  0 siblings, 1 reply; 21+ messages in thread
From: Adhemerval Zanella @ 2022-02-21 16:18 UTC (permalink / raw)
  To: Paul Eggert; +Cc: libc-alpha



On 21/02/2022 11:01, Adhemerval Zanella wrote:
> 
> 
> On 19/02/2022 00:50, Paul Eggert wrote:
>>> +  else
>>> +    {
>>> +      size_t datebytes = __strftime_l (timebuf->b, sizeof timebuf->b,
>>> +                       "%FT%T", gmtm, _nl_C_locobj_ptr);
>> RFC 5424 does not allow leap seconds, so something like this:
>>
>>     if (gmtm->tv_sec == 60)
>>       {
>>          gmtm->tv_sec = 59;
>>          gmtm->tv_nsec = 999999999;
>>       }
>>
>> before calling __strftime_l. (Or again, if the idea is to depart from RFC 5424, document the departure.)
> 
> I think this is worth to support, I will add such test.

In fact struct tm does not 'tv_nsec' so I am confused about your suggestion here.

^ permalink raw reply	[flat|nested] 21+ messages in thread

* Re: [PATCH v2 4/7] misc: syslog: Simplify implementation
  2022-02-21 14:06     ` Andreas Schwab
@ 2022-02-21 22:23       ` Paul Eggert
  0 siblings, 0 replies; 21+ messages in thread
From: Paul Eggert @ 2022-02-21 22:23 UTC (permalink / raw)
  To: Andreas Schwab; +Cc: Adhemerval Zanella, libc-alpha

On 2/21/22 06:06, Andreas Schwab wrote:
>> Also, the old code crashed when __localtime_r returns NULL
> How can that happen?

When the resulting tm_year would precede INT_MIN + 1900 or follow 
INT_MAX + 1900. Although this shouldn't happen on systems with accurate 
clocks for billions of years, syslog should work even when the clock is 
outlandishly wrong, to help diagnose clock failures etc.

^ permalink raw reply	[flat|nested] 21+ messages in thread

* Re: [PATCH v2 4/7] misc: syslog: Simplify implementation
  2022-02-21 13:15     ` Adhemerval Zanella
@ 2022-02-21 22:25       ` Paul Eggert
  0 siblings, 0 replies; 21+ messages in thread
From: Paul Eggert @ 2022-02-21 22:25 UTC (permalink / raw)
  To: Adhemerval Zanella; +Cc: libc-alpha

On 2/21/22 05:15, Adhemerval Zanella wrote:
> this is a transitory patch (the
> final version will use gmtime with a proper NULL tests),

Ah, I hadn't notice that. Never mind, then; it's not worth worrying about.

^ permalink raw reply	[flat|nested] 21+ messages in thread

* Re: [PATCH v2 7/7] misc: syslog: Use RFC5424
  2022-02-21 16:18       ` Adhemerval Zanella
@ 2022-02-21 22:25         ` Paul Eggert
  0 siblings, 0 replies; 21+ messages in thread
From: Paul Eggert @ 2022-02-21 22:25 UTC (permalink / raw)
  To: Adhemerval Zanella; +Cc: libc-alpha

On 2/21/22 08:18, Adhemerval Zanella wrote:
>>>      if (gmtm->tv_sec == 60)
>>>        {
>>>           gmtm->tv_sec = 59;
>>>           gmtm->tv_nsec = 999999999;
>>>        }
>>>
>>> before calling __strftime_l. (Or again, if the idea is to depart from RFC 5424, document the departure.)
>> I think this is worth to support, I will add such test.
> In fact struct tm does not 'tv_nsec' so I am confused about your suggestion here.

Oh, you're right, my suggestion should have been just:

   gmtm->tv_sec -= gmtm->tv_sec == 60;

However, as I understand from your other email you plan to support leap 
seconds and out-of-range years (even though this departs from RFC 5424) 
so in that case please ignore my corrected suggestion; all that's needed 
is documentation for the departure.

^ permalink raw reply	[flat|nested] 21+ messages in thread

end of thread, other threads:[~2022-02-21 22:25 UTC | newest]

Thread overview: 21+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2022-02-18 14:23 [PATCH v2 0/7] Use RFC5424 for syslog Adhemerval Zanella
2022-02-18 14:23 ` [PATCH v2 1/7] support: Add xmkfifo Adhemerval Zanella
2022-02-18 14:23 ` [PATCH v2 2/7] misc: Add syslog test Adhemerval Zanella
2022-02-18 14:23 ` [PATCH v2 3/7] misc: syslog: Fix indentation and style Adhemerval Zanella
2022-02-18 14:23 ` [PATCH v2 4/7] misc: syslog: Simplify implementation Adhemerval Zanella
2022-02-19  3:15   ` Paul Eggert
2022-02-21 13:15     ` Adhemerval Zanella
2022-02-21 22:25       ` Paul Eggert
2022-02-21 14:06     ` Andreas Schwab
2022-02-21 22:23       ` Paul Eggert
2022-02-18 14:23 ` [PATCH v2 5/7] misc: syslog: Use static buffer Adhemerval Zanella
2022-02-19  3:45   ` Paul Eggert
2022-02-21 13:31     ` Adhemerval Zanella
2022-02-18 14:23 ` [PATCH v2 6/7] misc: syslog: Move SYSLOG_NAME to USE_MISC (BZ #16355) Adhemerval Zanella
2022-02-18 14:23 ` [PATCH v2 7/7] misc: syslog: Use RFC5424 Adhemerval Zanella
2022-02-19  3:50   ` Paul Eggert
2022-02-21 14:01     ` Adhemerval Zanella
2022-02-21 16:18       ` Adhemerval Zanella
2022-02-21 22:25         ` Paul Eggert
2022-02-19 20:35   ` Dan Raymond
2022-02-19 22:23     ` Paul Eggert

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).