Append an optional station log and announce the software after login.

A log path that cannot be written leaves the station on the reflector, and the reflector learns which program joined.

Co-authored-by: Cursor <cursoragent@cursor.com>

station/behavior_test.go

@@ -24,9 +24,18 @@ type loggedIn struct {
 }
 
 func login(t *testing.T, callsign, key string, tg int, id uint16, codecs []string) loggedIn {
+	t.Helper()
+	return loginLog(t, callsign, key, tg, id, codecs, "")
+}
+
+func loginLog(t *testing.T, callsign, key string, tg int, id uint16, codecs []string, logPath string) loggedIn {
 	t.Helper()
 	refl := newReflector(t)
-	path := writeConfigFile(t, configJSON("127.0.0.1", refl.port, callsign, key, tg))
+	file := configJSON("127.0.0.1", refl.port, callsign, key, tg)
+	if logPath != "" {
+		file = configWithLog("127.0.0.1", refl.port, callsign, key, tg, logPath)
+	}
+	path := writeConfigFile(t, file)
 	clock := newFakeClock()
 	st, err := station.New(station.Options{ConfigPath: path, Clock: clock})
 	if err != nil {
@@ -63,6 +72,11 @@ func login(t *testing.T, callsign, key string, tg int, id uint16, codecs []strin
 	refl.writeFrame(t, 12, nil)
 	refl.writeFrame(t, 100, serverInfo(id, []string{"db0abc"}, codecs))
 	typ, body = refl.readFrame(t)
+	if typ != 111 {
+		t.Fatalf("type %d, want software identity", typ)
+	}
+	requireSoftwareIdentity(t, body)
+	typ, body = refl.readFrame(t)
 	if typ != 106 {
 		t.Fatalf("type %d, want select talk group", typ)
 	}

station/config.go

@@ -4,6 +4,7 @@ import (
 	"fmt"
 	"math"
 	"os"
+	"path/filepath"
 	"regexp"
 	"strings"
 
@@ -12,27 +13,34 @@ import (
 )
 
 type loaded struct {
-	host      string
-	port      int
-	callsign  string
-	authKey   string
-	talkGroup int
+	host          string
+	port          int
+	callsign      string
+	authKey       string
+	talkGroup     int
+	enableLogging bool
+	logPath       string
+	logNotice     string
 }
 
 type fileShape struct {
-	Host      jsontext.Value `json:"host"`
-	Port      jsontext.Value `json:"port"`
-	Callsign  jsontext.Value `json:"callsign"`
-	AuthKey   jsontext.Value `json:"authKey"`
-	TalkGroup jsontext.Value `json:"talkGroup"`
+	Host          jsontext.Value `json:"host"`
+	Port          jsontext.Value `json:"port"`
+	Callsign      jsontext.Value `json:"callsign"`
+	AuthKey       jsontext.Value `json:"authKey"`
+	TalkGroup     jsontext.Value `json:"talkGroup"`
+	EnableLogging jsontext.Value `json:"enableLogging"`
+	LogFile       jsontext.Value `json:"logFile"`
 }
 
 type templateFile struct {
-	Host      string `json:"host"`
-	Port      int    `json:"port"`
-	Callsign  string `json:"callsign"`
-	AuthKey   string `json:"authKey"`
-	TalkGroup int    `json:"talkGroup"`
+	Host          string `json:"host"`
+	Port          int    `json:"port"`
+	Callsign      string `json:"callsign"`
+	AuthKey       string `json:"authKey"`
+	TalkGroup     int    `json:"talkGroup"`
+	EnableLogging bool   `json:"enableLogging"`
+	LogFile       string `json:"logFile"`
 }
 
 var callsignPattern = regexp.MustCompile(`^[A-Z0-9][A-Z]{0,2}\d[A-Z0-9]{0,3}[A-Z](?:-[A-Z0-9]{1,3})?$`)
@@ -48,11 +56,11 @@ func loadConfig(path string) (loaded, error) {
 		}
 		return loaded{}, fmt.Errorf("could not be read")
 	}
-	return parseConfig(body)
+	return parseConfig(path, body)
 }
 
 func writeTemplate(path string) error {
-	body, err := jsonv2.Marshal(templateFile{})
+	body, err := jsonv2.Marshal(templateFile{LogFile: defaultLogPath()})
 	if err != nil {
 		return err
 	}
@@ -72,11 +80,36 @@ func writeTemplate(path string) error {
 	return os.Chmod(path, 0o600)
 }
 
-func parseConfig(body []byte) (loaded, error) {
+func parseConfig(path string, body []byte) (loaded, error) {
 	var shape fileShape
 	if err := jsonv2.Unmarshal(body, &shape); err != nil {
 		return loaded{}, fmt.Errorf("could not be read")
 	}
+	if block, notice := blockedLog(shape); block {
+		cfg, err := parseOperational(shape)
+		if err != nil {
+			return loaded{}, err
+		}
+		cfg.logNotice = notice
+		return cfg, nil
+	}
+	if missingLog(shape) {
+		if !operationalKindsOK(shape) {
+			return parseOperational(shape)
+		}
+		shape = withLogDefaults(shape)
+		if err := rewriteConfig(path, shape); err != nil {
+			return loaded{}, fmt.Errorf("could not be read")
+		}
+	}
+	cfg, err := parseOperational(shape)
+	if err != nil {
+		return loaded{}, err
+	}
+	return applyLog(cfg, shape), nil
+}
+
+func parseOperational(shape fileShape) (loaded, error) {
 	host, err := stringField("host", shape.Host)
 	if err != nil {
 		return loaded{}, err
@@ -153,3 +186,139 @@ func intField(name string, v jsontext.Value, min, max int) (int, error) {
 	}
 	return n, nil
 }
+
+func defaultLogPath() string {
+	home, err := os.UserHomeDir()
+	if err != nil {
+		return ""
+	}
+	return filepath.Join(home, "funknetz.log")
+}
+
+func present(v jsontext.Value) bool { return len(v) > 0 }
+
+func isBool(v jsontext.Value) bool {
+	return v.Kind() == jsontext.KindTrue || v.Kind() == jsontext.KindFalse
+}
+
+func missingLog(shape fileShape) bool {
+	return !present(shape.EnableLogging) || !present(shape.LogFile)
+}
+
+func operationalKindsOK(shape fileShape) bool {
+	if present(shape.Host) && shape.Host.Kind() != jsontext.KindString {
+		return false
+	}
+	if present(shape.Callsign) && shape.Callsign.Kind() != jsontext.KindString {
+		return false
+	}
+	if present(shape.AuthKey) && shape.AuthKey.Kind() != jsontext.KindString {
+		return false
+	}
+	if present(shape.Port) && shape.Port.Kind() != jsontext.KindNumber {
+		return false
+	}
+	if present(shape.TalkGroup) && shape.TalkGroup.Kind() != jsontext.KindNumber {
+		return false
+	}
+	return true
+}
+
+// blockedLog reports that a log value has the wrong JSON type, so the file
+// must not be rewritten. notice is empty when logging is not switched on.
+func blockedLog(shape fileShape) (block bool, notice string) {
+	enBad := present(shape.EnableLogging) && !isBool(shape.EnableLogging)
+	fileBad := present(shape.LogFile) && shape.LogFile.Kind() != jsontext.KindString
+	if !enBad && !fileBad {
+		return false, ""
+	}
+	if enBad {
+		return true, "enableLogging has the wrong type"
+	}
+	if shape.EnableLogging.Kind() == jsontext.KindTrue {
+		return true, "logFile has the wrong type"
+	}
+	return true, ""
+}
+
+func withLogDefaults(shape fileShape) fileShape {
+	shape.Host = rawOr(shape.Host, `""`)
+	shape.Port = rawOr(shape.Port, "0")
+	shape.Callsign = rawOr(shape.Callsign, `""`)
+	shape.AuthKey = rawOr(shape.AuthKey, `""`)
+	shape.TalkGroup = rawOr(shape.TalkGroup, "0")
+	shape.EnableLogging = rawOr(shape.EnableLogging, "false")
+	if !present(shape.LogFile) {
+		raw, err := jsonv2.Marshal(defaultLogPath())
+		if err != nil {
+			raw = []byte(`""`)
+		}
+		shape.LogFile = jsontext.Value(raw)
+	}
+	return shape
+}
+
+func rawOr(v jsontext.Value, fallback string) jsontext.Value {
+	if len(v) == 0 {
+		return jsontext.Value(fallback)
+	}
+	return v
+}
+
+func rewriteConfig(path string, shape fileShape) error {
+	info, err := os.Stat(path)
+	if err != nil {
+		return err
+	}
+	body, err := jsonv2.Marshal(shape)
+	if err != nil {
+		return err
+	}
+	body = append(body, '\n')
+	tmp, err := os.CreateTemp(filepath.Dir(path), ".funknetz-*.json")
+	if err != nil {
+		return err
+	}
+	tmpName := tmp.Name()
+	_, werr := tmp.Write(body)
+	cerr := tmp.Chmod(info.Mode().Perm())
+	clerr := tmp.Close()
+	if werr != nil || cerr != nil || clerr != nil {
+		os.Remove(tmpName)
+		if werr != nil {
+			return werr
+		}
+		if cerr != nil {
+			return cerr
+		}
+		return clerr
+	}
+	if err := os.Rename(tmpName, path); err != nil {
+		os.Remove(tmpName)
+		return err
+	}
+	return nil
+}
+
+func applyLog(cfg loaded, shape fileShape) loaded {
+	if shape.EnableLogging.Kind() != jsontext.KindTrue {
+		return cfg
+	}
+	var path string
+	if err := jsonv2.Unmarshal(shape.LogFile, &path); err != nil {
+		cfg.logNotice = "logFile has the wrong type"
+		return cfg
+	}
+	path = strings.TrimSpace(path)
+	if path == "" {
+		cfg.logNotice = "Cannot write logFile"
+		return cfg
+	}
+	if !filepath.IsAbs(path) {
+		cfg.logNotice = "Cannot write " + path
+		return cfg
+	}
+	cfg.enableLogging = true
+	cfg.logPath = path
+	return cfg
+}

station/config_test.go

@@ -44,11 +44,21 @@ func TestMissingConfigIsCreatedAndRejected(t *testing.T) {
 	if got["port"] != float64(0) || got["talkGroup"] != float64(0) {
 		t.Fatalf("numeric fields = %#v, want port and talkGroup at zero", got)
 	}
+	home, err := os.UserHomeDir()
+	if err != nil {
+		t.Fatal(err)
+	}
+	if got["enableLogging"] != false {
+		t.Fatalf("enableLogging = %#v, want false", got["enableLogging"])
+	}
+	if got["logFile"] != filepath.Join(home, "funknetz.log") {
+		t.Fatalf("logFile = %#v, want funknetz.log in the home directory", got["logFile"])
+	}
 }
 
 func TestExistingConfigIsNotRewritten(t *testing.T) {
 	path := filepath.Join(t.TempDir(), "funknetz.json")
-	original := []byte("{\"host\":\"127.0.0.1\",\"port\":5308,\"callsign\":\"DL1ABC\",\"authKey\":\"a b\",\"talkGroup\":20}\n")
+	original := []byte("{\"host\":\"127.0.0.1\",\"port\":5308,\"callsign\":\"DL1ABC\",\"authKey\":\"a b\",\"talkGroup\":20,\"enableLogging\":false,\"logFile\":\"/tmp/funknetz.log\"}\n")
 	if err := os.WriteFile(path, original, 0o640); err != nil {
 		t.Fatal(err)
 	}
@@ -117,8 +127,21 @@ func TestInvalidConfigNamesTheField(t *testing.T) {
 			if err != nil {
 				t.Fatal(err)
 			}
-			if string(after) != string(before) {
-				t.Fatalf("file = %q, want it left untouched", after)
+			if strings.Contains(tt.want, "wrong type") {
+				if string(after) != string(before) {
+					t.Fatalf("file = %q, want it left untouched", after)
+				}
+				return
+			}
+			var got map[string]any
+			if err := jsonv2.Unmarshal(after, &got); err != nil {
+				t.Fatalf("rewritten file is not JSON: %v\n%s", err, after)
+			}
+			if got["enableLogging"] != false {
+				t.Fatalf("enableLogging = %#v, want false", got["enableLogging"])
+			}
+			if _, ok := got["logFile"].(string); !ok {
+				t.Fatalf("logFile = %#v, want a string", got["logFile"])
 			}
 		})
 	}
@@ -163,6 +186,179 @@ func TestCallsignIsTrimmedAndUppercased(t *testing.T) {
 	}
 }
 
+func TestMissingLogKeysAreRewritten(t *testing.T) {
+	path := filepath.Join(t.TempDir(), "funknetz.json")
+	original := []byte("{\"note\":true,\"host\":\" 127.0.0.1 \",\"port\":5308,\"callsign\":\" dl1abc \",\"authKey\":\"a b\",\"talkGroup\":20}\n")
+	if err := os.WriteFile(path, original, 0o640); err != nil {
+		t.Fatal(err)
+	}
+	st, err := station.New(station.Options{ConfigPath: path})
+	if err != nil {
+		t.Fatal(err)
+	}
+	t.Cleanup(st.Close)
+	if st.State().Callsign != "DL1ABC" {
+		t.Fatalf("Callsign = %q", st.State().Callsign)
+	}
+	info, err := os.Stat(path)
+	if err != nil {
+		t.Fatal(err)
+	}
+	if got, want := info.Mode().Perm(), os.FileMode(0o640); got != want {
+		t.Fatalf("mode = %o, want %o", got, want)
+	}
+	body, err := os.ReadFile(path)
+	if err != nil {
+		t.Fatal(err)
+	}
+	var got map[string]any
+	if err := jsonv2.Unmarshal(body, &got); err != nil {
+		t.Fatal(err)
+	}
+	if _, ok := got["note"]; ok {
+		t.Fatalf("note = %#v, want it dropped", got["note"])
+	}
+	if got["callsign"] != " dl1abc " || got["authKey"] != "a b" || got["host"] != " 127.0.0.1 " {
+		t.Fatalf("kept fields = %#v", got)
+	}
+	if got["enableLogging"] != false {
+		t.Fatalf("enableLogging = %#v", got["enableLogging"])
+	}
+	home, err := os.UserHomeDir()
+	if err != nil {
+		t.Fatal(err)
+	}
+	if got["logFile"] != filepath.Join(home, "funknetz.log") {
+		t.Fatalf("logFile = %#v", got["logFile"])
+	}
+	if st.State().Detail != "Idle" {
+		t.Fatalf("Detail = %q, want Idle", st.State().Detail)
+	}
+}
+
+func TestLogSettingsDoNotStopTheStation(t *testing.T) {
+	home := t.TempDir()
+	t.Setenv("HOME", home)
+
+	t.Run("missing log file uses home", func(t *testing.T) {
+		path := filepath.Join(t.TempDir(), "funknetz.json")
+		body := []byte(`{"host":"127.0.0.1","port":5308,"callsign":"DL1ABC","authKey":"key","talkGroup":20,"enableLogging":true}`)
+		if err := os.WriteFile(path, body, 0o600); err != nil {
+			t.Fatal(err)
+		}
+		st, err := station.New(station.Options{ConfigPath: path})
+		if err != nil {
+			t.Fatal(err)
+		}
+		t.Cleanup(st.Close)
+		got, err := os.ReadFile(path)
+		if err != nil {
+			t.Fatal(err)
+		}
+		var fields map[string]any
+		if err := jsonv2.Unmarshal(got, &fields); err != nil {
+			t.Fatal(err)
+		}
+		wantPath := filepath.Join(home, "funknetz.log")
+		if fields["logFile"] != wantPath || fields["enableLogging"] != true {
+			t.Fatalf("fields = %#v", fields)
+		}
+		if _, err := os.Stat(wantPath); err != nil {
+			t.Fatal(err)
+		}
+	})
+
+	t.Run("logging off ignores a bad path", func(t *testing.T) {
+		path := filepath.Join(t.TempDir(), "funknetz.json")
+		logPath := filepath.Join(t.TempDir(), "funknetz.log")
+		body := []byte(`{"host":"127.0.0.1","port":5308,"callsign":"DL1ABC","authKey":"key","talkGroup":20,"enableLogging":false,"logFile":1}`)
+		if err := os.WriteFile(path, body, 0o600); err != nil {
+			t.Fatal(err)
+		}
+		before, err := os.ReadFile(path)
+		if err != nil {
+			t.Fatal(err)
+		}
+		st, err := station.New(station.Options{ConfigPath: path})
+		if err != nil {
+			t.Fatal(err)
+		}
+		t.Cleanup(st.Close)
+		if st.State().Detail != "Idle" {
+			t.Fatalf("Detail = %q, want Idle", st.State().Detail)
+		}
+		after, err := os.ReadFile(path)
+		if err != nil {
+			t.Fatal(err)
+		}
+		if string(after) != string(before) {
+			t.Fatalf("file = %s, want it left untouched", after)
+		}
+		if _, err := os.Stat(logPath); !os.IsNotExist(err) {
+			t.Fatalf("log file err = %v, want not exist", err)
+		}
+	})
+
+	cases := []struct {
+		name   string
+		body   string
+		detail string
+		same   bool
+	}{
+		{name: "relative", body: `{"host":"127.0.0.1","port":5308,"callsign":"DL1ABC","authKey":"key","talkGroup":20,"enableLogging":true,"logFile":"funknetz.log"}`, detail: "Cannot write funknetz.log", same: true},
+		{name: "empty", body: `{"host":"127.0.0.1","port":5308,"callsign":"DL1ABC","authKey":"key","talkGroup":20,"enableLogging":true,"logFile":"  "}`, detail: "Cannot write logFile", same: true},
+		{name: "tilde", body: `{"host":"127.0.0.1","port":5308,"callsign":"DL1ABC","authKey":"key","talkGroup":20,"enableLogging":true,"logFile":"~/funknetz.log"}`, detail: "Cannot write ~/funknetz.log", same: true},
+		{name: "enable type", body: `{"host":"127.0.0.1","port":5308,"callsign":"DL1ABC","authKey":"key","talkGroup":20,"enableLogging":"yes","logFile":"/tmp/funknetz.log"}`, detail: "enableLogging has the wrong type", same: true},
+		{name: "file type", body: `{"host":"127.0.0.1","port":5308,"callsign":"DL1ABC","authKey":"key","talkGroup":20,"enableLogging":true,"logFile":1}`, detail: "logFile has the wrong type", same: true},
+		{name: "both types", body: `{"host":"127.0.0.1","port":5308,"callsign":"DL1ABC","authKey":"key","talkGroup":20,"enableLogging":"yes","logFile":1}`, detail: "enableLogging has the wrong type", same: true},
+		{name: "missing enable and bad file", body: `{"host":"127.0.0.1","port":5308,"callsign":"DL1ABC","authKey":"key","talkGroup":20,"logFile":1}`, detail: "Idle", same: true},
+	}
+	for _, tt := range cases {
+		t.Run(tt.name, func(t *testing.T) {
+			path := filepath.Join(t.TempDir(), "funknetz.json")
+			if err := os.WriteFile(path, []byte(tt.body), 0o600); err != nil {
+				t.Fatal(err)
+			}
+			st, err := station.New(station.Options{ConfigPath: path})
+			if err != nil {
+				t.Fatal(err)
+			}
+			t.Cleanup(st.Close)
+			if st.State().Detail != tt.detail {
+				t.Fatalf("Detail = %q, want %q", st.State().Detail, tt.detail)
+			}
+			if tt.same {
+				after, err := os.ReadFile(path)
+				if err != nil {
+					t.Fatal(err)
+				}
+				if string(after) != tt.body {
+					t.Fatalf("file = %s, want it left untouched", after)
+				}
+			}
+		})
+	}
+
+	t.Run("bad host still quits", func(t *testing.T) {
+		path := filepath.Join(t.TempDir(), "funknetz.json")
+		body := []byte(`{"host":"","port":5308,"callsign":"DL1ABC","authKey":"key","talkGroup":20,"enableLogging":"yes"}`)
+		if err := os.WriteFile(path, body, 0o600); err != nil {
+			t.Fatal(err)
+		}
+		_, err := station.New(station.Options{ConfigPath: path})
+		if err == nil || err.Error() != "host is empty" {
+			t.Fatalf("New() error = %v, want host is empty", err)
+		}
+		after, err := os.ReadFile(path)
+		if err != nil {
+			t.Fatal(err)
+		}
+		if string(after) != string(body) {
+			t.Fatalf("file = %s, want it left untouched", after)
+		}
+	})
+}
+
 func configJSON(host string, port int, callsign, authKey string, talkGroup int) string {
 	body, err := jsonv2.Marshal(map[string]any{
 		"host":      host,
@@ -176,3 +372,19 @@ func configJSON(host string, port int, callsign, authKey string, talkGroup int)
 	}
 	return string(body)
 }
+
+func configWithLog(host string, port int, callsign, authKey string, talkGroup int, logPath string) string {
+	body, err := jsonv2.Marshal(map[string]any{
+		"host":          host,
+		"port":          port,
+		"callsign":      callsign,
+		"authKey":       authKey,
+		"talkGroup":     talkGroup,
+		"enableLogging": true,
+		"logFile":       logPath,
+	})
+	if err != nil {
+		panic(err)
+	}
+	return string(body)
+}

station/log.go

@@ -0,0 +1,125 @@
+package station
+
+import (
+	"fmt"
+	"os"
+	"strings"
+	"time"
+)
+
+// Close releases the log file. It is safe to call more than once.
+func (s *Station) Close() {
+	s.mu.Lock()
+	defer s.mu.Unlock()
+	s.closeLogLocked()
+}
+
+func (s *Station) openLog() {
+	f, err := os.OpenFile(s.logPath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0o600)
+	if err != nil {
+		s.logNotice = "Cannot write " + s.logPath
+		if s.state.Talker == "" {
+			s.state.Detail = s.logNotice
+		}
+		return
+	}
+	s.logFile = f
+}
+
+func (s *Station) closeLogLocked() {
+	if s.logFile != nil {
+		s.logFile.Close()
+		s.logFile = nil
+	}
+}
+
+func (s *Station) writeLog(ts time.Time, msg string) {
+	if s.logFile == nil {
+		return
+	}
+	line := ts.Format(time.RFC3339) + " " + msg + "\n"
+	if _, err := s.logFile.Write([]byte(line)); err != nil {
+		s.closeLogLocked()
+		if s.logNotice == "" {
+			s.logNotice = "Cannot write " + s.logPath
+		}
+	}
+}
+
+func (s *Station) noteTransmitLocked() {
+	s.noteTransmitAt(s.clock.Now())
+}
+
+func (s *Station) noteTransmitAt(now time.Time) {
+	tx := s.transmitting()
+	if tx && !s.sending {
+		s.sending = true
+		s.sendStart = now
+		return
+	}
+	if !tx && s.sending {
+		start := s.sendStart
+		s.sending = false
+		s.writeLog(start, fmt.Sprintf("sending for %d seconds.", wholeSeconds(start, now)))
+	}
+}
+
+func (s *Station) closeTalkerLocked(now time.Time) {
+	if s.talkCall == "" {
+		return
+	}
+	call := s.talkCall
+	start := s.talkStart
+	s.talkCall = ""
+	s.writeLog(start, fmt.Sprintf("%s talked for %d seconds.", call, wholeSeconds(start, now)))
+}
+
+func (s *Station) noteDownLocked(now time.Time, dial bool) {
+	s.closeTalkerLocked(now)
+	s.state.Connection = "Disconnected"
+	s.remoteTalker = ""
+	s.roomBusy = false
+	s.noteTransmitAt(now)
+	switch {
+	case s.up:
+		s.up = false
+		s.outage = true
+		s.writeLog(now, "disconnected")
+	case dial && !s.outage:
+		s.outage = true
+		s.writeLog(now, "disconnected")
+	}
+	s.publish()
+}
+
+func (s *Station) endFatal(msg string, log bool) {
+	s.mu.Lock()
+	defer s.mu.Unlock()
+	if s.fatal != "" {
+		return
+	}
+	now := s.clock.Now()
+	s.closeTalkerLocked(now)
+	s.fatal = msg
+	s.remoteTalker = ""
+	s.roomBusy = false
+	s.noteTransmitAt(now)
+	if log {
+		s.up = false
+		s.outage = true
+		s.writeLog(now, oneLine(msg))
+	}
+	s.publish()
+}
+
+func wholeSeconds(start, end time.Time) int {
+	d := end.Sub(start)
+	if d <= 0 {
+		return 0
+	}
+	return int(d / time.Second)
+}
+
+func oneLine(msg string) string {
+	return strings.NewReplacer("\r\n", " ", "\n", " ", "\r", " ").Replace(msg)
+}

station/log_test.go

@@ -0,0 +1,197 @@
+package station_test
+
+import (
+	"context"
+	"net"
+	"os"
+	"path/filepath"
+	"strings"
+	"testing"
+	"time"
+
+	"gitea.neitzel.de/konrad/funknetz/station"
+)
+
+func TestLogAppendsSessionEvents(t *testing.T) {
+	logPath := filepath.Join(t.TempDir(), "funknetz.log")
+	if err := os.WriteFile(logPath, []byte("kept\n"), 0o640); err != nil {
+		t.Fatal(err)
+	}
+	in := loginLog(t, "DL1ABC", "super-secret-key", 20, 7, []string{"OPUS"}, logPath)
+
+	in.clock.Advance(2 * time.Second)
+	in.refl.writeFrame(t, 104, appendStr(appendU32(nil, 20), "DB0XYZ"))
+	if _, err := in.st.Wait(context.Background(), func(s station.State) bool { return s.Talker == "DB0XYZ" }); err != nil {
+		t.Fatal(err)
+	}
+	in.clock.Advance(3 * time.Second)
+	in.refl.tcp.Close()
+	if _, err := in.st.Wait(context.Background(), func(s station.State) bool { return s.Connection == "Disconnected" }); err != nil {
+		t.Fatal(err)
+	}
+
+	got := readLog(t, logPath)
+	want := strings.Join([]string{
+		"kept",
+		"2026-10-03T12:00:00Z connected",
+		"2026-10-03T12:00:02Z DB0XYZ talked for 3 seconds.",
+		"2026-10-03T12:00:05Z disconnected",
+		"",
+	}, "\n")
+	if got != want {
+		t.Fatalf("log = %q, want %q", got, want)
+	}
+	if strings.Contains(got, "super-secret-key") {
+		t.Fatal("log contains the auth key")
+	}
+	info, err := os.Stat(logPath)
+	if err != nil {
+		t.Fatal(err)
+	}
+	if got, want := info.Mode().Perm(), os.FileMode(0o640); got != want {
+		t.Fatalf("mode = %o, want %o", got, want)
+	}
+}
+
+func TestLogRecordsSendingAndARemoteTalker(t *testing.T) {
+	logPath := filepath.Join(t.TempDir(), "funknetz.log")
+	in := loginLog(t, "DL1ABC", "key", 20, 7, []string{"OPUS"}, logPath)
+
+	in.st.HoldButton()
+	in.st.ReleaseButton()
+	in.clock.Advance(2 * time.Second)
+	in.st.HoldButton()
+	in.refl.writeFrame(t, 104, appendStr(appendU32(nil, 20), "DL1ABC"))
+	in.clock.Advance(2 * time.Second)
+	in.refl.writeFrame(t, 104, appendStr(appendU32(nil, 20), "DB0XYZ"))
+	if _, err := in.st.Wait(context.Background(), func(s station.State) bool { return s.Talker == "DB0XYZ" }); err != nil {
+		t.Fatal(err)
+	}
+	in.st.HoldButton()
+	in.st.ReleaseButton()
+	in.clock.Advance(4 * time.Second)
+	in.refl.writeFrame(t, 105, appendStr(appendU32(nil, 20), "DB0XYZ"))
+	if _, err := in.st.Wait(context.Background(), func(s station.State) bool { return s.Talker == "" && !s.Transmitting }); err != nil {
+		t.Fatal(err)
+	}
+
+	got := readLog(t, logPath)
+	want := strings.Join([]string{
+		"2026-10-03T12:00:00Z connected",
+		"2026-10-03T12:00:00Z sending for 0 seconds.",
+		"2026-10-03T12:00:02Z sending for 2 seconds.",
+		"2026-10-03T12:00:04Z DB0XYZ talked for 4 seconds.",
+		"",
+	}, "\n")
+	if got != want {
+		t.Fatalf("log = %q, want %q", got, want)
+	}
+	info, err := os.Stat(logPath)
+	if err != nil {
+		t.Fatal(err)
+	}
+	if got, want := info.Mode().Perm(), os.FileMode(0o600); got != want {
+		t.Fatalf("mode = %o, want %o", got, want)
+	}
+}
+
+func TestLogFailureStaysInTheIdleSlot(t *testing.T) {
+	logPath := filepath.Join(t.TempDir(), "missing", "funknetz.log")
+	in := loginLog(t, "DL1ABC", "key", 20, 7, []string{"OPUS"}, logPath)
+	notice := "Cannot write " + logPath
+	if got := in.st.State(); got.Connection != "Connected" || got.Detail != notice {
+		t.Fatalf("State = %+v, want Connected and the log failure", got)
+	}
+	in.refl.writeFrame(t, 104, appendStr(appendU32(nil, 20), "DB0XYZ"))
+	got, err := in.st.Wait(context.Background(), func(s station.State) bool { return s.Talker == "DB0XYZ" })
+	if err != nil {
+		t.Fatal(err)
+	}
+	if got.Detail != "Idle" {
+		t.Fatalf("Detail = %q, want the talker to take the line", got.Detail)
+	}
+	in.refl.writeFrame(t, 105, appendStr(appendU32(nil, 20), "DB0XYZ"))
+	got, err = in.st.Wait(context.Background(), func(s station.State) bool { return s.Talker == "" })
+	if err != nil {
+		t.Fatal(err)
+	}
+	if got.Detail != notice {
+		t.Fatalf("Detail = %q, want the log failure back", got.Detail)
+	}
+}
+
+func TestFirstDialFailureIsLoggedOnce(t *testing.T) {
+	logPath := filepath.Join(t.TempDir(), "funknetz.log")
+	ln := listenClosed(t)
+	path := writeConfigFile(t, configWithLog("127.0.0.1", ln, "DL1ABC", "key", 4, logPath))
+	clock := newFakeClock()
+	st, err := station.New(station.Options{ConfigPath: path, Clock: clock})
+	if err != nil {
+		t.Fatal(err)
+	}
+	ctx, cancel := context.WithCancel(t.Context())
+	defer cancel()
+	go func() { _ = st.Run(ctx) }()
+
+	want := "2026-10-03T12:00:00Z disconnected\n"
+	deadline := time.Now().Add(2 * time.Second)
+	for readLog(t, logPath) != want {
+		if time.Now().After(deadline) {
+			t.Fatalf("log = %q, want %q", readLog(t, logPath), want)
+		}
+		time.Sleep(time.Millisecond)
+	}
+	clock.BlockUntilWaiting(t)
+	clock.Advance(2 * time.Second)
+	clock.BlockUntilWaiting(t)
+	if got := readLog(t, logPath); got != want {
+		t.Fatalf("log = %q, want the dial failure logged once", got)
+	}
+}
+
+func TestReflectorErrorsAreOneLogLine(t *testing.T) {
+	logPath := filepath.Join(t.TempDir(), "funknetz.log")
+	refl := newReflector(t)
+	path := writeConfigFile(t, configWithLog("127.0.0.1", refl.port, "DL1ABC", "key", 20, logPath))
+	clock := newFakeClock()
+	st, err := station.New(station.Options{ConfigPath: path, Clock: clock})
+	if err != nil {
+		t.Fatal(err)
+	}
+	ctx, cancel := context.WithCancel(t.Context())
+	defer cancel()
+	go func() { _ = st.Run(ctx) }()
+	refl.accept(t)
+	refl.readFrame(t)
+	refl.writeFrame(t, 13, appendStr(nil, "bad\nline"))
+	if _, err := st.Wait(ctx, func(s station.State) bool { return s.Detail == "bad\nline" }); err != nil {
+		t.Fatal(err)
+	}
+	got := readLog(t, logPath)
+	if got != "2026-10-03T12:00:00Z bad line\n" {
+		t.Fatalf("log = %q", got)
+	}
+	if strings.Contains(got, "disconnected") {
+		t.Fatalf("log = %q, want no disconnected line", got)
+	}
+}
+
+func listenClosed(t *testing.T) int {
+	t.Helper()
+	ln, err := net.Listen("tcp", "127.0.0.1:0")
+	if err != nil {
+		t.Fatal(err)
+	}
+	port := ln.Addr().(*net.TCPAddr).Port
+	ln.Close()
+	return port
+}
+
+func readLog(t *testing.T, path string) string {
+	t.Helper()
+	b, err := os.ReadFile(path)
+	if err != nil {
+		t.Fatal(err)
+	}
+	return string(b)
+}

station/protocol.go

@@ -17,6 +17,7 @@ const (
 	tcpTalkerStart   = 104
 	tcpTalkerStop    = 105
 	tcpSelectTG      = 106
+	tcpNodeInfo      = 111
 
 	udpHeartbeat = 1
 	udpAudio     = 101

station/reflector_test.go

@@ -2,6 +2,7 @@ package station_test
 
 import (
 	"encoding/binary"
+	"encoding/json"
 	"io"
 	"net"
 	"os"
@@ -283,6 +284,21 @@ func takeU32(t *testing.T, b []byte) (uint32, []byte) {
 	return binary.BigEndian.Uint32(b[:4]), b[4:]
 }
 
+func requireSoftwareIdentity(t *testing.T, body []byte) {
+	t.Helper()
+	raw, rest := takeStr(t, body)
+	if len(rest) != 0 {
+		t.Fatalf("software identity has %d trailing bytes", len(rest))
+	}
+	var got map[string]string
+	if err := json.Unmarshal([]byte(raw), &got); err != nil {
+		t.Fatalf("software identity %q: %v", raw, err)
+	}
+	if len(got) != 2 || got["sw"] != station.SoftwareName || got["swVer"] != station.SoftwareVersion {
+		t.Fatalf("software identity = %#v, want sw %q and swVer %q only", got, station.SoftwareName, station.SoftwareVersion)
+	}
+}
+
 func takeStr(t *testing.T, b []byte) (string, []byte) {
 	t.Helper()
 	n, rest := takeU16(t, b)

station/session.go

@@ -20,6 +20,7 @@ var errStopped = errors.New("session stopped")
 
 // Run keeps the reflector session until ctx is canceled.
 func (s *Station) Run(ctx context.Context) error {
+	defer s.Close()
 	for {
 		if ctx.Err() != nil {
 			return nil
@@ -41,8 +42,7 @@ func (s *Station) Run(ctx context.Context) error {
 				return nil
 			}
 			s.mu.Lock()
-			s.state.Connection = "Disconnected"
-			s.publish()
+			s.noteDownLocked(s.clock.Now(), true)
 			s.mu.Unlock()
 			if !s.wait(ctx, 2*time.Second) {
 				return nil
@@ -54,14 +54,13 @@ func (s *Station) Run(ctx context.Context) error {
 		conn.Close()
 		s.mu.Lock()
 		s.closeUDP()
-		if s.fatal == "" {
-			s.state.Connection = "Disconnected"
-			s.remoteTalker = ""
-			s.roomBusy = false
-		}
 		s.mic = nil
 		s.play = nil
-		s.publish()
+		if s.fatal == "" {
+			s.noteDownLocked(s.clock.Now(), false)
+		} else {
+			s.publish()
+		}
 		fatal := s.fatal != ""
 		s.mu.Unlock()
 		if ctx.Err() != nil {
@@ -289,7 +288,7 @@ func (s *Station) onTCP(conn net.Conn, f frame, done <-chan struct{}, udpCh *cha
 		if err != nil {
 			msg = "could not be read"
 		}
-		s.stop(msg)
+		s.endFatal(msg, true)
 		return errStopped
 	case tcpServerInfo:
 		return s.onServerInfo(conn, f.body, done, udpCh, udpErr, udpReady, udpRx, lastTCP)
@@ -310,7 +309,7 @@ func (s *Station) onServerInfo(conn net.Conn, body []byte, done <-chan struct{},
 		return err
 	}
 	if !hasOPUS(codecs) {
-		s.stop(noOpus)
+		s.endFatal(noOpus, true)
 		return errStopped
 	}
 	enc, err := opus.NewEncoder()
@@ -322,6 +321,17 @@ func (s *Station) onServerInfo(conn net.Conn, body []byte, done <-chan struct{},
 		enc.Close()
 		return err
 	}
+	info, err := softwareIdentityBody()
+	if err != nil {
+		enc.Close()
+		dec.Close()
+		return err
+	}
+	if err := writeFrame(conn, tcpNodeInfo, info); err != nil {
+		enc.Close()
+		dec.Close()
+		return err
+	}
 	var tg [4]byte
 	binary.BigEndian.PutUint32(tg[:], uint32(s.cfg.talkGroup))
 	if err := writeFrame(conn, tcpSelectTG, tg[:]); err != nil {
@@ -362,6 +372,10 @@ func (s *Station) onServerInfo(conn net.Conn, body []byte, done <-chan struct{},
 		return err
 	}
 	s.state.Connection = "Connected"
+	s.up = true
+	s.outage = false
+	s.noteTransmitLocked()
+	s.writeLog(s.clock.Now(), "connected")
 	s.publish()
 	s.mu.Unlock()
 
@@ -372,12 +386,7 @@ func (s *Station) onServerInfo(conn net.Conn, body []byte, done <-chan struct{},
 	return nil
 }
 
-func (s *Station) stop(msg string) {
-	s.mu.Lock()
-	defer s.mu.Unlock()
-	s.fatal = msg
-	s.publish()
-}
+func (s *Station) stop(msg string) { s.endFatal(msg, false) }
 
 // Fail stops retries and shows message until the operator quits.
 func (s *Station) Fail(message string) { s.stop(message) }
@@ -393,19 +402,24 @@ func (s *Station) onTalker(body []byte, start bool) {
 	}
 	s.mu.Lock()
 	defer s.mu.Unlock()
+	now := s.clock.Now()
 	if start {
 		if call == s.cfg.callsign {
 			return
 		}
+		s.closeTalkerLocked(now)
 		was := s.transmitting()
 		s.remoteTalker = call
 		s.roomBusy = true
+		s.talkCall = call
+		s.talkStart = now
 		if was && !s.transmitting() {
 			s.endTransmit()
 		}
 		s.publish()
 		return
 	}
+	s.closeTalkerLocked(now)
 	s.remoteTalker = ""
 	s.roomBusy = false
 	s.publish()
@@ -500,6 +514,7 @@ func (s *Station) transmitting() bool {
 }
 
 func (s *Station) publish() {
+	s.noteTransmitLocked()
 	s.state.Callsign = s.cfg.callsign
 	s.state.TalkGroup = s.cfg.talkGroup
 	if s.fatal != "" {
@@ -517,6 +532,9 @@ func (s *Station) publish() {
 		} else {
 			s.state.Talker = s.remoteTalker
 		}
+		if s.state.Talker == "" && s.logNotice != "" {
+			s.state.Detail = s.logNotice
+		}
 	}
 	select {
 	case s.wake <- struct{}{}:

station/session_test.go

@@ -67,6 +67,12 @@ func TestLoginAnnouncesProtocolAndJoinsTheTalkGroup(t *testing.T) {
 	refl.writeFrame(t, 12, nil)
 	refl.writeFrame(t, 100, serverInfo(0x1234, []string{"db0abc"}, []string{"GSM", "OPUS"}))
 
+	typ, body = refl.readFrame(t)
+	if typ != 111 {
+		t.Fatalf("frame type %d, want software identity", typ)
+	}
+	requireSoftwareIdentity(t, body)
+
 	typ, body = refl.readFrame(t)
 	if typ != 106 {
 		t.Fatalf("frame type %d, want select talk group", typ)
@@ -89,7 +95,7 @@ func TestLoginAnnouncesProtocolAndJoinsTheTalkGroup(t *testing.T) {
 		t.Fatalf("State = %+v, want Connected Idle", got)
 	}
 
-	// No other talk group and no station profile: the next TCP message is a heartbeat, not type 107 or 111.
+	// No other talk group: the next TCP message is a heartbeat, not a monitor set.
 	clock.BlockUntilWaiting(t)
 	clock.Advance(10 * time.Second)
 	typ, _ = refl.readFrame(t)

station/software.go

@@ -0,0 +1,24 @@
+package station
+
+import "encoding/json"
+
+// SoftwareName and SoftwareVersion are the identity sent to the reflector
+// after login. Edit them here.
+const (
+	SoftwareName    = "funknetz"
+	SoftwareVersion = "1.0.0"
+)
+
+func softwareIdentityBody() ([]byte, error) {
+	raw, err := json.Marshal(struct {
+		SW    string `json:"sw"`
+		SWVer string `json:"swVer"`
+	}{
+		SW:    SoftwareName,
+		SWVer: SoftwareVersion,
+	})
+	if err != nil {
+		return nil, err
+	}
+	return appendString(nil, string(raw)), nil
+}

station/station.go

@@ -5,6 +5,7 @@ package station
 import (
 	"context"
 	"net"
+	"os"
 	"sync"
 	"time"
 
@@ -48,6 +49,16 @@ type Station struct {
 	lastUDPSend  time.Time
 	enc          *opus.Encoder
 	dec          *opus.Decoder
+
+	logFile   *os.File
+	logPath   string
+	logNotice string
+	up        bool
+	outage    bool
+	sending   bool
+	sendStart time.Time
+	talkCall  string
+	talkStart time.Time
 }
 
 // New loads the config at opt.ConfigPath. A missing file is created mode 0600
@@ -61,17 +72,26 @@ func New(opt Options) (*Station, error) {
 	if clock == nil {
 		clock = wallClock{}
 	}
+	detail := "Idle"
+	if cfg.logNotice != "" {
+		detail = cfg.logNotice
+	}
 	s := &Station{
-		cfg:   cfg,
-		clock: clock,
-		wake:  make(chan struct{}, 1),
+		cfg:       cfg,
+		clock:     clock,
+		wake:      make(chan struct{}, 1),
+		logPath:   cfg.logPath,
+		logNotice: cfg.logNotice,
 		state: State{
 			Connection: "Disconnected",
-			Detail:     "Idle",
+			Detail:     detail,
 			Callsign:   cfg.callsign,
 			TalkGroup:  cfg.talkGroup,
 		},
 	}
+	if cfg.enableLogging {
+		s.openLog()
+	}
 	return s, nil
 }