From 63b8e5b50ae82c9c5440fb23bf1579987b102013 Mon Sep 17 00:00:00 2001 From: lucarin91 Date: Thu, 20 Nov 2025 10:41:30 +0100 Subject: [PATCH 1/9] wip: debug the update flow --- internal/api/handlers/update.go | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) diff --git a/internal/api/handlers/update.go b/internal/api/handlers/update.go index 839fdcf5..18fe0d4b 100644 --- a/internal/api/handlers/update.go +++ b/internal/api/handlers/update.go @@ -127,13 +127,17 @@ func HandleUpdateApply(updater *update.Manager) http.HandlerFunc { func HandleUpdateEvents(updater *update.Manager) http.HandlerFunc { return func(w http.ResponseWriter, r *http.Request) { + slog.Info("Client connected to SSE stream", slog.String("client", r.RemoteAddr)) sseStream, err := render.NewSSEStream(r.Context(), w) if err != nil { slog.Error("Unable to create SSE stream", slog.String("error", err.Error())) render.EncodeResponse(w, http.StatusInternalServerError, models.ErrorResponse{Details: "unable to create SSE stream"}) return } - defer sseStream.Close() + defer func() { + sseStream.Close() + slog.Info("SSE stream closed", slog.String("client", r.RemoteAddr)) + }() ch := updater.Subscribe() defer updater.Unsubscribe(ch) @@ -142,9 +146,10 @@ func HandleUpdateEvents(updater *update.Manager) http.HandlerFunc { select { case event, ok := <-ch: if !ok { - slog.Info("APT event channel closed, stopping SSE stream") + slog.Info("event channel closed, stopping SSE stream") return } + slog.Debug("Sending update event to SSE stream", slog.String("type", event.Type.String()), slog.String("client", r.RemoteAddr)) if event.Type == update.ErrorEvent { err := event.GetError() code := render.InternalServiceErr @@ -163,6 +168,7 @@ func HandleUpdateEvents(updater *update.Manager) http.HandlerFunc { } case <-r.Context().Done(): + slog.Info("context killed SSE stream", slog.String("client", r.RemoteAddr)) return } } From 35ce35f463ae87ebbd667126814b212dda10cabb Mon Sep 17 00:00:00 2001 From: lucarin91 Date: Thu, 20 Nov 2025 10:42:40 +0100 Subject: [PATCH 2/9] set debug log --- .../arduino-app-cli/etc/systemd/system/arduino-app-cli.service | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/debian/arduino-app-cli/etc/systemd/system/arduino-app-cli.service b/debian/arduino-app-cli/etc/systemd/system/arduino-app-cli.service index 93ed0367..fcb02007 100644 --- a/debian/arduino-app-cli/etc/systemd/system/arduino-app-cli.service +++ b/debian/arduino-app-cli/etc/systemd/system/arduino-app-cli.service @@ -4,7 +4,7 @@ After=network-online.target docker.service arduino-router.service Wants=network-online.target docker.service arduino-router.service [Service] -ExecStart=/usr/bin/arduino-app-cli daemon --port 8800 --log-level error +ExecStart=/usr/bin/arduino-app-cli daemon --port 8800 --log-level debug User=arduino Group=arduino Environment="ARDUINO_ROUTER_SOCKET=/var/run/arduino-router.sock" From 8be8ed9800646e9144c0feb001df6dcf88e0d680 Mon Sep 17 00:00:00 2001 From: lucarin91 Date: Thu, 20 Nov 2025 10:55:00 +0100 Subject: [PATCH 3/9] someother logs --- internal/api/handlers/update.go | 3 ++- internal/render/sse.go | 6 +++--- 2 files changed, 5 insertions(+), 4 deletions(-) diff --git a/internal/api/handlers/update.go b/internal/api/handlers/update.go index 18fe0d4b..b16a1ee1 100644 --- a/internal/api/handlers/update.go +++ b/internal/api/handlers/update.go @@ -16,6 +16,7 @@ package handlers import ( + "context" "net/http" "strings" @@ -128,7 +129,7 @@ func HandleUpdateApply(updater *update.Manager) http.HandlerFunc { func HandleUpdateEvents(updater *update.Manager) http.HandlerFunc { return func(w http.ResponseWriter, r *http.Request) { slog.Info("Client connected to SSE stream", slog.String("client", r.RemoteAddr)) - sseStream, err := render.NewSSEStream(r.Context(), w) + sseStream, err := render.NewSSEStream(context.WithValue(r.Context(), "remote_addr", r.RemoteAddr), w) if err != nil { slog.Error("Unable to create SSE stream", slog.String("error", err.Error())) render.EncodeResponse(w, http.StatusInternalServerError, models.ErrorResponse{Details: "unable to create SSE stream"}) diff --git a/internal/render/sse.go b/internal/render/sse.go index 3f269f9a..6e947ef7 100644 --- a/internal/render/sse.go +++ b/internal/render/sse.go @@ -114,11 +114,11 @@ func (s *SSEStream) loop() { for { select { case <-s.ctx.Done(): - slog.Debug("stream SSE request context done") + slog.Debug("stream SSE request context done", slog.Any("remote_addr", s.ctx.Value("remote_addr"))) return case <-time.After(s.heartbeatInterval): if err := s.heartbeat(); err != nil { - slog.Error("failed to send ping", slog.Any("error", err)) + slog.Error("failed to send ping", slog.Any("error", err), slog.Any("remote_addr", s.ctx.Value("remote_addr"))) return } case event, canProduce := <-s.messageCh: @@ -127,7 +127,7 @@ func (s *SSEStream) loop() { return } if err := s.send(event); err != nil { - slog.Debug("failed to send SSE event", slog.String("event", event.Type), slog.Any("error", err)) + slog.Debug("failed to send SSE event", slog.String("event", event.Type), slog.Any("error", err), slog.Any("remote_addr", s.ctx.Value("remote_addr"))) return } } From 8839da3752aa0a1ddbbc013ef80dd44248ac1f4c Mon Sep 17 00:00:00 2001 From: lucarin91 Date: Thu, 20 Nov 2025 11:11:10 +0100 Subject: [PATCH 4/9] add initial heartbeat --- internal/api/handlers/update.go | 3 +++ 1 file changed, 3 insertions(+) diff --git a/internal/api/handlers/update.go b/internal/api/handlers/update.go index b16a1ee1..d633663a 100644 --- a/internal/api/handlers/update.go +++ b/internal/api/handlers/update.go @@ -140,6 +140,9 @@ func HandleUpdateEvents(updater *update.Manager) http.HandlerFunc { slog.Info("SSE stream closed", slog.String("client", r.RemoteAddr)) }() + // Send an initial heartbeat to return a feedback to the client + sseStream.Send(render.SSEEvent{Type: "heartbeat"}) + ch := updater.Subscribe() defer updater.Unsubscribe(ch) From d2e263bcfae288186b0f8f0ea9ea50956836072a Mon Sep 17 00:00:00 2001 From: lucarin91 Date: Thu, 20 Nov 2025 11:14:58 +0100 Subject: [PATCH 5/9] fixup! add initial heartbeat --- internal/render/sse.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/internal/render/sse.go b/internal/render/sse.go index 6e947ef7..4a467ebd 100644 --- a/internal/render/sse.go +++ b/internal/render/sse.go @@ -39,7 +39,7 @@ type SSEErrorData struct { type SSEEvent struct { Type string `json:"type"` - Data any `json:"data"` + Data any `json:"data,omitempty"` } func NewErrorEvent(data any) SSEEvent { From f5e2a35a189e6055743e5cf496a6d02606ce004b Mon Sep 17 00:00:00 2001 From: lucarin91 Date: Thu, 20 Nov 2025 11:33:20 +0100 Subject: [PATCH 6/9] more logs --- internal/api/handlers/update.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/internal/api/handlers/update.go b/internal/api/handlers/update.go index d633663a..d4ee490c 100644 --- a/internal/api/handlers/update.go +++ b/internal/api/handlers/update.go @@ -128,7 +128,7 @@ func HandleUpdateApply(updater *update.Manager) http.HandlerFunc { func HandleUpdateEvents(updater *update.Manager) http.HandlerFunc { return func(w http.ResponseWriter, r *http.Request) { - slog.Info("Client connected to SSE stream", slog.String("client", r.RemoteAddr)) + slog.Info("Client connected to SSE stream", slog.String("client", r.RemoteAddr), slog.String("path", r.URL.Path), slog.String("method", r.Method)) sseStream, err := render.NewSSEStream(context.WithValue(r.Context(), "remote_addr", r.RemoteAddr), w) if err != nil { slog.Error("Unable to create SSE stream", slog.String("error", err.Error())) From bdc9c6891e6fefe87be33e80efdb971bde3c64ce Mon Sep 17 00:00:00 2001 From: lucarin91 Date: Thu, 20 Nov 2025 11:36:58 +0100 Subject: [PATCH 7/9] send and initial log message --- internal/api/handlers/update.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/internal/api/handlers/update.go b/internal/api/handlers/update.go index d4ee490c..e1cc321d 100644 --- a/internal/api/handlers/update.go +++ b/internal/api/handlers/update.go @@ -141,7 +141,7 @@ func HandleUpdateEvents(updater *update.Manager) http.HandlerFunc { }() // Send an initial heartbeat to return a feedback to the client - sseStream.Send(render.SSEEvent{Type: "heartbeat"}) + sseStream.Send(render.SSEEvent{Type: update.UpgradeLineEvent.String(), Data: "connected to update events stream"}) ch := updater.Subscribe() defer updater.Unsubscribe(ch) From 574dbcf240b7a98cdcf9c85bbd900e767f22e8ee Mon Sep 17 00:00:00 2001 From: lucarin91 Date: Thu, 20 Nov 2025 11:54:55 +0100 Subject: [PATCH 8/9] handle head request --- internal/api/handlers/update.go | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/internal/api/handlers/update.go b/internal/api/handlers/update.go index e1cc321d..036ef3a5 100644 --- a/internal/api/handlers/update.go +++ b/internal/api/handlers/update.go @@ -128,6 +128,12 @@ func HandleUpdateApply(updater *update.Manager) http.HandlerFunc { func HandleUpdateEvents(updater *update.Manager) http.HandlerFunc { return func(w http.ResponseWriter, r *http.Request) { + // Handle HEAD requests with erly return + if r.Method == http.MethodHead { + render.EncodeResponse(w, http.StatusOK, nil) + return + } + slog.Info("Client connected to SSE stream", slog.String("client", r.RemoteAddr), slog.String("path", r.URL.Path), slog.String("method", r.Method)) sseStream, err := render.NewSSEStream(context.WithValue(r.Context(), "remote_addr", r.RemoteAddr), w) if err != nil { From de1519f134b309a349002f6df6c3935986575447 Mon Sep 17 00:00:00 2001 From: lucarin91 Date: Thu, 20 Nov 2025 16:15:46 +0100 Subject: [PATCH 9/9] enable http/2 --- cmd/arduino-app-cli/daemon/daemon.go | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) diff --git a/cmd/arduino-app-cli/daemon/daemon.go b/cmd/arduino-app-cli/daemon/daemon.go index eeac105c..e91d5cee 100644 --- a/cmd/arduino-app-cli/daemon/daemon.go +++ b/cmd/arduino-app-cli/daemon/daemon.go @@ -24,6 +24,8 @@ import ( "github.com/jub0bs/cors" "github.com/spf13/cobra" + "golang.org/x/net/http2" + "golang.org/x/net/http2/h2c" "github.com/arduino/arduino-app-cli/cmd/arduino-app-cli/internal/servicelocator" "github.com/arduino/arduino-app-cli/internal/api" @@ -120,12 +122,15 @@ func httpHandler(ctx context.Context, cfg config.Configuration, daemonPort, vers panic(err) } apiSrv = corsMiddlware.Wrap(apiSrv) + apiSrv = httprecover.RecoverPanic(apiSrv) // Start the HTTP server address := "127.0.0.1:" + daemonPort httpSrv := http.Server{ - Addr: address, - Handler: httprecover.RecoverPanic(apiSrv), + Addr: address, + Handler: h2c.NewHandler(apiSrv, &http2.Server{ + MaxConcurrentStreams: 250, + }), ReadHeaderTimeout: 60 * time.Second, } go func() {