route add default fails with ESRCH?

route add default fails with ESRCH?

[Arun Sharma]

I've been trying to debug this strange problem with recent 3.2 kernels:

# boot to single user mode
# service network start
# ifconfig eth0
eth0      Link encap:Ethernet  HWaddr <blah>
           inet addr:10.47.46.39  Bcast:10.47.46.255  Mask:255.255.255.0

<Link is up>
# strace route add default gw 10.47.46.1
ioctl(3, SIOCADDRT, 0x7fff1fd4db80)     = -1 ESRCH (No such process)

Couple of data points:

* This didn't happen with 2.6.3x kernels
* This doesn't happen on all machines. Only a small subset

I tried to debug using perf probe points:

# cmdline : /usr/bin/perf record -e 
probe:fib_get_table,probe:fib_new_table,probe:fib_table_insert route add 
default gw 10.47.46.1

            route  7800 [001]  4170.916261: fib_get_table: 
(ffffffff81406528 <- ffffffff814065a6) ret=ffff8802142605c0
            route  7800 [001]  4170.916265: fib_get_table: 
(ffffffff81406528 <- ffffffff814067d3) ret=ffff880212a36680
            route  7800 [001]  4170.916266: fib_new_table: 
(ffffffff814067b6 <- ffffffff81406f04) ret=ffff880212a36680
            route  7800 [001]  4170.916270: fib_get_table: 
(ffffffff81406528 <- ffffffff8140d7fa) ret=ffff8802142605c0
            route  7800 [001]  4170.916271: fib_get_table: 
(ffffffff81406528 <- ffffffff8140d7fa) ret=ffff880212a36680
            route  7800 [001]  4170.916272: fib_get_table: 
(ffffffff81406528 <- ffffffff8140d7fa) ret=0
            route  7800 [001]  4170.916273: fib_table_insert: 
(ffffffff8140a60f <- ffffffff81406f18) ret=fffffffd

Any ideas on why fib_table_insert() is failing with -ESRCH?

  -Arun

Re: route add default fails with ESRCH?

[Arun Sharma]

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

[ Expanded cc ]

On 2/17/12 5:39 PM, Arun Sharma wrote:
>
> I've been trying to debug this strange problem with recent 3.2 kernels:
>
> # boot to single user mode
> # service network start
> # ifconfig eth0
> eth0 Link encap:Ethernet HWaddr <blah>
> inet addr:10.47.46.39 Bcast:10.47.46.255 Mask:255.255.255.0
>
> <Link is up>
> # strace route add default gw 10.47.46.1
> ioctl(3, SIOCADDRT, 0x7fff1fd4db80) = -1 ESRCH (No such process)

I git bisected the problem to this commit:

commit 3630b7c050d9c3564f143d595339fc06b888d6f3
Author: David S. Miller <davem@davemloft.net>
Date: Tue Feb 1 15:15:39 2011 -0800

ipv4: Remove fib_hash.

which came in via 2.6.39.

 > If there are any semantic differences found in fib_trie, we should
 > simply fix them.

Looks like the problem I'm running into falls into this bucket (since it 
goes away if I revert the commit).

I changed the pr_debug() in fib_trie.c to pr_info() and got some debug 
output (attached).

Based on the debug info, I think it's this call that's failing with ESRCH:

[   69.189627] Insert table=254 00000000/0

/sbin/route -V
net-tools 1.60
route 1.98 (2001-04-15)

# cat /proc/net/fib_trie
Local:
   +-- 0.0.0.0/1 1 0 0
      +-- 10.47.46.0/24 1 0 0
         +-- 10.47.46.0/26 1 0 0
            |-- 10.47.46.0
               /32 link BROADCAST
            |-- 10.47.46.39
               /32 host LOCAL
         |-- 10.47.46.255
            /32 link BROADCAST
      +-- 127.0.0.0/8 1 0 0
         +-- 127.0.0.0/31 1 0 0
            |-- 127.0.0.0
               /32 link BROADCAST
               /8 host LOCAL
            |-- 127.0.0.1
               /32 host LOCAL
         |-- 127.255.255.255
            /32 link BROADCAST

Please let me know if you have any suggestions.

  -Arun

[-- Attachment #2: fib_debug.txt --]
[-- Type: text/plain, Size: 4073 bytes --]

[   17.445984] Insert table=255 7f000001/32
[   17.445993] AT ffff880213d0ae40 s=56 32
[   17.445997] In tnode_resize ffff880213d0ae40 inflate_threshold=50 threshold=25
[   17.446014] Insert table=255 7f000000/8
[   17.446024] AT ffff880213d0ade0 s=56 32
[   17.446026] In tnode_resize ffff880213d0ade0 inflate_threshold=50 threshold=25
[   17.446030] Insert table=255 7f000000/32
[   17.446035] Insert table=255 7fffffff/32
[   17.446038] AT ffff880213d0ad20 s=56 32
[   17.446040] In tnode_resize ffff880213d0ad20 inflate_threshold=50 threshold=25
[   17.446941] Insert table=255 7f000001/32
[   17.446944] Insert table=255 7f000000/8
[   17.446946] Insert table=255 7f000000/32
[   17.446948] Insert table=255 7fffffff/32
[   37.708794] e1000e 0000:05:00.0: irq 66 for MSI/MSI-X
[   37.761305] e1000e 0000:05:00.0: irq 66 for MSI/MSI-X
[   37.763389] ADDRCONF(NETDEV_UP): eth0: link is not ready
[   40.643385] e1000e: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
[   40.644668] ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   44.040787] Insert table=255 0a2f2e27/32
[   44.040798] AT ffff880213d45960 s=56 32
[   44.040800] In tnode_resize ffff880213d45960 inflate_threshold=50 threshold=25
[   44.040807] Insert table=255 0affffff/32
[   44.040811] AT ffff880213d45a20 s=56 32
[   44.040813] In tnode_resize ffff880213d45960 inflate_threshold=50 threshold=25
[   44.040817] Insert table=254 0a000000/8
[   44.040821] AT ffff880213d45840 s=56 32
[   44.040823] In tnode_resize ffff880213d45840 inflate_threshold=50 threshold=25
[   44.040827] Insert table=255 0a000000/32
[   44.040830] AT ffff880213d457e0 s=56 32
[   44.040831] In tnode_resize ffff880213d45a20 inflate_threshold=50 threshold=25
[   44.040833] In tnode_resize ffff880213d45960 inflate_threshold=50 threshold=25
[   44.040837] Insert table=255 0affffff/32
[   44.040886] Deleting 0a000000/8 tos=0 t=ffff880212b846a0
[   44.040889] entering trie_leaf_remove(ffff880211585070)
[   44.040891] Deleting 0affffff/32 tos=0 t=ffff880213d07d20
[   44.040894] entering trie_leaf_remove(ffff880211585038)
[   44.040895] In tnode_resize ffff880213d45a20 inflate_threshold=50 threshold=25
[   44.040897] In tnode_resize ffff880213d45960 inflate_threshold=50 threshold=25
[   44.040900] Deleting 0a000000/32 tos=0 t=ffff880213d07d20
[   44.040902] entering trie_leaf_remove(ffff8802115850a8)
[   44.040904] In tnode_resize ffff880213d457e0 inflate_threshold=50 threshold=25
[   44.040906] In tnode_resize ffff880213d45960 inflate_threshold=50 threshold=25
[   44.040908] Deleting 0a2f2e27/32 tos=0 t=ffff880213d07d20
[   44.040910] entering trie_leaf_remove(ffff880211585000)
[   44.040912] In tnode_resize ffff880213d45960 inflate_threshold=50 threshold=25
[   44.041833] Insert table=255 0a2f2e27/32
[   44.041835] AT ffff880213d45ae0 s=56 32
[   44.041837] In tnode_resize ffff880213d45ae0 inflate_threshold=50 threshold=25
[   44.041841] Insert table=255 0a2f2eff/32
[   44.041844] AT ffff880213d45720 s=56 32
[   44.041846] In tnode_resize ffff880213d45ae0 inflate_threshold=50 threshold=25
[   44.041849] Insert table=254 0a2f2e00/24
[   44.041852] AT ffff880213d45a80 s=56 32
[   44.041854] In tnode_resize ffff880213d45a80 inflate_threshold=50 threshold=25
[   44.041857] Insert table=255 0a2f2e00/32
[   44.041860] AT ffff880213d456c0 s=56 32
[   44.041862] In tnode_resize ffff880213d45720 inflate_threshold=50 threshold=25
[   44.041864] In tnode_resize ffff880213d45ae0 inflate_threshold=50 threshold=25
[   44.041868] Insert table=255 0a2f2eff/32
[   44.050950] Insert table=254 00000000/0
[   44.050961] AT ffff880213d0a5a0 s=56 32
[   44.050963] In tnode_resize ffff880213d0a5a0 inflate_threshold=50 threshold=25
[   44.351839] Deleting 00000000/0 tos=0 t=ffff880212b846a0
[   44.351843] entering trie_leaf_remove(ffff880213d120e0)
[   44.351846] In tnode_resize ffff880213d0a5a0 inflate_threshold=50 threshold=25
[   44.351852] Deleting 0a2f2e00/24 tos=0 t=ffff880212b846a0
[   44.351855] entering trie_leaf_remove(ffff880211585150)
[   69.189627] Insert table=254 00000000/0

Re: route add default fails with ESRCH?

[Julian Anastasov]

	Hello,

On Wed, 22 Feb 2012, Arun Sharma wrote:

> [ Expanded cc ]
> 
> On 2/17/12 5:39 PM, Arun Sharma wrote:
> > 
> > I've been trying to debug this strange problem with recent 3.2 kernels:
> > 
> > # boot to single user mode
> > # service network start
> > # ifconfig eth0
> > eth0 Link encap:Ethernet HWaddr <blah>
> > inet addr:10.47.46.39 Bcast:10.47.46.255 Mask:255.255.255.0
> > 
> > <Link is up>
> > # strace route add default gw 10.47.46.1
> > ioctl(3, SIOCADDRT, 0x7fff1fd4db80) = -1 ESRCH (No such process)
> 
> I git bisected the problem to this commit:
> 
> commit 3630b7c050d9c3564f143d595339fc06b888d6f3
> Author: David S. Miller <davem@davemloft.net>
> Date: Tue Feb 1 15:15:39 2011 -0800
> 
> ipv4: Remove fib_hash.
> 
> which came in via 2.6.39.
> 
> > If there are any semantic differences found in fib_trie, we should
> > simply fix them.
> 
> Looks like the problem I'm running into falls into this bucket (since it goes
> away if I revert the commit).
> 
> I changed the pr_debug() in fib_trie.c to pr_info() and got some debug output
> (attached).
> 
> Based on the debug info, I think it's this call that's failing with ESRCH:

	Why the subnet is deleted from table main (254) in
the same second ?

	First default route is removed:

[   44.351839] Deleting 00000000/0 tos=0 t=ffff880212b846a0
[   44.351843] entering trie_leaf_remove(ffff880213d120e0)
[   44.351846] In tnode_resize ffff880213d0a5a0 inflate_threshold=50
threshold=25

	Then link route 10.47.46.0/24:

[   44.351852] Deleting 0a2f2e00/24 tos=0 t=ffff880212b846a0
[   44.351855] entering trie_leaf_remove(ffff880211585150)

	Insert tries to find if GW 10.47.46.1 is reachable,
there must be 10.47.46.0/24 in table main but it was
deleted just before adding the IP.

[   69.189627] Insert table=254 00000000/0

> [   69.189627] Insert table=254 00000000/0
> 
> /sbin/route -V
> net-tools 1.60
> route 1.98 (2001-04-15)
> 
> # cat /proc/net/fib_trie

	Where is "Main:" here?

> Local:
>   +-- 0.0.0.0/1 1 0 0
>      +-- 10.47.46.0/24 1 0 0
>         +-- 10.47.46.0/26 1 0 0
>            |-- 10.47.46.0
>               /32 link BROADCAST
>            |-- 10.47.46.39
>               /32 host LOCAL
>         |-- 10.47.46.255
>            /32 link BROADCAST
>      +-- 127.0.0.0/8 1 0 0
>         +-- 127.0.0.0/31 1 0 0
>            |-- 127.0.0.0
>               /32 link BROADCAST
>               /8 host LOCAL
>            |-- 127.0.0.1
>               /32 host LOCAL
>         |-- 127.255.255.255
>            /32 link BROADCAST
> 
> Please let me know if you have any suggestions.

	The only place that returns ESRCH during insert is
net/core/fib_rules.c fib_rules_lookup(). Are you sure that
some daemon is not monitoring your actions and playing
with the ip rules and routes? May be during 'route add'
there are no ip rules and the link route is removed too.
Is the problem some race with such routing daemon?

Regards

--
Julian Anastasov <ja@ssi.bg>

Re: route add default fails with ESRCH?

[Arun Sharma]

On 2/22/12 1:27 PM, Julian Anastasov wrote:

> 	Why the subnet is deleted from table main (254) in
> the same second ?

The machine was in single user mode. All I did was execute

# service network start

dhclient is the only user process I see running on the system.

>
> 	First default route is removed:
>
> [   44.351839] Deleting 00000000/0 tos=0 t=ffff880212b846a0
> [   44.351843] entering trie_leaf_remove(ffff880213d120e0)
> [   44.351846] In tnode_resize ffff880213d0a5a0 inflate_threshold=50
> threshold=25
>
> 	Then link route 10.47.46.0/24:
>
> [   44.351852] Deleting 0a2f2e00/24 tos=0 t=ffff880212b846a0
> [   44.351855] entering trie_leaf_remove(ffff880211585150)
>
> 	Insert tries to find if GW 10.47.46.1 is reachable,
> there must be 10.47.46.0/24 in table main but it was
> deleted just before adding the IP.
>
> [   69.189627] Insert table=254 00000000/0
>

All of this was done by my network startup scripts. These scripts should 
be fairly standard and used by lots of other people. The only thing 
that's special about my setup is:

# grep LINKDELAY /etc/sysconfig/network
LINKDELAY=20

Without this my eth0 driver complains about link not being ready.

>> # cat /proc/net/fib_trie
>
> 	Where is "Main:" here?

I think answering this is key.

This is the main difference between systems that work and the ones that 
don't. Systems that work have a non-empty Main table:

# cat /proc/net/fib_trie
Main:
   +-- 0.0.0.0/0 4 3 10
      +-- 0.0.0.0/4 1 0 0
         |-- 0.0.0.0
            /0 universe THROW

I'll try to figure out why my RT_TABLE_MAIN was empty after my network 
startup scripts finished. But given my experience with 2.6.38, fib_hash 
handled this case just fine and fib_trie broke it :(

  -Arun

Re: route add default fails with ESRCH?

[Arun Sharma]

On 2/22/12 1:52 PM, Arun Sharma wrote:

> I'll try to figure out why my RT_TABLE_MAIN was empty after my network
> startup scripts finished. But given my experience with 2.6.38, fib_hash
> handled this case just fine and fib_trie broke it :(
>

Turns out that we had a /sbin/ifup-local that deleted all the routes 
including default gw and populated the route afresh.

route del default gw ...
ip route | grep -v scope | awk '{print $1}' | while read route; do ip 
route flush $route; done

This worked fine with fib_hash, but breaks with fib_trie. I'll 
investigate why this was done and look for a workaround if possible.

  -Arun

Re: route add default fails with ESRCH?

[David Miller]

From: Arun Sharma <asharma@fb.com>
Date: Wed, 22 Feb 2012 15:03:11 -0800

> Turns out that we had a /sbin/ifup-local that deleted all the routes
> including default gw and populated the route afresh.
> 
> route del default gw ...
> ip route | grep -v scope | awk '{print $1}' | while read route; do ip
> route flush $route; done
> 
> This worked fine with fib_hash, but breaks with fib_trie. I'll
> investigate why this was done and look for a workaround if possible.

It breaks because that script sequence quoted above depends upon the
order in which the routes are listed.  Since fib_hash and fib_trie use
different datastructures, the order in which route entries are dumped
will not be the same and this is completely unavoidable.

You therefore must not, and can not, have scripts which have such a
dependency.

Re: route add default fails with ESRCH?

[Julian Anastasov]

	Hello,

On Wed, 22 Feb 2012, Arun Sharma wrote:

> Without this my eth0 driver complains about link not being ready.
> 
> > > # cat /proc/net/fib_trie
> > 
> > 	Where is "Main:" here?
> 
> I think answering this is key.

	Main is not printed only when the main table is
empty. The table name is printed only if there are nodes
in the table. May be all rules (ESRCH) and all routes (no Main)
are flushed.

> This is the main difference between systems that work and the ones that don't.
> Systems that work have a non-empty Main table:
> 
> # cat /proc/net/fib_trie
> Main:
>   +-- 0.0.0.0/0 4 3 10
>      +-- 0.0.0.0/4 1 0 0
>         |-- 0.0.0.0
>            /0 universe THROW
> 
> I'll try to figure out why my RT_TABLE_MAIN was empty after my network startup
> scripts finished. But given my experience with 2.6.38, fib_hash handled this
> case just fine and fib_trie broke it :(

	printk for current->comm should show the process name
that removes the routes. If problem is ifup-local I remember
only for one difference: fib_trie can list 0.0.0.0/0 before
other routes but ip route flush default simply removes all
routes, even on old kernels. May be route del default gw...
does not delete the default route and then
'ip route flush default' does the bad job.

Regards

--
Julian Anastasov <ja@ssi.bg>

Re: route add default fails with ESRCH?

[Arun Sharma]

On 2/22/12 3:56 PM, David Miller wrote:
>
> It breaks because that script sequence quoted above depends upon the
> order in which the routes are listed.  Since fib_hash and fib_trie use
> different datastructures, the order in which route entries are dumped
> will not be the same and this is completely unavoidable.

Here's a minimal repro case:

# ip route flush default
# route add default gw 192.168.143.2
SIOCADDRT: No such process

This fails for me on both 2.6.38 and 3.2.

I think the dependency we have is the actual format of the default route 
entry:

fib_hash:

# ip route
<bunch of routes>
throw default

fib_trie:

# ip route
default via 192.168.143.2 dev eth0  proto static
<bunch of routes>

when the output was piped to awk '{ print $1 }' we ended up deleting the 
default route for fib_trie case, but not the fib_hash case.

I'll just fix up our scripts. Thanks for looking into it.

  -Arun