route add default fails with ESRCH?

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

[ Expanded cc ]

I git bisected the problem to this commit:

commit 3630b7c050d9c3564f143d595339fc06b888d6f3
Author: David S. Miller <[email protected]>
Date: Tue Feb 1 15:15:39 2011 -0800

ipv4: Remove fib_hash.

which came in via 2.6.39.

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

[   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

Hello,

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

Where is "Main:" here?

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 <[email protected]>

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.

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.

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

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

From: Arun Sharma <[email protected]>
Date: Wed, 22 Feb 2012 15:03:11 -0800

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.

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

Hello,

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.

	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 <[email protected]>