個人原創，轉載請註明出處

自畢業以來已經從事兩年Android Framewok開發，到如今才積累一點點能夠拿出來分享的東西，今天記錄一篇關於手機循環重啟問題的分析和解決過程。

問題描述：

　　一部被退回返修的手機，搭載Android N OS，手機開機到出現systemui界面即立刻重啟，如此循環往復直至電量耗盡。

對問題進行合理猜測：

　　手機重啟一般可以分兩大類，

　　　　1 上層重要進程crash，比如system_server進程掛掉，watchdog重啟，或者其他進程crash把system_server進程帶掛了。

　　　　2 kernel 導致的重啟，比如空指針，非法地址等。

　　既然能夠開機到systemui顯示，大體可以先判斷為system_server發生了Crash導致手機重啟。

　　抓log觀察一下，這裏有必要介紹一點adb shell dumpsys的知識，

　　dumpsys activity //查詢AMS服務相關信息

　　dumpsys window //查詢WMS服務相關信息

　　dumpsys cpuinfo //查詢CPU情況

　　dumpsys meminfo //查詢內存情況

　　比如我經常使用的兩個dumpsys命令是：

　　adb shell dumpsys activity top 和 adb shell pm path "packageName"

　　adb shell dumpsys activity top 命令可以查看當前手機最上層窗口顯示界面所屬的應用的包名，拿到報名之後就可以通過adb shell pm path "packageName"拿到它的安裝目錄。

　　好了，言歸正傳，分析手機循環重啟問題我們需要用到另一個dumpsys 命令：adb shell dumpsys dropbox -p

　　Android dropbox提供了一種保存日誌的機制，支持將內核、Native、Java多種日誌保存在"/data/system/dropbox"目錄中。用以上命令就可以將這種日誌提取出來，當然也可以用adb pull /data/system/dropbox提取。此處我們用grep過濾一下log

　　adb shell dumpsys dropbox -p | tee log1.txt | grep FATAL

　　06-19 09:15:14.858 E/AndroidRuntime( 1170): *** FATAL EXCEPTION IN SYSTEM PROCESS: notification-sqlite-log

　　此處註意 "FATAL EXCEPTION IN SYSTEM PROCESS: notification-sqlite-log"

　　那麽打開log1.txt,搜索"FATAL EXCEPTION IN SYSTEM PROCESS: notification-sqlite-log"

06-19 09:15:14.845 E/SQLiteLog( 1170): (2570) os_unix.c:32626: (13) unlink(/data/system/notification_log.db-journal) -
06-19 09:15:14.845 E/SQLiteLog( 1170): (2570) disk I/O error
06-19 09:15:14.830 W/notification-sq( 1396): type=1400 audit(0.0:76): avc: denied { write } for name="system" dev="mmcblk0p27" ino=360449 scontext=u:r:system_server:s0 tcontext=u:object_r:unlabeled:s0 tclass=dir permissive=0
06-19 09:15:14.848 D/WifiService( 1170): onReceive, action:android.net.wifi.WIFI_STATE_CHANGED
06-19 09:15:14.857 E/SQLiteDatabase( 1170): Failed to open database ‘/data/system/notification_log.db‘.
06-19 09:15:14.857 E/SQLiteDatabase( 1170): android.database.sqlite.SQLiteDiskIOException: disk I/O error (code 2570): , while compiling: PRAGMA journal_mode
06-19 09:15:14.857 E/SQLiteDatabase( 1170): at android.database.sqlite.SQLiteConnection.nativePrepareStatement(Native Method)
06-19 09:15:14.857 E/SQLiteDatabase( 1170): at android.database.sqlite.SQLiteConnection.acquirePreparedStatement(SQLiteConnection.java:898)
06-19 09:15:14.857 E/SQLiteDatabase( 1170): at android.database.sqlite.SQLiteConnection.executeForString(SQLiteConnection.java:643)
06-19 09:15:14.857 E/SQLiteDatabase( 1170): at android.database.sqlite.SQLiteConnection.setJournalMode(SQLiteConnection.java:325)
06-19 09:15:14.857 E/SQLiteDatabase( 1170): at android.database.sqlite.SQLiteConnection.setWalModeFromConfiguration(SQLiteConnection.java:299)
06-19 09:15:14.857 E/SQLiteDatabase( 1170): at android.database.sqlite.SQLiteConnection.open(SQLiteConnection.java:220)
06-19 09:15:14.857 E/SQLiteDatabase( 1170): at android.database.sqlite.SQLiteConnection.open(SQLiteConnection.java:198)
06-19 09:15:14.857 E/SQLiteDatabase( 1170): at android.database.sqlite.SQLiteConnectionPool.openConnectionLocked(SQLiteConnectionPool.java:463)
06-19 09:15:14.857 E/SQLiteDatabase( 1170): at android.database.sqlite.SQLiteConnectionPool.open(SQLiteConnectionPool.java:185)
06-19 09:15:14.857 E/SQLiteDatabase( 1170): at android.database.sqlite.SQLiteConnectionPool.open(SQLiteConnectionPool.java:177)
06-19 09:15:14.857 E/SQLiteDatabase( 1170): at android.database.sqlite.SQLiteDatabase.openInner(SQLiteDatabase.java:838)
06-19 09:15:14.857 E/SQLiteDatabase( 1170): at android.database.sqlite.SQLiteDatabase.open(SQLiteDatabase.java:823)
06-19 09:15:14.857 E/SQLiteDatabase( 1170): at android.database.sqlite.SQLiteDatabase.openDatabase(SQLiteDatabase.java:716)
06-19 09:15:14.857 E/SQLiteDatabase( 1170): at android.app.ContextImpl.openOrCreateDatabase(ContextImpl.java:664)
06-19 09:15:14.857 E/SQLiteDatabase( 1170): at android.database.sqlite.SQLiteOpenHelper.getDatabaseLocked(SQLiteOpenHelper.java:223)
06-19 09:15:14.857 E/SQLiteDatabase( 1170): at android.database.sqlite.SQLiteOpenHelper.getWritableDatabase(SQLiteOpenHelper.java:163)
06-19 09:15:14.857 E/SQLiteDatabase( 1170): at com.android.server.notification.NotificationUsageStats$SQLiteLog.writeEvent(NotificationUsageStats.java:1212)
06-19 09:15:14.857 E/SQLiteDatabase( 1170): at com.android.server.notification.NotificationUsageStats$SQLiteLog.-wrap0(NotificationUsageStats.java)
06-19 09:15:14.857 E/SQLiteDatabase( 1170): at com.android.server.notification.NotificationUsageStats$SQLiteLog$1.handleMessage(NotificationUsageStats.java:1065)
06-19 09:15:14.857 E/SQLiteDatabase( 1170): at android.os.Handler.dispatchMessage(Handler.java:110)
06-19 09:15:14.857 E/SQLiteDatabase( 1170): at android.os.Looper.loop(Looper.java:203)
06-19 09:15:14.857 E/SQLiteDatabase( 1170): at android.os.HandlerThread.run(HandlerThread.java:61)

06-19 09:15:14.858 E/AndroidRuntime( 1170): *** FATAL EXCEPTION IN SYSTEM PROCESS: notification-sqlite-log
06-19 09:15:14.858 E/AndroidRuntime( 1170): android.database.sqlite.SQLiteDiskIOException: disk I/O error (code 2570): , while compiling: PRAGMA journal_mode
06-19 09:15:14.858 E/AndroidRuntime( 1170): at android.database.sqlite.SQLiteConnection.nativePrepareStatement(Native Method)
06-19 09:15:14.858 E/AndroidRuntime( 1170): at android.database.sqlite.SQLiteConnection.acquirePreparedStatement(SQLiteConnection.java:898)
06-19 09:15:14.858 E/AndroidRuntime( 1170): at android.database.sqlite.SQLiteConnection.executeForString(SQLiteConnection.java:643)
06-19 09:15:14.858 E/AndroidRuntime( 1170): at android.database.sqlite.SQLiteConnection.setJournalMode(SQLiteConnection.java:325)
06-19 09:15:14.858 E/AndroidRuntime( 1170): at android.database.sqlite.SQLiteConnection.setWalModeFromConfiguration(SQLiteConnection.java:299)
06-19 09:15:14.858 E/AndroidRuntime( 1170): at android.database.sqlite.SQLiteConnection.open(SQLiteConnection.java:220)
06-19 09:15:14.858 E/AndroidRuntime( 1170): at android.database.sqlite.SQLiteConnection.open(SQLiteConnection.java:198)
06-19 09:15:14.858 E/AndroidRuntime( 1170): at android.database.sqlite.SQLiteConnectionPool.openConnectionLocked(SQLiteConnectionPool.java:463)
06-19 09:15:14.858 E/AndroidRuntime( 1170): at android.database.sqlite.SQLiteConnectionPool.open(SQLiteConnectionPool.java:185)
06-19 09:15:14.858 E/AndroidRuntime( 1170): at android.database.sqlite.SQLiteConnectionPool.open(SQLiteConnectionPool.java:177)
06-19 09:15:14.858 E/AndroidRuntime( 1170): at android.database.sqlite.SQLiteDatabase.openInner(SQLiteDatabase.java:838)
06-19 09:15:14.858 E/AndroidRuntime( 1170): at android.database.sqlite.SQLiteDatabase.open(SQLiteDatabase.java:823)
06-19 09:15:14.858 E/AndroidRuntime( 1170): at android.database.sqlite.SQLiteDatabase.openDatabase(SQLiteDatabase.java:716)
06-19 09:15:14.858 E/AndroidRuntime( 1170): at android.app.ContextImpl.openOrCreateDatabase(ContextImpl.java:664)
06-19 09:15:14.858 E/AndroidRuntime( 1170): at android.database.sqlite.SQLiteOpenHelper.getDatabaseLocked(SQLiteOpenHelper.java:223)
06-19 09:15:14.858 E/AndroidRuntime( 1170): at android.database.sqlite.SQLiteOpenHelper.getWritableDatabase(SQLiteOpenHelper.java:163)
06-19 09:15:14.858 E/AndroidRuntime( 1170): at com.android.server.notification.NotificationUsageStats$SQLiteLog.writeEvent(NotificationUsageStats.java:1212)
06-19 09:15:14.858 E/AndroidRuntime( 1170): at com.android.server.notification.NotificationUsageStats$SQLiteLog.-wrap0(NotificationUsageStats.java)
06-19 09:15:14.858 E/AndroidRuntime( 1170): at com.android.server.notification.NotificationUsageStats$SQLiteLog$1.handleMessage(NotificationUsageStats.java:1065)
06-19 09:15:14.858 E/AndroidRuntime( 1170): at android.os.Handler.dispatchMessage(Handler.java:110)
06-19 09:15:14.858 E/AndroidRuntime( 1170): at android.os.Looper.loop(Looper.java:203)
06-19 09:15:14.858 E/AndroidRuntime( 1170): at android.os.HandlerThread.run(HandlerThread.java:61)

註意到進程pid:1170,FATAL EXCEPTION IN SYSTEM PROCESS: notification-sqlite-log,system_server進程在此處Crash了，這也就導致手機循環重啟直至電量耗盡。

再往前看一點，就會發現真正掛掉的原因是Failed to open database ‘/data/system/notification_log.db‘.notification_log.db出現了問題拖死了system_server。

繼續看android.database.sqlite.SQLiteDiskIOException: disk I/O error (code 2570): , while compiling: PRAGMA journal_mode，error code是非常重要的信息，查詢一下這個錯誤碼：

(2570) SQLITE_IOERR_DELETE

The SQLITE_IOERR_UNLOCK error code is an extended error code for SQLITE_IOERR indicating an I/O error within xDelete method on the sqlite3_vfs object.

這個error code就證明是文件格式被損壞了，Sqlite在解析數據庫文件的時候出現了致命錯誤。如何證明這個判斷呢？我們可以註意到數據庫文件所處的路徑在/data/system/notification_log.db-journal，也就是本博文貼出的log的第一行：

06-19 09:15:14.845 E/SQLiteLog( 1170): (2570) os_unix.c:32626: (13) unlink(/data/system/notification_log.db-journal) -

我們用正常的文件去替換掉該路徑的notification_log.db和notification_log.db-journal就可以證明我的判斷，果然是文件損壞，替換文件之後手機就恢復正常了，但是與這個問題相關的代碼是谷歌的源碼，並且在數據庫並發方面做了加鎖保護，又是用戶退機，沒辦法找出文件被損壞的根本原因。但是我們可以針對文件損壞做一些保護機制，比如在發生這種循壞重啟時五次之後就進入恢復出廠設置模式，或者每隔一段時間對文件進行備份，當出現這種情況是就進行文件替換，將正常的文件拷貝到該目錄。

再多說一點.db-journal文件，這個文件主要用於sqlite事務回滾機制，在事務開始時產生，在事務結束時刪除；當程序發生崩潰或者系統斷電時該文件將留在磁盤上，以便下次程序運行時進行事務回滾。本身就是一個保護機制，但是不幸的是這個文件格式損壞導致了手機循環重啟。至此問題分析總結完畢，真實的分析過程並沒有博客中的來的順利。

解決Android手機循環重啟問題