[Bug 1208929] [NEW] Udev occasionally does not write log priority change messages

[Richard Michael]

Public bug reported:

"udevadm control --log-priority=XXX" normally causes udevd to write a
message to syslog indicating it has received SET_LOG_PRIORITY message
and the resulting (and now current) log priority.

I expect udevd to consistently write notification messages, but
occasionally it does not.  Aside, I am uncertain if it has actually
changed priority in the cases when it fails to write the notification
messages.  Often, when udevd drops the log change messages, it seems to
be also dropping other event messages.  So I suspect the failure to
write messages might not be unique to the SET_LOG_PRIORITY message type.

strace shows udevd has received the signal, but not written the message:
after receiving some messages, it does not call the time() or send()
syscalls.

I suspected udevd might be *not* writing messages when the "new"
priority is the same as the current priority, e.g. "udevadm control
--log-priority=debug" twice in a row.  But this is not the case: under
normal operation udevd does indeed write "change" notifications for both
udevadm invocations.

Note, I have disabled rsyslogd's buffered logging ($RepeatedMsgReduction
off).  Although, given the missing syscalls, this seems to be a
behaviour of udevd, independent of the syslog implementation.

I have attached output of several invocations of udevdadm, the log
messages written by udevd and corresponding strace output; with
timestamps and comments.


(ubuntu) ~ lsb_release -rd
Description:    Ubuntu 12.04.2 LTS
Release:        12.04

(ubuntu) ~ apt-cache policy udev
udev:
  Installed: 175-0ubuntu9.4
  Candidate: 175-0ubuntu9.4
  Version table:
 *** 175-0ubuntu9.4 0
        500 http://us.archive.ubuntu.com/ubuntu/ precise-updates/main i386 Packages
        100 /var/lib/dpkg/status
     175-0ubuntu9 0
        500 http://us.archive.ubuntu.com/ubuntu/ precise/main i386 Packages

** Affects: udev (Ubuntu)
     Importance: Undecided
         Status: New

** Attachment added: "Timestamped and commented output of udevadm, udevd's log and strace."
   https://bugs.launchpad.net/bugs/1208929/+attachment/3762619/+files/udevadm-udevd-log-strace.txt

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

Title:
  Udev occasionally does not write log priority change messages

Status in “udev” package in Ubuntu:
  New

Bug description:
  "udevadm control --log-priority=XXX" normally causes udevd to write a
  message to syslog indicating it has received SET_LOG_PRIORITY message
  and the resulting (and now current) log priority.

  I expect udevd to consistently write notification messages, but
  occasionally it does not.  Aside, I am uncertain if it has actually
  changed priority in the cases when it fails to write the notification
  messages.  Often, when udevd drops the log change messages, it seems
  to be also dropping other event messages.  So I suspect the failure to
  write messages might not be unique to the SET_LOG_PRIORITY message
  type.

  strace shows udevd has received the signal, but not written the
  message: after receiving some messages, it does not call the time() or
  send() syscalls.

  I suspected udevd might be *not* writing messages when the "new"
  priority is the same as the current priority, e.g. "udevadm control
  --log-priority=debug" twice in a row.  But this is not the case: under
  normal operation udevd does indeed write "change" notifications for
  both udevadm invocations.

  Note, I have disabled rsyslogd's buffered logging
  ($RepeatedMsgReduction off).  Although, given the missing syscalls,
  this seems to be a behaviour of udevd, independent of the syslog
  implementation.

  I have attached output of several invocations of udevdadm, the log
  messages written by udevd and corresponding strace output; with
  timestamps and comments.


  (ubuntu) ~ lsb_release -rd
  Description:    Ubuntu 12.04.2 LTS
  Release:        12.04

  (ubuntu) ~ apt-cache policy udev
  udev:
    Installed: 175-0ubuntu9.4
    Candidate: 175-0ubuntu9.4
    Version table:
   *** 175-0ubuntu9.4 0
          500 http://us.archive.ubuntu.com/ubuntu/ precise-updates/main i386 Packages
          100 /var/lib/dpkg/status
       175-0ubuntu9 0
          500 http://us.archive.ubuntu.com/ubuntu/ precise/main i386 Packages

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