Bug 404761 - Packet lost inside kernel
Packet lost inside kernel
Status: CLOSED NOTABUG
Product: Fedora
Classification: Fedora
Component: kernel (Show other bugs)
7
athlon Linux
low Severity high
: ---
: ---
Assigned To: Kernel Maintainer List
Fedora Extras Quality Assurance
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2007-11-29 12:59 EST by Eric Hopper
Modified: 2007-12-01 21:00 EST (History)
0 users

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2007-12-01 21:00:45 EST
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description Eric Hopper 2007-11-29 12:59:39 EST
My Fedora based router is dropping a packet in between the time I can see it
with tcpdump and the time it hits the raw:PREROUTING table.

In the following, notice how the debug2 LOG target never seems to be fired.

Showing the table:
# iptables -t raw -nL PREROUTING Chain PREROUTING (policy ACCEPT)
target     prot opt source               destination         
LOG        icmp --  0.0.0.0/0            216.254.16.18       LOG flags 0 level 4
prefix `debug ' 
LOG        icmp --  0.0.0.0/0            216.254.16.17       LOG flags 0 level 4
prefix `debug2 ' 

------

What tcpdump shows:

# tcpdump -eni eth0 ip host 209.40.196.143 and not tcp
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on eth0, link-type EN10MB (Ethernet), capture size 96 bytes
09:48:05.949100 00:90:1a:40:a2:a2 > 00:e0:81:2c:b6:e2, ethertype IPv4 (0x0800),
length 98: 209.40.196.143 > 216.254.16.18: ICMP echo request, id 37964, seq 1,
length 64
09:48:07.948419 00:90:1a:40:a2:a2 > 00:e0:81:2c:b6:e2, ethertype IPv4 (0x0800),
length 98: 209.40.196.143 > 216.254.16.18: ICMP echo request, id 37964, seq 2,
length 64
09:48:09.947579 00:90:1a:40:a2:a2 > 00:e0:81:2c:b6:e2, ethertype IPv4 (0x0800),
length 98: 209.40.196.143 > 216.254.16.18: ICMP echo request, id 37964, seq 3,
length 64
09:48:12.863715 00:90:1a:40:a2:a2 > 00:0d:61:91:5d:e6, ethertype IPv4 (0x0800),
length 98: 209.40.196.143 > 216.254.16.17: ICMP echo request, id 49484, seq 1,
length 64
09:48:12.863960 00:0d:61:91:5d:e6 > 00:90:1a:40:a2:a2, ethertype IPv4 (0x0800),
length 98: 216.254.16.17 > 209.40.196.143: ICMP echo reply, id 49484, seq 1,
length 64
09:48:14.864049 00:90:1a:40:a2:a2 > 00:0d:61:91:5d:e6, ethertype IPv4 (0x0800),
length 98: 209.40.196.143 > 216.254.16.17: ICMP echo request, id 49484, seq 2,
length 64
09:48:14.864258 00:0d:61:91:5d:e6 > 00:90:1a:40:a2:a2, ethertype IPv4 (0x0800),
length 98: 216.254.16.17 > 209.40.196.143: ICMP echo reply, id 49484, seq 2,
length 64
09:48:16.863956 00:90:1a:40:a2:a2 > 00:0d:61:91:5d:e6, ethertype IPv4 (0x0800),
length 98: 209.40.196.143 > 216.254.16.17: ICMP echo request, id 49484, seq 3,
length 64
09:48:16.864159 00:0d:61:91:5d:e6 > 00:90:1a:40:a2:a2, ethertype IPv4 (0x0800),
length 98: 216.254.16.17 > 209.40.196.143: ICMP echo reply, id 49484, seq 3,
length 64

------

What /var/log/messages shows:

Nov 29 09:48:12 dark kernel: debug2 IN=eth0 OUT=
MAC=00:0d:61:91:5d:e6:00:90:1a:40:a2:a2:08:00 SRC=209.40.196.143
DST=216.254.16.17 LEN=84 TOS=0x00 PREC=0x20 TTL=58 ID=0 DF PROTO=ICMP TYPE=8
CODE=0 ID=49484 SEQ=1 
Nov 29 09:48:14 dark kernel: debug2 IN=eth0 OUT=
MAC=00:0d:61:91:5d:e6:00:90:1a:40:a2:a2:08:00 SRC=209.40.196.143
DST=216.254.16.17 LEN=84 TOS=0x00 PREC=0x20 TTL=58 ID=0 DF PROTO=ICMP TYPE=8
CODE=0 ID=49484 SEQ=2 
Nov 29 09:48:16 dark kernel: debug2 IN=eth0 OUT=
MAC=00:0d:61:91:5d:e6:00:90:1a:40:a2:a2:08:00 SRC=209.40.196.143
DST=216.254.16.17 LEN=84 TOS=0x00 PREC=0x20 TTL=58 ID=0 DF PROTO=ICMP TYPE=8
CODE=0 ID=49484 SEQ=3 
Nov 29 09:50:31 dark kernel: debug2 IN=eth0 OUT=
MAC=00:0d:61:91:5d:e6:00:90:1a:40:a2:a2:08:00 SRC=67.15.240.43 DST=216.254.16.17
LEN=78 TOS=0x00 PREC=0x20 TTL=53 ID=0 DF PROTO=ICMP TYPE=8 CODE=0 ID=1 SEQ=9131
Comment 1 Eric Hopper 2007-11-29 13:03:05 EST
Better kernel log:

Nov 29 09:47:58 dark kernel: device eth0 entered promiscuous mode
Nov 29 09:47:58 dark kernel: audit(1196358478.738:10): dev=eth0 prom=256
old_prom=0 auid=4294967295
Nov 29 09:48:12 dark kernel: debug2 IN=eth0 OUT=
MAC=00:0d:61:91:5d:e6:00:90:1a:40:a2:a2:08:00 SRC=209.40.196.143
DST=216.254.16.17 LEN=84 TOS=0x00 PREC=0x20 TTL=58 ID=0 DF PROTO=ICMP TYPE=8
CODE=0 ID=49484 SEQ=1 
Nov 29 09:48:14 dark kernel: debug2 IN=eth0 OUT=
MAC=00:0d:61:91:5d:e6:00:90:1a:40:a2:a2:08:00 SRC=209.40.196.143
DST=216.254.16.17 LEN=84 TOS=0x00 PREC=0x20 TTL=58 ID=0 DF PROTO=ICMP TYPE=8
CODE=0 ID=49484 SEQ=2 
Nov 29 09:48:16 dark kernel: debug2 IN=eth0 OUT=
MAC=00:0d:61:91:5d:e6:00:90:1a:40:a2:a2:08:00 SRC=209.40.196.143
DST=216.254.16.17 LEN=84 TOS=0x00 PREC=0x20 TTL=58 ID=0 DF PROTO=ICMP TYPE=8
CODE=0 ID=49484 SEQ=3 
Nov 29 09:50:31 dark kernel: debug2 IN=eth0 OUT=
MAC=00:0d:61:91:5d:e6:00:90:1a:40:a2:a2:08:00 SRC=67.15.240.43 DST=216.254.16.17
LEN=78 TOS=0x00 PREC=0x20 TTL=53 ID=0 DF PROTO=ICMP TYPE=8 CODE=0 ID=1 SEQ=9131 
Comment 2 Chuck Ebbert 2007-11-29 13:25:32 EST
(In reply to comment #0)
> 
> In the following, notice how the debug2 LOG target never seems to be fired.
> 
> LOG        icmp --  0.0.0.0/0            216.254.16.17       LOG flags 0 level 4
> prefix `debug2 ' 

> Nov 29 09:48:12 dark kernel: debug2 IN=eth0 OUT=
                               ^^^^^^
debug2 is there-------------------

> MAC=00:0d:61:91:5d:e6:00:90:1a:40:a2:a2:08:00 SRC=209.40.196.143
> DST=216.254.16.17 LEN=84 TOS=0x00 PREC=0x20 TTL=58 ID=0 DF PROTO=ICMP TYPE=8
> CODE=0 ID=49484 SEQ=1 
Comment 3 Eric Hopper 2007-11-29 13:36:13 EST
I'm sorry, I meant 'debug'.  'debug2' is associated with the rule for
216.254.16.17, an IP that is properly routed and everything.  And 'debug' is
associated with the rule for 216.254.16.18, an IP for which all of the incoming
packets are currently being eaten by the kernel somewhere between tcpdump and
raw:PREROUTING
Comment 4 Chuck Ebbert 2007-11-29 14:06:14 EST
Please post the output of the 'ifconfig' command.
Comment 5 Eric Hopper 2007-11-29 14:13:17 EST
eth0      Link encap:Ethernet  HWaddr 00:0D:61:91:5D:E6  
          inet addr:216.254.16.16  Bcast:216.254.16.16  Mask:255.255.255.255
          inet6 addr: fe80::20d:61ff:fe91:5de6/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:321895 errors:0 dropped:0 overruns:0 frame:0
          TX packets:270299 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:1000 
          RX bytes:173078587 (165.0 MiB)  TX bytes:150066298 (143.1 MiB)
          Interrupt:22 Base address:0xa000
Comment 6 Chuck Ebbert 2007-11-30 15:34:49 EST
The packets destined for 216.254.16.18 are being sent to a different network
adapter, with MAC address 00:e0:81:2c:b6:e2
Comment 7 Eric Hopper 2007-12-01 21:00:45 EST
Oh, you're right.  I didn't notice this.  How interesting and odd.  Thanks a
whole lot.  This is now not the bug I thought it was, but may still be a bug.

216.254.16.16 is a firewall.  I have 4 static IPs not in a subnetwork.  I have
eth0 configured to proxy arp.  So 216.254.16.1 (the gateway at the ISP) should
never have seen that ethernet address, which is the Ethernet address of
216.254.16.18.

Oh!  I know how that happened.  It was because of a debugging session with my
ISP.  It took many minutes awhile for the gateway's ARP cache to timeout. 
Something very weird is going on with the way my ISP is routing packets and
they've been trying to blame it on me.

Sorry to call in a bug report when it wasn't.

Note You need to log in before you can comment on or make changes to this bug.