android – Logcat的日志时间戳不按顺序排列

我正在调试数据连接,事情发生的顺序很重要.我在终端中使用带有ADB时间戳的logcat,并收集我稍后分析的小时日志.我遇到的问题是,时间戳有时不是顺序的.由于Logcat是一个循环缓冲区,我不明白为什么会这样.所以,如果时间戳中存在错误或者事件实际上没有按顺序记录,我就会徘徊,我应该参考日志序列而不是时间戳(请参阅第8和第9行转换).有人知道吗？用于获取日志的命令是：

adb logcat -b radio -v time

和日志：

...
09-06 18:32:29.426 D/GSM     (  200): getNitzTimeZone returning America/Detroit
09-06 18:32:29.434 I/AT      (   65): AT(14)< +CGDCONT: 1,"IP","pda.bell.ca","",0
09-06 18:32:29.434 I/AT      (   65): AT(14)< OK
09-06 18:32:29.434 E/RIL     (   65): processRequest: OPERATOR
09-06 18:32:29.434 E/AT      (   65): ---AT+copS=3,0;+copS?;+copS=3,1;+copS?;+copS=3,2;+copS?
09-06 18:32:29.434 I/AT      (   65): AT(14)> AT+copS=3,2;+copS?
09-06 18:32:29.434 D/RILJ    (  200): [UNSL]< UNSOL_DATA_CALL_LIST_CHANGED [DataCallState: { cid: 1,active: 0,type: IP,apn: pda.bell.ca,address:  }]
09-06 18:32:29.434 I/GSM     (  200): NITZ: Setting time of day to Thu Sep 06 18:32:29 EDT 2012 NITZ receive delay(ms): 14 gained(ms): -423 from 12/09/06,22:32:29-16,1
09-06 18:32:29.017 I/AT      (   65): AT(14)< +copS: 0,"Bell",2
09-06 18:32:29.017 I/AT      (   65): AT(14)< +copS: 0,1,2,"302610",2
09-06 18:32:29.017 I/AT      (   65): AT(14)< OK
09-06 18:32:29.017 I/RIL     (   65): swiril_cache_set: updating cache for OPERATOR
09-06 18:32:29.017 E/RIL     (   65): processRequest: GPRS_REGISTRATION_STATE
09-06 18:32:29.017 E/AT      (   65): --- AT+CGREG?
09-06 18:32:29.017 I/AT      (   65): AT(14)> AT+CGREG?
09-06 18:32:29.017 D/RILJ    (  200): [0612]< OPERATOR {Bell,Bell,302610}
09-06 18:32:29.025 I/AT      (   65): AT(14)< +CGREG: 2,"2D8C","067C358F",2
09-06 18:32:29.025 I/AT      (   65): AT(14)< OK
09-06 18:32:29.025 I/RIL     (   65): swiril_cache_set: updating cache for GPRS_REGISTRATION_STATE
09-06 18:32:29.025 E/RIL     (   65): processRequest: REGISTRATION_STATE
09-06 18:32:29.025 E/AT      (   65): --- AT*CNTI=0
09-06 18:32:29.025 I/AT      (   65): AT(14)> AT*CNTI=0
09-06 18:32:29.025 D/RILJ    (  200): [0613]< GPRS_REGISTRATION_STATE {1,2d8c,067c358f,3}
09-06 18:32:29.029 I/AT      (   65): AT(14)< *CNTI: 0,umts
...

解决方法

时间戳不是顺序的,因为Log.i操作在系统内不是原子的.
让我们看看Log.i如何在基本的几个步骤中工作：
1.首先,它获得系统时间
然后使用获得的系统时间格式化字符串
3.应用程序将消息放入传出缓冲区
4.最后,后台线程会不时地将日志数据刷出应用程序上下文(到中央日志记录系统)

想象一下,并行运行两个进程.
运气不好的情况下,调度程序会在完成第1步的过程中暂停您的进程.
然后调度程序将cpu时间给予下一个进程,这也使Log.i有足够的时间来完成它的Log.i作业.
最后,调度程序为我们的进程提供cpu时间来完成日志记录操作.

在此示例中,您可以看到混合时间戳是由非原子Log.i操作和传出日志条目的缓冲引起的.
应用程序无法在每个日志条目之后刷新日志条目,因为在应用程序和日志记录系统之间切换上下文非常非常昂贵的cpu操作.
相反,它缓冲日志条目,当缓冲区已满或经过一段时间后,它会执行日志刷新.这种方法大大提高了性能.

如果您需要订购日志条目,可以在进一步处理之前订购它们.

android – Logcat的日志时间戳不按顺序排列

解决方法

相关文章