ing_filter debug messages

ing_filter debug messages

[Wichert Akkerman]

After upgrading a machine to (unpatched mainline) 2.6.10 my kernel log
is filled with ing_filter (debug?) messages:

Dec 30 16:24:58 thunder kernel: ing_filter:  fixed  eth1 out eth1
Dec 30 16:24:58 thunder kernel: ing_filter:  fixed  eth1 out eth1
Dec 30 16:37:08 thunder kernel: ing_filter:  fixed  eth1 out eth1
Dec 30 16:37:08 thunder kernel: ing_filter:  fixed  eth1 out eth1
Dec 30 16:49:08 thunder kernel: ing_filter:  fixed  eth1 out eth1
Dec 30 16:49:08 thunder kernel: ing_filter:  fixed  eth1 out eth1
Dec 30 17:01:08 thunder kernel: ing_filter:  fixed  eth1 out eth1
Dec 30 17:01:08 thunder kernel: ing_filter:  fixed  eth1 out eth1

the messages always come in pairs. eth1 is the externel interface which
has a standard wondershaper configuration attached to it. Relevant bits
of .config are below.

Wichert.


#
# QoS and/or fair queueing
#
CONFIG_NET_SCHED=y
CONFIG_NET_SCH_CLK_JIFFIES=y
# CONFIG_NET_SCH_CLK_GETTIMEOFDAY is not set
# CONFIG_NET_SCH_CLK_CPU is not set
CONFIG_NET_SCH_CBQ=y
CONFIG_NET_SCH_HTB=y
# CONFIG_NET_SCH_HFSC is not set
# CONFIG_NET_SCH_PRIO is not set
# CONFIG_NET_SCH_RED is not set
CONFIG_NET_SCH_SFQ=y
# CONFIG_NET_SCH_TEQL is not set
CONFIG_NET_SCH_TBF=y
# CONFIG_NET_SCH_GRED is not set
# CONFIG_NET_SCH_DSMARK is not set
# CONFIG_NET_SCH_NETEM is not set
CONFIG_NET_SCH_INGRESS=y
CONFIG_NET_QOS=y
CONFIG_NET_ESTIMATOR=y
CONFIG_NET_CLS=y
CONFIG_NET_CLS_TCINDEX=y
CONFIG_NET_CLS_ROUTE4=y
CONFIG_NET_CLS_ROUTE=y
CONFIG_NET_CLS_FW=y
CONFIG_NET_CLS_U32=y
# CONFIG_CLS_U32_PERF is not set
# CONFIG_NET_CLS_IND is not set
CONFIG_NET_CLS_RSVP=y
CONFIG_NET_CLS_RSVP6=y
CONFIG_NET_CLS_ACT=y
CONFIG_NET_ACT_POLICE=y
CONFIG_NET_ACT_GACT=y
CONFIG_GACT_PROB=y
CONFIG_NET_ACT_MIRRED=y
CONFIG_NET_ACT_IPT=y
CONFIG_NET_ACT_PEDIT=y


-- 
Wichert Akkerman <wichert@wiggy.net>    It is simple to make things.
http://www.wiggy.net/                   It is hard to make things simple.

Re: ing_filter debug messages

[jamal]

The emssage is useful but debug (mostly). 
Whats your ifconfig look like? Have some tunnels in there maybe?
Whats your netfilter setup? 

cheers,
jamal

On Thu, 2004-12-30 at 11:06, Wichert Akkerman wrote:
> After upgrading a machine to (unpatched mainline) 2.6.10 my kernel log
> is filled with ing_filter (debug?) messages:
> 
> Dec 30 16:24:58 thunder kernel: ing_filter:  fixed  eth1 out eth1
> Dec 30 16:24:58 thunder kernel: ing_filter:  fixed  eth1 out eth1
> Dec 30 16:37:08 thunder kernel: ing_filter:  fixed  eth1 out eth1
> Dec 30 16:37:08 thunder kernel: ing_filter:  fixed  eth1 out eth1
> Dec 30 16:49:08 thunder kernel: ing_filter:  fixed  eth1 out eth1
> Dec 30 16:49:08 thunder kernel: ing_filter:  fixed  eth1 out eth1
> Dec 30 17:01:08 thunder kernel: ing_filter:  fixed  eth1 out eth1
> Dec 30 17:01:08 thunder kernel: ing_filter:  fixed  eth1 out eth1
> 
> the messages always come in pairs. eth1 is the externel interface which
> has a standard wondershaper configuration attached to it. Relevant bits
> of .config are below.
> 
> Wichert.
> 
> 
> #
> # QoS and/or fair queueing
> #
> CONFIG_NET_SCHED=y
> CONFIG_NET_SCH_CLK_JIFFIES=y
> # CONFIG_NET_SCH_CLK_GETTIMEOFDAY is not set
> # CONFIG_NET_SCH_CLK_CPU is not set
> CONFIG_NET_SCH_CBQ=y
> CONFIG_NET_SCH_HTB=y
> # CONFIG_NET_SCH_HFSC is not set
> # CONFIG_NET_SCH_PRIO is not set
> # CONFIG_NET_SCH_RED is not set
> CONFIG_NET_SCH_SFQ=y
> # CONFIG_NET_SCH_TEQL is not set
> CONFIG_NET_SCH_TBF=y
> # CONFIG_NET_SCH_GRED is not set
> # CONFIG_NET_SCH_DSMARK is not set
> # CONFIG_NET_SCH_NETEM is not set
> CONFIG_NET_SCH_INGRESS=y
> CONFIG_NET_QOS=y
> CONFIG_NET_ESTIMATOR=y
> CONFIG_NET_CLS=y
> CONFIG_NET_CLS_TCINDEX=y
> CONFIG_NET_CLS_ROUTE4=y
> CONFIG_NET_CLS_ROUTE=y
> CONFIG_NET_CLS_FW=y
> CONFIG_NET_CLS_U32=y
> # CONFIG_CLS_U32_PERF is not set
> # CONFIG_NET_CLS_IND is not set
> CONFIG_NET_CLS_RSVP=y
> CONFIG_NET_CLS_RSVP6=y
> CONFIG_NET_CLS_ACT=y
> CONFIG_NET_ACT_POLICE=y
> CONFIG_NET_ACT_GACT=y
> CONFIG_GACT_PROB=y
> CONFIG_NET_ACT_MIRRED=y
> CONFIG_NET_ACT_IPT=y
> CONFIG_NET_ACT_PEDIT=y
> 

Re: ing_filter debug messages

[Wichert Akkerman]

Previously jamal wrote:
> The emssage is useful but debug (mostly). 
> Whats your ifconfig look like? Have some tunnels in there maybe?

three ethernet interfaces and a ipv6/ip tunnel. Here is the ifconfig
output:

eth0      Link encap:Ethernet  HWaddr 00:50:04:0B:DD:79
          inet addr:192.168.10.1  Bcast:192.168.10.255  Mask:255.255.255.0
          inet6 addr: fe80::250:4ff:fe0b:dd79/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:673540 errors:0 dropped:0 overruns:0 frame:0
          TX packets:668357 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:229549898 (218.9 MiB)  TX bytes:465650601 (444.0 MiB)
          Interrupt:11 Base address:0xec00

eth1      Link encap:Ethernet  HWaddr 00:90:27:BE:60:55
          inet addr:194.109.254.66  Bcast:255.255.255.255  Mask:255.255.255.0
          inet6 addr: fe80::290:27ff:febe:6055/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:1276385 errors:0 dropped:0 overruns:0 frame:0
          TX packets:1172898 errors:0 dropped:0 overruns:0 carrier:0
          collisions:1128 txqueuelen:1000
          RX bytes:1332651102 (1.2 GiB)  TX bytes:293617934 (280.0 MiB)

eth2      Link encap:Ethernet  HWaddr 00:90:27:BE:4B:EC
          inet addr:192.168.1.1  Bcast:192.168.1.255  Mask:255.255.255.0
          inet6 addr: 2001:888:101d::1/64 Scope:Global
          inet6 addr: fe80::290:27ff:febe:4bec/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:713928 errors:0 dropped:0 overruns:0 frame:0
          TX packets:752929 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000
          RX bytes:111560554 (106.3 MiB)  TX bytes:860040830 (820.1 MiB)

lo        Link encap:Local Loopback
          inet addr:127.0.0.1  Mask:255.0.0.0
          inet6 addr: ::1/128 Scope:Host
          UP LOOPBACK RUNNING  MTU:16436  Metric:1
          RX packets:33261 errors:0 dropped:0 overruns:0 frame:0
          TX packets:33261 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0
          RX bytes:3401641 (3.2 MiB)  TX bytes:3401641 (3.2 MiB)

xs4all    Link encap:IPv6-in-IPv4
          inet6 addr: 2001:888:10:1d::2/64 Scope:Global
          inet6 addr: fe80::c26d:fe42/64 Scope:Link
          inet6 addr: fe80::c0a8:a01/64 Scope:Link
          inet6 addr: fe80::c0a8:102/64 Scope:Link
          inet6 addr: fe80::c0a8:101/64 Scope:Link
          UP POINTOPOINT RUNNING NOARP  MTU:1480  Metric:1
          RX packets:128 errors:0 dropped:0 overruns:0 frame:0
          TX packets:116 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0
          RX bytes:95545 (93.3 KiB)  TX bytes:19613 (19.1 KiB)

there is also a secondary address on eth2 which ifconfig does not show.

> Whats your netfilter setup? 

One chain attached to the FORWARD chain and two to the OUTPUT chain,
all pretty simple.

Wichert.

-- 
Wichert Akkerman <wichert@wiggy.net>    It is simple to make things.
http://www.wiggy.net/                   It is hard to make things simple.

Re: ing_filter debug messages

[jamal]

[-- Attachment #1: Type: text/plain, Size: 3271 bytes --]

The sit tunnel is on top of eth1?
Does attached patch fix it?

cheers,
jamal

On Fri, 2004-12-31 at 04:38, Wichert Akkerman wrote:
> Previously jamal wrote:
> > The emssage is useful but debug (mostly). 
> > Whats your ifconfig look like? Have some tunnels in there maybe?
> 
> three ethernet interfaces and a ipv6/ip tunnel. Here is the ifconfig
> output:
> 
> eth0      Link encap:Ethernet  HWaddr 00:50:04:0B:DD:79
>           inet addr:192.168.10.1  Bcast:192.168.10.255  Mask:255.255.255.0
>           inet6 addr: fe80::250:4ff:fe0b:dd79/64 Scope:Link
>           UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
>           RX packets:673540 errors:0 dropped:0 overruns:0 frame:0
>           TX packets:668357 errors:0 dropped:0 overruns:0 carrier:0
>           collisions:0 txqueuelen:1000
>           RX bytes:229549898 (218.9 MiB)  TX bytes:465650601 (444.0 MiB)
>           Interrupt:11 Base address:0xec00
> 
> eth1      Link encap:Ethernet  HWaddr 00:90:27:BE:60:55
>           inet addr:194.109.254.66  Bcast:255.255.255.255  Mask:255.255.255.0
>           inet6 addr: fe80::290:27ff:febe:6055/64 Scope:Link
>           UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
>           RX packets:1276385 errors:0 dropped:0 overruns:0 frame:0
>           TX packets:1172898 errors:0 dropped:0 overruns:0 carrier:0
>           collisions:1128 txqueuelen:1000
>           RX bytes:1332651102 (1.2 GiB)  TX bytes:293617934 (280.0 MiB)
> 
> eth2      Link encap:Ethernet  HWaddr 00:90:27:BE:4B:EC
>           inet addr:192.168.1.1  Bcast:192.168.1.255  Mask:255.255.255.0
>           inet6 addr: 2001:888:101d::1/64 Scope:Global
>           inet6 addr: fe80::290:27ff:febe:4bec/64 Scope:Link
>           UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
>           RX packets:713928 errors:0 dropped:0 overruns:0 frame:0
>           TX packets:752929 errors:0 dropped:0 overruns:0 carrier:0
>           collisions:0 txqueuelen:1000
>           RX bytes:111560554 (106.3 MiB)  TX bytes:860040830 (820.1 MiB)
> 
> lo        Link encap:Local Loopback
>           inet addr:127.0.0.1  Mask:255.0.0.0
>           inet6 addr: ::1/128 Scope:Host
>           UP LOOPBACK RUNNING  MTU:16436  Metric:1
>           RX packets:33261 errors:0 dropped:0 overruns:0 frame:0
>           TX packets:33261 errors:0 dropped:0 overruns:0 carrier:0
>           collisions:0 txqueuelen:0
>           RX bytes:3401641 (3.2 MiB)  TX bytes:3401641 (3.2 MiB)
> 
> xs4all    Link encap:IPv6-in-IPv4
>           inet6 addr: 2001:888:10:1d::2/64 Scope:Global
>           inet6 addr: fe80::c26d:fe42/64 Scope:Link
>           inet6 addr: fe80::c0a8:a01/64 Scope:Link
>           inet6 addr: fe80::c0a8:102/64 Scope:Link
>           inet6 addr: fe80::c0a8:101/64 Scope:Link
>           UP POINTOPOINT RUNNING NOARP  MTU:1480  Metric:1
>           RX packets:128 errors:0 dropped:0 overruns:0 frame:0
>           TX packets:116 errors:0 dropped:0 overruns:0 carrier:0
>           collisions:0 txqueuelen:0
>           RX bytes:95545 (93.3 KiB)  TX bytes:19613 (19.1 KiB)
> 
> there is also a secondary address on eth2 which ifconfig does not show.
> 
> > Whats your netfilter setup? 
> 
> One chain attached to the FORWARD chain and two to the OUTPUT chain,
> all pretty simple.
> 
> Wichert.

[-- Attachment #2: sit-p --]
[-- Type: text/plain, Size: 341 bytes --]

--- a/net/ipv6/sit.c	2004/12/31 11:03:32	1.1
+++ b/net/ipv6/sit.c	2004/12/31 11:06:50
@@ -385,7 +385,7 @@
 		skb->pkt_type = PACKET_HOST;
 		tunnel->stat.rx_packets++;
 		tunnel->stat.rx_bytes += skb->len;
-		skb->dev = tunnel->dev;
+		skb->input_dev = skb->dev = tunnel->dev;
 		dst_release(skb->dst);
 		skb->dst = NULL;
 		nf_reset(skb);

Re: ing_filter debug messages

[Wichert Akkerman]

Previously jamal wrote:
> The sit tunnel is on top of eth1?

Yes.

> Does attached patch fix it?

I'll give it a spin later today, have to figure out what to make for
dinner tonight and do the associated shopping first :)

Wichert.

-- 
Wichert Akkerman <wichert@wiggy.net>    It is simple to make things.
http://www.wiggy.net/                   It is hard to make things simple.

Re: ing_filter debug messages

[Wichert Akkerman]

Previously jamal wrote:
> Does attached patch fix it?

No change at all I'm afraid . While rebooting to the kernel with that
patch applied it got stuck in the shutdown sequence while repeating this
line:

unregister_netdevice: waiting for xs4all for become free, Usage count = 1

Wichert.

-- 
Wichert Akkerman <wichert@wiggy.net>    It is simple to make things.
http://www.wiggy.net/                   It is hard to make things simple.

Re: ing_filter debug messages

[jamal]

On Fri, 2004-12-31 at 08:15, Wichert Akkerman wrote:
> Previously jamal wrote:
> > Does attached patch fix it?
> 
> No change at all I'm afraid . While rebooting to the kernel with that
> patch applied it got stuck in the shutdown sequence while repeating this
> line:
> 
> unregister_netdevice: waiting for xs4all for become free, Usage count = 1

I doubt this has anything to do with what i sent you. What i sent you is
certainly needed. Let me poke around for a few minutes - I am begining
to think theres a relation; the only way to be sure is to compile out
netfilter.

cheers,
jamal

Re: ing_filter debug messages

[jamal]

[-- Attachment #1: Type: text/plain, Size: 96 bytes --]

Wichert,
Try also the attached patch with netfilter on and your rules installed.

cheers,
jamal

[-- Attachment #2: indev2-p --]
[-- Type: text/plain, Size: 591 bytes --]

--- a/net/ipv4/ip_output.c	2004/12/31 14:26:08	1.1
+++ b/net/ipv4/ip_output.c	2004/12/31 14:27:53
@@ -111,6 +111,7 @@
 #ifdef CONFIG_NETFILTER_DEBUG
 	nf_debug_ip_loopback_xmit(newskb);
 #endif
+	newskb->input_dev = newskb->dev;
 	netif_rx(newskb);
 	return 0;
 }
--- a/net/ipv6/ip6_output.c	2004-12-24 16:33:51.000000000 -0500
+++ b/net/ipv6/ip6_output.c	2004-12-31 10:29:47.505392096 -0500
@@ -102,7 +102,7 @@
 	newskb->pkt_type = PACKET_LOOPBACK;
 	newskb->ip_summed = CHECKSUM_UNNECESSARY;
 	BUG_TRAP(newskb->dst);
-
+	newskb->input_dev = newskb->dev;
 	netif_rx(newskb);
 	return 0;
 }

Re: ing_filter debug messages

[Wichert Akkerman]

Previously jamal wrote:
> Try also the attached patch with netfilter on and your rules installed.

That seems to do the trick: I no longer see the debug messages appear.
The tunnel still works as well.

However, the unregister_netdev problem still persists.

Wichert.

-- 
Wichert Akkerman <wichert@wiggy.net>    It is simple to make things.
http://www.wiggy.net/                   It is hard to make things simple.

unregister_netdev Annoyance WAS(Re: ing_filter debug messages

[jamal]

On Fri, 2004-12-31 at 10:48, Wichert Akkerman wrote:
> Previously jamal wrote:
> > Try also the attached patch with netfilter on and your rules installed.
> 
> That seems to do the trick: I no longer see the debug messages appear.
> The tunnel still works as well.
> 
> However, the unregister_netdev problem still persists.

I am pretty sure its a different problem. Quick scan shows the
register/unregister state machine may be at fault. 
Just changed the subject because there have been threads on this topic
that other people have been discussing that i havent followed.
Lets see if this gets their attention - If it doesnt i will poke around.

cheers,
jamal

Re: unregister_netdev Annoyance WAS(Re: ing_filter debug messages

[Andre Tomt]

jamal wrote:
> On Fri, 2004-12-31 at 10:48, Wichert Akkerman wrote:
> 
>>Previously jamal wrote:
>>
>>>Try also the attached patch with netfilter on and your rules installed.
>>
>>That seems to do the trick: I no longer see the debug messages appear.
>>The tunnel still works as well.
>>
>>However, the unregister_netdev problem still persists.
> 
> 
> I am pretty sure its a different problem. Quick scan shows the
> register/unregister state machine may be at fault. 
> Just changed the subject because there have been threads on this topic
> that other people have been discussing that i havent followed.
> Lets see if this gets their attention - If it doesnt i will poke around.

Just had this happen on a router yesterday, while booting for testing a 
netfilter bugfix. The dot1q VLAN interfaces got stuck waiting to become 
free on ifdown (part of the system shutdown process in this case)

There have been several such bugs in recent 2.6 kernel versions, and 
several refcounting leaks have been plugged since, but somehow it keeps 
coming back to hunt me from time to time. I'm about to disable ifdown -a 
on shutdown, but I find that a rather silly workaround to such a problem ;-)

Kernel is 2.6.10, ipv6 and ip_conntrack loaded, running 
zebra/ospfd/ospf6d. ipip and sch/cls modules loaded, but currently not 
in use (and wasn't since boot)

# lsmod
Module                  Size  Used by
dm_mod                 44668  0
sch_htb                18816  0
sch_sfq                 4480  0
cls_u32                 6788  0
softdog                 4368  0
ip6table_filter         2048  1
ip6t_limit              1920  0
ip6t_LOG                5888  0
ip6_tables             14976  3 ip6table_filter,ip6t_limit,ip6t_LOG
ip_conntrack_irc       70320  0
ip_conntrack_ftp       70960  0
iptable_filter          2944  1
ipt_limit               1920  6
ipt_REJECT              5120  2
ipt_LOG                 5376  3
ipt_state               1536  252
ip_conntrack           34164  3 ip_conntrack_irc,ip_conntrack_ftp,ipt_state
ip_tables              14336  5 
iptable_filter,ipt_limit,ipt_REJECT,ipt_LOG,ipt_state
ipip                    7396  0
xfrm4_tunnel            2820  1 ipip
8021q                  14728  0
8139too                17664  0
mii                     3712  1 8139too
crc32                   3968  1 8139too
ipv6                  189568  23
rtc                     8760  0
af_packet              14344  0
unix                   19124  145
ext3                   99208  6
jbd                    41496  1 ext3
mbcache                 5636  1 ext3

# cat /etc/sysctl.conf
#
# /etc/sysctl.conf - Configuration file for setting system variables
# See sysctl.conf (5) for information.

net.ipv4.icmp_ignore_bogus_error_responses=1
net.ipv4.icmp_echo_ignore_broadcasts=1

net.ipv4.conf.default.send_redirects=0
net.ipv4.conf.default.accept_redirects=0
net.ipv4.conf.default.secure_redirects=0
net.ipv4.conf.default.shared_media=0

net.ipv6.conf.default.forwarding=1
net.ipv6.conf.default.accept_ra=0
net.ipv6.conf.default.accept_redirects=0
net.ipv6.conf.default.autoconf=0
net.ipv6.conf.default.router_solicitations=0

net.ipv6.conf.all.forwarding=1
net.ipv6.conf.all.accept_ra=0
net.ipv6.conf.all.accept_redirects=0
net.ipv6.conf.all.autoconf=0
net.ipv6.conf.all.router_solicitations=0

kernel.panic=60
kernel.panic_on_oops=1

vm.overcommit_memory=2

net.ipv4.netfilter.ip_conntrack_max=131072
net.ipv4.netfilter.ip_conntrack_log_invalid=6

Re: unregister_netdev Annoyance WAS(Re: ing_filter debug messages

[bert hubert]

> > However, the unregister_netdev problem still persists.
> 
> I am pretty sure its a different problem. Quick scan shows the
> register/unregister state machine may be at fault. 

This is a separate and known problem - see 'Re: Major deadlock:
unregister_netdevice: waiting for <device> to become free. Usage count = 1'
by Peter Bieringer.

For some reason this issue has been widely ignored. I see it as well here
and it is the one reason I don't entirely trust 2.6.10 yet in production.

Thanks for looking into it Jamal!

-- 
http://www.PowerDNS.com      Open source, database driven DNS Software 
http://lartc.org           Linux Advanced Routing & Traffic Control HOWTO

Re: unregister_netdev Annoyance WAS(Re: ing_filter debug messages

[jamal]

On Sun, 2005-01-02 at 07:13, bert hubert wrote:

> This is a separate and known problem - see 'Re: Major deadlock:
> unregister_netdevice: waiting for <device> to become free. Usage count = 1'
> by Peter Bieringer.
> 
> For some reason this issue has been widely ignored. I see it as well here
> and it is the one reason I don't entirely trust 2.6.10 yet in production.
> 
> Thanks for looking into it Jamal!

This issue was already being looked into by about 3 people {Dave,
Yoshfuji-san, Herbert}. They have more knowledge about the circumstances
than i do. The holidays are over, so give it a short time and lets see
what happens.

cheers,
jamal