On 14/04/22(Thu) 18:29, Alexander Bluhm wrote:
> [...]
> vn_lock: v_usecount == 0: 0x23e6b910, type VREG, use 0, write 0, hold 0, 
> flags (VBIOONFREELIST)
>         tag VT_UFS, ino 703119, on dev 0, 10 flags 0x100, effnlink 1, nlink 1
>         mode 0100660, owner 21, group 21, size 13647873
> ==> vnode_history_print 0x23e6b910, next=5
>  [3] c++[68540] usecount 2>1
> #0  0x625703e0
>  [4] reaper[31684] usecount 1>0
> #0  splx+0x30
> #1  0xfffffffc
> #2  vrele+0x5c
> #3  uvn_detach+0x154

I wonder if the `uvn' has the UVM_VNODE_CANPERSIST set at this point.
This would explain why the associate pages are not freed and end up in
the inactive list.

Is there an easy way to check that?

> #4  uvm_unmap_detach+0x1a4
> #5  uvm_map_teardown+0x184
> #6  uvmspace_free+0x60
> #7  uvm_exit+0x30
> #8  reaper+0x138
> #9  fork_trampoline+0x14
> 
> panic: vn_lock: v_usecount == 0
> Stopped at      db_enter+0x24:  lwz r11,12(r1)
>     TID    PID    UID     PRFLAGS     PFLAGS  CPU  COMMAND
>  433418  19000     21         0x2          0    0  c++
> *232867  36343      0     0x14000      0x200    1K pagedaemon
> db_enter() at db_enter+0x20
> panic(9434f4) at panic+0x158
> vn_lock(49535400,202000) at vn_lock+0x1c4
> uvn_io(5db64f85,a994c4,a979f4,ffffffff,e4010000) at uvn_io+0x254
> uvn_put(fec3fe2c,e7ebbdd4,23ca9af0,40e0880) at uvn_put+0x64
> uvm_pager_put(0,0,e7ebbd70,32c0c0,2000000,80000000,0) at uvm_pager_put+0x15c
> uvmpd_scan_inactive(0) at uvmpd_scan_inactive+0x224
> uvmpd_scan() at uvmpd_scan+0x158
> uvm_pageout(5d4841c9) at uvm_pageout+0x398
> fork_trampoline() at fork_trampoline+0x14
> end trace frame: 0x0, count: 5
> 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{1}> show panic
> *cpu1: vn_lock: v_usecount == 0
> 
> ddb{1}> trace
> db_enter() at db_enter+0x20
> panic(9434f4) at panic+0x158
> vn_lock(49535400,202000) at vn_lock+0x1c4
> uvn_io(5db64f85,a994c4,a979f4,ffffffff,e4010000) at uvn_io+0x254
> uvn_put(fec3fe2c,e7ebbdd4,23ca9af0,40e0880) at uvn_put+0x64
> uvm_pager_put(0,0,e7ebbd70,32c0c0,2000000,80000000,0) at uvm_pager_put+0x15c
> uvmpd_scan_inactive(0) at uvmpd_scan_inactive+0x224
> uvmpd_scan() at uvmpd_scan+0x158
> uvm_pageout(5d4841c9) at uvm_pageout+0x398
> fork_trampoline() at fork_trampoline+0x14
> end trace frame: 0x0, count: -10
> 
> ddb{1}> show register
> r0              0x8552f8        panic+0x15c
> r1            0xe7ebbb60
> r2                     0
> r3              0xafcc00        cpu_info+0x4c0
> r4              0xb00000        uvm_small_amap_pool+0x130
> r5                   0x1
> r6                     0
> r7            0xe7bb9000
> r8                     0
> r9              0x91ae69        digits
> r10                 0x14
> r11           0xb9c58763
> r12           0x972ab42e
> r13                    0
> r14             0xaf51b8        bcstats
> r15             0xa979d0        uvmexp
> r16                    0
> r17                    0
> r18                    0
> r19             0x202000        rtable_match+0x4c
> r20               0x1000        tlbdsmsize+0xf18
> r21               0x1000        tlbdsmsize+0xf18
> r22             0xa80294        netlock
> r23           0xe4010000
> r24           0x23ca9b08
> r25           0x23ca9b0c
> r26             0x925186        digits+0xa31d
> r27                    0
> r28                    0
> r29             0xafcec0        cpu_info+0x780
> r30             0x9434f4        cy_pio_rec+0x10c93
> r31             0xa97afc        uvmexp+0x12c
> lr              0x465b64        db_enter+0x24
> cr            0x48228204
> xer           0x20000000
> ctr             0x84331c        openpic_splx
> iar             0x465b64        db_enter+0x24
> msr               0x9032        tlbdsmsize+0x8f4a
> dar                    0
> dsisr                  0
> db_enter+0x24:  lwz r11,12(r1)
> 
> ddb{1}> ps
>    PID     TID   PPID    UID  S       FLAGS  WAIT          COMMAND
>  19000  433418  88497     21  7         0x2                c++
>  88497  403151  58565     21  3    0x10008a  sigsusp       sh
>  41513  242275   9837     21  2         0x2                c++
>   9837   71908  58565     21  3    0x10008a  sigsusp       sh
>  58565  163952  54207     21  3    0x10008a  sigsusp       make
>  54207   76575  55963     21  3    0x10008a  sigsusp       sh
>  55963  491542  28020     21  3    0x10008a  sigsusp       make
>  28020  11887215     21  3    0x10008a  sigsusp       make
>  17215  246222  89415     21  3    0x10008a  sigsusp       sh
>  89415  114664  17720     21  3    0x10008a  sigsusp       make
>  17720  164665  66695      0  3    0x10008a  sigsusp       sh
>  66695   16970  75998      0  3    0x10008a  sigsusp       make
>  75998  377562  93606      0  3    0x10008a  sigsusp       make
>  93606  189705  64097      0  3    0x10008a  sigsusp       sh
>  64097  134632  17259      0  3        0x82  piperd        perl
>  17259  145120  30986      0  3    0x10008a  sigsusp       ksh
>  30986  428793  43374      0  3        0x9a  kqread        sshd
>  62653  378789      1      0  3    0x100083  ttyin         getty
>  72583   62696      1      0  3    0x100098  kqread        cron
>   1933  419760      1     99  3   0x1100090  kqread        sndiod
>  73776  124138      1    110  3    0x100090  kqread        sndiod
>   7481  214185  45433     95  3   0x1100092  kqread        smtpd
>   6611  409063  45433    103  3   0x1100092  kqread        smtpd
>  16731  262914  45433     95  3   0x1100092  kqread        smtpd
>  40301   71250  45433     95  3    0x100092  kqread        smtpd
>  96109  124474  45433     95  3   0x1100092  kqread        smtpd
>  13936  404650  45433     95  3   0x1100092  kqread        smtpd
>  45433  263236      1      0  3    0x100080  kqread        smtpd
>    343  120441      1      0  3    0x100080  kqread        snmpd
>  87257  308298      1     91  3   0x1000092  kqread        snmpd
>  43374   12041      1      0  3        0x88  kqread        sshd
>  36767  275688      0      0  3     0x14280  nfsidl        nfsio
>  23523  322381      0      0  3     0x14280  nfsidl        nfsio
>  18830   59893      0      0  3     0x14280  nfsidl        nfsio
>  69933  327304      0      0  3     0x14280  nfsidl        nfsio
>  76335  497295      1      0  3    0x100080  kqread        ntpd
>  49727   34189  86240     83  3    0x100092  kqread        ntpd
>  86240  183312      1     83  3   0x1100092  kqread        ntpd
>  80059  107446  93928     74  3   0x1100092  bpf           pflogd
>  93928  203794      1      0  3        0x80  netio         pflogd
>   6842   97383  70269     73  3   0x1100090  kqread        syslogd
>  70269  299053      1      0  3    0x100082  netio         syslogd
>  96628  496905      1      0  3    0x100080  kqread        resolvd
>  24421  272632  88548     77  3    0x100092  kqread        dhcpleased
>    593  201390  88548     77  3    0x100092  kqread        dhcpleased
>  88548  261115      1      0  3        0x80  kqread        dhcpleased
>   6816  477914  60015    115  3    0x100092  kqread        slaacd
>  60023  386633  60015    115  3    0x100092  kqread        slaacd
>  60015   89490      1      0  3    0x100080  kqread        slaacd
>  94936   82285      0      0  3     0x14200  bored         smr
>  24751  194620      0      0  3  0x40014200                idle1
>  76151  100547      0      0  2     0x14200                zerothread
>   9389  345055      0      0  3     0x14200  aiodoned      aiodoned
>  72624  434131      0      0  3     0x14200  syncer        update
>  60402  516935      0      0  3     0x14200  cleaner       cleaner
>  31684  508907      0      0  3     0x14200  reaper        reaper
> *36343  232867      0      0  7     0x14200                pagedaemon
>  96816   67592      0      0  3     0x14200  usbtsk        usbtask
>  77492   19911      0      0  3     0x14200  usbatsk       usbatsk
>  36069   22766      0      0  3     0x14200  bored         sensors
>  36770  121581      0      0  2     0x14200                softnet
>  44639  205909      0      0  3     0x14200  bored         systqmp
>  56468  113797      0      0  3     0x14200  bored         systq
>  91597  251663      0      0  3  0x40014200  bored         softclock
>  48713  469657      0      0  3  0x40014200                idle0
>      1  516722      0      0  3        0x82  wait          init
>      0       0     -1      0  3     0x10200  scheduler     swapper
> 
> ddb{1}> x/s version
> version:        OpenBSD 7.1-current (GENERIC.MP) #0: Wed Apr 13 15:47:33 CEST 
> 2022\012    
> [email protected]:/usr/src/sys/arch/macppc/compile/GENERIC.MP\012
> 
> ddb{1}> show uvm
> Current UVM status:
>   pagesize=4096 (0x1000), pagemask=0xfff, pageshift=12
>   500889 VM pages: 174484 active, 178200 inactive, 1 wired, 39224 free (0 
> zero)
>   min  10% (25) anon, 10% (25) vnode, 5% (12) vtext
>   freemin=16696, free-target=22261, inactive-target=125065, wired-max=166963
>   faults=969270667, traps=0, intrs=1106855, ctxswitch=15212500 
> fpuswitch=3248421
>   softint=8160299, syscalls=1385935235, kmapent=8
>   fault counts:
>     noram=0, noanon=0, noamap=0, pgwait=0, pgrele=0
>     ok relocks(total)=633576(636470), anget(retries)=781401497(0), 
> amapcopy=60231123
>     neighbor anon/obj pg=68714269/141374437, gets(lock/unlock)=49238431/637452
>     cases: anon=779642530, anoncow=1758967, obj=42501171, prcopy=6733384, 
> przero=138634615
>   daemon and swap counts:
>     woke=5, revs=1, scans=22738, obscans=22518, anscans=0
>     busy=0, freed=22517, reactivate=220, deactivate=0
>     pageouts=1, pending=0, nswget=0
>     nswapdev=1
>     swpages=589823, swpginuse=0, swpgonly=0 paging=0
>   kernel pointers:
>     objs(kern)=0xb03480
> 
> ddb{1}> show vnode /f 0x23e6b910
> 0x23e6b910 tag UFS(1) type VREG(1) mount 0xe040f800 typedata 0x0
> data 0x23d51dc0 usecount 0 writecount 0 holdcnt 0 numoutput 0
> flag 0x0 lflag 0x0 bioflag 0x4
> clean bufs:
> dirty bufs:
> ==> vnode_history_print 0x23e6b910, next=5
>  [3] c++[68540] usecount 2>1
> #0  0x625703e0
>  [4] reaper[31684] usecount 1>0
> #0  splx+0x30
> #1  0xfffffffc
> #2  vrele+0x5c
> #3  uvn_detach+0x154
> #4  uvm_unmap_detach+0x1a4
> #5  uvm_map_teardown+0x184
> #6  uvmspace_free+0x60
> #7  uvm_exit+0x30
> #8  reaper+0x138
> #9  fork_trampoline+0x14
> 
> ddb{1}> show mount 0xe040f800
> flags 201818<NOSUID,NODEV,WXALLOWED,LOCAL,SWAPPABLE>
> vnodecovered 0x311750a0 syncer 0x31175250 data 0xe024fe00
> vfsconf: ops 0xa53e84 name "ffs" num 1 ref 9 flags 0x201000
> statvfs cache: bsize 800 iosize 4000
> blocks 3094879 free 3092871 avail 2938128
>   files 805502 ffiles 803496 favail 803496
>   f_fsidx {0xa, 0x4069424e} owner 0 ctime 0x6256d525
>   syncwrites 392685 asyncwrites = 188844
>   syncreads 3825549 asyncreads = 0
>   fstype "ffs" mnton "/usr/obj" mntfrom "/dev/wd0k" mntspec 
> "6102496318219727.k"
> locked vnodes:
> 
> Unfortunately the address in the trace is not correct this time.
> vn_lock(49535400,202000) at vn_lock+0x1c4
> 0x49535400 is not a vnode.
> 

Reply via email to