Skip to content

Commit e6ae9cc

Browse files
crosbymichaelcrosbymichael
committed
Shim pluggable logging
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 <crosbymichael@gmail.com>
1 parent aa328df commit e6ae9cc

File tree

16 files changed

+538
-105
lines changed

16 files changed

+538
-105
lines changed

‎cio/io.go‎

Lines changed: 47 additions & 17 deletions
Original file line numberDiff line numberDiff line change
@@ -20,8 +20,8 @@ import (
2020
"context"
2121
"fmt"
2222
"io"
23+
"net/url"
2324
"os"
24-
"path/filepath"
2525
"sync"
2626

2727
"github.com/containerd/containerd/defaults"
@@ -222,46 +222,76 @@ type DirectIO struct {
222222
cio
223223
}
224224

225-
var _ IO = &DirectIO{}
225+
var (
226+
_ IO = &DirectIO{}
227+
_ IO = &logURI{}
228+
)
229+
230+
// LogURI provides the raw logging URI
231+
func LogURI(uri *url.URL) Creator {
232+
return func(_ string) (IO, error) {
233+
return &logURI{
234+
config: Config{
235+
Stdout: uri.String(),
236+
Stderr: uri.String(),
237+
},
238+
}, nil
239+
}
240+
}
241+
242+
// BinaryIO forwards container STDOUT|STDERR directly to a logging binary
243+
func BinaryIO(binary string, args map[string]string) Creator {
244+
return func(_ string) (IO, error) {
245+
uri := &url.URL{
246+
Scheme: "binary",
247+
Host: binary,
248+
}
249+
for k, v := range args {
250+
uri.Query().Set(k, v)
251+
}
252+
return &logURI{
253+
config: Config{
254+
Stdout: uri.String(),
255+
Stderr: uri.String(),
256+
},
257+
}, nil
258+
}
259+
}
226260

227261
// LogFile creates a file on disk that logs the task's STDOUT,STDERR.
228262
// If the log file already exists, the logs will be appended to the file.
229263
func LogFile(path string) Creator {
230264
return func(_ string) (IO, error) {
231-
if err := os.MkdirAll(filepath.Dir(path), 0755); err != nil {
232-
return nil, err
233-
}
234-
f, err := os.OpenFile(path, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644)
235-
if err != nil {
236-
return nil, err
265+
uri := &url.URL{
266+
Scheme: "file",
267+
Host: path,
237268
}
238-
f.Close()
239-
return &logIO{
269+
return &logURI{
240270
config: Config{
241-
Stdout: path,
242-
Stderr: path,
271+
Stdout: uri.String(),
272+
Stderr: uri.String(),
243273
},
244274
}, nil
245275
}
246276
}
247277

248-
type logIO struct {
278+
type logURI struct {
249279
config Config
250280
}
251281

252-
func (l *logIO) Config() Config {
282+
func (l *logURI) Config() Config {
253283
return l.config
254284
}
255285

256-
func (l *logIO) Cancel() {
286+
func (l *logURI) Cancel() {
257287

258288
}
259289

260-
func (l *logIO) Wait() {
290+
func (l *logURI) Wait() {
261291

262292
}
263293

264-
func (l *logIO) Close() error {
294+
func (l *logURI) Close() error {
265295
return nil
266296
}
267297

‎cmd/ctr/commands/run/run.go‎

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -99,6 +99,10 @@ var Command = cli.Command{
9999
Name: "null-io",
100100
Usage: "send all IO to /dev/null",
101101
},
102+
cli.StringFlag{
103+
Name: "log-uri",
104+
Usage: "log uri",
105+
},
102106
cli.BoolFlag{
103107
Name: "detach,d",
104108
Usage: "detach from the task after it has started execution",
@@ -161,7 +165,7 @@ var Command = cli.Command{
161165
}
162166
opts := getNewTaskOpts(context)
163167
ioOpts := []cio.Opt{cio.WithFIFODir(context.String("fifo-dir"))}
164-
task, err := tasks.NewTask(ctx, client, container, context.String("checkpoint"), con, context.Bool("null-io"), ioOpts, opts...)
168+
task, err := tasks.NewTask(ctx, client, container, context.String("checkpoint"), con, context.Bool("null-io"), context.String("log-uri"), ioOpts, opts...)
165169
if err != nil {
166170
return err
167171
}

‎cmd/ctr/commands/tasks/start.go‎

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -35,6 +35,10 @@ var startCommand = cli.Command{
3535
Name: "null-io",
3636
Usage: "send all IO to /dev/null",
3737
},
38+
cli.StringFlag{
39+
Name: "log-uri",
40+
Usage: "log uri",
41+
},
3842
cli.StringFlag{
3943
Name: "fifo-dir",
4044
Usage: "directory used for storing IO FIFOs",
@@ -85,7 +89,7 @@ var startCommand = cli.Command{
8589
}
8690
}
8791

88-
task, err := NewTask(ctx, client, container, "", con, context.Bool("null-io"), ioOpts, opts...)
92+
task, err := NewTask(ctx, client, container, "", con, context.Bool("null-io"), context.String("log-uri"), ioOpts, opts...)
8993
if err != nil {
9094
return err
9195
}

‎cmd/ctr/commands/tasks/tasks_unix.go‎

Lines changed: 9 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -20,6 +20,7 @@ package tasks
2020

2121
import (
2222
gocontext "context"
23+
"net/url"
2324
"os"
2425
"os/signal"
2526

@@ -67,7 +68,7 @@ func HandleConsoleResize(ctx gocontext.Context, task resizer, con console.Consol
6768
}
6869

6970
// NewTask creates a new task
70-
func NewTask(ctx gocontext.Context, client *containerd.Client, container containerd.Container, checkpoint string, con console.Console, nullIO bool, ioOpts []cio.Opt, opts ...containerd.NewTaskOpts) (containerd.Task, error) {
71+
func NewTask(ctx gocontext.Context, client *containerd.Client, container containerd.Container, checkpoint string, con console.Console, nullIO bool, logURI string, ioOpts []cio.Opt, opts ...containerd.NewTaskOpts) (containerd.Task, error) {
7172
stdio := cio.NewCreator(append([]cio.Opt{cio.WithStdio}, ioOpts...)...)
7273
if checkpoint != "" {
7374
im, err := client.GetImage(ctx, checkpoint)
@@ -86,6 +87,13 @@ func NewTask(ctx gocontext.Context, client *containerd.Client, container contain
8687
}
8788
ioCreator = cio.NullIO
8889
}
90+
if logURI != "" {
91+
u, err := url.Parse(logURI)
92+
if err != nil {
93+
return nil, err
94+
}
95+
ioCreator = cio.LogURI(u)
96+
}
8997
return container.NewTask(ctx, ioCreator, opts...)
9098
}
9199

‎cmd/ctr/commands/tasks/tasks_windows.go‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -58,7 +58,7 @@ func HandleConsoleResize(ctx gocontext.Context, task resizer, con console.Consol
5858
}
5959

6060
// NewTask creates a new task
61-
func NewTask(ctx gocontext.Context, client *containerd.Client, container containerd.Container, _ string, con console.Console, nullIO bool, ioOpts []cio.Opt, opts ...containerd.NewTaskOpts) (containerd.Task, error) {
61+
func NewTask(ctx gocontext.Context, client *containerd.Client, container containerd.Container, _ string, con console.Console, nullIO bool, logURI string, ioOpts []cio.Opt, opts ...containerd.NewTaskOpts) (containerd.Task, error) {
6262
var ioCreator cio.Creator
6363
if con != nil {
6464
if nullIO {

‎runtime/proc/proc.go‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -72,7 +72,7 @@ type Process interface {
7272
// platform implementations
7373
type Platform interface {
7474
CopyConsole(ctx context.Context, console console.Console, stdin, stdout, stderr string,
75-
wg, cwg *sync.WaitGroup) (console.Console, error)
75+
wg *sync.WaitGroup) (console.Console, error)
7676
ShutdownConsole(ctx context.Context, console console.Console) error
7777
Close() error
7878
}

‎runtime/v1/linux/proc/exec.go‎

Lines changed: 27 additions & 21 deletions
Original file line numberDiff line numberDiff line change
@@ -46,7 +46,7 @@ type execProcess struct {
4646
mu sync.Mutex
4747
id string
4848
console console.Console
49-
io runc.IO
49+
io *processIO
5050
status int
5151
exited time.Time
5252
pid *safePid
@@ -172,29 +172,30 @@ func (e *execProcess) start(ctx context.Context) (err error) {
172172
// access e.pid until it is updated.
173173
e.pid.Lock()
174174
defer e.pid.Unlock()
175+
175176
var (
176177
socket *runc.Socket
177-
pidfile = filepath.Join(e.path, fmt.Sprintf("%s.pid", e.id))
178+
pio *processIO
179+
pidFile = newExecPidFile(e.path, e.id)
178180
)
179181
if e.stdio.Terminal {
180182
if socket, err = runc.NewTempConsoleSocket(); err != nil {
181183
return errors.Wrap(err, "failed to create runc console socket")
182184
}
183185
defer socket.Close()
184-
} else if e.stdio.IsNull() {
185-
if e.io, err = runc.NewNullIO(); err != nil {
186-
return errors.Wrap(err, "creating new NULL IO")
187-
}
188186
} else {
189-
if e.io, err = runc.NewPipeIO(e.parent.IoUID, e.parent.IoGID, withConditionalIO(e.stdio)); err != nil {
190-
return errors.Wrap(err, "failed to create runc io pipes")
187+
if pio, err = createIO(ctx, e.id, e.parent.IoUID, e.parent.IoGID, e.stdio); err != nil {
188+
return errors.Wrap(err, "failed to create init process I/O")
191189
}
190+
e.io = pio
192191
}
193192
opts := &runc.ExecOpts{
194-
PidFile: pidfile,
195-
IO: e.io,
193+
PidFile: pidFile.Path(),
196194
Detach: true,
197195
}
196+
if pio != nil {
197+
opts.IO = pio.IO()
198+
}
198199
if socket != nil {
199200
opts.ConsoleSocket = socket
200201
}
@@ -203,38 +204,43 @@ func (e *execProcess) start(ctx context.Context) (err error) {
203204
return e.parent.runtimeError(err, "OCI runtime exec failed")
204205
}
205206
if e.stdio.Stdin != "" {
206-
sc, err := fifo.OpenFifo(context.Background(), e.stdio.Stdin, syscall.O_WRONLY|syscall.O_NONBLOCK, 0)
207-
if err != nil {
208-
return errors.Wrapf(err, "failed to open stdin fifo %s", e.stdio.Stdin)
207+
if err := e.openStdin(e.stdio.Stdin); err != nil {
208+
return err
209209
}
210-
e.closers = append(e.closers, sc)
211-
e.stdin = sc
212210
}
213-
var copyWaitGroup sync.WaitGroup
214211
ctx, cancel := context.WithTimeout(ctx, 30*time.Second)
215212
defer cancel()
216213
if socket != nil {
217214
console, err := socket.ReceiveMaster()
218215
if err != nil {
219216
return errors.Wrap(err, "failed to retrieve console master")
220217
}
221-
if e.console, err = e.parent.Platform.CopyConsole(ctx, console, e.stdio.Stdin, e.stdio.Stdout, e.stdio.Stderr, &e.wg, &copyWaitGroup); err != nil {
218+
if e.console, err = e.parent.Platform.CopyConsole(ctx, console, e.stdio.Stdin, e.stdio.Stdout, e.stdio.Stderr, &e.wg); err != nil {
222219
return errors.Wrap(err, "failed to start console copy")
223220
}
224-
} else if !e.stdio.IsNull() {
225-
if err := copyPipes(ctx, e.io, e.stdio.Stdin, e.stdio.Stdout, e.stdio.Stderr, &e.wg, &copyWaitGroup); err != nil {
221+
} else {
222+
if err := pio.Copy(ctx, &e.wg); err != nil {
226223
return errors.Wrap(err, "failed to start io pipe copy")
227224
}
228225
}
229-
copyWaitGroup.Wait()
230-
pid, err := runc.ReadPidFile(opts.PidFile)
226+
pid, err := pidFile.Read()
231227
if err != nil {
232228
return errors.Wrap(err, "failed to retrieve OCI runtime exec pid")
233229
}
234230
e.pid.pid = pid
235231
return nil
236232
}
237233

234+
func (e *execProcess) openStdin(path string) error {
235+
sc, err := fifo.OpenFifo(context.Background(), path, syscall.O_WRONLY|syscall.O_NONBLOCK, 0)
236+
if err != nil {
237+
return errors.Wrapf(err, "failed to open stdin fifo %s", path)
238+
}
239+
e.stdin = sc
240+
e.closers = append(e.closers, sc)
241+
return nil
242+
}
243+
238244
func (e *execProcess) Status(ctx context.Context) (string, error) {
239245
s, err := e.parent.Status(ctx)
240246
if err != nil {

0 commit comments

Comments
 (0)