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 -DsettopList=D8:3A:DD:13:8C:13 "-DfilterTestType=GROUP_OR_AUTOID " -DupdateRdkPortal=true -Dgrb=rdk-next -Dend_point=RACK_DEVICE -DfilterTestIds=TC-RDKB-DEVICE-RESET-1003 -DexecutionMode=RDKB -Dgr=rdkb-tests -DBUILD_NAME=rdkb-generic-broadband-image_rdk-next_20240207050050 -DJMD_ID=456 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.130: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] [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 118 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 --- 15:59:02,671 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender] 15:59:04,030 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [stdOutAppender] 15:59:05,250 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@7:13 - no applicable action for [onMatch], current ElementPath is [[configuration][appender][filter][onMatch]] 15:59:05,250 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@8:16 - no applicable action for [onMismatch], current ElementPath is [[configuration][appender][filter][onMismatch]] 15:59:05,251 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property 15:59:05,309 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender] 15:59:05,432 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [deviceSiftingAppender] 15:59:05,434 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@18:13 - no applicable action for [onMatch], current ElementPath is [[configuration][appender][filter][onMatch]] 15:59:05,434 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@19:16 - no applicable action for [onMismatch], current ElementPath is [[configuration][appender][filter][onMismatch]] 15:59:05,483 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.sift.MDCBasedDiscriminator] for [discriminator] property 15:59:05,506 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender] 15:59:05,506 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [TraceLogger] 15:59:05,506 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.sift.MDCBasedDiscriminator] for [discriminator] property 15:59:05,507 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender] 15:59:05,507 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [SerialTrace] 15:59:05,507 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.sift.MDCBasedDiscriminator] for [discriminator] property 15:59:05,507 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender] 15:59:05,507 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [crash-analysis] 15:59:05,507 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.sift.MDCBasedDiscriminator] for [discriminator] property 15:59:05,508 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [org.apache.http] to false 15:59:05,508 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - org.apache.http level set to INFO 15:59:05,509 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [deviceSiftingAppender] to Logger[org.apache.http] 15:59:05,509 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [ConnectionTrace] to TRACE 15:59:05,509 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [ConnectionTrace] to false 15:59:05,509 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [TraceLogger] to Logger[ConnectionTrace] 15:59:05,509 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [SerialTrace] to TRACE 15:59:05,509 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [SerialTrace] to false 15:59:05,509 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [SerialTrace] to Logger[SerialTrace] 15:59:05,509 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [crash-analysis] to DEBUG 15:59:05,510 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [crash-analysis] to false 15:59:05,510 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [crash-analysis] to Logger[crash-analysis] 15:59:05,510 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [stdOutAppender] to Logger[ROOT] 15:59:05,510 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [deviceSiftingAppender] to Logger[ROOT] 15:59:05,510 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration. 15:59:05,510 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@7bc12907 - Registering current configuration as safe fallback point [INFO][2024-05-08 15:59:05,512][[com.automatics.executor.Starter.main()] - Starting the execution process for the given test cases. 15:59:05,709 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.FileAppender] 15:59:05,711 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE-test-suite] 15:59:05,721 |-INFO in ch.qos.logback.core.FileAppender[FILE-test-suite] - File property is set to [target/logs/test-suite.log] [INFO][2024-05-08 15:59:07,421][[com.automatics.executor.Starter.main()] - Initializing application context partner-applicationContext.xml [INFO][2024-05-08 15:59:21,063][[com.automatics.executor.Starter.main()] - Initializing application context applicationContext.xml [INFO][2024-05-08 15:59:22,105][[com.automatics.executor.Starter.main()] - AutomaticsPropertyUtility: Reading automatics.properties file from http://192.168.2.130:8080/AutomaticsProps/automatics.properties [INFO][2024-05-08 15:59:23,567][[com.automatics.executor.Starter.main()] - Automatics Response - {} [INFO][2024-05-08 15:59:23,596][[com.automatics.executor.Starter.main()] - ***************** Automatics BUILD PARAMETERS ***************** [INFO][2024-05-08 15:59:23,597][[com.automatics.executor.Starter.main()] - Shut Down Hook Attached. [INFO][2024-05-08 15:59:23,674][[com.automatics.executor.Starter.main()] - Start Execution Test Suite [INFO][2024-05-08 15:59:23,675][[com.automatics.executor.Starter.main()] - Bean testInitializer is not configured. [INFO][2024-05-08 15:59:23,676][[com.automatics.executor.Starter.main()] - Cleaning the trace log directory [INFO][2024-05-08 15:59:24,032][[com.automatics.executor.Starter.main()] - AutomaticsPropertyUtility: Reading automatics.properties file from http://192.168.2.130:8080/AutomaticsProps/automatics.properties [INFO][2024-05-08 15:59:24,055][[com.automatics.executor.Starter.main()] - >>>[INIT]: Validating config files [INFO][2024-05-08 15:59:24,057][[com.automatics.executor.Starter.main()] - INIT- Requesting device config from http://192.168.2.130:8080/AutomaticsProps/deviceProps.json [INFO][2024-05-08 15:59:25,399][[com.automatics.executor.Starter.main()] - INIT- Requesting device config from http://192.168.2.130:8080/AutomaticsProps/deviceProps.json [INFO][2024-05-08 15:59:25,405][[com.automatics.executor.Starter.main()] - frameworkSupportedModels=Rpi-RDKB,Rpi-RDKV, [INFO][2024-05-08 15:59:25,406][[com.automatics.executor.Starter.main()] - rdkvGWModels= [INFO][2024-05-08 15:59:25,406][[com.automatics.executor.Starter.main()] - rdkvCLModels=Rpi-RDKV, [INFO][2024-05-08 15:59:25,407][[com.automatics.executor.Starter.main()] - rdkbModels=Rpi-RDKB, [INFO][2024-05-08 15:59:25,407][[com.automatics.executor.Starter.main()] - rdkcModels= [INFO][2024-05-08 15:59:26,287][[com.automatics.executor.Starter.main()] - Reading implementation from core for deviceProvider [INFO][2024-05-08 15:59:26,572][[com.automatics.executor.Starter.main()] - Is Account based test: false [INFO][2024-05-08 15:59:26,690][[com.automatics.executor.Starter.main()] - INIT-D8:3A:DD:13:8C:13 Get device details [INFO][2024-05-08 15:59:28,912][[com.automatics.executor.Starter.main()] - Fetching device details for D8:3A:DD:13:8C:13 Url Path: http://192.168.2.130:8080/DeviceManager/deviceManagement/getDeviceDetails [INFO][2024-05-08 15:59:29,364][[com.automatics.executor.Starter.main()] - Response: {"devices":[{"id":"3845","name":"","hardwareRevision":"","hostMacAddress":"D8:3A:DD:13:8C:13","hostIp4Address":"192.168.2.184","hostIp6Address":null,"clientIpAddress":"192.168.2.184","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.184","headend":"HE","gatewayMac":"D8:3A:DD:13:8C:13","extraProperties":{"deviceIp":"192.168.2.184","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-05-08 15:59:29,555][[com.automatics.executor.Starter.main()] - INIT-D8:3A:DD:13:8C:13 Obtained device details [INFO][2024-05-08 15:59:29,556][[com.automatics.executor.Starter.main()] - Found matching device object from config for rack model Rpi-RDKB [INFO][2024-05-08 15:59:29,556][[com.automatics.executor.Starter.main()] - >>>[INIT]: Found device config mapped for rack model Rpi-RDKB [INFO][2024-05-08 15:59:29,556][[com.automatics.executor.Starter.main()] - >>>[INIT]: Mapping rack model Rpi-RDKB to automatics model Rpi-RDKB [INFO][2024-05-08 15:59:29,557][[com.automatics.executor.Starter.main()] - [INIT LOG] : Non RDKV Client device [INFO][2024-05-08 15:59:29,581][[pool-2-thread-1] - INIT-{} Check if device already lockedD8:3A:DD:13:8C:13 [INFO][2024-05-08 15:59:29,602][[pool-2-thread-1] - Fetching lock status for device D8:3A:DD:13:8C:13 Url Path: http://192.168.2.130:8080/DeviceManager/deviceManagement/device/allocationStatus [INFO][2024-05-08 15:59:29,618][[pool-2-thread-1] - Response: {"allocationStatus":"AVAILABLE"} [INFO][2024-05-08 15:59:29,620][[pool-2-thread-1] - DeviceConfig allocation status [INFO][2024-05-08 15:59:29,620][[pool-2-thread-1] - [INIT LOG] : Locking device D8:3A:DD:13:8C:13 [INFO][2024-05-08 15:59:29,620][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Locking device [INFO][2024-05-08 15:59:29,646][[pool-2-thread-1] - Locking device D8:3A:DD:13:8C:13 Url Path: http://192.168.2.130:8080/DeviceManager/deviceManagement/device/lock [INFO][2024-05-08 15:59:29,706][[pool-2-thread-1] - Response: {"status":"SUCCESS","mac":"D8:3A:DD:13:8C:13"} [INFO][2024-05-08 15:59:29,709][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Lock success [INFO][2024-05-08 15:59:29,710][[pool-2-thread-1] - Setting access mechanism for device D8:3A:DD:13:8C:13 SSH [INFO][2024-05-08 15:59:29,710][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Setting access method SSH [INFO][2024-05-08 15:59:29,710][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Checking if accessibility check required [INFO][2024-05-08 15:59:29,711][[pool-2-thread-1] - Setting accessibility check required to false for device D8:3A:DD:13:8C:13 from device config [INFO][2024-05-08 15:59:29,711][[pool-2-thread-1] - Accessibility check required for device D8:3A:DD:13:8C:13 false [INFO][2024-05-08 15:59:29,711][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Checking if accessibility check required is false [INFO][2024-05-08 15:59:29,711][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Assuming device is accessible [INFO][2024-05-08 15:59:29,712][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Is device accessible true [INFO][2024-05-08 15:59:29,712][[pool-2-thread-1] - [INIT LOG] : Wiring device.D8:3A:DD:13:8C:13 [INFO][2024-05-08 15:59:29,712][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Performing provider wiring [INFO][2024-05-08 15:59:29,713][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 PowerProvider wiring [INFO][2024-05-08 15:59:29,713][[pool-2-thread-1] - Reading implementation from core for powerProvider [INFO][2024-05-08 15:59:29,715][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 DeviceConfig Connection Based TraceProvider wiring [INFO][2024-05-08 15:59:29,724][[pool-2-thread-1] - Reading implementation from partner for deviceConnectionProvider [INFO][2024-05-08 15:59:29,727][[pool-2-thread-1] - Additional trace support : null [INFO][2024-05-08 15:59:29,728][[pool-2-thread-1] - settopObj.getModel() = Rpi-RDKB [INFO][2024-05-08 15:59:29,728][[pool-2-thread-1] - Additional logging requirement if any enabled will be skipped due to configuration issue [INFO][2024-05-08 15:59:29,731][[pool-2-thread-1] - Trace Log File location /var/lib/jenkins/workspace/JOB1/target/settoptrace/D83ADD138C13settop_trace.log [INFO][2024-05-08 15:59:29,732][[pool-2-thread-1] - Crash Analysis not enabled during trace monitoring [INFO][2024-05-08 15:59:29,733][[pool-2-thread-1] - Serial based trace to be initialized: false [INFO][2024-05-08 15:59:29,741][[pool-2-thread-1] - [INIT LOG] : Adding dut to locked list [INFO][2024-05-08 15:59:29,741][[pool-2-thread-1] - DeviceConfig Macs D8:3A:DD:13:8C:13 [INFO][2024-05-08 15:59:29,742][[pool-2-thread-1] - Dut Added to locked list D8:3A:DD:13:8C:13 [INFO][2024-05-08 15:59:32,573][[com.automatics.executor.Starter.main()] - Finished Non-IP Initialization Threads [INFO][2024-05-08 15:59:32,573][[com.automatics.executor.Starter.main()] - Collecting dut info [INFO][2024-05-08 15:59:32,574][[com.automatics.executor.Starter.main()] - Requesting data from http://192.168.2.59:8084/api/rack/service/getmasterconfig?configName=TEST_TYPE_MAP [INFO][2024-05-08 15:59:32,609][[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-05-08 15:59:35,567][[com.automatics.executor.Starter.main()] - AutomaticsTapApi instance not available. Creating new instance [INFO][2024-05-08 15:59:35,567][[com.automatics.executor.Starter.main()] - Creating new instance for AutomaticsTapApi [INFO][2024-05-08 15:59:35,567][[com.automatics.executor.Starter.main()] - Reading implementation from partner for deviceConnectionProvider [INFO][2024-05-08 15:59:35,625][[com.automatics.executor.Starter.main()] - >>>[BEFORE_SUITE]: Perform before suite initialization [INFO][2024-05-08 15:59:35,625][[com.automatics.executor.Starter.main()] - Bean testInitializer is not configured. [INFO][2024-05-08 15:59:35,626][[com.automatics.executor.Starter.main()] - Adding locked devices to dut object in AutomaticsTestBase [INFO][2024-05-08 15:59:35,626][[com.automatics.executor.Starter.main()] - Locked Settops: 1 [INFO][2024-05-08 15:59:35,627][[pool-6-thread-1] - >>>[BEFORE_SUITE]: Verifying if build loaded in device as expected [INFO][2024-05-08 15:59:35,627][[pool-6-thread-1] - [BEFORE-SUITE:]Expected build in device is rdkb-generic-broadband-image_rdk-next_20240207050050 [INFO][2024-05-08 15:59:35,628][[pool-6-thread-1] - [BEFORE-SUITE:]Verifying if build changed before test [INFO][2024-05-08 15:59:35,628][[pool-6-thread-1] - Skipping build change verification as partner specific initialization is not configured. [INFO][2024-05-08 15:59:35,628][[pool-6-thread-1] - [BEFORE-SUITE:]Build Change Status: NO_CHANGE [INFO][2024-05-08 15:59:35,628][[pool-6-thread-1] - >>>[BEFORE_SUITE]: Build in device is as expected [INFO][2024-05-08 15:59:35,629][[pool-6-thread-1] - >>>[BEFORE_SUITE]: Setting appropritate build appender based on executionMode [INFO][2024-05-08 15:59:35,703][[pool-6-thread-1] - Skipping setting of execution mode in device as partner specific initialization is not configured. [INFO][2024-05-08 15:59:35,704][[pool-6-thread-1] - INIT-D8:3A:DD:13:8C:13 Perform before suite initialization [INFO][2024-05-08 15:59:35,704][[pool-6-thread-1] - Skipping partner specific before suite initialization as it is not configured. [INFO][2024-05-08 15:59:35,704][[pool-6-thread-1] - >>>[BEFORE_SUITE]: Starting device connection trace [INFO][2024-05-08 15:59:35,705][[pool-6-thread-1] - Starting trace with command : tail -F -n 0 /rdklogs/logs/* [INFO][2024-05-08 15:59:35,715][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Starting reading..D83ADD138C13settop_trace.log, 15:59:35,717 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.FileAppender] 15:59:35,718 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE-D83ADD138C13settop_trace.log] 15:59:35,719 |-INFO in ch.qos.logback.core.FileAppender[FILE-D83ADD138C13settop_trace.log] - File property is set to [target/settoptrace/D83ADD138C13settop_trace.log] [INFO][2024-05-08 15:59:35,720][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Going to connect device for trace monitoring .....! [INFO][2024-05-08 15:59:35,720][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - XX Host IP Address : 192.168.2.184 [INFO][2024-05-08 15:59:35,720][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - XX Host IP6 Address : null [INFO][2024-05-08 15:59:35,721][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - XX Host MAC Address : D8:3A:DD:13:8C:13 [INFO][2024-05-08 15:59:35,721][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Settoptrace debugging:Inside Non RDKV client device [INFO][2024-05-08 15:59:35,721][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - getConnection method invoked [INFO][2024-05-08 15:59:35,754][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - SSH Host IP : 192.168.2.184 [INFO][2024-05-08 15:59:35,755][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - SSh connection attempet : 1 [INFO][2024-05-08 15:59:35,788][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Reading server-config.xml from /var/lib/jenkins/workspace/testrepo/server-config.xml [INFO][2024-05-08 15:59:35,825][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-05-08 15:59:36,314][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - About to create SSH connection to DeviceIP:192.168.2.184 [INFO][2024-05-08 15:59:36,314][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - SSH Host IP : 192.168.2.184 [INFO][2024-05-08 15:59:36,314][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - SSh connection attempet : 1 [INFO][2024-05-08 15:59:36,337][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-05-08 15:59:36,630][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Inside sendTraceCommand [INFO][2024-05-08 15:59:41,746][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Closing SSH connection from DeviceIP:192.168.2.184 [INFO][2024-05-08 15:59:41,768][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Received response: [INFO][2024-05-08 15:59:43,809][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Connectiongateway iscom.automatics.providers.connection.SshConnection@6770305e [INFO][2024-05-08 15:59:43,809][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - inside null != connectionGateway condition [INFO][2024-05-08 15:59:43,809][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - gateWayDeviceInputStream iscom.jcraft.jsch.Channel$MyPipedInputStream@34650081 [INFO][2024-05-08 15:59:43,811][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Settoptrace debugging:Inside else block [INFO][2024-05-08 15:59:43,811][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Creating polling connection [INFO][2024-05-08 15:59:43,811][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Entered into readOutputFromChannel method [INFO][2024-05-08 15:59:43,811][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Is RDKV Client trace false [INFO][2024-05-08 15:59:43,812][[PollingThread_26_(D8:3A:DD:13:8C:13)] - getConnection method invoked [INFO][2024-05-08 15:59:43,812][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSH Host IP : 192.168.2.184 [INFO][2024-05-08 15:59:43,813][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSh connection attempet : 1 [INFO][2024-05-08 15:59:43,886][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-05-08 15:59:44,138][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Checking if trace connection alive [INFO][2024-05-08 15:59:44,138][[PollingThread_26_(D8:3A:DD:13:8C:13)] - sshConnectionPoll established [INFO][2024-05-08 15:59:44,138][[PollingThread_26_(D8:3A:DD:13:8C:13)] - getConnection method invoked [INFO][2024-05-08 15:59:44,138][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSH Host IP : 192.168.2.184 [INFO][2024-05-08 15:59:44,138][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSh connection attempet : 1 [INFO][2024-05-08 15:59:44,151][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-05-08 15:59:44,352][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Value of responseString: null [INFO][2024-05-08 15:59:44,352][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not nul in execute: [INFO][2024-05-08 15:59:44,352][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Executing command: echo CONNECTION_IS_ALIVE [INFO][2024-05-08 15:59:44,355][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not null sendRecive: [INFO][2024-05-08 15:59:44,502][[PollingThread_26_(D8:3A:DD:13:8C:13)] - <=========================== RESPONSE =======================> CONNECTION_IS_ALIVE <=============================================================> [INFO][2024-05-08 15:59:44,502][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Closing SSH connection from DeviceIP:com.automatics.device.Device@5f9dd759 [INFO][2024-05-08 15:59:44,878][[PollingThread_26_(D8:3A:DD:13:8C:13)] - ConnectionPoll disconnected [INFO][2024-05-08 16:00:05,971][[pool-6-thread-1] - Is trace required for connected gateway: false [INFO][2024-05-08 16:00:07,567][[pool-6-thread-1] - Is trace required for connected gateway: false [INFO][2024-05-08 16:00:08,978][[com.automatics.executor.Starter.main()] - Starting testing on class: org.testng.TestRunner [INFO][2024-05-08 16:00:11,122][[com.automatics.executor.Starter.main()] - Doing initialization for D8:3A:DD:13:8C:13 [INFO][2024-05-08 16:00:13,876][[TestNG-PoolService-0] - >>>[BEFORE_METHOD]: Perform before method initialization D8:3A:DD:13:8C:13 [INFO][2024-05-08 16:00:13,894][[TestNG-PoolService-0] - Setting dattime in patter yyyy-MM-dd HH:mm:ss [INFO][2024-05-08 16:00:14,913][[TestNG-PoolService-0] - startTime 2024-05-08 10:30:14 [INFO][2024-05-08 16:00:14,913][[TestNG-PoolService-0] - >>>[BEFORE_METHOD]: Sending test exection start time to Automatics D8:3A:DD:13:8C:13 [INFO][2024-05-08 16:00:15,062][[TestNG-PoolService-0] - http://192.168.2.59:8080/Automatics/captureTestTriggerTime.htm [INFO][2024-05-08 16:00:15,250][[TestNG-PoolService-0] - {"jobId":456,"automationId":"TC-RDKB-DEVICE-RESET-1003","macAddress":"D8:3A:DD:13:8C:13","startDateTimeEST":1715164215027,"endDateTimeEST":0} [INFO][2024-05-08 16:00:18,616][[TestNG-PoolService-0] - Capture execution time - Response : HTTP/1.1 400 Bad Request [INFO][2024-05-08 16:00:18,617][D8:3A:DD:13:8C:13[TestNG-PoolService-0] - Skipping partner specific before method initialization as it is not configured. 16:00:18,617 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.FileAppender] 16:00:18,660 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE-Rpi-RDKB-D83ADD138C13] 16:00:18,661 |-INFO in ch.qos.logback.core.FileAppender[FILE-Rpi-RDKB-D83ADD138C13] - File property is set to [target/logs/Rpi-RDKB-D83ADD138C13.log] [INFO][2024-05-08 16:00:18,662][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-05-08 16:00:18,662][D8:3A:DD:13:8C:13[TestNG-PoolService-0] - Get the locked status: false [INFO][2024-05-08 16:00:18,673][D8:3A:DD:13:8C:13[TestNG-PoolService-0] - Is trace required for connected gateway: false [INFO][2024-05-08 16:00:18,673][D8:3A:DD:13:8C:13[TestNG-PoolService-0] - Is trace required for connected gateway: false [INFO][2024-05-08 16:00:18,826][D8:3A:DD:13:8C:13[TestNG-PoolService-0] - STARTED - testToVerifyWiFiModuleRestartFromWebGui - com.automatics.device.Device@5f9dd759 [INFO][2024-05-08 16:00:18,827][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Getting MDC = D83ADD138C13settop_trace.log [INFO][2024-05-08 16:00:18,827][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Getting MDC = D8:3A:DD:13:8C:13 [INFO][2024-05-08 16:00:18,879][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - STARTING TEST CASE: TC-RDKB-DEVICE-RESET-003 [INFO][2024-05-08 16:00:18,879][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - ************************************************************************************************ [INFO][2024-05-08 16:00:18,879][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - TEST DESCRIPTION: Test to Verify WiFi module restart ( Residential Devices) using WebGUI [INFO][2024-05-08 16:00:18,879][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - ************************************************************************************************ [INFO][2024-05-08 16:00:18,879][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - STEP 1: Verify Broad band login page is launched and logged in successfully. [INFO][2024-05-08 16:00:18,879][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - STEP 2: Verify navigation to Reset/Restore Gateway page is successful. [INFO][2024-05-08 16:00:18,879][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - STEP 3: Verifying Resetting Wi-Fi module from GUI and Restarted status. [INFO][2024-05-08 16:00:18,879][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - STEP 4: Verify WiFi module restarted logs from PAMlog.txt.0 file. [INFO][2024-05-08 16:00:18,879][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - STEP 5: Verify WIFI_RESET_COUNT logs from PAMlog.txt.0 file. [INFO][2024-05-08 16:00:18,879][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - ************************************************************************************************ [INFO][2024-05-08 16:00:18,879][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - STEP 1: DESCRIPTION : Launch Broad band admin login page and verify login status. [INFO][2024-05-08 16:00:18,879][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - STEP 1: ACTION :Navigate to http://:8080 and Login with admin/Password [INFO][2024-05-08 16:00:18,879][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - STEP 1: EXPECTED :admin page should be launched and login should be successful. [INFO][2024-05-08 16:00:18,880][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - ******************************************************************************* [INFO][2024-05-08 16:00:18,880][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-05-08 16:00:18,880][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-05-08 16:00:18,880][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - TR181 Access Method: DMCLI [INFO][2024-05-08 16:00:18,896][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Going to find protocol specific names [INFO][2024-05-08 16:00:18,920][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Going to execute commands [INFO][2024-05-08 16:00:18,921][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.184 [INFO][2024-05-08 16:00:18,921][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - SSH Host IP : 192.168.2.184 [INFO][2024-05-08 16:00:18,921][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-05-08 16:00:19,064][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-05-08 16:00:19,441][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Executing command: dmcli eRT getv Device.DeviceInfo.X_COMCAST-COM_WAN_IP [INFO][2024-05-08 16:00:19,441][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-05-08 16:00:19,608][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : 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_IP Execution succeed. Parameter 1 name: Device.DeviceInfo.X_COMCAST-COM_WAN_IP type: string, value: 192.168.2.184 <=============================================================> [INFO][2024-05-08 16:00:19,609][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.184 [INFO][2024-05-08 16:00:19,609][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : 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_IP Execution succeed. Parameter 1 name: Device.DeviceInfo.X_COMCAST-COM_WAN_IP type: string, value: 192.168.2.184 [INFO][2024-05-08 16:00:19,609][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : 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_IP Execution succeed. Parameter 1 name: Device.DeviceInfo.X_COMCAST-COM_WAN_IP type: string, value: 192.168.2.184 [INFO][2024-05-08 16:00:19,609][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Dmcli param value : 192.168.2.184 [INFO][2024-05-08 16:00:19,610][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - TR181 Response : [tableName=null, index=null, name=Device.DeviceInfo.X_COMCAST-COM_WAN_IP, protocolSpecificParamName=Device.DeviceInfo.X_COMCAST-COM_WAN_IP, value=192.168.2.184, datatype=null, statusCode=0] [INFO][2024-05-08 16:00:20,155][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - INIT-2C:44:FD:18:F9:FE Get device details [INFO][2024-05-08 16:00:20,163][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Fetching device details for 2C:44:FD:18:F9:FE Url Path: http://192.168.2.130:8080/DeviceManager/deviceManagement/getDeviceDetails [INFO][2024-05-08 16:00:20,177][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - 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":"Ethernet","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":"IN_USE","rackGroups":null,"features":null,"components":null,"wanMacAddress":""}],"errorMsg":null,"remarks":null} [INFO][2024-05-08 16:00:20,196][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - INIT-2C:44:FD:18:F9:FE Obtained device details [INFO][2024-05-08 16:00:20,197][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - >>>[INIT]: No device config mapped for rack model WINDOWSVM. Proceeding with rack model [INFO][2024-05-08 16:00:20,197][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - WAN DUT instance : com.automatics.device.Device@f491e84 [INFO][2024-05-08 16:00:20,197][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - 2C:44:FD:18:F9:FE : Mac Address of the WAN PC [INFO][2024-05-08 16:00:20,198][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - 192.168.2.81 : IP Address of the WAN PC [INFO][2024-05-08 16:00:20,203][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Starting Method getParameterValuesUsingWebPaOrDmcli() [INFO][2024-05-08 16:00:20,204][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Is WebpaConnectionBroken : false [INFO][2024-05-08 16:00:20,204][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-05-08 16:00:20,204][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-05-08 16:00:20,205][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - TR181 Access Method: DMCLI [INFO][2024-05-08 16:00:20,205][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Going to find protocol specific names [INFO][2024-05-08 16:00:20,205][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Going to execute commands [INFO][2024-05-08 16:00:20,205][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.184 [INFO][2024-05-08 16:00:20,205][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - SSH Host IP : 192.168.2.184 [INFO][2024-05-08 16:00:20,206][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-05-08 16:00:20,353][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-05-08 16:00:20,594][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Executing command: dmcli eRT getv Device.X_CISCO_COM_DeviceControl.HTTPPort [INFO][2024-05-08 16:00:20,595][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-05-08 16:00:20,717][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : 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.X_CISCO_COM_DeviceControl.HTTPPort Execution succeed. Parameter 1 name: Device.X_CISCO_COM_DeviceControl.HTTPPort type: uint, value: 8080 <=============================================================> [INFO][2024-05-08 16:00:20,717][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.184 [INFO][2024-05-08 16:00:20,718][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : 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.X_CISCO_COM_DeviceControl.HTTPPort Execution succeed. Parameter 1 name: Device.X_CISCO_COM_DeviceControl.HTTPPort type: uint, value: 8080 [INFO][2024-05-08 16:00:20,718][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : 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.X_CISCO_COM_DeviceControl.HTTPPort Execution succeed. Parameter 1 name: Device.X_CISCO_COM_DeviceControl.HTTPPort type: uint, value: 8080 [INFO][2024-05-08 16:00:20,718][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Dmcli param value : 8080 [INFO][2024-05-08 16:00:20,718][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - TR181 Response : [tableName=null, index=null, name=Device.X_CISCO_COM_DeviceControl.HTTPPort, protocolSpecificParamName=Device.X_CISCO_COM_DeviceControl.HTTPPort, value=8080, datatype=null, statusCode=0] [INFO][2024-05-08 16:00:20,718][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Parameter Value is : 8080 [INFO][2024-05-08 16:00:20,719][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Ending Method getParameterValuesUsingWebPaOrDmcli() [INFO][2024-05-08 16:00:20,719][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Starting Method getParameterValuesUsingWebPaOrDmcli() [INFO][2024-05-08 16:00:20,719][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Is WebpaConnectionBroken : false [INFO][2024-05-08 16:00:20,719][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-05-08 16:00:20,719][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-05-08 16:00:20,719][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - TR181 Access Method: DMCLI [INFO][2024-05-08 16:00:20,719][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Going to find protocol specific names [INFO][2024-05-08 16:00:20,719][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Going to execute commands [INFO][2024-05-08 16:00:20,719][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.184 [INFO][2024-05-08 16:00:20,719][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - SSH Host IP : 192.168.2.184 [INFO][2024-05-08 16:00:20,719][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-05-08 16:00:20,729][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-05-08 16:00:20,989][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Executing command: dmcli eRT getv Device.X_CISCO_COM_DeviceControl.HTTPSPort [INFO][2024-05-08 16:00:20,989][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-05-08 16:00:21,112][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : 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.X_CISCO_COM_DeviceControl.HTTPSPort Execution succeed. Parameter 1 name: Device.X_CISCO_COM_DeviceControl.HTTPSPort type: uint, value: 8181 <=============================================================> [INFO][2024-05-08 16:00:21,113][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.184 [INFO][2024-05-08 16:00:21,113][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : 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.X_CISCO_COM_DeviceControl.HTTPSPort Execution succeed. Parameter 1 name: Device.X_CISCO_COM_DeviceControl.HTTPSPort type: uint, value: 8181 [INFO][2024-05-08 16:00:21,113][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : 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.X_CISCO_COM_DeviceControl.HTTPSPort Execution succeed. Parameter 1 name: Device.X_CISCO_COM_DeviceControl.HTTPSPort type: uint, value: 8181 [INFO][2024-05-08 16:00:21,113][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Dmcli param value : 8181 [INFO][2024-05-08 16:00:21,113][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - TR181 Response : [tableName=null, index=null, name=Device.X_CISCO_COM_DeviceControl.HTTPSPort, protocolSpecificParamName=Device.X_CISCO_COM_DeviceControl.HTTPSPort, value=8181, datatype=null, statusCode=0] [INFO][2024-05-08 16:00:21,113][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Parameter Value is : 8181 [INFO][2024-05-08 16:00:21,113][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Ending Method getParameterValuesUsingWebPaOrDmcli() [INFO][2024-05-08 16:00:21,170][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - URL to be launched: http://192.168.2.184:8080/ [INFO][2024-05-08 16:00:21,172][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-05-08 16:00:21,172][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-05-08 16:00:21,172][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - TR181 Access Method: DMCLI [INFO][2024-05-08 16:00:21,172][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Going to find protocol specific names [INFO][2024-05-08 16:00:21,173][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Going to execute commands [INFO][2024-05-08 16:00:21,173][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.184 [INFO][2024-05-08 16:00:21,173][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - SSH Host IP : 192.168.2.184 [INFO][2024-05-08 16:00:21,173][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-05-08 16:00:21,183][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-05-08 16:00:21,381][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Executing command: dmcli eRT getv Device.DeviceInfo.X_RDKCENTRAL-COM_Syndication.PartnerId [INFO][2024-05-08 16:00:21,381][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-05-08 16:00:21,514][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : 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_RDKCENTRAL-COM_Syndication.PartnerId Execution succeed. Parameter 1 name: Device.DeviceInfo.X_RDKCENTRAL-COM_Syndication.PartnerId type: string, value: RDKM <=============================================================> [INFO][2024-05-08 16:00:21,514][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.184 [INFO][2024-05-08 16:00:21,514][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : 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_RDKCENTRAL-COM_Syndication.PartnerId Execution succeed. Parameter 1 name: Device.DeviceInfo.X_RDKCENTRAL-COM_Syndication.PartnerId type: string, value: RDKM [INFO][2024-05-08 16:00:21,514][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : 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_RDKCENTRAL-COM_Syndication.PartnerId Execution succeed. Parameter 1 name: Device.DeviceInfo.X_RDKCENTRAL-COM_Syndication.PartnerId type: string, value: RDKM [INFO][2024-05-08 16:00:21,514][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Dmcli param value : RDKM [INFO][2024-05-08 16:00:21,514][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - TR181 Response : [tableName=null, index=null, name=Device.DeviceInfo.X_RDKCENTRAL-COM_Syndication.PartnerId, protocolSpecificParamName=Device.DeviceInfo.X_RDKCENTRAL-COM_Syndication.PartnerId, value=RDKM, datatype=null, statusCode=0] [INFO][2024-05-08 16:00:21,514][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Current Partner ID of the device Retrieved via WEBPA is :RDKM [INFO][2024-05-08 16:00:21,514][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Entering executeCommandUsingSsh method [INFO][2024-05-08 16:00:21,515][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - About to create SSH connection to DutIP:192.168.2.184 [INFO][2024-05-08 16:00:21,515][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - SSH Host IP : 192.168.2.184 [INFO][2024-05-08 16:00:21,515][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-05-08 16:00:21,550][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-05-08 16:00:21,738][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Executing command: syscfg get user_name_3 [INFO][2024-05-08 16:00:21,738][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-05-08 16:00:21,860][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - <=========================== RESPONSE =======================> admin <=============================================================> [INFO][2024-05-08 16:00:21,860][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Received response: admin [INFO][2024-05-08 16:00:21,860][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Exiting executeCommandUsingSsh method [INFO][2024-05-08 16:00:21,860][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Entering executeCommandUsingSsh method [INFO][2024-05-08 16:00:21,860][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - About to create SSH connection to DutIP:192.168.2.184 [INFO][2024-05-08 16:00:21,861][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - SSH Host IP : 192.168.2.184 [INFO][2024-05-08 16:00:21,861][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-05-08 16:00:21,875][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-05-08 16:00:22,121][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Executing command: syscfg get user_password_3 [INFO][2024-05-08 16:00:22,122][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-05-08 16:00:22,244][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - <=========================== RESPONSE =======================> <=============================================================> [INFO][2024-05-08 16:00:22,244][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Received response: [INFO][2024-05-08 16:00:22,244][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Exiting executeCommandUsingSsh method [INFO][2024-05-08 16:00:22,244][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Setting password using WEBPA: password1 [INFO][2024-05-08 16:00:22,289][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - WebPa data type: STRING [INFO][2024-05-08 16:00:22,292][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - TR181 parametrs status code added 0 [INFO][2024-05-08 16:00:22,292][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-05-08 16:00:22,292][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-05-08 16:00:22,293][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Dmcli Command to be executed: dmcli eRT setv Device.Users.User.3.Password string password1 [INFO][2024-05-08 16:00:22,293][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.184 [INFO][2024-05-08 16:00:22,293][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - SSH Host IP : 192.168.2.184 [INFO][2024-05-08 16:00:22,294][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-05-08 16:00:22,308][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-05-08 16:00:22,508][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Executing command: dmcli eRT setv Device.Users.User.3.Password string password1 [INFO][2024-05-08 16:00:22,508][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-05-08 16:00:22,631][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. setv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.Users.User.3.Password Execution succeed. <=============================================================> [INFO][2024-05-08 16:00:22,631][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.184 [INFO][2024-05-08 16:00:22,631][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Received response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. setv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.Users.User.3.Password Execution succeed. [INFO][2024-05-08 16:00:22,631][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Dmcli Response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. setv from/to component(eRT.com.cisco.spvtg.ccsp.pam): Device.Users.User.3.Password Execution succeed. [INFO][2024-05-08 16:00:22,631][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - TR181 Response : {Device.Users.User.3.Password=Success} [INFO][2024-05-08 16:00:22,632][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - ENDING METHOD: setWebPaParameterValues : success [INFO][2024-05-08 16:00:22,632][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - RESPONSE CODE: 0 [INFO][2024-05-08 16:00:22,632][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - RESPONSE MESSAGE: success [INFO][2024-05-08 16:00:22,654][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - WEBPA PARAM - Device.Users.User.3.Password SET WITH VALUE - password1 IS SUCCESSFUL: true [INFO][2024-05-08 16:00:22,665][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - USER NAME: User [INFO][2024-05-08 16:00:22,665][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - CLIENT TYPE: Ethernet [INFO][2024-05-08 16:00:22,665][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - DeviceConfig [2C:44:FD:18:F9:FE] is identified as NON RDK DeviceConfig. [INFO][2024-05-08 16:00:22,666][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Executing command on non-RDK device: 2C:44:FD:18:F9:FE unzip -v [INFO][2024-05-08 16:00:22,666][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.81 [INFO][2024-05-08 16:00:22,842][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - (SSH EXECUTION) : Executing command unzip -v on client : Mac Address [2C:44:FD:18:F9:FE] , User Name [User], IP Address [192.168.2.81] and Port Number [22] [INFO][2024-05-08 16:00:22,842][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Executing command: unzip -v [INFO][2024-05-08 16:00:22,842][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Using configured response timeout: 50000 [INFO][2024-05-08 16:00:23,093][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - <=========================== RESPONSE =======================> UnZip 6.00 of 20 April 2009, by Info-ZIP. Maintained by C. Spieler. Send bug reports using http://www.info-zip.org/zip-bug.html; see README for details. Latest sources and executables are at ftp://ftp.info-zip.org/pub/infozip/ ; see ftp://ftp.info-zip.org/pub/infozip/UnZip.html for other sites. Compiled with gcc 5.4.0 for Unix (Cygwin) on Feb 22 2017. UnZip special compilation options: COPYRIGHT_CLEAN (PKZIP 0.9x unreducing method not supported) SET_DIR_ATTRIB SYMLINKS (symbolic links supported, if RTL and file system permit) TIMESTAMP UNIXBACKUP USE_EF_UT_TIME USE_UNSHRINK (PKZIP/Zip 1.x unshrinking method supported) USE_DEFLATE64 (PKZIP 4.x Deflate64(tm) supported) UNICODE_SUPPORT [wide-chars, char coding: UTF-8] (handle UTF-8 paths) MBCS-support (multibyte character support, MB_CUR_MAX = 6) LARGE_FILE_SUPPORT (large files over 2 GiB supported) ZIP64_SUPPORT (archives using Zip64 for large files supported) USE_BZIP2 (PKZIP 4.6+, using bzip2 lib version 1.0.8, 13-Jul-2019) VMS_TEXT_CONV [decryption, version 2.11 of 05 Jan 2007] UnZip and ZipInfo environment options: UNZIP: [none] UNZIPOPT: [none] ZIPINFO: [none] ZIPINFOOPT: [none] <=============================================================> [INFO][2024-05-08 16:00:23,093][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.81 [INFO][2024-05-08 16:00:23,094][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Received response: UnZip 6.00 of 20 April 2009, by Info-ZIP. Maintained by C. Spieler. Send bug reports using http://www.info-zip.org/zip-bug.html; see README for details. Latest sources and executables are at ftp://ftp.info-zip.org/pub/infozip/ ; see ftp://ftp.info-zip.org/pub/infozip/UnZip.html for other sites. Compiled with gcc 5.4.0 for Unix (Cygwin) on Feb 22 2017. UnZip special compilation options: COPYRIGHT_CLEAN (PKZIP 0.9x unreducing method not supported) SET_DIR_ATTRIB SYMLINKS (symbolic links supported, if RTL and file system permit) TIMESTAMP UNIXBACKUP USE_EF_UT_TIME USE_UNSHRINK (PKZIP/Zip 1.x unshrinking method supported) USE_DEFLATE64 (PKZIP 4.x Deflate64(tm) supported) UNICODE_SUPPORT [wide-chars, char coding: UTF-8] (handle UTF-8 paths) MBCS-support (multibyte character support, MB_CUR_MAX = 6) LARGE_FILE_SUPPORT (large files over 2 GiB supported) ZIP64_SUPPORT (archives using Zip64 for large files supported) USE_BZIP2 (PKZIP 4.6+, using bzip2 lib version 1.0.8, 13-Jul-2019) VMS_TEXT_CONV [decryption, version 2.11 of 05 Jan 2007] UnZip and ZipInfo environment options: UNZIP: [none] UNZIPOPT: [none] ZIPINFO: [none] ZIPINFOOPT: [none] [INFO][2024-05-08 16:00:23,094][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Received response: UnZip 6.00 of 20 April 2009, by Info-ZIP. Maintained by C. Spieler. Send bug reports using http://www.info-zip.org/zip-bug.html; see README for details. Latest sources and executables are at ftp://ftp.info-zip.org/pub/infozip/ ; see ftp://ftp.info-zip.org/pub/infozip/UnZip.html for other sites. Compiled with gcc 5.4.0 for Unix (Cygwin) on Feb 22 2017. UnZip special compilation options: COPYRIGHT_CLEAN (PKZIP 0.9x unreducing method not supported) SET_DIR_ATTRIB SYMLINKS (symbolic links supported, if RTL and file system permit) TIMESTAMP UNIXBACKUP USE_EF_UT_TIME USE_UNSHRINK (PKZIP/Zip 1.x unshrinking method supported) USE_DEFLATE64 (PKZIP 4.x Deflate64(tm) supported) UNICODE_SUPPORT [wide-chars, char coding: UTF-8] (handle UTF-8 paths) MBCS-support (multibyte character support, MB_CUR_MAX = 6) LARGE_FILE_SUPPORT (large files over 2 GiB supported) ZIP64_SUPPORT (archives using Zip64 for large files supported) USE_BZIP2 (PKZIP 4.6+, using bzip2 lib version 1.0.8, 13-Jul-2019) VMS_TEXT_CONV [decryption, version 2.11 of 05 Jan 2007] UnZip and ZipInfo environment options: UNZIP: [none] UNZIPOPT: [none] ZIPINFO: [none] ZIPINFOOPT: [none] [INFO][2024-05-08 16:00:23,109][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Presence of parameter command not found in the command output : false [INFO][2024-05-08 16:00:23,110][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Unzip support available in Cygwin [INFO][2024-05-08 16:00:23,220][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - java.lang.ExceptionInInitializerError: null at com.automatics.rdkb.utils.wifi.connectedclients.BroadBandConnectedClientUtils.verifyBrowserAndDriverCapabilityOnConnectedClient(BroadBandConnectedClientUtils.java:5599) at com.automatics.rdkb.webui.page.LanSideBasePage.invokeBrowserinConnectedClient(LanSideBasePage.java:709) at com.automatics.rdkb.webui.page.LanWebGuiLoginPage.logintoLanPageinConnectedClient(LanWebGuiLoginPage.java:177) at com.automatics.rdkb.webui.page.LanWebGuiLoginPage.logintoLanPageUsingWanIp(LanWebGuiLoginPage.java:1858) at com.automatics.rdkb.tests.webgui.BroadBandMsoWebGuiTest.testToVerifyWiFiModuleRestartFromWebGui(BroadBandMsoWebGuiTest.java:5913) 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) Caused by: java.lang.NullPointerException: null at com.automatics.rdkb.constants.BroadBandTestConstants$16.(BroadBandTestConstants.java:4746) at com.automatics.rdkb.constants.BroadBandTestConstants.(BroadBandTestConstants.java:4743) ... 20 common frames omitted [INFO][2024-05-08 16:00:23,260][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - STARTING METHOD: invokeBrowserInNode() [INFO][2024-05-08 16:00:23,261][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Validating browser selection for client - true [INFO][2024-05-08 16:00:23,280][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - [Selenium Configuration] : Connecting to Selenium Node:http://192.168.2.81:4444/wd/hub [INFO][2024-05-08 16:00:23,280][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - [Selenium Configuration] : Browser Type:chrome [INFO][2024-05-08 16:00:23,280][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - [Selenium Configuration] : Setting capabilities for chrome driver May 08, 2024 4:00:23 PM org.openqa.selenium.remote.DesiredCapabilities chrome INFO: Using `new ChromeOptions()` is preferred to `DesiredCapabilities.chrome()` May 08, 2024 4:00:27 PM org.openqa.selenium.remote.ProtocolHandshake createSession INFO: Detected dialect: W3C [INFO][2024-05-08 16:00:27,253][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - URL to be launched in ADMIN UI login page ==> http://192.168.2.184:8080/ [INFO][2024-05-08 16:00:44,879][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Creating polling connection [INFO][2024-05-08 16:00:44,879][[PollingThread_26_(D8:3A:DD:13:8C:13)] - getConnection method invoked [INFO][2024-05-08 16:00:44,879][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSH Host IP : 192.168.2.184 [INFO][2024-05-08 16:00:44,879][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSh connection attempet : 1 [INFO][2024-05-08 16:00:44,892][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-05-08 16:00:45,080][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Checking if trace connection alive [INFO][2024-05-08 16:00:45,080][[PollingThread_26_(D8:3A:DD:13:8C:13)] - sshConnectionPoll established [INFO][2024-05-08 16:00:45,080][[PollingThread_26_(D8:3A:DD:13:8C:13)] - getConnection method invoked [INFO][2024-05-08 16:00:45,080][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSH Host IP : 192.168.2.184 [INFO][2024-05-08 16:00:45,080][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSh connection attempet : 1 [INFO][2024-05-08 16:00:45,092][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-05-08 16:00:45,276][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Value of responseString: null [INFO][2024-05-08 16:00:45,276][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not nul in execute: [INFO][2024-05-08 16:00:45,276][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Executing command: echo CONNECTION_IS_ALIVE [INFO][2024-05-08 16:00:45,276][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not null sendRecive: [INFO][2024-05-08 16:00:45,399][[PollingThread_26_(D8:3A:DD:13:8C:13)] - <=========================== RESPONSE =======================> CONNECTION_IS_ALIVE <=============================================================> [INFO][2024-05-08 16:00:45,399][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Closing SSH connection from DeviceIP:com.automatics.device.Device@5f9dd759 [INFO][2024-05-08 16:00:45,402][[PollingThread_26_(D8:3A:DD:13:8C:13)] - ConnectionPoll disconnected [INFO][2024-05-08 16:01:01,039][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Element not foundExpected condition failed: waiting for text ('Gateway > Login') to be present in element found by By.xpath: //*[@id="content"]/h1 (tried for 30 second(s) with 500 milliseconds interval) [INFO][2024-05-08 16:01:01,106][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - cusAdminPageTitle : Login - RDKM [INFO][2024-05-08 16:01:01,107][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Pattern Found = Login - RDKM [INFO][2024-05-08 16:01:01,107][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Login - RDKM [INFO][2024-05-08 16:01:01,107][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - is patter found for Login - RDKM in target string = true [INFO][2024-05-08 16:01:01,107][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Successfully verified Lan Side Admin page launched status : true [INFO][2024-05-08 16:01:01,296][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Username :admin [INFO][2024-05-08 16:01:01,361][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Password :password1 [INFO][2024-05-08 16:01:36,129][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Exception occurred while validating Browser Alert :Expected condition failed: waiting for alert to be present (tried for 30 second(s) with 500 milliseconds interval) Build info: version: '3.12.0', revision: '7c6e0b3', time: '2018-05-08T14:04:26.12Z' System info: host: 'COMCAST2', ip: '192.168.2.74', os.name: 'Linux', os.arch: 'amd64', os.version: '3.10.0-1160.80.1.el7.x86_64', java.version: '11.0.17' Driver info: org.openqa.selenium.remote.RemoteWebDriver Capabilities {acceptInsecureCerts: true, browserName: chrome, browserVersion: 124.0.6367.119, chrome: {chromedriverVersion: 123.0.6312.105 (399174dbe6e..., userDataDir: C:\Windows\SystemTemp\scope...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:60796}, javascriptEnabled: true, networkConnectionEnabled: false, pageLoadStrategy: normal, platform: WINDOWS, platformName: WINDOWS, proxy: Proxy(), setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, webauthn:extension:credBlob: true, webauthn:extension:largeBlob: true, webauthn:extension:minPinLength: true, webauthn:extension:prf: true, webauthn:virtualAuthenticators: true, webdriver.remote.sessionid: aefb8c2aa6abe990a24db3bd11e...} Session ID: aefb8c2aa6abe990a24db3bd11e0334e [INFO][2024-05-08 16:01:36,129][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Validating UI Alert for Residential class device [INFO][2024-05-08 16:01:36,129][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Waiting for 'Alert?' PopUp message. [INFO][2024-05-08 16:01:45,402][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Creating polling connection [INFO][2024-05-08 16:01:45,402][[PollingThread_26_(D8:3A:DD:13:8C:13)] - getConnection method invoked [INFO][2024-05-08 16:01:45,402][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSH Host IP : 192.168.2.184 [INFO][2024-05-08 16:01:45,402][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSh connection attempet : 1 [INFO][2024-05-08 16:01:45,423][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-05-08 16:01:45,651][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Checking if trace connection alive [INFO][2024-05-08 16:01:45,651][[PollingThread_26_(D8:3A:DD:13:8C:13)] - sshConnectionPoll established [INFO][2024-05-08 16:01:45,651][[PollingThread_26_(D8:3A:DD:13:8C:13)] - getConnection method invoked [INFO][2024-05-08 16:01:45,651][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSH Host IP : 192.168.2.184 [INFO][2024-05-08 16:01:45,651][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSh connection attempet : 1 [INFO][2024-05-08 16:01:45,671][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-05-08 16:01:45,911][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Value of responseString: null [INFO][2024-05-08 16:01:45,911][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not nul in execute: [INFO][2024-05-08 16:01:45,911][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Executing command: echo CONNECTION_IS_ALIVE [INFO][2024-05-08 16:01:45,911][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not null sendRecive: [INFO][2024-05-08 16:01:45,948][[PollingThread_26_(D8:3A:DD:13:8C:13)] - <=========================== RESPONSE =======================> CONNECTION_IS_ALIVE <=============================================================> [INFO][2024-05-08 16:01:45,948][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Closing SSH connection from DeviceIP:com.automatics.device.Device@5f9dd759 [INFO][2024-05-08 16:01:45,949][[PollingThread_26_(D8:3A:DD:13:8C:13)] - ConnectionPoll disconnected [INFO][2024-05-08 16:02:06,171][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Exception occurred while validating UI Alert for Residential Device:no such element: Unable to locate element: {"method":"xpath","selector":"//*[@id="popup_title"]"} (Session info: chrome=124.0.6367.119) For documentation on this error, please visit: http://seleniumhq.org/exceptions/no_such_element.html Build info: version: '3.12.0', revision: '7c6e0b3', time: '2018-05-08T14:04:26.12Z' System info: host: 'COMCAST2', ip: '192.168.2.74', os.name: 'Linux', os.arch: 'amd64', os.version: '3.10.0-1160.80.1.el7.x86_64', java.version: '11.0.17' Driver info: org.openqa.selenium.remote.RemoteWebDriver Capabilities {acceptInsecureCerts: true, browserName: chrome, browserVersion: 124.0.6367.119, chrome: {chromedriverVersion: 123.0.6312.105 (399174dbe6e..., userDataDir: C:\Windows\SystemTemp\scope...}, fedcm:accounts: true, goog:chromeOptions: {debuggerAddress: localhost:60796}, javascriptEnabled: true, networkConnectionEnabled: false, pageLoadStrategy: normal, platform: WINDOWS, platformName: WINDOWS, proxy: Proxy(), setWindowRect: true, strictFileInteractability: false, timeouts: {implicit: 0, pageLoad: 300000, script: 30000}, unhandledPromptBehavior: dismiss and notify, webauthn:extension:credBlob: true, webauthn:extension:largeBlob: true, webauthn:extension:minPinLength: true, webauthn:extension:prf: true, webauthn:virtualAuthenticators: true, webdriver.remote.sessionid: aefb8c2aa6abe990a24db3bd11e...} Session ID: aefb8c2aa6abe990a24db3bd11e0334e *** Element info: {Using=xpath, value=//*[@id="popup_title"]} [INFO][2024-05-08 16:02:06,171][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - UI Alert :false [INFO][2024-05-08 16:02:06,200][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Driver:::RemoteWebDriver: chrome on WINDOWS (aefb8c2aa6abe990a24db3bd11e0334e) [INFO][2024-05-08 16:02:06,213][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - pageTitle:::Gateway > At a Glance - RDKM [INFO][2024-05-08 16:02:06,213][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Obtained Page title from driver instance : Gateway > At a Glance - RDKM [INFO][2024-05-08 16:02:06,214][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Verified AdminUI Home page title, Expected title:Gateway > At a Glance - RDKMActual title: Gateway > At a Glance - RDKM status for launching atGlancePage:true [INFO][2024-05-08 16:02:06,242][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - ####################################################################################### [INFO][2024-05-08 16:02:06,242][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Exception occured for DSL gateway page verification [INFO][2024-05-08 16:02:06,243][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - ####################################################################################### [INFO][2024-05-08 16:02:06,243][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Admin page should be launched and login should be successful [INFO][2024-05-08 16:02:06,246][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-DEVICE-RESET-003] [step Number : s1][ Execution status : PASS] [Error Message : ] [INFO][2024-05-08 16:02:06,256][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Fetching device property: FIRMWARE_VERSION [INFO][2024-05-08 16:02:06,273][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Fetching device props for D8:3A:DD:13:8C:13 for props [FIRMWARE_VERSION] Url Path: http://192.168.2.130:8080/DeviceManager/deviceManagement/getDeviceProps [INFO][2024-05-08 16:02:06,299][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : 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-05-08 16:02:06,299][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Getting value for property: FIRMWARE_VERSION [INFO][2024-05-08 16:02:06,299][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Value: RPI-RDKB [INFO][2024-05-08 16:02:06,299][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Device property name: FIRMWARE_VERSION value obtained: RPI-RDKB [INFO][2024-05-08 16:02:06,310][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-DEVICE-RESET-003","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-DEVICE-RESET-1003"} [ERROR][2024-05-08 16:02:06,337][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : 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-05-08 16:02:06,338][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - ******************************************************************************* [INFO][2024-05-08 16:02:06,338][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - STEP 2: DESCRIPTION : Verify navigation to Reset/Restore Gateway page is successful. [INFO][2024-05-08 16:02:06,338][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - STEP 2: ACTION : Click 'Troubleshooting' -> 'Reset / Restore Gateway' link and verify navigation status. [INFO][2024-05-08 16:02:06,338][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - STEP 2: EXPECTED : Navigation should be successful and it should display the Reset/Resore Gateway Page content. [INFO][2024-05-08 16:02:06,338][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - ******************************************************************************* [INFO][2024-05-08 16:02:07,955][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Waiting for text to appear 'Troubleshooting > Logs'. [INFO][2024-05-08 16:02:08,007][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Desired text 'Troubleshooting > Logs' appeared successfully. [INFO][2024-05-08 16:02:08,008][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Getting page title of Troubleshooting home page. [INFO][2024-05-08 16:02:08,014][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Obtained trouble shooting page title is: Troubleshooting > Logs - RDKM [INFO][2024-05-08 16:02:08,014][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Verifying page title for obtained trouble shooting home page. [INFO][2024-05-08 16:02:08,014][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Successfully verified Troubleshooting page navigation status: true [INFO][2024-05-08 16:02:08,014][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - In navigateToGatewayResetPage :resetRestoregatewayLinkText is : Reset/Restore Gateway [INFO][2024-05-08 16:02:09,642][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Obtained gateway reset page title : Troubleshooting > Reset / Restore Gateway - RDKM [INFO][2024-05-08 16:02:09,642][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Successfully verified Trouble shooting page navigation statustrue [INFO][2024-05-08 16:02:09,648][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Obtained Page title from driver instance : Troubleshooting > Reset / Restore Gateway - RDKM [INFO][2024-05-08 16:02:09,648][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - The verification status of 'Troubleshooting > Reset / Restore Gateway' is true [INFO][2024-05-08 16:02:09,649][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Successfully navigated TO 'Troubleshooting' -> 'Reset / Restore Gateway' page. [INFO][2024-05-08 16:02:09,649][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-DEVICE-RESET-003] [step Number : s2][ Execution status : PASS] [Error Message : ] [INFO][2024-05-08 16:02:09,650][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-DEVICE-RESET-003","stepNumber":"s2","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"","executionStatus":"PASS","skipRemaining":true,"partnerName":"","automationId":"TC-RDKB-DEVICE-RESET-1003"} [ERROR][2024-05-08 16:02:09,659][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : 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-05-08 16:02:09,659][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - ******************************************************************************* [INFO][2024-05-08 16:02:09,659][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - STEP 3: DESCRIPTION : Verifying Resetting Wi-Fi module from GUI and Restarted status. [INFO][2024-05-08 16:02:09,659][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - STEP 3: ACTION : Click 'RESET WI-FI MODULE' icon and click Ok pop up [INFO][2024-05-08 16:02:09,660][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - STEP 3: EXPECTED : Wi-Fi module should be restarted [INFO][2024-05-08 16:02:09,660][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - ******************************************************************************* [INFO][2024-05-08 16:02:09,660][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Entering executeCommandUsingSsh method [INFO][2024-05-08 16:02:09,660][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - About to create SSH connection to DutIP:192.168.2.184 [INFO][2024-05-08 16:02:09,660][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - SSH Host IP : 192.168.2.184 [INFO][2024-05-08 16:02:09,660][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-05-08 16:02:09,681][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-05-08 16:02:09,930][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Executing command: tail -F /rdklogs/logs/PAMlog.txt.0 > /nvram/automation_sample.txt [INFO][2024-05-08 16:02:09,931][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-05-08 16:02:19,958][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - <=========================== RESPONSE =======================> <=============================================================> [INFO][2024-05-08 16:02:19,997][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Received response: [INFO][2024-05-08 16:02:19,997][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Exiting executeCommandUsingSsh method [INFO][2024-05-08 16:02:19,999][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Going to click RESTART_ONLY_WIFI_MODULE Button in 'Troubleshooting > Reset / Restore Gateway' page [INFO][2024-05-08 16:02:20,106][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Waiting for 'Are You Sure?' PopUp message. [INFO][2024-05-08 16:02:20,106][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Clicking on 'ok' button to accept PopUp. [INFO][2024-05-08 16:02:20,199][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Pop up Message :Operation in Progress [INFO][2024-05-08 16:02:20,223][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Waiting for 90 seconds as per pop message to restart Wi-Fi Module. [INFO][2024-05-08 16:02:45,949][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Creating polling connection [INFO][2024-05-08 16:02:45,949][[PollingThread_26_(D8:3A:DD:13:8C:13)] - getConnection method invoked [INFO][2024-05-08 16:02:45,949][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSH Host IP : 192.168.2.184 [INFO][2024-05-08 16:02:45,949][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSh connection attempet : 1 [INFO][2024-05-08 16:02:45,959][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-05-08 16:02:46,200][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Checking if trace connection alive [INFO][2024-05-08 16:02:46,200][[PollingThread_26_(D8:3A:DD:13:8C:13)] - sshConnectionPoll established [INFO][2024-05-08 16:02:46,200][[PollingThread_26_(D8:3A:DD:13:8C:13)] - getConnection method invoked [INFO][2024-05-08 16:02:46,200][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSH Host IP : 192.168.2.184 [INFO][2024-05-08 16:02:46,200][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSh connection attempet : 1 [INFO][2024-05-08 16:02:46,210][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-05-08 16:02:46,425][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Value of responseString: null [INFO][2024-05-08 16:02:46,425][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not nul in execute: [INFO][2024-05-08 16:02:46,425][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Executing command: echo CONNECTION_IS_ALIVE [INFO][2024-05-08 16:02:46,425][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not null sendRecive: [INFO][2024-05-08 16:02:46,568][[PollingThread_26_(D8:3A:DD:13:8C:13)] - <=========================== RESPONSE =======================> CONNECTION_IS_ALIVE <=============================================================> [INFO][2024-05-08 16:02:46,568][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Closing SSH connection from DeviceIP:com.automatics.device.Device@5f9dd759 [INFO][2024-05-08 16:02:46,569][[PollingThread_26_(D8:3A:DD:13:8C:13)] - ConnectionPoll disconnected [INFO][2024-05-08 16:03:46,569][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Creating polling connection [INFO][2024-05-08 16:03:46,569][[PollingThread_26_(D8:3A:DD:13:8C:13)] - getConnection method invoked [INFO][2024-05-08 16:03:46,569][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSH Host IP : 192.168.2.184 [INFO][2024-05-08 16:03:46,569][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSh connection attempet : 1 [INFO][2024-05-08 16:03:46,579][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-05-08 16:03:46,844][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Checking if trace connection alive [INFO][2024-05-08 16:03:46,844][[PollingThread_26_(D8:3A:DD:13:8C:13)] - sshConnectionPoll established [INFO][2024-05-08 16:03:46,844][[PollingThread_26_(D8:3A:DD:13:8C:13)] - getConnection method invoked [INFO][2024-05-08 16:03:46,844][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSH Host IP : 192.168.2.184 [INFO][2024-05-08 16:03:46,844][[PollingThread_26_(D8:3A:DD:13:8C:13)] - SSh connection attempet : 1 [INFO][2024-05-08 16:03:46,853][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-05-08 16:03:47,051][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Value of responseString: null [INFO][2024-05-08 16:03:47,051][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not nul in execute: [INFO][2024-05-08 16:03:47,051][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Executing command: echo CONNECTION_IS_ALIVE [INFO][2024-05-08 16:03:47,051][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not null sendRecive: [INFO][2024-05-08 16:03:47,098][[PollingThread_26_(D8:3A:DD:13:8C:13)] - <=========================== RESPONSE =======================> CONNECTION_IS_ALIVE <=============================================================> [INFO][2024-05-08 16:03:47,098][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Closing SSH connection from DeviceIP:com.automatics.device.Device@5f9dd759 [INFO][2024-05-08 16:03:47,098][[PollingThread_26_(D8:3A:DD:13:8C:13)] - ConnectionPoll disconnected [INFO][2024-05-08 16:03:50,239][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Obtained Page title from driver instance: Troubleshooting > Reset / Restore Gateway - RDKM [INFO][2024-05-08 16:03:50,240][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - The verification status of 'Troubleshooting > Reset / Restore Gateway' is true [INFO][2024-05-08 16:03:50,240][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - ******************************************************************************* [INFO][2024-05-08 16:03:50,240][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-DEVICE-RESET-003] [step Number : s3][ Execution status : PASS] [Error Message : ] [INFO][2024-05-08 16:03:50,240][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-DEVICE-RESET-003","stepNumber":"s3","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"","executionStatus":"PASS","skipRemaining":false,"partnerName":"","automationId":"TC-RDKB-DEVICE-RESET-1003"} [ERROR][2024-05-08 16:03:50,248][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : 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-05-08 16:03:50,248][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - ******************************************************************************* [INFO][2024-05-08 16:03:50,248][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - STEP 4: DESCRIPTION : Verify WiFi module restarted logs from PAMlog.txt.0 file [INFO][2024-05-08 16:03:50,248][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - STEP 4: ACTION : Execute command "cat /rdklogs/logs/PAMlog.txt.0" and verify WiFi is going to reboot now logs [INFO][2024-05-08 16:03:50,248][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - STEP 4: EXPECTED : WiFi module restart logs must be present in PAMlog.txt.0 [INFO][2024-05-08 16:03:50,248][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - ******************************************************************************* [INFO][2024-05-08 16:03:50,248][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Entering executeCommandUsingSsh method [INFO][2024-05-08 16:03:50,248][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - About to create SSH connection to DutIP:192.168.2.184 [INFO][2024-05-08 16:03:50,248][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - SSH Host IP : 192.168.2.184 [INFO][2024-05-08 16:03:50,248][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-05-08 16:03:50,260][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-05-08 16:03:50,500][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Executing command: cat /nvram/automation_sample.txt [INFO][2024-05-08 16:03:50,500][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-05-08 16:03:50,640][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - <=========================== RESPONSE =======================> 240508-10:32:31.913580 [mod=PAM, lvl=NOTICE] [tid=1103] CosaDmlIpIfMlanGetSubnetMask... 240508-10:32:31.928994 [mod=PAM, lvl=NOTICE] [tid=1103] CosaDmlIpIfMlanGetIPv4Addr... 240508-10:32:31.930373 [mod=PAM, lvl=NOTICE] [tid=1103] CosaDmlIpIfMlanGetSubnetMask... 240508-10:32:42.358068 [mod=PAM, lvl=WARN] [tid=1103] DslhObjcoValidate: RebootDevice, bsUpdate = 3 240508-10:32:42.358249 [mod=PAM, lvl=WARN] [tid=1103] Before committing:Device.X_CISCO_COM_DeviceControl. 240508-10:32:42.358416 [mod=PAM, lvl=WARN] [tid=1103] RebootDevice:CosaDmlDcRebootWifi thread called to reboot WiFi 240508-10:32:42.358614 [mod=PAM, lvl=WARN] [tid=1103] After committing:Device.X_CISCO_COM_DeviceControl.:0 240508-10:32:42.358722 [mod=PAM, lvl=WARN] [tid=1832] RebootDevice:WiFi is going to reboot now 240508-10:32:42.381725 [mod=PAM, lvl=WARN] [tid=1832] WIFI_RESET_COUNT : 2 Time : Wed May 8 10:32:42 UTC 2024 <=============================================================> [INFO][2024-05-08 16:03:50,641][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Received response: 240508-10:32:31.913580 [mod=PAM, lvl=NOTICE] [tid=1103] CosaDmlIpIfMlanGetSubnetMask... 240508-10:32:31.928994 [mod=PAM, lvl=NOTICE] [tid=1103] CosaDmlIpIfMlanGetIPv4Addr... 240508-10:32:31.930373 [mod=PAM, lvl=NOTICE] [tid=1103] CosaDmlIpIfMlanGetSubnetMask... 240508-10:32:42.358068 [mod=PAM, lvl=WARN] [tid=1103] DslhObjcoValidate: RebootDevice, bsUpdate = 3 240508-10:32:42.358249 [mod=PAM, lvl=WARN] [tid=1103] Before committing:Device.X_CISCO_COM_DeviceControl. 240508-10:32:42.358416 [mod=PAM, lvl=WARN] [tid=1103] RebootDevice:CosaDmlDcRebootWifi thread called to reboot WiFi 240508-10:32:42.358614 [mod=PAM, lvl=WARN] [tid=1103] After committing:Device.X_CISCO_COM_DeviceControl.:0 240508-10:32:42.358722 [mod=PAM, lvl=WARN] [tid=1832] RebootDevice:WiFi is going to reboot now 240508-10:32:42.381725 [mod=PAM, lvl=WARN] [tid=1832] WIFI_RESET_COUNT : 2 Time : Wed May 8 10:32:42 UTC 2024 [INFO][2024-05-08 16:03:50,641][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Exiting executeCommandUsingSsh method [INFO][2024-05-08 16:03:50,641][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Is expected logs for wifi module restart logs present in PAMlog.txt.0 file: true [INFO][2024-05-08 16:03:50,641][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - ******************************************************************************* [INFO][2024-05-08 16:03:50,641][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-DEVICE-RESET-003] [step Number : s4][ Execution status : PASS] [Error Message : ] [INFO][2024-05-08 16:03:50,642][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-DEVICE-RESET-003","stepNumber":"s4","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"","executionStatus":"PASS","skipRemaining":false,"partnerName":"","automationId":"TC-RDKB-DEVICE-RESET-1003"} [ERROR][2024-05-08 16:03:50,651][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : 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-05-08 16:03:50,651][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - ******************************************************************************* [INFO][2024-05-08 16:03:50,651][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - STEP 5: DESCRIPTION : Verify WIFI_RESET_COUNT logs from PAMlog.txt.0 file [INFO][2024-05-08 16:03:50,651][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - STEP 5: DESCRIPTION : Execute command "cat /rdklogs/logs/PAMlog.txt.0" and verify WIFI_RESET_COUNT logs [INFO][2024-05-08 16:03:50,652][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - STEP 5: DESCRIPTION : WIFI_RESET_COUNT logs must be present in PAMlog.txt.0 [INFO][2024-05-08 16:03:50,652][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - ******************************************************************************* [INFO][2024-05-08 16:03:50,652][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - IS WIFI_RESET_COUNT logs present in PAMlog.txt.0 log file : true [INFO][2024-05-08 16:03:50,652][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - ******************************************************************************* [INFO][2024-05-08 16:03:50,652][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-DEVICE-RESET-003] [step Number : s5][ Execution status : PASS] [Error Message : ] [INFO][2024-05-08 16:03:50,652][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-DEVICE-RESET-003","stepNumber":"s5","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"","executionStatus":"PASS","skipRemaining":false,"partnerName":"","automationId":"TC-RDKB-DEVICE-RESET-1003"} [ERROR][2024-05-08 16:03:50,660][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : 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-05-08 16:03:50,660][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Entering executeCommandUsingSsh method [INFO][2024-05-08 16:03:50,660][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - About to create SSH connection to DutIP:192.168.2.184 [INFO][2024-05-08 16:03:50,660][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - SSH Host IP : 192.168.2.184 [INFO][2024-05-08 16:03:50,660][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - SSh connection attempet : 1 [INFO][2024-05-08 16:03:50,668][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-05-08 16:03:50,919][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Executing command: rm -rf /nvram/automation_sample.txt [INFO][2024-05-08 16:03:50,920][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-05-08 16:03:51,051][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - <=========================== RESPONSE =======================> <=============================================================> [INFO][2024-05-08 16:03:51,051][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Received response: [INFO][2024-05-08 16:03:51,051][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Exiting executeCommandUsingSsh method [INFO][2024-05-08 16:03:51,052][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - ENDING TESTCASE : TC-RDKB-DEVICE-RESET-003 [INFO][2024-05-08 16:03:51,075][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - >>>[AFTER_METHOD]: Clear device trace buffer for D8:3A:DD:13:8C:13 [INFO][2024-05-08 16:03:51,098][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - NewLocation for log saving logs /var/lib/jenkins/workspace/JOB1/target/TC-RDKB-DEVICE-RESET-1003/D83ADD138C13/settoptrace/ [INFO][2024-05-08 16:03:51,118][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - created a new directory true [INFO][2024-05-08 16:03:51,118][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - New trace location from the strings /var/lib/jenkins/workspace/JOB1/target/settoptrace/D83ADD138C13settop_trace.log [INFO][2024-05-08 16:03:51,135][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Writing stated from line [INFO][2024-05-08 16:03:51,207][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - NewLocation for log saving logs /var/lib/jenkins/workspace/JOB1/target/TC-RDKB-DEVICE-RESET-1003/D83ADD138C13/logs/ [INFO][2024-05-08 16:03:51,207][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - created a new directory true [INFO][2024-05-08 16:03:51,208][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Destination Summary file doesn't exist. Creating one! [INFO][2024-05-08 16:03:51,208][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Writing stated from line [INFO][2024-05-08 16:03:51,403][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - [ HTML LOG PARSER ] : End of log parser Wed May 08 16:03:51 IST 2024 [INFO][2024-05-08 16:03:51,404][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - >>>[AFTER_METHOD]: Sending test execution completion time for D8:3A:DD:13:8C:13 [INFO][2024-05-08 16:03:51,404][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - http://192.168.2.59:8080/Automatics/captureTestTriggerTime.htm [INFO][2024-05-08 16:03:51,405][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - {"jobId":456,"automationId":"TC-RDKB-DEVICE-RESET-1003","macAddress":"D8:3A:DD:13:8C:13","startDateTimeEST":0,"endDateTimeEST":1715164431404} [INFO][2024-05-08 16:03:51,415][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Capture execution time - Response : HTTP/1.1 400 Bad Request [INFO][2024-05-08 16:03:51,416][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Restarting Trace in after method [INFO][2024-05-08 16:03:51,416][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Is trace required for connected gateway: false [INFO][2024-05-08 16:03:51,417][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Is trace required for connected gateway: false [INFO][2024-05-08 16:03:51,417][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Going for if build changed : Test Type : GROUP_OR_AUTOID [INFO][2024-05-08 16:03:51,417][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - Skipping build change verification as partner specific initialization is not configured. [INFO][2024-05-08 16:03:51,417][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : D83ADD138C13] - >>>[AFTER_METHOD]: Build Change Status: NO_CHANGE [INFO][2024-05-08 16:03:51,418][D8:3A:DD:13:8C:13[TC-RDKB-DEVICE-RESET-1003 : 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.webgui.BroadBandMsoWebGuiTest@fa5e6e4]org.testng.TestRunner@753b290f 262530788 AutomaticsTestBase.performBeforeMethodInit([Ljava.lang.Object;, org.testng.ITestResult)[pri:0, instance:com.automatics.rdkb.tests.webgui.BroadBandMsoWebGuiTest@fa5e6e4][Ljava.lang.Object;@53729921 [TestResult name={null} status=CREATED method=BroadBandMsoWebGuiTest.testToVerifyWiFiModuleRestartFromWebGui(com.automatics.device.Dut)[pri:0, instance:com.automatics.rdkb.tests.webgui.BroadBandMsoWebGuiTest@fa5e6e4] output={null}] 262530788 BroadBandMsoWebGuiTest.testToVerifyWiFiModuleRestartFromWebGui(com.automatics.device.Dut)[pri:0, instance:com.automatics.rdkb.tests.webgui.BroadBandMsoWebGuiTest@fa5e6e4]com.automatics.device.Device@5f9dd759 262530788 AutomaticsTestBase.performAfterMethodCleanup([Ljava.lang.Object;, org.testng.ITestResult)[pri:0, instance:com.automatics.rdkb.tests.webgui.BroadBandMsoWebGuiTest@fa5e6e4][Ljava.lang.Object;@53729921 [TestResult name=testToVerifyWiFiModuleRestartFromWebGui status=SUCCESS method=BroadBandMsoWebGuiTest.testToVerifyWiFiModuleRestartFromWebGui(com.automatics.device.Dut)[pri:0, instance:com.automatics.rdkb.tests.webgui.BroadBandMsoWebGuiTest@fa5e6e4] output={null}] 262530788 ===== PASSED: testToVerifyWiFiModuleRestartFromWebGui(com.automatics.device.Device@5f9dd759) =============================================== MyTest Tests run: 1, Failures: 0, Skips: 0 =============================================== [INFO][2024-05-08 16:03:51,538][[com.automatics.executor.Starter.main()] - Finished testing class: org.testng.TestRunner [INFO][2024-05-08 16:03:51,539][[com.automatics.executor.Starter.main()] - >>>[AFTER-SUITE]: Performing after suite cleanup [INFO][2024-05-08 16:03:51,544][[com.automatics.executor.Starter.main()] - Bean testInitializer is not configured. [INFO][2024-05-08 16:03:51,544][[com.automatics.executor.Starter.main()] - >>>[AFTER-SUITE]: Locked devices after suite execution 1 [INFO][2024-05-08 16:03:51,544][[com.automatics.executor.Starter.main()] - Value of intial testType : QUICK [INFO][2024-05-08 16:03:51,544][[com.automatics.executor.Starter.main()] - Value of TestType provided by job : GROUP_OR_AUTOID [INFO][2024-05-08 16:03:51,545][[com.automatics.executor.Starter.main()] - >>>[AFTER-SUITE]: Verifying if build changed after test [INFO][2024-05-08 16:03:51,545][[com.automatics.executor.Starter.main()] - Skipping build change verification as partner specific initialization is not configured. [INFO][2024-05-08 16:03:51,545][[com.automatics.executor.Starter.main()] - >>>[AFTER-SUITE]: Build Change Status: NO_CHANGE [INFO][2024-05-08 16:03:51,545][[com.automatics.executor.Starter.main()] - Is trace required for connected gateway: false [ERROR][2024-05-08 16:03:51,546][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Sleep interrupted sleep interrupted [ERROR][2024-05-08 16:03:51,547][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - readOutputFromChannel - Exception Details ------ java.io.InterruptedIOException: null at java.base/java.io.PipedInputStream.read(PipedInputStream.java:328) at java.base/java.io.PipedInputStream.read(PipedInputStream.java:377) at java.base/sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284) at java.base/sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326) at java.base/sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178) at java.base/java.io.InputStreamReader.read(InputStreamReader.java:181) at java.base/java.io.BufferedReader.fill(BufferedReader.java:161) at java.base/java.io.BufferedReader.readLine(BufferedReader.java:326) at java.base/java.io.BufferedReader.readLine(BufferedReader.java:392) at com.automatics.providers.trace.AbstractTraceProviderImpl.readOutputFromChannel(AbstractTraceProviderImpl.java:824) at com.automatics.providers.trace.AbstractTraceProviderImpl.connectAndRead(AbstractTraceProviderImpl.java:735) at com.automatics.providers.trace.AbstractTraceProviderImpl$ConnectionThread.run(AbstractTraceProviderImpl.java:1143) [INFO][2024-05-08 16:03:51,554][[com.automatics.executor.Starter.main()] - Connection instance is Null [INFO][2024-05-08 16:03:51,554][[com.automatics.executor.Starter.main()] - Connection instance is Null [INFO][2024-05-08 16:03:51,554][[com.automatics.executor.Starter.main()] - Is trace required for connected gateway: false [INFO][2024-05-08 16:03:51,554][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Connection instance is Null [INFO][2024-05-08 16:03:51,554][[com.automatics.executor.Starter.main()] - Skipping parter specific after suite clean up as it is not configured. [INFO][2024-05-08 16:03:51,554][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Connection instance is Null [INFO][2024-05-08 16:03:51,554][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Exited from readOutputFromChannel method [INFO][2024-05-08 16:03:51,559][[com.automatics.executor.Starter.main()] - Releasing device D8:3A:DD:13:8C:13 Url Path: http://192.168.2.130:8080/DeviceManager/deviceManagement/device/release [INFO][2024-05-08 16:03:51,599][[com.automatics.executor.Starter.main()] - Response: {"status":"SUCCESS","mac":"D8:3A:DD:13:8C:13"} [INFO][2024-05-08 16:03:51,601][[com.automatics.executor.Starter.main()] - Successfully unlocked RDKB (D8:3A:DD:13:8C:13) mapped components - [INFO][2024-05-08 16:03:51,601][[com.automatics.executor.Starter.main()] - SETTOP - D8:3A:DD:13:8C:13 RELEASED. [INFO][2024-05-08 16:03:51,602][[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":1715164175626,"completionTime":1715164431601,"JMD_ID":456,"updateRdkPortal":true,"result":{"build_name":"RPI-RDKB","type":"GROUP_OR_AUTOID ","tests":[]}} =============================================== MySuite Total tests run: 1, Passes: 1, Failures: 0, Skips: 0 =============================================== [INFO][2024-05-08 16:03:51,777][[com.automatics.executor.Starter.main()] - Updating final execution status to Automatics [INFO][2024-05-08 16:03:51,787][[Thread-66] - ============= MESSAGE SEND TO AUTOMATICS ============== [INFO][2024-05-08 16:03:51,787][[Thread-66] - Tested build name : RPI-RDKB [INFO][2024-05-08 16:03:51,788][[Thread-66] - Final execution status : COMPLETED [INFO][2024-05-08 16:03:51,789][[Thread-66] - Final successful device list : ["D8:3A:DD:13:8C:13"] [INFO][2024-05-08 16:03:51,790][[Thread-66] - Job Id : 456 [INFO][2024-05-08 16:03:51,790][[Thread-66] - ============================================================== [INFO][2024-05-08 16:03:51,790][[Thread-66] - >>>[INIT]: Automatics JSON -> {"status":"COMPLETED","service":"","buildImageName":"RPI-RDKB","settopList":["D8:3A:DD:13:8C:13"],"startTime":1715164175626,"completionTime":1715164431601,"JMD_ID":456,"updateRdkPortal":true,"result":{"build_name":"RPI-RDKB","type":"GROUP_OR_AUTOID ","tests":[]}} [INFO][2024-05-08 16:03:51,790][[Thread-66] - http://192.168.2.59:8080/Automatics/executionResponse.htm [INFO][2024-05-08 16:03:51,805][[Thread-66] - HTTP STATUS LINE : HTTP/1.1 200 OK [INFO][2024-05-08 16:03:51,805][[Thread-66] - HTTP STATUS CODE : 200 [INFO][2024-05-08 16:03:51,819][[com.automatics.executor.Starter.main()] - ******** EXECUTION COMPLETED ********* [INFO] ------------------------------------------------------------------------ [INFO] BUILD SUCCESS [INFO] ------------------------------------------------------------------------ [INFO] Total time: 05:33 min [INFO] Finished at: 2024-05-08T16:03:51+05:30 [INFO] ------------------------------------------------------------------------ Inside Add Shutdown Hook [INFO][2024-05-08 16:03:51,861][[Thread-1] - Bean testInitializer is not configured. [INFO][2024-05-08 16:03:51,861][[Thread-1] - Closing partner application context [INFO][2024-05-08 16:03:51,865][[Thread-1] - Closing core application context [JOB1] $ /bin/sh -xe /tmp/jenkins5444283561025634927.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