Project

General

Profile

Actions

Bug #8653

closed

Use after free in UDP socket close.

Added by Andy Fiddaman over 4 years ago. Updated about 4 years ago.

Status:
Closed
Priority:
Normal
Assignee:
Category:
networking
Start date:
2017-09-12
Due date:
% Done:

100%

Estimated time:
Difficulty:
Medium
Tags:
needs-triage
Gerrit CR:

Description

I have a couple of servers that run as outbound DNS resolvers for my network and run unbound (https://www.unbound.net/) in a native zone under OmniOS r151022.
Unbound is linked against `libev` and that is configured to use event ports.

The servers are crashing at least a week (sometimes once a day) and the stack trace always looks the same:

@> $c
mutex_enter+0xb()
udp_do_close+0x57(ffffff32cf4f1600)
udp_close+0x28(ffffff32cf4f1600, 83, ffffff076c8bc2a0)
so_close+0x8c(ffffff0cb24c62f8, 83, ffffff076c8bc2a0)
socket_close_internal+0x58(ffffff0cb24c62f8, 83, ffffff076c8bc2a0)
socket_vop_close+0x128(ffffff19b3128000, 83, 1, 0, ffffff076c8bc2a0, 0)
fop_close+0x61(ffffff19b3128000, 83, 1, 0, ffffff076c8bc2a0, 0)
closef+0x97(ffffff07916b2068)
closeandsetf+0x3e6(25, 0)
close+0x13(25)
sys_syscall+0x296()

ffffff32cf4f1600::whatis

ffffff32cf4f1600 is ffffff32cf450000+a1600, freed from the heap vmem arena:
ADDR TYPE START END SIZE
THREAD TIMESTAMP
ffffff16368fdcb0 FREE ffffff32cf450000 ffffff32cf4f5000 675840@

I'm running a debug kernel so tracing the kmem allocations I can see the initial socket being created:

ADDR BUFADDR TIMESTAMP THREAD
CACHE LASTLOG CONTENTS
ffffff06ea6c19c0 ffffff0cb24c62f8 63a0b17e1604a ffffff073e7c43e0
ffffff07202f2448 ffffff06ea65ea80 ffffff06fa89f800
kmem_cache_alloc_debug+0x2e0
kmem_cache_alloc+0xdd
socket_sonode_create+0x72
socket_create+0xd1
so_socket+0x228

and then the same thread creates and destroys the UDP conn_t

ffffff06ea6c1a80 ffffff32cf4f1600 63a0b17e1b908 ffffff073e7c43e0
ffffff071bd08448 0 0
kmem_slab_alloc_impl+0x2f4
kmem_slab_alloc+0x65
kmem_cache_alloc+0x283
ipcl_conn_create+0x53
udp_do_open+0xe2
udp_create+0x6f
socket_init_common+0x1c0
so_init+0x25
socket_create+0xeb
so_socket+0x228
ffffff06ea6d0000 ffffff32cf4f1600 63a0b44b5adc1 ffffff073e7c43e0
ffffff071bd08448 ffffff06ea6c1a80 ffffff06fa8c5430
kmem_slab_free+0x3a9
kmem_slab_free_constructed+0x8a
kmem_cache_free+0xe0
ipcl_conn_destroy+0x4d6
ipcl_hash_remove+0x104
ip_quiesce_conn+0xd7
udp_do_close+0x57
udp_close+0x28
so_close+0x8c
socket_close_internal+0x58
socket_vop_close+0x128
fop_close+0x61
closef+0x97
closeandsetf+0x3e6
close+0x13

And then the crash occurs - same thread, just a little later on.

@panic[cpu7]/thread=ffffff073e7c43e0:
ffffff0021398c10 mutex_enter+0xb()
ffffff0021398c40 udp_do_close+0x57(ffffff32cf4f1600)
ffffff0021398c80 udp_close+0x28(ffffff32cf4f1600, 83, ffffff076c8bc2a0)
ffffff0021398ce0 so_close+0x8c(ffffff0cb24c62f8, 83, ffffff076c8bc2a0)
ffffff0021398d30 socket_close_internal+0x58(ffffff0cb24c62f8, 83,
ffffff076c8bc2a0)
ffffff0021398da0 socket_vop_close+0x128(ffffff19b3128000, 83, 1, 0,
ffffff076c8bc2a0, 0)
ffffff0021398e20 fop_close+0x61(ffffff19b3128000, 83, 1, 0, ffffff076c8bc2a0, 0
)
ffffff0021398e60 closef+0x97(ffffff07916b2068)
ffffff0021398ed0 closeandsetf+0x3e6(25, 0)
ffffff0021398ef0 close+0x13(25)
ffffff0021398f00 sys_syscall+0x296()

CPU ADDRESS TIMESTAMP TYPE VC HANDLER PC
7 ffffff07224d5028 e7e29312bc4e trap e #pf mutex_enter+b@

So far, the socket has always been an IPv6 one

> ffffff0cb24c62f8::print -t struct sonode so_family
short so_family = 0x1a

I'm running some dtrace scripts to try and get more information when this next occurs and will post here with anything new.

Actions

Also available in: Atom PDF