search

Graylog2 / graylog-s3-lambda

An AWS Lambda function that reads logs from S3 and sends them to Graylog
GNU General Public License v3.0
12 stars 6 forks source link

Fix Errors In processing Logs from CloudFlare #9

Closed bud1979 closed 4 years ago

bud1979 commented 4 years ago

Currently Getting Errors, while processing logs, resulting in the whole log file not being imported.

Errors are:

graylog.txt

Next Steps:

  1. Set up a lab environment where CloudFlare can be tested (Lambda function, EC2 instance running Graylog).
  2. Generate Logs to see if issue can be replicated
  3. Use customer supplied logs to see if related to specific log issue
waab76 commented 4 years ago

Successfully recreated the issue. It is due to a ClassCastException as documented in PR.

lingpri commented 4 years ago

@waab76 - Great work. I'm wondering, if the fix, addresses the warning in the graylog.txt

1581694332542,"WARNING: Not all bytes were read from the S3ObjectInputStream, aborting HTTP connection. This is likely an error and may result in sub-optimal behavior. Request only the bytes you need via a ranged GET or drain the input stream after use."

Also, how does your trace of logs looks like, after the fix, when you test in your lab environment ?

waab76 commented 4 years ago

The logs look like the following (trimmed some events from the middle):

START RequestId: c8646349-e8d0-4e51-876c-ab78438dcd46 Version: $LATEST

2020-03-11 20:53:17 c8646349-e8d0-4e51-876c-ab78438dcd46 INFO GraylogS3Function:87 - Log level is now set to [TRACE]. org.graylog.integrations.s3.codec.CodecProcessor org.graylog.integrations.s3.CompressionType com.github.joschi.jadconfig.JadConfig org.graylog.integrations.s3.GraylogS3Function org.graylog.integrations.s3.ProtocolType org.graylog.integrations.s3.ContentType

2020-03-11 20:53:17 c8646349-e8d0-4e51-876c-ab78438dcd46 DEBUG GraylogS3Function:59 - Configuration{, graylogHost='3.133.159.146', graylogPort=12201, connectTimeout=10000, reconnectDelay=10000, tcpKeepAlive=true, tcpNoDelay=true, queueSize=512, maxInflightSends=512, contentType='application/x.cloudflare.log', compressionType='gzip', protocolType='tcp', messageFields='[]', messageSummaryFields='[ClientRequestHost, ClientRequestPath, OriginIP, ClientSrcPort, EdgeServerIP, EdgeResponseBytes]'}

2020-03-11 20:53:21 c8646349-e8d0-4e51-876c-ab78438dcd46 DEBUG GraylogS3Function:107 - Graylog host: 3.133.159.146:12201

2020-03-11 20:53:21 c8646349-e8d0-4e51-876c-ab78438dcd46 DEBUG GraylogS3Function:109 - Attempting to read object [com.amazonaws.services.s3.event.S3EventNotification$S3Entity@78186a70] from S3.

2020-03-11 20:53:24 c8646349-e8d0-4e51-876c-ab78438dcd46 DEBUG GraylogS3Function:112 - Object read from S3 successfully.

2020-03-11 20:53:25 c8646349-e8d0-4e51-876c-ab78438dcd46 TRACE CodecProcessor:61 - Setting EdgeStartTimestamp timestamp [1.583452797E9].

2020-03-11 20:53:25 c8646349-e8d0-4e51-876c-ab78438dcd46 DEBUG CodecProcessor:115 - The value is: 1372000000

2020-03-11 20:53:25 c8646349-e8d0-4e51-876c-ab78438dcd46 TRACE CodecProcessor:37 - Message contains [57] fields.

2020-03-11 20:53:25 c8646349-e8d0-4e51-876c-ab78438dcd46 TRACE CodecProcessor:61 - Setting EdgeStartTimestamp timestamp [1.583452799E9].

2020-03-11 20:53:25 c8646349-e8d0-4e51-876c-ab78438dcd46 DEBUG CodecProcessor:115 - The value is: 0

2020-03-11 20:53:25 c8646349-e8d0-4e51-876c-ab78438dcd46 TRACE CodecProcessor:37 - Message contains [55] fields.

2020-03-11 20:53:25 c8646349-e8d0-4e51-876c-ab78438dcd46 TRACE CodecProcessor:61 - Setting EdgeStartTimestamp timestamp [1.583452801E9].

2020-03-11 20:53:25 c8646349-e8d0-4e51-876c-ab78438dcd46 DEBUG CodecProcessor:115 - The value is: 2324000000

2020-03-11 20:53:25 c8646349-e8d0-4e51-876c-ab78438dcd46 TRACE CodecProcessor:37 - Message contains [57] fields.

...

2020-03-11 20:53:32 c8646349-e8d0-4e51-876c-ab78438dcd46 DEBUG CodecProcessor:115 - The value is: 0

2020-03-11 20:53:32 c8646349-e8d0-4e51-876c-ab78438dcd46 TRACE CodecProcessor:37 - Message contains [56] fields.

2020-03-11 20:53:32 c8646349-e8d0-4e51-876c-ab78438dcd46 TRACE CodecProcessor:61 - Setting EdgeStartTimestamp timestamp [1.583452886E9].

2020-03-11 20:53:32 c8646349-e8d0-4e51-876c-ab78438dcd46 DEBUG CodecProcessor:115 - The value is: 272000000

2020-03-11 20:53:32 c8646349-e8d0-4e51-876c-ab78438dcd46 TRACE CodecProcessor:37 - Message contains [57] fields.

2020-03-11 20:53:32 c8646349-e8d0-4e51-876c-ab78438dcd46 DEBUG GraylogS3Function:200 - Finished sending [592] messages.

2020-03-11 20:53:32 c8646349-e8d0-4e51-876c-ab78438dcd46 DEBUG GraylogS3Function:131 - Waiting up to [100ms] with [600] retries while waiting for transport shutdown to occur.

2020-03-11 20:53:32 INFO GelfTcpTransport:115 - Channel disconnected!

2020-03-11 20:53:42 ERROR GelfTcpTransport:138 - Connection failed: executor not accepting a task

2020-03-11 20:53:44 c8646349-e8d0-4e51-876c-ab78438dcd46 DEBUG GraylogS3Function:136 - Transport shutdown complete.

2020-03-11 20:53:44 c8646349-e8d0-4e51-876c-ab78438dcd46 INFO GraylogS3Function:64 - Processed [1] S3 records.

END RequestId: c8646349-e8d0-4e51-876c-ab78438dcd46

REPORT RequestId: c8646349-e8d0-4e51-876c-ab78438dcd46 Duration: 28142.79 ms Billed Duration: 28200 ms Memory Size: 512 MB Max Memory Used: 191 MB Init Duration: 1434.76 ms

I believe the previous WARNING message was being generated because the unexpected exception was causing the Lambda to terminate before reading the entire S3 object. Now that the exception is no longer an issue, the Lambda doesn't terminate and thus the whole S3 object is being processed.