Messages not being flushed from queue on subsequent runs

Đang mở

#40 mở ngày 14/3/2023 1 bình luận 2 reaction 0 người được giao Xem trên GitHub

Chưa có ai nhận issue này.

Đánh giá

Độ khó: 4/5
Thời gian dự kiến: 3-5 ngày
Mức phù hợp với người mới: 32/100

Loại issue: Lỗi
Độ rõ ràng: Cần làm rõ
Mức độ hoạt động: Đình trệ
Công nghệ: aws, java
Lĩnh vực: backend, cloud, observability-sre

Hướng nghiên cứu

Bắt đầu với S3EventProcessor và theo dõi vòng đời transport của nó qua GelfSenderThread và GelfTcpTransport, sử dụng các log Lambda được cung cấp để so sánh lần gọi đầu tiên với các lần gọi tiếp theo. Xem xét hành vi của queue và shutdown liên quan đến TCP_QUEUE_SIZE và SHUTDOWN_FLUSH_RETRIES; được xem là hoàn tất khi các message được gửi đến Graylog trong những lần chạy tiếp theo mà không làm mất vòng đời transport.

Do mô hình lập chỉ mục viết ra từ nội dung của issue.

Mô tả

bug triaged

We are encountering an issue where log messages are not being sent to Graylog. When the lambda first starts, it's able to process one message but it fails for all subsequent runs without any apparent reason (or log message).

Runtime: Java 8 on Amazon Linux 2
Memory: 512 MB

I've tried tweaking the following but nothing seems to help

TCP_QUEUE_SIZE
SHUTDOWN_FLUSH_RETRIES

Logs

message
INIT_START Runtime Version: java:8.al2.v18	Runtime Version ARN: arn:aws:lambda:us-west-2::runtime:xxx
Transforming org/apache/logging/log4j/core/lookup/JndiLookup (lambdainternal.CustomerClassLoader@37bba400)
START RequestId: 90958b19-01b9-4744-863f-1bde7ffc5c7a Version: $LATEST
2023-03-14 06:45:00 90958b19-01b9-4744-863f-1bde7ffc5c7a INFO  GraylogS3Function:65 - Log level is now set to [DEBUG].
"io.netty.channel.socket.nio.NioSocketChannel
"
org.graylog2.gelfclient.encoder.GelfMessageJsonEncoder
"io.netty.channel.MultithreadEventLoopGroup
"
"io.netty.util.internal.InternalThreadLocalMap
"
io.netty.util.internal.PlatformDependent0
"io.netty.channel.AbstractChannel
"
"io.netty.util.concurrent.AbstractEventExecutor
"
"io.netty.util.concurrent.GlobalEventExecutor
"
org.graylog2.gelfclient.transport.AbstractGelfTransport
"io.netty.util.internal.PlatformDependent
"
org.graylog2.gelfclient.transport.GelfSenderThread
"com.github.joschi.jadconfig.JadConfig
"
"io.netty.channel.AbstractChannelHandlerContext
"
"io.netty.channel.nio.AbstractNioChannel
"
org.graylog.integrations.s3.CompressionType
"io.netty.channel.DefaultChannelId
"
"io.netty.channel.ChannelInitializer
"
"io.netty.util.concurrent.SingleThreadEventExecutor
"
"io.netty.util.NetUtilInitializations
"
org.graylog2.gelfclient.transport.GelfTcpTransport
"io.netty.util.NetUtil
"
"io.netty.util.concurrent.DefaultPromise.rejectedExecution
"
io.netty.util.internal.CleanerJava6
"io.netty.util.ResourceLeakDetector
"
"io.netty.buffer.PooledByteBufAllocator
"
"io.netty.util.internal.MacAddressUtil
"
"io.netty.util.internal.SystemPropertyUtil
"
"io.netty.channel.ChannelOutboundBuffer
"
"io.netty.util.concurrent.DefaultPromise
"
"io.netty.bootstrap.Bootstrap
"
"io.netty.resolver.AddressResolverGroup
"
"io.netty.buffer.ByteBufUtil
"
"io.netty.buffer.PoolThreadCache
"
org.graylog.integrations.s3.S3EventProcessor
"io.netty.channel.nio.NioEventLoop
"
org.graylog.integrations.s3.S3ScannerFactory
org.graylog.integrations.s3.GraylogS3Function
org.graylog.integrations.s3.ProtocolType
org.graylog.integrations.s3.ContentType
"io.netty.util.internal.logging.InternalLoggerFactory
"
"io.netty.channel.DefaultChannelPipeline
"
"io.netty.channel.ChannelHandlerMask
"
"2023-03-14 06:45:00 90958b19-01b9-4744-863f-1bde7ffc5c7a DEBUG GraylogS3Function:37 - Configuration{, graylogHost='xxx.xx.xx.xxx', graylogPort=12201, connectTimeout=10000, reconnectDelay=10000, tcpKeepAlive=true, tcpNoDelay=true, queueSize=4, maxInflightSends=512, contentType='text/plain', compressionType='none', protocolType='tcp', messageFields='[]', messageSummaryFields='[ClientRequestHost, ClientRequestPath, OriginIP, ClientSrcPort, EdgeServerIP, EdgeResponseBytes]'}"
2023-03-14 06:45:00 90958b19-01b9-4744-863f-1bde7ffc5c7a INFO  S3EventProcessor:45 - Reading object [prod-company-integration-webhooks-functionF19B1A04-8zoCVNRl0Zsn/2023/03/14/06-44-54-814351.log] from bucket [integration-webhooks-logs]
"2023-03-14 06:45:03 90958b19-01b9-4744-863f-1bde7ffc5c7a DEBUG AbstractGelfTransport:94 - Sending message: GelfMessage{version=""1.1"" timestamp=""1678776303.922"" short_message=""[{'time': '2023-03-14T06:43:54.697Z', 'type': 'platform.start', 'record': {'requestId': 'ad89fcd8-d804-4270-bb6b-b5e816c57a22', 'version': '8'}}, {'time': '2023-03-14T06:43:54.697Z', 'type': 'function', 'record': '{""request_id"": null, ""levelname"": ""INFO"", ""name"": ""company.webhook_router.handler"", ""module"": ""handler"", ""lineno"": 97, ""message"": ""Health check PASSED"", ""timestamp"": ""2023-03-14T06:43:54.697837+00:00""}
'}, {'time': '2023-03-14T06:43:55.028Z', 'type': 'platform.end', 'record': {'requestId': 'ad89fcd8-d804-4270-bb6b-b5e816c57a22'}}, {'time': '2023-03-14T06:43:55.028Z', 'type': 'platform.report', 'record': {'requestId': 'ad89fcd8-d804-4270-bb6b-b5e816c57a22', 'metrics': {'durationMs': 331.874, 'billedDurationMs': 332, 'memorySizeMB': 128, 'maxMemoryUsedMB': 113}}}]"", level=""ALERT(1)""}"
2023-03-14 06:45:03 90958b19-01b9-4744-863f-1bde7ffc5c7a INFO  S3EventProcessor:94 - Sent [1] messages.
2023-03-14 06:45:03 90958b19-01b9-4744-863f-1bde7ffc5c7a DEBUG S3EventProcessor:51 - Waiting up to [100ms] with [10] retries while waiting for transport shutdown to occur.
2023-03-14 06:45:03 90958b19-01b9-4744-863f-1bde7ffc5c7a DEBUG GelfSenderThread:156 - Attempting to flush messages in [100/MILLISECONDS] with [10] retries
"2023-03-14 06:45:03 90958b19-01b9-4744-863f-1bde7ffc5c7a DEBUG GelfSenderThread:164 - Flushing in progress. [1] messages are still enqueued, and [0] messages are still in-flight."
"2023-03-14 06:45:04 90958b19-01b9-4744-863f-1bde7ffc5c7a DEBUG GelfSenderThread:164 - Flushing in progress. [0] messages are still enqueued, and [1] messages are still in-flight."
"2023-03-14 06:45:04 90958b19-01b9-4744-863f-1bde7ffc5c7a DEBUG GelfSenderThread:164 - Flushing in progress. [0] messages are still enqueued, and [1] messages are still in-flight."
"2023-03-14 06:45:04 90958b19-01b9-4744-863f-1bde7ffc5c7a DEBUG GelfSenderThread:164 - Flushing in progress. [0] messages are still enqueued, and [1] messages are still in-flight."
2023-03-14 06:45:04 90958b19-01b9-4744-863f-1bde7ffc5c7a DEBUG GelfSenderThread:160 - Successfully flushed messages. Shutting down now.
2023-03-14 06:45:04  INFO  GelfTcpTransport:115 - Channel disconnected!
2023-03-14 06:45:04  DEBUG GelfSenderThread:123 - GelfSenderThread exiting!
2023-03-14 06:45:06  DEBUG PoolThreadCache:224 - Freed 1 thread-local buffer(s) from thread: gelfTcpTransport-1-1
2023-03-14 06:45:06 90958b19-01b9-4744-863f-1bde7ffc5c7a DEBUG S3EventProcessor:55 - Transport shutdown complete.
2023-03-14 06:45:06 90958b19-01b9-4744-863f-1bde7ffc5c7a INFO  GraylogS3Function:42 - Processed [1] S3 events.
END RequestId: 90958b19-01b9-4744-863f-1bde7ffc5c7a
REPORT RequestId: 90958b19-01b9-4744-863f-1bde7ffc5c7a	Duration: 6418.68 ms	Billed Duration: 6419 ms	Memory Size: 512 MB	Max Memory Used: 116 MB
START RequestId: d6e85b8b-e151-45c3-826c-eb5c1a5938c3 Version: $LATEST
"io.netty.channel.socket.nio.NioSocketChannel
"
org.graylog2.gelfclient.encoder.GelfMessageJsonEncoder
"io.netty.channel.MultithreadEventLoopGroup
"
"io.netty.util.internal.InternalThreadLocalMap
"
io.netty.util.internal.PlatformDependent0
"io.netty.channel.AbstractChannel
"
"io.netty.util.concurrent.AbstractEventExecutor
"
"io.netty.util.concurrent.GlobalEventExecutor
"
org.graylog2.gelfclient.transport.AbstractGelfTransport
"io.netty.util.internal.PlatformDependent
"
org.graylog2.gelfclient.transport.GelfSenderThread
"com.github.joschi.jadconfig.JadConfig
"
"io.netty.channel.AbstractChannelHandlerContext
"
"io.netty.channel.nio.AbstractNioChannel
"
org.graylog.integrations.s3.CompressionType
"io.netty.channel.DefaultChannelId
"
"io.netty.buffer.AbstractByteBuf
"
"io.netty.channel.ChannelInitializer
"
"io.netty.util.concurrent.SingleThreadEventExecutor
"
"io.netty.util.NetUtilInitializations
"
org.graylog2.gelfclient.transport.GelfTcpTransport
"io.netty.util.NetUtil
"
"io.netty.util.concurrent.DefaultPromise.rejectedExecution
"
io.netty.util.internal.CleanerJava6
"io.netty.util.ResourceLeakDetector
"
"io.netty.buffer.PooledByteBufAllocator
"
"io.netty.util.internal.MacAddressUtil
"
"io.netty.util.internal.SystemPropertyUtil
"
"io.netty.util.Recycler
"
"io.netty.channel.ChannelOutboundBuffer
"
"io.netty.util.concurrent.DefaultPromise
"
"io.netty.bootstrap.Bootstrap
"
"io.netty.resolver.AddressResolverGroup
"
"io.netty.buffer.ByteBufUtil
"
"io.netty.buffer.PoolThreadCache
"
org.graylog.integrations.s3.S3EventProcessor
"io.netty.util.ReferenceCountUtil
"
"io.netty.channel.nio.NioEventLoop
"
org.graylog.integrations.s3.S3ScannerFactory
"io.netty.util.ResourceLeakDetectorFactory
"
org.graylog.integrations.s3.GraylogS3Function
org.graylog.integrations.s3.ProtocolType
org.graylog.integrations.s3.ContentType
"io.netty.util.internal.logging.InternalLoggerFactory
"
"io.netty.channel.DefaultChannelPipeline
"
"io.netty.channel.ChannelHandlerMask
"
2023-03-14 06:45:55 d6e85b8b-e151-45c3-826c-eb5c1a5938c3 INFO  GraylogS3Function:65 - Log level is now set to [DEBUG].
"2023-03-14 06:45:55 d6e85b8b-e151-45c3-826c-eb5c1a5938c3 DEBUG GraylogS3Function:37 - Configuration{, graylogHost='xxx.xx.xx.xxx', graylogPort=12201, connectTimeout=10000, reconnectDelay=10000, tcpKeepAlive=true, tcpNoDelay=true, queueSize=4, maxInflightSends=512, contentType='text/plain', compressionType='none', protocolType='tcp', messageFields='[]', messageSummaryFields='[ClientRequestHost, ClientRequestPath, OriginIP, ClientSrcPort, EdgeServerIP, EdgeResponseBytes]'}"
2023-03-14 06:45:56 d6e85b8b-e151-45c3-826c-eb5c1a5938c3 INFO  S3EventProcessor:45 - Reading object [prod-company-integration-webhooks-functionF19B1A04-8zoCVNRl0Zsn/2023/03/14/06-45-54-692438.log] from bucket [integration-webhooks-logs]
"2023-03-14 06:45:56 d6e85b8b-e151-45c3-826c-eb5c1a5938c3 DEBUG AbstractGelfTransport:94 - Sending message: GelfMessage{version=""1.1"" timestamp=""1678776356.731"" short_message=""[{'time': '2023-03-14T06:44:54.813Z', 'type': 'platform.start', 'record': {'requestId': 'a80f2222-c2fd-411d-9ac0-324ed2af8997', 'version': '8'}}, {'time': '2023-03-14T06:44:54.828Z', 'type': 'function', 'record': '{""request_id"": null, ""levelname"": ""INFO"", ""name"": ""company.webhook_router.handler"", ""module"": ""handler"", ""lineno"": 97, ""message"": ""Health check PASSED"", ""timestamp"": ""2023-03-14T06:44:54.814409+00:00""}
'}, {'time': '2023-03-14T06:44:55.098Z', 'type': 'platform.end', 'record': {'requestId': 'a80f2222-c2fd-411d-9ac0-324ed2af8997'}}, {'time': '2023-03-14T06:44:55.098Z', 'type': 'platform.report', 'record': {'requestId': 'a80f2222-c2fd-411d-9ac0-324ed2af8997', 'metrics': {'durationMs': 284.761, 'billedDurationMs': 285, 'memorySizeMB': 128, 'maxMemoryUsedMB': 113}}}]"", level=""ALERT(1)""}"
2023-03-14 06:45:56 d6e85b8b-e151-45c3-826c-eb5c1a5938c3 INFO  S3EventProcessor:94 - Sent [1] messages.
2023-03-14 06:45:56 d6e85b8b-e151-45c3-826c-eb5c1a5938c3 DEBUG S3EventProcessor:51 - Waiting up to [100ms] with [10] retries while waiting for transport shutdown to occur.
2023-03-14 06:45:56 d6e85b8b-e151-45c3-826c-eb5c1a5938c3 DEBUG GelfSenderThread:156 - Attempting to flush messages in [100/MILLISECONDS] with [10] retries
"2023-03-14 06:45:56 d6e85b8b-e151-45c3-826c-eb5c1a5938c3 DEBUG GelfSenderThread:164 - Flushing in progress. [1] messages are still enqueued, and [0] messages are still in-flight."
"2023-03-14 06:45:56 d6e85b8b-e151-45c3-826c-eb5c1a5938c3 DEBUG GelfSenderThread:164 - Flushing in progress. [1] messages are still enqueued, and [0] messages are still in-flight."
"2023-03-14 06:45:56 d6e85b8b-e151-45c3-826c-eb5c1a5938c3 DEBUG GelfSenderThread:164 - Flushing in progress. [1] messages are still enqueued, and [0] messages are still in-flight."
"2023-03-14 06:45:57 d6e85b8b-e151-45c3-826c-eb5c1a5938c3 DEBUG GelfSenderThread:164 - Flushing in progress. [1] messages are still enqueued, and [0] messages are still in-flight."
"2023-03-14 06:45:57 d6e85b8b-e151-45c3-826c-eb5c1a5938c3 DEBUG GelfSenderThread:164 - Flushing in progress. [1] messages are still enqueued, and [0] messages are still in-flight."
"2023-03-14 06:45:57 d6e85b8b-e151-45c3-826c-eb5c1a5938c3 DEBUG GelfSenderThread:164 - Flushing in progress. [1] messages are still enqueued, and [0] messages are still in-flight."
"2023-03-14 06:45:57 d6e85b8b-e151-45c3-826c-eb5c1a5938c3 DEBUG GelfSenderThread:164 - Flushing in progress. [1] messages are still enqueued, and [0] messages are still in-flight."
"2023-03-14 06:45:57 d6e85b8b-e151-45c3-826c-eb5c1a5938c3 DEBUG GelfSenderThread:164 - Flushing in progress. [1] messages are still enqueued, and [0] messages are still in-flight."
"2023-03-14 06:45:57 d6e85b8b-e151-45c3-826c-eb5c1a5938c3 DEBUG GelfSenderThread:164 - Flushing in progress. [1] messages are still enqueued, and [0] messages are still in-flight."
"2023-03-14 06:45:57 d6e85b8b-e151-45c3-826c-eb5c1a5938c3 DEBUG GelfSenderThread:164 - Flushing in progress. [1] messages are still enqueued, and [0] messages are still in-flight."
"2023-03-14 06:45:57 d6e85b8b-e151-45c3-826c-eb5c1a5938c3 DEBUG GelfSenderThread:164 - Flushing in progress. [1] messages are still enqueued, and [0] messages are still in-flight."
2023-03-14 06:45:57 d6e85b8b-e151-45c3-826c-eb5c1a5938c3 ERROR GelfSenderThread:175 - Failed to flush messages in [10] attempts. Shutting down anyway.
2023-03-14 06:45:57 d6e85b8b-e151-45c3-826c-eb5c1a5938c3 DEBUG S3EventProcessor:55 - Transport shutdown complete.
2023-03-14 06:45:57 d6e85b8b-e151-45c3-826c-eb5c1a5938c3 INFO  GraylogS3Function:42 - Processed [1] S3 events.
END RequestId: d6e85b8b-e151-45c3-826c-eb5c1a5938c3
REPORT RequestId: d6e85b8b-e151-45c3-826c-eb5c1a5938c3	Duration: 1882.47 ms	Billed Duration: 1883 ms	Memory Size: 512 MB	Max Memory Used: 116 MB

Ngôn ngữ chính: Java
Star: 13
Fork: 6
Chỉ số merge pull request: Không có pull request nào được merge trong 30 ngày

Chuẩn bị môi trường

Không có Dockerfile hay tệp Docker Compose
Không có mẫu pull request
Đọc hướng dẫn đóng góp

Bắt đầu từ đâu

Đọc hết issue, rồi đọc hướng dẫn đóng góp của dự án.
Bình luận trên issue rằng bạn sẽ nhận — tránh hai người làm cùng một việc.
Fork repository và làm thay đổi trên một nhánh.
Mở pull request có tham chiếu số hiệu của issue.

Issue khác của Graylog2/graylog-s3-lambda

Safer - Compatible Updates to Fix Vulnerable Dependencies
Đang mở
- Có gì không ổn?
Độ khó 5/5 Hơn một tuần Mức phù hợp với người mới 18/100

Graylog2/graylog-s3-lambda#44 · Mở ngày 16/7/2025
Current release causes excessive timeouts
Đang mở
- Có gì không ổn?
triaged

Độ khó 4/5 3-5 ngày Mức phù hợp với người mới 25/100

Graylog2/graylog-s3-lambda#38 · 20 bình luận · Mở ngày 19/1/2022
Automate graylog-s3-lambda releases
Đang mở
- Có gì không ổn?
triaged

Độ khó 4/5 3-5 ngày Mức phù hợp với người mới 35/100

Graylog2/graylog-s3-lambda#28 · 1 bình luận · Mở ngày 13/12/2021
Increased memory usage on the Amazon Corretto runtime
Đang mở
- Có gì không ổn?
triaged

Độ khó 4/5 3-5 ngày Mức phù hợp với người mới 35/100

Graylog2/graylog-s3-lambda#23 · 3 bình luận · Mở ngày 7/7/2021
Cloudflare IP fields are set as string instead of IP
Đang mở
- Có gì không ổn?
feature triaged

Độ khó 3/5 1-2 ngày Mức phù hợp với người mới 42/100

Graylog2/graylog-s3-lambda#21 · 1 bình luận · Mở ngày 17/6/2021

Tất cả issue của Graylog2/graylog-s3-lambda

Issue tương tự

Unit tests: replace explicit `any` with real types in No-code block utils
Đang mở
- Có gì không ổn?
area/frontend good first issue kind/cooldown

Độ khó 2/5 1-3 giờ Mức phù hợp với người mới 78/100

kestra-io/kestra#20061 · Mở ngày 1/10/2026

Maintainer thường phản hồi trong vòng 1 ngày
[launcher] Warn when TORNADOVM_HOME and TORNADO_SDK point to different SDKs
Đang mở
- Có gì không ổn?
Độ khó 2/5 1-3 giờ Mức phù hợp với người mới 84/100

beehive-lab/TornadoVM#1151 · Mở ngày 30/9/2026

Maintainer thường phản hồi trong vòng 1 ngày
TestOs ignores a locally built sqllogictest library when the checkout path contains a target directory
Đang mở
- Có gì không ổn?
Độ khó 2/5 1-3 giờ Mức phù hợp với người mới 88/100

questdb/questdb#7696 · Mở ngày 30/9/2026

Maintainer thường phản hồi trong vòng 1 ngày
(cbor) `maxStringLength` not consistently checked for chunked (indefinite-length) text values
Đang mở
- Có gì không ổn?
Độ khó 2/5 1-3 giờ Mức phù hợp với người mới 77/100

FasterXML/jackson-dataformats-binary#823 · Mở ngày 30/9/2026

Maintainer thường phản hồi trong vòng 1 ngày
Add example and comments for the profile HMAC configuration
Đang mở
- Có gì không ổn?
Độ khó 1/5 Dưới một giờ Mức phù hợp với người mới 90/100

networknt/light-4j#2806 · Mở ngày 30/9/2026

Maintainer thường phản hồi trong vòng 1 ngày

Thêm issue về Java

Messages not being flushed from queue on subsequent runs

Có gì không ổn?

Đánh giá

Hướng nghiên cứu

Mô tả

Chuẩn bị môi trường

Bắt đầu từ đâu

Issue khác của Graylog2/graylog-s3-lambda

Có gì không ổn?

Có gì không ổn?

Có gì không ổn?

Có gì không ổn?

Có gì không ổn?

Issue tương tự

Có gì không ổn?

Có gì không ổn?

Có gì không ổn?

Có gì không ổn?

Có gì không ổn?

Nhận issue mới trong hộp thư của bạn