podman

1
//go:build linux || freebsd
2

3
package events
4

5
import (
6
	"bufio"
7
	"context"
8
	"errors"
9
	"fmt"
10
	"io"
11
	"os"
12
	"path"
13
	"path/filepath"
14
	"time"
15

16
	"github.com/containers/podman/v5/pkg/util"
17
	"github.com/containers/storage/pkg/lockfile"
18
	"github.com/nxadm/tail"
19
	"github.com/sirupsen/logrus"
20
	"golang.org/x/sys/unix"
21
)
22

23
// EventLogFile is the structure for event writing to a logfile. It contains the eventer
24
// options and the event itself.  Methods for reading and writing are also defined from it.
25
type EventLogFile struct {
26
	options EventerOptions
27
}
28

29
// newLogFileEventer creates a new EventLogFile eventer
30
func newLogFileEventer(options EventerOptions) (*EventLogFile, error) {
31
	// Create events log dir
32
	if err := os.MkdirAll(filepath.Dir(options.LogFilePath), 0700); err != nil {
33
		return nil, fmt.Errorf("creating events dirs: %w", err)
34
	}
35
	// We have to make sure the file is created otherwise reading events will hang.
36
	// https://github.com/containers/podman/issues/15688
37
	fd, err := os.OpenFile(options.LogFilePath, os.O_RDONLY|os.O_CREATE, 0700)
38
	if err != nil {
39
		return nil, fmt.Errorf("failed to create event log file: %w", err)
40
	}
41
	return &EventLogFile{options: options}, fd.Close()
42
}
43

44
// Writes to the log file
45
func (e EventLogFile) Write(ee Event) error {
46
	// We need to lock events file
47
	lock, err := lockfile.GetLockFile(e.options.LogFilePath + ".lock")
48
	if err != nil {
49
		return err
50
	}
51
	lock.Lock()
52
	defer lock.Unlock()
53

54
	eventJSONString, err := ee.ToJSONString()
55
	if err != nil {
56
		return err
57
	}
58

59
	if _, err := rotateLog(e.options.LogFilePath, eventJSONString, e.options.LogFileMaxSize); err != nil {
60
		return err
61
	}
62

63
	return e.writeString(eventJSONString)
64
}
65

66
func (e EventLogFile) writeString(s string) error {
67
	f, err := os.OpenFile(e.options.LogFilePath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0700)
68
	if err != nil {
69
		return err
70
	}
71
	return writeToFile(s, f)
72
}
73

74
func writeToFile(s string, f *os.File) error {
75
	_, err := f.WriteString(s + "\n")
76
	return err
77
}
78

79
func (e EventLogFile) getTail(options ReadOptions) (*tail.Tail, error) {
80
	seek := tail.SeekInfo{Offset: 0, Whence: io.SeekEnd}
81
	if options.FromStart || !options.Stream {
82
		seek.Whence = 0
83
	}
84
	stream := options.Stream
85
	return tail.TailFile(e.options.LogFilePath, tail.Config{ReOpen: stream, Follow: stream, Location: &seek, Logger: tail.DiscardingLogger, Poll: true})
86
}
87

88
func (e EventLogFile) readRotateEvent(event *Event) (begin bool, end bool, err error) {
89
	if event.Status != Rotate {
90
		return
91
	}
92
	if event.Details.Attributes == nil {
93
		// may be an old event before storing attributes in the rotate event
94
		return
95
	}
96
	switch event.Details.Attributes[rotateEventAttribute] {
97
	case rotateEventBegin:
98
		begin = true
99
		return
100
	case rotateEventEnd:
101
		end = true
102
		return
103
	default:
104
		err = fmt.Errorf("unknown rotate-event attribute %q", event.Details.Attributes[rotateEventAttribute])
105
		return
106
	}
107
}
108

109
// Reads from the log file
110
func (e EventLogFile) Read(ctx context.Context, options ReadOptions) error {
111
	defer close(options.EventChannel)
112
	filterMap, err := generateEventFilters(options.Filters, options.Since, options.Until)
113
	if err != nil {
114
		return fmt.Errorf("failed to parse event filters: %w", err)
115
	}
116
	t, err := e.getTail(options)
117
	if err != nil {
118
		return err
119
	}
120
	if len(options.Until) > 0 {
121
		untilTime, err := util.ParseInputTime(options.Until, false)
122
		if err != nil {
123
			return err
124
		}
125
		go func() {
126
			time.Sleep(time.Until(untilTime))
127
			if err := t.Stop(); err != nil {
128
				logrus.Errorf("Stopping logger: %v", err)
129
			}
130
		}()
131
	}
132
	logrus.Debugf("Reading events from file %q", e.options.LogFilePath)
133

134
	// Get the time *before* starting to read.  Comparing the timestamps
135
	// with events avoids returning events more than once after a log-file
136
	// rotation.
137
	readTime, err := func() (time.Time, error) {
138
		// We need to lock events file
139
		lock, err := lockfile.GetLockFile(e.options.LogFilePath + ".lock")
140
		if err != nil {
141
			return time.Time{}, err
142
		}
143
		lock.Lock()
144
		defer lock.Unlock()
145
		return time.Now(), nil
146
	}()
147
	if err != nil {
148
		return err
149
	}
150

151
	var line *tail.Line
152
	var ok bool
153
	var skipRotate bool
154
	for {
155
		select {
156
		case <-ctx.Done():
157
			// the consumer has cancelled
158
			t.Kill(errors.New("hangup by client"))
159
			return nil
160
		case line, ok = <-t.Lines:
161
			if !ok {
162
				// channel was closed
163
				return nil
164
			}
165
			// fallthrough
166
		}
167

168
		event, err := newEventFromJSONString(line.Text)
169
		if err != nil {
170
			return err
171
		}
172
		switch event.Type {
173
		case Image, Volume, Pod, Container, Network:
174
			//	no-op
175
		case System:
176
			begin, end, err := e.readRotateEvent(event)
177
			if err != nil {
178
				return err
179
			}
180
			if begin && event.Time.After(readTime) {
181
				// If the rotation event happened _after_ we
182
				// started reading, we need to ignore/skip
183
				// subsequent event until the end of the
184
				// rotation.
185
				skipRotate = true
186
				logrus.Debugf("Skipping already read events after log-file rotation: %v", event)
187
			} else if end {
188
				// This rotate event
189
				skipRotate = false
190
			}
191
		default:
192
			return fmt.Errorf("event type %s is not valid in %s", event.Type.String(), e.options.LogFilePath)
193
		}
194
		if skipRotate {
195
			continue
196
		}
197
		if applyFilters(event, filterMap) {
198
			options.EventChannel <- event
199
		}
200
	}
201
}
202

203
// String returns a string representation of the logger
204
func (e EventLogFile) String() string {
205
	return LogFile.String()
206
}
207

208
const (
209
	rotateEventAttribute = "io.podman.event.rotate"
210
	rotateEventBegin     = "begin"
211
	rotateEventEnd       = "end"
212
)
213

214
func writeRotateEvent(f *os.File, logFilePath string, begin bool) error {
215
	rEvent := NewEvent(Rotate)
216
	rEvent.Type = System
217
	rEvent.Name = logFilePath
218
	rEvent.Attributes = make(map[string]string)
219
	if begin {
220
		rEvent.Attributes[rotateEventAttribute] = rotateEventBegin
221
	} else {
222
		rEvent.Attributes[rotateEventAttribute] = rotateEventEnd
223
	}
224
	rotateJSONString, err := rEvent.ToJSONString()
225
	if err != nil {
226
		return err
227
	}
228
	return writeToFile(rotateJSONString, f)
229
}
230

231
// Rotates the log file if the log file size and content exceeds limit
232
func rotateLog(logfile string, content string, limit uint64) (bool, error) {
233
	needsRotation, err := logNeedsRotation(logfile, content, limit)
234
	if err != nil || !needsRotation {
235
		return false, err
236
	}
237
	if err := truncate(logfile); err != nil {
238
		return false, err
239
	}
240
	return true, nil
241
}
242

243
// logNeedsRotation return true if the log file needs to be rotated.
244
func logNeedsRotation(logfile string, content string, limit uint64) (bool, error) {
245
	if limit == 0 {
246
		return false, nil
247
	}
248
	file, err := os.Stat(logfile)
249
	if err != nil {
250
		if errors.Is(err, os.ErrNotExist) {
251
			// The logfile does not exist yet.
252
			return false, nil
253
		}
254
		return false, err
255
	}
256
	var filesize = uint64(file.Size())
257
	var contentsize = uint64(len([]rune(content)))
258
	if filesize+contentsize < limit {
259
		return false, nil
260
	}
261

262
	return true, nil
263
}
264

265
// Truncates the log file and saves 50% of content to new log file
266
func truncate(filePath string) error {
267
	orig, err := os.Open(filePath)
268
	if err != nil {
269
		return err
270
	}
271
	defer orig.Close()
272

273
	origFinfo, err := orig.Stat()
274
	if err != nil {
275
		return err
276
	}
277

278
	size := origFinfo.Size()
279
	threshold := size / 2
280

281
	tmp, err := os.CreateTemp(path.Dir(filePath), "")
282
	if err != nil {
283
		// Retry in /tmp in case creating a tmp file in the same
284
		// directory has failed.
285
		tmp, err = os.CreateTemp("", "")
286
		if err != nil {
287
			return err
288
		}
289
	}
290
	defer tmp.Close()
291

292
	// Jump directly to the threshold, drop the first line and copy the remainder
293
	if _, err := orig.Seek(threshold, 0); err != nil {
294
		return err
295
	}
296
	reader := bufio.NewReader(orig)
297
	if _, err := reader.ReadString('\n'); err != nil {
298
		if !errors.Is(err, io.EOF) {
299
			return err
300
		}
301
	}
302

303
	if err := writeRotateEvent(tmp, filePath, true); err != nil {
304
		return fmt.Errorf("writing rotation event begin marker: %w", err)
305
	}
306
	if _, err := reader.WriteTo(tmp); err != nil {
307
		return fmt.Errorf("writing truncated contents: %w", err)
308
	}
309
	if err := writeRotateEvent(tmp, filePath, false); err != nil {
310
		return fmt.Errorf("writing rotation event end marker: %w", err)
311
	}
312

313
	if err := renameLog(tmp.Name(), filePath); err != nil {
314
		return fmt.Errorf("writing back %s to %s: %w", tmp.Name(), filePath, err)
315
	}
316

317
	return nil
318
}
319

320
// Renames from, to
321
func renameLog(from, to string) error {
322
	err := os.Rename(from, to)
323
	if err == nil {
324
		return nil
325
	}
326

327
	if !errors.Is(err, unix.EXDEV) {
328
		return err
329
	}
330

331
	// Files are not on the same partition, so we need to copy them the
332
	// hard way.
333
	fFrom, err := os.Open(from)
334
	if err != nil {
335
		return err
336
	}
337
	defer fFrom.Close()
338

339
	// Remove the old file to make sure we're not truncating current
340
	// readers.
341
	if err := os.Remove(to); err != nil {
342
		return fmt.Errorf("recreating file %s: %w", to, err)
343
	}
344

345
	fTo, err := os.Create(to)
346
	if err != nil {
347
		return err
348
	}
349
	defer fTo.Close()
350

351
	if _, err := io.Copy(fTo, fFrom); err != nil {
352
		return fmt.Errorf("writing back from temporary file: %w", err)
353
	}
354

355
	if err := os.Remove(from); err != nil {
356
		return fmt.Errorf("removing temporary file: %w", err)
357
	}
358

359
	return nil
360
}
361