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?

Solution

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.