Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Closed
maghul opened this issue Apr 11, 2016 · 8 comments

Comments

@maghul
Copy link

maghul commented Apr 11, 2016

Please answer these questions before submitting your issue. Thanks!

  1. What version of Go are you using (go version)?
    go version go1.6 linux/amd64
  2. 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"
  3. 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
@bradfitz 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 bradfitz added this to the Unplanned milestone Apr 11, 2016
@mikioh 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
Copy link
Contributor

mikioh commented Apr 11, 2016

@maghul,

Do you have any numbers on performance?

@maghul
Copy link
Author

maghul commented Apr 11, 2016

@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 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
@mikioh
Copy link
Contributor

mikioh commented Apr 12, 2016

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
Copy link
Contributor

mikioh commented Apr 12, 2016

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

@maghul
Copy link
Author

maghul commented Apr 12, 2016

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
Copy link
Contributor

mikioh commented Apr 13, 2016

@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
Copy link
Author

maghul commented Apr 13, 2016

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
Copy link

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

@mikioh mikioh removed their assignment Apr 15, 2016
@mikioh mikioh modified the milestones: Go1.7, Unplanned Apr 15, 2016
@golang golang locked and limited conversation to collaborators Apr 15, 2017
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

4 participants