Rpi3 panic: non-current pmap 0xfffffd001e05b130

From: bob prohaska <fbsd_at_www.zefox.net>
Date: Sat, 30 Nov 2019 17:16:15 -0800
A Pi3 running r355024 reported a panic while doing a -j3 make of
www/chromium:

panic: non-current pmap 0xfffffd001e05b130
cpuid = 0
time = 1575161361
KDB: stack backtrace:
db_trace_self() at db_trace_self_wrapper+0x28
	 pc = 0xffff000000729e4c  lr = 0xffff0000001066c8
	 sp = 0xffff000059f3e2b0  fp = 0xffff000059f3e4c0

db_trace_self_wrapper() at vpanic+0x18c
	 pc = 0xffff0000001066c8  lr = 0xffff000000400d7c
	 sp = 0xffff000059f3e4d0  fp = 0xffff000059f3e580

vpanic() at panic+0x44
	 pc = 0xffff000000400d7c  lr = 0xffff000000400b2c
	 sp = 0xffff000059f3e590  fp = 0xffff000059f3e610

panic() at pmap_remove_pages+0x8d4
	 pc = 0xffff000000400b2c  lr = 0xffff00000074154c
	 sp = 0xffff000059f3e620  fp = 0xffff000059f3e6e0

pmap_remove_pages() at vmspace_exit+0xc0
	 pc = 0xffff00000074154c  lr = 0xffff0000006c9c00
	 sp = 0xffff000059f3e6f0  fp = 0xffff000059f3e720

vmspace_exit() at exit1+0x4f8
	 pc = 0xffff0000006c9c00  lr = 0xffff0000003bc2a4
	 sp = 0xffff000059f3e730  fp = 0xffff000059f3e7a0

exit1() at sys_sys_exit+0x10
	 pc = 0xffff0000003bc2a4  lr = 0xffff0000003bbda8
	 sp = 0xffff000059f3e7b0  fp = 0xffff000059f3e7b0

sys_sys_exit() at do_el0_sync+0x514
	 pc = 0xffff0000003bbda8  lr = 0xffff000000747aa4
	 sp = 0xffff000059f3e7c0  fp = 0xffff000059f3e860

do_el0_sync() at handle_el0_sync+0x90
	 pc = 0xffff000000747aa4  lr = 0xffff00000072ca14
	 sp = 0xffff000059f3e870  fp = 0xffff000059f3e980

handle_el0_sync() at 0x404e6d60
	 pc = 0xffff00000072ca14  lr = 0x00000000404e6d60
	 sp = 0xffff000059f3e990  fp = 0x0000ffffffffd590

KDB: enter: panic
[ thread pid 94966 tid 100145 ]
Stopped at      0x40505460:     undefined       54000042
db> bt
Tracing pid 94966 tid 100145 td 0xfffffd002552b000
db_trace_self() at db_stack_trace+0xf8
         pc = 0xffff000000729e4c  lr = 0xffff000000103b0c
         sp = 0xffff000059f3de80  fp = 0xffff000059f3deb0

db_stack_trace() at db_command+0x228
         pc = 0xffff000000103b0c  lr = 0xffff000000103784
         sp = 0xffff000059f3dec0  fp = 0xffff000059f3dfa0

db_command() at db_command_loop+0x58
         pc = 0xffff000000103784  lr = 0xffff00000010352c
         sp = 0xffff000059f3dfb0  fp = 0xffff000059f3dfd0

db_command_loop() at db_trap+0xf4
         pc = 0xffff00000010352c  lr = 0xffff000000106830
         sp = 0xffff000059f3dfe0  fp = 0xffff000059f3e200

db_trap() at kdb_trap+0x1d8
         pc = 0xffff000000106830  lr = 0xffff0000004492fc
         sp = 0xffff000059f3e210  fp = 0xffff000059f3e2c0
        
kdb_trap() at do_el1h_sync+0xf4
         pc = 0xffff0000004492fc  lr = 0xffff000000747418
         sp = 0xffff000059f3e2d0  fp = 0xffff000059f3e300

do_el1h_sync() at handle_el1h_sync+0x78
         pc = 0xffff000000747418  lr = 0xffff00000072c878
         sp = 0xffff000059f3e310  fp = 0xffff000059f3e420

handle_el1h_sync() at kdb_enter+0x34
         pc = 0xffff00000072c878  lr = 0xffff000000448948
         sp = 0xffff000059f3e430  fp = 0xffff000059f3e4c0

kdb_enter() at vpanic+0x1a8
         pc = 0xffff000000448948  lr = 0xffff000000400d98
         sp = 0xffff000059f3e4d0  fp = 0xffff000059f3e580

vpanic() at panic+0x44
         pc = 0xffff000000400d98  lr = 0xffff000000400b2c
         sp = 0xffff000059f3e590  fp = 0xffff000059f3e610
        
panic() at pmap_remove_pages+0x8d4
         pc = 0xffff000000400b2c  lr = 0xffff00000074154c
         sp = 0xffff000059f3e620  fp = 0xffff000059f3e6e0

pmap_remove_pages() at vmspace_exit+0xc0
         pc = 0xffff00000074154c  lr = 0xffff0000006c9c00
         sp = 0xffff000059f3e6f0  fp = 0xffff000059f3e720

vmspace_exit() at exit1+0x4f8
         pc = 0xffff0000006c9c00  lr = 0xffff0000003bc2a4
         sp = 0xffff000059f3e730  fp = 0xffff000059f3e7a0

exit1() at sys_sys_exit+0x10
         pc = 0xffff0000003bc2a4  lr = 0xffff0000003bbda8
         sp = 0xffff000059f3e7b0  fp = 0xffff000059f3e7b0

sys_sys_exit() at do_el0_sync+0x514
         pc = 0xffff0000003bbda8  lr = 0xffff000000747aa4
         sp = 0xffff000059f3e7c0  fp = 0xffff000059f3e860
        
do_el0_sync() at handle_el0_sync+0x90
         pc = 0xffff000000747aa4  lr = 0xffff00000072ca14
         sp = 0xffff000059f3e870  fp = 0xffff000059f3e980

handle_el0_sync() at 0x404e6d60
         pc = 0xffff00000072ca14  lr = 0x00000000404e6d60
         sp = 0xffff000059f3e990  fp = 0x0000ffffffffd590

db> 

The last top screen showed

last pid: 94966;  load averages:  1.22,  1.42,  1.40                      up 0+05:10:16  16:49:20
43 processes:  1 running, 42 sleeping
CPU:  3.7% user,  0.0% nice, 20.0% system,  5.5% interrupt, 70.8% idle
Mem: 502M Active, 6672K Inact, 150M Laundry, 184M Wired, 90M Buf, 55M Free
Swap: 7194M Total, 3835M Used, 3359M Free, 53% Inuse, 11M In, 3852K Out

  PID USERNAME    THR PRI NICE   SIZE    RES STATE    C   TIME    WCPU COMMAND
71350 root          1  22    0   951M   144M swread   0  10:20   5.97% c++
58502 root          1  21    0   986M   232M swread   1  11:23   3.42% c++
77283 root          1  22    0   963M   151M swread   0   8:45   3.30% c++
 6904 root          1  22    0  1144M   191M swread   0  21:26   3.29% c++
 1091 bob           1  52    0    11M   324K wait     3   0:55   0.27% sh
 1079 bob           1  20    0    13M  1636K CPU0     0   0:57   0.22% top
 1074 bob           1  20    0    19M  1316K select   1   0:13   0.03% sshd
  970 root          1  20    0    16M  1500K select   1   0:02   0.02% sendmail
 1069 root          1  20    0   204M  1044K select   3   1:40   0.00% ninja
 1050 root          1  20    0    12M   972K select   2   0:02   0.00% make
  977 root          1  20    0    11M     0B nanslp   1   0:02   0.00% <cron>
  957 root          1  20    0    19M  1216K select   1   0:01   0.00% sshd
  824 root          1  20    0    11M  1084K select   2   0:01   0.00% syslogd
 1084 bob           1  20    0    13M  1008K ttyin    0   0:00   0.00% tcsh

and the last few storage activity log entries were:

dT: 1.002s  w: 1.000s
 L(q)  ops/s    r/s   kBps   ms/r    w/s   kBps   ms/w    d/s   kBps   ms/d   %busy Name
    1    713    694   4666    3.7     20    116    6.0      0      0    0.0   90.9  mmcsd0
    1    713    694   4666    3.8     20    116    6.0      0      0    0.0   91.2  mmcsd0s2
    2    751    734   4730    2.0     17     96    0.6      0      0    0.0   79.4  da0
    1    713    694   4666    3.8     20    116    6.0      0      0    0.0   91.4  mmcsd0s2b
    2    751    734   4730    2.0     17     96    0.6      0      0    0.0   79.9  da0p6
Sat Nov 30 16:48:21 PST 2019
Device          1K-blocks     Used    Avail Capacity
/dev/mmcsd0s2b    4404252  1958976  2445276    44%
/dev/da0p6        5242880  1956872  3286008    37%
Total             9647132  3915848  5731284    41%
Nov 30 16:38:17 www sshd[91264]: error: PAM: Authentication error for illegal user support from 103.133.104.114
Nov 30 16:38:17 www sshd[91264]: error: Received disconnect from 103.133.104.114 port 52716:14: No more user authentication methods available. [preauth]
0/1016/1016/19178 mbuf clusters in use (current/cache/total/max)
procs     memory       page                      disks     faults       cpu
r b w     avm     fre  flt  re  pi  po    fr   sr mm0 da0   in   sy   cs us sy id
 0  0 12 4523836   56064  6988 186 715 257  6931 25128   0   0 30789  1073 29817 14 26 60
dT: 1.002s  w: 1.000s
 L(q)  ops/s    r/s   kBps   ms/r    w/s   kBps   ms/w    d/s   kBps   ms/d   %busy Name
    0    709    687   4588    3.9     22    144    5.8      0      0    0.0   90.5  mmcsd0
    0    709    687   4588    3.9     22    144    5.8      0      0    0.0   90.9  mmcsd0s2
    2    698    679   4696    2.1     19    104    0.6      0      0    0.0   75.2  da0
    0    709    687   4588    3.9     22    144    5.8      0      0    0.0   91.0  mmcsd0s2b
    2    698    679   4696    2.2     19    104    0.6      0      0    0.0   75.7  da0p6
Sat Nov 30 16:48:22 PST 2019
Device          1K-blocks     Used    Avail Capacity
/dev/mmcsd0s2b    4404252  1959032  2445220    44%
/dev/da0p6        5242880  1956928  3285952    37%
Total             9647132  3915960  5731172    41%
Nov 30 16:38:17 www sshd[91264]: error: PAM: Authentication error for illegal user support from 103.133.104.114
Nov 30 16:38:17 www sshd[91264]: error: Received disconnect from 103.133.104.114 port 52716:14: No more user authentication methods available. [preauth]
0/1016/1016/19178 mbuf clusters in use (current/cache/total/max)
procs     memory       page                      disks     faults       cpu
r b w     avm     fre  flt  re  pi  po    fr   sr mm0 da0   in   sy   cs us sy id
 0  0 12 4523836   55844  6989 186 715 257  6932 25127 604 604 30790  1073 29819 14 26 60
dT: 1.001s  w: 1.000s
 L(q)  ops/s    r/s   kBps   ms/r    w/s   kBps   ms/w    d/s   kBps   ms/d   %busy Name
    2    736    680   4829    3.9     56    292    5.0      0      0    0.0   94.4  mmcsd0
    2    736    680   4829    4.0     56    292    5.0      0      0    0.0   94.6  mmcsd0s2
    1    680    627   4014    1.9     53    328    1.0      0      0    0.0   71.1  da0
    2    736    680   4829    4.0     56    292    5.0      0      0    0.0   94.7  mmcsd0s2b
    1    680    627   4014    1.9     53    328    1.0      0      0    0.0   71.7  da0p6
Sat Nov 30 16:48:24 PST 2019
Device          1K-blocks     Used    Avail Capacity
/dev/mmcsd0s2b    4404252  1959324  2444928    44%
/dev/da0p6        5242880  1957468  3285412    37%
Total             9647132  3916792  5730340    41%
Nov 30 16:38:17 www sshd[91264]: error: PAM: Authentication error for illegal user support from 103.133.104.114
Nov 30 16:38:17 www sshd[91264]: error: Received disconnect from 103.133.104.114 port 52716:14: No more user authentication methods available. [preauth]
0/1016/1016/19178 mbuf clusters in use (current/cache/total/max)
procs     memory       page                      disks     faults       cpu
r b w     avm     fre  flt  re  pi  po    fr   sr mm0 da0   in   sy   cs us sy id
 0  0 12 4523836   52860  6989 186 715 257  6932 25125 1038 1038 30790  1073 29820 14 26 60
dT: 1.002s  w: 1.000s
 L(q)  ops/s    r/s   kBps   ms/r    w/s   kBps   ms/w    d/s   kBps   ms/d   %busy Name
    1    751    702   4860    4.0     49    251    5.0      0      0    0.0   94.4  mmcsd0
    1    751    702   4860    4.1     49    251    5.1      0      0    0.0   94.7  mmcsd0s2
    2    704    658   4082    1.8     46    235    0.6      0      0    0.0   71.9  da0
    1    751    702   4860    4.1     49    251    5.1      0      0    0.0   94.8  mmcsd0s2b
    2    704    658   4082    1.8     46    235    0.7      0      0    0.0   72.6  da0p6
Sat Nov 30 16:48:26 PST 2019
Device          1K-blocks     Used    Avail Capacity
/dev/mmcsd0s2b    4404252  1959504  2444748    44%
/dev/da0p6        5242880  1957540  3285340    37%
Total             9647132  3917044  5730088    41%
Nov 30 16:38:17 www sshd[91264]: error: PAM: Authentication error for illegal user support from 103.133.104.114
Nov 30 16:38:17 www sshd[91264]: error: Received disconnect from 103.133.104.114 port 52716:14: No more user authentication methods available. [preauth]
0/1016/1016/19178 mbuf clusters in use (current/cache/total/max)
procs     memory       page                      disks     faults       cpu
r b w     avm     fre  flt  re  pi  po    fr   sr mm0 da0   in   sy   cs us sy id
 0  0 12 4523868   46872  6989 186 715 257  6932 25123   0   0 30790  1073 29820 14 26 60
dT: 1.002s  w: 1.000s
 L(q)  ops/s    r/s   kBps   ms/r    w/s   kBps   ms/w    d/s   kBps   ms/d   %busy Name
    2    700    681   4888    3.7     19    108    3.7      0      0    0.0   92.1  mmcsd0
    2    700    681   4888    3.8     19    108    3.7      0      0    0.0   92.5  mmcsd0s2
    2    709    687   4314    2.1     22    108    3.4      0      0    0.0   78.2  da0
    2    700    681   4888    3.8     19    108    3.7      0      0    0.0   92.6  mmcsd0s2b
    2    709    687   4314    2.1     22    108    3.4      0      0    0.0   78.7  da0p6
Sat Nov 30 16:48:28 PST 2019
Device          1K-blocks     Used    Avail Capacity
/dev/mmcsd0s2b    440

It's clear the machine was heavily loaded, but storage didn't appear to be swamped.
I hope the foregoing has been of some interest, thanks for reading!

bob prohaska
Received on Sun Dec 01 2019 - 00:16:21 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:41:22 UTC