Trace32 basic operation based on Qualcomm platform

Useful Command

do coreX_reg.cmm                  // load cmm files
d.dump $ADDRESS                   // View memory address of $ADDRESS
d.l $ADDRESS                      // Show the assembly code of $ADDRESS
v.f                               // View Stack Frame
r.View                            // Register view
y.SourcePATH.SetRecurseDir        // Set source code path

Refer https://www2.lauterbach.com/pdf/commandlist.pdf for more detail

Analysis Step

Review files(RAMOOPS.bin, RAMDUMP_MSG.txt, dmesg_tz.txt, etc) to determine if need T32.
Find matched vmlinux and using ramdump parser.
launch T32, find out which process killing system.

Analysis

From RAMDUMP_MSG.txt

reset reason: 0x776655aa 
reset message: Unknown

There is unknow reason, so device might be shut down by security element. (that is, there is someone higher level than “kernel”, and can control device without kernel)

From TZLOG.BIN

HYP Virt: Illegal virtualization request for reg addr=0x62b40004 
Core:6, Data abort from EL1, Translation fault 3rd level 
 Read operation 
 Faulting Address: 0x62b40004 
 Address of Last Instruction Executed: 0xffffff8026346810 at EL1 
 System Registers: 
  ESR_EL2(93930007) 
  FAR_EL2(ffffff800ffa0004) 
  HPFAR_EL2(62b400) 
  ELR_EL2(ffffff8026346810) 
  HCR_EL2(80080007)

From dmesg_tz.txt (we focus on core6)

(--------------------------------------------------------------------------------)
Parsing CPU6 context start 172f37000 end 172f37800
Core 6 PC: UNKNOWN+0 <1c02a590>
Core 6 LR: UNKNOWN+0 <857173bc>

[<1c02a590>] UNKNOWN+0x0
[<ffffff8026346a80>] UNKNOWN+0x0
[<ffffff802c0e1e4c>] gpiolib_seq_show+0xd0
[<ffffff802be8479c>] seq_read+0x370
[<ffffff802bf958b8>] full_proxy_read+0x60
[<ffffff802be58e0c>] vfs_read+0xa0
[<ffffff802be5a508>] SyS_read+0x60
[<ffffff802bc83f80>] el0_svc_naked+0x34

core6 regs:
   x0       = 0x0000000000000001
   x1       = 0x020bcf577e7c5920
   x2       = 0x000000000682aaab
   x3       = 0x0000000000000004
   x4       = 0x000000000115e2b6
   x5       = 0x0000000000000015
   x6       = 0x0000000006118a82
   x7       = 0xffffffc72d95fce0
   x8       = 0xffffffc79a668080
   x9       = 0x0000000000000003
   x10      = 0x203a203834316f69
   x11      = 0x6d32203020206e69
   x12      = 0x64206c6c75702041
   x13      = 0x697067200a6e776f
   x14      = 0x69203a203934316f
   x15      = 0xaaaaaaaaaaaaaaab
   x16      = 0xffffff802be5a4a8
   x17      = 0x0000006fd84fef7c
   x18      = 0x0000000000000001
   x19      = 0xffffff800ffa0004
   x20      = 0x0000000000000004
   x21      = 0x0000000000000000
   x22      = 0xffffff8026348180
   x23      = 0x0000000000000000
   x24      = 0xffffffc7e6aca0a8
   x25      = 0xffffff8026349580
   x26      = 0xffffff80263487c8
   x27      = 0xffffffc7e9369ea0
   x28      = 0xffffffc7e9369e98
   x29      = 0xffffffc72d95fc30
   x30      = 0x00000000857173bc
   pc       = 0x000000001c02a590
   currentEL = 0x0000000000000000
   sp_el3   = 0x0000000000000000
   elr_el3  = 0x00000000857115ec
   spsr_el3 = 0x00000000800003c9
   sp_el2   = 0x000000008589abd0
   elr_el2  = 0xffffff8026346810
   spsr_el2 = 0x0000000060400145
   sp_el1   = 0xffffffc72d95fc30
   elr_el1  = 0x0000006fd84fef84
   spsr_el1 = 0x0000000060000000
   sp_el0   = 0xffffffc745c6c680
   cpumerrsr_el1 = 0x0000000093930007
   l2merrsr_el1 = 0xffffff800ffa0004

=============== secure contex ===========
   x0       = 0x0000000080080007
   x1       = 0x0000000000000000
   x2       = 0x0000000000000000
   x3       = 0x0000000000000000
   x4       = 0x0000000000000000
   x5       = 0x0000000000000000
   x6       = 0x0000000000000000
   x7       = 0x0000000000000180
   x8       = 0x0000000000000000
   x9       = 0x000000001c132b5c
   x10      = 0x0000000000000001
   x11      = 0x00000000733ce000
   x12      = 0x0000000000000180
   x13      = 0x0000000000000001
   x14      = 0x0000000000000000
   x15      = 0x0000000000000000
   x16      = 0x0000000000700124
   x17      = 0x000000001c132cb7
   x18      = 0x000000001c13aef8
   x19      = 0x000000001c0d0189
   x20      = 0x0000000000000000
   x21      = 0x0000000000000020
   x22      = 0x0000000000000000
   x23      = 0x0000000000000033
   x24      = 0x0000000000700012
   x25      = 0x000000001c19e428
   x26      = 0x0000000000000000
   x27      = 0x0000000000000000
   x28      = 0x0000000000000000
   x29      = 0x0000000000000000
   x30      = 0x0000000000000000
   pc       = 0x0000000000000000
   currentEL = 0x0000000000000000
   sp_el3   = 0x000000001c132e60
   elr_el3  = 0x000000001c02a590
   spsr_el3 = 0x000000001c02a590
   sp_el2   = 0x0000000000000000
   elr_el2  = 0x0000000000000000
   spsr_el2 = 0x00000000857115ec
   sp_el1   = 0x00000000800003c9
   elr_el1  = 0x000000008589abd0
   spsr_el1 = 0xffffff8026346810
   sp_el0   = 0x0000000060400145
   cpumerrsr_el1 = 0x000000001c132e50
   l2merrsr_el1 = 0x000000001c02a590
============ end secure context ===========
(--------------------------------------------------------------------------------)
CPU6 2 process is running
 |--curr: cat(2841)
 |--idle: swapper/6(0)
 |--stop: migration/6(64)
CFS 1 process is pending
 |--curr: 1 process is grouping
 |   |--curr: cat(2841)
 |   |--next: None(0)
 |   |--last: None(0)
 |   |--skip: None(0)
 |--next: None(0)
 |--last: None(0)
 |--skip: None(0)
RT 1 process is pending
 |--pend: DispSync(932)
current callstack is maybe:
0xffffffc72d95f358:('debug_smp_processor_id', 28L)
0xffffffc72d95f368:('debug_smp_processor_id', 28L)
0xffffffc72d95f3a8:('unwind_frame', 444L)
0xffffffc72d95f3b8:('walk_stackframe', 44L)
0xffffffc72d95f3d8:('debug_smp_processor_id', 28L)
0xffffffc72d95f3e8:('debug_smp_processor_id', 28L)
0xffffffc72d95f418:('unwind_frame', 444L)
0xffffffc72d95f428:('unwind_frame', 444L)
0xffffffc72d95f438:('walk_stackframe', 44L)
0xffffffc72d95f450:('save_return_addr', 0L)
0xffffffc72d95f478:('return_address', 96L)
0xffffffc72d95f488:('_raw_spin_unlock_irqrestore', 96L)
0xffffffc72d95f4a8:('preempt_count_sub', 536L)
0xffffffc72d95f4b8:('sched_clock', 56L)
0xffffffc72d95f4c8:('preempt_count_sub', 464L)
0xffffffc72d95f4d8:('_raw_spin_unlock_irqrestore', 96L)
0xffffffc72d95f4e0:('depot_save_stack', 928L)
0xffffffc72d95f508:('_raw_spin_unlock_irqrestore', 96L)
0xffffffc72d95f568:('depot_save_stack', 928L)
0xffffffc72d95f588:('save_stack', 196L)
0xffffffc72d95f590:('__set_page_owner', 68L)
0xffffffc72d95f608:('__set_page_owner', 68L)
0xffffffc72d95f648:('get_page_from_freelist', 2344L)
0xffffffc72d95f650:('__alloc_pages_nodemask', 364L)
0xffffffc72d95f658:('handle_pte_fault', 2664L)
0xffffffc72d95f660:('__handle_mm_fault', 188L)
0xffffffc72d95f668:('handle_mm_fault', 148L)
0xffffffc72d95f670:('do_page_fault', 952L)
0xffffffc72d95f678:('do_translation_fault', 104L)
0xffffffc72d95f680:('do_mem_abort', 100L)
0xffffffc72d95f688:('el1_ia', 36L)
0xffffffc72d95f690:('full_proxy_read', 96L)
0xffffffc72d95f698:('vfs_read', 160L)
0xffffffc72d95f6a0:('SyS_read', 96L)
0xffffffc72d95f6a8:('el0_svc_naked', 52L)
0xffffffc72d95f6b8:('__set_page_owner', 44L)
0xffffffc72d95f6d8:('get_page_from_freelist', 2344L)
0xffffffc72d95f708:('__alloc_pages_nodemask', 364L)
0xffffffc72d95f768:('preempt_count_sub', 536L)
0xffffffc72d95f778:('sync_entity_load_avg', 120L)
0xffffffc72d95f788:('debug_smp_processor_id', 28L)
0xffffffc72d95f7b8:('sync_entity_load_avg', 120L)
0xffffffc72d95f7c8:('debug_smp_processor_id', 28L)
0xffffffc72d95f7f8:('select_energy_cpu_brute', 2272L)
0xffffffc72d95f808:('select_energy_cpu_brute', 5688L)
0xffffffc72d95f818:('walk_stackframe', 44L)
0xffffffc72d95f838:('select_task_rq_fair', 1240L)
0xffffffc72d95f8d8:('sched_clock', 56L)
0xffffffc72d95f8e8:('trace_clock_local', 32L)
0xffffffc72d95f918:('rb_reserve_next_event', 148L)
0xffffffc72d95f948:('stm_channel_alloc', 116L)
0xffffffc72d95f958:('sched_clock', 56L)
0xffffffc72d95f968:('stm_trace_data_header', 156L)
0xffffffc72d95f978:('sched_clock', 56L)
0xffffffc72d95f988:('trace_clock_local', 32L)
0xffffffc72d95f998:('sched_clock', 56L)
0xffffffc72d95f9a8:('trace_clock_local', 32L)
0xffffffc72d95f9d8:('rb_reserve_next_event', 148L)
0xffffffc72d95f9e8:('stm_channel_alloc', 116L)
0xffffffc72d95f9f8:('sched_clock', 56L)
0xffffffc72d95fa08:('stm_channel_alloc', 116L)
0xffffffc72d95fa18:('sched_clock', 56L)
0xffffffc72d95fa28:('stm_trace_data_header', 156L)
0xffffffc72d95fa38:('debug_smp_processor_id', 28L)
0xffffffc72d95fa78:('unwind_frame', 444L)
0xffffffc72d95fa88:('walk_stackframe', 44L)
0xffffffc72d95faa0:('save_return_addr', 0L)
0xffffffc72d95fab8:('debug_smp_processor_id', 28L)
0xffffffc72d95fac8:('number', 800L)
0xffffffc72d95fad8:('debug_smp_processor_id', 28L)
0xffffffc72d95fae8:('vsnprintf', 892L)
0xffffffc72d95fb48:('string', 108L)
0xffffffc72d95fb58:('vsnprintf', 148L)
0xffffffc72d95fb88:('seq_printf', 208L)
0xffffffc72d95fbb8:('sched_clock', 56L)
0xffffffc72d95fbc8:('uncached_logk', 192L)
0xffffffc72d95fc68:('gpiolib_seq_show', 208L)
0xffffffc72d95fce8:('seq_read', 880L)
0xffffffc72d95fd68:('full_proxy_read', 96L)
0xffffffc72d95fdc8:('full_proxy_read', 48L)
0xffffffc72d95fdf8:('vfs_read', 160L)
0xffffffc72d95fe38:('SyS_read', 96L)
0xffffffc72d95fe78:('el0_svc_naked', 52L)

Core6 backtrace

[<1c02a590>] UNKNOWN+0x0
[<ffffff8026346a80>] UNKNOWN+0x0
[<ffffff802c0e1e4c>] gpiolib_seq_show+0xd0
[<ffffff802be8479c>] seq_read+0x370
[<ffffff802bf958b8>] full_proxy_read+0x60
[<ffffff802be58e0c>] vfs_read+0xa0
[<ffffff802be5a508>] SyS_read+0x60
[<ffffff802bc83f80>] el0_svc_naked+0x34

Start Trace32

by launch_t32.bat

do core6_regs.cmm

v.f

we could see that there is nothing on core6’s frame when it almost dead.

Core6 reg status:

   x29      = 0xffffffc72d95fc30
   x30      = 0x00000000857173bc
   pc       = 0x000000001c02a590
   currentEL = 0x0000000000000000
   sp_el3   = 0x0000000000000000
   elr_el3  = 0x00000000857115ec
   spsr_el3 = 0x00000000800003c9
   sp_el2   = 0x000000008589abd0
   elr_el2  = 0xffffff8026346810
   spsr_el2 = 0x0000000060400145
   sp_el1   = 0xffffffc72d95fc30
   elr_el1  = 0x0000006fd84fef84
   spsr_el1 = 0x0000000060000000
   sp_el0   = 0xffffffc745c6c680
   cpumerrsr_el1 = 0x0000000093930007
   l2merrsr_el1 = 0xffffff800ffa0004
   
  =============== secure contex =========== 
   x29      = 0x0000000000000000
   x30      = 0x0000000000000000
   pc       = 0x0000000000000000
   currentEL = 0x0000000000000000
   sp_el3   = 0x000000001c132e60
   elr_el3  = 0x000000001c02a590
   spsr_el3 = 0x000000001c02a590
   sp_el2   = 0x0000000000000000
   elr_el2  = 0x0000000000000000
   spsr_el2 = 0x00000000857115ec
   sp_el1   = 0x00000000800003c9
   elr_el1  = 0x000000008589abd0
   spsr_el1 = 0xffffff8026346810
   sp_el0   = 0x0000000060400145
   cpumerrsr_el1 = 0x000000001c132e50
   l2merrsr_el1 = 0x000000001c02a590
============ end secure context ===========