Kafka errors

[ivocarvalho]

Hello.

Trying to deploy a new ManageIQ appliance on VMware.

After configuring networking I go do appliance_console and start the application configuration.

Database configuration works great, then I get the menu to configure Messaging and select 1:
1) Configure this appliance as a messaging server

After that I can select one of these options, so I choose N:

Stopping ManageIQ Server...
Configure Application

Installed file /opt/kafka/config/server.properties found.

Already configured on this Appliance, Un-Configure first? (Y/N): 

And continue:

Proceed with Configuration? (Y/N): y

Message Server Parameters:

Enter the Message Server Hostname or IP address: |manageiq.domain.com| 
Enter the Message Keystore Username: |admin| 
Enter the Message Keystore Password: ********
Configure a new persistent disk volume? (Y/N): n

Message Server Configuration:
Message Server Details:
    Message Server Hostname: manageiq.domain.com
  Message Keystore Username: admin

Proceed? (Y/N): y
Checking connectivity to manageiq.domain.com ... 
Succeeded.
Create Jaas Config
Create Client Properties
Create Logs Directory
Configure Firewall
Configure Keystore
Create Server Properties
Configure Messaging Yaml
Starting zookeeper and configure it to start on reboots ...
Starting kafka and configure it to start on reboots ...

Message Server configured successfully.

Starting ManageIQ Server...

This is where I'm stuck. Kafka service fails a few seconds later:

[root@manageiq ~]# systemctl status kafka
● kafka.service - kafka service
   Loaded: loaded (/usr/lib/systemd/system/kafka.service; enabled; vendor preset: disabled)
   Active: failed (Result: exit-code) since Tue 2024-08-06 18:03:31 WEST; 2min 19s ago
  Process: 14689 ExecStart=/opt/kafka/bin/kafka-server-start.sh /opt/kafka/config/server.properties (code=exited, status=1/FAILURE)
 Main PID: 14689 (code=exited, status=1/FAILURE)

Aug 06 18:03:31 manageiq.domain.com systemd[1]: kafka.service: Failed with result 'exit-code'.
Aug 06 18:03:31 manageiq.domain.com systemd[1]: kafka.service: Service RestartSec=100ms expired, scheduling restart.
Aug 06 18:03:31 manageiq.domain.com systemd[1]: kafka.service: Scheduled restart job, restart counter is at 11.
Aug 06 18:03:31 manageiq.domain.com systemd[1]: Stopped kafka service.
Aug 06 18:03:31 manageiq.domain.com systemd[1]: kafka.service: Start request repeated too quickly.
Aug 06 18:03:31 manageiq.domain.com systemd[1]: kafka.service: Failed with result 'exit-code'.
Aug 06 18:03:31 manageiq.domain.com systemd[1]: Failed to start kafka service.

Checking Kafka logs:

[2024-08-06 18:03:30,751] INFO Registered kafka:type=kafka.Log4jController MBean (kafka.utils.Log4jControllerRegistration$)
[2024-08-06 18:03:31,077] INFO Setting -D jdk.tls.rejectClientInitiatedRenegotiation=true to disable client-initiated TLS renegotiation (org.apache.zookeeper.common.X509Util)
[2024-08-06 18:03:31,176] ERROR Exiting Kafka due to fatal exception (kafka.Kafka$)
org.apache.kafka.common.KafkaException: Exception while loading Zookeeper JAAS login context [java.security.auth.login.config=/opt/kafka/config/kafka_server_jaas.conf, zookeeper.sasl.client=default:true, zookeeper.sasl.clientconfig=default:Client]
        at org.apache.kafka.common.security.JaasUtils.isZkSaslEnabled(JaasUtils.java:67)
        at kafka.server.KafkaServer$.zkClientConfigFromKafkaConfig(KafkaServer.scala:80)
        at kafka.server.KafkaServer.<init>(KafkaServer.scala:150)
        at kafka.Kafka$.buildServer(Kafka.scala:73)
        at kafka.Kafka$.main(Kafka.scala:87)
        at kafka.Kafka.main(Kafka.scala)
Caused by: java.lang.SecurityException: java.io.IOException: Configuration Error:
        Line 4: expected [option key], found [null]
        at sun.security.provider.ConfigFile$Spi.<init>(ConfigFile.java:137)
        at sun.security.provider.ConfigFile.<init>(ConfigFile.java:102)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
        at java.lang.Class.newInstance(Class.java:442)
        at javax.security.auth.login.Configuration$2.run(Configuration.java:255)
        at javax.security.auth.login.Configuration$2.run(Configuration.java:247)
        at java.security.AccessController.doPrivileged(Native Method)
        at javax.security.auth.login.Configuration.getConfiguration(Configuration.java:246)
        at org.apache.kafka.common.security.JaasUtils.isZkSaslEnabled(JaasUtils.java:63)
        ... 5 more
Caused by: java.io.IOException: Configuration Error:
        Line 4: expected [option key], found [null]
        at sun.security.provider.ConfigFile$Spi.ioException(ConfigFile.java:666)
        at sun.security.provider.ConfigFile$Spi.match(ConfigFile.java:579)
        at sun.security.provider.ConfigFile$Spi.parseLoginEntry(ConfigFile.java:477)
        at sun.security.provider.ConfigFile$Spi.readConfig(ConfigFile.java:427)
        at sun.security.provider.ConfigFile$Spi.init(ConfigFile.java:329)
        at sun.security.provider.ConfigFile$Spi.init(ConfigFile.java:271)
        at sun.security.provider.ConfigFile$Spi.<init>(ConfigFile.java:135)
        ... 16 more

No idea where to go from here.
Any help would be great.

Thanks!

[Fryguy]

@nasark Can you help out here?

[nasark]

@ivocarvalho The error suggests that there may be a nil value in the config:

Caused by: java.lang.SecurityException: java.io.IOException: Configuration Error:
        Line 4: expected [option key], found [null]

Can you try outputting the messaging config to see if all the relevant values are present? It should look something like this:

[root@nasark2 ~]# cat /var/www/miq/vmdb/config/messaging.yml 
---
base:
  host: localhost
  port: 9092
  protocol: Kafka
  encoding: json
  username: admin
  password: smartvm
development:
  host: localhost
  port: 9092
  protocol: Kafka
  encoding: json
  username: admin
  password: smartvm
production:
  host: <host>
  port: 9093
  protocol: Kafka
  encoding: json
  username: admin
  password: <password>
  ssl: true
  ca_file: "/opt/kafka/config/keystore/ca-cert"
test:
  host: localhost
  port: 9092
  protocol: Kafka
  encoding: json
  username: admin
  password: smartvm

[nasark]

@ivocarvalho @mschmitt-nasuni Can you provide your build? cat /var/www/miq/vmdb/BUILD
I can try to reproduce

[mschmitt-nasuni]

@nasark

[root@itmiq001 ~]# cat /var/www/miq/vmdb/BUILD 
20240402225756_f6add08

[ivocarvalho]

Same build as @mschmitt-nasuni here.

[root@manageiq ~]# cat /var/www/miq/vmdb/BUILD
20240402225756_f6add08

[mschmitt-nasuni]

I found another discussion from a few weeks ago talking about this same thing:

https://github.com/orgs/ManageIQ/discussions/23068

There, @erwinb3 stated he got it to work by using smartvm as the password at every password prompt, and even doing passwd root and setting that to smartvm as well.

I tried this, and using the same .ova as before, did a fresh deployment, ssh'd in, changed the password initially, then changed it back to smartvm, ran appliance_console, and went through the whole setup same as before, except putting in smartvm for the password whenever a password was needed.

This time, it worked. The server started up and kafka did not crash.

I would like to be able to use a more secure server, database, and messaging password, but this gets me around the initial hurdle at least...

[ivocarvalho]

Confirmed, set all passwords to smartvm and the server started.
Thanks for the tip.

[natemontgomery]

So, I did some digging around the JKS password and found that docs for the lib imply that it supports ASCII characters for its passwords. This would include # for example, even in strict 7-bit ASCII mode. The results of the discussion up to now have mostly been to restrict the password entry to a-z and $ and *, which I think works as a short-term fix but does not solve what seems to be a mismatch in the password handling that should be allowed for JKS. From a bit more digging around in the appliance console I noticed a couple things.

The HighLine version used for the prompt code is a bit outdated (2 years old), gemspec uses v2.1 vs newest of v3.1, could be worth updating to a newer version. I have not found any 'smoking gun' evidence that the HighLine version would resolve any bad ASCII characters, so I think this is more of a side note.

I also noticed that there is no encoding set for these prompt configurations to output (not that HighLine documents anything needed for that) so I think the output strings will be in UTF-8. This seems like it should be ok to handle as ASCII being passed into the JKS (ie 'foo#'.force_encoding('ASCII') is still 'foo#') side but I wonder if there may be some encoding shenanigans to blame for the odd password behavior. Mostly just a thought right now as I have not done enough experimenting to see what could really go wrong here but it seems worth noting at least.

Would be glad to help troubleshoot if desired, I stopped at the point of testing out that HighLine returns UTF-8 string and trying out some encoding changes, but I have not tried anything to do with the JKS setup.