A race condition in sysvinit exists where the utmp entry that getty needs to update may not be written by sysvinit by the time getty accesses it. This happens more often (and almost exclusively) on uniprocessor systems due to the way time-slicing is done by the kernel. Reproducible: Sometimes Steps to Reproduce: Using the linux text console: 1. Log-onto tty1 2. Log-off tty1 3. Log-on tty1 again 4. Log-on tty2 5. Log-off tty1 6. do a $ who -a /var/run/utmp Actual Results: system boot Aug 9 13:43 Aug 9 13:43 2722 id=rc term=0 exit=0 run-level 3 Aug 9 13:43 last=S Aug 9 13:43 3809 id=l3 term=0 exit=0 Aug 9 13:44 4413 id=c1 Aug 9 13:43 4399 id=c2 LOGIN tty3 Aug 9 13:43 4349 id=c3 LOGIN tty4 Aug 9 13:43 4350 id=c4 LOGIN tty5 Aug 9 13:43 4355 id=c5 LOGIN tty6 Aug 9 13:43 4356 id=c6 root - tty1 Aug 9 13:43 00:07 4375 root - tty2 Aug 9 13:44 . 4399 LOGIN tty1 Aug 9 13:44 4413 id=1 Expected Results: Same as above, but without the multiple entries for tty1. Also note that the ttys are now out-of-order. This is a side-effect of this bug. This race condition exists because when the getty is spawned from init, it is assumed that the return from the function that spawns the getty will happen faster than it takes for getty to start and update the utmp file. On a multiprocessor system, this is likely to happen because init and getty will run in parallel. However, on a uniprocessor system, due to the way that Linux schedules subprocesses, getty will have the processor for enough of a timeslice that the function return in init will not happen until after getty has proceeded to update utmp. Because getty expects that init has written the initial utmp entry, and the entry doesn't exist, getty creates another entry. These bogus extra entries are seen as extra logins by "uptime" and "top" and so the number of logins becomes incorrect as a result. Note that to view all the entries in utmp, you MUST specify the filename as indicated in the "steps to reproduce" above. There is cruft in "who" that filters out the bogus entries when executed normally (this actually just hides this bug and may actually have been added because nobody could figure out why this was happening). Attached (or, rather, will be attached in a moment) is a fix that moves the utmp write in init to an appropriate place where the race condition will not occur. I have tested this patch on my main system for several weeks and it has not had any ill effects, and has completely fixed the problem.
Created attachment 127383 [details, diff] Proposed patch for sysvinit race condition Patch was applied to sys-apps/sysvinit-2.86-r8 after standard Gentoo patching takes place.
Confirmed (used tty2 & 3 instead of 1 & 2): Aug 9 20:04 916 id=si term=0 exit=0 system boot Aug 9 20:04 Aug 9 20:04 2120 id=rc term=0 exit=0 run-level 3 Aug 9 20:04 last=S Aug 9 20:04 4003 id=l3 term=0 exit=0 chainsaw - tty1 Aug 9 20:05 02:57 4899 Aug 9 23:02 6478 id=c2 Aug 9 23:01 6445 id=c3 LOGIN tty4 Aug 9 20:04 4902 id=c4 LOGIN tty5 Aug 9 20:04 4905 id=c5 LOGIN tty6 Aug 9 20:04 4906 id=c6 root - tty2 Aug 9 23:02 . 6460 root - tty3 Aug 9 23:02 . 6445 LOGIN tty2 Aug 9 23:02 6478 id=2 System info: Portage 2.1.3.3 (default-linux/ppc/ppc64/2007.0/64bit-userland/970, gcc-4.1.2, glibc-2.6-r0, 2.6.23-rc2-g4a2a4df7-dirty ppc64) ================================================================= System uname: 2.6.23-rc2-g4a2a4df7-dirty ppc64 PPC970FX, altivec supported Gentoo Base System release 1.12.10 Timestamp of tree: Unknown dev-lang/python: 2.4.4-r4 dev-python/pycrypto: 2.0.1-r6 sys-apps/sandbox: 1.2.18.1 sys-devel/autoconf: 2.13, 2.61-r1 sys-devel/automake: 1.4_p6, 1.6.3, 1.7.9-r1, 1.8.5-r3, 1.9.6-r2, 1.10 sys-devel/binutils: 2.17.50.0.17 sys-devel/gcc-config: 1.3.16 sys-devel/libtool: 1.5.24 virtual/os-headers: 2.6.22-r2 ACCEPT_KEYWORDS="ppc64 ~ppc64" AUTOCLEAN="yes" CBUILD="powerpc64-unknown-linux-gnu" CFLAGS="-O2 -pipe -mcpu=970 -mtune=970 -mabi=altivec" CHOST="powerpc64-unknown-linux-gnu" CONFIG_PROTECT="/etc /usr/share/X11/xkb" CONFIG_PROTECT_MASK="/etc/env.d /etc/gconf /etc/revdep-rebuild /etc/terminfo" CXXFLAGS="-O2 -pipe -mcpu=970 -mtune=970 -mabi=altivec" DISTDIR="/usr/portage/distfiles" FEATURES="autoconfig distlocks metadata-transfer sandbox sfperms strict unmerge-orphans userfetch" GENTOO_MIRRORS="http://distfiles.gentoo.org http://distro.ibiblio.org/pub/linux/distributions/gentoo" LDFLAGS="-Wl,--as-needed" MAKEOPTS="-j2" PKGDIR="/usr/portage/packages" PORTAGE_RSYNC_OPTS="--recursive --links --safe-links --perms --times --compress --force --whole-file --delete --delete-after --stats --timeout=180 --exclude=/distfiles --exclude=/local --exclude=/packages --filter=H_**/files/digest-*" PORTAGE_TMPDIR="/var/tmp" PORTDIR="/cvs/gentoo-x86" PORTDIR_OVERLAY="/usr/local/portage" SYNC="rsync://rsync.gentoo.org/gentoo-portage" USE="X a52 aac aalib acl adplug alsa altivec audacious avahi bash-completion berkdb bitmap-fonts cairo cddb cdparanoia chardet cli cracklib crypt cups dbus dri dts dv dvd enca encode exif fbcon ffmpeg fftw flac fortran ftp gdbm gif glitz gnutls gpm gtk hal hpn iconv idle ipv6 isdnlog jbig jpeg libcaca libnotify lzo mad md5sum midi modplug mp2 mp3 mp4 mplayer mudflap musepack ncurses nls nptl nptlonly ogg opengl openmp pam pcre perl plugins png pnm ppc64 ppds pppd python quicktime readline reflection rtc sdl session sid sndfile speex spell spl srt srv ssl startup-notification svg tga theora tiff trayicon truetype truetype-fonts tta type1-fonts unicode vorbis vorbis-psy wavpack wma xcomposite xhtml xinerama xml xorg xv xvid zlib" ALSA_CARDS="emu10k1" ALSA_PCM_PLUGINS="adpcm alaw asym copy dmix dshare dsnoop empty extplug file hooks iec958 ioplug ladspa lfloat linear meter mulaw multi null plug rate route share shm softvol" ELIBC="glibc" INPUT_DEVICES="keyboard mouse evdev" KERNEL="linux" LCD_DEVICES="bayrad cfontz cfontz633 glk hd44780 lb216 lcdm001 mtxorb ncurses text" LIRC_DEVICES="livedrive_midi" USERLAND="GNU" VIDEO_CARDS="radeon" Unset: CTARGET, EMERGE_DEFAULT_OPTS, INSTALL_MASK, LANG, LC_ALL, LINGUAS, PORTAGE_COMPRESS, PORTAGE_COMPRESS_FLAGS, PORTAGE_RSYNC_EXTRA_OPTS
To confirm, the patch resolves the issue: Aug 9 23:27 910 id=si term=0 exit=0 system boot Aug 9 23:27 Aug 9 23:28 2095 id=rc term=0 exit=0 run-level 3 Aug 9 23:28 last=S Aug 9 23:28 4033 id=l3 term=0 exit=0 chainsaw - tty1 Aug 9 23:28 00:06 5340 LOGIN tty2 Aug 9 23:34 5711 id=c2 root - tty3 Aug 9 23:33 . 5678 LOGIN tty4 Aug 9 23:28 5343 id=c4 LOGIN tty5 Aug 9 23:28 5344 id=c5 LOGIN tty6 Aug 9 23:28 5345 id=c6 This is after repeating the instructions 4 times. Previously I saw the bug occur in the second run. I would recommend that this patch be applied.
Fixed, thanks! BTW, this gets my vote for Best Reported Bug of 2007 :)
