I meet a phone reset problem when I moving out of WiFi connection coverage.
Looks like Android system is not strong enough when there are many market APPs try to call to ConnectivityManager API.
I dump bugreport and found the below result:
// System_server receive incoming binder transactions but wait the lock which held by ConnectivityThread and looks like a lot of market APPs are accessing ConnectivityManager API and cause binder full.
11-24 17:58:05.191 4566 4566 I binder_sample: [android.net.IConnectivityManager,3,131,com.htc.htcadaptivesound,26]
11-24 17:58:05.191 26093 26093 I binder_sample: [android.net.IConnectivityManager,3,338,com.tencent.mm,67]
pending transaction 34312987: ffffffd2ad97b280 from 26093:26093 to 3336:0 code 3 flags 10 pri 0:120 r1 node 64996 size 76:0 data ffffff80178027c0
11-24 17:58:05.194 24582 24582 I binder_sample: [android.net.IConnectivityManager,3,141,com.autonavi.minimap,28]
incoming transaction 34312519: ffffffd1e5abfb00 from 24582:24796 to 3336:4617 code 3 flags 10 pri 0:120 r1 node 64996 size 76:0 data ffffff8017805890
pending transaction 34312651: ffffffd2a1e84980 from 24582:24746 to 3336:0 code 3 flags 10 pri 0:120 r1 node 64996 size 76:0 data ffffff8017800ac0
11-24 17:58:05.194 29204 29204 I binder_sample: [android.net.IConnectivityManager,3,119,com.htcmarket:connect,23]
pending transaction 34313012: ffffffd1fe8a7f00 from 29204:29204 to 3336:0 code 3 flags 10 pri 0:120 r1 node 64996 size 76:0 data ffffff8017802a98
11-24 17:58:05.196 28340 28340 I binder_sample: [android.net.IConnectivityManager,3,154,com.youdao.dict:core,30]
incoming transaction 34312525: ffffffd205900100 from 28340:28340 to 3336:4579 code 3 flags 10 pri 0:120 r1 node 64996 size 76:0 data ffffff8017805de8
pending transaction 34313044: ffffffd254527100 from 28340:5879 to 3336:0 code 3 flags 10 pri 0:120 r1 node 64996 size 76:0 data ffffff8017806e28
11-24 17:58:05.198 15506 15506 I binder_sample: [android.net.IConnectivityManager,3,165,com.netease.pushservice.core.NetEasePus,33]
11-24 17:58:05.223 3239 3239 I binder_sample: [android.net.IConnectivityManager,3,175,com.xiaohaizi.ui
ushservice,35]
pending transaction 34312661: ffffffd1e60e5d00 from 3239:3434 to 3336:0 code 3 flags 10 pri 0:118 r1 node 64996 size 76:0 data ffffff8017800cf0
11-24 17:58:05.224 21153 21153 I binder_sample: [android.net.IConnectivityManager,3,164,com.qiyi.video,32]
pending transaction 34313000: ffffffd2ad97bf80 from 21153:21153 to 3336:0 code 3 flags 10 pri 0:120 r1 node 64996 size 76:0 data ffffff8017802868
11-24 17:58:05.229 23061 23061 I binder_sample: [android.net.IConnectivityManager,3,141,com.youdao.dict,28]
pending transaction 34312699: ffffffd247530700 from 23061:23061 to 3336:0 code 3 flags 10 pri 0:120 r1 node 64996 size 76:0 data ffffff8017804f40
11-24 17:58:05.229 2423 2423 I binder_sample: [android.net.IConnectivityManager,3,143,com.koudai.weidian.buyer,28]
pending transaction 34312710: ffffffd1d87bbe00 from 2423:2423 to 3336:0 code 3 flags 10 pri 0:120 r1 node 64996 size 76:0 data ffffff80178045f0
11-24 17:58:05.232 19738 19738 I binder_sample: [android.net.IConnectivityManager,3,161,com.tencent.mm:exdevice,32]
pending transaction 34312725: ffffffd205900400 from 19738:19738 to 3336:0 code 3 flags 10 pri 0:120 r1 node 64996 size 76:0 data ffffff8017801580
11-24 17:58:05.220 22388 22388 I binder_sample: [android.net.IConnectivityManager,3,137,com.ximalaya.ting.android,27]
pending transaction 34312853: ffffffd1e9719b00 from 22388:22388 to 3336:0 code 3 flags 10 pri 0:120 r1 node 64996 size 76:0 data ffffff8017801f30
// Phone receive incoming binder transaction and attempt bind to system_server but failed due to system_server binder threads full
proc 4211
outgoing transaction 34312648: ffffffd260191500 from 4211:22509 to 3336:0 code 15 flags 10 pri 0:120 r1
incoming transaction 34312647: ffffffd260191380 from 17297:17297 to 4211:22509 code 48 flags 10 pri 0:120 r1 node 91723 size 92:0 data ffffff801ce000b8
outgoing transaction 34312688: ffffffd285972100 from 4211:4224 to 3336:0 code 15 flags 10 pri 0:120 r1
incoming transaction 34312684: ffffffd21079af80 from 4053:4351 to 4211:4224 code 48 flags 10 pri 0:120 r1 node 91723 size 92:0 data ffffff801ce00170
outgoing transaction 34312690: ffffffd2a1e84680 from 4211:4815 to 3336:0 code 15 flags 10 pri 0:120 r1
incoming transaction 34312686: ffffffd2a1e84d00 from 24021:5865 to 4211:4815 code 11 flags 10 pri 0:120 r1 node 81160 size 80:0 data ffffff801ce002e0
…
outgoing transaction 34313029: ffffffd25dd92e80 from 4211:5517 to 3336:0 code 2c flags 10 pri 0:120 r1
incoming transaction 34313005: ffffffd1fe8a7b80 from 4031:5068 to 4211:5517 code 3 flags 10 pri 0:120 r1 node 81160 size 116:0 data ffffff801ce010c8
outgoing transaction 34313089: ffffffd2649a3e00 from 4211:4493 to 3336:0 code 1 flags 10 pri 0:120 r1 HwBinder:4211_1
// Finally, ConnectivityThread attempt bind to phone but failed due to phone binder threads full
proc 3336
outgoing transaction 34313019: ffffffd27d657080 from 3336:3921 to 4211:0 code 1b flags 10 pri 0:120 r1
And from call stack below, it looks NetworkPolcyService will call to SubscriptionManager API which will call to SettingsProvider to get default subscription. This behavior will cause a lot of IPC transaction between phone process and system server process and looks like cause system binder thread full.
"ConnectivityThread" prio=5 tid=72 Native
| group="main" sCount=1 dsCount=0 flags=1 obj=0x1641dcf8 self=0x74d3784e00
| sysTid=3921 nice=0 cgrp=default sched=0/0 handle=0x74cd5f64f0
| state=S schedstat=( 1546261457 1528895360 4782 ) utm=116 stm=38 core=0 HZ=100
| stack=0x74cd4f4000-0x74cd4f6000 stackSize=1037KB
| held mutexes=
at android.os.BinderProxy.transactNative(Native method)
at android.os.BinderProxy.transact(Binder.java:756)
at com.android.internal.telephony.ISub$Stub$Proxy.getActiveSubIdList(ISub.java:923)
at android.telephony.SubscriptionManager.getActiveSubscriptionIdList(SubscriptionManager.java:1249)
at com.android.server.net.NetworkPolicyManagerService.isTemplateRelevant(NetworkPolicyManagerService.java:1513)
at com.android.server.net.NetworkPolicyManagerService.updateNotificationsNL(NetworkPolicyManagerService.java:1451)
at com.android.server.net.NetworkPolicyManagerService$14.onReceive(NetworkPolicyManagerService.java:1745)
- locked <0x0ec410d0> (a java.lang.Object)
- locked <0x01913893> (a java.lang.Object)
at com.android.server.net.NetworkPolicyManagerService$21.onLost(NetworkPolicyManagerService.java:930)
at android.net.ConnectivityManager$CallbackHandler.handleMessage(ConnectivityManager.java:2770)
at android.os.Handler.dispatchMessage(Handler.java:105)
at android.os.Looper.loop(Looper.java:180)
at android.os.HandlerThread.run(HandlerThread.java:65)
Looks like Android system is not strong enough when there are many market APPs try to call to ConnectivityManager API.
I dump bugreport and found the below result:
// System_server receive incoming binder transactions but wait the lock which held by ConnectivityThread and looks like a lot of market APPs are accessing ConnectivityManager API and cause binder full.
11-24 17:58:05.191 4566 4566 I binder_sample: [android.net.IConnectivityManager,3,131,com.htc.htcadaptivesound,26]
11-24 17:58:05.191 26093 26093 I binder_sample: [android.net.IConnectivityManager,3,338,com.tencent.mm,67]
pending transaction 34312987: ffffffd2ad97b280 from 26093:26093 to 3336:0 code 3 flags 10 pri 0:120 r1 node 64996 size 76:0 data ffffff80178027c0
11-24 17:58:05.194 24582 24582 I binder_sample: [android.net.IConnectivityManager,3,141,com.autonavi.minimap,28]
incoming transaction 34312519: ffffffd1e5abfb00 from 24582:24796 to 3336:4617 code 3 flags 10 pri 0:120 r1 node 64996 size 76:0 data ffffff8017805890
pending transaction 34312651: ffffffd2a1e84980 from 24582:24746 to 3336:0 code 3 flags 10 pri 0:120 r1 node 64996 size 76:0 data ffffff8017800ac0
11-24 17:58:05.194 29204 29204 I binder_sample: [android.net.IConnectivityManager,3,119,com.htcmarket:connect,23]
pending transaction 34313012: ffffffd1fe8a7f00 from 29204:29204 to 3336:0 code 3 flags 10 pri 0:120 r1 node 64996 size 76:0 data ffffff8017802a98
11-24 17:58:05.196 28340 28340 I binder_sample: [android.net.IConnectivityManager,3,154,com.youdao.dict:core,30]
incoming transaction 34312525: ffffffd205900100 from 28340:28340 to 3336:4579 code 3 flags 10 pri 0:120 r1 node 64996 size 76:0 data ffffff8017805de8
pending transaction 34313044: ffffffd254527100 from 28340:5879 to 3336:0 code 3 flags 10 pri 0:120 r1 node 64996 size 76:0 data ffffff8017806e28
11-24 17:58:05.198 15506 15506 I binder_sample: [android.net.IConnectivityManager,3,165,com.netease.pushservice.core.NetEasePus,33]
11-24 17:58:05.223 3239 3239 I binder_sample: [android.net.IConnectivityManager,3,175,com.xiaohaizi.ui
ushservice,35]pending transaction 34312661: ffffffd1e60e5d00 from 3239:3434 to 3336:0 code 3 flags 10 pri 0:118 r1 node 64996 size 76:0 data ffffff8017800cf0
11-24 17:58:05.224 21153 21153 I binder_sample: [android.net.IConnectivityManager,3,164,com.qiyi.video,32]
pending transaction 34313000: ffffffd2ad97bf80 from 21153:21153 to 3336:0 code 3 flags 10 pri 0:120 r1 node 64996 size 76:0 data ffffff8017802868
11-24 17:58:05.229 23061 23061 I binder_sample: [android.net.IConnectivityManager,3,141,com.youdao.dict,28]
pending transaction 34312699: ffffffd247530700 from 23061:23061 to 3336:0 code 3 flags 10 pri 0:120 r1 node 64996 size 76:0 data ffffff8017804f40
11-24 17:58:05.229 2423 2423 I binder_sample: [android.net.IConnectivityManager,3,143,com.koudai.weidian.buyer,28]
pending transaction 34312710: ffffffd1d87bbe00 from 2423:2423 to 3336:0 code 3 flags 10 pri 0:120 r1 node 64996 size 76:0 data ffffff80178045f0
11-24 17:58:05.232 19738 19738 I binder_sample: [android.net.IConnectivityManager,3,161,com.tencent.mm:exdevice,32]
pending transaction 34312725: ffffffd205900400 from 19738:19738 to 3336:0 code 3 flags 10 pri 0:120 r1 node 64996 size 76:0 data ffffff8017801580
11-24 17:58:05.220 22388 22388 I binder_sample: [android.net.IConnectivityManager,3,137,com.ximalaya.ting.android,27]
pending transaction 34312853: ffffffd1e9719b00 from 22388:22388 to 3336:0 code 3 flags 10 pri 0:120 r1 node 64996 size 76:0 data ffffff8017801f30
// Phone receive incoming binder transaction and attempt bind to system_server but failed due to system_server binder threads full
proc 4211
outgoing transaction 34312648: ffffffd260191500 from 4211:22509 to 3336:0 code 15 flags 10 pri 0:120 r1
incoming transaction 34312647: ffffffd260191380 from 17297:17297 to 4211:22509 code 48 flags 10 pri 0:120 r1 node 91723 size 92:0 data ffffff801ce000b8
outgoing transaction 34312688: ffffffd285972100 from 4211:4224 to 3336:0 code 15 flags 10 pri 0:120 r1
incoming transaction 34312684: ffffffd21079af80 from 4053:4351 to 4211:4224 code 48 flags 10 pri 0:120 r1 node 91723 size 92:0 data ffffff801ce00170
outgoing transaction 34312690: ffffffd2a1e84680 from 4211:4815 to 3336:0 code 15 flags 10 pri 0:120 r1
incoming transaction 34312686: ffffffd2a1e84d00 from 24021:5865 to 4211:4815 code 11 flags 10 pri 0:120 r1 node 81160 size 80:0 data ffffff801ce002e0
…
outgoing transaction 34313029: ffffffd25dd92e80 from 4211:5517 to 3336:0 code 2c flags 10 pri 0:120 r1
incoming transaction 34313005: ffffffd1fe8a7b80 from 4031:5068 to 4211:5517 code 3 flags 10 pri 0:120 r1 node 81160 size 116:0 data ffffff801ce010c8
outgoing transaction 34313089: ffffffd2649a3e00 from 4211:4493 to 3336:0 code 1 flags 10 pri 0:120 r1 HwBinder:4211_1
// Finally, ConnectivityThread attempt bind to phone but failed due to phone binder threads full
proc 3336
outgoing transaction 34313019: ffffffd27d657080 from 3336:3921 to 4211:0 code 1b flags 10 pri 0:120 r1
And from call stack below, it looks NetworkPolcyService will call to SubscriptionManager API which will call to SettingsProvider to get default subscription. This behavior will cause a lot of IPC transaction between phone process and system server process and looks like cause system binder thread full.
"ConnectivityThread" prio=5 tid=72 Native
| group="main" sCount=1 dsCount=0 flags=1 obj=0x1641dcf8 self=0x74d3784e00
| sysTid=3921 nice=0 cgrp=default sched=0/0 handle=0x74cd5f64f0
| state=S schedstat=( 1546261457 1528895360 4782 ) utm=116 stm=38 core=0 HZ=100
| stack=0x74cd4f4000-0x74cd4f6000 stackSize=1037KB
| held mutexes=
at android.os.BinderProxy.transactNative(Native method)
at android.os.BinderProxy.transact(Binder.java:756)
at com.android.internal.telephony.ISub$Stub$Proxy.getActiveSubIdList(ISub.java:923)
at android.telephony.SubscriptionManager.getActiveSubscriptionIdList(SubscriptionManager.java:1249)
at com.android.server.net.NetworkPolicyManagerService.isTemplateRelevant(NetworkPolicyManagerService.java:1513)
at com.android.server.net.NetworkPolicyManagerService.updateNotificationsNL(NetworkPolicyManagerService.java:1451)
at com.android.server.net.NetworkPolicyManagerService$14.onReceive(NetworkPolicyManagerService.java:1745)
- locked <0x0ec410d0> (a java.lang.Object)
- locked <0x01913893> (a java.lang.Object)
at com.android.server.net.NetworkPolicyManagerService$21.onLost(NetworkPolicyManagerService.java:930)
at android.net.ConnectivityManager$CallbackHandler.handleMessage(ConnectivityManager.java:2770)
at android.os.Handler.dispatchMessage(Handler.java:105)
at android.os.Looper.loop(Looper.java:180)
at android.os.HandlerThread.run(HandlerThread.java:65)
