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

os: reading from tun device after using command pipe: read /dev/net/tun: not pollable #38618

Closed
mandelsoft opened this issue Apr 23, 2020 · 11 comments
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone

Comments

@mandelsoft
Copy link

What version of Go are you using (go version)?

$ go version
go version go1.13.10 linux/amd64
go version go1.14.2 linux/amd64

Does not appear with 1.12

Does this issue reproduce with the latest release?

yes

What operating system and processor architecture are you using (go env)?

go env Output
$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/root/.cache/go-build"
GOENV="/root/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/root/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/home/d021770/dev/go/ip/src/github.com/mandelsoft/k8sbridge/go.mod"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build606326318=/tmp/go-build -gno-record-gcc-switches"

What did you do?

I'm creating a tun device and trying to read from it.
Read aborts with the error read /dev/net/tun: not pollable, if before creating the tun device (file descriptor) an exec.Command is executed, but only if this catches the output.

Calling the program below with argument no works.
If argument yes is given, the problem occurs in most of the cases, but not always.

If the output is not catched (remove c.Stdout` assignment in code below) it also works if the
command is executed before the interface creation.

package main

import (
	"bytes"
	"fmt"
	"log"
	"os"
	"os/exec"
	"sync"
	"syscall"
	"unsafe"

	"github.com/pkg/errors"
	"github.com/vishvananda/netlink"
	"golang.org/x/sys/unix"
)

const TUNIP = "192.168.1.2"
const TUNCIDR = TUNIP + "/24"


func ExitOnErr(msg string, args ...interface{}) {
	if args[len(args)-1] == nil {
		return
	}
	fmt.Printf(msg+": %s\n", args...)
	os.Exit(1)
}

func echo(text string) {
	c := exec.Command("echo",  text)
	var out bytes.Buffer
	c.Stdout = &out
	c.Start()
	c.Wait()
	fmt.Printf("-> %s\n", out.String())
}

func cstringToGoString(cstring []byte) string {
	strs := bytes.Split(cstring, []byte{0x00})
	return string(strs[0])
}

type ifreq struct {
	name  [unix.IFNAMSIZ]byte // c string
	flags uint16                 // c short
	_pad  [24 - unsafe.Sizeof(uint16(0))]byte
}

func ioctl(fd, request uintptr, argp unsafe.Pointer) error {
	if _, _, e := syscall.Syscall6(syscall.SYS_IOCTL, fd, request, uintptr(argp), 0, 0, 0); e != 0 {
		return e
	}
	return nil
}

func createInterface(flags uint16, name string) (string, *os.File, error) {
	// Last byte of name must be nil for C string, so name must be
	// short enough to allow that
	if len(name) > syscall.IFNAMSIZ-1 {
		return "", nil, errors.New("device name too long")
	}

	f, err := os.OpenFile("/dev/net/tun", os.O_RDWR, 0600)
	if err != nil {
		return "", nil, err
	}

	var nbuf [syscall.IFNAMSIZ]byte
	copy(nbuf[:], []byte(name))

	fd := f.Fd()
	ifr := ifreq{
		name:  nbuf,
		flags: flags,
	}
	if err := ioctl(fd, syscall.TUNSETIFF, unsafe.Pointer(&ifr)); err != nil {
		return "", nil, err
	}
	return cstringToGoString(ifr.name[:]), f, nil
}

func main() {
	problem := len(os.Args) > 1 && os.Args[1]=="yes"

	if problem {
		echo("with problem")
	}

	name, fd, err:= createInterface(unix.IFF_TUN|unix.IFF_NO_PI, "")
	ExitOnErr("cannot create tun", err)
	fmt.Printf("tun: %s\n", name)

	if !problem {
		echo("without problem")
	}

	link, err := netlink.LinkByName(name)
	ExitOnErr("cannot get link %q", name, err)

	addr, err := netlink.ParseAddr(TUNCIDR)
	ExitOnErr("cannot create addr %q", TUNCIDR, err)

	err = netlink.AddrAdd(link, addr)
	ExitOnErr("cannot add addr %q", TUNCIDR, err)

	err = netlink.LinkSetUp(link)
	ExitOnErr("cannot bring up %q", name, err)


	wait := sync.WaitGroup{}
	wait.Add(1)

	go func() {
		buffer := [2000]byte{}
		for {
			n, err := fd.Read(buffer[:])  // booom
			if n <= 0 || err != nil {
				fmt.Printf("END: %d bytes, err=%s\n", n, err)
				break
			}
			log.Printf("Read %d bytes", n)
		}
		wait.Done()
	}()

	wait.Wait()
	log.Print("Closing")
	err = fd.Close()
	if err != nil {
		log.Print("Close errored: ", err)
	}
	log.Print("Exiting")
}

What did you expect to see?

I expect the read to work and the program should print the size of the packet send to the tun device.

What did you see instead?

Instead the read failed with the error read /dev/net/tun: not pollable

@andybons
Copy link
Member

#30426 seems related

@crvv who had valuable insight before

@andybons andybons changed the title Reading from tun device after using command pipe: read /dev/net/tun: not pollable os: reading from tun device after using command pipe: read /dev/net/tun: not pollable Apr 23, 2020
@andybons andybons added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Apr 23, 2020
@andybons andybons added this to the Unplanned milestone Apr 23, 2020
@mandelsoft
Copy link
Author

Hi @andybons,

I've also tried the SysConn variant

s, _ := fd.SyscallConn()
s.Control(func(fd uintptr) {
		_, _, errno = unix.Syscall(
			unix.SYS_IOCTL,
			fd,
			uintptr(unix.TUNSETIFF),
			uintptr(unsafe.Pointer(&ifr[0])),
           )
})

It works even worse. It completely blocks the Read call. The fix here is to add an fd.Fd() call in front of the reading loop. But even with this workaround, I get the not pollable error once I try to read from the file descriptor.
It really seems to be related to the usage of the pipe for the command execution of the exec.Command execution prior to the unix.Syscall or syscall.Syscall stuff used for the tun creation.

@ianlancetaylor
Copy link
Contributor

I can get the problem to occur when running the program without an argument, although it fails much more often with the argument "yes".

@ianlancetaylor
Copy link
Contributor

An strace shows

[pid  6403] openat(AT_FDCWD, "/dev/net/tun", O_RDWR|O_CLOEXEC <unfinished ...>
[pid  6403] <... openat resumed> )      = 3
[pid  6403] epoll_ctl(4, EPOLL_CTL_ADD, 3, {EPOLLIN|EPOLLOUT|EPOLLRDHUP|EPOLLET, {u32=1803304728, u64=139828758593304}} <unfinished ...>
[pid  6403] <... epoll_ctl resumed> )   = 0
[pid  6406] <... epoll_pwait resumed> [{EPOLLERR, {u32=1803304728, u64=139828758593304}}], 128, -1, NULL, 0) = 1

In other words, we can successfully register the descriptor with epoll, but epoll then immediately reports an error on the newly registered descriptor. We record that error and wind up reporting it back to the program as not pollable.

@ianlancetaylor
Copy link
Contributor

@mandelsoft Could you see if https://golang.org/cl/229764 fixes the problem for you? Thanks.

@gopherbot
Copy link

Change https://golang.org/cl/229764 mentions this issue: internal/poll: treat immediate poll error as non-pollable file

@crvv
Copy link
Contributor

crvv commented Apr 25, 2020

Please see #30426.

The tun fd is put into epoll before ioctl, so epoll won't work on that fd.
But function createInterface calls (*os.File).Fd, which put the fd into blocking mode.
So Read can work without epoll.
The fix is simple. Use unix.Open, ioctl, unix.SetNonBlock and os.NewFile.

The EPOLLERR returned by epoll_wait is #30426 (comment)

But it returns EPOLLERR only if epoll_wait is called before ioctl.
If ioctl is called before epoll_wait, epoll_wait will never return that EPOLLERR. And in this case, epoll still doesn't work on that fd.

With CL 229764, it will always work if the fd is in blocking mode.

@mandelsoft
Copy link
Author

mandelsoft commented Apr 25, 2020

Hi @crvv, thank you very much, using unix.Open instead of os.OpenFile and setting the fd to NonBlocking seems to solve the problem, it also works in my original project.

Maybe someone should bring this fix to the pkg/taptun project. That's the first search result when using google to look for golang taptunor golang tun.

@ianlancetaylor
Copy link
Contributor

@mandelsoft @crvv Do you think it would be a good idea to apply CL 229764, or should we just treat this as a Linux kernel bug that can be worked around in Go code by using unix.Open?

@mandelsoft
Copy link
Author

I'm not so deep into this OS topic to decide on this. I just found this taptun library and tried to used it.

@ianlancetaylor
Copy link
Contributor

OK, thanks. Closing this issue as there is a workaround.

scareything added a commit to openziti/edge that referenced this issue Aug 6, 2020
scareything added a commit to openziti/edge that referenced this issue Aug 7, 2020
@golang golang locked and limited conversation to collaborators Apr 27, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Projects
None yet
Development

No branches or pull requests

5 participants