* Kernel recieves DNS reply, but doesn't deliver it to a waiting application
@ 2012-10-03 19:25 Andrew Savchenko
2012-10-13 12:36 ` [BUG] " Andrew Savchenko
0 siblings, 1 reply; 16+ messages in thread
From: Andrew Savchenko @ 2012-10-03 19:25 UTC (permalink / raw)
To: netdev
[-- Attachment #1: Type: text/plain, Size: 2262 bytes --]
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
[-- Attachment #2: Type: application/pgp-signature, Size: 198 bytes --]
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [BUG] Kernel recieves DNS reply, but doesn't deliver it to a waiting application
2012-10-03 19:25 Kernel recieves DNS reply, but doesn't deliver it to a waiting application Andrew Savchenko
@ 2012-10-13 12:36 ` Andrew Savchenko
2012-10-13 13:44 ` Eric Dumazet
0 siblings, 1 reply; 16+ messages in thread
From: Andrew Savchenko @ 2012-10-13 12:36 UTC (permalink / raw)
To: netdev
[-- Attachment #1: Type: text/plain, Size: 2517 bytes --]
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
[-- Attachment #2: Type: application/pgp-signature, Size: 198 bytes --]
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [BUG] Kernel recieves DNS reply, but doesn't deliver it to a waiting application
2012-10-13 12:36 ` [BUG] " Andrew Savchenko
@ 2012-10-13 13:44 ` Eric Dumazet
2012-10-13 23:11 ` Andrew Savchenko
0 siblings, 1 reply; 16+ messages in thread
From: Eric Dumazet @ 2012-10-13 13:44 UTC (permalink / raw)
To: Andrew Savchenko; +Cc: netdev
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:
> > 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
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [BUG] Kernel recieves DNS reply, but doesn't deliver it to a waiting application
2012-10-13 13:44 ` Eric Dumazet
@ 2012-10-13 23:11 ` Andrew Savchenko
2012-10-20 23:25 ` Andrew Savchenko
0 siblings, 1 reply; 16+ messages in thread
From: Andrew Savchenko @ 2012-10-13 23:11 UTC (permalink / raw)
To: Eric Dumazet; +Cc: netdev
[-- Attachment #1: Type: text/plain, Size: 1311 bytes --]
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:
> > 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:
[...]
> > > 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
[-- Attachment #2: Type: application/pgp-signature, Size: 198 bytes --]
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [BUG] Kernel recieves DNS reply, but doesn't deliver it to a waiting application
2012-10-13 23:11 ` Andrew Savchenko
@ 2012-10-20 23:25 ` Andrew Savchenko
2012-10-21 12:52 ` Eric Dumazet
2012-11-23 7:45 ` Andrew Savchenko
0 siblings, 2 replies; 16+ messages in thread
From: Andrew Savchenko @ 2012-10-20 23:25 UTC (permalink / raw)
To: Eric Dumazet; +Cc: netdev
[-- Attachment #1: Type: text/plain, Size: 4558 bytes --]
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:
> > On Sat, 2012-10-13 at 16:36 +0400, Andrew Savchenko wrote:
> > > 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:
> [...]
> > > > 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
[-- Attachment #2: Type: application/pgp-signature, Size: 198 bytes --]
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [BUG] Kernel recieves DNS reply, but doesn't deliver it to a waiting application
2012-10-20 23:25 ` Andrew Savchenko
@ 2012-10-21 12:52 ` Eric Dumazet
2012-10-22 3:36 ` Andrew Savchenko
2012-11-23 7:45 ` Andrew Savchenko
1 sibling, 1 reply; 16+ messages in thread
From: Eric Dumazet @ 2012-10-21 12:52 UTC (permalink / raw)
To: Andrew Savchenko; +Cc: netdev
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:
> > On Sat, 13 Oct 2012 15:44:20 +0200 Eric Dumazet wrote:
> > > On Sat, 2012-10-13 at 16:36 +0400, Andrew Savchenko wrote:
> > > > 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:
> > [...]
> > > > > 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 ?
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [BUG] Kernel recieves DNS reply, but doesn't deliver it to a waiting application
2012-10-21 12:52 ` Eric Dumazet
@ 2012-10-22 3:36 ` Andrew Savchenko
2012-10-22 6:48 ` Eric Dumazet
0 siblings, 1 reply; 16+ messages in thread
From: Andrew Savchenko @ 2012-10-22 3:36 UTC (permalink / raw)
To: Eric Dumazet; +Cc: netdev
[-- Attachment #1.1: Type: text/plain, Size: 5420 bytes --]
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:
[...]
> > 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
[-- Attachment #1.2: dropwatch.bug --]
[-- Type: application/octet-stream, Size: 6228 bytes --]
dropwatch> start
Enabling monitoring...
Kernel monitoring activated.
Issue Ctrl-C to stop monitoring
1 drops at netlink_unicast+1ae (0xffffffff8136a7cc)
891 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
1 drops at skb_free_datagram_locked+0 (0xffffffff8134200b)
1 drops at __udp_queue_rcv_skb+61 (0xffffffff813bd670)
1 drops at nf_hook_slow+107 (0xffffffff8136cac8)
1043 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
2 drops at unix_stream_connect+1b8 (0xffffffff813f479b)
4 drops at __udp_queue_rcv_skb+61 (0xffffffff813bd670)
2 drops at skb_free_datagram_locked+0 (0xffffffff8134200b)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
861 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
3 drops at __udp_queue_rcv_skb+61 (0xffffffff813bd670)
1 drops at nf_hook_slow+107 (0xffffffff8136cac8)
3 drops at skb_free_datagram_locked+0 (0xffffffff8134200b)
1 drops at __udp4_lib_rcv+4a1 (0xffffffff813c0d0c)
760 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
2 drops at __udp_queue_rcv_skb+61 (0xffffffff813bd670)
1 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
2 drops at nf_hook_slow+107 (0xffffffff8136cac8)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
610 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
1 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
3 drops at nf_hook_slow+107 (0xffffffff8136cac8)
1 drops at ppp_read+13c (0xffffffff812dcb86)
1 drops at skb_free_datagram_locked+0 (0xffffffff8134200b)
1 drops at __udp_queue_rcv_skb+61 (0xffffffff813bd670)
915 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
1 drops at __udp_queue_rcv_skb+61 (0xffffffff813bd670)
1 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
1 drops at nf_hook_slow+107 (0xffffffff8136cac8)
737 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
2 drops at __udp_queue_rcv_skb+61 (0xffffffff813bd670)
1 drops at skb_free_datagram_locked+0 (0xffffffff8134200b)
1 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
592 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
1 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
1 drops at nf_hook_slow+107 (0xffffffff8136cac8)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
1 drops at __udp4_lib_rcv+4a1 (0xffffffff813c0d0c)
624 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
1 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
2 drops at nf_hook_slow+107 (0xffffffff8136cac8)
629 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
1 drops at __udp_queue_rcv_skb+61 (0xffffffff813bd670)
2 drops at nf_hook_slow+107 (0xffffffff8136cac8)
2 drops at skb_free_datagram_locked+0 (0xffffffff8134200b)
2 drops at ppp_read+13c (0xffffffff812dcb86)
1 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
506 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
1 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
1 drops at nf_hook_slow+107 (0xffffffff8136cac8)
573 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
2 drops at nf_hook_slow+107 (0xffffffff8136cac8)
1 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
1 drops at __udp4_lib_rcv+4a1 (0xffffffff813c0d0c)
1 drops at ip_mr_forward+79 (0xffffffff813d816e)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
2 drops at icmp_rcv+11d (0xffffffff813c3f39)
1 drops at __udp_queue_rcv_skb+61 (0xffffffff813bd670)
506 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
4 drops at nf_hook_slow+107 (0xffffffff8136cac8)
2 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
1 drops at __udp4_lib_rcv+4a1 (0xffffffff813c0d0c)
574 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
2 drops at nf_hook_slow+107 (0xffffffff8136cac8)
2 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
1 drops at __udp_queue_rcv_skb+61 (0xffffffff813bd670)
571 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
1 drops at ip_mr_forward+79 (0xffffffff813d816e)
2 drops at nf_hook_slow+107 (0xffffffff8136cac8)
1 drops at ppp_read+13c (0xffffffff812dcb86)
2 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
878 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
1 drops at nf_hook_slow+107 (0xffffffff8136cac8)
707 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
548 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
1 drops at nf_hook_slow+107 (0xffffffff8136cac8)
1 drops at ip_mr_forward+79 (0xffffffff813d816e)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
1 drops at __udp4_lib_rcv+4a1 (0xffffffff813c0d0c)
735 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
2 drops at nf_hook_slow+107 (0xffffffff8136cac8)
684 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
2 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
2 drops at nf_hook_slow+107 (0xffffffff8136cac8)
2 drops at ppp_read+13c (0xffffffff812dcb86)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
702 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
1 drops at ip_mr_forward+79 (0xffffffff813d816e)
1 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
1 drops at nf_hook_slow+107 (0xffffffff8136cac8)
560 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
668 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
1 drops at nf_hook_slow+107 (0xffffffff8136cac8)
1 drops at __udp4_lib_rcv+4a1 (0xffffffff813c0d0c)
824 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
1 drops at ip_mr_forward+79 (0xffffffff813d816e)
2 drops at nf_hook_slow+107 (0xffffffff8136cac8)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
762 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
3 drops at nf_hook_slow+107 (0xffffffff8136cac8)
1 drops at ppp_read+13c (0xffffffff812dcb86)
1 drops at skb_free_datagram_locked+0 (0xffffffff8134200b)
1 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
857 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
1 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
1 drops at nf_hook_slow+107 (0xffffffff8136cac8)
1096 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
1 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
1 drops at ip_mr_forward+79 (0xffffffff813d816e)
1 drops at icmp_rcv+11d (0xffffffff813c3f39)
1170 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
1 drops at nf_hook_slow+107 (0xffffffff8136cac8)
2 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
1 drops at __udp4_lib_rcv+4a1 (0xffffffff813c0d0c)
^CGot a stop message
[-- Attachment #1.3: dropwatch.normal --]
[-- Type: application/octet-stream, Size: 3613 bytes --]
dropwatch> start
Enabling monitoring...
Kernel monitoring activated.
Issue Ctrl-C to stop monitoring
1 drops at netlink_unicast+1ae (0xffffffff8136a7cc)
1393 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
1 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
1 drops at nf_hook_slow+107 (0xffffffff8136cac8)
1751 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
3 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
1345 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
5 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
1 drops at nf_hook_slow+107 (0xffffffff8136cac8)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
1 drops at __udp4_lib_rcv+4a1 (0xffffffff813c0d0c)
2116 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
6 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
4 drops at nf_hook_slow+107 (0xffffffff8136cac8)
2098 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
7 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
2 drops at nf_hook_slow+107 (0xffffffff8136cac8)
2 drops at ppp_read+13c (0xffffffff812dcb86)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
1978 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
7 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
1 drops at nf_hook_slow+107 (0xffffffff8136cac8)
2299 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
2 drops at nf_hook_slow+107 (0xffffffff8136cac8)
6 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
1 drops at __udp4_lib_rcv+4a1 (0xffffffff813c0d0c)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
2123 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
6 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
4 drops at nf_hook_slow+107 (0xffffffff8136cac8)
1 drops at __udp4_lib_rcv+4a1 (0xffffffff813c0d0c)
2082 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
5 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
2 drops at nf_hook_slow+107 (0xffffffff8136cac8)
2136 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
5 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
2 drops at nf_hook_slow+107 (0xffffffff8136cac8)
1 drops at ppp_read+13c (0xffffffff812dcb86)
1710 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
3 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
1 drops at nf_hook_slow+107 (0xffffffff8136cac8)
1676 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
4 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
1599 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
5 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
1 drops at nf_hook_slow+107 (0xffffffff8136cac8)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
1 drops at __udp4_lib_rcv+4a1 (0xffffffff813c0d0c)
1989 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
7 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
5 drops at nf_hook_slow+107 (0xffffffff8136cac8)
3 drops at skb_free_datagram_locked+0 (0xffffffff8134200b)
2001 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
6 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
4 drops at nf_hook_slow+107 (0xffffffff8136cac8)
2 drops at ppp_read+13c (0xffffffff812dcb86)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
2189 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
7 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
3 drops at nf_hook_slow+107 (0xffffffff8136cac8)
1805 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
3 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
5 drops at skb_free_datagram_locked+0 (0xffffffff8134200b)
1 drops at br_stp_rcv+77 (0xffffffff81438201)
1788 drops at packet_rcv_spkt+39 (0xffffffff8142aeb9)
2 drops at ipv6_rcv+147 (0xffffffff813fb9cd)
1 drops at nf_hook_slow+107 (0xffffffff8136cac8)
1 drops at __udp4_lib_rcv+4a1 (0xffffffff813c0d0c)
^CGot a stop message
[-- Attachment #1.4: netstat-s --]
[-- Type: application/octet-stream, Size: 3429 bytes --]
$ netstat -s
Ip:
1258376226 total packets received
68 with invalid headers
8729 with invalid addresses
986336591 forwarded
0 incoming packets discarded
226645746 incoming packets delivered
1397083323 requests sent out
4220 fragments dropped after timeout
101092287 reassemblies required
50310250 packets reassembled ok
471302 packet reassembles failed
156043507 fragments received ok
13056 fragments failed
312087425 fragments created
Icmp:
16951 ICMP messages received
10501 input ICMP message failed.
ICMP input histogram:
destination unreachable: 16908
echo requests: 12
echo replies: 31
81582 ICMP messages sent
0 ICMP messages failed
ICMP output histogram:
destination unreachable: 78532
time exceeded: 3006
echo request: 32
echo replies: 12
IcmpMsg:
InType0: 31
InType3: 16908
InType8: 12
OutType0: 12
OutType3: 78532
OutType8: 32
OutType11: 3006
Tcp:
5903 active connections openings
3298 passive connection openings
5697 failed connection attempts
22 connection resets received
3 connections established
17065674 segments received
6067567 segments send out
11794 segments retransmited
0 bad segments received.
36 resets sent
Udp:
198891130 packets received
40714 packets to unknown port received.
845 packet receive errors
315052 packets sent
0 receive buffer errors
0 send buffer errors
UdpLite:
TcpExt:
18 resets received for embryonic SYN_RECV sockets
15 packets pruned from receive queue because of socket buffer overrun
9 ICMP packets dropped because they were out-of-window
2769 TCP sockets finished time wait in fast timer
2090 delayed acks sent
1204 delayed acks further delayed because of locked socket
Quick ack mode was activated 2 times
1181909 packets directly queued to recvmsg prequeue.
2172536151 bytes directly in process context from backlog
1992120562 bytes directly received in process context from prequeue
12959268 packet headers predicted
2159999 packets header predicted and directly queued to user
62159 acknowledgments not containing data payload received
1855367 predicted acknowledgments
90 times recovered from packet loss by selective acknowledgements
12 congestion windows recovered without slow start after partial ack
TCPLostRetransmit: 2
889 fast retransmits
11 forward retransmits
5694 other TCP timeouts
1 SACK retransmits failed
6 times receiver scheduled too late for direct processing
1444 packets collapsed in receive queue due to low socket buffer
3 DSACKs sent for old packets
28 DSACKs received
3 connections reset due to unexpected data
40 connections aborted due to timeout
TCPDSACKIgnoredOld: 1
TCPDSACKIgnoredNoUndo: 3
TCPSpuriousRTOs: 1
TCPSackShifted: 4881
TCPSackMerged: 1465
TCPSackShiftFallback: 1217
TCPBacklogDrop: 5000
TCPDeferAcceptDrop: 2939
IPReversePathFilter: 64181
TCPRcvCoalesce: 4
IpExt:
InMcastPkts: 532105
OutMcastPkts: 310186
InBcastPkts: 110406
OutBcastPkts: 25354
InOctets: 953399407223
OutOctets: 1130740735729
InMcastOctets: 88775757
OutMcastOctets: 24850249
InBcastOctets: 12840305
OutBcastOctets: 2949734
[-- Attachment #1.5: proc_net_udp --]
[-- Type: application/octet-stream, Size: 4073 bytes --]
$ cat /proc/net/udp
sl local_address rem_address st tx_queue rx_queue tr tm->when retrnsmt uid timeout inode ref pointer drops
13: 0100007F:2745 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 253469 2 ffff88000423c380 0
44: 00000000:2D64 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 251478 2 ffff88003d581180 0
70: 00000000:857E 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 253765 2 ffff880039aa1880 0
171: 00000000:A9E3 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4859 2 ffff88003d4ece00 0
188: 7E0F330A:01F4 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5332 2 ffff880039aa0380 0
199: 0100007F:03FF 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4853 2 ffff88003d4eca80 0
201: 00000000:0801 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 253755 2 ffff880039aa0e00 0
253: 010013AC:0035 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 253582 2 ffff880039aa0a80 0
253: 0100007F:0035 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 253581 2 ffff880039aa0700 0
267: 00000000:0043 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 251500 2 ffff88003d580e00 0
288: 7E0F330A:9458 1200320A:06A5 01 00000000:00000000 00:00000000 00000000 0 0 254288 4 ffff88003b9b2e00 0
311: 00000000:006F 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4550 2 ffff88003d4ec000 0
319: 00000000:0277 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 253883 2 ffff880039aa1180 0
323: 074A070A:007B 00000000:0000 07 FFFDF700:00000000 00:00000000 00000000 123 0 254469 2 ffff88003d581880 0
323: 010213AC:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5189 2 ffff880039aa0000 0
323: 010013AC:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5188 2 ffff880039993c00 0
323: 00FCA8C0:007B 00000000:0000 07 FFFFF900:00000000 00:00000000 00000000 0 0 5187 2 ffff880039993880 0
323: 7E0F330A:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5186 2 ffff880039993500 0
323: 0100007F:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5185 2 ffff880039993180 0
323: 00000000:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5178 2 ffff880039992a80 0
337: FF0013AC:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 253948 2 ffff88003d580380 0
337: 010013AC:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 253947 2 ffff880039992e00 0
337: FF0213AC:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 253944 2 ffff88000423ca80 0
337: 010213AC:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 253943 2 ffff88000423ce00 0
337: 00000000:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 253940 2 ffff880039aa1c00 0
338: FF0013AC:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 253950 2 ffff88003d581c00 0
338: 010013AC:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 253949 2 ffff88003d580a80 0
338: FF0213AC:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 253946 2 ffff88003d4edc00 0
338: 010213AC:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 253945 2 ffff88000420e700 0
338: 00000000:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 253941 2 ffff88000423d180 0
365: 00000000:06A5 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 254281 2 ffff88003b9b2380 0
454: 00000000:90FE 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 253718 2 ffff880039aa1500 0
477: 00000000:0315 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4569 2 ffff88003d4ec380 0
[-- Attachment #2: Type: application/pgp-signature, Size: 198 bytes --]
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [BUG] Kernel recieves DNS reply, but doesn't deliver it to a waiting application
2012-10-22 3:36 ` Andrew Savchenko
@ 2012-10-22 6:48 ` Eric Dumazet
2012-10-22 21:27 ` Andrew Savchenko
0 siblings, 1 reply; 16+ messages in thread
From: Eric Dumazet @ 2012-10-22 6:48 UTC (permalink / raw)
To: Andrew Savchenko; +Cc: netdev
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.
>
> > 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
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [BUG] Kernel recieves DNS reply, but doesn't deliver it to a waiting application
2012-10-22 6:48 ` Eric Dumazet
@ 2012-10-22 21:27 ` Andrew Savchenko
2012-12-12 8:27 ` Andrew Savchenko
0 siblings, 1 reply; 16+ messages in thread
From: Andrew Savchenko @ 2012-10-22 21:27 UTC (permalink / raw)
To: Eric Dumazet; +Cc: netdev
[-- Attachment #1.1: Type: text/plain, Size: 2580 bytes --]
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:
[...]
> > 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
[-- Attachment #1.2: lspci-v --]
[-- Type: application/octet-stream, Size: 5774 bytes --]
00:00.0 Host bridge: Intel Corporation 82915G/P/GV/GL/PL/910GL Memory Controller Hub (rev 0e)
Subsystem: Micro-Star International Co., Ltd. Device 7223
Flags: bus master, fast devsel, latency 0
Capabilities: [e0] Vendor Specific Information: Len=09 <?>
00:02.0 VGA compatible controller: Intel Corporation 82915G/GV/910GL Integrated Graphics Controller (rev 0e) (prog-if 00 [VGA controller])
Subsystem: Micro-Star International Co., Ltd. Device 7223
Flags: bus master, fast devsel, latency 0, IRQ 10
Memory at fbe80000 (32-bit, non-prefetchable) [size=512K]
I/O ports at cc00 [size=8]
Memory at d0000000 (32-bit, prefetchable) [size=256M]
Memory at fbe40000 (32-bit, non-prefetchable) [size=256K]
Expansion ROM at <unassigned> [disabled]
Capabilities: [d0] Power Management version 2
00:1d.0 USB controller: Intel Corporation 82801FB/FBM/FR/FW/FRW (ICH6 Family) USB UHCI #1 (rev 04) (prog-if 00 [UHCI])
Subsystem: Micro-Star International Co., Ltd. Device 7223
Flags: bus master, medium devsel, latency 0, IRQ 23
I/O ports at c880 [size=32]
Kernel driver in use: uhci_hcd
00:1d.1 USB controller: Intel Corporation 82801FB/FBM/FR/FW/FRW (ICH6 Family) USB UHCI #2 (rev 04) (prog-if 00 [UHCI])
Subsystem: Micro-Star International Co., Ltd. Device 7223
Flags: bus master, medium devsel, latency 0, IRQ 19
I/O ports at c800 [size=32]
Kernel driver in use: uhci_hcd
00:1d.2 USB controller: Intel Corporation 82801FB/FBM/FR/FW/FRW (ICH6 Family) USB UHCI #3 (rev 04) (prog-if 00 [UHCI])
Subsystem: Micro-Star International Co., Ltd. Device 7223
Flags: bus master, medium devsel, latency 0, IRQ 18
I/O ports at c480 [size=32]
Kernel driver in use: uhci_hcd
00:1d.3 USB controller: Intel Corporation 82801FB/FBM/FR/FW/FRW (ICH6 Family) USB UHCI #4 (rev 04) (prog-if 00 [UHCI])
Subsystem: Micro-Star International Co., Ltd. Device 7223
Flags: bus master, medium devsel, latency 0, IRQ 16
I/O ports at c400 [size=32]
Kernel driver in use: uhci_hcd
00:1d.7 USB controller: Intel Corporation 82801FB/FBM/FR/FW/FRW (ICH6 Family) USB2 EHCI Controller (rev 04) (prog-if 20 [EHCI])
Subsystem: Micro-Star International Co., Ltd. Device 7223
Flags: bus master, medium devsel, latency 0, IRQ 23
Memory at fbe3bc00 (32-bit, non-prefetchable) [size=1K]
Capabilities: [50] Power Management version 2
Capabilities: [58] Debug port: BAR=1 offset=00a0
Kernel driver in use: ehci_hcd
00:1e.0 PCI bridge: Intel Corporation 82801 PCI Bridge (rev d4) (prog-if 01 [Subtractive decode])
Flags: bus master, fast devsel, latency 0
Bus: primary=00, secondary=02, subordinate=02, sec-latency=64
I/O behind bridge: 0000d000-0000efff
Memory behind bridge: fbf00000-fbffffff
Capabilities: [50] Subsystem: Micro-Star International Co., Ltd. Device 7223
00:1f.0 ISA bridge: Intel Corporation 82801FB/FR (ICH6/ICH6R) LPC Interface Bridge (rev 04)
Subsystem: Micro-Star International Co., Ltd. Device 7223
Flags: bus master, medium devsel, latency 0
00:1f.1 IDE interface: Intel Corporation 82801FB/FBM/FR/FW/FRW (ICH6 Family) IDE Controller (rev 04) (prog-if 8a [Master SecP PriP])
Subsystem: Micro-Star International Co., Ltd. Device 7223
Flags: bus master, medium devsel, latency 0, IRQ 18
I/O ports at 01f0 [size=8]
I/O ports at 03f4
I/O ports at 0170 [size=8]
I/O ports at 0374
I/O ports at ffa0 [size=16]
Kernel driver in use: ata_piix
00:1f.2 IDE interface: Intel Corporation 82801FB/FW (ICH6/ICH6W) SATA Controller (rev 04) (prog-if 8f [Master SecP SecO PriP PriO])
Subsystem: Micro-Star International Co., Ltd. Device 7223
Flags: bus master, 66MHz, medium devsel, latency 0, IRQ 19
I/O ports at c080 [size=8]
I/O ports at c000 [size=4]
I/O ports at bc00 [size=8]
I/O ports at b880 [size=4]
I/O ports at b800 [size=16]
Capabilities: [70] Power Management version 2
Kernel driver in use: ata_piix
00:1f.3 SMBus: Intel Corporation 82801FB/FBM/FR/FW/FRW (ICH6 Family) SMBus Controller (rev 04)
Subsystem: Micro-Star International Co., Ltd. Device 7223
Flags: medium devsel, IRQ 19
I/O ports at 0400 [size=32]
Kernel driver in use: i801_smbus
02:00.0 Ethernet controller: Realtek Semiconductor Co., Ltd. RTL-8139/8139C/8139C+ (rev 10)
Subsystem: Compex FN22-3(A) LinxPRO Ethernet Adapter
Flags: bus master, medium devsel, latency 128, IRQ 16
I/O ports at e800 [size=256]
Memory at fbfffc00 (32-bit, non-prefetchable) [size=256]
Expansion ROM at fbfe0000 [disabled] [size=64K]
Capabilities: [50] Power Management version 2
Kernel driver in use: 8139too
02:01.0 Ethernet controller: D-Link System Inc DGE-528T Gigabit Ethernet Adapter (rev 10)
Subsystem: D-Link System Inc DGE-528T Gigabit Ethernet Adapter
Flags: bus master, 66MHz, medium devsel, latency 64, IRQ 17
I/O ports at e400 [size=256]
Memory at fbfff800 (32-bit, non-prefetchable) [size=256]
Expansion ROM at fbfc0000 [disabled] [size=128K]
Capabilities: [dc] Power Management version 2
Kernel driver in use: r8169
02:02.0 Ethernet controller: D-Link System Inc DGE-528T Gigabit Ethernet Adapter (rev 10)
Subsystem: D-Link System Inc DGE-528T Gigabit Ethernet Adapter
Flags: bus master, 66MHz, medium devsel, latency 64, IRQ 18
I/O ports at e000 [size=256]
Memory at fbfff400 (32-bit, non-prefetchable) [size=256]
Expansion ROM at fbfa0000 [disabled] [size=128K]
Capabilities: [dc] Power Management version 2
Kernel driver in use: r8169
02:06.0 Ethernet controller: Realtek Semiconductor Co., Ltd. RTL-8139/8139C/8139C+ (rev 10)
Subsystem: Micro-Star International Co., Ltd. Device 223c
Flags: bus master, medium devsel, latency 64, IRQ 20
I/O ports at d800 [size=256]
Memory at fbfff000 (32-bit, non-prefetchable) [size=256]
Expansion ROM at fbf90000 [disabled] [size=64K]
Capabilities: [50] Power Management version 2
Kernel driver in use: 8139too
[-- Attachment #2: Type: application/pgp-signature, Size: 198 bytes --]
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [BUG] Kernel recieves DNS reply, but doesn't deliver it to a waiting application
2012-10-20 23:25 ` Andrew Savchenko
2012-10-21 12:52 ` Eric Dumazet
@ 2012-11-23 7:45 ` Andrew Savchenko
1 sibling, 0 replies; 16+ messages in thread
From: Andrew Savchenko @ 2012-11-23 7:45 UTC (permalink / raw)
To: Eric Dumazet; +Cc: netdev
[-- Attachment #1: Type: text/plain, Size: 2113 bytes --]
Hello,
On Sun, 21 Oct 2012 03:25:43 +0400 Andrew Savchenko wrote:
> > On Sat, 13 Oct 2012 15:44:20 +0200 Eric Dumazet wrote:
[...]
> > > 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
[-- Attachment #2: Type: application/pgp-signature, Size: 198 bytes --]
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [BUG] Kernel recieves DNS reply, but doesn't deliver it to a waiting application
2012-10-22 21:27 ` Andrew Savchenko
@ 2012-12-12 8:27 ` Andrew Savchenko
2012-12-23 11:06 ` Andrew Savchenko
0 siblings, 1 reply; 16+ messages in thread
From: Andrew Savchenko @ 2012-12-12 8:27 UTC (permalink / raw)
To: Eric Dumazet; +Cc: netdev
[-- Attachment #1: Type: text/plain, Size: 6266 bytes --]
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:
[...]
> > 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 updated kernel on this system to 3.7.0 and udp anomaly is still
present:
$ cat /proc/net/udp
sl local_address rem_address st tx_queue rx_queue tr tm->when retrnsmt uid timeout inode ref pointer drops
0: 00000000:06A5 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5326 2 ffff88003dbf0a80 0
8: 00000000:7EAD 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5157 2 ffff8800398c2000 0
89: 00000000:90FE 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5101 2 ffff88003dbd3500 0
160: 0100007F:2745 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4598 2 ffff88003d612700 0
184: 0100007F:035D 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4774 2 ffff88003d612a80 0
217: 00000000:857E 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5195 2 ffff8800398c2700 0
318: 00000000:A9E3 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4782 2 ffff88003d612e00 0
335: 7E0F330A:01F4 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5303 2 ffff8800398c2e00 0
348: 00000000:0801 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5186 2 ffff8800398c2380 0
387: 7E0F330A:DE28 1400320A:06A5 01 00000000:00000000 00:00000000 00000000 0 0 5332 4 ffff88003dbf0e00 0
400: 010013AC:0035 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4842 2 ffff88003d613880 0
400: 0100007F:0035 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4841 2 ffff88003d613500 0
414: 00000000:0043 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5273 2 ffff8800398c2a80 0
458: 00000000:006F 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4483 2 ffff88003d612000 0
459: 00000000:0270 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4507 2 ffff88003d612380 0
466: 00000000:0277 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4802 2 ffff88003d613180 0
470: 076A070A:007B 00000000:0000 07 FFFF4600:00000000 00:00000000 00000000 123 0 5552 2 ffff880039974380 0
470: 010213AC:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4986 2 ffff88003dbd3180 0
470: 010013AC:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4985 2 ffff88003dbd2e00 0
470: 00FCA8C0:007B 00000000:0000 07 FFFFFB00:00000000 00:00000000 00000000 0 0 4984 2 ffff88003dbd2a80 0
470: 7E0F330A:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4983 2 ffff88003dbd2700 0
470: 0100007F:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4982 2 ffff88003dbd2380 0
470: 00000000:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4975 2 ffff88003d613c00 0
484: FF0013AC:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5316 2 ffff88003dbf0000 0
484: 010013AC:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5315 2 ffff88003dbd3880 0
484: FF0213AC:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5312 2 ffff8800398c3c00 0
484: 010213AC:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5311 2 ffff8800398c3880 0
484: 00000000:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5308 2 ffff8800398c3180 0
485: FF0013AC:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5318 2 ffff88003dbf0700 0
485: 010013AC:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5317 2 ffff88003dbf0380 0
485: FF0213AC:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5314 2 ffff88003dbd3c00 0
485: 010213AC:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5313 2 ffff88003dbd2000 0
485: 00000000:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5309 2 ffff8800398c3500 0
The bug hasn't shown up yet, I'll need to wait for about a week to see
if it is reproducible.
Best regards,
Andrew Savchenko
[-- Attachment #2: Type: application/pgp-signature, Size: 198 bytes --]
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [BUG] Kernel recieves DNS reply, but doesn't deliver it to a waiting application
2012-12-12 8:27 ` Andrew Savchenko
@ 2012-12-23 11:06 ` Andrew Savchenko
2012-12-28 18:11 ` Eric Dumazet
0 siblings, 1 reply; 16+ messages in thread
From: Andrew Savchenko @ 2012-12-23 11:06 UTC (permalink / raw)
To: Eric Dumazet; +Cc: netdev
[-- Attachment #1.1: Type: text/plain, Size: 7633 bytes --]
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:
> [...]
> > > 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 updated kernel on this system to 3.7.0 and udp anomaly is still
> present:
>
> $ cat /proc/net/udp
> sl local_address rem_address st tx_queue rx_queue tr tm->when retrnsmt uid timeout inode ref pointer drops
> 0: 00000000:06A5 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5326 2 ffff88003dbf0a80 0
> 8: 00000000:7EAD 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5157 2 ffff8800398c2000 0
> 89: 00000000:90FE 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5101 2 ffff88003dbd3500 0
> 160: 0100007F:2745 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4598 2 ffff88003d612700 0
> 184: 0100007F:035D 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4774 2 ffff88003d612a80 0
> 217: 00000000:857E 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5195 2 ffff8800398c2700 0
> 318: 00000000:A9E3 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4782 2 ffff88003d612e00 0
> 335: 7E0F330A:01F4 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5303 2 ffff8800398c2e00 0
> 348: 00000000:0801 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5186 2 ffff8800398c2380 0
> 387: 7E0F330A:DE28 1400320A:06A5 01 00000000:00000000 00:00000000 00000000 0 0 5332 4 ffff88003dbf0e00 0
> 400: 010013AC:0035 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4842 2 ffff88003d613880 0
> 400: 0100007F:0035 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4841 2 ffff88003d613500 0
> 414: 00000000:0043 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5273 2 ffff8800398c2a80 0
> 458: 00000000:006F 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4483 2 ffff88003d612000 0
> 459: 00000000:0270 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4507 2 ffff88003d612380 0
> 466: 00000000:0277 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4802 2 ffff88003d613180 0
> 470: 076A070A:007B 00000000:0000 07 FFFF4600:00000000 00:00000000 00000000 123 0 5552 2 ffff880039974380 0
> 470: 010213AC:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4986 2 ffff88003dbd3180 0
> 470: 010013AC:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4985 2 ffff88003dbd2e00 0
> 470: 00FCA8C0:007B 00000000:0000 07 FFFFFB00:00000000 00:00000000 00000000 0 0 4984 2 ffff88003dbd2a80 0
> 470: 7E0F330A:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4983 2 ffff88003dbd2700 0
> 470: 0100007F:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4982 2 ffff88003dbd2380 0
> 470: 00000000:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4975 2 ffff88003d613c00 0
> 484: FF0013AC:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5316 2 ffff88003dbf0000 0
> 484: 010013AC:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5315 2 ffff88003dbd3880 0
> 484: FF0213AC:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5312 2 ffff8800398c3c00 0
> 484: 010213AC:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5311 2 ffff8800398c3880 0
> 484: 00000000:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5308 2 ffff8800398c3180 0
> 485: FF0013AC:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5318 2 ffff88003dbf0700 0
> 485: 010013AC:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5317 2 ffff88003dbf0380 0
> 485: FF0213AC:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5314 2 ffff88003dbd3c00 0
> 485: 010213AC:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5313 2 ffff88003dbd2000 0
> 485: 00000000:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5309 2 ffff8800398c3500 0
>
> The bug hasn't shown up yet, I'll need to wait for about a week to see
> if it is reproducible.
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
[-- Attachment #1.2: kernel-udp-bug.tar.xz --]
[-- Type: application/octet-stream, Size: 19320 bytes --]
[-- Attachment #2: Type: application/pgp-signature, Size: 198 bytes --]
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [BUG] Kernel recieves DNS reply, but doesn't deliver it to a waiting application
2012-12-23 11:06 ` Andrew Savchenko
@ 2012-12-28 18:11 ` Eric Dumazet
2013-01-16 16:36 ` Andrew Savchenko
0 siblings, 1 reply; 16+ messages in thread
From: Eric Dumazet @ 2012-12-28 18:11 UTC (permalink / raw)
To: Andrew Savchenko; +Cc: netdev
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:
> > [...]
> > > > 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 updated kernel on this system to 3.7.0 and udp anomaly is still
> > present:
> >
> > $ cat /proc/net/udp
> > sl local_address rem_address st tx_queue rx_queue tr tm->when retrnsmt uid timeout inode ref pointer drops
> > 0: 00000000:06A5 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5326 2 ffff88003dbf0a80 0
> > 8: 00000000:7EAD 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5157 2 ffff8800398c2000 0
> > 89: 00000000:90FE 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5101 2 ffff88003dbd3500 0
> > 160: 0100007F:2745 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4598 2 ffff88003d612700 0
> > 184: 0100007F:035D 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4774 2 ffff88003d612a80 0
> > 217: 00000000:857E 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5195 2 ffff8800398c2700 0
> > 318: 00000000:A9E3 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4782 2 ffff88003d612e00 0
> > 335: 7E0F330A:01F4 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5303 2 ffff8800398c2e00 0
> > 348: 00000000:0801 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5186 2 ffff8800398c2380 0
> > 387: 7E0F330A:DE28 1400320A:06A5 01 00000000:00000000 00:00000000 00000000 0 0 5332 4 ffff88003dbf0e00 0
> > 400: 010013AC:0035 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4842 2 ffff88003d613880 0
> > 400: 0100007F:0035 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4841 2 ffff88003d613500 0
> > 414: 00000000:0043 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5273 2 ffff8800398c2a80 0
> > 458: 00000000:006F 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4483 2 ffff88003d612000 0
> > 459: 00000000:0270 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4507 2 ffff88003d612380 0
> > 466: 00000000:0277 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4802 2 ffff88003d613180 0
> > 470: 076A070A:007B 00000000:0000 07 FFFF4600:00000000 00:00000000 00000000 123 0 5552 2 ffff880039974380 0
> > 470: 010213AC:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4986 2 ffff88003dbd3180 0
> > 470: 010013AC:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4985 2 ffff88003dbd2e00 0
> > 470: 00FCA8C0:007B 00000000:0000 07 FFFFFB00:00000000 00:00000000 00000000 0 0 4984 2 ffff88003dbd2a80 0
> > 470: 7E0F330A:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4983 2 ffff88003dbd2700 0
> > 470: 0100007F:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4982 2 ffff88003dbd2380 0
> > 470: 00000000:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4975 2 ffff88003d613c00 0
> > 484: FF0013AC:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5316 2 ffff88003dbf0000 0
> > 484: 010013AC:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5315 2 ffff88003dbd3880 0
> > 484: FF0213AC:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5312 2 ffff8800398c3c00 0
> > 484: 010213AC:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5311 2 ffff8800398c3880 0
> > 484: 00000000:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5308 2 ffff8800398c3180 0
> > 485: FF0013AC:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5318 2 ffff88003dbf0700 0
> > 485: 010013AC:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5317 2 ffff88003dbf0380 0
> > 485: FF0213AC:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5314 2 ffff88003dbd3c00 0
> > 485: 010213AC:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5313 2 ffff88003dbd2000 0
> > 485: 00000000:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5309 2 ffff8800398c3500 0
> >
> > The bug hasn't shown up yet, I'll need to wait for about a week to see
> > if it is reproducible.
>
> 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(-)
diff --git a/net/l2tp/l2tp_core.c b/net/l2tp/l2tp_core.c
index 1a9f372..d77e655 100644
--- a/net/l2tp/l2tp_core.c
+++ b/net/l2tp/l2tp_core.c
@@ -1123,8 +1123,6 @@ int l2tp_xmit_skb(struct l2tp_session *session, struct sk_buff *skb, int hdr_len
struct udphdr *uh;
struct inet_sock *inet;
__wsum csum;
- int old_headroom;
- int new_headroom;
int headroom;
int uhlen = (tunnel->encap == L2TP_ENCAPTYPE_UDP) ? sizeof(struct udphdr) : 0;
int udp_len;
@@ -1136,16 +1134,12 @@ int l2tp_xmit_skb(struct l2tp_session *session, struct sk_buff *skb, int hdr_len
*/
headroom = NET_SKB_PAD + sizeof(struct iphdr) +
uhlen + hdr_len;
- old_headroom = skb_headroom(skb);
if (skb_cow_head(skb, headroom)) {
kfree_skb(skb);
return NET_XMIT_DROP;
}
- new_headroom = skb_headroom(skb);
skb_orphan(skb);
- skb->truesize += new_headroom - old_headroom;
-
/* Setup L2TP header */
session->build_header(session, __skb_push(skb, hdr_len));
diff --git a/net/l2tp/l2tp_ppp.c b/net/l2tp/l2tp_ppp.c
index 286366e..716605c 100644
--- a/net/l2tp/l2tp_ppp.c
+++ b/net/l2tp/l2tp_ppp.c
@@ -388,8 +388,6 @@ static int pppol2tp_xmit(struct ppp_channel *chan, struct sk_buff *skb)
struct l2tp_session *session;
struct l2tp_tunnel *tunnel;
struct pppol2tp_session *ps;
- int old_headroom;
- int new_headroom;
int uhlen, headroom;
if (sock_flag(sk, SOCK_DEAD) || !(sk->sk_state & PPPOX_CONNECTED))
@@ -408,7 +406,6 @@ static int pppol2tp_xmit(struct ppp_channel *chan, struct sk_buff *skb)
if (tunnel == NULL)
goto abort_put_sess;
- old_headroom = skb_headroom(skb);
uhlen = (tunnel->encap == L2TP_ENCAPTYPE_UDP) ? sizeof(struct udphdr) : 0;
headroom = NET_SKB_PAD +
sizeof(struct iphdr) + /* IP header */
@@ -418,9 +415,6 @@ static int pppol2tp_xmit(struct ppp_channel *chan, struct sk_buff *skb)
if (skb_cow_head(skb, headroom))
goto abort_put_sess_tun;
- new_headroom = skb_headroom(skb);
- skb->truesize += new_headroom - old_headroom;
-
/* Setup PPP header */
__skb_push(skb, sizeof(ppph));
skb->data[0] = ppph[0];
^ permalink raw reply related [flat|nested] 16+ messages in thread
* Re: [BUG] Kernel recieves DNS reply, but doesn't deliver it to a waiting application
2012-12-28 18:11 ` Eric Dumazet
@ 2013-01-16 16:36 ` Andrew Savchenko
2013-02-04 13:39 ` Andrew Savchenko
0 siblings, 1 reply; 16+ messages in thread
From: Andrew Savchenko @ 2013-01-16 16:36 UTC (permalink / raw)
To: Eric Dumazet; +Cc: netdev
[-- Attachment #1.1: Type: text/plain, Size: 2135 bytes --]
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:
[...]
> > 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
[-- Attachment #1.2: proc.net.udp --]
[-- Type: application/octet-stream, Size: 4224 bytes --]
sl local_address rem_address st tx_queue rx_queue tr tm->when retrnsmt uid timeout inode ref pointer drops
0: 00000000:06A5 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5013 2 ffff88003d605c00 0
89: 00000000:90FE 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5074 2 ffff88003bcba700 0
90: 7E18340A:88FF 1400320A:06A5 01 00000000:00000000 00:00000000 00000000 0 0 5034 4 ffff88003bcba000 0
136: 00000000:892D 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5049 2 ffff88003bcba380 0
160: 0100007F:2745 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4495 2 ffff88003d604380 0
183: 0100007F:035C 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4770 2 ffff88003d604a80 0
217: 00000000:857E 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5146 2 ffff88003bd34700 0
310: 00000000:03DB 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4520 2 ffff88003d604700 0
318: 00000000:A9E3 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4776 2 ffff88003d604e00 0
348: 00000000:0801 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5137 2 ffff88003bd34380 0
400: 010013AC:0035 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4876 2 ffff88003d605880 0
400: 0100007F:0035 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4875 2 ffff88003d605500 0
414: 00000000:0043 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5176 2 ffff88003bd35500 0
458: 00000000:006F 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4486 2 ffff88003d604000 0
466: 00000000:0277 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 4818 2 ffff88003d605180 0
470: 076A070A:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 123 0 5526 2 ffff88003bd35c00 0
470: 010213AC:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5121 2 ffff88003bd34000 0
470: 010013AC:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5120 2 ffff88003bcbbc00 0
470: 00FCA8C0:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5119 2 ffff88003bcbb880 0
470: 7E18340A:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5118 2 ffff88003bcbb500 0
470: 0100007F:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5117 2 ffff88003bcbb180 0
470: 00000000:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5111 2 ffff88003bcbaa80 0
484: FF0013AC:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5298 2 ffff880039fbd500 0
484: 010013AC:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5297 2 ffff880039fbd180 0
484: FF0213AC:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5294 2 ffff880039fbc700 0
484: 010213AC:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5293 2 ffff880039fbc380 0
484: 00000000:0089 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5290 2 ffff88003bcbae00 0
485: FF0013AC:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5300 2 ffff880039fbdc00 0
485: 010013AC:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5299 2 ffff880039fbd880 0
485: FF0213AC:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5296 2 ffff880039fbce00 0
485: 010213AC:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5295 2 ffff880039fbca80 0
485: 00000000:008A 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 5291 2 ffff880039fbc000 0
[-- Attachment #2: Type: application/pgp-signature, Size: 198 bytes --]
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [BUG] Kernel recieves DNS reply, but doesn't deliver it to a waiting application
2013-01-16 16:36 ` Andrew Savchenko
@ 2013-02-04 13:39 ` Andrew Savchenko
2013-02-04 15:21 ` Eric Dumazet
0 siblings, 1 reply; 16+ messages in thread
From: Andrew Savchenko @ 2013-02-04 13:39 UTC (permalink / raw)
To: Eric Dumazet; +Cc: netdev
[-- Attachment #1.1: Type: text/plain, Size: 1480 bytes --]
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:
[...]
> > 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
[-- Attachment #1.2: proc.net.udp --]
[-- Type: application/octet-stream, Size: 1794 bytes --]
# cat /proc/net/udp
sl local_address rem_address st tx_queue rx_queue tr tm->when retrnsmt uid timeout inode ref pointer drops
42: 00000000:7B2A 00000000:0000 07 FFFFFFB0:00000000 00:00000000 00000000 65534 0 6239 2 816bb760 1
53: 00000000:0035 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 1476 2 81b6e440 0
67: 00000000:0043 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 1471 2 81b6e220 0
76: 00000000:1B4C 00000000:0000 07 FFFFFFB0:00000000 00:00000000 00000000 65534 0 6225 2 816bacc0 1
95: 00000000:165F 00000000:0000 07 FFFFFFB0:00000000 00:00000000 00000000 65534 0 6221 2 816ba880 1
101: 0A34182E:AE65 0A320014:06A5 01 00000000:00000000 00:00000000 00000000 0 0 1538 4 81b6ecc0 0
123: 00000000:007B 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 1530 2 81b6e880 0
126: 00000000:847E 00000000:0000 07 FFFFFFB0:00000000 00:00000000 00000000 65534 0 6223 2 816baaa0 1
153: 00000000:CF99 00000000:0000 07 FFFFFFB0:00000000 00:00000000 00000000 65534 0 6233 2 816bb540 1
163: 00000000:09A3 00000000:0000 07 FFFFFFB0:00000000 00:00000000 00000000 65534 0 6227 2 816baee0 1
165: 00000000:06A5 00000000:0000 07 00000000:00000000 00:00000000 00000000 0 0 1523 2 81b6e660 0
184: 00000000:70B8 00000000:0000 07 FFFFFFB0:00000000 00:00000000 00000000 65534 0 6231 2 816bb320 1
226: 00000000:CCE2 00000000:0000 07 FFFFFFB0:00000000 00:00000000 00000000 65534 0 6229 2 816bb100 1
[-- Attachment #2: Type: application/pgp-signature, Size: 198 bytes --]
^ permalink raw reply [flat|nested] 16+ messages in thread
* Re: [BUG] Kernel recieves DNS reply, but doesn't deliver it to a waiting application
2013-02-04 13:39 ` Andrew Savchenko
@ 2013-02-04 15:21 ` Eric Dumazet
0 siblings, 0 replies; 16+ messages in thread
From: Eric Dumazet @ 2013-02-04 15:21 UTC (permalink / raw)
To: Andrew Savchenko; +Cc: netdev
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.
^ permalink raw reply [flat|nested] 16+ messages in thread
end of thread, other threads:[~2013-02-04 15:21 UTC | newest]
Thread overview: 16+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2012-10-03 19:25 Kernel recieves DNS reply, but doesn't deliver it to a waiting application Andrew Savchenko
2012-10-13 12:36 ` [BUG] " Andrew Savchenko
2012-10-13 13:44 ` Eric Dumazet
2012-10-13 23:11 ` Andrew Savchenko
2012-10-20 23:25 ` Andrew Savchenko
2012-10-21 12:52 ` Eric Dumazet
2012-10-22 3:36 ` Andrew Savchenko
2012-10-22 6:48 ` Eric Dumazet
2012-10-22 21:27 ` Andrew Savchenko
2012-12-12 8:27 ` Andrew Savchenko
2012-12-23 11:06 ` Andrew Savchenko
2012-12-28 18:11 ` Eric Dumazet
2013-01-16 16:36 ` Andrew Savchenko
2013-02-04 13:39 ` Andrew Savchenko
2013-02-04 15:21 ` Eric Dumazet
2012-11-23 7:45 ` Andrew Savchenko
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).