Started by user RDK-Test Running as SYSTEM Building in workspace /var/lib/jenkins/workspace/JOB1 [JOB1] $ /var/lib/jenkins/tools/hudson.tasks.Maven_MavenInstallation/installmaven/bin/mvn -s /mnt/maven/settings.xml clean install -U exec:java -DskipTests=true -DretryByDefault=false -DbuildType=RDK -Dhttps.protocols=TLSv1.1,TLSv1.2 -Dsun.security.ssl.allowUnsafeRenegotiation=true -Dautomatics.properties.file=http://192.168.2.12:8080/AutomaticsProps/automatics.properties [INFO] Scanning for projects... [WARNING] [WARNING] Some problems were encountered while building the effective model for RDKMAutomationRDKBTests:rdkb-automation:jar:0.0.1-SNAPSHOT [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 171 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 314 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 457 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 600 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 743 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 886 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 1029 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 1172 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 1315 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 1458 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 1601 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 1744 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 1887 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 2030 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 2173 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 2316 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 2459 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 2602 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 2745 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 2888 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 3031 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 3174 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 3317 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 3460 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 3603 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 3746 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 3889 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 4032 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 4175 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 4318 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 4461 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 4604 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 4747 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 4890 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 5033 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 5176 [WARNING] 'dependencies.dependency.(groupId:artifactId:type:classifier)' must be unique: com.automatics.providers:rpi-provider-impl:jar -> duplicate declaration of version 0.0.1-SNAPSHOT @ line 12, column 5319 [WARNING] [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 120 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 --- 16:25:17,071 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback-test.xml] at [jar:file:/root/.m2/repository/com/automatics/apps/automatics-core/2.27.0/automatics-core-2.27.0.jar!/logback-test.xml] 16:25:17,081 |-INFO in ch.qos.logback.core.joran.spi.ConfigurationWatchList@8adc8d - URL [jar:file:/root/.m2/repository/com/automatics/apps/automatics-core/2.27.0/automatics-core-2.27.0.jar!/logback-test.xml] is not of type file 16:25:17,184 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender] 16:25:17,186 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [stdOutAppender] 16:25:17,193 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@7:13 - no applicable action for [onMatch], current ElementPath is [[configuration][appender][filter][onMatch]] 16:25:17,193 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@8:16 - no applicable action for [onMismatch], current ElementPath is [[configuration][appender][filter][onMismatch]] 16:25:17,194 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property 16:25:17,209 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender] 16:25:17,211 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [deviceSiftingAppender] 16:25:17,213 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@18:13 - no applicable action for [onMatch], current ElementPath is [[configuration][appender][filter][onMatch]] 16:25:17,213 |-ERROR in ch.qos.logback.core.joran.spi.Interpreter@19:16 - no applicable action for [onMismatch], current ElementPath is [[configuration][appender][filter][onMismatch]] 16:25:17,215 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.sift.MDCBasedDiscriminator] for [discriminator] property 16:25:17,218 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender] 16:25:17,218 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [TraceLogger] 16:25:17,218 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.sift.MDCBasedDiscriminator] for [discriminator] property 16:25:17,218 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender] 16:25:17,218 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [SerialTrace] 16:25:17,219 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.sift.MDCBasedDiscriminator] for [discriminator] property 16:25:17,219 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.classic.sift.SiftingAppender] 16:25:17,219 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [crash-analysis] 16:25:17,219 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.sift.MDCBasedDiscriminator] for [discriminator] property 16:25:17,220 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [org.apache.http] to false 16:25:17,220 |-INFO in ch.qos.logback.classic.joran.action.LevelAction - org.apache.http level set to INFO 16:25:17,220 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [deviceSiftingAppender] to Logger[org.apache.http] 16:25:17,221 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [ConnectionTrace] to TRACE 16:25:17,221 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [ConnectionTrace] to false 16:25:17,221 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [TraceLogger] to Logger[ConnectionTrace] 16:25:17,221 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [SerialTrace] to TRACE 16:25:17,221 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [SerialTrace] to false 16:25:17,221 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [SerialTrace] to Logger[SerialTrace] 16:25:17,221 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [crash-analysis] to DEBUG 16:25:17,221 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting additivity of logger [crash-analysis] to false 16:25:17,221 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [crash-analysis] to Logger[crash-analysis] 16:25:17,221 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [stdOutAppender] to Logger[ROOT] 16:25:17,221 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [deviceSiftingAppender] to Logger[ROOT] 16:25:17,221 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration. 16:25:17,222 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@384919c1 - Registering current configuration as safe fallback point [INFO][2024-12-20 16:25:17,224][[com.automatics.executor.Starter.main()] - Starting the execution process for the given test cases. 16:25:17,225 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.FileAppender] 16:25:17,227 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE-test-suite] 16:25:17,229 |-INFO in ch.qos.logback.core.FileAppender[FILE-test-suite] - File property is set to [target/logs/test-suite.log] [INFO][2024-12-20 16:25:17,250][[com.automatics.executor.Starter.main()] - Initializing application context partner-applicationContext.xml [INFO][2024-12-20 16:25:17,522][[com.automatics.executor.Starter.main()] - Initializing application context applicationContext.xml [INFO][2024-12-20 16:25:17,563][[com.automatics.executor.Starter.main()] - AutomaticsPropertyUtility: Reading automatics.properties file from http://192.168.2.12:8080/AutomaticsProps/automatics.properties [INFO][2024-12-20 16:25:17,595][[com.automatics.executor.Starter.main()] - Automatics Response - {"message":"Data already fetched from Automatics by http:\/\/192.168.2.231:8080\/job\/python_JOB1\/31 for this job id. Will not be provided again."} [INFO][2024-12-20 16:25:17,597][[com.automatics.executor.Starter.main()] - ***************** Automatics BUILD PARAMETERS ***************** [INFO][2024-12-20 16:25:17,604][[com.automatics.executor.Starter.main()] - message | Data already fetched from Automatics by http://192.168.2.231:8080/job/python_JOB1/31 for this job id. Will not be provided again. [INFO][2024-12-20 16:25:17,605][[com.automatics.executor.Starter.main()] - Shut Down Hook Attached. [INFO][2024-12-20 16:25:17,608][[com.automatics.executor.Starter.main()] - Start Execution Test Suite [INFO][2024-12-20 16:25:17,609][[com.automatics.executor.Starter.main()] - Bean testInitializer is not configured. [INFO][2024-12-20 16:25:17,610][[com.automatics.executor.Starter.main()] - Cleaning the trace log directory [INFO][2024-12-20 16:25:17,634][[com.automatics.executor.Starter.main()] - AutomaticsPropertyUtility: Reading automatics.properties file from http://192.168.2.12:8080/AutomaticsProps/automatics.properties [INFO][2024-12-20 16:25:17,639][[com.automatics.executor.Starter.main()] - >>>[INIT]: Validating config files [INFO][2024-12-20 16:25:17,640][[com.automatics.executor.Starter.main()] - INIT- Requesting device config from http://192.168.2.12:8080/AutomaticsProps/deviceProps.json [INFO][2024-12-20 16:25:17,948][[com.automatics.executor.Starter.main()] - INIT- Requesting device config from http://192.168.2.12:8080/AutomaticsProps/deviceProps.json [INFO][2024-12-20 16:25:17,963][[com.automatics.executor.Starter.main()] - frameworkSupportedModels=Rpi-RDKB,Rpi-RDKV, [INFO][2024-12-20 16:25:17,964][[com.automatics.executor.Starter.main()] - rdkvGWModels= [INFO][2024-12-20 16:25:17,964][[com.automatics.executor.Starter.main()] - rdkvCLModels=Rpi-RDKV, [INFO][2024-12-20 16:25:17,964][[com.automatics.executor.Starter.main()] - rdkbModels=Rpi-RDKB, [INFO][2024-12-20 16:25:17,967][[com.automatics.executor.Starter.main()] - rdkcModels= [INFO][2024-12-20 16:25:17,998][[com.automatics.executor.Starter.main()] - Reading implementation from core for deviceProvider [INFO][2024-12-20 16:25:18,030][[com.automatics.executor.Starter.main()] - Is Account based test: false [INFO][2024-12-20 16:25:18,033][[com.automatics.executor.Starter.main()] - INIT-D8:3A:DD:13:8C:13 Get device details [INFO][2024-12-20 16:25:18,358][[com.automatics.executor.Starter.main()] - Fetching device details for D8:3A:DD:13:8C:13 Url Path: http://192.168.2.12:8080/DeviceManager/deviceManagement/getDeviceDetails [INFO][2024-12-20 16:25:18,484][[com.automatics.executor.Starter.main()] - Response: {"devices":[{"id":"3845","name":"","hardwareRevision":"","hostMacAddress":"D8:3A:DD:13:8C:13","hostIp4Address":"192.168.2.47","hostIp6Address":null,"clientIpAddress":"192.168.2.47","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.47","headend":"HE","gatewayMac":"D8:3A:DD:13:8C:13","extraProperties":{"deviceIp":"192.168.2.47","connectedClients":"192.168.2.57","password":"root123","ethernetMacAddress":"D8:3A:DD:13:8C:13","wi-ficapability":"Dual band","nodePort":"22","connectionType":"SSH","username":"root"},"rackId":"","deviceType":"","rackName":"","slotName":"","slotNumber":"","settopGroupName":"","homeAccountName":"","homeAccountNumber":"123456789","homeAccountGroupName":"","rackServerHost":"","rackServerPort":0,"status":"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-12-20 16:25:18,520][[com.automatics.executor.Starter.main()] - INIT-D8:3A:DD:13:8C:13 Obtained device details [INFO][2024-12-20 16:25:18,521][[com.automatics.executor.Starter.main()] - Found matching device object from config for rack model Rpi-RDKB [INFO][2024-12-20 16:25:18,522][[com.automatics.executor.Starter.main()] - >>>[INIT]: Found device config mapped for rack model Rpi-RDKB [INFO][2024-12-20 16:25:18,522][[com.automatics.executor.Starter.main()] - >>>[INIT]: Mapping rack model Rpi-RDKB to automatics model Rpi-RDKB [INFO][2024-12-20 16:25:18,522][[com.automatics.executor.Starter.main()] - [INIT LOG] : Non RDKV Client device [INFO][2024-12-20 16:25:18,526][[pool-2-thread-1] - INIT-{} Check if device already lockedD8:3A:DD:13:8C:13 [INFO][2024-12-20 16:25:18,538][[pool-2-thread-1] - Fetching lock status for device D8:3A:DD:13:8C:13 Url Path: http://192.168.2.12:8080/DeviceManager/deviceManagement/device/allocationStatus [INFO][2024-12-20 16:25:18,545][[pool-2-thread-1] - Response: {"allocationStatus":"AVAILABLE"} [INFO][2024-12-20 16:25:18,547][[pool-2-thread-1] - DeviceConfig allocation status [INFO][2024-12-20 16:25:18,547][[pool-2-thread-1] - [INIT LOG] : Locking device D8:3A:DD:13:8C:13 [INFO][2024-12-20 16:25:18,547][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Locking device [INFO][2024-12-20 16:25:18,556][[pool-2-thread-1] - Locking device D8:3A:DD:13:8C:13 Url Path: http://192.168.2.12:8080/DeviceManager/deviceManagement/device/lock [INFO][2024-12-20 16:25:18,602][[pool-2-thread-1] - Response: {"status":"SUCCESS","mac":"D8:3A:DD:13:8C:13"} [INFO][2024-12-20 16:25:18,604][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Lock success [INFO][2024-12-20 16:25:18,605][[pool-2-thread-1] - Setting access mechanism for device D8:3A:DD:13:8C:13 SSH [INFO][2024-12-20 16:25:18,605][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Setting access method SSH [INFO][2024-12-20 16:25:18,605][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Checking if accessibility check required [INFO][2024-12-20 16:25:18,605][[pool-2-thread-1] - Setting accessibility check required to false for device D8:3A:DD:13:8C:13 from device config [INFO][2024-12-20 16:25:18,605][[pool-2-thread-1] - Accessibility check required for device D8:3A:DD:13:8C:13 false [INFO][2024-12-20 16:25:18,606][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Checking if accessibility check required is false [INFO][2024-12-20 16:25:18,606][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Assuming device is accessible [INFO][2024-12-20 16:25:18,606][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Is device accessible true [INFO][2024-12-20 16:25:18,606][[pool-2-thread-1] - [INIT LOG] : Wiring device.D8:3A:DD:13:8C:13 [INFO][2024-12-20 16:25:18,606][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 Performing provider wiring [INFO][2024-12-20 16:25:18,607][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 PowerProvider wiring [INFO][2024-12-20 16:25:18,607][[pool-2-thread-1] - Reading implementation from core for powerProvider [INFO][2024-12-20 16:25:18,608][[pool-2-thread-1] - INIT-D8:3A:DD:13:8C:13 DeviceConfig Connection Based TraceProvider wiring [INFO][2024-12-20 16:25:18,610][[pool-2-thread-1] - Reading implementation from partner for deviceConnectionProvider [INFO][2024-12-20 16:25:18,613][[pool-2-thread-1] - Additional trace support : null [INFO][2024-12-20 16:25:18,613][[pool-2-thread-1] - settopObj.getModel() = Rpi-RDKB [INFO][2024-12-20 16:25:18,613][[pool-2-thread-1] - Additional logging requirement if any enabled will be skipped due to configuration issue [INFO][2024-12-20 16:25:18,616][[pool-2-thread-1] - Trace Log File location /var/lib/jenkins/workspace/JOB1/target/settoptrace/D83ADD138C13settop_trace.log [INFO][2024-12-20 16:25:18,616][[pool-2-thread-1] - Crash Analysis not enabled during trace monitoring [INFO][2024-12-20 16:25:18,617][[pool-2-thread-1] - Serial based trace to be initialized: false [INFO][2024-12-20 16:25:18,617][[pool-2-thread-1] - [INIT LOG] : Adding dut to locked list [INFO][2024-12-20 16:25:18,617][[pool-2-thread-1] - DeviceConfig Macs D8:3A:DD:13:8C:13 [INFO][2024-12-20 16:25:18,618][[pool-2-thread-1] - Dut Added to locked list D8:3A:DD:13:8C:13 [INFO][2024-12-20 16:25:21,523][[com.automatics.executor.Starter.main()] - Finished Non-IP Initialization Threads [INFO][2024-12-20 16:25:21,524][[com.automatics.executor.Starter.main()] - Collecting dut info [INFO][2024-12-20 16:25:21,525][[com.automatics.executor.Starter.main()] - Requesting data from http://192.168.2.59:8084/api/rack/service/getmasterconfig?configName=TEST_TYPE_MAP [INFO][2024-12-20 16:25:21,540][[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-12-20 16:25:22,584][[com.automatics.executor.Starter.main()] - AutomaticsTapApi instance not available. Creating new instance [INFO][2024-12-20 16:25:22,584][[com.automatics.executor.Starter.main()] - Creating new instance for AutomaticsTapApi [INFO][2024-12-20 16:25:22,585][[com.automatics.executor.Starter.main()] - Reading implementation from partner for deviceConnectionProvider [INFO][2024-12-20 16:25:22,622][[com.automatics.executor.Starter.main()] - >>>[BEFORE_SUITE]: Perform before suite initialization [INFO][2024-12-20 16:25:22,622][[com.automatics.executor.Starter.main()] - Bean testInitializer is not configured. [INFO][2024-12-20 16:25:22,622][[com.automatics.executor.Starter.main()] - Adding locked devices to dut object in AutomaticsTestBase [INFO][2024-12-20 16:25:22,623][[com.automatics.executor.Starter.main()] - Locked Settops: 1 [INFO][2024-12-20 16:25:22,623][[pool-6-thread-1] - >>>[BEFORE_SUITE]: Verifying if build loaded in device as expected [INFO][2024-12-20 16:25:22,624][[pool-6-thread-1] - [BEFORE-SUITE:]Expected build in device is rdkb-generic-broadband-image_rdkb-2023q1-dunfell_20230925052003 [INFO][2024-12-20 16:25:22,624][[pool-6-thread-1] - [BEFORE-SUITE:]Verifying if build changed before test [INFO][2024-12-20 16:25:22,625][[pool-6-thread-1] - Skipping build change verification as partner specific initialization is not configured. [INFO][2024-12-20 16:25:22,625][[pool-6-thread-1] - [BEFORE-SUITE:]Build Change Status: NO_CHANGE [INFO][2024-12-20 16:25:22,625][[pool-6-thread-1] - >>>[BEFORE_SUITE]: Build in device is as expected [INFO][2024-12-20 16:25:22,625][[pool-6-thread-1] - >>>[BEFORE_SUITE]: Setting appropritate build appender based on executionMode [INFO][2024-12-20 16:25:22,630][[pool-6-thread-1] - Skipping setting of execution mode in device as partner specific initialization is not configured. [INFO][2024-12-20 16:25:22,630][[pool-6-thread-1] - INIT-D8:3A:DD:13:8C:13 Perform before suite initialization [INFO][2024-12-20 16:25:22,630][[pool-6-thread-1] - Skipping partner specific before suite initialization as it is not configured. [INFO][2024-12-20 16:25:22,630][[pool-6-thread-1] - >>>[BEFORE_SUITE]: Starting device connection trace [INFO][2024-12-20 16:25:22,631][[pool-6-thread-1] - Starting trace with command : tail -F -n 0 /rdklogs/logs/* [INFO][2024-12-20 16:25:22,638][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Starting reading..D83ADD138C13settop_trace.log, 16:25:22,638 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.FileAppender] 16:25:22,639 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE-D83ADD138C13settop_trace.log] 16:25:22,640 |-INFO in ch.qos.logback.core.FileAppender[FILE-D83ADD138C13settop_trace.log] - File property is set to [target/settoptrace/D83ADD138C13settop_trace.log] [INFO][2024-12-20 16:25:22,640][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Going to connect device for trace monitoring .....! [INFO][2024-12-20 16:25:22,640][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - XX Host IP Address : 192.168.2.47 [INFO][2024-12-20 16:25:22,640][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - XX Host IP6 Address : null [INFO][2024-12-20 16:25:22,641][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - XX Host MAC Address : D8:3A:DD:13:8C:13 [INFO][2024-12-20 16:25:22,641][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Settoptrace debugging:Inside Non RDKV client device [INFO][2024-12-20 16:25:22,650][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Reading server-config.xml from /var/lib/jenkins/workspace/testrepo/server-config.xml [INFO][2024-12-20 16:25:22,668][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:25:22,975][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - About to create SSH connection to DeviceIP:192.168.2.47 [INFO][2024-12-20 16:25:22,987][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:25:28,136][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Closing SSH connection from DeviceIP:192.168.2.47 [INFO][2024-12-20 16:25:28,143][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Connectiongateway iscom.automatics.providers.connection.SshConnection@322ef0db [INFO][2024-12-20 16:25:28,143][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - inside null != connectionGateway condition [INFO][2024-12-20 16:25:28,144][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - gateWayDeviceInputStream iscom.jcraft.jsch.Channel$MyPipedInputStream@727a2aa7 [INFO][2024-12-20 16:25:28,146][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Settoptrace debugging:Inside else block [INFO][2024-12-20 16:25:28,146][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Entered into readOutputFromChannel method [INFO][2024-12-20 16:25:28,147][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Is RDKV Client trace false [INFO][2024-12-20 16:25:28,165][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:25:28,328][[PollingThread_26_(D8:3A:DD:13:8C:13)] - sshConnectionPoll established [INFO][2024-12-20 16:25:28,342][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:25:28,480][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Value of responseString: null [INFO][2024-12-20 16:25:28,481][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Executing command: echo CONNECTION_IS_ALIVE [INFO][2024-12-20 16:25:28,485][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not null sendRecive: [INFO][2024-12-20 16:25:28,611][[PollingThread_26_(D8:3A:DD:13:8C:13)] - <=========================== RESPONSE =======================> CONNECTION_IS_ALIVE <=============================================================> [INFO][2024-12-20 16:25:28,611][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Closing SSH connection from DeviceIP:com.automatics.device.Device@1ad20a8a [INFO][2024-12-20 16:25:28,622][[PollingThread_26_(D8:3A:DD:13:8C:13)] - ConnectionPoll disconnected [INFO][2024-12-20 16:25:52,638][[pool-6-thread-1] - Is trace required for connected gateway: false [INFO][2024-12-20 16:25:52,639][[pool-6-thread-1] - Is trace required for connected gateway: false [INFO][2024-12-20 16:25:55,626][[com.automatics.executor.Starter.main()] - Starting testing on class: org.testng.TestRunner [INFO][2024-12-20 16:25:55,658][[com.automatics.executor.Starter.main()] - Doing initialization for D8:3A:DD:13:8C:13 [INFO][2024-12-20 16:25:55,676][[com.automatics.executor.Starter.main()] - Getting device account no. for D8:3A:DD:13:8C:13 [INFO][2024-12-20 16:25:55,677][[com.automatics.executor.Starter.main()] - INIT-D8:3A:DD:13:8C:13 Get device details [INFO][2024-12-20 16:25:55,689][[com.automatics.executor.Starter.main()] - Fetching device details for D8:3A:DD:13:8C:13 Url Path: http://192.168.2.12:8080/DeviceManager/deviceManagement/getDeviceDetails [INFO][2024-12-20 16:25:55,702][[com.automatics.executor.Starter.main()] - Response: {"devices":[{"id":"3845","name":"","hardwareRevision":"","hostMacAddress":"D8:3A:DD:13:8C:13","hostIp4Address":"192.168.2.47","hostIp6Address":null,"clientIpAddress":"192.168.2.47","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.47","headend":"HE","gatewayMac":"D8:3A:DD:13:8C:13","extraProperties":{"deviceIp":"192.168.2.47","connectedClients":"192.168.2.57","password":"root123","ethernetMacAddress":"D8:3A:DD:13:8C:13","wi-ficapability":"Dual band","nodePort":"22","connectionType":"SSH","username":"root"},"rackId":"","deviceType":"","rackName":"","slotName":"","slotNumber":"","settopGroupName":"","homeAccountName":"","homeAccountNumber":"123456789","homeAccountGroupName":"","rackServerHost":"","rackServerPort":0,"status":"IN_USE","rackGroups":null,"features":null,"components":null,"wanMacAddress":""}],"errorMsg":null,"remarks":null} [INFO][2024-12-20 16:25:55,717][[com.automatics.executor.Starter.main()] - INIT-D8:3A:DD:13:8C:13 Obtained device details [INFO][2024-12-20 16:25:55,718][[com.automatics.executor.Starter.main()] - Device account 123456789 for device D8:3A:DD:13:8C:13 [INFO][2024-12-20 16:25:55,718][[com.automatics.executor.Starter.main()] - Getting device account no. for D8:3A:DD:13:8C:13 [INFO][2024-12-20 16:25:55,718][[com.automatics.executor.Starter.main()] - INIT-D8:3A:DD:13:8C:13 Get device details [INFO][2024-12-20 16:25:55,724][[com.automatics.executor.Starter.main()] - Fetching device details for D8:3A:DD:13:8C:13 Url Path: http://192.168.2.12:8080/DeviceManager/deviceManagement/getDeviceDetails [INFO][2024-12-20 16:25:55,735][[com.automatics.executor.Starter.main()] - Response: {"devices":[{"id":"3845","name":"","hardwareRevision":"","hostMacAddress":"D8:3A:DD:13:8C:13","hostIp4Address":"192.168.2.47","hostIp6Address":null,"clientIpAddress":"192.168.2.47","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.47","headend":"HE","gatewayMac":"D8:3A:DD:13:8C:13","extraProperties":{"deviceIp":"192.168.2.47","password":"root123","connectedClients":"192.168.2.57","ethernetMacAddress":"D8:3A:DD:13:8C:13","wi-ficapability":"Dual band","nodePort":"22","connectionType":"SSH","username":"root"},"rackId":"","deviceType":"","rackName":"","slotName":"","slotNumber":"","settopGroupName":"","homeAccountName":"","homeAccountNumber":"123456789","homeAccountGroupName":"","rackServerHost":"","rackServerPort":0,"status":"IN_USE","rackGroups":null,"features":null,"components":null,"wanMacAddress":""}],"errorMsg":null,"remarks":null} [INFO][2024-12-20 16:25:55,748][[com.automatics.executor.Starter.main()] - INIT-D8:3A:DD:13:8C:13 Obtained device details [INFO][2024-12-20 16:25:55,748][[com.automatics.executor.Starter.main()] - Device account 123456789 for device D8:3A:DD:13:8C:13 [INFO][2024-12-20 16:25:55,748][[com.automatics.executor.Starter.main()] - Locking connected devices [INFO][2024-12-20 16:25:55,749][[com.automatics.executor.Starter.main()] - Getting devices for home account 123456789 [INFO][2024-12-20 16:25:55,755][[com.automatics.executor.Starter.main()] - Fetching account details for 123456789 Url Path: http://192.168.2.12:8080/DeviceManager/deviceManagement/getAccountDetails [INFO][2024-12-20 16:25:55,768][[com.automatics.executor.Starter.main()] - Response: {"id":"","name":"","accountNumber":"123456789","phoneNumber":"","address":"","homeAccountGroup":"","devices":[{"id":"3845","name":"","hardwareRevision":"","hostMacAddress":"D8:3A:DD:13:8C:13","hostIp4Address":"192.168.2.47","hostIp6Address":null,"clientIpAddress":"192.168.2.47","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.47","headend":"HE","gatewayMac":"D8:3A:DD:13:8C:13","extraProperties":{"deviceIp":"192.168.2.47","password":"root123","connectedClients":"192.168.2.57","ethernetMacAddress":"D8:3A:DD:13:8C:13","wi-ficapability":"Dual band","nodePort":"22","connectionType":"SSH","username":"root"},"rackId":"","deviceType":"","rackName":"","slotName":"","slotNumber":"","settopGroupName":"","homeAccountName":"","homeAccountNumber":"123456789","homeAccountGroupName":"","rackServerHost":"","rackServerPort":0,"status":"IN_USE","rackGroups":null,"features":null,"components":null,"wanMacAddress":""},{"id":"3853","name":"","hardwareRevision":"","hostMacAddress":"2C:44:FD:18:F9:FE","hostIp4Address":"192.168.2.57","hostIp6Address":null,"clientIpAddress":"192.168.2.57","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.57","headend":"HE","gatewayMac":"","extraProperties":{"deviceIp":"192.168.2.57","password":"asdf@1234","ethernetMacAddress":"2C:44:FD:18:F9:FE","osType":"WINDOWS","devicePort":"22","wifiCapability":"Dual Band","connectionType":"Wi-Fi","nodePort":"4444","wifiMacAddress":"18:D6:C7:08:C6:C1","username":"User"},"rackId":"","deviceType":"","rackName":"","slotName":"","slotNumber":"","settopGroupName":"","homeAccountName":"","homeAccountNumber":"123456789","homeAccountGroupName":"","rackServerHost":"","rackServerPort":0,"status":"GOOD","rackGroups":null,"features":null,"components":null,"wanMacAddress":""}]} [INFO][2024-12-20 16:25:55,782][[com.automatics.executor.Starter.main()] - Devices for home account 123456789 are [D8:3A:DD:13:8C:13, 2C:44:FD:18:F9:FE] [INFO][2024-12-20 16:25:55,782][[com.automatics.executor.Starter.main()] - Obtained all connected device macs for the account [INFO][2024-12-20 16:25:55,782][[com.automatics.executor.Starter.main()] - INIT-2C:44:FD:18:F9:FE Get device details [INFO][2024-12-20 16:25:55,787][[com.automatics.executor.Starter.main()] - Fetching device details for 2C:44:FD:18:F9:FE Url Path: http://192.168.2.12:8080/DeviceManager/deviceManagement/getDeviceDetails [INFO][2024-12-20 16:25:55,797][[com.automatics.executor.Starter.main()] - Response: {"devices":[{"id":"3853","name":"","hardwareRevision":"","hostMacAddress":"2C:44:FD:18:F9:FE","hostIp4Address":"192.168.2.57","hostIp6Address":null,"clientIpAddress":"192.168.2.57","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.57","headend":"HE","gatewayMac":"","extraProperties":{"deviceIp":"192.168.2.57","password":"asdf@1234","ethernetMacAddress":"2C:44:FD:18:F9:FE","osType":"WINDOWS","devicePort":"22","wifiCapability":"Dual Band","connectionType":"Wi-Fi","nodePort":"4444","username":"User","wifiMacAddress":"18:D6:C7:08:C6:C1"},"rackId":"","deviceType":"","rackName":"","slotName":"","slotNumber":"","settopGroupName":"","homeAccountName":"","homeAccountNumber":"123456789","homeAccountGroupName":"","rackServerHost":"","rackServerPort":0,"status":"GOOD","rackGroups":null,"features":null,"components":null,"wanMacAddress":""}],"errorMsg":null,"remarks":null} [INFO][2024-12-20 16:25:55,807][[com.automatics.executor.Starter.main()] - INIT-2C:44:FD:18:F9:FE Obtained device details [INFO][2024-12-20 16:25:55,807][[com.automatics.executor.Starter.main()] - >>>[INIT]: No device config mapped for rack model WINDOWSVM. Proceeding with rack model [INFO][2024-12-20 16:25:55,808][[com.automatics.executor.Starter.main()] - [INIT LOG] : Non RDKV Client device [INFO][2024-12-20 16:25:55,808][[pool-15-thread-1] - INIT-{} Check if device already locked2C:44:FD:18:F9:FE [INFO][2024-12-20 16:25:55,813][[pool-15-thread-1] - Fetching lock status for device 2C:44:FD:18:F9:FE Url Path: http://192.168.2.12:8080/DeviceManager/deviceManagement/device/allocationStatus [INFO][2024-12-20 16:25:55,819][[pool-15-thread-1] - Response: {"allocationStatus":"AVAILABLE"} [INFO][2024-12-20 16:25:55,820][[pool-15-thread-1] - DeviceConfig allocation status [INFO][2024-12-20 16:25:55,821][[pool-15-thread-1] - [INIT LOG] : Locking device 2C:44:FD:18:F9:FE [INFO][2024-12-20 16:25:55,821][[pool-15-thread-1] - INIT-2C:44:FD:18:F9:FE Locking device [INFO][2024-12-20 16:25:55,825][[pool-15-thread-1] - Locking device 2C:44:FD:18:F9:FE Url Path: http://192.168.2.12:8080/DeviceManager/deviceManagement/device/lock [INFO][2024-12-20 16:25:55,868][[pool-15-thread-1] - Response: {"status":"SUCCESS","mac":"2C:44:FD:18:F9:FE"} [INFO][2024-12-20 16:25:55,869][[pool-15-thread-1] - INIT-2C:44:FD:18:F9:FE Lock success [INFO][2024-12-20 16:25:55,869][[pool-15-thread-1] - DeviceConfig [2C:44:FD:18:F9:FE] is identified as NON RDK DeviceConfig. [INFO][2024-12-20 16:25:55,869][[pool-15-thread-1] - Setting default SSH access mechanism for device null [INFO][2024-12-20 16:25:55,869][[pool-15-thread-1] - INIT-2C:44:FD:18:F9:FE Setting access method SSH [INFO][2024-12-20 16:25:55,869][[pool-15-thread-1] - INIT-2C:44:FD:18:F9:FE Checking if accessibility check required [INFO][2024-12-20 16:25:55,870][[pool-15-thread-1] - Accessibility check required for device 2C:44:FD:18:F9:FE false [INFO][2024-12-20 16:25:55,870][[pool-15-thread-1] - INIT-2C:44:FD:18:F9:FE Checking if accessibility check required is false [INFO][2024-12-20 16:25:55,870][[pool-15-thread-1] - INIT-2C:44:FD:18:F9:FE Assuming device is accessible [INFO][2024-12-20 16:25:55,870][[pool-15-thread-1] - INIT-2C:44:FD:18:F9:FE Is device accessible true [INFO][2024-12-20 16:25:55,870][[pool-15-thread-1] - [INIT LOG] : Wiring device.2C:44:FD:18:F9:FE [INFO][2024-12-20 16:25:55,870][[pool-15-thread-1] - INIT-2C:44:FD:18:F9:FE Performing provider wiring [INFO][2024-12-20 16:25:55,870][[pool-15-thread-1] - INIT-2C:44:FD:18:F9:FE PowerProvider wiring [INFO][2024-12-20 16:25:55,870][[pool-15-thread-1] - Reading implementation from core for powerProvider [INFO][2024-12-20 16:25:55,870][[pool-15-thread-1] - [INIT LOG] : Adding dut to locked list [INFO][2024-12-20 16:25:55,870][[pool-15-thread-1] - DeviceConfig Macs D8:3A:DD:13:8C:13 [INFO][2024-12-20 16:25:55,870][[pool-15-thread-1] - Dut Added to locked list 2C:44:FD:18:F9:FE [INFO][2024-12-20 16:25:58,808][[com.automatics.executor.Starter.main()] - Finished Non-IP Initialization Threads [INFO][2024-12-20 16:25:58,809][[com.automatics.executor.Starter.main()] - Starting trace from provider for connected clients if not already started [INFO][2024-12-20 16:25:58,809][[com.automatics.executor.Starter.main()] - ========================================================================= [INFO][2024-12-20 16:25:58,809][[com.automatics.executor.Starter.main()] - DeviceConfig [2C:44:FD:18:F9:FE] is identified as NON RDK DeviceConfig. [INFO][2024-12-20 16:25:58,810][[com.automatics.executor.Starter.main()] - Trace not applicable for Non RDK Devices - 2C:44:FD:18:F9:FE [INFO][2024-12-20 16:25:58,817][[com.automatics.executor.Starter.main()] - NUMBER OF CONNECTED CLIENTS ASSOCIATED WITH DEVICE D8:3A:DD:13:8C:13 IS 1 [INFO][2024-12-20 16:25:58,818][[com.automatics.executor.Starter.main()] - CONNECTED CLIENTS ASSOCIATED WITH DEVICE D8:3A:DD:13:8C:13 IS 2C:44:FD:18:F9:FE [INFO][2024-12-20 16:25:58,832][[TestNG-PoolService-0] - >>>[BEFORE_METHOD]: Perform before method initialization D8:3A:DD:13:8C:13 [INFO][2024-12-20 16:25:58,833][[TestNG-PoolService-0] - Setting dattime in patter yyyy-MM-dd HH:mm:ss [INFO][2024-12-20 16:25:58,837][[TestNG-PoolService-0] - startTime 2024-12-20 10:55:58 [INFO][2024-12-20 16:25:58,837][[TestNG-PoolService-0] - >>>[BEFORE_METHOD]: Sending test exection start time to Automatics D8:3A:DD:13:8C:13 [INFO][2024-12-20 16:25:58,839][[TestNG-PoolService-0] - http://192.168.2.59:8080/Automatics/captureTestTriggerTime.htm [INFO][2024-12-20 16:25:58,841][[TestNG-PoolService-0] - {"jobId":456,"automationId":"TC-RDKB-WIFI-BAND-STEERING-1006","macAddress":"D8:3A:DD:13:8C:13","startDateTimeEST":1734692158838,"endDateTimeEST":0} [INFO][2024-12-20 16:25:58,930][[TestNG-PoolService-0] - Capture execution time - Response : HTTP/1.1 200 [INFO][2024-12-20 16:25:58,931][D8:3A:DD:13:8C:13[TestNG-PoolService-0] - Skipping partner specific before method initialization as it is not configured. 16:25:58,931 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.FileAppender] 16:25:58,931 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE-Rpi-RDKB-D83ADD138C13] 16:25:58,932 |-INFO in ch.qos.logback.core.FileAppender[FILE-Rpi-RDKB-D83ADD138C13] - File property is set to [target/logs/Rpi-RDKB-D83ADD138C13.log] [INFO][2024-12-20 16:25:58,932][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-12-20 16:25:58,933][D8:3A:DD:13:8C:13[TestNG-PoolService-0] - Get the locked status: false [INFO][2024-12-20 16:25:58,933][D8:3A:DD:13:8C:13[TestNG-PoolService-0] - Get the locked status: false [INFO][2024-12-20 16:25:58,933][D8:3A:DD:13:8C:13[TestNG-PoolService-0] - Is trace required for connected gateway: false [INFO][2024-12-20 16:25:58,933][D8:3A:DD:13:8C:13[TestNG-PoolService-0] - Is trace required for connected gateway: false [INFO][2024-12-20 16:25:58,943][D8:3A:DD:13:8C:13[TestNG-PoolService-0] - STARTED - testVerifyBandSteeringProcessGetsKilledWhen5GhzDisabled - com.automatics.device.Device@1ad20a8a [INFO][2024-12-20 16:25:58,943][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Getting MDC = D83ADD138C13settop_trace.log [INFO][2024-12-20 16:25:58,944][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Getting MDC = D8:3A:DD:13:8C:13 [INFO][2024-12-20 16:25:58,952][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ####################################################################################### [INFO][2024-12-20 16:25:58,952][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STARTING TEST CASE: TC-RDKB-WIFI-BAND-STEERING-106 [INFO][2024-12-20 16:25:58,952][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TEST DESCRIPTION: verify that Band steering process gets killed when 5GHz Wireless network is disabled [INFO][2024-12-20 16:25:58,952][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:25:58,952][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 1:Enable band steering on AP either via SNMP [INFO][2024-12-20 16:25:58,952][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 2:Make the SSID name for  band 2.4 and 5Ghz radios same Ex: RDKB for 2.4GHz and RDKBfor 5GHz [INFO][2024-12-20 16:25:58,953][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 3:Connect the wireless client to 5GHz wifi frequency band [INFO][2024-12-20 16:25:58,953][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 4: run ping to check connectivity between clients [INFO][2024-12-20 16:25:58,953][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 5: Disable 5ghz radio using webpa [INFO][2024-12-20 16:25:58,953][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 6: Check the lbd process is not running on RPI device [INFO][2024-12-20 16:25:58,953][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 7: Enable 5ghz radio using webpa [INFO][2024-12-20 16:25:58,953][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 8: Check the lbd process is running on RPI device [INFO][2024-12-20 16:25:58,953][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - POSTCONDITION : Going to set the old SSID back to the device [INFO][2024-12-20 16:25:58,953][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:25:58,953][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-12-20 16:25:58,953][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-12-20 16:25:58,953][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method: DMCLI [INFO][2024-12-20 16:25:58,954][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Going to find protocol specific names [INFO][2024-12-20 16:25:58,956][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Going to execute commands [INFO][2024-12-20 16:25:58,956][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.47 [INFO][2024-12-20 16:25:58,968][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:25:59,095][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: dmcli eRT getv Device.WiFi.SSID.1.SSID [INFO][2024-12-20 16:25:59,095][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:25:59,218][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. Parameter 1 name: Device.WiFi.SSID.1.SSID type: string, value: TDKB_2.4ghz <=============================================================> [INFO][2024-12-20 16:25:59,219][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.47 [INFO][2024-12-20 16:25:59,219][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. Parameter 1 name: Device.WiFi.SSID.1.SSID type: string, value: TDKB_2.4ghz [INFO][2024-12-20 16:25:59,220][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli param value : TDKB_2.4ghz [INFO][2024-12-20 16:25:59,220][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.47 [INFO][2024-12-20 16:25:59,235][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:25:59,384][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: dmcli eRT getv Device.WiFi.SSID.2.SSID [INFO][2024-12-20 16:25:59,384][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:25:59,506][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. Parameter 1 name: Device.WiFi.SSID.2.SSID type: string, value: RPI_RDKB-AP1 <=============================================================> [INFO][2024-12-20 16:25:59,506][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.47 [INFO][2024-12-20 16:25:59,507][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. Parameter 1 name: Device.WiFi.SSID.2.SSID type: string, value: RPI_RDKB-AP1 [INFO][2024-12-20 16:25:59,507][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli param value : RPI_RDKB-AP1 [INFO][2024-12-20 16:25:59,508][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Response : [tableName=null, index=null, name=Device.WiFi.SSID.10001.SSID, protocolSpecificParamName=Device.WiFi.SSID.1.SSID, value=TDKB_2.4ghz, datatype=null, statusCode=0, tableName=null, index=null, name=Device.WiFi.SSID.10101.SSID, protocolSpecificParamName=Device.WiFi.SSID.2.SSID, value=RPI_RDKB-AP1, datatype=null, statusCode=0] [INFO][2024-12-20 16:25:59,508][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:25:59,509][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 1: DESCRIPTION : Enable band steering using SNMP from gateway device [INFO][2024-12-20 16:25:59,509][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 1: ACTION : Enabling band steering using SNMP object -rdkbRgDot11BandSteeringEnable [OID- .1.3.6.1.4.1.17270.50.2.2.8.2.0 ] to 1 for true [INFO][2024-12-20 16:25:59,509][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 1: EXPECTED : Band steering should be enabled via SNMP successfully. [INFO][2024-12-20 16:25:59,509][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:25:59,521][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Current SNMP protocol: v2 [INFO][2024-12-20 16:25:59,522][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Reading implementation from core for snmpProviderFactory [INFO][2024-12-20 16:25:59,523][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Snmp protocol version: v2 [INFO][2024-12-20 16:25:59,524][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Is SNMPv3 enabled using appender - false [INFO][2024-12-20 16:25:59,526][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Reading implementation from partner for deviceConnectionProvider [INFO][2024-12-20 16:25:59,526][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Performing snmpset on device D8:3A:DD:13:8C:13 [INFO][2024-12-20 16:25:59,527][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Target IP is 192.168.2.47 [INFO][2024-12-20 16:25:59,528][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - SNMP PROVIDER versionv2 [INFO][2024-12-20 16:25:59,528][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - SNMP PROVIDER port 161 [INFO][2024-12-20 16:25:59,529][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - SNMP PROVIDER protocol udp [INFO][2024-12-20 16:25:59,529][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - SNMP PROVIDER V2 [INFO][2024-12-20 16:25:59,529][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - SNMP PROVIDER community private [INFO][2024-12-20 16:25:59,535][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.47 [INFO][2024-12-20 16:25:59,552][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:25:59,677][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: snmpset -v 2c -c private -t 10 -OQ udp:192.168.2.47:161 .1.3.6.1.4.1.17270.50.2.2.8.2.0 i 1 [INFO][2024-12-20 16:25:59,677][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:25:59,800][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> SNMPv2-SMI::enterprises.17270.50.2.2.8.2.0 = 1 <=============================================================> [INFO][2024-12-20 16:25:59,801][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.47 [INFO][2024-12-20 16:25:59,802][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 1 : ACTUAL :Successfully enabled band steering using snmp [INFO][2024-12-20 16:25:59,802][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:25:59,803][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WIFI-BAND-STEERING-106] [step Number : s1][ Execution status : PASS] [Error Message : ] [INFO][2024-12-20 16:25:59,806][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-12-20 16:25:59,807][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Fetching device property: FIRMWARE_VERSION [INFO][2024-12-20 16:25:59,815][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Fetching device props for D8:3A:DD:13:8C:13 for props [FIRMWARE_VERSION] Url Path: http://192.168.2.12:8080/DeviceManager/deviceManagement/getDeviceProps [INFO][2024-12-20 16:25:59,826][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : 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-12-20 16:25:59,826][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Getting value for property: FIRMWARE_VERSION [INFO][2024-12-20 16:25:59,826][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Value: RPI-RDKB [INFO][2024-12-20 16:25:59,826][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Device property name: FIRMWARE_VERSION value obtained: RPI-RDKB [INFO][2024-12-20 16:25:59,830][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WIFI-BAND-STEERING-106","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-WIFI-BAND-STEERING-1006"} [ERROR][2024-12-20 16:25:59,843][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : 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-12-20 16:25:59,843][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-12-20 16:25:59,843][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:25:59,843][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 2: DESCRIPTION : Make the SSID name for  band 2.4 and 5Ghz radios same [INFO][2024-12-20 16:25:59,844][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 2: ACTION : Execute set on webpa Device.WiFi.SSID.10001.SSID and Device.WiFi.SSID.10101.SSID . Ex: RDKB for 2.4GHz and RDKB for 5GHz [INFO][2024-12-20 16:25:59,844][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 2: EXPECTED : Webpa should return success. [INFO][2024-12-20 16:25:59,844][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:25:59,853][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - WebPa data type: STRING [INFO][2024-12-20 16:25:59,853][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 parameters status code added 0 [INFO][2024-12-20 16:25:59,853][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - WebPa data type: STRING [INFO][2024-12-20 16:25:59,853][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 parameters status code added 0 [INFO][2024-12-20 16:25:59,853][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-12-20 16:25:59,853][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-12-20 16:25:59,854][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Command to be executed: dmcli eRT setv Device.WiFi.SSID.1.SSID string RDKB [INFO][2024-12-20 16:25:59,854][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.47 [INFO][2024-12-20 16:25:59,866][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:26:00,006][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: dmcli eRT setv Device.WiFi.SSID.1.SSID string RDKB [INFO][2024-12-20 16:26:00,006][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:26:00,129][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. <=============================================================> [INFO][2024-12-20 16:26:00,129][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.47 [INFO][2024-12-20 16:26:00,130][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. [INFO][2024-12-20 16:26:00,130][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Apply settings dmcli command to be executed [INFO][2024-12-20 16:26:00,130][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.47 [INFO][2024-12-20 16:26:00,145][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:26:00,318][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: ps | grep -i "onewifi" [INFO][2024-12-20 16:26:00,318][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:26:00,441][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> 32642 root 0:03 /usr/bin/OneWifi -subsys eRT. 40278 root 0:00 sh -c ps | grep -i "onewifi" 40280 root 0:00 grep -i onewifi <=============================================================> [INFO][2024-12-20 16:26:00,441][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.47 [INFO][2024-12-20 16:26:00,442][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - The device has One Wifi : 32642 root 0:03 /usr/bin/OneWifi -subsys eRT. 40278 root 0:00 sh -c ps | grep -i "onewifi" 40280 root 0:00 grep -i onewifi [INFO][2024-12-20 16:26:00,442][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Apply settings dmcli command to be executed for One WIFI [INFO][2024-12-20 16:26:00,442][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli param name: Device.WiFi.SSID.1.SSID [INFO][2024-12-20 16:26:00,443][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Command to be executed: dmcli eRT setv Device.WiFi.ApplyAccessPointSettings bool 1 [INFO][2024-12-20 16:26:00,443][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DutIP:192.168.2.47 [INFO][2024-12-20 16:26:00,458][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:26:00,617][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: dmcli eRT setv Device.WiFi.ApplyAccessPointSettings bool 1 [INFO][2024-12-20 16:26:00,618][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:26:00,740][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. <=============================================================> [INFO][2024-12-20 16:26:00,741][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. [INFO][2024-12-20 16:26:00,741][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Command to be executed: dmcli eRT setv Device.WiFi.SSID.2.SSID string RDKB [INFO][2024-12-20 16:26:00,741][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.47 [INFO][2024-12-20 16:26:00,751][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:26:00,871][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: dmcli eRT setv Device.WiFi.SSID.2.SSID string RDKB [INFO][2024-12-20 16:26:00,871][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:26:00,994][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. <=============================================================> [INFO][2024-12-20 16:26:00,994][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.47 [INFO][2024-12-20 16:26:00,995][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. [INFO][2024-12-20 16:26:00,995][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Apply settings dmcli command to be executed [INFO][2024-12-20 16:26:00,995][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.47 [INFO][2024-12-20 16:26:01,011][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:26:01,142][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: ps | grep -i "onewifi" [INFO][2024-12-20 16:26:01,143][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:26:01,267][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> 32642 root 0:03 /usr/bin/OneWifi -subsys eRT. 40348 root 0:00 sh -c ps | grep -i "onewifi" 40352 root 0:00 grep -i onewifi <=============================================================> [INFO][2024-12-20 16:26:01,267][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.47 [INFO][2024-12-20 16:26:01,267][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - The device has One Wifi : 32642 root 0:03 /usr/bin/OneWifi -subsys eRT. 40348 root 0:00 sh -c ps | grep -i "onewifi" 40352 root 0:00 grep -i onewifi [INFO][2024-12-20 16:26:01,268][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Apply settings dmcli command to be executed for One WIFI [INFO][2024-12-20 16:26:01,268][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli param name: Device.WiFi.SSID.2.SSID [INFO][2024-12-20 16:26:01,268][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Command to be executed: dmcli eRT setv Device.WiFi.ApplyAccessPointSettings bool 1 [INFO][2024-12-20 16:26:01,268][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DutIP:192.168.2.47 [INFO][2024-12-20 16:26:01,282][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:26:01,416][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: dmcli eRT setv Device.WiFi.ApplyAccessPointSettings bool 1 [INFO][2024-12-20 16:26:01,416][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:26:01,539][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. <=============================================================> [INFO][2024-12-20 16:26:01,539][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. [INFO][2024-12-20 16:26:01,539][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Response : {Device.WiFi.SSID.10001.SSID=Success, Device.WiFi.SSID.10101.SSID=Success} [INFO][2024-12-20 16:26:28,638][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:26:28,770][[PollingThread_26_(D8:3A:DD:13:8C:13)] - sshConnectionPoll established [INFO][2024-12-20 16:26:28,783][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:26:28,922][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Value of responseString: null [INFO][2024-12-20 16:26:28,922][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Executing command: echo CONNECTION_IS_ALIVE [INFO][2024-12-20 16:26:28,922][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not null sendRecive: [INFO][2024-12-20 16:26:29,045][[PollingThread_26_(D8:3A:DD:13:8C:13)] - <=========================== RESPONSE =======================> CONNECTION_IS_ALIVE <=============================================================> [INFO][2024-12-20 16:26:29,045][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Closing SSH connection from DeviceIP:com.automatics.device.Device@1ad20a8a [INFO][2024-12-20 16:26:29,045][[PollingThread_26_(D8:3A:DD:13:8C:13)] - ConnectionPoll disconnected [INFO][2024-12-20 16:27:29,061][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:27:29,192][[PollingThread_26_(D8:3A:DD:13:8C:13)] - sshConnectionPoll established [INFO][2024-12-20 16:27:29,206][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:27:29,364][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Value of responseString: null [INFO][2024-12-20 16:27:29,364][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Executing command: echo CONNECTION_IS_ALIVE [INFO][2024-12-20 16:27:29,364][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not null sendRecive: [INFO][2024-12-20 16:27:29,487][[PollingThread_26_(D8:3A:DD:13:8C:13)] - <=========================== RESPONSE =======================> CONNECTION_IS_ALIVE <=============================================================> [INFO][2024-12-20 16:27:29,487][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Closing SSH connection from DeviceIP:com.automatics.device.Device@1ad20a8a [INFO][2024-12-20 16:27:29,487][[PollingThread_26_(D8:3A:DD:13:8C:13)] - ConnectionPoll disconnected [INFO][2024-12-20 16:28:01,541][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 2 : ACTUAL :Failed to configure same SSID for both radios [INFO][2024-12-20 16:28:01,541][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:28:01,541][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WIFI-BAND-STEERING-106] [step Number : s2][ Execution status : PASS] [Error Message : ] [INFO][2024-12-20 16:28:01,541][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-12-20 16:28:01,542][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WIFI-BAND-STEERING-106","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-WIFI-BAND-STEERING-1006"} [ERROR][2024-12-20 16:28:01,554][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : 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-12-20 16:28:01,554][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-12-20 16:28:01,555][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:28:01,555][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 3: DESCRIPTION : Connect the wireless clients to WIFI_BAND_5_GHZ [INFO][2024-12-20 16:28:01,555][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 3: ACTION : Execute Linux :nmcli dev wifi connect password indows : netsh wlan connect ssid= name= [INFO][2024-12-20 16:28:01,556][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 3: EXPECTED : Devices should be connected with WIFI_BAND_5_GHZ wifi network. [INFO][2024-12-20 16:28:01,556][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:28:01,556][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STARTING METHOD: getConnectedClientBasedOnCapability() [INFO][2024-12-20 16:28:01,556][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - client settop: 192.168.2.57 [INFO][2024-12-20 16:28:01,557][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Number of Connected client with Capability Dual band found is 1 [INFO][2024-12-20 16:28:01,572][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - connectedClient.getModel()====WINDOWSVM [INFO][2024-12-20 16:28:01,573][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Starting Method getParameterValuesUsingWebPaOrDmcli() [INFO][2024-12-20 16:28:01,573][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Is WebpaConnectionBroken : false [INFO][2024-12-20 16:28:01,573][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-12-20 16:28:01,573][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-12-20 16:28:01,573][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method: DMCLI [INFO][2024-12-20 16:28:01,573][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Going to find protocol specific names [INFO][2024-12-20 16:28:01,574][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Going to execute commands [INFO][2024-12-20 16:28:01,574][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.47 [INFO][2024-12-20 16:28:01,587][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:28:01,720][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: dmcli eRT getv Device.WiFi.SSID.2.SSID [INFO][2024-12-20 16:28:01,721][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:28:01,843][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. Parameter 1 name: Device.WiFi.SSID.2.SSID type: string, value: RDKB <=============================================================> [INFO][2024-12-20 16:28:01,844][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.47 [INFO][2024-12-20 16:28:01,844][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. Parameter 1 name: Device.WiFi.SSID.2.SSID type: string, value: RDKB [INFO][2024-12-20 16:28:01,845][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli param value : RDKB [INFO][2024-12-20 16:28:01,845][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Response : [tableName=null, index=null, name=Device.WiFi.SSID.10101.SSID, protocolSpecificParamName=Device.WiFi.SSID.2.SSID, value=RDKB, datatype=null, statusCode=0] [INFO][2024-12-20 16:28:01,846][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Parameter Value is : RDKB [INFO][2024-12-20 16:28:01,846][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Ending Method getParameterValuesUsingWebPaOrDmcli() [INFO][2024-12-20 16:28:01,846][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Starting Method getParameterValuesUsingWebPaOrDmcli() [INFO][2024-12-20 16:28:01,846][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Is WebpaConnectionBroken : false [INFO][2024-12-20 16:28:01,846][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-12-20 16:28:01,847][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-12-20 16:28:01,847][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method: DMCLI [INFO][2024-12-20 16:28:01,847][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Going to find protocol specific names [INFO][2024-12-20 16:28:01,847][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Going to execute commands [INFO][2024-12-20 16:28:01,847][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.47 [INFO][2024-12-20 16:28:01,861][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:28:02,021][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: dmcli eRT getv Device.WiFi.AccessPoint.2.Security.X_COMCAST-COM_KeyPassphrase [INFO][2024-12-20 16:28:02,021][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:28:02,143][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. Parameter 1 name: Device.WiFi.AccessPoint.2.Security.X_COMCAST-COM_KeyPassphrase type: string, value: rdk@1234 <=============================================================> [INFO][2024-12-20 16:28:02,144][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.47 [INFO][2024-12-20 16:28:02,144][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. Parameter 1 name: Device.WiFi.AccessPoint.2.Security.X_COMCAST-COM_KeyPassphrase type: string, value: rdk@1234 [INFO][2024-12-20 16:28:02,145][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli param value : rdk@1234 [INFO][2024-12-20 16:28:02,145][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Response : [tableName=null, index=null, name=Device.WiFi.AccessPoint.10101.Security.X_COMCAST-COM_KeyPassphrase, protocolSpecificParamName=Device.WiFi.AccessPoint.2.Security.X_COMCAST-COM_KeyPassphrase, value=rdk@1234, datatype=null, statusCode=0] [INFO][2024-12-20 16:28:02,145][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Parameter Value is : rdk@1234 [INFO][2024-12-20 16:28:02,145][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Ending Method getParameterValuesUsingWebPaOrDmcli() [INFO][2024-12-20 16:28:02,146][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Client device connection type : Wi-Fi [INFO][2024-12-20 16:28:02,147][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Client device wifi capability : Dual Band [INFO][2024-12-20 16:28:02,152][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : isWindows [INFO][2024-12-20 16:28:02,154][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - DeviceConfig [2C:44:FD:18:F9:FE] is identified as NON RDK DeviceConfig. [INFO][2024-12-20 16:28:02,154][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command on non-RDK device: 2C:44:FD:18:F9:FE netsh wlan show profiles [INFO][2024-12-20 16:28:02,154][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.57 [INFO][2024-12-20 16:28:02,349][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - (SSH EXECUTION) : Executing command netsh wlan show profiles on client : Mac Address [2C:44:FD:18:F9:FE] , User Name [User], IP Address [192.168.2.57] and Port Number [22] [INFO][2024-12-20 16:28:02,350][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: netsh wlan show profiles [INFO][2024-12-20 16:28:02,350][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Using configured response timeout: 50000 [INFO][2024-12-20 16:28:04,315][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> Profiles on interface Wi-Fi 3: Group policy profiles (read only) --------------------------------- User profiles ------------- All User Profile : RDKB <=============================================================> [INFO][2024-12-20 16:28:04,316][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.57 [INFO][2024-12-20 16:28:04,317][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Driver name from client: Wi-Fi 3 [INFO][2024-12-20 16:28:04,318][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - DeviceConfig [2C:44:FD:18:F9:FE] is identified as NON RDK DeviceConfig. [INFO][2024-12-20 16:28:04,318][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command on non-RDK device: 2C:44:FD:18:F9:FE netsh interface set interface "Wi-Fi 3" disable [INFO][2024-12-20 16:28:04,318][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.57 [INFO][2024-12-20 16:28:04,490][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - (SSH EXECUTION) : Executing command netsh interface set interface "Wi-Fi 3" disable on client : Mac Address [2C:44:FD:18:F9:FE] , User Name [User], IP Address [192.168.2.57] and Port Number [22] [INFO][2024-12-20 16:28:04,491][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: netsh interface set interface "Wi-Fi 3" disable [INFO][2024-12-20 16:28:04,491][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Using configured response timeout: 50000 [INFO][2024-12-20 16:28:07,638][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> <=============================================================> [INFO][2024-12-20 16:28:07,638][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.57 [INFO][2024-12-20 16:28:07,638][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Waiting for 30 seconds [INFO][2024-12-20 16:28:29,509][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:28:29,684][[PollingThread_26_(D8:3A:DD:13:8C:13)] - sshConnectionPoll established [INFO][2024-12-20 16:28:29,697][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:28:29,839][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Value of responseString: null [INFO][2024-12-20 16:28:29,839][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Executing command: echo CONNECTION_IS_ALIVE [INFO][2024-12-20 16:28:29,840][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not null sendRecive: [INFO][2024-12-20 16:28:29,962][[PollingThread_26_(D8:3A:DD:13:8C:13)] - <=========================== RESPONSE =======================> CONNECTION_IS_ALIVE <=============================================================> [INFO][2024-12-20 16:28:29,962][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Closing SSH connection from DeviceIP:com.automatics.device.Device@1ad20a8a [INFO][2024-12-20 16:28:29,963][[PollingThread_26_(D8:3A:DD:13:8C:13)] - ConnectionPoll disconnected [INFO][2024-12-20 16:28:37,641][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - DeviceConfig [2C:44:FD:18:F9:FE] is identified as NON RDK DeviceConfig. [INFO][2024-12-20 16:28:37,641][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command on non-RDK device: 2C:44:FD:18:F9:FE netsh interface set interface "Wi-Fi 3" enable [INFO][2024-12-20 16:28:37,641][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.57 [INFO][2024-12-20 16:28:37,825][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - (SSH EXECUTION) : Executing command netsh interface set interface "Wi-Fi 3" enable on client : Mac Address [2C:44:FD:18:F9:FE] , User Name [User], IP Address [192.168.2.57] and Port Number [22] [INFO][2024-12-20 16:28:37,825][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: netsh interface set interface "Wi-Fi 3" enable [INFO][2024-12-20 16:28:37,825][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Using configured response timeout: 50000 [INFO][2024-12-20 16:28:43,674][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> <=============================================================> [INFO][2024-12-20 16:28:43,674][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.57 [INFO][2024-12-20 16:28:43,675][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Waiting for 60 seconds after enabling the WiFi driver [INFO][2024-12-20 16:29:29,978][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:29:30,179][[PollingThread_26_(D8:3A:DD:13:8C:13)] - sshConnectionPoll established [INFO][2024-12-20 16:29:30,193][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:29:30,336][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Value of responseString: null [INFO][2024-12-20 16:29:30,337][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Executing command: echo CONNECTION_IS_ALIVE [INFO][2024-12-20 16:29:30,337][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not null sendRecive: [INFO][2024-12-20 16:29:30,459][[PollingThread_26_(D8:3A:DD:13:8C:13)] - <=========================== RESPONSE =======================> CONNECTION_IS_ALIVE <=============================================================> [INFO][2024-12-20 16:29:30,460][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Closing SSH connection from DeviceIP:com.automatics.device.Device@1ad20a8a [INFO][2024-12-20 16:29:30,460][[PollingThread_26_(D8:3A:DD:13:8C:13)] - ConnectionPoll disconnected [INFO][2024-12-20 16:29:43,676][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - DeviceConfig [2C:44:FD:18:F9:FE] is identified as NON RDK DeviceConfig. [INFO][2024-12-20 16:29:43,676][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command on non-RDK device: 2C:44:FD:18:F9:FE netsh wlan show networks |grep -i "RDKB" [INFO][2024-12-20 16:29:43,676][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.57 [INFO][2024-12-20 16:29:43,852][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - (SSH EXECUTION) : Executing command grep -i "RDKB"< <(netsh wlan show networks ) on client : Mac Address [2C:44:FD:18:F9:FE] , User Name [User], IP Address [192.168.2.57] and Port Number [22] [INFO][2024-12-20 16:29:43,853][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: grep -i "RDKB"< <(netsh wlan show networks ) [INFO][2024-12-20 16:29:43,853][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Using configured response timeout: 50000 [INFO][2024-12-20 16:29:45,699][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> SSID 6 : RDKB SSID 21 : RPI_RDKB-AP0 <=============================================================> [INFO][2024-12-20 16:29:45,699][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.57 [INFO][2024-12-20 16:29:45,706][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Pattern Found = RDKB [INFO][2024-12-20 16:29:45,706][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - RDKB [INFO][2024-12-20 16:29:45,706][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - is patter found for RDKB in target string = true [INFO][2024-12-20 16:29:45,706][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - DeviceConfig [2C:44:FD:18:F9:FE] is identified as NON RDK DeviceConfig. [INFO][2024-12-20 16:29:45,706][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command on non-RDK device: 2C:44:FD:18:F9:FE netsh wlan delete profile name=* [INFO][2024-12-20 16:29:45,706][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.57 [INFO][2024-12-20 16:29:45,880][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - (SSH EXECUTION) : Executing command netsh wlan delete profile name=* on client : Mac Address [2C:44:FD:18:F9:FE] , User Name [User], IP Address [192.168.2.57] and Port Number [22] [INFO][2024-12-20 16:29:45,880][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: netsh wlan delete profile name=* [INFO][2024-12-20 16:29:45,881][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Using configured response timeout: 50000 [INFO][2024-12-20 16:29:47,726][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> Profile "RDKB" is deleted from interface "Wi-Fi 3". <=============================================================> [INFO][2024-12-20 16:29:47,726][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.57 [INFO][2024-12-20 16:29:47,727][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Successfully removed all existing profiles on NUC 2C:44:FD:18:F9:FE [INFO][2024-12-20 16:29:47,727][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : Creating profile with ssid & password.... [INFO][2024-12-20 16:29:47,727][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : hostMacAddress : 2C44FD18F9FE [INFO][2024-12-20 16:29:47,728][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] 2: hostMacAddress : F9FE [INFO][2024-12-20 16:29:47,732][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : profileNameToAdd : .F9FE_RDKB.xml [INFO][2024-12-20 16:29:47,733][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : path : /var/lib/jenkins/workspace/JOB1/.F9FE_RDKB.xml [INFO][2024-12-20 16:29:47,733][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : securityModeToVerify : WPA2 [INFO][2024-12-20 16:29:47,733][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : isSsidHidden : false [INFO][2024-12-20 16:29:47,734][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : Creating new profile in server : /var/lib/jenkins/workspace/JOB1/.F9FE_RDKB.xml [INFO][2024-12-20 16:29:47,738][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : Document : [#document: null] [INFO][2024-12-20 16:29:47,739][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : subnList.item(i).setTextContent(content) name [INFO][2024-12-20 16:29:47,739][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : subnList.item(i).setTextContent(content) name [INFO][2024-12-20 16:29:47,740][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : bIntegerSSID : 1380207426 [INFO][2024-12-20 16:29:47,740][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : hex : 52444b42 [INFO][2024-12-20 16:29:47,740][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : subnList.item(i).setTextContent(content) hex [INFO][2024-12-20 16:29:47,741][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : subnList.item(i).setTextContent(content) nonBroadcast [INFO][2024-12-20 16:29:47,741][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : subnList.item(i).setTextContent(content) keyMaterial [INFO][2024-12-20 16:29:47,783][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : Successfully created profile [INFO][2024-12-20 16:29:47,784][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : resp: true [INFO][2024-12-20 16:29:47,786][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : Document : [#document: null] [INFO][2024-12-20 16:29:47,786][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : subnList.item(i).setTextContent(content) name [INFO][2024-12-20 16:29:47,787][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : subnList.item(i).setTextContent(content) name [INFO][2024-12-20 16:29:47,787][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : bIntegerSSID : 1380207426 [INFO][2024-12-20 16:29:47,787][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : hex : 52444b42 [INFO][2024-12-20 16:29:47,788][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : subnList.item(i).setTextContent(content) hex [INFO][2024-12-20 16:29:47,788][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : subnList.item(i).setTextContent(content) nonBroadcast [INFO][2024-12-20 16:29:47,788][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : subnList.item(i).setTextContent(content) keyMaterial [INFO][2024-12-20 16:29:47,790][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : Successfully created profile [INFO][2024-12-20 16:29:47,790][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : Copying new profile to device : /var/lib/jenkins/workspace/JOB1/.F9FE_RDKB.xml [INFO][2024-12-20 16:29:47,790][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : Copying File From JumpServer To Client [INFO][2024-12-20 16:29:47,791][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : Path for Copying File From :/var/lib/jenkins/workspace/JOB1/.F9FE_RDKB.xml [INFO][2024-12-20 16:29:47,791][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : Path for Copying File To :/home/User/.F9FE_RDKB.xml [INFO][2024-12-20 16:29:48,160][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - DeviceConfig [2C:44:FD:18:F9:FE] is identified as NON RDK DeviceConfig. [INFO][2024-12-20 16:29:48,160][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command on non-RDK device: 2C:44:FD:18:F9:FE ls -la | grep .F9FE_RDKB.xml [INFO][2024-12-20 16:29:48,160][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.57 [INFO][2024-12-20 16:29:48,293][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - (SSH EXECUTION) : Executing command grep .F9FE_RDKB.xml< <(ls -la ) on client : Mac Address [2C:44:FD:18:F9:FE] , User Name [User], IP Address [192.168.2.57] and Port Number [22] [INFO][2024-12-20 16:29:48,293][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: grep .F9FE_RDKB.xml< <(ls -la ) [INFO][2024-12-20 16:29:48,293][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Using configured response timeout: 50000 [INFO][2024-12-20 16:29:48,527][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> -rw-r--r-- 1 User None 885 Dec 20 16:29 .F9FE_RDKB.xml <=============================================================> [INFO][2024-12-20 16:29:48,527][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.57 [INFO][2024-12-20 16:29:48,527][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Pattern Found = .F9FE_RDKB.xml [INFO][2024-12-20 16:29:48,528][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - .F9FE_RDKB.xml [INFO][2024-12-20 16:29:48,528][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - is patter found for .F9FE_RDKB.xml in target string = true [INFO][2024-12-20 16:29:48,528][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Is wifi profile xml moved to client : true [INFO][2024-12-20 16:29:48,528][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : Adding wifi profile for ssid RDKB [INFO][2024-12-20 16:29:48,529][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - DeviceConfig [2C:44:FD:18:F9:FE] is identified as NON RDK DeviceConfig. [INFO][2024-12-20 16:29:48,529][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command on non-RDK device: 2C:44:FD:18:F9:FE netsh wlan add profile filename=.F9FE_RDKB.xml [INFO][2024-12-20 16:29:48,529][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.57 [INFO][2024-12-20 16:29:48,654][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - (SSH EXECUTION) : Executing command netsh wlan add profile filename=.F9FE_RDKB.xml on client : Mac Address [2C:44:FD:18:F9:FE] , User Name [User], IP Address [192.168.2.57] and Port Number [22] [INFO][2024-12-20 16:29:48,655][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: netsh wlan add profile filename=.F9FE_RDKB.xml [INFO][2024-12-20 16:29:48,655][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Using configured response timeout: 50000 [INFO][2024-12-20 16:29:50,479][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> Profile RDKB is added on interface Wi-Fi 3. <=============================================================> [INFO][2024-12-20 16:29:50,479][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.57 [INFO][2024-12-20 16:29:50,480][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : Wifi profile added successfully for ssid RDKB [INFO][2024-12-20 16:29:50,481][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Removed profile created locally in server [INFO][2024-12-20 16:29:50,481][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : command : netsh wlan show networks | grep -i RDKB [INFO][2024-12-20 16:29:50,482][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : startTime : 1734692390482 [INFO][2024-12-20 16:29:50,482][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - DeviceConfig [2C:44:FD:18:F9:FE] is identified as NON RDK DeviceConfig. [INFO][2024-12-20 16:29:50,482][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command on non-RDK device: 2C:44:FD:18:F9:FE netsh wlan show networks | grep -i RDKB [INFO][2024-12-20 16:29:50,482][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.57 [INFO][2024-12-20 16:29:50,599][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - (SSH EXECUTION) : Executing command grep -i RDKB< <(netsh wlan show networks ) on client : Mac Address [2C:44:FD:18:F9:FE] , User Name [User], IP Address [192.168.2.57] and Port Number [22] [INFO][2024-12-20 16:29:50,599][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: grep -i RDKB< <(netsh wlan show networks ) [INFO][2024-12-20 16:29:50,599][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Using configured response timeout: 50000 [INFO][2024-12-20 16:29:52,444][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> SSID 7 : RDKB SSID 12 : RPI_RDKB-AP0 <=============================================================> [INFO][2024-12-20 16:29:52,445][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.57 [INFO][2024-12-20 16:29:52,446][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [TEST LOG] : commandResponse : SSID 7 : RDKB SSID 12 : RPI_RDKB-AP0 [INFO][2024-12-20 16:29:52,446][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Pattern Found = RDKB [INFO][2024-12-20 16:29:52,446][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - RDKB [INFO][2024-12-20 16:29:52,446][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - is patter found for RDKB in target string = true [INFO][2024-12-20 16:29:52,447][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Going to validate Wifi Security Mode for the SSID : RDKB on the windows client [INFO][2024-12-20 16:29:52,447][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - DeviceConfig [2C:44:FD:18:F9:FE] is identified as NON RDK DeviceConfig. [INFO][2024-12-20 16:29:52,447][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command on non-RDK device: 2C:44:FD:18:F9:FE netsh wlan show networks | awk '/RDKB/,/Encryption/' | grep Authentication [INFO][2024-12-20 16:29:52,447][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.57 [INFO][2024-12-20 16:29:52,640][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - (SSH EXECUTION) : Executing command grep Authentication< <(( awk '/RDKB/,/Encryption/' )< <(netsh wlan show networks )) on client : Mac Address [2C:44:FD:18:F9:FE] , User Name [User], IP Address [192.168.2.57] and Port Number [22] [INFO][2024-12-20 16:29:52,640][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: grep Authentication< <(( awk '/RDKB/,/Encryption/' )< <(netsh wlan show networks )) [INFO][2024-12-20 16:29:52,641][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Using configured response timeout: 50000 [INFO][2024-12-20 16:29:54,475][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> Authentication : WPA2-Personal Authentication : WPA2-Personal <=============================================================> [INFO][2024-12-20 16:29:54,475][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.57 [INFO][2024-12-20 16:29:54,476][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Response for wifi security mode in Windows client : Authentication : WPA2-Personal Authentication : WPA2-Personal [INFO][2024-12-20 16:29:54,477][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - DeviceConfig [2C:44:FD:18:F9:FE] is identified as NON RDK DeviceConfig. [INFO][2024-12-20 16:29:54,477][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command on non-RDK device: 2C:44:FD:18:F9:FE netsh wlan connect name="RDKB" [INFO][2024-12-20 16:29:54,477][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.57 [INFO][2024-12-20 16:29:54,635][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - (SSH EXECUTION) : Executing command netsh wlan connect name="RDKB" on client : Mac Address [2C:44:FD:18:F9:FE] , User Name [User], IP Address [192.168.2.57] and Port Number [22] [INFO][2024-12-20 16:29:54,636][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: netsh wlan connect name="RDKB" [INFO][2024-12-20 16:29:54,636][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Using configured response timeout: 50000 [INFO][2024-12-20 16:29:56,450][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> Connection request was completed successfully. <=============================================================> [INFO][2024-12-20 16:29:56,450][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.57 [INFO][2024-12-20 16:29:56,451][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - DeviceConfig [2C:44:FD:18:F9:FE] is identified as NON RDK DeviceConfig. [INFO][2024-12-20 16:29:56,451][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command on non-RDK device: 2C:44:FD:18:F9:FE netsh wlan show interface | grep -i "state" [INFO][2024-12-20 16:29:56,451][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.57 [INFO][2024-12-20 16:29:56,626][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - (SSH EXECUTION) : Executing command grep -i "state"< <(netsh wlan show interface ) on client : Mac Address [2C:44:FD:18:F9:FE] , User Name [User], IP Address [192.168.2.57] and Port Number [22] [INFO][2024-12-20 16:29:56,627][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: grep -i "state"< <(netsh wlan show interface ) [INFO][2024-12-20 16:29:56,627][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Using configured response timeout: 50000 [INFO][2024-12-20 16:29:58,453][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> State : connected <=============================================================> [INFO][2024-12-20 16:29:58,453][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.57 [INFO][2024-12-20 16:29:58,455][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Is the device connected to Gateway Wi-Fi true [INFO][2024-12-20 16:29:58,455][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Device successfully connected to WIFI_BAND_5_GHZ wifi. Connected device 2C:44:FD:18:F9:FE to WIFI_BAND_5_GHZ wifi band [INFO][2024-12-20 16:29:58,456][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 3 : ACTUAL : Wireless client connected toWIFI_BAND_5_GHZ [INFO][2024-12-20 16:29:58,456][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:29:58,456][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WIFI-BAND-STEERING-106] [step Number : s3][ Execution status : PASS] [Error Message : ] [INFO][2024-12-20 16:29:58,456][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-12-20 16:29:58,457][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WIFI-BAND-STEERING-106","stepNumber":"s3","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"","executionStatus":"PASS","skipRemaining":true,"partnerName":"","automationId":"TC-RDKB-WIFI-BAND-STEERING-1006"} [ERROR][2024-12-20 16:29:58,470][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : 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-12-20 16:29:58,470][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-12-20 16:29:58,470][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:29:58,470][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 4: DESCRIPTION :run ping to check connectivity between clients [INFO][2024-12-20 16:29:58,470][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 4: ACTION : Execute From Client 1 : ping addressOfClient1 [INFO][2024-12-20 16:29:58,470][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 4: EXPECTED: Ping should be succesful and clients should be able to communicate between them [INFO][2024-12-20 16:29:58,470][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:29:58,471][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Windows device is connected to Gateway device to Wi-Fi [INFO][2024-12-20 16:29:58,471][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - searchTrace in getIpOrMacFromWindowsConnectedClient "Wireless LAN adapter Wi" [INFO][2024-12-20 16:29:58,471][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Command to be executed is ipconfig /all |grep -A 40 "Wireless LAN adapter Wi"|grep -i "IPv4 Address" [INFO][2024-12-20 16:29:58,471][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - DeviceConfig [2C:44:FD:18:F9:FE] is identified as NON RDK DeviceConfig. [INFO][2024-12-20 16:29:58,472][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command on non-RDK device: 2C:44:FD:18:F9:FE ipconfig /all |grep -A 40 "Wireless LAN adapter Wi"|grep -i "IPv4 Address" [INFO][2024-12-20 16:29:58,472][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.57 [INFO][2024-12-20 16:29:58,677][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - (SSH EXECUTION) : Executing command grep -i "IPv4 Address"< <((grep -A 40 "Wireless LAN adapter Wi")< <(ipconfig /all )) on client : Mac Address [2C:44:FD:18:F9:FE] , User Name [User], IP Address [192.168.2.57] and Port Number [22] [INFO][2024-12-20 16:29:58,677][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: grep -i "IPv4 Address"< <((grep -A 40 "Wireless LAN adapter Wi")< <(ipconfig /all )) [INFO][2024-12-20 16:29:58,677][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Using configured response timeout: 50000 [INFO][2024-12-20 16:30:00,502][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> IPv4 Address. . . . . . . . . . . : 10.0.0.184(Preferred) IPv4 Address. . . . . . . . . . . : 192.168.2.57(Preferred) <=============================================================> [INFO][2024-12-20 16:30:00,502][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.57 [INFO][2024-12-20 16:30:00,503][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - response of ipconfig is IPv4 Address. . . . . . . . . . . : 10.0.0.184(Preferred) IPv4 Address. . . . . . . . . . . : 192.168.2.57(Preferred) [INFO][2024-12-20 16:30:00,504][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Value of ip is - 10.0.0.184 [INFO][2024-12-20 16:30:00,504][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - response .lenght - 2 [INFO][2024-12-20 16:30:00,504][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - response of ip or mac is - IPv4 Address. . . . . . . . . . . : 10.0.0.184(Preferred) [INFO][2024-12-20 16:30:00,505][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Value of ip or mac is -10.0.0.184. device Model :Rpi-RDKB [INFO][2024-12-20 16:30:00,507][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Entering executeCommandUsingSsh method [INFO][2024-12-20 16:30:00,507][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DutIP:192.168.2.47 [INFO][2024-12-20 16:30:00,525][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:30:00,653][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: arp -a | grep -i 10.0.0.184 [INFO][2024-12-20 16:30:00,653][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:30:00,776][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> sh: arp: command not found <=============================================================> [INFO][2024-12-20 16:30:00,776][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Exiting executeCommandUsingSsh method [INFO][2024-12-20 16:30:00,781][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Validate response is -sh: arp: command not found. [INFO][2024-12-20 16:30:00,781][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Value of Windows connected client is 10.0.0.184 [INFO][2024-12-20 16:30:00,781][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Going to ping 10.0.0.184 from device [INFO][2024-12-20 16:30:00,782][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STARTING METHOD : verifyPingConnection() [INFO][2024-12-20 16:30:00,782][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - OS TYPE OF THE WIFI CLIENT: WINDOWS [INFO][2024-12-20 16:30:00,782][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Ping Command: ping -n 5 [INFO][2024-12-20 16:30:00,783][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - BroadBandCommonUtils.concatStringUsingStringBuffer(pingCommand, ipAddress) is: ping -n 5 10.0.0.184 [INFO][2024-12-20 16:30:00,783][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - DeviceConfig [2C:44:FD:18:F9:FE] is identified as NON RDK DeviceConfig. [INFO][2024-12-20 16:30:00,783][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command on non-RDK device: 2C:44:FD:18:F9:FE ping -n 5 10.0.0.184 [INFO][2024-12-20 16:30:00,783][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.57 [INFO][2024-12-20 16:30:00,948][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - (SSH EXECUTION) : Executing command ping -n 5 10.0.0.184 on client : Mac Address [2C:44:FD:18:F9:FE] , User Name [User], IP Address [192.168.2.57] and Port Number [22] [INFO][2024-12-20 16:30:00,948][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: ping -n 5 10.0.0.184 [INFO][2024-12-20 16:30:00,948][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Using configured response timeout: 50000 [INFO][2024-12-20 16:30:06,787][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> Pinging 10.0.0.184 with 32 bytes of data: Reply from 10.0.0.184: bytes=32 time<1ms TTL=128 Reply from 10.0.0.184: bytes=32 time<1ms TTL=128 Reply from 10.0.0.184: bytes=32 time<1ms TTL=128 Reply from 10.0.0.184: bytes=32 time<1ms TTL=128 Reply from 10.0.0.184: bytes=32 time<1ms TTL=128 Ping statistics for 10.0.0.184: Packets: Sent = 5, Received = 5, Lost = 0 (0% loss), Approximate round trip times in milli-seconds: Minimum = 0ms, Maximum = 0ms, Average = 0ms <=============================================================> [INFO][2024-12-20 16:30:06,788][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.57 [INFO][2024-12-20 16:30:06,789][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - response is: Pinging 10.0.0.184 with 32 bytes of data: Reply from 10.0.0.184: bytes=32 time<1ms TTL=128 Reply from 10.0.0.184: bytes=32 time<1ms TTL=128 Reply from 10.0.0.184: bytes=32 time<1ms TTL=128 Reply from 10.0.0.184: bytes=32 time<1ms TTL=128 Reply from 10.0.0.184: bytes=32 time<1ms TTL=128 Ping statistics for 10.0.0.184: Packets: Sent = 5, Received = 5, Lost = 0 (0% loss), Approximate round trip times in milli-seconds: Minimum = 0ms, Maximum = 0ms, Average = 0ms [ERROR][2024-12-20 16:30:06,789][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Pattern Not Found = TTL Expired in Transit [INFO][2024-12-20 16:30:06,789][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - is patter found for TTL Expired in Transit in target string = false [ERROR][2024-12-20 16:30:06,790][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Pattern Not Found = Destination host unreachable [INFO][2024-12-20 16:30:06,790][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - is patter found for Destination host unreachable in target string = false [ERROR][2024-12-20 16:30:06,790][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Pattern Not Found = Request timed out [INFO][2024-12-20 16:30:06,790][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - is patter found for Request timed out in target string = false [ERROR][2024-12-20 16:30:06,790][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Pattern Not Found = Unknown host [INFO][2024-12-20 16:30:06,791][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - is patter found for Unknown host in target string = false [ERROR][2024-12-20 16:30:06,791][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Pattern Not Found = Ping request could not find host [INFO][2024-12-20 16:30:06,791][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - is patter found for Ping request could not find host in target string = false [ERROR][2024-12-20 16:30:06,791][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Pattern Not Found = Request timeout for icmp_seq [INFO][2024-12-20 16:30:06,791][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - is patter found for Request timeout for icmp_seq in target string = false [INFO][2024-12-20 16:30:06,792][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - validate Ping Response is :false [INFO][2024-12-20 16:30:06,792][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - PATTERN MATCHED STRING:0 [INFO][2024-12-20 16:30:06,793][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 4 : ACTUAL :WIFI_BAND_5_GHZ has connecetivity in ipv4 interface [INFO][2024-12-20 16:30:06,793][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:30:06,793][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WIFI-BAND-STEERING-106] [step Number : s4][ Execution status : PASS] [Error Message : ] [INFO][2024-12-20 16:30:06,793][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-12-20 16:30:06,794][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WIFI-BAND-STEERING-106","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-WIFI-BAND-STEERING-1006"} [ERROR][2024-12-20 16:30:06,807][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : 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-12-20 16:30:06,807][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-12-20 16:30:06,807][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:30:06,808][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 5: DESCRIPTION : Disable WIFI_BAND_5_GHZ radio using webpa [INFO][2024-12-20 16:30:06,808][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 5: ACTION : Execute set on WIFI_BAND_5_GHZ enable status value false [INFO][2024-12-20 16:30:06,808][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 5: EXPECTED : Webpa should execute successfully [INFO][2024-12-20 16:30:06,808][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:30:06,811][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Going to DisableWIFI_BAND_5_GHZ [INFO][2024-12-20 16:30:06,813][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - WebPa data type: BOOLEAN [INFO][2024-12-20 16:30:06,813][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 parameters status code added 0 [INFO][2024-12-20 16:30:06,813][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-12-20 16:30:06,813][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-12-20 16:30:06,813][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Command to be executed: dmcli eRT setv Device.WiFi.SSID.2.Enable bool false [INFO][2024-12-20 16:30:06,813][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.47 [INFO][2024-12-20 16:30:06,827][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:30:06,961][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: dmcli eRT setv Device.WiFi.SSID.2.Enable bool false [INFO][2024-12-20 16:30:06,961][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:30:07,084][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. <=============================================================> [INFO][2024-12-20 16:30:07,084][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.47 [INFO][2024-12-20 16:30:07,084][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. [INFO][2024-12-20 16:30:07,085][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Apply settings dmcli command to be executed [INFO][2024-12-20 16:30:07,085][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.47 [INFO][2024-12-20 16:30:07,099][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:30:07,240][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: ps | grep -i "onewifi" [INFO][2024-12-20 16:30:07,240][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:30:07,363][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> 32642 root 0:04 /usr/bin/OneWifi -subsys eRT. 46193 root 0:00 sh -c ps | grep -i "onewifi" 46195 root 0:00 grep -i onewifi <=============================================================> [INFO][2024-12-20 16:30:07,363][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.47 [INFO][2024-12-20 16:30:07,363][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - The device has One Wifi : 32642 root 0:04 /usr/bin/OneWifi -subsys eRT. 46193 root 0:00 sh -c ps | grep -i "onewifi" 46195 root 0:00 grep -i onewifi [INFO][2024-12-20 16:30:07,363][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Apply settings dmcli command to be executed for One WIFI [INFO][2024-12-20 16:30:07,364][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli param name: Device.WiFi.SSID.2.Enable [INFO][2024-12-20 16:30:07,364][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Command to be executed: dmcli eRT setv Device.WiFi.ApplyAccessPointSettings bool 1 [INFO][2024-12-20 16:30:07,364][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DutIP:192.168.2.47 [INFO][2024-12-20 16:30:07,378][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:30:07,499][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: dmcli eRT setv Device.WiFi.ApplyAccessPointSettings bool 1 [INFO][2024-12-20 16:30:07,500][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:30:07,622][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. <=============================================================> [INFO][2024-12-20 16:30:07,622][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. [INFO][2024-12-20 16:30:07,624][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Response : {Device.WiFi.SSID.10101.Enable=Success} [INFO][2024-12-20 16:30:07,625][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ENDING METHOD: setWebPaParameterValues : success [INFO][2024-12-20 16:30:07,625][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - RESPONSE CODE: 0 [INFO][2024-12-20 16:30:07,625][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - RESPONSE MESSAGE: success [INFO][2024-12-20 16:30:07,638][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - WEBPA PARAM - Device.WiFi.SSID.10101.Enable SET WITH VALUE - false IS SUCCESSFUL: true [INFO][2024-12-20 16:30:07,638][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Status of setting WebPaParameter values: true [INFO][2024-12-20 16:30:07,639][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Entering executeCommandUsingSsh method [INFO][2024-12-20 16:30:07,639][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DutIP:192.168.2.47 [INFO][2024-12-20 16:30:07,651][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:30:07,780][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: dmcli eRT setv Device.WiFi.ApplyAccessPointSettings bool 1 [INFO][2024-12-20 16:30:07,780][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:30:07,902][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. <=============================================================> [INFO][2024-12-20 16:30:07,902][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Exiting executeCommandUsingSsh method [INFO][2024-12-20 16:30:07,902][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Entering executeCommandUsingSsh method [INFO][2024-12-20 16:30:07,903][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DutIP:192.168.2.47 [INFO][2024-12-20 16:30:07,913][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:30:08,042][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: dmcli eRT setv Device.WiFi.ApplyRadioSettings bool 1 [INFO][2024-12-20 16:30:08,042][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:30:08,164][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. <=============================================================> [INFO][2024-12-20 16:30:08,165][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Exiting executeCommandUsingSsh method [INFO][2024-12-20 16:30:08,165][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Waiting for 90 seconds to reflect the WiFi changes before getting or setting any WiFi parameters. [INFO][2024-12-20 16:30:30,475][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:30:30,598][[PollingThread_26_(D8:3A:DD:13:8C:13)] - sshConnectionPoll established [INFO][2024-12-20 16:30:30,607][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:30:30,724][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Value of responseString: null [INFO][2024-12-20 16:30:30,724][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Executing command: echo CONNECTION_IS_ALIVE [INFO][2024-12-20 16:30:30,724][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not null sendRecive: [INFO][2024-12-20 16:30:30,846][[PollingThread_26_(D8:3A:DD:13:8C:13)] - <=========================== RESPONSE =======================> CONNECTION_IS_ALIVE <=============================================================> [INFO][2024-12-20 16:30:30,846][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Closing SSH connection from DeviceIP:com.automatics.device.Device@1ad20a8a [INFO][2024-12-20 16:30:30,847][[PollingThread_26_(D8:3A:DD:13:8C:13)] - ConnectionPoll disconnected [INFO][2024-12-20 16:31:30,861][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:31:31,001][[PollingThread_26_(D8:3A:DD:13:8C:13)] - sshConnectionPoll established [INFO][2024-12-20 16:31:31,014][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:31:31,147][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Value of responseString: null [INFO][2024-12-20 16:31:31,147][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Executing command: echo CONNECTION_IS_ALIVE [INFO][2024-12-20 16:31:31,147][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not null sendRecive: [INFO][2024-12-20 16:31:31,269][[PollingThread_26_(D8:3A:DD:13:8C:13)] - <=========================== RESPONSE =======================> CONNECTION_IS_ALIVE <=============================================================> [INFO][2024-12-20 16:31:31,269][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Closing SSH connection from DeviceIP:com.automatics.device.Device@1ad20a8a [INFO][2024-12-20 16:31:31,270][[PollingThread_26_(D8:3A:DD:13:8C:13)] - ConnectionPoll disconnected [INFO][2024-12-20 16:31:38,166][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-12-20 16:31:38,166][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-12-20 16:31:38,166][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method: DMCLI [INFO][2024-12-20 16:31:38,166][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Going to find protocol specific names [INFO][2024-12-20 16:31:38,166][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Going to execute commands [INFO][2024-12-20 16:31:38,166][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.47 [INFO][2024-12-20 16:31:38,180][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:31:38,318][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: dmcli eRT getv Device.WiFi.SSID.2.Enable [INFO][2024-12-20 16:31:38,318][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:31:38,441][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. Parameter 1 name: Device.WiFi.SSID.2.Enable type: bool, value: false <=============================================================> [INFO][2024-12-20 16:31:38,441][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.47 [INFO][2024-12-20 16:31:38,441][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. Parameter 1 name: Device.WiFi.SSID.2.Enable type: bool, value: false [INFO][2024-12-20 16:31:38,442][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli param value : false [INFO][2024-12-20 16:31:38,442][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Response : [tableName=null, index=null, name=Device.WiFi.SSID.10101.Enable, protocolSpecificParamName=Device.WiFi.SSID.2.Enable, value=false, datatype=null, statusCode=0] [INFO][2024-12-20 16:31:38,443][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - valueToBePassed: false [INFO][2024-12-20 16:31:38,443][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - response: false [INFO][2024-12-20 16:31:38,443][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Pattern Found = false [INFO][2024-12-20 16:31:38,443][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - false [INFO][2024-12-20 16:31:38,443][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - is patter found for false in target string = true [INFO][2024-12-20 16:31:38,444][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Status of getting WebPaParameter values: true [INFO][2024-12-20 16:31:38,444][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Disable WIFI_BAND_5_GHZ success [INFO][2024-12-20 16:31:38,444][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 5 : ACTUAL :Disable WIFI_BAND_5_GHZ radio using webpa is success [INFO][2024-12-20 16:31:38,445][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:31:38,445][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WIFI-BAND-STEERING-106] [step Number : s5][ Execution status : PASS] [Error Message : ] [INFO][2024-12-20 16:31:38,445][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-12-20 16:31:38,446][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WIFI-BAND-STEERING-106","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-WIFI-BAND-STEERING-1006"} [ERROR][2024-12-20 16:31:38,458][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : 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-12-20 16:31:38,458][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-12-20 16:31:38,458][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:31:38,459][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 6: DESCRIPTION : Check the lbd process is not running on the RPI device [INFO][2024-12-20 16:31:38,459][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 6: ACTION : Exceute command : ps | grep lbd and check for String /sbin/lbd -C /tmp/lbd.conf in the command response [INFO][2024-12-20 16:31:38,459][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 6: EXPECTED : logs confirms that band steering daemon is stopped. lbd.conf must be killed, since there is no target band. The String "/sbin/lbd -C /tmp/lbd.conf" should not be present in the command output [INFO][2024-12-20 16:31:38,459][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:31:38,459][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Waiting for 2 minutes before checking the lbd process [INFO][2024-12-20 16:32:31,284][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:32:31,437][[PollingThread_26_(D8:3A:DD:13:8C:13)] - sshConnectionPoll established [INFO][2024-12-20 16:32:31,449][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:32:31,588][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Value of responseString: null [INFO][2024-12-20 16:32:31,589][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Executing command: echo CONNECTION_IS_ALIVE [INFO][2024-12-20 16:32:31,589][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not null sendRecive: [INFO][2024-12-20 16:32:31,711][[PollingThread_26_(D8:3A:DD:13:8C:13)] - <=========================== RESPONSE =======================> CONNECTION_IS_ALIVE <=============================================================> [INFO][2024-12-20 16:32:31,711][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Closing SSH connection from DeviceIP:com.automatics.device.Device@1ad20a8a [INFO][2024-12-20 16:32:31,712][[PollingThread_26_(D8:3A:DD:13:8C:13)] - ConnectionPoll disconnected [INFO][2024-12-20 16:33:31,726][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:33:31,857][[PollingThread_26_(D8:3A:DD:13:8C:13)] - sshConnectionPoll established [INFO][2024-12-20 16:33:31,869][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:33:32,021][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Value of responseString: null [INFO][2024-12-20 16:33:32,021][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Executing command: echo CONNECTION_IS_ALIVE [INFO][2024-12-20 16:33:32,021][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not null sendRecive: [INFO][2024-12-20 16:33:32,143][[PollingThread_26_(D8:3A:DD:13:8C:13)] - <=========================== RESPONSE =======================> CONNECTION_IS_ALIVE <=============================================================> [INFO][2024-12-20 16:33:32,144][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Closing SSH connection from DeviceIP:com.automatics.device.Device@1ad20a8a [INFO][2024-12-20 16:33:32,144][[PollingThread_26_(D8:3A:DD:13:8C:13)] - ConnectionPoll disconnected [INFO][2024-12-20 16:33:38,459][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Entering executeCommandUsingSsh method [INFO][2024-12-20 16:33:38,459][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DutIP:192.168.2.47 [INFO][2024-12-20 16:33:38,473][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:33:38,657][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: ps | grep lbd [INFO][2024-12-20 16:33:38,657][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:33:38,779][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> 50456 root 0:00 sh -c ps | grep lbd 50459 root 0:00 grep lbd <=============================================================> [INFO][2024-12-20 16:33:38,780][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Exiting executeCommandUsingSsh method [INFO][2024-12-20 16:33:38,780][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Response of command : 50456 root 0:00 sh -c ps | grep lbd 50459 root 0:00 grep lbd [INFO][2024-12-20 16:33:38,781][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 6 : ACTUAL :Band Steering process is not running when target WIFI_BAND_5_GHZ band is disabled [INFO][2024-12-20 16:33:38,781][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:33:38,781][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WIFI-BAND-STEERING-106] [step Number : s6][ Execution status : PASS] [Error Message : ] [INFO][2024-12-20 16:33:38,781][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-12-20 16:33:38,782][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WIFI-BAND-STEERING-106","stepNumber":"s6","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"","executionStatus":"PASS","skipRemaining":false,"partnerName":"","automationId":"TC-RDKB-WIFI-BAND-STEERING-1006"} [ERROR][2024-12-20 16:33:38,795][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : 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-12-20 16:33:38,795][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-12-20 16:33:38,795][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:33:38,796][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 7: DESCRIPTION : Enable WIFI_BAND_5_GHZ radio using webpa [INFO][2024-12-20 16:33:38,796][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 7: ACTION : Execute set on WIFI_BAND_5_GHZ Enable value is true [INFO][2024-12-20 16:33:38,796][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 7: EXPECTED : Webpa should execute successfully [INFO][2024-12-20 16:33:38,796][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:33:38,796][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Going to EnableWIFI_BAND_5_GHZ [INFO][2024-12-20 16:33:38,796][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - WebPa data type: BOOLEAN [INFO][2024-12-20 16:33:38,797][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 parameters status code added 0 [INFO][2024-12-20 16:33:38,797][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-12-20 16:33:38,797][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-12-20 16:33:38,797][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Command to be executed: dmcli eRT setv Device.WiFi.SSID.2.Enable bool true [INFO][2024-12-20 16:33:38,797][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.47 [INFO][2024-12-20 16:33:38,809][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:33:38,942][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: dmcli eRT setv Device.WiFi.SSID.2.Enable bool true [INFO][2024-12-20 16:33:38,942][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:33:39,065][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. <=============================================================> [INFO][2024-12-20 16:33:39,065][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.47 [INFO][2024-12-20 16:33:39,065][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. [INFO][2024-12-20 16:33:39,065][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Apply settings dmcli command to be executed [INFO][2024-12-20 16:33:39,065][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.47 [INFO][2024-12-20 16:33:39,079][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:33:39,227][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: ps | grep -i "onewifi" [INFO][2024-12-20 16:33:39,228][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:33:39,350][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> 32642 root 0:05 /usr/bin/OneWifi -subsys eRT. 50465 root 0:00 sh -c ps | grep -i "onewifi" 50467 root 0:00 grep -i onewifi <=============================================================> [INFO][2024-12-20 16:33:39,350][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.47 [INFO][2024-12-20 16:33:39,350][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - The device has One Wifi : 32642 root 0:05 /usr/bin/OneWifi -subsys eRT. 50465 root 0:00 sh -c ps | grep -i "onewifi" 50467 root 0:00 grep -i onewifi [INFO][2024-12-20 16:33:39,351][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Apply settings dmcli command to be executed for One WIFI [INFO][2024-12-20 16:33:39,351][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli param name: Device.WiFi.SSID.2.Enable [INFO][2024-12-20 16:33:39,351][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Command to be executed: dmcli eRT setv Device.WiFi.ApplyAccessPointSettings bool 1 [INFO][2024-12-20 16:33:39,351][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DutIP:192.168.2.47 [INFO][2024-12-20 16:33:39,364][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:33:39,502][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: dmcli eRT setv Device.WiFi.ApplyAccessPointSettings bool 1 [INFO][2024-12-20 16:33:39,502][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:33:39,625][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. <=============================================================> [INFO][2024-12-20 16:33:39,625][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. [INFO][2024-12-20 16:33:39,625][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Response : {Device.WiFi.SSID.10101.Enable=Success} [INFO][2024-12-20 16:33:39,626][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ENDING METHOD: setWebPaParameterValues : success [INFO][2024-12-20 16:33:39,626][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - RESPONSE CODE: 0 [INFO][2024-12-20 16:33:39,626][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - RESPONSE MESSAGE: success [INFO][2024-12-20 16:33:39,626][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - WEBPA PARAM - Device.WiFi.SSID.10101.Enable SET WITH VALUE - true IS SUCCESSFUL: true [INFO][2024-12-20 16:33:39,626][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Status of setting WebPaParameter values: true [INFO][2024-12-20 16:33:39,626][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Entering executeCommandUsingSsh method [INFO][2024-12-20 16:33:39,626][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DutIP:192.168.2.47 [INFO][2024-12-20 16:33:39,638][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:33:39,772][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: dmcli eRT setv Device.WiFi.ApplyAccessPointSettings bool 1 [INFO][2024-12-20 16:33:39,772][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:33:39,895][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. <=============================================================> [INFO][2024-12-20 16:33:39,895][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Exiting executeCommandUsingSsh method [INFO][2024-12-20 16:33:39,895][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Entering executeCommandUsingSsh method [INFO][2024-12-20 16:33:39,895][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DutIP:192.168.2.47 [INFO][2024-12-20 16:33:39,909][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:33:40,046][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: dmcli eRT setv Device.WiFi.ApplyRadioSettings bool 1 [INFO][2024-12-20 16:33:40,047][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:33:40,169][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. <=============================================================> [INFO][2024-12-20 16:33:40,170][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Exiting executeCommandUsingSsh method [INFO][2024-12-20 16:33:40,170][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Waiting for 90 seconds to reflect the WiFi changes before getting or setting any WiFi parameters. [INFO][2024-12-20 16:34:32,158][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:34:32,278][[PollingThread_26_(D8:3A:DD:13:8C:13)] - sshConnectionPoll established [INFO][2024-12-20 16:34:32,290][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:34:32,433][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Value of responseString: null [INFO][2024-12-20 16:34:32,433][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Executing command: echo CONNECTION_IS_ALIVE [INFO][2024-12-20 16:34:32,433][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not null sendRecive: [INFO][2024-12-20 16:34:32,556][[PollingThread_26_(D8:3A:DD:13:8C:13)] - <=========================== RESPONSE =======================> CONNECTION_IS_ALIVE <=============================================================> [INFO][2024-12-20 16:34:32,556][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Closing SSH connection from DeviceIP:com.automatics.device.Device@1ad20a8a [INFO][2024-12-20 16:34:32,556][[PollingThread_26_(D8:3A:DD:13:8C:13)] - ConnectionPoll disconnected [INFO][2024-12-20 16:35:10,171][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-12-20 16:35:10,171][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-12-20 16:35:10,171][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method: DMCLI [INFO][2024-12-20 16:35:10,171][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Going to find protocol specific names [INFO][2024-12-20 16:35:10,171][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Going to execute commands [INFO][2024-12-20 16:35:10,171][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.47 [INFO][2024-12-20 16:35:10,184][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:35:10,342][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: dmcli eRT getv Device.WiFi.SSID.2.Enable [INFO][2024-12-20 16:35:10,342][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:35:10,464][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. Parameter 1 name: Device.WiFi.SSID.2.Enable type: bool, value: true <=============================================================> [INFO][2024-12-20 16:35:10,465][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.47 [INFO][2024-12-20 16:35:10,465][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli response : CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. Parameter 1 name: Device.WiFi.SSID.2.Enable type: bool, value: true [INFO][2024-12-20 16:35:10,465][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli param value : true [INFO][2024-12-20 16:35:10,465][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Response : [tableName=null, index=null, name=Device.WiFi.SSID.10101.Enable, protocolSpecificParamName=Device.WiFi.SSID.2.Enable, value=true, datatype=null, statusCode=0] [INFO][2024-12-20 16:35:10,466][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - valueToBePassed: true [INFO][2024-12-20 16:35:10,466][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - response: true [INFO][2024-12-20 16:35:10,466][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Pattern Found = true [INFO][2024-12-20 16:35:10,466][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - true [INFO][2024-12-20 16:35:10,466][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - is patter found for true in target string = true [INFO][2024-12-20 16:35:10,466][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Status of getting WebPaParameter values: true [INFO][2024-12-20 16:35:10,467][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Enable WIFI_BAND_5_GHZ success [INFO][2024-12-20 16:35:10,467][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 7 : ACTUAL :Enable WIFI_BAND_5_GHZ radio using webpa is success [INFO][2024-12-20 16:35:10,467][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:35:10,467][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WIFI-BAND-STEERING-106] [step Number : s7][ Execution status : PASS] [Error Message : ] [INFO][2024-12-20 16:35:10,468][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-12-20 16:35:10,469][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WIFI-BAND-STEERING-106","stepNumber":"s7","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"","executionStatus":"PASS","skipRemaining":false,"partnerName":"","automationId":"TC-RDKB-WIFI-BAND-STEERING-1006"} [ERROR][2024-12-20 16:35:10,480][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : 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-12-20 16:35:10,480][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-12-20 16:35:10,480][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:35:10,480][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 8: DESCRIPTION : Check the lbd process is running on the RPI device [INFO][2024-12-20 16:35:10,480][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 8: ACTION : Exceute command : ps | grep lbd and compare with not null response [INFO][2024-12-20 16:35:10,480][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 8: EXPECTED : logs confirms that band steering daemon is running. lbd.conf must be reinitiated and band steering must work as expected. [INFO][2024-12-20 16:35:10,480][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:35:10,480][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Waiting for 2 minutes before checking the lbd process [INFO][2024-12-20 16:35:32,570][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:35:32,706][[PollingThread_26_(D8:3A:DD:13:8C:13)] - sshConnectionPoll established [INFO][2024-12-20 16:35:32,719][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:35:32,849][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Value of responseString: null [INFO][2024-12-20 16:35:32,849][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Executing command: echo CONNECTION_IS_ALIVE [INFO][2024-12-20 16:35:32,849][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not null sendRecive: [INFO][2024-12-20 16:35:32,971][[PollingThread_26_(D8:3A:DD:13:8C:13)] - <=========================== RESPONSE =======================> CONNECTION_IS_ALIVE <=============================================================> [INFO][2024-12-20 16:35:32,971][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Closing SSH connection from DeviceIP:com.automatics.device.Device@1ad20a8a [INFO][2024-12-20 16:35:32,972][[PollingThread_26_(D8:3A:DD:13:8C:13)] - ConnectionPoll disconnected [INFO][2024-12-20 16:36:32,990][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:36:33,115][[PollingThread_26_(D8:3A:DD:13:8C:13)] - sshConnectionPoll established [INFO][2024-12-20 16:36:33,126][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Default SSH custom port is set [INFO][2024-12-20 16:36:33,243][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Value of responseString: null [INFO][2024-12-20 16:36:33,243][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Executing command: echo CONNECTION_IS_ALIVE [INFO][2024-12-20 16:36:33,243][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Conn is not null sendRecive: [INFO][2024-12-20 16:36:33,365][[PollingThread_26_(D8:3A:DD:13:8C:13)] - <=========================== RESPONSE =======================> CONNECTION_IS_ALIVE <=============================================================> [INFO][2024-12-20 16:36:33,365][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Closing SSH connection from DeviceIP:com.automatics.device.Device@1ad20a8a [INFO][2024-12-20 16:36:33,366][[PollingThread_26_(D8:3A:DD:13:8C:13)] - ConnectionPoll disconnected [INFO][2024-12-20 16:37:10,481][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Entering executeCommandUsingSsh method [INFO][2024-12-20 16:37:10,481][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DutIP:192.168.2.47 [INFO][2024-12-20 16:37:10,495][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:37:10,621][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: ps | grep lbd [INFO][2024-12-20 16:37:10,621][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:37:10,743][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> 60036 root 0:00 sh -c ps | grep lbd 60038 root 0:00 grep lbd <=============================================================> [INFO][2024-12-20 16:37:10,744][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Exiting executeCommandUsingSsh method [INFO][2024-12-20 16:37:10,744][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Response of command : 60036 root 0:00 sh -c ps | grep lbd 60038 root 0:00 grep lbd [INFO][2024-12-20 16:37:10,745][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - STEP 8 : ACTUAL :Band Steering process is running when target WIFI_BAND_5_GHZ band is enabled [INFO][2024-12-20 16:37:10,745][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - ************************************************************************* [INFO][2024-12-20 16:37:10,745][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [STB MAC : D8:3A:DD:13:8C:13][ Manual test ID : TC-RDKB-WIFI-BAND-STEERING-106] [step Number : s8][ Execution status : PASS] [Error Message : ] [INFO][2024-12-20 16:37:10,745][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Entered into updateExecutionStatus method [INFO][2024-12-20 16:37:10,746][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Result Details ->{"JMD_ID":"456","manualId":"TC-RDKB-WIFI-BAND-STEERING-106","stepNumber":"s8","testType":"GROUP_OR_AUTOID ","buildName":"RPI-RDKB","macAddress":"D8:3A:DD:13:8C:13","remarks":"","executionStatus":"PASS","skipRemaining":false,"partnerName":"","automationId":"TC-RDKB-WIFI-BAND-STEERING-1006"} [ERROR][2024-12-20 16:37:10,757][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : 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-12-20 16:37:10,758][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Exited from updateExecutionStatus method [INFO][2024-12-20 16:37:10,758][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - POSTCONDITION : Going to set the old SSID back to the device [INFO][2024-12-20 16:37:10,758][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - WebPa data type: STRING [INFO][2024-12-20 16:37:10,758][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 parameters status code added 0 [INFO][2024-12-20 16:37:10,758][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - WebPa data type: STRING [INFO][2024-12-20 16:37:10,758][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 parameters status code added 0 [INFO][2024-12-20 16:37:10,758][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method configured in Automatics Props: null [INFO][2024-12-20 16:37:10,759][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Access Method going to use: DMCLI [INFO][2024-12-20 16:37:10,759][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Command to be executed: dmcli eRT setv Device.WiFi.SSID.1.SSID string TDKB_2.4ghz [INFO][2024-12-20 16:37:10,759][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.47 [INFO][2024-12-20 16:37:10,771][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:37:10,895][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: dmcli eRT setv Device.WiFi.SSID.1.SSID string TDKB_2.4ghz [INFO][2024-12-20 16:37:10,895][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:37:11,017][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. <=============================================================> [INFO][2024-12-20 16:37:11,017][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.47 [INFO][2024-12-20 16:37:11,018][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. [INFO][2024-12-20 16:37:11,018][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Apply settings dmcli command to be executed [INFO][2024-12-20 16:37:11,018][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.47 [INFO][2024-12-20 16:37:11,031][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:37:11,190][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: ps | grep -i "onewifi" [INFO][2024-12-20 16:37:11,190][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:37:11,312][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> 32642 root 0:06 /usr/bin/OneWifi -subsys eRT. 60044 root 0:00 sh -c ps | grep -i "onewifi" 60046 root 0:00 grep -i onewifi <=============================================================> [INFO][2024-12-20 16:37:11,312][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.47 [INFO][2024-12-20 16:37:11,313][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - The device has One Wifi : 32642 root 0:06 /usr/bin/OneWifi -subsys eRT. 60044 root 0:00 sh -c ps | grep -i "onewifi" 60046 root 0:00 grep -i onewifi [INFO][2024-12-20 16:37:11,313][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Apply settings dmcli command to be executed for One WIFI [INFO][2024-12-20 16:37:11,313][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli param name: Device.WiFi.SSID.1.SSID [INFO][2024-12-20 16:37:11,313][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Command to be executed: dmcli eRT setv Device.WiFi.ApplyAccessPointSettings bool 1 [INFO][2024-12-20 16:37:11,313][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DutIP:192.168.2.47 [INFO][2024-12-20 16:37:11,326][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:37:11,468][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: dmcli eRT setv Device.WiFi.ApplyAccessPointSettings bool 1 [INFO][2024-12-20 16:37:11,469][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:37:11,591][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. <=============================================================> [INFO][2024-12-20 16:37:11,592][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. [INFO][2024-12-20 16:37:11,592][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Command to be executed: dmcli eRT setv Device.WiFi.SSID.2.SSID string RPI_RDKB-AP1 [INFO][2024-12-20 16:37:11,592][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.47 [INFO][2024-12-20 16:37:11,605][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:37:11,759][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: dmcli eRT setv Device.WiFi.SSID.2.SSID string RPI_RDKB-AP1 [INFO][2024-12-20 16:37:11,759][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:37:11,882][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. <=============================================================> [INFO][2024-12-20 16:37:11,882][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.47 [INFO][2024-12-20 16:37:11,882][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. [INFO][2024-12-20 16:37:11,882][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Apply settings dmcli command to be executed [INFO][2024-12-20 16:37:11,883][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DeviceIP:192.168.2.47 [INFO][2024-12-20 16:37:11,894][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:37:12,033][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: ps | grep -i "onewifi" [INFO][2024-12-20 16:37:12,033][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:37:12,155][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> 32642 root 0:06 /usr/bin/OneWifi -subsys eRT. 60067 root 0:00 sh -c ps | grep -i "onewifi" 60069 root 0:00 grep -i onewifi <=============================================================> [INFO][2024-12-20 16:37:12,155][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Closing SSH connection from DeviceIP:192.168.2.47 [INFO][2024-12-20 16:37:12,155][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - The device has One Wifi : 32642 root 0:06 /usr/bin/OneWifi -subsys eRT. 60067 root 0:00 sh -c ps | grep -i "onewifi" 60069 root 0:00 grep -i onewifi [INFO][2024-12-20 16:37:12,156][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Apply settings dmcli command to be executed for One WIFI [INFO][2024-12-20 16:37:12,156][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli param name: Device.WiFi.SSID.2.SSID [INFO][2024-12-20 16:37:12,156][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Command to be executed: dmcli eRT setv Device.WiFi.ApplyAccessPointSettings bool 1 [INFO][2024-12-20 16:37:12,156][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - About to create SSH connection to DutIP:192.168.2.47 [INFO][2024-12-20 16:37:12,169][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Default SSH custom port is set [INFO][2024-12-20 16:37:12,302][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Executing command: dmcli eRT setv Device.WiFi.ApplyAccessPointSettings bool 1 [INFO][2024-12-20 16:37:12,302][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Conn is not null sendRecive: [INFO][2024-12-20 16:37:12,425][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - <=========================== RESPONSE =======================> CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. <=============================================================> [INFO][2024-12-20 16:37:12,425][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Dmcli Response: CR component name is: eRT.com.cisco.spvtg.ccsp.CR subsystem_prefix eRT. Execution succeed. [INFO][2024-12-20 16:37:12,425][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - TR181 Response : {Device.WiFi.SSID.10001.SSID=Success, Device.WiFi.SSID.10101.SSID=Success} [INFO][2024-12-20 16:37:12,426][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Successfully set the parameter : Device.WiFi.SSID.10001.SSID [INFO][2024-12-20 16:37:12,426][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Successfully set the parameter : Device.WiFi.SSID.10101.SSID [INFO][2024-12-20 16:37:12,431][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - >>>[AFTER_METHOD]: Clear device trace buffer for D8:3A:DD:13:8C:13 [INFO][2024-12-20 16:37:12,441][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - NewLocation for log saving logs /var/lib/jenkins/workspace/JOB1/target/TC-RDKB-WIFI-BAND-STEERING-1006/D83ADD138C13/settoptrace/ [INFO][2024-12-20 16:37:12,442][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - created a new directory true [INFO][2024-12-20 16:37:12,443][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - New trace location from the strings /var/lib/jenkins/workspace/JOB1/target/settoptrace/D83ADD138C13settop_trace.log [INFO][2024-12-20 16:37:12,444][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Writing stated from line [INFO][2024-12-20 16:37:12,934][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [ HTML LOG PARSER ] : End of log parser Fri Dec 20 16:37:12 IST 2024 [INFO][2024-12-20 16:37:12,935][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - NewLocation for log saving logs /var/lib/jenkins/workspace/JOB1/target/TC-RDKB-WIFI-BAND-STEERING-1006/D83ADD138C13/logs/ [INFO][2024-12-20 16:37:12,935][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - created a new directory true [INFO][2024-12-20 16:37:12,935][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Destination Summary file doesn't exist. Creating one! [INFO][2024-12-20 16:37:12,936][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Writing stated from line [INFO][2024-12-20 16:37:12,990][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - [ HTML LOG PARSER ] : End of log parser Fri Dec 20 16:37:12 IST 2024 [INFO][2024-12-20 16:37:12,990][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - >>>[AFTER_METHOD]: Sending test execution completion time for D8:3A:DD:13:8C:13 [INFO][2024-12-20 16:37:12,990][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - http://192.168.2.59:8080/Automatics/captureTestTriggerTime.htm [INFO][2024-12-20 16:37:12,990][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - {"jobId":456,"automationId":"TC-RDKB-WIFI-BAND-STEERING-1006","macAddress":"D8:3A:DD:13:8C:13","startDateTimeEST":0,"endDateTimeEST":1734692832990} [INFO][2024-12-20 16:37:13,001][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Capture execution time - Response : HTTP/1.1 200 [INFO][2024-12-20 16:37:13,001][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Restarting Trace in after method [INFO][2024-12-20 16:37:13,004][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Is trace required for connected gateway: false [INFO][2024-12-20 16:37:13,004][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Is trace required for connected gateway: false [INFO][2024-12-20 16:37:13,004][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Going for if build changed : Test Type : GROUP_OR_AUTOID [INFO][2024-12-20 16:37:13,004][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - Skipping build change verification as partner specific initialization is not configured. [INFO][2024-12-20 16:37:13,005][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13] - >>>[AFTER_METHOD]: Build Change Status: NO_CHANGE [INFO][2024-12-20 16:37:13,005][D8:3A:DD:13:8C:13[TC-RDKB-WIFI-BAND-STEERING-1006 : 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.wifi.BroadBandSteeringTests@3378f3cf]org.testng.TestRunner@fc485a3 863564751 AutomaticsTestBase.performBeforeMethodInit([Ljava.lang.Object;, org.testng.ITestResult)[pri:0, instance:com.automatics.rdkb.tests.wifi.BroadBandSteeringTests@3378f3cf][Ljava.lang.Object;@38615e4c [TestResult name={null} status=CREATED method=BroadBandSteeringTests.testVerifyBandSteeringProcessGetsKilledWhen5GhzDisabled(com.automatics.device.Dut)[pri:0, instance:com.automatics.rdkb.tests.wifi.BroadBandSteeringTests@3378f3cf] output={null}] 863564751 BroadBandSteeringTests.testVerifyBandSteeringProcessGetsKilledWhen5GhzDisabled(com.automatics.device.Dut)[pri:0, instance:com.automatics.rdkb.tests.wifi.BroadBandSteeringTests@3378f3cf]com.automatics.device.Device@1ad20a8a 863564751 AutomaticsTestBase.performAfterMethodCleanup([Ljava.lang.Object;, org.testng.ITestResult)[pri:0, instance:com.automatics.rdkb.tests.wifi.BroadBandSteeringTests@3378f3cf][Ljava.lang.Object;@38615e4c [TestResult name=testVerifyBandSteeringProcessGetsKilledWhen5GhzDisabled status=SUCCESS method=BroadBandSteeringTests.testVerifyBandSteeringProcessGetsKilledWhen5GhzDisabled(com.automatics.device.Dut)[pri:0, instance:com.automatics.rdkb.tests.wifi.BroadBandSteeringTests@3378f3cf] output={null}] 863564751 ===== PASSED: testVerifyBandSteeringProcessGetsKilledWhen5GhzDisabled(com.automatics.device.Device@1ad20a8a) =============================================== MyTest Tests run: 1, Failures: 0, Skips: 0 =============================================== [INFO][2024-12-20 16:37:13,049][[com.automatics.executor.Starter.main()] - Finished testing class: org.testng.TestRunner [INFO][2024-12-20 16:37:13,050][[com.automatics.executor.Starter.main()] - >>>[AFTER-SUITE]: Performing after suite cleanup [INFO][2024-12-20 16:37:13,050][[com.automatics.executor.Starter.main()] - Bean testInitializer is not configured. [INFO][2024-12-20 16:37:13,050][[com.automatics.executor.Starter.main()] - >>>[AFTER-SUITE]: Locked devices after suite execution 1 [INFO][2024-12-20 16:37:13,050][[com.automatics.executor.Starter.main()] - Value of intial testType : QUICK [INFO][2024-12-20 16:37:13,051][[com.automatics.executor.Starter.main()] - Value of TestType provided by job : GROUP_OR_AUTOID [INFO][2024-12-20 16:37:13,051][[com.automatics.executor.Starter.main()] - >>>[AFTER-SUITE]: Verifying if build changed after test [INFO][2024-12-20 16:37:13,051][[com.automatics.executor.Starter.main()] - Skipping build change verification as partner specific initialization is not configured. [INFO][2024-12-20 16:37:13,051][[com.automatics.executor.Starter.main()] - >>>[AFTER-SUITE]: Build Change Status: NO_CHANGE [INFO][2024-12-20 16:37:13,051][[com.automatics.executor.Starter.main()] - Is trace required for connected gateway: false [ERROR][2024-12-20 16:37:13,051][[PollingThread_26_(D8:3A:DD:13:8C:13)] - Sleep interrupted sleep interrupted [INFO][2024-12-20 16:37:13,053][[com.automatics.executor.Starter.main()] - Connection instance is Null [INFO][2024-12-20 16:37:13,053][[com.automatics.executor.Starter.main()] - Connection instance is Null [INFO][2024-12-20 16:37:13,053][[com.automatics.executor.Starter.main()] - Is trace required for connected gateway: false [INFO][2024-12-20 16:37:13,053][[com.automatics.executor.Starter.main()] - Skipping parter specific after suite clean up as it is not configured. [ERROR][2024-12-20 16:37:13,053][[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:820) at com.automatics.providers.trace.AbstractTraceProviderImpl.connectAndRead(AbstractTraceProviderImpl.java:734) at com.automatics.providers.trace.AbstractTraceProviderImpl$ConnectionThread.run(AbstractTraceProviderImpl.java:1135) [INFO][2024-12-20 16:37:13,054][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Connection instance is Null [INFO][2024-12-20 16:37:13,054][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Connection instance is Null [INFO][2024-12-20 16:37:13,054][[ConnectionThread_21 (D8:3A:DD:13:8C:13)] - Exited from readOutputFromChannel method [INFO][2024-12-20 16:37:13,057][[com.automatics.executor.Starter.main()] - Releasing device D8:3A:DD:13:8C:13 Url Path: http://192.168.2.12:8080/DeviceManager/deviceManagement/device/release [INFO][2024-12-20 16:37:13,098][[com.automatics.executor.Starter.main()] - Response: {"status":"SUCCESS","mac":"D8:3A:DD:13:8C:13"} [INFO][2024-12-20 16:37:13,103][[com.automatics.executor.Starter.main()] - Releasing device 2C:44:FD:18:F9:FE Url Path: http://192.168.2.12:8080/DeviceManager/deviceManagement/device/release [INFO][2024-12-20 16:37:13,140][[com.automatics.executor.Starter.main()] - Response: {"status":"SUCCESS","mac":"2C:44:FD:18:F9:FE"} [INFO][2024-12-20 16:37:13,141][[com.automatics.executor.Starter.main()] - Successfully unlocked RDKB (D8:3A:DD:13:8C:13) mapped components - (WINDOWSVM) - 2C:44:FD:18:F9:FE [INFO][2024-12-20 16:37:13,141][[com.automatics.executor.Starter.main()] - SETTOP - D8:3A:DD:13:8C:13 RELEASED. [INFO][2024-12-20 16:37:13,142][[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":1734692122623,"completionTime":1734692833141,"JMD_ID":456,"updateRdkPortal":true,"result":{"build_name":"RPI-RDKB","type":"GROUP_OR_AUTOID ","tests":[]}} [INFO][2024-12-20 16:37:13,152][[com.automatics.executor.Starter.main()] - [ HTML LOG PARSER ] : line [INFO][2024-12-20 16:25:58,943][456][D8:3A:DD:13:8C:13|TestNG-PoolService-0|com.automatics.executor.AutomaticsTestListener:onTestStart:110] STARTED - testVerifyBandSteeringProcessGetsKilledWhen5GhzDisabled - com.automatics.device.Device@1ad20a8a [INFO][2024-12-20 16:37:13,152][[com.automatics.executor.Starter.main()] - [ HTML LOG PARSER ] : line [DEBUG][2024-12-20 16:25:58,943][456][D8:3A:DD:13:8C:13|TC-RDKB-WIFI-BAND-STEERING-1006 : D83ADD138C13|com.automatics.executor.AutomaticsTestListener:onTestStart:150] Started appending log =============================================== MySuite Total tests run: 1, Passes: 1, Failures: 0, Skips: 0 =============================================== [INFO][2024-12-20 16:37:13,236][[com.automatics.executor.Starter.main()] - Updating final execution status to Automatics [INFO][2024-12-20 16:37:13,237][[Thread-205] - ============= MESSAGE SEND TO AUTOMATICS ============== [INFO][2024-12-20 16:37:13,237][[Thread-205] - Tested build name : RPI-RDKB [INFO][2024-12-20 16:37:13,237][[Thread-205] - Final execution status : COMPLETED [INFO][2024-12-20 16:37:13,237][[Thread-205] - Final successful device list : ["D8:3A:DD:13:8C:13"] [INFO][2024-12-20 16:37:13,237][[Thread-205] - Job Id : 456 [INFO][2024-12-20 16:37:13,237][[Thread-205] - ============================================================== [INFO][2024-12-20 16:37:13,238][[Thread-205] - >>>[INIT]: Automatics JSON -> {"status":"COMPLETED","service":"","buildImageName":"RPI-RDKB","settopList":["D8:3A:DD:13:8C:13"],"startTime":1734692122623,"completionTime":1734692833141,"JMD_ID":456,"updateRdkPortal":true,"result":{"build_name":"RPI-RDKB","type":"GROUP_OR_AUTOID ","tests":[]}} [INFO][2024-12-20 16:37:13,238][[Thread-205] - http://192.168.2.59:8080/Automatics/executionResponse.htm [INFO][2024-12-20 16:39:13,396][[Thread-205] - HTTP STATUS LINE : HTTP/1.1 200 [INFO][2024-12-20 16:39:13,396][[Thread-205] - HTTP STATUS CODE : 200 [INFO][2024-12-20 16:39:13,397][[com.automatics.executor.Starter.main()] - ******** EXECUTION COMPLETED ********* [INFO] ------------------------------------------------------------------------ [INFO] BUILD SUCCESS [INFO] ------------------------------------------------------------------------ [INFO] Total time: 14:09 min [INFO] Finished at: 2024-12-20T16:39:13+05:30 [INFO] ------------------------------------------------------------------------ Inside Add Shutdown Hook [INFO][2024-12-20 16:39:13,404][[Thread-1] - Bean testInitializer is not configured. [INFO][2024-12-20 16:39:13,405][[Thread-1] - Closing partner application context [INFO][2024-12-20 16:39:13,407][[Thread-1] - Closing core application context [JOB1] $ /bin/sh -xe /tmp/jenkins4132989565714922895.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