Project

General

Profile

Actions

Bug #12753

closed

simnet requests zero-sized kmem alloc

Added by Ryan Zezeski about 2 years ago. Updated almost 2 years ago.

Status:
Closed
Priority:
Normal
Assignee:
Category:
networking
Start date:
Due date:
% Done:

100%

Estimated time:
Difficulty:
Medium
Tags:
Gerrit CR:

Description

This is an upstream of SmartOS ticket OS-7840. The original bug report is found below, copied verbatim.

While testing OS-7520 on a DEBUG kernel I noticed that simnet is making some zero-size kmem allocations.

/var/adm/messages

2019-06-14T15:55:39.632484+00:00 testsos genunix: [ID 957100 kern.warning] WARNING: kmem_alloc(): sleeping allocation with size of 0; see kmem_zerosized_log for details
2019-06-14T15:55:40.067416+00:00 testsos genunix: [ID 957100 kern.warning] WARNING: kmem_alloc(): sleeping allocation with size of 0; see kmem_zerosized_log for details

# mdb -k
Loading modules: [ unix genunix specfs dtrace mac cpu.generic uppc apix scsi_vhci ufs ip hook neti sockfs arp usba mm stmf_sbd stmf zfs lofs mpt idm sd cpc logindmux ptm sppp nfs ]
> ::kmalog zerosized

T-0.000000000  addr=0  0
         kmem_log_event+0x8f
         kmem_alloc+0x15c
         0xfffffffff7b00c69
         mac_bcast_delete+0x37e
         mac_multicast_remove+0x5e
         dls_multicst_remove+0xbd
         proto_disabmulti_req+0xc4
         dld_proto+0x225
         dld_wput_nondata_task+0xb3
         taskq_d_thread+0xf3
         thread_start+8

T-0.351649531  addr=0  0
         kmem_log_event+0x8f
         kmem_alloc+0x15c
         0xfffffffff7b00c69
         mac_bcast_delete+0x37e
         mac_multicast_remove+0x5e
         dls_multicst_remove+0xbd
         proto_disabmulti_req+0xc4
         dld_proto+0x225
         dld_wput_nondata_task+0xb3
         taskq_d_thread+0xf3
         thread_start+8
(1) <GZ> root@testsos [~]
# dtrace -qn 'mac_bcast_delete:entry { self->t = 1; } kmem_alloc:entry /self->t && arg0 == 0/ { ustack(); stack(); } mac_bcast_delete:return { self->t = 0; }'

              simnet`simnet_m_multicst+0x79
              mac`mac_bcast_delete+0x37e
              mac`mac_multicast_remove+0x5e
              dls`dls_multicst_remove+0xbd
              dld`proto_disabmulti_req+0xc4
              dld`dld_proto+0x225
              dld`dld_wput_nondata_task+0xb3
              genunix`taskq_d_thread+0xf3
              unix`thread_start+0x8

              simnet`simnet_m_multicst+0x79
              mac`mac_bcast_delete+0x37e
              mac`mac_multicast_remove+0x5e
              dls`dls_multicst_remove+0xbd
              dld`proto_disabmulti_req+0xc4
              dld`dld_proto+0x225
              dld`dld_wput_nondata_task+0xb3
              genunix`taskq_d_thread+0xf3
              unix`thread_start+0x8

Files

simnet-multicast-dbg.d (3.11 KB) simnet-multicast-dbg.d Ryan Zezeski, 2020-05-20 04:35 AM
Actions #1

Updated by Ryan Zezeski almost 2 years ago

To aid in testing I wrote a dtrace script to track the adding and removing of multicast addresses on simnet devices, as well as the receiving of multicast traffic on simnet devices. This makes it clear when an address is added to the device's table and when an Rx multicast packet is accepted or dropped.

First, I created two simnets with primary clients on top of them. It was important to use primary clients because simnet doesn't have ring/group support yet and thus a non-primary client puts it in promisc mode. In promisc mode we can't exercise the mcastaddr_lookup() function.

rpz@thunderhead:~$ pfexec dladm create-simnet rpz1
rpz@thunderhead:~$ pfexec dladm create-simnet rpz2
rpz@thunderhead:~$ pfexec dladm modify-simnet -p rpz2 rpz1
rpz@thunderhead:~$ pfexec ipadm create-addr -t -T static -a 192.168.66.1/24 rpz1/v4
rpz@thunderhead:~$ pfexec ipadm create-addr -t -T static -a 192.168.66.2/24 rpz2/v4

Next, I ran the dtrace script.

rpz@thunderhead:~$ pfexec dtrace -Cqs /data/d/simnet-multicast-dbg.d

I started two instances of socat to listen on two different multicast addresses: 224.255.0.1 and 224.255.0.2. These are listening on the client on rpz2.

rpz@thunderhead:~$ socat -u UDP4-RECV:6666,ip-add-membership=224.255.0.1:192.168.66.2 STDOUT

rpz@thunderhead:~$ socat -u UDP4-RECV:6667,ip-add-membership=224.255.0.2:192.168.66.2 STDOUT

While starting these severs the script prints the state of the multicast table as it changes. There are also DROP messages caused by IGMP messages being sent across the network to advertise the new group membership -- but the client isn't asking for this traffic so it's dropped. As the socat receiving processes are started you can see the 1:0:5e:7f:0:1 and 1:0:5e:7f:0:2 multicast addresses are added to the table.

rpz@thunderhead:~$ pfexec dtrace -Cqs /data/d/simnet-multicast-dbg.d 
simnet simnet1004 received multicast addr 1:0:5e:0:0:16 => Adding mcast addr: 1:0:5e:7f:0:1
sdev multicast addr count: 1
First 5 multicast addrs in sdev:
1:0:5e:0:0:1
0:0:0:0:0:0
0:0:0:0:0:0
0:0:0:0:0:0
0:0:0:0:0:0

DROP
Finished adding mcast addr
sdev multicast addr count: 2
First 5 multicast addrs in sdev:
1:0:5e:0:0:1
1:0:5e:7f:0:1
0:0:0:0:0:0
0:0:0:0:0:0
0:0:0:0:0:0

simnet simnet1004 received multicast addr 1:0:5e:0:0:16 => DROP
simnet simnet1004 received multicast addr 1:0:5e:0:0:16 => Adding mcast addr: 1:0:5e:7f:0:2
sdev multicast addr count: 2
First 5 multicast addrs in sdev:
1:0:5e:0:0:1
1:0:5e:7f:0:1
0:0:0:0:0:0
0:0:0:0:0:0
0:0:0:0:0:0

DROP
Finished adding mcast addr
sdev multicast addr count: 3
First 5 multicast addrs in sdev:
1:0:5e:0:0:1
1:0:5e:7f:0:1
1:0:5e:7f:0:2
0:0:0:0:0:0
0:0:0:0:0:0

simnet simnet1004 received multicast addr 1:0:5e:0:0:16 => DROP
simnet simnet1004 received multicast addr 1:0:5e:0:0:16 => DROP
simnet simnet1004 received multicast addr 1:0:5e:0:0:16 => DROP

Next, set the ipv4 hostmodel property to src-priority so that I know when I use bind(2) the traffic will actually go out of the requested interface.

rpz@thunderhead:~$ pfexec ipadm set-prop -p hostmodel=src-priority ipv4

In another window I send a simple "hello" message to the 1:0:5e:7f:0:1 process.

rpz@thunderhead:~$ pfexec socat -u STDIN UDP4-SENDTO:224.255.0.1:6666,bind=192.168.66.1
hello
^Crpz@thunderhead:~$

This result in the following dtrace output.

simnet simnet1005 received multicast addr 1:0:5e:7f:0:1 => PASS

And we see this on the receiving end.

rpz@thunderhead:~$ socat -u UDP4-RECV:6666,ip-add-membership=224.255.0.1:192.168.66.2 STDOUT
hello

Then I stop the 1:0:5e:7f:0:1 process and see the following dtrace output.

simnet simnet1004 received multicast addr 1:0:5e:0:0:16 => Removing mcast addr: 1:0:5e:7f:0:1
sdev multicast addr count: 3
First 5 multicast addrs in sdev:
1:0:5e:0:0:1
1:0:5e:7f:0:1
1:0:5e:7f:0:2
0:0:0:0:0:0
0:0:0:0:0:0

DROP
Finished removing mcast addr
sdev multicast addr count: 2
First 5 multicast addrs in sdev:
1:0:5e:0:0:1
1:0:5e:7f:0:2
0:0:0:0:0:0
0:0:0:0:0:0
0:0:0:0:0:0

Finally, I stop the 1:0:5e:7f:0:2 process and see the following dtrace output.

simnet simnet1004 received multicast addr 1:0:5e:0:0:16 => DROP
Removing mcast addr: 1:0:5e:7f:0:2
sdev multicast addr count: 2
First 5 multicast addrs in sdev:
1:0:5e:0:0:1
1:0:5e:7f:0:2
0:0:0:0:0:0
0:0:0:0:0:0
0:0:0:0:0:0

Finished removing mcast addr
sdev multicast addr count: 1
First 5 multicast addrs in sdev:
1:0:5e:0:0:1
0:0:0:0:0:0
0:0:0:0:0:0
0:0:0:0:0:0
0:0:0:0:0:0
Actions #2

Updated by Electric Monk almost 2 years ago

  • Status changed from New to Closed
  • % Done changed from 0 to 100

git commit 537911b676ea740315ce9055d857ea1d626e6fe7

commit  537911b676ea740315ce9055d857ea1d626e6fe7
Author: Ryan Zezeski <rpz@joyent.com>
Date:   2020-05-21T16:40:18.000Z

    12753 simnet requests zero-sized kmem alloc
    Reviewed by: Robert Mustacchi <rm@joyent.com>
    Approved by: Dan McDonald <danmcd@joyent.com>

Actions

Also available in: Atom PDF