Search code examples
linuxamazon-web-servicesaws-iot-coreaws-iot-greengrass

(nucleus):IDT 4.7.0 for greengrass v2 cloudcomponent test failed Failed at 'the Greengrass deployment is COMPLETED on the device after 180 seconds


Hope someone can help me out with this ; stuck on the error for days

Describe the Error

Running IDT shows error in cloudcomponent log

the Greengrass deployment is COMPLETED on the device after 180 seconds

comes up with

2023-Mar-29 10:22:22,494 [cloudComponent] [idt-c057b1fc3d6bc618a399] [ERROR] greengrass/features/cloudComponent.feature - Failed at step: 'the Greengrass deployment is COMPLETED on the device after 180 seconds'
java.lang.IllegalStateException: Deployment idt-c057b1fc3d6bc618a399-gg-deployment did not reach COMPLETED
        at com.aws.greengrass.testing.features.DeploymentSteps.deploymentSucceeds(DeploymentSteps.java:311) ~[AWSGreengrassV2TestingIDT-1.0.jar:?]
        at ✽.the Greengrass deployment is COMPLETED on the device after 180 seconds(classpath:greengrass/features/cloudComponent.feature:26) ~[?:?]
2023-Mar-29 10:22:22,510 [cloudComponent] [idt-c057b1fc3d6bc618a399] [INFO] greengrass/features/cloudComponent.feature - Finished step: 'the com.aws.HelloWorld log on the device contains the line "Hello World!!" within 20 seconds' with status SKIPPED
2023-03-28T05:33:39.019Z [ERROR] (Copier) com.aws.greengrass.util.orchestration.SystemdUtils: systemd-setup. {stderr=Created symlink /etc/systemd/system/multi-user.target.wants/greengrass.service → /etc/systemd/system/greengrass.service., command=systemctl enable greengrass.service}

It seems like the mqtt test also have same error in the log after a couple times of trying not sure the problem related to the error

but some how the mqtt test pass

./mqtt/mqttpubsub/greengrass_2023_03_29_01_0.log:2023-03-29T01:59:34.313Z [ERROR] (Copier) com.aws.greengrass.util.orchestration.SystemdUtils: systemd-setup. {stderr=Created symlink /etc/systemd/system/multi-user.target.wants/greengrass.service → /etc/systemd/system/greengrass.service., command=systemctl enable greengrass.service}

Details:

I am tyring to use IDT for greengrass v2 following https://docs.aws.amazon.com/greengrass/v2/developerguide/device-config-setup.html by following the official guide

after by launching greengrass with

sudo -E java -Droot="/test/greengrass/v2" -Dlog.store=FILE -jar ./GreengrassInstaller/lib/Greengrass.jar --aws-region us-west-2 --thing-name IM30 --thing-group-name GreengrassQuickStartGroup_test --component-default-user root:root --provision true --setup-system-service true --deploy-dev-tools true

it shows

"Successfully set up Nucleus as a system service"

while watching systemctl status greengrass.service


root@i350-evk:/test/greengrass/v2# systemctl status greengrass.service
● greengrass.service - Greengrass Core
     Loaded: loaded (/etc/systemd/system/greengrass.service; enabled; vendor preset: disabled)
     Active: active (running) since Wed 2023-03-29 02:46:35 UTC; 16s ago
   Main PID: 11178 (sh)
      Tasks: 68 (limit: 3443)
     Memory: 277.0M
     CGroup: /system.slice/greengrass.service
             ├─11178 /bin/sh /test/greengrass/v2/alts/current/distro/bin/loader
             └─11182 java -Dlog.store=FILE -Dlog.store=FILE -Droot=/test/greengrass/v2 -jar /test/greengrass/v2/alts/current/distro/lib/Greengrass.jar --setup-system-service false

Mar 29 02:46:35 i350-evk systemd[1]: Started Greengrass Core.
Mar 29 02:46:35 i350-evk sh[11178]: Greengrass root: /test/greengrass/v2
Mar 29 02:46:35 i350-evk sh[11178]: Java executable: java
Mar 29 02:46:35 i350-evk sh[11178]: JVM options: -Dlog.store=FILE -Droot=/test/greengrass/v2
Mar 29 02:46:35 i350-evk sh[11178]: Nucleus options: --setup-system-service false
Mar 29 02:46:39 i350-evk sh[11182]: Launching Nucleus...
Mar 29 02:46:46 i350-evk sh[11182]: Launched Nucleus successfully.

Mar 29 02:46:35 i350-evk systemd[1]: Started Greengrass Core.
Mar 29 02:46:35 i350-evk sh[11178]: Greengrass root: /test/greengrass/v2
Mar 29 02:46:35 i350-evk sh[11178]: Java executable: java
Mar 29 02:46:35 i350-evk sh[11178]: JVM options: -Dlog.store=FILE -Droot=/test/greengrass/v2
Mar 29 02:46:35 i350-evk sh[11178]: Nucleus options: --setup-system-service false
Mar 29 02:46:39 i350-evk sh[11182]: Launching Nucleus...
Mar 29 02:46:46 i350-evk sh[11182]: Launched Nucleus successfully.

however while I launch the deployment of idt with command:

./devicetester_linux_x86-64 run-suite --suite-id GGV2Q_2.5.0 --userdate userdata.json

the test_manager.log in idt shows

[ERROR] [2023-03-28 16:56:12]: Test exited unsuccessfully testCaseId=cloudcomponent error=exit status 1 executionId=9f12b10c-cd42-11ed-bb24-080027641c32
[INFO] [2023-03-28 16:56:12]: All tests finished. executionId=9f12b10c-cd42-11ed-bb24-080027641c32
[INFO] [2023-03-28 16:56:13]:

========== Test Summary ==========
Execution Time:         26m50s
Tests Completed:        7
Tests Passed:           6
Tests Failed:           1
Tests Skipped:          0
----------------------------------
Test Groups:
    lambdadeployment:           PASSED
    mqtt:                       PASSED
    component:                  FAILED
    pretestvalidation:          PASSED
    coredependencies:           PASSED
    version:                    PASSED
----------------------------------
Failed Tests:
    Group Name: component
        Test Name: cloudcomponent
            Reason: Failed at 'the Greengrass deployment is COMPLETED on the device after 180 seconds'
----------------------------------
Path to AWS IoT Device Tester Report: /home/user/test/devicetester_greengrass_v2_linux/results/20230328T162913/awsiotdevicetester_report.xml
Path to Test Execution Logs: /home/user/test/devicetester_greengrass_v2_linux/results/20230328T162913/logs
Path to Aggregated JUnit Report: /home/user/test/devicetester_greengrass_v2_linux/results/20230328T162913/GGV2Q_Report.xml
==================================



logs/component/cloudcomponent greengrass_2023_03_28_05_0.log shows:

2023-03-28T05:33:10.582Z [INFO] (main) com.aws.greengrass.deployment.DeviceConfiguration: Copy Nucleus artifacts to component store. {destination=/test/greengrass/v2/packages/artifacts-unarchived/aws.greengrass.Nucleus/2.9.4/aws.greengrass.nucleus, source=/test/GreengrassInstaller}
2023-03-28T05:33:37.517Z [INFO] (main) com.aws.greengrass.lifecyclemanager.KernelLifecycle: Waiting for services to shutdown. {}
2023-03-28T05:33:37.543Z [INFO] (main) com.aws.greengrass.lifecyclemanager.Kernel: effective-config-dump-complete. {file=/test/greengrass/v2/config/effectiveConfig.yaml}
2023-03-28T05:33:39.019Z [ERROR] (Copier) com.aws.greengrass.util.orchestration.SystemdUtils: systemd-setup. {stderr=Created symlink /etc/systemd/system/multi-user.target.wants/greengrass.service → /etc/systemd/system/greengrass.service., command=systemctl enable greengrass.service}
2023-03-28T05:33:39.889Z [INFO] (main) com.aws.greengrass.util.orchestration.SystemdUtils: systemd-setup. Successfully set up systemd service. {}
2023-03-28T05:33:39.891Z [INFO] (main) com.aws.greengrass.lifecyclemanager.KernelLifecycle: system-shutdown. {main=null}
2023-03-28T05:33:39.902Z [INFO] (main) com.aws.greengrass.lifecyclemanager.KernelLifecycle: Waiting for services to shutdown. {}
2023-03-28T05:33:39.933Z [INFO] (main) com.aws.greengrass.lifecyclemanager.Kernel: effective-config-dump-complete. {file=/test/greengrass/v2/config/effectiveConfig.yaml}
2023-03-28T05:33:39.937Z [INFO] (Serialized listener processor) com.aws.greengrass.lifecyclemanager.KernelLifecycle: executor-service-shutdown-initiated. {}
2023-03-28T05:33:39.938Z [INFO] (main) com.aws.greengrass.lifecyclemanager.KernelLifecycle: Waiting for executors to shutdown. {}
2023-03-28T05:33:39.940Z [INFO] (main) com.aws.greengrass.lifecyclemanager.KernelLifecycle: executor-service-shutdown-complete. {executor-terminated=true, scheduled-executor-terminated=true}
2023-03-28T05:33:39.941Z [INFO] (main) com.aws.greengrass.lifecyclemanager.KernelLifecycle: context-shutdown-initiated. {}
2023-03-28T05:33:39.945Z [INFO] (main) com.aws.greengrass.lifecyclemanager.KernelLifecycle: context-shutdown-complete. {}

greengrass-test-run.log shows:

2023-Mar-29 10:19:21,514 [cloudComponent] [idt-c057b1fc3d6bc618a399] [INFO] greengrass/features/cloudComponent.feature - Finished step: 'I create a Greengrass deployment with components' with status PASSED
2023-Mar-29 10:19:22,164 [cloudComponent] [idt-c057b1fc3d6bc618a399] [INFO] com.aws.greengrass.testing.resources.AbstractAWSResourceLifecycle - Created GreengrassDeployment in GreengrassV2Lifecycle
2023-Mar-29 10:19:22,165 [cloudComponent] [idt-c057b1fc3d6bc618a399] [INFO] com.aws.greengrass.testing.features.DeploymentSteps - Created Greengrass deployment: fe860f32-3236-4493-b71d-56e585382c0c
2023-Mar-29 10:19:22,166 [cloudComponent] [idt-c057b1fc3d6bc618a399] [INFO] greengrass/features/cloudComponent.feature - Finished step: 'I deploy the Greengrass deployment configuration to thing group' with status PASSED
2023-Mar-29 10:22:22,494 [cloudComponent] [idt-c057b1fc3d6bc618a399] [ERROR] greengrass/features/cloudComponent.feature - Failed at step: 'the Greengrass deployment is COMPLETED on the device after 180 seconds'
java.lang.IllegalStateException: Deployment idt-c057b1fc3d6bc618a399-gg-deployment did not reach COMPLETED
        at com.aws.greengrass.testing.features.DeploymentSteps.deploymentSucceeds(DeploymentSteps.java:311) ~[AWSGreengrassV2TestingIDT-1.0.jar:?]
        at ✽.the Greengrass deployment is COMPLETED on the device after 180 seconds(classpath:greengrass/features/cloudComponent.feature:26) ~[?:?]
2023-Mar-29 10:22:22,510 [cloudComponent] [idt-c057b1fc3d6bc618a399] [INFO] greengrass/features/cloudComponent.feature - Finished step: 'the com.aws.HelloWorld log on the device contains the line "Hello World!!" within 20 seconds' with status SKIPPED
2023-Mar-29 10:22:22,511 [cloudComponent] [idt-c057b1fc3d6bc618a399] [INFO] greengrass/features/cloudComponent.feature - Finished step: 'I create a Greengrass deployment with components' with status SKIPPED
2023-Mar-29 10:22:22,512 [cloudComponent] [idt-c057b1fc3d6bc618a399] [INFO] greengrass/features/cloudComponent.feature - Finished step: 'I deploy the Greengrass deployment configuration to thing group' with status SKIPPED
2023-Mar-29 10:22:22,513 [cloudComponent] [idt-c057b1fc3d6bc618a399] [INFO] greengrass/features/cloudComponent.feature - Finished step: 'the Greengrass deployment is COMPLETED on the device after 180 seconds' with status SKIPPED
2023-Mar-29 10:22:22,513 [cloudComponent] [idt-c057b1fc3d6bc618a399] [INFO] greengrass/features/cloudComponent.feature - Finished step: 'the com.aws.HelloWorld log on the device contains the line "Hello World Updated!!" within 20 seconds' with status SKIPPED

To Reproduce See above.

Expected behavior IDT for greengrass v2 pass all of the test

Actual behavior IDT for greengrass v2 failed on cloud component test

Environment

Additional context Notice the same error on https://github.com/aws-greengrass/aws-greengrass-nucleus/issues/876#issuecomment-786948524 not sure if it is related but other test Pass

the link above show that the config (.yaml) of greengrass causing the error but I do believe it has been set correctly

see below

my effectiveConfig.yaml :

---
system:
  certificateFilePath: "/test/greengrass/v2/thingCert.crt"
  privateKeyPath: "/test/greengrass/v2/privKey.key"
  rootCaPath: "/test/greengrass/v2/rootCA.pem"
  rootpath: "/test/greengrass/v2"
  thingName: "IM30"
services:
  aws.greengrass.LocalHelloWorld:
    componentType: "GENERIC"
    configuration: {}
    dependencies: []
    lifecycle:
      Run: "java -DcomponentName=\"HelloWorld\" -jar /test/greengrass/v2/packages/artifacts/aws.greengrass.LocalHelloWorld/1.0.0/cloudcomponent.jar"
    version: "1.0.0"
  aws.greengrass.Nucleus:
    componentType: "NUCLEUS"
    configuration:
      awsRegion: "us-west-2"
      componentStoreMaxSizeBytes: "10000000000"
      deploymentPollingFrequencySeconds: "15"
      envStage: "prod"
      fleetStatus:
        periodicStatusPublishIntervalSeconds: 86400
      greengrassDataPlaneEndpoint: ""
      greengrassDataPlanePort: "8443"
      httpClient: {}
      interpolateComponentConfiguration: false
      iotCredEndpoint: "xxx.credentials.iot.us-west-2.amazonaws.com"
      iotDataEndpoint: "xxx-ats.iot.us-west-2.amazonaws.com"
      iotRoleAlias: "GreengrassV2TokenExchangeRoleAlias"
      jvmOptions: "-Dlog.store=FILE"
      logging: {}
      mqtt:
        spooler: {}
      networkProxy:
        proxy: {}
      platformOverride: {}
      runWithDefault:
        posixShell: "sh"
        posixUser: "root:root"
      telemetry: {}
    dependencies: []
    lifecycle:
      bootstrap:
        requiresPrivilege: "true"
        script: "\nset -eu\nKERNEL_ROOT=\"/test/greengrass/v2\"\nUNPACK_DIR=\"/test/greengrass/v2/packages/artifacts-unarchived/aws.greengrass.Nucleus/2.9.4/aws.greengrass.nucleus\"\
          \nrm -r \"$KERNEL_ROOT\"/alts/current/*\necho \"-Dlog.store=FILE\" > \"\
          $KERNEL_ROOT/alts/current/launch.params\"\nln -sf \"$UNPACK_DIR\" \"$KERNEL_ROOT/alts/current/distro\"\
          \nexit 100"
    version: "2.9.4"
  DeploymentService:
    ComponentToGroups:
      aws.greengrass.LocalHelloWorld:
        "4e69ead5-a595-4b96-a7c8-45da74475fe0": "LOCAL_DEPLOYMENT"
    dependencies: []
    GroupToLastDeployment:
      LOCAL_DEPLOYMENT:
        configArn: null
        timestamp: 1679992938275
      thing/IM30:
        configArn: "arn:aws:greengrass:us-west-2:116407744508:configuration:thing/IM30:111"
        timestamp: 1679993636499
      thinggroup/GreengrassQuickStartGroup_test:
        configArn: "arn:aws:greengrass:us-west-2:116407744508:configuration:thinggroup/GreengrassQuickStartGroup_test:51"
        timestamp: 1679993661994
    GroupToRootComponents:
      LOCAL_DEPLOYMENT:
        aws.greengrass.LocalHelloWorld:
          groupConfigArn: "4e69ead5-a595-4b96-a7c8-45da74475fe0"
          groupConfigName: "LOCAL_DEPLOYMENT"
          version: "1.0.0"
      thing/IM30: {}
      thinggroup/GreengrassQuickStartGroup_test: {}
    runtime:
      ProcessedDeployments:
        "1679993661353":
          ConfigurationArn: "arn:aws:greengrass:us-west-2:116407744508:configuration:thing/IM30:111"
          DeploymentId: "arn:aws:greengrass:us-west-2:116407744508:configuration:thing/IM30:111"
          DeploymentRootPackages: []
          DeploymentStatus: "SUCCEEDED"
          DeploymentStatusDetails:
            detailed-deployment-status: "SUCCESSFUL"
          DeploymentType: "SHADOW"
          GreengrassDeploymentId: "ef974963-4dfe-49a4-a1fc-73c8aa49a545"
    version: "0.0.0"
  FleetStatusService:
    dependencies: []
    lastPeriodicUpdateTime: 1679981624527
    sequenceNumber: 122
    version: "0.0.0"
  main:
    dependencies:
    - "FleetStatusService:HARD"
    - "DeploymentService:HARD"
    - "aws.greengrass.LocalHelloWorld"
    - "TelemetryAgent:HARD"
    - "aws.greengrass.Nucleus"
    - "UpdateSystemPolicyService:HARD"
    - "aws.greengrass.Nucleus"
    lifecycle: {}
    runtime:
      service-digest: {}
  TelemetryAgent:
    dependencies: []
    runtime:
      lastPeriodicAggregationMetricsTime: 1679981624784
      lastPeriodicPublishMetricsTime: 1679981624784
    version: "0.0.0"
  UpdateSystemPolicyService:
    dependencies: []
    version: "0.0.0"



Solution

  • See the answer and details in aws re:post https://repost.aws/questions/QU9lwv47QcQHWAE0IdCiy5Ig/can-anyone-help-me-out-with-the-idt-error-problem-the-greengrass-deployment-is-completed-on-the-device-after-180-seconds

    https://repost.aws/questions/QUfFmnIZhqQTa2qcwMpale-A/nucleus-idt-4-7-0-for-greengrass-v2-cloudcomponent-test-failed-failed-at-the-greengrass-deployment-is-completed-on-the-device-after-180-seconds

    after days of research we found out that the security credential cause the problem

    ========== Test Summary ==========
    Execution Time:     23m57s
    Tests Completed:    7
    Tests Passed:       7
    Tests Failed:       0
    Tests Skipped:      0
    ----------------------------------
    Test Groups:
        coredependencies:       PASSED
        version:            PASSED
        lambdadeployment:       PASSED
        component:          PASSED
        mqtt:           PASSED
        pretestvalidation:      PASSED
    ----------------------------------
    Path to AWS IoT Device Tester Report: /home/user/test/devicetester_greengrass_v2_linux/results/20230407T152513/awsiotdevicetester_report.xml
    Path to Test Execution Logs: /home/user/test/devicetester_greengrass_v2_linux/results/20230407T152513/logs
    Path to Aggregated JUnit Report: /home/user/test/devicetester_greengrass_v2_linux/results/20230407T152513/GGV2Q_Report.xml