Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

log/loki: limit line size #2475

Merged
merged 3 commits into from
Jul 27, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
26 changes: 17 additions & 9 deletions app/log/loki/client.go
Original file line number Diff line number Diff line change
Expand Up @@ -25,11 +25,12 @@
)

const (
contentType = "application/x-protobuf"
maxErrMsgLen = 1024
httpTimeout = 10 * time.Second
batchWait = 1 * time.Second
batchMax = 5 * 1 << 20 // 5MB
contentType = "application/x-protobuf"
maxErrMsgLen = 1024
httpTimeout = 10 * time.Second
batchWait = 1 * time.Second
batchMax = 5 * 1 << 20 // 5MB
maxLogLineLen = 4 << 10 // 4096B
)

// lazyLabelsFunc abstracts lazy loading of labels, logs will only be sent when it returns true.
Expand All @@ -39,18 +40,18 @@
type logFunc func(string, error)

// NewForT returns a new Client for testing.
func NewForT(endpoint string, serviceLabel string, batchWait time.Duration, batchMax int,
func NewForT(endpoint string, serviceLabel string, batchWait time.Duration, batchMax, maxLogLineLen int,
moreLabelsFunc lazyLabelsFunc,
) *Client {
return newInternal(endpoint, serviceLabel, batchWait, batchMax, func(string, error) {}, moreLabelsFunc)
return newInternal(endpoint, serviceLabel, batchWait, batchMax, maxLogLineLen, func(string, error) {}, moreLabelsFunc)
}

// New returns a new Client.
func New(endpoint string, serviceLabel string, logFunc logFunc, moreLabelsFunc lazyLabelsFunc) *Client {
return newInternal(endpoint, serviceLabel, batchWait, batchMax, logFunc, moreLabelsFunc)
return newInternal(endpoint, serviceLabel, batchWait, batchMax, maxLogLineLen, logFunc, moreLabelsFunc)

Check warning on line 51 in app/log/loki/client.go

View check run for this annotation

Codecov / codecov/patch

app/log/loki/client.go#L51

Added line #L51 was not covered by tests
}

func newInternal(endpoint string, serviceLabel string, batchWait time.Duration, batchMax int,
func newInternal(endpoint string, serviceLabel string, batchWait time.Duration, batchMax, maxLogLineLen int,
logFunc logFunc, moreLabelsFunc lazyLabelsFunc,
) *Client {
return &Client{
Expand All @@ -60,6 +61,7 @@
input: make(chan string),
batchMax: batchMax,
batchWait: batchWait,
maxLogLineLen: maxLogLineLen,
logFunc: logFunc,
serviceLabel: serviceLabel,
moreLabelsFunc: moreLabelsFunc,
Expand All @@ -74,6 +76,7 @@
endpoint string
batchWait time.Duration
batchMax int
maxLogLineLen int
serviceLabel string
moreLabelsFunc lazyLabelsFunc
logFunc logFunc
Expand Down Expand Up @@ -101,10 +104,15 @@
for {
select {
case line := <-c.input:
if len(line) > c.maxLogLineLen && c.maxLogLineLen != 0 {
continue // Silently drop log line longer than maxLogLineLen if set
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

not sure about silent, what about using a log filter?

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm doing what batch does pretty much, we discussed this briefly on Slack and you suggested to just drop it.

What behavior would you like to see instead?

Copy link
Contributor

@corverroos corverroos Jul 26, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

well, log it using a log filter: log.Warn(ctx, "Dropping to large logging line", z.Str("prefix", line[:10]), dropFilter with dropFilter being dropFilter := log.Filter().

but sure, this is only loki client itself, which is not our primary logging framework, it is best effort, so yeah, maybe silent drop is fine.

}

batch.Add(&pbv1.Entry{
Timestamp: timestamppb.Now(),
Line: line,
})

if batch.Size() > c.batchMax {
batch = newBatch() // Just silently drop, there should have been multiple error logs below.
}
Expand Down
53 changes: 52 additions & 1 deletion app/log/loki/client_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -53,7 +53,7 @@ func TestLoki(t *testing.T) {
}, true
}

cl := loki.NewForT(srv.URL, serviceLabel, time.Millisecond, 1024, lazyLabels)
cl := loki.NewForT(srv.URL, serviceLabel, time.Millisecond, 1024, 0, lazyLabels)

const n = 4

Expand Down Expand Up @@ -81,3 +81,54 @@ func decode(t *testing.T, b []byte) *pbv1.PushRequest {

return resp
}

func TestLongLines(t *testing.T) {
const (
// copied fromm client.go, simulate production workload
batchMax = 5 * 1 << 20
maxLogLineLen = 4 << 10

serviceLabel = "test"
normal = "normal log line"
huge = `ts=2023-07-26T11:38:47.922888118+02:00 level=debug caller=loki/client_test.go:124 msg=error data=0x03000000000000000c000000640000006b2839e6c4634ea95859035d4015217ff4fd04fe826db77ff3d9f6d940d3664b0d01dba3da9a6322ac63106e0fb2e05f35b3ec65ef53f12e1c708cd85b263dc83ce7f0cbfb6b0200689740241a2a873616125e0454ebb62a9becc12ee9f9b60f3d3224af96711900f07f5192b99f1200a38dddf858e822dcec4fd7fcc24b37609d1ad4deeadbfd0e45cc339cf4c5db643923599323f97b5209f079cbe32eb290bd9c6a40698ebf7bad15bcb7d25168c954000000c16669c4607dddf98e0810d1ca1d3db455dccd4abbe1d7e618b404e50c8d385690d0243a88976177c947f29d2c9b212981dfb36015bd81c4f9f8991c034db96d130cf3def3c936b758a18bb2f31e61f048b8e233006e8afc967f31dbd503f8aed73eb5adbe609662d6df696deaa3ede04f53f87432de73f73ec80bcd82bd63f80000000000000000dbee54d9dd388a8b31a6d5a3214a0b7e1766723a5eba409a6681eaf80ac4c8c4efb4668dec541dfd4ad53724414203bc4063f732d2f57877dd3085c0fcb34c648401000084010000840100009603000096030000d4438030f503129e62ba2c8c5106881b13589657506f7bbcfe50f80428ab00949c00ef52c0e982d71dba0334bf260cf6d6eaeee2d4a3d1d85c89ad251fb4397deb80bc4cf894c5e0cdd7f9f61f69d70964ab21058df89d2f5e54fa92b8a10aee2632dea72bb3fa0da2ffa6fe4e0afe49c6fa13609bfa44ba30b30470cb8e28112f2259f65ae5317a48d6ab7bbd14b357bd1cfc34a948c6a844a21377e72ae9cc96030000ee050000080000000d010000e4000000c0a32c3d104e0f00dfdf245254cd1e001ca9a04fa692be0969f3db2e449c1e59fc293863b733145c2f7b50145e0f5e5fbe9a7c1a6e59120002609f3634d68656968985a6328c1cebf881f4cc40aa0f3d5052931dbd6857747ba895b9a3290b00ba5787b5679750222f78a834ac8f1d28aab935294dd6efa04fff56062b53d85f0bdfefc6b8aae6027f29e972e80a344cfba4879520c83a4ed12c19f657397a3d9b2b6d20e93683890ea5936e276ffa9525fb4add29d698488f92ab6be3b3048aea55ace8b4c0f5961d45587b4edd7dbdbc30221fb6db9f2626646d63cc55d56f000000000000000000000000000000002000000000000000000000000000000001e4000000ee05f4523d0b16005c422d8201cd1d009e90eb16200b5c1844fce2966bd4a4fdcbb087622d95560e31b84fb31df9f4bbd67921c58678170096dbc7f35a5ca0a1dfe850c268db2209fcdf0b758b92e67e92ea1afc94c15ca4a562642b0b391b00d4b9818f6e3f3cf4bbe5392619b038e6f2bb09d8e276d8bc2e0bf98014c084f9d4e1f06199660c84628c402d0d9b06fbbac8897b01c095d1be800caabd8238de068a6fe49f721c2ab1dd67521aa6d08eb1026a9d80b8c7b315cee17d9328849e8554d4d4bb6eb7614edb5ebffa8eba85f1faf2e68973800db0de3ee5b64366d800000004000000000000000000000000000000000000000000000000000000000133e8d02630aca3c951cc3b88a5bfee6a4728cdf2ea15479e451d6674e0ccb338000000000000000000000000000000000000000020e3a87506703bf0ab292a9fbcf6eb2887a1695091534f0cd7865148d0dc63832cee9d28b865ca501cc56ad6b6017d74e451f6eadb8e47cc47fb7ed60c1c5f11000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004ab5fb11437d1eeb4394333d581b72352f4c9c3266cbf2827fa4628468f47be00000000000000000000000000000000000000000000000000000000000000000380200009f3428aebf6a2346533c6a20d75fcf6731eccc22f36bc7dbaa334a6c3f6972ebc95ed111b516bc895b2fd90d6bcfb809ed6909f58ee488e4fda670fdbeeea335406b5b82d90b5d921d92afb21a2798aedbb5d8b6f377e51d2bce499696c3b63600000000000000000000000000000000000000000000000000000000000000005e6284ed098b6712ecdf23bb172e32add234e0a873046a37e6596b770d61f79e pretty="DEBG error {\"data\": \"0x03000000000000000c000000640000006b2839e6c4634ea95859035d4015217ff4fd04fe826db77ff3d9f6d940d3664b0d01dba3da9a6322ac63106e0fb2e05f35b3ec65ef53f12e1c708cd85b263dc83ce7f0cbfb6b0200689740241a2a873616125e0454ebb62a9becc12ee9f9b60f3d3224af96711900f07f5192b99f1200a38dddf858e822dcec4fd7fcc24b37609d1ad4deeadbfd0e45cc339cf4c5db643923599323f97b5209f079cbe32eb290bd9c6a40698ebf7bad15bcb7d25168c954000000c16669c4607dddf98e0810d1ca1d3db455dccd4abbe1d7e618b404e50c8d385690d0243a88976177c947f29d2c9b212981dfb36015bd81c4f9f8991c034db96d130cf3def3c936b758a18bb2f31e61f048b8e233006e8afc967f31dbd503f8aed73eb5adbe609662d6df696deaa3ede04f53f87432de73f73ec80bcd82bd63f80000000000000000dbee54d9dd388a8b31a6d5a3214a0b7e1766723a5eba409a6681eaf80ac4c8c4efb4668dec541dfd4ad53724414203bc4063f732d2f57877dd3085c0fcb34c648401000084010000840100009603000096030000d4438030f503129e62ba2c8c5106881b13589657506f7bbcfe50f80428ab00949c00ef52c0e982d71dba0334bf260cf6d6eaeee2d4a3d1d85c89ad251fb4397deb80bc4cf894c5e0cdd7f9f61f69d70964ab21058df89d2f5e54fa92b8a10aee2632dea72bb3fa0da2ffa6fe4e0afe49c6fa13609bfa44ba30b30470cb8e28112f2259f65ae5317a48d6ab7bbd14b357bd1cfc34a948c6a844a21377e72ae9cc96030000ee050000080000000d010000e4000000c0a32c3d104e0f00dfdf245254cd1e001ca9a04fa692be0969f3db2e449c1e59fc293863b733145c2f7b50145e0f5e5fbe9a7c1a6e59120002609f3634d68656968985a6328c1cebf881f4cc40aa0f3d5052931dbd6857747ba895b9a3290b00ba5787b5679750222f78a834ac8f1d28aab935294dd6efa04fff56062b53d85f0bdfefc6b8aae6027f29e972e80a344cfba4879520c83a4ed12c19f657397a3d9b2b6d20e93683890ea5936e276ffa9525fb4add29d698488f92ab6be3b3048aea55ace8b4c0f5961d45587b4edd7dbdbc30221fb6db9f2626646d63cc55d56f000000000000000000000000000000002000000000000000000000000000000001e4000000ee05f4523d0b16005c422d8201cd1d009e90eb16200b5c1844fce2966bd4a4fdcbb087622d95560e31b84fb31df9f4bbd67921c58678170096dbc7f35a5ca0a1dfe850c268db2209fcdf0b758b92e67e92ea1afc94c15ca4a562642b0b391b00d4b9818f6e3f3cf4bbe5392619b038e6f2bb09d8e276d8bc2e0bf98014c084f9d4e1f06199660c84628c402d0d9b06fbbac8897b01c095d1be800caabd8238de068a6fe49f721c2ab1dd67521aa6d08eb1026a9d80b8c7b315cee17d9328849e8554d4d4bb6eb7614edb5ebffa8eba85f1faf2e68973800db0de3ee5b64366d800000004000000000000000000000000000000000000000000000000000000000133e8d02630aca3c951cc3b88a5bfee6a4728cdf2ea15479e451d6674e0ccb338000000000000000000000000000000000000000020e3a87506703bf0ab292a9fbcf6eb2887a1695091534f0cd7865148d0dc63832cee9d28b865ca501cc56ad6b6017d74e451f6eadb8e47cc47fb7ed60c1c5f11000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000004ab5fb11437d1eeb4394333d581b72352f4c9c3266cbf2827fa4628468f47be00000000000000000000000000000000000000000000000000000000000000000380200009f3428aebf6a2346533c6a20d75fcf6731eccc22f36bc7dbaa334a6c3f6972ebc95ed111b516bc895b2fd90d6bcfb809ed6909f58ee488e4fda670fdbeeea335406b5b82d90b5d921d92afb21a2798aedbb5d8b6f377e51d2bce499696c3b63600000000000000000000000000000000000000000000000000000000000000005e6284ed098b6712ecdf23bb172e32add234e0a873046a37e6596b770d61f79e\"}"`
)

ctx := context.Background()

entriesChan := make(chan string)
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
b, err := io.ReadAll(r.Body)
require.NoError(t, err)
require.NoError(t, r.Body.Close())
req := decode(t, b)
require.Len(t, req.Streams, 1)
require.Contains(t, req.Streams[0].Labels, fmt.Sprintf(`service="%s"`, serviceLabel))
for _, entry := range req.Streams[0].Entries {
entriesChan <- entry.Line
}
close(entriesChan)
}))

cl := loki.NewForT(srv.URL, serviceLabel, time.Millisecond, batchMax, maxLogLineLen, func() (map[string]string, bool) {
return map[string]string{}, true
})

go cl.Run()

cl.Add(normal)

for i := 0; i < 1000; i++ {
cl.Add(huge)
}

go cl.Stop(ctx)

var entries []string
for entry := range entriesChan {
require.NotEqual(t, huge, entry)
entries = append(entries, entry)
}

require.Len(t, entries, 1)
require.Equal(t, normal, entries[0])
}
Loading