diff --git a/app/handle-websocket.go b/app/handle-websocket.go index 9c7e299..b86cd0c 100644 --- a/app/handle-websocket.go +++ b/app/handle-websocket.go @@ -65,18 +65,17 @@ whitelist: conn.SetReadLimit(DefaultMaxMessageSize) defer conn.CloseNow() listener := &Listener{ - ctx: ctx, - Server: s, - conn: conn, - remote: remote, - req: r, + ctx: ctx, + Server: s, + conn: conn, + remote: remote, + req: r, + startTime: time.Now(), } chal := make([]byte, 32) rand.Read(chal) listener.challenge.Store([]byte(hex.Enc(chal))) - // If admins are configured, immediately prompt client to AUTH (NIP-42) - if len(s.Config.Admins) > 0 { - // log.D.F("sending initial AUTH challenge to %s", remote) + if s.Config.ACLMode != "none" { log.D.F("sending AUTH challenge to %s", remote) if err = authenvelope.NewChallengeWith(listener.challenge.Load()). Write(listener); chk.E(err) { @@ -89,20 +88,23 @@ whitelist: go s.Pinger(ctx, conn, ticker, cancel) defer func() { log.D.F("closing websocket connection from %s", remote) - + // Cancel context and stop pinger cancel() ticker.Stop() - + // Cancel all subscriptions for this connection log.D.F("cancelling subscriptions for %s", remote) listener.publishers.Receive(&W{Cancel: true}) - + // Log detailed connection statistics - log.D.F("ws connection closed %s: msgs=%d, REQs=%d, EVENTs=%d, duration=%v", - remote, listener.msgCount, listener.reqCount, listener.eventCount, - time.Since(time.Now())) // Note: This will be near-zero, would need start time tracked - + dur := time.Since(listener.startTime) + log.D.F( + "ws connection closed %s: msgs=%d, REQs=%d, EVENTs=%d, duration=%v", + remote, listener.msgCount, listener.reqCount, listener.eventCount, + dur, + ) + // Log any remaining connection state if listener.authedPubkey.Load() != nil { log.D.F("ws connection %s was authenticated", remote) @@ -118,7 +120,7 @@ whitelist: } var typ websocket.MessageType var msg []byte - // log.T.F("waiting for message from %s", remote) + log.T.F("waiting for message from %s", remote) // Block waiting for message; rely on pings and context cancellation to detect dead peers typ, msg, err = conn.Read(ctx) @@ -160,9 +162,15 @@ whitelist: pongStart := time.Now() if err = conn.Write(writeCtx, PongMessage, msg); chk.E(err) { pongDuration := time.Since(pongStart) - log.E.F("failed to send PONG to %s after %v: %v", remote, pongDuration, err) + log.E.F( + "failed to send PONG to %s after %v: %v", remote, + pongDuration, err, + ) if writeCtx.Err() != nil { - log.E.F("PONG write timeout to %s after %v (limit=%v)", remote, pongDuration, DefaultWriteTimeout) + log.E.F( + "PONG write timeout to %s after %v (limit=%v)", remote, + pongDuration, DefaultWriteTimeout, + ) } writeCancel() return @@ -196,31 +204,37 @@ func (s *Server) Pinger( case <-ticker.C: pingCount++ log.D.F("sending PING #%d", pingCount) - + // Create a write context with timeout for ping operation pingCtx, pingCancel := context.WithTimeout(ctx, DefaultWriteTimeout) pingStart := time.Now() - + if err = conn.Ping(pingCtx); err != nil { pingDuration := time.Since(pingStart) - log.E.F("PING #%d FAILED after %v: %v", pingCount, pingDuration, err) - + log.E.F( + "PING #%d FAILED after %v: %v", pingCount, pingDuration, + err, + ) + if pingCtx.Err() != nil { - log.E.F("PING #%d timeout after %v (limit=%v)", pingCount, pingDuration, DefaultWriteTimeout) + log.E.F( + "PING #%d timeout after %v (limit=%v)", pingCount, + pingDuration, DefaultWriteTimeout, + ) } - + chk.E(err) pingCancel() return } - + pingDuration := time.Since(pingStart) log.D.F("PING #%d sent successfully in %v", pingCount, pingDuration) - + if pingDuration > time.Millisecond*100 { log.D.F("SLOW PING #%d: %v (>100ms)", pingCount, pingDuration) } - + pingCancel() case <-ctx.Done(): log.D.F("pinger context cancelled after %d pings", pingCount) diff --git a/app/listener.go b/app/listener.go index de0cdd8..08283ab 100644 --- a/app/listener.go +++ b/app/listener.go @@ -19,6 +19,7 @@ type Listener struct { req *http.Request challenge atomic.Bytes authedPubkey atomic.Bytes + startTime time.Time // Diagnostics: per-connection counters msgCount int reqCount int diff --git a/pkg/encoders/tag/tags.go b/pkg/encoders/tag/tags.go index b5d7457..fae20fc 100644 --- a/pkg/encoders/tag/tags.go +++ b/pkg/encoders/tag/tags.go @@ -4,6 +4,7 @@ import ( "bytes" "lol.mleku.dev/chk" + "lol.mleku.dev/log" "next.orly.dev/pkg/utils" ) @@ -83,6 +84,10 @@ func (s *S) MarshalJSON() (b []byte, err error) { } func (s *S) Marshal(dst []byte) (b []byte) { + if s == nil { + log.I.F("tags cannot be used without initialization") + return + } b = dst b = append(b, '[') for i, ss := range *s { diff --git a/pkg/version/version b/pkg/version/version index a13c8b3..d278187 100644 --- a/pkg/version/version +++ b/pkg/version/version @@ -1 +1 @@ -v0.8.6 \ No newline at end of file +v0.8.7 \ No newline at end of file