[Android N]KeyStore mBinder成员空指针引起system process不断重启

本地编译Android N项目得Rom刷机后，发现重启回到值SYSTEM_PROCESS无法启动，一直重启停留再开机动画阶段。

---

经查，发现android.security.keystore对应的service binder对象为NULL，报了空指针异常（LOG如下所示）。

--------- beginning of crash01-01 00:54:27.593  1102  1102 E AndroidRuntime: *** FATAL EXCEPTION IN SYSTEM PROCESS: main01-01 00:54:27.593  1102  1102 E AndroidRuntime: java.lang.RuntimeException: Error receiving broadcast Intent { act=android.intent.action.USER_STARTED flg=0x50000010 (has extras) } in com.android.server.ConnectivityService$3@26aa3ad01-01 00:54:27.593  1102  1102 E AndroidRuntime:    at android.app.LoadedApk$ReceiverDispatcher$Args.run(LoadedApk.java:1174)01-01 00:54:27.593  1102  1102 E AndroidRuntime:    at android.os.Handler.handleCallback(Handler.java:836)01-01 00:54:27.593  1102  1102 E AndroidRuntime:    at android.os.Handler.dispatchMessage(Handler.java:103)01-01 00:54:27.593  1102  1102 E AndroidRuntime:    at android.os.Looper.loop(Looper.java:203)01-01 00:54:27.593  1102  1102 E AndroidRuntime:    at com.android.server.SystemServer.run(SystemServer.java:432)01-01 00:54:27.593  1102  1102 E AndroidRuntime:    at com.android.server.SystemServer.main(SystemServer.java:286)01-01 00:54:27.593  1102  1102 E AndroidRuntime:    at java.lang.reflect.Method.invoke(Native Method)01-01 00:54:27.593  1102  1102 E AndroidRuntime:    at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1084)01-01 00:54:27.593  1102  1102 E AndroidRuntime:    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:945)01-01 00:54:27.593  1102  1102 E AndroidRuntime: Caused by: java.lang.NullPointerException: Attempt to invoke interface method 'int android.security.IKeystoreService.exist(java.lang.String, int)' on a null object reference01-01 00:54:27.593  1102  1102 E AndroidRuntime:    at android.security.KeyStore.contains(KeyStore.java:210)01-01 00:54:27.593  1102  1102 E AndroidRuntime:    at android.security.KeyStore.contains(KeyStore.java:218)01-01 00:54:27.593  1102  1102 E AndroidRuntime:    at com.android.server.net.LockdownVpnTracker.isEnabled(LockdownVpnTracker.java:98)01-01 00:54:27.593  1102  1102 E AndroidRuntime:    at com.android.server.ConnectivityService.onUserStart(ConnectivityService.java:4060)01-01 00:54:27.593  1102  1102 E AndroidRuntime:    at com.android.server.ConnectivityService.-wrap27(ConnectivityService.java)01-01 00:54:27.593  1102  1102 E AndroidRuntime:    at com.android.server.ConnectivityService$3.onReceive(ConnectivityService.java:4114)01-01 00:54:27.593  1102  1102 E AndroidRuntime:    at android.app.LoadedApk$ReceiverDispatcher$Args.run(LoadedApk.java:1164)01-01 00:54:27.593  1102  1102 E AndroidRuntime:    ... 8 more01-01 00:54:27.643  1102  1102 D AMEventHook: onEvent: AM_EndOfErrorDumpThread

经此LOG跟踪，发现是ConncetivityService在收到android.intent.action.USER_STARTED广播后，进行响应处理时调用了KeyStore的mBinder成员为空，导致系统进程无法正常地运行。

/frameworks/base/keystore/java/android/security/KeyStore.java

    public boolean contains(String key, int uid) {        try {            return mBinder.exist(key, uid) == NO_ERROR;//mBinder == NULL        } catch (RemoteException e) {            Log.w(TAG, "Cannot connect to keystore", e);            return false;        }    }    public boolean contains(String key) {        return contains(key, UID_SELF);    }

ConnectivityService响应广播时，通过LockdownVpnTracker.isEnabled()，间接地使用KeyStore的getInstance()方法和contains()方法。
/frameworks/base/services/core/java/com/android/server/ConnectivityService.java

    public static boolean isEnabled() {        return KeyStore.getInstance().contains(Credentials.LOCKDOWN_VPN);    }

---

经此，调用关系很清晰简单，问题也很明显，现在需要确定的是时序问题，看看是android.security.keystore这个服务启动绑定失败还是时序上的小偏差，前者的可能性更大，下面进行验证。

首先，看看KeyStore的mBinder怎么来的。
/frameworks/base/keystore/java/android/security/KeyStore.java

    private KeyStore(IKeystoreService binder) {        mBinder = binder;        mContext = getApplicationContext();    }    public static KeyStore getInstance() {        IKeystoreService keystore = IKeystoreService.Stub.asInterface(ServiceManager                .getService("android.security.keystore"));//        Log.i(TAG, "---->KeyStore getInstance on keystore file-- xdy ----->");        return new KeyStore(keystore);    }

是从ServiceManager中根据android.security.keystore去获取对应的服务，这就需要看是谁往ServiceManager中注册了此服务。

经过一番搜寻，发现是keystore_main.cpp中有个main方法，往SM中addService。
/system/security/keystore/keystore_main.cpp

int main(int argc, char* argv[]) {    ALOGE("------------> system --> security --> xdy1--->");    if (argc < 2) {        ALOGE("A directory must be specified!");        return 1;    }    ALOGE("------------> system --> security --> xdy2--->");    if (chdir(argv[1]) == -1) {        ALOGE("chdir: %s: %s", argv[1], strerror(errno));        return 1;    }    ALOGE("------------> system --> security --> xdy3--->");    Entropy entropy;    if (!entropy.open()) {        return 1;    }    ALOGE("------------> system --> security --> xdy4--->");    keymaster2_device_t* dev;    if (keymaster_device_initialize(&dev)) {        ALOGE("keystore keymaster could not be initialized; exiting");        return 1;    }    ALOGE("------------> system --> security --> xdy5--->");    keymaster2_device_t* fallback;    if (fallback_keymaster_device_initialize(&fallback)) {        ALOGE("software keymaster could not be initialized; exiting");        return 1;    }    ALOGE("------------> system --> security --> xdy6--->");    if (configure_keymaster_devices(dev, fallback)) {        ALOGE("Keymaster devices could not be configured; exiting");        return 1;    }    ALOGE("------------> system --> security --> xdy7--->");    if (configure_selinux() == -1) {        return -1;    }    ALOGE("------------> system --> security --> xdy8--->");    KeyStore keyStore(&entropy, dev, fallback);    keyStore.initialize();    android::sp<android::IServiceManager> sm = android::defaultServiceManager();    android::sp<android::KeyStoreService> service = new android::KeyStoreService(&keyStore);    android::status_t ret = sm->addService(android::String16("android.security.keystore"), service); ///核心代码    if (ret != android::OK) {        ALOGE("Couldn't register binder service!");        ALOGE("------------> system --> security --> xdy9--->");        return -1;    }    ALOGE("------------> system --> security --> xdy10--->");    /*     * We're the only thread in existence, so we're just going to process     * Binder transaction as a single-threaded program.     */    android::IPCThreadState::self()->joinThreadPool();    keymaster_device_release(dev);    return 1;}

上方自添加了一些ALOGE LOG。

---

经过重新编译，重新刷机，发现reboot不再复现该问题，但二者时序可以从下方log看出。
1.keystore

2.USER_STARTED

3.ConnectivityService启动

 1579: 01-01 03:30:54.638540  1100  1100 I SystemServer: StartConnectivityService 1580: 01-01 03:30:54.683255  1100  1100 D ConnectivityService: ConnectivityService starting up

---

综合上述LOG，最先addService，然后ConnectivityService被实例化启动，AMS发送USER_STARTED广播，ConnectivityService响应。

所以结论是，在keystore_main.cpp的main方法执行时,addService注册binder service不成功，应该会有如下log输出才对。

    android::status_t ret = sm->addService(android::String16("android.security.keystore"), service);    if (ret != android::OK) {        ALOGE("Couldn't register binder service!");//LOG输出        return -1;    }

其实从addService出现的地方就应该能够基本确定了，keystore是要在ConnectivityService之前的。

---

遗憾的是复现的版本，只是从终端logcat一部分log，未抓取到keystore部分的log，且暂记录之。