Gentoo Websites Logo
Go to: Gentoo Home Documentation Forums Lists Bugs Planet Store Wiki Get Gentoo!
Bug 637092 - sys-apps/util-linux-2.30.2 - logger prints error when getting multiple lines and specific $PID for --id switch
Summary: sys-apps/util-linux-2.30.2 - logger prints error when getting multiple lines ...
Status: RESOLVED NEEDINFO
Alias: None
Product: Gentoo Linux
Classification: Unclassified
Component: Current packages (show other bugs)
Hardware: All Linux
: Normal normal
Assignee: Gentoo's Team for Core System packages
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2017-11-10 21:12 UTC by Nico Rittner
Modified: 2017-11-12 14:23 UTC (History)
0 users

See Also:
Package list:
Runtime testing required: ---


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Nico Rittner 2017-11-10 21:12:23 UTC
hi,

i came up to a strange problem today with "logger" from util-linux
after emerging world. when using logger with the --id switch, it
throws the error "logger: send message failed: invalid argument".
this happens only if logger gets more than one line via stdin and
if the value used for --id is a pid of a currently running process.
if logger receives only one line or if the value for --id is not
currently associated with a running process, no error is shown
and syslogd receives all input without a problem.
as a result of the first case only the first line is received
by syslogd and logger exits with success (0) anyway.

example:

$ ( echo 1; echo 2; echo 3; ) | logger --id=$$
logger: send message failed: Das Argument ist ungültig
logger: send message failed: Das Argument ist ungültig

strace output:

(...)
read(0, "1\n2\n3\n", 4096)              = 6
getpid()                                = 3302
geteuid32()                             = 0
kill(30318, SIG_0)                      = 0
sendmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="<13>Nov 10 21:34:11 root[30318]:"..., iov_len=33}, {iov_base="1", iov_len=1}], msg_iovlen=2, msg_control=[{cmsg_len=24, cmsg_level=SOL_SOCKET, cmsg_type=SCM_CREDENTIALS, cmsg_data={pid=30318, uid=134514384, gid=13}}], msg_controllen=24, msg_flags=0}, 0) = 34
getpid()                                = 3302
geteuid32()                             = 0
kill(30318, SIG_0)                      = 0
sendmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="<13>Nov 10 21:34:11 root[30318]:"..., iov_len=33}, {iov_base="2", iov_len=1}], msg_iovlen=2, msg_control=[{cmsg_len=24, cmsg_level=SOL_SOCKET, cmsg_type=SCM_CREDENTIALS, cmsg_data={pid=30318, uid=3214637644, gid=4294967295}}], msg_controllen=24, msg_flags=0}, 0) = -1 EINVAL (Invalid argument)
write(2, "logger: ", 8logger: )                 = 8
write(2, "send message failed", 19send message failed)     = 19
write(2, ": ", 2: )                       = 2
(...)
getpid()                                = 3302
geteuid32()                             = 0
kill(30318, SIG_0)                      = 0
sendmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="<13>Nov 10 21:34:11 root[30318]:"..., iov_len=33}, {iov_base="3", iov_len=1}], msg_iovlen=2, msg_control=[{cmsg_len=24, cmsg_level=SOL_SOCKET, cmsg_type=SCM_CREDENTIALS, cmsg_data={pid=30318, uid=3214637644, gid=4294967295}}], msg_controllen=24, msg_flags=0}, 0) = -1 EINVAL (Invalid argument)

went back to util-linux-2.28.2, but the problem persists, so i assume
the problem relates to the fact that both were built with recent glibc 2.25-r8
which also appeared in portage some days ago.
there is a comment in logger.c of util-linux which relates in some kind
to my described case:

/* syslog/journald may follow local socket credentials rather
* than in the message PID. If we use --id as root than we can
* force kernel to accept another valid PID than the real logger(1)
* PID.
*/

syslog-ng is the logging daemon here. no systemd used.

is there any tip/fix beside downgrading glibc, or can anybody reproduce?

thanks a lot,

nico


Reproducible: Always

Steps to Reproduce:
( echo 1; echo 2; echo 3; ) | logger --id=$$;
Actual Results:  
first line is received by logging daemon.
error message for each remaining line.

Expected Results:  
all lines received by logging daemon.
no error messages.

Portage 2.3.8 (python 2.7.14-final-0, default/linux/x86/13.0, gcc-5.4.0, glibc-2.25-r8, 4.4.26-jason-default-x86_64-1479738800 x86_64)
=================================================================
System uname: Linux-4.4.26-jason-default-x86_64-1479738800-x86_64-Intel-R-_Pentium-R-_CPU_G6950_@_2.80GHz-with-gentoo-2.4.1
KiB Mem:    10151324 total,    172364 free
KiB Swap:          0 total,         0 free
Timestamp of repository gentoo: Fri, 10 Nov 2017 14:00:01 +0000
Head commit of repository gentoo: 9974fd94f4fdc69679834e441c7f86a787effe8e
sh bash 4.3_p48-r1
ld GNU ld (Gentoo 2.28.1 p1.0) 2.28.1
app-shells/bash:          4.3_p48-r1::gentoo
dev-lang/perl:            5.24.3::gentoo
dev-lang/python:          2.7.14::gentoo
dev-util/cmake:           3.8.2::gentoo
dev-util/pkgconfig:       0.29.2::gentoo
sys-apps/baselayout:      2.4.1-r2::gentoo
sys-apps/openrc:          0.32.1::gentoo
sys-apps/sandbox:         2.10-r4::gentoo
sys-devel/autoconf:       2.69::gentoo
sys-devel/automake:       1.11.6-r2::gentoo, 1.13.4-r1::gentoo, 1.15.1-r1::gentoo
sys-devel/binutils:       2.28.1::gentoo
sys-devel/gcc:            5.4.0-r3::gentoo
sys-devel/gcc-config:     1.8-r1::gentoo
sys-devel/libtool:        2.4.6-r3::gentoo
sys-devel/make:           4.2.1::gentoo
sys-kernel/linux-headers: 4.4::gentoo (virtual/os-headers)
sys-libs/glibc:           2.25-r8::gentoo
Repositories:

gentoo
    location: /var/db/portage
    sync-type: rsync
    sync-uri: rsync://rsync.gentoo.org/gentoo-portage
    priority: -1000

layer23
    location: /dat/local/share/portage/db
    masters: gentoo

ACCEPT_KEYWORDS="x86"
ACCEPT_LICENSE="* -@EULA"
CBUILD="i686-pc-linux-gnu"
CFLAGS="-O2 -march=i686 -fomit-frame-pointer -pipe"
CHOST="i686-pc-linux-gnu"
CONFIG_PROTECT="/etc /usr/share/gnupg/qualified.txt /var/bind"
CONFIG_PROTECT_MASK="/etc/ca-certificates.conf /etc/env.d /etc/fonts/fonts.conf /etc/gconf /etc/gentoo-release /etc/php/apache2-php5.6/ext-active/ /etc/php/apache2-php7.0/ext-active/ /etc/php/cgi-php5.6/ext-active/ /etc/php/cgi-php7.0/ext-active/ /etc/php/cli-php5.6/ext-active/ /etc/php/cli-php7.0/ext-active/ /etc/revdep-rebuild /etc/sandbox.d /etc/terminfo"
CXXFLAGS="-O2 -march=i686 -fomit-frame-pointer -pipe"
DISTDIR="/tmp"
FCFLAGS="-O2 -march=i686 -pipe"
FEATURES="assume-digests binpkg-logs config-protect-if-modified distlocks ebuild-locks fixlafiles merge-sync multilib-strict news parallel-fetch preserve-libs protect-owned sandbox sfperms strict unknown-features-warn unmerge-logs unmerge-orphans userfetch userpriv usersandbox usersync"
FFLAGS="-O2 -march=i686 -pipe"
GENTOO_MIRRORS="http://distfiles.gentoo.org"
LANG="C"
LC_ALL="de_DE.UTF-8"
LDFLAGS="-Wl,-O1 -Wl,--as-needed"
MAKEOPTS="-j3"
PKGDIR="/tmp"
PORTAGE_CONFIGROOT="/"
PORTAGE_RSYNC_OPTS="--recursive --links --safe-links --perms --times --omit-dir-times --compress --force --whole-file --delete --stats --human-readable --timeout=180 --exclude=/distfiles --exclude=/local --exclude=/packages --exclude=/.git"
PORTAGE_TMPDIR="/var/tmp"
USE="acl alsa berkdb bzip2 cli cxx dri fortran gd iconv imap ipv6 jpeg ldap mbox modules mysql ncurses nptl openmp pam pcre perl png readline sasl seccomp session ssl syslog tcpd tiff truetype unicode x86 xml zlib" ABI_X86="32" ALSA_CARDS="ali5451 als4000 atiixp atiixp-modem bt87x ca0106 cmipci emu10k1 emu10k1x ens1370 ens1371 es1938 es1968 fm801 hda-intel intel8x0 intel8x0m maestro3 trident usb-audio via82xx via82xx-modem ymfpci" APACHE2_MODULES="actions alias asis auth_basic auth_digest filter authn_core authn_file authn_anon authz_core authz_groupfile authz_host authz_owner authz_user access_compat cache cache_disk cgi deflate dumpio dav dav_fs dir env expires headers include info log_config macro mime mime_magic proxy proxy_balancer proxy_connect proxy_fcgi proxy_http ratelimit rewrite setenvif slotmem_shm so socache_shmcb status substitute userdir unique_id unixd vhost_alias" APACHE2_MPMS="prefork" CALLIGRA_FEATURES="kexi words flow plan sheets stage tables krita karbon braindump author" COLLECTD_PLUGINS="df interface irq load memory rrdtool swap syslog" ELIBC="glibc" GPSD_PROTOCOLS="ashtech aivdm earthmate evermore fv18 garmin garmintxt gpsclock isync itrax mtk3301 nmea ntrip navcom oceanserver oldstyle oncore rtcm104v2 rtcm104v3 sirf skytraq superstar2 timing tsip tripmate tnt ublox ubx" INPUT_DEVICES="libinput keyboard mouse" KERNEL="linux" LCD_DEVICES="bayrad cfontz cfontz633 glk hd44780 lb216 lcdm001 mtxorb ncurses text" LIBREOFFICE_EXTENSIONS="presenter-console presenter-minimizer" NGINX_MODULES_HTTP="access auth_basic charset dav fastcgi geo gzip limit_req lua map memcached proxy rewrite ssl stub_status upstream_keepalive" OFFICE_IMPLEMENTATION="libreoffice" PHP_TARGETS="php5-6" POSTGRES_TARGETS="postgres9_5" PYTHON_SINGLE_TARGET="python2_7" PYTHON_TARGETS="python2_7" QEMU_SOFTMMU_TARGETS="i386" RUBY_TARGETS="ruby22" USERLAND="GNU" VIDEO_CARDS="amdgpu fbdev intel nouveau radeon radeonsi vesa dummy v4l" XTABLES_ADDONS="quota2 psd pknock lscan length2 ipv4options ipset ipp2p iface geoip fuzzy condition tee tarpit sysrq steal rawnat logmark ipmark dhcpmac delude chaos account"
Unset:  CC, CPPFLAGS, CTARGET, CXX, EMERGE_DEFAULT_OPTS, INSTALL_MASK, PORTAGE_BUNZIP2_COMMAND, PORTAGE_COMPRESS, PORTAGE_COMPRESS_FLAGS, PORTAGE_RSYNC_EXTRA_OPTS

problem happens under x86 (doing crosscompile for x86 under x86_64)
Comment 1 Thomas Deutschmann (RETIRED) gentoo-dev 2017-11-11 14:14:10 UTC
I am unable to reproduce with >=sys-apps/util-linux-2.31 on an OpenRC system. Can you please try to reproduce with util-linux-2.31 or later?
Comment 2 Nico Rittner 2017-11-12 14:23:09 UTC
just tried logger from util-linux-2.31. - same behaviour ("cannot send message...")

also tried the following:

separate invocation of logger for each line. (works)
$ for i in 1 2 3; do echo $i | logger --id=$$; done;

simple imitation of logger's job as described yesterday. (works too)
$ ( echo 1; echo 2; echo 3; ) | perl -MSys::Syslog -e 'openlog(test,"ndelay,pid", "local0"); syslog(LOG_INFO,$_) while (<>); closelog';

i also temporarily exchanged syslog-ng with sysklogd (same error).

current versions for x86:
sys-apps/util-linux-2.30.2::gentoo  USE="cramfs ncurses pam readline suid unicode -build -caps -fdformat -kill -nls -python (-selinux) -slang -static-libs -systemd {-test} -tty-helpers -udev" PYTHON_SINGLE_TARGET="python2_7 -python3_4 -python3_5 (-python3_6)" PYTHON_TARGETS="python2_7 -python3_4 -python3_5 (-python3_6)" 4.339 KiB
sys-libs/glibc-2.25-r9:2.2::gentoo  USE="gd rpc -audit -caps -debug (-hardened) (-multilib) -nscd -profile (-selinux) -suid -systemtap (-vanilla)" 13.613 KiB
app-admin/syslog-ng-3.7.3::gentoo  USE="tcpd -amqp -caps -dbi -geoip -ipv6 -json (-libressl) -mongodb -pacct -python -redis -smtp -spoof-source -systemd" PYTHON_TARGETS="python2_7" 3.429 KiB

on amd64/x86_64 platform the problem does NOT occur.
the only difference is that there is glibc-2.25-r8
instead of glibc-2.25-r9. (no ~xyz keywords in use).