Monthly Archives: January 2018

记一个Nexus 6p解锁loop问题

用了两年多的Nexus 6p出现问题了。
表现为:启动到主屏的时候,输入正确的密码后,系统闪退,然后再次要求输入密码。
在Android Central里,有人报过类似的问题

adb log显示:

01-11 19:26:41.950 4549 5940 W System.err: java.security.UnrecoverableKeyException: Failed to obtain information about key
01-11 19:26:41.950 4549 5940 W System.err: at android.security.keystore.AndroidKeyStoreProvider.loadAndroidKeyStoreSecretKeyFromKeystore(AndroidKeyStoreProvider.java:282)
01-11 19:26:41.950 4549 5940 W System.err: at android.security.keystore.AndroidKeyStoreSpi.engineGetKey(AndroidKeyStoreSpi.java:98)
01-11 19:26:41.950 4549 5940 W System.err: at java.security.KeyStore.getKey(KeyStore.java:1062)
01-11 19:26:41.950 4549 5940 W System.err: at com.android.server.locksettings.SyntheticPasswordCrypto.decryptBlob(SyntheticPasswordCrypto.java:120)
01-11 19:26:41.950 4549 5940 W System.err: at com.android.server.locksettings.SyntheticPasswordManager.decryptSPBlob(SyntheticPasswordManager.java:1040)
01-11 19:26:41.950 4549 5940 W System.err: at com.android.server.locksettings.SyntheticPasswordManager.unwrapSyntheticPasswordBlob(SyntheticPasswordManager.java:906)
01-11 19:26:41.950 4549 5940 W System.err: at com.android.server.locksettings.SyntheticPasswordManager.unwrapPasswordBasedSyntheticPassword(SyntheticPasswordManager.java:843)
01-11 19:26:41.950 4549 5940 W System.err: at com.android.server.locksettings.LockSettingsService.spBasedDoVerifyCredential(LockSettingsService.java:2105)
01-11 19:26:41.950 4549 5940 W System.err: at com.android.server.locksettings.LockSettingsService.doVerifyCredential(LockSettingsService.java:1553)
01-11 19:26:41.950 4549 5940 W System.err: at com.android.server.locksettings.LockSettingsService.checkCredential(LockSettingsService.java:1526)
01-11 19:26:41.950 4549 5940 W System.err: at com.android.internal.widget.ILockSettings$Stub.onTransact(ILockSettings.java:164)
01-11 19:26:41.950 4549 5940 W System.err: at android.os.Binder.execTransact(Binder.java:697)
01-11 19:26:41.950 4549 5940 W System.err: Caused by: android.security.KeyStoreException: Key not yet valid
01-11 19:26:41.950 4549 5940 W System.err: at android.security.KeyStore.getKeyStoreException(KeyStore.java:697)
01-11 19:26:41.950 4549 5940 W System.err: at android.security.keystore.AndroidKeyStoreProvider.loadAndroidKeyStoreSecretKeyFromKeystore(AndroidKeyStoreProvider.java:283)
01-11 19:26:41.950 4549 5940 W System.err: ... 11 more
01-11 19:26:41.951 4549 5940 E JavaBinder: *** Uncaught remote exception! (Exceptions are not yet supported across processes.)
01-11 19:26:41.951 4549 5940 E JavaBinder: java.lang.RuntimeException: Failed to decrypt blob
01-11 19:26:41.951 4549 5940 E JavaBinder: at com.android.server.locksettings.SyntheticPasswordCrypto.decryptBlob(SyntheticPasswordCrypto.java:129)
01-11 19:26:41.951 4549 5940 E JavaBinder: at com.android.server.locksettings.SyntheticPasswordManager.decryptSPBlob(SyntheticPasswordManager.java:1040)
01-11 19:26:41.951 4549 5940 E JavaBinder: at com.android.server.locksettings.SyntheticPasswordManager.unwrapSyntheticPasswordBlob(SyntheticPasswordManager.java:906)
01-11 19:26:41.951 4549 5940 E JavaBinder: at com.android.server.locksettings.SyntheticPasswordManager.unwrapPasswordBasedSyntheticPassword(SyntheticPasswordManager.java:843)
01-11 19:26:41.951 4549 5940 E JavaBinder: at com.android.server.locksettings.LockSettingsService.spBasedDoVerifyCredential(LockSettingsService.java:2105)
01-11 19:26:41.951 4549 5940 E JavaBinder: at com.android.server.locksettings.LockSettingsService.doVerifyCredential(LockSettingsService.java:1553)
01-11 19:26:41.951 4549 5940 E JavaBinder: at com.android.server.locksettings.LockSettingsService.checkCredential(LockSettingsService.java:1526)
01-11 19:26:41.951 4549 5940 E JavaBinder: at com.android.internal.widget.ILockSettings$Stub.onTransact(ILockSettings.java:164)
01-11 19:26:41.951 4549 5940 E JavaBinder: at android.os.Binder.execTransact(Binder.java:697)
01-11 19:26:41.951 4549 5940 E JavaBinder: Caused by: java.security.UnrecoverableKeyException: Failed to obtain information about key
01-11 19:26:41.951 4549 5940 E JavaBinder: at android.security.keystore.AndroidKeyStoreProvider.loadAndroidKeyStoreSecretKeyFromKeystore(AndroidKeyStoreProvider.java:282)
01-11 19:26:41.951 4549 5940 E JavaBinder: at android.security.keystore.AndroidKeyStoreSpi.engineGetKey(AndroidKeyStoreSpi.java:98)
01-11 19:26:41.951 4549 5940 E JavaBinder: at java.security.KeyStore.getKey(KeyStore.java:1062)
01-11 19:26:41.951 4549 5940 E JavaBinder: at com.android.server.locksettings.SyntheticPasswordCrypto.decryptBlob(SyntheticPasswordCrypto.java:120)
01-11 19:26:41.951 4549 5940 E JavaBinder: ... 8 more
01-11 19:26:41.951 4549 5940 E JavaBinder: Caused by: android.security.KeyStoreException: Key not yet valid
01-11 19:26:41.951 4549 5940 E JavaBinder: at android.security.KeyStore.getKeyStoreException(KeyStore.java:697)
01-11 19:26:41.951 4549 5940 E JavaBinder: at android.security.keystore.AndroidKeyStoreProvider.loadAndroidKeyStoreSecretKeyFromKeystore(AndroidKeyStoreProvider.java:283)
01-11 19:26:41.951 4549 5940 E JavaBinder: ... 11 more

根据crash的log看,应该是系统在从keystore里读key的时候,认为时间无效:

01-11 19:26:41.950 4549 5940 W System.err: Caused by: android.security.KeyStoreException: Key not yet valid

相关的code,大概是在https://android.googlesource.com/platform/system/security/+/master/keystore/keystore_keymaster_enforcement.h#41

bool activation_date_valid(uint64_t activation_date) const override {
  time_t now = time(NULL);
  if (now == static_cast<time_t>(-1)) {
    // Failed to obtain current time -- fail safe: activation_date hasn't yet occurred.
    return false;
  } else if (now < 0) {
    // Current time is prior to start of the epoch -- activation_date hasn't yet occurred.
    return false;
  }
  // time(NULL) returns seconds since epoch and "loses" milliseconds information. We thus add
  // 999 ms to now_date to avoid a situation where an activation_date of up to 999ms in the
  // past may still be considered to still be in the future. This can be removed once
  // time(NULL) is replaced by a millisecond-precise source of time.
  uint64_t now_date = static_cast<uint64_t>(now) * 1000 + 999;
  return now_date >= activation_date;
}

因为有root,可以尝试设置系统时间,结果还是没用,即使设置到2250年,它还是报同样的错。所以我也不知道到底问题是不是在这里了。

然后注意到hwclock不太对:

angler:/sys/class/rtc/rtc0 # date "030100002018"
Thu Mar 1 00:00:00 CST 2018
angler:/sys/class/rtc/rtc0 # hwclock -l
Mon Jan 12 09:21:32 1970 0.000000 seconds
angler:/sys/class/rtc/rtc0 # hwclock -w
hwclock: ioctl 4024700a: Invalid argument

高通的这个RTC莫非根本不能写,只能读?

angler:/sys/class/rtc/rtc0 # ls -l
total 0
-r--r--r-- 1 root root 4096 2018-03-01 00:01 date
-r--r--r-- 1 root root 4096 2018-03-01 00:01 dev
lrwxrwxrwx 1 root root 0 2018-03-01 00:01 device -> ../../../qpnp-rtc-8
-r--r--r-- 1 root root 4096 2018-03-01 00:01 hctosys
-rw-r--r-- 1 root root 4096 2018-03-01 00:01 max_user_freq
-r--r--r-- 1 root root 4096 2018-03-01 00:01 name
drwxr-xr-x 2 root root 0 2018-03-01 00:01 power
-r--r--r-- 1 root root 4096 2018-03-01 00:01 since_epoch
lrwxrwxrwx 1 root root 0 2018-03-01 00:01 subsystem -> ../../../../../class/rtc
-r--r--r-- 1 root root 4096 2018-03-01 00:01 time
-rw-r--r-- 1 root root 4096 2018-03-01 00:01 uevent

最后我怀疑是time(NULL);返回了-1,但是没有log,也不知道是不是这样。

总之,这个问题,好像只能factory reset了。
如果再出问题,能只编个AOSP,加上log看一下了。

Share

记一个systemd的NFS boot问题

前段时间遇到个问题,一个基于systemd的系统在从NFS启动的时候,user space启动到一半,网络掉了,于是NFS hang住,系统也不可用了。

从log上看,很明显是systemd-networkd启动之后,IP被release掉,又没有拿到新的IP,于是网络就断了。

由于systemd-networkd是通过读取配置文件来初始化网络的,一开始猜测,是不是它先release掉IP,然后再读配置文件,导致这样的问题的。
然而从code上看,它倒是先读了config,然后再初始化网络的。

先是在SO上提了个问题,没人回答。
然后经过一番Google,发现了CriticalConnection这个config,作用是:

When true, the connection will never be torn down even if the DHCP lese expires.

虽然它在说DHCP的connection不会被释放,但是经过测试,其实它也适用于static ip。

也就是说,只要在config文件里加上了这么一段:

[DHCP]
CriticalConnection=true

这个interface的网络在systemd-networkd启动的时候就不会被断开,这样NFS mount就不会hang住,系统也就能正常启动了。(顺便自己回答了SO上的问题。。。)

Share