influx-cli icon indicating copy to clipboard operation
influx-cli copied to clipboard

influx write hangs when executed via ssh non-interactively

Open adrian-thurston opened this issue 4 years ago • 0 comments

Problem

Running the following, where the line protocol input is only 4 lines, the influx binary hangs after writing the data.

ssh thurston07 ./build/influx-cli/bin/linux/influx write \
    --host http://window2-regression.a.influxcloud.dev.local \
    --org perf \
    --bucket perf \
    --token yxBdXF3qfHchfC4QaYIxN8hBGiTaj7_fuaxsWNZ5b0HxBGs29ulRsAWSro1_G9GXsu6eeaxeiRFnHPILKf38iQ== \
    -f local-ssd/window2-regression/working/window2-regression-tools-jaeger-traces-data.lp

Workaround

If I login to the machine first to get an interactive shell, the command exits after writing. If I add a step to explicitly close stdin, then the process also exits no problem:

ssh thurston07 echo '|' ./build/influx-cli/bin/linux/influx write \
    --host http://window2-regression.a.influxcloud.dev.local \
    --org perf \
    --bucket perf \
    --token yxBdXF3qfHchfC4QaYIxN8hBGiTaj7_fuaxsWNZ5b0HxBGs29ulRsAWSro1_G9GXsu6eeaxeiRFnHPILKf38iQ== \
    -f local-ssd/window2-regression/working/window2-regression-tools-jaeger-traces-data.lp

Investigation

When I run non-interactively (failure to terminate), the process's STDIO file descriptors are pipes:

lr-x------ 1 thurston thurston 64 Sep 15 00:28 0 -> 'pipe:[1906281]'
l-wx------ 1 thurston thurston 64 Sep 15 00:28 1 -> 'pipe:[1906282]'
l-wx------ 1 thurston thurston 64 Sep 15 00:28 2 -> 'pipe:[1906283]'

When run interactively they are a pseudo TTY. They look something like this:

lrwx------ 1 thurston thurston 64 Sep 14 17:44 0 -> /dev/pts/22
lrwx------ 1 thurston thurston 64 Sep 14 17:44 1 -> /dev/pts/22
lrwx------ 1 thurston thurston 64 Sep 14 17:44 2 -> /dev/pts/22

When I attach to the blocked process (non-interactive, without the echo to close stdin):

(dlv) goroutines
  Goroutine 1 - User: ./build/influx-cli/clients/write/buffer_batcher.go:45 github.com/influxdata/influx-cli/v2/clients/write.(*BufferBatcher).WriteBatches (0xa5cc0d) [select]
  Goroutine 2 - User: /opt/golang/1.16.5/src/runtime/proc.go:337 runtime.gopark (0x438f45) [force gc (idle)]
  Goroutine 3 - User: /opt/golang/1.16.5/src/runtime/proc.go:337 runtime.gopark (0x438f45) [GC sweep wait]
  Goroutine 4 - User: /opt/golang/1.16.5/src/runtime/proc.go:337 runtime.gopark (0x438f45) [GC scavenge wait]
  Goroutine 5 - User: /opt/golang/1.16.5/src/runtime/proc.go:337 runtime.gopark (0x438f45) [finalizer wait]
  Goroutine 6 - User: /opt/golang/1.16.5/src/runtime/proc.go:337 runtime.gopark (0x438f45) [select]
  Goroutine 17 - User: /opt/golang/1.16.5/src/runtime/sigqueue.go:168 os/signal.signal_recv (0x468e65) (thread 191048)
  Goroutine 18 - User: ./build/influx-cli/pkg/signals/context.go:18 github.com/influxdata/influx-cli/v2/pkg/signals.WithSignals.func1 (0xa102cd) [select]
  Goroutine 19 - User: ./build/influx-cli/clients/write/buffer_batcher.go:113 github.com/influxdata/influx-cli/v2/clients/write.(*BufferBatcher).write (0xa5d31c) [select]
  Goroutine 20 - User: /opt/golang/1.16.5/src/syscall/asm_linux_amd64.s:26 syscall.Syscall (0x4b60bb) (thread 191049) [select]
[10 goroutines]
(dlv) goroutine 20
Switched from 0 to 20 (thread 191049)
(dlv) bt
 0  0x00000000004b60bb in syscall.Syscall
    at /opt/golang/1.16.5/src/syscall/asm_linux_amd64.s:26
 1  0x00000000004b3d5a in syscall.read
    at /opt/golang/1.16.5/src/syscall/zsyscall_linux_amd64.go:686
 2  0x00000000004d1605 in syscall.Read
    at /opt/golang/1.16.5/src/syscall/syscall_unix.go:187
 3  0x00000000004d1605 in internal/poll.ignoringEINTRIO
    at /opt/golang/1.16.5/src/internal/poll/fd_unix.go:581
 4  0x00000000004d1605 in internal/poll.(*FD).Read
    at /opt/golang/1.16.5/src/internal/poll/fd_unix.go:162
 5  0x00000000004d91b7 in os.(*File).read
    at /opt/golang/1.16.5/src/os/file_posix.go:31
 6  0x00000000004d91b7 in os.(*File).Read
    at /opt/golang/1.16.5/src/os/file.go:117
 7  0x00000000004ad092 in io.(*multiReader).Read
    at /opt/golang/1.16.5/src/io/multi.go:26
 8  0x0000000000563309 in bufio.(*Scanner).Scan
    at /opt/golang/1.16.5/src/bufio/scan.go:214
 9  0x0000000000a5ce59 in github.com/influxdata/influx-cli/v2/clients/write.(*BufferBatcher).read
    at ./build/influx-cli/clients/write/buffer_batcher.go:72
10  0x000000000046c101 in runtime.goexit
    at /opt/golang/1.16.5/src/runtime/asm_amd64.s:1371
(dlv) frame 9
> syscall.Syscall() /opt/golang/1.16.5/src/syscall/asm_linux_amd64.s:26 (PC: 0x4b60bb)
Warning: debugging optimized function
Frame 9: ./build/influx-cli/clients/write/buffer_batcher.go:72 (PC: a5ce59)
    67:         if b.MaxLineLength > 0 {
    68:                 maxLineLength = b.MaxLineLength
    69:         }
    70:         scanner.Buffer(nil, maxLineLength)
    71:
=>  72:         for scanner.Scan() {
    73:                 // exit early if the context is done
    74:                 select {
    75:                 // NOTE: We purposefully don't use scanner.Bytes() here because it returns a slice
    76:                 // pointing to an array which is reused / overwritten on every call to Scan().
    77:                 case lines <- []byte(scanner.Text()):
(dlv) frame 6
> syscall.Syscall() /opt/golang/1.16.5/src/syscall/asm_linux_amd64.s:26 (PC: 0x4b60bb)
Warning: debugging optimized function
Frame 6: /opt/golang/1.16.5/src/os/file.go:117 (PC: 4d91b7)
   112: // At end of file, Read returns 0, io.EOF.
   113: func (f *File) Read(b []byte) (n int, err error) {
   114:         if err := f.checkValid("read"); err != nil {
   115:                 return 0, err
   116:         }
=> 117:         n, e := f.read(b)
   118:         return n, f.wrapErr("read", e)
   119: }
   120:
   121: // ReadAt reads len(b) bytes from the File starting at byte offset off.
   122: // It returns the number of bytes read and the error, if any.
(dlv) print f
*os.File {
        file: *os.file {
                pfd: (*"internal/poll.FD")(0xc00006a060),
                name: "/dev/stdin",
                dirinfo: *os.dirInfo nil,
                nonblock: false,
                stdoutOrErr: false,
                appendMode: false,},}

It looks like the process is blocked waiting on data from stdin. If this is true, then somehow stdin gets into the list of files that the process is to read line protocol from, even though -f was given.

adrian-thurston avatar Sep 15 '21 01:09 adrian-thurston