Attachment 194962 Details for Bug 229614 – Debugging attempts (command line output)

Debugging attempts (command line output)

zfs_lockup.txt (text/plain), 6.63 KB, created by Andreas Sommer on 2018-07-08 20:42:53 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Andreas Sommer

Created: 2018-07-08 20:42:53 UTC

Size: 6.63 KB

patch

obsolete

>$ uname -a
>FreeBSD asommer-devpm-ci 11.2-RELEASE FreeBSD 11.2-RELEASE #0 r335510: Fri Jun 22 04:32:14 UTC 2018     root@releng2.nyi.freebsd.org:/usr/obj/usr/src/sys/GENERIC  amd64
>
># ps -p 69994
>  PID TT  STAT     TIME COMMAND
>69994  -  SJ   40:08.73 /usr/local/bin/python3.6 /usr/local/bin/buildbot start --nodaemon /var/buildbot-master
>
># procstat -kk 69994
>  PID    TID COMM                TDNAME              KSTACK
>69994 100411 python3.6           -                   mi_switch+0xe6 sleepq_catch_signals+0x40c sleepq_timedwait_sig+0x14 _cv_timedwait_sig_sbt+0x18c seltdwait+0x7b kern_poll+0x3fd sys_poll+0x50 amd64_syscall+0xa38 fast_syscall_common+0x101
>69994 101219 python3.6           -                   mi_switch+0xe6 sleepq_catch_signals+0x40c sleepq_wait_sig+0xf _sleep+0x231 umtxq_sleep+0x143 do_sem2_wait+0x68a __umtx_op_sem2_wait+0x4b amd64_syscall+0xa38 fast_syscall_common+0x101
>69994 101224 python3.6           -                   mi_switch+0xe6 sleepq_wait+0x2c _sx_xlock_hard+0x306 zil_commit_impl+0x11d zfs_freebsd_putpages+0x635 VOP_PUTPAGES_APV+0x82 vnode_pager_putpages+0x8e vm_pageout_flush+0xea vm_object_page_collect_flush+0x213 vm_object_page_clean+0x146 vm_object_terminate+0x93 zfs_freebsd_reclaim+0x1e VOP_RECLAIM_APV+0x82 vgonel+0x208 vrecycle+0x4a zfs_freebsd_inactive+0xd VOP_INACTIVE_APV+0x82 vinactive+0xfc
>
># procstat -f 69994
>  PID COMM                FD T V FLAGS    REF  OFFSET PRO NAME
>69994 python3.6         text v r r-------   -       - -   /usr/jails/devpm-ci-buildbot-master/usr/local/bin/python3.6m
>69994 python3.6          cwd v d r-------   -       - -   /usr/jails/devpm-ci-buildbot-master/var/buildbot-master
>69994 python3.6         root v d r-------   -       - -   /usr/jails/devpm-ci-buildbot-master
>69994 python3.6         jail v d r-------   -       - -   /usr/jails/devpm-ci-buildbot-master
>69994 python3.6            0 v c r-------   3       0 -   /usr/jails/devpm-ci-buildbot-master/dev/null
>69994 python3.6            1 p - rw------   4       0 -   -
>69994 python3.6            2 p - rw------   4       0 -   -
>69994 python3.6            3 v c r-------   1   17504 -   /usr/jails/devpm-ci-buildbot-master/dev/random
>69994 python3.6            4 p - rw---n--   1       0 -   -
>69994 python3.6            5 p - rw---n--   1       0 -   -
>69994 python3.6            6 v r rw------   1 1412352 -   /usr/jails/devpm-ci-buildbot-master/var/buildbot-master/twistd.log
>69994 python3.6            7 p - rw---n--   1       0 -   -
>69994 python3.6            8 p - rw---n--   1       0 -   -
>69994 python3.6            9 s - rw---n--   1       0 TCP 10.90.0.123:8010 0.0.0.0:0
>69994 python3.6           10 v r rw------   1 8011278 -   /usr/jails/devpm-ci-buildbot-master/var/buildbot-master/http.log
>69994 python3.6           11 s - rw---n--   1       0 TCP 10.90.0.123:9989 0.0.0.0:0
>69994 python3.6           12 s - rw---n--   1       0 TCP 10.90.0.123:9989 10.90.0.140:18287
>69994 python3.6           13 v r rw------   1 31363072 -   /usr/jails/devpm-ci-buildbot-master/var/buildbot-master/state.sqlite
>69994 python3.6           14 v r rw------   1       0 -   /usr/jails/devpm-ci-buildbot-master/var/buildbot-master/state.sqlite-wal
>69994 python3.6           15 s - rw---n--   1       0 TCP 10.90.0.123:8010 10.90.0.123:12500
>69994 python3.6           16 p - rw---n--   1       0 -   -
>69994 python3.6           18 p - rw---n--   1       0 -   -
>69994 python3.6           20 p - rw---n--   1       0 -   -
>
># procstat -r 69994
>  PID COMM             RESOURCE                          VALUE
>69994 python3.6        user time                    00:22:47.525292
>69994 python3.6        system time                  00:17:24.714624
>69994 python3.6        maximum RSS                           121192 KB
>69994 python3.6        integral shared memory               1012116 KB
>69994 python3.6        integral unshared data               1012108 KB
>69994 python3.6        integral unshared stack             64764800 KB
>69994 python3.6        page reclaims                      210434399
>69994 python3.6        page faults                            88776
>69994 python3.6        swaps                                      0
>69994 python3.6        block reads                            24881
>69994 python3.6        block writes                         1062660
>69994 python3.6        messages sent                           6331
>69994 python3.6        messages received                       6338
>69994 python3.6        signals received                      150375
>69994 python3.6        voluntary context switches           6946443
>69994 python3.6        involuntary context switches           45063
>
># top
>last pid: 33208;  load averages:  1.49,  1.29,  1.25                                                                                                                                  up 6+11:43:30  20:19:48
>99 processes:  2 running, 94 sleeping, 3 zombie
>CPU:  0.0% user,  0.0% nice, 24.9% system,  0.0% interrupt, 75.1% idle
>Mem: 27M Active, 1392M Inact, 10G Wired, 3845M Free
>ARC: 5752M Total, 3804M MFU, 559M MRU, 3589K Anon, 99M Header, 1286M Other
>     3509M Compressed, 5372M Uncompressed, 1.53:1 Ratio
>Swap: 2048M Total, 2048M Free
>
>  PID USERNAME       THR PRI NICE   SIZE    RES STATE   C   TIME    WCPU COMMAND
>69994 asommer          3  20    0   127M   118M select  1  40:12   0.38% python3.6
>33208 root             1  20    0  7916K  3476K CPU0    0   0:00   0.05% top
>  715 root             1  20    0  6336K  1984K nanslp  0   0:18   0.01% svscan
>33121 asommer          1  20    0 13160K  8160K select  1   0:00   0.00% sshd
>12709 asommer          1  20    0 13176K  4048K select  0   0:04   0.00% gpg-agent
>  718 root             1  20    0 10452K  6112K select  1   0:06   0.00% sendmail
>  716 root             1  20    0  4232K  1928K piperd  1   0:05   0.00% readproctitle
>99312 asommer          1  26    0     0K    16K CPU3    3  67.3H   0.00% python3.6
>32379 root             1  20    0  4232K  1928K zilog-  2   1:39   0.00% sync # <- two manual sync calls I started, one in a jail
>  918 asommer          1  20    0 40008K 36544K select  2   0:23   0.00% python3.6
>32388 root             1  20    0  4232K  1960K zilog-  1   0:22   0.00% sync # <- two manual sync calls I started, one in a jail
>  729 www              1  20    0 13228K  8864K kqread  0   0:16   0.00% nginx
>  898 root             1  20    0  6336K  2016K nanslp  1   0:14   0.00% svscan
> 1079 root             1  20    0  6336K  2016K nanslp  0   0:14   0.00% svscan
>  919 root             1  20    0 10444K  6264K select  2   0:05   0.00% sendmail
>[...snip...]
>
>[root@devpm-ci-buildbot-master /]# sqlite3 /var/buildbot-master/state.sqlite
>SQLite version 3.22.0 2018-01-22 18:45:57
>Enter ".help" for usage hints.
>sqlite> .tables
>Error: database is locked

Actions: View

Attachments on bug 229614: 194962