On Mon, 29 Feb 2016, Christos Zoulas wrote:
| Hello,
|
| the problem occurs only on one of my servers. I tried to find the
| difference. It is the bind9 (bind-9.10.3pl3). If I stop the bind9, tcpdump
| works without problems. When I restart the bind9, the CPU load goes back
| to 100%.
|
| Is it a problem of the kernel, tcpdump or bind9?
Can you ktrace the bind? Perhaps it is waking up tcpdump spuriously.
That would indicate a kernel problem.
ktrace tcpdump starting at timestamp 1456773618
1847 1 tcpdump 1456773617.999999648 CALL read(3,0x7f7ff7b16000,0x80000)
1847 1 tcpdump 1456773618.000001813 RET read -1 errno 35 Resource
temporarily unavailable
1847 1 tcpdump 1456773618.000003699 CALL read(3,0x7f7ff7b16000,0x80000)
1847 1 tcpdump 1456773618.000006213 RET read -1 errno 35 Resource
temporarily unavailable
1847 1 tcpdump 1456773618.000008029 CALL read(3,0x7f7ff7b16000,0x80000)
1847 1 tcpdump 1456773618.000010333 RET read -1 errno 35 Resource
temporarily unavailable
1847 1 tcpdump 1456773618.000012289 CALL read(3,0x7f7ff7b16000,0x80000)
1847 1 tcpdump 1456773618.000015641 RET read -1 errno 35 Resource
temporarily unavailable
1847 1 tcpdump 1456773618.000017667 CALL read(3,0x7f7ff7b16000,0x80000)
1847 1 tcpdump 1456773618.000020111 RET read -1 errno 35 Resource
temporarily unavailable
1847 1 tcpdump 1456773618.000022206 CALL read(3,0x7f7ff7b16000,0x80000)
1847 1 tcpdump 1456773618.000024860 RET read -1 errno 35 Resource
temporarily unavailable
1847 1 tcpdump 1456773618.000026746 CALL read(3,0x7f7ff7b16000,0x80000)
1847 1 tcpdump 1456773618.000028981 RET read -1 errno 35 Resource
temporarily unavailable
...
ktrace named starting at timestamp 1456773618
2362 9 named 1456773617.648034355 CALL
setsockopt(0x262,0xffff,0x800,0x7f7ff09f8484,4)
2362 6 named 1456773618.151726698 RET setsockopt 0
2362 6 named 1456773618.151732844 CALL
setsockopt(0x260,0xffff,0x2000,0x7f7ff15fb484,4)
2362 3 named 1456773618.151748627 RET setsockopt 0
2362 6 named 1456773618.151749815 RET setsockopt 0
2362 3 named 1456773618.151760291 CALL
getsockopt(0x261,0xffff,0x1002,0x7f7ff21fe43c,0x7f7ff21fe438)
2362 6 named 1456773618.151763224 CALL
getsockopt(0x260,0xffff,0x1002,0x7f7ff15fb48c,0x7f7ff15fb488)
2362 9 named 1456773618.151783617 RET setsockopt 0
2362 3 named 1456773618.151790601 RET getsockopt 0
2362 6 named 1456773618.151792696 RET getsockopt 0
2362 5 named 1456773618.151793395 RET __socket30 14/0xe
2362 3 named 1456773618.151807642 CALL
bind(0x261,0x7f7ff21fe630,0x10)
2362 5 named 1456773618.151812601 CALL fcntl(0xe,0,0x200)
2362 9 named 1456773618.151791509 CALL
setsockopt(0x262,0xffff,0x2000,0x7f7ff09f8484,4)
2362 3 named 1456773618.151817071 MISC mbsoname: [0.0.0.0]
2362 6 named 1456773618.151803941 CALL
bind(0x260,0x7f7ff15fb680,0x10)
2362 6 named 1456773618.151832016 MISC mbsoname: [0.0.0.0]
2362 3 named 1456773618.151861768 RET bind 0
2362 5 named 1456773618.151883279 RET fcntl 611/0x263
2362 3 named 1456773618.151884815 CALL
recvmsg(0x261,0x7f7ff21fe320,0)
2362 5 named 1456773618.151889844 CALL close(0xe)
2362 3 named 1456773618.151893545 MISC msghdr: [name=0x7f7fef511088,
namelen=128, iov=0x7f7ff21fe350, iovlen=1, control=0x7f7ff39a6fa0,
controllen=96, flags=4000000]
2362 5 named 1456773618.151908980 RET close 0
2362 5 named 1456773618.151913729 CALL fcntl(0x263,3,0)
2362 5 named 1456773618.151916732 RET fcntl 2
2362 5 named 1456773618.151920992 CALL fcntl(0x263,4,6)
2362 9 named 1456773618.151922808 RET setsockopt 0
2362 9 named 1456773618.151943900 CALL
getsockopt(0x262,0xffff,0x1002,0x7f7ff09f848c,0x7f7ff09f8488)
2362 9 named 1456773618.151980705 RET getsockopt 0
2362 9 named 1456773618.151992299 CALL
bind(0x262,0x7f7ff09f8680,0x10)
2362 9 named 1456773618.152000051 MISC mbsoname: [0.0.0.0]
2362 11 named 1456773618.152002845 RET close 0
2362 11 named 1456773618.152016184 CALL read(5,0x7f7ff01f6f10,8)
2362 9 named 1456773618.152018768 RET bind 0
2362 6 named 1456773618.152018140 RET bind 0
2362 3 named 1456773618.152029244 RET recvmsg -1 errno 35 Resource
temporarily unavailable
2362 11 named 1456773618.152035390 GIO fd 5 read 8 bytes
",\^B\0\0\M-{\M^?\M^?\M^?"
2362 11 named 1456773618.152041396 RET read 8
2362 6 named 1456773618.152040698 CALL
recvmsg(0x260,0x7f7ff15fb370,0)
2362 9 named 1456773618.152033854 CALL
recvmsg(0x262,0x7f7ff09f8370,0)
2362 11 named 1456773618.152050266 CALL
__kevent50(8,0x7f7ff01f6f20,1,0,0,0)
2362 9 named 1456773618.152061650 MISC msghdr: [name=0x7f7fef50f328,
namelen=128, iov=0x7f7ff09f83a0, iovlen=1, control=0x7f7ff3d98fa0,
controllen=96, flags=4000000]
2362 6 named 1456773618.152051663 MISC msghdr: [name=0x7f7fef517088,
namelen=128, iov=0x7f7ff15fb3a0, iovlen=1, control=0x7f7fec6ca1e0,
controllen=96, flags=4000000]
2362 3 named 1456773618.152041047 CALL write(7,0x7f7ff21fe3e0,8)
2362 11 named 1456773618.152075688 RET __kevent50 -1 errno 2 No such
file or directory
2362 9 named 1456773618.152081694 RET recvmsg -1 errno 35 Resource
temporarily unavailable
2362 6 named 1456773618.152085116 RET recvmsg -1 errno 35 Resource
temporarily unavailable
2362 9 named 1456773618.152089586 CALL write(7,0x7f7ff09f8430,8)
2362 6 named 1456773618.152093986 CALL write(7,0x7f7ff15fb430,8)
2362 11 named 1456773618.152082322 CALL
__kevent50(8,0x7f7ff01f6f20,1,0,0,0)
2362 9 named 1456773618.152102087 GIO fd 7 wrote 8 bytes
"b\^B\0\0\M-}\M^?\M^?\M^?"
2362 6 named 1456773618.152106976 GIO fd 7 wrote 8 bytes
"`\^B\0\0\M-}\M^?\M^?\M^?"
2362 3 named 1456773618.152084837 GIO fd 7 wrote 8 bytes
"a\^B\0\0\M-}\M^?\M^?\M^?"
2362 11 named 1456773618.152107674 RET __kevent50 -1 errno 2 No such
file or directory
2362 3 named 1456773618.152118150 RET write 8
...
maybe interesting:
kdump -T -f bind.ktrace | grep temporarily
...
2362 7 named 1456773591.659648856 RET recvmsg -1 errno 35 Resource
temporarily unavailable
2362 3 named 1456773591.659831278 RET recvmsg -1 errno 35 Resource
temporarily unavailable
2362 11 named 1456773591.659937993 RET read -1 errno 35 Resource
temporarily unavailable
2362 3 named 1456773591.660328049 RET recvmsg -1 errno 35 Resource
temporarily unavailable
2362 11 named 1456773591.660407666 RET read -1 errno 35 Resource
temporarily unavailable
2362 11 named 1456773591.660658950 RET read -1 errno 35 Resource
temporarily unavailable
...
2362 3 named 1456773618.152029244 RET recvmsg -1 errno 35 Resource
temporarily unavailable
2362 9 named 1456773618.152081694 RET recvmsg -1 errno 35 Resource
temporarily unavailable
2362 6 named 1456773618.152085116 RET recvmsg -1 errno 35 Resource
temporarily unavailable
2362 8 named 1456773618.656240078 RET recvmsg -1 errno 35 Resource
temporarily unavailable
2362 6 named 1456773618.656509381 RET recvmsg -1 errno 35 Resource
temporarily unavailable
2362 9 named 1456773618.656578243 RET recvmsg -1 errno 35 Resource
temporarily unavailable
2362 7 named 1456773618.657299200 RET recvmsg -1 errno 35 Resource
temporarily unavailable
2362 3 named 1456773618.657380703 RET recvmsg -1 errno 35 Resource
temporarily unavailable
2362 9 named 1456773618.790215928 RET recvmsg -1 errno 35 Resource
temporarily unavailable
Any Ideas?
Regards
Uwe
