Reading from PTY in OSX makes the CPU go to 100%

[kristoiv]

The following go code running on OSX (version 10.12.6, MacBook Pro (Retina, 15-inch, Mid 2014)) will cause the CPU to go to 100% within 10 seconds, and stay there. It is due to the io.Copy(stdout, t) line. It doesn't happen on Ubuntu 16.04 (nor Android 5.1.1).

Anyone have any ideas as to why?

package main

import (
	"io"
	"log"
	"os"
	"os/exec"

	"golang.org/x/crypto/ssh/terminal"

	"github.com/kr/pty"
)

func main() {
	stdin := os.Stdin
	stdout := os.Stdout

	os.Stdin = nil
	os.Stdout = nil
	// os.Stderr = nil

	bash := exec.Command("/bin/bash")

	// Allocate a terminal for this channel
	t, err := pty.Start(bash)
	if err != nil {
		log.Fatalf("Could not start pty (%s)\n", err)
	}

	_, err = terminal.MakeRaw(int(stdin.Fd()))
	if err != nil {
		log.Fatalln(err)
	}

	go func() {
		if _, err := io.Copy(stdout, t); err != nil {
			log.Fatalln(err)
		}
	}()

	if _, err := io.Copy(t, stdin); err != nil {
		log.Fatalln(err)
	}
}

[kristoiv]

I also tried writing my own copy function to see what was happening, log a little, but there is no use as it is a single Read(buf) when there is nothing to read that blocks and races the cpu @ 100%.

[creack]

Could you confirm the golang version for both your OSX and Ubuntu tests?

[kristoiv]

Docker container golang:latest (id=1cdc81f11b10):
root@7a0e3a0ec696:/go# go version
go version go1.9 linux/amd64
root@7a0e3a0ec696:/go# cat /etc/*release
PRETTY_NAME="Debian GNU/Linux 9 (stretch)"
NAME="Debian GNU/Linux"
VERSION_ID="9"
VERSION="9 (stretch)"
ID=debian

OSX version 10.12.6:
$ go version
go version go1.9 darwin/amd64

[creack]

Thanks. For reference, I reproduced the issue with:

package main

import (
        "github.com/kr/pty"
)

func main() {
        pty, _, err := pty.Open()
        if err != nil {
                panic(err)
        }
        _, _ = pty.Read([]byte{0})
}

[creack]

After investigating, it looks like the issues comes from flags added by Go's stdlib.

Consider the following snippet:

package main

import (
	"errors"
	"os"
	"syscall"
	"unsafe"
)

func ioctl(fd, cmd, ptr uintptr) error {
	if _, _, e := syscall.Syscall(syscall.SYS_IOCTL, fd, cmd, ptr); e != 0 {
		return e
	}
	return nil
}

func grantpt(fd uintptr) error {
	return ioctl(fd, syscall.TIOCPTYGRANT, 0)
}

func unlockpt(fd uintptr) error {
	return ioctl(fd, syscall.TIOCPTYUNLK, 0)
}

func ptsname(fd uintptr) (string, error) {
	n := make([]byte, 128)
	if err := ioctl(fd, syscall.TIOCPTYGNAME, uintptr(unsafe.Pointer(&n[0]))); err != nil {
		return "", err
	}

	for i, c := range n {
		if c == 0 {
			return string(n[:i]), nil
		}
	}
	return "", errors.New("TIOCPTYGNAME string not NUL-terminated")
}

func main1() {
	// Open master.
	ptmxFd, err := syscall.Open("/dev/ptmx", syscall.O_RDWR, 0)
	if err != nil {
		panic(err)
	}
	fd := uintptr(ptmxFd)

	// Fetch next available slave.
	sname, err := ptsname(fd)
	if err != nil {
		panic(err)
	}
	// Grant/unlock slave.
	if err := grantpt(fd); err != nil {
		panic(err)
	}
	if err := unlockpt(fd); err != nil {
		panic(err)
	}

	// Open slave.
	tFd, err := syscall.Open(sname, syscall.O_RDWR, 0)
	if err != nil {
		panic(err)
	}
	_ = tFd

	// Read master.
	if _, err := syscall.Read(ptmxFd, []byte{0}); err != nil {
		panic(err)
	}
}

func main() {
	// Open master.
	ptmx, err := os.OpenFile("/dev/ptmx", os.O_RDWR, 0)
	if err != nil {
		panic(err)
	}
	fd := ptmx.Fd()

	// Fetch next available slave.
	sname, err := ptsname(fd)
	if err != nil {
		panic(err)
	}
	// Grant/unlock slave.
	if err := grantpt(fd); err != nil {
		panic(err)
	}
	if err := unlockpt(fd); err != nil {
		panic(err)
	}

	// Open slave.
	t, err := os.OpenFile(sname, os.O_RDWR, 0)
	if err != nil {
		panic(err)
	}
	_ = t

	// Read slave.
	if _, err := ptmx.Read([]byte{0}); err != nil {
		panic(err)
	}
}

main() uses 100% while main1() works as expected. A fix might be as simple as using syscall instead of os, but I'm still digging to see exactly where it comes from.

[kristoiv]

Great work! Very interesting.

[creack]

Ok, I confirm the issue, it is due to the os.OpenFile() behavior.

os.OpenFile calls os.newFile with the pollable flag true here: https://github.com/golang/go/blob/9f7fd893dc455339233a8e081f5fb5e2c51e7b5d/src/os/file_unix.go#L186

This in turn tries to add the file to the poller. https://github.com/golang/go/blob/9f7fd893dc455339233a8e081f5fb5e2c51e7b5d/src/os/file_unix.go#L105

It then sets the non-block flag, which fails on the master, but works on the slave, my guess is that this is why it ends up taking 100% CPU https://github.com/golang/go/blob/9f7fd893dc455339233a8e081f5fb5e2c51e7b5d/src/os/file_unix.go#L115

I'm working on a fix now and I'll submit a report upstream to see if it is an expected behavior from the lib or an actual bug. I think the lib should expose a way to toggle the pollable flag instead of forcing it.

[creack]

@kristoiv You can use #53 for now, if nobody objects, I'll merge this week.

[creack]

Solved by #53