[qpimd-users] Interface mismatch: recv PIM pkt from 192.168.1.6 to 224.0.0.13 on fd=12: recv_ifindex=4 (eth2) sock_ifindex=3 (eth1)

[Andrew Lunn]

2009/04/15 08:06:07 PIM: Scheduling READ event on IGMP socket fd=11
2009/04/15 08:06:07 PIM: Recv IP IGMP pkt size=56 from 192.168.1.1 to 224.0.0.22 on fd=13 on ifindex=3 (sock_ifindex=4)
2009/04/15 08:06:07 PIM: Interface mismatch: recv IGMP pkt from 192.168.1.1 to 224.0.0.22 on fd=13: recv_ifindex=3 (eth1) s
ock_ifindex=4 (eth2)

I used tcpdump to look at the packets. They are on the correct
interface, so this looks like a pimd problem. These packets are on
eth1, so recv_ifindex (eth1) is correct and sock_ifindex=4 (eth2) is
wrong.

eth0 Link encap:Serial Line IP
NOARP MTU:1500 Metric:1
RX packets:0 errors:0 dropped:0 overruns:0 frame:0
TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:256
RX bytes:0 (0.0 b) TX bytes:0 (0.0 b)
Interrupt:5

eth1 Link encap:Ethernet HWaddr FE:FE:00:00:01:01
inet addr:192.168.1.1 Bcast:192.168.1.3 Mask:255.255.255.252
UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
RX packets:125 errors:0 dropped:0 overruns:0 frame:0
TX packets:105 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:10216 (9.9 KiB) TX bytes:8834 (8.6 KiB)
Interrupt:5

eth2 Link encap:Ethernet HWaddr FE:FE:00:00:01:02
inet addr:192.168.1.5 Bcast:192.168.1.7 Mask:255.255.255.252
UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
RX packets:18 errors:0 dropped:0 overruns:0 frame:0
TX packets:65 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:994 (994.0 b) TX bytes:4796 (4.6 KiB)
Interrupt:5

eth10 Link encap:Ethernet HWaddr 7A:02:C9:C1:65:BF
inet addr:192.168.41.253 Bcast:192.168.41.255 Mask:255.255.255.0
UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
RX packets:35 errors:0 dropped:0 overruns:0 frame:0
TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:6017 (5.8 KiB) TX bytes:0 (0.0 b)
Interrupt:5

lo Link encap:Local Loopback
inet addr:127.0.0.1 Mask:255.0.0.0
UP LOOPBACK RUNNING MTU:16436 Metric:1
RX packets:0 errors:0 dropped:0 overruns:0 frame:0
TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:0
RX bytes:0 (0.0 b) TX bytes:0 (0.0 b)

pimd.conf contains

interface eth1
ip pim ssm
ip igmp

interface eth2
ip pim ssm
ip igmp

I tried adding eth0, but that made no difference.

At startup it logs:

2009/04/15 08:06:06 PIM: Quagga 0.99.11 pimd 0.144 starting, VTY interface at port TCP 2611
2009/04/15 08:06:06 PIM: PIM_MOTD_VERSION: adding pimd version to default MOTD
2009/04/15 08:06:06 PIM: PIM_ZCLIENT_DEBUG: zclient debugging is supported, mode is OFF (see option -Z)
2009/04/15 08:06:06 PIM: PIM_CHECK_RECV_IFINDEX_SANITY: will match socket ifindex against recv ifindex
2009/04/15 08:06:06 PIM: PIM_USE_QUAGGA_INET_CHECKSUM: using Quagga's builtin checksum
2009/04/15 08:06:06 PIM: zclient update contacting ZEBRA daemon at socket UNIX /usr/local/run/zserv.api
2009/04/15 08:06:06 PIM: pim_zebra_init: zclient update socket initialized
2009/04/15 08:06:06 PIM: zclient_lookup_sched_now: zclient lookup immediate connection scheduled
2009/04/15 08:06:06 PIM: zclient_lookup_new: zclient lookup socket initialized
2009/04/15 08:06:06 PIM: zclient_lookup_connect: FIXME blocking connect: zclient_socket_un()
2009/04/15 08:06:06 PIM: pim_zebra_if_add: eth0 index 2 flags 128 metric 1 mtu 1500 operative 0
2009/04/15 08:06:06 PIM: pim_zebra_if_add: eth1 index 3 flags 69699 metric 1 mtu 1500 operative 1
2009/04/15 08:06:06 PIM: pim_zebra_if_address_add: eth1 connected IP address 192.168.1.1/30
2009/04/15 08:06:06 PIM: Socket fd=11 joined group 224.0.0.1 on interface address 192.168.1.1
2009/04/15 08:06:06 PIM: Socket fd=11 joined group 224.0.0.22 on interface address 192.168.1.1
2009/04/15 08:06:06 PIM: Creating IGMP socket fd=11 for address 192.168.1.1 on interface eth1
2009/04/15 08:06:06 PIM: Scheduling READ event on IGMP socket fd=11
2009/04/15 08:06:06 PIM: Querier 192.168.1.1 scheduling 31-second (startup) TIMER event for IGMP query on fd=11
2009/04/15 08:06:06 PIM: Socket fd=12 joined group 224.0.0.13 on interface address 192.168.1.1
2009/04/15 08:06:06 PIM: Scheduling READ event on PIM socket fd=12
2009/04/15 08:06:06 PIM: Scheduling 1241 msec triggered hello on interface eth1
2009/04/15 08:06:06 PIM: pim_zebra_if_add: eth2 index 4 flags 69699 metric 1 mtu 1500 operative 1
2009/04/15 08:06:06 PIM: pim_zebra_if_address_add: eth2 connected IP address 192.168.1.5/30
2009/04/15 08:06:06 PIM: Socket fd=13 joined group 224.0.0.1 on interface address 192.168.1.5
2009/04/15 08:06:06 PIM: Socket fd=13 joined group 224.0.0.22 on interface address 192.168.1.5
2009/04/15 08:06:06 PIM: Creating IGMP socket fd=13 for address 192.168.1.5 on interface eth2
2009/04/15 08:06:06 PIM: Scheduling READ event on IGMP socket fd=13
2009/04/15 08:06:06 PIM: Querier 192.168.1.5 scheduling 31-second (startup) TIMER event for IGMP query on fd=13
2009/04/15 08:06:06 PIM: Socket fd=14 joined group 224.0.0.13 on interface address 192.168.1.5

Andrew

[Everton Marques]

Hi,

Post by Andrew Lunn
2009/04/15 08:06:07 PIM: Scheduling READ event on IGMP socket fd=11
2009/04/15 08:06:07 PIM: Recv IP IGMP pkt size=56 from 192.168.1.1 to 224.0.0.22 on fd=13 on ifindex=3 (sock_ifindex=4)
2009/04/15 08:06:07 PIM: Interface mismatch: recv IGMP pkt from 192.168.1.1 to 224.0.0.22 on fd=13: recv_ifindex=3 (eth1) s
ock_ifindex=4 (eth2)
I used tcpdump to look at the packets. They are on the correct
interface, so this looks like a pimd problem. These packets are on
eth1, so recv_ifindex (eth1) is correct and sock_ifindex=4 (eth2) is
wrong.

Yes, I currently face the same behavior here, however it does not prevent the
correct multicasting for me. Of course, it should be tackled at some point.
I've added it as an entry to the TODO list.

Are you able to test with the following tarball? The major change is a
functional
maintenance strategy for the RPF cache. There are several minor corrections,
including a fix for the self-neighboring effect you pointed out.

http://download.savannah.nongnu.org/releases-noredirect/qpimd/qpimd-0.145.tar.gz

Cheers,
Everton

[Andrew Lunn]

Post by Everton Marques
Are you able to test with the following tarball? The major change is a
functional
maintenance strategy for the RPF cache. There are several minor corrections,
including a fix for the self-neighboring effect you pointed out.
http://download.savannah.nongnu.org/releases-noredirect/qpimd/qpimd-0.145.tar.gz

Thanks for the new tarball.

I'm starting to make progress.

uml1> show ip mroute
Proto: I=IGMP P=PIM

Source Group Proto Input iVifI Output oVifI TTL Uptime
192.168.1.1 232.0.0.42 I eth1 3 eth1 3 1 00:34:57
192.168.1.1 232.0.0.42 I eth1 3 eth2 4 1 00:34:23

Doesn't the first rule cause a loop, I'm seeing the same packet
multiple times on the network, since there is another node on the same
network, again eth1 with the rules:

Source Group Proto Input iVifI Output oVifI TTL Uptime
192.168.1.1 232.0.0.42 I eth1 3 eth1 3 1 00:38:03
192.168.1.1 232.0.0.42 I eth1 3 eth2 4 1 00:37:23
192.168.1.1 232.0.0.42 I eth1 3 eth3 5 1 00:37:49

The packet seems to be going round and around with decreasing TTL.

I'm also getting some crashes:

2009/04/16 14:00:05 PIM: Interface mismatch: recv IGMP pkt from 192.168.3.5 to 224.0.0.22 on fd=13: recv_ifindex=5 (eth3) sock_ifindex=4 (
eth2)
2009/04/16 14:00:05 PIM: stream_getc: Attempt to get char out of bounds
2009/04/16 14:00:05 PIM: &(struct stream): 0x667610, size: 4096, endp: 15, getp: 15

2009/04/16 14:00:05 PIM: Assertion `0' failed in file /home/lunn/Multicast/mobtel07/src/quagga/lib/stream.c, line 272, function stream_get
c
2009/04/16 14:00:05 PIM: Backtrace for 15 stack frames:
2009/04/16 14:00:05 PIM: [bt 0] /usr/local/lib/libzebra.so.0(zlog_backtrace+0x2b) [0x40145d28]
2009/04/16 14:00:05 PIM: [bt 1] /usr/local/lib/libzebra.so.0(_zlog_assert_failed+0xa5) [0x40145e98]
2009/04/16 14:00:05 PIM: [bt 2] /usr/local/lib/libzebra.so.0(stream_getc+0x84) [0x40142c59]
2009/04/16 14:00:05 PIM: [bt 3] /usr/local/sbin/pimd [0x40f4bc]
2009/04/16 14:00:05 PIM: [bt 4] /usr/local/sbin/pimd [0x40b708]
2009/04/16 14:00:05 PIM: [bt 5] /usr/local/sbin/pimd [0x40be84]
2009/04/16 14:00:05 PIM: [bt 6] /usr/local/sbin/pimd [0x40ce3f]
2009/04/16 14:00:05 PIM: [bt 7] /usr/local/sbin/pimd [0x40cfd4]
2009/04/16 14:00:05 PIM: [bt 8] /usr/local/sbin/pimd [0x40d2f9]
2009/04/16 14:00:05 PIM: [bt 9] /usr/local/sbin/pimd [0x40a769]
2009/04/16 14:00:05 PIM: [bt 10] /usr/local/sbin/pimd [0x40abcb]
2009/04/16 14:00:05 PIM: [bt 11] /usr/local/lib/libzebra.so.0(thread_call+0x68) [0x4013a14b]
2009/04/16 14:00:05 PIM: [bt 12] /usr/local/sbin/pimd [0x402db1]
2009/04/16 14:00:05 PIM: [bt 13] /lib/libc.so.6(__libc_start_main+0xda) [0x404c04ca]
2009/04/16 14:00:05 PIM: [bt 14] /usr/local/sbin/pimd [0x4029b9]

I used gdb to turn the addresses into symbols:
0x40f4bc <zclient_lookup_nexthop+633>
0x40b708 <fib_lookup_if_vif_index+48>
0x40be84 <igmp_source_forward_start
0x40ce3f <igmp_source_timer_on+223>
0x40cfd4 <igmp_source_reset_gmi+183>
0x40d2f9 <allow+119>
0x40a769 <pim_igmp_packet+2000>
0x40abcb <pim_igmp_read+628>

Andrew

[Everton Marques]

Post by Andrew Lunn
uml1> show ip mroute
Proto: I=IGMP P=PIM
Source Group Proto Input iVifI Output oVifI TTL Uptime
192.168.1.1 232.0.0.42 I eth1 3 eth1 3 1 00:34:57
192.168.1.1 232.0.0.42 I eth1 3 eth2 4 1 00:34:23
Doesn't the first rule cause a loop, I'm seeing the same packet
multiple times on the network, since there is another node on the same

Yes, it seems an IGMP-specific issue, since PIM should not create
loops. Can you apply the attached patch over the 0.145 source
tree and then let me know if it solves the problem?
I have also included additional debugging hooks in that
attached patch. If you try it, maybe it could shed some
light on those crashes.

Thanks a lot for the reports!

Cheers,
Everton