How Does ADB Logcat Timestamping Work

Question

I'm trying to figure out when events happen on my AirPad so I'm issuing the logcat command:

adb logcat -v time -d -b radio -b events -b main -b system -b radio

In looking at the timestamps, however, each buffer's first timestamp seems to start immediately after the last time stamp of the buffer before it.

--------- beginning of /dev/log/radio

10-20 19:30:37.878 D/RILD    (   53): Do not switch user to radio

...

10-20 19:30:37.998 D/RIL     (   53): Wait device...

--------- beginning of /dev/log/events

10-20 19:30:39.608 I/boot_progress_start(   54): 9398

...


10-20 19:31:13.998 D/RIL     (   53): Wait device...

--------- beginning of /dev/log/system

10-20 19:31:15.008 D/ConnectivityService(   99): tearing down Mobile networks due to setting

...

10-20 19:32:28.418 V/ActivityManager(   99): Launching: HistoryRecord{408d6a00 com.amazon.kindle/com.amazon.kcp.reader.BookReaderActivity} icicle=null with results=null newIntents=null andResume=true

--------- beginning of /dev/log/main

10-20 19:32:28.428 D/VPU     (   55): VPU: vpu_power_on 01`

So my question is, what do the timestamps represent - do they represent the time when the event occurred? If so, why are they working out this way?

Answer 1

The timestamps are correct.

When specifying multiple buffers, logcat intertwines them all, and prints everything ordered by time. The "beginning of.." lines just indicate where each buffer's first message is; they're not file separators.