This morning my Xperia 10iii (SFOS 5.0.0.77) entered the Android restart loop as well. After several attempts, I managed to extract these logs:
05-05 08:08:43.223 310 338 W system_server: Throwing OutOfMemoryError "Failed to allocate a 104 byte allocation with 438952 free bytes and 428KB
until OOM, target footprint 268435456, growth limit 268435456; giving up on allocation because <1% of heap free after GC." (VmSize 17406728 kB)
05-05 08:08:43.223 310 338 E AndroidRuntime: *** FATAL EXCEPTION IN SYSTEM PROCESS: android.bg
05-05 08:08:43.223 310 338 E AndroidRuntime: java.lang.OutOfMemoryError: Failed to allocate a 104 byte allocation with 438952 free bytes and 428
KB until OOM, target footprint 268435456, growth limit 268435456; giving up on allocation because <1% of heap free after GC.
So it’s the heap thing. Do we really not have a solution to this? This is terrible.
EDIT: This is a full log from a crash:
05-05 08:38:10.487 62 62 D AndroidRuntime: >>>>>> START com.android.internal.os.ZygoteInit uid 0 <<<<<<
05-05 08:38:10.794 61 61 D AndroidRuntime: >>>>>> START com.android.internal.os.ZygoteInit uid 0 <<<<<<
05-05 08:38:11.321 62 62 I AndroidRuntime: Using default boot image
05-05 08:38:11.321 62 62 I AndroidRuntime: Leaving lock profiling enabled
05-05 08:38:11.673 61 61 I AndroidRuntime: Using default boot image
05-05 08:38:11.673 61 61 I AndroidRuntime: Leaving lock profiling enabled
05-05 08:38:15.576 311 311 W system_server: Failed to upload odrefresh metrics: metrics file '/data/misc/odrefresh/odrefresh-metrics.txt' could not be opened: No such file or directory
05-05 08:38:15.576 311 311 E system_server: Not starting debugger since process cannot load the jdwp agent.
05-05 08:38:16.132 311 311 E system_server: Disallowing getting service: android.hardware.memtrack@1.0::IMemtrack
05-05 08:38:16.210 311 346 E system_server: Cannot obtain CPU frequency count
05-05 08:38:16.211 311 346 E system_server: Cannot obtain CPU frequency count
05-05 08:38:16.211 311 346 E system_server: Cannot obtain CPU frequency count
05-05 08:38:16.212 311 346 E system_server: Cannot read thread CPU times for PID 311
05-05 08:38:16.319 311 346 E system_server: Cannot obtain CPU frequency count
05-05 08:38:16.320 311 346 E system_server: Cannot obtain CPU frequency count
05-05 08:38:16.320 311 346 E system_server: Cannot obtain CPU frequency count
05-05 08:38:16.321 311 346 E system_server: Cannot read thread CPU times for PID 311
05-05 08:38:16.805 311 346 E system_server: Cannot obtain CPU frequency count
05-05 08:38:16.806 311 346 E system_server: Cannot obtain CPU frequency count
05-05 08:38:16.806 311 346 E system_server: Cannot obtain CPU frequency count
05-05 08:38:16.806 311 346 E system_server: Cannot read thread CPU times for PID 311
05-05 08:38:16.846 311 323 I system_server: Background concurrent copying GC freed 216187(10MB) AllocSpace objects, 109(4420KB) LOS objects, 45% free, 7508KB/13MB, paused 122us,59us total 110.974ms
05-05 08:38:16.859 311 346 E system_server: Cannot obtain CPU frequency count
05-05 08:38:16.860 311 346 E system_server: Cannot obtain CPU frequency count
05-05 08:38:16.861 311 346 E system_server: Cannot obtain CPU frequency count
05-05 08:38:16.861 311 346 E system_server: Cannot read thread CPU times for PID 311
05-05 08:38:16.863 311 346 E system_server: Cannot obtain CPU frequency count
05-05 08:38:16.863 311 346 E system_server: Cannot obtain CPU frequency count
05-05 08:38:16.864 311 346 E system_server: Cannot obtain CPU frequency count
05-05 08:38:16.864 311 346 E system_server: Cannot read thread CPU times for PID 311
05-05 08:38:16.944 311 311 I system_server: Created attach input device service listener
05-05 08:38:17.262 311 340 I DropBoxManagerService: add tag=system_server_wtf isTagEnabled=true flags=0x2
05-05 08:38:17.307 311 340 I DropBoxManagerService: add tag=system_server_wtf isTagEnabled=true flags=0x2
05-05 08:38:17.308 311 340 I DropBoxManagerService: add tag=system_server_wtf isTagEnabled=true flags=0x2
05-05 08:38:17.310 311 340 I DropBoxManagerService: add tag=system_server_wtf isTagEnabled=true flags=0x2
05-05 08:38:17.311 311 340 I DropBoxManagerService: add tag=system_server_wtf isTagEnabled=true flags=0x2
05-05 08:38:17.313 311 340 I DropBoxManagerService: add tag=system_server_wtf isTagEnabled=true flags=0x2
05-05 08:38:17.758 311 311 I system_server: Waiting for a blocking GC ClassLinker
05-05 08:38:17.789 311 311 I system_server: WaitForGcToComplete blocked ClassLinker on Background for 31.341ms
05-05 08:38:17.858 311 311 W ActivityManager: Too early to start/bind service in system_server: Phase=550 ComponentInfo{com.android.server.telecom/com.android.server.telecom.components.TelecomService}
05-05 08:38:17.859 311 311 W ActivityManager: Too early to start/bind service in system_server: Phase=550 ComponentInfo{com.android.server.telecom/com.android.server.telecom.components.TelecomService}
05-05 08:38:18.093 311 311 D ConnectivityModuleConnector: Starting networking module in system_server process
05-05 08:38:18.095 311 311 D ConnectivityModuleConnector: Starting networking module in system_server process
05-05 08:38:18.248 311 311 I system_server: Waiting for a blocking GC ClassLinker
05-05 08:38:18.297 311 311 I system_server: WaitForGcToComplete blocked ClassLinker on Background for 47.136ms
05-05 08:38:18.903 510 510 I AndroidRuntime: VM exiting with result code 0, cleanup skipped.
05-05 08:38:18.956 511 511 I AndroidRuntime: VM exiting with result code 0, cleanup skipped.
05-05 08:38:19.163 311 339 I system_server: Using smaps_rollup for pss collection
05-05 08:38:19.186 311 346 E system_server: Cannot obtain CPU frequency count
05-05 08:38:19.187 311 346 E system_server: Cannot obtain CPU frequency count
05-05 08:38:19.188 311 346 E system_server: Cannot obtain CPU frequency count
05-05 08:38:19.188 311 346 E system_server: Cannot read thread CPU times for PID 311
05-05 08:38:19.455 311 323 I system_server: Background concurrent copying GC freed 27579(3000KB) AllocSpace objects, 21(772KB) LOS objects, 17% free, 28MB/34MB, paused 427us,282us total 113.746ms
05-05 08:38:19.659 311 323 I system_server: Background concurrent copying GC freed 12388(4034KB) AllocSpace objects, 5(164KB) LOS objects, 11% free, 47MB/53MB, paused 218us,285us total 112.965ms
05-05 08:38:19.849 311 323 I system_server: Background concurrent copying GC freed 10566(2277KB) AllocSpace objects, 0(0B) LOS objects, 9% free, 56MB/62MB, paused 153us,107us total 103.346ms
05-05 08:38:20.040 311 323 I system_server: Background concurrent copying GC freed 2023(2742KB) AllocSpace objects, 0(0B) LOS objects, 7% free, 78MB/84MB, paused 189us,86us total 114.120ms
05-05 08:38:20.287 311 323 I system_server: Background concurrent copying GC freed 382(242KB) AllocSpace objects, 0(0B) LOS objects, 5% free, 108MB/114MB, paused 683us,85us total 159.513ms
05-05 08:38:20.573 311 323 I system_server: Background concurrent copying GC freed 413(3472KB) AllocSpace objects, 7(140KB) LOS objects, 4% free, 136MB/142MB, paused 128us,80us total 186.290ms
05-05 08:38:20.861 311 323 I system_server: Background concurrent copying GC freed 6085(5489KB) AllocSpace objects, 0(0B) LOS objects, 3% free, 157MB/163MB, paused 734us,405us total 222.818ms
05-05 08:38:21.323 311 323 I system_server: Background concurrent copying GC freed 31115(1976KB) AllocSpace objects, 14(728KB) LOS objects, 3% free, 185MB/191MB, paused 143us,77us total 365.490ms
05-05 08:38:21.453 311 332 I system_server: Waiting for a blocking GC Explicit
05-05 08:38:21.532 311 323 I system_server: Background young concurrent copying GC freed 26065(4004KB) AllocSpace objects, 10(536KB) LOS objects, 0% free, 200MB/200MB, paused 119us,93us total 166.428ms
05-05 08:38:21.532 311 332 I system_server: Waiting for a blocking GC Explicit
05-05 08:38:21.905 311 323 I system_server: Background concurrent copying GC freed 1367(2696KB) AllocSpace objects, 0(0B) LOS objects, 2% free, 239MB/245MB, paused 121us,85us total 373.477ms
05-05 08:38:21.906 311 332 I system_server: WaitForGcToComplete blocked Explicit on Background for 452.536ms
05-05 08:38:22.019 311 339 I system_server: Waiting for a blocking GC Alloc
05-05 08:38:22.400 311 364 I system_server: Waiting for a blocking GC Alloc
05-05 08:38:22.434 311 389 I system_server: Waiting for a blocking GC Alloc
05-05 08:38:22.461 311 580 I system_server: Waiting for a blocking GC Alloc
05-05 08:38:22.546 311 332 I system_server: Explicit concurrent copying GC freed 27506(3984KB) AllocSpace objects, 0(0B) LOS objects, 2% free, 246MB/252MB, paused 259us,57us total 639.899ms
05-05 08:38:22.546 311 323 I system_server: WaitForGcToComplete blocked Background on Explicit for 578.536ms
05-05 08:38:22.546 311 339 I system_server: WaitForGcToComplete blocked Alloc on Explicit for 527.519ms
05-05 08:38:22.546 311 339 I system_server: Starting a blocking GC Alloc
05-05 08:38:22.546 311 364 I system_server: WaitForGcToComplete blocked Alloc on Explicit for 146.084ms
05-05 08:38:22.546 311 364 I system_server: Starting a blocking GC Alloc
05-05 08:38:22.547 311 389 I system_server: WaitForGcToComplete blocked Alloc on Explicit for 112.612ms
05-05 08:38:22.547 311 389 I system_server: Starting a blocking GC Alloc
05-05 08:38:22.547 311 580 I system_server: WaitForGcToComplete blocked Alloc on Explicit for 86.464ms
05-05 08:38:22.547 311 580 I system_server: Starting a blocking GC Alloc
05-05 08:38:22.601 311 339 I system_server: Waiting for a blocking GC Alloc
05-05 08:38:22.622 311 311 I system_server: Waiting for a blocking GC Alloc
05-05 08:38:22.641 311 507 I system_server: Waiting for a blocking GC Alloc
05-05 08:38:22.667 311 339 I system_server: WaitForGcToComplete blocked Alloc on Background for 66.082ms
05-05 08:38:22.667 311 339 I system_server: Starting a blocking GC Alloc
05-05 08:38:22.668 311 311 I system_server: Waiting for a blocking GC Alloc
05-05 08:38:22.669 311 507 I system_server: Waiting for a blocking GC Alloc
05-05 08:38:22.747 311 339 I system_server: Waiting for a blocking GC Alloc
05-05 08:38:22.749 311 423 I system_server: Waiting for a blocking GC Alloc
05-05 08:38:22.749 311 348 I system_server: Waiting for a blocking GC Alloc
05-05 08:38:22.875 311 340 I system_server: Waiting for a blocking GC Alloc
05-05 08:38:23.053 311 323 I system_server: Clamp target GC heap from 257MB to 256MB
05-05 08:38:23.054 311 323 I system_server: Background concurrent copying GC freed 2249(3691KB) AllocSpace objects, 0(0B) LOS objects, 1% free, 251MB/256MB, paused 143us,59us total 385.511ms
05-05 08:38:23.054 311 311 I system_server: WaitForGcToComplete blocked Alloc on Background for 432.144ms
05-05 08:38:23.054 311 311 I system_server: Starting a blocking GC Alloc
05-05 08:38:23.055 311 507 I system_server: WaitForGcToComplete blocked Alloc on Background for 413.717ms
05-05 08:38:23.055 311 507 I system_server: Starting a blocking GC Alloc
05-05 08:38:23.055 311 339 I system_server: WaitForGcToComplete blocked Alloc on Background for 307.643ms
05-05 08:38:23.055 311 339 I system_server: Starting a blocking GC Alloc
05-05 08:38:23.055 311 423 I system_server: WaitForGcToComplete blocked Alloc on Background for 306.575ms
05-05 08:38:23.055 311 423 I system_server: Starting a blocking GC Alloc
05-05 08:38:23.057 311 348 I system_server: WaitForGcToComplete blocked Alloc on Background for 307.368ms
05-05 08:38:23.057 311 348 I system_server: Starting a blocking GC Alloc
05-05 08:38:23.057 311 340 I system_server: WaitForGcToComplete blocked Alloc on Background for 182.254ms
05-05 08:38:23.057 311 340 I system_server: Starting a blocking GC Alloc
05-05 08:38:23.094 311 959 I system_server: Starting a blocking GC Alloc
05-05 08:38:23.094 311 959 I system_server: Starting a blocking GC Alloc
05-05 08:38:23.095 311 339 I system_server: Waiting for a blocking GC Alloc
05-05 08:38:23.128 311 580 I system_server: Waiting for a blocking GC Alloc
05-05 08:38:23.141 311 959 I system_server: Alloc young concurrent copying GC freed 3110(295KB) AllocSpace objects, 0(0B) LOS objects, 0% free, 254MB/256MB, paused 269us,66us total 46.794ms
05-05 08:38:23.141 311 959 I system_server: Forcing collection of SoftReferences for 24B allocation
05-05 08:38:23.141 311 959 I system_server: Starting a blocking GC Alloc
05-05 08:38:23.141 311 339 I system_server: Waiting for a blocking GC Alloc
05-05 08:38:23.141 311 580 I system_server: Waiting for a blocking GC Alloc
05-05 08:38:23.730 311 959 I system_server: Clamp target GC heap from 260MB to 256MB
05-05 08:38:23.730 311 959 I system_server: Alloc concurrent copying GC freed 1098(69KB) AllocSpace objects, 0(0B) LOS objects, 0% free, 254MB/256MB, paused 106us,62us total 589.197ms
05-05 08:38:23.731 311 959 W system_server: Throwing OutOfMemoryError "Failed to allocate a 24 byte allocation with 1555648 free bytes and 1519KB until OOM, target footprint 268435456, growth limit 268435456; giving up on allocation because <1% of heap free after GC." (VmSize 17123192 kB)
05-05 08:38:23.731 311 339 I system_server: WaitForGcToComplete blocked Alloc on Alloc for 635.701ms
05-05 08:38:23.731 311 339 I system_server: Starting a blocking GC Alloc
05-05 08:38:23.731 311 580 I system_server: WaitForGcToComplete blocked Alloc on Alloc for 603.141ms
05-05 08:38:23.731 311 580 I system_server: Starting a blocking GC Alloc
05-05 08:38:23.731 311 959 E AndroidRuntime: *** FATAL EXCEPTION IN SYSTEM PROCESS: NetworkMonitor/100
05-05 08:38:23.731 311 959 E AndroidRuntime: java.lang.OutOfMemoryError: Failed to allocate a 24 byte allocation with 1555648 free bytes and 1519KB until OOM, target footprint 268435456, growth limit 268435456; giving up on allocation because <1% of heap free after GC.
05-05 08:38:23.731 311 959 E AndroidRuntime: at com.android.server.connectivity.NetworkMonitor$DnsStallDetector.accumulateConsecutiveDnsTimeoutCount(NetworkMonitor.java:3347)
05-05 08:38:23.731 311 959 E AndroidRuntime: at com.android.server.connectivity.NetworkMonitor$ValidatedState.processMessage(NetworkMonitor.java:1161)
05-05 08:38:23.731 311 959 E AndroidRuntime: at android.net.networkstack.util.StateMachine$SmHandler.processMsg(StateMachine.java:993)
05-05 08:38:23.731 311 959 E AndroidRuntime: at android.net.networkstack.util.StateMachine$SmHandler.handleMessage(StateMachine.java:810)
05-05 08:38:23.731 311 959 E AndroidRuntime: at android.os.Handler.dispatchMessage(Handler.java:106)
05-05 08:38:23.731 311 959 E AndroidRuntime: at android.os.Looper.loopOnce(Looper.java:201)
05-05 08:38:23.731 311 959 E AndroidRuntime: at android.os.Looper.loop(Looper.java:288)
05-05 08:38:23.731 311 959 E AndroidRuntime: at android.os.HandlerThread.run(HandlerThread.java:67)
05-05 08:38:23.732 311 959 I DropBoxManagerService: add tag=system_server_crash isTagEnabled=true flags=0x2
05-05 08:38:23.929 61 61 E Zygote : Zygote failed to write to system_server FD: Connection refused
05-05 08:38:24.044 1006 1032 E AndroidRuntime: FATAL EXCEPTION: High Pri Worker #1
05-05 08:38:24.044 1006 1032 E AndroidRuntime: Process: com.whatsapp, PID: 1006
05-05 08:38:24.044 1006 1032 E AndroidRuntime: DeadSystemException: The system died; earlier logs will point to the root cause
05-05 08:38:25.164 549 549 D AndroidRuntime: Shutting down VM
05-05 08:38:25.165 549 549 E AndroidRuntime: FATAL EXCEPTION: main
05-05 08:38:25.165 549 549 E AndroidRuntime: Process: com.android.phone, PID: 549
05-05 08:38:25.165 549 549 E AndroidRuntime: DeadSystemException: The system died; earlier logs will point to the root cause