can't boot laptop

nass · 12-27-2010, 10:31 AM

heelo everyone,
all of a sudden my laptop decided to not bootup. It stops while loading syslogd. I started up in single user mode and added a few echo statements in rc.syslog so it looks like:

Code:

syslogd_start() {
  if [ -x /usr/sbin/syslogd -a -x /usr/sbin/klogd ]; then
    echo -n "Starting sysklogd daemons:  "
    echo -n "/usr/sbin/syslogd "
    /usr/sbin/syslogd
    # prevent syslogd/klogd race condition on SMP kernels
    echo -n "started syslogd!"
    if ps acx | grep -q udevd ; then
      while [ ! -e /dev/log ] ; do
        sleep 0
        echo -n "caught in the loooooop!"
      done
    else
      sleep 1
    fi
    echo "/usr/sbin/klogd -c 3 -x"
    # '-c 3' = display level 'error' or higher messages on console
    # '-x' = turn off broken EIP translation
    /usr/sbin/klogd -c 3 -x
  fi

after restarting, the last message I see on the bootup screen is:
"Starting sysklogd daemons: /usr/sbin/syslogd"

this means that execution of the script doesn't seem to get past the "/usr/sbin/syslogd" line.
Well at least thats the case in the first 2-3 minutes. Afterwards my screen gets flooded with the next echo I placed "caught in the loooooop!".
Again, stating the obvious, the script reads on and gets caught in the while loop. obviously there is no /dev/log and something must have messed up the execution of syslogd. what could that be it?

Recently I was fiddling around with jackd and trying to setup a jack-rack on my laptop. To do that I had to recompile alsa-driver from scratch in order to include the virtual soundcard driver. I also had to rebuild the mainline kernel to add low-latency (I did not switch to kernel-rt). Overall, I've been running with a custom kernel more than 2 months now and never had a problem with syslogd startup. The new low latency custom kernel is just like the previous one but with only difference the low latency setting. With the low latency kernel I've been using the pc for approx a week and have done 5+ reboots. So the problem appeared now out of nowhere...

What shall I assume? how can I tackle it?
Thank you for your help

EDIT: if I disable rc.syslog and I start the pc, and then start it up, syslogd with execute nicely and quickly as if there was no problem, ever... grrrrr

business_kid · 12-27-2010, 01:57 PM

Edit your bootup line, and add the word init=/bin/bash and boot on that. You have / mounted ro & nothing else. I would then
/sbin/mount -o remount,rw /

Then stop syslogd from starting,
/usr/bin/chmod -x /etc/rc.d/rc.syslog
and reboot.

Then when you're running, figure it out by starting it in a terminal.

nass · 12-29-2010, 08:59 AM

here are my findings:

if I do as you say and then startup the laptop normally, I can start the syslog deamon without a hitch.
outputting debuging info also doesn't show anything out of the ordinary....

for reference here it is:

Quote:

root@starboard:~# cat syslog.log
Allocated parts table for 1024 file descriptors.
Starting.
Called init.
Called allocate_log, nlogs = -1.
cfline(*.info;*.!warn;authpriv.none;cron.none;mail.none;news.none -/var/log/messages)
symbolic name: info ==> 6
symbolic name: warn ==> 4
symbolic name: none ==> 16
symbolic name: authpriv ==> 80
symbolic name: none ==> 16
symbolic name: cron ==> 72
symbolic name: none ==> 16
symbolic name: mail ==> 16
symbolic name: none ==> 16
symbolic name: news ==> 56
leading char in action: /
filename: /var/log/messages
Called allocate_log, nlogs = 0.
cfline(*.warn;authpriv.none;cron.none;mail.none;news.none -/var/log/syslog)
symbolic name: warn ==> 4
symbolic name: none ==> 16
symbolic name: authpriv ==> 80
symbolic name: none ==> 16
symbolic name: cron ==> 72
symbolic name: none ==> 16
symbolic name: mail ==> 16
symbolic name: none ==> 16
symbolic name: news ==> 56
leading char in action: /
filename: /var/log/syslog
Called allocate_log, nlogs = 1.
cfline(*.=debug -/var/log/debug)
symbolic name: debug ==> 7
leading char in action: /
filename: /var/log/debug
Called allocate_log, nlogs = 2.
cfline(authpriv.* -/var/log/secure)
symbolic name: * ==> 255
symbolic name: authpriv ==> 80
leading char in action: /
filename: /var/log/secure
Called allocate_log, nlogs = 3.
cfline(cron.* -/var/log/cron)
symbolic name: * ==> 255
symbolic name: cron ==> 72
leading char in action: /
filename: /var/log/cron
Called allocate_log, nlogs = 4.
cfline(mail.* -/var/log/maillog)
symbolic name: * ==> 255
symbolic name: mail ==> 16
leading char in action: /
filename: /var/log/maillog
Called allocate_log, nlogs = 5.
cfline(*.emerg *)
symbolic name: emerg ==> 0
leading char in action: *
write-all
Called allocate_log, nlogs = 6.
cfline(uucp,news.crit -/var/log/spooler)
symbolic name: crit ==> 2
symbolic name: uucp ==> 64
symbolic name: news ==> 56
leading char in action: /
filename: /var/log/spooler
Opened UNIX socket `/dev/log'.
0: 60 60 X 60 60 60 60 X 60 X X 60 60 60 60 60 60 60 60 60 60 60 60 60 60 FILE: /var/log/messages
1: 1F 1F X 1F 1F 1F 1F X 1F X X 1F 1F 1F 1F 1F 1F 1F 1F 1F 1F 1F 1F 1F 1F FILE: /var/log/syslog
2: 80 80 80 80 80 80 80 80 80 80 80 80 80 80 80 80 80 80 80 80 80 80 80 80 80 FILE: /var/log/debug
3: X X X X X X X X X X FF X X X X X X X X X X X X X X FILE: /var/log/secure
4: X X X X X X X X X FF X X X X X X X X X X X X X X X FILE: /var/log/cron
5: X X FF X X X X X X X X X X X X X X X X X X X X X X FILE: /var/log/maillog
6: 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 1 WALL:
7: X X X X X X X 7 7 X X X X X X X X X X X X X X X X FILE: /var/log/spooler
logmsg: syslog.info<46>, flags 4, from starboard, msg syslogd 1.4.1: restart.
Called fprintlog, logging to FILE /var/log/messages
syslogd: restarted.
Debugging disabled, SIGUSR1 to turn on debugging.
root@starboard:~#

now if I reboot, and start my kernel with init=/bin/bash, i'll end up with the bash prompt. if from then on I start loading one by one the rc.M entries (after remounting rw), syslog will be the 3rd in line to load.
starting /usr/sbin/syslogd -d will NOT output anything - as soon as I press [Enter] i'll just get a new bash prompt. and If I try to load /usr/sbin/syslogd i'll get in the same mess as before. The command will seem to be executed, I won't be able to exit with [Ctrl+C]. and basically I'm stuck there for a few minutes. After that, I get a bash prompt again, but there is no /dev/log...

I'm googling insanely but nothing seems to fit my situation.. let alone no problem between syslog and slackware seems to exist... ad without any output from syslogd -d I'm rather helpless.. any pointers I could get from here on, would be MOST appreciated...

business_kid · 12-30-2010, 04:15 AM

The key check is 'pgrep syslogd' which should return the process number if it is running.

My /dev/log looks this way
dec@genius:~$ ls -l /dev/log
srw-rw-rw- 1 root root 0 2010-12-30 09:46 /dev/log=

try ldd /usr/sbin/syslogd |grep found. This should output missing libs, if you're missing any.

Note also rc.M
# Start the system logger.
if [ -x /etc/rc.d/rc.syslog -a -x /usr/sbin/syslogd -a -d /var/log ]; then
. /etc/rc.d/rc.syslog start
fi

That seems to check that a) rc.syslog is executable; b) /usr/sbin/syslogd is executable; c) the directory /var/log exists and is bootable. Check those.
From rc.syslog:
syslogd_start() {
if [ -x /usr/sbin/syslogd -a -x /usr/sbin/klogd ]; then
echo -n "Starting sysklogd daemons: "
echo -n "/usr/sbin/syslogd "
/usr/sbin/syslogd
# prevent syslogd/klogd race condition on SMP kernels
if ps acx | grep -q udevd ; then
while [ ! -e /dev/log ] ; do
sleep 0
--
fi

Here we can add
d) /usr/sbin/syslogd is executable; e) /usr/sbin/klogd is executable;
Let us know what you find.

nass · 12-30-2010, 10:01 AM

well,
the answer to a) through e) is yes... unfortunately the problem is not here...
the truth is that since the /usr/sbin/syslogd line gets executed it means that all if statements branch towards this command, as expected...

so far I have just commented out the while loop since there is no exit out of it.

ldd returns:

Quote:

root@starboard:~# cat ldd_sys
linux-gate.so.1 => (0xffffe000)
libc.so.6 => /lib/libc.so.6 (0xb773a000)
/lib/ld-linux.so.2 (0xb78c5000)
root@starboard:~#

so no problem here either

When i boot with init=/bin/bash - thats where /usr/sbin/syslogd takes 5 minutes to execute - something must be missing and syslogd doesn't start. I mean if I let the pc boot properly and I run rc.syslogd manually , then syslog will start up properly.
So I tried starting rc.udev before rc.syslog - which is normally loaded afterwards in rc.M - but that didn't help either.

Perhaps I should also note that I'm using ULOG to log firewall msgs in a separate file (instead of flooding into /var/log/messages). But i've been using ulog for the past 2 months now and I didn't have a problem.

finally I can output strace on /usr/sbin/syslogd command so that we can see what's going on.

Quote:

root@starboard:~# cat strace-sys
execve("/usr/sbin/syslogd", ["/usr/sbin/syslogd"], [/* 7 vars */]) = 0
brk(0) = 0x804f000
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb774d000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=156133, ...}) = 0
mmap2(NULL, 156133, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7726000
close(3) = 0
open("/lib/libc.so.6", O_RDONLY) = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\340l\1\0004\0\0\0<"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=1649149, ...}) = 0
mmap2(NULL, 1452296, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb75c3000
mprotect(0xb771f000, 4096, PROT_NONE) = 0
mmap2(0xb7720000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x15c) = 0xb7720000
mmap2(0xb7723000, 10504, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb7723000
close(3) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb75c2000
set_thread_area({entry_number:-1 -> 6, base_addr:0xb75c26c0, limit:1048575, seg_32bit:1, contents:0, read_exec_only:0, limit_in_pages:1, seg_not_present:0, useable:1}) = 0
mprotect(0xb7720000, 8192, PROT_READ) = 0
mprotect(0xb776b000, 4096, PROT_READ) = 0
munmap(0xb7726000, 156133) = 0
getpid() = 917
chdir("/") = 0
brk(0) = 0x804f000
brk(0x8070000) = 0x8070000
open("/var/run/syslogd.pid", O_RDONLY) = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=4, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb774c000
read(3, "914\n"..., 4096) = 4
close(3) = 0
munmap(0xb774c000, 4096) = 0
kill(914, SIG_0) = -1 ESRCH (No such process)
rt_sigaction(SIGTERM, {0x8049790, [TERM], SA_RESTART}, {SIG_DFL, [], 0}, 8) = 0
clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0xb75c2728) = 918
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigaction(SIGCHLD, NULL, {SIG_DFL, [], 0}, 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
nanosleep({300, 0}, 0xbfa7dc44) = ? ERESTART_RESTARTBLOCK (To be restarted)
--- SIGCHLD (Child exited) @ 0 (0) ---
restart_syscall(<... resuming interrupted call ...>) = 0
# here is where the process halts for about 5 mins #
exit_group(1) = ?
root@starboard:~#

it looks like the child process that is forked in order for syslogd to start in the background exits . I'm not an expect or linux signals but I guess that shouldn't be happening... should it?

business_kid · 12-31-2010, 03:09 AM

You could always try the m$ solution, in your case

upgradepkg --reinstall sysklogd-1.4.1-i486-10

I would also check user & group (root:root) and writability of everywhere and every file it uses.

The trace is good but I'm no expert either. I would email the maintainer with that trace, however.

nass · 01-02-2011, 12:45 PM

nope reinstalling the package didn't fix the problem.
the files accessed by the deamon that I see on the strace as well as its conf are all with the normal permissions.

I changed the rc.syslog command to

Quote:

/usr/sbin/syslogd -d &

and now during boot I can see the debug output popping up. Of course it takes some time to load syslogd after the command is called (in fact the debug output is seen much after the klogd command has been run and rc.syslog has exited) but by the time I get the login prompt syslogd is up and running too.

I will try to gather some more info and contact the maintainer, but I want to ask: Is there a problem with the fact that syslogd starts up after klogd and other applications, too? are there applications that will not log at all if they don't find /dev/log existing during their startup?

Thank you for your help