Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat(uat): implement GGMQ scenario based on GGAD-1-T25 #385

Conversation

eschastlivtsev
Copy link

@eschastlivtsev eschastlivtsev commented Aug 1, 2023

Issue #, if available:
Implement GGMQ scenario based on GGAD-1-T25

Description of changes:

  • Add T25 scenario
  • Add new step - rename a connection

Why is this change necessary:
Implement scenarios

How was this change tested:
Run scenario locally

Test results:

Given my device is registered as a Thing....................................passed
And my device is running Greengrass.........................................passed
When I create a Greengrass deployment with components.......................passed
And I create client device "publisher"......................................passed
And I create client device "subscriber".....................................passed
And I update my Greengrass deployment configuration, setting the component aws.greengrass.clientdevices.Auth configuration to:.passed
And I update my Greengrass deployment configuration, setting the component aws.greengrass.client.Mqtt5PythonPahoClient configuration to:.passed
When I associate "publisher" with ggc.......................................passed
When I associate "subscriber" with ggc......................................passed
And I deploy the Greengrass deployment configuration........................passed
Then the Greengrass deployment is COMPLETED on the device after 5 minutes...passed
And the aws.greengrass.clientdevices.mqtt.EMQX log on the device contains the line "is running now!." within 1 minutes.passed
Then I discover core device broker as "localMqttBroker1" from "publisher" in OTF.passed
Then I discover core device broker as "localMqttBroker2" from "subscriber" in OTF.passed
And I connect device "publisher" on aws.greengrass.client.Mqtt5PythonPahoClient to "localMqttBroker1" using mqtt "v5".passed
And I connect device "subscriber" on aws.greengrass.client.Mqtt5PythonPahoClient to "localMqttBroker2" using mqtt "v5".passed
When I subscribe "subscriber" to "iot_data_0" with qos 1....................passed
When I publish from "publisher" to "iot_data_0" with qos 1 and message "Test message" and expect status 0.passed
And message "Test message" received on "subscriber" from "iot_data_0" topic within 5 seconds.passed
And I rename connection "publisher" to "publisher_old"......................passed
And I connect device "publisher" on aws.greengrass.client.Mqtt5PythonPahoClient to "localMqttBroker1" using mqtt "v5".passed
When I publish from "publisher" to "iot_data_0" with qos 1 and message "Connect again" and expect status 0.passed
And message "Connect again" received on "subscriber" from "iot_data_0" topic within 5 seconds.passed

All clients (except Java Paho):

[INFO ] 2023-08-01 15:54:25.075 [main] StepTrackingReporting - Passed: 'GGMQ-1-T25-v3-sdk-java: As a customer, I connect with same client id twice (not reconnect) and be able to publish and subscribe to messages.'
[INFO ] 2023-08-01 15:54:25.075 [main] StepTrackingReporting - Passed: 'GGMQ-1-T25-v3-mosquitto-c: As a customer, I connect with same client id twice (not reconnect) and be able to publish and subscribe to messages.'
[INFO ] 2023-08-01 15:54:25.075 [main] StepTrackingReporting - Passed: 'GGMQ-1-T25-v3-paho-python: As a customer, I connect with same client id twice (not reconnect) and be able to publish and subscribe to messages.'
[INFO ] 2023-08-01 15:54:25.075 [main] StepTrackingReporting - Passed: 'GGMQ-1-T25-v5-sdk-java: As a customer, I connect with same client id twice (not reconnect) and be able to publish and subscribe to messages.'
[INFO ] 2023-08-01 15:54:25.075 [main] StepTrackingReporting - Passed: 'GGMQ-1-T25-v5-mosquitto-c: As a customer, I connect with same client id twice (not reconnect) and be able to publish and subscribe to messages.'
[INFO ] 2023-08-01 15:54:25.075 [main] StepTrackingReporting - Passed: 'GGMQ-1-T25-v5-paho-python: As a customer, I connect with same client id twice (not reconnect) and be able to publish and subscribe to messages.'

Client Log:

2023-08-01T17:41:50.820Z [INFO] (pool-2-thread-23) aws.greengrass.client.Mqtt5JavaPahoClient: shell-runner-start. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=STARTING, command=["java -jar /tmp/gg-testing-12375312970262000714/gg-df6909aca85d4c94507b/package..."]}
2023-08-01T17:41:54.454Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:41:54.440 [main] GRPCLinkImpl - Making gPRC client connection with 172.21.0.1:45553 as aws.greengrass.client.Mqtt5JavaPahoClient.... {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:41:54.482Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance.. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:41:56.192Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:41:56.189 [main] GRPCLinkImpl - Client connection with Control is established, local address is 192.168.100.20. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:41:56.330Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:41:56.330 [main] GRPCControlServer - GRPCControlServer created and listed on 192.168.100.20:39165. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:41:56.730Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:41:56.724 [main] GRPCLinkImpl - Handle gRPC requests. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:41:56.730Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:41:56.724 [main] GRPCControlServer - Server awaitTermination. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:42:21.621Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:42:21.620 [grpc-default-executor-0] GRPCControlServer - createMqttConnection: clientId gg-df6909aca85d4c94507b-publisher broker 192.168.100.20:8883. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:42:23.870Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:42:23.870 [grpc-default-executor-0] GRPCControlServer - createMqttConnection: clientId gg-df6909aca85d4c94507b-subscriber broker 192.168.100.20:8883. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:42:25.138Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:42:25.138 [grpc-default-executor-0] GRPCControlServer - Subscription: filter 'iot_data_0' QoS 1 noLocal false retainAsPublished false retainHandling 0. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:42:25.139Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:42:25.139 [grpc-default-executor-0] GRPCControlServer - Subscribe: connectionId 2 for 1 filters. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:42:25.169Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:42:25.169 [grpc-default-executor-0] GRPCControlServer - Subscribe response: connectionId 2 reason codes [1] reason string ''. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:42:25.200Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:42:25.199 [grpc-default-executor-0] GRPCControlServer - Publish: connectionId 1 topic 'iot_data_0' QoS 1 retain false. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:42:25.217Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:42:25.213 [MQTT Call: gg-df6909aca85d4c94507b-publisher] MqttConnectionImpl - Delivery completion is true. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:42:25.217Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:42:25.214 [grpc-default-executor-0] GRPCControlServer - Publish response: connectionId 1 reason code 0 reason string ''. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:42:25.231Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:42:25.230 [MQTT Call: gg-df6909aca85d4c94507b-subscriber] MqttConnectionImpl - Received MQTT message: connectionId 2 topic 'iot_data_0' QoS 1 retain false. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:42:25.232Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:42:25.232 [MQTT Call: gg-df6909aca85d4c94507b-subscriber] MqttConnectionImpl - Received MQTT message has payload format indicator 'false'. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:42:25.260Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:42:25.261 [grpc-default-executor-0] GRPCControlServer - createMqttConnection: clientId gg-df6909aca85d4c94507b-publisher broker 192.168.100.20:8883. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:42:26.468Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:42:26.467 [MQTT Rec: gg-df6909aca85d4c94507b-publisher] MqttConnectionImpl - MQTT connectionId 1 disconnected error 'null' disconnectInfo 'com.aws.greengrass.testing.mqtt5.client.GRPCClient$DisconnectInfo@42609add'. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:42:26.477Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:42:26.476 [grpc-default-executor-0] GRPCControlServer - Publish: connectionId 3 topic 'iot_data_0' QoS 1 retain false. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:42:26.486Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:42:26.483 [grpc-default-executor-0] GRPCControlServer - Publish response: connectionId 3 reason code 0 reason string ''. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:42:26.487Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:42:26.485 [MQTT Call: gg-df6909aca85d4c94507b-subscriber] MqttConnectionImpl - Received MQTT message: connectionId 2 topic 'iot_data_0' QoS 1 retain false. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:42:26.487Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:42:26.486 [MQTT Call: gg-df6909aca85d4c94507b-subscriber] MqttConnectionImpl - Received MQTT message has payload format indicator 'false'. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:42:26.498Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:42:26.495 [MQTT Call: gg-df6909aca85d4c94507b-publisher] MqttConnectionImpl - Delivery completion is true. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:42:27.392Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: Run script exited. {exitCode=137, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=STOPPING}

Test console log:

sudo -E java -Dggc.archive=greengrass-nucleus-latest.zip -Dtest.log.path=logs -Dtags="@GGMQ-1-T25 and @mqtt5 and @paho-java" -jar testing-features/target/client-devices-auth-testing-features.jar
[sudo] password for egor: 
WARNING: sun.reflect.Reflection.getCallerClass is not supported. This will impact performance.
[INFO ] 2023-08-01 20:40:10.095 [main] GreengrassContextModule - Extracting greengrass-nucleus-latest.zip into /tmp/gg-testing-12375312970262000714/greengrass
[INFO ] 2023-08-01 20:40:10.610 [main] LoggerSteps - OTF Version is otf-1.2.0-SNAPSHOT
[INFO ] 2023-08-01 20:40:10.610 [main] LoggerSteps - Attaching thread context to scenario: 'GGMQ-1-T25-v5-paho-java: As a customer, I connect with same client id twice (not reconnect) and be able to publish and subscribe to messages.'
[INFO ] 2023-08-01 20:40:11.705 [main] AbstractAWSResourceLifecycle - Created GreengrassCoreDevice in GreengrassV2Lifecycle
[INFO ] 2023-08-01 20:40:12.298 [main] AbstractAWSResourceLifecycle - Created IotPolicy in IotLifecycle
[INFO ] 2023-08-01 20:40:13.523 [main] AbstractAWSResourceLifecycle - Created IamPolicy in IamLifecycle
[INFO ] 2023-08-01 20:40:13.984 [main] AbstractAWSResourceLifecycle - Created IamRole in IamLifecycle
[INFO ] 2023-08-01 20:40:14.342 [main] AbstractAWSResourceLifecycle - Created IotRoleAlias in IotLifecycle
[INFO ] 2023-08-01 20:40:14.511 [main] AbstractAWSResourceLifecycle - Created IotPolicy in IotLifecycle
[INFO ] 2023-08-01 20:40:14.669 [main] AbstractAWSResourceLifecycle - Created IotThingGroup in IotLifecycle
[INFO ] 2023-08-01 20:40:15.641 [main] AbstractAWSResourceLifecycle - Created IotCertificate in IotLifecycle
[INFO ] 2023-08-01 20:40:15.810 [main] AbstractAWSResourceLifecycle - Created IotThing in IotLifecycle
[INFO ] 2023-08-01 20:40:16.469 [main] RegistrationSteps - IoT Role alias not ready yet, got 400: {"message":"Unable to assume the role, or the role to assume does not exist"}
[INFO ] 2023-08-01 20:40:22.866 [main] RegistrationSteps - IoT Role alias returned 200, credentials should be good to go!
[INFO ] 2023-08-01 20:40:23.060 [main] feature - Finished step: 'my device is registered as a Thing' with status PASSED
[INFO ] 2023-08-01 20:40:24.311 [main] DefaultGreengrass - Starting Greengrass on pid 19618
[INFO ] 2023-08-01 20:40:24.312 [main] feature - Finished step: 'my device is running Greengrass' with status PASSED
[INFO ] 2023-08-01 20:40:27.354 [main] AbstractAWSResourceLifecycle - Created S3Bucket in S3Lifecycle
[INFO ] 2023-08-01 20:40:36.252 [main] AbstractAWSResourceLifecycle - Created S3Object in S3Lifecycle
[INFO ] 2023-08-01 20:40:36.253 [main] RecipeComponentPreparationService - Uploaded /tmp/gg-testing-12375312970262000714/df6909aca85d4c94507b/components/aws.greengrass.client.Mqtt5JavaPahoClient/aws.greengrass.client.Mqtt5JavaPahoClient.jar to s3://gg-df6909aca85d4c94507b-gg-component-store/local-store/artifacts/aws.greengrass.client.Mqtt5JavaPahoClient.jar
[INFO ] 2023-08-01 20:40:37.016 [main] AbstractAWSResourceLifecycle - Created GreengrassComponent in GreengrassV2Lifecycle
[INFO ] 2023-08-01 20:40:37.016 [main] RecipeComponentPreparationService - Created component aws.greengrass.client.Mqtt5JavaPahoClient:1.0.0-df6909aca85d4c94507b from /local-store/recipes/client_java_paho.yaml
[INFO ] 2023-08-01 20:40:37.017 [main] feature - Finished step: 'I create a Greengrass deployment with components' with status PASSED
[INFO ] 2023-08-01 20:40:37.172 [main] EngineControlImpl - MQTT client control gRPC server started, listening on 45553
[INFO ] 2023-08-01 20:40:37.172 [main] MqttControlSteps - MQTT clients control started gRPC service on port 45553 addresses [172.21.0.1, 172.18.0.1, 172.17.0.1, 192.168.100.20]
[INFO ] 2023-08-01 20:40:37.318 [main] AbstractAWSResourceLifecycle - Created IotPolicy in IotLifecycle
[INFO ] 2023-08-01 20:40:38.064 [main] AbstractAWSResourceLifecycle - Created IotCertificate in IotLifecycle
[INFO ] 2023-08-01 20:40:38.065 [main] AbstractAWSResourceLifecycle - Created IotThing in IotLifecycle
[INFO ] 2023-08-01 20:40:38.065 [main] feature - Finished step: 'I create client device "publisher"' with status PASSED
[INFO ] 2023-08-01 20:40:38.224 [main] AbstractAWSResourceLifecycle - Created IotPolicy in IotLifecycle
[INFO ] 2023-08-01 20:40:39.025 [main] AbstractAWSResourceLifecycle - Created IotCertificate in IotLifecycle
[INFO ] 2023-08-01 20:40:39.025 [main] AbstractAWSResourceLifecycle - Created IotThing in IotLifecycle
[INFO ] 2023-08-01 20:40:39.025 [main] feature - Finished step: 'I create client device "subscriber"' with status PASSED
[INFO ] 2023-08-01 20:40:39.169 [main] feature - Finished step: 'I associate "publisher" with ggc' with status PASSED
[INFO ] 2023-08-01 20:40:39.292 [main] feature - Finished step: 'I associate "subscriber" with ggc' with status PASSED
[INFO ] 2023-08-01 20:40:39.306 [main] feature - Finished step: 'I update my Greengrass deployment configuration, setting the component aws.greengrass.clientdevices.Auth configuration to:' with status PASSED
[INFO ] 2023-08-01 20:40:39.307 [main] feature - Finished step: 'I update my Greengrass deployment configuration, setting the component aws.greengrass.client.Mqtt5JavaPahoClient configuration to:' with status PASSED
[INFO ] 2023-08-01 20:40:39.685 [main] AbstractAWSResourceLifecycle - Created GreengrassDeployment in GreengrassV2Lifecycle
[INFO ] 2023-08-01 20:40:39.685 [main] DeploymentSteps - Created Greengrass deployment: e095b5e0-4101-4a63-b2b1-9954248cf8ce
[INFO ] 2023-08-01 20:40:39.685 [main] feature - Finished step: 'I deploy the Greengrass deployment configuration' with status PASSED
[INFO ] 2023-08-01 20:41:56.062 [grpc-default-executor-0] GRPCDiscoveryServer - RegisterAgent: agentId aws.greengrass.client.Mqtt5JavaPahoClient
[INFO ] 2023-08-01 20:41:56.359 [grpc-default-executor-0] GRPCDiscoveryServer - DiscoveryClient: agentId aws.greengrass.client.Mqtt5JavaPahoClient address 192.168.100.20 port 39165
[INFO ] 2023-08-01 20:41:56.362 [grpc-default-executor-0] EngineControlImpl - Created new agent control for aws.greengrass.client.Mqtt5JavaPahoClient on 192.168.100.20:39165
[INFO ] 2023-08-01 20:41:56.604 [grpc-default-executor-0] MqttControlSteps - Agent aws.greengrass.client.Mqtt5JavaPahoClient is connected
[INFO ] 2023-08-01 20:42:18.724 [main] feature - Finished step: 'the Greengrass deployment is COMPLETED on the device after 5 minutes' with status PASSED
[INFO ] 2023-08-01 20:42:19.754 [main] feature - Finished step: 'the aws.greengrass.clientdevices.mqtt.EMQX log on the device contains the line "is running now!." within 1 minutes' with status PASSED
[INFO ] 2023-08-01 20:42:20.772 [main] MqttControlSteps - Discovered data for broker localMqttBroker1:
[INFO ] 2023-08-01 20:42:20.774 [main] MqttControlSteps - groupId greengrassV2-coreDevice-gg-df6909aca85d4c94507b-ggc-thing with 1 CA
[INFO ] 2023-08-01 20:42:20.774 [main] MqttControlSteps - Core with thing Arn arn:aws:iot:eu-central-1:285891398846:thing/gg-df6909aca85d4c94507b-ggc-thing
[INFO ] 2023-08-01 20:42:20.775 [main] MqttControlSteps - Connectivity info: id 192.168.100.20 host 192.168.100.20 port 8883
[INFO ] 2023-08-01 20:42:20.777 [main] feature - Finished step: 'I discover core device broker as "localMqttBroker1" from "publisher" in OTF' with status PASSED
[INFO ] 2023-08-01 20:42:21.481 [main] MqttControlSteps - Discovered data for broker localMqttBroker2:
[INFO ] 2023-08-01 20:42:21.481 [main] MqttControlSteps - groupId greengrassV2-coreDevice-gg-df6909aca85d4c94507b-ggc-thing with 1 CA
[INFO ] 2023-08-01 20:42:21.481 [main] MqttControlSteps - Core with thing Arn arn:aws:iot:eu-central-1:285891398846:thing/gg-df6909aca85d4c94507b-ggc-thing
[INFO ] 2023-08-01 20:42:21.481 [main] MqttControlSteps - Connectivity info: id 192.168.100.20 host 192.168.100.20 port 8883
[INFO ] 2023-08-01 20:42:21.481 [main] feature - Finished step: 'I discover core device broker as "localMqttBroker2" from "subscriber" in OTF' with status PASSED
[INFO ] 2023-08-01 20:42:21.482 [main] MqttControlSteps - Creating MQTT connection with broker localMqttBroker1 to address 192.168.100.20:8883 as Thing gg-df6909aca85d4c94507b-publisher on aws.greengrass.client.Mqtt5JavaPahoClient using MQTT v5
[INFO ] 2023-08-01 20:42:23.805 [main] AgentControlImpl - Created connection with id 1 CONNACK 'sessionPresent: false
retainAvailable: true
maximumPacketSize: 268435455
'
[INFO ] 2023-08-01 20:42:23.863 [main] AgentControlImpl - createMqttConnection: MQTT connectionId 1 created
[INFO ] 2023-08-01 20:42:23.863 [main] MqttControlSteps - Connection with broker localMqttBroker1 established to address 192.168.100.20:8883 as Thing gg-df6909aca85d4c94507b-publisher on aws.greengrass.client.Mqtt5JavaPahoClient
[INFO ] 2023-08-01 20:42:23.863 [main] feature - Finished step: 'I connect device "publisher" on aws.greengrass.client.Mqtt5JavaPahoClient to "localMqttBroker1" using mqtt "v5"' with status PASSED
[INFO ] 2023-08-01 20:42:23.864 [main] MqttControlSteps - Creating MQTT connection with broker localMqttBroker2 to address 192.168.100.20:8883 as Thing gg-df6909aca85d4c94507b-subscriber on aws.greengrass.client.Mqtt5JavaPahoClient using MQTT v5
[INFO ] 2023-08-01 20:42:25.117 [main] AgentControlImpl - Created connection with id 2 CONNACK 'sessionPresent: false
retainAvailable: true
maximumPacketSize: 268435455
'
[INFO ] 2023-08-01 20:42:25.124 [main] AgentControlImpl - createMqttConnection: MQTT connectionId 2 created
[INFO ] 2023-08-01 20:42:25.124 [main] MqttControlSteps - Connection with broker localMqttBroker2 established to address 192.168.100.20:8883 as Thing gg-df6909aca85d4c94507b-subscriber on aws.greengrass.client.Mqtt5JavaPahoClient
[INFO ] 2023-08-01 20:42:25.125 [main] feature - Finished step: 'I connect device "subscriber" on aws.greengrass.client.Mqtt5JavaPahoClient to "localMqttBroker2" using mqtt "v5"' with status PASSED
[INFO ] 2023-08-01 20:42:25.126 [main] MqttControlSteps - Create MQTT subscription for Thing gg-df6909aca85d4c94507b-subscriber to topics filter iot_data_0 with QoS 1 no local false retain handling MQTT5_RETAIN_SEND_AT_SUBSCRIPTION
[INFO ] 2023-08-01 20:42:25.127 [main] AgentControlImpl - SubscribeMqtt: subscribe on connection 2
[INFO ] 2023-08-01 20:42:25.174 [main] MqttControlSteps - MQTT subscription has on topics filter iot_data_0 been created with reason code 1
[INFO ] 2023-08-01 20:42:25.174 [main] feature - Finished step: 'I subscribe "subscriber" to "iot_data_0" with qos 1' with status PASSED
[INFO ] 2023-08-01 20:42:25.175 [main] MqttControlSteps - Publishing MQTT message 'Test message' as Thing gg-df6909aca85d4c94507b-publisher to topic iot_data_0 with QoS 1 retain false payload format indicator null message expire interval null response topic null correlation data null
[INFO ] 2023-08-01 20:42:25.177 [main] AgentControlImpl - PublishMqtt: publishing on connectionId 1 topic iot_data_0
[INFO ] 2023-08-01 20:42:25.224 [main] MqttControlSteps - MQTT message 'Test message' has been succesfully published
[INFO ] 2023-08-01 20:42:25.225 [main] feature - Finished step: 'I publish from "publisher" to "iot_data_0" with qos 1 and message "Test message"' with status PASSED
[INFO ] 2023-08-01 20:42:25.225 [main] MqttControlSteps - Awaiting for MQTT message 'Test message' with retain null payload format indicator null message expiry interval null response topic null correlation data null on topic 'iot_data_0' on Thing 'gg-df6909aca85d4c94507b-subscriber' for 5 seconds
[INFO ] 2023-08-01 20:42:25.252 [grpc-default-executor-0] GRPCDiscoveryServer - OnReceiveMessage: agentId aws.greengrass.client.Mqtt5JavaPahoClient connectionId 2 topic iot_data_0 QoS 1
[INFO ] 2023-08-01 20:42:25.253 [main] feature - Finished step: 'message "Test message" received on "subscriber" from "iot_data_0" topic within 5 seconds' with status PASSED
[INFO ] 2023-08-01 20:42:25.254 [main] MqttControlSteps - Connection gg-df6909aca85d4c94507b-publisher was renamed to gg-df6909aca85d4c94507b-publisher_old
[INFO ] 2023-08-01 20:42:25.254 [main] feature - Finished step: 'I rename connection "publisher" to "publisher_old"' with status PASSED
[INFO ] 2023-08-01 20:42:25.254 [main] MqttControlSteps - Creating MQTT connection with broker localMqttBroker1 to address 192.168.100.20:8883 as Thing gg-df6909aca85d4c94507b-publisher on aws.greengrass.client.Mqtt5JavaPahoClient using MQTT v5
[INFO ] 2023-08-01 20:42:25.253 [grpc-default-executor-0] MqttControlSteps - Message received on connection with name gg-df6909aca85d4c94507b-subscriber: topic: "iot_data_0"
payload: "Test message"
qos: MQTT_QOS_1
payloadFormatIndicator: false

[INFO ] 2023-08-01 20:42:26.470 [main] AgentControlImpl - Created connection with id 3 CONNACK 'sessionPresent: false
retainAvailable: true
maximumPacketSize: 268435455
'
[INFO ] 2023-08-01 20:42:26.470 [main] AgentControlImpl - createMqttConnection: MQTT connectionId 3 created
[INFO ] 2023-08-01 20:42:26.470 [main] MqttControlSteps - Connection with broker localMqttBroker1 established to address 192.168.100.20:8883 as Thing gg-df6909aca85d4c94507b-publisher on aws.greengrass.client.Mqtt5JavaPahoClient
[INFO ] 2023-08-01 20:42:26.470 [main] feature - Finished step: 'I connect device "publisher" on aws.greengrass.client.Mqtt5JavaPahoClient to "localMqttBroker1" using mqtt "v5"' with status PASSED
[INFO ] 2023-08-01 20:42:26.471 [main] MqttControlSteps - Publishing MQTT message 'Connect again' as Thing gg-df6909aca85d4c94507b-publisher to topic iot_data_0 with QoS 1 retain false payload format indicator null message expire interval null response topic null correlation data null
[INFO ] 2023-08-01 20:42:26.471 [main] AgentControlImpl - PublishMqtt: publishing on connectionId 3 topic iot_data_0
[INFO ] 2023-08-01 20:42:26.498 [grpc-default-executor-0] GRPCDiscoveryServer - OnReceiveMessage: agentId aws.greengrass.client.Mqtt5JavaPahoClient connectionId 2 topic iot_data_0 QoS 1
[INFO ] 2023-08-01 20:42:26.498 [grpc-default-executor-0] MqttControlSteps - Message received on connection with name gg-df6909aca85d4c94507b-subscriber: topic: "iot_data_0"
payload: "Connect again"
qos: MQTT_QOS_1
payloadFormatIndicator: false

[INFO ] 2023-08-01 20:42:26.497 [main] MqttControlSteps - MQTT message 'Connect again' has been succesfully published
[INFO ] 2023-08-01 20:42:26.498 [main] feature - Finished step: 'I publish from "publisher" to "iot_data_0" with qos 1 and message "Connect again"' with status PASSED
[INFO ] 2023-08-01 20:42:26.500 [main] MqttControlSteps - Awaiting for MQTT message 'Connect again' with retain null payload format indicator null message expiry interval null response topic null correlation data null on topic 'iot_data_0' on Thing 'gg-df6909aca85d4c94507b-subscriber' for 5 seconds
[INFO ] 2023-08-01 20:42:26.500 [main] feature - Finished step: 'message "Connect again" received on "subscriber" from "iot_data_0" topic within 5 seconds' with status PASSED
[INFO ] 2023-08-01 20:42:26.581 [grpc-default-executor-0] GRPCDiscoveryServer - OnMqttDisconnect: agentId aws.greengrass.client.Mqtt5JavaPahoClient connectionId 1 disconnect 'reasonCode: 142
' error ''
[INFO ] 2023-08-01 20:42:26.584 [grpc-default-executor-0] MqttControlSteps - MQTT client disconnected. Error: 
[INFO ] 2023-08-01 20:42:44.001 [main] DefaultGreengrass - Stopped Greengrass on pid 19618
[INFO ] 2023-08-01 20:42:44.535 [main] AbstractAWSResourceLifecycle - Removed S3Object in S3Lifecycle
[INFO ] 2023-08-01 20:42:44.972 [main] AbstractAWSResourceLifecycle - Removed S3Bucket in S3Lifecycle
[INFO ] 2023-08-01 20:42:46.298 [main] AbstractAWSResourceLifecycle - Removed IamRole in IamLifecycle
[INFO ] 2023-08-01 20:42:46.838 [main] AbstractAWSResourceLifecycle - Removed IamPolicy in IamLifecycle
[INFO ] 2023-08-01 20:42:47.367 [main] AbstractAWSResourceLifecycle - Removed IotThing in IotLifecycle
[INFO ] 2023-08-01 20:42:47.813 [main] AbstractAWSResourceLifecycle - Removed IotCertificate in IotLifecycle
[INFO ] 2023-08-01 20:42:48.034 [main] AbstractAWSResourceLifecycle - Removed IotPolicy in IotLifecycle
[INFO ] 2023-08-01 20:42:48.307 [main] AbstractAWSResourceLifecycle - Removed IotThing in IotLifecycle
[INFO ] 2023-08-01 20:42:48.705 [main] AbstractAWSResourceLifecycle - Removed IotCertificate in IotLifecycle
[INFO ] 2023-08-01 20:42:48.945 [main] AbstractAWSResourceLifecycle - Removed IotPolicy in IotLifecycle
[INFO ] 2023-08-01 20:42:49.197 [main] AbstractAWSResourceLifecycle - Removed IotThing in IotLifecycle
[INFO ] 2023-08-01 20:42:49.643 [main] AbstractAWSResourceLifecycle - Removed IotCertificate in IotLifecycle
[INFO ] 2023-08-01 20:42:49.765 [main] AbstractAWSResourceLifecycle - Removed IotThingGroup in IotLifecycle
[INFO ] 2023-08-01 20:42:49.961 [main] AbstractAWSResourceLifecycle - Removed IotPolicy in IotLifecycle
[INFO ] 2023-08-01 20:42:50.069 [main] AbstractAWSResourceLifecycle - Removed IotRoleAlias in IotLifecycle
[INFO ] 2023-08-01 20:42:50.285 [main] AbstractAWSResourceLifecycle - Removed IotPolicy in IotLifecycle
[INFO ] 2023-08-01 20:42:50.766 [main] AbstractAWSResourceLifecycle - Removed GreengrassDeployment in GreengrassV2Lifecycle
[INFO ] 2023-08-01 20:42:51.001 [main] AbstractAWSResourceLifecycle - Removed GreengrassComponent in GreengrassV2Lifecycle
[INFO ] 2023-08-01 20:42:51.263 [main] AbstractAWSResourceLifecycle - Removed GreengrassCoreDevice in GreengrassV2Lifecycle
[INFO ] 2023-08-01 20:42:51.263 [main] AWSResourcesSteps - Successfully removed externally created resources
[INFO ] 2023-08-01 20:42:51.267 [main] AgentControlImpl - shutting down channel with agent id aws.greengrass.client.Mqtt5JavaPahoClient
[INFO ] 2023-08-01 20:42:51.276 [main] AgentControlImpl - channel terminated with agent id aws.greengrass.client.Mqtt5JavaPahoClient
[INFO ] 2023-08-01 20:42:51.276 [main] MqttControlSteps - Agent aws.greengrass.client.Mqtt5JavaPahoClient is disconnected
[INFO ] 2023-08-01 20:42:51.289 [main] EngineControlImpl - gRPC MQTT client control server stopped
[INFO ] 2023-08-01 20:42:51.301 [main] LoggerSteps - Clearing thread context on scenario: 'GGMQ-1-T25-v5-paho-java: As a customer, I connect with same client id twice (not reconnect) and be able to publish and subscribe to messages.'
[INFO ] 2023-08-01 20:42:51.313 [main] StepTrackingReporting - Passed: 'GGMQ-1-T25-v5-paho-java: As a customer, I connect with same client id twice (not reconnect) and be able to publish and subscribe to messages.'
[INFO ] 2023-08-01 20:42:51.513 [Thread-1] AWSResourcesCleanupModule - Cleaned up TestContext{testId=TestId{prefix=gg, id=df6909aca85d4c94507b}, testDirectory=/tmp/gg-testing-12375312970262000714/gg-df6909aca85d4c94507b, testResultsPath=logs, cleanupContext=CleanupContext{persistAWSResources=false, persistInstalledSoftware=false, persistGeneratedFiles=false}, initializationContext=InitializationContext{persistModes=[], persistAWSResources=false, persistInstalledSoftware=false, persistGeneratedFiles=false}, logLevel=INFO, installRoot=/tmp/gg-testing-12375312970262000714/gg-df6909aca85d4c94507b, currentUser=root, coreThingName=gg-df6909aca85d4c94507b-ggc-thing, coreVersion=2.11.1, tesRoleName=, hsmConfigured=false, trustedPluginsPaths=[]}
[INFO ] 2023-08-01 20:42:51.514 [Thread-1] AWSResourcesCleanupModule - Cleaned up com.aws.greengrass.testing.resources.AWSResources@b4b352d4
[INFO ] 2023-08-01 20:42:51.515 [Thread-1] AWSResourcesCleanupModule - Cleaned up com.aws.greengrass.testing.api.device.local.LocalDevice@12e12ac9
[INFO ] 2023-08-01 20:42:51.530 [Thread-1] AWSResourcesCleanupModule - Cleaned up GreengrassContext{version=2.11.1, tempDirectory=/tmp/gg-testing-12375312970262000714, cleanupContext=CleanupContext{persistAWSResources=false, persistInstalledSoftware=false, persistGeneratedFiles=false}}
[INFO ] 2023-08-01 20:42:51.533 [Thread-1] AWSResourcesCleanupModule - Cleaned up com.aws.greengrass.testing.resources.iam.IamLifecycle$$EnhancerByGuice$$29755102@e14b7a97
[INFO ] 2023-08-01 20:42:51.533 [Thread-1] AWSResourcesCleanupModule - Cleaned up com.aws.greengrass.testing.resources.greengrass.GreengrassV2Lifecycle$$EnhancerByGuice$$22233735@1f55939a

Any additional information or context required to review the change:

By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.

@bgklika bgklika requested a review from MikeDombo August 1, 2023 13:59
And message "Test message" received on "subscriber" from "iot_data_0" topic within 5 seconds
And I rename connection "publisher" to "publisher_old"

# Reconnect publisher with the same device id
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

How can we check that the old client loses the connection due to duplicate client ID?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Such a step is not implemented at this moment. Original GGAD T25 did not have such a check

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

How do you know if this works? Do you have logs showing that the duplicate client was disconnected?

Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In that T25 we just check second connection is alive and we can publishing messages over it.
It repeat the same steps as original GGAD-1-T25.
We expecting add steps to checking disconnection when implement T26 scenario.
In addition when T26 will ready we can update T25 to add step with check connection has been really disconnected.
We expecting T26 takes a time to implement that check.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

How do you know that this actually creates a new connection and doesn't just reuse the existing connection? Can you show me a log showing the disconnect and new connect call?

Copy link

@bgklika bgklika Aug 1, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sure we can show the logs, each connection has unique connection_id number also disconnection event is logged.
To observe these events on steps level we need pass it via control to the EventStore.
I know you decided it is over complicated but despite of evergreen assert() checks are not used in the OTF and we just follows the OTF style and architecture.

@eschastlivtsev Could you attach client's and test's console logs to the task in new Test Results block ?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I've attached additional logs, where we can see that broker disconnects the previous connection
In client log:

2023-08-01T17:42:25.260Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:42:25.261 [grpc-default-executor-0] GRPCControlServer - createMqttConnection: clientId gg-df6909aca85d4c94507b-publisher broker 192.168.100.20:8883. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:42:26.468Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:42:26.467 [MQTT Rec: gg-df6909aca85d4c94507b-publisher] MqttConnectionImpl - MQTT connectionId 1 disconnected error 'null' disconnectInfo 'com.aws.greengrass.testing.mqtt5.client.GRPCClient$DisconnectInfo@42609add'. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:42:26.477Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:42:26.476 [grpc-default-executor-0] GRPCControlServer - Publish: connectionId 3 topic 'iot_data_0' QoS 1 retain false. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}
2023-08-01T17:42:26.486Z [INFO] (Copier) aws.greengrass.client.Mqtt5JavaPahoClient: stdout. [INFO ] 2023-08-01 20:42:26.483 [grpc-default-executor-0] GRPCControlServer - Publish response: connectionId 3 reason code 0 reason string ''. {scriptName=services.aws.greengrass.client.Mqtt5JavaPahoClient.lifecycle.Run, serviceName=aws.greengrass.client.Mqtt5JavaPahoClient, currentState=RUNNING}

In test console log:

[INFO ] 2023-08-01 20:42:26.581 [grpc-default-executor-0] GRPCDiscoveryServer - OnMqttDisconnect: agentId aws.greengrass.client.Mqtt5JavaPahoClient connectionId 1 disconnect 'reasonCode: 142
' error ''
[INFO ] 2023-08-01 20:42:26.584 [grpc-default-executor-0] MqttControlSteps - MQTT client disconnected. Error: 

@bgklika
Copy link

bgklika commented Aug 1, 2023

@eschastlivtsev I put PR on draft to add paho-java client before merge.

@eschastlivtsev eschastlivtsev force-pushed the GGMQ-206-implement-ggmq-scenario-based-on-ggad-1-t-25 branch from 7e351b8 to ba58062 Compare August 1, 2023 15:53
@eschastlivtsev eschastlivtsev marked this pull request as ready for review August 1, 2023 18:05
@MikeDombo MikeDombo merged commit 66d062e into aws-greengrass:uat-dev Aug 1, 2023
6 of 8 checks passed
@eschastlivtsev eschastlivtsev deleted the GGMQ-206-implement-ggmq-scenario-based-on-ggad-1-t-25 branch August 2, 2023 07:05
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants