A line per frame, for the frames nobody has named

ANKER_MQTT_FRAME_LOG logs every inbound cloud frame with its bytes,
decoded or not — the ones this package drops are exactly the ones worth
naming, so they are logged before the drop.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
This commit is contained in:
tajniak81
2026-09-03 12:08:53 +02:00
co-authored by Claude Opus 5
parent 245870a96a
commit a7719fca6a
6 changed files with 102 additions and 0 deletions
@@ -44,11 +44,14 @@ import (
"crypto/x509"
"encoding/base64"
"encoding/binary"
"encoding/hex"
"encoding/json"
"errors"
"fmt"
"log"
"math/big"
"net"
"os"
"strings"
"sync"
"time"
@@ -469,15 +472,46 @@ func (c *mqttConn) idleLoop() {
}
}
// mqttFrameLog writes a line for every inbound frame — the ones this package can
// read and, the whole point, the ones it cannot. Off unless ANKER_MQTT_FRAME_LOG
// is set on the server: it exists to put a name to a frame nobody has named yet
// (a card held against the reader, say, or one of the two types the map lists as
// unnamed), not to write a line per telemetry message on a running server.
var mqttFrameLog = os.Getenv("ANKER_MQTT_FRAME_LOG") != ""
// frameLogLine is that line. The bytes are the part that matters — a frame this
// package drops is unreadable here but perfectly readable afterwards — so they
// are always in it, capped so one long frame cannot fill a log.
func frameLogLine(sn, topic string, data []byte, msgType string, values map[string]any, err error) string {
hexed := hex.EncodeToString(data)
if len(hexed) > 1024 {
hexed = hexed[:1024] + "..."
}
if err != nil {
return fmt.Sprintf("ANKER-MQTT FRAME sn=%s topic=%s len=%d unreadable=%q hex=%s",
sn, topic, len(data), err.Error(), hexed)
}
return fmt.Sprintf("ANKER-MQTT FRAME sn=%s topic=%s len=%d type=%s fields=%d hex=%s values=%v",
sn, topic, len(data), msgType, len(values), hexed, values)
}
// ingest decodes one inbound message and folds it into the sending charger's
// state. Anything it cannot read is dropped: these frames come from a cloud
// connection, and a malformed one must not be recorded as a reading.
func (c *mqttConn) ingest(msg mqtt.Message) {
sn, data, ok := parseEnvelope(msg)
if !ok {
if mqttFrameLog {
log.Printf("ANKER-MQTT ENVELOPE topic=%s unreadable payload=%s", msg.Topic, msg.Payload)
}
return
}
msgType, values, err := decodeFrame(data)
// Logged before the drop below, because the frames worth naming are exactly
// the ones this package throws away.
if mqttFrameLog {
log.Print(frameLogLine(sn, msg.Topic, data, msgType, values, err))
}
if err != nil || len(values) == 0 {
return
}
@@ -0,0 +1,36 @@
package ankersolix
import (
"errors"
"strings"
"testing"
)
// The frame nobody can read is the one worth logging, so its bytes have to be in
// the line — that is the whole of what a capture is.
func TestFrameLogLineCarriesTheBytes(t *testing.T) {
data := []byte{0xff, 0x09, 0x01, 0x02}
line := frameLogLine("EVSN1", "dt/app/A5191/EVSN1/x", data, "", nil, errors.New("bad marker"))
if !strings.Contains(line, "hex=ff090102") {
t.Errorf("unreadable frame: %q, want the bytes in it", line)
}
if !strings.Contains(line, "unreadable=") || !strings.Contains(line, "EVSN1") {
t.Errorf("unreadable frame: %q, want the reason and the serial", line)
}
line = frameLogLine("EVSN1", "t", data, "0857", map[string]any{"a": 1}, nil)
if !strings.Contains(line, "type=0857") || !strings.Contains(line, "fields=1") {
t.Errorf("readable frame: %q, want its type and field count", line)
}
}
// One long frame must not fill a log file.
func TestFrameLogLineCapsTheHex(t *testing.T) {
line := frameLogLine("EVSN1", "t", make([]byte, 4096), "0410", nil, nil)
if len(line) > 1400 {
t.Errorf("line is %d chars, want it capped", len(line))
}
if !strings.Contains(line, "...") {
t.Error("a truncated frame should say so")
}
}