[SOLVED] device logging history - How to read

[jaywalker]

Now that output produced by device discovery/plugging/unplugging is no longer captured in /var/log/messages has anyone devised a simple method to archive the dmesg file on shutdown so that some history can be preserved?

It would be really nice if the relative timestamps could also be converted to absolute date/time so that some human-readable context could be preserved, but this could maybe be done manually on the next startup.

Any ideas?

UPDATE.
As of yesterday's updates (1 April;-) the recording of kernel boot messages in the /var/log/messages file has been restored. The madness is over.

[junk_no_spam]

Now that output produced by device discovery/plugging/unplugging is no longer captured in /var/log/messages

Don't tell my Mageia release 2 (Cauldron) for x86_64 that. I just now plugged in a usb stick and saw messages about sdg and running dmesg showed activity.

has anyone devised a simple method to archive the dmesg file on shutdown so that some history can be preserved?

Supposedly /sbin/halt.pre and /sbin/halt.local scripts can be created by root to do whatever they like.
More information found in https://bugs.mageia.org/show_bug.cgi?id=3744

[jaywalker]

Hmm, perhaps I should get my Mageia release 2 Cauldron for x86_64 to talk to yours for some advice :~) I am getting no kernel messages whatsoever (OK I haven't analysed them all for provenance) related to device discovery and the like in my /var/log/messages.

I wanted to check to see when a problem with an internal SATA drive had first occurred and what messages were emitted when it was working OK. I found ... nothing. Only dmesg had info about the problem in the current session, so nothing to compare it to from last week.

I will watch the progress of Bug 3744 with interest as it looks like the only way to bodge the fix I need. In the meantime I guess I'll just have to teach myself advanced shell programming so I can have something to the job the distro used to do.

[doktor5000]

So you say that dmesg output is not contained anymore in /var/log/messages nor syslog?

[jaywalker]

Yes, I think so. Wasn't it removed some time last month? It was definitely in Alpha2 because I was troubleshooting one of those "atomic scheduler" bugs on a netbook, but when I went hunting for drive discovery information on a Beta2 install (dating from Feb 24) the cupboard was bare.

Oh, syslog. Didn't know about that one - I thought everything was in messages. I'll take a look now.

UPDATE;
OK, syslog is a smidgin larger than messages - about 18k. From a cursory scan it contains mostly the same thing as messages - including the (almost) complete dearth of ata3 messages I was looking for.

[junk_no_spam]

So you say that dmesg output is not contained anymore in /var/log/messages nor syslog?

You can have the first part or your question answered here.
https://bugs.mageia.org/show_bug.cgi?id=4131

[junk_no_spam]

I will watch the progress of Bug 3744 with interest as it looks like the only way to bodge the fix I need.

I would think you do not have to wait for bug resolution . I ran the attached regression test script not too long ago and one of the /sbin scripts does execute on shutdown. I just forget which.

In the meantime I guess I'll just have to teach myself advanced shell programming

It would depend on what you want done. Down and dirty would be a simple "dmesg >> /some/where/dmesg.log" in the /sbin/script
and reboot. /some/where/dmesg.log should have dmesg contents. IIRC dmesg contents are x number of lines before the first line disappears.

As for shell programming I find http://tldp.org/LDP/abs/html/index.html helpful.

.

so I can have something to the job the distro used to do.

Hopefully https://bugs.mageia.org/show_bug.cgi?id=4131 will get a resolution pretty soon.

[jaywalker]

Hopefully https://bugs.mageia.org/show_bug.cgi?id=4131 will get a resolution pretty soon.

I wish I could do more than hope. When I read things like this in the bug thread ;

Code: Select all

Do you reckon we should have dmesg output in /var/log/messages? Or is it better to have it in /var/log/dmesg as it is now

it makes me think that I am the only one screaming "No-o-o-o-o! This new way is worse than useless!". On the other hand, when the steam stops coming out of my ears, I can understand that someone unfamiliar with flakey hardware and intermittent faults, someone who always finds the causes of problems by instinct or experience, that person may well have little need for a history of their kernel's performance and activity over an extensive period. Either that or they get the info some other way which i have yet to discover.

As for shell programming I find http://tldp.org/LDP/abs/html/index.html helpful.

Thank you for that. I used to learn new programming languages just for fun, back in the day when I could:-) For some reason I have never been able to get comfortable with bash - came to it too late I suppose, but I'll keep trying.

Down and dirty would be a simple "dmesg >> /some/where/dmesg.log" in the /sbin/script and reboot.

Yeah, I was thinking of starting there. What I need to do is replace the relative timestamps with absolute date/time in the dmesg dump and merge this on each shutdown with the "messages" log so that I can restore some context to the events. Even if I can achieve this I may still lose some info from dmesg if it overflows its buffer in the lifetime of a session. At least it will be better than nothing and the effort will be worth it the next time I go problem hunting.

[junk_no_spam]

<snip, snip>
it makes me think that I am the only one screaming "No-o-o-o-o! This new way is worse than useless!".

I hear that. I wanted to shout at him, but he is spending his time making large contributions to Mageia.

As for shell programming I find http://tldp.org/LDP/abs/html/index.html helpful.

Thank you for that. I used to learn new programming languages just for fun, back in the day when I could:-) For some reason I have never been able to get comfortable with bash - came to it too late I suppose, but I'll keep trying.
What I need to do is replace the relative timestamps with absolute date/time in the dmesg dump .

Here is a quick untested kludge to play with.

save it as dmesg_dump
chmod +x dmesg_dump
$PWD/dmesg_dump

This should give you something to start hacking around with.

Code: Select all

#!/bin/bash

_dm_fn=/var/log/dmesg
_dm_birth=$(stat --format=%W $_dm_fn)

while read -r line; do
  _char2=${line:1:1}
  if [ "$_char2" = " " ] ; then
    _shift=2
  else
    _shift=1
  fi
  set -- $(IFS='[.] ';echo $line)
  _s=$1
  _sec=$(echo "$_s + $_dm_birth" | bc)
  _date=$(date --date="@$_sec"  +'%b %a %H:%M:%S')
  set -- $(echo $line)
  shift $_shift
  line="$@"
  echo "$_date $line"
done < $_dm_fn


I can recommend doing a man stat, man date. To understand the set command
man bash followed with
/ set \[
That is slash space space set space backslash left bracket. The / is used by less to search in the man page. q to quit.
To understand IFS, man bash again and do a
/Word Splitting

[doktor5000]

@jaywalker: If you know what you're looking for (a string or device name or something like that) than just do

Code: Select all

grep -Ri foo /var/log

(grepping recursively and non-case-sensitively for the string "foo" below /var/log) and supplement this for the older, already-logrotated files, which are compressed now, with

Code: Select all

zgrep -Ri foo /var/log

everything as root.

[jaywalker]

Ah, lateral thinking. That one passed me by. I should have thought of searching all of the logs. I'll give it a whirl now to see if I can find past references to "ata3" which should give me the info about the sda1 failure I had on Sunday. zgrep is new to me but I'm glad somebody thought of it

The / is used by less to search in the man page.

That's another incredibly useful tip I learned tonight. Thanks to you both.

UPDATE
OK Dok, that worked as well as can be expected. It tells me that the information from Sunday has gone forever. From memory the failure of the drive was something to do with DMA access and I recall that over a period (of some minutes I think) the system was trying successively slower DMA speeds (from 133 to 33MHz and possibly one of the slower modes). The information from syslog and messages is the same and was produced by udevd on Sunday afternoon while I was trying to mount sda1.

I'll have to wait a bit to try the zgrep version as none of the logs is old enough yet to have been rotated.