2015-02-03 18:41:26 -05:00
|
|
|
package logger
|
|
|
|
|
|
|
|
import (
|
2015-05-28 16:59:25 -04:00
|
|
|
"bytes"
|
2015-02-03 18:41:26 -05:00
|
|
|
"io"
|
2015-03-18 14:44:14 -04:00
|
|
|
"sync"
|
2015-02-03 18:41:26 -05:00
|
|
|
"time"
|
|
|
|
|
|
|
|
"github.com/Sirupsen/logrus"
|
|
|
|
)
|
|
|
|
|
Improve logging of long log lines
This change updates how we handle long lines of output from the
container. The previous logic used a bufio reader to read entire lines
of output from the container through an intermediate BytesPipe, and that
allowed the container to cause dockerd to consume an unconstrained
amount of memory as it attempted to collect a whole line of output, by
outputting data without newlines.
To avoid that, we replace the bufio reader with our own buffering scheme
that handles log lines up to 16k in length, breaking up anything longer
than that into multiple chunks. If we can dispense with noting this
detail properly at the end of output, we can switch from using
ReadBytes() to using ReadLine() instead. We add a field ("Partial") to
the log message structure to flag when we pass data to the log driver
that did not end with a newline.
The Line member of Message structures that we pass to log drivers is now
a slice into data which can be overwritten between calls to the log
driver's Log() method, so drivers which batch up Messages before
processing them need to take additional care: we add a function
(logger.CopyMessage()) that can be used to create a deep copy of a
Message structure, and modify the awslogs driver to use it.
We update the jsonfile log driver to append a "\n" to the data that it
logs to disk only when the Partial flag is false (it previously did so
unconditionally), to make its "logs" output correctly reproduce the data
as we received it.
Likewise, we modify the journald log driver to add a data field with
value CONTAINER_PARTIAL_MESSAGE=true to entries when the Partial flag is
true, and update its "logs" reader to refrain from appending a "\n" to
the data that it retrieves if it does not see this field/value pair (it
also previously did this unconditionally).
Signed-off-by: Nalin Dahyabhai <nalin@redhat.com> (github: nalind)
2016-05-24 14:12:47 -04:00
|
|
|
const (
|
|
|
|
bufSize = 16 * 1024
|
|
|
|
readSize = 2 * 1024
|
|
|
|
)
|
|
|
|
|
2016-06-02 00:10:51 -04:00
|
|
|
// Copier can copy logs from specified sources to Logger and attach Timestamp.
|
Improve logging of long log lines
This change updates how we handle long lines of output from the
container. The previous logic used a bufio reader to read entire lines
of output from the container through an intermediate BytesPipe, and that
allowed the container to cause dockerd to consume an unconstrained
amount of memory as it attempted to collect a whole line of output, by
outputting data without newlines.
To avoid that, we replace the bufio reader with our own buffering scheme
that handles log lines up to 16k in length, breaking up anything longer
than that into multiple chunks. If we can dispense with noting this
detail properly at the end of output, we can switch from using
ReadBytes() to using ReadLine() instead. We add a field ("Partial") to
the log message structure to flag when we pass data to the log driver
that did not end with a newline.
The Line member of Message structures that we pass to log drivers is now
a slice into data which can be overwritten between calls to the log
driver's Log() method, so drivers which batch up Messages before
processing them need to take additional care: we add a function
(logger.CopyMessage()) that can be used to create a deep copy of a
Message structure, and modify the awslogs driver to use it.
We update the jsonfile log driver to append a "\n" to the data that it
logs to disk only when the Partial flag is false (it previously did so
unconditionally), to make its "logs" output correctly reproduce the data
as we received it.
Likewise, we modify the journald log driver to add a data field with
value CONTAINER_PARTIAL_MESSAGE=true to entries when the Partial flag is
true, and update its "logs" reader to refrain from appending a "\n" to
the data that it retrieves if it does not see this field/value pair (it
also previously did this unconditionally).
Signed-off-by: Nalin Dahyabhai <nalin@redhat.com> (github: nalind)
2016-05-24 14:12:47 -04:00
|
|
|
// Writes are concurrent, so you need implement some sync in your logger.
|
2015-02-03 18:41:26 -05:00
|
|
|
type Copier struct {
|
|
|
|
// srcs is map of name -> reader pairs, for example "stdout", "stderr"
|
2016-06-27 17:14:17 -04:00
|
|
|
srcs map[string]io.Reader
|
|
|
|
dst Logger
|
|
|
|
copyJobs sync.WaitGroup
|
|
|
|
closeOnce sync.Once
|
|
|
|
closed chan struct{}
|
2015-02-03 18:41:26 -05:00
|
|
|
}
|
|
|
|
|
2015-07-28 14:17:25 -04:00
|
|
|
// NewCopier creates a new Copier
|
2016-05-31 15:46:55 -04:00
|
|
|
func NewCopier(srcs map[string]io.Reader, dst Logger) *Copier {
|
2015-02-03 18:41:26 -05:00
|
|
|
return &Copier{
|
2016-01-15 08:42:23 -05:00
|
|
|
srcs: srcs,
|
|
|
|
dst: dst,
|
|
|
|
closed: make(chan struct{}),
|
2015-07-28 14:17:25 -04:00
|
|
|
}
|
2015-02-03 18:41:26 -05:00
|
|
|
}
|
|
|
|
|
|
|
|
// Run starts logs copying
|
|
|
|
func (c *Copier) Run() {
|
|
|
|
for src, w := range c.srcs {
|
2015-03-18 14:44:14 -04:00
|
|
|
c.copyJobs.Add(1)
|
2015-02-03 18:41:26 -05:00
|
|
|
go c.copySrc(src, w)
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
func (c *Copier) copySrc(name string, src io.Reader) {
|
2015-03-18 14:44:14 -04:00
|
|
|
defer c.copyJobs.Done()
|
Improve logging of long log lines
This change updates how we handle long lines of output from the
container. The previous logic used a bufio reader to read entire lines
of output from the container through an intermediate BytesPipe, and that
allowed the container to cause dockerd to consume an unconstrained
amount of memory as it attempted to collect a whole line of output, by
outputting data without newlines.
To avoid that, we replace the bufio reader with our own buffering scheme
that handles log lines up to 16k in length, breaking up anything longer
than that into multiple chunks. If we can dispense with noting this
detail properly at the end of output, we can switch from using
ReadBytes() to using ReadLine() instead. We add a field ("Partial") to
the log message structure to flag when we pass data to the log driver
that did not end with a newline.
The Line member of Message structures that we pass to log drivers is now
a slice into data which can be overwritten between calls to the log
driver's Log() method, so drivers which batch up Messages before
processing them need to take additional care: we add a function
(logger.CopyMessage()) that can be used to create a deep copy of a
Message structure, and modify the awslogs driver to use it.
We update the jsonfile log driver to append a "\n" to the data that it
logs to disk only when the Partial flag is false (it previously did so
unconditionally), to make its "logs" output correctly reproduce the data
as we received it.
Likewise, we modify the journald log driver to add a data field with
value CONTAINER_PARTIAL_MESSAGE=true to entries when the Partial flag is
true, and update its "logs" reader to refrain from appending a "\n" to
the data that it retrieves if it does not see this field/value pair (it
also previously did this unconditionally).
Signed-off-by: Nalin Dahyabhai <nalin@redhat.com> (github: nalind)
2016-05-24 14:12:47 -04:00
|
|
|
buf := make([]byte, bufSize)
|
|
|
|
n := 0
|
|
|
|
eof := false
|
|
|
|
msg := &Message{Source: name}
|
2015-05-28 16:59:25 -04:00
|
|
|
|
|
|
|
for {
|
2016-01-15 08:42:23 -05:00
|
|
|
select {
|
|
|
|
case <-c.closed:
|
|
|
|
return
|
|
|
|
default:
|
Improve logging of long log lines
This change updates how we handle long lines of output from the
container. The previous logic used a bufio reader to read entire lines
of output from the container through an intermediate BytesPipe, and that
allowed the container to cause dockerd to consume an unconstrained
amount of memory as it attempted to collect a whole line of output, by
outputting data without newlines.
To avoid that, we replace the bufio reader with our own buffering scheme
that handles log lines up to 16k in length, breaking up anything longer
than that into multiple chunks. If we can dispense with noting this
detail properly at the end of output, we can switch from using
ReadBytes() to using ReadLine() instead. We add a field ("Partial") to
the log message structure to flag when we pass data to the log driver
that did not end with a newline.
The Line member of Message structures that we pass to log drivers is now
a slice into data which can be overwritten between calls to the log
driver's Log() method, so drivers which batch up Messages before
processing them need to take additional care: we add a function
(logger.CopyMessage()) that can be used to create a deep copy of a
Message structure, and modify the awslogs driver to use it.
We update the jsonfile log driver to append a "\n" to the data that it
logs to disk only when the Partial flag is false (it previously did so
unconditionally), to make its "logs" output correctly reproduce the data
as we received it.
Likewise, we modify the journald log driver to add a data field with
value CONTAINER_PARTIAL_MESSAGE=true to entries when the Partial flag is
true, and update its "logs" reader to refrain from appending a "\n" to
the data that it retrieves if it does not see this field/value pair (it
also previously did this unconditionally).
Signed-off-by: Nalin Dahyabhai <nalin@redhat.com> (github: nalind)
2016-05-24 14:12:47 -04:00
|
|
|
// Work out how much more data we are okay with reading this time.
|
|
|
|
upto := n + readSize
|
|
|
|
if upto > cap(buf) {
|
|
|
|
upto = cap(buf)
|
2015-05-28 16:59:25 -04:00
|
|
|
}
|
Improve logging of long log lines
This change updates how we handle long lines of output from the
container. The previous logic used a bufio reader to read entire lines
of output from the container through an intermediate BytesPipe, and that
allowed the container to cause dockerd to consume an unconstrained
amount of memory as it attempted to collect a whole line of output, by
outputting data without newlines.
To avoid that, we replace the bufio reader with our own buffering scheme
that handles log lines up to 16k in length, breaking up anything longer
than that into multiple chunks. If we can dispense with noting this
detail properly at the end of output, we can switch from using
ReadBytes() to using ReadLine() instead. We add a field ("Partial") to
the log message structure to flag when we pass data to the log driver
that did not end with a newline.
The Line member of Message structures that we pass to log drivers is now
a slice into data which can be overwritten between calls to the log
driver's Log() method, so drivers which batch up Messages before
processing them need to take additional care: we add a function
(logger.CopyMessage()) that can be used to create a deep copy of a
Message structure, and modify the awslogs driver to use it.
We update the jsonfile log driver to append a "\n" to the data that it
logs to disk only when the Partial flag is false (it previously did so
unconditionally), to make its "logs" output correctly reproduce the data
as we received it.
Likewise, we modify the journald log driver to add a data field with
value CONTAINER_PARTIAL_MESSAGE=true to entries when the Partial flag is
true, and update its "logs" reader to refrain from appending a "\n" to
the data that it retrieves if it does not see this field/value pair (it
also previously did this unconditionally).
Signed-off-by: Nalin Dahyabhai <nalin@redhat.com> (github: nalind)
2016-05-24 14:12:47 -04:00
|
|
|
// Try to read that data.
|
|
|
|
if upto > n {
|
|
|
|
read, err := src.Read(buf[n:upto])
|
|
|
|
if err != nil {
|
|
|
|
if err != io.EOF {
|
|
|
|
logrus.Errorf("Error scanning log stream: %s", err)
|
|
|
|
return
|
|
|
|
}
|
|
|
|
eof = true
|
2016-01-15 08:42:23 -05:00
|
|
|
}
|
Improve logging of long log lines
This change updates how we handle long lines of output from the
container. The previous logic used a bufio reader to read entire lines
of output from the container through an intermediate BytesPipe, and that
allowed the container to cause dockerd to consume an unconstrained
amount of memory as it attempted to collect a whole line of output, by
outputting data without newlines.
To avoid that, we replace the bufio reader with our own buffering scheme
that handles log lines up to 16k in length, breaking up anything longer
than that into multiple chunks. If we can dispense with noting this
detail properly at the end of output, we can switch from using
ReadBytes() to using ReadLine() instead. We add a field ("Partial") to
the log message structure to flag when we pass data to the log driver
that did not end with a newline.
The Line member of Message structures that we pass to log drivers is now
a slice into data which can be overwritten between calls to the log
driver's Log() method, so drivers which batch up Messages before
processing them need to take additional care: we add a function
(logger.CopyMessage()) that can be used to create a deep copy of a
Message structure, and modify the awslogs driver to use it.
We update the jsonfile log driver to append a "\n" to the data that it
logs to disk only when the Partial flag is false (it previously did so
unconditionally), to make its "logs" output correctly reproduce the data
as we received it.
Likewise, we modify the journald log driver to add a data field with
value CONTAINER_PARTIAL_MESSAGE=true to entries when the Partial flag is
true, and update its "logs" reader to refrain from appending a "\n" to
the data that it retrieves if it does not see this field/value pair (it
also previously did this unconditionally).
Signed-off-by: Nalin Dahyabhai <nalin@redhat.com> (github: nalind)
2016-05-24 14:12:47 -04:00
|
|
|
n += read
|
|
|
|
}
|
|
|
|
// If we have no data to log, and there's no more coming, we're done.
|
|
|
|
if n == 0 && eof {
|
2016-01-15 08:42:23 -05:00
|
|
|
return
|
2015-05-28 16:59:25 -04:00
|
|
|
}
|
Improve logging of long log lines
This change updates how we handle long lines of output from the
container. The previous logic used a bufio reader to read entire lines
of output from the container through an intermediate BytesPipe, and that
allowed the container to cause dockerd to consume an unconstrained
amount of memory as it attempted to collect a whole line of output, by
outputting data without newlines.
To avoid that, we replace the bufio reader with our own buffering scheme
that handles log lines up to 16k in length, breaking up anything longer
than that into multiple chunks. If we can dispense with noting this
detail properly at the end of output, we can switch from using
ReadBytes() to using ReadLine() instead. We add a field ("Partial") to
the log message structure to flag when we pass data to the log driver
that did not end with a newline.
The Line member of Message structures that we pass to log drivers is now
a slice into data which can be overwritten between calls to the log
driver's Log() method, so drivers which batch up Messages before
processing them need to take additional care: we add a function
(logger.CopyMessage()) that can be used to create a deep copy of a
Message structure, and modify the awslogs driver to use it.
We update the jsonfile log driver to append a "\n" to the data that it
logs to disk only when the Partial flag is false (it previously did so
unconditionally), to make its "logs" output correctly reproduce the data
as we received it.
Likewise, we modify the journald log driver to add a data field with
value CONTAINER_PARTIAL_MESSAGE=true to entries when the Partial flag is
true, and update its "logs" reader to refrain from appending a "\n" to
the data that it retrieves if it does not see this field/value pair (it
also previously did this unconditionally).
Signed-off-by: Nalin Dahyabhai <nalin@redhat.com> (github: nalind)
2016-05-24 14:12:47 -04:00
|
|
|
// Break up the data that we've buffered up into lines, and log each in turn.
|
|
|
|
p := 0
|
|
|
|
for q := bytes.Index(buf[p:n], []byte{'\n'}); q >= 0; q = bytes.Index(buf[p:n], []byte{'\n'}) {
|
|
|
|
msg.Line = buf[p : p+q]
|
|
|
|
msg.Timestamp = time.Now().UTC()
|
|
|
|
msg.Partial = false
|
|
|
|
select {
|
|
|
|
case <-c.closed:
|
|
|
|
return
|
|
|
|
default:
|
|
|
|
if logErr := c.dst.Log(msg); logErr != nil {
|
|
|
|
logrus.Errorf("Failed to log msg %q for logger %s: %s", msg.Line, c.dst.Name(), logErr)
|
|
|
|
}
|
|
|
|
}
|
|
|
|
p += q + 1
|
|
|
|
}
|
|
|
|
// If there's no more coming, or the buffer is full but
|
|
|
|
// has no newlines, log whatever we haven't logged yet,
|
|
|
|
// noting that it's a partial log line.
|
|
|
|
if eof || (p == 0 && n == len(buf)) {
|
|
|
|
if p < n {
|
|
|
|
msg.Line = buf[p:n]
|
|
|
|
msg.Timestamp = time.Now().UTC()
|
|
|
|
msg.Partial = true
|
|
|
|
if logErr := c.dst.Log(msg); logErr != nil {
|
|
|
|
logrus.Errorf("Failed to log msg %q for logger %s: %s", msg.Line, c.dst.Name(), logErr)
|
|
|
|
}
|
|
|
|
p = 0
|
|
|
|
n = 0
|
|
|
|
}
|
|
|
|
if eof {
|
|
|
|
return
|
|
|
|
}
|
|
|
|
}
|
|
|
|
// Move any unlogged data to the front of the buffer in preparation for another read.
|
|
|
|
if p > 0 {
|
|
|
|
copy(buf[0:], buf[p:n])
|
|
|
|
n -= p
|
|
|
|
}
|
2015-05-28 16:59:25 -04:00
|
|
|
}
|
2015-02-03 18:41:26 -05:00
|
|
|
}
|
|
|
|
}
|
2015-03-18 14:44:14 -04:00
|
|
|
|
|
|
|
// Wait waits until all copying is done
|
|
|
|
func (c *Copier) Wait() {
|
|
|
|
c.copyJobs.Wait()
|
|
|
|
}
|
2016-01-15 08:42:23 -05:00
|
|
|
|
|
|
|
// Close closes the copier
|
|
|
|
func (c *Copier) Close() {
|
2016-06-27 17:14:17 -04:00
|
|
|
c.closeOnce.Do(func() {
|
2016-01-15 08:42:23 -05:00
|
|
|
close(c.closed)
|
2016-06-27 17:14:17 -04:00
|
|
|
})
|
2016-01-15 08:42:23 -05:00
|
|
|
}
|