net: zoneToIndex will not cache the RIB and is called on each IPv6-linklocal datagram read #15237

maghul · 2016-04-11T20:41:06Z

Please answer these questions before submitting your issue. Thanks!

What version of Go are you using (go version)?
go version go1.6 linux/amd64
What operating system and processor architecture are you using (go env)?
GOARCH="amd64"
GOBIN=""
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/home/magnus/Projects/go"
GORACE=""
GOROOT="/opt/go"
GOTOOLDIR="/opt/go/pkg/tool/linux_amd64"
GO15VENDOREXPERIMENT="1"
CC="gcc"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0"
CXX="g++"
CGO_ENABLED="1"
What did you do?
If possible, provide a recipe for reproducing the error.
A complete runnable program is good.
A link on play.golang.org is best.

This is a performance issue rather than an error. When ReadFromUDP returns with an IPv6
address of the peer it will map the Zone field using zoneToString. This will call syscall.NetlinkRIB
to get the interfaces of the host. This information is not cached and syscall.NetlinkRIB will be called
for every received packet.

To see the problem the following code can be run with strace -f on linux:

package main

import (
    "net"
    "fmt"
)

var myhost="fe80::461e:a1ff:fece:f4a9"

func transmitter(port int) {
    b := make([]byte,1200)

    raddr, err := net.ResolveUDPAddr("udp6", fmt.Sprintf("[%s]:%d",myhost, port))
    if err!=nil {
        panic(err)
    }

    conn, err := net.ListenUDP("udp6", nil)
    if err!=nil {
        panic(err)
    }
    for ii:=2; ii>0; ii-- {
        _, err := conn.WriteToUDP(b,raddr)
        if err!=nil {
            panic(err)
        }
    }


}


func receiver() (int, chan bool) {
    laddr,err := net.ResolveUDPAddr("udp6", ":0")
    if err!=nil {
        panic(err)
    }

    conn, err := net.ListenUDP("udp6", laddr)
    if err!=nil {
        panic(err)
    }

    dc := make(chan bool)

    go func() {
        b := make([]byte,1200)
        for ii:=2; ii>0; ii-- {
            fmt.Println( "                       PRE ReadFromUDP" )
            _, addr, err := conn.ReadFromUDP(b)
            fmt.Println( "                       POST ReadFromUDP, addr=", addr.Zone )
            if err!=nil {
                panic(err)
            }

        }
        dc <- true
    }()
    return conn.LocalAddr().(*net.UDPAddr).Port, dc

}

func main() {
    port, dc := receiver()

       transmitter(port)

    <- dc
}

```-------------------------------------------------------------------------------------

4. What did you expect to see?

Running the testcode with strace in linux I get
    .
    .
    . 
7[pid 23098] write(1, "                       PRE ReadF"..., 39                       PRE ReadFromUDP
 <unfinished ...>
[pid 23099] <... select resumed> )      = 0 (Timeout)
[pid 23098] <... write resumed> )       = 39
[pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
[pid 23098] recvfrom(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1200, 0, {sa_family=AF_INET6, sin6_port=htons(50115), inet_pton(AF_INET6, "fe80::461e:a1ff:fece:f4a9", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=if_nametoindex("eth0")}, [28]) = 1200
[pid 23099] <... select resumed> )      = 0 (Timeout)
[pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
[pid 23098] write(1, "interfaceTable ifindex= 2\n", 26interfaceTable ifindex= 2
) = 26
[pid 23098] socket(PF_NETLINK, SOCK_RAW, 0) = 6
[pid 23099] <... select resumed> )      = 0 (Timeout)
[pid 23098] bind(6, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12 <unfinished ...>
[pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
[pid 23098] <... bind resumed> )        = 0
[pid 23098] sendto(6, "\21\0\0\0\22\0\1\3\1\0\0\0\0\0\0\0\0", 17, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12 <unfinished ...>
[pid 23099] <... select resumed> )      = 0 (Timeout)
[pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
[pid 23098] <... sendto resumed> )      = 17
[pid 23098] recvfrom(6,  <unfinished ...>
[pid 23099] <... select resumed> )      = 0 (Timeout)
[pid 23098] <... recvfrom resumed> "|\4\0\0\20\0\2\0\1\0\0\0:Z\0\0\0\0\4\3\1\0\0\0I\0\1\0\0\0\0\0"..., 4096, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, [12]) = 3452
[pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
[pid 23098] getsockname(6, {sa_family=AF_NETLINK, pid=23098, groups=00000000}, [12]) = 0
[pid 23098] getsockname(6, {sa_family=AF_NETLINK, pid=23098, groups=00000000}, [12]) = 0
[pid 23099] <... select resumed> )      = 0 (Timeout)
[pid 23098] getsockname(6,  <unfinished ...>
[pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
[pid 23098] <... getsockname resumed> {sa_family=AF_NETLINK, pid=23098, groups=00000000}, [12]) = 0
[pid 23098] recvfrom(6, "\24\0\0\0\3\0\2\0\1\0\0\0:Z\0\0\0\0\0\0", 4096, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, [12]) = 20
[pid 23098] getsockname(6,  <unfinished ...>
[pid 23099] <... select resumed> )      = 0 (Timeout)
[pid 23098] <... getsockname resumed> {sa_family=AF_NETLINK, pid=23098, groups=00000000}, [12]) = 0
[pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
[pid 23099] <... select resumed> )      = 0 (Timeout)
[pid 23098] write(1, "ReadMsgUDP:IPv6: addr [fe80::461"..., 73 <unfinished ...>
ReadMsgUDP:IPv6: addr [fe80::461e:a1ff:fece:f4a9%eth0]:50115 , zoneid= 2
[pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
[pid 23098] <... write resumed> )       = 73
[pid 23098] write(1, "                       POST Read"..., 52                       POST ReadFromUDP, addr= eth0
) = 52
[pid 23098] write(1, "                       PRE ReadF"..., 39 <unfinished ...>
                       PRE ReadFromUDP
[pid 23099] <... select resumed> )      = 0 (Timeout)
[pid 23098] <... write resumed> )       = 39
[pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
[pid 23098] recvfrom(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1200, 0, {sa_family=AF_INET6, sin6_port=htons(50115), inet_pton(AF_INET6, "fe80::461e:a1ff:fece:f4a9", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=if_nametoindex("eth0")}, [28]) = 1200
[pid 23098] write(1, "interfaceTable ifindex= 2\n", 26 <unfinished ...>
interfaceTable ifindex= 2
[pid 23099] <... select resumed> )      = 0 (Timeout)
[pid 23098] <... write resumed> )       = 26
[pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
[pid 23098] write(1, "ReadMsgUDP:IPv6: addr [fe80::461"..., 73ReadMsgUDP:IPv6: addr [fe80::461e:a1ff:fece:f4a9%eth0]:50115 , zoneid= 2
) = 73
[pid 23099] <... select resumed> )      = 0 (Timeout)
[pid 23098] write(1, "                       POST Read"..., 52                       POST ReadFromUDP, addr= eth0


5. What did you see instead?


Running the testcode with strace in linux I get
    .
    .
    . 
7[pid 23098] write(1, "                       PRE ReadF"..., 39                       PRE ReadFromUDP
 <unfinished ...>
[pid 23099] <... select resumed> )      = 0 (Timeout)
[pid 23098] <... write resumed> )       = 39
[pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
[pid 23098] recvfrom(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1200, 0, {sa_family=AF_INET6, sin6_port=htons(50115), inet_pton(AF_INET6, "fe80::461e:a1ff:fece:f4a9", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=if_nametoindex("eth0")}, [28]) = 1200
[pid 23099] <... select resumed> )      = 0 (Timeout)
[pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
[pid 23098] write(1, "interfaceTable ifindex= 2\n", 26interfaceTable ifindex= 2
) = 26
[pid 23098] socket(PF_NETLINK, SOCK_RAW, 0) = 6
[pid 23099] <... select resumed> )      = 0 (Timeout)
[pid 23098] bind(6, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12 <unfinished ...>
[pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
[pid 23098] <... bind resumed> )        = 0
[pid 23098] sendto(6, "\21\0\0\0\22\0\1\3\1\0\0\0\0\0\0\0\0", 17, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12 <unfinished ...>
[pid 23099] <... select resumed> )      = 0 (Timeout)
[pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
[pid 23098] <... sendto resumed> )      = 17
[pid 23098] recvfrom(6,  <unfinished ...>
[pid 23099] <... select resumed> )      = 0 (Timeout)
[pid 23098] <... recvfrom resumed> "|\4\0\0\20\0\2\0\1\0\0\0:Z\0\0\0\0\4\3\1\0\0\0I\0\1\0\0\0\0\0"..., 4096, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, [12]) = 3452
[pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
[pid 23098] getsockname(6, {sa_family=AF_NETLINK, pid=23098, groups=00000000}, [12]) = 0
[pid 23098] getsockname(6, {sa_family=AF_NETLINK, pid=23098, groups=00000000}, [12]) = 0
[pid 23099] <... select resumed> )      = 0 (Timeout)
[pid 23098] getsockname(6,  <unfinished ...>
[pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
[pid 23098] <... getsockname resumed> {sa_family=AF_NETLINK, pid=23098, groups=00000000}, [12]) = 0
[pid 23098] recvfrom(6, "\24\0\0\0\3\0\2\0\1\0\0\0:Z\0\0\0\0\0\0", 4096, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, [12]) = 20
[pid 23098] getsockname(6,  <unfinished ...>
[pid 23099] <... select resumed> )      = 0 (Timeout)
[pid 23098] <... getsockname resumed> {sa_family=AF_NETLINK, pid=23098, groups=00000000}, [12]) = 0
[pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
[pid 23098] close(6)                    = 0
[pid 23099] <... select resumed> )      = 0 (Timeout)
[pid 23098] write(1, "ReadMsgUDP:IPv6: addr [fe80::461"..., 73 <unfinished ...>
ReadMsgUDP:IPv6: addr [fe80::461e:a1ff:fece:f4a9%eth0]:50115 , zoneid= 2
[pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
[pid 23098] <... write resumed> )       = 73
[pid 23098] write(1, "                       POST Read"..., 52                       POST ReadFromUDP, addr= eth0
) = 52
[pid 23098] write(1, "                       PRE ReadF"..., 39 <unfinished ...>
                       PRE ReadFromUDP
[pid 23099] <... select resumed> )      = 0 (Timeout)
[pid 23098] <... write resumed> )       = 39
[pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
[pid 23098] recvfrom(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 1200, 0, {sa_family=AF_INET6, sin6_port=htons(50115), inet_pton(AF_INET6, "fe80::461e:a1ff:fece:f4a9", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=if_nametoindex("eth0")}, [28]) = 1200
[pid 23098] write(1, "interfaceTable ifindex= 2\n", 26 <unfinished ...>
interfaceTable ifindex= 2
[pid 23099] <... select resumed> )      = 0 (Timeout)
[pid 23098] <... write resumed> )       = 26
[pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>

            These commands are a superfluous read of the RIB
                            [pid 23098] socket(PF_NETLINK, SOCK_RAW, 0) = 6
                [pid 23098] bind(6, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 0
                [pid 23098] sendto(6, "\21\0\0\0\22\0\1\3\1\0\0\0\0\0\0\0\0", 17, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12 <unfinished ...>
                [pid 23099] <... select resumed> )      = 0 (Timeout)
                [pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
                [pid 23098] <... sendto resumed> )      = 17
                [pid 23098] recvfrom(6, "|\4\0\0\20\0\2\0\1\0\0\0:Z\0\0\0\0\4\3\1\0\0\0I\0\1\0\0\0\0\0"..., 4096, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, [12]) = 3452
                [pid 23099] <... select resumed> )      = 0 (Timeout)
                [pid 23098] mmap(NULL, 1439992, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0 <unfinished ...>
                [pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
                [pid 23098] <... mmap resumed> )        = 0x2b7c4c96e000
                [pid 23098] getsockname(6, {sa_family=AF_NETLINK, pid=23098, groups=00000000}, [12]) = 0
                [pid 23098] getsockname(6,  <unfinished ...>
                [pid 23099] <... select resumed> )      = 0 (Timeout)
                [pid 23098] <... getsockname resumed> {sa_family=AF_NETLINK, pid=23098, groups=00000000}, [12]) = 0
                [pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
                [pid 23098] getsockname(6, {sa_family=AF_NETLINK, pid=23098, groups=00000000}, [12]) = 0
                [pid 23098] recvfrom(6, "\24\0\0\0\3\0\2\0\1\0\0\0:Z\0\0\0\0\0\0", 4096, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, [12]) = 20
                [pid 23098] getsockname(6,  <unfinished ...>
                [pid 23099] <... select resumed> )      = 0 (Timeout)
                [pid 23098] <... getsockname resumed> {sa_family=AF_NETLINK, pid=23098, groups=00000000}, [12]) = 0
                [pid 23099] select(0, NULL, NULL, NULL, {0, 20} <unfinished ...>
                [pid 23098] close(6)                    = 0
[pid 23098] write(1, "ReadMsgUDP:IPv6: addr [fe80::461"..., 73ReadMsgUDP:IPv6: addr [fe80::461e:a1ff:fece:f4a9%eth0]:50115 , zoneid= 2
) = 73
[pid 23099] <... select resumed> )      = 0 (Timeout)
[pid 23098] write(1, "                       POST Read"..., 52                       POST ReadFromUDP, addr= eth0

The text was updated successfully, but these errors were encountered:

mikioh · 2016-04-11T22:17:51Z

@maghul,

Do you have any numbers on performance?

maghul · 2016-04-11T23:44:45Z

@mikioh,

No, not yet.

The UDP traffic I need to handle is too slow to be impacted by this. What
made me notice it was when I heap-profiled my code and ~90% of all allocations
were in syscall.NetlinkRIB.

I will try to make some kind of test-bench to compare ReadFromUDP and plain Read
on a "connected" UDP socket.

mikioh · 2016-04-12T00:25:43Z

You perhaps might find github.com/mikioh/bulk helpful. It implements dumb cache for IPv6 addressing scope zone. Out of curiosity, what's your application? I wonder (nowadays) what type of application requires really fast (up to 1G bps/1.5M pps?) UDP over IPv6-linklocal transport, except peer-to-peer stuff on wireless/mobile ad-hoc network.

mikioh · 2016-04-12T00:49:11Z

Unlink BSD variants, some Linux distributions restrict IPv6-linklocal traffic for some reasons. You need to let them free before IPv6-linklocal benchmarking.

maghul · 2016-04-12T15:28:13Z

My applications are two different RTP implementations. One is audio over RTP and the second is RTP-MIDI. Neither have high bandwidth requirements. The RTP-MIDI protocol is however quite sensitive to latency and jitter. The RTP audio is not as sensitive but the lower the latency the better.

I have made some performance tests. The code is at

http://play.golang.org/p/CTzoRQSt6l

it can't be run on the playground of course.

When running it in linux I get

magnus@durer ~/Projects/go $ ./ribperf -count=10000 -readfrom
Starting receiver using udpConn.ReadFromUDP
Starting transmitter on IP= fe80::461e:a1ff:fece:f4a9
Transmitted  91865  packet, received  10000  packets, duration= 712.561593ms

magnus@durer ~/Projects/go $ ./ribperf -count=10000
Starting receiver using udpConn.Read
Starting transmitter on IP= fe80::461e:a1ff:fece:f4a9
Transmitted  10001  packet, received  10000  packets, duration= 81.208198ms
magnus@durer ~/Projects/go $

and it's even worse on Windows, albeit on a slower machine:

m:\Projects\go>ribperf.exe -count=10000 -readfrom
Starting receiver using udpConn.ReadFromUDP
Starting transmitter on IP= fe80::f593:7c86:f18e:7eaf
Transmitted  699598  packet, received  10000  packets, duration= 14.0954094s

m:\Projects\go>ribperf.exe -count=10000
Starting receiver using udpConn.Read
Starting transmitter on IP= fe80::f593:7c86:f18e:7eaf
Transmitted  10000  packet, received  10000  packets, duration= 245.0245ms

m:\Projects\go>

mikioh · 2016-04-13T01:28:43Z

@maghul,

Is there any specific reason why not to use IPv6 global addresses for your datagram-based real-time application? Just for benchmarking? I think the workaround would be to use IPv6 addresses that are greater than link-local scope.

Also I made a simple patch. What happens when you give https://go-review.googlesource.com/#/c/21952/ a shot?

maghul · 2016-04-13T16:17:17Z

I'm not really in control of the addresses if the hosts where the code will run. I worked around the problem in my code already using UDPConn.Read instead of UDPConn.ReadFromUDP
which works well in my case.

I tried the patch and the performance looks good.

magnus@durer ~/Projects/go $ ./ribperf -readfrom -count=1000000
Starting receiver using udpConn.ReadFromUDP
Starting transmitter on IP= fe80::a11:96ff:fe1c:a8bc
Transmitted  1000038  packet, received  1000000  packets, duration= 6.040882167s
magnus@durer ~/Projects/go $ ./ribperf -count=1000000
Starting receiver using udpConn.Read
Starting transmitter on IP= fe80::a11:96ff:fe1c:a8bc
Transmitted  1000001  packet, received  1000000  packets, duration= 6.023831995s

Looks OK in Windows too

magnus@CHIMAY /cygdrive/m/Projects/go$ ./ribperf.exe -count 100000
Starting receiver using udpConn.Read
zone= Local Area Connection
Starting transmitter on IP= fe80::f593:7c86:f18e:7eaf
Transmitted  100989  packet, received  100000  packets, duration= 2.2151716s

magnus@CHIMAY /cygdrive/m/Projects/go$ ./ribperf.exe -readfrom -count 100000
Starting receiver using udpConn.ReadFromUDP
zone= Local Area Connection
Starting transmitter on IP= fe80::f593:7c86:f18e:7eaf
Transmitted  100943  packet, received  100000  packets, duration= 2.3711696s

gopherbot · 2016-04-14T04:00:53Z

CL https://golang.org/cl/21952 mentions this issue.

bradfitz changed the title ~~zoneToIndex will not cache the RIB and is called on every ReadFromUDP~~ net: zoneToIndex will not cache the RIB and is called on every ReadFromUDP Apr 11, 2016

bradfitz added this to the Unplanned milestone Apr 11, 2016

bradfitz added the Performance label Apr 11, 2016

bradfitz assigned mikioh Apr 11, 2016

mikioh changed the title ~~net: zoneToIndex will not cache the RIB and is called on every ReadFromUDP~~ net: zoneToIndex will not cache the RIB and is called on every IPv6-linklocal datagram reads Apr 11, 2016

mikioh changed the title ~~net: zoneToIndex will not cache the RIB and is called on every IPv6-linklocal datagram reads~~ net: zoneToIndex will not cache the RIB and is called on each IPv6-linklocal datagram read Apr 12, 2016

gopherbot closed this as completed in 1d214f7 Apr 15, 2016

mikioh removed their assignment Apr 15, 2016

mikioh modified the milestones: Go1.7, Unplanned Apr 15, 2016

golang locked and limited conversation to collaborators Apr 15, 2017

gopherbot added the FrozenDueToAge label Apr 15, 2017

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

net: zoneToIndex will not cache the RIB and is called on each IPv6-linklocal datagram read #15237

net: zoneToIndex will not cache the RIB and is called on each IPv6-linklocal datagram read #15237

maghul commented Apr 11, 2016

mikioh commented Apr 11, 2016

maghul commented Apr 11, 2016

mikioh commented Apr 12, 2016

mikioh commented Apr 12, 2016

maghul commented Apr 12, 2016

mikioh commented Apr 13, 2016

maghul commented Apr 13, 2016

gopherbot commented Apr 14, 2016

net: zoneToIndex will not cache the RIB and is called on each IPv6-linklocal datagram read #15237

net: zoneToIndex will not cache the RIB and is called on each IPv6-linklocal datagram read #15237

Comments

maghul commented Apr 11, 2016

mikioh commented Apr 11, 2016

maghul commented Apr 11, 2016

mikioh commented Apr 12, 2016

mikioh commented Apr 12, 2016

maghul commented Apr 12, 2016

mikioh commented Apr 13, 2016

maghul commented Apr 13, 2016

gopherbot commented Apr 14, 2016