search

canonical / kafka-test-app

This is a Kafka Test app charm to be used to tests and load a Charmed Kafka Cluster
Apache License 2.0
0 stars 1 forks source link

Action start-process complains about topic_name value provided #9

Closed gustavosr98 closed 1 year ago

gustavosr98 commented 1 year ago

Steps to reproduce

➜  ~ date                  
lun 10 jul 2023 18:37:00 -05
➜  ~ juju run-action producer-app/0 start-process username=relation-10 password=oCLPVdhzUV95rhlLaktc1hNTplPmMJid servers=172.16.7.214:9093 topic_name=test-topic  
ERROR key "topic_name" must start and end with lowercase alphanumeric, and contain only lowercase alphanumeric and hyphens
➜  ~ juju run-action producer-app/0 start-process username=relation-10 password=oCLPVdhzUV95rhlLaktc1hNTplPmMJid servers=172.16.7.214:9093 topic_name=test      
ERROR key "topic_name" must start and end with lowercase alphanumeric, and contain only lowercase alphanumeric and hyphens
➜  ~ juju run-action producer-app/0 start-process username=relation-10 password=oCLPVdhzUV95rhlLaktc1hNTplPmMJid servers=172.16.7.214:9093
{}
ERROR validation failed: (root) : "topic_name" property is missing and required, given {"password":"oCLPVdhzUV95rhlLaktc1hNTplPmMJid","servers":"172.16.7.214:9093","username":"relation-10"}

Expected behavior

Not to complain about topic_name value provided

Versions

Juju CLI: 2.9.42 Juju Controller: 2.9.37 Charm revision: kafka-test-app 5/edge

$ juju status
Model  Controller     Cloud/Region   Version  SLA          Timestamp
kafka  felab-default  felab/default  2.9.37   unsupported  18:33:15-05:00

App                        Version  Status  Scale  Charm                      Channel        Rev  Exposed  Message
consumer-app                        active      1  kafka-test-app             edge             5  no       Topic test-topic enabled with process consumer
data-integrator                     active      1  data-integrator            latest/stable   11  no       
external-ca                         active      1  tls-certificates-operator  latest/edge     27  no       
kafka                               active      1  kafka                      3/stable       123  no       
producer-app                        active      1  kafka-test-app             edge             5  no       Topic test-topic enabled with process producer
tls-certificates-operator           active      1  tls-certificates-operator  latest/edge     27  no       
zookeeper                           active      3  zookeeper                  3/stable       100  no       

Unit                          Workload  Agent  Machine  Public address  Ports  Message
consumer-app/0*               active    idle   0/lxd/5  172.16.7.207           Topic test-topic enabled with process consumer
data-integrator/0*            active    idle   0        172.16.11.1            
external-ca/0*                active    idle   0/lxd/4  172.16.7.206           
kafka/0*                      active    idle   0        172.16.11.1            machine system settings are not optimal - see logs for info
producer-app/0*               active    idle   0/lxd/6  172.16.7.208           Topic test-topic enabled with process producer
tls-certificates-operator/0*  active    idle   0/lxd/0  172.16.7.234           
zookeeper/0                   active    idle   0/lxd/1  172.16.7.247           
zookeeper/1*                  active    idle   0/lxd/2  172.16.7.248           
zookeeper/2                   active    idle   0/lxd/3  172.16.7.246           

Machine  State    Address       Inst id              Series  AZ       Message
0        started  172.16.11.1   rynin                jammy   default  Deployed
0/lxd/0  started  172.16.7.234  juju-1b0be2-0-lxd-0  jammy   default  Container started
0/lxd/1  started  172.16.7.247  juju-1b0be2-0-lxd-1  jammy   default  Container started
0/lxd/2  started  172.16.7.248  juju-1b0be2-0-lxd-2  jammy   default  Container started
0/lxd/3  started  172.16.7.246  juju-1b0be2-0-lxd-3  jammy   default  Container started
0/lxd/4  started  172.16.7.206  juju-1b0be2-0-lxd-4  jammy   default  Container started
0/lxd/5  started  172.16.7.207  juju-1b0be2-0-lxd-5  jammy   default  Container started
0/lxd/6  started  172.16.7.208  juju-1b0be2-0-lxd-6  jammy   default  Container started

Log output

$ juju ssh producer-app/0 cat /var/log/juju/unit-producer-app-0.log
2023-07-10 23:10:29 INFO juju unit_agent.go:289 Starting unit workers for "producer-app/0"
2023-07-10 23:10:29 INFO juju.worker.apicaller connect.go:163 [d42ac9] "unit-producer-app-0" successfully connected to "172.16.7.24:17070"
2023-07-10 23:10:29 INFO juju.worker.apicaller connect.go:260 [d42ac9] password changed for "unit-producer-app-0"
2023-07-10 23:10:29 INFO juju.worker.apicaller connect.go:163 [d42ac9] "unit-producer-app-0" successfully connected to "172.16.7.24:17070"
2023-07-10 23:10:29 INFO juju.worker.migrationminion worker.go:142 migration phase is now: NONE
2023-07-10 23:10:29 INFO juju.worker.logger logger.go:120 logger worker started
2023-07-10 23:10:29 INFO juju.worker.upgrader upgrader.go:216 no waiter, upgrader is done
2023-07-10 23:10:29 ERROR juju.worker.meterstatus runner.go:91 error running "meter-status-changed": charm missing from disk
2023-07-10 23:10:29 INFO juju.worker.uniter uniter.go:326 unit "producer-app/0" started
2023-07-10 23:10:29 INFO juju.worker.uniter uniter.go:631 resuming charm install
2023-07-10 23:10:29 INFO juju.worker.uniter.charm bundles.go:78 downloading ch:amd64/jammy/kafka-test-app-5 from API server
2023-07-10 23:10:33 INFO juju.worker.uniter uniter.go:344 hooks are retried true
2023-07-10 23:10:33 INFO juju.worker.uniter.storage resolver.go:127 initial storage attachments ready
2023-07-10 23:10:33 INFO juju.worker.uniter resolver.go:149 found queued "install" hook
2023-07-10 23:10:34 INFO unit.producer-app/0.juju-log server.go:316 Running legacy hooks/install.
2023-07-10 23:10:35 INFO juju.worker.uniter.operation runhook.go:146 ran "install" hook (via hook dispatching script: dispatch)
2023-07-10 23:10:36 INFO juju.worker.uniter.operation runhook.go:146 ran "kafka-cluster-relation-created" hook (via hook dispatching script: dispatch)
2023-07-10 23:10:36 INFO juju.worker.uniter.operation runhook.go:146 ran "app-peers-relation-created" hook (via hook dispatching script: dispatch)
2023-07-10 23:10:36 INFO juju.worker.uniter resolver.go:149 found queued "leader-elected" hook
2023-07-10 23:10:37 INFO juju.worker.uniter.operation runhook.go:146 ran "leader-elected" hook (via hook dispatching script: dispatch)
2023-07-10 23:10:38 INFO unit.producer-app/0.juju-log server.go:316 Configuration changed to producer
2023-07-10 23:10:38 INFO juju.worker.uniter.operation runhook.go:146 ran "config-changed" hook (via hook dispatching script: dispatch)
2023-07-10 23:10:38 INFO juju.worker.uniter resolver.go:149 found queued "start" hook
2023-07-10 23:10:38 INFO unit.producer-app/0.juju-log server.go:316 Running legacy hooks/start.
2023-07-10 23:10:39 INFO juju.worker.uniter.operation runhook.go:146 ran "start" hook (via hook dispatching script: dispatch)
2023-07-10 23:10:40 INFO juju.worker.uniter.operation runhook.go:146 ran "kafka-cluster-relation-joined" hook (via hook dispatching script: dispatch)
2023-07-10 23:10:41 INFO juju.worker.uniter.operation runhook.go:146 ran "kafka-cluster-relation-changed" hook (via hook dispatching script: dispatch)
2023-07-10 23:10:59 INFO unit.producer-app/0.juju-log server.go:316 kafka-cluster:14: topic created at 2023-07-10 23:10:59.990700
2023-07-10 23:11:00 INFO unit.producer-app/0.juju-log server.go:316 kafka-cluster:14: Topic successfully created: test-topic with username: relation-14
2023-07-10 23:11:00 INFO juju.worker.uniter.operation runhook.go:146 ran "kafka-cluster-relation-changed" hook (via hook dispatching script: dispatch)
2023-07-10 23:11:00 INFO unit.producer-app/0.juju-log server.go:316 app-peers:12: Topic successfully created: test-topic with username: relation-14
2023-07-10 23:11:01 INFO juju.worker.uniter.operation runhook.go:146 ran "app-peers-relation-changed" hook (via hook dispatching script: dispatch)
2023-07-10 23:14:34 INFO unit.producer-app/0.juju-log server.go:316 Topic successfully created: test-topic with username: relation-14
2023-07-10 23:14:34 WARNING unit.producer-app/0.juju-log server.go:316 No relation: certificates
2023-07-10 23:14:34 INFO juju.worker.uniter.operation runhook.go:146 ran "update-status" hook (via hook dispatching script: dispatch)
2023-07-10 23:20:19 INFO unit.producer-app/0.juju-log server.go:316 Topic successfully created: test-topic with username: relation-14
2023-07-10 23:20:19 WARNING unit.producer-app/0.juju-log server.go:316 No relation: certificates
2023-07-10 23:20:19 INFO juju.worker.uniter.operation runhook.go:146 ran "update-status" hook (via hook dispatching script: dispatch)
2023-07-10 23:25:19 INFO unit.producer-app/0.juju-log server.go:316 Topic successfully created: test-topic with username: relation-14
2023-07-10 23:25:19 WARNING unit.producer-app/0.juju-log server.go:316 No relation: certificates
2023-07-10 23:25:19 INFO juju.worker.uniter.operation runhook.go:146 ran "update-status" hook (via hook dispatching script: dispatch)
2023-07-10 23:27:30 INFO unit.producer-app/0.juju-log server.go:316 certificates:15: Topic successfully created: test-topic with username: relation-14
2023-07-10 23:27:30 INFO juju.worker.uniter.operation runhook.go:146 ran "certificates-relation-created" hook (via hook dispatching script: dispatch)
2023-07-10 23:27:31 INFO unit.producer-app/0.juju-log server.go:316 certificates:15: Topic successfully created: test-topic with username: relation-14
2023-07-10 23:27:31 INFO unit.producer-app/0.juju-log server.go:316 certificates:15: Certificate request sent to provider
2023-07-10 23:27:32 INFO juju.worker.uniter.operation runhook.go:146 ran "certificates-relation-joined" hook (via hook dispatching script: dispatch)
2023-07-10 23:27:32 INFO unit.producer-app/0.juju-log server.go:316 certificates:15: Topic successfully created: test-topic with username: relation-14
2023-07-10 23:27:32 WARNING unit.producer-app/0.juju-log server.go:316 certificates:15: Provider relation data did not pass JSON Schema validation: {}
2023-07-10 23:27:33 INFO juju.worker.uniter.operation runhook.go:146 ran "certificates-relation-changed" hook (via hook dispatching script: dispatch)
2023-07-10 23:27:33 INFO unit.producer-app/0.juju-log server.go:316 certificates:15: Topic successfully created: test-topic with username: relation-14
2023-07-10 23:27:33 INFO juju.worker.uniter.operation runhook.go:146 ran "certificates-relation-changed" hook (via hook dispatching script: dispatch)
2023-07-10 23:29:23 INFO unit.producer-app/0.juju-log server.go:316 Topic successfully created: test-topic with username: relation-14
2023-07-10 23:29:23 INFO unit.producer-app/0.juju-log server.go:316 starting app_type: producer
2023-07-10 23:29:23 INFO unit.producer-app/0.juju-log server.go:316 nohup python3 -m charms.kafka.v0.client --username relation-14 --password ddV0AClXcbPsMxrYDQNwkdX7vi8qoxXz --servers 172.16.7.214:9093 --topic test-topic  --cafile-path /tmp/ca.pem --certfile-path /tmp/server.pem --keyfile-path /tmp/server.key --security-protocol SASL_SSL  --producer --replication-factor 1 --num-partitions 5 --num-messages 1000
2023-07-10 23:29:23 INFO unit.producer-app/0.juju-log server.go:316 Auto-Started producer process with pid: 3849
2023-07-10 23:29:24 INFO juju.worker.uniter.operation runhook.go:146 ran "update-status" hook (via hook dispatching script: dispatch)
2023-07-10 23:33:33 INFO juju.worker.uniter.operation runhook.go:146 ran "update-status" hook (via hook dispatching script: dispatch)
2023-07-10 23:37:35 INFO juju.worker.uniter.operation runhook.go:146 ran "update-status" hook (via hook dispatching script: dispatch

Additional Context

It looks the charm is writing into Kafka without the action running successfully

$ juju ssh producer-app/0 cat /tmp/1689031763_producer.log
INFO:__main__:Creating new topic - test-topic
INFO:kafka.conn:<BrokerConnection node_id=bootstrap-0 host=172.16.7.214:9093 <connecting> [IPv4 ('172.16.7.214', 9093)]>: connecting to 172.16.7.214:9093 [('172.16.7.214', 9093) IPv4]
INFO:kafka.conn:Probing node bootstrap-0 broker version
INFO:kafka.conn:<BrokerConnection node_id=bootstrap-0 host=172.16.7.214:9093 <handshake> [IPv4 ('172.16.7.214', 9093)]>: Loading SSL CA from /tmp/ca.pem
INFO:kafka.conn:<BrokerConnection node_id=bootstrap-0 host=172.16.7.214:9093 <authenticating> [IPv4 ('172.16.7.214', 9093)]>: Authenticated as relation-14 via SCRAM-SHA-512
INFO:kafka.conn:<BrokerConnection node_id=bootstrap-0 host=172.16.7.214:9093 <authenticating> [IPv4 ('172.16.7.214', 9093)]>: Connection complete.
INFO:kafka.conn:Broker version identified as 2.5.0
INFO:kafka.conn:Set configuration api_version=(2, 5, 0) to skip auto check_version requests on startup
INFO:kafka.conn:Probing node bootstrap-0 broker version
INFO:kafka.conn:Broker version identified as 2.5.0
INFO:kafka.conn:Set configuration api_version=(2, 5, 0) to skip auto check_version requests on startup
INFO:kafka.conn:<BrokerConnection node_id=0 host=172.16.7.214:9093 <connecting> [IPv4 ('172.16.7.214', 9093)]>: connecting to 172.16.7.214:9093 [('172.16.7.214', 9093) IPv4]
INFO:kafka.conn:Probing node 0 broker version
INFO:kafka.conn:<BrokerConnection node_id=0 host=172.16.7.214:9093 <handshake> [IPv4 ('172.16.7.214', 9093)]>: Loading SSL CA from /tmp/ca.pem
INFO:kafka.conn:<BrokerConnection node_id=0 host=172.16.7.214:9093 <authenticating> [IPv4 ('172.16.7.214', 9093)]>: Authenticated as relation-14 via SCRAM-SHA-512
INFO:kafka.conn:<BrokerConnection node_id=0 host=172.16.7.214:9093 <authenticating> [IPv4 ('172.16.7.214', 9093)]>: Connection complete.
INFO:kafka.conn:<BrokerConnection node_id=bootstrap-0 host=172.16.7.214:9093 <connected> [IPv4 ('172.16.7.214', 9093)]>: Closing connection. 
INFO:kafka.conn:Broker version identified as 2.5.0
INFO:kafka.conn:Set configuration api_version=(2, 5, 0) to skip auto check_version requests on startup
INFO:__main__:Topic already exists
INFO:__main__:--producer - Starting...
INFO:kafka.conn:<BrokerConnection node_id=bootstrap-0 host=172.16.7.214:9093 <connecting> [IPv4 ('172.16.7.214', 9093)]>: connecting to 172.16.7.214:9093 [('172.16.7.214', 9093) IPv4]
INFO:kafka.conn:Probing node bootstrap-0 broker version
INFO:kafka.conn:<BrokerConnection node_id=bootstrap-0 host=172.16.7.214:9093 <handshake> [IPv4 ('172.16.7.214', 9093)]>: Loading SSL CA from /tmp/ca.pem
INFO:kafka.conn:<BrokerConnection node_id=bootstrap-0 host=172.16.7.214:9093 <authenticating> [IPv4 ('172.16.7.214', 9093)]>: Authenticated as relation-14 via SCRAM-SHA-512
INFO:kafka.conn:<BrokerConnection node_id=bootstrap-0 host=172.16.7.214:9093 <authenticating> [IPv4 ('172.16.7.214', 9093)]>: Connection complete.
INFO:kafka.conn:Broker version identified as 2.5.0
INFO:kafka.conn:Set configuration api_version=(2, 5, 0) to skip auto check_version requests on startup
INFO:kafka.conn:<BrokerConnection node_id=0 host=172.16.7.214:9093 <connecting> [IPv4 ('172.16.7.214', 9093)]>: connecting to 172.16.7.214:9093 [('172.16.7.214', 9093) IPv4]
INFO:kafka.conn:<BrokerConnection node_id=0 host=172.16.7.214:9093 <handshake> [IPv4 ('172.16.7.214', 9093)]>: Loading SSL CA from /tmp/ca.pem
INFO:kafka.conn:<BrokerConnection node_id=0 host=172.16.7.214:9093 <authenticating> [IPv4 ('172.16.7.214', 9093)]>: Authenticated as relation-14 via SCRAM-SHA-512
INFO:kafka.conn:<BrokerConnection node_id=0 host=172.16.7.214:9093 <authenticating> [IPv4 ('172.16.7.214', 9093)]>: Connection complete.
INFO:kafka.conn:<BrokerConnection node_id=bootstrap-0 host=172.16.7.214:9093 <connected> [IPv4 ('172.16.7.214', 9093)]>: Closing connection. 
INFO:__main__:Message published to topic=test-topic, message content: {"timestamp": 1689031766.903758, "_id": "ae493cc354ec4f70b2e297c87364819e", "origin": "juju-1b0be2-0-lxd-6 (172.16.7.208)", "content": "Message #0"}
INFO:__main__:Message published to topic=test-topic, message content: {"timestamp": 1689031767.775172, "_id": "770dd7ed1fcf493faf3d2c331274da71", "origin": "juju-1b0be2-0-lxd-6 (172.16.7.208)", "content": "Message #1"}
INFO:__main__:Message published to topic=test-topic, message content: {"timestamp": 1689031768.281024, "_id": "b56b32874835414682b46b5d1dd60023", "origin": "juju-1b0be2-0-lxd-6 (172.16.7.208)", "content": "Message #2"}
INFO:__main__:Message published to topic=test-topic, message content: {"timestamp": 1689031768.786095, "_id": "4bb5cf43d4c74d128ca0cd1a4be0e25f", "origin": "juju-1b0be2-0-lxd-6 (172.16.7.208)", "content": "Message #3"}
INFO:__main__:Message published to topic=test-topic, message content: {"timestamp": 1689031769.291802, "_id": "06ff781d8bc94c7bab530627be53ce19", "origin": "juju-1b0be2-0-lxd-6 (172.16.7.208)", "content": "Message #4"}

It is also the same result even after stopping the process 

juju show-action-output 14
UnitId: producer-app/0
id: "14"
results:
  Stderr: |
    kill: (3849): No such process
  process: "3849"
status: completed
timing:
  completed: 2023-07-10 23:53:29 +0000 UTC
  enqueued: 2023-07-10 23:53:26 +0000 UTC
  started: 2023-07-10 23:53:29 +0000 UTC
➜  ~ juju run-action producer-app/0 stop-process --wait
unit-producer-app-0:
  UnitId: producer-app/0
  id: "16"
  message: No process to stop!
  results: {}
  status: failed
  timing:
    completed: 2023-07-10 23:54:03 +0000 UTC
    enqueued: 2023-07-10 23:53:58 +0000 UTC
    started: 2023-07-10 23:54:03 +0000 UTC
➜  ~ juju run-action producer-app/0 start-process username=relation-10 password=oCLPVdhzUV95rhlLaktc1hNTplPmMJid servers=172.16.7.214:9093 topic_name=test
ERROR key "topic_name" must start and end with lowercase alphanumeric, and contain only lowercase alphanumeric and hyphens
github-actions[bot] commented 1 year ago

https://warthogs.atlassian.net/browse/DPE-2226

deusebio commented 1 year ago

@gustavosr98 Thanks for raising this! This bug should be addressed by #12