grafana / loki

Like Prometheus, but for logs.
https://grafana.com/loki
GNU Affero General Public License v3.0
23.28k stars 3.37k forks source link

Multiline logs: like java exception loki responds error="server returned HTTP status 400 Bad Request (400): stream #6149

Open prashnatgthorat opened 2 years ago

prashnatgthorat commented 2 years ago

I am new to explore and working on log ingestor.

While sending multiline log event to Loki throws response "msg="final error sending batch" status=400 error="server returned HTTP status 400 Bad Request (400):"

if i reduce max_lines to 15 then it is working perfectly, but if increased max_lines to greater than 15 (defualt : 180) then it throws Bad request error

Below is configuration of promtail and loki.

Promtail Conf :

server: http_listen_port: 9080 grpc_listen_port: 0 grpc_server_max_recv_msg_size : 104857600 grpc_server_max_send_msg_size : 104857600 log_level: debug positions: filename: D:/GrafanaLabs/promtail-windows-amd64/positions.yaml

clients:

scrape_configs:

Loki Conf :

auth_enabled: false

server: http_listen_port: 3100 grpc_listen_port: 9096 log_level: debug query_range: parallelise_shardable_queries: true querier: max_concurrent: 20 frontend: address: 127.0.0.1

common: path_prefix: D:/GrafanaLabs/loki-windows-amd64/loki storage: filesystem: chunks_directory: D:/GrafanaLabs/loki-windows-amd64/loki/chunks rules_directory: D:/GrafanaLabs/loki-windows-amd64/loki/rules replication_factor: 1 ring: instance_addr: 127.0.0.1 kvstore: store: inmemory ingester: lifecycler: address: 127.0.0.1 ring: kvstore: store: inmemory replication_factor: 1 final_sleep: 0s chunk_idle_period: 1h # Any chunk not receiving new logs in this time will be flushed max_chunk_age: 1h # All chunks will be flushed when they hit this age, default is 1h chunk_target_size: 1048576 # Loki will attempt to build chunks up to 1.5MB, flushing first if chunk_idle_period or max_chunk_age is reached first chunk_retain_period: 30s # Must be greater than index read cache TTL if using an index cache (Default index read cache TTL is 5m) max_returned_stream_errors: 0 max_transfer_retries: 0 # Chunk transfers disabled

schema_config: configs:

ruler: alertmanager_url: http://localhost:9093

Log Event :

13-04-2022 11:56:47.753 [org.springframework.amqp.rabbit.RabbitListenerEndpointContainer#0-16] [myapp, , ] ERROR o.s.a.r.l.SimpleMessageListenerContainer.redeclareElementsIfNecessary - Failed to check/redeclare auto-delete queue(s). org.springframework.amqp.AmqpConnectException: java.net.ConnectException: Connection refused: connect at org.springframework.amqp.rabbit.support.RabbitExceptionTranslator.convertRabbitAccessException(RabbitExceptionTranslator.java:61) at org.springframework.amqp.rabbit.connection.AbstractConnectionFactory.createBareConnection(AbstractConnectionFactory.java:524) at org.springframework.amqp.rabbit.connection.CachingConnectionFactory.createConnection(CachingConnectionFactory.java:751) at org.springframework.amqp.rabbit.connection.ConnectionFactoryUtils.createConnection(ConnectionFactoryUtils.java:214) at org.springframework.amqp.rabbit.core.RabbitTemplate.doExecute(RabbitTemplate.java:2089) at org.springframework.amqp.rabbit.core.RabbitTemplate.execute(RabbitTemplate.java:2062) at org.springframework.amqp.rabbit.core.RabbitTemplate.execute(RabbitTemplate.java:2042) at org.springframework.amqp.rabbit.core.RabbitAdmin.getQueueInfo(RabbitAdmin.java:407) at org.springframework.amqp.rabbit.core.RabbitAdmin.getQueueProperties(RabbitAdmin.java:391) at org.springframework.amqp.rabbit.listener.AbstractMessageListenerContainer.attemptDeclarations(AbstractMessageListenerContainer.java:1842) at org.springframework.amqp.rabbit.listener.AbstractMessageListenerContainer.redeclareElementsIfNecessary(AbstractMessageListenerContainer.java:1823) at org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer$AsyncMessageProcessingConsumer.initialize(SimpleMessageListenerContainer.java:1354) at org.springframework.amqp.rabbit.listener.SimpleMessageListenerContainer$AsyncMessageProcessingConsumer.run(SimpleMessageListenerContainer.java:1200) at java.base/java.lang.Thread.run(Thread.java:834) Caused by: java.net.ConnectException: Connection refused: connect at java.base/java.net.PlainSocketImpl.waitForConnect(Native Method) at java.base/java.net.PlainSocketImpl.socketConnect(PlainSocketImpl.java:107) at java.base/java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:399) at java.base/java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:242) at java.base/java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:224) at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:403) at java.base/java.net.Socket.connect(Socket.java:591) at com.rabbitmq.client.impl.SocketFrameHandlerFactory.create(SocketFrameHandlerFactory.java:60) at com.rabbitmq.client.ConnectionFactory.newConnection(ConnectionFactory.java:1137) at com.rabbitmq.client.ConnectionFactory.newConnection(ConnectionFactory.java:1087) at com.rabbitmq.client.ConnectionFactory.newConnection(ConnectionFactory.java:1255) at org.springframework.amqp.rabbit.connection.AbstractConnectionFactory.connectHostPort(AbstractConnectionFactory.java:569) at org.springframework.amqp.rabbit.connection.AbstractConnectionFactory.connect(AbstractConnectionFactory.java:536) at org.springframework.amqp.rabbit.connection.AbstractConnectionFactory.createBareConnection(AbstractConnectionFactory.java:487)

Error Log in Promtail Console

level=error ts=2022-05-12T06:42:23.5535705Z caller=client.go:360 component=client host=localhost:3100 msg="final error sending batch" status=400 error="server returned HTTP status 400 Bad Request (400): stream '{filename=\"D:/logs/log1.log\", job=\"applog\", msg=\"[myapp, , ] ERROR o.s.a.r.l.SimpleMessageListenerContainer.redeclareElementsIfNecessary - Failed to check/redeclare auto-delete queue(s).\rorg.springframework.amqp.AmqpConnectException: java.net.ConnectException: Connection refused: connect\r\tat org.springframework.amqp.rabbit.support.RabbitExceptionTranslator.convertRabbitAccessException(RabbitExceptionTranslator.java:61)\r\tat org.springframework.amqp.rabbit.connection.AbstractConnectionFactory.createBareConnection(AbstractConnectionFactory.java:524)\r\tat org.springframework.amqp.rabbit.connection.CachingConnectionFactory.createConnection(CachingConnectionFactory.java:751)\r\tat org.springframework.amqp.rabbit.connection.ConnectionFactoryUtils.createConnection(ConnectionFactoryUtils.java:214)\r\tat org.springframework.amqp.rabbit.core.RabbitTemplate.doExecute(RabbitTemplate.java:2089)\r\tat org.springframework.amqp.rabbit.core.RabbitTemplate.execute(Rabb"

hmrks commented 2 years ago

Hi @prashnatgthorat!

I had the same issue as you and found out the root cause.

Turns out the issue is not related to the multiline configuration at all, but the size of the msg label which is being rejected by Loki. You could create a single line message with the same size (and even the same content), and you would get the very same error message.

The issue can be resolved by setting the max_label_value_length to a higher value (see the corresponding configuration settings for Loki), or using the output stage (link) and only send the value of the msg field as the log message and the rest as labels. Of course you would need to create named fields in the regex stage to achieve this.

output:
  source: msg

Better yet for Java, simply skip setting the log message as a label and that's it.

To be honest it is a bit unfortunate that neither Promtail nor Loki gives you a clear error message about this.

cstyan commented 10 months ago

@prashnatgthorat are you still seeing this issue?