11.0-RELEASE and mbuf-related trace

[Slawa Olhovchenkov]

Has anybody comment on this?
During debug tcp-related freeze I am collect starnge mbuf-related
freeze (this is like recursive lock to UMA Slabs keg) and trace:

last pid: 49575; load averages: 2.00, 2.05, 3.75 up 1+01:12:08 22:13:42
853 processes: 15 running, 769 sleeping, 35 waiting, 34 lock
CPU 0: 0.0% user, 0.0% nice, 0.0% system, 100% interrupt, 0.0% idle
CPU 1: 0.0% user, 0.0% nice, 0.0% system, 0.0% interrupt, 100% idle
CPU 2: 0.0% user, 0.0% nice, 0.0% system, 0.0% interrupt, 100% idle
CPU 3: 0.0% user, 0.0% nice, 0.0% system, 0.0% interrupt, 100% idle
CPU 4: 0.0% user, 0.0% nice, 0.0% system, 0.0% interrupt, 100% idle
CPU 5: 0.0% user, 0.0% nice, 0.0% system, 0.0% interrupt, 100% idle
CPU 6: 0.0% user, 0.0% nice, 0.4% system, 0.0% interrupt, 99.6% idle
CPU 7: 0.0% user, 0.0% nice, 0.0% system, 0.0% interrupt, 100% idle
CPU 8: 0.0% user, 0.0% nice, 0.0% system, 0.0% interrupt, 100% idle
CPU 9: 0.0% user, 0.0% nice, 0.0% system, 0.0% interrupt, 100% idle
CPU 10: 0.0% user, 0.0% nice, 0.4% system, 0.0% interrupt, 99.6% idle
CPU 11: 0.0% user, 0.0% nice, 0.0% system, 0.0% interrupt, 100% idle
Mem: 8659M Active, 8385M Inact, 107G Wired, 1325M Free
ARC: 99G Total, 88G MFU, 10G MRU, 32K Anon, 167M Header, 529M Other
Swap: 32G Total, 32G Free

# procstat -k -k 1046
PID TID COMM TDNAME KSTACK
1046 100686 nginx - mi_switch+0xd2 critical_exit+0x7e lapic_handle_timer+0xb1 Xtimerint+0x8c __mtx_lock_sleep+0x168 zone_fetch_slab+0x47 zone_import+0x52 zone_alloc_item+0x36 keg_alloc_slab+0x63 keg_fetch_slab+0x16e zone_fetch_slab+0x6e zone_import+0x52 uma_zalloc_arg+0x36e m_getm2+0x14f m_uiotombuf+0x64 sosend_generic+0x356 soo_write+0x42 dofilewrite+0x87

Some info below posible incorectly decoded.

(kgdb) thread 809
[Switching to thread 809 (Thread 100686)]
(kgdb) bt
#0 sched_switch (td=0xfffff8014485f500, newtd=0xfffff8011422b000, flags=<optimized out>) at /usr/src/sys/kern/sched_ule.c:1973
#1 0xffffffff804a8d92 in mi_switch (flags=<optimized out>, newtd=0x0) at /usr/src/sys/kern/kern_synch.c:455
#2 0xffffffff804a6bee in critical_exit () at /usr/src/sys/kern/kern_switch.c:218
#3 0xffffffff80771701 in lapic_handle_timer (frame=0xfffffe2021699340) at /usr/src/sys/x86/x86/local_apic.c:1184
#4 <signal handler called>
#5 0xffffffff804de424 in lock_delay (la=<optimized out>) at /usr/src/sys/kern/subr_lock.c:127
#6 0xffffffff80484dc8 in __mtx_lock_sleep (c=<optimized out>, tid=18446735283061126400, opts=<optimized out>, file=<optimized out>, line=<optimized out>) at /usr/src/sys/kern/kern_mutex.c:514
#7 0xffffffff806a4257 in zone_fetch_slab (zone=0xfffff8207ffe6000, keg=0xfffff8207ffe7180, flags=1) at /usr/src/sys/vm/uma_core.c:2371
#8 0xffffffff806a4312 in zone_import (zone=<optimized out>, bucket=<optimized out>, max=<optimized out>, flags=<optimized out>) at /usr/src/sys/vm/uma_core.c:2501
#9 0xffffffff806a0986 in zone_alloc_item (zone=0xfffff8207ffe6000, udata=0x0, flags=1) at /usr/src/sys/vm/uma_core.c:2591
#10 0xffffffff806a2463 in keg_alloc_slab (keg=0xfffff8010f9ecd80, zone=0xfffff80114236000, wait=1) at /usr/src/sys/vm/uma_core.c:964
#11 0xffffffff806a48ce in keg_fetch_slab (keg=<optimized out>, zone=<optimized out>, flags=<optimized out>) at /usr/src/sys/vm/uma_core.c:2343
#12 0xffffffff806a427e in zone_fetch_slab (zone=<optimized out>, keg=<optimized out>, flags=<optimized out>) at /usr/src/sys/vm/uma_core.c:2375
#13 0xffffffff806a4312 in zone_import (zone=<optimized out>, bucket=<optimized out>, max=<optimized out>, flags=<optimized out>) at /usr/src/sys/vm/uma_core.c:2501
#14 0xffffffff806a147e in zone_alloc_bucket (flags=2, zone=<optimized out>, udata=<optimized out>) at /usr/src/sys/vm/uma_core.c:2531
#15 uma_zalloc_arg (zone=<optimized out>, udata=0xfffff8105a700300, flags=2) at /usr/src/sys/vm/uma_core.c:2257
#16 0xffffffff8048231f in m_getjcl (how=2, type=1, flags=<optimized out>, size=4096) at /usr/src/sys/kern/kern_mbuf.c:829
#17 m_getm2 (m=<optimized out>, len=<optimized out>, how=<optimized out>, type=<optimized out>, flags=<optimized out>) at /usr/src/sys/kern/kern_mbuf.c:861
#18 0xffffffff80516044 in m_uiotombuf (uio=0xfffff818dcfbaec0, how=60, len=<optimized out>, align=0, flags=0) at /usr/src/sys/kern/uipc_mbuf.c:1535
#19 0xffffffff8051ce56 in sosend_generic (so=<optimized out>, addr=0x0, uio=<optimized out>, top=<optimized out>, control=<optimized out>, flags=<optimized out>, td=<optimized out>) at /usr/src/sys/kern/uipc_socket.c:1332
#20 0xffffffff804fd872 in soo_write (fp=<optimized out>, uio=0xfffff818dcfbaec0, active_cred=<optimized out>, flags=<optimized out>, td=<optimized out>) at /usr/src/sys/kern/sys_socket.c:146
#21 0xffffffff804f5c97 in fo_write (fp=<optimized out>, uio=0xfffff818dcfbaec0, active_cred=0xc0, flags=0, td=<optimized out>) at /usr/src/sys/sys/file.h:311
#22 dofilewrite (td=0xfffff8014485f500, fd=1531, fp=0xfffff80ac09fa960, auio=0xfffff818dcfbaec0, offset=<optimized out>, flags=0) at /usr/src/sys/kern/sys_generic.c:590
#23 0xffffffff804f5978 in kern_writev (td=0xfffff8014485f500, fd=1531, auio=0xfffff818dcfbaec0) at /usr/src/sys/kern/sys_generic.c:506
#24 0xffffffff804f5be6 in sys_writev (td=0xfffff8014485f500, uap=0xfffffe2021699a40) at /usr/src/sys/kern/sys_generic.c:491
#25 0xffffffff806e4051 in syscallenter (td=0xfffff8014485f500, sa=<optimized out>) at /usr/src/sys/amd64/amd64/../../kern/subr_syscall.c:135
#26 amd64_syscall (td=0xfffff8014485f500, traced=0) at /usr/src/sys/amd64/amd64/trap.c:942

# vmstat -M /var/crash/vmcore.1 -z| grep -i mbuf
mbuf_packet: 256, 52276395, 26987, 189713,705271653, 0, 0
mbuf: 256, 52276395, 61994, 782439,46250344524, 0, 0
mbuf_cluster: 2048, 1048576, 49207, 34461, 293307, 0, 0
mbuf_jumbo_page: 4096, 4084093, 61839, 613537,8265099417, 0, 0
mbuf_jumbo_9k: 9216, 3630303, 0, 0, 0, 0, 0
mbuf_jumbo_16k: 16384, 2722728, 0, 0, 0, 0, 0

(kgdb) frame 14
#14 0xffffffff806a147e in zone_alloc_bucket (flags=2, zone=<optimized out>, udata=<optimized out>) at /usr/src/sys/vm/uma_core.c:2531
2531 bucket->ub_cnt = zone->uz_import(zone->uz_arg, bucket->ub_bucket,
(kgdb) x/40i 0xffffffff806a1450
0xffffffff806a1450 <uma_zalloc_arg+832>: mov 0x10(%rbx),%eax
0xffffffff806a1453 <uma_zalloc_arg+835>: mov %ax,0x12(%r15)
0xffffffff806a1458 <uma_zalloc_arg+840>: cwtl
0xffffffff806a1459 <uma_zalloc_arg+841>: movzwl 0x1a0(%r12),%edx
0xffffffff806a1462 <uma_zalloc_arg+850>: cmp %edx,%eax
0xffffffff806a1464 <uma_zalloc_arg+852>: cmovle %eax,%edx
0xffffffff806a1467 <uma_zalloc_arg+855>: mov 0x100(%r12),%rdi
0xffffffff806a146f <uma_zalloc_arg+863>: lea 0x18(%r15),%rsi
0xffffffff806a1473 <uma_zalloc_arg+867>: mov -0x3c(%rbp),%ecx
0xffffffff806a1476 <uma_zalloc_arg+870>: callq *0xf0(%r12)
=> 0xffffffff806a147e <uma_zalloc_arg+878>: mov %ax,0x10(%r15)
0xffffffff806a1483 <uma_zalloc_arg+883>: test %ax,%ax

(kgdb) info registers
rax 0x3c 60
rbx 0xffffffff80ab54f0 -2136255248
rcx 0xa 10
rdx 0xc0 192
rsi 0x12c 300
rdi 0xfffffe2021699468 -2061023734680
rbp 0xfffffe2021699720 0xfffffe2021699720
rsp 0xfffffe20216996c0 0xfffffe20216996c0
r8 0x0 0
r9 0xfffff8076fb8e648 -8764153862584
r10 0xfffff8207ffe7198 -8656506687080
r11 0xfffffe2021699b80 -2061023732864
r12 0xfffff80114236000 -8791460192256
r13 0x1 1
r14 0xfffff80114236200 -8791460191744
r15 0xfffff80c877ca000 -8742280323072
rip 0xffffffff806a147e 0xffffffff806a147e <uma_zalloc_arg+878>
eflags 0x207 [ CF PF IF ]
cs 0x20 32
ss 0x28 40
ds <unavailable>
es <unavailable>
fs <unavailable>
gs <unavailable>

(kgdb) p *(uma_zone_t) 0xfffff80114236000
$2 = {uz_lock = {lock_object = {lo_name = 0xffffffff807d99ad "mbuf_jumbo_page", lo_flags = 21168128, lo_data = 0, lo_witness = 0x0}, mtx_lock = 4}, uz_lockptr = 0xfffff8010f9ecd80, uz_name = 0xffffffff807d99ad "mbuf_jumbo_page", uz_link = {le_next = 0x0, le_prev = 0xfffff8010f9ece10}, uz_buckets = {
lh_first = 0xfffff818f919f000}, uz_kegs = {lh_first = 0xfffff801142360b0}, uz_klink = {kl_link = {le_next = 0x0, le_prev = 0xfffff801142360a8}, kl_keg = 0xfffff8010f9ecd80}, uz_slab = 0xffffffff806a4210 <zone_fetch_slab>, uz_ctor = 0xffffffff80482fb0 <mb_ctor_clust>, uz_dtor = 0x0, uz_init = 0x0, uz_fini = 0x0,
uz_import = 0xffffffff806a42c0 <zone_import>, uz_release = 0xffffffff806a4470 <zone_release>, uz_arg = 0xfffff80114236000, uz_flags = 264, uz_size = 4096, uz_allocs = 8265099417, uz_fails = 0, uz_frees = 8265036555, uz_sleeps = 0, uz_count = 253, uz_count_min = 1,
uz_warning = 0xffffffff807d99bd "kern.ipc.nmbjumbop limit reached", uz_ratecheck = {tv_sec = 0, tv_usec = 0}, uz_maxaction = {ta_link = {stqe_next = 0x0}, ta_pending = 0, ta_priority = 0, ta_func = 0xffffffff80482f50 <mb_reclaim>, ta_context = 0xfffff80114236000}, uz_cpu = {{uc_freebucket = 0xfffff81589c23000,
uc_allocbucket = 0x0, uc_allocs = 0, uc_frees = 0}}}

(kgdb) p *(uma_zone_t) 0xfffff8207ffe6000
$4 = {uz_lock = {lock_object = {lo_name = 0xffffffff80807ceb "UMA Slabs", lo_flags = 21168128, lo_data = 0, lo_witness = 0x0}, mtx_lock = 4}, uz_lockptr = 0xfffff8207ffe7180, uz_name = 0xffffffff80807ceb "UMA Slabs", uz_link = {le_next = 0x0, le_prev = 0xfffff8207ffe7210}, uz_buckets = {lh_first = 0x0}, uz_kegs = {
lh_first = 0xfffff8207ffe60b0}, uz_klink = {kl_link = {le_next = 0x0, le_prev = 0xfffff8207ffe60a8}, kl_keg = 0xfffff8207ffe7180}, uz_slab = 0xffffffff806a4210 <zone_fetch_slab>, uz_ctor = 0x0, uz_dtor = 0x0, uz_init = 0x0, uz_fini = 0x0, uz_import = 0xffffffff806a42c0 <zone_import>,
uz_release = 0xffffffff806a4470 <zone_release>, uz_arg = 0xfffff8207ffe6000, uz_flags = 536870912, uz_size = 80, uz_allocs = 2782941, uz_fails = 0, uz_frees = 1697864, uz_sleeps = 0, uz_count = 0, uz_count_min = 0, uz_warning = 0x0, uz_ratecheck = {tv_sec = 0, tv_usec = 0}, uz_maxaction = {ta_link = {
stqe_next = 0x0}, ta_pending = 0, ta_priority = 0, ta_func = 0x0, ta_context = 0x0}, uz_cpu = {{uc_freebucket = 0x0, uc_allocbucket = 0x0, uc_allocs = 0, uc_frees = 0}}}

(kgdb) p *(uma_keg_t) 0xfffff8207ffe7180
$6 = {uk_lock = {lock_object = {lo_name = 0xffffffff80807ceb "UMA Slabs", lo_flags = 21168128, lo_data = 0, lo_witness = 0x0}, mtx_lock = 4}, uk_hash = {uh_slab_hash = 0x0, uh_hashsize = 0, uh_hashmask = 0}, uk_zones = {lh_first = 0xfffff8207ffe6000}, uk_part_slab = {lh_first = 0xfffff812aabe9fb0}, uk_free_slab = {
lh_first = 0x0}, uk_full_slab = {lh_first = 0xfffff80a53dd7fb0}, uk_align = 7, uk_pages = 22943, uk_free = 62073, uk_reserve = 0, uk_size = 80, uk_rsize = 80, uk_maxpages = 0, uk_init = 0x0, uk_fini = 0x0, uk_allocf = 0xffffffff806e4700 <uma_small_alloc>, uk_freef = 0xffffffff806e47c0 <uma_small_free>,
uk_offset = 0, uk_kva = 0, uk_slabzone = 0x0, uk_slabsize = 4096, uk_pgoff = 4016, uk_ppera = 1, uk_ipers = 50, uk_flags = 536870912, uk_name = 0xffffffff80807ceb "UMA Slabs", uk_link = {le_next = 0xfffff8207ffe7000, le_prev = 0xfffff8207ffe7420}}

vmstat -M /var/crash/vmcore.1 -N ./kernel -z | grep -i uma
ITEM SIZE LIMIT USED FREE REQ FAIL SLEEP

UMA Kegs: 384, 0, 234, 6, 234, 0, 0
UMA Zones: 2176, 0, 251, 0, 251, 0, 0
UMA Slabs: 80, 0, 1085077, 62073, 2782941, 0, 0
UMA Hash: 256, 0, 66, 39, 105, 0, 0

frame #7:
#7 0xffffffff806a4257 in zone_fetch_slab (zone=0xfffff8207ffe6000, keg=0xfffff8207ffe7180, flags=1) at /usr/src/sys/vm/uma_core.c:2371

2364 static uma_slab_t
2365 zone_fetch_slab(uma_zone_t zone, uma_keg_t keg, int flags)
2366 {
2367 uma_slab_t slab;
2368
2369 if (keg == NULL) {
2370 keg = zone_first_keg(zone);
2371 KEG_LOCK(keg);
2372 }
2373
2374 for (;;) {
2375 slab = keg_fetch_slab(keg, zone, flags);
2376 if (slab)
2377 return (slab);
2378 if (flags & (M_NOWAIT | M_NOVM))
2379 break;
2380 }
2381 KEG_UNLOCK(keg);
2382 return (NULL);
2383 }

zone_fetch_slab REALY call with keg==NULL and assign keg at line 2370.

#8 0xffffffff806a4312 in zone_import (zone=<optimized out>, bucket=<optimized out>, max=<optimized out>, flags=<optimized out>) at /usr/src/sys/vm/uma_core.c:2501
2490 static int
2491 zone_import(uma_zone_t zone, void **bucket, int max, int flags)
2492 {
2493 uma_slab_t slab;
2494 uma_keg_t keg;
2495 int i;
2496
2497 slab = NULL;
2498 keg = NULL;
2499 /* Try to keep the buckets totally full */
2500 for (i = 0; i < max; ) {
2501 if ((slab = zone->uz_slab(zone, keg, flags)) == NULL)
2502 break;
2503 keg = slab->us_keg;
2504 while (slab->us_freecount && i < max) {
2505 bucket[i++] = slab_alloc_item(keg, slab);
2506 if (keg->uk_free <= keg->uk_reserve)
2507 break;
2508 }
2509 /* Don't grab more than one slab at a time. */
2510 flags &= ~M_WAITOK;
2511 flags |= M_NOWAIT;
2512 }
2513 if (slab != NULL)
2514 KEG_UNLOCK(keg);
2515
2516 return i;
2517 }

(kgdb) frame 8
#8 0xffffffff806a4312 in zone_import (zone=<optimized out>, bucket=<optimized out>, max=<optimized out>, flags=<optimized out>) at /usr/src/sys/vm/uma_core.c:2501
2501 if ((slab = zone->uz_slab(zone, keg, flags)) == NULL)
(kgdb) p i
$7 = 0

#9 0xffffffff806a0986 in zone_alloc_item (zone=0xfffff8207ffe6000, udata=0x0, flags=1) at /usr/src/sys/vm/uma_core.c:2591
2591 if (zone->uz_import(zone->uz_arg, &item, 1, flags) != 1)
2581 static void *
2582 zone_alloc_item(uma_zone_t zone, void *udata, int flags)
2583 {
2584 void *item;
2585
2586 item = NULL;
2587
2588 #ifdef UMA_DEBUG_ALLOC
2589 printf("INTERNAL: Allocating one item from %s(%p)\n", zone->uz_name, zone);
2590 #endif
2591 if (zone->uz_import(zone->uz_arg, &item, 1, flags) != 1)

#10 0xffffffff806a2463 in keg_alloc_slab (keg=0xfffff8010f9ecd80, zone=0xfffff80114236000, wait=1) at /usr/src/sys/vm/uma_core.c:964
964 slab = zone_alloc_item(keg->uk_slabzone, NULL, wait);
944 static uma_slab_t
945 keg_alloc_slab(uma_keg_t keg, uma_zone_t zone, int wait)
946 {
947 uma_alloc allocf;
948 uma_slab_t slab;
949 uint8_t *mem;
950 uint8_t flags;
951 int i;
952
953 mtx_assert(&keg->uk_lock, MA_OWNED);
954 slab = NULL;
955 mem = NULL;
956
957 #ifdef UMA_DEBUG
958 printf("alloc_slab: Allocating a new slab for %s\n", keg->uk_name);
959 #endif
960 allocf = keg->uk_allocf;
961 KEG_UNLOCK(keg);
962
963 if (keg->uk_flags & UMA_ZONE_OFFPAGE) {
964 slab = zone_alloc_item(keg->uk_slabzone, NULL, wait);
965 if (slab == NULL)
966 goto out;
967 }

(kgdb) p *keg
$8 = {uk_lock = {lock_object = {lo_name = 0xffffffff807d99ad "mbuf_jumbo_page", lo_flags = 21168128, lo_data = 0, lo_witness = 0x0}, mtx_lock = 4}, uk_hash = {uh_slab_hash = 0xfffffe19df420000, uh_hashsize = 1048576, uh_hashmask = 1048575}, uk_zones = {lh_first = 0xfffff80114236000}, uk_part_slab = {
lh_first = 0x0}, uk_free_slab = {lh_first = 0x0}, uk_full_slab = {lh_first = 0xfffff80065c7f000}, uk_align = 7, uk_pages = 675502, uk_free = 0, uk_reserve = 0, uk_size = 4096, uk_rsize = 4096, uk_maxpages = 4084093, uk_init = 0x0, uk_fini = 0x0, uk_allocf = 0xffffffff806e4700 <uma_small_alloc>,
uk_freef = 0xffffffff806e47c0 <uma_small_free>, uk_offset = 0, uk_kva = 0, uk_slabzone = 0xfffff8207ffe6000, uk_slabsize = 4096, uk_pgoff = 0, uk_ppera = 1, uk_ipers = 1, uk_flags = 264, uk_name = 0xffffffff807d99ad "mbuf_jumbo_page", uk_link = {le_next = 0xfffff8010f9ecc00, le_prev = 0xfffff80114238120}}

_______________________________________________
freebsd...@freebsd.org mailing list
https://lists.freebsd.org/mailman/listinfo/freebsd-stable
To unsubscribe, send any mail to "freebsd-stabl...@freebsd.org"