Mainline OpenWrt on a Wemo® Insight Smart Plug

2020-05-31

The firmware this smart plug (model number: F7C029de) runs doesn’t seem to be particularly stable and the software base seems very dated. Let’s try running our own firmware for fun and profit.

This article has been updated 2020-06-10, 2020-06-21 and 2020-07-24.

Hardware

The F7C029de smart plug contains three PCBs:

  1. The power board holds the relay, isolation and a power supply for the logic board.
  2. The power sensor board contains a chip similar (but not identical) to the 78M6610+PSU (datasheet) Energy Measurement Processor for Single-Phase Power-Supply Units and a few passive components. The board is soldered onto the power board.
  3. The logic board features a Ralink (Mediatek) RT5350F (datasheet) WiFi SoC with a 360 MHz MIPS24KEc CPU core and a IEEE 802.11n 1T1R peripheral. In addition, there is a MX25L12835F (datasheet) 16 MiB serial NOR flash and a W9825G6KH (datasheet) 32 MiB SDRAM as well as some LEDs, a tactile button, some voltage regulators and a USB micro AB receptacle.
Power board with power sensor board soldered on
Power board with power sensor board soldered on
Logic board
Logic board

J15 Connector pinout

  1. Relay signal (3.3V level output)
  2. GND
  3. 5V
  4. 5V
  5. GND
  6. ?
  7. UART from power sensor (3.3V level input)
  8. 3.3V

Pin 1 is marked with a little dot on the silk screen. It’s located on the right-hand side in the above photo of the board.

The logic board can be powered via the USB receptacle J11 (5V). The 3.3V rail is generated on the logic board.

Serial console

A serial console is available via test pads. It’s somewhat difficult to solder to the pads because they can be quite oxidized. I lifted a pad and decided to solder to the resistor pads instead. The voltage level is 3.3V and the default configuration is 57600 baud 8N1.

Bootloader

The board uses a modified u-boot version from the Ralink SDK v3.5.0.0. This is the u-boot console log:

U-Boot 1.1.3 (May  4 2015 - 18:32:38)

Board: Ralink APSoC DRAM:  32 MB
relocate_code Pointer at: 81fb4000
spi_wait_nsec: 21 
spi device id: c2 20 18 c2 20 (2018c220)
find flash: MX25L12805D
raspi_read: from:30000 len:1000 
.raspi_read: from:30000 len:1000 
.============================================ 
Ralink UBoot Version: 3.5.0.0
-------------------------------------------- 
ASIC 5350_MP (Port5<->None)
DRAM_CONF_FROM: Boot-Strapping 
DRAM_TYPE: SDRAM 
DRAM_SIZE: 256 Mbits
DRAM_WIDTH: 16 bits
DRAM_TOTAL_WIDTH: 16 bits
TOTAL_MEMORY_SIZE: 32 MBytes
Flash component: SPI Flash
Date:May  4 2015  Time:18:32:38
============================================ 
icache: sets:256, ways:4, linesz:32 ,total:32768
dcache: sets:128, ways:4, linesz:32 ,total:16384 

    ##### The CPU freq = 360 MHZ #### 
    estimate memory size =32 Mbytes
    #### u-boot for Insight  2013.05.10 ####
set GPIO 0, 1, 2, 18, 19 to 1 Output
set GPIO 17, 20 to 0 Iutput

Please choose the operation: 
    1: Load system code to SDRAM via TFTP. 
    2: Load system code then write to Flash via TFTP. 
    3: Boot system code via Flash (default).
    4: Entr boot command line interface.
    7: Load Boot Loader code then write to Flash via Serial. 
    9: Load Boot Loader code then write to Flash via TFTP. 
    0 
    
3: System Boot system code via Flash.
Trying to boot from B...bootstate=[2]
Boot B addr_str=[0xBC7C0000]
## Booting image at bc7c0000 ...
raspi_read: from:7c0000 len:40 
.   Image Name:   MIPS OpenWrt Linux-2.6.21
    Created:      2017-02-13  14:26:50 UTC
    Image Type:   MIPS Linux Kernel Image (lzma compressed)
    Data Size:    876413 Bytes = 855.9 kB
    Load Address: 80000000
    Entry Point:  80274000
raspi_read: from:7c0040 len:d5f7d 
..............   Verifying Checksum ... OK
    Uncompressing Kernel Image ... OK
No initrd
## Transferring control to Linux (at address 80274000) ...
## Giving linux memsize in MB, 32

Starting kernel ...

The interactive shell can be entered by pressing and holding the 4 key while powering up the board. These are the available commands:

RT5350 # help
?       - alias for 'help'
bootm   - boot application image from memory
cp      - memory copy
erase   - erase SPI FLASH memory
flash_test - test flash status, argv => test_pattern_start test_pattern_end test_repeat
go      - start application at address 'addr'
help    - print online help
loadb   - load binary file over serial line (kermit mode)
md      - memory display
mdio   - Ralink PHY register R/W command !!
mm      - memory modify (auto-incrementing)
mw      - memory write (fill)
nm      - memory modify (constant address)
printenv- print environment variables
reset   - Perform RESET of the CPU
rf      - read/write rf register
saveenv - save environment variables to persistent storage
setenv  - set environment variables
tftpboot- boot image via network using TFTP protocol
version - print monitor version

The stock environment looks like this:

RT5350 # printenv
bootcmd=tftp
bootdelay=1
baudrate=57600
ethaddr="00:AA:BB:CC:DD:10"
ramargs=setenv bootargs root=/dev/ram rw
addip=setenv bootargs $(bootargs) ip=$(ipaddr):$(serverip):$(gatewayip):$(netmask):$(hostname):$(netdev):off
addmisc=setenv bootargs $(bootargs) console=ttyS0,$(baudrate) ethaddr=$(ethaddr) panic=1
flash_self=run ramargs addip addmisc;bootm $(kernel_addr) $(ramdisk_addr)
kernel_addr=BFC40000
u-boot=u-boot.bin
load=tftp 8A100000 $(u-boot)
u_b=protect off 1:0-1;era 1:0-1;cp.b 8A100000 BC400000 $(filesize)
loadfs=tftp 8A100000 root.cramfs
u_fs=era bc540000 bc83ffff;cp.b 8A100000 BC540000 $(filesize)
test_tftp=tftp 8A100000 root.cramfs;run test_tftp
ethact=Eth0 (10/100-M)
SerialNumber=221510K1200BCF
filesize=5c3205
fileaddr=80800000
ipaddr=10.22.22.1
serverip=10.22.22.2
autostart=no
bootfile=Insight_Test_FW_v1.1.bin
bootpart=1
bootargs=console=ttyS1,57600n8 root=/dev/mtdblock4
bootstate=2
check_boot=0
stdin=serial
stdout=serial
stderr=serial

Environment size: 959/4092 bytes

The bootm command is modified and doesn’t behave like it does in upstream u-boot. It’s behaviour is dependent on the value of the bootstate environment variable. If bootstate=0, the bootm command behaves normally—at least if only one argument (the address) is passed to it.

Unfortunately, it doesn’t seem possible to change the baud rate to anything faster than 57600 baud. This means that serial downloads take a while.

Stock OS

This is the console log of the Linux OS after the settings had been restored to the factory defaults. After the device had been powered up, it was connected to a WiFi network.

LINUX started...

    THIS IS ASIC
Linux version 2.6.21 (sulfur@irv-wemo-embed) (gcc version 4.3.3 (GCC) ) #1 Mon Feb 13 06:26:47 PST 2017

    The CPU frequency set to 360 MHz
CPU revision is: 0001964c
Determined physical RAM map:
    memory: 02000000 @ 00000000 (usable)
Initrd not found or empty - disabling initrd
Built 1 zonelists.  Total pages: 8128
Kernel command line: console=ttyS1,57600n8 root=/dev/mtdblock4
root_dev_setup: line=[/dev/mtdblock4]
Primary instruction cache 32kB, physically tagged, 4-way, linesize 32 bytes.
Primary data cache 16kB, 4-way, linesize 32 bytes.
Synthesized TLB refill handler (20 instructions).
Synthesized TLB load handler fastpath (32 instructions).
Synthesized TLB store handler fastpath (32 instructions).
Synthesized TLB modify handler fastpath (31 instructions).
Cache parity protection disabled
cause = 50808000, status = 11000000
PID hash table entries: 128 (order: 7, 512 bytes)
calculating r4koff... 0015f900(1440000)
CPU frequency 360.00 MHz
Using 180.000 MHz high precision timer.
Console: colour dummy device 80x25
Dentry cache hash table entries: 4096 (order: 2, 16384 bytes)
Inode-cache hash table entries: 2048 (order: 1, 8192 bytes)
Memory: 29736k/32768k available (2130k kernel code, 3032k reserved, 377k data, 124k init, 0k highmem)
Mount-cache hash table entries: 512
NET: Registered protocol family 16
SCSI subsystem initialized
usbcore: registered new interface driver usbfs
usbcore: registered new interface driver hub
usbcore: registered new device driver usb
Time: MIPS clocksource has been installed.
deice id : c2 20 18 c2 20 (2018c220)
MX25L12805D(c2 2018c220) (16384 Kbytes)
mtd .name = raspi, .size = 0x01000000 (16M) .erasesize = 0x00010000 (64K) .numeraseregions = 0
Creating 12 MTD partitions on "raspi":
0x00000000-0x00050000 : "uboot"
0x00050000-0x00190000 : "Kernel_1"
0x00190000-0x007c0000 : "rootfs_1"
0x007c0000-0x00900000 : "Kernel_2"
0x00900000-0x00f30000 : "rootfs_2"
mtd: partition "rootfs_2" set to be root filesystem
mtd: partition "rootfs_data" created automatically, ofs=C90000, len=2A0000 
0x00c90000-0x00f30000 : "rootfs_data"
0x00fe0000-0x00ff0000 : "nvram"
0x00ff0000-0x01000000 : "User_Factory"
0x00040000-0x00050000 : "Factory"
0x00f30000-0x00fd0000 : "Belkin_settings"
0x00030000-0x00040000 : "Uboot_env"
0x00050000-0x007c0000 : "Firmware_1"
0x007c0000-0x00f30000 : "Firmware_2"
NET: Registered protocol family 2
IP route cache hash table entries: 1024 (order: 0, 4096 bytes)
TCP established hash table entries: 1024 (order: 1, 8192 bytes)
TCP bind hash table entries: 1024 (order: 0, 4096 bytes)
TCP: Hash tables configured (established 1024 bind 1024)
TCP reno registered
RT3xxx EHCI/OHCI init.
squashfs: version 3.0 (2006/03/15) Phillip Lougher
Registering mini_fo version $Id$
NTFS driver 2.1.28 [Flags: R/O].
EFS: 1.0a - http://aeschi.ch.eu.org/efs/
JFFS2 version 2.2. (NAND) (C) 2001-2006 Red Hat, Inc.
io scheduler noop registered (default)
RALINK_REG_GPIOMODE = [0x004042D5]
    ################################################
    #                                              #
    #            SDK - BOARD_EVT                   #
    #                                              #
    ################################################
reg1_gpio_dir before = [0x002DFFFF]
reg1_gpio_dir after = [0x002DFFFF]
Ralink gpio driver initialized
Gemtek LED init...
GPIO_init: registered WeMoProc POWER_BUTTON
GPIO_init: registered WeMoProc POWER_RELAY
GPIO_init: registered WeMoProc RELAY_LED
GPIO_init: registered WeMoProc MIN_OUT_RATE
################## Don't Restore to Factory Defaults ###################
################## restoreValue= 0 ##################
Serial: 8250/16550 driver $Revision: 1.90 $ 2 ports, IRQ sharing disabled
serial8250: ttyS0 at I/O 0xb0000500 (irq = 37) is a 16550A
serial8250: ttyS1 at I/O 0xb0000c00 (irq = 12) is a 16550A
RAMDISK driver initialized: 16 RAM disks of 8192K size 1024 blocksize
loop: loaded (max 8 devices)
block2mtd: version $Revision: 1.30 $
rt3xxx-ehci rt3xxx-ehci: Ralink EHCI Host Controller
rt3xxx-ehci rt3xxx-ehci: new USB bus registered, assigned bus number 1
rt3xxx-ehci rt3xxx-ehci: irq 18, io mem 0x101c0000
rt3xxx-ehci rt3xxx-ehci: USB 0.0 started, EHCI 1.00, driver 10 Dec 2004
usb usb1: configuration #1 chosen from 1 choice
hub 1-0:1.0: USB hub found
hub 1-0:1.0: 1 port detected
rt3xxx-ohci rt3xxx-ohci: RT3xxx OHCI Controller
rt3xxx-ohci rt3xxx-ohci: new USB bus registered, assigned bus number 2
rt3xxx-ohci rt3xxx-ohci: irq 18, io mem 0x101c1000
usb usb2: configuration #1 chosen from 1 choice
hub 2-0:1.0: USB hub found
hub 2-0:1.0: 1 port detected
usbcore: registered new interface driver cdc_acm
drivers/usb/class/cdc-acm.c: v0.25:USB Abstract Control Model driver for USB modems and ISDN adapters
Initializing USB Mass Storage driver...
usbcore: registered new interface driver usb-storage
USB Mass Storage support registered.
TCP cubic registered
NET: Registered protocol family 1
NET: Registered protocol family 17
saved_root_name is [/dev/mtdblock4]
root_device_name is [/dev/mtdblock4]
name is [/dev/root]
fs_names is [squashfs]
fs_names p is [squashfs], flags is 0x8001
VFS: [/dev/root] Mounted root (squashfs filesystem) readonly.
mount_fail 0 is 0
Freeing unused kernel memory: 124k freed
Please be patient, while OpenWrt loads ...
- preinit -
- regular preinit -
switching to jffs2
mini_fo: using base directory: /
mini_fo: using storage directory: /overlay
- init -

(none) login: Jan  1 00:00:10 syslogd started: BusyBox v1.22.1
    
********************************************************************
    Copyright (c) 2013 by Belkin, Inc. All Rights Reserved.
    02/13/17 06:19:41
WeMo_WW_2.00.10966.PVT-OWRT-Insight
********************************************************************
nvram/1468/InitSharedMem: Ignoring CRC error (calculated 0x705fe70e, stored 0xffffffff)
nvram/1468/BuildIndex: BuildIndex: Removing garbage string '�����������������������������������������������������������nvram/1468/BuildIndex: 0 variables defined in NVRAM
nvram/1468/InitSharedMem: Returning 0
nvram/1470/NvramCommitCmd: Called
nvram/1471/NvramSetCmd: Set test_nvram=verified
nvram/1471/NvramSet: error - NVRAM full
nvram parition is corrupted reinitializing...
********************************************************************
nvram/1475/NvramResetCmd: Called
nvram/1475/BuildIndex: 0 variables defined in NVRAM
nvram/1475/NvramRestore: Returning 0
nvram/1475/NvramStartDaemon: Called
nvram/1475/NvramStartDaemon: Starting daemon
nvram/1478/NvramDaemon: NVRAM daemon starting - pid 1478
nvram/1478/NvramCommitInternal: Flushing cache to flash
nvram/1478/NvramCommitInternal: Flash write complete
nvram/1478/BuildIndex: 3 variables defined in NVRAM
nvram/1479/NvramSetCmd: Set test_nvram=verified
nvram/1479/NvramStartDaemon: Called
nvram/1479/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
##### nvram SerialNumber : 
##### nvram target_country : 
##### nvram country_code : 
##### nvram wl0_macaddr : 
##### nvram cwf_serial_number : 
##### nvram hwVersion : 
##### factory serial_number : 221710K12001FD
nvram/1497/NvramSetCmd: Set SerialNumber=221710K12001FD
nvram/1497/NvramStartDaemon: Called
##### factory target_country : de
nvram/1499/NvramSetCmd: Set target_country=de
nvram/1499/NvramStartDaemon: Called
##### factory country_code : 0
nvram/1501/NvramSetCmd: Set country_code=0
nvram/1501/NvramStartDaemon: Called
##### factory wl0_macaddr : 60:38:E0:1B:75:A4
nvram/1503/NvramSetCmd: Set wl0_macaddr=60:38:E0:1B:75:A4
nvram/1503/NvramStartDaemon: Called
##### factory cwf_serial_number : 221710K12001FD
nvram/1505/NvramSetCmd: Set cwf_serial_number=221710K12001FD
nvram/1505/NvramStartDaemon: Called
##### factory product.name : WeMo_insight
##### factory hwVersion : 1
nvram/1507/NvramSetCmd: Set hwVersion=1
nvram/1507/NvramStartDaemon: Called
##### WiFi setup for de
MAC_ADRH -- : 0x00000000
MAC_ADRL -- : 0x00000000
Ralink APSoC Ethernet Driver Initilization. v2.0  256 rx/tx descriptors allocated, mtu = 1500!
MAC_ADRH -- : 0x00006238
MAC_ADRL -- : 0xe01b75a4
PROC INIT OK!
nvram/1478/NvramCommitInternal: Flushing cache to flash

phy_tx_ring = 0x01b3d000, tx_ring = 0xa1b3d000

phy_rx_ring0 = 0x01b3e000, rx_ring0 = 0xa1b3e000
RT305x_ESW: Link down
nvram/1478/NvramCommitInternal: Flash write complete
nvram/1478/BuildIndex: 10 variables defined in NVRAM
rt2860v2_ap: module license 'unspecified' taints kernel.


=== pAd = c005c000, size = 925608 ===

<-- RTMPAllocAdapterBlock, Status=0
rdm_major = 253
Software Watchdog Timer: 0.07 initialized. soft_noboot=0 soft_margin=310 sec (nowayout= 0)
insightd sets custom speed on ttyS0. This is deprecated.
RX DESC a1b7b000  size = 2048
<-- RTMPAllocTxRxRingMemory, Status=0
Key2Str is Invalid key length(0) or Type(0)
Key3Str is Invalid key length(0) or Type(0)
Key4Str is Invalid key length(0) or Type(0)
2a:55:44:e4:05:1a:cb:eb:01:93:83:88:b2:c3:4f:8f:
50:b2:65:62:c1:a3:cb:f9:52:8e:b0:b1:79:c9:b6:97:

1. Phy Mode = 9
2. Phy Mode = 9
3. Phy Mode = 9
MCS Set = ff 00 00 00 01
SYNC - BBP R4 to 20MHz.l
SYNC - BBP R4 to 20MHz.l
SYNC - BBP R4 to 20MHz.l
SYNC - BBP R4 to 20MHz.l
SYNC - BBP R4 to 20MHz.l
SYNC - BBP R4 to 20MHz.l
SYNC - BBP R4 to 20MHz.l
SYNC - BBP R4 to 20MHz.l
SYNC - BBP R4 to 20MHz.l
SYNC - BBP R4 to 20MHz.l
SYNC - BBP R4 to 20MHz.l
@@@ ed_monitor_init : ===>
@@@ ed_monitor_init : <===
Main bssid = 60:38:e0:1b:75:a4
<==== rt28xx_init, Status=0
0x1300 = 00064320
@@@ APPeerBeaconAction : BssChannelAPCount=2, ed_ap_threshold=1,  go to ed_monitor_exit()!!
@@@ ed_monitor_exit : ===>
@@@ ed_monitor_exit : <===
nvram/1708/NvramSetCmd: Set wl0_currentChannel=11
nvram/1708/NvramStartDaemon: Called
nvram/1708/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
nvram/1478/NvramCommitInternal: Flushing cache to flash
nvram/1478/NvramCommitInternal: Flash write complete
nvram/1478/BuildIndex: 11 variables defined in NVRAM
thready: make_tname_key key now "0"
thready: Setting thread name to "main" (tid:715849728).
SetBelkinParameter - ParameterName = SysLogLevel , ParameterValue = 7
GetLock (1756): Initializing Robust mutex for syslog, et al
nvram/1756/NvramStartDaemon: Called
nvram/1756/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
nvram/1756/NvramStartDaemon: Called
nvram/1756/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
nvram/1478/NvramCommitInternal: Flushing cache to flash
nvram/1756/GetSemaphore: Timeout waiting NVRAM Semaphore owned by tid 1478.
GetLock (1755): Initializing Robust mutex for syslog, et al
nvram/1478/NvramCommitInternal: Flash write complete
nvram/1478/BuildIndex: 12 variables defined in NVRAM
nvram/1755/GetSemaphore: Timeout waiting NVRAM Semaphore owned by tid 1478.
nvram/1756/GetSemaphore: Got semaphore previously owned by pid -1.
nvram/1755/GetSemaphore: Got semaphore previously owned by pid 1478.
thready: make_tname_key key now "0"
thready: Setting thread name to "StartIpcUdsServer" (tid:715849728).
@@@ ed_monitor_init : ===>
@@@ ed_monitor_init : <===
@@@ APPeerBeaconAction : BssChannelAPCount=2, ed_ap_threshold=1,  go to ed_monitor_exit()!!
@@@ ed_monitor_exit : ===>
@@@ ed_monitor_exit : <===
SetBelkinParameter - ParameterName = FW_UPGRD_MemThr , ParameterValue = 5600
nvram/1756/NvramStartDaemon: Called
nvram/1756/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
SetBelkinParameter - ParameterName = import_pkey_name , ParameterValue = WeMoPubKey.asc
nvram/1756/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = settime_sec , ParameterValue = 
SetBelkinParameter - ParameterName = restore_state , ParameterValue = 0
nvram/1756/NvramStartDaemon: Called
nvram/1756/NvramStartDaemon: Called
nvram/1756/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
nvram/1478/NvramCommitInternal: Flushing cache to flash
thready: Setting thread name to "watchDogTask" (tid:724776224).
watchdog: Device or resource busy
nvram/1756/GetSemaphore: Timeout waiting NVRAM Semaphore owned by tid 1478.
nvram/1756/GetSemaphore: sem_timedwait failed - Interrupted system call
nvram/1478/NvramCommitInternal: Flash write complete
nvram/1478/BuildIndex: 15 variables defined in NVRAM
nvram/1756/GetSemaphore: Got semaphore previously owned by pid 1478.
SetBelkinParameter - ParameterName = NotificationFlag , ParameterValue = 0
nvram/1756/NvramStartDaemon: Called
nvram/1756/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
SetBelkinParameter - ParameterNamGPIO_write_proc: GPIO_PIN_NUM: 0x40000
e = NotificationGPIO_write_proc: GPIO_PIN_NUM: 0x40000 - 0x0
Flag , ParameterGPIO_write_proc: GPIO_PIN_NUM: 0x2
Value = 1
nvram/1756/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = WeMo_version , ParameterValue = 2.00.10966
nvram/1756/NvramStartDaemon: Called
MAC Address: 60:38:E0:1B:75:A4
PLUGIN_LED_GPIO_proc ledcount=5
[Set_SiteSurvey_Proc] g_SiteSurvey_SSID = 1
thready: Setting thread name to "PowerButtonTask" (tid:728970528).
thready: Setting thread name to "ButtonTaskMonitorThread" (tid:731067680).
thready: Setting thread name to "RelayControlTask" (tid:733164832).
thready: Setting thread name to "systemRestore" (tid:735261984).
@@@ ed_monitor_init : ===>
@@@ ed_monitor_init : <===
nvram/1478/NvramCommitInternal: Flushing cache to flash
[Set_SiteSurvey_Proc] g_SiteSurvey_SSID = 1
thready: Setting thread name to "RulesNtpTimeCheckTask" (tid:793982240).
nvram/1756/GetSemaphore: Timeout waiting NVRAM Semaphore owned by tid 1478.
nvram/1478/NvramCommitInternal: Flash write complete
nvram/1478/BuildIndex: 17 variables defined in NVRAM
nvram/1756/GetSemaphore: Got semaphore previously owned by pid 1478.
thready: Setting thread name to "sendRemoteAccessUpdateStatusThread" (tid:796079392).
thready: Setting thread name to "sendRemAccessUpdStatusThdMonitor" (tid:798176544).
thready: Setting thread name to "sendConfigChangeStatusThread" (tid:800273696).
thready: Setting thread name to "rcvSendstatusRspThread" (tid:802370848).
thready: Setting thread name to "ChildFDTask" (tid:722216224).
thready: Setting thread name to "ChildFDTask" (tid:724313376).
thready: Destructor freeing name "ChildFDTask".
thready: Setting thread name to "StartInsightTask" (tid:808662304).
SetBelkinParameter - ParameterName = PowerThreshold , ParameterValue = 8000
nvram/1830/NvramStartDaemon: Called
nvram/1830/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
SetBelkinParameter - ParameterName = PushToAppTime , ParameterValue = 2
nvram/1830/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = PushToCloudTime , ParameterValue = 60
nvram/1830/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = TodayONTime , ParameterValue = 0
nvram/1830/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = TodayONTimeTS , ParameterValue = 0
nvram/1830/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = TodaySBYTime , ParameterValue = 0
nvram/1830/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = TodaySBYTimeTS , ParameterValue = 0
nvram/1830/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = TodayDate , ParameterValue = 1
nvram/1830/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = WriteToFlashTime , ParameterValue = 1800
nvram/1830/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = Currency , ParameterValue = 1
nvram/1830/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = EnergyPerUnitCost , ParameterValue = 111
nvram/1830/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = EnergyPerUnitCostVersion , ParameterValue = 1
nvram/1830/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = DaysCount , ParameterValue = 0
nvram/1830/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = EventEnable , ParameterValue = 0
nvram/1830/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = EventDuration , ParameterValue = 1800
nvram/1830/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = StateLog , ParameterValue = 0
nvram/1830/NvramStartDaemon: Called
nvram/1756/NvramStartDaemon: Called
nvram/1756/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
nvram/1478/NvramCommitInternal: Flushing cache to flash
nvram/1478/NvramCommitInternal: Flash write complete
nvram/1478/BuildIndex: 33 variables defined in NVRAM
@@@ ed_status_read: pAd->false_cca_stat[15]=226,  pAd->false_cca_threshold=180 !!
@@@ ed_status_read: go to ed_monitor_exit()!!
@@@ ed_monitor_exit : ===>
@@@ ed_monitor_exit : <===
Rcv Wcid(1) AddBAReq
Start Seq = 0000000d
SetBelkinParameter - ParameterName = EnergyPerUnitCost , ParameterValue = 938
nvram/1818/NvramStartDaemon: Called
nvram/1818/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
SetBelkinParameter - ParameterName = Currency , ParameterValue = 19
nvram/1818/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = EnergyPerUnitCostVersion , ParameterValue = 2
nvram/1818/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = FriendlyName , ParameterValue = MyWemo
nvram/1820/NvramStartDaemon: Called
[Set_SiteSurvey_Proc] g_SiteSurvey_SSID = 1
nvram/1756/NvramStartDaemon: Called
nvram/1756/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
nvram/1756/NvramStartDaemon: Called
nvram/1756/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
nvram/1478/NvramCommitInternal: Flushing cache to flash
nvram/1478/NvramCommitInternal: Flash write complete
nvram/1478/BuildIndex: 34 variables defined in NVRAM
thready: Destructor freeing name "".
SetBelkinParameter - ParameterName = DstSupportFlag , ParameterValue = 1
nvram/1816/NvramStartDaemon: Called
nvram/1816/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
SetBelkinParameter - ParameterName = LastTimeZone , ParameterValue = 1.0
nvram/1816/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = DstSupportFlag , ParameterValue = 1
nvram/1756/NvramStartDaemon: Called
nvram/1756/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
nvram/1478/NvramCommitInternal: Flushing cache to flash
thready: Setting thread name to "StartPairAndRegisterThread" (tid:785593632).
nvram/1478/NvramCommitInternal: Flash write complete
nvram/1478/BuildIndex: 36 variables defined in NVRAM
[Set_SiteSurvey_Proc] g_SiteSurvey_SSID = 1
@@@ ed_monitor_init : ===>
@@@ ed_monitor_init : <===
ApCliSsid - SSID string = ApCliSsid=***REDACTED***
@@@ APPeerBeaconAction : BssChannelAPCount=3, ed_ap_threshold=1,  go to ed_monitor_exit()!!
@@@ ed_monitor_exit : ===>
@@@ ed_monitor_exit : <===
ApCliSsid - SSID string = ApCliSsid=***REDACTED***
Rcv Wcid(1) AddBAReq
Start Seq = 00000000
===>ERROR!!! CntlEnqueueForRecv: BlockAck Request frame length size = 44 incorrect
===>killall: udhcpc: no process killed
SetBelkinParameter - ParameterName = wan_netmask , ParameterValue = 0.0.0.0
nvram/1895/NvramStartDaemon: Called
nvram/1895/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
SetBelkinParameter - ParameterName = wan_ipaddr , ParameterValue = 0.0.0.0
nvram/1895/NvramStartDaemon: Called
is bootp packet! bootpFlag=0x0
is bootp packet! bootpFlag=0x0
UpdateWanDefaultGateway: line = 192.168.0.1

UpdateWanDefaultGateway: GATEWAY = 192.168.0.1

thready: Setting thread name to "resolveArpRequest" (tid:739456288).
Cached MAC Address = 60:38:E0:1B:75:A4 
GetWanDefaultGateway: GATEWAY = 192.168.0.1
thready: Setting thERROR!!! CntlEnqueueForRecv: BlockAck Request frame length size = 44 incorrect
read name to "ntpUpdateThread" (PLUGIN_LED_GPIO_proc ledcount=1
tid:812856608).
route: SIOCDELRT: No such process
SetBelkinParameter - ParameterName = SetupCompleteTS , ParameterValue = 1590521648
nvram/1895/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = ClientSSID , ParameterValue = ***REDACTED***
nvram/1895/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = ClientPass , ParameterValue = ***REDACTED***
190A
nvram/1895/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = ClientAuth , ParameterValue = WPA2PSK
nvram/1895/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = ClientEncryp , ParameterValue = AES
nvram/1895/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = APChannel , ParameterValue = 6
nvram/1895/NvramStartDaemon: Called
thready: Setting thread name to "ledTimerTask" (tid:814953760).
thready: Setting thread name to "checkInetConnectivity" (tid:817050912).
thready: Setting thread name to "InetMonitorTask" (tid:819148064).
killall: ntpclient: no process killed
nvram/1756/NvramStartDaemon: Called
nvram/1756/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
nvram/1478/NvramCommitInternal: Flushing cache to flash
thready: Destructor freeing name "RulesNtpTimeChec".
nvram/1478/NvramCommitInternal: Flash write complete
nvram/1478/BuildIndex: 44 variables defined in NVRAM
thready: Destructor freeing name "StartPairAndRegi".
thready: Setting thread name to "remoteRegThread" (tid:793982240).
5, flush one!
Rcv Wcid(1) AddBAReq
Start Seq = 00000000
ERROR!!! CntlEnqueueForRecv: BlockAck Request frame length size = 44 incorrect
43975 70450.069   81038.0     13.3  906097.8   1083.4         0
thready: Destructor freeing name "ntpUpdateThread".
thready: Destructor freeing name "".
thready: Destructor freeing name "".
thready: Destructor freeing name "".
thready: Destructor freeing name "".
GetWanDefaultGateway: GATEWAY = 192.168.0.1
thready: Destructor freeing name "resolveArpReques".
SetBelkinParameter - ParameterName = SetupCompleteTS , ParameterValue = 1590525250
nvram/1830/NvramStartDaemon: Called
nvram/1830/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
SetBelkinParameter - ParameterName = TodayDate , ParameterValue = 26
nvram/1830/NvramStartDaemon: Called
UpdateWanDefaultGateway: line = 192.168.0.1

UpdateWanDefaultGateway: GATEWAY = 192.168.0.1

thready: Setting thread name to "resolveArpRequest" (tid:739456288).
Cached MAC Address = 60:38:E0:1B:75:A4 
GetWanDefaultGateway: GATEWAY = 192.168.0.1
thready: Destructor freeing name "resolveArpReques".
thready: Destructor freeing name "StartInsightTask".
thready: Setting thread name to "InsightGPIOTask" (tid:739456288).
thready: Setting thread name to "InsightEventTask" (tid:766719264).
route: SIOCDELRT: No such process
nvram/1756/NvramStartDaemon: Called
nvram/1756/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
nvram/1478/NvramCommitInternal: Flushing cache to flash
thready: Setting thread name to "CtrlPtRediscoverTask" (tid:825439520).
nvram/1756/GetSemaphore: Timeout waiting NVRAM Semaphore owned by tid 1478.
nvram/1478/NvramCommitInternal: Flash write complete
nvram/1478/BuildIndex: 44 variables defined in NVRAM
nvram/1756/GetSemaphore: Got semaphore previously owned by pid 1478.
> POST /apis/http/plugin/registerPlugin HTTP/1.1
Host: api.xbcs.net:8443
Content-Type: application/xml
Accept: application/xml
Authorization: dummy
X-Belkin-Client-Type-Id: WeMo_WW_2.00.10966.PVT-OWRT-Insight:5e7e-40a7-8bf4-539d1dc2ce42
Content-Length: 817

< HTTP/1.1 200 OK
< Date: Tue, 26 May 2020 19:34:16 GMT
< Content-Type: application/xml;charset=UTF-8
< Content-Length: 1731
< Connection: keep-alive
< X-Wemo-Trace-Id: Self=1-5ecd6f38-133184cb518f2f9afce09827;Root=1-5ecd6f37-e5935bb00d13eb387d40d430
< X-Wemo-Host-Ip: 10.0.61.4
< X-Application-Context: application
< Status: 200 OK
< 
SetBelkinParameter - ParameterName = restore_state , ParameterValue = 0
SetBelkinParameter - ParameterName = home_id , ParameterValue = 27501
nvram/1971/NvramStartDaemon: Called
nvram/1971/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
SetBelkinParameter - ParameterName = SmartDeviceId , ParameterValue = df09fec6816459a7e06859671a89ebf90bd2472d
nvram/1971/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = plugin_key , ParameterValue = 545caab0-453c-47ef-8c41-fe628f9c3711
nvram/1971/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = PluginCloudId , ParameterValue = 427156
nvram/1971/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = RouterMac , ParameterValue = 5890435A35F4
nvram/1971/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = RouterSsid , ParameterValue = ***REDACTED***
nvram/1971/NvramStartDaemon: Called
nvram/1756/NvramStartDaemon: Called
nvram/1756/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
nvram/1478/NvramCommitInternal: Flushing cache to flash
thready: Destructor freeing name "remoteRegThread".
thready: Setting thread name to "remoteAccessInitThd" (tid:724313376).
nvram/2016/GetSemaphore: Timeout waiting NVRAM Semaphore owned by tid 1478.
nvram/1478/NvramCommitInternal: Flash write complete
nvram/1478/BuildIndex: 50 variables defined in NVRAM
nvram/2016/GetSemaphore: Got semaphore previously owned by pid 1478.
    22:34:19.236 os_core_unix.c  pjlib 1.8.10 for POSIX initialized
    22:34:19.238          pjlib  select() I/O Queue created (0x464814)
    22:34:19.240 tcprel0x4658e0  TURN client session created
    22:34:19.241 tcprel0x4658e0  Resolving 3.81.166.40 with DNS A
    22:34:19.241 tcprel0x4658e0  State changed Null --> Resolving
in turn_sock=0
    22:34:19.242 turn_wrapper.c  State Null --> Resolving
    22:34:19.243 tcprel0x4658e0  State changed Resolving --> Resolved
in turn_sock=0
    22:34:19.243 turn_wrapper.c  State Resolving --> Resolved
    22:34:19.244 tcprel0x4658e0  Connecting to 3.81.166.40:3478
    22:34:19.362 tcprel0x4658e0  TCP connected
conn type= TCP
    22:34:19.363 tcprel0x4658e0  State changed Resolved --> Allocating
in turn_sock=0
    22:34:19.363 turn_wrapper.c  State Resolved --> Allocating
    22:34:19.364 tcprel0x4658e0  TX 48 bytes STUN message to 3.81.166.40:3478:
--- begin STUN message ---
STUN Allocate request
    Hdr: length=28, magic=2112a442, tsx_id=000006db333ab105628c895d
    Attributes:
    REQUESTED-TRANSPORT: length=4, value=100663296 (0x6000000)
    SOFTWARE: length=13, value="pjnath-1.8.10"
--- end of STUN message ---

    22:34:19.365 stuntsx0x46978  STUN client transaction created
    22:34:19.366 stuntsx0x46978  STUN sending message (transmit count=8)
in func turn_on_send_pkt
dst addr=3.81.166.40 htons.port=3478 ntwk.port=38413
check  server_addr.sin_addr=3.81.166.40 .port=38413 
    22:34:19.484 tcprel0x4658e0  RX 140 bytes STUN message from 3.81.166.40:3478:
--- begin STUN message ---
STUN Allocate error response
    Hdr: length=120, magic=2112a442, tsx_id=000006db333ab105628c895d
    Attributes:
    ERROR-CODE: length=20, err_code=401, reason="Unauthorized"
    REALM: length=10, value="belkin.org"
    NONCE: length=48, value="5ecd7d4c0000000088b594dea928a930d11328d11b63179a"
    SOFTWARE: length=14, value="TurnServer 0.4"
    FINGERPRINT: length=4, value=1730986421 (0x672cc1b5)
--- end of STUN message ---

    22:34:19.486 tcprel0x4658e0  Retrying request with new authentication
    22:34:19.487 tcprel0x4658e0  TX 156 bytes STUN message to 3.81.166.40:3478:
--- begin STUN message ---
STUN Allocate request
    Hdr: length=136, magic=2112a442, tsx_id=000006db721da317628c895e
    Attributes:
    REQUESTED-TRANSPORT: length=4, value=100663296 (0x6000000)
    SOFTWARE: length=13, value="pjnath-1.8.10"
    USERNAME: length=12, value="6038E01B75A4"
    REALM: length=10, value="belkin.org"
    NONCE: length=48, value="5ecd7d4c0000000088b594dea928a930d11328d11b63179a"
    MESSAGE-INTEGRITY: length=20, data=509d5ffb90ea53e82c9ec50d41e7d4649882f971
--- end of STUN message ---

    22:34:19.488 stuntsx0x46998  STUN client transaction created
    22:34:19.489 stuntsx0x46998  STUN sending message (transmit count=8)
in func turn_on_send_pkt
dst addr=3.81.166.40 htons.port=3478 ntwk.port=38413
check  server_addr.sin_addr=3.81.166.40 .port=38413 
    22:34:19.654 tcprel0x4658e0  RX 104 bytes STUN message from 3.81.166.40:3478:
--- begin STUN message ---
STUN Allocate success response
    Hdr: length=84, magic=2112a442, tsx_id=000006db721da317628c895e
    Attributes:
    XOR-RELAYED-ADDRESS: length=8, IPv4 addr=10.0.90.108:36433
    LIFETIME: length=4, value=330 (0x14a)
    XOR-MAPPED-ADDRESS: length=8, IPv4 addr=109.108.210.20:4992
    SOFTWARE: length=14, value="TurnServer 0.4"
    MESSAGE-INTEGRITY: length=20, data=4548bfae89cc1b167b1274273024a431bc9ba150
    FINGERPRINT: length=4, value=735342363 (0x2bd46f1b)
--- end of STUN message ---

    22:34:19.654 tcprel0x4658e0  State changed Allocating --> Ready
in turn_sock=0
    22:34:19.655 turn_wrapper.c  State Allocating --> Ready
    22:34:21.493 stuntsx0x46978  STUN client transaction destroyed
    22:34:21.656 stuntsx0x46998  STUN client transaction destroyed
> POST /apis/http/dlr/peerAddresses HTTP/1.1
Host: api.xbcs.net:8443
Content-Type: application/xml
Accept: application/xml
Authorization: 6038E01B75A4:Esd56bmeHr3rUyERkY7Tu9XwDgI=:1590525761
X-Belkin-Client-Type-Id: WeMo_WW_2.00.10966.PVT-OWRT-Insight:5e7e-40a7-8bf4-539d1dc2ce42
Content-Length: 242

> POST /apis/http/plugin/sendNotification HTTP/1.1
Host: api.xbcs.net:8443
Content-Type: application/xml
Accept: application/xml
Authorization: 6038E01B75A4:Esd56bmeHr3rUyERkY7Tu9XwDgI=:1590525761
Log-Data: ;TimeZone: 1.00
X-Belkin-Client-Type-Id: WeMo_WW_2.00.10966.PVT-OWRT-Insight:5e7e-40a7-8bf4-539d1dc2ce42
Content-Length: 700

< HTTP/1.1 200 OK
< Date: Tue, 26 May 2020 19:34:23 GMT
< Content-Type: application/xml;charset=UTF-8
< Content-Length: 1263
< Connection: keep-alive
< X-Application-Context: application
< 
thready: Destructor freeing name "remoteAccessInit".
thready: Setting thread name to "remoteInitNatClient24" (tid:728507680).
< HTTP/1.1 200 OK
< Date: Tue, 26 May 2020 19:34:24 GMT
< Content-Type: application/xml;charset=UTF-8
< Content-Length: 122
< Connection: keep-alive
< X-Wemo-Trace-Id: Self=1-5ecd6f40-dd9e970078226fb068424290;Root=1-5ecd6f3f-54f5c65dc17661517a886917
< X-Wemo-Host-Ip: 10.0.60.12
< X-Application-Context: application
< Status: 200 OK
< 
> POST /apis/http/plugin/insight/sendInsightParams HTTP/1.1
Host: api.xbcs.net:8443
Content-Type: application/xml
Accept: application/xml
Authorization: 6038E01B75A4:B2wW5GY2ZL88Mqelj/4ALXoXETI=:1590525763
Log-Data: ;TimeZone: 1.00
X-Belkin-Client-Type-Id: WeMo_WW_2.00.10966.PVT-OWRT-Insight:5e7e-40a7-8bf4-539d1dc2ce42
Content-Length: 215

< HTTP/1.1 200 OK
< Date: Tue, 26 May 2020 19:34:24 GMT
< Content-Type: application/xml;charset=UTF-8
< Content-Length: 217
< Connection: keep-alive
< X-Wemo-Trace-Id: Self=1-5ecd6f40-fa93867e526434d0038244f4;Root=1-5ecd6f40-777b363a28282e633f30645f
< X-Wemo-Host-Ip: 10.0.61.14
< X-Application-Context: application
< Status: 200 OK
< 
> POST /apis/http/plugin/insight/insightNotification HTTP/1.1
Host: api.xbcs.net:8443
Content-Type: application/xml
Accept: application/xml
Authorization: 6038E01B75A4:B2wW5GY2ZL88Mqelj/4ALXoXETI=:1590525763
Log-Data: ;TimeZone: 1.00
X-Belkin-Client-Type-Id: WeMo_WW_2.00.10966.PVT-OWRT-Insight:5e7e-40a7-8bf4-539d1dc2ce42
Content-Length: 500

< HTTP/1.1 200 OK
< Date: Tue, 26 May 2020 19:34:24 GMT
< Content-Type: application/xml;charset=UTF-8
< Content-Length: 231
< Connection: keep-alive
< X-Wemo-Trace-Id: Self=1-5ecd6f40-a3835638d1b7d30251872eda;Root=1-5ecd6f40-fa70c78904a986ac653f8698
< X-Wemo-Host-Ip: 10.0.63.5
< X-Application-Context: application
< Status: 200 OK
< 
    22:34:24.539 tcprel0x4658e0  RX 92 bytes STUN message from 3.81.166.40:3478:
--- begin STUN message ---
STUN ConnectionAttempt indication
    Hdr: length=72, magic=2112a442, tsx_id=6626f89fbc9e8826f42d1d7c
    Attributes:
    SOFTWARE: length=14, value="TurnServer 0.4"
    CONNECTION-ID: length=4, value=4038643033 (0xf0b8cd59)
    XOR-PEER-ADDRESS: length=8, IPv4 addr=10.0.61.4:39424
    MESSAGE-INTEGRITY: length=20, data=41a394d95d2a81547bbd02971acfa11ef9f75a5d
    FINGERPRINT: length=4, value=1860324126 (0x6ee24b1e)
--- end of STUN message ---

    22:34:24.540 tcprel0x4658e0  Received PJ_STUN_CONNECTION_ATTEMPT_INDICATION indication
    22:34:24.542 tcprel0x4658e0  TX 156 bytes STUN message to 3.81.166.40:3478:
--- begin STUN message ---
STUN ConnectionBind request
    Hdr: length=136, magic=2112a442, tsx_id=000006db2d1d5ae9628c895f
    Attributes:
    CONNECTION-ID: length=4, value=4038643033 (0xf0b8cd59)
    SOFTWARE: length=13, value="pjnath-1.8.10"
    USERNAME: length=12, value="6038E01B75A4"
    REALM: length=10, value="belkin.org"
    NONCE: length=48, value="5ecd7d4c0000000088b594dea928a930d11328d11b63179a"
    MESSAGE-INTEGRITY: length=20, data=7244b883dfd0513386a8b895f61eea5160033205
--- end of STUN message ---

    22:34:24.543 stuntsx0x4abb9  STUN client transaction created
    22:34:24.544 stuntsx0x4abb9  STUN sending message (transmit count=8)
in func turn_on_send_pkt
dst addr=3.81.166.40 htons.port=3478 ntwk.port=38413
check  server_addr.sin_addr=3.81.166.40 .port=38413 
data sock fd=10 data_port=0
data_port aftr htons=0
turn_sock->data_sock while setting =10
*********************
this shud print only for CONN BIND
*********************
sending 156 bytes of data to turn server
after senddata status=156

data_channel_recv thread spawned for handling data being received for data_sock=10 successfully
    22:34:24.667 tcprel0x4658e0  Leaving Received PJ_STUN_CONNECTION_ATTEMPT_INDICATION indication condition
    22:34:24.668 tcprel0x4658e0  Received Data indication with missing attributes

data_channel_recv entry for data_sock = 10
waiting to recv the message header
Received 80 Bytes
this is a response -> method in resp=11
waiting to recv the message header
Received 248 Bytes
hdr recv, msg_type=feed len=240
Copied 240 bytes from recv_data to payload_buffer
in data_channel_recv thread before invoking application handler 22:34:24.907 turn_wrapper.c  ***Client received 240 bytes data*** actual data_sock=10
waiting to recv the message header
hdr recv failure, going out of loop=10 setting nodatarcv 
data_channel_recv exit
thready: Destructor freeing name "".
PLUGIN_LED_GPIO_proc ledcount=4
thready: Destructor freeing name "ledTimerTask".
> POST /apis/http/dlr/peerLocalAddress HTTP/1.1
Host: api.xbcs.net:8443
Content-Type: application/xml
Accept: application/xml
Authorization: 6038E01B75A4:ruo3rmWRj/FVJlYZi0wXI3X+MUU=:1590525782
X-Belkin-Client-Type-Id: WeMo_WW_2.00.10966.PVT-OWRT-Insight:5e7e-40a7-8bf4-539d1dc2ce42
Content-Length: 275

< HTTP/1.1 200 OK
< Date: Tue, 26 May 2020 19:34:44 GMT
< Content-Type: application/xml;charset=UTF-8
< Content-Length: 466
< Connection: keep-alive
< X-Application-Context: application
< 
thready: Destructor freeing name "".
    22:35:04.553 stuntsx0x4abb9  STUN timeout waiting for response
    22:35:04.553 tcprel0x4658e0  Unexpected STUN 11 response
    22:35:06.557 stuntsx0x4abb9  STUN client transaction destroyed
    22:35:28.804 tcprel0x4658e0  RX 92 bytes STUN message from 3.81.166.40:3478:
--- begin STUN message ---
STUN ConnectionAttempt indication
    Hdr: length=72, magic=2112a442, tsx_id=a08b2c51643bdb760916a129
    Attributes:
    SOFTWARE: length=14, value="TurnServer 0.4"
    CONNECTION-ID: length=4, value=4092930162 (0xf3f52872)
    XOR-PEER-ADDRESS: length=8, IPv4 addr=10.0.63.5:40398
    MESSAGE-INTEGRITY: length=20, data=9b3527ffd1f89b9cba2605ea92ea2cabcb2af336
    FINGERPRINT: length=4, value=1701134437 (0x65654065)
--- end of STUN message ---

    22:35:28.804 tcprel0x4658e0  Received PJ_STUN_CONNECTION_ATTEMPT_INDICATION indication
    22:35:28.806 tcprel0x4658e0  TX 156 bytes STUN message to 3.81.166.40:3478:
--- begin STUN message ---
STUN ConnectionBind request
    Hdr: length=136, magic=2112a442, tsx_id=000006db6763845e628c8960
    Attributes:
    CONNECTION-ID: length=4, value=4092930162 (0xf3f52872)
    SOFTWARE: length=13, value="pjnath-1.8.10"
    USERNAME: length=12, value="6038E01B75A4"
    REALM: length=10, value="belkin.org"
    NONCE: length=48, value="5ecd7d4c0000000088b594dea928a930d11328d11b63179a"
    MESSAGE-INTEGRITY: length=20, data=cc20886d4eeb9f0dae1ac29c3430cd501c58f309
--- end of STUN message ---

    22:35:28.806 stuntsx0x4abb9  STUN client transaction created
    22:35:28.807 stuntsx0x4abb9  STUN sending message (transmit count=8)
in func turn_on_send_pkt
dst addr=3.81.166.40 htons.port=3478 ntwk.port=38413
check  server_addr.sin_addr=3.81.166.40 .port=38413 
data sock fd=10 data_port=0
data_port aftr htons=0
turn_sock->data_sock while setting =10
*********************
this shud print only for CONN BIND
*********************
sending 156 bytes of data to turn server
after senddata status=156

data_channel_recv thread spawned for handling data being received for data_sock=10 successfully
    22:35:28.921 tcprel0x4658e0  Leaving Received PJ_STUN_CONNECTION_ATTEMPT_INDICATION indication condition
    22:35:28.922 tcprel0x4658e0  Received Data indicaGPIO_write_proc: GPIO_PIN_NUM: 0x40000
tion with missinGPIO_write_proc: GPIO_PIN_NUM: 0x40000 - 0x1
g attributes

data_channel_recGPIO_write_proc: GPIO_PIN_NUM: 0x2
v entry for data_sock = 10
waiting to recv the message header
Received 80 Bytes
this is a response -> method in resp=11
waiting to recv the message header
Received 328 Bytes
hdr recv, msg_type=feed len=320
Copied 320 bytes from recv_data to payload_buffer
in data_channel_recv thread before invoking application handler 22:35:29.146 turn_wrapper.c  ***Client received 320 bytes data*** actual data_sock=10
waiting to recv the message header
hdr recv failure, going out of loop=10 setting nodatarcv 
data_channel_recv exit
thready: Destructor freeing name "".
    22:35:31.791 tcprel0x4658e0  RX 92 bytes STUN message from 3.81.166.40:3478:
--- begin STUN message ---
STUN ConnectionAttempt indication
    Hdr: length=72, magic=2112a442, tsx_id=2f90c81ccd3df1139e16ab7f
    Attributes:
    SOFTWARE: length=14, value="TurnServer 0.4"
    CONNECTION-ID: length=4, value=253717270 (0xf1f6b16)
    XOR-PEER-ADDRESS: length=8, IPv4 addr=10.0.60.12:43746
    MESSAGE-INTEGRITY: length=20, data=655ab60362587dd79fa1272f7c821024f10451cd
    FINGERPRINT: length=4, value=2476244466 (0x93987df2)
--- end of STUN message ---

    22:35:31.792 tcprel0x4658e0  Received PJ_STUN_CONNECTION_ATTEMPT_INDICATION indication
    22:35:31.794 tcprel0x4658e0  TX 156 bytes STUN message to 3.81.166.40:3478:
--- begin STUN message ---
STUN ConnectionBind request
    Hdr: length=136, magic=2112a442, tsx_id=000006db75a2a8d4628c8961
    Attributes:
    CONNECTION-ID: length=4, value=253717270 (0xf1f6b16)
    SOFTWARE: length=13, value="pjnath-1.8.10"
    USERNAME: length=12, value="6038E01B75A4"
    REALM: length=10, value="belkin.org"
    NONCE: length=48, value="5ecd7d4c0000000088b594dea928a930d11328d11b63179a"
    MESSAGE-INTEGRITY: length=20, data=93c8100dcafcbe5753dbab46c307517565671ad6
--- end of STUN message ---

    22:35:31.794 stuntsx0x485ba  STUN client transaction created
    22:35:31.795 stuntsx0x485ba  STUN sending message (transmit count=8)
in func turn_on_send_pkt
dst addr=3.81.166.40 htons.port=3478 ntwk.port=38413
check  server_addr.sin_addr=3.81.166.40 .port=38413 
data sock fd=10 data_port=0
data_port aftr htons=0
turn_sock->data_sock while setting =10
*********************
this shud print only for CONN BIND
*********************
sending 156 bytes of data to turn server
after senddata status=156

data_channel_recv thread spawned for handling data being received for data_sock=10 successfully
    22:35:31.914 tcprel0x4658e0  Leaving Received PJ_STUN_CONNECTION_ATTEMPT_INDICATION indication condition
    22:35:31.914 tcprel0x4658e0  Received Data indication with missing attributes

data_channel_recv entry for data_sock = 10
waiting to recv the message header
Received 80 Bytes
this is a response -> method in resp=11
waiting to recv the message header
Received 200 Bytes
hdr recv, msg_type=feed len=192
Copied 192 bytes from recv_data to payload_buffer
in data_channel_recv thread before invoking application handler 22:35:32.147 turn_wrapper.c  ***Client received 192 bytes data*** actual data_sock=10
Cached MAC Address = 60:38:E0:1B:75:A4 
SetBelkinParameter - ParameterName = PushToCloudTime , ParameterValue = 6
nvram/1829/NvramStartDaemon: Called
nvram/1829/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
waiting to recv the message header
hdr recv failure, going out of loop=10 setting nodatarcv 
data_channel_recv exit
thready: Destructor freeing name "".
> POST /apis/http/plugin/sendNotification HTTP/1.1
Host: api.xbcs.net:8443
Content-Type: application/xml
Accept: application/xml
Authorization: 6038E01B75A4:2k4cfwIO0t/WFo/mfN7qif20j6g=:1590525834
Log-Data: Actuation: Manual - mobile App;Remote: 1;TimeZone: 1.00
X-Belkin-Client-Type-Id: WeMo_WW_2.00.10966.PVT-OWRT-Insight:5e7e-40a7-8bf4-539d1dc2ce42
Content-Length: 709

nvram/1478/NvramCommitInternal: Flushing cache to flash
< HTTP/1.1 200 OK
< Date: Tue, 26 May 2020 19:35:36 GMT
< Content-Type: application/xml;charset=UTF-8
< Content-Length: 122
< Connection: keep-alive
< X-Wemo-Trace-Id: Self=1-5ecd6f88-fb92418929b59ce2d6ab1a51;Root=1-5ecd6f87-710a28a8068d6f7043ab7d80
< X-Wemo-Host-Ip: 10.0.60.12
< X-Application-Context: application
< Status: 200 OK
< 
nvram/1822/GetSemaphore: Timeout waiting NVRAM Semaphore owned by tid 1478.
nvram/1478/NvramCommitInternal: Flash write complete
nvram/1478/BuildIndex: 50 variables defined in NVRAM
nvram/1822/GetSemaphore: Got semaphore previously owned by pid 1478.
> POST /apis/http/plugin/insight/insightNotification HTTP/1.1
Host: api.xbcs.net:8443
Content-Type: application/xml
Accept: application/xml
Authorization: 6038E01B75A4:gWnZzirp+l+K/tkYRDxVk2mTV2Q=:1590525835
Log-Data: ;TimeZone: 1.00
X-Belkin-Client-Type-Id: WeMo_WW_2.00.10966.PVT-OWRT-Insight:5e7e-40a7-8bf4-539d1dc2ce42
Content-Length: 500

< HTTP/1.1 200 OK
< Date: Tue, 26 May 2020 19:35:37 GMT
< Content-Type: application/xml;charset=UTF-8
< Content-Length: 231
< Connection: keep-alive
< X-Wemo-Trace-Id: Self=1-5ecd6f89-34aa10c07c938d5030b41ce0;Root=1-5ecd6f88-e3ab19e8cb3735a8a578f1c8
< X-Wemo-Host-Ip: 10.0.63.5
< X-Application-Context: application
< Status: 200 OK
< 
> POST /apis/http/plugin/insight/insightNotification HTTP/1.1
Host: api.xbcs.net:8443
Content-Type: application/xml
Accept: application/xml
Authorization: 6038E01B75A4:F2LpOXIcP5g6axCwCvmTRhIA0bo=:1590525866
Log-Data: ;TimeZone: 1.00
X-Belkin-Client-Type-Id: WeMo_WW_2.00.10966.PVT-OWRT-Insight:5e7e-40a7-8bf4-539d1dc2ce42
Content-Length: 501

< HTTP/1.1 200 OK
< Date: Tue, 26 May 2020 19:36:07 GMT
< Content-Type: application/xml;charset=UTF-8
< Content-Length: 231
< Connection: keep-alive
< X-Wemo-Trace-Id: Self=1-5ecd6fa7-ce16218f7ea03a8f3e91e098;Root=1-5ecd6fa7-60ed0da0a212750859771d50
< X-Wemo-Host-Ip: 10.0.63.5
< X-Application-Context: application
< Status: 200 OK
< 
> POST /apis/http/plugin/insight/insightNotification HTTP/1.1
Host: api.xbcs.net:8443
Content-Type: application/xml
Accept: application/xml
Authorization: 6038E01B75A4:F2LpOXIcP5g6axCwCvmTRhIA0bo=:1590525866
Log-Data: ;TimeZone: 1.00
X-Belkin-Client-Type-Id: WeMo_WW_2.00.10966.PVT-OWRT-Insight:5e7e-40a7-8bf4-539d1dc2ce42
Content-Length: 501

< HTTP/1.1 200 OK
< Date: Tue, 26 May 2020 19:36:08 GMT
< Content-Type: application/xml;charset=UTF-8
< Content-Length: 231
< Connection: keep-alive
< X-Wemo-Trace-Id: Self=1-5ecd6fa8-e4d58bd45ec1a8d86a38d842;Root=1-5ecd6fa7-4115cd90a2bf44c03654f020
< X-Wemo-Host-Ip: 10.0.60.12
< X-Application-Context: application
< Status: 200 OK
< 
    22:36:08.808 stuntsx0x4abb9  STUN timeout waiting for response
    22:36:08.809 tcprel0x4658e0  Unexpected STUN 11 response
    22:36:10.813 stuntsx0x4abb9  STUN client transaction destroyed
    22:36:11.050 tcprel0x4658e0  RX 92 bytes STUN message from 3.81.166.40:3478:
--- begin STUN message ---
STUN ConnectionAttempt indication
    Hdr: length=72, magic=2112a442, tsx_id=7fd22776b8a6778a5281ef16
    Attributes:
    SOFTWARE: length=14, value="TurnServer 0.4"
    CONNECTION-ID: length=4, value=1859721256 (0x6ed91828)
    XOR-PEER-ADDRESS: length=8, IPv4 addr=10.0.61.4:40558
    MESSAGE-INTEGRITY: length=20, data=2b9f962446a441ac5daa1d7ba7ad851ba49d66ac
    FINGERPRINT: length=4, value=2577094097 (0x999b55d1)
--- end of STUN message ---

    22:36:11.051 tcprel0x4658e0  Received PJ_STUN_CONNECTION_ATTEMPT_INDICATION indication
    22:36:11.052 tcprel0x4658e0  TX 156 bytes STUN message to 3.81.166.40:3478:
--- begin STUN message ---
STUN ConnectionBind request
    Hdr: length=136, magic=2112a442, tsx_id=000006db08edbdab628c8962
    Attributes:
    CONNECTION-ID: length=4, value=1859721256 (0x6ed91828)
    SOFTWARE: length=13, value="pjnath-1.8.10"
    USERNAME: length=12, value="6038E01B75A4"
    REALM: length=10, value="belkin.org"
    NONCE: length=48, value="5ecd7d4c0000000088b594dea928a930d11328d11b63179a"
    MESSAGE-INTEGRITY: length=20, data=ef7aa999e18ed10fe8b8866a0cc7e8d7eba0847c
--- end of STUN message ---

    22:36:11.053 stuntsx0x49338  STUN client transaction created
    22:36:11.054 stuntsx0x49338  STUN sending message (transmit count=8)
in func turn_on_send_pkt
dst addr=3.81.166.40 htons.port=3478 ntwk.port=38413
check  server_addr.sin_addr=3.81.166.40 .port=38413 
data sock fd=10 data_port=0
data_port aftr htons=0
turn_sock->data_sock while setting =10
*********************
this shud print only for CONN BIND
*********************
sending 156 bytes of data to turn server
after senddata status=156

data_channel_recv thread spawned for handling data being received for data_sock=10 successfully
    22:36:11.182 tcprel0x4658e0  Leaving Received PJ_STUN_CONNECTION_ATTEMPT_INDICATION indication condition
    22:36:11.183 tcprel0x4658e0  Received Data indication with missing attributes

data_channel_recv entry for data_sock = 10
waiting to recv the message header
Received 80 Bytes
this is a resGPIO_write_proc: GPIO_PIN_NUM: 0x40000
ponse -> method GPIO_write_proc: GPIO_PIN_NUM: 0x40000 - 0x0
in resp=11
waitGPIO_write_proc: GPIO_PIN_NUM: 0x2
ing to recv the message header
Received 328 Bytes
hdr recv, msg_type=feed len=320
Copied 320 bytes from recv_data to payload_buffer
in data_channel_recv thread before invoking application handler 22:36:11.416 turn_wrapper.c  ***Client received 320 bytes data*** actual data_sock=10
waiting to recv the message header
hdr recv failure, going out of loop=10 setting nodatarcv 
data_channel_recv exit
thready: Destructor freeing name "".
    22:36:11.805 stuntsx0x485ba  STUN timeout waiting for response
    22:36:11.806 tcprel0x4658e0  Unexpected STUN 11 response
    22:36:13.809 stuntsx0x485ba  STUN client transaction destroyed
> POST /apis/http/plugin/sendNotification HTTP/1.1
Host: api.xbcs.net:8443
Content-Type: application/xml
Accept: application/xml
Authorization: 6038E01B75A4:n+DnWT/UFhtds7RrPs5fCJuYgzA=:1590525877
Log-Data: Actuation: Manual - mobile App;Remote: 1;TimeZone: 1.00
X-Belkin-Client-Type-Id: WeMo_WW_2.00.10966.PVT-OWRT-Insight:5e7e-40a7-8bf4-539d1dc2ce42
Content-Length: 709

< HTTP/1.1 200 OK
< Date: Tue, 26 May 2020 19:36:19 GMT
< Content-Type: application/xml;charset=UTF-8
< Content-Length: 122
< Connection: keep-alive
< X-Wemo-Trace-Id: Self=1-5ecd6fb3-2124d3b2bba21a967ddc1e50;Root=1-5ecd6fb2-6b0fa468221931e0682691a0
< X-Wemo-Host-Ip: 10.0.60.11
< X-Application-Context: application
< Status: 200 OK
< 
    22:36:31.837 tcprel0x4658e0  RX 92 bytes STUN message from 3.81.166.40:3478:
--- begin STUN message ---
STUN ConnectionAttempt indication
    Hdr: length=72, magic=2112a442, tsx_id=19be61a509d2f74d196c0474
    Attributes:
    SOFTWARE: length=14, value="TurnServer 0.4"
    CONNECTION-ID: length=4, value=966996554 (0x39a3324a)
    XOR-PEER-ADDRESS: length=8, IPv4 addr=10.0.61.14:44590
    MESSAGE-INTEGRITY: length=20, data=00998c796b19a313b11a55b49c17be8af993d1c2
    FINGERPRINT: length=4, value=252332036 (0xf0a4804)
--- end of STUN message ---

    22:36:31.838 tcprel0x4658e0  Received PJ_STUN_CONNECTION_ATTEMPT_INDICATION indication
    22:36:31.839 tcprel0x4658e0  TX 156 bytes STUN message to 3.81.166.40:3478:
--- begin STUN message ---
STUN ConnectionBind request
    Hdr: length=136, magic=2112a442, tsx_id=000006db79838cb2628c8963
    Attributes:
    CONNECTION-ID: length=4, value=966996554 (0x39a3324a)
    SOFTWARE: length=13, value="pjnath-1.8.10"
    USERNAME: length=12, value="6038E01B75A4"
    REALM: length=10, value="belkin.org"
    NONCE: length=48, value="5ecd7d4c0000000088b594dea928a930d11328d11b63179a"
    MESSAGE-INTEGRITY: length=20, data=3a582da1dd8084761cacf6b15ccdc618ae7f219d
--- end of STUN message ---

    22:36:31.840 stuntsx0x485ba  STUN client transaction created
    22:36:31.841 stuntsx0x485ba  STUN sending message (transmit count=8)
in func turn_on_send_pkt
dst addr=3.81.166.40 htons.port=3478 ntwk.port=38413
check  server_addr.sin_addr=3.81.166.40 .port=38413 
data sock fd=10 data_port=0
data_port aftr htons=0
turn_sock->data_sock while setting =10
*********************
this shud print only for CONN BIND
*********************
sending 156 bytes of data to turn server
after senddata status=156

data_channel_recv thread spawned for handling data being received for data_sock=10 successfully
    22:36:31.951 tcprel0x4658e0  Leaving Received PJ_STUN_CONNECTION_ATTEMPT_INDICATION indication condition
    22:36:31.951 tcprel0x4658e0  Received Data indication with missing attributes

data_channel_recv entry for data_sock = 10
waiting to recv the message header
Received 80 Bytes
this is a response -> method in resp=11
waiting to recv the message header
Received 200 Bytes
hdr recv, msg_type=feed len=192
Copied 192 bytes from recv_data to payload_buffer
in data_channel_recv thread before invoking application handler 22:36:32.167 turn_wrapper.c  ***Client received 192 bytes data*** actual data_sock=10
Cached MAC Address = 60:38:E0:1B:75:A4 
SetBelkinParameter - ParameterName = PushToCloudTime , ParameterValue = 6
waiting to recv the message header
hdr recv failure, going out of loop=10 setting nodatarcv 
data_channel_recv exit
thready: Destructor freeing name "".
    22:36:51.065 stuntsx0x49338  STUN timeout waiting for response
    22:36:51.066 tcprel0x4658e0  Unexpected STUN 11 response
    22:36:53.069 stuntsx0x49338  STUN client transaction destroyed
    22:37:11.849 stuntsx0x485ba  STUN timeout waiting for response
    22:37:11.850 tcprel0x4658e0  Unexpected STUN 11 response
    22:37:13.853 stuntsx0x485ba  STUN client transaction destroyed
    22:37:31.790 tcprel0x4658e0  RX 92 bytes STUN message from 3.81.166.40:3478:
--- begin STUN message ---
STUN ConnectionAttempt indication
    Hdr: length=72, magic=2112a442, tsx_id=943be6f76c1bc8111517963f
    Attributes:
    SOFTWARE: length=14, value="TurnServer 0.4"
    CONNECTION-ID: length=4, value=1398619039 (0x535d3b9f)
    XOR-PEER-ADDRESS: length=8, IPv4 addr=10.0.61.4:41454
    MESSAGE-INTEGRITY: length=20, data=f1380fe16b1e60ad73e53e60d18add661f6b02ab
    FINGERPRINT: length=4, value=3448016328 (0xcd848dc8)
--- end of STUN message ---

    22:37:31.791 tcprel0x4658e0  Received PJ_STUN_CONNECTION_ATTEMPT_INDICATION indication
    22:37:31.792 tcprel0x4658e0  TX 156 bytes STUN message to 3.81.166.40:3478:
--- begin STUN message ---
STUN ConnectionBind request
    Hdr: length=136, magic=2112a442, tsx_id=000006db4353d0cd628c8964
    Attributes:
    CONNECTION-ID: length=4, value=1398619039 (0x535d3b9f)
    SOFTWARE: length=13, value="pjnath-1.8.10"
    USERNAME: length=12, value="6038E01B75A4"
    REALM: length=10, value="belkin.org"
    NONCE: length=48, value="5ecd7d4c0000000088b594dea928a930d11328d11b63179a"
    MESSAGE-INTEGRITY: length=20, data=7d85109ab0f62c7ee684794c15f206d15fb429c4
--- end of STUN message ---

    22:37:31.793 stuntsx0x4abb9  STUN client transaction created
    22:37:31.794 stuntsx0x4abb9  STUN sending message (transmit count=8)
in func turn_on_send_pkt
dst addr=3.81.166.40 htons.port=3478 ntwk.port=38413
check  server_addr.sin_addr=3.81.166.40 .port=38413 
data sock fd=10 data_port=0
data_port aftr htons=0
turn_sock->data_sock while setting =10
*********************
this shud print only for CONN BIND
*********************
sending 156 bytes of data to turn server
after senddata status=156

data_channel_recv thread spawned for handling data being received for data_sock=10 successfully
    22:37:31.904 tcprel0x4658e0  Leaving Received PJ_STUN_CONNECTION_ATTEMPT_INDICATION indication condition
    22:37:31.905 tcprel0x4658e0  Received Data indication with missing attributes

data_channel_recv entry for data_sock = 10
waiting to recv the message header
Received 80 Bytes
this is a response -> method in resp=11
waiting to recv the message header
Received 200 Bytes
hdr recv, msg_type=feed len=192
Copied 192 bytes from recv_data to payload_buffer
in data_channel_recv thread before invoking application handler 22:37:32.119 turn_wrapper.c  ***Client received 192 bytes data*** actual data_sock=10
Cached MAC Address = 60:38:E0:1B:75:A4 
SetBelkinParameter - ParameterName = PushToCloudTime , ParameterValue = 6
waiting to recv the message header
hdr recv failure, going out of loop=10 setting nodatarcv 
data_channel_recv exit
thready: Destructor freeing name "".
    22:37:36.261 tcprel0x4658e0  TCP connection closed: End of file (PJ_EEOF)
    22:37:36.261 tcprel0x4658e0  State changed Ready --> Deallocated
in turn_sock=0
    22:37:36.262 turn_wrapper.c  State Ready --> Deallocated
    22:37:36.263 turn_wrapper.c  Relay shutting down..
    22:37:36.263 turn_wrapper.c  Relay shutting down..status 0

    22:37:36.264 tcprel0x4658e0  Request to shutdown in state Deallocated, cause:0
    22:37:36.264 tcprel0x4658e0  State changed Deallocated --> Destroying
in turn_sock=0
    22:37:36.265 turn_wrapper.c  State Deallocated --> Destroying
    22:37:36.266 turn_wrapper.c  Destroying..status 0

    22:37:36.266 turn_wrapper.c  Destroying..status == ..set g.relay=NULL
    22:37:36.267 tcprel0x4658e0  Destroying TURN
    22:37:36.268 stuntsx0x4abb9  STUN client transaction destroyed
    22:37:36.270 tcprel0x4658e0  TURN client session destroyed
thready: Destructor freeing name "".
thready: Setting thread name to "remoteAccessInitThd" (tid:724313376).
    22:37:43.605 os_core_unix.c  pjlib 1.8.10 for POSIX initialized
    22:37:43.606          pjlib  select() I/O Queue created (0x4923e4)
    22:37:43.608 tcprel0x492e40  TURN client session created
    22:37:43.609 tcprel0x492e40  Resolving 35.173.223.183 with DNS A
    22:37:43.610 tcprel0x492e40  State changed Null --> Resolving
in turn_sock=0
    22:37:43.611 turn_wrapper.c  State Null --> Resolving
    22:37:43.611 tcprel0x492e40  State changed Resolving --> Resolved
in turn_sock=0
    22:37:43.612 turn_wrapper.c  State Resolving --> Resolved
    22:37:43.613 tcprel0x492e40  Connecting to 35.173.223.183:3478
    22:37:43.729 tcprel0x492e40  TCP connected
conn type= TCP
    22:37:43.730 tcprel0x492e40  State changed Resolved --> Allocating
in turn_sock=0
    22:37:43.730 turn_wrapper.c  State Resolved --> Allocating
    22:37:43.731 tcprel0x492e40  TX 48 bytes STUN message to 35.173.223.183:3478:
--- begin STUN message ---
STUN Allocate request
    Hdr: length=28, magic=2112a442, tsx_id=000006db542289ec628c8965
    Attributes:
    REQUESTED-TRANSPORT: length=4, value=100663296 (0x6000000)
    SOFTWARE: length=13, value="pjnath-1.8.10"
--- end of STUN message ---

    22:37:43.732 stuntsx0x4673e  STUN client transaction created
    22:37:43.732 stuntsx0x4673e  STUN sending message (transmit count=8)
in func turn_on_send_pkt
dst addr=35.173.223.183 htons.port=3478 ntwk.port=38413
check  server_addr.sin_addr=35.173.223.183 .port=38413 
    22:37:43.847 tcprel0x492e40  RX 140 bytes STUN message from 35.173.223.183:3478:
--- begin STUN message ---
STUN Allocate error response
    Hdr: length=120, magic=2112a442, tsx_id=000006db542289ec628c8965
    Attributes:
    ERROR-CODE: length=20, err_code=401, reason="Unauthorized"
    REALM: length=10, value="belkin.org"
    NONCE: length=48, value="5ecd7e1800000000f859a539144fd887f3adcc97f4bbd850"
    SOFTWARE: length=14, value="TurnServer 0.4"
    FINGERPRINT: length=4, value=913478227 (0x36729253)
--- end of STUN message ---

    22:37:43.848 tcprel0x492e40  Retrying request with new authentication
    22:37:43.849 tcprel0x492e40  TX 156 bytes STUN message to 35.173.223.183:3478:
--- begin STUN message ---
STUN Allocate request
    Hdr: length=136, magic=2112a442, tsx_id=000006db6de91b18628c8966
    Attributes:
    REQUESTED-TRANSPORT: length=4, value=100663296 (0x6000000)
    SOFTWARE: length=13, value="pjnath-1.8.10"
    USERNAME: length=12, value="6038E01B75A4"
    REALM: length=10, value="belkin.org"
    NONCE: length=48, value="5ecd7e1800000000f859a539144fd887f3adcc97f4bbd850"
    MESSAGE-INTEGRITY: length=20, data=2b993187f5546eb255772f4ad794b173bbc106f6
--- end of STUN message ---

    22:37:43.850 stuntsx0x4675f  STUN client transaction created
    22:37:43.850 stuntsx0x4675f  STUN sending message (transmit count=8)
in func turn_on_send_pkt
dst addr=35.173.223.183 htons.port=3478 ntwk.port=38413
check  server_addr.sin_addr=35.173.223.183 .port=38413 
    22:37:44.001 tcprel0x492e40  RX 104 bytes STUN message from 35.173.223.183:3478:
--- begin STUN message ---
STUN Allocate success response
    Hdr: length=84, magic=2112a442, tsx_id=000006db6de91b18628c8966
    Attributes:
    XOR-RELAYED-ADDRESS: length=8, IPv4 addr=10.0.90.85:10188
    LIFETIME: length=4, value=330 (0x14a)
    XOR-MAPPED-ADDRESS: length=8, IPv4 addr=109.108.210.20:3869
    SOFTWARE: length=14, value="TurnServer 0.4"
    MESSAGE-INTEGRITY: length=20, data=a14a082088b2ad4326888193b9aa98e297f243ea
    FINGERPRINT: length=4, value=572692860 (0x2222997c)
--- end of STUN message ---

    22:37:44.002 tcprel0x492e40  State changed Allocating --> Ready
in turn_sock=0
    22:37:44.002 turn_wrapper.c  State Allocating --> Ready
    22:37:45.857 stuntsx0x4673e  STUN client transaction destroyed
    22:37:46.013 stuntsx0x4675f  STUN client transaction destroyed
> POST /apis/http/dlr/peerAddresses HTTP/1.1
Host: api.xbcs.net:8443
Content-Type: application/xml
Accept: application/xml
Authorization: 6038E01B75A4:7/MkHW4NQgjYM60BsWQTjMyoRGw=:1590525965
X-Belkin-Client-Type-Id: WeMo_WW_2.00.10966.PVT-OWRT-Insight:5e7e-40a7-8bf4-539d1dc2ce42
Content-Length: 241

< HTTP/1.1 200 OK
< Date: Tue, 26 May 2020 19:37:47 GMT
< Content-Type: application/xml;charset=UTF-8
< Content-Length: 1262
< Connection: keep-alive
< X-Application-Context: application
< 
thready: Destructor freeing name "remoteInitNatCli".
thready: Destructor freeing name "remoteAccessInit".
thready: Setting thread name to "remoteInitNatClient24" (tid:728507680).
GetWanDefaultGateway: GATEWAY = 192.168.0.1
GetWanDefaultGateway: GATEWAY = 192.168.0.1
GetWanDefaultGateway: GATEWAY = 192.168.0.1
    22:42:14.027 tcprel0x492e40  TX 148 bytes STUN message to 35.173.223.183:3478:
--- begin STUN message ---
STUN Refresh request
    Hdr: length=128, magic=2112a442, tsx_id=000006db7644a45c628c8967
    Attributes:
    SOFTWARE: length=13, value="pjnath-1.8.10"
    USERNAME: length=12, value="6038E01B75A4"
    REALM: length=10, value="belkin.org"
    NONCE: length=48, value="5ecd7e1800000000f859a539144fd887f3adcc97f4bbd850"
    MESSAGE-INTEGRITY: length=20, data=c6163fde36bef73d33d0c7754a66caa6fd490c3d
--- end of STUN message ---

    22:42:14.028 stuntsx0x48471  STUN client transaction created
    22:42:14.028 stuntsx0x48471  STUN sending message (transmit count=8)
in func turn_on_send_pkt
dst addr=35.173.223.183 htons.port=3478 ntwk.port=38413
check  server_addr.sin_addr=35.173.223.183 .port=38413 
    22:42:14.140 tcprel0x492e40  RX 80 bytes STUN message from 35.173.223.183:3478:
--- begin STUN message ---
STUN Refresh success response
    Hdr: length=60, magic=2112a442, tsx_id=000006db7644a45c628c8967
    Attributes:
    LIFETIME: length=4, value=330 (0x14a)
    SOFTWARE: length=14, value="TurnServer 0.4"
    MESSAGE-INTEGRITY: length=20, data=2ac7b7eb0ed5577f16d02896601c3763cbf6cce9
    FINGERPRINT: length=4, value=3045209281 (0xb58234c1)
--- end of STUN message ---

    22:42:16.145 stuntsx0x48471  STUN client transaction destroyed
GetWanDefaultGateway: GATEWAY = 192.168.0.1
SetBelkinParameter - ParameterName = TodayONTime , ParameterValue = 0
SetBelkinParameter - ParameterName = TodayONTimeTS , ParameterValue = 0
SetBelkinParameter - ParameterName = TodaySBYTime , ParameterValue = 42
nvram/1983/NvramStartDaemon: Called
nvram/1983/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
SetBelkinParameter - ParameterName = TodaySBYTimeTS , ParameterValue = 42
nvram/1983/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = TodayKWH , ParameterValue = 0
nvram/1983/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = TodayKWHON , ParameterValue = 0
nvram/1983/NvramStartDaemon: Called
SetBelkinParameter - ParameterName = TodayKWHSBY , ParameterValue = 0
nvram/1983/NvramStartDaemon: Called
nvram/1756/NvramStartDaemon: Called
nvram/1756/NvramStartDaemon: Sending SIGHUP to nvramd (1478)
nvram/1478/NvramCommitInternal: Flushing cache to flash
nvram/1478/NvramCommitInternal: Flash write complete
nvram/1478/BuildIndex: 53 variables defined in NVRAM
GetWanDefaultGateway: GATEWAY = 192.168.0.1
GetWanDefaultGateway: GATEWAY = 192.168.0.1
GetWanDefaultGateway: GATEWAY = 192.168.0.1
GetWanDefaultGateway: GATEWAY = 192.168.0.1
GetWanDefaultGateway: GATEWAY = 192.168.0.1
GetWanDefaultGateway: GATEWAY = 192.168.0.1
GetWanDefaultGateway: GATEWAY = 192.168.0.1
GetWanDefaultGateway: GATEWAY = 192.168.0.1
GetWanDefaultGateway: GATEWAY = 192.168.0.1
GetWanDefaultGateway: GATEWAY = 192.168.0.1
GetWanDefaultGateway: GATEWAY = 192.168.0.1
GetWanDefaultGateway: GATEWAY = 192.168.0.1
GetWanDefaultGateway: GATEWAY = 192.168.0.1
GetWanDefaultGateway: GATEWAY = 192.168.0.1
GetWanDefaultGateway: GATEWAY = 192.168.0.1
GetWanDefaultGateway: GATEWAY = 192.168.0.1
thready: Destructor freeing name "CtrlPtRediscover".
GetWanDefaultGateway: GATEWAY = 192.168.0.1
GetWanDefaultGateway: GATEWAY = 192.168.0.1
GetWanDefaultGateway: GATEWAY = 192.168.0.1
GetWanDefaultGateway: GATEWAY = 192.168.0.1
GetWanDefaultGateway: GATEWAY = 192.168.0.1
GetWanDefaultGateway: GATEWAY = 192.168.0.1

The firmware version is WeMo_WW_2.00.10966.PVT-OWRT-Insight. There is a login prompt which doesn’t use a trivial password for the root user. I have been unable to crack the password using John The Ripper; here’s the salt and MD5 hash: $1$9CaSVCnb$y1c1i01eMl02W5pTmwehD1.

Partitions

The flash partition layout is as follows:

MX25L12805D(c2 2018c220) (16384 Kbytes)
mtd .name = raspi, .size = 0x01000000 (16M) .erasesize = 0x00010000 (64K) .numeraseregions = 0
Creating 12 MTD partitions on "raspi":
0x00000000-0x00050000 : "uboot"
0x00050000-0x00190000 : "Kernel_1"
0x00190000-0x007c0000 : "rootfs_1"
0x007c0000-0x00900000 : "Kernel_2"
0x00900000-0x00f30000 : "rootfs_2"
mtd: partition "rootfs_2" set to be root filesystem
mtd: partition "rootfs_data" created automatically, ofs=C90000, len=2A0000 
0x00c90000-0x00f30000 : "rootfs_data"
0x00fe0000-0x00ff0000 : "nvram"
0x00ff0000-0x01000000 : "User_Factory"
0x00040000-0x00050000 : "Factory"
0x00f30000-0x00fd0000 : "Belkin_settings"
0x00030000-0x00040000 : "Uboot_env"
0x00050000-0x007c0000 : "Firmware_1"
0x007c0000-0x00f30000 : "Firmware_2"

We know furthermore, that the root filesystem is a SquashFS 3.0 with a JFFS2 mini_fo overlay. There are two kernel partitions and two root filesystem partitions. This is used for firmware updates where the new firmware is written to the inactive partition set. The Factory partition seems to hold calibration data for the WiFi peripheral. Belkin_settings is a JFFS2 partition with some application data. nvram is a key-value store for configuration parameters. uboot and Uboot_env holds the u-boot program and its environment, respectively. User_Factory appears to hold static manufacturing data like serial number, region, country, model and MAC address.

Booting your own Kernel

I’m not sure whether it’s possible to specify kernel command line and device tree from u-boot, so the safest bet is to use a kernel with baked in command line and appended device tree. This type of image is built by default when building RT5350 images with OpenWrt. My initial plan was to mount one of the existing root filesystem partitions when booting the custom kernel. However, the device uses SquashFS 3.0 which is incompatible with the current version 4.0. In order to have a functional root filesystem, we boot an image with initial RAM disk. This type of image is also built automatically by OpenWrt. The OpenWrt target f7c027 is close enough to this hardware that it boots the kernel without problems. However, I have also created a f7c029 target which has the correct LED and button GPIO mapping.

In order to boot a custom image, run the following in an interactive u-boot shell:

setenv bootstate 0; loadb 0x80600000
# Send openwrt-ramips-rt305x-f7c029-initramfs-kernel.bin via kermit
bootm 0x80600000

This will take some time but it will get you a Linux shell. Depending on which packages you built, you can read and transfer (gkermit) the stock partitions. You will also be able to transfer the an image permanently to flash which allows you to boot much faster afterwards. I have written kernel and root filesystem to the inactive partitions, i.e. the one that doesn’t hold the currently active stock image. This target partition should be labelled firmware in the device tree while the other one should be called firmware2.

cd /tmp
gkermit -r
# Send openwrt-ramips-rt305x-f7c029-squashfs-sysupgrade.bin via kermit
sysupgrade -n /tmp/openwrt-ramips-rt305x-f7c029-squashfs-sysupgrade.bin

It makes sense to increase the serial baud rate to 230400 before these transfers in order to save some time:

stty -F /dev/ttyS0 230400

After a reboot, you’ll be able to boot your kernel and root filesystem by running the following in the u-boot shell (note, that these values depend on whether you write your stuff to Firmware_1 or Firmware_2:

setenv bootstate 0
bootm 0xBC050000

In order to make it permanent, run:

setenv bootstate 0
setenv bootpart 0
setenv check_boot 0
saveenv
reset

Excursion: kermit with minicom on Arch Linux

There seems to be a problem with some lock files that ckermit tries to write in Arch Linux. In order to fix this, modify your ~/.minirc.dfl to contain the following lines:

pu pname7           YUYNNkermit
pu pname8           NDYNNkermit
pu pprog7           /usr/bin/env LOCK_DIR=/tmp /usr/bin/ckermit -i -l %l -b %b -s
pu pprog8           /usr/bin/env LOCK_DIR=/tmp /usr/bin/ckermit -i -l %l -b %b -r

Additionally, I have found the following ~/.kermrc to work:

set carrier-watch off
set handshake none
set flow-control none
robust
set file type bin
set rec pack 1000
set send pack 1000
set window 5

Controlling the relay

In order to control the relay via HTTP, add the following small CGI script to /www/cgi-bin/relay and make it executable:

#!/bin/sh

relay_file="/sys/class/leds/f7c029:device:relay/brightness"

bad_request() {
    echo "Status: 400 Bad Request"
    echo
    exit 1
}

set_state() {
    echo "$1" > "$relay_file"
    echo "$1" > "/sys/class/leds/f7c029:green:power/brightness"
}

if [ "$REQUEST_METHOD" == "GET" ]; then
    echo
    sed -e s/0/off/ -e s/1/on/ "$relay_file"
elif [ "$REQUEST_METHOD" == "POST" ]; then
    cmd="$(cat)"
    case "$cmd" in
    on)
        set_state 1
        ;;
    off)
        set_state 0
        ;;
    *)
        bad_request
        ;;
    esac	

    echo
    echo "$cmd"
else
    bad_request
fi

Now the relay can be controlled e.g. via cURL:

curl -d {on,off} OpenWrt.local/cgi-bin/relay

Manual control via the touch button

Adding the following executable script to /etc/rc.button/BTN_1 allows to control the relay using the touch field:

#!/bin/sh

relay_file="/sys/class/leds/f7c029:device:relay/brightness"

set_state() {
    echo "$1" > "$relay_file"
    echo "$1" > "/sys/class/leds/f7c029:green:power/brightness"
}

if [ "$ACTION" != "pressed" ]; then
    exit
fi

case "$(cat "$relay_file")" in
0)
    set_state 1
    ;;
1)
    set_state 0
    ;;
esac

Interfacing the power sensor

The power sensor reports data periodically via UART. This is a unidirectional interface. The format is similar but not identical to the format described in the 78M6610+PSU datasheet (section 4.1.2 Auto-Reported Data). There is some excellent detective work available on the web regarding the power sensor and the protocol format.

I built a small service that listens to the power sensor data coming in over serial and making it available via OpenWrt’s inter-process communication bus: ubus. The data can also be accessed via HTTP from outside the device:

curl -s wemo.local/cgi-bin/insight | jq
{
    "int_temperature": 26.700001,
    "ext_temperature": -22.855001,
    "rms_voltage": 237.996017,
    "rms_current": 4.117907,
    "active_power": 980.039978,
    "average_power": 981.375,
    "power_factor": 1,
    "line_frequency": 49.358002,
    "active_energy": 0.238
}

The temperature data looks jumpy and fishy in general, but that’s arguably not very important for most applications. I took the information that the first two words are in fact temperature values from some Belkin code.

Issues

Remaining work

References