Message "in_cksum_skip: out of data by ...."

[David Wolfskill]

I started seeing these messages spewed (to both console &
/var/log/messages) following an update from:

FreeBSD g1-227.catwhisker.org 10.0-CURRENT FreeBSD 10.0-CURRENT #697 241222M: Fri Oct 5 05:32:19 PDT 2012 ***@g1-227.catwhisker.org:/usr/obj/usr/src/sys/CANARY i386

to

FreeBSD g1-227.catwhisker.org 10.0-CURRENT FreeBSD 10.0-CURRENT #698 241245M: Sat Oct 6 08:01:23 PDT 2012 ***@g1-227.catwhisker.org:/usr/obj/usr/src/sys/CANARY i386

and I'm still seeing them as of

FreeBSD g1-227.catwhisker.org 10.0-CURRENT FreeBSD 10.0-CURRENT #699 241309M: Sun Oct 7 07:35:41 PDT 2012 ***@g1-227.catwhisker.org:/usr/obj/usr/src/sys/CANARY i386

E.g.:
Oct 6 08:24:10 g1-227 kernel: wlan0: Ethernet address: 00:21:6a:26:34:c0
Oct 6 08:24:10 g1-227 kernel: Expensive timeout(9) function: 0xc0c27520(0) 0.010540166 s
Oct 6 08:24:10 g1-227 kernel: in_cksum_skip: out of data by 10200
Oct 6 08:24:10 g1-227 kernel: in_cksum_skip: out of data by 10200
Oct 6 08:24:10 g1-227 kernel: in_cksum_skip: out of data by 18105
Oct 6 08:24:10 g1-227 kernel: in_cksum_skip: out of data by 18105
Oct 6 08:24:10 g1-227 kernel: in_cksum_skip: out of data by 17340
Oct 6 08:24:10 g1-227 last message repeated 3 times
Oct 6 08:24:10 g1-227 kernel: in_cksum_skip: out of data by 19380
Oct 6 08:24:10 g1-227 kernel: in_cksum_skip: out of data by 10200
Oct 6 08:24:10 g1-227 kernel: in_cksum_skip: out of data by 19380
Oct 6 08:24:10 g1-227 last message repeated 4 times
..

or (more recently):
Oct 7 07:58:53 g1-227 kernel: wlan0: Ethernet address: 00:21:6a:26:34:c0
Oct 7 07:58:53 g1-227 kernel: Expensive timeout(9) function: 0xc0c27550(0) 0.011038204 s
Oct 7 07:58:53 g1-227 kernel: in_cksum_skip: out of data by 18105
Oct 7 07:58:53 g1-227 kernel: in_cksum_skip: out of data by 18105
Oct 7 07:58:53 g1-227 kernel: in_cksum_skip: out of data by 17340
Oct 7 07:58:53 g1-227 last message repeated 3 times
Oct 7 07:58:53 g1-227 kernel: in_cksum_skip: out of data by 10200
Oct 7 07:58:53 g1-227 kernel: in_cksum_skip: out of data by 19380
Oct 7 07:58:54 g1-227 last message repeated 4 times
..

As far as I have been able to tell so far, the machine (my laptop) is
not exhibiting any (aother) indications of problems.

I confess that I am not entirely clear on what information the
message is apparently trying to convey (let alone what I can or
should do about it -- if anything).

Peace,
david

[Michael Butler]

Post by David Wolfskill
I started seeing these messages spewed (to both console &
to
and I'm still seeing them as of
Oct 6 08:24:10 g1-227 kernel: wlan0: Ethernet address: 00:21:6a:26:34:c0
Oct 6 08:24:10 g1-227 kernel: Expensive timeout(9) function: 0xc0c27520(0) 0.010540166 s
Oct 6 08:24:10 g1-227 kernel: in_cksum_skip: out of data by 10200

+1 on a laptop running with:

re0: <RealTek 8168/8111 B/C/CP/D/DP/E/F PCIe Gigabit Ethernet> port
0x2000-0x20ff mem 0xf0700000-0xf0700fff,0xf0200000-0xf0203fff irq 17 at
device 0.0 on pci3
re0: Using 1 MSI-X message
re0: ASPM disabled
re0: Chip rev. 0x28000000
re0: MAC rev. 0x00000000
miibus0: <MII bus> on re0
rgephy0: <RTL8169S/8110S/8211 1000BASE-T media interface> PHY 1 on miibus0
rgephy0: none, 10baseT, 10baseT-FDX, 10baseT-FDX-flow, 100baseTX,
100baseTX-FDX, 100baseTX-FDX-flow, 1000baseT, 1000baseT-master,
1000baseT-FDX, 1000baseT-FDX-master, 1000baseT-FDX-flow,
1000baseT-FDX-flow-master, auto, auto-flow
re0: Ethernet address: 00:0a:cd:1d:30:a2

I thought it may have had something to do with a VirtualBox module, so I
recompiled that too .. no joy :-(

imb

[Garrett Cooper]

On Sun, Oct 7, 2012 at 9:16 AM, Michael Butler

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Post by David Wolfskill
I started seeing these messages spewed (to both console &
to
and I'm still seeing them as of
Oct 6 08:24:10 g1-227 kernel: wlan0: Ethernet address: 00:21:6a:26:34:c0
Oct 6 08:24:10 g1-227 kernel: Expensive timeout(9) function: 0xc0c27520(0) 0.010540166 s
Oct 6 08:24:10 g1-227 kernel: in_cksum_skip: out of data by 10200

re0: <RealTek 8168/8111 B/C/CP/D/DP/E/F PCIe Gigabit Ethernet> port
0x2000-0x20ff mem 0xf0700000-0xf0700fff,0xf0200000-0xf0203fff irq 17 at
device 0.0 on pci3
re0: Using 1 MSI-X message
re0: ASPM disabled
re0: Chip rev. 0x28000000
re0: MAC rev. 0x00000000
miibus0: <MII bus> on re0
rgephy0: <RTL8169S/8110S/8211 1000BASE-T media interface> PHY 1 on miibus0
rgephy0: none, 10baseT, 10baseT-FDX, 10baseT-FDX-flow, 100baseTX,
100baseTX-FDX, 100baseTX-FDX-flow, 1000baseT, 1000baseT-master,
1000baseT-FDX, 1000baseT-FDX-master, 1000baseT-FDX-flow,
1000baseT-FDX-flow-master, auto, auto-flow
re0: Ethernet address: 00:0a:cd:1d:30:a2
I thought it may have had something to do with a VirtualBox module, so I
recompiled that too .. no joy :-(

Maybe these revisions had something to do with it... (r241245 is
more likely)?

------------------------------------------------------------------------
r241245 | glebius | 2012-10-06 03:02:11 -0700 (Sat, 06 Oct 2012) | 19 lines

A step in resolving mess with byte ordering for AF_INET. After this change:

- All packets in NETISR_IP queue are in net byte order.
- ip_input() is entered in net byte order and converts packet
to host byte order right _after_ processing pfil(9) hooks.
- ip_output() is entered in host byte order and converts packet
to net byte order right _before_ processing pfil(9) hooks.
- ip_fragment() accepts and emits packet in net byte order.
- ip_forward(), ip_mloopback() use host byte order (untouched actually).
- ip_fastforward() no longer modifies packet at all (except ip_ttl).
- Swapping of byte order there and back removed from the following modules:
pf(4), ipfw(4), enc(4), if_bridge(4).
- Swapping of byte order added to ipfilter(4), based on __FreeBSD_version
- __FreeBSD_version bumped.
- pfil(9) manual page updated.

Reviewed by: ray, luigi, eri, melifaro
Tested by: glebius (LE), ray (BE)

------------------------------------------------------------------------
r241244 | glebius | 2012-10-06 00:06:57 -0700 (Sat, 06 Oct 2012) | 5 lines

The pfil(9) layer guarantees us presence of the protocol header,
so remove extra check, that is always false.

P.S. Also, goto there lead to unlocking a not locked rwlock.

------------------------------------------------------------------------

Did you rebuild all of your modules, and (for David) are you
running any firmware blobs with your wireless NIC?
Cheers,
-Garrett

[David Wolfskill]

Post by Garrett Cooper
...
Maybe these revisions had something to do with it... (r241245 is
more likely)?
------------------------------------------------------------------------
r241245 | glebius | 2012-10-06 03:02:11 -0700 (Sat, 06 Oct 2012) | 19 lines
...
------------------------------------------------------------------------
r241244 | glebius | 2012-10-06 00:06:57 -0700 (Sat, 06 Oct 2012) | 5 lines
The pfil(9) layer guarantees us presence of the protocol header,
so remove extra check, that is always false.
...
Did you rebuild all of your modules, and (for David) are you
running any firmware blobs with your wireless NIC?

Yes; when I update, my changes from the process in src/UPDATING
generally augment what's there (e.g., to clear /usr/include &
/usr/share/man before the make installworld).

And the NIC that's in use (at home -- and most other places) on the
laptop is iwn(4), so yes, there is a firmware blob:

4 1 0xc138a000 54e38 iwn5000fw.ko

(Well, that particular line is from kldstat when it's running stable/9;
I just checked the head slice, and the blob had been rebuilt (based on
mtime), and has contents different from the contents in stable/9:

g1-227(9.1-P)[3] md5 /{,S4/}boot/kernel/iwn5000fw.ko
MD5 (/boot/kernel/iwn5000fw.ko) = 8f98e8f28c70fe801c73aec4f717973f
MD5 (/S4/boot/kernel/iwn5000fw.ko) = a0150e03bfd307595ab37b0924252844
g1-227(9.1-P)[4] ls -lT !$
ls -lT /{,S4/}boot/kernel/iwn5000fw.ko
-r-xr-xr-x 1 root wheel 345868 Oct 7 07:48:46 2012 /S4/boot/kernel/iwn5000fw.ko
-r-xr-xr-x 1 root wheel 344416 Oct 7 04:51:11 2012 /boot/kernel/iwn5000fw.ko
g1-227(9.1-P)[5]

FWIW.)

As noted, the message does not appear to be associated with (other)
unwanted behavior, so I wouldn't consider this of earth-shattering
importance. It just seemed rather odd, and I got to wondering if
the developer who committed the change had intended this result.
And if said result was actually of use to anyone. :-}

Peace,
david

[Garrett Cooper]

Post by David Wolfskill

Post by Garrett Cooper
...
Maybe these revisions had something to do with it... (r241245 is
more likely)?
------------------------------------------------------------------------
r241245 | glebius | 2012-10-06 03:02:11 -0700 (Sat, 06 Oct 2012) | 19 lines
...
------------------------------------------------------------------------
r241244 | glebius | 2012-10-06 00:06:57 -0700 (Sat, 06 Oct 2012) | 5 lines
The pfil(9) layer guarantees us presence of the protocol header,
so remove extra check, that is always false.
...
Did you rebuild all of your modules, and (for David) are you
running any firmware blobs with your wireless NIC?

Yes; when I update, my changes from the process in src/UPDATING
generally augment what's there (e.g., to clear /usr/include &
/usr/share/man before the make installworld).
And the NIC that's in use (at home -- and most other places) on the
4 1 0xc138a000 54e38 iwn5000fw.ko
(Well, that particular line is from kldstat when it's running stable/9;
I just checked the head slice, and the blob had been rebuilt (based on
g1-227(9.1-P)[3] md5 /{,S4/}boot/kernel/iwn5000fw.ko
MD5 (/boot/kernel/iwn5000fw.ko) = 8f98e8f28c70fe801c73aec4f717973f
MD5 (/S4/boot/kernel/iwn5000fw.ko) = a0150e03bfd307595ab37b0924252844
g1-227(9.1-P)[4] ls -lT !$
ls -lT /{,S4/}boot/kernel/iwn5000fw.ko
-r-xr-xr-x 1 root wheel 345868 Oct 7 07:48:46 2012 /S4/boot/kernel/iwn5000fw.ko
-r-xr-xr-x 1 root wheel 344416 Oct 7 04:51:11 2012 /boot/kernel/iwn5000fw.ko
g1-227(9.1-P)[5]
FWIW.)
As noted, the message does not appear to be associated with (other)
unwanted behavior, so I wouldn't consider this of earth-shattering
importance. It just seemed rather odd, and I got to wondering if
the developer who committed the change had intended this result.
And if said result was actually of use to anyone. :-}

Given that the issue is present on both your machine and
Michael's, it's unlikely that it's firmware related (unless re(4) is
doing something hacktacularly awesome!), but I just wanted to gather
all the facts before something's brought up to glebius@, if the issue
is indeed one of the two commits (or both) mentioned above.
Could you guys please try reverting one or both of the commits to
see if the issue goes away?
Thanks!
-Garrett

[Michael Butler]

Post by Garrett Cooper
Maybe these revisions had something to do with it... (r241245 is
more likely)?

I reverted r241245 and the messages went away,

Post by Garrett Cooper
Did you rebuild all of your modules, and (for David) are you
running any firmware blobs with your wireless NIC?

I always rebuild modules (system and ports) along with a new kernel,

imb

[Garrett Cooper]

On Sun, Oct 7, 2012 at 10:51 AM, Michael Butler

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Post by Garrett Cooper
Maybe these revisions had something to do with it... (r241245 is
more likely)?

I reverted r241245 and the messages went away,

Post by Garrett Cooper
Did you rebuild all of your modules, and (for David) are you
running any firmware blobs with your wireless NIC?

I always rebuild modules (system and ports) along with a new kernel,

Gleb CCed then.
Thanks!
-Garrett

[Gleb Smirnoff]

David and Michael,

On Sun, Oct 07, 2012 at 10:52:13AM -0700, Garrett Cooper wrote:
G> > On 10/07/12 13:03, Garrett Cooper wrote:
G> >> Maybe these revisions had something to do with it... (r241245 is
G> >> more likely)?
G> >
G> > I reverted r241245 and the messages went away,

Can you please try r241344?

[David Wolfskill]

Post by Gleb Smirnoff
David and Michael,
G> >> Maybe these revisions had something to do with it... (r241245 is
G> >> more likely)?
G> >
G> > I reverted r241245 and the messages went away,
Can you please try r241344?

Done; seems to work:

FreeBSD g1-227.catwhisker.org 10.0-CURRENT FreeBSD 10.0-CURRENT #700 241344M: Mon Oct 8 06:20:59 PDT 2012 ***@g1-227.catwhisker.org:/usr/obj/usr/src/sys/CANARY i386

No whines in /var/log/messages or console (about "in_cksum_skip:
out of data by ....", at least).

Thanks!

Peace,
david

[Michael Butler]

Post by Gleb Smirnoff
David and Michael,
G> >> Maybe these revisions had something to do with it... (r241245 is
G> >> more likely)?
G> >
G> > I reverted r241245 and the messages went away,
Can you please try r241344?

Sorry for the delay; it seems that the last remaining cause was resolved
with SVN r241547. Thanks,

imb

[Gleb Smirnoff]

On Sun, Oct 07, 2012 at 01:51:20PM -0400, Michael Butler wrote:
M> On 10/07/12 13:03, Garrett Cooper wrote:
M> > Maybe these revisions had something to do with it... (r241245 is
M> > more likely)?
M>
M> I reverted r241245 and the messages went away,

I'll handle that. Sorry for breakage.

[Gleb Smirnoff]

David and Michael,

can you please build a kernel with attached patch and options KDB,
and report what's the trace is.

Unfortunately my iwn(4) is running on amd64, so I can reproduce
exactly your case.