On Wed, Feb 03, 2021 at 10:34:48PM +0000, Edd Barrett wrote:
> On Wed, Feb 03, 2021 at 11:22:53PM +0100, Mark Kettenis wrote:
> > The actual panic message would be helpful...
>
> Doh. If it aint there, then I fudged the copy-paste. I can try to
> reproduce it...
Got it! See below.
Note that I upddated my snapshot since last time. I can provide a new
dmesg if required, but I'd need to reboot. First let's confirm that we
have everything we need from ddb (i still have it at the prompt on the
serial line).
panic: uvm_fault failed: ffffff8000422080 esr 96000007 far ffffff8001fc3380
Stopped at panic+0x158: mov w0, w20
TID PID UID PRFLAGS PFLAGS CPU COMMAND
* 20589 81386 0 0x11 0 0K perl
506484 33678 0 0x13 0 2 perl
db_enter() at panic+0x154
panic() at do_el1h_sync+0x21c
do_el0_sync() at handle_el1h_sync+0x6c
handle_el1h_sync() at pmap_copy_page+0x98
pmap_copy_page() at pmap_copy_page+0x98
pmap_copy_page() at uvm_fault_upper+0x144
uvm_fault_upper() at uvm_fault+0x100
https://www.openbsd.org/ddb.html describes the minimum info required in bug
reports. Insufficient info makes it difficult to find and fix bugs.
ddb{0}> show panic
uvm_fault failed: ffffff8000422080 esr 96000007 far ffffff8001fc3380
ddb{0}> show reg
x0 0x1
x1 0xffffff8028413000
x2 0x4
x3 0xb0 $d.1+0x9d
x4 0xffffff80286238c0
x5 0
x6 0x2
x7 0xffffff8028623c10
x8 0x1
x9 0x92178fc3ac5bcdfb
x10 0xb
x11 0x1
x12 0xffffffc8
x13 0x61781003
x14 0xffffffff
x15 0x4d4223665ac6ecd
x16 0x901933ca8
x17 0x8f7094788
x18 0xffffff8028623920
x19 0xffffff8000c459b5 $d.2+0x27b
x20 0x100 $d.1+0xed
x21 0xffffff8000e1ca90 kprintf_mutex
x22 0xffffff8000eee000 rttimer_pool+0x148
x23 0xffffff8028623970
x24 0xffffff8000ee50c0 kernel_map_store
x25 0xffffff8001fc3000 _end+0x106e210
x26 0xffffff802861f000
x27 0x20 $d.1+0xd
x28 0x9b $d.1+0x88
x29 0xffffff8028623920
x30 0
sp 0xffffff8028623920
spsr 0x60000345
elr 0xffffff80009ef9d8 db_enter+0x14
lr 0xffffff80006821cc panic+0x158
panic+0x158: mov w0, w20
ddb{0}> machine ddbcpu 1
Stopped at ampintc_ipi_ddb+0x1c: ldr x15, [sp,#16]
db_enter() at ampintc_ipi_ddb+0x18
ampintc_ipi_ddb() at ampintc_irq_handler+0x1c4
ampintc_irq_handler() at arm_cpu_intr+0x30
arm_cpu_intr() at handle_el1h_irq+0x6c
handle_el1h_irq() at sched_idle+0x290
sched_idle() at sched_idle+0x290
sched_idle() at proc_trampoline+0x10
ddb{1}> show reg
x0 0xffffff8011b3f400
x1 0xffffff8028413000
x2 0x4
x3 0xfffffff0
x4 0xffffff800096b2a0 smc_call
x5 0xffffff8028471000
x6 0x62 $d.1+0x4f
x7 0x1
x8 0xffffff8011b3f400
x9 0xffffff800061db50 ampintc_ipi_ddb
x10 0xb0 $d.1+0x9d
x11 0xffffff8011b3a800
x12 0xffffff8011b3f400
x13 0
x14 0xffffff8000cfd510 ap_bits_kern
x15 0x4d4223665a5946d
x16 0xffffff8000f0c000 uvm_map_entry_pool+0x110
x17 0xffffff8000f0c000 uvm_map_entry_pool+0x110
x18 0xffffff8028475c20
x19 0
x20 0x1
x21 0xffffff8028475cd0
x22 0xffffff8000f0b000 pfr_mask+0x18
x23 0
x24 0xffffff8011b41580
x25 0
x26 0x28 $d.1+0x15
x27 0x3
x28 0x1
x29 0xffffff8028475c20
x30 0
sp 0xffffff8028475c20
spsr 0xa0000345
elr 0xffffff80009ef9d8 db_enter+0x14
lr 0xffffff800061db6c ampintc_ipi_ddb+0x1c
ampintc_ipi_ddb+0x1c: ldr x15, [sp,#16]
ddb{1}> machine ddbcpu 2
Stopped at ampintc_ipi_ddb+0x1c: ldr x15, [sp,#16]
db_enter() at ampintc_ipi_ddb+0x18
ampintc_ipi_ddb() at ampintc_irq_handler+0x1c4
ampintc_irq_handler() at arm_cpu_intr+0x30
arm_cpu_intr() at handle_el1h_irq+0x6c
handle_el1h_irq() at udata_abort+0x118
udata_abort() at udata_abort+0x118
udata_abort() at do_el0_sync+0x13c
ddb{2}> show reg
x0 0xffffff8011b3f400
x1 0xffffff8028413000
x2 0x4
x3 0xfffffff0
x4 0xffffff8000626a94 uvm_map_inentry_sp
x5 0x2
x6 0
x7 0
x8 0xffffff8011b3f400
x9 0xffffff800061db50 ampintc_ipi_ddb
x10 0xb0 $d.1+0x9d
x11 0xffffff8011b44000
x12 0xffffff8011b3f400
x13 0xc0000 $d.1+0xbffed
x14 0xfc000 $d.1+0xfbfed
x15 0x4d4223665a5946d
x16 0x901933e58
x17 0x8f708f7c4
x18 0xffffff802a4a7bf0
x19 0
x20 0x1
x21 0xffffff802a4a7ca0
x22 0xffffff8000f0b000 pfr_mask+0x18
x23 0
x24 0xffffff8011b41580
x25 0
x26 0x28 $d.1+0x15
x27 0x85f7c1000
x28 0x40 $d.1+0x2d
x29 0xffffff802a4a7bf0
x30 0
sp 0xffffff802a4a7bf0
spsr 0xa0000345
elr 0xffffff80009ef9d8 db_enter+0x14
lr 0xffffff800061db6c ampintc_ipi_ddb+0x1c
ampintc_ipi_ddb+0x1c: ldr x15, [sp,#16]
ddb{2}> machine ddbcpu 3
Stopped at ampintc_ipi_ddb+0x1c: ldr x15, [sp,#16]
db_enter() at ampintc_ipi_ddb+0x18
ampintc_ipi_ddb() at ampintc_irq_handler+0x1c4
ampintc_irq_handler() at arm_cpu_intr+0x30
arm_cpu_intr() at handle_el1h_irq+0x6c
handle_el1h_irq() at sched_idle+0x290
sched_idle() at sched_idle+0x290
sched_idle() at proc_trampoline+0x10
ddb{3}> show reg
x0 0xffffff8011b3f400
x1 0xffffff8028413000
x2 0x4
x3 0xfffffff0
x4 0xffffff800096b2a0 smc_call
x5 0xffffff802847d000
x6 0xb02bb6d38bee4a07
x7 0
x8 0xffffff8011b3f400
x9 0xffffff800061db50 ampintc_ipi_ddb
x10 0xb0 $d.1+0x9d
x11 0xffffff8011b44800
x12 0xffffff8011b3f400
x13 0
x14 0x3b9aca00
x15 0x4d4223665a5946d
x16 0x14 $d.1+0x1
x17 0x8f70b0430
x18 0xffffff8028481c20
x19 0
x20 0x1
x21 0xffffff8028481cd0
x22 0xffffff8000f0b000 pfr_mask+0x18
x23 0
x24 0xffffff8011b41580
x25 0
x26 0x28 $d.1+0x15
x27 0x3
x28 0x1
x29 0xffffff8028481c20
x30 0
sp 0xffffff8028481c20
spsr 0xa0000345
elr 0xffffff80009ef9d8 db_enter+0x14
lr 0xffffff800061db6c ampintc_ipi_ddb+0x1c
ampintc_ipi_ddb+0x1c: ldr x15, [sp,#16]
ddb{0}> ps
PID TID PPID UID S FLAGS WAIT COMMAND
*81386 20589 33678 0 7 0x11 perl
43340 231344 34457 55 3 0x2 bqwait ld.lld
43340 359315 34457 55 3 0x4000082 fsleep ld.lld
43340 38601 34457 55 3 0x4000082 fsleep ld.lld
43340 231750 34457 55 3 0x4000082 fsleep ld.lld
43340 377913 34457 55 3 0x4000082 fsleep ld.lld
34457 462205 27690 55 3 0x82 wait cc
27690 401886 15933 55 3 0x200082 poll miniruby
27690 453437 15933 55 3 0x4200082 poll miniruby
15933 459398 75514 55 3 0x10008a sigsusp sh
75514 78812 48167 55 3 0x10008a sigsusp make
48167 96186 58908 55 3 0x10008a sigsusp sh
58908 454846 6135 55 3 0x10008a sigsusp make
6135 50049 96543 55 3 0x10008a sigsusp make
96543 478499 46118 55 3 0x10008a sigsusp sh
46118 166608 33755 55 3 0x10008a sigsusp make
33755 239357 94329 55 3 0x10008a sigsusp sh
94329 475508 33678 55 3 0x10008a sigsusp make
7568 16158 56753 1000 3 0x100083 poll top
56753 279171 64123 1000 3 0x10008b sigsusp ksh
33678 506484 69489 0 7 0x13 perl
69489 40952 71215 0 3 0x10008b sigsusp ksh
71215 352113 64123 1000 3 0x10008b sigsusp ksh
64123 446796 1 1000 3 0x100080 kqread tmux
7254 474451 1 0 3 0x100083 ttyin getty
65057 5194 1 0 3 0x100098 poll cron
3381 54908 1 99 3 0x100090 poll sndiod
15623 29370 1 110 3 0x100090 poll sndiod
48070 373922 93618 95 3 0x100092 kqread smtpd
5392 63995 93618 103 3 0x100092 kqread smtpd
2129 47763 93618 95 3 0x100092 kqread smtpd
62156 75475 93618 95 3 0x100092 kqread smtpd
58977 471444 93618 95 3 0x100092 kqread smtpd
43789 417562 93618 95 3 0x100092 kqread smtpd
93618 341463 1 0 3 0x100080 kqread smtpd
3471 475173 1 0 3 0x80 select sshd
94214 42281 1 0 3 0x100080 poll ntpd
40001 291382 23730 83 3 0x100092 poll ntpd
23730 5990 1 83 3 0x100092 poll ntpd
15283 133676 57214 74 3 0x100092 bpf pflogd
57214 285694 1 0 3 0x80 netio pflogd
62987 308017 9962 73 3 0x100090 kqread syslogd
9962 283510 1 0 3 0x100082 netio syslogd
97453 382325 77967 115 3 0x100092 kqread slaacd
84901 495061 77967 115 3 0x100092 kqread slaacd
77967 283269 1 0 3 0x100080 kqread slaacd
8247 475743 0 0 3 0x14200 bored smr
41206 421626 0 0 3 0x14200 pgzero zerothread
47538 512418 0 0 3 0x14200 aiodoned aiodoned
86063 391830 0 0 3 0x14200 bqwait update
61385 219501 0 0 3 0x14200 cleaner cleaner
9044 244147 0 0 3 0x14200 reaper reaper
40386 229370 0 0 3 0x14200 pgdaemon pagedaemon
64029 172554 0 0 3 0x14200 bored crynlk
99225 105130 0 0 3 0x14200 bored crypto
92412 24463 0 0 3 0x40014200 acpi0 acpi0
27015 467716 0 0 3 0x14200 usbtsk usbtask
61051 95902 0 0 3 0x14200 usbatsk usbatsk
99634 450063 0 0 7 0x40014200 idle3
6801 268986 0 0 3 0x40014200 idle2
90550 464913 0 0 7 0x40014200 idle1
67752 457826 0 0 3 0x14200 bored softnet
48397 377854 0 0 3 0x14200 bored systqmp
88690 230054 0 0 3 0x14200 bored systq
14185 429422 0 0 3 0x40014200 bored softclock
88850 59880 0 0 3 0x40014200 idle0
2994 322564 0 0 3 0x14200 kmalloc kmthread
1 362803 0 0 3 0x82 wait init
0 0 -1 0 3 0x10200 scheduler swapper
ddb{3}> show uvm
Current UVM status:
pagesize=4096 (0x1000), pagemask=0xfff, pageshift=12
1770326 VM pages: 35282 active, 85064 inactive, 1 wired, 1126150 free (141726
zero)
min 10% (25) anon, 10% (25) vnode, 5% (12) vtext
freemin=59010, free-target=78680, inactive-target=78681, wired-max=590108
faults=161531384, traps=0, intrs=0, ctxswitch=5770326 fpuswitch=0
softint=4167971, syscalls=108978586, kmapent=16
fault counts:
noram=0, noanon=0, noamap=0, pgwait=0, pgrele=0
ok relocks(total)=318962(319600), anget(retries)=60066360(0), amapcopy=3648
0996
neighbor anon/obj pg=5542462/87231636, gets(lock/unlock)=68211676/319600
cases: anon=54148894, anoncow=5917466, obj=66495873, prcopy=1715165, przero
=33254007
daemon and swap counts:
woke=35, revs=0, scans=0, obscans=0, anscans=0
busy=0, freed=0, reactivate=0, deactivate=0
pageouts=0, pending=0, nswget=0
nswapdev=1
swpages=263063, swpginuse=0, swpgonly=0 paging=0
kernel pointers:
objs(kern)=0xffffff8000e912c0
ddb{3}> show bcstats
Current Buffer Cache status:
numbufs 52574 busymapped 0, delwri 37
kvaslots 235 avail kva slots 235
bufpages 484414, dmapages 3702, dirtypages 320
pendingreads 0, pendingwrites 0
highflips 217185, highflops 0, dmaflips 22564
--
Best Regards
Edd Barrett
http://www.theunixzoo.co.uk
