死亡通知与进程异常退出;ANR与进程重启后状态跟之前不对

通常情况,分析 问题总会把关注点放在逻辑上,而不会从系统的角度来考虑.

如果是系统原因导致的,不结合操作系统知识,是理解不到的, 这也是学习操作系统知识应该注意的方面,

我们不会去写操作系统,但是正常状态,异常状态对我们应用,进程会有什么影响,这种正向思维, 对分析bug时的反向思维很有帮助.

可以通过分析log的实践方式来学习OS

通过Log 多个地方可以看到进程有重启的迹象

例子:音乐播放进程在通话结束后没有恢复,只有之前的暂停。

CallManager request audio focus 之后有去 abadon focus

./sys_log:44119:08-28 16:37:29.870   872   872 V Telecom : CallAudioManager: requestAudioFocusAndSetMode : stream: STEAM_NONE -> STREAM_RING, mode: MODE_RINGTONE

./sys_log:44120:08-28 16:37:29.872   872   872 I Telecom : CallAudioManager: requestAudioFocusAndSetMode : requesting stream: STEAM_NONE -> STREAM_RING

./sys_log:45692:08-28 16:37:48.051   872  4041 V Telecom : CallAudioManager: requestAudioFocusAndSetMode : stream: STREAM_RING -> STREAM_VOICE_CALL, mode: MODE_IN_CALL

./sys_log:45693:08-28 16:37:48.054   872  4041 I Telecom : CallAudioManager: requestAudioFocusAndSetMode : requesting stream: STREAM_RING -> STREAM_VOICE_CALL

./sys_log:46366:08-28 16:37:53.143   872  4041 V Telecom : CallAudioManager: requestAudioFocusAndSetMode : stream: STREAM_VOICE_CALL -> STREAM_VOICE_CALL, mode: MODE_IN_CALL

./sys_log:46472:08-28 16:37:53.892   872  4041 V Telecom : CallAudioManager: requestAudioFocusAndSetMode : stream: STREAM_VOICE_CALL -> STREAM_VOICE_CALL, mode: MODE_IN_CALL

./sys_log:46576:08-28 16:37:55.382   872   872 I Telecom : CallAudioManager: reset audio system before abandonAudioFocus

./sys_log:46582:08-28 16:37:55.402   872   872 V Telecom : CallAudioManager: abandoning audio focus

./sys_log:46585:08-28 16:37:55.409   872   872 I Telecom : CallAudioManager: after abandoning audio focus, mFlightModeOn = false

仔细看 Music 的进程号有变化，从4440 --> 6091 ---> 6770

        Line 15: ./main_log:20510:08-28 16:37:30.008  6770  6770 V MusicService: AudioFocus: received AUDIOFOCUS_LOSS_TRANSIENT

Line 53: ./main_log.1:18046:08-28 16:31:28.642  4440  4440 V MusicService: AudioFocus: received AUDIOFOCUS_GAIN
Line 83: ./main_log.1:105866:08-28 16:33:43.078  6091  6091 V MusicService: AudioFocus: received AUDIOFOCUS_LOSS_TRANSIENT
Line 116: ./main_log.1:140495:08-28 16:35:10.487  6770  6770 V MusicService: AudioFocus: received AUDIOFOCUS_LOSS_TRANSIENT
Line 124: ./main_log.1:166420:08-28 16:35:37.248  6770  6770 V MusicService: AudioFocus: received AUDIOFOCUS_GAIN
Line 144: ./main_log.1:180848:08-28 16:36:08.586  6770  6770 V MusicService: AudioFocus: received AUDIOFOCUS_LOSS_TRANSIENT
Line 160: ./main_log.1:203346:08-28 16:36:36.919  6770  6770 V MusicService: AudioFocus: received AUDIOFOCUS_GAIN
Line 208: ./main_log.2:79524:08-28 16:27:51.657  4440  4440 V MusicService: AudioFocus: received AUDIOFOCUS_LOSS_TRANSIENT
Line 217: ./main_log.2:110043:08-28 16:28:30.685  4440  4440 V MusicService: AudioFocus: received AUDIOFOCUS_GAIN
Line 234: ./main_log.2:139840:08-28 16:29:15.196  4440  4440 V MusicService: AudioFocus: received AUDIOFOCUS_LOSS_TRANSIENT
Line 237: ./main_log.2:149687:08-28 16:29:30.890  4440  4440 V MusicService: AudioFocus: received AUDIOFOCUS_GAIN
Line 256: ./main_log.2:203258:08-28 16:30:59.071  4440  4440 V MusicService: AudioFocus: received AUDIOFOCUS_LOSS_TRANSIENT

再看MediaFocusControl 有死亡通知，也是三次。

./main_log:29155:08-28 16:37:37.372   872   884 W MediaFocusControl:   AudioFocus   audio focus client died

./main_log:29206:08-28 16:37:37.383   872   884 I MediaFocusControl: AudioFocus  removeFocusStackEntry(): removing entry for android.os.BinderProxy@564f861

./main_log.1:49337:08-28 16:32:08.072   872  1506 W MediaFocusControl:   AudioFocus   audio focus client died

./main_log.1:49341:08-28 16:32:08.073   872  1506 I MediaFocusControl: AudioFocus  removeFocusStackEntry(): removing entry for android.os.BinderProxy@2d14a51

./main_log.1:115701:08-28 16:33:52.660   872  1030 W MediaFocusControl:   AudioFocus   audio focus client died

./main_log.1:115805:08-28 16:33:52.694   872  1030 I MediaFocusControl: AudioFocus  removeFocusStackEntry(): removing entry for android.os.BinderProxy@877514d

event.log:

因为music, MediaProvider是相同的share id,系统是去杀MediaProvider所在的android.process.media，同时把music杀了

event log show  music iskilled：

./events_log:2888:08-2816:34:06.043   872  6058 I am_kill : [0,6661,com.android.music,5,dependson provider com.android.providers.media/.MediaProvider in dying procandroid.process.media]

./events_log:3729:08-2816:37:37.068   872  6061 I am_kill : [0,6770,com.android.music,2,dependson provider com.android.providers.media/.MediaProvider in dying procandroid.process.media]

./events_log:3909:08-2816:38:01.799   872  4041 I am_kill : [0,7981,com.android.music,5,dependson provider com.android.providers.media/.MediaProvider in dying procandroid.process.media]

 

Kernel log:

 adj 8: low priority process

[109:display_idle_de][name:lowmemorykiller&]lowmemorykiller: Killing'd.process.media' (2139), adj 8, score_adj 470

[109:display_idle_de][name:lowmemorykiller&]lowmemorykiller:Killing 'd.process.media' (6807), adj 2, score_adj 117,

[74:kswapd0][name:lowmemorykiller&]lowmemorykiller:Killing 'd.process.media' (8021), adj 8, score_adj 470