From 01d3223514251d57e62713f0b47b61e02df28d54 Mon Sep 17 00:00:00 2001 From: SolarPower2024 Date: Mon, 5 Oct 2026 20:51:53 +0200 Subject: [PATCH 1/6] =?UTF-8?q?Log-Datei:=20Ausgabe=20in=20Tagesdateien=20?= =?UTF-8?q?in=20util/logstash=20(noch=20nicht=20eingeh=C3=A4ngt)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit fileSink schreibt den Logstrom ab einem eigenen Level in evcc-YYYY-MM-DD.log, packt die Vortagesdatei im Hintergrund, räumt nach Alter und nach 1 GB auf und schaltet sich bei Fehlern für den Lauf ab. Output reicht jede Zeile unverändert an den Ringpuffer der Log-Seite und unter demselben Mutex an die Datei; das Einschalten schreibt den Pufferinhalt ohne Lücke und ohne Duplikat. SetFile, FileStatus und CloseFile sind die Schnittstelle. Ohne SetFile passiert nichts. Co-Authored-By: Claude Sonnet 5.5 --- util/logstash/file_custom.go | 641 ++++++++++++++++++++++++++++++ util/logstash/file_custom_test.go | 551 +++++++++++++++++++++++++ 2 files changed, 1192 insertions(+) create mode 100644 util/logstash/file_custom.go create mode 100644 util/logstash/file_custom_test.go diff --git a/util/logstash/file_custom.go b/util/logstash/file_custom.go new file mode 100644 index 0000000000..793ef31ce2 --- /dev/null +++ b/util/logstash/file_custom.go @@ -0,0 +1,641 @@ +package logstash + +// Custom extension: the log in daily files, set in the ui on the log page. +// +// evcc keeps its log in a ring buffer for the log page, a few hours of debug. +// This writes the same stream (all areas and levels, already redacted) to +// /evcc-YYYY-MM-DD.log from a level of its own, independent of the console +// level. The first line of a new day switches the file, the day before is +// compressed in the background, older files are deleted by age and by a fixed +// size limit for the whole folder. +// +// Output sits between the loggers and the ring buffer. It hands every line +// to the buffer unchanged and, under the buffer's lock, to the file. Switching +// the file on dumps the buffer into it under the same lock, so there is neither +// a gap nor a line twice. Nothing is written, and no folder created, until +// SetFile switches it on. + +import ( + "bufio" + "bytes" + "compress/gzip" + "errors" + "fmt" + "io" + "os" + "path/filepath" + "regexp" + "slices" + "strings" + "sync" + "time" + + jww "github.com/spf13/jwalterweatherman" +) + +const ( + fileSizeLimit = 1 << 30 // all files together + fileBufferSize = 64 << 10 + fileFlushEvery = 2 * time.Second + fileMinDays = 1 + fileMaxDays = 90 + + dayLayout = "2006-01-02" + timeLayout = "2006/01/02 15:04:05" // as the loggers write it +) + +// fileNameRE matches the files this writes, their date is the first group +var fileNameRE = regexp.MustCompile(`^evcc-(\d{4}-\d{2}-\d{2})\.log(\.gz)?$`) + +// maintainMu lets one folder clean-up run at a time, also across a switched off and on file +var maintainMu sync.Mutex + +// FileConfig is the log file setting +type FileConfig struct { + Enabled bool `json:"enabled"` + Level string `json:"level"` // error, warn, info, debug or trace + Days int `json:"days"` // retention + + // set by the caller, not part of the stored or posted setting + Dir string `json:"-"` // folder of the files + Version string `json:"-"` // evcc version for the header line + Log func(jww.Threshold, string) `json:"-"` // reports warnings and errors +} + +// DefaultFileConfig is what the ui starts with +var DefaultFileConfig = FileConfig{Level: "debug", Days: 14} + +// FileState is what the ui shows +type FileState struct { + Enabled bool `json:"enabled"` + Level string `json:"level"` + Days int `json:"days"` + Dir string `json:"dir"` + Files int `json:"files"` + Size int64 `json:"size"` + Error string `json:"error,omitempty"` +} + +// Validate checks level and retention +func (c FileConfig) Validate() error { + switch strings.ToLower(c.Level) { + case "error", "warn", "info", "debug", "trace": + default: + return fmt.Errorf("invalid log level: %q", c.Level) + } + + if c.Days < fileMinDays || c.Days > fileMaxDays { + return fmt.Errorf("invalid retention: %d days, allowed %d to %d", c.Days, fileMinDays, fileMaxDays) + } + + return nil +} + +// Output is where the loggers write to: the log buffer of the log page and, if switched on, the file +var Output io.Writer = out + +var out = newTee(DefaultHandler) + +// SetFile switches the log file on, off or to other settings. The error is one +// of the settings, a file that cannot be written is in the state. +func SetFile(cfg FileConfig) (FileState, error) { + return out.setFile(cfg) +} + +// FileStatus returns folder, files, size and the error that switched the file off +func FileStatus() FileState { + return out.status() +} + +// CloseFile writes out what is buffered and closes the file, on shutdown +func CloseFile() { + out.close() +} + +// tee hands every line to the log buffer and to the file +type tee struct { + l *logger + + // for tests + now func() time.Time + sizeLimit int64 + flushEvery time.Duration + + // guarded by l.mu + cfg FileConfig + sink *fileSink + err error // why the file is off, kept until the next setting +} + +var _ io.Writer = (*tee)(nil) + +func newTee(l *logger) *tee { + return &tee{l: l, now: time.Now, sizeLimit: fileSizeLimit, flushEvery: fileFlushEvery} +} + +func (t *tee) Write(p []byte) (int, error) { + return t.l.writeWith(p, t.toFile) +} + +// toFile runs under the lock of the log buffer +func (t *tee) toFile(e element) { + if t.sink == nil { + return + } + + t.sink.write(e) + + if err := t.sink.failure(); err != nil { + t.fail(err) + } +} + +// fail switches the file off for this run. The setting stays, the next start tries again. +func (t *tee) fail(err error) { + t.sink.close() + t.sink = nil + t.err = err + t.report(jww.LevelError, fmt.Sprintf("log file switched off: %v", err)) +} + +// report logs asynchronously: the caller holds the lock of the log buffer, which the log line needs +func (t *tee) report(level jww.Threshold, msg string) { + if log := t.cfg.Log; log != nil { + go log(level, msg) + } +} + +func (t *tee) setFile(cfg FileConfig) (FileState, error) { + if err := cfg.Validate(); err != nil { + return t.status(), err + } + + t.l.mu.Lock() + + if t.sink != nil { + t.sink.close() + t.sink = nil + } + + t.cfg = cfg + t.err = nil + + if cfg.Enabled { + s, err := newFileSink(cfg, t.now, t.sizeLimit, t.flushEvery) + if err == nil { + // the buffer first, then the lines that follow, nothing in between + t.l.merged(func(e entry) { s.write(e.text) }) + s.flush() // the folder shows the file as it is switched on + err = s.failure() + } + + if err != nil { + if s != nil { + s.close() + } + t.err = err + t.report(jww.LevelError, fmt.Sprintf("log file not written: %v", err)) + } else { + s.start() + s.maintainAsync() + t.sink = s + } + } + + t.l.mu.Unlock() + + return t.status(), nil +} + +func (t *tee) status() FileState { + t.l.mu.RLock() + cfg, sink, err := t.cfg, t.sink, t.err + t.l.mu.RUnlock() + + if cfg.Level == "" { + cfg.Level = DefaultFileConfig.Level + } + if cfg.Days == 0 { + cfg.Days = DefaultFileConfig.Days + } + + if err == nil && sink != nil { + err = sink.failure() + } + + res := FileState{Enabled: cfg.Enabled, Level: strings.ToLower(cfg.Level), Days: cfg.Days, Dir: cfg.Dir} + if err != nil { + res.Error = err.Error() + } + + if cfg.Dir != "" { + for _, f := range listFiles(cfg.Dir) { + res.Files++ + res.Size += f.size + } + } + + return res +} + +func (t *tee) close() { + t.l.mu.Lock() + defer t.l.mu.Unlock() + + if t.sink != nil { + t.sink.close() + t.sink = nil + } +} + +// writeWith is Write, additionally handing the stored line to fn while the lock is held +func (l *logger) writeWith(p []byte, fn func(element)) (int, error) { + if bytes.HasPrefix(p, []byte("[cache ]")) { + return len(p), nil + } + + e := element(p) + _, level := e.areaLevel() + + l.mu.Lock() + defer l.mu.Unlock() + + l.seq++ + if level == jww.LevelTrace { + l.trace.add(entry{l.seq, e}) + } else { + l.other.add(entry{l.seq, e}) + } + + fn(e) + + return len(p), nil +} + +// merged calls fn for every stored entry in the order it was written. The caller holds the lock. +func (l *logger) merged(fn func(entry)) { + var trace, other []entry + l.trace.visit(func(e entry) { trace = append(trace, e) }) + l.other.visit(func(e entry) { other = append(other, e) }) + + for len(trace) > 0 || len(other) > 0 { + if len(other) == 0 || (len(trace) > 0 && trace[0].seq < other[0].seq) { + fn(trace[0]) + trace = trace[1:] + } else { + fn(other[0]) + other = other[1:] + } + } +} + +// fileSink writes the lines of one day to a file and switches at midnight +type fileSink struct { + dir, version string + level jww.Threshold + levelName string + days int + sizeLimit int64 + now func() time.Time + log func(jww.Threshold, string) + + mu sync.Mutex + f *os.File + w *bufio.Writer + day string + err error + + flushEvery time.Duration + stopC chan struct{} + ticker sync.WaitGroup + bg sync.WaitGroup // clean-up runs +} + +// newFileSink creates the folder and opens today's file with its header line +func newFileSink(cfg FileConfig, now func() time.Time, sizeLimit int64, flushEvery time.Duration) (*fileSink, error) { + if cfg.Dir == "" { + return nil, errors.New("no folder for the log files") + } + + s := &fileSink{ + dir: cfg.Dir, + version: cfg.Version, + level: LogLevelToThreshold(cfg.Level), + levelName: strings.ToLower(cfg.Level), + days: cfg.Days, + sizeLimit: sizeLimit, + now: now, + log: cfg.Log, + flushEvery: flushEvery, + stopC: make(chan struct{}), + } + + if err := os.MkdirAll(s.dir, 0o755); err != nil { + return nil, err + } + + s.mu.Lock() + defer s.mu.Unlock() + + if err := s.open(); err != nil { + return nil, err + } + + return s, nil +} + +func fileName(day string) string { + return "evcc-" + day + ".log" +} + +// open opens the file of the current day and writes the header line, the caller holds s.mu +func (s *fileSink) open() error { + now := s.now() + day := now.Format(dayLayout) + + f, err := os.OpenFile(filepath.Join(s.dir, fileName(day)), os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0o644) + if err != nil { + s.err = err + return err + } + + s.f, s.w, s.day = f, bufio.NewWriterSize(f, fileBufferSize), day + s.line(fmt.Sprintf("[logfil] INFO %s evcc %s, level %s", now.Format(timeLayout), s.version, s.levelName)) + + return s.err +} + +// line writes a line to the buffer, the caller holds s.mu +func (s *fileSink) line(text string) { + if !strings.HasSuffix(text, "\n") { + text += "\n" + } + + if _, err := s.w.WriteString(text); err != nil { + s.fail(err) + } +} + +// fail switches this file off, the caller holds s.mu +func (s *fileSink) fail(err error) { + if s.err == nil { + s.err = err + } + if s.f != nil { + _ = s.f.Close() + } + s.f, s.w = nil, nil +} + +// write adds a line from the level on, the first line of a new day switches the file +func (s *fileSink) write(e element) { + if _, level := e.areaLevel(); level < s.level { + return + } + + s.mu.Lock() + defer s.mu.Unlock() + + if s.w == nil { + return + } + + if s.now().Format(dayLayout) != s.day { + s.rotate() + if s.w == nil { + return + } + } + + s.line(string(e)) +} + +// rotate closes the file of the day before and opens the next, the caller holds s.mu +func (s *fileSink) rotate() { + if err := s.w.Flush(); err != nil { + s.fail(err) + return + } + + if err := s.f.Close(); err != nil { + s.fail(err) + return + } + + if err := s.open(); err != nil { + s.fail(err) + return + } + + s.maintainAsync() +} + +// failure is what switched the file off +func (s *fileSink) failure() error { + s.mu.Lock() + defer s.mu.Unlock() + + return s.err +} + +// start flushes every flushEvery +func (s *fileSink) start() { + s.ticker.Add(1) + go func() { + defer s.ticker.Done() + + tick := time.NewTicker(s.flushEvery) + defer tick.Stop() + + for { + select { + case <-tick.C: + s.flush() + case <-s.stopC: + return + } + } + }() +} + +func (s *fileSink) flush() { + s.mu.Lock() + defer s.mu.Unlock() + + if s.w != nil { + if err := s.w.Flush(); err != nil { + s.fail(err) + } + } +} + +// close writes out what is buffered and closes the file +func (s *fileSink) close() { + select { + case <-s.stopC: + default: + close(s.stopC) + } + s.ticker.Wait() + + s.mu.Lock() + defer s.mu.Unlock() + + if s.w != nil { + if err := s.w.Flush(); err != nil { + s.fail(err) + } + } + + if s.f != nil { + _ = s.f.Close() + } + s.f, s.w = nil, nil +} + +func (s *fileSink) maintainAsync() { + s.bg.Add(1) + go func() { + defer s.bg.Done() + s.maintain() + }() +} + +// logFile is a file of the folder +type logFile struct { + name string + day time.Time + size int64 + gz bool +} + +// listFiles returns the files this writes, oldest first +func listFiles(dir string) []logFile { + entries, err := os.ReadDir(dir) + if err != nil { + return nil + } + + var res []logFile + for _, e := range entries { + m := fileNameRE.FindStringSubmatch(e.Name()) + if m == nil || e.IsDir() { + continue + } + + day, err := time.ParseInLocation(dayLayout, m[1], time.Local) + info, ierr := e.Info() + if err != nil || ierr != nil { + continue + } + + res = append(res, logFile{e.Name(), day, info.Size(), m[2] != ""}) + } + + slices.SortFunc(res, func(a, b logFile) int { + if c := a.day.Compare(b.day); c != 0 { + return c + } + return strings.Compare(a.name, b.name) + }) + + return res +} + +// maintain compresses the files of the days before, deletes those older than +// the retention and then the oldest ones while the folder is over its limit. +// Today's file stays. +func (s *fileSink) maintain() { + maintainMu.Lock() + defer maintainMu.Unlock() + + now := s.now() + today := time.Date(now.Year(), now.Month(), now.Day(), 0, 0, 0, 0, time.Local) + + // left by a run that was stopped while compressing + if tmp, err := filepath.Glob(filepath.Join(s.dir, "evcc-*.log.gz.tmp")); err == nil { + for _, f := range tmp { + _ = os.Remove(f) + } + } + + for _, f := range listFiles(s.dir) { + if f.gz || !f.day.Before(today) { + continue + } + if err := compress(filepath.Join(s.dir, f.name)); err != nil { + s.report(jww.LevelWarn, fmt.Sprintf("log file %s not compressed: %v", f.name, err)) + } + } + + var total int64 + files := listFiles(s.dir) + for _, f := range files { + if f.day.Before(today.AddDate(0, 0, -s.days)) { + if err := os.Remove(filepath.Join(s.dir, f.name)); err != nil { + s.report(jww.LevelWarn, fmt.Sprintf("log file %s not deleted: %v", f.name, err)) + } + continue + } + total += f.size + } + + for _, f := range listFiles(s.dir) { + if total <= s.sizeLimit || !f.day.Before(today) { + break + } + + if err := os.Remove(filepath.Join(s.dir, f.name)); err != nil { + s.report(jww.LevelWarn, fmt.Sprintf("log file %s not deleted: %v", f.name, err)) + continue + } + + total -= f.size + s.report(jww.LevelWarn, fmt.Sprintf("log files over %d MB, deleted %s", s.sizeLimit>>20, f.name)) + } +} + +func (s *fileSink) report(level jww.Threshold, msg string) { + if s.log != nil { + s.log(level, msg) + } +} + +// compress packs a file to path.gz and deletes the original, streaming +func compress(path string) (err error) { + in, err := os.Open(path) + if err != nil { + return err + } + defer in.Close() + + tmp := path + ".gz.tmp" + out, err := os.Create(tmp) + if err != nil { + return err + } + + defer func() { + if err != nil { + _ = os.Remove(tmp) + } + }() + + zw := gzip.NewWriter(out) + if _, err = io.Copy(zw, in); err == nil { + err = zw.Close() + } + if cerr := out.Close(); err == nil { + err = cerr + } + if err != nil { + return err + } + + if err = os.Rename(tmp, path+".gz"); err != nil { + return err + } + + _ = in.Close() + return os.Remove(path) +} diff --git a/util/logstash/file_custom_test.go b/util/logstash/file_custom_test.go new file mode 100644 index 0000000000..3bf37b575d --- /dev/null +++ b/util/logstash/file_custom_test.go @@ -0,0 +1,551 @@ +package logstash + +import ( + "compress/gzip" + "fmt" + "io" + "os" + "path/filepath" + "slices" + "strings" + "sync" + "testing" + "time" + + jww "github.com/spf13/jwalterweatherman" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +// fileTest is a log buffer with a file output, a clock and a folder of its own +type fileTest struct { + *tee + dir string + + mu sync.Mutex + time time.Time + logs []string +} + +func newFileTest(t *testing.T) *fileTest { + t.Helper() + + f := &fileTest{ + tee: newTee(New(10000)), + dir: filepath.Join(t.TempDir(), "logs"), // does not exist yet + time: time.Date(2026, 10, 5, 12, 0, 0, 0, time.Local), + } + f.tee.now = f.clock + f.tee.flushEvery = time.Hour // flushed by close, unless a test wants the ticker + + t.Cleanup(f.tee.close) + + return f +} + +func (f *fileTest) clock() time.Time { + f.mu.Lock() + defer f.mu.Unlock() + return f.time +} + +func (f *fileTest) setTime(tm time.Time) { + f.mu.Lock() + defer f.mu.Unlock() + f.time = tm +} + +func (f *fileTest) config(level string, days int) FileConfig { + return FileConfig{ + Enabled: true, + Level: level, + Days: days, + Dir: f.dir, + Version: "0.1.2", + Log: func(l jww.Threshold, msg string) { + f.mu.Lock() + defer f.mu.Unlock() + f.logs = append(f.logs, fmt.Sprintf("%d %s", l, msg)) + }, + } +} + +func (f *fileTest) logged() []string { + f.mu.Lock() + defer f.mu.Unlock() + return slices.Clone(f.logs) +} + +// waitMaintain waits for the clean-up that switching on or a new day started +func (f *fileTest) waitMaintain() { + f.l.mu.RLock() + s := f.sink + f.l.mu.RUnlock() + + if s != nil { + s.bg.Wait() + } +} + +func (f *fileTest) read(t *testing.T, name string) string { + t.Helper() + b, err := os.ReadFile(filepath.Join(f.dir, name)) + require.NoError(t, err) + return string(b) +} + +func (f *fileTest) names(t *testing.T) []string { + t.Helper() + entries, err := os.ReadDir(f.dir) + require.NoError(t, err) + + var res []string + for _, e := range entries { + res = append(res, e.Name()) + } + return res +} + +func readGz(t *testing.T, path string) string { + t.Helper() + in, err := os.Open(path) + require.NoError(t, err) + defer in.Close() + + zr, err := gzip.NewReader(in) + require.NoError(t, err) + b, err := io.ReadAll(zr) + require.NoError(t, err) + return string(b) +} + +func (f *fileTest) write(lines ...string) { + for _, s := range lines { + _, _ = f.Write([]byte(s)) + } +} + +const header = "[logfil] INFO 2026/10/05 12:00:00 evcc 0.1.2, level " + +var ( + lTrace = "[mqtt ] TRACE 2026/10/05 12:00:01 trace" + lDebug = "[site ] DEBUG 2026/10/05 12:00:02 debug" + lInfo = "[site ] INFO 2026/10/05 12:00:03 info" + lWarn = "[site ] WARN 2026/10/05 12:00:04 warn" + lError = "[site ] ERROR 2026/10/05 12:00:05 error" +) + +// TestFileInert: without SetFile nothing is written and no folder created, the +// log buffer gets every line as without the output +func TestFileInert(t *testing.T) { + f := newFileTest(t) + ref := New(10000) + + for _, s := range []string{lTrace, lDebug, lInfo, "[cache ] DEBUG dropped", lWarn, lError, "no header"} { + f.write(s) + _, _ = ref.Write([]byte(s)) + } + + assert.Equal(t, ref.All(nil, jww.LevelTrace, 0), f.l.All(nil, jww.LevelTrace, 0), "same buffer as without the output") + assert.Len(t, f.l.All(nil, jww.LevelTrace, 0), 6) + + assert.NoDirExists(t, f.dir) + st := f.status() + assert.False(t, st.Enabled) + assert.Equal(t, "debug", st.Level) + assert.Equal(t, 14, st.Days) + assert.Empty(t, st.Dir) + assert.Zero(t, st.Files) + + f.close() // nothing to close + assert.NoDirExists(t, f.dir) +} + +// TestFileOutputIsBuffer: the package output reaches the buffer of the log +// page unchanged, the contract util.newLogger relies on +func TestFileOutputIsBuffer(t *testing.T) { + line := "[tstout] DEBUG 2026/10/05 12:00:00 reaches the log page" + + n, err := Output.Write([]byte(line)) + require.NoError(t, err) + assert.Equal(t, len(line), n) + + assert.Contains(t, All([]string{"tstout"}, jww.LevelTrace, 0), line) + + _, _ = Output.Write([]byte("[cache ] DEBUG dropped as in the buffer")) + assert.Empty(t, All([]string{"cache"}, jww.LevelTrace, 0)) +} + +func TestFileLevelFilter(t *testing.T) { + for level, want := range map[string][]string{ + "error": {lError}, + "warn": {lWarn, lError}, + "info": {lInfo, lWarn, lError}, + "debug": {lDebug, lInfo, lWarn, lError}, + "trace": {lTrace, lDebug, lInfo, lWarn, lError}, + } { + t.Run(level, func(t *testing.T) { + f := newFileTest(t) + + st, err := f.setFile(f.config(level, 14)) + require.NoError(t, err) + assert.True(t, st.Enabled) + assert.Empty(t, st.Error) + + f.write(lTrace, lDebug, lInfo, lWarn, lError) + f.close() + + exp := header + level + "\n" + for _, s := range want { + exp += s + "\n" + } + assert.Equal(t, exp, f.read(t, "evcc-2026-10-05.log")) + }) + } +} + +// TestFileDumpsBuffer: switching on writes the buffer in the order the lines +// came, trace and other lines mixed, filtered by level, without cache lines +func TestFileDumpsBuffer(t *testing.T) { + f := newFileTest(t) + + f.write(lTrace, lDebug, "[cache ] DEBUG dropped", lInfo, "[mqtt ] TRACE 2026/10/05 12:00:02 trace 2", lError) + + _, err := f.setFile(f.config("debug", 14)) + require.NoError(t, err) + + f.write(lWarn) + f.close() + + assert.Equal(t, header+"debug\n"+lDebug+"\n"+lInfo+"\n"+lError+"\n"+lWarn+"\n", f.read(t, "evcc-2026-10-05.log")) + + // switched on again: appended, with a header of its own + _, err = f.setFile(f.config("error", 14)) + require.NoError(t, err) + f.close() + + got := f.read(t, "evcc-2026-10-05.log") + assert.Equal(t, 2, strings.Count(got, "[logfil] INFO")) + assert.True(t, strings.HasSuffix(got, header+"error\n"+lError+"\n")) +} + +// TestFileDumpNoGapNoDuplicate: lines written by other goroutines while the +// file is switched on end up in the file exactly once, in order +func TestFileDumpNoGapNoDuplicate(t *testing.T) { + f := newFileTest(t) + + const writers, lines = 8, 1000 + + var wg sync.WaitGroup + start := make(chan struct{}) + for w := range writers { + wg.Go(func() { + <-start + for i := range lines { + f.write(fmt.Sprintf("[site ] INFO 2026/10/05 12:00:00 w%d-%04d", w, i)) + if i%100 == 0 { + time.Sleep(time.Millisecond) + } + } + }) + } + + close(start) + time.Sleep(2 * time.Millisecond) + _, err := f.setFile(f.config("info", 14)) + require.NoError(t, err) + + wg.Wait() + f.close() + + seen := make(map[string]int) + next := make(map[int]int) + for _, l := range strings.Split(strings.TrimSpace(f.read(t, "evcc-2026-10-05.log")), "\n")[1:] { + id := l[strings.LastIndex(l, " ")+1:] + seen[id]++ + + var w, i int + _, err := fmt.Sscanf(id, "w%d-%d", &w, &i) + require.NoError(t, err) + assert.Equal(t, next[w], i, "writer %d in order", w) + next[w] = i + 1 + } + + assert.Len(t, seen, writers*lines) + for id, n := range seen { + assert.Equal(t, 1, n, id) + } +} + +func TestFileDayRotation(t *testing.T) { + f := newFileTest(t) + + _, err := f.setFile(f.config("debug", 14)) + require.NoError(t, err) + f.write(lInfo) + + // the first line of the next day switches the file + f.setTime(time.Date(2026, 10, 6, 0, 0, 3, 0, time.Local)) + f.write(lError) + f.waitMaintain() + f.close() + + assert.ElementsMatch(t, []string{"evcc-2026-10-05.log.gz", "evcc-2026-10-06.log"}, f.names(t), "the day before is packed, the original gone") + assert.Equal(t, header+"debug\n"+lInfo+"\n", readGz(t, filepath.Join(f.dir, "evcc-2026-10-05.log.gz"))) + + day2 := f.read(t, "evcc-2026-10-06.log") + assert.True(t, strings.HasPrefix(day2, "[logfil] INFO 2026/10/06 00:00:03 evcc 0.1.2, level debug\n"), day2) + assert.True(t, strings.HasSuffix(day2, lError+"\n")) +} + +// TestFileRetention: older than the retention is deleted when switching on and +// at a new day; files the day before that were left unpacked get packed +func TestFileRetention(t *testing.T) { + f := newFileTest(t) + require.NoError(t, os.MkdirAll(f.dir, 0o755)) + + touch := func(name, content string) { + require.NoError(t, os.WriteFile(filepath.Join(f.dir, name), []byte(content), 0o644)) + } + touch("evcc-2026-09-20.log.gz", "old") // 15 days: deleted + touch("evcc-2026-09-29.log.gz", "old") // 6 days: kept + touch("evcc-2026-09-28.log", "old") // 7 days: kept + touch("evcc-2026-10-03.log", "left\n") // not packed yet + touch("evcc-2026-10-01.log.gz.tmp", "") // stopped while packing + touch("notes.txt", "not ours") + touch("evcc-x.log", "not ours") + + _, err := f.setFile(f.config("debug", 7)) + require.NoError(t, err) + f.waitMaintain() + + assert.ElementsMatch(t, []string{ + "evcc-2026-09-29.log.gz", "evcc-2026-09-28.log.gz", "evcc-2026-10-03.log.gz", "evcc-2026-10-05.log", "notes.txt", "evcc-x.log", + }, f.names(t)) + assert.Equal(t, "left\n", readGz(t, filepath.Join(f.dir, "evcc-2026-10-03.log.gz"))) + + // a new day moves the window + f.setTime(time.Date(2026, 10, 6, 0, 0, 1, 0, time.Local)) + f.write(lInfo) + f.waitMaintain() + + assert.NotContains(t, f.names(t), "evcc-2026-09-28.log.gz") + assert.Contains(t, f.names(t), "evcc-2026-09-29.log.gz") + assert.Contains(t, f.names(t), "evcc-2026-10-05.log.gz") +} + +// TestFileSizeLimit: over the limit the oldest files go with a warning +func TestFileSizeLimit(t *testing.T) { + f := newFileTest(t) + f.sizeLimit = 150 + require.NoError(t, os.MkdirAll(f.dir, 0o755)) + + for _, d := range []string{"01", "02", "03"} { + require.NoError(t, os.WriteFile(filepath.Join(f.dir, "evcc-2026-10-"+d+".log.gz"), make([]byte, 60), 0o644)) + } + + _, err := f.setFile(f.config("debug", 14)) + require.NoError(t, err) + f.waitMaintain() + + // 180 and the header (58 bytes) over 150: the two oldest go + assert.ElementsMatch(t, []string{"evcc-2026-10-03.log.gz", "evcc-2026-10-05.log"}, f.names(t)) + + warns := f.logged() + require.Len(t, warns, 2) + for i, d := range []string{"01", "02"} { + assert.Contains(t, warns[i], fmt.Sprintf("%d ", jww.LevelWarn)) + assert.Contains(t, warns[i], "evcc-2026-10-"+d+".log.gz") + } +} + +// TestFileSizeLimitKeepsToday: today's file is never deleted, however large +func TestFileSizeLimitKeepsToday(t *testing.T) { + f := newFileTest(t) + f.sizeLimit = 100 + + _, err := f.setFile(f.config("debug", 14)) + require.NoError(t, err) + f.waitMaintain() + + f.write("[site ] INFO " + strings.Repeat("x", 300)) + f.l.mu.RLock() + f.sink.flush() + f.l.mu.RUnlock() + f.sink.maintain() + + assert.Equal(t, []string{"evcc-2026-10-05.log"}, f.names(t)) + assert.Empty(t, f.logged()) +} + +// TestFileSizeLimitKeepsNewer: only as many of the oldest go as needed +func TestFileSizeLimitKeepsNewer(t *testing.T) { + f := newFileTest(t) + f.sizeLimit = 200 + require.NoError(t, os.MkdirAll(f.dir, 0o755)) + + for _, d := range []string{"01", "02", "03", "04"} { + require.NoError(t, os.WriteFile(filepath.Join(f.dir, "evcc-2026-10-"+d+".log.gz"), make([]byte, 60), 0o644)) + } + + _, err := f.setFile(f.config("debug", 14)) + require.NoError(t, err) + f.waitMaintain() + + // 240 and the header over 200: the two oldest go + assert.ElementsMatch(t, []string{"evcc-2026-10-03.log.gz", "evcc-2026-10-04.log.gz", "evcc-2026-10-05.log"}, f.names(t)) +} + +// TestFileErrorFolder: a folder that cannot be created is reported once, shown +// in the state, and the log buffer keeps working +func TestFileErrorFolder(t *testing.T) { + f := newFileTest(t) + + blocker := filepath.Join(t.TempDir(), "file") + require.NoError(t, os.WriteFile(blocker, nil, 0o644)) + + cfg := f.config("debug", 14) + cfg.Dir = filepath.Join(blocker, "logs") + + st, err := f.setFile(cfg) + require.NoError(t, err, "a file that cannot be written is no invalid setting") + assert.True(t, st.Enabled, "the setting stays on") + assert.NotEmpty(t, st.Error) + + f.write(lInfo) + assert.Equal(t, []string{lInfo}, f.l.All(nil, jww.LevelTrace, 0)) + + assert.Eventually(t, func() bool { return len(f.logged()) == 1 }, time.Second, time.Millisecond) + assert.Contains(t, f.logged()[0], fmt.Sprintf("%d ", jww.LevelError)) + + assert.NotEmpty(t, f.status().Error) + + // no folder at all + cfg.Dir = "" + st, err = f.setFile(cfg) + require.NoError(t, err) + assert.NotEmpty(t, st.Error) +} + +// TestFileErrorWriting: a file that fails while running switches itself off +// once, the buffer and the other outputs go on +func TestFileErrorWriting(t *testing.T) { + f := newFileTest(t) + + _, err := f.setFile(f.config("debug", 14)) + require.NoError(t, err) + + // the disk fails: the file is gone from under the writer + f.l.mu.RLock() + require.NoError(t, f.sink.f.Close()) + f.l.mu.RUnlock() + + line := "[site ] INFO 2026/10/05 12:00:00 " + strings.Repeat("x", 1000) + for range 100 { // more than the 64 KB buffer + f.write(line) + } + + assert.Len(t, f.l.All(nil, jww.LevelTrace, 0), 100, "the log page is not affected") + + st := f.status() + assert.True(t, st.Enabled) + assert.NotEmpty(t, st.Error) + + f.l.mu.RLock() + assert.Nil(t, f.sink, "off for this run") + f.l.mu.RUnlock() + + assert.Eventually(t, func() bool { return len(f.logged()) == 1 }, time.Second, time.Millisecond) + assert.Contains(t, f.logged()[0], fmt.Sprintf("%d ", jww.LevelError)) + + // a new setting tries again + st, err = f.setFile(f.config("debug", 14)) + require.NoError(t, err) + assert.Empty(t, st.Error) +} + +func TestFileDisable(t *testing.T) { + f := newFileTest(t) + + _, err := f.setFile(f.config("debug", 14)) + require.NoError(t, err) + f.write(lInfo) + + st, err := f.setFile(FileConfig{Level: "debug", Days: 14, Dir: f.dir}) + require.NoError(t, err) + assert.False(t, st.Enabled) + assert.Equal(t, 1, st.Files, "files stay") + assert.Positive(t, st.Size) + + f.write(lError) + assert.Equal(t, header+"debug\n"+lInfo+"\n", f.read(t, "evcc-2026-10-05.log"), "flushed on switching off, nothing after") +} + +func TestFileValidate(t *testing.T) { + f := newFileTest(t) + + for _, cfg := range []FileConfig{ + {Enabled: true, Level: "verbose", Days: 14, Dir: f.dir}, + {Enabled: true, Level: "", Days: 14, Dir: f.dir}, + {Enabled: true, Level: "debug", Days: 0, Dir: f.dir}, + {Enabled: true, Level: "debug", Days: 91, Dir: f.dir}, + } { + _, err := f.setFile(cfg) + assert.Error(t, err, "%+v", cfg) + } + assert.NoDirExists(t, f.dir) + assert.False(t, f.status().Enabled) + + for _, l := range []string{"error", "WARN", "Info", "debug", "trace"} { + assert.NoError(t, FileConfig{Level: l, Days: 90}.Validate(), l) + } +} + +// TestFileFlushes: written out every flush interval, not only on closing +func TestFileFlushes(t *testing.T) { + f := newFileTest(t) + f.flushEvery = 5 * time.Millisecond + + _, err := f.setFile(f.config("debug", 14)) + require.NoError(t, err) + f.write(lInfo) + + assert.Eventually(t, func() bool { + b, _ := os.ReadFile(filepath.Join(f.dir, "evcc-2026-10-05.log")) + return strings.Contains(string(b), lInfo) + }, 2*time.Second, 5*time.Millisecond) +} + +// TestFileLineWithoutNewline: every line ends in a newline in the file +func TestFileLineWithoutNewline(t *testing.T) { + f := newFileTest(t) + _, err := f.setFile(f.config("debug", 14)) + require.NoError(t, err) + + f.write(lInfo, lError+"\n", lWarn) + f.close() + + assert.Equal(t, header+"debug\n"+lInfo+"\n"+lError+"\n"+lWarn+"\n", f.read(t, "evcc-2026-10-05.log")) +} + +// TestFileStatus: folder, number and size of the files +func TestFileStatus(t *testing.T) { + f := newFileTest(t) + + st, err := f.setFile(f.config("info", 30)) + require.NoError(t, err) + assert.Equal(t, f.dir, st.Dir) + assert.Equal(t, "info", st.Level) + assert.Equal(t, 30, st.Days) + assert.Equal(t, 1, st.Files) + assert.EqualValues(t, len(header+"info\n"), st.Size, "the header is on disk right away") + + f.write(lInfo) + f.l.mu.RLock() + f.sink.flush() + f.l.mu.RUnlock() + + st = f.status() + assert.Equal(t, 1, st.Files) + assert.EqualValues(t, len(header+"info\n"+lInfo+"\n"), st.Size) +} From 6be7eace09df0720e9c752a631b3a36739299867 Mon Sep 17 00:00:00 2001 From: SolarPower2024 Date: Mon, 5 Oct 2026 20:54:15 +0200 Subject: [PATCH 2/6] Log-Datei: Hooks in util/log.go und cmd/root.go, Vertragstests MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit newLogger schreibt über logstash.Output statt direkt in den Ringpuffer, runRoot ruft nach den Shutdown-Funktionen logstash.CloseFile. Vertragstests: eine Zeile jedes Levels, redigiert, landet in Datei und Log-Seite; der Puffer vor dem Einschalten ist in der Datei; CloseFile schreibt aus. forkHooks und Touch-Point-Tabelle um beide Hooks ergänzt. Co-Authored-By: Claude Sonnet 5.5 --- cmd/root.go | 3 + core/fork_hooks_test.go | 2 + core/lm/README.md | 2 + util/log.go | 2 +- util/logstash/file_hook_custom_test.go | 95 ++++++++++++++++++++++++++ 5 files changed, 103 insertions(+), 1 deletion(-) create mode 100644 util/logstash/file_hook_custom_test.go diff --git a/cmd/root.go b/cmd/root.go index f602d9257f..f2e69fff9f 100644 --- a/cmd/root.go +++ b/cmd/root.go @@ -28,6 +28,7 @@ import ( "github.com/evcc-io/evcc/ui" "github.com/evcc-io/evcc/util" "github.com/evcc-io/evcc/util/auth" + "github.com/evcc-io/evcc/util/logstash" "github.com/evcc-io/evcc/util/pipe" "github.com/evcc-io/evcc/util/sponsor" "github.com/evcc-io/evcc/util/telemetry" @@ -556,6 +557,8 @@ func runRoot(cmd *cobra.Command, args []string) { case <-time.After(max(conf.Interval, 5*time.Second)): } + logstash.CloseFile() // custom: write out the log file, see util/logstash/file_custom.go + // exit code 1 on error os.Exit(cast.ToInt(err != nil)) } diff --git a/core/fork_hooks_test.go b/core/fork_hooks_test.go index 713928317c..c5153ed572 100644 --- a/core/fork_hooks_test.go +++ b/core/fork_hooks_test.go @@ -48,6 +48,8 @@ var forkHooks = []struct { {"api/globalconfig/types.go", "TariffRefs.IsConfigured", []string{"FeedInEeg"}}, {"api/globalconfig/types.go", "TariffRefs.Used", []string{"FeedInEeg"}}, {"charger/switchsocket.go", "NewSwitchSocketFromConfig", []string{"RatedPower"}}, + {"util/log.go", "newLogger", []string{"Output"}}, + {"cmd/root.go", "runRoot", []string{"CloseFile"}}, } // forkUiHooks lists the fork's mounts in evcc's ui files diff --git a/core/lm/README.md b/core/lm/README.md index a1290a8989..5591c1c4f4 100644 --- a/core/lm/README.md +++ b/core/lm/README.md @@ -459,6 +459,8 @@ Every change in an evcc file. Check these when merging a new evcc version. | `core/loadpoint/config.go`, `server/http_config_loadpoint_handler.go` | `PhaseSwitchConfig` in the dynamic config, applied after min/max current, read back for the ui | | `core/circuit/circuit.go` | over power logged via `overPowerLog()` (info, no ui notification) | | `charger/switchsocket.go` | `RatedPower` config field | +| `util/log.go` | `newLogger` writes to `logstash.Output` instead of `logstash.DefaultHandler`, which passes every line on to it and to the log file | +| `cmd/root.go` | `logstash.CloseFile()` at the end of `runRoot`, after the shutdown functions | | `templates/definition/charger/homeassistant-switch.yaml` | `ratedpower` parameter | | `api/globalconfig/types.go`, `tariff/tariffs.go`, `cmd/setup.go`, `server/http_config_device_handler.go` | `feedInEeg` tariff: ref field, `Used`/`IsConfigured`, one `configureTariff` call, cleared on delete | | `server/http.go` | `addCustomSiteRoutes`: a route colliding with an evcc route is left out and logged | diff --git a/util/log.go b/util/log.go index d77408eba2..697d00ed40 100644 --- a/util/log.go +++ b/util/log.go @@ -60,7 +60,7 @@ func newLogger(area string, lp int) *Logger { redactor := new(Redactor) notepad := jww.NewNotepad( level, jww.LevelTrace, - &redactWriter{os.Stdout, redactor}, &redactWriter{logstash.DefaultHandler, redactor}, + &redactWriter{os.Stdout, redactor}, &redactWriter{logstash.Output, redactor}, // custom: log file, see util/logstash/file_custom.go padded, log.Ldate|log.Ltime) logger := &Logger{ diff --git a/util/logstash/file_hook_custom_test.go b/util/logstash/file_hook_custom_test.go new file mode 100644 index 0000000000..62b9aafe8d --- /dev/null +++ b/util/logstash/file_hook_custom_test.go @@ -0,0 +1,95 @@ +package logstash_test + +import ( + "os" + "path/filepath" + "strings" + "testing" + "time" + + "github.com/evcc-io/evcc/util" + "github.com/evcc-io/evcc/util/logstash" + jww "github.com/spf13/jwalterweatherman" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +// TestLoggerWritesToLogFile pins the hook in newLogger: every line of every +// level, redacted, reaches the log file as well as the log page. The buffer +// content before switching on is in the file. An external test, as the lines +// land in the global log buffer that the tests of util count. The secret is as +// long as its replacement: evcc drops a line from the log page if redaction +// changes its length (io.MultiWriter stops at the short write of the console). +func TestLoggerWritesToLogFile(t *testing.T) { + dir := filepath.Join(t.TempDir(), "logs") + + log := util.NewLogger("tstfile").Redact("pwd") + log.DEBUG.Print("before the file") + + // inert until switched on + assert.NoDirExists(t, dir) + + st, err := logstash.SetFile(logstash.FileConfig{Enabled: true, Level: "trace", Days: 14, Dir: dir, Version: "test"}) + require.NoError(t, err) + require.Empty(t, st.Error) + t.Cleanup(func() { + _, _ = logstash.SetFile(logstash.FileConfig{Level: "trace", Days: 14, Dir: dir}) + }) + + log.TRACE.Print("a trace line") + log.INFO.Print("password pwd") + log.ERROR.Print("an error") + + // the log page keeps its content + page := logstash.All([]string{"tstfile"}, jww.LevelTrace, 0) + assert.Len(t, page, 4) + + logstash.CloseFile() + + files, err := filepath.Glob(filepath.Join(dir, "evcc-*.log")) + require.NoError(t, err) + require.Len(t, files, 1) + + b, err := os.ReadFile(files[0]) + require.NoError(t, err) + got := string(b) + + assert.Contains(t, got, "before the file") + assert.Contains(t, got, "a trace line") + assert.Contains(t, got, "an error") + assert.NotContains(t, got, "pwd", "redacted before the file") + assert.Contains(t, got, "password") + + // the file holds what the log page holds + assert.Contains(t, got, strings.Join(page, "")) +} + +// TestCloseFileWritesOut: what the shutdown hook calls writes the buffered +// lines out, without waiting for the flush interval +func TestCloseFileWritesOut(t *testing.T) { + dir := filepath.Join(t.TempDir(), "logs") + + _, err := logstash.SetFile(logstash.FileConfig{Enabled: true, Level: "info", Days: 14, Dir: dir}) + require.NoError(t, err) + t.Cleanup(func() { + _, _ = logstash.SetFile(logstash.FileConfig{Level: "info", Days: 14, Dir: dir}) + }) + + util.NewLogger("tstclose").INFO.Print("last line before exit") + logstash.CloseFile() + + files, err := filepath.Glob(filepath.Join(dir, "evcc-*.log")) + require.NoError(t, err) + require.Len(t, files, 1) + + b, err := os.ReadFile(files[0]) + require.NoError(t, err) + assert.Contains(t, string(b), "last line before exit") + + // nothing is written after closing + util.NewLogger("tstclose").INFO.Print("after") + time.Sleep(10 * time.Millisecond) + b, err = os.ReadFile(files[0]) + require.NoError(t, err) + assert.NotContains(t, string(b), "after") +} From 7ccfcc60283fe0c2322bef14f606437287042cab Mon Sep 17 00:00:00 2001 From: SolarPower2024 Date: Mon, 5 Oct 2026 20:56:44 +0200 Subject: [PATCH 3/6] Log-Datei: Einstellung, Wiederherstellung und API MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Key logFile, site.API LogFile/SetLogFile, GET und POST /api/logfile mit Prüfung von Level und Tagen. restoreLogFile hängt in restoreCustom und schaltet die Datei nach einem Neustart wieder ein. Ordner: /config/logs, wenn /config ein Verzeichnis ist, sonst logs neben der Datenbank. Tests: Ordnerwahl, ohne Einstellung nichts geschrieben, Einstellung übersteht den Neustart, ungültige Werte, Routen. Co-Authored-By: Claude Sonnet 5.5 --- core/keys/site_custom.go | 3 + core/site/api_custom.go | 5 ++ core/site_lm.go | 1 + core/site_logfile.go | 95 ++++++++++++++++++++++++ core/site_logfile_test.go | 146 +++++++++++++++++++++++++++++++++++++ core/site_restore_test.go | 7 ++ server/http_custom.go | 30 ++++++++ server/http_custom_test.go | 40 ++++++++++ 8 files changed, 327 insertions(+) create mode 100644 core/site_logfile.go create mode 100644 core/site_logfile_test.go diff --git a/core/keys/site_custom.go b/core/keys/site_custom.go index c2a9e4390a..9e4de467b3 100644 --- a/core/keys/site_custom.go +++ b/core/keys/site_custom.go @@ -69,4 +69,7 @@ const ( // export under a second feed-in tariff, see core/site_feedin_eeg.go FeedInEegEntity = "feedInEegEntity" // Home Assistant energy counter of the EEG export TariffFeedInEeg = "tariffFeedInEeg" // published: current EEG price + + // log in daily files, see core/site_logfile.go + LogFile = "logFile" ) diff --git a/core/site/api_custom.go b/core/site/api_custom.go index 31db061b1b..13d221a6e5 100644 --- a/core/site/api_custom.go +++ b/core/site/api_custom.go @@ -4,6 +4,7 @@ import ( "time" "github.com/evcc-io/evcc/core/lm/profile" + "github.com/evcc-io/evcc/util/logstash" ) // CustomAPI is the part of the site api added by this fork. It lives in its own @@ -56,6 +57,10 @@ type CustomAPI interface { GetFeedInEegEntity() string SetFeedInEegEntity(string) error + // log in daily files, see core/site_logfile.go + LogFile() logstash.FileState + SetLogFile(logstash.FileConfig) error + // peak shaving, see core/site_peakshaving.go GetPeakShaving() bool SetPeakShaving(bool) error diff --git a/core/site_lm.go b/core/site_lm.go index 12161b9da0..058a125985 100644 --- a/core/site_lm.go +++ b/core/site_lm.go @@ -100,6 +100,7 @@ func (site *Site) restoreCustom() { site.restoreLmSettings() site.restorePeakSettings() site.restoreFeedInEeg() + site.restoreLogFile() } // updateCustom runs the fork's per cycle work once the meters are read, before diff --git a/core/site_logfile.go b/core/site_logfile.go new file mode 100644 index 0000000000..dcc15676a1 --- /dev/null +++ b/core/site_logfile.go @@ -0,0 +1,95 @@ +package core + +// Custom extension: the log in daily files, set in the ui on the log page. The +// writing is in util/logstash/file_custom.go, this holds the setting, the folder +// and the api. Without a stored setting nothing is written and no folder created. + +import ( + "os" + "path/filepath" + "strings" + "sync" + + "github.com/evcc-io/evcc/core/keys" + "github.com/evcc-io/evcc/db" + "github.com/evcc-io/evcc/db/settings" + "github.com/evcc-io/evcc/util" + "github.com/evcc-io/evcc/util/logstash" + jww "github.com/spf13/jwalterweatherman" +) + +// logFileMu serializes saving and applying the setting +var logFileMu sync.Mutex + +// logFileDir returns the folder of the log files, replaced in tests +var logFileDir = func() string { + return logFileDirFor("/config", db.FilePath()) +} + +// logFileDirFor returns /config/logs where /config is a folder (the add-on, reachable through +// its share), else logs next to the database file. Empty without either, e.g. an in-memory database. +func logFileDirFor(configDir, dbFile string) string { + if fi, err := os.Stat(configDir); err == nil && fi.IsDir() { + return filepath.Join(configDir, "logs") + } + + if dbFile == "" || strings.Contains(dbFile, ":memory:") || strings.Contains(dbFile, "mode=memory") { + return "" + } + + return filepath.Join(filepath.Dir(dbFile), "logs") +} + +// restoreLogFile applies the persisted setting, switched on again after a restart +func (site *Site) restoreLogFile() { + cfg := logstash.DefaultFileConfig + + if err := settings.Json(keys.LogFile, &cfg); err != nil || cfg.Validate() != nil { + cfg = logstash.DefaultFileConfig + } + + site.applyLogFile(cfg) +} + +// applyLogFile hands the setting to the writer +func (site *Site) applyLogFile(cfg logstash.FileConfig) { + log := util.NewLogger("logfil") + + cfg.Level = strings.ToLower(cfg.Level) + cfg.Dir = logFileDir() + cfg.Version = util.FormattedVersion() + cfg.Log = func(level jww.Threshold, msg string) { + if level >= jww.LevelError { + log.ERROR.Println(msg) + } else { + log.WARN.Println(msg) + } + } + + _, _ = logstash.SetFile(cfg) +} + +// LogFile returns the log file setting with folder, files and size +func (site *Site) LogFile() logstash.FileState { + return logstash.FileStatus() +} + +// SetLogFile saves the log file setting and applies it +func (site *Site) SetLogFile(cfg logstash.FileConfig) error { + if err := cfg.Validate(); err != nil { + return err + } + + cfg.Level = strings.ToLower(cfg.Level) + + logFileMu.Lock() + defer logFileMu.Unlock() + + if err := settings.SetJson(keys.LogFile, cfg); err != nil { + return err + } + + site.applyLogFile(cfg) + + return nil +} diff --git a/core/site_logfile_test.go b/core/site_logfile_test.go new file mode 100644 index 0000000000..f4c8e8e039 --- /dev/null +++ b/core/site_logfile_test.go @@ -0,0 +1,146 @@ +package core + +import ( + "os" + "path/filepath" + "testing" + + "github.com/evcc-io/evcc/core/keys" + "github.com/evcc-io/evcc/db/settings" + "github.com/evcc-io/evcc/util/logstash" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +// useLogFileDir points the log file at a folder of the test and switches it off afterwards +func useLogFileDir(t *testing.T) string { + t.Helper() + + dir := filepath.Join(t.TempDir(), "logs") + + prev := logFileDir + logFileDir = func() string { return dir } + t.Cleanup(func() { + logFileDir = prev + _, _ = logstash.SetFile(logstash.DefaultFileConfig) + }) + + return dir +} + +func TestLogFileDirFor(t *testing.T) { + root := t.TempDir() + file := filepath.Join(root, "file") + require.NoError(t, os.WriteFile(file, nil, 0o644)) + + // the add-on: /config is a folder and takes precedence over the database + assert.Equal(t, filepath.Join(root, "logs"), logFileDirFor(root, "/var/lib/evcc/evcc.db")) + + // /config missing or no folder: next to the database + assert.Equal(t, filepath.Join("/var/lib/evcc", "logs"), logFileDirFor(filepath.Join(root, "none"), "/var/lib/evcc/evcc.db")) + assert.Equal(t, filepath.Join("/var/lib/evcc", "logs"), logFileDirFor(file, "/var/lib/evcc/evcc.db")) + + // no place to write to + assert.Empty(t, logFileDirFor(root+"/none", "")) + assert.Empty(t, logFileDirFor(root+"/none", ":memory:")) + assert.Empty(t, logFileDirFor(root+"/none", "file::memory:?cache=shared")) +} + +// TestLogFileInertWhenUnused: without a stored setting nothing is written and +// no folder created +func TestLogFileInertWhenUnused(t *testing.T) { + noSettingsDB(t) + keepSettings(t) + dir := useLogFileDir(t) + + site := &Site{} + site.restoreLogFile() + + st := site.LogFile() + assert.False(t, st.Enabled) + assert.Equal(t, "debug", st.Level) + assert.Equal(t, 14, st.Days) + assert.Equal(t, dir, st.Dir) + assert.Zero(t, st.Files) + assert.NoDirExists(t, dir) +} + +// TestLogFileSettingSurvivesRestart: set through the api, switched on again by +// restoreLogFile, folder and version are not stored +func TestLogFileSettingSurvivesRestart(t *testing.T) { + noSettingsDB(t) + keepSettings(t) + dir := useLogFileDir(t) + + a := &Site{} + require.NoError(t, a.SetLogFile(logstash.FileConfig{Enabled: true, Level: "INFO", Days: 30})) + + st := a.LogFile() + assert.True(t, st.Enabled) + assert.Empty(t, st.Error) + assert.Equal(t, "info", st.Level) + assert.Equal(t, 30, st.Days) + assert.Equal(t, dir, st.Dir) + assert.DirExists(t, dir) + + stored, err := settings.String(keys.LogFile) + require.NoError(t, err) + assert.JSONEq(t, `{"enabled":true,"level":"info","days":30}`, stored) + + // restart: the writer starts from nothing + _, err = logstash.SetFile(logstash.DefaultFileConfig) + require.NoError(t, err) + require.NoError(t, os.RemoveAll(dir)) + + b := &Site{} + b.restoreLogFile() + + st = b.LogFile() + assert.True(t, st.Enabled) + assert.Equal(t, "info", st.Level) + assert.Equal(t, 30, st.Days) + assert.Empty(t, st.Error) + assert.DirExists(t, dir, "switched on again") + + // switched off: stays off after a restart, files stay + require.NoError(t, b.SetLogFile(logstash.FileConfig{Level: "info", Days: 30})) + assert.False(t, b.LogFile().Enabled) + assert.Equal(t, 1, b.LogFile().Files) + + _, err = logstash.SetFile(logstash.DefaultFileConfig) + require.NoError(t, err) + c := &Site{} + c.restoreLogFile() + assert.False(t, c.LogFile().Enabled) +} + +func TestLogFileInvalidSetting(t *testing.T) { + noSettingsDB(t) + keepSettings(t) + dir := useLogFileDir(t) + + site := &Site{} + + assert.Error(t, site.SetLogFile(logstash.FileConfig{Enabled: true, Level: "verbose", Days: 14})) + assert.Error(t, site.SetLogFile(logstash.FileConfig{Enabled: true, Level: "debug", Days: 0})) + assert.Error(t, site.SetLogFile(logstash.FileConfig{Enabled: true, Level: "debug", Days: 91})) + + assert.False(t, settings.Exists(keys.LogFile), "nothing stored") + assert.False(t, site.LogFile().Enabled) + assert.NoDirExists(t, dir) +} + +// TestLogFileStoredInvalidIsIgnored: a stored setting that no longer validates falls back to off +func TestLogFileStoredInvalidIsIgnored(t *testing.T) { + noSettingsDB(t) + keepSettings(t) + dir := useLogFileDir(t) + + settings.SetString(keys.LogFile, `{"enabled":true,"level":"loud","days":14}`) + + site := &Site{} + site.restoreLogFile() + + assert.False(t, site.LogFile().Enabled) + assert.NoDirExists(t, dir) +} diff --git a/core/site_restore_test.go b/core/site_restore_test.go index 84537981e9..eb0bd26088 100644 --- a/core/site_restore_test.go +++ b/core/site_restore_test.go @@ -9,6 +9,7 @@ import ( "github.com/evcc-io/evcc/db/settings" "github.com/evcc-io/evcc/util" "github.com/evcc-io/evcc/util/config" + "github.com/evcc-io/evcc/util/logstash" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" ) @@ -23,6 +24,8 @@ func TestRestoreCustomAfterRestart(t *testing.T) { config.Reset() t.Cleanup(config.Reset) + useLogFileDir(t) + main, err := circuit.New(util.NewLogger("test"), "main", 0, 10000, nil, 0) require.NoError(t, err) require.NoError(t, config.Circuits().Add(config.NewStaticDevice(config.Named{Name: "main"}, api.Circuit(main)))) @@ -50,6 +53,7 @@ func TestRestoreCustomAfterRestart(t *testing.T) { require.NoError(t, a.SetPeakFollowBuffer(1000)) require.NoError(t, a.SetPeakFollow(true)) require.NoError(t, a.SetPeakTariff("price", 40)) + require.NoError(t, a.SetLogFile(logstash.FileConfig{Enabled: true, Level: "info", Days: 30})) // set through Home Assistant in the ui, stored as names settings.SetString(keys.PeakShavingEntity, "input_number.peak") @@ -84,4 +88,7 @@ func TestRestoreCustomAfterRestart(t *testing.T) { assert.Equal(t, "input_number.charge", b.GetPeakShavingChargeEntity()) assert.Equal(t, "sensor.grid_import", b.GetPeakShavingEnergyEntity()) assert.Equal(t, "sensor.eeg_export", b.GetFeedInEegEntity()) + assert.True(t, b.LogFile().Enabled) + assert.Equal(t, "info", b.LogFile().Level) + assert.Equal(t, 30, b.LogFile().Days) } diff --git a/server/http_custom.go b/server/http_custom.go index feb36a58d0..171ba8da93 100644 --- a/server/http_custom.go +++ b/server/http_custom.go @@ -18,6 +18,7 @@ import ( "github.com/evcc-io/evcc/core/metrics" "github.com/evcc-io/evcc/core/site" "github.com/evcc-io/evcc/util" + "github.com/evcc-io/evcc/util/logstash" "github.com/gorilla/mux" ) @@ -101,6 +102,10 @@ func customSiteRoutes(site site.API) map[string]route { "feedineegentitydelete": {"DELETE", "/feedineegentity", stringHandler(site.SetFeedInEegEntity, site.GetFeedInEegEntity)}, "feedinsplit": {"GET", "/feedinsplit", feedInSplitHandler}, + // log in daily files, see core/site_logfile.go + "logfile": {"GET", "/logfile", logFileHandler(site)}, + "logfileset": {"POST", "/logfile", logFileSetHandler(site)}, + // peak shaving, see core/site_peakshaving.go "peakshaving": {"POST", "/peakshaving/{value:[01truefalse]+}", boolHandler(site.SetPeakShaving, site.GetPeakShaving)}, "peakshavinglimit": {"POST", "/peakshavinglimit/{value:[0-9.]+}", floatHandler(site.SetPeakShavingLimit, site.GetPeakShavingLimit)}, @@ -120,6 +125,31 @@ func customSiteRoutes(site site.API) map[string]route { } } +// logFileHandler returns the log file setting and the state of the files +func logFileHandler(site site.API) http.HandlerFunc { + return func(w http.ResponseWriter, r *http.Request) { + jsonWrite(w, site.LogFile()) + } +} + +// logFileSetHandler saves the log file setting sent as json and answers like logFileHandler +func logFileSetHandler(site site.API) http.HandlerFunc { + return func(w http.ResponseWriter, r *http.Request) { + var cfg logstash.FileConfig + err := json.NewDecoder(http.MaxBytesReader(w, r.Body, 4<<10)).Decode(&cfg) + if err == nil { + err = site.SetLogFile(cfg) + } + + if err != nil { + jsonError(w, http.StatusBadRequest, err) + return + } + + jsonWrite(w, site.LogFile()) + } +} + // lmProfileSaveHandler creates or updates a battery profile sent as json func lmProfileSaveHandler(site site.API) http.HandlerFunc { return func(w http.ResponseWriter, r *http.Request) { diff --git a/server/http_custom_test.go b/server/http_custom_test.go index 48790c89ad..2a020b9d6e 100644 --- a/server/http_custom_test.go +++ b/server/http_custom_test.go @@ -10,6 +10,7 @@ import ( "github.com/evcc-io/evcc/core" "github.com/evcc-io/evcc/core/lm/profile" "github.com/evcc-io/evcc/core/site" + "github.com/evcc-io/evcc/util/logstash" "github.com/gorilla/mux" "github.com/stretchr/testify/assert" ) @@ -116,6 +117,8 @@ var customRouteSamples = map[string]string{ "feedineegentity": "/feedineegentity/sensor.eeg_export", "feedineegentitydelete": "/feedineegentity", "feedinsplit": "/feedinsplit?from=2026-09-01&to=2026-10-01&aggregate=day", + "logfile": "/logfile", + "logfileset": "/logfile", "peakshaving": "/peakshaving/false", "peakshavinglimit": "/peakshavinglimit/7000", "peakfollow": "/peakfollow/true", @@ -186,3 +189,40 @@ func must[T any](v T, err error) T { } return v } + +// TestLogFileRoutes: GET and POST answer the state, an invalid level or retention is a 400 +func TestLogFileRoutes(t *testing.T) { + r := mux.NewRouter() + for _, rt := range customSiteRoutes(core.NewSite()) { + r.Methods(rt.Methods()...).Path(rt.Pattern).Handler(rt.HandlerFunc) + } + + do := func(method, body string) *httptest.ResponseRecorder { + w := httptest.NewRecorder() + r.ServeHTTP(w, httptest.NewRequest(method, "/logfile", strings.NewReader(body))) + return w + } + + t.Cleanup(func() { _, _ = logstash.SetFile(logstash.DefaultFileConfig) }) + + w := do(http.MethodGet, "") + assert.Equal(t, http.StatusOK, w.Code) + assert.Contains(t, w.Body.String(), `"enabled":false`) + + // disabled: stored, nothing written + w = do(http.MethodPost, `{"enabled":false,"level":"WARN","days":7,"dir":"/ignored"}`) + assert.Equal(t, http.StatusOK, w.Code) + assert.Contains(t, w.Body.String(), `"level":"warn"`) + assert.Contains(t, w.Body.String(), `"days":7`) + assert.NotContains(t, w.Body.String(), "ignored") + + for _, body := range []string{ + `{"enabled":true,"level":"loud","days":7}`, + `{"enabled":true,"level":"info","days":0}`, + `{"enabled":true,"level":"info","days":91}`, + `{"enabled":true,"level":"info"}`, + `not json`, + } { + assert.Equal(t, http.StatusBadRequest, do(http.MethodPost, body).Code, body) + } +} From 5190f3a372c7570053a127ee37f790d9f86e3346 Mon Sep 17 00:00:00 2001 From: SolarPower2024 Date: Mon, 5 Oct 2026 21:02:47 +0200 Subject: [PATCH 4/6] Log-Datei: Knopf und Dialog auf der Log-Seite, Texte de/en MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit LogFileButton neben dem Download-Knopf zeigt aus oder das Level, der Dialog schaltet die Datei ein, setzt Level und Aufbewahrung und zeigt Ordner, Anzahl Dateien, Größe und einen Fehler. Eine Zeile in Log.vue hängt den Knopf ein, als UI-Hook in forkUiHooks und in der Touch-Point-Tabelle. Co-Authored-By: Claude Sonnet 5.5 --- .../js/components/LogFile/LogFileButton.vue | 61 ++++++ assets/js/components/LogFile/LogFileModal.vue | 200 ++++++++++++++++++ assets/js/types/evcc-lm.ts | 16 ++ assets/js/views/Log.vue | 4 + core/fork_hooks_test.go | 1 + core/lm/README.md | 1 + i18n/de.json | 15 ++ i18n/en.json | 15 ++ 8 files changed, 313 insertions(+) create mode 100644 assets/js/components/LogFile/LogFileButton.vue create mode 100644 assets/js/components/LogFile/LogFileModal.vue diff --git a/assets/js/components/LogFile/LogFileButton.vue b/assets/js/components/LogFile/LogFileButton.vue new file mode 100644 index 0000000000..69337203de --- /dev/null +++ b/assets/js/components/LogFile/LogFileButton.vue @@ -0,0 +1,61 @@ + + + diff --git a/assets/js/components/LogFile/LogFileModal.vue b/assets/js/components/LogFile/LogFileModal.vue new file mode 100644 index 0000000000..27a3ebb4a0 --- /dev/null +++ b/assets/js/components/LogFile/LogFileModal.vue @@ -0,0 +1,200 @@ + + + + diff --git a/assets/js/types/evcc-lm.ts b/assets/js/types/evcc-lm.ts index 6b362d7d80..f98ca0ae64 100644 --- a/assets/js/types/evcc-lm.ts +++ b/assets/js/types/evcc-lm.ts @@ -257,3 +257,19 @@ export interface LmConfigLoadpoint { phaseScale3pDelay?: number; // ns before scaling up, 0/empty = enable delay phaseScale1pDelay?: number; // ns before scaling down, 0/empty = disable delay } + +/** Log file setting and state, see core/site_logfile.go. */ +export interface LogFileState { + enabled: boolean; + /** Level of the file: error, warn, info, debug or trace. */ + level: string; + /** Days the files are kept. */ + days: number; + /** Folder of the files, set by evcc. */ + dir: string; + files: number; + /** Bytes of all files. */ + size: number; + /** Why the file is off, empty = none. */ + error?: string; +} diff --git a/assets/js/views/Log.vue b/assets/js/views/Log.vue index 6e20ecb078..7b4dc97ae8 100644 --- a/assets/js/views/Log.vue +++ b/assets/js/views/Log.vue @@ -36,6 +36,8 @@ > + +
, default: () => [] }, diff --git a/core/fork_hooks_test.go b/core/fork_hooks_test.go index c5153ed572..661c6a816c 100644 --- a/core/fork_hooks_test.go +++ b/core/fork_hooks_test.go @@ -64,6 +64,7 @@ var forkUiHooks = []struct { {"assets/js/components/Config/LoadpointModal.vue", []string{" Date: Mon, 5 Oct 2026 21:03:25 +0200 Subject: [PATCH 5/6] Log-Datei: README-Abschnitt, Dateiliste, watch.json MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Abschnitt 18 beschreibt Verhalten, Ordner, Aufräumen, Fehlerfall und API; eigene Dateien in der Liste; watch.json beobachtet den Logger-Unterbau (evcc PR 32018). Co-Authored-By: Claude Sonnet 5.5 --- .github/upstream-check/watch.json | 7 +++++ core/lm/README.md | 43 +++++++++++++++++++++++++++++++ 2 files changed, 50 insertions(+) diff --git a/.github/upstream-check/watch.json b/.github/upstream-check/watch.json index 1809d95e46..f30959f536 100644 --- a/.github/upstream-check/watch.json +++ b/.github/upstream-check/watch.json @@ -124,6 +124,13 @@ "keywords": ["SetMaxPower"], "paths": ["core/circuit/", "core/site.go", "server/"] }, + { + "name": "Log-Datei (Tagesdateien)", + "files": ["util/logstash/file_custom.go", "core/site_logfile.go"], + "prs": [32018], + "keywords": ["log file", "logfile", "LogFile", "logrotate", "lumberjack", "rotat"], + "paths": ["util/log.go", "util/logstash/"] + }, { "name": "Grundlagen, auf denen der Fork aufbaut", "files": ["core/loadpoint_lm.go"], diff --git a/core/lm/README.md b/core/lm/README.md index a1b7df2336..1d1ed44de8 100644 --- a/core/lm/README.md +++ b/core/lm/README.md @@ -27,6 +27,7 @@ Part 1 describes the features, part 2 how the fork is kept maintainable. 15. [Second feed-in tariff (EEG)](#15-second-feed-in-tariff-eeg) 16. [Optimizer inputs](#16-optimizer-inputs) 17. [Advanced settings](#17-advanced-settings) +18. [Log file](#18-log-file) **Part 2: maintenance** @@ -423,6 +424,47 @@ values are not stored, so a changed default applies. Also there: the load management circuit ([7](#7-load-management-circuit-and-switch)) and evcc's `profilePercentile` ([13](#13-home-consumption-forecast)). +## 18. Log file + +evcc keeps its log in a ring buffer of 10,000 lines for the log page, which at +debug is an hour or two. *Log page → Log-Datei* (off by default, nothing is +written and no folder created until it is switched on) writes the same stream +(all areas and levels, already redacted) to `evcc-YYYY-MM-DD.log` in the local +date. The level (error to trace, default debug) is the file's own and +independent of the console level, so the console or the add-on log can stay on +info while the file gets debug. + +- the folder is fixed, shown in the dialog only: `/config/logs` where `/config` + is a folder (the add-on, readable through its Samba share under + `addon_configs`), else `logs` next to the database file +- switching on writes the log buffer into the file first (so the lines from + before the settings were loaded are in), then the new lines follow, both under + the buffer's lock: no gap, no line twice. Each file and each switching on starts + with `[logfil] INFO