chore: fix logger

Kim committed Mar 12, 2026 at 11:19 UTC b114cf85dea681f63b74ca15afb809fd0dea4fdb
7 files changed +166 -26
cmd/portal-tunnel/main.go
+2
@@ -34,6 +34,7 @@ var (
34
35 func main() {
36 zerolog.TimeFieldFormat = time.RFC3339
37 + zerolog.SetGlobalLevel(zerolog.InfoLevel)
38 log.Logger = log.Output(zerolog.ConsoleWriter{Out: os.Stdout, TimeFormat: time.RFC3339})
39 logger := log.With().Str("component", "portal-tunnel").Logger()
40
@@ -86,6 +87,7 @@ func runTunnel() error {
87 defer exposure.Close()
88
89 logger.Info().
90 + Str("release_version", types.ReleaseVersion).
91 Str("local", flagHost).
92 Msg("starting portal tunnel")
93
cmd/relay-server/main.go
+2 -1
@@ -10,6 +10,7 @@ import (
10 "github.com/rs/zerolog"
11 "github.com/rs/zerolog/log"
12
13 + "github.com/gosuda/portal/v2/types"
14 "github.com/gosuda/portal/v2/utils"
15 )
16
@@ -103,8 +104,8 @@ func main() {
104 }
105
106 logger.Info().
107 + Str("release_version", types.ReleaseVersion).
108 Str("portal_url", cfg.PortalURL).
107 - Strs("bootstraps", cfg.Bootstraps).
109 Msg("configured relay server")
110
111 if err := runServer(cfg); err != nil {
sdk/api_client.go
+2 -2
@@ -26,8 +26,8 @@ const (
26 defaultHandshakeTimeout = 15 * time.Second
27 defaultLeaseTTL = 30 * time.Second
28 defaultRenewBefore = 30 * time.Second
29 - defaultReadyTarget = 1
30 - defaultRetryWait = 10 * time.Second
29 + defaultReadyTarget = 2
30 + defaultRetryWait = 3 * time.Second
31 defaultHTTPShutdownTimeout = 5 * time.Second
32 )
33
sdk/expose.go
+74 -13
@@ -9,6 +9,7 @@ import (
9 "strings"
10 "sync"
11 "sync/atomic"
12 + "time"
13
14 "github.com/rs/zerolog/log"
15
@@ -21,6 +22,7 @@ import (
22 type Exposure struct {
23 listener net.Listener
24 relays []exposureRelay
25 + done chan struct{}
26
27 closeOnce sync.Once
28 connSeq atomic.Uint64
@@ -37,7 +39,6 @@ func Expose(ctx context.Context, relayUrls []string, name string, metadata types
39 if len(relayURLs) == 0 {
40 return nil, nil
41 }
40 -
42 relays := make([]exposureRelay, 0, len(relayURLs))
43 cleanup := func() error {
44 var closeErr error
@@ -77,13 +78,15 @@ func Expose(ctx context.Context, relayUrls []string, name string, metadata types
78 exposure := &Exposure{
79 listener: merged,
80 relays: relays,
81 + done: make(chan struct{}),
82 }
83 + go exposure.monitorStartupCounts(ctx)
84
85 log.Info().
86 + Str("release_version", types.ReleaseVersion).
87 Int("relay_count", len(exposure.relays)).
88 Strs("relays", exposure.RelayURLs()).
85 - Strs("public_urls", exposure.PublicURLs()).
86 - Msg("exposure started")
89 + Msgf("exposure relay started")
90
91 return exposure, nil
92 }
@@ -97,8 +100,7 @@ func (e *Exposure) Accept() (net.Conn, error) {
100 conn, err := e.listener.Accept()
101 if err != nil {
102 if !errors.Is(err, net.ErrClosed) {
100 - logger := log.With().Str("component", "sdk-exposure").Logger()
101 - logger.Warn().
103 + log.Warn().
104 Err(err).
105 Str("local_addr", utils.AddrString(e.listener.Addr())).
106 Msg("exposure accept failed")
@@ -107,8 +109,7 @@ func (e *Exposure) Accept() (net.Conn, error) {
109 }
110
111 connID := e.connSeq.Add(1)
110 - logger := log.With().Str("component", "sdk-exposure").Logger()
111 - logger.Info().
112 + log.Info().
113 Uint64("conn_id", connID).
114 Str("local_addr", utils.AddrString(conn.LocalAddr())).
115 Str("remote_addr", utils.AddrString(conn.RemoteAddr())).
@@ -190,16 +191,18 @@ func (e *Exposure) Close() error {
191
192 var closeErr error
193 e.closeOnce.Do(func() {
194 + if e.done != nil {
195 + close(e.done)
196 + }
197 if e.listener != nil {
198 closeErr = errors.Join(closeErr, e.listener.Close())
199 }
200
197 - logger := log.With().Str("component", "sdk-exposure").Logger()
198 - event := logger.Info().
201 + event := log.Info().
202 Int("relay_count", len(e.relays)).
203 Strs("relays", e.RelayURLs())
204 if closeErr != nil {
202 - event = logger.Warn().
205 + event = log.Warn().
206 Err(closeErr).
207 Int("relay_count", len(e.relays)).
208 Strs("relays", e.RelayURLs())
@@ -315,6 +318,65 @@ func RunHTTP(ctx context.Context, relayListener net.Listener, handler http.Handl
318 return errors.Join(serveErr, shutdownErr)
319 }
320
321 +func (e *Exposure) monitorStartupCounts(ctx context.Context) {
322 + if e == nil {
323 + return
324 + }
325 +
326 + ticker := time.NewTicker(time.Second)
327 + defer ticker.Stop()
328 + prevStatuses := make(map[string]listenerStatus, len(e.relays))
329 + firstRun := true
330 +
331 + for {
332 + readyCount, inactiveCount := 0, 0
333 + activated := make([]string, 0)
334 + deactivated := make([]string, 0)
335 + for _, relay := range e.relays {
336 + status := listenerStatusInactive
337 + if relay.listener != nil {
338 + status = relay.listener.StartupStatus()
339 + }
340 + if status == listenerStatusReady {
341 + readyCount++
342 + } else {
343 + inactiveCount++
344 + }
345 +
346 + if prev, ok := prevStatuses[relay.relayURL]; ok && prev != status {
347 + if status == listenerStatusReady {
348 + activated = append(activated, relay.relayURL)
349 + } else {
350 + deactivated = append(deactivated, relay.relayURL)
351 + }
352 + }
353 + prevStatuses[relay.relayURL] = status
354 + }
355 +
356 + if firstRun || len(activated) > 0 || len(deactivated) > 0 {
357 + event := log.Info().
358 + Int("inactive", inactiveCount).
359 + Int("ready", readyCount)
360 + if len(activated) > 0 {
361 + event = event.Strs("activated", activated)
362 + }
363 + if len(deactivated) > 0 {
364 + event = event.Strs("deactivated", deactivated)
365 + }
366 + event.Msg("relay status")
367 + firstRun = false
368 + }
369 +
370 + select {
371 + case <-e.done:
372 + return
373 + case <-ctx.Done():
374 + return
375 + case <-ticker.C:
376 + }
377 + }
378 +}
379 +
380 type exposureRelay struct {
381 relayURL string
382 listener *Listener
@@ -336,13 +398,12 @@ func (c *exposureConn) Close() error {
398 closeErr = nil
399 }
400
339 - logger := log.With().Str("component", "sdk-exposure").Logger()
340 - event := logger.Info().
401 + event := log.Info().
402 Uint64("conn_id", c.id).
403 Str("local_addr", c.localAddr).
404 Str("remote_addr", c.remoteAddr)
405 if closeErr != nil {
345 - event = logger.Warn().
406 + event = log.Warn().
407 Err(closeErr).
408 Uint64("conn_id", c.id).
409 Str("local_addr", c.localAddr).
sdk/listener.go
+76 -3
@@ -32,6 +32,13 @@ type ListenerConfig struct {
32 RetryWait time.Duration
33 }
34
35 +type listenerStatus string
36 +
37 +const (
38 + listenerStatusInactive listenerStatus = "inactive"
39 + listenerStatusReady listenerStatus = "ready"
40 +)
41 +
42 type Listener struct {
43 tlsCloser io.Closer
44 tlsConfig *tls.Config
@@ -45,6 +52,9 @@ type Listener struct {
52 cancel context.CancelFunc
53 api *apiClient
54 accepted chan net.Conn
55 + relayURL string
56 + startupStatus listenerStatus
57 + activeSessions int
58 leaseID string
59 hostname string
60 metadata types.LeaseMetadata
@@ -78,6 +88,8 @@ func NewListener(ctx context.Context, relayURL string, cfg ListenerConfig) (*Lis
88 cancel: cancel,
89 api: api,
90 accepted: make(chan net.Conn, max(readyTarget*2, 1)),
91 + relayURL: api.baseURL.String(),
92 + startupStatus: listenerStatusInactive,
93 readyTarget: readyTarget,
94 retryCount: cfg.RetryCount,
95 retryWait: retryWait,
@@ -102,7 +114,7 @@ func (l *Listener) runStartup(ctx context.Context) {
114 }
115 go l.runRenewLoop(ctx)
116 log.Info().
105 - Str("component", "sdk-listener").
117 + Str("relay_url", l.relayURL).
118 Str("lease_id", l.LeaseID()).
119 Str("hostname", l.Hostname()).
120 Msg("listener ready")
@@ -215,6 +227,9 @@ func (l *Listener) runSessionLoop(ctx context.Context) {
227 retries = 0
228 default:
229 retries++
230 + if l.ActiveSessions() == 0 {
231 + l.setStartupStatus(listenerStatusInactive)
232 + }
233 if !l.retryOrClose(ctx, "reverse session connect", err, retries) {
234 return
235 }
@@ -266,6 +281,8 @@ func (l *Listener) runSession(ctx context.Context) (bool, error) {
281 if err != nil {
282 return false, err
283 }
284 + l.sessionOpened()
285 + defer l.sessionClosed()
286
287 var marker [1]byte
288 for {
@@ -394,11 +411,15 @@ func (l *Listener) retryOrClose(ctx context.Context, operation string, err error
411 }
412
413 logger := log.With().
397 - Str("component", "sdk-listener").
414 + Str("relay_url", l.relayURL).
415 Str("operation", operation).
416 Str("lease_id", l.LeaseID()).
417 Logger()
418
419 + if operation == "lease registration" {
420 + l.setStartupStatus(listenerStatusInactive)
421 + }
422 +
423 if l.retryCount > 0 && retries > l.retryCount {
424 if operation != "lease renewal" {
425 logger.Error().
@@ -411,7 +432,7 @@ func (l *Listener) retryOrClose(ctx context.Context, operation string, err error
432 }
433
434 if operation != "lease renewal" {
414 - logger.Warn().
435 + logger.Debug().
436 Err(err).
437 Int("retry_attempt", retries).
438 Int("retry_count", l.retryCount).
@@ -448,3 +469,55 @@ func (l *Listener) drainAccepted() {
469 }
470 }
471 }
472 +
473 +func (l *Listener) setStartupStatus(status listenerStatus) {
474 + if l == nil {
475 + return
476 + }
477 + l.mu.Lock()
478 + l.startupStatus = status
479 + l.mu.Unlock()
480 +}
481 +
482 +func (l *Listener) StartupStatus() listenerStatus {
483 + if l == nil {
484 + return listenerStatusInactive
485 + }
486 +
487 + l.mu.Lock()
488 + defer l.mu.Unlock()
489 + return l.startupStatus
490 +}
491 +
492 +func (l *Listener) ActiveSessions() int {
493 + if l == nil {
494 + return 0
495 + }
496 +
497 + l.mu.Lock()
498 + defer l.mu.Unlock()
499 + return l.activeSessions
500 +}
501 +
502 +func (l *Listener) sessionOpened() {
503 + if l == nil {
504 + return
505 + }
506 +
507 + l.mu.Lock()
508 + l.activeSessions++
509 + l.startupStatus = listenerStatusReady
510 + l.mu.Unlock()
511 +}
512 +
513 +func (l *Listener) sessionClosed() {
514 + if l == nil {
515 + return
516 + }
517 +
518 + l.mu.Lock()
519 + if l.activeSessions > 0 {
520 + l.activeSessions--
521 + }
522 + l.mu.Unlock()
523 +}
types/api.go
-7
@@ -6,13 +6,6 @@ import (
6 "time"
7 )
8
9 -const (
10 - HeaderReverseToken = "X-Portal-Token"
11 - MarkerKeepalive = byte(0x00)
12 - MarkerTLSStart = byte(0x02)
13 - SDKProtocolVersion = "1"
14 -)
15 -
9 type APIEnvelope[T any] struct {
10 Data T `json:"data,omitempty"`
11 Error *APIError `json:"error,omitempty"`
types/types.go new
+10
@@ -0,0 +1,10 @@
1 +package types
2 +
3 +const (
4 + ReleaseVersion = "v2.0.4"
5 + SDKProtocolVersion = "1"
6 +
7 + HeaderReverseToken = "X-Portal-Token"
8 + MarkerKeepalive = byte(0x00)
9 + MarkerTLSStart = byte(0x02)
10 +)