Messages not being flushed from queue on subsequent runs

オープン

#40 2023年3月14日に作成コメント 1 件リアクション 2 件担当者 0 名 GitHub で見る

まだ誰も着手していません。

評価

難易度: 4/5
見積もり時間: 3〜5日
初心者へのやさしさ: 32/100

issue の種類: バグ
明瞭さ: 説明が足りない
活発さ: 停滞
技術スタック: aws, java
領域: backend, cloud, observability-sre

調査の方向性

S3EventProcessor から始め、そのトランスポートライフサイクルを GelfSenderThread と GelfTcpTransport まで追跡し、提供された Lambda ログを使って最初の呼び出しと後続の呼び出しを比較します。TCP_QUEUE_SIZE と SHUTDOWN_FLUSH_RETRIES に関連するキューおよびシャットダウンの動作を確認します。後続の実行でメッセージが Graylog に配信され、トランスポートライフサイクルが失われなければ完了です。

索引モデルが issue の本文から書いたものです。

説明

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

主要言語: Java
スター: 13
フォーク: 6
PR マージ指標: 30日以内にマージされた PR はありません

環境構築

Dockerfile・Docker Compose ファイルなし
プルリクエストのテンプレートなし
コントリビューションガイドを読む

はじめの一歩

issue を最後まで読み、次にプロジェクトのコントリビューションガイドを読みます。
着手することを issue にコメントします — 二人が同じ作業をするのを防げます。
リポジトリをフォークし、ブランチを切って変更します。
issue 番号を参照したプルリクエストを送ります。

Graylog2/graylog-s3-lambda のほかの issue

Safer - Compatible Updates to Fix Vulnerable Dependencies
オープン
- 何か問題がありますか？
難易度 5/5 1週間以上初心者へのやさしさ 18/100

Graylog2/graylog-s3-lambda#44 · 2025年7月16日に作成
Current release causes excessive timeouts
オープン
- 何か問題がありますか？
triaged

難易度 4/5 3〜5日初心者へのやさしさ 25/100

Graylog2/graylog-s3-lambda#38 · コメント 20 件 · 2022年1月19日に作成
Automate graylog-s3-lambda releases
オープン
- 何か問題がありますか？
triaged

難易度 4/5 3〜5日初心者へのやさしさ 35/100

Graylog2/graylog-s3-lambda#28 · コメント 1 件 · 2021年12月13日に作成
Increased memory usage on the Amazon Corretto runtime
オープン
- 何か問題がありますか？
triaged

難易度 4/5 3〜5日初心者へのやさしさ 35/100

Graylog2/graylog-s3-lambda#23 · コメント 3 件 · 2021年7月7日に作成
Cloudflare IP fields are set as string instead of IP
オープン
- 何か問題がありますか？
feature triaged

難易度 3/5 1〜2日初心者へのやさしさ 42/100

Graylog2/graylog-s3-lambda#21 · コメント 1 件 · 2021年6月17日に作成

Graylog2/graylog-s3-lambda の issue をすべて見る

似ている issue

OllamaClient reports a partial token count as the total
オープン
- 何か問題がありますか？
難易度 2/5 1〜3時間初心者へのやさしさ 88/100

JetBrains/koog#2278 · 2026年9月30日に作成

メンテナーはふだん 1 日以内に返信
Flight SQL JDBC interval strings use the default locale for digits
オープン
- 何か問題がありますか？
難易度 1/5 1時間未満初心者へのやさしさ 88/100

apache/arrow-java#1311 · 2026年9月30日に作成

メンテナーはふだん 2 日以内に返信
`automated` visibility tokenized but not handled crashes the scan
オープン
- 何か問題がありますか？
bug triage

難易度 2/5 1〜3時間初心者へのやさしさ 85/100

integrated-application-development/sonar-delphi#471 · 2026年9月30日に作成
[Bug] BigDecimalBooleanConverter treats scaled one values as false
オープン
- 何か問題がありますか？
難易度 2/5 1〜3時間初心者へのやさしさ 88/100

apache/fesod#1150 · 2026年9月30日に作成

メンテナーはふだん 1 日以内に返信
🔒 [IBM OSPO Security Notification] — IBM/networking-java-sdk
オープン
- 何か問題がありますか？
security

難易度 2/5 1〜3時間初心者へのやさしさ 65/100

IBM/networking-java-sdk#204 · 2026年9月30日に作成

Java の issue をもっと見る

Messages not being flushed from queue on subsequent runs

何か問題がありますか？

評価

調査の方向性

説明

環境構築

はじめの一歩

Graylog2/graylog-s3-lambda のほかの issue

何か問題がありますか？

何か問題がありますか？

何か問題がありますか？

何か問題がありますか？

何か問題がありますか？

似ている issue

何か問題がありますか？

何か問題がありますか？

何か問題がありますか？

何か問題がありますか？

何か問題がありますか？

新しい issue をメールで受け取る