[Bug 1875708] Re: Truncated messages in journald since systemd v244

Thu Jul 23 13:25:18 UTC 2020

This bug was fixed in the package systemd - 245.4-4ubuntu3.2

---------------
systemd (245.4-4ubuntu3.2) focal; urgency=medium

   [ Dan Streetman ]
   * Hotadd only offline memory and CPUs (LP: #1876018)
     File: debian/extra/rules-ubuntu/40-vm-hotadd.rules
     https://git.launchpad.net/~ubuntu-core-dev/ubuntu/+source/systemd/commit/?id=72d815471596056b7727be5b10f87513ff1d5757
   * Lock swap blockdevice while calling mkswap (LP: #1838329)
     Files:
     - d/p/lp1838329/0001-blockdev-propagate-one-more-unexpected-error.patch
     - d/p/lp1838329/0002-makefs-log-about-OOM-condition.patch
     - d/p/lp1838329/0003-dissect-use-log_debug_errno-where-appropriate.patch
     - d/p/lp1838329/0004-blockdev-add-helper-for-locking-whole-block-device.patch
     - d/p/lp1838329/0005-makefs-lock-device-while-we-operate.patch
     - d/p/lp1838329/0006-makefs-normalize-logging-a-bit.patch
     - d/p/lp1838329/0007-cryptsetup-generator-use-systemd-makefs-for-implemen.patch
     https://git.launchpad.net/~ubuntu-core-dev/ubuntu/+source/systemd/commit/?id=c81b75c4297cbb04554488b070b6f79996b8cceb

   [ Balint Reczey ]
   * debian/udev.postinst: Allow kvm to be an already present non-system group
     (LP: #1880541)
     File: debian/udev.postinst
     https://git.launchpad.net/~ubuntu-core-dev/ubuntu/+source/systemd/commit/?id=8b5c31828d4323ddb719326b1316c179b7cdbdef
   * d/p/hwdb-Mask-rfkill-event-from-intel-hid-on-HP-platforms.patch:
     hwdb: Mask rfkill event from intel-hid on HP platforms
     (LP: #1883846)
     https://git.launchpad.net/~ubuntu-core-dev/ubuntu/+source/systemd/commit/?id=164c016b466210c7d6d05963fd753eccf4679844
   * journald: stream pid change newline fix (LP: #1875708)
     Files:
     - debian/patches/lp1875708/journald-Increase-stdout-buffer-size-sooner-when-almost-f.patch
     - debian/patches/lp1875708/journald-rework-end-of-line-marker-handling-to-use-a-fiel.patch
     - debian/patches/lp1875708/journald-rework-pid-change-handling.patch
     - debian/patches/lp1875708/journald-use-log_warning_errno-where-appropriate.patch
     - debian/patches/lp1875708/journald-use-the-fact-that-client_context_release-returns.patch
     - debian/patches/lp1875708/man-document-the-new-_LINE_BREAK-type.patch
     - debian/patches/lp1875708/socket-util-introduce-type-safe-dereferencing-wrapper-CMS.patch
     - debian/patches/lp1875708/test-Add-a-test-case-for-15654.patch
     https://git.launchpad.net/~ubuntu-core-dev/ubuntu/+source/systemd/commit/?id=2dc19f7ae4aad7277e9d89849182453ff1d046dc

 -- Dan Streetman <ddstreet at canonical.com>  Mon, 06 Jul 2020 17:38:31
-0400

** Changed in: systemd (Ubuntu Focal)
       Status: Fix Committed => Fix Released

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to systemd in Ubuntu.
https://bugs.launchpad.net/bugs/1875708

Title:
  Truncated messages in journald since systemd v244

Status in libvirt package in Ubuntu:
  Invalid
Status in systemd package in Ubuntu:
  Fix Released
Status in libvirt source package in Focal:
  Confirmed
Status in systemd source package in Focal:
  Fix Released
Status in libvirt source package in Groovy:
  Invalid
Status in systemd source package in Groovy:
  Fix Released

Bug description:
  [Impact]

   * since 09d0b46a "journal: refresh cached credentials of stdout streams"
     in ~244 output may be trincated.

   * Upstream has a fix in https://github.com/systemd/systemd/pull/15685

   * Backporting the fix will avoid truncation of log output to journald

  [Test Case]

   * This could happen in any case, but is more likely when a program that 
     has output going to journald is spawning short-lived sub-programs often.
     Therefore the test emphasizes on that:

     - Use a test service like /etc/systemd/system/test.service:
  [Unit]
  Description=Test Truncate
  After=network.target

  [Service]
  ExecStart=/usr/lib/test.sh long-test-for-start
  ExecStop=/usr/lib/test.sh long-test-for-stop
  Type=oneshot
  RemainAfterExit=yes
  StandardOutput=journal+console
  TimeoutStopSec=0

  [Install]
  WantedBy=multi-user.target

     - And a test script like /usr/lib/test.sh:
  #!/bin/sh
  gettext "This will"
  echo
  gettext "usually fail"
  echo
  gettext "and be truncated"
  echo 

  Start/Stopping that service without the fix will look like:
  Apr 30 18:56:40 f systemd[1]: Stopping Test Truncate...
  Apr 30 18:56:40 f test.sh[1165]: T
  Apr 30 18:56:40 f test.sh[1167]: T
  Apr 30 18:56:40 f test.sh[1167]: sually fai
  Apr 30 18:56:40 f test.sh[1165]: s
  Apr 30 18:56:40 f test.sh[1168]: s
  Apr 30 18:56:40 f test.sh[1168]: nd be truncate
  Apr 30 18:56:40 f test.sh[1165]: n
  Apr 30 18:56:40 f systemd[1]: test.service: Succeeded.
  Apr 30 18:56:40 f systemd[1]: Stopped Test Truncate.

  
  [Regression Potential] 

   * The patches are rather small, but there might be a slightly increased 
     memory consumption of journald for output buffers. 
   * Issues (if any and I couldn't find any so far) should be only to 
     journald output handling. Systemd is huge, this at least narrows
     down the potential places of a regression a lot.

  [Other Info]
   
   * n/a

  --- --- --- --- --- --- --- --- --- --- --- --- --- --- ---

  Originally reported against libvirt which happens to be one of the
  example-triggers

  Hi,

  when I shut down my machine I see messages from /usr/lib/libvirt
  /libvirt-guests.sh but there are 2 anomalies:

   - 3 libvirt-guests.sh processes are run
   - messages are truncated

  ProblemType: Bug
  DistroRelease: Ubuntu 20.04
  Package: libvirt-daemon 6.0.0-0ubuntu8
  Uname: Linux 5.6.7-050607-generic x86_64
  ApportVersion: 2.20.11-0ubuntu27
  Architecture: amd64
  CasperMD5CheckResult: skip
  CurrentDesktop: KDE
  Date: Tue Apr 28 19:42:56 2020
  SourcePackage: libvirt
  UpgradeStatus: No upgrade log present (probably fresh install)
  modified.conffile..etc.libvirt.nwfilter.allow-arp.xml: [inaccessible: [Errno 13] Permission denied: '/etc/libvirt/nwfilter/allow-arp.xml']
  modified.conffile..etc.libvirt.nwfilter.allow-dhcp-server.xml: [inaccessible: [Errno 13] Permission denied: '/etc/libvirt/nwfilter/allow-dhcp-server.xml']
  modified.conffile..etc.libvirt.nwfilter.allow-dhcp.xml: [inaccessible: [Errno 13] Permission denied: '/etc/libvirt/nwfilter/allow-dhcp.xml']
  modified.conffile..etc.libvirt.nwfilter.allow-incoming-ipv4.xml: [inaccessible: [Errno 13] Permission denied: '/etc/libvirt/nwfilter/allow-incoming-ipv4.xml']
  modified.conffile..etc.libvirt.nwfilter.allow-ipv4.xml: [inaccessible: [Errno 13] Permission denied: '/etc/libvirt/nwfilter/allow-ipv4.xml']
  modified.conffile..etc.libvirt.nwfilter.clean-traffic-gateway.xml: [inaccessible: [Errno 13] Permission denied: '/etc/libvirt/nwfilter/clean-traffic-gateway.xml']
  modified.conffile..etc.libvirt.nwfilter.clean-traffic.xml: [inaccessible: [Errno 13] Permission denied: '/etc/libvirt/nwfilter/clean-traffic.xml']
  modified.conffile..etc.libvirt.nwfilter.no-arp-ip-spoofing.xml: [inaccessible: [Errno 13] Permission denied: '/etc/libvirt/nwfilter/no-arp-ip-spoofing.xml']
  modified.conffile..etc.libvirt.nwfilter.no-arp-mac-spoofing.xml: [inaccessible: [Errno 13] Permission denied: '/etc/libvirt/nwfilter/no-arp-mac-spoofing.xml']
  modified.conffile..etc.libvirt.nwfilter.no-arp-spoofing.xml: [inaccessible: [Errno 13] Permission denied: '/etc/libvirt/nwfilter/no-arp-spoofing.xml']
  modified.conffile..etc.libvirt.nwfilter.no-ip-multicast.xml: [inaccessible: [Errno 13] Permission denied: '/etc/libvirt/nwfilter/no-ip-multicast.xml']
  modified.conffile..etc.libvirt.nwfilter.no-ip-spoofing.xml: [inaccessible: [Errno 13] Permission denied: '/etc/libvirt/nwfilter/no-ip-spoofing.xml']
  modified.conffile..etc.libvirt.nwfilter.no-mac-broadcast.xml: [inaccessible: [Errno 13] Permission denied: '/etc/libvirt/nwfilter/no-mac-broadcast.xml']
  modified.conffile..etc.libvirt.nwfilter.no-mac-spoofing.xml: [inaccessible: [Errno 13] Permission denied: '/etc/libvirt/nwfilter/no-mac-spoofing.xml']
  modified.conffile..etc.libvirt.nwfilter.no-other-l2-traffic.xml: [inaccessible: [Errno 13] Permission denied: '/etc/libvirt/nwfilter/no-other-l2-traffic.xml']
  modified.conffile..etc.libvirt.nwfilter.no-other-rarp-traffic.xml: [inaccessible: [Errno 13] Permission denied: '/etc/libvirt/nwfilter/no-other-rarp-traffic.xml']
  modified.conffile..etc.libvirt.nwfilter.qemu-announce-self-rarp.xml: [inaccessible: [Errno 13] Permission denied: '/etc/libvirt/nwfilter/qemu-announce-self-rarp.xml']
  modified.conffile..etc.libvirt.nwfilter.qemu-announce-self.xml: [inaccessible: [Errno 13] Permission denied: '/etc/libvirt/nwfilter/qemu-announce-self.xml']
  modified.conffile..etc.libvirt.qemu.conf: [inaccessible: [Errno 13] Permission denied: '/etc/libvirt/qemu.conf']
  modified.conffile..etc.libvirt.qemu.networks.default.xml: [inaccessible: [Errno 13] Permission denied: '/etc/libvirt/qemu/networks/default.xml']

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/libvirt/+bug/1875708/+subscriptions