search

confluentinc / ksql

The database purpose-built for stream processing applications.
https://ksqldb.io
Other
119 stars 1.04k forks source link

ksqldb Server provides no stdout message when configured to an unavailable Kafka cluster #4712

Open rspurgeon opened 4 years ago

rspurgeon commented 4 years ago

Description When starting ksqlDB via bin/ksql-server config/ksql-server.properties as documented, and the Kafka broker is unreachable for any reason, ksqlDB will print minimal log4j 'headers', hang for a significant period of time, then the process will die with no meaningful debugging output.

To Reproduce

  1. build from source with master as of 10am CST, 3/5/2020
  2. Configure ksql to attempt to connect to an invalid broker, for instance in config/ksql-server.properties, set bootstrap.servers=localhost:12345, where localhost:12345 is a non-existent kafka broker.
  3. run ksqldb with ./bin/ksql-server config/ksql-server.properties (not in daemon mode to see the loggign)
  4. Observe no meaningful debugging information as the server hangs
  5. Observe the server process terminate without details on the failure

Expected behavior I would expect to see logging output to indicate that ksqlDB is attempting and unable to connect to a valid broker.

Actual behaviour

10:08:27 in ksql on  master [!] took 6s
[I] ➜ cat config/ksql-server.properties| grep bootstrap
# The set of Kafka brokers to bootstrap Kafka cluster information from:
bootstrap.servers=localhost:12345

10:08:30 in ksql on  master [!]
[I] ➜ telnet localhost 12345
Trying ::1...
telnet: connect to address ::1: Connection refused
Trying 127.0.0.1...
telnet: connect to address 127.0.0.1: Connection refused
telnet: Unable to connect to remote host

10:08:37 in ksql on  master [!]
[I] ➜ ./bin/ksql-server-start config/ksql-server.properties
SLF4J: A number (108) of logging calls during the initialization phase have been intercepted and are
SLF4J: now being replayed. These are subject to the filtering rules of the underlying logging system.
SLF4J: See also http://www.slf4j.org/codes.html#replay

10:09:44 in ksql on  master [!] took 1m 3s
[I] ➜
colinhicks commented 4 years ago

By default, ksql-server-start configures log4j with the config/log4j-rolling.properties file, which writes output to ${ksql.log.dir}/ksql.log.

To access the logging you're after, you can use:

In both cases, the expected output for the invalid broker scenario should log: [2020-03-06 08:06:26,774] WARN [AdminClient clientId=adminclient-1] Connection to node -1 (localhost/127.0.0.1:9092) could not be established. Broker may not be available. (org.apache.kafka.clients.NetworkClient:762)

@rspurgeon could you point to the documentation you were looking at? We can clarify the behavior there.

colinhicks commented 4 years ago

Oh, I remembered you referenced CONTRIBUTING.md in the #ksqldb-dev community slack thread. There is a relevant line there:

Check the logs folder for the log files that the server writes including any errors.

Do you have any suggestions for making this stand out more?

rspurgeon commented 4 years ago

@colinhicks Thanks, I see that log now. I changed the title of this issue and removed the bug label and changed it to a UX issue instead. IMO we would want to show a runner of the service on the CLI a message that broker connection failed.