Skip to content

Conversation

@crosbymichael
Copy link
Member

@crosbymichael crosbymichael commented Mar 8, 2019

Closes #603

This adds logging facilities at the shim level to provide minimal I/O
overhead and pluggable logging options. Log handling is done within the
shim so that all I/O, cpu, and memory can be charged to the container.

A sample logging driver setting up logging for a container the systemd
journal looks like this:

package main

import (
	"bufio"
	"context"
	"fmt"
	"io"
	"sync"

	"github.com/containerd/containerd/runtime/v2/logging"
	"github.com/coreos/go-systemd/journal"
)

func main() {
	logging.Run(log)
}

func log(ctx context.Context, config *logging.Config, ready func() error) error {
	// construct any log metadata for the container
	vars := map[string]string{
		"SYSLOG_IDENTIFIER": fmt.Sprintf("%s:%s", config.Namespace, config.ID),
	}
	var wg sync.WaitGroup
	wg.Add(2)
	// forward both stdout and stderr to the journal
	go copy(&wg, config.Stdout, journal.PriInfo, vars)
	go copy(&wg, config.Stderr, journal.PriErr, vars)

	// signal that we are ready and setup for the container to be started
	if err := ready(); err != nil {
		return err
	}
	wg.Wait()
	return nil
}

func copy(wg *sync.WaitGroup, r io.Reader, pri journal.Priority, vars map[string]string) {
	defer wg.Done()
	s := bufio.NewScanner(r)
	for s.Scan() {
		if s.Err() != nil {
			return
		}
		journal.Send(s.Text(), pri, vars)
	}
}

A logging package has been created to assist log developers create
logging plugins for containerd.

This uses a URI based approach for logging drivers that can be expanded
in the future.

Supported URI scheme's are:

  • binary
  • fifo
  • file

You can pass the log url via ctr on the command line:

> ctr run --rm --runtime io.containerd.runc.v2 --log-uri binary://shim-journald docker.io/library/redis:alpine redis
> journalctl -f -t default:redis

-- Logs begin at Tue 2018-12-11 16:29:51 EST. --
Mar 08 16:08:22 deathstar default:redis[120760]: 1:C 08 Mar 2019 21:08:22.703 # Warning: no config file specified, using the default config. In order to specify a config file use redis-server /path/to/redis.conf
Mar 08 16:08:22 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:22.704 # You requested maxclients of 10000 requiring at least 10032 max file descriptors.
Mar 08 16:08:22 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:22.704 # Server can't set maximum open files to 10032 because of OS error: Operation not permitted.
Mar 08 16:08:22 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:22.704 # Current maximum open files is 1024. maxclients has been reduced to 992 to compensate for low ulimit. If you need higher maxclients increase 'ulimit -n'.
Mar 08 16:08:22 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:22.705 * Running mode=standalone, port=6379.
Mar 08 16:08:22 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:22.705 # WARNING: The TCP backlog setting of 511 cannot be enforced because /proc/sys/net/core/somaxconn is set to the lower value of 128.
Mar 08 16:08:22 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:22.705 # Server initialized
Mar 08 16:08:22 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:22.705 # WARNING overcommit_memory is set to 0! Background save may fail under low memory condition. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
Mar 08 16:08:22 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:22.705 # WARNING you have Transparent Huge Pages (THP) support enabled in your kernel. This will create latency and memory usage issues with Redis. To fix this issue run the command 'echo never > /sys/kernel/mm/transparent_hugepage/enabled' as root, and add it to your /etc/rc.local in order to retain the setting after a reboot. Redis must be restarted after THP is disabled.
Mar 08 16:08:22 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:22.705 * Ready to accept connections
Mar 08 16:08:50 deathstar default:redis[120760]: 1:signal-handler (1552079330) Received SIGINT scheduling shutdown...
Mar 08 16:08:50 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:50.405 # User requested shutdown...
Mar 08 16:08:50 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:50.406 * Saving the final RDB snapshot before exiting.
Mar 08 16:08:50 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:50.452 * DB saved on disk
Mar 08 16:08:50 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:50.453 # Redis is now ready to exit, bye bye...

The following client side Opts are added:

// LogURI provides the raw logging URI
func LogURI(uri *url.URL) Creator { }
// BinaryIO forwards contianer STDOUT|STDERR directly to a logging binary
func BinaryIO(binary string, args map[string]string) Creator {}

Signed-off-by: Michael Crosby [email protected]

@crosbymichael crosbymichael force-pushed the shim-logs branch 3 times, most recently from fb20e39 to d382468 Compare March 8, 2019 22:04
@crosbymichael
Copy link
Member Author

Updated and ready for a full review

@jterry75
Copy link
Contributor

@crosbymichael - Change looks good. Can you please update the Runtime V2 markdown to include a section on IO logging capabilities. It would be nice to include your schemes there for Linux/Windows.

binary, file - Both
fifo - Linux
npipe - Windows

Closes containerd#603

This adds logging facilities at the shim level to provide minimal I/O
overhead and pluggable logging options.  Log handling is done within the
shim so that all I/O, cpu, and memory can be charged to the container.

A sample logging driver setting up logging for a container the systemd
journal looks like this:

```go
package main

import (
	"bufio"
	"context"
	"fmt"
	"io"
	"sync"

	"github.com/containerd/containerd/runtime/v2/logging"
	"github.com/coreos/go-systemd/journal"
)

func main() {
	logging.Run(log)
}

func log(ctx context.Context, config *logging.Config, ready func() error) error {
	// construct any log metadata for the container
	vars := map[string]string{
		"SYSLOG_IDENTIFIER": fmt.Sprintf("%s:%s", config.Namespace, config.ID),
	}
	var wg sync.WaitGroup
	wg.Add(2)
	// forward both stdout and stderr to the journal
	go copy(&wg, config.Stdout, journal.PriInfo, vars)
	go copy(&wg, config.Stderr, journal.PriErr, vars)

	// signal that we are ready and setup for the container to be started
	if err := ready(); err != nil {
		return err
	}
	wg.Wait()
	return nil
}

func copy(wg *sync.WaitGroup, r io.Reader, pri journal.Priority, vars map[string]string) {
	defer wg.Done()
	s := bufio.NewScanner(r)
	for s.Scan() {
		if s.Err() != nil {
			return
		}
		journal.Send(s.Text(), pri, vars)
	}
}
```

A `logging` package has been created to assist log developers create
logging plugins for containerd.

This uses a URI based approach for logging drivers that can be expanded
in the future.

Supported URI scheme's are:

* binary
* fifo
* file

You can pass the log url via ctr on the command line:

```bash
> ctr run --rm --runtime io.containerd.runc.v2 --log-uri binary://shim-journald docker.io/library/redis:alpine redis
```

```bash
> journalctl -f -t default:redis

-- Logs begin at Tue 2018-12-11 16:29:51 EST. --
Mar 08 16:08:22 deathstar default:redis[120760]: 1:C 08 Mar 2019 21:08:22.703 # Warning: no config file specified, using the default config. In order to specify a config file use redis-server /path/to/redis.conf
Mar 08 16:08:22 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:22.704 # You requested maxclients of 10000 requiring at least 10032 max file descriptors.
Mar 08 16:08:22 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:22.704 # Server can't set maximum open files to 10032 because of OS error: Operation not permitted.
Mar 08 16:08:22 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:22.704 # Current maximum open files is 1024. maxclients has been reduced to 992 to compensate for low ulimit. If you need higher maxclients increase 'ulimit -n'.
Mar 08 16:08:22 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:22.705 * Running mode=standalone, port=6379.
Mar 08 16:08:22 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:22.705 # WARNING: The TCP backlog setting of 511 cannot be enforced because /proc/sys/net/core/somaxconn is set to the lower value of 128.
Mar 08 16:08:22 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:22.705 # Server initialized
Mar 08 16:08:22 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:22.705 # WARNING overcommit_memory is set to 0! Background save may fail under low memory condition. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
Mar 08 16:08:22 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:22.705 # WARNING you have Transparent Huge Pages (THP) support enabled in your kernel. This will create latency and memory usage issues with Redis. To fix this issue run the command 'echo never > /sys/kernel/mm/transparent_hugepage/enabled' as root, and add it to your /etc/rc.local in order to retain the setting after a reboot. Redis must be restarted after THP is disabled.
Mar 08 16:08:22 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:22.705 * Ready to accept connections
Mar 08 16:08:50 deathstar default:redis[120760]: 1:signal-handler (1552079330) Received SIGINT scheduling shutdown...
Mar 08 16:08:50 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:50.405 # User requested shutdown...
Mar 08 16:08:50 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:50.406 * Saving the final RDB snapshot before exiting.
Mar 08 16:08:50 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:50.452 * DB saved on disk
Mar 08 16:08:50 deathstar default:redis[120760]: 1:M 08 Mar 2019 21:08:50.453 # Redis is now ready to exit, bye bye...
```

The following client side Opts are added:

```go
// LogURI provides the raw logging URI
func LogURI(uri *url.URL) Creator { }
// BinaryIO forwards contianer STDOUT|STDERR directly to a logging binary
func BinaryIO(binary string, args map[string]string) Creator {}
```

Signed-off-by: Michael Crosby <[email protected]>
@crosbymichael
Copy link
Member Author

@jterry75 updated

Copy link
Contributor

@jterry75 jterry75 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks great thanks! LGTM

Copy link
Member

@estesp estesp left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

@alexellis
Copy link
Contributor

alexellis commented Feb 23, 2020

I'm wondering if I can use this when creating containers from code using the containerd client instead of via ctr? https://github.com/openfaas/faasd/blob/master/pkg/provider/handlers/deploy.go#L100 https://github.com/openfaas/faasd/blob/master/pkg/provider/handlers/deploy.go#L148

I can see runtime/v1 in the commits, are there equivalents for v2? Would this log streaming survive a restart of containerd or the client that created the container?

@jbguerraz jbguerraz mentioned this pull request Dec 3, 2020
42wim added a commit to 42wim/containerd that referenced this pull request Mar 6, 2022
When a specific variable NOMAD_META_NOMADGEN_LOGRATE we run the
shim-journald-limiter binary as stderr/stdout logger

This will allow us to let nomad run docker containers which combined
with containerd ratelimits the messages per container sent to journald,
as journald itself can not ratelimit from specific containers.

Based upon containerd#3085
42wim added a commit to 42wim/containerd that referenced this pull request Mar 6, 2022
When a specific variable NOMAD_META_NOMADGEN_LOGRATE we run the
shim-journald-limiter binary as stderr/stdout logger

This will allow us to let nomad run docker containers which combined
with containerd ratelimits the messages per container sent to journald,
as journald itself can not ratelimit from specific containers.

Based upon containerd#3085
42wim added a commit to 42wim/containerd that referenced this pull request Mar 7, 2022
When a specific variable NOMAD_META_NOMADGEN_LOGRATE we run the
shim-journald-limiter binary as stderr/stdout logger

This will allow us to let nomad run docker containers which combined
with containerd ratelimits the messages per container sent to journald,
as journald itself can not ratelimit from specific containers.

Based upon containerd#3085
42wim added a commit to 42wim/containerd that referenced this pull request Mar 7, 2022
When a specific variable NOMAD_META_NOMADGEN_LOGRATE we run the
shim-journald-limiter binary as stderr/stdout logger

This will allow us to let nomad run docker containers which combined
with containerd ratelimits the messages per container sent to journald,
as journald itself can not ratelimit from specific containers.

Based upon containerd#3085
42wim added a commit to 42wim/containerd that referenced this pull request Mar 7, 2022
When a specific variable NOMAD_META_NOMADGEN_LOGRATE we run the
shim-journald-limiter binary as stderr/stdout logger

This will allow us to let nomad run docker containers which combined
with containerd ratelimits the messages per container sent to journald,
as journald itself can not ratelimit from specific containers.

Based upon containerd#3085
42wim added a commit to 42wim/containerd that referenced this pull request Mar 7, 2022
When a specific variable NOMAD_META_NOMADGEN_LOGRATE we run the
shim-journald-limiter binary as stderr/stdout logger

This will allow us to let nomad run docker containers which combined
with containerd ratelimits the messages per container sent to journald,
as journald itself can not ratelimit from specific containers.

Based upon containerd#3085
42wim added a commit to 42wim/containerd that referenced this pull request May 5, 2022
When a specific variable NOMAD_META_NOMADGEN_LOGRATE we run the
shim-journald-limiter binary as stderr/stdout logger

This will allow us to let nomad run docker containers which combined
with containerd ratelimits the messages per container sent to journald,
as journald itself can not ratelimit from specific containers.

Based upon containerd#3085
@ankitdbst
Copy link

Is there a way to provide the log binary (--log-uri) when containers are started using K8s?

@crosbymichael
Copy link
Member Author

@ankitdbst I think to support this, we just need a simple config option for the CRI service then you would be able to add your own loggers for pods. It should be a simple change to make to enable this.

@ankitdbst
Copy link

ankitdbst commented May 25, 2022 via email

@mikebrow
Copy link
Member

While yes it would be simple.. and we can do it.. the current format for k8s CRI logs are set, and we'd need to change kubelet as well to allow for alternate formats/driver models, unless proposing a tee which would result in a bit of a double charge to the container/runtime for the logging to both kubelet directed path/format and your proposed tee. That or you would be disabling kubernetes container logging. Currently the logging providers watching the output log tree specified by kubelet and convert the incoming logs from the k8s format to the desired format.

https://github.com/kubernetes/design-proposals-archive/blob/main/node/kubelet-cri-logging.md

The typical result for people migrating from dockershim to a CRI container runtime is to discuss with their logging provider if they work with kubernetes logging format/model.

@ankitdbst
Copy link

ankitdbst commented May 26, 2022

Thanks for the link @mikebrow

unless proposing a tee which would result in a bit of a double charge to the container/runtime for the logging to both kubelet directed path/format and your proposed tee.

Yeah, I think it should be an opt-in for someone wanting to tee the output to their preferred logging system.
Fluentd is kind of natively supported but logging to journald etc requires writing your custom plugin.

We can watch over the log dirs of the containers and then parse and write to journal too but it is slightly more work.

@mikebrow
Copy link
Member

either way we need this feature, at least because, kubernetes is not our only client..

@mikebrow
Copy link
Member

#4798 linking discussion...

42wim added a commit to 42wim/containerd that referenced this pull request Jun 9, 2024
When a specific variable NOMAD_META_NOMADGEN_LOGRATE we run the
shim-journald-limiter binary as stderr/stdout logger

This will allow us to let nomad run docker containers which combined
with containerd ratelimits the messages per container sent to journald,
as journald itself can not ratelimit from specific containers.

Based upon containerd#3085
42wim added a commit to 42wim/containerd that referenced this pull request Jun 9, 2024
When a specific variable NOMAD_META_NOMADGEN_LOGRATE we run the
shim-journald-limiter binary as stderr/stdout logger

This will allow us to let nomad run docker containers which combined
with containerd ratelimits the messages per container sent to journald,
as journald itself can not ratelimit from specific containers.

Based upon containerd#3085
42wim added a commit to 42wim/containerd that referenced this pull request Nov 21, 2024
When a specific variable NOMAD_META_NOMADGEN_LOGRATE we run the
shim-journald-limiter binary as stderr/stdout logger

This will allow us to let nomad run docker containers which combined
with containerd ratelimits the messages per container sent to journald,
as journald itself can not ratelimit from specific containers.

Based upon containerd#3085
42wim added a commit to 42wim/containerd that referenced this pull request Mar 25, 2025
When a specific variable NOMAD_META_NOMADGEN_LOGRATE we run the
shim-journald-limiter binary as stderr/stdout logger

This will allow us to let nomad run docker containers which combined
with containerd ratelimits the messages per container sent to journald,
as journald itself can not ratelimit from specific containers.

Based upon containerd#3085
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Log formatting in shim

7 participants