Started by user RDK-Test Running as SYSTEM Building in workspace /var/lib/jenkins/workspace/JOB1 [JOB1] $ /var/lib/jenkins/tools/hudson.tasks.Maven_MavenInstallation/installmaven/bin/mvn -s /mnt/maven/settings.xml clean install -U exec:java -DskipTests=true -DretryByDefault=false -DbuildType=RDK -Dhttps.protocols=TLSv1.1,TLSv1.2 -Dsun.security.ssl.allowUnsafeRenegotiation=true -Dautomatics.properties.file=http://192.168.2.145:8080/AutomaticsProps/automatics.properties [INFO] Scanning for projects... [WARNING] [WARNING] Some problems were encountered while building the effective model for RDKMAutomationRDKBTests:rdkb-automation:jar:0.0.1-SNAPSHOT [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 171 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 314 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 457 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 600 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 743 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 886 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 1029 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 1172 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 1315 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 1458 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 1601 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 1744 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 1887 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 2030 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 2173 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 2316 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 2459 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 2602 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 2745 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 2888 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 3031 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 3174 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 3317 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 3460 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 3603 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 3746 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 3889 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 4032 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 4175 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 4318 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 4461 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 4604 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 4747 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 4890 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 5033 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 5176 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 5319 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 5462 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 5605 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 5748 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 5891 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 6034 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 6177 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 6320 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 6463 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 6606 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 6749 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 6892 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 7035 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 7178 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 7321 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 7464 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 7607 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 7750 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 7893 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 8036 [WARNING] [WARNING] It is highly recommended to fix these problems because they threaten the stability of your build. [WARNING] [WARNING] For this reason, future Maven versions might no longer support building such malformed projects. [WARNING] [INFO] [INFO] --------------< RDKMAutomationRDKBTests:rdkb-automation >--------------- [INFO] Building rdkb-automation 0.0.1-SNAPSHOT [INFO] --------------------------------[ jar ]--------------------------------- [INFO] [INFO] --- maven-clean-plugin:2.5:clean (default-clean) @ rdkb-automation --- [INFO] Deleting /var/lib/jenkins/workspace/JOB1/target [INFO] [INFO] --- maven-resources-plugin:2.6:resources (default-resources) @ rdkb-automation --- [INFO] Using 'UTF-8' encoding to copy filtered resources. [INFO] Copying 3 resources [INFO] [INFO] --- maven-compiler-plugin:3.11.0:compile (default-compile) @ rdkb-automation --- [INFO] No sources to compile [INFO] [INFO] --- maven-resources-plugin:2.6:testResources (default-testResources) @ rdkb-automation --- [INFO] Using 'UTF-8' encoding to copy filtered resources. [INFO] skip non existing resourceDirectory /var/lib/jenkins/workspace/JOB1/src/test/resources [INFO] [INFO] --- maven-compiler-plugin:3.11.0:testCompile (default-testCompile) @ rdkb-automation --- [INFO] Changes detected - recompiling the module! :source [INFO] Compiling 119 source files with javac [debug target 11] to target/test-classes [INFO] /var/lib/jenkins/workspace/JOB1/src/test/java/com/automatics/rdkb/tests/docsis/BroadBandDocsisTest.java: /var/lib/jenkins/workspace/JOB1/src/test/java/com/automatics/rdkb/tests/docsis/BroadBandDocsisTest.java uses unchecked or unsafe operations. [INFO] /var/lib/jenkins/workspace/JOB1/src/test/java/com/automatics/rdkb/tests/docsis/BroadBandDocsisTest.java: Recompile with -Xlint:unchecked for details. [INFO] [INFO] --- maven-surefire-plugin:2.12.4:test (default-test) @ rdkb-automation --- [INFO] Tests are skipped. [INFO] [INFO] --- maven-jar-plugin:2.4:jar (default-jar) @ rdkb-automation --- [INFO] Building jar: /var/lib/jenkins/workspace/JOB1/target/rdkb-automation-0.0.1-SNAPSHOT.jar [INFO] [INFO] --- maven-install-plugin:2.4:install (default-install) @ rdkb-automation --- [INFO] Installing /var/lib/jenkins/workspace/JOB1/target/rdkb-automation-0.0.1-SNAPSHOT.jar to /root/.m2/repository/RDKMAutomationRDKBTests/rdkb-automation/0.0.1-SNAPSHOT/rdkb-automation-0.0.1-SNAPSHOT.jar [INFO] Installing /var/lib/jenkins/workspace/JOB1/pom.xml to /root/.m2/repository/RDKMAutomationRDKBTests/rdkb-automation/0.0.1-SNAPSHOT/rdkb-automation-0.0.1-SNAPSHOT.pom [INFO] [INFO] >>> exec-maven-plugin:1.2.1:java (default-cli) > validate @ rdkb-automation >>> [INFO] [INFO] <<< exec-maven-plugin:1.2.1:java (default-cli) < validate @ rdkb-automation <<< [INFO] [INFO] [INFO] --- exec-maven-plugin:1.2.1:java (default-cli) @ rdkb-automation --- 12:07:59,019 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback-test.xml] at [jar:file:/root/.m2/repository/com/automatics/apps/automatics-core/2.24.0/automatics-core-2.24.0.jar!/logback-test.xml] 12:07:59,031 |-INFO in ch.qos.logback.core.joran.spi.ConfigurationWatchList@183885a - URL [jar:file:/root/.m2/repository/com/automatics/apps/automatics-core/2.24.0/automatics-core-2.24.0.jar!/logback-test.xml] is not of type file 12:07:59,287 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender] 12:07:59,289 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [stdOutAppender] 12:07:59,296 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@7:13 - no applicable action for [onMatch], current ElementPath is [[configuration][appender][filter][onMatch]] 12:07:59,296 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@8:16 - no applicable action for [onMismatch], current ElementPath is [[configuration][appender][filter][onMismatch]] 12:07:59,296 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property 12:07:59,311 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender] 12:07:59,313 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [deviceSiftingAppender] 12:07:59,314 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@18:13 - no applicable action for [onMatch], current ElementPath is [[configuration][appender][filter][onMatch]] 12:07:59,315 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@19:16 - no applicable action for [onMismatch], current ElementPath is [[configuration][appender][filter][onMismatch]] 12:07:59,316 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.sift.MDCBasedDiscriminator] for [discriminator] property 12:07:59,319 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender] 12:07:59,319 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [TraceLogger] 12:07:59,320 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.sift.MDCBasedDiscriminator] for [discriminator] property 12:07:59,320 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender] 12:07:59,320 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [SerialTrace] 12:07:59,320 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.sift.MDCBasedDiscriminator] for [discriminator] property 12:07:59,321 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender] 12:07:59,321 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [crash-analysis] 12:07:59,321 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.sift.MDCBasedDiscriminator] for [discriminator] property 12:07:59,322 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [org.apache.http] to false 12:07:59,322 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - org.apache.http level set to INFO 12:07:59,322 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [deviceSiftingAppender] to Logger[org.apache.http] 12:07:59,322 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [ConnectionTrace] to TRACE 12:07:59,323 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [ConnectionTrace] to false 12:07:59,323 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [TraceLogger] to Logger[ConnectionTrace] 12:07:59,323 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [SerialTrace] to TRACE 12:07:59,323 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [SerialTrace] to false 12:07:59,323 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [SerialTrace] to Logger[SerialTrace] 12:07:59,323 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [crash-analysis] to DEBUG 12:07:59,323 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [crash-analysis] to false 12:07:59,323 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [crash-analysis] to Logger[crash-analysis] 12:07:59,323 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [stdOutAppender] to Logger[ROOT] 12:07:59,323 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [deviceSiftingAppender] to Logger[ROOT] 12:07:59,323 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration. 12:07:59,324 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@211a9d38 - Registering current configuration as safe fallback point [INFO][2024-09-27 12:07:59,325][[com.automatics.executor.Starter.main()] - Starting the execution process for the given test cases. 12:07:59,327 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.FileAppender] 12:07:59,328 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE-test-suite] 12:07:59,330 |-INFO in ch.qos.logback.core.FileAppender[FILE-test-suite] - File property is set to [target/logs/test-suite.log] [INFO][2024-09-27 12:07:59,339][[com.automatics.executor.Starter.main()] - Initializing application context partner-applicationContext.xml [INFO][2024-09-27 12:08:00,531][[com.automatics.executor.Starter.main()] - Initializing application context applicationContext.xml [INFO][2024-09-27 12:08:00,728][[com.automatics.executor.Starter.main()] - AutomaticsPropertyUtility: Reading automatics.properties file from http://192.168.2.145:8080/AutomaticsProps/automatics.properties [INFO][2024-09-27 12:08:00,916][[com.automatics.executor.Starter.main()] - Automatics Response - {"message":"Data already fetched from Automatics by http:\/\/192.168.2.231:8080\/job\/python_JOB1\/31 for this job id. Will not be provided again."} [INFO][2024-09-27 12:08:00,927][[com.automatics.executor.Starter.main()] - ***************** Automatics BUILD PARAMETERS ***************** [INFO][2024-09-27 12:08:00,936][[com.automatics.executor.Starter.main()] - message | Data already fetched from Automatics by http://192.168.2.231:8080/job/python_JOB1/31 for this job id. Will not be provided again. [INFO][2024-09-27 12:08:00,936][[com.automatics.executor.Starter.main()] - Shut Down Hook Attached. [INFO][2024-09-27 12:08:00,992][[com.automatics.executor.Starter.main()] - Start Execution Test Suite [INFO][2024-09-27 12:08:00,994][[com.automatics.executor.Starter.main()] - Bean testInitializer is not configured. [INFO][2024-09-27 12:08:00,994][[com.automatics.executor.Starter.main()] - Cleaning the trace log directory [INFO][2024-09-27 12:08:01,072][[com.automatics.executor.Starter.main()] - AutomaticsPropertyUtility: Reading automatics.properties file from http://192.168.2.145:8080/AutomaticsProps/automatics.properties [INFO][2024-09-27 12:08:01,077][[com.automatics.executor.Starter.main()] - >>>[INIT]: Validating config files [INFO][2024-09-27 12:08:01,078][[com.automatics.executor.Starter.main()] - INIT- Requesting device config from http://192.168.2.145:8080/AutomaticsProps/deviceProps.json [INFO][2024-09-27 12:08:01,367][[com.automatics.executor.Starter.main()] - INIT- Requesting device config from http://192.168.2.145:8080/AutomaticsProps/deviceProps.json [INFO][2024-09-27 12:08:01,373][[com.automatics.executor.Starter.main()] - frameworkSupportedModels=Rpi-RDKB,Rpi-RDKV, [INFO][2024-09-27 12:08:01,374][[com.automatics.executor.Starter.main()] - rdkvGWModels= [INFO][2024-09-27 12:08:01,374][[com.automatics.executor.Starter.main()] - rdkvCLModels=Rpi-RDKV, [INFO][2024-09-27 12:08:01,374][[com.automatics.executor.Starter.main()] - rdkbModels=Rpi-RDKB, [INFO][2024-09-27 12:08:01,375][[com.automatics.executor.Starter.main()] - rdkcModels= [INFO][2024-09-27 12:08:01,421][[com.automatics.executor.Starter.main()] - Reading implementation from core for deviceProvider [INFO][2024-09-27 12:08:01,437][[com.automatics.executor.Starter.main()] - Is Account based test: false [INFO][2024-09-27 12:08:01,439][[com.automatics.executor.Starter.main()] - INIT-D8:3A:DD:13:8C:13 Get device details [INFO][2024-09-27 12:08:03,011][[com.automatics.executor.Starter.main()] - Fetching device details for D8:3A:DD:13:8C:13 Url Path: http://192.168.2.145:8080/DeviceManager/deviceManagement/getDeviceDetails [INFO][2024-09-27 12:08:03,298][[com.automatics.executor.Starter.main()] - Response: {"devices":[{"id":"3845","name":"","hardwareRevision":"","hostMacAddress":"D8:3A:DD:13:8C:13","hostIp4Address":"192.168.2.144","hostIp6Address":null,"clientIpAddress":"192.168.2.144","model":"Rpi-RDKB","manufacturer":"","serialNumber":"","unitAddress":null,"remoteType":"","estbMacAddress":"D8:3A:DD:13:8C:13","mtaMacAddress":"D8:3A:DD:13:8C:13","mtaIpAddress":"","ecmMacAddress":"D8:3A:DD:13:8C:13","ecmIpAddress":"192.168.2.144","headend":"HE","gatewayMac":"D8:3A:DD:13:8C:13","extraProperties":{"deviceIp":"192.168.2.144","password":"root123","connectedClients":"192.168.2.81","ethernetMacAddress":"D8:3A:DD:13:8C:13","wi-ficapability":"Dual band","connectionType":"SSH","nodePort":"22","username":"root"},"rackId":"","deviceType":"","rackName":"","slotName":"","slotNumber":"","settopGroupName":"","homeAccountName":"","homeAccountNumber":"123456789","homeAccountGroupName":"","rackServerHost":"","rackServerPort":0,"status":"GOOD","rackGroups":null,"features":null,"components":null,"wanMacAddress":""}],"errorMsg":null,"remarks":null} WARNING: An illegal reflective access operation has occurred WARNING: Illegal reflective access by com.fasterxml.jackson.databind.util.ClassUtil (file:/root/.m2/repository/com/fasterxml/jackson/core/jackson-databind/2.4.1/jackson-databind-2.4.1.jar) to field java.time.format.DateTimeFormatter.locale WARNING: Please consider reporting this to the maintainers of com.fasterxml.jackson.databind.util.ClassUtil WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations WARNING: All illegal access operations will be denied in a future release [INFO][2024-09-27 12:08:03,411][[com.automatics.executor.Starter.main()] - INIT-D8:3A:DD:13:8C:13 Obtained device details [INFO][2024-09-27 12:08:03,411][[com.automatics.executor.Starter.main()] - Found matching device object from config for rack model Rpi-RDKB [INFO][2024-09-27 12:08:03,412][[com.automatics.executor.Starter.main()] - >>>[INIT]: Found device config mapped for rack model Rpi-RDKB [INFO][2024-09-27 12:08:03,412][[com.automatics.executor.Starter.main()] - >>>[INIT]: Mapping rack model Rpi-RDKB to automatics model Rpi-RDKB [INFO][2024-09-27 12:08:03,412][[com.automatics.executor.Starter.main()] - [INIT LOG] : Non RDKV Client device [INFO][2024-09-27 12:08:03,431][[pool-2-thread-1] - INIT-{} Check if device already lockedD8:3A:DD:13:8C:13 [INFO][2024-09-27 12:08:03,457][[pool-2-thread-1] - Fetching lock status for device D8:3A:DD:13:8C:13 Url Path: http://192.168.2.145:8080/DeviceManager/deviceManagement/device/allocationStatus [INFO][2024-09-27 12:08:03,465][[pool-2-thread-1] - Response: {"allocationStatus":"AVAILABLE"} [INFO][2024-09-27 12:08:03,468][[pool-2-thread-1] - DeviceConfig allocation status [INFO][2024-09-27 12:08:03,468][[pool-2-thread-1] - [INIT LOG] : Locking device D8:3A:DD:13:8C:13 [INFO][2024-09-27 12:08:03,468][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Locking device [INFO][2024-09-27 12:08:03,476][[pool-2-thread-1] - Locking device D8:3A:DD:13:8C:13 Url Path: http://192.168.2.145:8080/DeviceManager/deviceManagement/device/lock [INFO][2024-09-27 12:08:03,535][[pool-2-thread-1] - Response: {"status":"SUCCESS","mac":"D8:3A:DD:13:8C:13"} [INFO][2024-09-27 12:08:03,538][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Lock success [INFO][2024-09-27 12:08:03,538][[pool-2-thread-1] - Setting access mechanism for device D8:3A:DD:13:8C:13 SSH [INFO][2024-09-27 12:08:03,539][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Setting access method SSH [INFO][2024-09-27 12:08:03,539][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Checking if accessibility check required [INFO][2024-09-27 12:08:03,539][[pool-2-thread-1] - Setting accessibility check required to false for device D8:3A:DD:13:8C:13 from device config [INFO][2024-09-27 12:08:03,539][[pool-2-thread-1] - Accessibility check required for device D8:3A:DD:13:8C:13 false [INFO][2024-09-27 12:08:03,539][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Checking if accessibility check required is false [INFO][2024-09-27 12:08:03,540][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Assuming device is accessible [INFO][2024-09-27 12:08:03,540][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Is device accessible true [INFO][2024-09-27 12:08:03,540][[pool-2-thread-1] - [INIT LOG] : Wiring device.D8:3A:DD:13:8C:13 [INFO][2024-09-27 12:08:03,540][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Performing provider wiring [INFO][2024-09-27 12:08:03,541][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 PowerProvider wiring [INFO][2024-09-27 12:08:03,541][[pool-2-thread-1] - Reading implementation from core for powerProvider [INFO][2024-09-27 12:08:03,542][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 DeviceConfig Connection Based TraceProvider wiring [INFO][2024-09-27 12:08:03,578][[pool-2-thread-1] - Reading implementation from partner for deviceConnectionProvider [INFO][2024-09-27 12:08:03,581][[pool-2-thread-1] - Additional trace support : null [INFO][2024-09-27 12:08:03,582][[pool-2-thread-1] - settopObj.getModel() = Rpi-RDKB [INFO][2024-09-27 12:08:03,582][[pool-2-thread-1] - Additional logging requirement if any enabled will be skipped due to configuration issue [INFO][2024-09-27 12:08:03,585][[pool-2-thread-1] - Trace Log File location /var/lib/jenkins/workspace/JOB1/target/settoptrace/D83ADD138C13settop_trace.log [INFO][2024-09-27 12:08:03,585][[pool-2-thread-1] - Crash Analysis not enabled during trace monitoring [INFO][2024-09-27 12:08:03,586][[pool-2-thread-1] - Serial based trace to be initialized: false [INFO][2024-09-27 12:08:03,586][[pool-2-thread-1] - [INIT LOG] : Adding dut to locked list [INFO][2024-09-27 12:08:03,586][[pool-2-thread-1] - DeviceConfig Macs D8:3A:DD:13:8C:13 [INFO][2024-09-27 12:08:03,587][[pool-2-thread-1] - Dut Added to locked list D8:3A:DD:13:8C:13 [INFO][2024-09-27 12:08:06,413][[com.automatics.executor.Starter.main()] - Finished Non-IP Initialization Threads [INFO][2024-09-27 12:08:06,414][[com.automatics.executor.Starter.main()] - Collecting dut info [INFO][2024-09-27 12:08:06,415][[com.automatics.executor.Starter.main()] - Requesting data from http://192.168.2.59:8084/api/rack/service/getmasterconfig?configName=TEST_TYPE_MAP [INFO][2024-09-27 12:08:06,456][[com.automatics.executor.Starter.main()] - {"configName":"TEST_TYPE_MAP","configValue":"QUICK=qt,QUICK_CI=qt,FAST_QUICK=fast_qt,FAST_QUICK_CI=fast_qt,1HOUR=1h,2DAYS=2d,2DAYS_L2=2d_L2,2DAYS_L3=2d_L3,2DAYS_L4=2d_L4,4HOUR=4h,4HOUR_L2=4h_L2,4HOUR_L3=4h_L3,4HOUR_L4=4h_L4,CI=ci,COMPONENT=GROUP_OR_AUTOID,QT=qt,CI_QT=qt,1H=1h,4H=4h,2D=2d,PERFORMANCE=PERFORMANCE,SANITY=1h,SANITY_XI3=1h,SMOKE=4h,SMOKE_L2=4h_L2,SMOKE_L3=4h_L2,SMOKE_L4=4h_L2,SMOKE_XI3=4h,FUNCTIONAL=2d,FUNCTIONAL_L2=2d_L2,FUNCTIONAL_L3=2d_L3,FUNCTIONAL_L4=2d_L4,FUNCTIONAL_XI3=2d","isUserEditable":"Y","updatedDate":"2023-10-17T04:50:45.000+00:00","updatedUser":"root@localhost"} ... ... TestNG 7.0.1 by Cédric Beust (cedric@beust.com) ... [INFO][2024-09-27 12:08:07,570][[com.automatics.executor.Starter.main()] - AutomaticsTapApi instance not available. Creating new instance [INFO][2024-09-27 12:08:07,570][[com.automatics.executor.Starter.main()] - Creating new instance for AutomaticsTapApi [INFO][2024-09-27 12:08:07,570][[com.automatics.executor.Starter.main()] - Reading implementation from partner for deviceConnectionProvider [INFO][2024-09-27 12:08:07,641][[com.automatics.executor.Starter.main()] - >>>[BEFORE_SUITE]: Perform before suite initialization [INFO][2024-09-27 12:08:07,641][[com.automatics.executor.Starter.main()] - Bean testInitializer is not configured. [INFO][2024-09-27 12:08:07,641][[com.automatics.executor.Starter.main()] - Adding locked devices to dut object in AutomaticsTestBase [INFO][2024-09-27 12:08:07,641][[com.automatics.executor.Starter.main()] - Locked Settops: 1 [INFO][2024-09-27 12:08:07,643][[pool-6-thread-1] - >>>[BEFORE_SUITE]: Verifying if build loaded in device as expected [INFO][2024-09-27 12:08:07,643][[pool-6-thread-1] - [BEFORE-SUITE:]Expected build in device is rdkb-generic-broadband-image_rdk-next_20240801124800 [INFO][2024-09-27 12:08:07,643][[pool-6-thread-1] - [BEFORE-SUITE:]Verifying if build changed before test [INFO][2024-09-27 12:08:07,643][[pool-6-thread-1] - Skipping build change verification as partner specific initialization is not configured. [INFO][2024-09-27 12:08:07,643][[pool-6-thread-1] - [BEFORE-SUITE:]Build Change Status: NO_CHANGE [INFO][2024-09-27 12:08:07,643][[pool-6-thread-1] - >>>[BEFORE_SUITE]: Build in device is as expected [INFO][2024-09-27 12:08:07,644][[pool-6-thread-1] - >>>[BEFORE_SUITE]: Setting appropritate build appender based on executionMode [INFO][2024-09-27 12:08:07,761][[pool-6-thread-1] - Skipping setting of execution mode in device as partner specific initialization is not configured. [INFO][2024-09-27 12:08:07,761][[pool-6-thread-1] - INIT-D8:3A:DD:13:8C:13 Perform before suite initialization [INFO][2024-09-27 12:08:07,761][[pool-6-thread-1] - Skipping partner specific before suite initialization as it is not configured. [INFO][2024-09-27 12:08:07,762][[pool-6-thread-1] - >>>[BEFORE_SUITE]: Starting device connection trace [INFO][2024-09-27 12:08:07,762][[pool-6-thread-1] - Starting trace with command : tail -F -n 0 /rdklogs/logs/* [INFO][2024-09-27 12:08:07,776][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Starting reading..D83ADD138C13settop_trace.log, 12:08:07,777 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.FileAppender] 12:08:07,778 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE-D83ADD138C13settop_trace.log] 12:08:07,779 |-INFO in ch.qos.logback.core.FileAppender[FILE-D83ADD138C13settop_trace.log] - File property is set to [target/settoptrace/D83ADD138C13settop_trace.log] [INFO][2024-09-27 12:08:07,780][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Going to connect device for trace monitoring .....! [INFO][2024-09-27 12:08:07,781][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - XX Host IP Address : 192.168.2.144 [INFO][2024-09-27 12:08:07,781][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - XX Host IP6 Address : null [INFO][2024-09-27 12:08:07,781][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - XX Host MAC Address : D8:3A:DD:13:8C:13 [INFO][2024-09-27 12:08:07,781][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Settoptrace debugging:Inside Non RDKV client device [INFO][2024-09-27 12:08:07,781][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - getConnection method invoked [INFO][2024-09-27 12:08:07,825][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:08:07,825][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - SSh connection attempet : 1 [INFO][2024-09-27 12:08:07,858][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Reading server-config.xml from /var/lib/jenkins/workspace/testrepo/server-config.xml [INFO][2024-09-27 12:08:07,922][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-09-27 12:08:08,765][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:08:08,765][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:08:08,765][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - SSh connection attempet : 1 [INFO][2024-09-27 12:08:08,780][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-09-27 12:08:09,048][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Inside sendTraceCommand [INFO][2024-09-27 12:08:14,055][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:08:14,061][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Received response: [INFO][2024-09-27 12:08:14,062][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Connectiongateway iscom.automatics.providers.connection.SshConnection@278c3df [INFO][2024-09-27 12:08:14,062][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - inside null != connectionGateway condition [INFO][2024-09-27 12:08:14,062][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - gateWayDeviceInputStream iscom.jcraft.jsch.Channel$MyPipedInputStream@3ade3ef2 [INFO][2024-09-27 12:08:14,064][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Settoptrace debugging:Inside else block [INFO][2024-09-27 12:08:14,065][[PollingThread_26_(D8:3A:DD:13:8C:13)] - getConnection method invoked [INFO][2024-09-27 12:08:14,065][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Entered into readOutputFromChannel method [INFO][2024-09-27 12:08:14,065][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:08:14,065][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Is RDKV Client trace false [INFO][2024-09-27 12:08:14,065][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSh connection attempet : 1 [INFO][2024-09-27 12:08:14,082][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-09-27 12:08:14,309][[PollingThread_26_(D8:3A:DD:13:8C:13)] - sshConnectionPoll established [INFO][2024-09-27 12:08:14,309][[PollingThread_26_(D8:3A:DD:13:8C:13)] - getConnection method invoked [INFO][2024-09-27 12:08:14,310][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:08:14,310][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSh connection attempet : 1 [INFO][2024-09-27 12:08:14,325][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-09-27 12:08:14,553][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Value of responseString: null [INFO][2024-09-27 12:08:14,553][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not nul in execute: [INFO][2024-09-27 12:08:14,553][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Executing command: echo CONNECTION_IS_ALIVE [INFO][2024-09-27 12:08:14,556][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not null sendRecive: [INFO][2024-09-27 12:08:14,680][[PollingThread_26_(D8:3A:DD:13:8C:13)] - <=========================== RESPONSE =======================> CONNECTION_IS_ALIVE <=============================================================> [INFO][2024-09-27 12:08:14,681][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Closing SSH connection from DeviceIP:com.automatics.device.Device@3483c1be [INFO][2024-09-27 12:08:14,687][[PollingThread_26_(D8:3A:DD:13:8C:13)] - ConnectionPoll disconnected [INFO][2024-09-27 12:08:37,777][[pool-6-thread-1] - Is trace required for connected gateway: false [INFO][2024-09-27 12:08:37,778][[pool-6-thread-1] - Is trace required for connected gateway: false [INFO][2024-09-27 12:08:40,646][[com.automatics.executor.Starter.main()] - Starting testing on class: org.testng.TestRunner [INFO][2024-09-27 12:08:40,714][[com.automatics.executor.Starter.main()] - Doing initialization for D8:3A:DD:13:8C:13 [INFO][2024-09-27 12:08:40,729][[com.automatics.executor.Starter.main()] - Getting device account no. for D8:3A:DD:13:8C:13 [INFO][2024-09-27 12:08:40,730][[com.automatics.executor.Starter.main()] - INIT-D8:3A:DD:13:8C:13 Get device details [INFO][2024-09-27 12:08:40,742][[com.automatics.executor.Starter.main()] - Fetching device details for D8:3A:DD:13:8C:13 Url Path: http://192.168.2.145:8080/DeviceManager/deviceManagement/getDeviceDetails [INFO][2024-09-27 12:08:40,764][[com.automatics.executor.Starter.main()] - Response: {"devices":[{"id":"3845","name":"","hardwareRevision":"","hostMacAddress":"D8:3A:DD:13:8C:13","hostIp4Address":"192.168.2.144","hostIp6Address":null,"clientIpAddress":"192.168.2.144","model":"Rpi-RDKB","manufacturer":"","serialNumber":"","unitAddress":null,"remoteType":"","estbMacAddress":"D8:3A:DD:13:8C:13","mtaMacAddress":"D8:3A:DD:13:8C:13","mtaIpAddress":"","ecmMacAddress":"D8:3A:DD:13:8C:13","ecmIpAddress":"192.168.2.144","headend":"HE","gatewayMac":"D8:3A:DD:13:8C:13","extraProperties":{"deviceIp":"192.168.2.144","connectedClients":"192.168.2.81","password":"root123","ethernetMacAddress":"D8:3A:DD:13:8C:13","wi-ficapability":"Dual band","nodePort":"22","connectionType":"SSH","username":"root"},"rackId":"","deviceType":"","rackName":"","slotName":"","slotNumber":"","settopGroupName":"","homeAccountName":"","homeAccountNumber":"123456789","homeAccountGroupName":"","rackServerHost":"","rackServerPort":0,"status":"IN_USE","rackGroups":null,"features":null,"components":null,"wanMacAddress":""}],"errorMsg":null,"remarks":null} [INFO][2024-09-27 12:08:40,778][[com.automatics.executor.Starter.main()] - INIT-D8:3A:DD:13:8C:13 Obtained device details [INFO][2024-09-27 12:08:40,778][[com.automatics.executor.Starter.main()] - Device account 123456789 for device D8:3A:DD:13:8C:13 [INFO][2024-09-27 12:08:40,778][[com.automatics.executor.Starter.main()] - Getting device account no. for D8:3A:DD:13:8C:13 [INFO][2024-09-27 12:08:40,778][[com.automatics.executor.Starter.main()] - INIT-D8:3A:DD:13:8C:13 Get device details [INFO][2024-09-27 12:08:40,784][[com.automatics.executor.Starter.main()] - Fetching device details for D8:3A:DD:13:8C:13 Url Path: http://192.168.2.145:8080/DeviceManager/deviceManagement/getDeviceDetails [INFO][2024-09-27 12:08:40,796][[com.automatics.executor.Starter.main()] - Response: {"devices":[{"id":"3845","name":"","hardwareRevision":"","hostMacAddress":"D8:3A:DD:13:8C:13","hostIp4Address":"192.168.2.144","hostIp6Address":null,"clientIpAddress":"192.168.2.144","model":"Rpi-RDKB","manufacturer":"","serialNumber":"","unitAddress":null,"remoteType":"","estbMacAddress":"D8:3A:DD:13:8C:13","mtaMacAddress":"D8:3A:DD:13:8C:13","mtaIpAddress":"","ecmMacAddress":"D8:3A:DD:13:8C:13","ecmIpAddress":"192.168.2.144","headend":"HE","gatewayMac":"D8:3A:DD:13:8C:13","extraProperties":{"deviceIp":"192.168.2.144","connectedClients":"192.168.2.81","password":"root123","ethernetMacAddress":"D8:3A:DD:13:8C:13","wi-ficapability":"Dual band","connectionType":"SSH","nodePort":"22","username":"root"},"rackId":"","deviceType":"","rackName":"","slotName":"","slotNumber":"","settopGroupName":"","homeAccountName":"","homeAccountNumber":"123456789","homeAccountGroupName":"","rackServerHost":"","rackServerPort":0,"status":"IN_USE","rackGroups":null,"features":null,"components":null,"wanMacAddress":""}],"errorMsg":null,"remarks":null} [INFO][2024-09-27 12:08:40,807][[com.automatics.executor.Starter.main()] - INIT-D8:3A:DD:13:8C:13 Obtained device details [INFO][2024-09-27 12:08:40,807][[com.automatics.executor.Starter.main()] - Device account 123456789 for device D8:3A:DD:13:8C:13 [INFO][2024-09-27 12:08:40,808][[com.automatics.executor.Starter.main()] - Locking connected devices [INFO][2024-09-27 12:08:40,808][[com.automatics.executor.Starter.main()] - Getting devices for home account 123456789 [INFO][2024-09-27 12:08:40,814][[com.automatics.executor.Starter.main()] - Fetching account details for 123456789 Url Path: http://192.168.2.145:8080/DeviceManager/deviceManagement/getAccountDetails [INFO][2024-09-27 12:08:40,829][[com.automatics.executor.Starter.main()] - Response: {"id":"","name":"","accountNumber":"123456789","phoneNumber":"","address":"","homeAccountGroup":"","devices":[{"id":"3845","name":"","hardwareRevision":"","hostMacAddress":"D8:3A:DD:13:8C:13","hostIp4Address":"192.168.2.144","hostIp6Address":null,"clientIpAddress":"192.168.2.144","model":"Rpi-RDKB","manufacturer":"","serialNumber":"","unitAddress":null,"remoteType":"","estbMacAddress":"D8:3A:DD:13:8C:13","mtaMacAddress":"D8:3A:DD:13:8C:13","mtaIpAddress":"","ecmMacAddress":"D8:3A:DD:13:8C:13","ecmIpAddress":"192.168.2.144","headend":"HE","gatewayMac":"D8:3A:DD:13:8C:13","extraProperties":{"deviceIp":"192.168.2.144","password":"root123","connectedClients":"192.168.2.81","ethernetMacAddress":"D8:3A:DD:13:8C:13","wi-ficapability":"Dual band","nodePort":"22","connectionType":"SSH","username":"root"},"rackId":"","deviceType":"","rackName":"","slotName":"","slotNumber":"","settopGroupName":"","homeAccountName":"","homeAccountNumber":"123456789","homeAccountGroupName":"","rackServerHost":"","rackServerPort":0,"status":"IN_USE","rackGroups":null,"features":null,"components":null,"wanMacAddress":""},{"id":"3853","name":"","hardwareRevision":"","hostMacAddress":"2C:44:FD:18:F9:FE","hostIp4Address":"192.168.2.81","hostIp6Address":null,"clientIpAddress":"192.168.2.81","model":"WINDOWSVM","manufacturer":"","serialNumber":"","unitAddress":null,"remoteType":"","estbMacAddress":"2C:44:FD:18:F9:FE","mtaMacAddress":"","mtaIpAddress":"","ecmMacAddress":"2C:44:FD:18:F9:FE","ecmIpAddress":"192.168.2.81","headend":"HE","gatewayMac":"","extraProperties":{"deviceIp":"192.168.2.81","password":"asdf@1234","ethernetMacAddress":"2C:44:FD:18:F9:FE","osType":"WINDOWS","devicePort":"22","wifiCapability":"Dual Band","nodePort":"4444","connectionType":"Wi-Fi","wifiMacAddress":"18:D6:C7:08:C6:C1","username":"User"},"rackId":"","deviceType":"","rackName":"","slotName":"","slotNumber":"","settopGroupName":"","homeAccountName":"","homeAccountNumber":"123456789","homeAccountGroupName":"","rackServerHost":"","rackServerPort":0,"status":"GOOD","rackGroups":null,"features":null,"components":null,"wanMacAddress":""}]} [INFO][2024-09-27 12:08:40,841][[com.automatics.executor.Starter.main()] - Devices for home account 123456789 are [D8:3A:DD:13:8C:13, 2C:44:FD:18:F9:FE] [INFO][2024-09-27 12:08:40,841][[com.automatics.executor.Starter.main()] - Obtained all connected device macs for the account [INFO][2024-09-27 12:08:40,842][[com.automatics.executor.Starter.main()] - INIT-2C:44:FD:18:F9:FE Get device details [INFO][2024-09-27 12:08:40,847][[com.automatics.executor.Starter.main()] - Fetching device details for 2C:44:FD:18:F9:FE Url Path: http://192.168.2.145:8080/DeviceManager/deviceManagement/getDeviceDetails [INFO][2024-09-27 12:08:40,861][[com.automatics.executor.Starter.main()] - Response: {"devices":[{"id":"3853","name":"","hardwareRevision":"","hostMacAddress":"2C:44:FD:18:F9:FE","hostIp4Address":"192.168.2.81","hostIp6Address":null,"clientIpAddress":"192.168.2.81","model":"WINDOWSVM","manufacturer":"","serialNumber":"","unitAddress":null,"remoteType":"","estbMacAddress":"2C:44:FD:18:F9:FE","mtaMacAddress":"","mtaIpAddress":"","ecmMacAddress":"2C:44:FD:18:F9:FE","ecmIpAddress":"192.168.2.81","headend":"HE","gatewayMac":"","extraProperties":{"deviceIp":"192.168.2.81","password":"asdf@1234","ethernetMacAddress":"2C:44:FD:18:F9:FE","osType":"WINDOWS","devicePort":"22","wifiCapability":"Dual Band","connectionType":"Wi-Fi","nodePort":"4444","username":"User","wifiMacAddress":"18:D6:C7:08:C6:C1"},"rackId":"","deviceType":"","rackName":"","slotName":"","slotNumber":"","settopGroupName":"","homeAccountName":"","homeAccountNumber":"123456789","homeAccountGroupName":"","rackServerHost":"","rackServerPort":0,"status":"GOOD","rackGroups":null,"features":null,"components":null,"wanMacAddress":""}],"errorMsg":null,"remarks":null} [INFO][2024-09-27 12:08:40,871][[com.automatics.executor.Starter.main()] - INIT-2C:44:FD:18:F9:FE Obtained device details [INFO][2024-09-27 12:08:40,872][[com.automatics.executor.Starter.main()] - >>>[INIT]: No device config mapped for rack model WINDOWSVM. Proceeding with rack model [INFO][2024-09-27 12:08:40,872][[com.automatics.executor.Starter.main()] - [INIT LOG] : Non RDKV Client device [INFO][2024-09-27 12:08:40,872][[pool-15-thread-1] - INIT-{} Check if device already locked2C:44:FD:18:F9:FE [INFO][2024-09-27 12:08:40,877][[pool-15-thread-1] - Fetching lock status for device 2C:44:FD:18:F9:FE Url Path: http://192.168.2.145:8080/DeviceManager/deviceManagement/device/allocationStatus [INFO][2024-09-27 12:08:40,885][[pool-15-thread-1] - Response: {"allocationStatus":"AVAILABLE"} [INFO][2024-09-27 12:08:40,886][[pool-15-thread-1] - DeviceConfig allocation status [INFO][2024-09-27 12:08:40,886][[pool-15-thread-1] - [INIT LOG] : Locking device 2C:44:FD:18:F9:FE [INFO][2024-09-27 12:08:40,886][[pool-15-thread-1] - INIT-2C:44:FD:18:F9:FE Locking device [INFO][2024-09-27 12:08:40,891][[pool-15-thread-1] - Locking device 2C:44:FD:18:F9:FE Url Path: http://192.168.2.145:8080/DeviceManager/deviceManagement/device/lock [INFO][2024-09-27 12:08:40,951][[pool-15-thread-1] - Response: {"status":"SUCCESS","mac":"2C:44:FD:18:F9:FE"} [INFO][2024-09-27 12:08:40,952][[pool-15-thread-1] - INIT-2C:44:FD:18:F9:FE Lock success [INFO][2024-09-27 12:08:40,953][[pool-15-thread-1] - DeviceConfig [2C:44:FD:18:F9:FE] is identified as NON RDK DeviceConfig. [INFO][2024-09-27 12:08:40,953][[pool-15-thread-1] - Setting default SSH access mechanism for device null [INFO][2024-09-27 12:08:40,953][[pool-15-thread-1] - INIT-2C:44:FD:18:F9:FE Setting access method SSH [INFO][2024-09-27 12:08:40,953][[pool-15-thread-1] - INIT-2C:44:FD:18:F9:FE Checking if accessibility check required [INFO][2024-09-27 12:08:40,953][[pool-15-thread-1] - Accessibility check required for device 2C:44:FD:18:F9:FE false [INFO][2024-09-27 12:08:40,954][[pool-15-thread-1] - INIT-2C:44:FD:18:F9:FE Checking if accessibility check required is false [INFO][2024-09-27 12:08:40,954][[pool-15-thread-1] - INIT-2C:44:FD:18:F9:FE Assuming device is accessible [INFO][2024-09-27 12:08:40,954][[pool-15-thread-1] - INIT-2C:44:FD:18:F9:FE Is device accessible true [INFO][2024-09-27 12:08:40,954][[pool-15-thread-1] - [INIT LOG] : Wiring device.2C:44:FD:18:F9:FE [INFO][2024-09-27 12:08:40,954][[pool-15-thread-1] - INIT-2C:44:FD:18:F9:FE Performing provider wiring [INFO][2024-09-27 12:08:40,954][[pool-15-thread-1] - INIT-2C:44:FD:18:F9:FE PowerProvider wiring [INFO][2024-09-27 12:08:40,954][[pool-15-thread-1] - Reading implementation from core for powerProvider [INFO][2024-09-27 12:08:40,954][[pool-15-thread-1] - [INIT LOG] : Adding dut to locked list [INFO][2024-09-27 12:08:40,954][[pool-15-thread-1] - DeviceConfig Macs D8:3A:DD:13:8C:13 [INFO][2024-09-27 12:08:40,954][[pool-15-thread-1] - Dut Added to locked list 2C:44:FD:18:F9:FE [INFO][2024-09-27 12:08:43,872][[com.automatics.executor.Starter.main()] - Finished Non-IP Initialization Threads [INFO][2024-09-27 12:08:43,872][[com.automatics.executor.Starter.main()] - Starting trace from provider for connected clients if not already started [INFO][2024-09-27 12:08:43,873][[com.automatics.executor.Starter.main()] - ========================================================================= [INFO][2024-09-27 12:08:43,873][[com.automatics.executor.Starter.main()] - DeviceConfig [2C:44:FD:18:F9:FE] is identified as NON RDK DeviceConfig. [INFO][2024-09-27 12:08:43,873][[com.automatics.executor.Starter.main()] - Trace not applicable for Non RDK Devices - 2C:44:FD:18:F9:FE [INFO][2024-09-27 12:08:43,880][[com.automatics.executor.Starter.main()] - NUMBER OF CONNECTED CLIENTS ASSOCIATED WITH DEVICE D8:3A:DD:13:8C:13 IS 1 [INFO][2024-09-27 12:08:43,880][[com.automatics.executor.Starter.main()] - CONNECTED CLIENTS ASSOCIATED WITH DEVICE D8:3A:DD:13:8C:13 IS 2C:44:FD:18:F9:FE [INFO][2024-09-27 12:08:43,893][[TestNG-PoolService-0] - >>>[BEFORE_METHOD]: Perform before method initialization D8:3A:DD:13:8C:13 [INFO][2024-09-27 12:08:43,895][[TestNG-PoolService-0] - Setting dattime in patter yyyy-MM-dd HH:mm:ss [INFO][2024-09-27 12:08:43,899][[TestNG-PoolService-0] - startTime 2024-09-27 06:38:43 [INFO][2024-09-27 12:08:43,899][[TestNG-PoolService-0] - >>>[BEFORE_METHOD]: Sending test exection start time to Automatics D8:3A:DD:13:8C:13 [INFO][2024-09-27 12:08:43,901][[TestNG-PoolService-0] - http://192.168.2.59:8080/Automatics/captureTestTriggerTime.htm [INFO][2024-09-27 12:08:43,902][[TestNG-PoolService-0] - {"jobId":456,"automationId":"TC-RDKB-WH-WEBPA-1001","macAddress":"D8:3A:DD:13:8C:13","startDateTimeEST":1727419123900,"endDateTimeEST":0} [INFO][2024-09-27 12:08:44,078][[TestNG-PoolService-0] - Capture execution time - Response : HTTP/1.1 200 [INFO][2024-09-27 12:08:44,079][D8:3A:DD:13:8C:13[TestNG-PoolService-0] - Skipping partner specific before method initialization as it is not configured. 12:08:44,079 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.FileAppender] 12:08:44,079 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE-Rpi-RDKB-D83ADD138C13] 12:08:44,081 |-INFO in ch.qos.logback.core.FileAppender[FILE-Rpi-RDKB-D83ADD138C13] - File property is set to [target/logs/Rpi-RDKB-D83ADD138C13.log] [INFO][2024-09-27 12:08:44,081][D8:3A:DD:13:8C:13[TestNG-PoolService-0] - >>>[BEFORE_METHOD]: Extending allocation before method for testType : GROUP_OR_AUTOID D8:3A:DD:13:8C:13 [INFO][2024-09-27 12:08:44,081][D8:3A:DD:13:8C:13[TestNG-PoolService-0] - Get the locked status: false [INFO][2024-09-27 12:08:44,081][D8:3A:DD:13:8C:13[TestNG-PoolService-0] - Get the locked status: false [INFO][2024-09-27 12:08:44,082][D8:3A:DD:13:8C:13[TestNG-PoolService-0] - Is trace required for connected gateway: false [INFO][2024-09-27 12:08:44,082][D8:3A:DD:13:8C:13[TestNG-PoolService-0] - Is trace required for connected gateway: false [INFO][2024-09-27 12:08:44,093][D8:3A:DD:13:8C:13[TestNG-PoolService-0] - STARTED - compareSnmpAndWebpaResponseTimeForWarehouse - com.automatics.device.Device@3483c1be [INFO][2024-09-27 12:08:44,094][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Getting MDC = D83ADD138C13settop_trace.log [INFO][2024-09-27 12:08:44,095][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Getting MDC = D8:3A:DD:13:8C:13 [INFO][2024-09-27 12:08:44,103][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - #################### STARTING TEST CASE: TC-RDKB-WH-WEBPA-1001 ##################### [INFO][2024-09-27 12:08:44,103][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TEST DESCRIPTION: To compare the SNMP and WebPA response time for warehouse [INFO][2024-09-27 12:08:44,103][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TEST STEPS : [INFO][2024-09-27 12:08:44,104][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - 1.Capture the current time before reboot and executing WebPA parameters before reboot [INFO][2024-09-27 12:08:44,104][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - 2.Reboot the device [INFO][2024-09-27 12:08:44,104][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - 3.Capture the current time after reboot and executing WebPA parameters after reboot. [INFO][2024-09-27 12:08:44,104][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - 4. To calculate the time taken for device reboot. [INFO][2024-09-27 12:08:44,104][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - 5.Verify the CM MAC is retrieved using the WEBPA [INFO][2024-09-27 12:08:44,104][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - 6.Verify the WAN MAC Address is retieved using the WebPA [INFO][2024-09-27 12:08:44,104][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - 7.Verify device/box serial number using webpa parameter [INFO][2024-09-27 12:08:44,104][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - 8.Get the enable status of private SSID, PHASE1_LNF, PHASE2_LNF for 2.4Ghz using webpa [INFO][2024-09-27 12:08:44,104][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - 9.Get the enable status of private SSID, PHASE1_LNF, PHASE2_LNF for 5Ghz using webpa [INFO][2024-09-27 12:08:44,104][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - 10.Get the 2.4 and 5GHz SSIDs using webpa [INFO][2024-09-27 12:08:44,104][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - 11.Get the 2.4 and 5GHz passphrase using webpa [INFO][2024-09-27 12:08:44,104][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - 12.Get the 2.4 and 5GHz wifi radio enable status using webpa [INFO][2024-09-27 12:08:44,104][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - 13.Get the 2.4 and 5GHz wireless channel status [INFO][2024-09-27 12:08:44,104][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - 14.Get the firmware related details [INFO][2024-09-27 12:08:44,104][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - 15.Capture the time taken to execute webpa get parameters [INFO][2024-09-27 12:08:44,104][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - 16.Compare the time taken for reboot and WebPA get response [INFO][2024-09-27 12:08:44,105][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ##################################################################################### [INFO][2024-09-27 12:08:44,105][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:08:44,105][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 1: DESCRIPTION: Capture the current time before reboot and executing WebPA parameters. [INFO][2024-09-27 12:08:44,105][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 1: ACTION : Execute the following command via SSH: date +%Y-%m-%d' '%H:%M:%S [INFO][2024-09-27 12:08:44,105][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 1: EXPECTED: Successfully capture the time before executing WebPA and the reboot process. [INFO][2024-09-27 12:08:44,105][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:08:44,105][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Entering executeCommandUsingSsh method [INFO][2024-09-27 12:08:44,105][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DutIP:192.168.2.144 [INFO][2024-09-27 12:08:44,105][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:08:44,105][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:08:44,118][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:08:44,318][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: date +%Y-%m-%d' '%H:%M:%S [INFO][2024-09-27 12:08:44,318][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:08:44,441][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> 2024-09-27 06:38:44 <=============================================================> [INFO][2024-09-27 12:08:44,442][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: 2024-09-27 06:38:44 [INFO][2024-09-27 12:08:44,442][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exiting executeCommandUsingSsh method [INFO][2024-09-27 12:08:44,442][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 1 ACTUAL: Successfully captured the time before reboot: 2024-09-27 06:38:44 [INFO][2024-09-27 12:08:44,442][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:08:44,443][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WH-WEBPA-101] [step Number : s1][ Execution status : PASS] [Error Message : ] [INFO][2024-09-27 12:08:44,445][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-09-27 12:08:44,446][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Fetching device property: FIRMWARE_VERSION [INFO][2024-09-27 12:08:44,451][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Fetching device props for D8:3A:DD:13:8C:13 for props [FIRMWARE_VERSION] Url Path: http://192.168.2.145:8080/DeviceManager/deviceManagement/getDeviceProps [INFO][2024-09-27 12:08:44,462][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Response: {"mac":"D8:3A:DD:13:8C:13","HEAD_END":null,"FIRMWARE_VERSION":"RPI-RDKB","ECM_IP_ADDRESS":null,"ESTB_IP_ADDRESS":null} [INFO][2024-09-27 12:08:44,463][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Getting value for property: FIRMWARE_VERSION [INFO][2024-09-27 12:08:44,463][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Value: RPI-RDKB [INFO][2024-09-27 12:08:44,463][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Device property name: FIRMWARE_VERSION value obtained: RPI-RDKB [INFO][2024-09-27 12:08:44,469][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WH-WEBPA-101","stepNumber":"s1","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"","executionStatus":"PASS","skipRemaining":true,"partnerName":"","automationId":"TC-RDKB-WH-WEBPA-1001"} [ERROR][2024-09-27 12:08:44,481][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - FAILED TO UPDATE EXECUTION RESULT.Kindly check if this manual id and step are added in Automatics - Manage scripts against the automation id [INFO][2024-09-27 12:08:44,481][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-09-27 12:08:44,481][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:08:44,481][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 2: DESCRIPTION: Reboot the cpe [INFO][2024-09-27 12:08:44,482][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 2: ACTION: Execute command: reboot [INFO][2024-09-27 12:08:44,482][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 2: EXPECTED: Reboot should be successful [INFO][2024-09-27 12:08:44,482][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:08:44,482][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STARTING METHOD: rebootAndWaitForIpAccusition() [INFO][2024-09-27 12:08:44,482][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:08:44,495][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:08:44,704][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: echo test_connection; [INFO][2024-09-27 12:08:44,704][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:08:44,827][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> test_connection <=============================================================> [INFO][2024-09-27 12:08:44,827][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP: 192.168.2.144 [INFO][2024-09-27 12:08:44,827][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exiting method isDeviceAccessible. Status - true [INFO][2024-09-27 12:08:44,828][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Entering executeCommandUsingSsh method [INFO][2024-09-27 12:08:44,828][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DutIP:192.168.2.144 [INFO][2024-09-27 12:08:44,828][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:08:44,828][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:08:44,844][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:08:45,067][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: /sbin/reboot [INFO][2024-09-27 12:08:45,067][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:08:45,290][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> <=============================================================> [INFO][2024-09-27 12:08:45,291][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: [INFO][2024-09-27 12:08:45,291][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exiting executeCommandUsingSsh method [ERROR][2024-09-27 12:08:45,307][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exception in waitForEstbIpAcquisition() : com.automatics.exceptions.FailedTransitionException: RESOURCE_KEY_NOT_FOUND: Failed to find the key in the resource property file.Key not found on Automatics properties : wait.after.hard.reboot.initiated__rpi-rdkb at com.automatics.tap.AutomaticsTapApi.getSTBPropsValue(AutomaticsTapApi.java:424) at com.automatics.tap.AutomaticsTapApi.getWaitValue(AutomaticsTapApi.java:1953) at com.automatics.providers.impl.DeviceAccessValidatorImpl.waitForDeviceIpAcquisition(DeviceAccessValidatorImpl.java:145) at com.automatics.providers.impl.DeviceAccessValidatorImpl.waitForIpAcquisitionAfterReboot(DeviceAccessValidatorImpl.java:124) at com.automatics.utils.CommonMethods.waitForEstbIpAcquisition(CommonMethods.java:4009) at com.automatics.tap.AutomaticsTapApi.waitAfterHardRebootInitiated(AutomaticsTapApi.java:530) at com.automatics.tap.AutomaticsTapApi.reboot(AutomaticsTapApi.java:6581) at com.automatics.utils.CommonMethods.rebootAndWaitForIpAccusition(CommonMethods.java:4884) at com.automatics.rdkb.tests.webpa.BroadBandWebPaTests.compareSnmpAndWebpaResponseTimeForWarehouse(BroadBandWebPaTests.java:13592) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:134) at org.testng.internal.TestInvoker.invokeMethod(TestInvoker.java:597) at org.testng.internal.TestInvoker.invokeTestMethod(TestInvoker.java:173) at org.testng.internal.TestMethodWithDataProviderMethodWorker.call(TestMethodWithDataProviderMethodWorker.java:77) at org.testng.internal.TestMethodWithDataProviderMethodWorker.call(TestMethodWithDataProviderMethodWorker.java:15) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:829) [INFO][2024-09-27 12:08:45,319][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Completed execution of waitForEstbIpAcquisition() : Status : false. Time taken : 0 minutes [INFO][2024-09-27 12:08:45,320][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:08:45,337][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [ERROR][2024-09-27 12:08:45,345][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exiting occured while running command : CONNECTION: SSH connection failure to the server. [INFO][2024-09-27 12:08:45,345][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exiting method isDeviceAccessible. Status - false [INFO][2024-09-27 12:08:45,345][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ENDING METHOD: rebootAndWaitForIpAccusition() [INFO][2024-09-27 12:08:55,346][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 2: ACTUAL :reboot is successful [INFO][2024-09-27 12:08:55,346][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [ERROR][2024-09-27 12:08:55,346][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Error Message: Unable to reboot the cpe [INFO][2024-09-27 12:08:55,346][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WH-WEBPA-101] [step Number : s2][ Execution status : FAIL] [Error Message : Unable to reboot the cpe] [INFO][2024-09-27 12:08:55,346][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-09-27 12:08:55,348][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WH-WEBPA-101","stepNumber":"s2","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"Unable to reboot the cpe","executionStatus":"FAIL","skipRemaining":false,"partnerName":"","automationId":"TC-RDKB-WH-WEBPA-1001"} [ERROR][2024-09-27 12:08:55,361][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - FAILED TO UPDATE EXECUTION RESULT.Kindly check if this manual id and step are added in Automatics - Manage scripts against the automation id [INFO][2024-09-27 12:08:55,361][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-09-27 12:08:55,361][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:08:55,361][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 3: DESCRIPTION: Capture the current time after reboot and executing WebPA parameters. [INFO][2024-09-27 12:08:55,361][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 3: ACTION : Execute the following command via SSH: date +%Y-%m-%d' '%H:%M:%S [INFO][2024-09-27 12:08:55,361][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 3: EXPECTED: Successfully capture the time after reboot the device. [INFO][2024-09-27 12:08:55,361][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:08:55,361][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Entering executeCommandUsingSsh method [INFO][2024-09-27 12:08:55,361][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DutIP:192.168.2.144 [INFO][2024-09-27 12:08:55,361][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:08:55,362][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:08:55,375][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:08:55,383][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 failed due to CONNECTION: SSH connection failure to the server. for 192.168.2.144. Trying once more.. [INFO][2024-09-27 12:09:05,383][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 2 [INFO][2024-09-27 12:09:05,396][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:09:14,688][[PollingThread_26_(D8:3A:DD:13:8C:13)] - getConnection method invoked [INFO][2024-09-27 12:09:14,688][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:09:14,688][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSh connection attempet : 1 [INFO][2024-09-27 12:09:14,700][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-09-27 12:09:23,429][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSh connection attempet : 1 failed due to CONNECTION: SSH connection failure to the server. for 192.168.2.144. Trying once more.. [INFO][2024-09-27 12:09:23,429][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 2 failed due to CONNECTION: SSH connection failure to the server. for 192.168.2.144. Trying once more.. [INFO][2024-09-27 12:09:33,429][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSh connection attempet : 2 [INFO][2024-09-27 12:09:33,429][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 3 [INFO][2024-09-27 12:09:33,442][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-09-27 12:09:33,444][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:09:36,448][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSh connection attempet : 2 failed due to CONNECTION: SSH connection failure to the server. for 192.168.2.144. Trying once more.. [INFO][2024-09-27 12:09:36,448][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 3 failed due to CONNECTION: SSH connection failure to the server. for 192.168.2.144. Trying once more.. [INFO][2024-09-27 12:09:46,449][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 4 [INFO][2024-09-27 12:09:46,449][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSh connection attempet : 3 [INFO][2024-09-27 12:09:46,461][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-09-27 12:09:46,462][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:09:46,676][[PollingThread_26_(D8:3A:DD:13:8C:13)] - sshConnectionPoll established [INFO][2024-09-27 12:09:46,676][[PollingThread_26_(D8:3A:DD:13:8C:13)] - getConnection method invoked [INFO][2024-09-27 12:09:46,676][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:09:46,676][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSh connection attempet : 1 [INFO][2024-09-27 12:09:46,688][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-09-27 12:09:46,701][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: date +%Y-%m-%d' '%H:%M:%S [INFO][2024-09-27 12:09:46,701][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:09:46,823][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> 2024-09-03 13:49:51 <=============================================================> [INFO][2024-09-27 12:09:46,823][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: 2024-09-03 13:49:51 [INFO][2024-09-27 12:09:46,823][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exiting executeCommandUsingSsh method [INFO][2024-09-27 12:09:46,825][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 3 ACTUAL: Successfully captured the time after reboot: 2024-09-03 13:49:51 [INFO][2024-09-27 12:09:46,825][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:09:46,825][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WH-WEBPA-101] [step Number : s3][ Execution status : PASS] [Error Message : ] [INFO][2024-09-27 12:09:46,825][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-09-27 12:09:46,825][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WH-WEBPA-101","stepNumber":"s3","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"","executionStatus":"PASS","skipRemaining":true,"partnerName":"","automationId":"TC-RDKB-WH-WEBPA-1001"} [ERROR][2024-09-27 12:09:46,840][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - FAILED TO UPDATE EXECUTION RESULT.Kindly check if this manual id and step are added in Automatics - Manage scripts against the automation id [INFO][2024-09-27 12:09:46,840][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-09-27 12:09:46,840][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:09:46,840][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 4: DESCRIPTION: To calculate the time taken for device reboot. [INFO][2024-09-27 12:09:46,840][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 4: ACTION: Calculate the time difference between the dates of endTime and startTime in milliseconds and convert the result into seconds. [INFO][2024-09-27 12:09:46,840][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 4: EXPECTED: Successfully obtain the time taken for the device reboot. [INFO][2024-09-27 12:09:46,840][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:09:46,842][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 4 ACTUAL: Successfully calculated time taken for device reboot: 2047733.0 seconds. [INFO][2024-09-27 12:09:46,842][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:09:46,843][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WH-WEBPA-101] [step Number : s4][ Execution status : PASS] [Error Message : ] [INFO][2024-09-27 12:09:46,843][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-09-27 12:09:46,843][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WH-WEBPA-101","stepNumber":"s4","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"","executionStatus":"PASS","skipRemaining":true,"partnerName":"","automationId":"TC-RDKB-WH-WEBPA-1001"} [ERROR][2024-09-27 12:09:46,853][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - FAILED TO UPDATE EXECUTION RESULT.Kindly check if this manual id and step are added in Automatics - Manage scripts against the automation id [INFO][2024-09-27 12:09:46,854][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-09-27 12:09:46,854][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ***************************************************************************** [INFO][2024-09-27 12:09:46,854][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 5: DESCRIPTION: Verify the CM MAC is retrieved using the WEBPA [INFO][2024-09-27 12:09:46,854][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 5: ACTION: Exeute the webpa command :Device.DeviceInfo.X_COMCAST-COM_CM_MAC [INFO][2024-09-27 12:09:46,854][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 5: EXPECTED: Response should return CM MAC received from WEBPA API request [INFO][2024-09-27 12:09:46,854][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:09:46,854][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-09-27 12:09:46,854][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-09-27 12:09:46,854][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method: DMCLI [INFO][2024-09-27 12:09:46,855][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Going to find protocol specific names [INFO][2024-09-27 12:09:46,857][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Going to execute commands [INFO][2024-09-27 12:09:46,857][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:09:46,857][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:09:46,857][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:09:46,870][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:09:46,908][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Value of responseString: null [INFO][2024-09-27 12:09:46,908][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not nul in execute: [INFO][2024-09-27 12:09:46,908][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Executing command: echo CONNECTION_IS_ALIVE [INFO][2024-09-27 12:09:46,908][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not null sendRecive: [INFO][2024-09-27 12:09:47,030][[PollingThread_26_(D8:3A:DD:13:8C:13)] - <=========================== RESPONSE =======================> CONNECTION_IS_ALIVE <=============================================================> [INFO][2024-09-27 12:09:47,030][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Closing SSH connection from DeviceIP:com.automatics.device.Device@3483c1be [INFO][2024-09-27 12:09:47,031][[PollingThread_26_(D8:3A:DD:13:8C:13)] - ConnectionPoll disconnected [INFO][2024-09-27 12:09:47,063][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.DeviceInfo.X_COMCAST-COM_CM_MAC [INFO][2024-09-27 12:09:47,063][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:09:47,186][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.DeviceInfo.X_COMCAST-COM_CM_MAC Execution succeed. Parameter 1 name: Device.DeviceInfo.X_COMCAST-COM_CM_MAC type: string, value: D8:3A:DD:13:8C:13 <=============================================================> [INFO][2024-09-27 12:09:47,186][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:09:47,186][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.DeviceInfo.X_COMCAST-COM_CM_MAC Execution succeed. Parameter 1 name: Device.DeviceInfo.X_COMCAST-COM_CM_MAC type: string, value: D8:3A:DD:13:8C:13 [INFO][2024-09-27 12:09:47,186][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.DeviceInfo.X_COMCAST-COM_CM_MAC Execution succeed. Parameter 1 name: Device.DeviceInfo.X_COMCAST-COM_CM_MAC type: string, value: D8:3A:DD:13:8C:13 [INFO][2024-09-27 12:09:47,187][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : D8:3A:DD:13:8C:13 [INFO][2024-09-27 12:09:47,187][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Response : [tableName=null, index=null, name=Device.DeviceInfo.X_COMCAST-COM_CM_MAC, protocolSpecificParamName=Device.DeviceInfo.X_COMCAST-COM_CM_MAC, value=D8:3A:DD:13:8C:13, datatype=null, statusCode=0] [INFO][2024-09-27 12:09:47,187][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 5 ACTUAL: CM_MAC of the device is obtained from WEBPA GET API request as expected [INFO][2024-09-27 12:09:47,187][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:09:47,187][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WH-WEBPA-101] [step Number : s5][ Execution status : PASS] [Error Message : ] [INFO][2024-09-27 12:09:47,187][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-09-27 12:09:47,188][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WH-WEBPA-101","stepNumber":"s5","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"","executionStatus":"PASS","skipRemaining":true,"partnerName":"","automationId":"TC-RDKB-WH-WEBPA-1001"} [ERROR][2024-09-27 12:09:47,202][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - FAILED TO UPDATE EXECUTION RESULT.Kindly check if this manual id and step are added in Automatics - Manage scripts against the automation id [INFO][2024-09-27 12:09:47,202][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-09-27 12:09:47,202][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ********************************************************************************** [INFO][2024-09-27 12:09:47,202][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 6: DESCRIPTION : Verification of WAN MAC Address via WebPA/dmcli [INFO][2024-09-27 12:09:47,202][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 6: ACTION : a) Execute WebPA/dmcli GET command for TR-181( Device.DeviceInfo.X_COMCAST-COM_WAN_MAC ). E.g: dmcli eRT getv Device.DeviceInfo.X_COMCAST-COM_WAN_MAC [INFO][2024-09-27 12:09:47,202][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 6: EXPECTED :esponse should return WAN MAC received from WEBPA API request [INFO][2024-09-27 12:09:47,202][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ********************************************************************************** [INFO][2024-09-27 12:09:47,207][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Starting Method getParameterValuesUsingWebPaOrDmcli() [INFO][2024-09-27 12:09:47,208][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Is WebpaConnectionBroken : false [INFO][2024-09-27 12:09:47,208][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-09-27 12:09:47,208][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-09-27 12:09:47,208][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method: DMCLI [INFO][2024-09-27 12:09:47,208][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Going to find protocol specific names [INFO][2024-09-27 12:09:47,208][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Going to execute commands [INFO][2024-09-27 12:09:47,208][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:09:47,208][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:09:47,208][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:09:47,219][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:09:47,404][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.DeviceInfo.X_COMCAST-COM_WAN_MAC [INFO][2024-09-27 12:09:47,405][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:09:47,527][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.DeviceInfo.X_COMCAST-COM_WAN_MAC Execution succeed. Parameter 1 name: Device.DeviceInfo.X_COMCAST-COM_WAN_MAC type: string, value: d8:3a:dd:13:8c:13 <=============================================================> [INFO][2024-09-27 12:09:47,527][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:09:47,527][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.DeviceInfo.X_COMCAST-COM_WAN_MAC Execution succeed. Parameter 1 name: Device.DeviceInfo.X_COMCAST-COM_WAN_MAC type: string, value: d8:3a:dd:13:8c:13 [INFO][2024-09-27 12:09:47,527][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.DeviceInfo.X_COMCAST-COM_WAN_MAC Execution succeed. Parameter 1 name: Device.DeviceInfo.X_COMCAST-COM_WAN_MAC type: string, value: d8:3a:dd:13:8c:13 [INFO][2024-09-27 12:09:47,528][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : d8:3a:dd:13:8c:13 [INFO][2024-09-27 12:09:47,528][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Response : [tableName=null, index=null, name=Device.DeviceInfo.X_COMCAST-COM_WAN_MAC, protocolSpecificParamName=Device.DeviceInfo.X_COMCAST-COM_WAN_MAC, value=d8:3a:dd:13:8c:13, datatype=null, statusCode=0] [INFO][2024-09-27 12:09:47,528][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Parameter Value is : d8:3a:dd:13:8c:13 [INFO][2024-09-27 12:09:47,528][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Ending Method getParameterValuesUsingWebPaOrDmcli() [INFO][2024-09-27 12:09:47,528][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 6 ACTUAL: SUCCESSFULLY VERIFIED WAN MAC ADDRESS USING Device.DeviceInfo.X_COMCAST-COM_WAN_MAC [INFO][2024-09-27 12:09:47,528][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ********************************************************************************** [INFO][2024-09-27 12:09:47,528][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WH-WEBPA-101] [step Number : s7][ Execution status : PASS] [Error Message : ] [INFO][2024-09-27 12:09:47,528][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-09-27 12:09:47,529][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WH-WEBPA-101","stepNumber":"s7","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"","executionStatus":"PASS","skipRemaining":true,"partnerName":"","automationId":"TC-RDKB-WH-WEBPA-1001"} [ERROR][2024-09-27 12:09:47,542][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - FAILED TO UPDATE EXECUTION RESULT.Kindly check if this manual id and step are added in Automatics - Manage scripts against the automation id [INFO][2024-09-27 12:09:47,542][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-09-27 12:09:47,542][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:09:47,542][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 7: DESCRIPTION : Validate the Serial Number 'Device.DeviceInfo.SerialNumber' [INFO][2024-09-27 12:09:47,542][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 7: ACTION : Get the serial number using webpa param [INFO][2024-09-27 12:09:47,542][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 7: EXPECTED : Must retireve the serial number using webpa value successfully [INFO][2024-09-27 12:09:47,542][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:09:47,542][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Starting Method getParameterValuesUsingWebPaOrDmcli() [INFO][2024-09-27 12:09:47,542][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Is WebpaConnectionBroken : false [INFO][2024-09-27 12:09:47,542][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-09-27 12:09:47,542][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-09-27 12:09:47,542][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method: DMCLI [INFO][2024-09-27 12:09:47,543][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Going to find protocol specific names [INFO][2024-09-27 12:09:47,543][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Going to execute commands [INFO][2024-09-27 12:09:47,543][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:09:47,543][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:09:47,543][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:09:47,553][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:09:47,758][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.DeviceInfo.SerialNumber [INFO][2024-09-27 12:09:47,758][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:09:47,881][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.DeviceInfo.SerialNumber Execution succeed. Parameter 1 name: Device.DeviceInfo.SerialNumber type: string, value: 10000000edcb124b <=============================================================> [INFO][2024-09-27 12:09:47,881][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:09:47,881][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.DeviceInfo.SerialNumber Execution succeed. Parameter 1 name: Device.DeviceInfo.SerialNumber type: string, value: 10000000edcb124b [INFO][2024-09-27 12:09:47,881][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.DeviceInfo.SerialNumber Execution succeed. Parameter 1 name: Device.DeviceInfo.SerialNumber type: string, value: 10000000edcb124b [INFO][2024-09-27 12:09:47,881][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : 10000000edcb124b [INFO][2024-09-27 12:09:47,882][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Response : [tableName=null, index=null, name=Device.DeviceInfo.SerialNumber, protocolSpecificParamName=Device.DeviceInfo.SerialNumber, value=10000000edcb124b, datatype=null, statusCode=0] [INFO][2024-09-27 12:09:47,882][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Parameter Value is : 10000000edcb124b [INFO][2024-09-27 12:09:47,882][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Ending Method getParameterValuesUsingWebPaOrDmcli() [INFO][2024-09-27 12:09:47,882][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 7 : ACTUAL : Successfully retrieved and validated the serial number using webpa param [INFO][2024-09-27 12:09:47,882][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:09:47,882][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WH-WEBPA-101] [step Number : s7][ Execution status : PASS] [Error Message : ] [INFO][2024-09-27 12:09:47,882][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-09-27 12:09:47,883][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-09-27 12:09:47,883][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:09:47,883][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 8: DESCRIPTION : Get the enable status of private SSID,PHASE1_LNF, PHASE2_LNF for 2.4Ghz using webpa [INFO][2024-09-27 12:09:47,883][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 8: ACTION : Execute webpa command :Device.WiFi.SSID.10001.Enable,Device.WiFi.SSID.10004.Enable,Device.WiFi.SSID.10006.Enable [INFO][2024-09-27 12:09:47,883][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 8: EXPECTED : Response should return the status of 2.4Ghz SSID for private wifi,PHASE1_LNF, PHASE2_LNF successfully [INFO][2024-09-27 12:09:47,883][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:09:47,883][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-09-27 12:09:47,883][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-09-27 12:09:47,883][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method: DMCLI [INFO][2024-09-27 12:09:47,883][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Going to find protocol specific names [INFO][2024-09-27 12:09:47,883][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Going to execute commands [INFO][2024-09-27 12:09:47,883][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:09:47,883][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:09:47,883][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:09:47,895][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:09:48,077][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.WiFi.SSID.1.Enable [INFO][2024-09-27 12:09:48,077][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:09:48,200][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.1.Enable Execution succeed. Parameter 1 name: Device.WiFi.SSID.1.Enable type: bool, value: true <=============================================================> [INFO][2024-09-27 12:09:48,200][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:09:48,200][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.1.Enable Execution succeed. Parameter 1 name: Device.WiFi.SSID.1.Enable type: bool, value: true [INFO][2024-09-27 12:09:48,200][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.1.Enable Execution succeed. Parameter 1 name: Device.WiFi.SSID.1.Enable type: bool, value: true [INFO][2024-09-27 12:09:48,200][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : true [INFO][2024-09-27 12:09:48,200][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:09:48,200][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:09:48,200][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:09:48,211][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:09:48,401][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.WiFi.SSID.7.Enable [INFO][2024-09-27 12:09:48,401][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:09:48,523][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.7.Enable Execution succeed. Parameter 1 name: Device.WiFi.SSID.7.Enable type: bool, value: true <=============================================================> [INFO][2024-09-27 12:09:48,523][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:09:48,523][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.7.Enable Execution succeed. Parameter 1 name: Device.WiFi.SSID.7.Enable type: bool, value: true [INFO][2024-09-27 12:09:48,524][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.7.Enable Execution succeed. Parameter 1 name: Device.WiFi.SSID.7.Enable type: bool, value: true [INFO][2024-09-27 12:09:48,524][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : true [INFO][2024-09-27 12:09:48,524][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:09:48,524][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:09:48,524][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:09:48,535][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:09:48,536][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 failed due to CONNECTION: SSH connection failure to the server. for 192.168.2.144. Trying once more.. [INFO][2024-09-27 12:09:58,536][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 2 [INFO][2024-09-27 12:09:58,547][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:09:58,737][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.WiFi.SSID.11.Enable [INFO][2024-09-27 12:09:58,737][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:09:58,859][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.11.Enable Execution succeed. Parameter 1 name: Device.WiFi.SSID.11.Enable type: bool, value: true <=============================================================> [INFO][2024-09-27 12:09:58,859][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:09:58,860][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.11.Enable Execution succeed. Parameter 1 name: Device.WiFi.SSID.11.Enable type: bool, value: true [INFO][2024-09-27 12:09:58,860][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.11.Enable Execution succeed. Parameter 1 name: Device.WiFi.SSID.11.Enable type: bool, value: true [INFO][2024-09-27 12:09:58,862][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : true [INFO][2024-09-27 12:09:58,863][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Response : [tableName=null, index=null, name=Device.WiFi.SSID.10001.Enable, protocolSpecificParamName=Device.WiFi.SSID.1.Enable, value=true, datatype=null, statusCode=0, tableName=null, index=null, name=Device.WiFi.SSID.10004.Enable, protocolSpecificParamName=Device.WiFi.SSID.7.Enable, value=true, datatype=null, statusCode=0, tableName=null, index=null, name=Device.WiFi.SSID.10006.Enable, protocolSpecificParamName=Device.WiFi.SSID.11.Enable, value=true, datatype=null, statusCode=0] [INFO][2024-09-27 12:09:58,863][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 8: ACTUAL : Successfully retrieve status of 2.4Ghz SSID for private wifi,PHASE1_LNF, PHASE2_LNF [INFO][2024-09-27 12:09:58,863][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:09:58,863][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WH-WEBPA-101] [step Number : s8][ Execution status : PASS] [Error Message : ] [INFO][2024-09-27 12:09:58,863][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-09-27 12:09:58,864][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WH-WEBPA-101","stepNumber":"s8","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"","executionStatus":"PASS","skipRemaining":true,"partnerName":"","automationId":"TC-RDKB-WH-WEBPA-1001"} [ERROR][2024-09-27 12:09:58,877][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - FAILED TO UPDATE EXECUTION RESULT.Kindly check if this manual id and step are added in Automatics - Manage scripts against the automation id [INFO][2024-09-27 12:09:58,877][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-09-27 12:09:58,877][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:09:58,877][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 9: DESCRIPTION : Get the enable status of private SSID,PHASE1_LNF, PHASE2_LNF for 5Ghz using webpa [INFO][2024-09-27 12:09:58,877][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 9: ACTION : Execute webpa command :Device.WiFi.SSID.10101.Enable, Device.WiFi.SSID.10104.Enable,Device.WiFi.SSID.10106.Enable [INFO][2024-09-27 12:09:58,877][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 9: EXPECTED : Response should return the status of 5Ghz SSID for private wifi,PHASE1_LNF, PHASE2_LNF successfully [INFO][2024-09-27 12:09:58,877][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:09:58,877][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-09-27 12:09:58,878][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-09-27 12:09:58,878][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method: DMCLI [INFO][2024-09-27 12:09:58,878][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Going to find protocol specific names [INFO][2024-09-27 12:09:58,878][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Going to execute commands [INFO][2024-09-27 12:09:58,878][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:09:58,878][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:09:58,878][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:09:58,888][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:09:59,133][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.WiFi.SSID.2.Enable [INFO][2024-09-27 12:09:59,133][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:09:59,256][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.2.Enable Execution succeed. Parameter 1 name: Device.WiFi.SSID.2.Enable type: bool, value: true <=============================================================> [INFO][2024-09-27 12:09:59,256][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:09:59,256][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.2.Enable Execution succeed. Parameter 1 name: Device.WiFi.SSID.2.Enable type: bool, value: true [INFO][2024-09-27 12:09:59,256][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.2.Enable Execution succeed. Parameter 1 name: Device.WiFi.SSID.2.Enable type: bool, value: true [INFO][2024-09-27 12:09:59,256][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : true [INFO][2024-09-27 12:09:59,256][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:09:59,256][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:09:59,256][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:09:59,268][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:09:59,470][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.WiFi.SSID.8.Enable [INFO][2024-09-27 12:09:59,470][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:09:59,592][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.8.Enable Execution succeed. Parameter 1 name: Device.WiFi.SSID.8.Enable type: bool, value: true <=============================================================> [INFO][2024-09-27 12:09:59,592][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:09:59,592][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.8.Enable Execution succeed. Parameter 1 name: Device.WiFi.SSID.8.Enable type: bool, value: true [INFO][2024-09-27 12:09:59,593][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.8.Enable Execution succeed. Parameter 1 name: Device.WiFi.SSID.8.Enable type: bool, value: true [INFO][2024-09-27 12:09:59,593][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : true [INFO][2024-09-27 12:09:59,593][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:09:59,593][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:09:59,593][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:09:59,604][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:09:59,806][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.WiFi.SSID.12.Enable [INFO][2024-09-27 12:09:59,807][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:09:59,929][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.12.Enable Execution succeed. Parameter 1 name: Device.WiFi.SSID.12.Enable type: bool, value: true <=============================================================> [INFO][2024-09-27 12:09:59,929][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:09:59,929][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.12.Enable Execution succeed. Parameter 1 name: Device.WiFi.SSID.12.Enable type: bool, value: true [INFO][2024-09-27 12:09:59,929][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.12.Enable Execution succeed. Parameter 1 name: Device.WiFi.SSID.12.Enable type: bool, value: true [INFO][2024-09-27 12:09:59,929][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : true [INFO][2024-09-27 12:09:59,929][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Response : [tableName=null, index=null, name=Device.WiFi.SSID.10101.Enable, protocolSpecificParamName=Device.WiFi.SSID.2.Enable, value=true, datatype=null, statusCode=0, tableName=null, index=null, name=Device.WiFi.SSID.10104.Enable, protocolSpecificParamName=Device.WiFi.SSID.8.Enable, value=true, datatype=null, statusCode=0, tableName=null, index=null, name=Device.WiFi.SSID.10106.Enable, protocolSpecificParamName=Device.WiFi.SSID.12.Enable, value=true, datatype=null, statusCode=0] [INFO][2024-09-27 12:09:59,929][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 9: ACTUAL : Successfully retrieve status of 5Ghz SSID for private wifi,PHASE1_LNF, PHASE2_LNF [INFO][2024-09-27 12:09:59,929][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:09:59,930][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WH-WEBPA-101] [step Number : s9][ Execution status : PASS] [Error Message : ] [INFO][2024-09-27 12:09:59,930][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-09-27 12:09:59,930][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WH-WEBPA-101","stepNumber":"s9","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"","executionStatus":"PASS","skipRemaining":true,"partnerName":"","automationId":"TC-RDKB-WH-WEBPA-1001"} [ERROR][2024-09-27 12:09:59,942][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - FAILED TO UPDATE EXECUTION RESULT.Kindly check if this manual id and step are added in Automatics - Manage scripts against the automation id [INFO][2024-09-27 12:09:59,942][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-09-27 12:09:59,942][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:09:59,942][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 10: DESCRIPTION : Get the 2.4 and 5GHz SSIDs using webpa [INFO][2024-09-27 12:09:59,942][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 10: ACTION : Execute webpa command :Device.WiFi.SSID.10001.SSID ,Device.WiFi.SSID.10101.SSID [INFO][2024-09-27 12:09:59,942][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 10: EXPECTED : Response should return the status of 2Ghz & 5Ghz SSID for private wifi successfully [INFO][2024-09-27 12:09:59,942][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:09:59,942][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-09-27 12:09:59,942][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-09-27 12:09:59,942][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method: DMCLI [INFO][2024-09-27 12:09:59,943][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Going to find protocol specific names [INFO][2024-09-27 12:09:59,943][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Going to execute commands [INFO][2024-09-27 12:09:59,943][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:09:59,943][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:09:59,943][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:09:59,954][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:10:00,146][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.WiFi.SSID.1.SSID [INFO][2024-09-27 12:10:00,146][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:10:00,268][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.1.SSID Execution succeed. Parameter 1 name: Device.WiFi.SSID.1.SSID type: string, value: RPI_RDKB-AP0 <=============================================================> [INFO][2024-09-27 12:10:00,268][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:00,268][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.1.SSID Execution succeed. Parameter 1 name: Device.WiFi.SSID.1.SSID type: string, value: RPI_RDKB-AP0 [INFO][2024-09-27 12:10:00,268][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.1.SSID Execution succeed. Parameter 1 name: Device.WiFi.SSID.1.SSID type: string, value: RPI_RDKB-AP0 [INFO][2024-09-27 12:10:00,269][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : RPI_RDKB-AP0 [INFO][2024-09-27 12:10:00,269][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:00,269][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:10:00,269][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:10:00,280][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:10:00,475][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.WiFi.SSID.2.SSID [INFO][2024-09-27 12:10:00,475][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:10:00,598][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.2.SSID Execution succeed. Parameter 1 name: Device.WiFi.SSID.2.SSID type: string, value: RPI_RDKB-AP1 <=============================================================> [INFO][2024-09-27 12:10:00,598][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:00,598][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.2.SSID Execution succeed. Parameter 1 name: Device.WiFi.SSID.2.SSID type: string, value: RPI_RDKB-AP1 [INFO][2024-09-27 12:10:00,598][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.SSID.2.SSID Execution succeed. Parameter 1 name: Device.WiFi.SSID.2.SSID type: string, value: RPI_RDKB-AP1 [INFO][2024-09-27 12:10:00,598][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : RPI_RDKB-AP1 [INFO][2024-09-27 12:10:00,598][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Response : [tableName=null, index=null, name=Device.WiFi.SSID.10001.SSID, protocolSpecificParamName=Device.WiFi.SSID.1.SSID, value=RPI_RDKB-AP0, datatype=null, statusCode=0, tableName=null, index=null, name=Device.WiFi.SSID.10101.SSID, protocolSpecificParamName=Device.WiFi.SSID.2.SSID, value=RPI_RDKB-AP1, datatype=null, statusCode=0] [INFO][2024-09-27 12:10:00,598][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 10: ACTUAL : Successfully retrieve status of 2Ghz & 5Ghz SSID for private wifi [INFO][2024-09-27 12:10:00,598][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:10:00,598][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WH-WEBPA-101] [step Number : s10][ Execution status : PASS] [Error Message : ] [INFO][2024-09-27 12:10:00,598][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-09-27 12:10:00,599][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WH-WEBPA-101","stepNumber":"s10","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"","executionStatus":"PASS","skipRemaining":true,"partnerName":"","automationId":"TC-RDKB-WH-WEBPA-1001"} [ERROR][2024-09-27 12:10:00,612][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - FAILED TO UPDATE EXECUTION RESULT.Kindly check if this manual id and step are added in Automatics - Manage scripts against the automation id [INFO][2024-09-27 12:10:00,612][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-09-27 12:10:00,612][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:10:00,612][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 11 : DESCRIPTION : Get the 2.4 and 5GHz passphrase using webpa [INFO][2024-09-27 12:10:00,612][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 11 : ACTION : Execute webpa command :Device.WiFi.AccessPoint.10001.Security.KeyPassphrase , Device.WiFi.AccessPoint.10101.Security.KeyPassphrase [INFO][2024-09-27 12:10:00,612][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 11: EXPECTED : Response should return the status of 2Ghz & 5Ghz passphrase for private wifi successfully [INFO][2024-09-27 12:10:00,613][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:10:00,613][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-09-27 12:10:00,613][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-09-27 12:10:00,613][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method: DMCLI [INFO][2024-09-27 12:10:00,613][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Going to find protocol specific names [INFO][2024-09-27 12:10:00,613][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Going to execute commands [INFO][2024-09-27 12:10:00,613][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:00,613][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:10:00,613][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:10:00,624][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:10:00,824][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.WiFi.AccessPoint.1.Security.KeyPassphrase [INFO][2024-09-27 12:10:00,825][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:10:00,947][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.AccessPoint.1.Security.KeyPassphrase Execution succeed. Parameter 1 name: Device.WiFi.AccessPoint.1.Security.KeyPassphrase type: string, value: rdk@1234 <=============================================================> [INFO][2024-09-27 12:10:00,947][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:00,947][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.AccessPoint.1.Security.KeyPassphrase Execution succeed. Parameter 1 name: Device.WiFi.AccessPoint.1.Security.KeyPassphrase type: string, value: rdk@1234 [INFO][2024-09-27 12:10:00,947][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.AccessPoint.1.Security.KeyPassphrase Execution succeed. Parameter 1 name: Device.WiFi.AccessPoint.1.Security.KeyPassphrase type: string, value: rdk@1234 [INFO][2024-09-27 12:10:00,947][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : rdk@1234 [INFO][2024-09-27 12:10:00,947][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:00,947][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:10:00,947][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:10:00,959][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:10:01,144][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.WiFi.AccessPoint.2.Security.KeyPassphrase [INFO][2024-09-27 12:10:01,144][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:10:01,266][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.AccessPoint.2.Security.KeyPassphrase Execution succeed. Parameter 1 name: Device.WiFi.AccessPoint.2.Security.KeyPassphrase type: string, value: rdk@1234 <=============================================================> [INFO][2024-09-27 12:10:01,266][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:01,266][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.AccessPoint.2.Security.KeyPassphrase Execution succeed. Parameter 1 name: Device.WiFi.AccessPoint.2.Security.KeyPassphrase type: string, value: rdk@1234 [INFO][2024-09-27 12:10:01,266][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.AccessPoint.2.Security.KeyPassphrase Execution succeed. Parameter 1 name: Device.WiFi.AccessPoint.2.Security.KeyPassphrase type: string, value: rdk@1234 [INFO][2024-09-27 12:10:01,267][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : rdk@1234 [INFO][2024-09-27 12:10:01,267][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Response : [tableName=null, index=null, name=Device.WiFi.AccessPoint.10001.Security.KeyPassphrase, protocolSpecificParamName=Device.WiFi.AccessPoint.1.Security.KeyPassphrase, value=rdk@1234, datatype=null, statusCode=0, tableName=null, index=null, name=Device.WiFi.AccessPoint.10101.Security.KeyPassphrase, protocolSpecificParamName=Device.WiFi.AccessPoint.2.Security.KeyPassphrase, value=rdk@1234, datatype=null, statusCode=0] [INFO][2024-09-27 12:10:01,267][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 11: ACTUAL : Successfully retrieve status of 2Ghz & 5Ghz passphrase for private wifi [INFO][2024-09-27 12:10:01,267][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:10:01,267][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WH-WEBPA-101] [step Number : s11][ Execution status : PASS] [Error Message : ] [INFO][2024-09-27 12:10:01,267][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-09-27 12:10:01,268][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WH-WEBPA-101","stepNumber":"s11","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"","executionStatus":"PASS","skipRemaining":true,"partnerName":"","automationId":"TC-RDKB-WH-WEBPA-1001"} [ERROR][2024-09-27 12:10:01,281][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - FAILED TO UPDATE EXECUTION RESULT.Kindly check if this manual id and step are added in Automatics - Manage scripts against the automation id [INFO][2024-09-27 12:10:01,281][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-09-27 12:10:01,281][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:10:01,281][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 12 : DESCRIPTION : Get the 2.4 and 5GHz wifi radio enable status using webpa [INFO][2024-09-27 12:10:01,282][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 12 : ACTION : Execute webpa command :Device.WiFi.Radio.10000.Enable,Device.WiFi.Radio.10100.Enable [INFO][2024-09-27 12:10:01,282][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 12 : EXPECTED : Response should return the 2.4 and 5GHz wifi radio enable status successfully [INFO][2024-09-27 12:10:01,282][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:10:01,282][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-09-27 12:10:01,282][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-09-27 12:10:01,282][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method: DMCLI [INFO][2024-09-27 12:10:01,282][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Going to find protocol specific names [INFO][2024-09-27 12:10:01,282][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Going to execute commands [INFO][2024-09-27 12:10:01,282][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:01,282][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:10:01,282][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:10:01,292][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:10:01,472][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.WiFi.Radio.1.Enable [INFO][2024-09-27 12:10:01,472][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:10:01,594][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.Radio.1.Enable Execution succeed. Parameter 1 name: Device.WiFi.Radio.1.Enable type: bool, value: true <=============================================================> [INFO][2024-09-27 12:10:01,594][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:01,594][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.Radio.1.Enable Execution succeed. Parameter 1 name: Device.WiFi.Radio.1.Enable type: bool, value: true [INFO][2024-09-27 12:10:01,595][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.Radio.1.Enable Execution succeed. Parameter 1 name: Device.WiFi.Radio.1.Enable type: bool, value: true [INFO][2024-09-27 12:10:01,595][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : true [INFO][2024-09-27 12:10:01,595][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:01,595][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:10:01,595][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:10:01,607][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:10:01,783][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.WiFi.Radio.2.Enable [INFO][2024-09-27 12:10:01,784][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:10:01,906][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.Radio.2.Enable Execution succeed. Parameter 1 name: Device.WiFi.Radio.2.Enable type: bool, value: true <=============================================================> [INFO][2024-09-27 12:10:01,906][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:01,906][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.Radio.2.Enable Execution succeed. Parameter 1 name: Device.WiFi.Radio.2.Enable type: bool, value: true [INFO][2024-09-27 12:10:01,906][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.Radio.2.Enable Execution succeed. Parameter 1 name: Device.WiFi.Radio.2.Enable type: bool, value: true [INFO][2024-09-27 12:10:01,906][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : true [INFO][2024-09-27 12:10:01,907][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Response : [tableName=null, index=null, name=Device.WiFi.Radio.10000.Enable, protocolSpecificParamName=Device.WiFi.Radio.1.Enable, value=true, datatype=null, statusCode=0, tableName=null, index=null, name=Device.WiFi.Radio.10100.Enable, protocolSpecificParamName=Device.WiFi.Radio.2.Enable, value=true, datatype=null, statusCode=0] [INFO][2024-09-27 12:10:01,907][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 12: ACTUAL : Successfully retrieve status of 2.4 and 5GHz wifi radio enable status [INFO][2024-09-27 12:10:01,907][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:10:01,907][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WH-WEBPA-101] [step Number : s12][ Execution status : PASS] [Error Message : ] [INFO][2024-09-27 12:10:01,907][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-09-27 12:10:01,907][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WH-WEBPA-101","stepNumber":"s12","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"","executionStatus":"PASS","skipRemaining":true,"partnerName":"","automationId":"TC-RDKB-WH-WEBPA-1001"} [ERROR][2024-09-27 12:10:01,919][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - FAILED TO UPDATE EXECUTION RESULT.Kindly check if this manual id and step are added in Automatics - Manage scripts against the automation id [INFO][2024-09-27 12:10:01,920][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-09-27 12:10:01,920][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:10:01,920][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 13 : DESCRIPTION : Get the 2.4 and 5GHz wireless channel status using webpa [INFO][2024-09-27 12:10:01,920][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 13 : ACTION : Execute webpa command : Device.WiFi.Radio.10000.Channel,Device.WiFi.Radio.10100.Channel [INFO][2024-09-27 12:10:01,920][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 13: EXPECTED : Response should return the 2.4 and 5GHz wireless channel status successfully [INFO][2024-09-27 12:10:01,920][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:10:01,920][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-09-27 12:10:01,920][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-09-27 12:10:01,920][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method: DMCLI [INFO][2024-09-27 12:10:01,920][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Going to find protocol specific names [INFO][2024-09-27 12:10:01,920][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Going to execute commands [INFO][2024-09-27 12:10:01,920][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:01,920][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:10:01,920][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:10:01,935][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:10:02,138][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.WiFi.Radio.1.Channel [INFO][2024-09-27 12:10:02,138][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:10:02,260][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.Radio.1.Channel Execution succeed. Parameter 1 name: Device.WiFi.Radio.1.Channel type: uint, value: 1 <=============================================================> [INFO][2024-09-27 12:10:02,260][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:02,260][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.Radio.1.Channel Execution succeed. Parameter 1 name: Device.WiFi.Radio.1.Channel type: uint, value: 1 [INFO][2024-09-27 12:10:02,260][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.Radio.1.Channel Execution succeed. Parameter 1 name: Device.WiFi.Radio.1.Channel type: uint, value: 1 [INFO][2024-09-27 12:10:02,260][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : 1 [INFO][2024-09-27 12:10:02,261][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:02,261][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:10:02,261][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:10:02,271][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:10:02,455][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.WiFi.Radio.2.Channel [INFO][2024-09-27 12:10:02,456][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:10:02,578][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.Radio.2.Channel Execution succeed. Parameter 1 name: Device.WiFi.Radio.2.Channel type: uint, value: 44 <=============================================================> [INFO][2024-09-27 12:10:02,578][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:02,578][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.Radio.2.Channel Execution succeed. Parameter 1 name: Device.WiFi.Radio.2.Channel type: uint, value: 44 [INFO][2024-09-27 12:10:02,578][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.wifi): Device.WiFi.Radio.2.Channel Execution succeed. Parameter 1 name: Device.WiFi.Radio.2.Channel type: uint, value: 44 [INFO][2024-09-27 12:10:02,578][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : 44 [INFO][2024-09-27 12:10:02,578][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Response : [tableName=null, index=null, name=Device.WiFi.Radio.10000.Channel, protocolSpecificParamName=Device.WiFi.Radio.1.Channel, value=1, datatype=null, statusCode=0, tableName=null, index=null, name=Device.WiFi.Radio.10100.Channel, protocolSpecificParamName=Device.WiFi.Radio.2.Channel, value=44, datatype=null, statusCode=0] [INFO][2024-09-27 12:10:02,579][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 13: ACTUAL : Successfully retrieve the 2.4 and 5GHz wireless channel status [INFO][2024-09-27 12:10:02,579][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:10:02,579][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WH-WEBPA-101] [step Number : s13][ Execution status : PASS] [Error Message : ] [INFO][2024-09-27 12:10:02,579][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-09-27 12:10:02,579][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WH-WEBPA-101","stepNumber":"s13","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"","executionStatus":"PASS","skipRemaining":true,"partnerName":"","automationId":"TC-RDKB-WH-WEBPA-1001"} [ERROR][2024-09-27 12:10:02,592][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - FAILED TO UPDATE EXECUTION RESULT.Kindly check if this manual id and step are added in Automatics - Manage scripts against the automation id [INFO][2024-09-27 12:10:02,592][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-09-27 12:10:02,592][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:10:02,592][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 14 : DESCRIPTION : Get the firmware details like firmware version,firmware file,rdkbRgPlatformCapable,Reboot Reduction Flag,Firmware Load Protocol , HTTP/TFTP,SwServerAddressType,firmware load start,firmware load status [INFO][2024-09-27 12:10:02,592][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 14 : ACTION : Execute webpa command : firmware related commands [INFO][2024-09-27 12:10:02,592][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 14: EXPECTED : Response should return the firmware related details [INFO][2024-09-27 12:10:02,593][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:10:02,593][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-09-27 12:10:02,593][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-09-27 12:10:02,593][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Access Method: DMCLI [INFO][2024-09-27 12:10:02,593][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Going to find protocol specific names [INFO][2024-09-27 12:10:02,593][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Going to execute commands [INFO][2024-09-27 12:10:02,593][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:02,593][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:10:02,593][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:10:02,603][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:10:02,790][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.DeviceInfo.X_CISCO_COM_FirmwareName [INFO][2024-09-27 12:10:02,790][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:10:02,913][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.DeviceInfo.X_CISCO_COM_FirmwareName Execution succeed. Parameter 1 name: Device.DeviceInfo.X_CISCO_COM_FirmwareName type: string, value: rdkb-generic-broadband-image_rdkb-2024q2-kirkstone_20240903134936 <=============================================================> [INFO][2024-09-27 12:10:02,913][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:02,913][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.DeviceInfo.X_CISCO_COM_FirmwareName Execution succeed. Parameter 1 name: Device.DeviceInfo.X_CISCO_COM_FirmwareName type: string, value: rdkb-generic-broadband-image_rdkb-2024q2-kirkstone_20240903134936 [INFO][2024-09-27 12:10:02,913][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.DeviceInfo.X_CISCO_COM_FirmwareName Execution succeed. Parameter 1 name: Device.DeviceInfo.X_CISCO_COM_FirmwareName type: string, value: rdkb-generic-broadband-image_rdkb-2024q2-kirkstone_20240903134936 [INFO][2024-09-27 12:10:02,913][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : rdkb-generic-broadband-image_rdkb-2024q2-kirkstone_20240903134936 [INFO][2024-09-27 12:10:02,913][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:02,913][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:10:02,913][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:10:02,924][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:10:03,137][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareToDownload [INFO][2024-09-27 12:10:03,138][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:10:03,260][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.fwupgrademanager): Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareToDownload Execution succeed. Parameter 1 name: Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareToDownload type: string, value: <=============================================================> [INFO][2024-09-27 12:10:03,260][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:03,260][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.fwupgrademanager): Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareToDownload Execution succeed. Parameter 1 name: Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareToDownload type: string, value: [INFO][2024-09-27 12:10:03,260][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.fwupgrademanager): Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareToDownload Execution succeed. Parameter 1 name: Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareToDownload type: string, value: [INFO][2024-09-27 12:10:03,260][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : [INFO][2024-09-27 12:10:03,261][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:03,261][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:10:03,261][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:10:03,271][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:10:03,475][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.DeviceInfo.X_COMCAST-COM_rdkbPlatformCapable [INFO][2024-09-27 12:10:03,475][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:10:03,597][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.DeviceInfo.X_COMCAST-COM_rdkbPlatformCapable Execution succeed. Parameter 1 name: Device.DeviceInfo.X_COMCAST-COM_rdkbPlatformCapable type: bool, value: true <=============================================================> [INFO][2024-09-27 12:10:03,597][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:03,597][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.DeviceInfo.X_COMCAST-COM_rdkbPlatformCapable Execution succeed. Parameter 1 name: Device.DeviceInfo.X_COMCAST-COM_rdkbPlatformCapable type: bool, value: true [INFO][2024-09-27 12:10:03,597][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.DeviceInfo.X_COMCAST-COM_rdkbPlatformCapable Execution succeed. Parameter 1 name: Device.DeviceInfo.X_COMCAST-COM_rdkbPlatformCapable type: bool, value: true [INFO][2024-09-27 12:10:03,598][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : true [INFO][2024-09-27 12:10:03,598][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:03,598][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:10:03,598][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:10:03,609][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:10:03,806][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadAndFactoryReset [INFO][2024-09-27 12:10:03,806][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:10:03,928][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.fwupgrademanager): Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadAndFactoryReset Execution succeed. Parameter 1 name: Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadAndFactoryReset type: int, value: 0 <=============================================================> [INFO][2024-09-27 12:10:03,928][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:03,928][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.fwupgrademanager): Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadAndFactoryReset Execution succeed. Parameter 1 name: Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadAndFactoryReset type: int, value: 0 [INFO][2024-09-27 12:10:03,928][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.fwupgrademanager): Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadAndFactoryReset Execution succeed. Parameter 1 name: Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadAndFactoryReset type: int, value: 0 [INFO][2024-09-27 12:10:03,929][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : 0 [INFO][2024-09-27 12:10:03,929][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:03,929][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:10:03,929][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:10:03,940][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:10:04,125][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadNow [INFO][2024-09-27 12:10:04,125][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:10:04,248][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.fwupgrademanager): Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadNow Execution succeed. Parameter 1 name: Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadNow type: bool, value: false <=============================================================> [INFO][2024-09-27 12:10:04,248][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:04,248][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.fwupgrademanager): Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadNow Execution succeed. Parameter 1 name: Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadNow type: bool, value: false [INFO][2024-09-27 12:10:04,248][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.fwupgrademanager): Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadNow Execution succeed. Parameter 1 name: Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadNow type: bool, value: false [INFO][2024-09-27 12:10:04,248][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : false [INFO][2024-09-27 12:10:04,248][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:04,248][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:10:04,248][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:10:04,281][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:10:04,461][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: dmcli eRT getv Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadStatus [INFO][2024-09-27 12:10:04,461][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:10:04,584][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.fwupgrademanager): Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadStatus Execution succeed. Parameter 1 name: Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadStatus type: string, value: Not Started <=============================================================> [INFO][2024-09-27 12:10:04,584][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.144 [INFO][2024-09-27 12:10:04,584][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.fwupgrademanager): Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadStatus Execution succeed. Parameter 1 name: Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadStatus type: string, value: Not Started [INFO][2024-09-27 12:10:04,584][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. getv from/to component(eRT.com.cisco.spvtg.ccsp.fwupgrademanager): Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadStatus Execution succeed. Parameter 1 name: Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadStatus type: string, value: Not Started [INFO][2024-09-27 12:10:04,584][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Dmcli param value : Not Started [INFO][2024-09-27 12:10:04,584][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - TR181 Response : [tableName=null, index=null, name=Device.DeviceInfo.X_CISCO_COM_FirmwareName, protocolSpecificParamName=Device.DeviceInfo.X_CISCO_COM_FirmwareName, value=rdkb-generic-broadband-image_rdkb-2024q2-kirkstone_20240903134936, datatype=null, statusCode=0, tableName=null, index=null, name=Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareToDownload, protocolSpecificParamName=Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareToDownload, value=, datatype=null, statusCode=0, tableName=null, index=null, name=Device.DeviceInfo.X_COMCAST-COM_rdkbPlatformCapable, protocolSpecificParamName=Device.DeviceInfo.X_COMCAST-COM_rdkbPlatformCapable, value=true, datatype=null, statusCode=0, tableName=null, index=null, name=Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadAndFactoryReset, protocolSpecificParamName=Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadAndFactoryReset, value=0, datatype=null, statusCode=0, tableName=null, index=null, name=Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadNow, protocolSpecificParamName=Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadNow, value=false, datatype=null, statusCode=0, tableName=null, index=null, name=Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadStatus, protocolSpecificParamName=Device.DeviceInfo.X_RDKCENTRAL-COM_FirmwareDownloadStatus, value=Not Started, datatype=null, statusCode=0] [INFO][2024-09-27 12:10:04,584][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 14: ACTUAL : Successfully return the firmware related details [INFO][2024-09-27 12:10:04,584][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:10:04,584][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WH-WEBPA-101] [step Number : s14][ Execution status : PASS] [Error Message : ] [INFO][2024-09-27 12:10:04,584][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-09-27 12:10:04,585][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WH-WEBPA-101","stepNumber":"s14","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"","executionStatus":"PASS","skipRemaining":true,"partnerName":"","automationId":"TC-RDKB-WH-WEBPA-1001"} [ERROR][2024-09-27 12:10:04,599][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - FAILED TO UPDATE EXECUTION RESULT.Kindly check if this manual id and step are added in Automatics - Manage scripts against the automation id [INFO][2024-09-27 12:10:04,599][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-09-27 12:10:04,599][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:10:04,599][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 15: DESCRIPTION: Capture the time taken to execute webpa get parameters. [INFO][2024-09-27 12:10:04,599][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 15 ACTION : Execute the following command via SSH: date +%Y-%m-%d' '%H:%M:%S [INFO][2024-09-27 12:10:04,599][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 15 EXPECTED: Successfully Current system time should be fetched [INFO][2024-09-27 12:10:04,599][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:10:04,599][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Entering executeCommandUsingSsh method [INFO][2024-09-27 12:10:04,599][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - About to create SSH connection to DutIP:192.168.2.144 [INFO][2024-09-27 12:10:04,599][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSH Host IP : 192.168.2.144 [INFO][2024-09-27 12:10:04,599][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-09-27 12:10:04,610][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-09-27 12:10:04,804][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Executing command: date +%Y-%m-%d' '%H:%M:%S [INFO][2024-09-27 12:10:04,804][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-09-27 12:10:04,926][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - <=========================== RESPONSE =======================> 2024-09-03 13:50:09 <=============================================================> [INFO][2024-09-27 12:10:04,926][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Received response: 2024-09-03 13:50:09 [INFO][2024-09-27 12:10:04,926][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exiting executeCommandUsingSsh method [INFO][2024-09-27 12:10:04,927][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 15 ACTUAL: Successfully Current system time should be fetched 2024-09-03 13:49:51 [INFO][2024-09-27 12:10:04,927][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:10:04,927][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WH-WEBPA-101] [step Number : s15][ Execution status : PASS] [Error Message : ] [INFO][2024-09-27 12:10:04,927][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-09-27 12:10:04,928][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WH-WEBPA-101","stepNumber":"s15","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"","executionStatus":"PASS","skipRemaining":true,"partnerName":"","automationId":"TC-RDKB-WH-WEBPA-1001"} [ERROR][2024-09-27 12:10:04,941][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - FAILED TO UPDATE EXECUTION RESULT.Kindly check if this manual id and step are added in Automatics - Manage scripts against the automation id [INFO][2024-09-27 12:10:04,941][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-09-27 12:10:04,941][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:10:04,941][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 16: DESCRIPTION: Compare the time taken for reboot and WebPA get response [INFO][2024-09-27 12:10:04,941][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 16: ACTION: Calculate the time difference between the start and end of execution in milliseconds and convert the result into seconds. [INFO][2024-09-27 12:10:04,941][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 16: EXPECTED: Time difference between start and end of execution [INFO][2024-09-27 12:10:04,941][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:10:04,942][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - STEP 16 ACTUAL: Successfully calculated time taken for device reboot: 18.0 seconds. [INFO][2024-09-27 12:10:04,942][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - ****************************************************************************** [INFO][2024-09-27 12:10:04,942][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WH-WEBPA-101] [step Number : s16][ Execution status : PASS] [Error Message : ] [INFO][2024-09-27 12:10:04,942][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-09-27 12:10:04,943][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WH-WEBPA-101","stepNumber":"s16","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"","executionStatus":"PASS","skipRemaining":true,"partnerName":"","automationId":"TC-RDKB-WH-WEBPA-1001"} [ERROR][2024-09-27 12:10:04,953][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - FAILED TO UPDATE EXECUTION RESULT.Kindly check if this manual id and step are added in Automatics - Manage scripts against the automation id [INFO][2024-09-27 12:10:04,953][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-09-27 12:10:04,953][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - #################### ENDING TEST CASE: TC-RDKB-WH-WEBPA-1001 ##################### [INFO][2024-09-27 12:10:04,956][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - >>>[AFTER_METHOD]: Clear device trace buffer for D8:3A:DD:13:8C:13 [INFO][2024-09-27 12:10:04,965][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - NewLocation for log saving logs /var/lib/jenkins/workspace/JOB1/target/TC-RDKB-WH-WEBPA-1001/D83ADD138C13/settoptrace/ [INFO][2024-09-27 12:10:04,966][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - created a new directory true [INFO][2024-09-27 12:10:04,966][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - New trace location from the strings /var/lib/jenkins/workspace/JOB1/target/settoptrace/D83ADD138C13settop_trace.log [INFO][2024-09-27 12:10:04,968][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Writing stated from line [INFO][2024-09-27 12:10:05,013][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - [ HTML LOG PARSER ] : End of log parser Fri Sep 27 12:10:05 IST 2024 [INFO][2024-09-27 12:10:05,013][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - NewLocation for log saving logs /var/lib/jenkins/workspace/JOB1/target/TC-RDKB-WH-WEBPA-1001/D83ADD138C13/logs/ [INFO][2024-09-27 12:10:05,014][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - created a new directory true [INFO][2024-09-27 12:10:05,014][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Destination Summary file doesn't exist. Creating one! [INFO][2024-09-27 12:10:05,014][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Writing stated from line [INFO][2024-09-27 12:10:05,120][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - [ HTML LOG PARSER ] : End of log parser Fri Sep 27 12:10:05 IST 2024 [INFO][2024-09-27 12:10:05,121][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - >>>[AFTER_METHOD]: Sending test execution completion time for D8:3A:DD:13:8C:13 [INFO][2024-09-27 12:10:05,121][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - http://192.168.2.59:8080/Automatics/captureTestTriggerTime.htm [INFO][2024-09-27 12:10:05,121][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - {"jobId":456,"automationId":"TC-RDKB-WH-WEBPA-1001","macAddress":"D8:3A:DD:13:8C:13","startDateTimeEST":0,"endDateTimeEST":1727419205121} [INFO][2024-09-27 12:10:05,136][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Capture execution time - Response : HTTP/1.1 200 [INFO][2024-09-27 12:10:05,137][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Restarting Trace in after method [INFO][2024-09-27 12:10:05,137][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Is trace required for connected gateway: false [INFO][2024-09-27 12:10:05,137][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Is trace required for connected gateway: false [INFO][2024-09-27 12:10:05,137][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Going for if build changed : Test Type : GROUP_OR_AUTOID [INFO][2024-09-27 12:10:05,137][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Skipping build change verification as partner specific initialization is not configured. [INFO][2024-09-27 12:10:05,137][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - >>>[AFTER_METHOD]: Build Change Status: NO_CHANGE [INFO][2024-09-27 12:10:05,137][D8:3A:DD:13:8C:13[TC-RDKB-WH-WEBPA-1001 : D83ADD138C13] - Skipping parter specific after method clean up as it is not configured. ===== Invoked methods AutomaticsTestBase.performBeforeSuiteInit(org.testng.ITestContext)[pri:0, instance:com.automatics.rdkb.tests.webpa.BroadBandWebPaTests@1690f9c3]org.testng.TestRunner@11c5f427 378599875 AutomaticsTestBase.performBeforeMethodInit([Ljava.lang.Object;, org.testng.ITestResult)[pri:0, instance:com.automatics.rdkb.tests.webpa.BroadBandWebPaTests@1690f9c3][Ljava.lang.Object;@1471fcd5 [TestResult name={null} status=CREATED method=BroadBandWebPaTests.compareSnmpAndWebpaResponseTimeForWarehouse(com.automatics.device.Dut)[pri:0, instance:com.automatics.rdkb.tests.webpa.BroadBandWebPaTests@1690f9c3] output={null}] 378599875 BroadBandWebPaTests.compareSnmpAndWebpaResponseTimeForWarehouse(com.automatics.device.Dut)[pri:0, instance:com.automatics.rdkb.tests.webpa.BroadBandWebPaTests@1690f9c3]com.automatics.device.Device@3483c1be 378599875 AutomaticsTestBase.performAfterMethodCleanup([Ljava.lang.Object;, org.testng.ITestResult)[pri:0, instance:com.automatics.rdkb.tests.webpa.BroadBandWebPaTests@1690f9c3][Ljava.lang.Object;@1471fcd5 [TestResult name=compareSnmpAndWebpaResponseTimeForWarehouse status=SUCCESS method=BroadBandWebPaTests.compareSnmpAndWebpaResponseTimeForWarehouse(com.automatics.device.Dut)[pri:0, instance:com.automatics.rdkb.tests.webpa.BroadBandWebPaTests@1690f9c3] output={null}] 378599875 ===== PASSED: compareSnmpAndWebpaResponseTimeForWarehouse(com.automatics.device.Device@3483c1be) =============================================== MyTest Tests run: 1, Failures: 0, Skips: 0 =============================================== [INFO][2024-09-27 12:10:05,180][[com.automatics.executor.Starter.main()] - Finished testing class: org.testng.TestRunner [INFO][2024-09-27 12:10:05,182][[com.automatics.executor.Starter.main()] - >>>[AFTER-SUITE]: Performing after suite cleanup [INFO][2024-09-27 12:10:05,183][[com.automatics.executor.Starter.main()] - Bean testInitializer is not configured. [INFO][2024-09-27 12:10:05,183][[com.automatics.executor.Starter.main()] - >>>[AFTER-SUITE]: Locked devices after suite execution 1 [INFO][2024-09-27 12:10:05,184][[com.automatics.executor.Starter.main()] - Value of intial testType : QUICK [INFO][2024-09-27 12:10:05,185][[com.automatics.executor.Starter.main()] - Value of TestType provided by job : GROUP_OR_AUTOID [INFO][2024-09-27 12:10:05,185][[com.automatics.executor.Starter.main()] - >>>[AFTER-SUITE]: Verifying if build changed after test [INFO][2024-09-27 12:10:05,185][[com.automatics.executor.Starter.main()] - Skipping build change verification as partner specific initialization is not configured. [INFO][2024-09-27 12:10:05,186][[com.automatics.executor.Starter.main()] - >>>[AFTER-SUITE]: Build Change Status: NO_CHANGE [INFO][2024-09-27 12:10:05,186][[com.automatics.executor.Starter.main()] - Is trace required for connected gateway: false [INFO][2024-09-27 12:10:05,186][[com.automatics.executor.Starter.main()] - Connection instance is Null [INFO][2024-09-27 12:10:05,186][[com.automatics.executor.Starter.main()] - Connection instance is Null [ERROR][2024-09-27 12:10:05,186][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Sleep interrupted sleep interrupted [INFO][2024-09-27 12:10:05,186][[com.automatics.executor.Starter.main()] - Is trace required for connected gateway: false [INFO][2024-09-27 12:10:05,187][[com.automatics.executor.Starter.main()] - Skipping parter specific after suite clean up as it is not configured. [INFO][2024-09-27 12:10:05,188][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Connection instance is Null [INFO][2024-09-27 12:10:05,191][[com.automatics.executor.Starter.main()] - Releasing device D8:3A:DD:13:8C:13 Url Path: http://192.168.2.145:8080/DeviceManager/deviceManagement/device/release [INFO][2024-09-27 12:10:05,192][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Connection instance is Null [INFO][2024-09-27 12:10:05,192][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Exited from readOutputFromChannel method [INFO][2024-09-27 12:10:05,243][[com.automatics.executor.Starter.main()] - Response: {"status":"SUCCESS","mac":"D8:3A:DD:13:8C:13"} [INFO][2024-09-27 12:10:05,250][[com.automatics.executor.Starter.main()] - Releasing device 2C:44:FD:18:F9:FE Url Path: http://192.168.2.145:8080/DeviceManager/deviceManagement/device/release [INFO][2024-09-27 12:10:05,285][[com.automatics.executor.Starter.main()] - Response: {"status":"SUCCESS","mac":"2C:44:FD:18:F9:FE"} [INFO][2024-09-27 12:10:05,286][[com.automatics.executor.Starter.main()] - Successfully unlocked RDKB (D8:3A:DD:13:8C:13) mapped components - (WINDOWSVM) - 2C:44:FD:18:F9:FE [INFO][2024-09-27 12:10:05,287][[com.automatics.executor.Starter.main()] - SETTOP - D8:3A:DD:13:8C:13 RELEASED. [INFO][2024-09-27 12:10:05,288][[com.automatics.executor.Starter.main()] - [AFTER-SUITE:]JSON message to Automatics: {"status":"COMPLETED","service":"","buildImageName":"RPI-RDKB","settopList":["D8:3A:DD:13:8C:13"],"startTime":1727419087642,"completionTime":1727419205287,"JMD_ID":456,"updateRdkPortal":true,"result":{"build_name":"RPI-RDKB","type":"GROUP_OR_AUTOID ","tests":[]}} [INFO][2024-09-27 12:10:05,305][[com.automatics.executor.Starter.main()] - [ HTML LOG PARSER ] : line [INFO][2024-09-27 12:08:44,093][456][D8:3A:DD:13:8C:13|TestNG-PoolService-0|com.automatics.executor.AutomaticsTestListener:onTestStart:110] STARTED - compareSnmpAndWebpaResponseTimeForWarehouse - com.automatics.device.Device@3483c1be [INFO][2024-09-27 12:10:05,305][[com.automatics.executor.Starter.main()] - [ HTML LOG PARSER ] : line [DEBUG][2024-09-27 12:08:44,094][456][D8:3A:DD:13:8C:13|TC-RDKB-WH-WEBPA-1001 : D83ADD138C13|com.automatics.executor.AutomaticsTestListener:onTestStart:150] Started appending log =============================================== MySuite Total tests run: 1, Passes: 1, Failures: 0, Skips: 0 =============================================== [INFO][2024-09-27 12:10:05,404][[com.automatics.executor.Starter.main()] - Updating final execution status to Automatics [INFO][2024-09-27 12:10:05,405][[Thread-109] - ============= MESSAGE SEND TO AUTOMATICS ============== [INFO][2024-09-27 12:10:05,406][[Thread-109] - Tested build name : RPI-RDKB [INFO][2024-09-27 12:10:05,406][[Thread-109] - Final execution status : COMPLETED [INFO][2024-09-27 12:10:05,406][[Thread-109] - Final successful device list : ["D8:3A:DD:13:8C:13"] [INFO][2024-09-27 12:10:05,406][[Thread-109] - Job Id : 456 [INFO][2024-09-27 12:10:05,406][[Thread-109] - ============================================================== [INFO][2024-09-27 12:10:05,406][[Thread-109] - >>>[INIT]: Automatics JSON -> {"status":"COMPLETED","service":"","buildImageName":"RPI-RDKB","settopList":["D8:3A:DD:13:8C:13"],"startTime":1727419087642,"completionTime":1727419205287,"JMD_ID":456,"updateRdkPortal":true,"result":{"build_name":"RPI-RDKB","type":"GROUP_OR_AUTOID ","tests":[]}} [INFO][2024-09-27 12:10:05,407][[Thread-109] - http://192.168.2.59:8080/Automatics/executionResponse.htm [INFO][2024-09-27 12:12:05,549][[Thread-109] - HTTP STATUS LINE : HTTP/1.1 200 [INFO][2024-09-27 12:12:05,550][[Thread-109] - HTTP STATUS CODE : 200 [INFO][2024-09-27 12:12:05,551][[com.automatics.executor.Starter.main()] - ******** EXECUTION COMPLETED ********* [INFO] ------------------------------------------------------------------------ [INFO] BUILD SUCCESS [INFO] ------------------------------------------------------------------------ [INFO] Total time: 05:05 min [INFO] Finished at: 2024-09-27T12:12:05+05:30 [INFO] ------------------------------------------------------------------------ Inside Add Shutdown Hook [INFO][2024-09-27 12:12:05,559][[Thread-1] - Bean testInitializer is not configured. [INFO][2024-09-27 12:12:05,559][[Thread-1] - Closing partner application context [INFO][2024-09-27 12:12:05,561][[Thread-1] - Closing core application context [JOB1] $ /bin/sh -xe /tmp/jenkins5986686554401319040.sh + /var/lib/jenkins/pre-test-config.sh -g com.automatics.providers -a rpi-provider-impl -v 0.0.1-SNAPSHOT Mode: RDKB Dependency already exist. Dependency already exist. Adding dependency com.automatics.providersrpi-provider-impl0.0.1-SNAPSHOT Finished updating pom.xml Archiving artifacts Finished: SUCCESS