Elastic-Agent duplicates log.level from its sub components if they're not compatible with zap.

[belimawr]

When the Elastic-Agent reads a line written to stderr or stdout by a process it's running, it tries to parse it as JSON, then it tries to extract the log level from the key log.level. The value is then passed to UnmarshalText from zapcore.Level. If this call returns an error, the log.level key is left in the JSON and when the entry is logged the Elastic-Agent logger for that process will also add it's own log.level key, ending on a duplication.

The JSON is handled here

elastic-agent/pkg/component/runtime/log_writer.go

Lines 125 to 152 in 87336db

	func (r *logWriter) handleJSON(line string) bool {
	var evt map[string]interface{}
	if err := json.Unmarshal([]byte(line), &evt); err != nil {
	return false
	}
	lvl := getLevel(evt, r.logCfg.LevelKey)
	ts := getTimestamp(evt, r.logCfg.TimeKey, r.logCfg.TimeFormat)
	msg := getMessage(evt, r.logCfg.MessageKey)
	fields := getFields(evt, r.logCfg.IgnoreKeys)
	allowedLvl := r.logLevel.Level()
	unitId := getUnitId(evt)
	if unitId != "" {
	if r.unitLevels != nil {
	if unitLevel, ok := r.unitLevels[unitId]; ok {
	allowedLvl = unitLevel
	}
	}
	}
	if allowedLvl.Enabled(lvl) {
	_ = r.loggerCore.Write(zapcore.Entry{
	Level: lvl,
	Time: ts,
	Message: msg,
	}, fields)
	}
	return true
	}

then the level is parsed by getLevel

elastic-agent/pkg/component/runtime/log_writer.go

Lines 154 to 161 in 87336db

	func getLevel(evt map[string]interface{}, key string) zapcore.Level {
	lvl := zapcore.InfoLevel
	err := unmarshalLevel(&lvl, getStrVal(evt, key))
	if err == nil {
	delete(evt, key)
	}
	return lvl
	}

that calls unmarshalLevel

elastic-agent/pkg/component/runtime/log_writer.go

Lines 163 to 172 in 87336db

	func unmarshalLevel(lvl *zapcore.Level, val string) error {
	if val == "" {
	return errors.New("empty val")
	} else if val == "trace" {
	// zap doesn't handle trace level we cast to debug
	*lvl = zapcore.DebugLevel
	return nil
	}
	return lvl.UnmarshalText([]byte(val))
	}

which in turn delegates to zapcore.Level.UnmarshalText

elastic-agent/pkg/component/runtime/log_writer.go

Line 171 in 87336db

return lvl.UnmarshalText([]byte(val))

If the parsing errors, then the log.level is not removed from the JSON

elastic-agent/pkg/component/runtime/log_writer.go

Lines 157 to 159 in 87336db

	if err == nil {
	delete(evt, key)
	}

which leads to the duplication of log.level as zap will always add it to the final log entry.

[elasticmachine]

Pinging @elastic/elastic-agent (Team:Elastic-Agent)

[florianl]

Compatibility of zap increased with the merge of uber-go/zap#1429.
Previously, zap was not able to handle log.level if the level indicator was warning. A popular logging package, that uses warning instead of warn is sirupsen/logrus.