go-systemd icon indicating copy to clipboard operation
go-systemd copied to clipboard

Question: AddMatch conflict with SeekTail?

Open baude opened this issue 4 years ago • 2 comments

Not sure where else to direct this question. in the libpod/podman (github.com/containers/libpod), we implement an event system that reads and writes to journald. On the read, by default we want be able to seek the tail of the journal and "watch" for events from there. The following code does in fact do that with one annoying problem. If I enable (uncomment) the AddMatch to filter more specifically to our events, I am getting "old" events being processed; that is to say, events that occurred in the past.

Could someone take a quick look here and advise?

// Read reads events from the journal and sends qualified events to the event channel
func (e EventJournalD) Read(options ReadOptions) error {
	eventOptions, err := generateEventOptions(options.Filters, options.Since, options.Until)
	if err != nil {
		return errors.Wrapf(err, "failed to generate event options")
	}
	//podmanJournal := sdjournal.Match{Field: "SYSLOG_IDENTIFIER", Value: "podman"} //nolint
	j, err := sdjournal.NewJournal()                                              //nolint
	if err != nil {
		return err
	}
	if len(options.Since) == 0 && len(options.Until) == 0 && options.Stream {
		fmt.Println("--->")
		if err := j.SeekTail(); err != nil {
			return errors.Wrap(err, "failed to seek end of journal")
		}
	}
	// the api requires a next|prev before getting a cursor
	if _, err := j.Next(); err != nil {
		return err
	}
	prevCursor, err := j.GetCursor()
	if err != nil {
		return err
	}
	//if err := j.AddMatch(podmanJournal.String()); err != nil {
	//	return errors.Wrap(err, "failed to add filter for event log")
	//}
	defer close(options.EventChannel)
	for {
		if _, err := j.Next(); err != nil {
			return err
		}
		newCursor, err := j.GetCursor()
		if err != nil {
			return err
		}
		if prevCursor == newCursor {
			if len(options.Until) > 0 || !options.Stream {
				break
			}
			_ = j.Wait(sdjournal.IndefiniteWait) //nolint
			continue
		}
		prevCursor = newCursor
		entry, err := j.GetEntry()
		if err != nil {
			return err
		}
		newEvent, err := newEventFromJournalEntry(entry)
		if err != nil {
			// We can't decode this event.
			// Don't fail hard - that would make events unusable.
			// Instead, log and continue.
			if errors.Cause(err) != ErrEventTypeBlank {
				logrus.Errorf("Unable to decode event: %v", err)
			}
			continue
		}
		include := true
		for _, filter := range eventOptions {
			include = include && filter(newEvent)
		}
		if include {
			options.EventChannel <- newEvent
		}
	}
	return nil

}

baude avatar Aug 02 '19 00:08 baude

@jonboulle PTAL

rhatdan avatar Aug 02 '19 09:08 rhatdan

We were having an out-of-band chat about this. I don't have any reference at hand, but I seem to remember this is in fact a corner-case of the interaction between seeking and filtering. There isn't much logic related to that in this wrapping library, so I think it's a behavior directly coming from the libsystemd C library. This is just my gut feeling though, it would need to confirmed by reading through the C side. I'm not venturing on that journey right now due time shortage, thus keeping this ticket open until somebody reports back with relevant references. At that point, we can either fix the corner-case or improve the documentation to mention those non-orthogonal actions.

lucab avatar Aug 06 '19 13:08 lucab