How to sync Kernel time and logcat time?

Question

I am working on an Android phone based on the Linux Kernel. I'm using kmsg for kernel logs and adb logcat -v time for platform logs. The problem is Kernel logs shows time from 0.000000 and logcat is showing from the start of system time ( For example, if time on the phone is 10.43.00, it'll show the first log from this time )

Now I am unable to compare events from these 2 logs as the time base ( reference) is different. Can anyone kindly point out how to sync these 2 times?

Etra

Answer 1

Pavan,

Perhaps with you can tag your logcat prints with the time since last boot? This should be closer to the time shown in kmsg.

Time since last boot can be retrieved with elapsedRealtime().

Orate

@willytale:Thanks a lot! It works fine :) But the problem is I need to add elapsedRealtime() into every log! So I checked into logcat code. Time formatting is done in android_log_formatLogLine() in logprint.cpp. But elapsedRealtime() is in java and I dont know how to access it from a cpp file. I am not able to find an equivalent that I can use from this cpp file – Etra

The Android NDK provides a logging API for C/C++: manski.net/2012/05/logging-from-c-on-android – Convalescence

Answer 2

Another solution would be similar to jpg's answer, but in the other direction, redirect the kernel messages into logcat. This is better, because too many logcat messages might overload the serial console (if you have it active).

you can run this in an android shell:

cat /proc/kmsg | while read LINE; do echo '\06kernel\0'$LINE'\0' > /dev/log/main; done

or this in a host shell:

adb shell '(cat /proc/kmsg | while read LINE; do echo \\06kernel\\0$LINE\\0 > /dev/log/main; done)'

The first time you start the command you will see all of the current dmesg messages in one place, but any further messages will be interleaved, when they appear.

and then examine logcat in a different shell. If you examine logcat with -v time, then the kernel messages will contain both the logcat and the kernel timestamps. Of course there may be delays between the two.

Another, even simpler way to see messages interleaved would be:

adb shell '(logcat & cat /proc/kmsg) > /path/to/log/file'

But in this case it's a little harder to identify messages coming from the kernel, and you can't tell how kernel timestamps relate to logcat timestamps.

Suburbia

Answer 3

you can create a single file containing both kernel and platform logs as follows:

$adb shell    
$logcat -v time -f /dev/kmsg | cat /proc/kmsg > /data/klog_plog_log.txt

you can differentiate both the logs using time stamps in the platform logs. And then pull the file to your local drive using

adb pull /data/klog_plog_log.txt > sample.txt

Refer http://jai-tech.blogspot.com/2012/01/taking-kernel-and-platform-logs-of.html . Hope this helps.

Regards, JP

Extensity

Answer 4

The single file method described above is nice but may not always be useful as the input from logcat and kmsg might be delayed due to buffering. So you will most likely see a block of kmsg entries and then a block of logcat entries which might still be interleaved in real time.

That said, you might be able to sync kmsg time and logcat time by looking for device suspend messages in kmsg (grep UTC):

<6>[249485.550811] suspend: exit suspend, ret = 0 (2012-12-27 16:16:46.300872527 UTC)

As you can see those entries in kmsg report the current system wallclock time which can then be synchronized with the kmsg time value. Note however that the kmsg time value does not increase when the device is asleep while the wallclock time obviously does. To that end you will have to resynchronize on the wallclock time on every suspend entry and exit in order to get the correct wallclock time.

Inhabit

Answer 5

I think it can use like this:

adb shell logcat -v time -f /dev/kmsg | adb shell cat /proc/kmsg >sample.txt

Stereochemistry