Error with Entry.writerScanner: token too long

[r3nic1e]

If you pass too long string (or byte slice) without newlines to *io.PipeWriter, provided by Entry.WriterLevel, you can see errors like this:
Error while reading from Writer: bufio.Scanner: token too long.

Sample code to reproduce this issue:

package main

import "github.com/sirupsen/logrus"
import "bytes"
import "time"

func main() {
        i := 1
        b := []byte{0}
        log := logrus.New()
        for {
                log.Info("Logging ", i, " bytes")
                log.Writer().Write(b)
                b = bytes.Repeat(b, 2)
                i *= 2
                time.Sleep(200 * time.Millisecond)
        }
}

This is head of output on my machine:

INFO[0000] Logging 1 bytes
INFO[0000] Logging 2 bytes
INFO[0000] Logging 4 bytes
INFO[0000] Logging 8 bytes
INFO[0000] Logging 16 bytes
INFO[0001] Logging 32 bytes
INFO[0001] Logging 64 bytes
INFO[0001] Logging 128 bytes
INFO[0001] Logging 256 bytes
INFO[0001] Logging 512 bytes
INFO[0002] Logging 1024 bytes
INFO[0002] Logging 2048 bytes
INFO[0002] Logging 4096 bytes
INFO[0002] Logging 8192 bytes
INFO[0002] Logging 16384 bytes
INFO[0003] Logging 32768 bytes
INFO[0003] Logging 65536 bytes
ERRO[0003] Error while reading from Writer: bufio.Scanner: token too long
INFO[0003] Logging 131072 bytes
ERRO[0003] Error while reading from Writer: bufio.Scanner: token too long
INFO[0003] Logging 262144 bytes
ERRO[0003] Error while reading from Writer: bufio.Scanner: token too long
INFO[0003] Logging 524288 bytes
ERRO[0003] Error while reading from Writer: bufio.Scanner: token too long
INFO[0004] Logging 1048576 bytes
ERRO[0004] Error while reading from Writer: bufio.Scanner: token too long

This error (ErrTooLong) is set in Scanner.Scan if buffer length is greater than max token size.
Maximum token size is defined as constant - bufio.MaxScanTokenSize. Current value is 65536. But you can override it with passing custom buffer and max token size to Scanner.Buffer.

So I see 2 ways of fixing this error:

1. Use own buffer and increase max token size
2. Use bufio.Reader and handle ErrBufferFull error from it

[tgross]

We've run into this issue in TritonDataCenter/containerpilot#423. In our case it's happening because we're piping stdout of a child process and can't enforce that we're terminating it with newlines. (It's an end-user error for our project, but we still need to handle it gracefully.)

Looking at the implementation here, I'd argue that simply increasing the token size just pushes the issue off. I'll see if I can figure out a way to gracefully handle this error by handling ErrBufferFull as suggested above.

[r3nic1e]

I agree with you, increasing buffer size is not a solution.
We've faced this problem while using containerpilot with healthcheck (same as in mentioned TritonDataCenter/containerpilot#423) but figured out, that it's not a containerpilot bug.

[pasztorpisti]

In my opinion logrus shouldn't provide Logger.Writer. Implementing a completely independent io.Writer that serves as an adapter/bridge to logrus is easy and the solution is much less complicated than Logger.Writer.

I've expressed a similar opinion in another open issue where Logger.Writer was used to redirect the standard log into logrus: #436 There I've provided a logrus writer adapter optimised for the standard log library.

@tgross I've checked your exec.Command example in issue TritonDataCenter/containerpilot#423 and a solution without Logger.Writer would look like:

package main

import (
	"bytes"
	"github.com/sirupsen/logrus"
	"os/exec"
	"sync"
)

func main() {
	w := &logrusWriter{
		entry: logrus.StandardLogger().WithField("logger", "cmd"),
	}

	cmd := exec.Command("sh", "-c", "echo stdout; echo 1>&2 stderr")
	cmd.Stdout = w
	cmd.Stderr = w

	err := cmd.Start()
	if err != nil {
		logrus.Fatalf("Cmd.Start failed: %v", err)
	}

	err = cmd.Wait()
	w.Flush()
	if err != nil {
		logrus.Fatalf("Cmd.Wait failed: %v", err)
	}
}

type logrusWriter struct {
	entry *logrus.Entry
	buf   bytes.Buffer
	mu    sync.Mutex
}

func (w *logrusWriter) Write(b []byte) (int, error) {
	w.mu.Lock()
	defer w.mu.Unlock()

	origLen := len(b)
	for {
		if len(b) == 0 {
			return origLen, nil
		}
		i := bytes.IndexByte(b, '\n')
		if i < 0 {
			w.buf.Write(b)
			return origLen, nil
		}

		w.buf.Write(b[:i])
		w.alwaysFlush()
		b = b[i+1:]
	}
}

func (w *logrusWriter) alwaysFlush() {
	w.entry.Info(w.buf.String())
	w.buf.Reset()
}

func (w *logrusWriter) Flush() {
	w.mu.Lock()
	defer w.mu.Unlock()

	if w.buf.Len() != 0 {
		w.alwaysFlush()
	}
}

Some possible modifications that one might want in his/her own writer implementation:

• A safety valve to check for too large w.buf sizes
• Other writer implementations can implement the io.ReadCloser interface and automatically flush on close (or perhaps just provide a separate ReadCloser that wraps the original writer and calls its Flush method on close)

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

[AlbinoDrought]

Also encountering this issue when piping the output of a process with many progress-bar messages like Processing Files: 123/45678910\r (no \n).

Write() uses bufio.Scanner, and bufio.Scanner lets you change the line-detection method to anything using scanner.Split(). We can (ab)use this to print our long no-linebreak buffer and avoid bufio.ErrTooLong. Here's one way: https://gist.github.com/AlbinoDrought/c292adc185ea6593338fb5b56ac89aa7