diff --git a/server/client.go b/server/client.go index 0d3761b1ed..7ed961ad75 100644 --- a/server/client.go +++ b/server/client.go @@ -6089,6 +6089,14 @@ func (c *client) Warnf(format string, v ...any) { c.srv.Warnf(format, v...) } +func (c *client) rateLimitFormatWarnf(format string, v ...any) { + if _, loaded := c.srv.rateLimitLogging.LoadOrStore(format, time.Now()); loaded { + return + } + statement := fmt.Sprintf(format, v...) + c.Warnf("%s", statement) +} + func (c *client) RateLimitWarnf(format string, v ...any) { // Do the check before adding the client info to the format... statement := fmt.Sprintf(format, v...) diff --git a/server/jetstream_api.go b/server/jetstream_api.go index d34e1d05a8..066ebb7fad 100644 --- a/server/jetstream_api.go +++ b/server/jetstream_api.go @@ -862,10 +862,10 @@ func (js *jetStream) apiDispatch(sub *subscription, c *client, acc *Account, sub // Copy the state. Note the JSAPI only uses the hdr index to piece apart the // header from the msg body. No other references are needed. // Check pending and warn if getting backed up. - const warnThresh = 32 + const warnThresh = 128 pending := s.jsAPIRoutedReqs.push(&jsAPIRoutedReq{jsub, sub, acc, subject, reply, copyBytes(rmsg), c.pa}) - if pending > warnThresh { - s.RateLimitWarnf("JetStream request queue has high pending count: %d", pending) + if pending >= warnThresh { + s.rateLimitFormatWarnf("JetStream request queue has high pending count: %d", pending) } } diff --git a/server/log.go b/server/log.go index e1b9078a5e..6822265823 100644 --- a/server/log.go +++ b/server/log.go @@ -219,6 +219,14 @@ func (s *Server) Warnf(format string, v ...any) { }, format, v...) } +func (s *Server) rateLimitFormatWarnf(format string, v ...any) { + if _, loaded := s.rateLimitLogging.LoadOrStore(format, time.Now()); loaded { + return + } + statement := fmt.Sprintf(format, v...) + s.Warnf("%s", statement) +} + func (s *Server) RateLimitWarnf(format string, v ...any) { statement := fmt.Sprintf(format, v...) if _, loaded := s.rateLimitLogging.LoadOrStore(statement, time.Now()); loaded { diff --git a/server/server_test.go b/server/server_test.go index bf388b82cc..795c561950 100644 --- a/server/server_test.go +++ b/server/server_test.go @@ -2011,16 +2011,20 @@ func TestServerRateLimitLogging(t *testing.T) { s.RateLimitWarnf("Warning number 1") s.RateLimitWarnf("Warning number 2") + s.rateLimitFormatWarnf("warning value %d", 1) s.RateLimitWarnf("Warning number 1") s.RateLimitWarnf("Warning number 2") + s.rateLimitFormatWarnf("warning value %d", 2) checkLog := func(c1, c2 *client) { t.Helper() nb1 := "Warning number 1" nb2 := "Warning number 2" + nbv := "warning value" gotOne := 0 gotTwo := 0 + gotFormat := 0 for done := false; !done; { select { case w := <-l.warn: @@ -2028,6 +2032,8 @@ func TestServerRateLimitLogging(t *testing.T) { gotOne++ } else if strings.Contains(w, nb2) { gotTwo++ + } else if strings.Contains(w, nbv) { + gotFormat++ } case <-time.After(150 * time.Millisecond): done = true @@ -2039,27 +2045,39 @@ func TestServerRateLimitLogging(t *testing.T) { if gotTwo != 1 { t.Fatalf("Should have had only 1 warning for nb2, got %v", gotTwo) } + if gotFormat != 1 { + t.Fatalf("Should have had only 1 warning for format, got %v", gotFormat) + } // Wait for more than the expiration interval time.Sleep(200 * time.Millisecond) if c1 == nil { s.RateLimitWarnf(nb1) + s.rateLimitFormatWarnf("warning value %d", 1) } else { c1.RateLimitWarnf(nb1) c2.RateLimitWarnf(nb1) + c1.rateLimitFormatWarnf("warning value %d", 1) } gotOne = 0 + gotFormat = 0 for { select { case w := <-l.warn: if strings.Contains(w, nb1) { gotOne++ + } else if strings.Contains(w, nbv) { + gotFormat++ } case <-time.After(200 * time.Millisecond): if gotOne == 0 { t.Fatalf("Warning was still suppressed") } else if gotOne > 1 { t.Fatalf("Should have had only 1 warning for nb1, got %v", gotOne) + } else if gotFormat == 0 { + t.Fatalf("Warning was still suppressed") + } else if gotFormat > 1 { + t.Fatalf("Should have had only 1 warning for format, got %v", gotFormat) } else { // OK! we are done return @@ -2101,8 +2119,10 @@ func TestServerRateLimitLogging(t *testing.T) { c1.RateLimitWarnf("Warning number 1") c1.RateLimitWarnf("Warning number 2") + c1.rateLimitFormatWarnf("warning value %d", 1) c2.RateLimitWarnf("Warning number 1") c2.RateLimitWarnf("Warning number 2") + c2.rateLimitFormatWarnf("warning value %d", 2) checkLog(c1, c2) }