[
https://issues.apache.org/jira/browse/KAFKA-13804?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Luke Chen updated KAFKA-13804:
------------------------------
Description:
Currently, when the broker hit exception during startup, we will first log the
exception, ex:
_ERROR [KafkaServer id=0] Fatal error during KafkaServer startup. Prepare to
shutdown (kafka.server.KafkaServer)_
_java.io.IOException: No space left on device_
And then go through the shutdown process, to close all the resources (i.e.
threads, sockets, metrics...), and in the end, output:
_[KafkaServer id=0] shut down completed (kafka.server.KafkaServer)_
_ERROR Exiting Kafka (kafka.Kafka$)_
Sometimes, during closing the resources, we will also hit some exceptions, or
waiting for some other dependencies close, and output many more logs. When we
tried to find out why the broker is shutdown from the log, we have to go
through many lines of logs from the tail, and skip some unrelated exceptions,
and then identify the specific reason why the broker shutting down.
We could improve it by adding the reason why the broker is shutting down during
startup at the end of log, something like this:
{code:java}
[2022-04-07 18:19:33,005] ERROR [KafkaServer id=0] Fatal error during
KafkaServer startup. Prepare to shutdown (kafka.server.KafkaServer)
java.io.IOException: No space left on device
at kafka.server.KafkaServer.startup(KafkaServer.scala:461)
at kafka.Kafka$.main(Kafka.scala:110)
at kafka.Kafka.main(Kafka.scala)
[2022-04-07 18:19:33,007] INFO [KafkaServer id=0] shutting down
(kafka.server.KafkaServer)
[2022-04-07 18:19:33,008] INFO [KafkaServer id=0] Starting controlled shutdown
(kafka.server.KafkaServer)
[2022-04-07 18:19:33,016] INFO [KafkaServer id=0] Controlled shutdown request
returned successfully after 6ms (kafka.server.KafkaServer)
....
[2022-04-07 18:19:33,227] INFO Broker and topic stats closed
(kafka.server.BrokerTopicStats)
[2022-04-07 18:19:33,227] INFO App info kafka.server for 0 unregistered
(org.apache.kafka.common.utils.AppInfoParser)
[2022-04-07 18:19:33,227] INFO [KafkaServer id=0] shut down completed
// updated log
[2022-04-11 15:06:27,405] ERROR Exiting Kafka due to fatal exception during
startup (kafka.Kafka$)
java.io.IOException: No space left on device
at kafka.server.KafkaServer.startup(KafkaServer.scala:461)
at kafka.Kafka$.main(Kafka.scala:110)
at kafka.Kafka.main(Kafka.scala){code}
was:
Currently, when the broker hit exception, or SIGINT signal received, we will
first log the exception (or the reason we started to shutdown) ex:
_ERROR [KafkaServer id=0] Fatal error during KafkaServer startup. Prepare to
shutdown (kafka.server.KafkaServer)_
_java.io.IOException: No space left on device_
And then go through the shutdown process, to close all the resources (i.e.
threads, sockets, metrics...), and in the end, output:
_[KafkaServer id=0] shut down completed (kafka.server.KafkaServer)_
Sometimes, during closing the resources, we will also hit some exceptions, or
waiting for some other dependencies close, and output many more logs. When we
tried to find out why the broker is shutdown from the log, we have to go
through many lines of logs from the tail, and skip some unrelated exceptions,
and then identify the specific reason why the broker shutting down.
We could improve it by adding the reason why the broker is shutting down at the
end of log, something like this:
{code:java}
[2022-04-07 18:19:33,005] ERROR [KafkaServer id=0] Fatal error during
KafkaServer startup. Prepare to shutdown (kafka.server.KafkaServer)
java.io.IOException: No space left on device
at kafka.server.KafkaServer.startup(KafkaServer.scala:461)
at kafka.Kafka$.main(Kafka.scala:110)
at kafka.Kafka.main(Kafka.scala)
[2022-04-07 18:19:33,007] INFO [KafkaServer id=0] shutting down
(kafka.server.KafkaServer)
[2022-04-07 18:19:33,008] INFO [KafkaServer id=0] Starting controlled shutdown
(kafka.server.KafkaServer)
[2022-04-07 18:19:33,016] INFO [KafkaServer id=0] Controlled shutdown request
returned successfully after 6ms (kafka.server.KafkaServer)
....
[2022-04-07 18:19:33,227] INFO Broker and topic stats closed
(kafka.server.BrokerTopicStats)
[2022-04-07 18:19:33,227] INFO App info kafka.server for 0 unregistered
(org.apache.kafka.common.utils.AppInfoParser)
[2022-04-07 18:19:33,227] INFO [KafkaServer id=0] shut down completed
// updated log
[2022-04-11 15:06:27,405] ERROR Exiting Kafka due to fatal exception
(kafka.Kafka$)
java.io.IOException: No space left on device
at kafka.server.KafkaServer.startup(KafkaServer.scala:461)
at kafka.Kafka$.main(Kafka.scala:110)
at kafka.Kafka.main(Kafka.scala){code}
> Log broker shutdown reason during startup at the end of log output
> ------------------------------------------------------------------
>
> Key: KAFKA-13804
> URL: https://issues.apache.org/jira/browse/KAFKA-13804
> Project: Kafka
> Issue Type: Improvement
> Components: core
> Reporter: Luke Chen
> Assignee: Luke Chen
> Priority: Major
>
> Currently, when the broker hit exception during startup, we will first log
> the exception, ex:
> _ERROR [KafkaServer id=0] Fatal error during KafkaServer startup. Prepare to
> shutdown (kafka.server.KafkaServer)_
> _java.io.IOException: No space left on device_
>
> And then go through the shutdown process, to close all the resources (i.e.
> threads, sockets, metrics...), and in the end, output:
> _[KafkaServer id=0] shut down completed (kafka.server.KafkaServer)_
> _ERROR Exiting Kafka (kafka.Kafka$)_
>
> Sometimes, during closing the resources, we will also hit some exceptions, or
> waiting for some other dependencies close, and output many more logs. When we
> tried to find out why the broker is shutdown from the log, we have to go
> through many lines of logs from the tail, and skip some unrelated exceptions,
> and then identify the specific reason why the broker shutting down.
> We could improve it by adding the reason why the broker is shutting down
> during startup at the end of log, something like this:
>
> {code:java}
> [2022-04-07 18:19:33,005] ERROR [KafkaServer id=0] Fatal error during
> KafkaServer startup. Prepare to shutdown (kafka.server.KafkaServer)
> java.io.IOException: No space left on device
> at kafka.server.KafkaServer.startup(KafkaServer.scala:461)
> at kafka.Kafka$.main(Kafka.scala:110)
> at kafka.Kafka.main(Kafka.scala)
> [2022-04-07 18:19:33,007] INFO [KafkaServer id=0] shutting down
> (kafka.server.KafkaServer)
> [2022-04-07 18:19:33,008] INFO [KafkaServer id=0] Starting controlled
> shutdown (kafka.server.KafkaServer)
> [2022-04-07 18:19:33,016] INFO [KafkaServer id=0] Controlled shutdown request
> returned successfully after 6ms (kafka.server.KafkaServer)
> ....
> [2022-04-07 18:19:33,227] INFO Broker and topic stats closed
> (kafka.server.BrokerTopicStats)
> [2022-04-07 18:19:33,227] INFO App info kafka.server for 0 unregistered
> (org.apache.kafka.common.utils.AppInfoParser)
> [2022-04-07 18:19:33,227] INFO [KafkaServer id=0] shut down completed
> // updated log
> [2022-04-11 15:06:27,405] ERROR Exiting Kafka due to fatal exception during
> startup (kafka.Kafka$)
> java.io.IOException: No space left on device
> at kafka.server.KafkaServer.startup(KafkaServer.scala:461)
> at kafka.Kafka$.main(Kafka.scala:110)
> at kafka.Kafka.main(Kafka.scala){code}
>
>
>
--
This message was sent by Atlassian Jira
(v8.20.1#820001)
