head -r323246 Pine64+ 2GB context: boot1.efi (as bootaa64.efi), I had to revert to an older one that I had around; more

Sun Sep 10 08:34:40 UTC 2017

When I attempted to use the result of:

# cp -aRx /usr/obj/DESTDIRs/clang-cortexA53-installworld/boot/boot1.efi /mnt/EFI/BOOT/

the pine64+ boot sequence got over and over
a sequence like:

U-Boot 2017.07 (Sep 06 2017 - 07:49:12 +0000) Allwinner Technology

CPU:   Allwinner A64 (SUN50I)
Model: Pine64+
DRAM:  2 GiB
MMC:   SUNXI SD/MMC: 0
*** Warning - bad CRC, using default environment

In:    serial
Out:   serial
. . .
>> FreeBSD EFI boot block
   Loader path: /boot/loader.efi

   Initializing modules: ZFS UFS
   Load Path:
"Synchronous Abort" handler, esr 0x96000004
ELR:     bdf90b30
LR:      bdf8fb6c
x0 : 0000000000000000 x1 : 0000000000000000
x2 : 00000000bdffc000 x3 : 0000000040000000
x4 : 00000000b9f34d40 x5 : 0000000000000000
x6 : 0000000000000015 x7 : 0000000000000000
x8 : 00000000bdfa59b8 x9 : 000000000000001c
x10: 0000000000000002 x11: 0000000000000000
x12: 0000000000000000 x13: 0000000000000000
x14: 0000000000000000 x15: 0000000000000000
x16: 0000000000000000 x17: 0000000000000000
x18: 00000000b9f39df8 x19: 0000000000000000
x20: 0000000000000000 x21: 0000000000000002
x22: 00000000b8f34c98 x23: 00000000b8f34c88
x24: 00000000b8f34ca0 x25: 00000000000007d0
x26: 00000000b8f34c90 x27: 00000000b8f2f198
x28: 0000000000000000 x29: 00000000b9f34de0

Resetting CPU ...

resetting ...

I found an old boot1.efi to copy over instead (from
back in -r308??? time frames as I remember) and
doing the replacement got past this point.

Booting with the non-debug kernel appears to hang for
a bit and then gets to a db> prompt and a bt showed
(for example):
(The console output for the register dump seems
to always be incomplete and there is a wait to
end up at the db> prompt. Note the data_abort
closest to the fork_exit .)

. . .
Release APs
APs not started
CPU  0: ARM Cortex-A53 r0p4 affinity:  0
 Instruction Set Attributes 0 = <AES+PMULL,SHA1,SHA2,CRC32>
 Instruction Set Attributes 1 = <0>
         Processor Features 0 = <AdvSIMD,Float,EL3 32,EL2 32,EL1 32,EL0 32>
         Processor Features 1 = <0>
      Memory Model Features 0 = <4k Granule,64k Granule,MixedEndian,S/NS Mem,16bit ASID,1TB PA>
      Memory Model Features 1 = <>
             Debug Features 0 = <2 CTX Breakpoints,4 Watchpoints,6 Breakpoints,PMUv3,Debug v8>
             Debug Features 1 = <0>
         Auxiliary Features 0 = <0>
         Auxiliary Features 1 = <0>
CPU  1: (null) (null) r0p0 affinity:  0
CPU  2: (null) (null) r0p0 affinity:  0
CPU  3: (null) (null) r0p0 affinity:  0
  x0: ffff000000a1c000
  x1: fffffd000103a[ thread pid 0 tid 100057 ]
Stopped at      thread_lock_flags_+0x298:       ldr     w4, [x3, #156]
db> bt
Tracing pid 0 tid 100057 td 0xfffffd000103a000
db_trace_self() at db_stack_trace+0xec
         pc = 0xffff000000613688  lr = 0xffff000000084db4
         sp = 0xffff0000698f4260  fp = 0xffff0000698f4290

db_stack_trace() at db_command+0x224
         pc = 0xffff000000084db4  lr = 0xffff000000084a3c
         sp = 0xffff0000698f42a0  fp = 0xffff0000698f4380

db_command() at db_command_loop+0x60
         pc = 0xffff000000084a3c  lr = 0xffff0000000847fc
         sp = 0xffff0000698f4390  fp = 0xffff0000698f43b0

db_command_loop() at db_trap+0xf4
         pc = 0xffff0000000847fc  lr = 0xffff000000087964
         sp = 0xffff0000698f43c0  fp = 0xffff0000698f45e0

db_trap() at kdb_trap+0x180
         pc = 0xffff000000087964  lr = 0xffff0000003693e0
         sp = 0xffff0000698f45f0  fp = 0xffff0000698f4650

kdb_trap() at do_el1h_sync+0x90
         pc = 0xffff0000003693e0  lr = 0xffff00000062956c
         sp = 0xffff0000698f4660  fp = 0xffff0000698f4690

do_el1h_sync() at handle_el1h_sync+0x74
         pc = 0xffff00000062956c  lr = 0xffff000000615074
         sp = 0xffff0000698f46a0  fp = 0xffff0000698f47b0

handle_el1h_sync() at kdb_enter+0x38
         pc = 0xffff000000615074  lr = 0xffff000000368ac8
         sp = 0xffff0000698f47c0  fp = 0xffff0000698f4850

kdb_enter() at vpanic+0x180
         pc = 0xffff000000368ac8  lr = 0xffff000000326dd8
         sp = 0xffff0000698f4860  fp = 0xffff0000698f48d0

vpanic() at panic+0x48
         pc = 0xffff000000326dd8  lr = 0xffff000000326c54
         sp = 0xffff0000698f48e0  fp = 0xffff0000698f4960

panic() at data_abort+0x21c
         pc = 0xffff000000326c54  lr = 0xffff0000006298e8
         sp = 0xffff0000698f4970  fp = 0xffff0000698f4a20

data_abort() at do_el1h_sync+0xfc
         pc = 0xffff0000006298e8  lr = 0xffff0000006295d8
         sp = 0xffff0000698f4a30  fp = 0xffff0000698f4a60

do_el1h_sync() at handle_el1h_sync+0x74
         pc = 0xffff0000006295d8  lr = 0xffff000000615074
         sp = 0xffff0000698f4a70  fp = 0xffff0000698f4b80

handle_el1h_sync() at thread_lock_flags_+0x1a8
         pc = 0xffff000000615074  lr = 0xffff000000309060
         sp = 0xffff0000698f4b90  fp = 0xffff0000698f4c80

thread_lock_flags_() at statclock_cnt+0x11c
         pc = 0xffff000000309060  lr = 0xffff0000002c5b90
         sp = 0xffff0000698f4c90  fp = 0xffff0000698f4cb0

statclock_cnt() at handleevents+0x108
         pc = 0xffff0000002c5b90  lr = 0xffff00000064ad84
         sp = 0xffff0000698f4cc0  fp = 0xffff0000698f4d00

handleevents() at timercb+0xe0
         pc = 0xffff00000064ad84  lr = 0xffff00000064b51c
         sp = 0xffff0000698f4d10  fp = 0xffff0000698f4d80

timercb() at arm_tmr_intr+0x58
         pc = 0xffff00000064b51c  lr = 0xffff000000600e5c
         sp = 0xffff0000698f4d90  fp = 0xffff0000698f4d90

arm_tmr_intr() at intr_event_handle+0x64
         pc = 0xffff000000600e5c  lr = 0xffff0000002edd50
         sp = 0xffff0000698f4da0  fp = 0xffff0000698f4dd0

intr_event_handle() at intr_isrc_dispatch+0x30
         pc = 0xffff0000002edd50  lr = 0xffff00000064d8ec
         sp = 0xffff0000698f4de0  fp = 0xffff0000698f4df0

intr_isrc_dispatch() at arm_gic_intr+0xf0
         pc = 0xffff00000064d8ec  lr = 0xffff000000601848
         sp = 0xffff0000698f4e00  fp = 0xffff0000698f4e50

arm_gic_intr() at intr_irq_handler+0x60
         pc = 0xffff000000601848  lr = 0xffff00000064d6e0
         sp = 0xffff0000698f4e60  fp = 0xffff0000698f4e80

intr_irq_handler() at handle_el1h_irq+0x70
         pc = 0xffff00000064d6e0  lr = 0xffff000000615130
         sp = 0xffff0000698f4e90  fp = 0xffff0000698f4fa0

handle_el1h_irq() at ns8250_putc+0x2c
         pc = 0xffff000000615130  lr = 0xffff00000019a570
         sp = 0xffff0000698f4fb0  fp = 0xffff0000698f5050

ns8250_putc() at ns8250_putc+0x2c
         pc = 0xffff00000019a570  lr = 0xffff00000019a570
         sp = 0xffff0000698f5060  fp = 0xffff0000698f5080

ns8250_putc() at uart_cnputc+0x94
         pc = 0xffff00000019a570  lr = 0xffff0000001a0860
         sp = 0xffff0000698f5090  fp = 0xffff0000698f50c0

uart_cnputc() at cnputc+0x90
         pc = 0xffff0000001a0860  lr = 0xffff0000002cb3a8
         sp = 0xffff0000698f50d0  fp = 0xffff0000698f5120

cnputc() at cnputs+0xb4
         pc = 0xffff0000002cb3a8  lr = 0xffff0000002cb7c8
         sp = 0xffff0000698f5130  fp = 0xffff0000698f5150

cnputs() at putchar+0x158
         pc = 0xffff0000002cb7c8  lr = 0xffff00000036f04c
         sp = 0xffff0000698f5160  fp = 0xffff0000698f51e0

putchar() at kvprintf+0xda8
         pc = 0xffff00000036f04c  lr = 0xffff00000036ec70
         sp = 0xffff0000698f51f0  fp = 0xffff0000698f5300

kvprintf() at vprintf+0x7c
         pc = 0xffff00000036ec70  lr = 0xffff00000036f838
         sp = 0xffff0000698f5310  fp = 0xffff0000698f5420

vprintf() at printf+0x48
         pc = 0xffff00000036f838  lr = 0xffff00000036f7ac
         sp = 0xffff0000698f5430  fp = 0xffff0000698f54b0

printf() at print_registers+0x4c
         pc = 0xffff00000036f7ac  lr = 0xffff00000062966c
         sp = 0xffff0000698f54c0  fp = 0xffff0000698f54f0

print_registers() at data_abort+0x1f0
         pc = 0xffff00000062966c  lr = 0xffff0000006298bc
         sp = 0xffff0000698f5500  fp = 0xffff0000698f55b0

data_abort() at do_el1h_sync+0xfc
         pc = 0xffff0000006298bc  lr = 0xffff0000006295d8
         sp = 0xffff0000698f55c0  fp = 0xffff0000698f55f0

do_el1h_sync() at handle_el1h_sync+0x74
         pc = 0xffff0000006295d8  lr = 0xffff000000615074
         sp = 0xffff0000698f5600  fp = 0xffff0000698f5710

handle_el1h_sync() at sched_switch+0x54c
         pc = 0xffff000000615074  lr = 0xffff000000351dd4
         sp = 0xffff0000698f5720  fp = 0xffff0000698f5800

sched_switch() at mi_switch+0x118
         pc = 0xffff000000351dd4  lr = 0xffff000000330c14
         sp = 0xffff0000698f5810  fp = 0xffff0000698f5830

mi_switch() at taskqgroup_binder+0x74
         pc = 0xffff000000330c14  lr = 0xffff000000367864
         sp = 0xffff0000698f5840  fp = 0xffff0000698f5860

taskqgroup_binder() at gtaskqueue_run_locked+0x160
         pc = 0xffff000000367864  lr = 0xffff000000367710
         sp = 0xffff0000698f5870  fp = 0xffff0000698f58e0

gtaskqueue_run_locked() at gtaskqueue_thread_loop+0xcc
         pc = 0xffff000000367710  lr = 0xffff0000003672c8
         sp = 0xffff0000698f58f0  fp = 0xffff0000698f5910

gtaskqueue_thread_loop() at fork_exit+0x94
         pc = 0xffff0000003672c8  lr = 0xffff0000002eab20
         sp = 0xffff0000698f5920  fp = 0xffff0000698f5950

fork_exit() at fork_trampoline+0x10
         pc = 0xffff0000002eab20  lr = 0xffff00000062934c
         sp = 0xffff0000698f5960  fp = 0x0000000000000000

Booting with a debug kernel worked fine. (This matches up
with past reports about "recent" pine64+ handling.)

But trying to have the root file system on a USB SSD
drive failed to see the USB drive at all. (This matches
up with past reports about "recent" pine64+ handling.)

From a separate non-debug kernel boot attempt:
(remember the "thread_lock_flags_+0x298: ldr w4, [x3, #156]"
but also note x8 in addition to x3)

db> show reg
spsr        0x96000004000003c5
x0          0xffff00000069b000  $d.2+0x1ac
x1                         0x2
x2          0xffff00000069ba48  $d.5+0x1d
x3                  0xdeadc0d8 <<<<<<<<< Note the "0xdeadc0d8"
x4                         0x3
x5          0xffff000000610cf0  generic_bs_barrier
x6                           0
x7                        0x40  $d.14
x8                  0xdeadc0de <<<<<<<<< Note the "0xdeadc0de"
x9                           0
x10                 0x975c860b
x11                 0x975c860b
x12                  0x51eb850
x13                        0x4
x14                       0x66  $d.9+0x26
x15         0xffff0000007004ce  hex2ascii_data
x16                          0
x17                          0
x18         0xffff00006990ec10
x19         0xfffffd000103a000
x20         0xffff000000bcee70  blocked_lock+0x18
x21         0xffff00000080e5a8  sdt_lockstat___spin__release
x22                  0x3938700
x23         0xfffffd000103a000
x24         0xffff000000bcee58  blocked_lock
x25                        0x4
x26                   0x98967f
x27         0xffff0000009ef000  next_to_notify
x28         0xffff000000bb9000  proc0+0x4f8
x29         0xffff00006990ec80
lr          0xffff000000309064  thread_lock_flags_+0x1ac
elr         0xffff000000309154  thread_lock_flags_+0x29c
sp          0xffff00006990ec10
thread_lock_flags_+0x298:       ldr     w4, [x3, #156]
db> bt
Tracing pid 0 tid 100057 td 0xfffffd000103a000
db_trace_self() at db_stack_trace+0xec
         pc = 0xffff000000613688  lr = 0xffff000000084db4
         sp = 0xffff00006990e260  fp = 0xffff00006990e290

db_stack_trace() at db_command+0x224
         pc = 0xffff000000084db4  lr = 0xffff000000084a3c
         sp = 0xffff00006990e2a0  fp = 0xffff00006990e380

db_command() at db_command_loop+0x60
         pc = 0xffff000000084a3c  lr = 0xffff0000000847fc
         sp = 0xffff00006990e390  fp = 0xffff00006990e3b0

db_command_loop() at db_trap+0xf4
         pc = 0xffff0000000847fc  lr = 0xffff000000087964
         sp = 0xffff00006990e3c0  fp = 0xffff00006990e5e0

db_trap() at kdb_trap+0x180
         pc = 0xffff000000087964  lr = 0xffff0000003693e0
         sp = 0xffff00006990e5f0  fp = 0xffff00006990e650

kdb_trap() at do_el1h_sync+0x90
         pc = 0xffff0000003693e0  lr = 0xffff00000062956c
         sp = 0xffff00006990e660  fp = 0xffff00006990e690

do_el1h_sync() at handle_el1h_sync+0x74
         pc = 0xffff00000062956c  lr = 0xffff000000615074
         sp = 0xffff00006990e6a0  fp = 0xffff00006990e7b0

handle_el1h_sync() at kdb_enter+0x38
         pc = 0xffff000000615074  lr = 0xffff000000368ac8
         sp = 0xffff00006990e7c0  fp = 0xffff00006990e850

kdb_enter() at vpanic+0x180
         pc = 0xffff000000368ac8  lr = 0xffff000000326dd8
         sp = 0xffff00006990e860  fp = 0xffff00006990e8d0

vpanic() at panic+0x48
         pc = 0xffff000000326dd8  lr = 0xffff000000326c54
         sp = 0xffff00006990e8e0  fp = 0xffff00006990e960

panic() at data_abort+0x21c
         pc = 0xffff000000326c54  lr = 0xffff0000006298e8
         sp = 0xffff00006990e970  fp = 0xffff00006990ea20

data_abort() at do_el1h_sync+0xfc
         pc = 0xffff0000006298e8  lr = 0xffff0000006295d8
         sp = 0xffff00006990ea30  fp = 0xffff00006990ea60

do_el1h_sync() at handle_el1h_sync+0x74
         pc = 0xffff0000006295d8  lr = 0xffff000000615074
         sp = 0xffff00006990ea70  fp = 0xffff00006990eb80

handle_el1h_sync() at thread_lock_flags_+0x1a8
         pc = 0xffff000000615074  lr = 0xffff000000309060
         sp = 0xffff00006990eb90  fp = 0xffff00006990ec80

thread_lock_flags_() at statclock_cnt+0x11c
         pc = 0xffff000000309060  lr = 0xffff0000002c5b90
         sp = 0xffff00006990ec90  fp = 0xffff00006990ecb0

statclock_cnt() at handleevents+0x108
         pc = 0xffff0000002c5b90  lr = 0xffff00000064ad84
         sp = 0xffff00006990ecc0  fp = 0xffff00006990ed00

handleevents() at timercb+0xe0
         pc = 0xffff00000064ad84  lr = 0xffff00000064b51c
         sp = 0xffff00006990ed10  fp = 0xffff00006990ed80

timercb() at arm_tmr_intr+0x58
         pc = 0xffff00000064b51c  lr = 0xffff000000600e5c
         sp = 0xffff00006990ed90  fp = 0xffff00006990ed90

arm_tmr_intr() at intr_event_handle+0x64
         pc = 0xffff000000600e5c  lr = 0xffff0000002edd50
         sp = 0xffff00006990eda0  fp = 0xffff00006990edd0

intr_event_handle() at intr_isrc_dispatch+0x30
         pc = 0xffff0000002edd50  lr = 0xffff00000064d8ec
         sp = 0xffff00006990ede0  fp = 0xffff00006990edf0

intr_isrc_dispatch() at arm_gic_intr+0xf0
         pc = 0xffff00000064d8ec  lr = 0xffff000000601848
         sp = 0xffff00006990ee00  fp = 0xffff00006990ee50

arm_gic_intr() at intr_irq_handler+0x60
         pc = 0xffff000000601848  lr = 0xffff00000064d6e0
         sp = 0xffff00006990ee60  fp = 0xffff00006990ee80

intr_irq_handler() at handle_el1h_irq+0x70
         pc = 0xffff00000064d6e0  lr = 0xffff000000615130
         sp = 0xffff00006990ee90  fp = 0xffff00006990efa0

handle_el1h_irq() at ns8250_putc+0x2c
         pc = 0xffff000000615130  lr = 0xffff00000019a570
         sp = 0xffff00006990efb0  fp = 0xffff00006990f050

ns8250_putc() at ns8250_putc+0x2c
         pc = 0xffff00000019a570  lr = 0xffff00000019a570
         sp = 0xffff00006990f060  fp = 0xffff00006990f080

ns8250_putc() at uart_cnputc+0x94
         pc = 0xffff00000019a570  lr = 0xffff0000001a0860
         sp = 0xffff00006990f090  fp = 0xffff00006990f0c0

uart_cnputc() at cnputc+0x90
         pc = 0xffff0000001a0860  lr = 0xffff0000002cb3a8
         sp = 0xffff00006990f0d0  fp = 0xffff00006990f120

cnputc() at cnputs+0xb4
         pc = 0xffff0000002cb3a8  lr = 0xffff0000002cb7c8
         sp = 0xffff00006990f130  fp = 0xffff00006990f150

cnputs() at putchar+0x158
         pc = 0xffff0000002cb7c8  lr = 0xffff00000036f04c
         sp = 0xffff00006990f160  fp = 0xffff00006990f1e0

putchar() at kvprintf+0xda8
         pc = 0xffff00000036f04c  lr = 0xffff00000036ec70
         sp = 0xffff00006990f1f0  fp = 0xffff00006990f300

kvprintf() at vprintf+0x7c
         pc = 0xffff00000036ec70  lr = 0xffff00000036f838
         sp = 0xffff00006990f310  fp = 0xffff00006990f420

vprintf() at printf+0x48
         pc = 0xffff00000036f838  lr = 0xffff00000036f7ac
         sp = 0xffff00006990f430  fp = 0xffff00006990f4b0

printf() at print_registers+0x4c
         pc = 0xffff00000036f7ac  lr = 0xffff00000062966c
         sp = 0xffff00006990f4c0  fp = 0xffff00006990f4f0

print_registers() at data_abort+0x1f0
         pc = 0xffff00000062966c  lr = 0xffff0000006298bc
         sp = 0xffff00006990f500  fp = 0xffff00006990f5b0

data_abort() at do_el1h_sync+0xfc
         pc = 0xffff0000006298bc  lr = 0xffff0000006295d8
         sp = 0xffff00006990f5c0  fp = 0xffff00006990f5f0

do_el1h_sync() at handle_el1h_sync+0x74
         pc = 0xffff0000006295d8  lr = 0xffff000000615074
         sp = 0xffff00006990f600  fp = 0xffff00006990f710

handle_el1h_sync() at sched_switch+0x54c
         pc = 0xffff000000615074  lr = 0xffff000000351dd4
         sp = 0xffff00006990f720  fp = 0xffff00006990f800

sched_switch() at mi_switch+0x118
         pc = 0xffff000000351dd4  lr = 0xffff000000330c14
         sp = 0xffff00006990f810  fp = 0xffff00006990f830

mi_switch() at taskqgroup_binder+0x74
         pc = 0xffff000000330c14  lr = 0xffff000000367864
         sp = 0xffff00006990f840  fp = 0xffff00006990f860

taskqgroup_binder() at gtaskqueue_run_locked+0x160
         pc = 0xffff000000367864  lr = 0xffff000000367710
         sp = 0xffff00006990f870  fp = 0xffff00006990f8e0

gtaskqueue_run_locked() at gtaskqueue_thread_loop+0xcc
         pc = 0xffff000000367710  lr = 0xffff0000003672c8
         sp = 0xffff00006990f8f0  fp = 0xffff00006990f910

gtaskqueue_thread_loop() at fork_exit+0x94
         pc = 0xffff0000003672c8  lr = 0xffff0000002eab20
         sp = 0xffff00006990f920  fp = 0xffff00006990f950

fork_exit() at fork_trampoline+0x10
         pc = 0xffff0000002eab20  lr = 0xffff00000062934c
         sp = 0xffff00006990f960  fp = 0x0000000000000000

===
Mark Millard
markmi at dsl-only.net