Android4.4 XML解析死循环异常导致的开机无法正常启动

此文参考:https://blog.csdn.net/luzhenrong45/article/details/97393639

问题说明

项目在开机过程中出现无法正常启动，系统一直循环打印

D/dalvikvm( 358): GC_CONCURRENT freed 386K, 35% free 943K/1448K, paused 2ms+2ms, total 8ms

日志分析

--------- beginning of /dev/log/main
I/installd( 147): installd firing up
I/toolbox ( 145): getprop ro.product.device
I/Netd ( 143): Netd 1.0 starting
I/toolbox ( 152): id
W/InterfaceController( 143): Warning (dlopen failed: library "/system/lib/libnetcmdiface.so" not found) while opening the net interface command library
E/DirectVolume( 142): Vold managed volumes must have auto mount point; ignoring /mnt/media_rw/extsd
E/DirectVolume( 142): Vold managed volumes must have auto mount point; ignoring /mnt/media_rw/udisk
--------- beginning of /dev/log/system
I/Vold ( 142): Vold 2.1 (the revenge) firing up
D/Vold ( 142): Volume extsd state changing -1 (Initializing) -> 0 (No-Media)
D/Vold ( 142): Volume udisk state changing -1 (Initializing) -> 0 (No-Media)
D/MagDaemon( 155): init_sensors
I/toolbox ( 167): getprop user.kernellog
I/toolbox ( 164): getprop user.reset.bt.wifi.info
I/SurfaceFlinger( 139): SurfaceFlinger is starting
I/SurfaceFlinger( 139): SurfaceFlinger's main thread ready to run. Initializing graphics H/W...
I/toolbox ( 178): getprop user.kernellog
I/toolbox ( 182): getprop user.cmdline
I/toolbox ( 188): grep recovery_flag
I/toolbox ( 192): getprop user.recovery
I/toolbox ( 189): date
I/recovery_flag.sh( 158): user.recovery is NULL!
I/recovery_flag.sh( 158): recovery_flag.sh terminated by exit(1)
I/toolbox ( 194): grep rever_type
I/toolbox ( 196): getprop user.reverseradar.type
I/reverse.sh( 159): REVERSET not changed!
D/libEGL ( 139): loaded /system/lib/egl/libEGL_VIVANTE.so
I/toolbox ( 199): grep language
I/toolbox ( 200): dd if=/dev/zero of=/dev/block/mmcblk3 seek=524292 bs=1 count=2048
I/toolbox ( 203): grep backcar_type
I/toolbox ( 206): getprop user.language
I/toolbox ( 204): touch
I/toolbox ( 209): touch _oops
I/toolbox ( 210): getprop persist.sys.language
I/toolbox ( 213): getprop user.backcar.type
I/toolbox ( 211): mount -t pstore pstore /root/
I/backcar.sh( 157): Set backcar language: zh
I/yantu.sh( 149): Writing 32-bit value 0x1C060601 to address 0x020C9010
I/reverse.sh( 159): 2048+0 records in
I/reverse.sh( 159): 2048+0 records out
I/reverse.sh( 159): 2048 bytes transferred in 0.091 secs (22505 bytes/sec)
I/toolbox ( 220): sync
I/toolbox ( 219): chmod 777 /sys/class/hsaed531mc/cartype_info/cartype
I/toolbox ( 221): chmod 777 /sys/class/hsaed531mc/cartype_info/hwid
I/toolbox ( 223): touch /data/bt_addr.ini
I/backcar.sh( 157): TYPE not changed!
D/MagDaemon( 155): couldn't find 'FreescaleAccelerometer' input device
D/MagDaemon( 155): inital sensor error
I/toolbox ( 227): insmod /system/lib/modules/atmel_mxt_ts.ko
D/libEGL ( 139): loaded /system/lib/egl/libGLESv1_CM_VIVANTE.so
I/toolbox ( 231): dd if=/cache/tmp of=/dev/block/mmcblk3 seek=524292 bs=1
I/reverse.sh( 159): 402+0 records in
I/reverse.sh( 159): 402+0 records out
I/reverse.sh( 159): 402 bytes transferred in 0.017 secs (23647 bytes/sec)
I/toolbox ( 236): sync
I/toolbox ( 235): dd if=/dev/zero of=/dev/block/mmcblk3 seek=524292 bs=1 count=2048
I/backcar.sh( 157): 2048+0 records in
I/backcar.sh( 157): 2048+0 records out
I/backcar.sh( 157): 2048 bytes transferred in 0.016 secs (128000 bytes/sec)
I/toolbox ( 239): sync
D/libEGL ( 139): loaded /system/lib/egl/libGLESv2_VIVANTE.so
I/toolbox ( 242): dd if=/cache/tmp of=/dev/block/mmcblk3 seek=524292 bs=1
I/backcar.sh( 157): 402+0 records in
I/backcar.sh( 157): 402+0 records out
I/backcar.sh( 157): 402 bytes transferred in 0.003 secs (134000 bytes/sec)
I/toolbox ( 246): sync
I/toolbox ( 248): dd if=/dev/block/mmcblk3boot1 bs=512 count=1
I/toolbox ( 249): grep ^Already Written!$
I/imx6.gralloc( 139): open gpu gralloc module!
I/imx6.gralloc( 139): fb_device_open dispid:0, fb:0
W/imx6.gralloc( 139): using (fd=19)
W/imx6.gralloc( 139): id = DISP4 BG
W/imx6.gralloc( 139): xres = 1280 px
W/imx6.gralloc( 139): yres = 720 px
W/imx6.gralloc( 139): xres_virtual = 1280 px
W/imx6.gralloc( 139): yres_virtual = 2160 px
W/imx6.gralloc( 139): bpp = 32
W/imx6.gralloc( 139): r = 16:8
W/imx6.gralloc( 139): g = 8:8
W/imx6.gralloc( 139): b = 0:8
W/imx6.gralloc( 139): width = 203 mm (160.157639 dpi)
W/imx6.gralloc( 139): height = 114 mm (160.421051 dpi)
W/imx6.gralloc( 139): refresh rate = 60.02 Hz
I/FslHwcomposer( 139): using fsl hwc!!!
I/FslHwcomposer( 139): int hwc_device_open(const hw_module_t*, const char*, hw_device_t**),567
I/FslHwcomposer( 139): using fsl hwc!
I/FslHwcomposer( 139): fb0 is ldb
I/FslHwcomposer( 139): device
I/FslHwcomposer( 139): fb1 is overlay device
W/FslHwcomposer( 139): open /sys/class/graphics/fb2 failed
W/FslHwcomposer( 139): open /sys/class/graphics/fb3 failed
W/FslHwcomposer( 139): open /sys/class/graphics/fb4 failed
W/FslHwcomposer( 139): open /sys/class/graphics/fb5 failed
I/FslHwcomposer( 139): hwcomposer: open framebuffer fb0
I/imx6.gralloc( 139): fb_device_open dispid:0, fb:0
I/imx6.gralloc( 139): display already initialized...
I/FslHwcomposer( 139): int hwc_device_open(const hw_module_t*, const char*, hw_device_t**),426
I/SurfaceFlinger( 139): Using composer version 1.3
W/SurfaceFlinger( 139): no suitable EGLConfig found, trying a simpler query
I/SurfaceFlinger( 139): EGL informations:
I/SurfaceFlinger( 139): vendor : Android
I/SurfaceFlinger( 139): version : 1.4 Android META-EGL
I/SurfaceFlinger( 139): extensions: EGL_KHR_get_all_proc_addresses EGL_ANDROID_presentation_time EGL_KHR_image EGL_KHR_image_base EGL_KHR_image_pixmap EGL_KHR_lock_surface EGL_KHR_gl_texture_2D_image EGL_KHR_gl_texture_cubemap_image EGL_KHR_gl_renderbuffer_image EGL_KHR_reusable_sync EGL_KHR_fence_sync EGL_KHR_create_context EGL_EXT_create_context_robustness EGL_ANDROID_image_native_buffer EGL_KHR_wait_sync EGL_ANDROID_recordable
I/SurfaceFlinger( 139): Client API: OpenGL_ES
I/SurfaceFlinger( 139): EGLSurface: 8-8-8-8, config=0x16
W/linker ( 146): libfsl_jpeg_enc_arm11_elinux.so has text relocations. This is wasting memory and is a security risk. Please fix.
I/SurfaceFlinger( 139): OpenGL ES informations:
I/SurfaceFlinger( 139): vendor : Vivante Corporation
I/SurfaceFlinger( 139): renderer : Vivante GC2000
I/SurfaceFlinger( 139): version : OpenGL ES 3.0 V5.0.11.p8.41671
I/SurfaceFlinger( 139): extensions: GL_EXT_debug_marker GL_OES_vertex_type_10_10_10_2 GL_OES_vertex_half_float GL_OES_element_index_uint GL_OES_mapbuffer GL_OES_vertex_array_object GL_OES_compressed_ETC1_RGB8_texture GL_OES_compressed_paletted_texture GL_OES_texture_npot GL_OES_rgb8_rgba8 GL_OES_depth_texture GL_OES_depth_texture_cube_map GL_OES_depth24 GL_OES_depth32 GL_OES_packed_depth_stencil GL_OES_fbo_render_mipmap GL_OES_get_program_binary GL_OES_fragment_precision_high GL_OES_standard_derivatives GL_OES_EGL_image GL_OES_EGL_image_external GL_OES_EGL_sync GL_OES_required_internalformat GL_OES_surfaceless_context GL_EXT_texture_type_2_10_10_10_REV GL_EXT_texture_filter_anisotropic GL_EXT_texture_format_BGRA8888 GL_EXT_read_format_bgra GL_EXT_multi_draw_arrays GL_EXT_frag_depth GL_EXT_discard_framebuffer GL_EXT_blend_minmax GL_EXT_multisampled_render_to_texture GL_EXT_robustness GL_VIV_direct_texture
I/SurfaceFlinger( 139): GL_MAX_TEXTURE_SIZE = 8192
I/SurfaceFlinger( 139): GL_MAX_VIEWPORT_DIMS = 8192
E/cutils-trace( 139): Error opening trace file: Permission denied (13)
E/libEGL ( 139): EGLBoolean eglSetSwapRectangleANDROID(EGLDisplay, EGLSurface, EGLint, EGLint, EGLint, EGLint):1590 error 3008 (EGL_BAD_DISPLAY)
I/imx6.gralloc( 139): fb_device_open dispid:0, fb:0
I/imx6.gralloc( 139): display already initialized...
D/SurfaceFlinger( 139): Screen acquired, type=0 flinger=0x2b4e6008
I/FslHwcomposer( 139): prepare: targetHandle is null
I/mediaserver( 146): ServiceManager: 0x2bf87640
I/AudioFlinger( 146): Using default 3000 mSec as standby time.
I/CameraService( 146): CameraService started (pid=146)
I/CameraService( 146): Loaded "Freescale CameraHal Module" camera module
I/FslCameraHAL( 146): Face Back Camera is ak8859, orient is 0
I/FslCameraHAL( 146): Face Front Camera is 0, orient is 0
I/FslCameraHAL( 146): Checking the camera ak8859
I/FslCameraHAL( 146): Get sensor ak8859's dev path /dev/video0
I/FslCameraHAL( 146): Camera ID 0: name ak8859, Facing 0, orientation 0, dev path /dev/video0
I/AudioPolicyManagerBase( 146): loadAudioPolicyConfig() loaded /system/etc/audio_policy.conf
W/audio_hw_primary( 146): card 0, id ymu836audio ,driver ymu836-audio, name ymu836-audio
W/audio_hw_primary( 146): out rate 44100
W/audio_hw_primary( 146): in rate 44100, channels 1 format 0
W/audio_hw_primary( 146): card 1, id ymu836saudio ,driver ymu836s-audio, name ymu836s-audio
W/audio_hw_primary( 146): out rate 44100
W/audio_hw_primary( 146): in rate 44100, channels 1 format 0
I/AudioFlinger( 146): loadHwModule() Loaded primary audio interface from Freescale i.MX Audio HW HAL (audio) handle 1
W/audio_hw_primary( 146): open output stream devices 2, format 1, channels 3, sample_rate 44100, flag 2
W/audio_hw_primary( 146): opened out stream...735643512, type 1
I/AudioFlinger( 146): HAL output buffer size 384 frames, normal mix buffer size 768 frames
I/AudioMixer( 146): found effect "Multichannel Downmix To Stereo" from The Android Open Source Project
E/MonoPipe( 146): Failed to fetch local time frequency when constructing a MonoPipe (res = -32). getNextWriteTimestamp calls will be non-functional
D/AndroidRuntime( 140):
D/AndroidRuntime( 140): >>>>>> AndroidRuntime START com.android.internal.os.ZygoteInit <<<<<<
D/AndroidRuntime( 140): CheckJNI is OFF
I/AndroidRuntime( 140): JNI options: '-Xjniopts:warnonly'
D/libEGL ( 267): loaded /system/lib/egl/libEGL_VIVANTE.so
D/libEGL ( 267): loaded /system/lib/egl/libGLESv1_CM_VIVANTE.so
D/libEGL ( 267): loaded /system/lib/egl/libGLESv2_VIVANTE.so
E/cutils-trace( 267): Error opening trace file: Permission denied (13)
I/imx6.gralloc( 267): open gpu gralloc module!
E/BufferQueue( 139): [BootAnimation] dequeueBuffer: can't dequeue multiple buffers without setting the buffer count
I/BootAnimation( 267): bool android::BootAnimation::video() start
I/dalvikvm( 140): DexOpt: not all deps represented
E/dalvikvm( 140): /system/framework/anwsdk.jar odex has stale dependencies
D/dalvikvm( 140): Trying to load lib libjavacore.so 0x0
D/dalvikvm( 140): Added shared lib libjavacore.so 0x0
D/dalvikvm( 140): Trying to load lib libnativehelper.so 0x0
D/dalvikvm( 140): Added shared lib libnativehelper.so 0x0
D/dalvikvm( 140): No JNI_OnLoad found in libnativehelper.so 0x0, skipping init
D/dalvikvm( 140): Note: class Landroid/app/ActivityManagerNative; has 179 unimplemented (abstract) methods
E/memtrack( 140): Couldn't load memtrack module (No such file or directory)
E/android.os.Debug( 140): failed to load memtrack module: -2
I/SamplingProfilerIntegration( 140): Profiling disabled.
E/Zygote ( 140): Bootopt(2) enabled: Class/Resource preloading will be disabled!
D/ZZZ ( 140): Current timestamp(ms): 4179
D/ZZZ ( 140): persist.bolt.enable = false
D/ZZZ ( 140): persist.bolt.preload.defer = false
D/ZZZ ( 140): persist.bolt.preload.nores = false
D/ZZZ ( 140): persist.bolt.display.force = false
D/ZZZ ( 140): persist.bolt.ams.persist = false
D/ZZZ ( 140): persist.bolt.sss.priority = false
D/ZZZ ( 140): persist.bolt.sss.mthread = false
D/ZZZ ( 140): persist.bolt.pms.scan = false
D/ZZZ ( 140): persist.bolt.pms.scan.async = false
D/ZZZ ( 140): persist.bolt.pms.scan.early = false
D/ZZZ ( 140): persist.bolt.sysui.nokeyguard = false
D/ZZZ ( 140): persist.bolt.sysui.preload = false
D/ZZZ ( 140): persist.bolt.sysui.car = false
D/ZZZ ( 140): persist.bolt.prestart.launcher = false
D/ZZZ ( 140): persist.bolt.launcher.priority = false
D/ZZZ ( 140): persist.bolt.disable.wallpaper = false
D/ZZZ ( 140): persist.bolt.stop.bootanim = false
D/ZZZ ( 140): persist.bolt.preload.drawable = false
D/ZZZ ( 140): persist.bolt.prestart.autocore = false
D/ZZZ ( 140): persist.bolt.power.state = false
E/cutils-trace( 140): Error opening trace file: No such file or directory (2)
D/dalvikvm( 140): GC_EXPLICIT freed 32K, 7% free 492K/528K, paused 0ms+0ms, total 3ms
D/dalvikvm( 140): GC_EXPLICIT freed <1K, 7% free 492K/528K, paused 0ms+0ms, total 2ms
D/dalvikvm( 140): GC_EXPLICIT freed <1K, 7% free 492K/528K, paused 1ms+0ms, total 2ms
I/dalvikvm( 140): System server process 358 has been created
I/Zygote ( 140): Accepting command socket connections
D/SensorService( 358): nuSensorService starting...
I/SystemServer( 358): Entered the Android system server!
E/ ( 358): Couldn't find 'FreescaleAccelerometer' input device
E/ ( 358): Couldn't open /dev/mma8x5x (No such file or directory)
E/ ( 358): Can`t find the Acc sensor!
E/ ( 358): Couldn't find 'eCompass' input device
E/ ( 358): Can`t find the mag sensor!
E/ ( 358): Couldn't find 'isl29023 light sensor' input device
I/SensorService( 358): Freescale 3-axis Accelerometer
I/SensorService( 358): Freescale 3-axis Magnetic field sensor
I/SensorService( 358): Freescale Orientation sensor
I/SensorService( 358): ISL29023 Light sensor
D/SensorService( 358): Max socket buffer size 163840
D/SensorService( 358): nuSensorService thread starting...
I/installd( 147): new connection
I/SystemServer( 358): Waiting for installd to be ready.
I/Installer( 358): connecting...
I/SystemServer( 358): Power Manager
E/SWITCHPROFILE( 358): setprop: sys.interactive = active
I/SystemServer( 358): Activity Manager
I/ActivityManager( 358): Memory class: 64
D/dalvikvm( 358): GC_CONCURRENT freed 73K, 12% free 835K/944K, paused 2ms+0ms, total 6ms
W/BatteryStatsImpl( 358): Couldn't get kernel wake lock stats
D/dalvikvm( 358): GC_CONCURRENT freed 233K, 21% free 1027K/1296K, paused 16ms+1ms, total 23ms
W/UsageStats( 358): Usage stats version changed; dropping
D/dalvikvm( 358): GC_CONCURRENT freed 470K, 35% free 945K/1448K, paused 1ms+0ms, total 7ms
D/dalvikvm( 358): GC_CONCURRENT freed 388K, 35% free 943K/1448K, paused 2ms+1ms, total 7ms
V/NatController( 143): runCmd(/system/bin/iptables -F natctrl_FORWARD) res=0
V/NatController( 143): runCmd(/system/bin/iptables -A natctrl_FORWARD -j DROP) res=0
V/NatController( 143): runCmd(/system/bin/iptables -t nat -F natctrl_nat_POSTROUTING) res=0
V/NatController( 143): runCmd(/system/bin/ip rule flush) res=0
V/NatController( 143): runCmd(/system/bin/ip -6 rule flush) res=0
V/NatController( 143): runCmd(/system/bin/ip rule add from all lookup default prio 32767) res=0
V/NatController( 143): runCmd(/system/bin/ip rule add from all lookup main prio 32766) res=0
V/NatController( 143): runCmd(/system/bin/ip -6 rule add from all lookup default prio 32767) res=0
V/NatController( 143): runCmd(/system/bin/ip -6 rule add from all lookup main prio 32766) res=0
V/NatController( 143): runCmd(/system/bin/ip route flush cache) res=0
D/dalvikvm( 358): GC_CONCURRENT freed 384K, 35% free 943K/1448K, paused 1ms+1ms, total 6ms
V/NatController( 143): runCmd(/system/bin/iptables -F natctrl_tether_counters) res=1
V/NatController( 143): runCmd(/system/bin/iptables -X natctrl_tether_counters) res=1
V/NatController( 143): runCmd(/system/bin/iptables -N natctrl_tether_counters) res=0
D/dalvikvm( 358): GC_CONCURRENT freed 384K, 35% free 943K/1448K, paused 1ms+0ms, total 7ms
D/dalvikvm( 358): GC_CONCURRENT freed 384K, 35% free 943K/1448K, paused 2ms+1ms, total 8ms
D/dalvikvm( 358): GC_CONCURRENT freed 384K, 35% free 943K/1448K, paused 1ms+1ms, total 6ms
D/dalvikvm( 358): GC_CONCURRENT freed 384K, 35% free 943K/1448K, paused 1ms+0ms, total 7ms
D/dalvikvm( 358): GC_CONCURRENT freed 384K, 35% free 943K/1448K, paused 2ms+1ms, total 7ms
D/MDnsDS ( 143): MDnsSdListener::Hander starting up
D/MDnsDS ( 143): MDnsSdListener starting to monitor
D/MDnsDS ( 143): Going to poll with pollCount 1
D/dalvikvm( 358): GC_CONCURRENT freed 386K, 35% free 943K/1448K, paused 2ms+2ms, total 8ms
D/dalvikvm( 358): GC_CONCURRENT freed 390K, 35% free 943K/1448K, paused 1ms+2ms, total 8ms
D/dalvikvm( 358): GC_CONCURRENT freed 389K, 35% free 944K/1448K, paused 1ms+1ms, total 7ms
D/dalvikvm( 358): GC_CONCURRENT freed 393K, 35% free 944K/1448K, paused 1ms+1ms, total 7ms
D/dalvikvm( 358): GC_CONCURRENT freed 393K, 35% free 944K/1448K, paused 2ms+0ms, total 7ms
D/dalvikvm( 358): GC_CONCURRENT freed 393K, 35% free 944K/1448K, paused 2ms+1ms, total 8ms
D/dalvikvm( 358): GC_CONCURRENT freed 393K, 35% free 943K/1448K, paused 2ms+2ms, total 8ms
D/dalvikvm( 358): GC_CONCURRENT freed 384K, 35% free 943K/1448K, paused 1ms+1ms, total 6ms
D/dalvikvm( 358): GC_CONCURRENT freed 389K, 35% free 944K/1448K, paused 1ms+1ms, total 7ms
D/dalvikvm( 358): GC_CONCURRENT freed 393K, 35% free 943K/1448K, paused 1ms+0ms, total 7ms
D/dalvikvm( 358): GC_CONCURRENT freed 393K, 35% free 944K/1448K, paused 2ms+1ms, total 8ms
D/dalvikvm( 358): GC_CONCURRENT freed 393K, 35% free 943K/1448K, paused 2ms+1ms, total 8ms
D/dalvikvm( 358): GC_CONCURRENT freed 393K, 35% free 944K/1448K, paused 1ms+0ms, total 7ms
D/dalvikvm( 358): GC_CONCURRENT freed 393K, 35% free 943K/1448K, paused 1ms+2ms, total 8ms
D/dalvikvm( 358): GC_CONCURRENT freed 389K, 35% free 943K/1448K, paused 2ms+1ms, total 8ms
D/dalvikvm( 358): GC_CONCURRENT freed 393K, 35% free 943K/1448K, paused 2ms+2ms, total 9ms
D/dalvikvm( 358): GC_CONCURRENT freed 393K, 35% free 944K/1448K, paused 1ms+1ms, total 7ms
D/dalvikvm( 358): GC_CONCURRENT freed 393K, 35% free 944K/1448K, paused 1ms+1ms, total 8ms
D/dalvikvm( 358): GC_CONCURRENT freed 393K, 35% free 944K/1448K, paused 2ms+0ms, total 7ms
D/dalvikvm( 358): GC_CONCURRENT freed 393K, 35% free 944K/1448K, paused 2ms+1ms, total 9ms
D/dalvikvm( 358): GC_CONCURRENT freed 393K, 35% free 944K/1448K, paused 2ms+0ms, total 7ms

通过日志信息，根据
D/dalvikvm( 358): GC_CONCURRENT freed 393K, 35% free 944K/1448K, paused 1ms+1ms, total 8ms分析:
PID 358 通过PS查询可知问题出在system_server:

root@sabresd_6dq_wh_leinuo:/ # ps | grep 358
system 358 140 840304 38768 ffffffff 2b0f7834 S system_server

top查询system_server系统占用：

root@sabresd_6dq_wh_leinuo:/ # top | grep system_server359 0 51% S 62 840304K 38680K fg system system_server

经过与正常日志对比发现，出现异常时发现多了一行打印：
W/UsageStats( 358): Usage stats version changed; dropping

代码跟踪

UsageStatsService 是Android一个私有service，主要作用是收集用户使用每一个APP的频率、使用时常等，用于统计应用程序的使用情况。

该service 是在ActivityManagerService服务中启动的：

framework/base/services/java/com/android/server/am/ActivityManagerService.java

     private ActivityManagerService() {Slog.i(TAG, "Memory class: " + ActivityManager.staticGetMemoryClass());mFgBroadcastQueue = new BroadcastQueue(this, "foreground", BROADCAST_FG_TIMEOUT, false);mBgBroadcastQueue = new BroadcastQueue(this, "background", BROADCAST_BG_TIMEOUT, true);mBroadcastQueues[0] = mFgBroadcastQueue;mBroadcastQueues[1] = mBgBroadcastQueue;mServices = new ActiveServices(this);mProviderMap = new ProviderMap(this);File dataDir = Environment.getDataDirectory();File systemDir = new File(dataDir, "system");systemDir.mkdirs();mBatteryStatsService = new BatteryStatsService(new File( systemDir, "batterystats.bin").toString());mBatteryStatsService.getActiveStatistics().readLocked();mBatteryStatsService.getActiveStatistics().writeAsyncLocked();mOnBattery = DEBUG_POWER ? true: mBatteryStatsService.getActiveStatistics().getIsOnBattery();mBatteryStatsService.getActiveStatistics().setCallback(this);mProcessStats = new ProcessStatsService(this, new File(systemDir, "procstats"));mUsageStatsService = new UsageStatsService(new File(systemDir, "usagestats").toString());mAppOpsService = new AppOpsService(new File(systemDir, "appops.xml"));mGrantFile = new AtomicFile(new File(systemDir, "urigrants.xml"));mHeadless = "1".equals(SystemProperties.get("ro.config.headless", "0"));// User 0 is the first and only user that runs at boot.mStartedUsers.put(0, new UserStartedState(new UserHandle(0), true));mUserLru.add(Integer.valueOf(0));updateStartedUserArrayLocked();GL_ES_VERSION = SystemProperties.getInt("ro.opengles.version",ConfigurationInfo.GL_ES_VERSION_UNDEFINED);mConfiguration.setToDefaults();mConfiguration.setLocale(Locale.getDefault());......

搜索错误信息：Usage stats version changed; dropping
发现在文件：framework/base/services/java/com/android/server/am/UsageStatsService.java中：

    private void readStatsFLOCK(File file) throws IOException {Parcel in = getParcelForFile(file);int vers = in.readInt();if (vers != VERSION) {Slog.w(TAG, "Usage stats version changed; dropping");                                                                                                                            return;}    int N = in.readInt();while (N > 0) { N--; String pkgName = in.readString();if (pkgName == null) {break;}    if (localLOGV) Slog.v(TAG, "Reading package #" + N + ": " + pkgName);PkgUsageStatsExtended pus = new PkgUsageStatsExtended(in);synchronized (mStatsLock) {mStats.put(pkgName, pus);}    }    }

UsageStatsService会在/data/system/usagestats/目录下保存一些记录app使用频率和时长的数据文件。类似如下：

root@sabresd_6dq_wh_leinuo:/data/system/usagestats # ls -l
-rw------- system system 0    2019-08-17 16:30 usage-20190817
-rw------- system system 340  2019-09-22 14:15 usage-20190921
-rw------- system system 2008 2019-01-01 12:00 usage-20190922
-rw------- system system 880  2024-05-08 23:00 usage-20300423
-rw------- system system 0    2019-10-19 00:07 usage-history.xml

其中：
/data/system/usagestats/usage-日期” 文件记录的当天的使用记录的数据
/data/system/usagestats/usage-history.xml文件中读取每个APP中每个Activity最后启动的时间

UsageStatsService服务启动的时候，会去读取并解析这些文件。一般情况下，UsageStatsService取到的ver与 VERSION(常量1007)，通过增加log，发现这里取到的ver居然为0，/data/system/usagestats/usage-history.xml文件，为空文件零字节的！

猜想和验证

猜想：会不会是 system_server初始化过程中，UsageStatService解析这些零字节文件时发生了文件操作异常？

验证：使用 lsof 命令查看出问题时data分区所有被打开的文件，发现其中就有usage-history.xml ！并且操作该文件的进程恰恰就是system_server

root@android:/data/system/usagestats #　lsof　| grep data
system_se 1283 system 54 ??? ??? ??? ??? /data/system/usagestats/usage-history.xml

问题定位

到这里基本可以确定是system_server 启动过程中在读写 usage-history.xml 文件时出了问题。但是如果是简单的文件操作错误，最多是报个crash，理论上CPU占用率不应该那么高。除非是文件操作过程中发生死锁或者死循环之类的致命错误。

查了代码，UsageStatsService服务会在多个地方操作到usage-history.xml 文件，单纯从代码上看，并不能快速确定出总理的地方。

或许可以看看 system_server的调用堆栈，兴许可以给我们留下一些线索…

查看进程堆栈，一种简单而实用的方法就是使用Android自带的DDMS工具。打开DDMS, 选中需要查看的进程号，这里选择的自然是 system_server (进程号为1283)，UsageStatsService是由ActivityManager启动的，因此先选中ActivityManager，接下来就查看相应的调用堆栈了。

从函数中调用堆栈信息中，可以看到UsageStatsService相关的堆栈停在了readHistoryStatsFLOCK()
readHistoryStatsFLOCK(AtomicFile file)函数主要负责解析我们前面说到的usage-history.xml文件。

Android4.4 XML的解析

在JAVA的世界里，解析xml文件有多种方式，不同的解析方式有着各自的优缺点和适用环境。在Android中常见的XML解析器分别为SAX解析器、DOM解析器以及PULL解析器。
看代码，知道上面使用的是PULL的方式来解析xml文件的，PULL技术是基于事件类型的解析，基本的事件类型有 5 个：

START_DOCUMENT (常量0，标记文档的开始)
START_TAG (常量2，标记一个标签的开始)
TEXT (常量4，标记一个标签的内容)
END_TAG (常量3，标记一个标签的结束)
END_DOCUMENT (常量1，标记文档的结束)
使用 parser.next() 可以进入下一个元素并触发相应事件。现在，再来看看刚才那段代码：

while (eventType != XmlPullParser.START_TAG) {eventType = parser.next();
}

从代码上分析，这里用了一个while循环，想要实现的功能是，一旦识别到XML的标签事件（START_TAG），便退出等待循环，开始usage-history.xml标签内容的解析工作。

但是，此处该码有一个致命的问题：如果待解析的XML文件中到达文件结尾时，还解析不到START_TAG事件，便会陷入死循环当中！

而一旦陷在while死循环里面，system_server便无法往下继续启动
其他系统服务，因而不会等到系统ready后通知系统进入桌面。于是便出现系统开机后一直停留在开机动画播放阶段，不断循环的现象！

而前面我们说到，该设备usage-history.xml是个零字节空文件，因此问题便出在这里了！

问题修复
知道原因，那么，便知道怎么修改了，一旦解析到达xml文件末尾，还解析不到
START_TAG 事件，就应该主动退出while循环。

- while (eventType != XmlPullParser.START_TAG) {
+ //Danny： Fix empty xml file cause death cycle
+ while (eventType != XmlPullParser.START_TAG && eventType != XmlPullParser.END_DOCUMENT) {eventType = parser.next();}

查看了各个历史版本，Android4.4以更低的版本皆存在这样的隐患问题，而Android5.0之后，由于UsageStatsService机制改变，因此已经修复该问题。

usage-history.xml一般情况下都会有内容，因此，触发到死循环的概率很低。但有些情况也可能导致 usage-history.xml为零字节：

比如用户强行断电情况下便可能导致IO读写无法正常结束，引发零字节问题。
比如 flash 硬件质量问题
比如Android Ext4文件系统的延迟分配（delalloc）功能，该功能网上反馈有有比较大的问题，可能造成数据丢失、0长度等问题，
PS: 解决此类问题的方案就是在分区挂载的时候，禁用延迟分配功能，也就是开启 nodelalloc 选项。

杯弓蛇影

解决完这个问题后，留了一心眼，重新搜索了整个Android4.4的系统源码，发现还有几处代码也是采用 “while (eventType != XmlPullParser.START_TAG)” 这样的写法，并且没有主动判断跳出循环。这些地方也是埋了坑的，哪天不小心就会陷入这些死循环，导致另一个开机白屏问题。因此，也是需要把这些隐患一块修复掉！

diff --git a/services/java/com/android/server/am/CompatModePackages.java b/services/java/com/android/server/am/CompatModePackages.java
index 59e6787..470ecea 100755
--- a/services/java/com/android/server/am/CompatModePackages.java
+++ b/services/java/com/android/server/am/CompatModePackages.java
@@ -64,7 +64,8 @@ public final class CompatModePackages {XmlPullParser parser = Xml.newPullParser();parser.setInput(fis, null);int eventType = parser.getEventType();
- while (eventType != XmlPullParser.START_TAG) {
+ /* Fixed empty xml file cause death cycle */
+ while (eventType != XmlPullParser.START_TAG && eventType != XmlPullParser.END_DOCUMENT) {eventType = parser.next();}String tagName = parser.getName();
diff --git a/services/java/com/android/server/am/UsageStatsService.java b/services/java/com/android/server/am/UsageStatsService.java
index e96d8b1..40e43cb 100755
--- a/services/java/com/android/server/am/UsageStatsService.java
+++ b/services/java/com/android/server/am/UsageStatsService.java
@@ -396,8 +396,9 @@ public final class UsageStatsService extends IUsageStats.Stub {XmlPullParser parser = Xml.newPullParser();parser.setInput(fis, null);int eventType = parser.getEventType();
- while (eventType != XmlPullParser.START_TAG) {
- eventType = parser.next();
+ /* Fixed empty xml file cause death cycle */
+ while (eventType != XmlPullParser.START_TAG && eventType != XmlPullParser.END_DOCUMENT) {
+ eventType = parser.next();}String tagName = parser.getName();
diff --git a/services/java/com/android/server/am/UsageStatsService.java b/services/java/com/android/server/am/UsageStatsService.java
index e96d8b1..40e43cb 100755
--- a/services/java/com/android/server/am/UsageStatsService.java
+++ b/services/java/com/android/server/am/UsageStatsService.java
@@ -396,8 +396,9 @@ public final class UsageStatsService extends IUsageStats.Stub {XmlPullParser parser = Xml.newPullParser();parser.setInput(fis, null);int eventType = parser.getEventType();
- while (eventType != XmlPullParser.START_TAG) {
- eventType = parser.next();
+ /* Fixed empty xml file cause death cycle */
+ while (eventType != XmlPullParser.START_TAG && eventType != XmlPullParser.END_DOCUMENT) {
+ eventType = parser.next();}String tagName = parser.getName();if ("usage-history".equals(tagName)) {
diff --git a/services/java/com/android/server/content/SyncStorageEngine.java b/services/java/com/android/server/content/SyncStorageEngine.java
index 781280e..e8c45ff 100755
--- a/services/java/com/android/server/content/SyncStorageEngine.java
+++ b/services/java/com/android/server/content/SyncStorageEngine.java
@@ -1697,7 +1697,8 @@ public class SyncStorageEngine extends Handler {XmlPullParser parser = Xml.newPullParser();parser.setInput(fis, null);int eventType = parser.getEventType();
- while (eventType != XmlPullParser.START_TAG) {
+ /* Fixed empty xml file cause death cycle */
+ while (eventType != XmlPullParser.START_TAG && eventType != XmlPullParser.END_DOCUMENT) {eventType = parser.next();}String tagName = parser.getName();
(END)