diff --git a/cmd/m17-bridge/bridge.go b/cmd/m17-bridge/bridge.go index 5d1ce10..179908e 100644 --- a/cmd/m17-bridge/bridge.go +++ b/cmd/m17-bridge/bridge.go @@ -105,7 +105,7 @@ func setupLogging(c *config) { logWriter := os.Stderr if c.logRoot != "" { - logWriter, err = os.OpenFile(c.logPath+"/"+c.logRoot+".log", os.O_WRONLY|os.O_CREATE|os.O_SYNC, 0644) + logWriter, err = os.OpenFile(c.logPath+"/"+c.logRoot+".log", os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0644) if err != nil { log.Fatalf("Error opening server output, exiting: %v", err) } diff --git a/cmd/m17-gateway/gateway.go b/cmd/m17-gateway/gateway.go index 1b68538..b8889c3 100644 --- a/cmd/m17-gateway/gateway.go +++ b/cmd/m17-gateway/gateway.go @@ -300,7 +300,7 @@ func setupLogging(c config) { logWriter := os.Stderr if c.logRoot != "" { - logWriter, err = os.OpenFile(c.logPath+"/"+c.logRoot+".log", os.O_WRONLY|os.O_CREATE|os.O_SYNC, 0644) + logWriter, err = os.OpenFile(c.logPath+"/"+c.logRoot+".log", os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0644) if err != nil { log.Fatalf("Error opening server output, exiting: %v", err) } @@ -444,7 +444,7 @@ func (g *Gateway) transmitNetPacket(p m17.Packet) error { } // log.Printf("[DEBUG] received packet from server: %#v", p) if p.Type == m17.PacketTypeSMS && len(p.Payload) > 0 { - msg := string(p.Payload[0 : len(p.Payload)-1]) + msg := p.SMSText() g.dashLog.LogFrame(&lsf, "Internet", "Packet", "packetType", p.Type, "smsMessage", msg) } else { g.dashLog.LogFrame(&lsf, "Internet", "Packet", "packetType", p.Type) @@ -639,10 +639,14 @@ func (g *Gateway) receivedRFStreamEOT(lsf m17.LSF, sid, fn uint16, ber float64) func (g *Gateway) receivedRFPacket(lsf m17.LSF, payload []byte, ber float64) error { g.rxHeard() var err error - p := m17.NewPacketFromBytes(append(lsf.ToBytes(), payload...)) + p, err := m17.NewPacketFromBytes(append(lsf.ToBytes(), payload...)) + if err != nil { + log.Printf("[INFO] Dropping bad RF packet: %v", err) + return nil + } g.dashLog.LogGNSS(&lsf, "RF") if p.Type == m17.PacketTypeSMS && len(p.Payload) > 0 { - msg := string(p.Payload[0 : len(p.Payload)-1]) + msg := p.SMSText() g.dashLog.LogFrame(&lsf, "RF", "Packet", "mer", json.Number(fmt.Sprintf("%f", ber)), "packetType", p.Type, "smsMessage", msg) } else { g.dashLog.LogFrame(&lsf, "RF", "Packet", "mer", json.Number(fmt.Sprintf("%f", ber)), "packetType", p.Type) diff --git a/dashboard/logger.go b/dashboard/logger.go index 564f47e..f245a1e 100644 --- a/dashboard/logger.go +++ b/dashboard/logger.go @@ -18,8 +18,11 @@ type Logger struct { func New(l *slog.Logger) *Logger { return &Logger{l, time.Now()} } + +// Log writes one dashboard event. The Logger may wrap a nil *slog.Logger +// when no DashboardLog is configured; then nothing is written. func (l *Logger) Log(logType string, logSubtype string, addlArgs ...any) { - if l == nil { + if l == nil || l.Logger == nil { return } args := []any{"type", logType, "subtype", logSubtype} @@ -27,11 +30,17 @@ func (l *Logger) Log(logType string, logSubtype string, addlArgs ...any) { l.Info("", args...) } func (l *Logger) LogFrame(lsf *m17.LSF, logType string, logSubtype string, addlArgs ...any) { + if l == nil || l.Logger == nil { + return + } args := []any{"src", lsf.Src.Callsign(), "dst", lsf.Dst.Callsign(), "can", lsf.CAN()} args = append(args, addlArgs...) l.Log(logType, logSubtype, args...) } func (l *Logger) LogGNSS(lsf *m17.LSF, logType string) { + if l == nil || l.Logger == nil { + return + } if lsf.GNSS() != nil && lsf.GNSS().ValidLatLon && time.Since(l.lastLogTime) > 15*time.Second { log.Printf("[DEBUG] Writing GNSS data to dashboard.log: %s", lsf.GNSS().String()) l.lastLogTime = time.Now() diff --git a/dashboard/logger_test.go b/dashboard/logger_test.go new file mode 100644 index 0000000..acbcf77 --- /dev/null +++ b/dashboard/logger_test.go @@ -0,0 +1,21 @@ +package dashboard + +import ( + "testing" + + "github.com/jancona/m17" +) + +// With no DashboardLog configured the gateway passes a nil *slog.Logger; +// logging must then do nothing rather than panic. +func TestNilLoggerIsNoop(t *testing.T) { + lsf, err := m17.NewLSF("@ALL", "N0CALL", m17.LSFTypePacket, m17.LSFDataTypeData, 0) + if err != nil { + t.Fatal(err) + } + for _, l := range []*Logger{New(nil), nil} { + l.Log("Reflector", "Connect", "name", "M17-M17") + l.LogFrame(&lsf, "RF", "Packet") + l.LogGNSS(&lsf, "RF") + } +} diff --git a/inet/client.go b/inet/client.go index 6971616..8c63515 100644 --- a/inet/client.go +++ b/inet/client.go @@ -243,7 +243,11 @@ func (r *Client) handle() { } case m17.MagicM17Packet: // M17 packet if r.packetHandler != nil { - p := m17.NewPacketFromBytes(buffer[4:]) + p, err := m17.NewPacketFromBytes(buffer[4:]) + if err != nil { + log.Printf("[INFO] Dropping bad packet from reflector: %v", err) + continue + } // log.Printf("[DEBUG] Received packet from reflector. buffer: % 02x, buffer len: %d, p: %v", buffer[4:], len(buffer[4:]), p) r.packetHandler(p) } diff --git a/inet/server.go b/inet/server.go index 105c568..851312e 100644 --- a/inet/server.go +++ b/inet/server.go @@ -137,7 +137,11 @@ func (s *Server) handle() { } } case m17.MagicM17Packet: - p := m17.NewPacketFromBytes(buf[4:]) + p, err := m17.NewPacketFromBytes(buf[4:]) + if err != nil { + log.Printf("[INFO] Dropping bad packet from %s: %v", addr, err) + continue + } log.Printf("[DEBUG] Server received packet: %s", p.String()) c := s.lookupClient(addr) if c != nil { diff --git a/inet/server_test.go b/inet/server_test.go new file mode 100644 index 0000000..337e75b --- /dev/null +++ b/inet/server_test.go @@ -0,0 +1,49 @@ +package inet + +import ( + "net" + "testing" + "time" + + "github.com/jancona/m17" +) + +// A short M17P datagram from anyone on the internet must be dropped, not +// panic the server. +func TestServerSurvivesShortPacket(t *testing.T) { + // Find a free port + l, err := net.ListenPacket("udp", "127.0.0.1:0") + if err != nil { + t.Fatal(err) + } + addr := l.LocalAddr().String() + l.Close() + + s := NewServer("TEST", addr, nil) + done := make(chan struct{}) + go func() { + s.Start() + close(done) + }() + time.Sleep(100 * time.Millisecond) + + conn, err := net.Dial("udp", addr) + if err != nil { + t.Fatal(err) + } + defer conn.Close() + for _, n := range []int{0, 1, 10, m17.LSFLen, m17.LSFLen + 2} { + if _, err := conn.Write(append([]byte(m17.MagicM17Packet), make([]byte, n)...)); err != nil { + t.Fatal(err) + } + } + // A panic in the server goroutine would have ended the test binary by now + time.Sleep(200 * time.Millisecond) + + s.Close() + select { + case <-done: + case <-time.After(3 * time.Second): + t.Fatal("server did not stop") + } +} diff --git a/lsf_test.go b/lsf_test.go index c78fe34..e3e7fea 100644 --- a/lsf_test.go +++ b/lsf_test.go @@ -253,9 +253,45 @@ func TestNewPacketFromBytes(t *testing.T) { } for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { - if got := NewPacketFromBytes(tt.args.buf); !reflect.DeepEqual(got, tt.want) { + got, err := NewPacketFromBytes(tt.args.buf) + if err != nil { + t.Fatalf("NewPacketFromBytes() error = %v", err) + } + if !reflect.DeepEqual(got, tt.want) { t.Errorf("NewPacketFromBytes() = %v, want %v", got, tt.want) } }) } } + +func TestNewPacketFromBytesShort(t *testing.T) { + // Anything shorter than LSF + type + CRC must be rejected, not panic + for n := 0; n < LSFLen+1+CRCLen; n++ { + if _, err := NewPacketFromBytes(make([]byte, n)); err == nil { + t.Errorf("NewPacketFromBytes(%d bytes) returned no error", n) + } + } + // A two-byte UTF-8 packet type needs one more byte + buf := make([]byte, LSFLen+3) + copy(buf[LSFLen:], []byte{0xc2, 0x80, 0}) + if _, err := NewPacketFromBytes(buf); err == nil { + t.Errorf("NewPacketFromBytes() accepted a packet with a truncated CRC") + } +} + +func TestSMSText(t *testing.T) { + tests := []struct { + payload []byte + want string + }{ + {[]byte("Hello\x00"), "Hello"}, + {[]byte("Hello"), "Hello"}, + {[]byte("\x00"), ""}, + {[]byte{}, ""}, + } + for _, tt := range tests { + if got := (Packet{Payload: tt.payload}).SMSText(); got != tt.want { + t.Errorf("SMSText(%q) = %q, want %q", tt.payload, got, tt.want) + } + } +} diff --git a/packet.go b/packet.go index 8077c6f..52d9e79 100644 --- a/packet.go +++ b/packet.go @@ -4,6 +4,7 @@ import ( "encoding/binary" "fmt" "log" + "strings" "unicode/utf8" ) @@ -27,18 +28,32 @@ type Packet struct { CRC uint16 } -func NewPacketFromBytes(buf []byte) Packet { +// NewPacketFromBytes parses an LSF followed by a packet type, payload and CRC. +// The input comes from RF or the network, so its length is checked before +// slicing: a short buffer would otherwise panic and take the process down. +func NewPacketFromBytes(buf []byte) (Packet, error) { var p Packet - p.LSF = NewLSFFromBytes(buf[:LSFLen]) + if len(buf) < LSFLen+1+CRCLen { + return p, fmt.Errorf("packet too short: %d bytes", len(buf)) + } t, size := utf8.DecodeRune(buf[LSFLen:]) + if len(buf) < LSFLen+size+CRCLen { + return p, fmt.Errorf("packet too short for its %d byte type: %d bytes", size, len(buf)) + } + p.LSF = NewLSFFromBytes(buf[:LSFLen]) p.Type = PacketType(t) - p.Payload = buf[LSFLen+size : len(buf)-2] + p.Payload = buf[LSFLen+size : len(buf)-CRCLen] _, err := binary.Decode(buf[len(buf)-2:], binary.BigEndian, &p.CRC) if err != nil { // should never happen log.Printf("[ERROR] Error decoding CRC: %v", err) } - return p + return p, nil +} + +// SMSText returns the text of an SMS packet without its NUL terminator. +func (p Packet) SMSText() string { + return strings.TrimRight(string(p.Payload), "\x00") } func NewPacket(dst, src string, t PacketType, data []byte) (*Packet, error) {