search

raspberrypi / userland

Source code for ARM side libraries for interfacing to Raspberry Pi GPU.
BSD 3-Clause "New" or "Revised" License
2.05k stars 1.09k forks source link

OpenMAX insufficient resources when getting handle for egl_render component #626

Closed ardera closed 4 years ago

ardera commented 4 years ago

Description

OMX_GetHandle(..., "OMX.broadcom.egl_render", ..., {EventHandler, EmptyBufferDone, FillBufferDone});

fails with OMX_ErrorInsufficientResources

To Reproduce

I'm afraid I can't give a reduced example for this one. I encountered this when I was trying to play the /opt/vc/src/hello_pi/hello_video/test.h264 video (without Desktop) with GStreamer, using the following command:

gst-launch-1.0 --gst-debug omx*:5 filesrc location= /opt/vc/src/hello_pi/hello_video/test.h264 ! h264parse ! omxh264dec ! fakevideosink

This needs gstreamer1.0-tools and gstreamer1.0-omx to be installed.

Expected behaviour

Expected is a return value of OMX_ErrorNone, since the GPU should have enough memory. I tried allocating 16, 128, 256 and 512MB to the GPU, (I'm not sure the Pi 4 cares about how much mem is allocated to its GPU) all with the same error. I also tried using the legacy graphics driver, with exactly the same result.

Actual behaviour

In reality, OMX_ErrorInsufficientResources is returned. I'm not sure where exactly the failed allocation ocurrs, but it looks like it's in this procedure.

Also, some vcdbg outputs before and after running gstreamer:

vcdbg reloc stats

Before executing gstreamer:

``` Relocatable heap version 4 found at 0x30000000 total space allocated is 236M, with 236M relocatable, 0 legacy and 0 offline 0 legacy blocks of size 2359296 small_allocs : 25 allocs : 17 alloc_fails : 0 legacy_block_fails : 0 compactions : 0 discard_compactions : 0 aggressive_compactions : 0 aggressive_compaction_waits : 0 aggressive_compaction_timeouts: 0 locks : 0 small_locks : 0 free list at 0x3ea82d20 235M free memory in 1 free block(s) largest free block is 235M bytes ```

After:

``` Relocatable heap version 4 found at 0x30000000 total space allocated is 236M, with 236M relocatable, 0 legacy and 0 offline 0 legacy blocks of size 2359296 small_allocs : 25 allocs : 18 alloc_fails : 0 legacy_block_fails : 0 compactions : 0 discard_compactions : 0 aggressive_compactions : 0 aggressive_compaction_waits : 0 aggressive_compaction_timeouts: 0 locks : 0 small_locks : 0 free list at 0x3ea82ae0 235M free memory in 1 free block(s) largest free block is 235M bytes ```

vcdbg reloc small

Before:

``` Relocatable heap version 4 found at 0x30000000 total space allocated is 236M, with 236M relocatable, 0 legacy and 0 offline 0 legacy blocks of size 2359296 free list at 0x3ea82d20 235M free memory in 1 free block(s) largest free block is 235M bytes 0x30000000: free 235M [ 4] 0x3ea82d40: used 576 (refcount 1 lock count 0, size 512, align 4, data 0x3ea82d60, d0rual) 'ILCS VC buffer pool' [ 3] 0x3ea82f80: used 1.5M (refcount 1 lock count 8, size 1536000, align 4096, data 0x3ea83000, d1rual) 'ARM FB' [ 2] 0x3ebfafa0: used 16K (refcount 1 lock count 0, size 16384, align 32, data 0x3ebfafc0, d0ruAl) 'audioplus_tmp_buf' [ 1] 0x3ebfefe0: used 4.0K (refcount 1 lock count 0, size 0, align 4096, data 0x3ebff000, d1rual) 'camera fast alloc arena' small allocs found at 0x3ef33140 [2147483648] 0x3ef33140: used 0 (refcount 1 lock count 0, size 0, align 4, data 0x3ef33160, d0rual) 'zero size' [2147483649] 0x3ef331a0: used 0 (refcount 1 lock count 0, size 1, align 1, data 0x3ef331c0, d0rual) 'empty string' ```

After:

``` Relocatable heap version 4 found at 0x30000000 total space allocated is 236M, with 236M relocatable, 0 legacy and 0 offline 0 legacy blocks of size 2359296 free list at 0x3ea82ae0 235M free memory in 1 free block(s) largest free block is 235M bytes 0x30000000: free 235M [ 5] 0x3ea82b00: used 576 (refcount 1 lock count 0, size 512, align 4, data 0x3ea82b20, d0rual) 'ILCS VC buffer pool' [ 4] 0x3ea82d40: used 576 (refcount 1 lock count 0, size 512, align 4, data 0x3ea82d60, d0rual) 'ILCS VC buffer pool' 0x3ea82d40: corrupt trailer (space 576 != 577) [ 3] 0x3ea82f80: used 1.5M (refcount 1 lock count 8, size 1536000, align 4096, data 0x3ea83000, d1rual) 'ARM FB' [ 2] 0x3ebfafa0: used 16K (refcount 1 lock count 0, size 16384, align 32, data 0x3ebfafc0, d0ruAl) 'audioplus_tmp_buf' [ 1] 0x3ebfefe0: used 4.0K (refcount 1 lock count 0, size 0, align 4096, data 0x3ebff000, d1rual) 'camera fast alloc arena' heap corruption detected small allocs found at 0x3ef33140 [2147483648] 0x3ef33140: used 0 (refcount 1 lock count 0, size 0, align 4, data 0x3ef33160, d0rual) 'zero size' [2147483649] 0x3ef331a0: used 0 (refcount 1 lock count 0, size 1, align 1, data 0x3ef331c0, d0rual) 'empty string' ```

vcdbg malloc

Before:

``` Pool 0xbf2f9658 (3ee759cc) Malloc pool size=13M (pool=0x3f2f9658-0x3ff7ff2c) 0x3f2f9680 = malloc(128K) [call from 0x3eda3b36] 0x3f3196a0 = malloc(120) [call from 0x3ed57738] 0x3f31a000 = malloc(138K) [call from 0x3ec737a8] 0x3f33d060 = malloc(512) [v3d_gfxh16_thre] 0x3f33d280 = malloc(7.3K) [dma_transfer_xfers] 0x3f33efa0 = malloc(10K) [Gencmd service state] 0x3f3417e0 = malloc(180) [vcos_cmd_entries] 0x3f3418c0 = malloc(4.0K) [reaper] 0x3f3428e0 = malloc(8.0K) [call from 0x3ee17768] 0x3f344900 = malloc(100) [call from 0x3ee17784] 0x3f3449a0 = malloc(108) [call from 0x3ec68aee] 0x3f344a40 = malloc(24) [call from 0x3ec68acc] 0x3f344a80 = malloc(32K) [call from 0x3ecc03a6] 0x3f34caa0 = malloc(512) [call from 0x3ed3234c] 0x3f34ccc0 = malloc(272) [call from 0x3ecc05e8] 0x3f34ce00 = malloc(272) [call from 0x3ecc05e8] 0x3f34cf40 = malloc(272) [call from 0x3ecc05e8] 0x3f34d080 = malloc(272) [call from 0x3ecc05e8] 0x3f34d1c0 = malloc(272) [call from 0x3ecc05e8] 0x3f34d300 = malloc(272) [call from 0x3ecc05e8] 0x3f34d440 = malloc(272) [call from 0x3ecc05e8] 0x3f34d580 = malloc(272) [call from 0x3ecc05e8] 0x3f34d6c0 = malloc(272) [call from 0x3ecc05e8] 0x3f34d800 = malloc(272) [call from 0x3ecc05e8] 0x3f34d940 = malloc(272) [call from 0x3ecc05e8] 0x3f34da80 = malloc(272) [call from 0x3ecc05e8] 0x3f34dbc0 = malloc(272) [call from 0x3ecc05e8] 0x3f34dd00 = malloc(272) [call from 0x3ecc05e8] 0x3f34de40 = malloc(272) [call from 0x3ecc05e8] 0x3f34df80 = malloc(272) [call from 0x3ecc05e8] 0x3f34e0c0 = malloc(272) [call from 0x3ecc05e8] 0x3f34e200 = malloc(272) [call from 0x3ecc05e8] 0x3f34e340 = malloc(272) [call from 0x3ecc05e8] 0x3f34e480 = malloc(272) [call from 0x3ecc05e8] 0x3f34e5c0 = malloc(272) [call from 0x3ecc05e8] 0x3f34e700 = malloc(272) [call from 0x3ecc05e8] 0x3f34e840 = malloc(272) [call from 0x3ecc05e8] 0x3f34e980 = malloc(272) [call from 0x3ecc05e8] 0x3f34eac0 = malloc(272) [call from 0x3ecc05e8] 0x3f34ec00 = malloc(272) [call from 0x3ecc05e8] 0x3f34ed40 = malloc(272) [call from 0x3ecc05e8] 0x3f34ee80 = malloc(272) [call from 0x3ecc05e8] 0x3f34efc0 = malloc(272) [call from 0x3ecc05e8] 0x3f34f100 = malloc(272) [call from 0x3ecc05e8] 0x3f34f240 = malloc(272) [call from 0x3ecc05e8] 0x3f34f380 = malloc(272) [call from 0x3ecc05e8] 0x3f34f4c0 = malloc(272) [call from 0x3ecc05e8] 0x3f34f600 = malloc(272) [call from 0x3ecc05e8] 0x3f34f740 = malloc(272) [call from 0x3ecc05e8] 0x3f34f880 = malloc(272) [call from 0x3ecc05e8] 0x3f34f9c0 = malloc(272) [call from 0x3ecc05e8] 0x3f34fb00 = malloc(272) [call from 0x3ecc05e8] 0x3f34fc40 = malloc(272) [call from 0x3ecc05e8] 0x3f34fd80 = malloc(272) [call from 0x3ecc05e8] 0x3f34fec0 = malloc(272) [call from 0x3ecc05e8] 0x3f350000 = malloc(272) [call from 0x3ecc05e8] 0x3f350140 = malloc(272) [call from 0x3ecc05e8] 0x3f350280 = malloc(272) [call from 0x3ecc05e8] 0x3f3503c0 = malloc(272) [call from 0x3ecc05e8] 0x3f350500 = malloc(272) [call from 0x3ecc05e8] 0x3f350640 = malloc(272) [call from 0x3ecc05e8] 0x3f350780 = malloc(272) [call from 0x3ecc05e8] 0x3f3508c0 = malloc(272) [call from 0x3ecc05e8] 0x3f350a00 = malloc(272) [call from 0x3ecc05e8] 0x3f350b40 = malloc(512) [call from 0x3ec40b88] 0x3f350d60 = malloc(16K) [call from 0x3ec40bba] 0x3f354d80 = malloc(4.0K) [call from 0x3ec40c16] 0x3f355da0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f355e00 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f355e60 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f355ec0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f355f20 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f355f80 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f355fe0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356040 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f3560a0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356100 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356160 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f3561c0 = malloc(1008) [call from 0x3ec68204] 0x3f3565e0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356640 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f3566a0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356700 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356760 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f3567c0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356820 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356880 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f3568e0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356940 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f3569a0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356a00 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356a60 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356ac0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356b20 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356b80 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356be0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356c40 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356ca0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356d00 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356d60 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356dc0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356e20 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356e80 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356ee0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356f40 = malloc(4.0K) [call from 0x3ed11982] 0x3f357f60 = malloc(4.0K) [call from 0x3ed119b8] 0x3f358f80 = malloc(4.0K) [call from 0x3ed11982] 0x3f359fa0 = malloc(4.0K) [call from 0x3ed119b8] 0x3f35afc0 = malloc(8) [call from 0x3ec6354e] 0x3f35b000 = malloc(4.0K) [powerman] 0x3f35c020 = malloc(3.1K) [call from 0x3ec970e6] 0x3f35cc80 = malloc(356K) [call from 0x3ec97122] 0x3f3b5ca0 = malloc(356K) [call from 0x3ec9715c] 0x3f40ecc0 = malloc(115K) [call from 0x3ec9719e] 0x3f42ba80 = malloc(1.1K) [call from 0x3edd4c62] 0x3f42bf00 = malloc(2.0K) [call from 0x3edc620c] 0x3f42c720 = malloc(88) [call from 0x3ec6373e] 0x3f42c7a0 = malloc(16K) [call from 0x3ec59316] 0x3f4307c0 = malloc(4.0K) [display_update] 0x3f4317e0 = malloc(16K) [mbox_read] 0x3f435800 = malloc(4.0K) [display_update] 0x3f436820 = malloc(4.0K) [temp_check] 0x3f437840 = malloc(16K) [vchiq dma_xfer] 0x3f43b900 = malloc(16K) [vchiq dma_xfer] 0x3f43f9c0 = malloc(16K) [vchiq dma_xfer] 0x3f443a80 = malloc(16K) [vchiq dma_xfer] 0x3f447b40 = malloc(8.0K) [VCHIQ-0] 0x3f449b60 = malloc(8.0K) [VCHIQr-0] 0x3f44bb80 = malloc(8.0K) [VCHIQs-0] 0x3f44dba0 = malloc(56) [imageconv stats] 0x3f44dc00 = malloc(36) [vchiq_shim] 0x3f44dc60 = malloc(256) [vchiu_queue_init] 0x3f44dd80 = malloc(476) [VCHIQ service] 0x3f44df80 = malloc(36) [vchiq_shim] 0x3f44dfe0 = malloc(256) [vchiu_queue_init] 0x3f44e100 = malloc(476) [VCHIQ service] 0x3f44e300 = malloc(36) [vchiq_shim] 0x3f44e360 = malloc(256) [vchiu_queue_init] 0x3f44e480 = malloc(476) [VCHIQ service] 0x3f44e680 = malloc(36) [vchiq_shim] 0x3f44e6e0 = malloc(256) [vchiu_queue_init] 0x3f44e800 = malloc(476) [VCHIQ service] 0x3f44ea00 = malloc(36) [vchiq_shim] 0x3f44ea60 = malloc(256) [vchiu_queue_init] 0x3f44eb80 = malloc(476) [VCHIQ service] 0x3f44ed80 = malloc(36) [vchiq_shim] 0x3f44ede0 = malloc(256) [vchiu_queue_init] 0x3f44ef00 = malloc(476) [VCHIQ service] 0x3f44f100 = malloc(36) [vchiq_shim] 0x3f44f160 = malloc(256) [vchiu_queue_init] 0x3f44f280 = malloc(476) [VCHIQ service] 0x3f44f480 = malloc(36) [vchiq_shim] 0x3f44f4e0 = malloc(256) [vchiu_queue_init] 0x3f44f600 = malloc(476) [VCHIQ service] 0x3f44f800 = malloc(2.0K) [call from 0x3ee17768] 0x3f450000 = malloc(100) [call from 0x3ee17784] 0x3f4500a0 = malloc(4.0K) [GCMD_V] 0x3f4510c0 = malloc(2.0K) [HAUDVCHI] 0x3f4518e0 = malloc(36) [vchiq_shim] 0x3f451940 = malloc(256) [vchiu_queue_init] 0x3f451a60 = malloc(476) [VCHIQ service] 0x3f451c60 = malloc(37K) [ILCS State] 0x3f45af60 = malloc(1.0K) [vchiu_queue_init] 0x3f45b380 = malloc(476) [VCHIQ service] 0x3f45b580 = malloc(52) [ILCS_VC_COMMON] 0x3f45b5e0 = malloc(4.0K) [ILCS_VC] 0x3f45c600 = malloc(3.0K) [call from 0x3edde560] 0x3f45d220 = malloc(36) [vchiq_shim] 0x3f45d280 = malloc(256) [vchiu_queue_init] 0x3f45d3a0 = malloc(476) [VCHIQ service] 0x3f45d5a0 = malloc(36) [vchiq_shim] 0x3f45d600 = malloc(256) [vchiu_queue_init] 0x3f45d720 = malloc(476) [VCHIQ service] 0x3f45d920 = malloc(36) [vchiq_shim] 0x3f45d980 = malloc(256) [vchiu_queue_init] 0x3f45daa0 = malloc(476) [VCHIQ service] 0x3f45dca0 = malloc(36) [vchiq_shim] 0x3f45dd00 = malloc(256) [vchiu_queue_init] 0x3f45de20 = malloc(476) [VCHIQ service] 0x3f45e020 = malloc(36) [vchiq_shim] 0x3f45e080 = malloc(256) [vchiu_queue_init] 0x3f45e1a0 = malloc(476) [VCHIQ service] 0x3f45e3a0 = malloc(36) [vchiq_shim] 0x3f45e400 = malloc(256) [vchiu_queue_init] 0x3f45e520 = malloc(476) [VCHIQ service] 0x3f45e720 = malloc(36) [vchiq_shim] 0x3f45e780 = malloc(256) [vchiu_queue_init] 0x3f45e8a0 = malloc(476) [VCHIQ service] 0x3f45eaa0 = malloc(36) [vchiq_shim] 0x3f45eb00 = malloc(256) [vchiu_queue_init] 0x3f45ec20 = malloc(476) [VCHIQ service] 0x3f45ee20 = malloc(3.0K) [call from 0x3edde5d4] 0x3f45fa40 = malloc(36) [vchiq_shim] 0x3f45faa0 = malloc(256) [vchiu_queue_init] 0x3f45fbc0 = malloc(476) [VCHIQ service] 0x3f45fdc0 = malloc(36) [vchiq_shim] 0x3f45fe20 = malloc(256) [vchiu_queue_init] 0x3f45ff40 = malloc(476) [VCHIQ service] 0x3f460140 = malloc(36) [vchiq_shim] 0x3f4601a0 = malloc(256) [vchiu_queue_init] 0x3f4602c0 = malloc(476) [VCHIQ service] 0x3f4604c0 = malloc(36) [vchiq_shim] 0x3f460520 = malloc(256) [vchiu_queue_init] 0x3f460640 = malloc(476) [VCHIQ service] 0x3f460840 = malloc(36) [vchiq_shim] 0x3f4608a0 = malloc(256) [vchiu_queue_init] 0x3f4609c0 = malloc(476) [VCHIQ service] 0x3f460bc0 = malloc(36) [vchiq_shim] 0x3f460c20 = malloc(256) [vchiu_queue_init] 0x3f460d40 = malloc(476) [VCHIQ service] 0x3f460f40 = malloc(36) [vchiq_shim] 0x3f460fa0 = malloc(256) [vchiu_queue_init] 0x3f4610c0 = malloc(476) [VCHIQ service] 0x3f4612c0 = malloc(36) [vchiq_shim] 0x3f461320 = malloc(256) [vchiu_queue_init] 0x3f461440 = malloc(476) [VCHIQ service] 0x3f461640 = malloc(36) [vchiq_shim] 0x3f4616a0 = malloc(256) [vchiu_queue_init] 0x3f4617c0 = malloc(476) [VCHIQ service] 0x3f4619c0 = malloc(4.0K) [HREQ task] 0x3f4629e0 = malloc(4.6K) [call from 0x3edde694] 0x3f463c60 = malloc(4.0K) [FILESERV] 0x3f464c80 = malloc(36) [vchiq_shim] 0x3f464ce0 = malloc(256) [vchiu_queue_init] 0x3f464e00 = malloc(476) [VCHIQ service] 0x3f465000 = malloc(620) [Shared Memory Service] 0x3f4652a0 = malloc(4.0K) [sm_thread] 0x3f4662c0 = malloc(36) [vchiq_shim] 0x3f466320 = malloc(256) [vchiu_queue_init] 0x3f466440 = malloc(476) [VCHIQ service] 0x3f466640 = malloc(36) [vchiq_shim] 0x3f4666a0 = malloc(256) [vchiu_queue_init] 0x3f4667c0 = malloc(476) [VCHIQ service] 0x3f4669c0 = malloc(488) [Shared Memory Cache Test] 0x3f466be0 = malloc(4.0K) [smct_thread] 0x3f467c00 = malloc(36) [vchiq_shim] 0x3f467c60 = malloc(256) [vchiu_queue_init] 0x3f467d80 = malloc(476) [VCHIQ service] 0x3f467f80 = malloc(4.0K) [call from 0x3eddf4ec] 0x3f468fa0 = malloc(36) [vchiq_shim] 0x3f469000 = malloc(256) [vchiu_queue_init] 0x3f469120 = malloc(476) [VCHIQ service] 0x3f469320 = malloc(36) [vchiq_shim] 0x3f469380 = malloc(256) [vchiu_queue_init] 0x3f4694a0 = malloc(476) [VCHIQ service] 0x3f4696a0 = malloc(36) [vchiq_shim] 0x3f469700 = malloc(256) [vchiu_queue_init] 0x3f469820 = malloc(476) [VCHIQ service] 0x3f469a20 = malloc(36) [vchiq_shim] 0x3f469a80 = malloc(256) [vchiu_queue_init] 0x3f469ba0 = malloc(476) [VCHIQ service] 0x3f469da0 = malloc(36) [vchiq_shim] 0x3f469e00 = malloc(256) [vchiu_queue_init] 0x3f469f20 = malloc(476) [VCHIQ service] 0x3f46a120 = malloc(36) [vchiq_shim] 0x3f46a180 = malloc(256) [vchiu_queue_init] 0x3f46a2a0 = malloc(476) [VCHIQ service] 0x3f46a4a0 = malloc(36) [vchiq_shim] 0x3f46a500 = malloc(256) [vchiu_queue_init] 0x3f46a620 = malloc(476) [VCHIQ service] 0x3f46a820 = malloc(36) [vchiq_shim] 0x3f46a880 = malloc(256) [vchiu_queue_init] 0x3f46a9a0 = malloc(476) [VCHIQ service] 0x3f46aba0 = malloc(4.0K) [call from 0x3eddf568] 0x3f46bbc0 = malloc(36) [vchiq_shim] 0x3f46bc20 = malloc(256) [vchiu_queue_init] 0x3f46bd40 = malloc(476) [VCHIQ service] 0x3f46bf40 = malloc(36) [vchiq_shim] 0x3f46bfa0 = malloc(256) [vchiu_queue_init] 0x3f46c0c0 = malloc(476) [VCHIQ service] 0x3f46c2c0 = malloc(36) [vchiq_shim] 0x3f46c320 = malloc(256) [vchiu_queue_init] 0x3f46c440 = malloc(476) [VCHIQ service] 0x3f46c640 = malloc(36) [vchiq_shim] 0x3f46c6a0 = malloc(256) [vchiu_queue_init] 0x3f46c7c0 = malloc(476) [VCHIQ service] 0x3f46c9c0 = malloc(36) [vchiq_shim] 0x3f46ca20 = malloc(256) [vchiu_queue_init] 0x3f46cb40 = malloc(476) [VCHIQ service] 0x3f46cd40 = malloc(36) [vchiq_shim] 0x3f46cda0 = malloc(256) [vchiu_queue_init] 0x3f46cec0 = malloc(476) [VCHIQ service] 0x3f46d0c0 = malloc(36) [vchiq_shim] 0x3f46d120 = malloc(256) [vchiu_queue_init] 0x3f46d240 = malloc(476) [VCHIQ service] 0x3f46d440 = malloc(36) [vchiq_shim] 0x3f46d4a0 = malloc(256) [vchiu_queue_init] 0x3f46d5c0 = malloc(476) [VCHIQ service] 0x3f46d7c0 = malloc(4.0K) [] 0x3f46e7e0 = malloc(36) [vchiq_shim] 0x3f46e840 = malloc(256) [vchiu_queue_init] 0x3f46e960 = malloc(476) [VCHIQ service] 0x3f46eb60 = malloc(36) [vchiq_shim] 0x3f46ebc0 = malloc(256) [vchiu_queue_init] 0x3f46ece0 = malloc(476) [VCHIQ service] 0x3f46eee0 = malloc(36) [vchiq_shim] 0x3f46ef40 = malloc(256) [vchiu_queue_init] 0x3f46f060 = malloc(476) [VCHIQ service] 0x3f46f260 = malloc(36) [vchiq_shim] 0x3f46f2c0 = malloc(256) [vchiu_queue_init] 0x3f46f3e0 = malloc(476) [VCHIQ service] 0x3f46f5e0 = malloc(36) [vchiq_shim] 0x3f46f640 = malloc(256) [vchiu_queue_init] 0x3f46f760 = malloc(476) [VCHIQ service] 0x3f46f960 = malloc(36) [vchiq_shim] 0x3f46f9c0 = malloc(256) [vchiu_queue_init] 0x3f46fae0 = malloc(476) [VCHIQ service] 0x3f46fce0 = malloc(36) [vchiq_shim] 0x3f46fd40 = malloc(256) [vchiu_queue_init] 0x3f46fe60 = malloc(476) [VCHIQ service] 0x3f470060 = malloc(36) [vchiq_shim] 0x3f4700c0 = malloc(256) [vchiu_queue_init] 0x3f4701e0 = malloc(476) [VCHIQ service] 0x3f4703e0 = malloc(4.0K) [] 0x3f471400 = malloc(36) [vchiq_shim] 0x3f471460 = malloc(256) [vchiu_queue_init] 0x3f471580 = malloc(476) [VCHIQ service] 0x3f471780 = malloc(36) [vchiq_shim] 0x3f4717e0 = malloc(256) [vchiu_queue_init] 0x3f471900 = malloc(476) [VCHIQ service] 0x3f471b00 = malloc(36) [vchiq_shim] 0x3f471b60 = malloc(256) [vchiu_queue_init] 0x3f471c80 = malloc(476) [VCHIQ service] 0x3f471e80 = malloc(36) [vchiq_shim] 0x3f471ee0 = malloc(256) [vchiu_queue_init] 0x3f472000 = malloc(476) [VCHIQ service] 0x3f472200 = malloc(36) [vchiq_shim] 0x3f472260 = malloc(256) [vchiu_queue_init] 0x3f472380 = malloc(476) [VCHIQ service] 0x3f472580 = malloc(36) [vchiq_shim] 0x3f4725e0 = malloc(256) [vchiu_queue_init] 0x3f472700 = malloc(476) [VCHIQ service] 0x3f472900 = malloc(36) [vchiq_shim] 0x3f472960 = malloc(256) [vchiu_queue_init] 0x3f472a80 = malloc(476) [VCHIQ service] 0x3f472c80 = malloc(36) [vchiq_shim] 0x3f472ce0 = malloc(256) [vchiu_queue_init] 0x3f472e00 = malloc(476) [VCHIQ service] 0x3f473000 = malloc(36) [vchiq_shim] 0x3f473060 = malloc(256) [vchiu_queue_init] 0x3f473180 = malloc(476) [VCHIQ service] 0x3f473380 = malloc(36) [vchiq_shim] 0x3f4733e0 = malloc(256) [vchiu_queue_init] 0x3f473500 = malloc(476) [VCHIQ service] 0x3f473700 = malloc(36) [vchiq_shim] 0x3f473760 = malloc(256) [vchiu_queue_init] 0x3f473880 = malloc(476) [VCHIQ service] 0x3f473a80 = malloc(36) [vchiq_shim] 0x3f473ae0 = malloc(256) [vchiu_queue_init] 0x3f473c00 = malloc(476) [VCHIQ service] 0x3f473e00 = malloc(36) [vchiq_shim] 0x3f473e60 = malloc(256) [vchiu_queue_init] 0x3f473f80 = malloc(476) [VCHIQ service] 0x3f474180 = malloc(36) [vchiq_shim] 0x3f4741e0 = malloc(256) [vchiu_queue_init] 0x3f474300 = malloc(476) [VCHIQ service] 0x3f474500 = malloc(36) [vchiq_shim] 0x3f474560 = malloc(256) [vchiu_queue_init] 0x3f474680 = malloc(476) [VCHIQ service] 0x3f474880 = malloc(36) [vchiq_shim] 0x3f4748e0 = malloc(256) [vchiu_queue_init] 0x3f474a00 = malloc(476) [VCHIQ service] 0x3f474c00 = malloc(476) [VCHIQ service] 0x3f474e00 = malloc(476) [VCHIQ service] 0x3f475000 = malloc(476) [VCHIQ service] 0x3f475200 = malloc(476) [VCHIQ service] 0x3f475400 = malloc(476) [VCHIQ service] 0x3f475600 = malloc(476) [VCHIQ service] 0x3f475800 = malloc(476) [VCHIQ service] 0x3f475a00 = malloc(476) [VCHIQ service] 0x3f475c00 = malloc(476) [VCHIQ service] 0x3f475e00 = malloc(476) [VCHIQ service] 0x3f476000 = malloc(476) [VCHIQ service] 0x3f476200 = malloc(32) [GPU queue] 0x3f476240 = malloc(32) [GPU queue] 0x3f476280 = malloc(32) [GPU queue] 0x3f4762c0 = malloc(4.0K) [stack] 0x3f4772e0 = malloc(4.0K) [stack] 0x3f478300 = malloc(4.0K) [stack] 0x3f479320 = malloc(4.3K) [mmal debug log] 0x3f47a460 = malloc(16K) [mmal_host_log] 0x3f47e4a0 = malloc(512) [vchiu_queue_init] 0x3f47e6c0 = malloc(476) [VCHIQ service] 0x3f47e8c0 = malloc(40) [call from 0x3ed61412] 0x3f47e920 = malloc(40) [call from 0x3ed61412] 0x3f47e980 = malloc(40) [call from 0x3ed61412] 0x3f47e9e0 = malloc(40) [call from 0x3ed61412] 0x3f47ea40 = malloc(40) [call from 0x3ed61412] 0x3f47eaa0 = malloc(40) [call from 0x3ed61412] 0x3f47eb00 = malloc(40) [call from 0x3ed61412] 0x3f47eb60 = malloc(40) [call from 0x3ed61412] 0x3f47ebc0 = malloc(40) [call from 0x3ed61412] 0x3f47ec20 = malloc(40) [call from 0x3ed61412] 0x3f47ec80 = malloc(40) [call from 0x3ed61412] 0x3f47ece0 = malloc(40) [call from 0x3ed61412] 0x3f47ed40 = malloc(40) [call from 0x3ed61412] 0x3f47eda0 = malloc(40) [call from 0x3ed61412] 0x3f47ee00 = malloc(40) [call from 0x3ed61412] 0x3f47ee60 = malloc(40) [call from 0x3ed61412] 0x3f47eec0 = malloc(40) [call from 0x3ed61412] 0x3f47ef20 = malloc(40) [call from 0x3ed61412] 0x3f47ef80 = malloc(40) [call from 0x3ed61412] 0x3f47efe0 = malloc(40) [call from 0x3ed61412] 0x3f47f040 = malloc(40) [call from 0x3ed61412] 0x3f47f0a0 = malloc(256) [mmal msg queue mem] 0x3f47f1c0 = malloc(4.0K) [mmal msg queue ] 0x3f4801e0 = malloc(4.0K) [mmal msg queue ] 0x3f481200 = malloc(4.0K) [mmal worker] 0x3f482220 = malloc(476) [VCHIQ service] 0x3f482420 = malloc(4.0K) [vc watchdog] 0x3f483440 = malloc(476) [VCHIQ service] 0x3f483640 = malloc(476) [VCHIQ service] 0x3f483840 = malloc(476) [VCHIQ service] 0x3f483a30 = hole(11M) Malloced:1.5M Remaining:11M Failed allocs:0 ```

After:

``` Pool 0xbf2f9658 (3ee759cc) Malloc pool size=13M (pool=0x3f2f9658-0x3ff7ff2c) 0x3f2f9680 = malloc(128K) [call from 0x3eda3b36] 0x3f3196a0 = malloc(120) [call from 0x3ed57738] 0x3f31a000 = malloc(138K) [call from 0x3ec737a8] 0x3f33d060 = malloc(512) [v3d_gfxh16_thre] 0x3f33d280 = malloc(7.3K) [dma_transfer_xfers] 0x3f33efa0 = malloc(10K) [Gencmd service state] 0x3f3417e0 = malloc(180) [vcos_cmd_entries] 0x3f3418c0 = malloc(4.0K) [reaper] 0x3f3428e0 = malloc(8.0K) [call from 0x3ee17768] 0x3f344900 = malloc(100) [call from 0x3ee17784] 0x3f3449a0 = malloc(108) [call from 0x3ec68aee] 0x3f344a40 = malloc(24) [call from 0x3ec68acc] 0x3f344a80 = malloc(32K) [call from 0x3ecc03a6] 0x3f34caa0 = malloc(512) [call from 0x3ed3234c] 0x3f34ccc0 = malloc(272) [call from 0x3ecc05e8] 0x3f34ce00 = malloc(272) [call from 0x3ecc05e8] 0x3f34cf40 = malloc(272) [call from 0x3ecc05e8] 0x3f34d080 = malloc(272) [call from 0x3ecc05e8] 0x3f34d1c0 = malloc(272) [call from 0x3ecc05e8] 0x3f34d300 = malloc(272) [call from 0x3ecc05e8] 0x3f34d440 = malloc(272) [call from 0x3ecc05e8] 0x3f34d580 = malloc(272) [call from 0x3ecc05e8] 0x3f34d6c0 = malloc(272) [call from 0x3ecc05e8] 0x3f34d800 = malloc(272) [call from 0x3ecc05e8] 0x3f34d940 = malloc(272) [call from 0x3ecc05e8] 0x3f34da80 = malloc(272) [call from 0x3ecc05e8] 0x3f34dbc0 = malloc(272) [call from 0x3ecc05e8] 0x3f34dd00 = malloc(272) [call from 0x3ecc05e8] 0x3f34de40 = malloc(272) [call from 0x3ecc05e8] 0x3f34df80 = malloc(272) [call from 0x3ecc05e8] 0x3f34e0c0 = malloc(272) [call from 0x3ecc05e8] 0x3f34e200 = malloc(272) [call from 0x3ecc05e8] 0x3f34e340 = malloc(272) [call from 0x3ecc05e8] 0x3f34e480 = malloc(272) [call from 0x3ecc05e8] 0x3f34e5c0 = malloc(272) [call from 0x3ecc05e8] 0x3f34e700 = malloc(272) [call from 0x3ecc05e8] 0x3f34e840 = malloc(272) [call from 0x3ecc05e8] 0x3f34e980 = malloc(272) [call from 0x3ecc05e8] 0x3f34eac0 = malloc(272) [call from 0x3ecc05e8] 0x3f34ec00 = malloc(272) [call from 0x3ecc05e8] 0x3f34ed40 = malloc(272) [call from 0x3ecc05e8] 0x3f34ee80 = malloc(272) [call from 0x3ecc05e8] 0x3f34efc0 = malloc(272) [call from 0x3ecc05e8] 0x3f34f100 = malloc(272) [call from 0x3ecc05e8] 0x3f34f240 = malloc(272) [call from 0x3ecc05e8] 0x3f34f380 = malloc(272) [call from 0x3ecc05e8] 0x3f34f4c0 = malloc(272) [call from 0x3ecc05e8] 0x3f34f600 = malloc(272) [call from 0x3ecc05e8] 0x3f34f740 = malloc(272) [call from 0x3ecc05e8] 0x3f34f880 = malloc(272) [call from 0x3ecc05e8] 0x3f34f9c0 = malloc(272) [call from 0x3ecc05e8] 0x3f34fb00 = malloc(272) [call from 0x3ecc05e8] 0x3f34fc40 = malloc(272) [call from 0x3ecc05e8] 0x3f34fd80 = malloc(272) [call from 0x3ecc05e8] 0x3f34fec0 = malloc(272) [call from 0x3ecc05e8] 0x3f350000 = malloc(272) [call from 0x3ecc05e8] 0x3f350140 = malloc(272) [call from 0x3ecc05e8] 0x3f350280 = malloc(272) [call from 0x3ecc05e8] 0x3f3503c0 = malloc(272) [call from 0x3ecc05e8] 0x3f350500 = malloc(272) [call from 0x3ecc05e8] 0x3f350640 = malloc(272) [call from 0x3ecc05e8] 0x3f350780 = malloc(272) [call from 0x3ecc05e8] 0x3f3508c0 = malloc(272) [call from 0x3ecc05e8] 0x3f350a00 = malloc(272) [call from 0x3ecc05e8] 0x3f350b40 = malloc(512) [call from 0x3ec40b88] 0x3f350d60 = malloc(16K) [call from 0x3ec40bba] 0x3f354d80 = malloc(4.0K) [call from 0x3ec40c16] 0x3f355da0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f355e00 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f355e60 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f355ec0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f355f20 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f355f80 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f355fe0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356040 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f3560a0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356100 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356160 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f3561c0 = malloc(1008) [call from 0x3ec68204] 0x3f3565e0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356640 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f3566a0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356700 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356760 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f3567c0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356820 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356880 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f3568e0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356940 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f3569a0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356a00 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356a60 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356ac0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356b20 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356b80 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356be0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356c40 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356ca0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356d00 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356d60 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356dc0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356e20 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356e80 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356ee0 = malloc(60) [GPIOMAN_DEFINE_T] 0x3f356f40 = malloc(4.0K) [call from 0x3ed11982] 0x3f357f60 = malloc(4.0K) [call from 0x3ed119b8] 0x3f358f80 = malloc(4.0K) [call from 0x3ed11982] 0x3f359fa0 = malloc(4.0K) [call from 0x3ed119b8] 0x3f35afc0 = malloc(8) [call from 0x3ec6354e] 0x3f35b000 = malloc(4.0K) [powerman] 0x3f35c020 = malloc(3.1K) [call from 0x3ec970e6] 0x3f35cc80 = malloc(356K) [call from 0x3ec97122] 0x3f3b5ca0 = malloc(356K) [call from 0x3ec9715c] 0x3f40ecc0 = malloc(115K) [call from 0x3ec9719e] 0x3f42ba80 = malloc(1.1K) [call from 0x3edd4c62] 0x3f42bf00 = malloc(2.0K) [call from 0x3edc620c] 0x3f42c720 = malloc(88) [call from 0x3ec6373e] 0x3f42c7a0 = malloc(16K) [call from 0x3ec59316] 0x3f4307c0 = malloc(4.0K) [display_update] 0x3f4317e0 = malloc(16K) [mbox_read] 0x3f435800 = malloc(4.0K) [display_update] 0x3f436820 = malloc(4.0K) [temp_check] 0x3f437840 = malloc(16K) [vchiq dma_xfer] 0x3f43b900 = malloc(16K) [vchiq dma_xfer] 0x3f43f9c0 = malloc(16K) [vchiq dma_xfer] 0x3f443a80 = malloc(16K) [vchiq dma_xfer] 0x3f447b40 = malloc(8.0K) [VCHIQ-0] 0x3f449b60 = malloc(8.0K) [VCHIQr-0] 0x3f44bb80 = malloc(8.0K) [VCHIQs-0] 0x3f44dba0 = malloc(56) [imageconv stats] 0x3f44dc00 = malloc(36) [vchiq_shim] 0x3f44dc60 = malloc(256) [vchiu_queue_init] 0x3f44dd80 = malloc(476) [VCHIQ service] 0x3f44df80 = malloc(36) [vchiq_shim] 0x3f44dfe0 = malloc(256) [vchiu_queue_init] 0x3f44e100 = malloc(476) [VCHIQ service] 0x3f44e300 = malloc(36) [vchiq_shim] 0x3f44e360 = malloc(256) [vchiu_queue_init] 0x3f44e480 = malloc(476) [VCHIQ service] 0x3f44e680 = malloc(36) [vchiq_shim] 0x3f44e6e0 = malloc(256) [vchiu_queue_init] 0x3f44e800 = malloc(476) [VCHIQ service] 0x3f44ea00 = malloc(36) [vchiq_shim] 0x3f44ea60 = malloc(256) [vchiu_queue_init] 0x3f44eb80 = malloc(476) [VCHIQ service] 0x3f44ed80 = malloc(36) [vchiq_shim] 0x3f44ede0 = malloc(256) [vchiu_queue_init] 0x3f44ef00 = malloc(476) [VCHIQ service] 0x3f44f100 = malloc(36) [vchiq_shim] 0x3f44f160 = malloc(256) [vchiu_queue_init] 0x3f44f280 = malloc(476) [VCHIQ service] 0x3f44f480 = malloc(36) [vchiq_shim] 0x3f44f4e0 = malloc(256) [vchiu_queue_init] 0x3f44f600 = malloc(476) [VCHIQ service] 0x3f44f800 = malloc(2.0K) [call from 0x3ee17768] 0x3f450000 = malloc(100) [call from 0x3ee17784] 0x3f4500a0 = malloc(4.0K) [GCMD_V] 0x3f4510c0 = malloc(2.0K) [HAUDVCHI] 0x3f4518e0 = malloc(36) [vchiq_shim] 0x3f451940 = malloc(256) [vchiu_queue_init] 0x3f451a60 = malloc(476) [VCHIQ service] 0x3f451c50 = hole(42K) 0x3f45c600 = malloc(3.0K) [call from 0x3edde560] 0x3f45d220 = malloc(36) [vchiq_shim] 0x3f45d280 = malloc(256) [vchiu_queue_init] 0x3f45d3a0 = malloc(476) [VCHIQ service] 0x3f45d5a0 = malloc(36) [vchiq_shim] 0x3f45d600 = malloc(256) [vchiu_queue_init] 0x3f45d720 = malloc(476) [VCHIQ service] 0x3f45d920 = malloc(36) [vchiq_shim] 0x3f45d980 = malloc(256) [vchiu_queue_init] 0x3f45daa0 = malloc(476) [VCHIQ service] 0x3f45dca0 = malloc(36) [vchiq_shim] 0x3f45dd00 = malloc(256) [vchiu_queue_init] 0x3f45de20 = malloc(476) [VCHIQ service] 0x3f45e020 = malloc(36) [vchiq_shim] 0x3f45e080 = malloc(256) [vchiu_queue_init] 0x3f45e1a0 = malloc(476) [VCHIQ service] 0x3f45e3a0 = malloc(36) [vchiq_shim] 0x3f45e400 = malloc(256) [vchiu_queue_init] 0x3f45e520 = malloc(476) [VCHIQ service] 0x3f45e720 = malloc(36) [vchiq_shim] 0x3f45e780 = malloc(256) [vchiu_queue_init] 0x3f45e8a0 = malloc(476) [VCHIQ service] 0x3f45eaa0 = malloc(36) [vchiq_shim] 0x3f45eb00 = malloc(256) [vchiu_queue_init] 0x3f45ec20 = malloc(476) [VCHIQ service] 0x3f45ee20 = malloc(3.0K) [call from 0x3edde5d4] 0x3f45fa40 = malloc(36) [vchiq_shim] 0x3f45faa0 = malloc(256) [vchiu_queue_init] 0x3f45fbc0 = malloc(476) [VCHIQ service] 0x3f45fdc0 = malloc(36) [vchiq_shim] 0x3f45fe20 = malloc(256) [vchiu_queue_init] 0x3f45ff40 = malloc(476) [VCHIQ service] 0x3f460140 = malloc(36) [vchiq_shim] 0x3f4601a0 = malloc(256) [vchiu_queue_init] 0x3f4602c0 = malloc(476) [VCHIQ service] 0x3f4604c0 = malloc(36) [vchiq_shim] 0x3f460520 = malloc(256) [vchiu_queue_init] 0x3f460640 = malloc(476) [VCHIQ service] 0x3f460840 = malloc(36) [vchiq_shim] 0x3f4608a0 = malloc(256) [vchiu_queue_init] 0x3f4609c0 = malloc(476) [VCHIQ service] 0x3f460bc0 = malloc(36) [vchiq_shim] 0x3f460c20 = malloc(256) [vchiu_queue_init] 0x3f460d40 = malloc(476) [VCHIQ service] 0x3f460f40 = malloc(36) [vchiq_shim] 0x3f460fa0 = malloc(256) [vchiu_queue_init] 0x3f4610c0 = malloc(476) [VCHIQ service] 0x3f4612c0 = malloc(36) [vchiq_shim] 0x3f461320 = malloc(256) [vchiu_queue_init] 0x3f461440 = malloc(476) [VCHIQ service] 0x3f461640 = malloc(36) [vchiq_shim] 0x3f4616a0 = malloc(256) [vchiu_queue_init] 0x3f4617c0 = malloc(476) [VCHIQ service] 0x3f4619c0 = malloc(4.0K) [HREQ task] 0x3f4629e0 = malloc(4.6K) [call from 0x3edde694] 0x3f463c60 = malloc(4.0K) [FILESERV] 0x3f464c80 = malloc(36) [vchiq_shim] 0x3f464ce0 = malloc(256) [vchiu_queue_init] 0x3f464e00 = malloc(476) [VCHIQ service] 0x3f465000 = malloc(620) [Shared Memory Service] 0x3f4652a0 = malloc(4.0K) [sm_thread] 0x3f4662c0 = malloc(36) [vchiq_shim] 0x3f466320 = malloc(256) [vchiu_queue_init] 0x3f466440 = malloc(476) [VCHIQ service] 0x3f466640 = malloc(36) [vchiq_shim] 0x3f4666a0 = malloc(256) [vchiu_queue_init] 0x3f4667c0 = malloc(476) [VCHIQ service] 0x3f4669c0 = malloc(488) [Shared Memory Cache Test] 0x3f466be0 = malloc(4.0K) [smct_thread] 0x3f467c00 = malloc(36) [vchiq_shim] 0x3f467c60 = malloc(256) [vchiu_queue_init] 0x3f467d80 = malloc(476) [VCHIQ service] 0x3f467f80 = malloc(4.0K) [call from 0x3eddf4ec] 0x3f468fa0 = malloc(36) [vchiq_shim] 0x3f469000 = malloc(256) [vchiu_queue_init] 0x3f469120 = malloc(476) [VCHIQ service] 0x3f469320 = malloc(36) [vchiq_shim] 0x3f469380 = malloc(256) [vchiu_queue_init] 0x3f4694a0 = malloc(476) [VCHIQ service] 0x3f4696a0 = malloc(36) [vchiq_shim] 0x3f469700 = malloc(256) [vchiu_queue_init] 0x3f469820 = malloc(476) [VCHIQ service] 0x3f469a20 = malloc(36) [vchiq_shim] 0x3f469a80 = malloc(256) [vchiu_queue_init] 0x3f469ba0 = malloc(476) [VCHIQ service] 0x3f469da0 = malloc(36) [vchiq_shim] 0x3f469e00 = malloc(256) [vchiu_queue_init] 0x3f469f20 = malloc(476) [VCHIQ service] 0x3f46a120 = malloc(36) [vchiq_shim] 0x3f46a180 = malloc(256) [vchiu_queue_init] 0x3f46a2a0 = malloc(476) [VCHIQ service] 0x3f46a4a0 = malloc(36) [vchiq_shim] 0x3f46a500 = malloc(256) [vchiu_queue_init] 0x3f46a620 = malloc(476) [VCHIQ service] 0x3f46a820 = malloc(36) [vchiq_shim] 0x3f46a880 = malloc(256) [vchiu_queue_init] 0x3f46a9a0 = malloc(476) [VCHIQ service] 0x3f46aba0 = malloc(4.0K) [call from 0x3eddf568] 0x3f46bbc0 = malloc(36) [vchiq_shim] 0x3f46bc20 = malloc(256) [vchiu_queue_init] 0x3f46bd40 = malloc(476) [VCHIQ service] 0x3f46bf40 = malloc(36) [vchiq_shim] 0x3f46bfa0 = malloc(256) [vchiu_queue_init] 0x3f46c0c0 = malloc(476) [VCHIQ service] 0x3f46c2c0 = malloc(36) [vchiq_shim] 0x3f46c320 = malloc(256) [vchiu_queue_init] 0x3f46c440 = malloc(476) [VCHIQ service] 0x3f46c640 = malloc(36) [vchiq_shim] 0x3f46c6a0 = malloc(256) [vchiu_queue_init] 0x3f46c7c0 = malloc(476) [VCHIQ service] 0x3f46c9c0 = malloc(36) [vchiq_shim] 0x3f46ca20 = malloc(256) [vchiu_queue_init] 0x3f46cb40 = malloc(476) [VCHIQ service] 0x3f46cd40 = malloc(36) [vchiq_shim] 0x3f46cda0 = malloc(256) [vchiu_queue_init] 0x3f46cec0 = malloc(476) [VCHIQ service] 0x3f46d0c0 = malloc(36) [vchiq_shim] 0x3f46d120 = malloc(256) [vchiu_queue_init] 0x3f46d240 = malloc(476) [VCHIQ service] 0x3f46d440 = malloc(36) [vchiq_shim] 0x3f46d4a0 = malloc(256) [vchiu_queue_init] 0x3f46d5c0 = malloc(476) [VCHIQ service] 0x3f46d7c0 = malloc(4.0K) [] 0x3f46e7e0 = malloc(36) [vchiq_shim] 0x3f46e840 = malloc(256) [vchiu_queue_init] 0x3f46e960 = malloc(476) [VCHIQ service] 0x3f46eb60 = malloc(36) [vchiq_shim] 0x3f46ebc0 = malloc(256) [vchiu_queue_init] 0x3f46ece0 = malloc(476) [VCHIQ service] 0x3f46eee0 = malloc(36) [vchiq_shim] 0x3f46ef40 = malloc(256) [vchiu_queue_init] 0x3f46f060 = malloc(476) [VCHIQ service] 0x3f46f260 = malloc(36) [vchiq_shim] 0x3f46f2c0 = malloc(256) [vchiu_queue_init] 0x3f46f3e0 = malloc(476) [VCHIQ service] 0x3f46f5e0 = malloc(36) [vchiq_shim] 0x3f46f640 = malloc(256) [vchiu_queue_init] 0x3f46f760 = malloc(476) [VCHIQ service] 0x3f46f960 = malloc(36) [vchiq_shim] 0x3f46f9c0 = malloc(256) [vchiu_queue_init] 0x3f46fae0 = malloc(476) [VCHIQ service] 0x3f46fce0 = malloc(36) [vchiq_shim] 0x3f46fd40 = malloc(256) [vchiu_queue_init] 0x3f46fe60 = malloc(476) [VCHIQ service] 0x3f470060 = malloc(36) [vchiq_shim] 0x3f4700c0 = malloc(256) [vchiu_queue_init] 0x3f4701e0 = malloc(476) [VCHIQ service] 0x3f4703e0 = malloc(4.0K) [] 0x3f471400 = malloc(36) [vchiq_shim] 0x3f471460 = malloc(256) [vchiu_queue_init] 0x3f471580 = malloc(476) [VCHIQ service] 0x3f471780 = malloc(36) [vchiq_shim] 0x3f4717e0 = malloc(256) [vchiu_queue_init] 0x3f471900 = malloc(476) [VCHIQ service] 0x3f471b00 = malloc(36) [vchiq_shim] 0x3f471b60 = malloc(256) [vchiu_queue_init] 0x3f471c80 = malloc(476) [VCHIQ service] 0x3f471e80 = malloc(36) [vchiq_shim] 0x3f471ee0 = malloc(256) [vchiu_queue_init] 0x3f472000 = malloc(476) [VCHIQ service] 0x3f472200 = malloc(36) [vchiq_shim] 0x3f472260 = malloc(256) [vchiu_queue_init] 0x3f472380 = malloc(476) [VCHIQ service] 0x3f472580 = malloc(36) [vchiq_shim] 0x3f4725e0 = malloc(256) [vchiu_queue_init] 0x3f472700 = malloc(476) [VCHIQ service] 0x3f472900 = malloc(36) [vchiq_shim] 0x3f472960 = malloc(256) [vchiu_queue_init] 0x3f472a80 = malloc(476) [VCHIQ service] 0x3f472c80 = malloc(36) [vchiq_shim] 0x3f472ce0 = malloc(256) [vchiu_queue_init] 0x3f472e00 = malloc(476) [VCHIQ service] 0x3f473000 = malloc(36) [vchiq_shim] 0x3f473060 = malloc(256) [vchiu_queue_init] 0x3f473180 = malloc(476) [VCHIQ service] 0x3f473380 = malloc(36) [vchiq_shim] 0x3f4733e0 = malloc(256) [vchiu_queue_init] 0x3f473500 = malloc(476) [VCHIQ service] 0x3f473700 = malloc(36) [vchiq_shim] 0x3f473760 = malloc(256) [vchiu_queue_init] 0x3f473880 = malloc(476) [VCHIQ service] 0x3f473a80 = malloc(36) [vchiq_shim] 0x3f473ae0 = malloc(256) [vchiu_queue_init] 0x3f473c00 = malloc(476) [VCHIQ service] 0x3f473e00 = malloc(36) [vchiq_shim] 0x3f473e60 = malloc(256) [vchiu_queue_init] 0x3f473f80 = malloc(476) [VCHIQ service] 0x3f474180 = malloc(36) [vchiq_shim] 0x3f4741e0 = malloc(256) [vchiu_queue_init] 0x3f474300 = malloc(476) [VCHIQ service] 0x3f474500 = malloc(36) [vchiq_shim] 0x3f474560 = malloc(256) [vchiu_queue_init] 0x3f474680 = malloc(476) [VCHIQ service] 0x3f474880 = malloc(36) [vchiq_shim] 0x3f4748e0 = malloc(256) [vchiu_queue_init] 0x3f474a00 = malloc(476) [VCHIQ service] 0x3f474c00 = malloc(476) [VCHIQ service] 0x3f474e00 = malloc(476) [VCHIQ service] 0x3f475000 = malloc(476) [VCHIQ service] 0x3f475200 = malloc(476) [VCHIQ service] 0x3f475400 = malloc(476) [VCHIQ service] 0x3f475600 = malloc(476) [VCHIQ service] 0x3f475800 = malloc(476) [VCHIQ service] 0x3f475a00 = malloc(476) [VCHIQ service] 0x3f475c00 = malloc(476) [VCHIQ service] 0x3f475e00 = malloc(476) [VCHIQ service] 0x3f476000 = malloc(476) [VCHIQ service] 0x3f476200 = malloc(32) [GPU queue] 0x3f476240 = malloc(32) [GPU queue] 0x3f476280 = malloc(32) [GPU queue] 0x3f4762c0 = malloc(4.0K) [stack] 0x3f4772e0 = malloc(4.0K) [stack] 0x3f478300 = malloc(4.0K) [stack] 0x3f479320 = malloc(4.3K) [mmal debug log] 0x3f47a460 = malloc(16K) [mmal_host_log] 0x3f47e4a0 = malloc(512) [vchiu_queue_init] 0x3f47e6c0 = malloc(476) [VCHIQ service] 0x3f47e8c0 = malloc(40) [call from 0x3ed61412] 0x3f47e920 = malloc(40) [call from 0x3ed61412] 0x3f47e980 = malloc(40) [call from 0x3ed61412] 0x3f47e9e0 = malloc(40) [call from 0x3ed61412] 0x3f47ea40 = malloc(40) [call from 0x3ed61412] 0x3f47eaa0 = malloc(40) [call from 0x3ed61412] 0x3f47eb00 = malloc(40) [call from 0x3ed61412] 0x3f47eb60 = malloc(40) [call from 0x3ed61412] 0x3f47ebc0 = malloc(40) [call from 0x3ed61412] 0x3f47ec20 = malloc(40) [call from 0x3ed61412] 0x3f47ec80 = malloc(40) [call from 0x3ed61412] 0x3f47ece0 = malloc(40) [call from 0x3ed61412] 0x3f47ed40 = malloc(40) [call from 0x3ed61412] 0x3f47eda0 = malloc(40) [call from 0x3ed61412] 0x3f47ee00 = malloc(40) [call from 0x3ed61412] 0x3f47ee60 = malloc(40) [call from 0x3ed61412] 0x3f47eec0 = malloc(40) [call from 0x3ed61412] 0x3f47ef20 = malloc(40) [call from 0x3ed61412] 0x3f47ef80 = malloc(40) [call from 0x3ed61412] 0x3f47efe0 = malloc(40) [call from 0x3ed61412] 0x3f47f040 = malloc(40) [call from 0x3ed61412] 0x3f47f0a0 = malloc(256) [mmal msg queue mem] 0x3f47f1c0 = malloc(4.0K) [mmal msg queue ] 0x3f4801e0 = malloc(4.0K) [mmal msg queue ] 0x3f481200 = malloc(4.0K) [mmal worker] 0x3f482220 = malloc(476) [VCHIQ service] 0x3f482420 = malloc(4.0K) [vc watchdog] 0x3f483440 = malloc(476) [VCHIQ service] 0x3f483640 = malloc(476) [VCHIQ service] 0x3f483840 = malloc(476) [VCHIQ service] 0x3f483a40 = malloc(37K) [ILCS State] 0x3f48cd40 = malloc(1.0K) [vchiu_queue_init] 0x3f48d160 = malloc(476) [VCHIQ service] 0x3f48d360 = malloc(52) [ILCS_VC_COMMON] 0x3f48d3c0 = malloc(4.0K) [] 0x3f48e3d0 = hole(11M) Malloced:1.5M Remaining:11M Failed allocs:0 ```

vcdbg log msg

``` 002315.457: arasan: arasan_emmc_open 002317.632: arasan: arasan_emmc_set_clock C0: 0x00000000 C1: 0x000e7187 emmc: 250000000 actual: 200000 div: 0x00000271 target: 200000 min: 100000 max: 400000 delay: 10 002434.386: arasan: arasan_emmc_set_clock C0: 0x00000000 C1: 0x000e7187 emmc: 250000000 actual: 200000 div: 0x00000271 target: 200000 min: 100000 max: 400000 delay: 10 002441.542: arasan: arasan_emmc_set_clock C0: 0x00000f00 C1: 0x000ec2c7 emmc: 250000000 actual: 129937 div: 0x000003c2 target: 130000 min: 100000 max: 400000 delay: 15 002496.543: arasan: arasan_emmc_set_clock C0: 0x00000f06 C1: 0x000e0307 emmc: 250000000 actual: 41666666 div: 0x00000003 target: 40000000 min: 0 max: 40000000 delay: 1 002752.220: brfs: File read: /mfs/sd/config.txt 002760.866: brfs: File read: 1808 bytes 002786.840: brfs: File read: /mfs/sd/config.txt 003234.826: gpioman: gpioman_get_pin_num: pin DISPLAY_DSI_PORT not defined 003537.411: *** Restart logging 003537.455: brfs: File read: 1808 bytes 003541.615: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead 003545.015: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead 003545.049: HDMI0: hdmi_pixel_encoding: 300000000 003545.063: HDMI1: hdmi_pixel_encoding: 300000000 003556.732: brfs: File read: /mfs/sd/bcm2711-rpi-4-b.dtb 003556.775: Loading 'bcm2711-rpi-4-b.dtb' to 0x100 size 0xa01c 003902.400: brfs: File read: 40988 bytes 003913.774: brfs: File read: /mfs/sd/overlays/rpi-ft5406.dtbo 003944.470: Loaded overlay 'rpi-ft5406' 004040.323: brfs: File read: 1018 bytes 004049.519: brfs: File read: /mfs/sd/overlays/rpi-backlight.dtbo 004079.890: Loaded overlay 'rpi-backlight' 004154.840: brfs: File read: 489 bytes 004159.433: brfs: File read: /mfs/sd/config.txt 004159.887: dtparam: spi=on 004197.111: dtparam: audio=on 004244.505: brfs: File read: 1808 bytes 004257.026: brfs: File read: /mfs/sd/overlays/vc4-fkms-v3d.dtbo 004333.624: Loaded overlay 'vc4-fkms-v3d' 004497.628: brfs: File read: 1255 bytes 004501.063: brfs: File read: /mfs/sd/cmdline.txt 004501.126: Read command line from file 'cmdline.txt': 004501.163: 'console=serial0,115200 console=tty1 root=PARTUUID=6c586e13-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait' 006109.754: brfs: File read: 121 bytes 006563.046: brfs: File read: /mfs/sd/kernel7l.img 006563.087: Loading 'kernel7l.img' to 0x8000 size 0x57d910 006563.126: Device tree loaded to 0x2eff5900 (size 0xa6a5) 006567.306: gpioman: gpioman_get_pin_num: pin SDCARD_CONTROL_POWER not defined 007927.238: vchiq_core: vchiq_init_state: slot_zero = 0xded80000, is_master = 1 012500.827: brfs: File read: 5757200 bytes ```

vcdbg log assert

No messages available

vcdbg log ex

No exceptions found

System

``` System Information ------------------ Raspberry Pi 4 Model B Rev 1.1 PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" Raspberry Pi reference 2019-09-26 Generated using pi-gen, https://github.com/RPi-Distro/pi-gen, 80d486687ea77d31fc3fc13cf3a2f8b464e129be, stage2 Linux hpi4 4.19.97-v7l+ #1294 SMP Thu Jan 30 13:21:14 GMT 2020 armv7l GNU/Linux Revision : b03111 Serial : 100000001afe70ee Model : Raspberry Pi 4 Model B Rev 1.1 Throttled flag : throttled=0x0 Camera : supported=0 detected=0 Videocore information --------------------- Feb 12 2020 12:36:21 Copyright (c) 2012 Broadcom version c3c8dbdf147686fb0c3f32aece709d0653368810 (clean) (release) (start) alloc failures: 0 compactions: 0 legacy block fails: 0 Filesystem information ---------------------- Filesystem 1K-blocks Used Available Use% Mounted on /dev/root 30391116 7106040 22014876 25% / devtmpfs 769552 0 769552 0% /dev tmpfs 901648 0 901648 0% /dev/shm tmpfs 901648 16860 884788 2% /run tmpfs 5120 4 5116 1% /run/lock tmpfs 901648 0 901648 0% /sys/fs/cgroup /dev/mmcblk0p1 258095 53465 204631 21% /boot tmpfs 180328 0 180328 0% /run/user/1000 Filename Type Size Used Priority /var/swap file 102396 0 -2 Package version information --------------------------- raspberrypi-ui-mods: Installed: 1.20200218 raspberrypi-sys-mods: Installed: 20191105 openbox: Installed: 3.6.1-8+rpt3 lxpanel: Installed: 0.10.0-2+rpt7 pcmanfm: Installed: 1.3.1-1+rpt20 rpd-plym-splash: Installed: 0.21 Networking Information ---------------------- eth0: flags=4163 mtu 1500 inet x.x.x.x netmask x.x.x.x broadcast x.x.x.x inet6 y.y.y.y.y.y.y.y prefixlen 64 scopeid 0x0 inet6 y::y.y.y.y prefixlen 64 scopeid 0x20 ether m.m.m.m txqueuelen 1000 (Ethernet) RX packets 2286 bytes 181939 (177.6 KiB) RX errors 0 dropped 4 overruns 0 frame 0 TX packets 1230 bytes 211225 (206.2 KiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 lo: flags=73 mtu 65536 inet x.x.x.x netmask x.x.x.x inet6 ::1 prefixlen 128 scopeid 0x10 loop txqueuelen 1000 (Local Loopback) RX packets 0 bytes 0 (0.0 B) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 0 bytes 0 (0.0 B) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 wlan0: flags=4163 mtu 1500 inet x.x.x.x netmask x.x.x.x broadcast x.x.x.x inet6 y::y.y.y.y prefixlen 64 scopeid 0x20 inet6 y.y.y.y.y.y.y.y prefixlen 64 scopeid 0x0 ether m.m.m.m txqueuelen 1000 (Ethernet) RX packets 708 bytes 40740 (39.7 KiB) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 42 bytes 5718 (5.5 KiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 USB Information --------------- /: Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/4p, 5000M /: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/1p, 480M |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/4p, 480M config.txt ---------- arm_freq=1500 audio_pwm_mode=514 config_hdmi_boost=5 core_freq=500 core_freq_min=200 disable_commandline_tags=2 disable_l2cache=1 disable_overscan=1 display_default_lcd=1 display_hdmi_rotate=-1 display_lcd_rotate=-1 enable_gic=1 enable_uart=1 force_eeprom_read=1 force_pwm_open=1 framebuffer_ignore_alpha=1 framebuffer_swap=1 gpu_freq=500 gpu_freq_min=250 init_uart_clock=0x2dc6c00 lcd_framerate=60 mask_gpu_interrupt0=1024 mask_gpu_interrupt1=0x10000 max_framebuffers=2 over_voltage_avs=-23750 pause_burst_frames=1 program_serial_random=1 total_mem=2048 hdmi_force_cec_address:0=65535 hdmi_force_cec_address:1=65535 hdmi_pixel_freq_limit:0=0x11e1a300 hdmi_pixel_freq_limit:1=0x11e1a300 device_tree=- overlay_prefix=overlays/ hdmi_cvt:0= hdmi_cvt:1= hdmi_edid_filename:0= hdmi_edid_filename:1= hdmi_timings:0= hdmi_timings:1= cmdline.txt ----------- coherent_pool=1M 8250.nr_uarts=1 cma=64M cma=256M smsc95xx.macaddr=DC:A6:32:2C:42:1A vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 console=ttyS0,115200 console=tty1 root=PARTUUID=6c586e13-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait raspi-gpio settings ------------------- BANK0 (GPIO 0 to 27): GPIO 0: level=1 fsel=0 func=INPUT pull=UP GPIO 1: level=1 fsel=0 func=INPUT pull=UP GPIO 2: level=1 fsel=0 func=INPUT pull=UP GPIO 3: level=1 fsel=0 func=INPUT pull=UP GPIO 4: level=1 fsel=0 func=INPUT pull=UP GPIO 5: level=1 fsel=0 func=INPUT pull=UP GPIO 6: level=1 fsel=0 func=INPUT pull=UP GPIO 7: level=1 fsel=1 func=OUTPUT pull=UP GPIO 8: level=1 fsel=1 func=OUTPUT pull=UP GPIO 9: level=0 fsel=4 alt=0 func=SPI0_MISO pull=DOWN GPIO 10: level=0 fsel=4 alt=0 func=SPI0_MOSI pull=DOWN GPIO 11: level=0 fsel=4 alt=0 func=SPI0_SCLK pull=DOWN GPIO 12: level=0 fsel=0 func=INPUT pull=DOWN GPIO 13: level=0 fsel=0 func=INPUT pull=DOWN GPIO 14: level=1 fsel=2 alt=5 func=TXD1 pull=NONE GPIO 15: level=1 fsel=2 alt=5 func=RXD1 pull=UP GPIO 16: level=0 fsel=0 func=INPUT pull=DOWN GPIO 17: level=0 fsel=0 func=INPUT pull=DOWN GPIO 18: level=0 fsel=0 func=INPUT pull=DOWN GPIO 19: level=0 fsel=0 func=INPUT pull=DOWN GPIO 20: level=0 fsel=0 func=INPUT pull=DOWN GPIO 21: level=0 fsel=0 func=INPUT pull=DOWN GPIO 22: level=0 fsel=0 func=INPUT pull=DOWN GPIO 23: level=0 fsel=0 func=INPUT pull=DOWN GPIO 24: level=0 fsel=0 func=INPUT pull=DOWN GPIO 25: level=0 fsel=0 func=INPUT pull=DOWN GPIO 26: level=0 fsel=0 func=INPUT pull=DOWN GPIO 27: level=0 fsel=0 func=INPUT pull=DOWN BANK1 (GPIO 28 to 45): GPIO 28: level=1 fsel=2 alt=5 func=RGMII_MDIO pull=UP GPIO 29: level=0 fsel=2 alt=5 func=RGMII_MDC pull=DOWN GPIO 30: level=0 fsel=7 alt=3 func=CTS0 pull=UP GPIO 31: level=0 fsel=7 alt=3 func=RTS0 pull=NONE GPIO 32: level=1 fsel=7 alt=3 func=TXD0 pull=NONE GPIO 33: level=1 fsel=7 alt=3 func=RXD0 pull=UP GPIO 34: level=1 fsel=7 alt=3 func=SD1_CLK pull=NONE GPIO 35: level=1 fsel=7 alt=3 func=SD1_CMD pull=UP GPIO 36: level=1 fsel=7 alt=3 func=SD1_DAT0 pull=UP GPIO 37: level=1 fsel=7 alt=3 func=SD1_DAT1 pull=UP GPIO 38: level=1 fsel=7 alt=3 func=SD1_DAT2 pull=UP GPIO 39: level=1 fsel=7 alt=3 func=SD1_DAT3 pull=UP GPIO 40: level=0 fsel=4 alt=0 func=PWM1_0 pull=NONE GPIO 41: level=0 fsel=4 alt=0 func=PWM1_1 pull=NONE GPIO 42: level=0 fsel=1 func=OUTPUT pull=UP GPIO 43: level=1 fsel=0 func=INPUT pull=UP GPIO 44: level=1 fsel=5 alt=1 func=SDA0 pull=UP GPIO 45: level=1 fsel=5 alt=1 func=SCL0 pull=UP BANK2 (GPIO 46 to 53): GPIO 46: level=0 fsel=0 func=INPUT pull=DOWN GPIO 47: level=0 fsel=0 func=INPUT pull=DOWN GPIO 48: level=0 fsel=0 func=INPUT pull=DOWN GPIO 49: level=0 fsel=0 func=INPUT pull=DOWN GPIO 50: level=0 fsel=0 func=INPUT pull=DOWN GPIO 51: level=0 fsel=0 func=INPUT pull=DOWN GPIO 52: level=0 fsel=0 func=INPUT pull=DOWN GPIO 53: level=0 fsel=0 func=INPUT pull=DOWN vcdbg log messages ------------------ 002314.495: arasan: arasan_emmc_open 002316.671: arasan: arasan_emmc_set_clock C0: 0x00000000 C1: 0x000e7187 emmc: 250000000 actual: 200000 div: 0x00000271 target: 200000 min: 100000 max: 400000 delay: 10 002433.431: arasan: arasan_emmc_set_clock C0: 0x00000000 C1: 0x000e7187 emmc: 250000000 actual: 200000 div: 0x00000271 target: 200000 min: 100000 max: 400000 delay: 10 002440.587: arasan: arasan_emmc_set_clock C0: 0x00000f00 C1: 0x000ec2c7 emmc: 250000000 actual: 129937 div: 0x000003c2 target: 130000 min: 100000 max: 400000 delay: 15 002495.038: arasan: arasan_emmc_set_clock C0: 0x00000f06 C1: 0x000e0307 emmc: 250000000 actual: 41666666 div: 0x00000003 target: 40000000 min: 0 max: 40000000 delay: 1 002762.507: brfs: File read: /mfs/sd/config.txt 002771.148: brfs: File read: 1808 bytes 002797.104: brfs: File read: /mfs/sd/config.txt 003245.083: gpioman: gpioman_get_pin_num: pin DISPLAY_DSI_PORT not defined 003547.678: *** Restart logging 003547.722: brfs: File read: 1808 bytes 003551.898: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead 003555.297: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead 003555.331: HDMI0: hdmi_pixel_encoding: 300000000 003555.345: HDMI1: hdmi_pixel_encoding: 300000000 003566.997: brfs: File read: /mfs/sd/bcm2711-rpi-4-b.dtb 003567.040: Loading 'bcm2711-rpi-4-b.dtb' to 0x100 size 0xa01c 003912.648: brfs: File read: 40988 bytes 003923.974: brfs: File read: /mfs/sd/overlays/rpi-ft5406.dtbo 003954.677: Loaded overlay 'rpi-ft5406' 004050.562: brfs: File read: 1018 bytes 004059.704: brfs: File read: /mfs/sd/overlays/rpi-backlight.dtbo 004090.053: Loaded overlay 'rpi-backlight' 004164.998: brfs: File read: 489 bytes 004169.578: brfs: File read: /mfs/sd/config.txt 004170.032: dtparam: spi=on 004207.231: dtparam: audio=on 004254.641: brfs: File read: 1808 bytes 004267.121: brfs: File read: /mfs/sd/overlays/vc4-fkms-v3d.dtbo 004343.686: Loaded overlay 'vc4-fkms-v3d' 004507.732: brfs: File read: 1255 bytes 004511.154: brfs: File read: /mfs/sd/cmdline.txt 004511.217: Read command line from file 'cmdline.txt': 004511.254: 'console=serial0,115200 console=tty1 root=PARTUUID=6c586e13-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait' 006120.153: brfs: File read: 121 bytes 006580.426: brfs: File read: /mfs/sd/kernel7l.img 006580.468: Loading 'kernel7l.img' to 0x8000 size 0x57d910 006580.507: Device tree loaded to 0x2eff5900 (size 0xa6a5) 006584.704: gpioman: gpioman_get_pin_num: pin SDCARD_CONTROL_POWER not defined 007944.504: vchiq_core: vchiq_init_state: slot_zero = 0xded80000, is_master = 1 012595.093: brfs: File read: 5757200 bytes dmesg log --------- [ 0.000000] Booting Linux on physical CPU 0x0 [ 0.000000] Linux version 4.19.97-v7l+ (dom@buildbot) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) #1294 SMP Thu Jan 30 13:21:14 GMT 2020 [ 0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d [ 0.000000] CPU: div instructions available: patching division code [ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache [ 0.000000] OF: fdt: Machine model: Raspberry Pi 4 Model B Rev 1.1 [ 0.000000] Memory policy: Data cache writealloc [ 0.000000] cma: Reserved 256 MiB at 0x000000001ec00000 [ 0.000000] On node 0 totalpages: 458752 [ 0.000000] DMA zone: 1728 pages used for memmap [ 0.000000] DMA zone: 0 pages reserved [ 0.000000] DMA zone: 196608 pages, LIFO batch:63 [ 0.000000] HighMem zone: 262144 pages, LIFO batch:63 [ 0.000000] random: get_random_bytes called from start_kernel+0xc0/0x4e8 with crng_init=0 [ 0.000000] percpu: Embedded 17 pages/cpu s36928 r8192 d24512 u69632 [ 0.000000] pcpu-alloc: s36928 r8192 d24512 u69632 alloc=17*4096 [ 0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 457024 [ 0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=1 cma=64M cma=256M smsc95xx.macaddr=m.m.m.m vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 console=ttyS0,115200 console=tty1 root=PARTUUID=6c586e13-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait [ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes) [ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes) [ 0.000000] Memory: 1539104K/1835008K available (8192K kernel code, 687K rwdata, 2408K rodata, 2048K init, 850K bss, 33760K reserved, 262144K cma-reserved, 1048576K highmem) [ 0.000000] Virtual kernel memory layout: vector : 0xffff0000 - 0xffff1000 ( 4 kB) fixmap : 0xffc00000 - 0xfff00000 (3072 kB) vmalloc : 0xf0800000 - 0xff800000 ( 240 MB) lowmem : 0xc0000000 - 0xf0000000 ( 768 MB) pkmap : 0xbfe00000 - 0xc0000000 ( 2 MB) modules : 0xbf000000 - 0xbfe00000 ( 14 MB) .text : 0x(ptrval) - 0x(ptrval) (10208 kB) .init : 0x(ptrval) - 0x(ptrval) (2048 kB) .data : 0x(ptrval) - 0x(ptrval) ( 688 kB) .bss : 0x(ptrval) - 0x(ptrval) ( 851 kB) [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1 [ 0.000000] ftrace: allocating 28692 entries in 85 pages [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16 [ 0.000000] GIC: Using split EOI/Deactivate mode [ 0.000000] arch_timer: cp15 timer(s) running at 54.00MHz (phys). [ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns [ 0.000005] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns [ 0.000022] Switching to timer-based delay loop, resolution 18ns [ 0.000247] Console: colour dummy device 80x30 [ 0.000701] console [tty1] enabled [ 0.000758] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=540000) [ 0.000795] pid_max: default: 32768 minimum: 301 [ 0.001077] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes) [ 0.001109] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes) [ 0.001873] CPU: Testing write buffer coherency: ok [ 0.002292] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000 [ 0.002942] Setting up static identity map for 0x200000 - 0x20003c [ 0.003114] rcu: Hierarchical SRCU implementation. [ 0.003982] smp: Bringing up secondary CPUs ... [ 0.004784] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001 [ 0.005700] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002 [ 0.006578] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003 [ 0.006711] smp: Brought up 1 node, 4 CPUs [ 0.006776] SMP: Total of 4 processors activated (432.00 BogoMIPS). [ 0.006799] CPU: All CPU(s) started in HYP mode. [ 0.006819] CPU: Virtualization extensions available. [ 0.007589] devtmpfs: initialized [ 0.017807] VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0 [ 0.018026] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns [ 0.018067] futex hash table entries: 1024 (order: 4, 65536 bytes) [ 0.025531] pinctrl core: initialized pinctrl subsystem [ 0.026397] NET: Registered protocol family 16 [ 0.029074] DMA: preallocated 1024 KiB pool for atomic coherent allocations [ 0.030486] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers. [ 0.030518] hw-breakpoint: maximum watchpoint size is 8 bytes. [ 0.030724] Serial: AMBA PL011 UART driver [ 0.034050] bcm2835-mbox fe00b880.mailbox: mailbox enabled [ 0.050018] raspberrypi-firmware soc:firmware: Attached to firmware from 2020-02-12 12:36, variant start [ 0.060035] raspberrypi-firmware soc:firmware: Firmware hash is c3c8dbdf147686fb0c3f32aece709d0653368810 [ 0.102529] bcm2835-dma fe007000.dma: DMA legacy API manager at (ptrval), dmachans=0x1 [ 0.105749] vgaarb: loaded [ 0.106113] SCSI subsystem initialized [ 0.106321] usbcore: registered new interface driver usbfs [ 0.106388] usbcore: registered new interface driver hub [ 0.106470] usbcore: registered new device driver usb [ 0.107681] clocksource: Switched to clocksource arch_sys_counter [ 0.185895] VFS: Disk quotas dquot_6.6.0 [ 0.186001] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes) [ 0.186160] FS-Cache: Loaded [ 0.186348] CacheFiles: Loaded [ 0.186907] simple-framebuffer 3ea83000.framebuffer: framebuffer at 0x3ea83000, 0x177000 bytes, mapped to 0x(ptrval) [ 0.186944] simple-framebuffer 3ea83000.framebuffer: format=a8r8g8b8, mode=800x480x32, linelength=3200 [ 0.189307] Console: switching to colour frame buffer device 100x30 [ 0.192248] simple-framebuffer 3ea83000.framebuffer: fb0: simplefb registered! [ 0.202470] NET: Registered protocol family 2 [ 0.204189] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes) [ 0.205305] TCP established hash table entries: 8192 (order: 3, 32768 bytes) [ 0.206456] TCP bind hash table entries: 8192 (order: 4, 65536 bytes) [ 0.207591] TCP: Hash tables configured (established 8192 bind 8192) [ 0.208789] UDP hash table entries: 512 (order: 2, 16384 bytes) [ 0.209858] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes) [ 0.211100] NET: Registered protocol family 1 [ 0.212661] RPC: Registered named UNIX socket transport module. [ 0.213700] RPC: Registered udp transport module. [ 0.214727] RPC: Registered tcp transport module. [ 0.215726] RPC: Registered tcp NFSv4.1 backchannel transport module. [ 0.216765] PCI: CLS 0 bytes, default 64 [ 0.219822] Initialise system trusted keyrings [ 0.221041] workingset: timestamp_bits=14 max_order=19 bucket_order=5 [ 0.231032] FS-Cache: Netfs 'nfs' registered for caching [ 0.232598] NFS: Registering the id_resolver key type [ 0.233658] Key type id_resolver registered [ 0.234678] Key type id_legacy registered [ 0.235708] nfs4filelayout_init: NFSv4 File Layout Driver Registering... [ 0.239021] Key type asymmetric registered [ 0.240041] Asymmetric key parser 'x509' registered [ 0.241133] bounce: pool size: 64 pages [ 0.242128] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250) [ 0.243279] io scheduler noop registered [ 0.244249] io scheduler deadline registered (default) [ 0.245356] io scheduler cfq registered [ 0.246276] io scheduler mq-deadline registered (default) [ 0.247179] io scheduler kyber registered [ 0.251228] brcm-pcie fd500000.pcie: could not get clock [ 0.252172] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges: [ 0.253085] brcm-pcie fd500000.pcie: MEM 0x600000000..0x603ffffff -> 0xf8000000 [ 0.307717] brcm-pcie fd500000.pcie: link up, 5.0 Gbps x1 (!SSC) [ 0.308822] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00 [ 0.309690] pci_bus 0000:00: root bus resource [bus 00-01] [ 0.310562] pci_bus 0000:00: root bus resource [mem 0x600000000-0x603ffffff] (bus address [0xf8000000-0xfbffffff]) [ 0.312394] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400 [ 0.312530] pci 0000:00:00.0: PME# supported from D0 D3hot [ 0.315284] PCI: bus0: Fast back to back transfers disabled [ 0.316226] pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring [ 0.317388] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330 [ 0.317513] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit] [ 0.317886] pci 0000:01:00.0: PME# supported from D0 D3cold [ 0.320651] PCI: bus1: Fast back to back transfers disabled [ 0.321617] pci_bus 0000:01: busn_res: [bus 01] end is updated to 01 [ 0.321662] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff] [ 0.322649] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit] [ 0.323676] pci 0000:00:00.0: PCI bridge to [bus 01] [ 0.324650] pci 0000:00:00.0: bridge window [mem 0x600000000-0x6000fffff] [ 0.325822] pcieport 0000:00:00.0: enabling device (0140 -> 0142) [ 0.326948] pcieport 0000:00:00.0: Signaling PME with IRQ 55 [ 0.328087] pcieport 0000:00:00.0: AER enabled with IRQ 55 [ 0.329196] pci 0000:01:00.0: enabling device (0140 -> 0142) [ 0.332552] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled [ 0.335517] iproc-rng200 fe104000.rng: hwrng registered [ 0.336683] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB) [ 0.338219] vc-sm: Videocore shared memory driver [ 0.339615] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000 [ 0.350616] brd: module loaded [ 0.361094] loop: module loaded [ 0.362854] Loading iSCSI transport class v2.0-870. [ 0.365550] libphy: Fixed MDIO Bus: probed [ 0.366984] bcmgenet fd580000.genet: failed to get enet clock [ 0.368069] bcmgenet fd580000.genet: GENET 5.0 EPHY: 0x0000 [ 0.369093] bcmgenet fd580000.genet: failed to get enet-wol clock [ 0.370104] bcmgenet fd580000.genet: failed to get enet-eee clock [ 0.371066] bcmgenet: Skipping UMAC reset [ 0.372236] unimac-mdio unimac-mdio.-19: DMA mask not set [ 0.387773] libphy: bcmgenet MII bus: probed [ 0.428202] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus at 0x(ptrval) [ 0.429999] usbcore: registered new interface driver r8152 [ 0.430995] usbcore: registered new interface driver lan78xx [ 0.431949] usbcore: registered new interface driver smsc95xx [ 0.433122] xhci_hcd 0000:01:00.0: xHCI Host Controller [ 0.434022] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1 [ 0.436716] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0000001000000890 [ 0.438859] genirq: irq_chip Brcm_MSI did not update eff. affinity mask of irq 56 [ 0.440665] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19 [ 0.441666] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 0.442637] usb usb1: Product: xHCI Host Controller [ 0.443576] usb usb1: Manufacturer: Linux 4.19.97-v7l+ xhci-hcd [ 0.444505] usb usb1: SerialNumber: 0000:01:00.0 [ 0.445903] hub 1-0:1.0: USB hub found [ 0.446881] hub 1-0:1.0: 1 port detected [ 0.448276] xhci_hcd 0000:01:00.0: xHCI Host Controller [ 0.449198] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2 [ 0.450121] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed [ 0.451397] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 4.19 [ 0.452366] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 0.453352] usb usb2: Product: xHCI Host Controller [ 0.454324] usb usb2: Manufacturer: Linux 4.19.97-v7l+ xhci-hcd [ 0.455302] usb usb2: SerialNumber: 0000:01:00.0 [ 0.456754] hub 2-0:1.0: USB hub found [ 0.457766] hub 2-0:1.0: 4 ports detected [ 0.459910] dwc_otg: version 3.00a 10-AUG-2012 (platform bus) [ 0.461058] dwc_otg: FIQ enabled [ 0.461067] dwc_otg: NAK holdoff enabled [ 0.461076] dwc_otg: FIQ split-transaction FSM enabled [ 0.461088] Module dwc_common_port init [ 0.461289] usbcore: registered new interface driver uas [ 0.462350] usbcore: registered new interface driver usb-storage [ 0.463465] mousedev: PS/2 mouse device common for all mice [ 0.465609] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer [ 0.468059] sdhci: Secure Digital Host Controller Interface driver [ 0.468993] sdhci: Copyright(c) Pierre Ossman [ 0.470274] mmc-bcm2835 fe300000.mmcnr: could not get clk, deferring probe [ 0.471576] sdhci-pltfm: SDHCI platform and OF driver helper [ 0.475452] ledtrig-cpu: registered to indicate activity on CPUs [ 0.476506] hidraw: raw HID events driver (C) Jiri Kosina [ 0.477552] usbcore: registered new interface driver usbhid [ 0.478498] usbhid: USB HID core driver [ 0.480070] vchiq: vchiq_init_state: slot_zero = (ptrval), is_master = 0 [ 0.482310] [vc_sm_connected_init]: start [ 0.488596] [vc_sm_connected_init]: end - returning 0 [ 0.490690] Initializing XFRM netlink socket [ 0.491639] NET: Registered protocol family 17 [ 0.492619] Key type dns_resolver registered [ 0.493750] Registering SWP/SWPB emulation handler [ 0.495199] registered taskstats version 1 [ 0.496077] Loading compiled-in X.509 certificates [ 0.503915] uart-pl011 fe201000.serial: cts_event_workaround enabled [ 0.504880] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 34, base_baud = 0) is a PL011 rev2 [ 0.511181] console [ttyS0] disabled [ 0.512163] fe215040.serial: ttyS0 at MMIO 0x0 (irq = 37, base_baud = 62500000) is a 16550 [ 1.900222] console [ttyS0] enabled [ 1.905317] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver [ 1.914487] brcmstb_thermal fd5d2200.thermal: registered AVS TMON of-sensor driver [ 1.923869] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0 [ 1.931046] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated [ 1.963964] sdhci-iproc fe340000.emmc2: Linked as a consumer to regulator.3 [ 1.972168] sdhci-iproc fe340000.emmc2: Linked as a consumer to regulator.4 [ 1.996575] mmc1: queuing unknown CIS tuple 0x80 (2 bytes) [ 2.004770] mmc1: queuing unknown CIS tuple 0x80 (3 bytes) [ 2.013063] mmc1: queuing unknown CIS tuple 0x80 (3 bytes) [ 2.019669] mmc0: SDHCI controller on fe340000.emmc2 [fe340000.emmc2] using ADMA [ 2.030457] of_cfs_init [ 2.033946] of_cfs_init: OK [ 2.038465] Waiting for root device PARTUUID=6c586e13-02... [ 2.047594] mmc1: queuing unknown CIS tuple 0x80 (7 bytes) [ 2.055746] mmc1: queuing unknown CIS tuple 0x80 (3 bytes) [ 2.111477] random: fast init done [ 2.158539] usb 1-1: new high-speed USB device number 2 using xhci_hcd [ 2.171043] mmc0: new ultra high speed DDR50 SDHC card at address e624 [ 2.181780] mmcblk0: mmc0:e624 SP32G 29.7 GiB [ 2.188139] mmc1: new high speed SDIO card at address 0001 [ 2.197854] mmcblk0: p1 p2 [ 2.228598] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null) [ 2.237848] VFS: Mounted root (ext4 filesystem) readonly on device 179:2. [ 2.252758] devtmpfs: mounted [ 2.264279] Freeing unused kernel memory: 2048K [ 2.270035] Run /sbin/init as init process [ 2.340383] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21 [ 2.349642] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0 [ 2.357828] usb 1-1: Product: USB2.0 Hub [ 2.364511] hub 1-1:1.0: USB hub found [ 2.369514] hub 1-1:1.0: 4 ports detected [ 2.676604] systemd[1]: System time before build time, advancing clock. [ 2.771335] NET: Registered protocol family 10 [ 2.778085] Segment Routing with IPv6 [ 2.815943] systemd[1]: systemd 241 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid) [ 2.841336] systemd[1]: Detected architecture arm. [ 2.861579] systemd[1]: Set hostname to . [ 3.520176] random: systemd: uninitialized urandom read (16 bytes read) [ 3.562720] systemd[1]: Condition check resulted in Journal Audit Socket being skipped. [ 3.572268] random: systemd: uninitialized urandom read (16 bytes read) [ 3.580517] systemd[1]: Listening on udev Kernel Socket. [ 3.588770] random: systemd: uninitialized urandom read (16 bytes read) [ 3.601832] systemd[1]: Created slice system-systemd\x2dfsck.slice. [ 3.611044] systemd[1]: Reached target Swap. [ 3.618378] systemd[1]: Listening on initctl Compatibility Named Pipe. [ 3.629120] systemd[1]: Created slice system-serial\x2dgetty.slice. [ 3.639184] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point. [ 4.309292] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null) [ 4.410555] systemd-journald[101]: Received request to flush runtime journal from PID 1 [ 4.959355] rpi-ft5406 rpi_ft5406: Probing device [ 4.962671] input: FT5406 memory based driver as /devices/virtual/input/input0 [ 4.998093] rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x0000ffff [ 4.998663] rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00000fff [ 4.999120] rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x0000ffff [ 4.999575] rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x0000ffff [ 5.025378] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned. [ 5.027302] bcm2835_vc_sm_cma_probe: Videocore shared memory driver [ 5.027317] [vc_sm_connected_init]: start [ 5.029843] media: Linux media interface: v0.10 [ 5.034925] [vc_sm_connected_init]: installed successfully [ 5.050862] videodev: Linux video capture interface: v2.00 [ 5.093386] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned. [ 5.110910] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned. [ 5.127628] bcm2835-codec bcm2835-codec: Device registered as /dev/video10 [ 5.127939] bcm2835-codec bcm2835-codec: Loaded V4L2 decode [ 5.127973] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned. [ 5.143698] bcm2835-codec bcm2835-codec: Device registered as /dev/video11 [ 5.143730] bcm2835-codec bcm2835-codec: Loaded V4L2 encode [ 5.150254] bcm2835-codec bcm2835-codec: Device registered as /dev/video12 [ 5.150286] bcm2835-codec bcm2835-codec: Loaded V4L2 isp [ 5.239322] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned. [ 5.266875] bcm2835_audio soc:audio: card created with 8 channels [ 5.394937] cfg80211: Loading compiled-in X.509 certificates for regulatory database [ 5.418499] [drm] Initialized v3d 1.0.0 20180419 for fec00000.v3d on minor 0 [ 5.422672] vc4-drm soc:gpu: bound fe600000.firmwarekms (ops vc4_fkms_ops [vc4]) [ 5.422689] checking generic (3ea83000 177000) vs hw (0 ffffffffffffffff) [ 5.422700] fb: switching to vc4drmfb from simple [ 5.422901] Console: switching to colour dummy device 80x30 [ 5.424545] [drm] Initialized vc4 0.0.0 20140616 for soc:gpu on minor 1 [ 5.424559] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013). [ 5.424569] [drm] No driver support for vblank timestamp query. [ 5.424578] [drm] Setting vblank_disable_immediate to false because get_vblank_timestamp == NULL [ 5.483723] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7' [ 5.499533] Console: switching to colour frame buffer device 100x30 [ 5.517965] vc4-drm soc:gpu: fb0: DRM emulated frame buffer device [ 5.529865] brcmfmac: F1 signature read @0x18000000=0x15264345 [ 5.538641] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 [ 5.538980] usbcore: registered new interface driver brcmfmac [ 5.773834] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6 [ 5.787508] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Mar 2 2020 23:30:41 version 7.45.202 (r724630 CY) FWID 01-72f6ece2 [ 7.559081] 8021q: 802.1Q VLAN Support v1.8 [ 7.615321] random: crng init done [ 7.615335] random: 7 urandom warning(s) missed due to ratelimiting [ 7.646686] uart-pl011 fe201000.serial: no DMA platform data [ 7.856676] Adding 102396k swap on /var/swap. Priority:-2 extents:1 across:102396k SSFS [ 8.046121] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready [ 8.046167] brcmfmac: power management disabled [ 8.342374] bcmgenet: Skipping UMAC reset [ 8.448280] bcmgenet fd580000.genet: configuring instance for external RGMII (no delay) [ 8.448847] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready [ 9.527959] bcmgenet fd580000.genet eth0: Link is Down [ 13.537354] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready [ 13.687918] bcmgenet fd580000.genet eth0: Link is Up - 1Gbps/Full - flow control rx/tx [ 13.687947] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready [ 14.307535] Bluetooth: Core ver 2.22 [ 14.307607] NET: Registered protocol family 31 [ 14.307617] Bluetooth: HCI device and connection manager initialized [ 14.307638] Bluetooth: HCI socket layer initialized [ 14.307654] Bluetooth: L2CAP socket layer initialized [ 14.307770] Bluetooth: SCO socket layer initialized [ 14.321683] Bluetooth: HCI UART driver ver 2.3 [ 14.321697] Bluetooth: HCI UART protocol H4 registered [ 14.321779] Bluetooth: HCI UART protocol Three-wire (H5) registered [ 14.322038] Bluetooth: HCI UART protocol Broadcom registered [ 14.498904] Bluetooth: BNEP (Ethernet Emulation) ver 1.3 [ 14.498911] Bluetooth: BNEP filters: protocol multicast [ 14.498921] Bluetooth: BNEP socket layer initialized [ 14.578764] Bluetooth: RFCOMM TTY layer initialized [ 14.578784] Bluetooth: RFCOMM socket layer initialized [ 14.578799] Bluetooth: RFCOMM ver 1.11 [ 14.762529] ICMPv6: process `dhcpcd' is using deprecated sysctl (syscall) net.ipv6.neigh.wlan0.retrans_time - use net.ipv6.neigh.wlan0.retrans_time_ms instead ```

Additional context

If it helps, the line calling OMX_GetHandle inside GStreamer is this one, which in turn is invoked by this line.

Some more logs from gstreamer, if needed:

``` omxvideodec gstomxvideodec.c:258:gst_omx_video_dec_open: Opening decoder 0:00:00.104451988 1390 0xbf0260 DEBUG omx gstomx.c:152:gst_omx_core_acquire: Successfully loaded core '/opt/vc/lib/libopenmaxil.so' 0:00:00.104812762 1390 0xbf0260 DEBUG omx gstomx.c:167:gst_omx_core_acquire: Successfully initialized core '/opt/vc/lib/libopenmaxil.so' 0:00:00.105490942 1390 0xbf0260 DEBUG omx gstomx.c:807:gst_omx_component_new: Successfully got component handle 0xc11800 (OMX.broadcom.video_decode) from core '/opt/vc/lib/libopenmaxil.so' 0:00:00.105580607 1390 0xbf0260 DEBUG omx gstomx.c:969:gst_omx_component_get_state: Getting state of video_decode 0:00:00.105605274 1390 0xbf0260 DEBUG omx gstomx.c:1019:gst_omx_component_get_state: video_decode returning state Loaded 0:00:00.105626533 1390 0xbf0260 DEBUG omx gstomx.c:1041:gst_omx_component_add_port: video_decode adding port 130 0:00:00.105648736 1390 0xbf0260 DEBUG omx gstomx.c:1132:gst_omx_component_get_parameter: Getting video_decode parameter at index 0x02000001 0:00:00.105740476 1390 0xbf0260 DEBUG omx gstomx.c:1135:gst_omx_component_get_parameter: Got video_decode parameter at index 0x02000001: None (0x00000000) 0:00:00.105785439 1390 0xbf0260 DEBUG omx gstomx.c:1041:gst_omx_component_add_port: video_decode adding port 131 0:00:00.105808605 1390 0xbf0260 DEBUG omx gstomx.c:1132:gst_omx_component_get_parameter: Getting video_decode parameter at index 0x02000001 0:00:00.105908808 1390 0xbf0260 DEBUG omx gstomx.c:1135:gst_omx_component_get_parameter: Got video_decode parameter at index 0x02000001: None (0x00000000) 0:00:00.105929827 1390 0xbf0260 DEBUG omxvideodec gstomxvideodec.c:327:gst_omx_video_dec_open: Opened decoder 0:00:00.105947160 1390 0xbf0260 DEBUG omxvideodec gstomxvideodec.c:330:gst_omx_video_dec_open: Opening EGL renderer 0:00:00.106112677 1390 0xbf0260 ERROR omx gstomx.c:799:gst_omx_component_new: Failed to get component handle 'OMX.broadcom.egl_render' from core '/opt/vc/lib/libopenmaxil.so': 0x80001000 0:00:00.106133917 1390 0xbf0260 DEBUG omx gstomx.c:209:gst_omx_core_release: Releasing core 0xc18e28 ```
6by9 commented 4 years ago 
System Information
------------------

Raspberry Pi 4 Model B Rev 1.1

The Pi4 doesn't support the firmware GLES/EGL interface, therefore the egl_render component is disabled. Otherwise it will fail on enabling the component, so better to fail early.

Someone needs to look again at disentangling the GStreamer use of egl_render within omxh264dec, but the other approach is to use v4l2h264dec instead.

ardera commented 4 years ago

The Pi4 doesn't support the firmware GLES/EGL interface, therefore the egl_render component is disabled. Otherwise it will fail on enabling the component, so better to fail early.

Okay that makes sense. Still, OMX_ErrorInsufficientResources seems like a kinda weird error to return in that case. I think OMX_ErrorComponentNotFound would be more fitting, even though it's not that precise as well.

v4l2h264dec works as expected! Thanks!

6by9 commented 4 years ago

Okay that makes sense. Still, OMX_ErrorInsufficientResources seems like a kinda weird error to return in that case.

The component module is there, but deliberately fails the create as it checks on the platform. The return value from create within the Broadcom framework is a pointer to the component, or NULL. NULL is translated to OMX_ErrorInsufficientResources.

The module choice is done through a dll loading mechanism, therefore there is no central list that we can nobble to drop egl_render from on Pi4. I also don't like messing with core code unless really necessary, particularly when it comes to IL!

ardera commented 4 years ago

@6by9 What is the replacement for the egl_render component on a Pi 4? The egl_render component also handled YUV -> RGB conversion before, it seems. There must a faster way for rendering into a GL texture / EGL image other than manual conversion and then glTexImage2D?

Btw it seems gstreamer forgets to do that YUV -> RGB conversion as well, since the colors are really really weird and not at all what they should be when using glImageSink.

6by9 commented 4 years ago

Import the buffers into EGL using dmabufs and eglCreateImageKHR. The Pi4 has a texture formatter hardware block that can take YUV images in and create a texture from it.

It may have bitrotted, but https://github.com/6by9/drm_mmal/blob/x11_export/drm_mmal.c or https://github.com/6by9/drm_mmal/blob/x11/drm_mmal.c should work as very basic examples for merging MMAL and Mesa EGL (written by Eric originally). The source of the dmabuf is largely irrelevant as to whether it is a dma-heap, V4L2 buffer, vcsm-cma, DRM, or something else. EGL shouldn't even require it to be contiguous as V3D has an IOMMU, but I wouldn't put money on that.

ardera commented 4 years ago

Thank you very much!

That helped me resolve my issue.

Though I didn't exactly do it the way you suggested. Instead of rendering the video to a texture, I implemented hardware plane support so I can render "around" the video output of omxplayer. HW plane support is basically impossible to achieve with the framework I am using, but thanks to some hacks involving EGLImages, I was able to work around that. Your comment pointed me in the right direction.

Btw, is it normal that I have to reflect the y-axis of the DRM overlay plane to get it to draw correctly? It's somehow scanned out upside down with the default settings. Also, is there some reason the number of available overlay planes is so limited?

6by9 commented 4 years ago

What is it that you're rendering? GL output? In which case, yes, as GL works with bottom left as the origin, whilst DRM uses top left.

If you look at the master branch of drm_mmal, it takes MMAL buffers from the video_decode component and pokes them straight into DRM. No y-reflect required there.

The number of overlays can be increased, but there are some limits. DRM has a limit of 32 planes total because it uses a u32 bitmask to handle them. You have to have a primary and cursor plane per crtc. Other planes can be left as available for any crtc and this is what the beta full KMS driver does (it has 6 crtcs, so otherwise hits that limit very fast).

FKMS does take it to the minimum and only adds one overlay, but that would only require a quick loop at https://github.com/raspberrypi/linux/blob/rpi-5.4.y/drivers/gpu/drm/vc4/vc4_firmware_kms.c#L1742 to create multiple overlay planes pepr crtc. You'd need to pass in a zpos or overlay number to vc4_fkms_plane_init so that it can set up default_zpos sensibly. I'm open to a PR for that, otherwise it'll get added to my long list of jobs. The firmware side of FKMS allows for up to 16 planes spread over both displays, although that could be increased if really needed (it's only a define).

ardera commented 4 years ago

What is it that you're rendering? GL output? In which case, yes, as GL works with bottom left as the origin, whilst DRM uses top left.

Okay that makes sense. Yeah, it's GL output

FKMS does take it to the minimum and only adds one overlay, but that would only require a quick loop at https://github.com/raspberrypi/linux/blob/rpi-5.4.y/drivers/gpu/drm/vc4/vc4_firmware_kms.c#L1742 to create multiple overlay planes pepr crtc. You'd need to pass in a zpos or overlay number to vc4_fkms_plane_init so that it can set up default_zpos sensibly. I'm open to a PR for that, otherwise it'll get added to my long list of jobs.

Okay. I think multiple overlay planes would be nice to have, though they're not strictly necessary for me right now either. If I find a use for them at some point I'll write a PR.

The firmware side of FKMS allows for up to 16 planes spread over both displays, although that could be increased if really needed (it's only a define).

Is it also the same with the DSI display? (I assume you meant the HDMI displays) Does this 16 plane firmware-side limitation also affect the planes used by OpenMAX or MMAL? In other words, could I make use of 16 DRM planes simultaneously and at the same time use omxplayer to display some video?

6by9 commented 4 years ago

16 planes over whichever 2 displays have been initialised. DSI+HDMI0, DPI+HDMI0, or HDMI0+HDMI1.

IL, MMAL, and DispmanX APIs all create their own client instance of DispmanX, so you can add as many layers as you can get the hardware to handle via that route. This limit of 16 planes is only through the mailbox API that FKMS uses.

We will be looking at shifting the main focus towards the pure ARM KMS driver (full KMS) at some point, at which point IL, MMAL, and DispmanX stop working, and DRM is the only route to putting images on the screen.

ardera commented 4 years ago

16 planes over whichever 2 displays have been initialised. DSI+HDMI0, DPI+HDMI0, or HDMI0+HDMI1.

IL, MMAL, and DispmanX APIs all create their own client instance of DispmanX, so you can add as many layers as you can get the hardware to handle via that route. This limit of 16 planes is only through the mailbox API that FKMS uses.

Okay, that makes sense. Thanks for explaining it

We will be looking at shifting the main focus towards the pure ARM KMS driver (full KMS) at some point, at which point IL, MMAL, and DispmanX stop working, and DRM is the only route to putting images on the screen.

I'm looking forward to full KMS!