From: Andrew Savchenko <hidden> Date: 2012-10-03 19:26:01
Hello,
I encountered a very weird bug: after a while of uptime kernel stops to deliver
DNS reply to applications. Tcpdump shows that correct reply is recieved, but
strace shows inquiring application never recieves it and ends with timeout,
epoll_wait() always returns 0:
a slice from: $ host kernel.org 8.8.8.8:
sendmsg(20, {msg_name(16)={sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("8.8.8.8")}, msg_iov(1)=[{"\266\344\1\0\0\1\0\0\0\0\0\0\6k
ernel\3org\0\0\1\0\1", 28}], msg_controllen=0, msg_flags=0}, 0) = 28
epoll_wait(3, {}, 64, 0) = 0
epoll_wait(3, {}, 64, 4999) = 0
Though tcpdump shows a normal reply:
20:28:44.162897 IP 10.7.74.7.43167 > 8.8.8.8.domain: 46820+ A? kernel.org. (28)
20:28:44.221308 IP 8.8.8.8.domain > 10.7.74.7.43167: 46820 1/0/0 A 149.20.4.69
(44)
After this bug has occured, it is no longer possible to perform DNS request on
the crippled system. I tried to stop/restart all network-related daemons, to
recreate network interfaces whenever possible (e.g. pppX devices), but with no
help. I use iptables and ebtables on this host, but reseting them (flushing all
chains, removing user chains, setting all policies to ACCEPT) doesn't help. The
only worknig solution is to reboot the system.
This bug happens rarely and randomly (about once in 7-12 days on 24x7 available
production system), but I had it 5 times already. Due to rare and random nature
of the bug I can't bisect it.
This problem occured after I updated vanilla kernel from 2.6.39.4 to 3.4.6.
Afterward I updated kernel to 3.4.10 in the hope that this will fix the
problem, but with no result. (I updated kernel due to commit
2ce42ec4ef551b08d2e5d26775d838ac640f82ad, which describes somewhat similar
issue, though I don't use I/OAT engine due to lack of hardware support.)
More details, attached trace files and kernel configs are available at bugzilla:
https://bugzilla.kernel.org/show_bug.cgi?id=48081
In a few days I'll try 3.4.12 (I need to rebuild kernel anyway due to unrelated
issue) and will report if this bug will occur again. But please note it may
take several weeks to check this.
Best regards,
Andrew Savchenko
From: Andrew Savchenko <hidden> Date: 2012-10-13 12:36:54
Hello,
On Wed, 3 Oct 2012 23:25:48 +0400 Andrew Savchenko wrote:
I encountered a very weird bug: after a while of uptime kernel stops to deliver
DNS reply to applications. Tcpdump shows that correct reply is recieved, but
strace shows inquiring application never recieves it and ends with timeout,
epoll_wait() always returns 0:
a slice from: $ host kernel.org 8.8.8.8:
sendmsg(20, {msg_name(16)={sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("8.8.8.8")}, msg_iov(1)=[{"\266\344\1\0\0\1\0\0\0\0\0\0\6k
ernel\3org\0\0\1\0\1", 28}], msg_controllen=0, msg_flags=0}, 0) = 28
epoll_wait(3, {}, 64, 0) = 0
epoll_wait(3, {}, 64, 4999) = 0
Though tcpdump shows a normal reply:
20:28:44.162897 IP 10.7.74.7.43167 > 8.8.8.8.domain: 46820+ A? kernel.org. (28)
20:28:44.221308 IP 8.8.8.8.domain > 10.7.74.7.43167: 46820 1/0/0 A 149.20.4.69
(44)
After this bug has occured, it is no longer possible to perform DNS request on
the crippled system. I tried to stop/restart all network-related daemons, to
recreate network interfaces whenever possible (e.g. pppX devices), but with no
help. I use iptables and ebtables on this host, but reseting them (flushing all
chains, removing user chains, setting all policies to ACCEPT) doesn't help. The
only worknig solution is to reboot the system.
This bug happens rarely and randomly (about once in 7-12 days on 24x7 available
production system), but I had it 5 times already. Due to rare and random nature
of the bug I can't bisect it.
This problem occured after I updated vanilla kernel from 2.6.39.4 to 3.4.6.
Afterward I updated kernel to 3.4.10 in the hope that this will fix the
problem, but with no result. (I updated kernel due to commit
2ce42ec4ef551b08d2e5d26775d838ac640f82ad, which describes somewhat similar
issue, though I don't use I/OAT engine due to lack of hardware support.)
More details, attached trace files and kernel configs are available at bugzilla:
https://bugzilla.kernel.org/show_bug.cgi?id=48081
In a few days I'll try 3.4.12 (I need to rebuild kernel anyway due to unrelated
issue) and will report if this bug will occur again. But please note it may
take several weeks to check this.
I got this problem again with 3.4.12 kernel. System lasted less than
a week and reboot was the only option...
Best regards,
Andrew Savchenko
From: Eric Dumazet <hidden> Date: 2012-10-13 13:44:23
On Sat, 2012-10-13 at 16:36 +0400, Andrew Savchenko wrote:
Hello,
On Wed, 3 Oct 2012 23:25:48 +0400 Andrew Savchenko wrote:
quoted
I encountered a very weird bug: after a while of uptime kernel stops to deliver
DNS reply to applications. Tcpdump shows that correct reply is recieved, but
strace shows inquiring application never recieves it and ends with timeout,
epoll_wait() always returns 0:
a slice from: $ host kernel.org 8.8.8.8:
sendmsg(20, {msg_name(16)={sa_family=AF_INET, sin_port=htons(53),
sin_addr=inet_addr("8.8.8.8")}, msg_iov(1)=[{"\266\344\1\0\0\1\0\0\0\0\0\0\6k
ernel\3org\0\0\1\0\1", 28}], msg_controllen=0, msg_flags=0}, 0) = 28
epoll_wait(3, {}, 64, 0) = 0
epoll_wait(3, {}, 64, 4999) = 0
Though tcpdump shows a normal reply:
20:28:44.162897 IP 10.7.74.7.43167 > 8.8.8.8.domain: 46820+ A? kernel.org. (28)
20:28:44.221308 IP 8.8.8.8.domain > 10.7.74.7.43167: 46820 1/0/0 A 149.20.4.69
(44)
After this bug has occured, it is no longer possible to perform DNS request on
the crippled system. I tried to stop/restart all network-related daemons, to
recreate network interfaces whenever possible (e.g. pppX devices), but with no
help. I use iptables and ebtables on this host, but reseting them (flushing all
chains, removing user chains, setting all policies to ACCEPT) doesn't help. The
only worknig solution is to reboot the system.
This bug happens rarely and randomly (about once in 7-12 days on 24x7 available
production system), but I had it 5 times already. Due to rare and random nature
of the bug I can't bisect it.
This problem occured after I updated vanilla kernel from 2.6.39.4 to 3.4.6.
Afterward I updated kernel to 3.4.10 in the hope that this will fix the
problem, but with no result. (I updated kernel due to commit
2ce42ec4ef551b08d2e5d26775d838ac640f82ad, which describes somewhat similar
issue, though I don't use I/OAT engine due to lack of hardware support.)
More details, attached trace files and kernel configs are available at bugzilla:
https://bugzilla.kernel.org/show_bug.cgi?id=48081
In a few days I'll try 3.4.12 (I need to rebuild kernel anyway due to unrelated
issue) and will report if this bug will occur again. But please note it may
take several weeks to check this.
I got this problem again with 3.4.12 kernel. System lasted less than
a week and reboot was the only option...
You should investigate and check where the incoming packet is lost
Tools :
netstat -s
drop_monitor module and dropwatch command
cat /proc/net/udp
From: Andrew Savchenko <hidden> Date: 2012-10-13 23:11:33
Hello,
On Sat, 13 Oct 2012 15:44:20 +0200 Eric Dumazet wrote:
On Sat, 2012-10-13 at 16:36 +0400, Andrew Savchenko wrote:
quoted
On Wed, 3 Oct 2012 23:25:48 +0400 Andrew Savchenko wrote:
quoted
I encountered a very weird bug: after a while of uptime kernel stops to deliver
DNS reply to applications. Tcpdump shows that correct reply is recieved, but
strace shows inquiring application never recieves it and ends with timeout,
epoll_wait() always returns 0:
a slice from: $ host kernel.org 8.8.8.8:
[...]
quoted
quoted
In a few days I'll try 3.4.12 (I need to rebuild kernel anyway due to unrelated
issue) and will report if this bug will occur again. But please note it may
take several weeks to check this.
I got this problem again with 3.4.12 kernel. System lasted less than
a week and reboot was the only option...
You should investigate and check where the incoming packet is lost
Tools :
netstat -s
drop_monitor module and dropwatch command
cat /proc/net/udp
Thank you for you reply; I updated my kernel to 3.4.14, enabled
CONFIG_NET_DROP_MONITOR, and installed dropwatch utility.
I will report back when the bug will struck again.
This may take a weak or two, however.
Best regards,
Andrew Savchenko
From: Andrew Savchenko <hidden> Date: 2012-10-20 23:26:11
Hello,
On Sun, 14 Oct 2012 03:11:19 +0400 Andrew Savchenko wrote:
On Sat, 13 Oct 2012 15:44:20 +0200 Eric Dumazet wrote:
quoted
On Sat, 2012-10-13 at 16:36 +0400, Andrew Savchenko wrote:
quoted
On Wed, 3 Oct 2012 23:25:48 +0400 Andrew Savchenko wrote:
quoted
I encountered a very weird bug: after a while of uptime kernel stops to deliver
DNS reply to applications. Tcpdump shows that correct reply is recieved, but
strace shows inquiring application never recieves it and ends with timeout,
epoll_wait() always returns 0:
a slice from: $ host kernel.org 8.8.8.8:
[...]
quoted
quoted
quoted
In a few days I'll try 3.4.12 (I need to rebuild kernel anyway due to unrelated
issue) and will report if this bug will occur again. But please note it may
take several weeks to check this.
I got this problem again with 3.4.12 kernel. System lasted less than
a week and reboot was the only option...
You should investigate and check where the incoming packet is lost
Tools :
netstat -s
drop_monitor module and dropwatch command
cat /proc/net/udp
Thank you for you reply; I updated my kernel to 3.4.14, enabled
CONFIG_NET_DROP_MONITOR, and installed dropwatch utility.
I will report back when the bug will struck again.
This may take a weak or two, however.
This bug is back again on kernel 3.4.14, but this time I was able to
get debug data and to recover running kernel without reboot.
Drowpatch showed that DNS UDP replies are always dropped here:
1 drops at __udp_queue_rcv_skb+61 (0xffffffff813bd670)
Another observations:
- only UDP replies are lost, TCP works fine;
- if network load is dropped dramatically (ip_forward disabled, most
network daemons are stopped) UDP DNS queries work again; but with
gradual load increase replies became first slow and than cease at all.
- CPU load is very low (uptime is below 0.05), so this shouldn't be
an insufficient computing power issue.
I found __udp_queue_rcv_skb function in net/ipv4/udp.c. From the code
and observations above it follows that this is likely to be a ENOMEM
condition leading to a packet loss.
This is a memory data after bug happened:
# cat /proc/meminfo
MemTotal: 1021576 kB
MemFree: 32056 kB
Buffers: 105204 kB
Cached: 646716 kB
SwapCached: 236 kB
Active: 205932 kB
Inactive: 587156 kB
Active(anon): 20636 kB
Inactive(anon): 22488 kB
Active(file): 185296 kB
Inactive(file): 564668 kB
Unevictable: 2152 kB
Mlocked: 2152 kB
SwapTotal: 995992 kB
SwapFree: 995020 kB
Dirty: 0 kB
Writeback: 0 kB
AnonPages: 43120 kB
Mapped: 7504 kB
Shmem: 148 kB
Slab: 176004 kB
SReclaimable: 118636 kB
SUnreclaim: 57368 kB
KernelStack: 688 kB
PageTables: 2948 kB
NFS_Unstable: 0 kB
Bounce: 0 kB
WritebackTmp: 0 kB
CommitLimit: 1506780 kB
Committed_AS: 62708 kB
VmallocTotal: 34359738367 kB
VmallocUsed: 262732 kB
VmallocChunk: 34359474615 kB
AnonHugePages: 0 kB
DirectMap4k: 33536 kB
DirectMap2M: 1013760 kB
# sysctl -a | grep mem
net.core.optmem_max = 20480
net.core.rmem_default = 229376
net.core.rmem_max = 131071
net.core.wmem_default = 229376
net.core.wmem_max = 131071
net.ipv4.igmp_max_memberships = 20
net.ipv4.tcp_mem = 22350 29801 44700
net.ipv4.tcp_rmem = 4096 87380 6291456
net.ipv4.tcp_wmem = 4096 16384 4194304
net.ipv4.udp_mem = 24150 32202 48300
net.ipv4.udp_rmem_min = 4096
net.ipv4.udp_wmem_min = 4096
vm.lowmem_reserve_ratio = 256 256 32
vm.overcommit_memory = 0
Sysctl memory parameters are system defaults, I haven't changed them
via sysctl or /proc interfaces.
I tried to increase udm_mem values to the following:
net.ipv4.udp_mem = 100000 150000 200000
This solved my issue, at least for a while: DNS queries are working
fine now.
But I suspect that there is some memory loss in the kernel UDP stack,
because this issue never happens after reboot and always after about
a week of network operation. So this memory increase should help only
for a month or so, if memory loss is linear.
If you need some memory debug information, let me know which one and
what tools will be needed.
Best regards,
Andrew Savchenko
From: Eric Dumazet <hidden> Date: 2012-10-21 12:52:26
On Sun, 2012-10-21 at 03:25 +0400, Andrew Savchenko wrote:
Hello,
On Sun, 14 Oct 2012 03:11:19 +0400 Andrew Savchenko wrote:
quoted
On Sat, 13 Oct 2012 15:44:20 +0200 Eric Dumazet wrote:
quoted
On Sat, 2012-10-13 at 16:36 +0400, Andrew Savchenko wrote:
quoted
On Wed, 3 Oct 2012 23:25:48 +0400 Andrew Savchenko wrote:
quoted
I encountered a very weird bug: after a while of uptime kernel stops to deliver
DNS reply to applications. Tcpdump shows that correct reply is recieved, but
strace shows inquiring application never recieves it and ends with timeout,
epoll_wait() always returns 0:
a slice from: $ host kernel.org 8.8.8.8:
[...]
quoted
quoted
quoted
In a few days I'll try 3.4.12 (I need to rebuild kernel anyway due to unrelated
issue) and will report if this bug will occur again. But please note it may
take several weeks to check this.
I got this problem again with 3.4.12 kernel. System lasted less than
a week and reboot was the only option...
You should investigate and check where the incoming packet is lost
Tools :
netstat -s
drop_monitor module and dropwatch command
cat /proc/net/udp
Thank you for you reply; I updated my kernel to 3.4.14, enabled
CONFIG_NET_DROP_MONITOR, and installed dropwatch utility.
I will report back when the bug will struck again.
This may take a weak or two, however.
This bug is back again on kernel 3.4.14, but this time I was able to
get debug data and to recover running kernel without reboot.
Drowpatch showed that DNS UDP replies are always dropped here:
1 drops at __udp_queue_rcv_skb+61 (0xffffffff813bd670)
Another observations:
- only UDP replies are lost, TCP works fine;
- if network load is dropped dramatically (ip_forward disabled, most
network daemons are stopped) UDP DNS queries work again; but with
gradual load increase replies became first slow and than cease at all.
- CPU load is very low (uptime is below 0.05), so this shouldn't be
an insufficient computing power issue.
I found __udp_queue_rcv_skb function in net/ipv4/udp.c. From the code
and observations above it follows that this is likely to be a ENOMEM
condition leading to a packet loss.
This is a memory data after bug happened:
# cat /proc/meminfo
MemTotal: 1021576 kB
MemFree: 32056 kB
Buffers: 105204 kB
Cached: 646716 kB
SwapCached: 236 kB
Active: 205932 kB
Inactive: 587156 kB
Active(anon): 20636 kB
Inactive(anon): 22488 kB
Active(file): 185296 kB
Inactive(file): 564668 kB
Unevictable: 2152 kB
Mlocked: 2152 kB
SwapTotal: 995992 kB
SwapFree: 995020 kB
Dirty: 0 kB
Writeback: 0 kB
AnonPages: 43120 kB
Mapped: 7504 kB
Shmem: 148 kB
Slab: 176004 kB
SReclaimable: 118636 kB
SUnreclaim: 57368 kB
KernelStack: 688 kB
PageTables: 2948 kB
NFS_Unstable: 0 kB
Bounce: 0 kB
WritebackTmp: 0 kB
CommitLimit: 1506780 kB
Committed_AS: 62708 kB
VmallocTotal: 34359738367 kB
VmallocUsed: 262732 kB
VmallocChunk: 34359474615 kB
AnonHugePages: 0 kB
DirectMap4k: 33536 kB
DirectMap2M: 1013760 kB
# sysctl -a | grep mem
net.core.optmem_max = 20480
net.core.rmem_default = 229376
net.core.rmem_max = 131071
net.core.wmem_default = 229376
net.core.wmem_max = 131071
net.ipv4.igmp_max_memberships = 20
net.ipv4.tcp_mem = 22350 29801 44700
net.ipv4.tcp_rmem = 4096 87380 6291456
net.ipv4.tcp_wmem = 4096 16384 4194304
net.ipv4.udp_mem = 24150 32202 48300
net.ipv4.udp_rmem_min = 4096
net.ipv4.udp_wmem_min = 4096
vm.lowmem_reserve_ratio = 256 256 32
vm.overcommit_memory = 0
Sysctl memory parameters are system defaults, I haven't changed them
via sysctl or /proc interfaces.
I tried to increase udm_mem values to the following:
net.ipv4.udp_mem = 100000 150000 200000
This solved my issue, at least for a while: DNS queries are working
fine now.
But I suspect that there is some memory loss in the kernel UDP stack,
because this issue never happens after reboot and always after about
a week of network operation. So this memory increase should help only
for a month or so, if memory loss is linear.
If you need some memory debug information, let me know which one and
what tools will be needed.
If drop is in __udp_queue_rcv_skb(), its not because you dont have
enough memory. Frame was already received and handled by IP stack.
Thats because sock_queue_rcv_skb() said : there are already enough
frames in socket receive buffer, I dont want to add another frame.
You forgot to attach :
cat /proc/net/udp
netstat -s
By the way, I suspect you are hit by skb recycling.
(skb truesize is too big after few iterations)
We removed skb recycling in linux-3.7-rc1
If so, linux-3.7-rc1 or linux-3.7-rc2 should be fine.
What NIC are you using ?
From: Andrew Savchenko <hidden> Date: 2012-10-22 03:36:50
Hello,
On Sun, 21 Oct 2012 14:52:21 +0200 Eric Dumazet wrote:
On Sun, 2012-10-21 at 03:25 +0400, Andrew Savchenko wrote:
[...]
quoted
This bug is back again on kernel 3.4.14, but this time I was able to
get debug data and to recover running kernel without reboot.
Drowpatch showed that DNS UDP replies are always dropped here:
1 drops at __udp_queue_rcv_skb+61 (0xffffffff813bd670)
Another observations:
- only UDP replies are lost, TCP works fine;
- if network load is dropped dramatically (ip_forward disabled, most
network daemons are stopped) UDP DNS queries work again; but with
gradual load increase replies became first slow and than cease at all.
- CPU load is very low (uptime is below 0.05), so this shouldn't be
an insufficient computing power issue.
I found __udp_queue_rcv_skb function in net/ipv4/udp.c. From the code
and observations above it follows that this is likely to be a ENOMEM
condition leading to a packet loss.
This is a memory data after bug happened:
# cat /proc/meminfo
MemTotal: 1021576 kB
MemFree: 32056 kB
Buffers: 105204 kB
Cached: 646716 kB
SwapCached: 236 kB
Active: 205932 kB
Inactive: 587156 kB
Active(anon): 20636 kB
Inactive(anon): 22488 kB
Active(file): 185296 kB
Inactive(file): 564668 kB
Unevictable: 2152 kB
Mlocked: 2152 kB
SwapTotal: 995992 kB
SwapFree: 995020 kB
Dirty: 0 kB
Writeback: 0 kB
AnonPages: 43120 kB
Mapped: 7504 kB
Shmem: 148 kB
Slab: 176004 kB
SReclaimable: 118636 kB
SUnreclaim: 57368 kB
KernelStack: 688 kB
PageTables: 2948 kB
NFS_Unstable: 0 kB
Bounce: 0 kB
WritebackTmp: 0 kB
CommitLimit: 1506780 kB
Committed_AS: 62708 kB
VmallocTotal: 34359738367 kB
VmallocUsed: 262732 kB
VmallocChunk: 34359474615 kB
AnonHugePages: 0 kB
DirectMap4k: 33536 kB
DirectMap2M: 1013760 kB
# sysctl -a | grep mem
net.core.optmem_max = 20480
net.core.rmem_default = 229376
net.core.rmem_max = 131071
net.core.wmem_default = 229376
net.core.wmem_max = 131071
net.ipv4.igmp_max_memberships = 20
net.ipv4.tcp_mem = 22350 29801 44700
net.ipv4.tcp_rmem = 4096 87380 6291456
net.ipv4.tcp_wmem = 4096 16384 4194304
net.ipv4.udp_mem = 24150 32202 48300
net.ipv4.udp_rmem_min = 4096
net.ipv4.udp_wmem_min = 4096
vm.lowmem_reserve_ratio = 256 256 32
vm.overcommit_memory = 0
Sysctl memory parameters are system defaults, I haven't changed them
via sysctl or /proc interfaces.
I tried to increase udm_mem values to the following:
net.ipv4.udp_mem = 100000 150000 200000
This solved my issue, at least for a while: DNS queries are working
fine now.
But I suspect that there is some memory loss in the kernel UDP stack,
because this issue never happens after reboot and always after about
a week of network operation. So this memory increase should help only
for a month or so, if memory loss is linear.
If you need some memory debug information, let me know which one and
what tools will be needed.
If drop is in __udp_queue_rcv_skb(), its not because you dont have
enough memory. Frame was already received and handled by IP stack.
Thats because sock_queue_rcv_skb() said : there are already enough
frames in socket receive buffer, I dont want to add another frame.
Actually there was a lot of dropwatch output. I decided that drops
are in __udp_queue_rcv_skb() by comparison between dropwatch outputs
under normal operation and under bug condition. I'm attaching both of
them.
You forgot to attach :
cat /proc/net/udp
netstat -s
Now bug is perfectly reproducible using net.ipv4.udp_mem values as
described in my previous mail. I reproduced reproducing bug
conditions and attaching these outputs.
By the way, I suspect you are hit by skb recycling.
(skb truesize is too big after few iterations)
We removed skb recycling in linux-3.7-rc1
If so, linux-3.7-rc1 or linux-3.7-rc2 should be fine.
I'll try 3.7 branch in a week or so. New kernel will require some
reconfiguration.
What NIC are you using ?
This host has four NICs:
2x Realtek Semiconductor Co., Ltd. RTL-8139/8139C/8139C+ (10ec:8139)
2x D-Link System Inc DGE-528T Gigabit Ethernet Adapter (1462:223c)
One D-Link card is operating on 1Gbit/FD with mtu 7000, other cards
are used as 100Mbit/FD mtu 1500.
2 D-Link and 1 Realtek card are forming a bridge and remaining Realtek
card is used for an uplink. This host serves as a NAT between
the bridge and the uplink (both MASQUERADE and DNAT are used). Also it
has several ipsec tunnels for multiple hosts (mostly AH), l2tp tunnel
(independent from ipsec) and serves as a multicast router using
mrouted. Rather sophisticated ebtables, iptables and ipset setup is
used.
Best regards,
Andrew Savchenko
From: Eric Dumazet <hidden> Date: 2012-10-22 06:48:16
On Mon, 2012-10-22 at 07:36 +0400, Andrew Savchenko wrote:
I'll try 3.7 branch in a week or so. New kernel will require some
reconfiguration.
quoted
What NIC are you using ?
This host has four NICs:
2x Realtek Semiconductor Co., Ltd. RTL-8139/8139C/8139C+ (10ec:8139)
2x D-Link System Inc DGE-528T Gigabit Ethernet Adapter (1462:223c)
One D-Link card is operating on 1Gbit/FD with mtu 7000, other cards
are used as 100Mbit/FD mtu 1500.
2 D-Link and 1 Realtek card are forming a bridge and remaining Realtek
card is used for an uplink. This host serves as a NAT between
the bridge and the uplink (both MASQUERADE and DNAT are used). Also it
has several ipsec tunnels for multiple hosts (mostly AH), l2tp tunnel
(independent from ipsec) and serves as a multicast router using
mrouted. Rather sophisticated ebtables, iptables and ipset setup is
used.
Best regards,
Andrew Savchenko
Some driver or protocol stack is messing with skb->truesize, as
your /proc/net/udp file contains anomalies :
$ cat /proc/net/udp
sl local_address rem_address st tx_queue rx_queue tr tm->when retrnsmt uid timeout inode ref pointer drops
...
323: 074A070A:007B 00000000:0000 07 FFFDF700:00000000 00:00000000 00000000 123 0 254469 2 ffff88003d581880 0
...
323: 00FCA8C0:007B 00000000:0000 07 FFFFF900:00000000 00:00000000 00000000 0 0 5187 2 ffff880039993880 0
Its clearly not possible to get tx_queue = 0xFFFDF700 or 0xFFFFF900
So what drivers handle following IP addresses : 192.168.252.0 , 10.7.74.7 ?
lspci -v
lsmod
From: Andrew Savchenko <hidden> Date: 2012-10-22 21:28:15
Hi,
On Mon, 22 Oct 2012 08:48:09 +0200 Eric Dumazet wrote:
On Mon, 2012-10-22 at 07:36 +0400, Andrew Savchenko wrote:
[...]
quoted
This host has four NICs:
2x Realtek Semiconductor Co., Ltd. RTL-8139/8139C/8139C+ (10ec:8139)
2x D-Link System Inc DGE-528T Gigabit Ethernet Adapter (1462:223c)
One D-Link card is operating on 1Gbit/FD with mtu 7000, other cards
are used as 100Mbit/FD mtu 1500.
2 D-Link and 1 Realtek card are forming a bridge and remaining Realtek
card is used for an uplink. This host serves as a NAT between
the bridge and the uplink (both MASQUERADE and DNAT are used). Also it
has several ipsec tunnels for multiple hosts (mostly AH), l2tp tunnel
(independent from ipsec) and serves as a multicast router using
mrouted. Rather sophisticated ebtables, iptables and ipset setup is
used.
Some driver or protocol stack is messing with skb->truesize, as
your /proc/net/udp file contains anomalies :
$ cat /proc/net/udp
sl local_address rem_address st tx_queue rx_queue tr tm->when retrnsmt uid timeout inode ref pointer drops
...
323: 074A070A:007B 00000000:0000 07 FFFDF700:00000000 00:00000000 00000000 123 0 254469 2 ffff88003d581880 0
...
323: 00FCA8C0:007B 00000000:0000 07 FFFFF900:00000000 00:00000000 00000000 0 0 5187 2 ffff880039993880 0
Its clearly not possible to get tx_queue = 0xFFFDF700 or 0xFFFFF900
So what drivers handle following IP addresses : 192.168.252.0 , 10.7.74.7 ?
192.168.252.0 is handled by eth0 interface running on Realtek
Semiconductor Co., Ltd. RTL-8139/8139C/8139C+ (10ec:8139) NIC.
Kernel driver 8139too. This interface handles multiple subnetworks:
# ip addr show eth0
2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 1000
link/ether 00:80:48:30:ca:f3 brd ff:ff:ff:ff:ff:ff
inet 10.51.15.126/25 brd 10.51.15.127 scope global eth0
inet 192.168.252.0/31 scope global eth0
10.7.74.7 is an l2tp connection handled by ppp over l2tp:
CONFIG_PPPOL2TP=y
It is running on top of eth0 described above.
# ip addr show ppp0
65: ppp0: <POINTOPOINT,MULTICAST,NOARP,UP,LOWER_UP> mtu 1400 qdisc pfifo_fast state UNKNOWN qlen 3
link/ppp
inet 10.7.74.7 peer 10.7.2.18/32 scope global ppp0
I don't know why both interfaces have unknown state: they are up and
running.
lspci -v
Attached.
lsmod
lsmod returns nothing: I compiled everything needed for daily use
into the kernel.
Best regards,
Andrew Savchenko
From: Andrew Savchenko <hidden> Date: 2012-11-23 07:46:10
Hello,
On Sun, 21 Oct 2012 03:25:43 +0400 Andrew Savchenko wrote:
quoted
On Sat, 13 Oct 2012 15:44:20 +0200 Eric Dumazet wrote:
[...]
quoted
quoted
You should investigate and check where the incoming packet is lost
Tools :
netstat -s
drop_monitor module and dropwatch command
cat /proc/net/udp
Thank you for you reply; I updated my kernel to 3.4.14, enabled
CONFIG_NET_DROP_MONITOR, and installed dropwatch utility.
I will report back when the bug will struck again.
This may take a weak or two, however.
This bug is back again on kernel 3.4.14, but this time I was able to
get debug data and to recover running kernel without reboot.
Drowpatch showed that DNS UDP replies are always dropped here:
1 drops at __udp_queue_rcv_skb+61 (0xffffffff813bd670)
Another observations:
- only UDP replies are lost, TCP works fine;
- if network load is dropped dramatically (ip_forward disabled, most
network daemons are stopped) UDP DNS queries work again; but with
gradual load increase replies became first slow and than cease at all.
- CPU load is very low (uptime is below 0.05), so this shouldn't be
an insufficient computing power issue.
I found __udp_queue_rcv_skb function in net/ipv4/udp.c. From the code
and observations above it follows that this is likely to be a ENOMEM
condition leading to a packet loss.
[...]
net.ipv4.udp_mem = 100000 150000 200000
This solved my issue, at least for a while: DNS queries are working
fine now.
And this solved problem only temporary: after 40 days of uptime the
same problem struck again with the same observables. I "solved" this
by increasing udp memory again:
net.ipv4.udp_mem = 200000 300000 400000
Of course, this solution is only a temporary workaround. Such
behaviour increases my suspicions on some kind of memory leak.
This host is still on 3.4.14, however: can't reboot now due to
workload. Will try 3.7 branch as soon as this will be possible.
Best regards,
Andrew Savchenko
From: Andrew Savchenko <hidden> Date: 2012-12-12 08:27:32
Hello,
On Tue, 23 Oct 2012 01:27:59 +0400 Andrew Savchenko wrote:
On Mon, 22 Oct 2012 08:48:09 +0200 Eric Dumazet wrote:
[...]
quoted
Some driver or protocol stack is messing with skb->truesize, as
your /proc/net/udp file contains anomalies :
$ cat /proc/net/udp
sl local_address rem_address st tx_queue rx_queue tr tm->when retrnsmt uid timeout inode ref pointer drops
...
323: 074A070A:007B 00000000:0000 07 FFFDF700:00000000 00:00000000 00000000 123 0 254469 2 ffff88003d581880 0
...
323: 00FCA8C0:007B 00000000:0000 07 FFFFF900:00000000 00:00000000 00000000 0 0 5187 2 ffff880039993880 0
Its clearly not possible to get tx_queue = 0xFFFDF700 or 0xFFFFF900
So what drivers handle following IP addresses : 192.168.252.0 , 10.7.74.7 ?
192.168.252.0 is handled by eth0 interface running on Realtek
Semiconductor Co., Ltd. RTL-8139/8139C/8139C+ (10ec:8139) NIC.
Kernel driver 8139too. This interface handles multiple subnetworks:
# ip addr show eth0
2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 1000
link/ether 00:80:48:30:ca:f3 brd ff:ff:ff:ff:ff:ff
inet 10.51.15.126/25 brd 10.51.15.127 scope global eth0
inet 192.168.252.0/31 scope global eth0
10.7.74.7 is an l2tp connection handled by ppp over l2tp:
CONFIG_PPPOL2TP=y
It is running on top of eth0 described above.
# ip addr show ppp0
65: ppp0: <POINTOPOINT,MULTICAST,NOARP,UP,LOWER_UP> mtu 1400 qdisc pfifo_fast state UNKNOWN qlen 3
link/ppp
inet 10.7.74.7 peer 10.7.2.18/32 scope global ppp0
From: Andrew Savchenko <hidden> Date: 2012-12-23 11:13:59
Hello,
the bug has struck again on 3.7.0, see details below.
On Wed, 12 Dec 2012 12:27:16 +0400 Andrew Savchenko wrote:
[...]
quoted
quoted
Some driver or protocol stack is messing with skb->truesize, as
your /proc/net/udp file contains anomalies :
$ cat /proc/net/udp
sl local_address rem_address st tx_queue rx_queue tr tm->when retrnsmt uid timeout inode ref pointer drops
...
323: 074A070A:007B 00000000:0000 07 FFFDF700:00000000 00:00000000 00000000 123 0 254469 2 ffff88003d581880 0
...
323: 00FCA8C0:007B 00000000:0000 07 FFFFF900:00000000 00:00000000 00000000 0 0 5187 2 ffff880039993880 0
Its clearly not possible to get tx_queue = 0xFFFDF700 or 0xFFFFF900
So what drivers handle following IP addresses : 192.168.252.0 , 10.7.74.7 ?
192.168.252.0 is handled by eth0 interface running on Realtek
Semiconductor Co., Ltd. RTL-8139/8139C/8139C+ (10ec:8139) NIC.
Kernel driver 8139too. This interface handles multiple subnetworks:
# ip addr show eth0
2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 1000
link/ether 00:80:48:30:ca:f3 brd ff:ff:ff:ff:ff:ff
inet 10.51.15.126/25 brd 10.51.15.127 scope global eth0
inet 192.168.252.0/31 scope global eth0
10.7.74.7 is an l2tp connection handled by ppp over l2tp:
CONFIG_PPPOL2TP=y
It is running on top of eth0 described above.
# ip addr show ppp0
65: ppp0: <POINTOPOINT,MULTICAST,NOARP,UP,LOWER_UP> mtu 1400 qdisc pfifo_fast state UNKNOWN qlen 3
link/ppp
inet 10.7.74.7 peer 10.7.2.18/32 scope global ppp0
I hit this bug again on uptime 11 days on 3.7.0 vanilla kernel.
See kernel config, /prot/net/upd, netstat -s and dropwatch logs
attached to this mail. This bug happens on UDP DNS requests only,
TCP requests work fine, see dig.log attached.
Increasing of net.ipv4.udp_mem from
24150 32201 48300
to
100000 150000 200000
helps, but I'm afraid only temporary again.
Dropwatch data was collected in the following way:
- dropwatch.bug.* files contain data obtained after bug occurred;
- dropwatch.*.background files contain background data when no
host or dig test was running; this system has active firewall
and complicated routing, ipv6 disabled via sysctl, etc, so some
drops are normal;
- dropwatch.*.host.request shows dropped packets recorded during
host ya.ru request; of course, during this time some background
packets were recorded as well (dropwatch doesn't support filtering
at this moment);
- dropwatch.nobug.* data was collected after the bug was
workarounded via net.ipv4.upd_mem as described above.
As can be seen from dropwatch logs, drop in __udp_queue_rcv_skb+61
happens only on host request on bug conditions, thus something is
wrong there.
Best regards,
Andrew Savchenko
From: Eric Dumazet <hidden> Date: 2012-12-28 18:11:08
On Sun, 2012-12-23 at 15:06 +0400, Andrew Savchenko wrote:
Hello,
the bug has struck again on 3.7.0, see details below.
On Wed, 12 Dec 2012 12:27:16 +0400 Andrew Savchenko wrote:
quoted
[...]
quoted
quoted
Some driver or protocol stack is messing with skb->truesize, as
your /proc/net/udp file contains anomalies :
$ cat /proc/net/udp
sl local_address rem_address st tx_queue rx_queue tr tm->when retrnsmt uid timeout inode ref pointer drops
...
323: 074A070A:007B 00000000:0000 07 FFFDF700:00000000 00:00000000 00000000 123 0 254469 2 ffff88003d581880 0
...
323: 00FCA8C0:007B 00000000:0000 07 FFFFF900:00000000 00:00000000 00000000 0 0 5187 2 ffff880039993880 0
Its clearly not possible to get tx_queue = 0xFFFDF700 or 0xFFFFF900
So what drivers handle following IP addresses : 192.168.252.0 , 10.7.74.7 ?
192.168.252.0 is handled by eth0 interface running on Realtek
Semiconductor Co., Ltd. RTL-8139/8139C/8139C+ (10ec:8139) NIC.
Kernel driver 8139too. This interface handles multiple subnetworks:
# ip addr show eth0
2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 1000
link/ether 00:80:48:30:ca:f3 brd ff:ff:ff:ff:ff:ff
inet 10.51.15.126/25 brd 10.51.15.127 scope global eth0
inet 192.168.252.0/31 scope global eth0
10.7.74.7 is an l2tp connection handled by ppp over l2tp:
CONFIG_PPPOL2TP=y
It is running on top of eth0 described above.
# ip addr show ppp0
65: ppp0: <POINTOPOINT,MULTICAST,NOARP,UP,LOWER_UP> mtu 1400 qdisc pfifo_fast state UNKNOWN qlen 3
link/ppp
inet 10.7.74.7 peer 10.7.2.18/32 scope global ppp0
I hit this bug again on uptime 11 days on 3.7.0 vanilla kernel.
See kernel config, /prot/net/upd, netstat -s and dropwatch logs
attached to this mail. This bug happens on UDP DNS requests only,
TCP requests work fine, see dig.log attached.
Increasing of net.ipv4.udp_mem from
24150 32201 48300
to
100000 150000 200000
helps, but I'm afraid only temporary again.
Dropwatch data was collected in the following way:
- dropwatch.bug.* files contain data obtained after bug occurred;
- dropwatch.*.background files contain background data when no
host or dig test was running; this system has active firewall
and complicated routing, ipv6 disabled via sysctl, etc, so some
drops are normal;
- dropwatch.*.host.request shows dropped packets recorded during
host ya.ru request; of course, during this time some background
packets were recorded as well (dropwatch doesn't support filtering
at this moment);
- dropwatch.nobug.* data was collected after the bug was
workarounded via net.ipv4.upd_mem as described above.
As can be seen from dropwatch logs, drop in __udp_queue_rcv_skb+61
happens only on host request on bug conditions, thus something is
wrong there.
Best regards,
Andrew Savchenko
Thanks a lot !
I see strange drops in dev_hard_start_xmit()
l2tp needs some care.
Please try the following patch, as skb_cow_head() API
doesnt really ease skb->truesize exact tracking anyway, better not mess
with it.
net/l2tp/l2tp_core.c | 6 ------
net/l2tp/l2tp_ppp.c | 6 ------
2 files changed, 12 deletions(-)
From: Andrew Savchenko <hidden> Date: 2013-01-16 16:43:22
Hello,
On Fri, 28 Dec 2012 10:11:03 -0800 Eric Dumazet wrote:
On Sun, 2012-12-23 at 15:06 +0400, Andrew Savchenko wrote:
[...]
quoted
I hit this bug again on uptime 11 days on 3.7.0 vanilla kernel.
See kernel config, /prot/net/upd, netstat -s and dropwatch logs
attached to this mail. This bug happens on UDP DNS requests only,
TCP requests work fine, see dig.log attached.
Increasing of net.ipv4.udp_mem from
24150 32201 48300
to
100000 150000 200000
helps, but I'm afraid only temporary again.
Dropwatch data was collected in the following way:
- dropwatch.bug.* files contain data obtained after bug occurred;
- dropwatch.*.background files contain background data when no
host or dig test was running; this system has active firewall
and complicated routing, ipv6 disabled via sysctl, etc, so some
drops are normal;
- dropwatch.*.host.request shows dropped packets recorded during
host ya.ru request; of course, during this time some background
packets were recorded as well (dropwatch doesn't support filtering
at this moment);
- dropwatch.nobug.* data was collected after the bug was
workarounded via net.ipv4.upd_mem as described above.
As can be seen from dropwatch logs, drop in __udp_queue_rcv_skb+61
happens only on host request on bug conditions, thus something is
wrong there.
Best regards,
Andrew Savchenko
Thanks a lot !
I see strange drops in dev_hard_start_xmit()
l2tp needs some care.
Please try the following patch, as skb_cow_head() API
doesnt really ease skb->truesize exact tracking anyway, better not mess
with it.
Sorry for the delay, but I was able to reboot kernel only today.
Your patch is applied on top of the 3.7.2 vanilla kernel.
l2tp works fine and /proc/net/udp tx_queue values are normal now, see
attached /prot/net/udp output. This is a good hint that problem is
probably solved, but we need to wait at least several weeks to be
sure.
Best regards,
Andrew Savchenko
From: Andrew Savchenko <hidden> Date: 2013-02-04 13:39:58
Hello,
On Wed, 16 Jan 2013 20:36:44 +0400 Andrew Savchenko wrote:
On Fri, 28 Dec 2012 10:11:03 -0800 Eric Dumazet wrote:
[...]
quoted
Thanks a lot !
I see strange drops in dev_hard_start_xmit()
l2tp needs some care.
Please try the following patch, as skb_cow_head() API
doesnt really ease skb->truesize exact tracking anyway, better not mess
with it.
Sorry for the delay, but I was able to reboot kernel only today.
Your patch is applied on top of the 3.7.2 vanilla kernel.
l2tp works fine and /proc/net/udp tx_queue values are normal now, see
attached /prot/net/udp output. This is a good hint that problem is
probably solved, but we need to wait at least several weeks to be
sure.
With 16-days uptime system works fine.
Also I was able to reproduce this bug on another box: an embedded
system running openwrt with 3.7.5 kernel with openl2tpd client and
dnsmasq server. Due to limited memory resources this bug happened to
be easily reproducible: several thousands of dns queries were
sufficient to reproduce this bug. Full debug on embedded box was not
possible due to constrained resources, but bug appearance was the same
and /proc/net/udp is apparently broken (see attached log).
I applied your patch on openwrt's 3.7.5 kernel and it fixed the bug
on this box too.
So we've found a solution and I'm looking forward for it in the main
kernel :)
Best regards,
Andrew Savchenko
From: Eric Dumazet <hidden> Date: 2013-02-04 15:21:10
On Mon, 2013-02-04 at 17:39 +0400, Andrew Savchenko wrote:
With 16-days uptime system works fine.
Also I was able to reproduce this bug on another box: an embedded
system running openwrt with 3.7.5 kernel with openl2tpd client and
dnsmasq server. Due to limited memory resources this bug happened to
be easily reproducible: several thousands of dns queries were
sufficient to reproduce this bug. Full debug on embedded box was not
possible due to constrained resources, but bug appearance was the same
and /proc/net/udp is apparently broken (see attached log).
I applied your patch on openwrt's 3.7.5 kernel and it fixed the bug
on this box too.
So we've found a solution and I'm looking forward for it in the main
kernel :)
Thanks a lot for testing, I'll send the official patch asap.