How to deal with getDeviceWifi().subscribe

[pcmester]

I'm trying to reverse engineer the communication protocol of the Xiaomi Linptech doorbell, and I'm stuck with this subscribe thing. I don't know how to deal with this. I can use the methods to control the device, but for data feedback, it uses this subscribe method, which is not familiar to me. Please help me figure out what to do with that.

https://github.com/MiEcosystem/miot-plugin-sdk/blob/38905bbe8452cf46bf1e9ba22879495423a1eff8/miot-sdk/Device.js#L24

[rytilahti]

Do you have any idea how the subscribe works? Can you give it an URL that gets pinged in case an event happens?

[pcmester]

Currently, I can't. I can give you logs from the doorbell. Unfortunately, I flashed the ESP on it, and now I cannot flash back the factory firmware.

[pcmester]

`| | ||| ||| ||
|| || _| _| _| _|
_| _| _| _| _| _| _|
_| _| _| _| _| _|
| | ||| ||| ||
JENKINS BUILD NUMBER: N/A
BUILD TIME: May 9 2019,19:30:13
BUILT BY: N/A
MIIO APP VER: 2.0.5
MIIO MCU VER: 0013
MIIO DID: 123500003
MIIO WIFI MAC: 04cf8c0fe8fa
MIIO MODEL: linp.doorbell.g03
ARCH TYPE: esp32,0x0000a601
ARCH VER: v3.1.4-56-g8ffb04960
08:00:01.020 [I] miio_net: Wifi event[1]
08:00:01.020 [I] miio_net: Wifi scan done
08:00:01.060 [D] miio_net: wifi scanning channel 2 for 200ms...
08:00:01.060 [I] miio_monitor: work time = 1s, memory left = 87228
08:00:01.060 [D] miio_net: reboot trigger will been pulled in 3599s
08:00:01.070 [D] miio_net: sta will close in 899s
08:00:01.220 [D] tou: recv=model
08:00:01.220 [D] tou: send=linp.doorbell.g03
08:00:01.230 [D] tou: recv=mcu_version 0013
08:00:01.240 [D] tou: send=ok
08:00:01.260 [I] miio_net: Wifi event[1]
08:00:01.260 [I] miio_net: Wifi scan done
08:00:01.260 [D] miio_net: wifi scanning channel 3 for 200ms...
08:00:01.500 [I] miio_net: Wifi event[1]
08:00:01.500 [I] miio_net: Wifi scan done
08:00:01.500 [D] tou: recv=ble_config set 1196 0001
08:00:01.500 [D] miio_net: wifi scanning channel 4 for 200ms...
08:00:01.510 [D] tou: send=ok
08:00:01.700 [I] miio_net: Wifi event[1]
08:00:01.700 [I] miio_net: Wifi scan done
08:00:01.700 [D] miio_net: wifi scanning channel 5 for 200ms...
08:00:01.740 [D] tou: recv=get_down
08:00:01.740 [D] tou: send=down MIIO_net_change offline
08:00:01.740 [D] tou: recv=net
08:00:01.750 [D] tou: send=offline
08:00:01.940 [I] miio_net: Wifi event[1]
08:00:01.940 [I] miio_net: Wifi scan done
08:00:01.940 [D] miio_net: wifi scanning channel 6 for 200ms...
08:00:01.940 [D] tou: recv=get_down
08:00:01.950 [D] tou: send=down none
08:00:02.140 [I] miio_net: Wifi event[1]
08:00:02.140 [I] miio_net: Wifi scan done
08:00:02.140 [D] miio_net: wifi scanning channel 7 for 200ms...
08:00:02.140 [D] tou: recv=get_down
08:00:02.150 [I] miio_monitor: work time = 2s, memory left = 87096
08:00:02.150 [D] miio_net: reboot trigger will been pulled in 3598s
08:00:02.160 [D] tou: send=down none
08:00:02.170 [D] miio_net: sta will close in 898s
08:00:02.370 [I] miio_net: Wifi event[1]
08:00:02.370 [I] miio_net: Wifi scan done
08:00:02.370 [D] tou: recv=get_down
08:00:02.380 [D] miio_net: insert ssid=SSID, bssid=SO:ME:MA:CA:DR:ESS, pri=7, rssi=-55, authmode=4
08:00:02.390 [D] tou: send=down none
08:00:02.390 [D] miio_net: wifi scanning channel 8 for 200ms...
08:00:02.540 [D] tou: recv=get_down
08:00:02.540 [D] tou: send=down none
08:00:02.620 [I] miio_net: Wifi event[1]
08:00:02.620 [I] miio_net: Wifi scan done
08:00:02.620 [D] miio_net: wifi scanning channel 9 for 200ms...
08:00:02.640 [D] tou: recv=net
08:00:02.640 [D] tou: send=offline
08:00:02.740 [D] tou: recv=get_down
08:00:02.740 [D] tou: send=down none
08:00:02.830 [I] miio_net: Wifi event[1]
08:00:02.830 [I] miio_net: Wifi scan done
08:00:02.830 [D] miio_net: wifi scanning channel 10 for 200ms...
08:00:02.940 [D] tou: recv=get_down
08:00:02.940 [D] tou: send=down none
08:00:03.060 [I] miio_net: Wifi event[1]
08:00:03.060 [I] miio_net: Wifi scan done
08:00:03.060 [D] miio_net: wifi scanning channel 11 for 200ms...
08:00:03.070 [I] miio_monitor: work time = 3s, memory left = 87144
08:00:03.070 [D] miio_net: reboot trigger will been pulled in 3597s
08:00:03.080 [D] miio_net: sta will close in 897s
08:00:03.140 [D] tou: recv=get_down
08:00:03.140 [D] tou: send=down none
08:00:03.260 [I] miio_net: Wifi event[1]
08:00:03.260 [I] miio_net: Wifi scan done
08:00:03.260 [D] miio_net: wifi scanning channel 12 for 200ms...
08:00:03.340 [D] tou: recv=get_down
08:00:03.340 [D] tou: send=down none
08:00:03.500 [I] miio_net: Wifi event[1]
08:00:03.500 [I] miio_net: Wifi scan done
08:00:03.500 [D] miio_net: wifi scanning channel 13 for 200ms...
08:00:03.540 [D] tou: recv=get_down
08:00:03.540 [D] tou: send=down none
08:00:03.540 [D] tou: recv=net
08:00:03.540 [D] tou: send=offline
08:00:03.700 [I] miio_net: Wifi event[1]
08:00:03.700 [I] miio_net: Wifi scan done
08:00:03.700 [D] miio_net: wifi scan finished, 1 SSID found.
08:00:03.710 [I] miio_net: bingo ssid=SSID, bssid=SO:ME:MA:CA:DR:ESS, pri=7, rssi=-55
I (4042) wifi: set country: cc=CN schan=1 nchan=13 policy=1

08:00:03.750 [D] tou: recv=get_down
08:00:03.750 [D] tou: send=down none
08:00:03.940 [D] tou: recv=get_down
08:00:03.940 [D] tou: send=down none
I (4282) wifi: n:7 2, o:1 0, ap:255 255, sta:7 2, prof:1
I (5262) wifi: state: init -> auth (b0)
I (5272) wifi: state: auth -> assoc (0)
08:00:04.940 [I] miio_monitor: work time = 4s, memory left = 86840
08:00:04.940 [D] miio_net: reboot trigger will been pulled in 3596s
I (5272) wifi: state: assoc -> run (10)
08:00:04.950 [D] miio_net: sta will close in 896s
08:00:04.960 [D] tou: recv=get_down
08:00:04.960 [D] tou: send=down none
08:00:04.970 [D] tou: recv=get_down
08:00:04.970 [D] tou: send=down none
I (5302) wifi: connected with SSID, channel 7
I (5312) wifi: pm start, type: 2

08:00:04.980 [I] miio_net: Wifi event[4]
08:00:04.980 [I] miio_net: Wifi station connected
08:00:04.990 [D] tou: recv=net
08:00:04.990 [D] tou: send=offline
08:00:05.000 [I] miio_monitor: work time = 5s, memory left = 86544
08:00:05.000 [D] miio_net: reboot trigger will been pulled in 3595s
08:00:05.010 [D] tou: recv=get_down
08:00:05.020 [D] miio_net: sta will close in 895s
08:00:05.020 [D] tou: send=down none
08:00:05.030 [D] tou: recv=get_down
08:00:05.030 [D] tou: send=down none
08:00:05.030 [D] tou: recv=get_down
08:00:05.040 [D] tou: send=down none
08:00:05.130 [D] tou: recv=get_down
08:00:05.130 [D] tou: send=down none
08:00:05.330 [D] tou: recv=get_down
08:00:05.340 [D] tou: send=down none
08:00:05.340 [D] tou: recv=net
08:00:05.340 [D] tou: send=offline
08:00:05.530 [D] tou: recv=get_down
08:00:05.530 [D] tou: send=down none
08:00:05.730 [D] tou: recv=get_down
08:00:05.730 [D] tou: send=down none
08:00:05.930 [D] tou: recv=get_down
08:00:05.930 [D] tou: send=down none
08:00:06.030 [I] miio_monitor: work time = 6s, memory left = 86548
08:00:06.030 [D] miio_net: reboot trigger will been pulled in 3594s
08:00:06.030 [D] miio_net: sta will close in 894s
I (6452) event: sta ip: 192.168.1.68, mask: 255.255.255.0, gw: 192.168.1.1
08:00:06.120 [I] miio_net: Wifi event[7]
08:00:06.120 [D] miio_net: Wifi ip=192.168.1.68,mask=255.255.255.0,gw=192.168.1.1
08:00:06.130 [D] ot: event emit[id=2,txt=otn.mode,ext_len=4]
08:00:06.130 [D] miio_ot: otn.mode[2] happened!
08:00:06.140 [I] miio_net: Wifi station got ip
08:00:06.140 [D] ots: get ctrl[type=1, arg_len=60]
08:00:06.150 [D] httpc: url = http://110.43.0.83/gslb?tver=2&id=123500003&dm=ots.io.mi.com&timestamp=6&sign=Wf0861SxgjUUJTSVbXlcbQBagTim2%2F%2BHVEGSnc%2FxDDE%3D
08:00:06.160 [D] tou: recv=get_down
08:00:06.170 [D] ots: set ctrl[type=1, arg_len=60]
08:00:06.170 [D] httpc: domain = 110.43.0.83::80
08:00:06.180 [D] tou: send=down MIIO_net_change local
08:00:06.180 [D] otu: get ctrl[type=1, arg_len=0]
08:00:06.190 [D] otu: set ctrl[type=1, arg_len=0]
08:00:06.200 [D] httpc: path = /gslb?tver=2&id=123500003&dm=ots.io.mi.com&timestamp=6&sign=Wf0861SxgjUUJTSVbXlcbQBagTim2%2F%2BHVEGSnc%2FxDDE%3D
08:00:06.210 [D] otu: otu is opening...
08:00:06.210 [D] httpc: hostname = dns.io.mi.com
08:00:06.220 [D] httpc: connecting
08:00:06.220 [D] ots: ots is connecting...
08:00:06.230 [D] tcp: opening
08:00:06.230 [I] otu: Opened.
08:00:06.240 [D] tou: recv=net
08:00:06.240 [D] tou: send=local
08:00:06.240 [D] otu: event emit[id=6,txt=otu.open_ok,ext_len=0]
08:00:06.250 [D] otu: otu.open_ok[6] happened!
08:00:06.330 [D] tou: recv=get_down
08:00:06.330 [D] tou: send=down none
08:00:06.530 [D] tou: recv=get_down
08:00:06.530 [D] tou: send=down none
08:00:06.590 [D] tcp: opened
08:00:06.590 [D] httpc:
GET /gslb?tver=2&id=123500003&dm=ots.io.mi.com&timestamp=6&sign=Wf0861SxgjUUJTSVbXlcbQBagTim2%2F%2BHVEGSnc%2FxDDE%3D HTTP/1.1
Host: dns.io.mi.com
User-Agent: MIoT

08:00:06.730 [D] tou: recv=get_down
08:00:06.730 [D] tou: send=down none
08:00:06.890 [D] httpc:
HTTP/1.1 200 OK
Server: Tengine/2.2.0
Date: Mon, 15 Jul 2019 13:58:52 GMT
Content-Type: text/plain
Content-Length: 216
Connection: keep-alive

08:00:06.890 [I] httpc: Content-Length 216
08:00:06.900 [I] httpc: ==> 100%
08:00:06.900 [I] httpc: GET Done(216bytes).
08:00:06.910 [I] httpc: File Done(216bytes).
08:00:06.910 [D] tcp: closed
08:00:06.920 [D] httpdns: {"info":{"host_list":[{"ip":"120.92.96.155","port":443},{"ip":"120.92.65.241","port":443},{"ip":"58.83.177.143","port":443}],"enable":1},"sign":"gzWKlqf793IWbPgweJ+ldyn3RYUb6RYyCaOAyqbSWfk=","timestamp":"1563199132"}
08:00:06.940 [D] tou: recv=get_down
08:00:06.940 [D] tou: send=down none
08:00:06.950 [D] httpdns: host_list[0] = 120.92.96.155::443
08:00:06.950 [D] httpdns: host_list[1] = 120.92.65.241::443
08:00:06.960 [D] httpdns: host_list[2] = 58.83.177.143::443
08:00:06.970 [D] httpdns: timestamp = 1563199132
08:00:06.970 [D] httpdns: sign_base64 = gzWKlqf793IWbPgweJ+ldyn3RYUb6RYyCaOAyqbSWfk=, len = 44
08:00:06.980 [D] ots: event emit[id=4,txt=ots.resolve_ok,ext_len=100]
08:00:06.990 [D] ots: ots.resolve_ok[4] happened!
08:00:06.990 [D] httpc: idle
08:00:07.000 [D] ots: get ctrl[type=2, arg_len=72]
08:00:07.000 [D] ots: set ctrl[type=2, arg_len=72]
08:00:07.010 [I] ots: ots connect 120.92.96.155::443...
08:00:07.010 [D] tls: opening
08:00:07.020 [D] ots: backlist[0] = 120.92.65.241::443
08:00:07.020 [D] tls: Loading the CA root certificate...
08:00:07.030 [D] ots: backlist[1] = 58.83.177.143::443
08:00:07.040 [D] tls: Setting up the SSL/TLS structure...
08:00:07.040 [D] tls: psk identity is DID=123500003.
08:00:07.050 [D] ots: login_timeout=45000
08:00:07.050 [I] tls: connect to server Mijia Cloud, domain is 120.92.96.155, port is 443.
08:00:07.130 [D] tou: recv=get_down
08:00:07.130 [D] tou: send=down none
08:00:07.130 [D] tou: recv=net
08:00:07.130 [D] tou: send=local
08:00:07.150 [I] miio_monitor: work time = 7s, memory left = 67100
08:00:07.150 [D] miio_net: reboot trigger will been pulled in 3593s
08:00:07.150 [D] miio_net: sta will close in 893s
08:00:07.330 [D] tou: recv=get_down
08:00:07.330 [D] tou: send=down none
08:00:07.390 [D] tls: Socket Connected.
08:00:07.400 [D] tls: TLS/SSL start handshake...
08:00:07.500 [W] tls: timeout[100]! mbedtls_ssl_handshake returned -0x6800 (d0_tls_open,369)
08:00:07.530 [D] tou: recv=get_down
08:00:07.530 [D] tou: send=down none
08:00:07.600 [W] tls: timeout[200]! mbedtls_ssl_handshake returned -0x6800 (d0_tls_open,369)
08:00:07.730 [D] tou: recv=get_down
08:00:07.730 [W] tls: timeout[300]! mbedtls_ssl_handshake returned -0x6800 (d0_tls_open,369)
08:00:07.730 [D] tou: send=down none
08:00:07.830 [W] tls: timeout[400]! mbedtls_ssl_handshake returned -0x6800 (d0_tls_open,369)
08:00:07.930 [W] tls: timeout[500]! mbedtls_ssl_handshake returned -0x6800 (d0_tls_open,369)
08:00:07.930 [D] tou: recv=get_down
08:00:07.930 [D] tou: send=down none
08:00:08.030 [D] tou: recv=net
08:00:08.030 [D] tou: send=local
08:00:08.130 [W] tls: timeout[600]! mbedtls_ssl_handshake returned -0x6800 (d0_tls_open,369)
08:00:08.130 [D] tou: recv=get_down
08:00:08.130 [D] tou: send=down none
08:00:08.150 [I] miio_monitor: work time = 8s, memory left = 62348
08:00:08.150 [D] miio_net: reboot trigger will been pulled in 3592s
08:00:08.150 [D] miio_net: sta will close in 892s
08:00:08.230 [W] tls: timeout[700]! mbedtls_ssl_handshake returned -0x6800 (d0_tls_open,369)
08:00:08.320 [D] tou: recv=get_down
08:00:08.330 [W] tls: timeout[800]! mbedtls_ssl_handshake returned -0x6800 (d0_tls_open,369)
08:00:08.330 [D] tou: send=down none
08:00:08.430 [W] tls: timeout[900]! mbedtls_ssl_handshake returned -0x6800 (d0_tls_open,369)
08:00:08.520 [D] tou: recv=get_down
08:00:08.530 [D] tou: send=down none
08:00:08.620 [W] tls: timeout[1000]! mbedtls_ssl_handshake returned -0x6800 (d0_tls_open,369)
08:00:08.720 [W] tls: timeout[1100]! mbedtls_ssl_handshake returned -0x6800 (d0_tls_open,369)
08:00:08.720 [D] tou: recv=get_down
08:00:08.720 [D] tou: send=down none
08:00:08.820 [W] tls: timeout[1200]! mbedtls_ssl_handshake returned -0x6800 (d0_tls_open,369)
08:00:08.920 [W] tls: timeout[1300]! mbedtls_ssl_handshake returned -0x6800 (d0_tls_open,369)
08:00:08.920 [D] tou: recv=get_down
08:00:08.920 [D] tou: send=down none
08:00:08.920 [D] tou: recv=net
08:00:08.930 [D] tou: send=local
08:00:09.020 [W] tls: timeout[1400]! mbedtls_ssl_handshake returned -0x6800 (d0_tls_open,369)
08:00:09.120 [W] tls: timeout[1500]! mbedtls_ssl_handshake returned -0x6800 (d0_tls_open,369)
08:00:09.120 [D] tou: recv=get_down
08:00:09.120 [D] tou: send=down none
08:00:09.130 [D] tls: handshake ok! Protocol is TLSv1.2, Ciphersuite is TLS-PSK-WITH-AES-128-CBC-SHA.
08:00:09.140 [I] ots: Connected.
08:00:09.140 [D] ots: event emit[id=6,txt=ots.connect_ok,ext_len=72]
08:00:09.150 [I] miio_monitor: work time = 9s, memory left = 69152
08:00:09.150 [D] miio_net: reboot trigger will been pulled in 3591s
08:00:09.160 [D] ots: ots.connect_ok[6] happened!
08:00:09.170 [D] miio_net: sta will close in 891s
08:00:09.170 [I] ots: -->sync sent.
08:00:09.320 [D] tou: recv=get_down
08:00:09.320 [D] tou: send=down none
08:00:09.520 [D] tou: recv=get_down
08:00:09.520 [D] tou: send=down none
08:00:09.650 [D] ots: recvd 24Bytes
08:00:09.650 [I] ots: <--sync ack.
08:00:09.650 [D] ots: sync costtime = 470
21:58:55.720 [D] tou: recv=get_down
21:58:55.720 [D] tou: send=down none
21:58:55.820 [D] tou: recv=net
21:58:55.820 [D] tou: send=local
21:58:55.920 [D] tou: recv=get_down
21:58:55.920 [D] tou: send=down none
21:58:56.120 [D] tou: recv=get_down
21:58:56.120 [D] tou: send=down none
21:58:56.170 [I] miio_monitor: work time = 10s, memory left = 69048
21:58:56.170 [D] miio_net: reboot trigger will been pulled in 3590s
21:58:56.170 [D] miio_net: sta will close in 890s
21:58:56.180 [D] ots: login req = 11linp.doorbell.g03
21:58:56.180 [I] ots: -->login sent.
21:58:56.320 [D] tou: recv=get_down
21:58:56.320 [D] tou: send=down none
21:58:56.470 [D] ots: recvd 9Bytes
21:58:56.470 [I] ots: <--login ack, code=0.
21:58:56.470 [D] ots: event emit[id=9,txt=ots.online,ext_len=0]
21:58:56.470 [D] ots: ots.online[9] happened!
21:58:56.480 [D] ots: login elpased 300ms
21:58:56.480 [D] ots: kplv_timeout=45000, kplv_interval=16000
21:58:56.490 [D] miio_ot: ots.online[9] happened!
21:58:56.490 [I] miio_ot: info(ots) will start in 0 ms...
21:58:56.500 [I] miio_instance: miio_online_hook_default called
21:58:56.510 [D] miio_net: miio_net_online_hook called
21:58:56.510 [I] app_main: app_online_hook_default called
21:58:56.520 [D] tou: recv=get_down
21:58:56.520 [D] tou: send=down MIIO_net_change cloud
21:58:56.530 [D] miio_ot: online_cnt = 1, offline_cnt = 0, switch_cnt = 0
21:58:56.540 [I] miio_instance: miio_info_kvs_hook_default called
21:58:56.540 [D] miio_net: miio_net_info_kvs_hook called
21:58:56.550 [I] miio_ot: -->info(ots).
21:58:56.550 [D] ots: {"id":900530177,"method":"_otc.info","params":{"life":10,"uid":1819670695,"model":"linp.doorbell.g03","token":"7bc6f4f2d44aea7804124262e12c50d1","fw_ver":"2.0.5","mcu_fw_ver":"0013","miio_ver":"0.0.5","hw_ver":"esp32","mmfree":66964,"mac":"04:CF:8C:0F:E8:FA","wifi_fw_ver":"v3.1.4-56-g8ffb04960","ap":{"ssid":"SSID","bssid":"SO:ME:MA:CA:DR:ESS","rssi":-55,"primary":7},"netif":{"localIp":"192.168.1.68","mask":"255.255.255.0","gw":"192.168.1.1"}}}
21:58:56.720 [D] tou: recv=get_down
21:58:56.720 [D] tou: send=down none
21:58:56.720 [D] tou: recv=net
21:58:56.720 [D] tou: send=cloud
21:58:56.920 [D] tou: recv=get_down
21:58:56.920 [D] tou: send=down none
21:58:57.110 [D] tou: recv=get_down
21:58:57.120 [D] tou: send=down none
21:58:57.170 [I] miio_monitor: work time = 11s, memory left = 67188
21:58:57.310 [D] tou: recv=get_down
21:58:57.310 [D] tou: send=down none
21:58:57.390 [D] ots: recvd 346Bytes
21:58:57.390 [D] ots: req or ack recvd.
21:58:57.390 [D] ots: {"id":900530177,"result":{"otc_list":[{"ip":"120.92.96.155","port":443},{"ip":"183.84.5.209","port":443},{"ip":"120.92.65.240","port":443},{"ip":"58.83.177.143","port":443}],"otc_test":{"list":[{"ip":"111.206.174.36","port":8053},{"ip":"120.92.153.181","port":8053},{"ip":"110.43.87.239","port":8053}],"interval":1800, "firsttest":249}}}.
21:58:57.420 [D] ots: send_cnt = 1[1], ack_cnt = 1[1,0], costtime = 870[870,870]
21:58:57.430 [D] ots: event emit[id=11,txt=ots.keeplive,ext_len=0]
21:58:57.430 [D] ots: ots.keeplive[11] happened!
21:58:57.440 [I] miio_ot: <--info ack(ots).
21:58:57.440 [D] miio_ot: otc_list[0] = 120.92.96.155::443
21:58:57.450 [D] miio_ot: otc_list[1] = 183.84.5.209::443
21:58:57.460 [D] miio_ot: otc_list[2] = 120.92.65.240::443
21:58:57.460 [D] miio_ot: otc_list[3] = 58.83.177.143::443
21:58:57.470 [D] ots: backlist[2] = 120.92.96.155::443
21:58:57.480 [D] ots: backlist[3] = 183.84.5.209::443
21:58:57.480 [D] miio_ot: otc_test ip[0] = 111.206.174.36::8053
21:58:57.490 [D] miio_ot: otc_test ip[1] = 120.92.153.181::8053
21:58:57.490 [D] miio_ot: otc_test ip[2] = 110.43.87.239::8053
21:58:57.500 [D] miio_ot: otc_test interval=1800000ms, firsttime=249000ms
21:58:57.510 [D] miio_net: miio_net_statistics_kvs_hook called
21:58:57.520 [D] tou: recv=get_down
21:58:57.520 [D] ots: {"id":2041053186,"method":"_otc.ncinfo","params":{"miio_ver":"0.0.5","miio_times":[11,6,4,1],"ap":{"ssid":"SSID","connect_count":1,"repeaters":[{"bssid":"SO:ME:MA:CA:DR:ESS","rssi":-55,"primary":7,"active":1}]},"ot_stat":[1,0,0],"ots_stat":[1,0,840,2150,870,870,1,1,0]}}
21:58:57.550 [D] tou: send=down none
21:58:57.550 [D] ots: {"id":1958674435,"method":"_otc.ncstat","params":{"timestamp":1563199136,"proto":2,"otip":"120.92.96.155","otport":443,"sendcnt":1,"ackcnt":1,"ackcnt_timeout":0,"costtime":870,"rpc":0,"rpcack":0,"dns":2,"keeplive_interval":16,"rpc_local":0,"rpcack_local":0}}
21:58:57.580 [D] ots: {"id":7471108,"method":"props","params":{"ota_progress":101,"ota_state":"idle"}}
21:58:57.590 [D] ots: {"id":786432005,"method":"event.miio_mode","params":[2],"retry":0,"timestamp":6}
21:58:57.620 [D] tou: recv=net
21:58:57.620 [D] tou: send=cloud
21:58:57.710 [D] tou: recv=get_down
21:58:57.720 [D] tou: send=down none
21:58:57.910 [D] tou: recv=get_down
21:58:57.910 [D] tou: send=down none
21:58:58.110 [D] tou: recv=get_down
21:58:58.110 [D] tou: send=down none
21:58:58.170 [I] miio_monitor: work time = 12s, memory left = 62192
21:58:58.310 [D] ots: recvd 40Bytes
21:58:58.310 [D] ots: req or ack recvd.
21:58:58.310 [D] tou: recv=get_down
21:58:58.320 [D] ots: {"id":2041053186,"result":"ok"}.
21:58:58.320 [D] tou: send=down none
21:58:58.320 [D] ots: send_cnt = 4[5], ack_cnt = 1[2,0], costtime = 800[863,862]
21:58:58.330 [D] ots: event emit[id=11,txt=ots.keeplive,ext_len=0]
21:58:58.340 [D] ots: ots.keeplive[11] happened!
21:58:58.510 [D] tou: recv=get_down
21:58:58.510 [D] tou: send=down none
21:58:58.510 [D] tou: recv=net
21:58:58.520 [D] tou: send=cloud
21:58:58.580 [D] tou: recv=mcu_version 0013
21:58:58.580 [D] tou: send=ok
21:58:58.830 [D] tou: recv=props volume 4
21:58:58.830 [D] tou: send=ok
21:58:58.900 [D] tou: recv=get_down
21:58:58.900 [D] tou: send=down none
21:58:59.090 [D] tou: recv=get_down
21:58:59.100 [D] tou: send=down none
21:58:59.130 [D] ots: recvd 40Bytes
21:58:59.130 [D] ots: req or ack recvd.
21:58:59.130 [D] ots: {"id":1958674435,"result":"ok"}.
21:58:59.130 [D] ots: send_cnt = 4[5], ack_cnt = 2[3,0], costtime = 2380[934,940]
21:58:59.140 [D] ots: event emit[id=11,txt=ots.keeplive,ext_len=0]
21:58:59.150 [D] ots: ots.keeplive[11] happened!
21:58:59.170 [I] miio_monitor: work time = 13s, memory left = 65424
21:58:59.180 [I] ots: -->sync sent.
21:58:59.290 [D] tou: recv=get_down
21:58:59.300 [D] tou: send=down none
21:58:59.410 [D] tou: recv=net
21:58:59.410 [D] tou: send=cloud
21:58:59.490 [D] tou: recv=get_down
21:58:59.500 [D] tou: send=down none
21:58:59.520 [D] ots: {"id":552271880,"method":"props","params":{"volume":4}}
21:58:59.690 [D] tou: recv=get_down
21:58:59.700 [D] tou: send=down none
21:58:59.890 [D] tou: recv=get_down
21:58:59.890 [D] tou: send=down none
21:59:00.090 [D] tou: recv=get_down
21:59:00.090 [D] tou: send=down none
21:59:00.170 [I] miio_monitor: work time = 14s, memory left = 62212
21:59:00.290 [D] tou: recv=get_down
21:59:00.290 [D] tou: send=down none
21:59:00.310 [D] tou: recv=net
21:59:00.310 [D] tou: send=cloud
21:59:00.490 [D] tou: recv=get_down
21:59:00.490 [D] tou: send=down none
21:59:00.690 [D] tou: recv=get_down
21:59:00.690 [D] tou: send=down none
21:59:00.880 [D] ots: recvd 24Bytes
21:59:00.880 [I] ots: <--sync ack.
21:59:00.880 [D] ots: sync costtime = 1700
21:59:00.890 [D] tou: recv=get_down
21:59:00.890 [D] tou: send=down none
21:59:01.090 [D] tou: recv=get_down
21:59:01.090 [D] tou: send=down none
21:59:01.170 [I] miio_monitor: work time = 15s, memory left = 68460
21:59:01.210 [D] tou: recv=net
21:59:01.210 [D] tou: send=cloud
21:59:01.290 [D] tou: recv=get_down
21:59:01.290 [D] tou: send=down none
21:59:01.490 [D] tou: recv=get_down
21:59:01.490 [D] tou: send=down none
21:59:01.590 [W] ot: up session[id=7471108] timeout (ot_timer_up_session_timeout,847)
21:59:01.590 [W] miio_info: no "result" in property_ack (send_property_ack,708)
21:59:01.600 [W] ot: up session[id=786432005] timeout (ot_timer_up_session_timeout,847)
21:59:01.600 [W] miio_info: no "result" in property_ack (send_event_ack,1207)
21:59:01.690 [D] tou: recv=get_down
21:59:01.690 [D] tou: send=down none
21:59:01.690 [D] ots: recvd 37Bytes
21:59:01.690 [D] ots: req or ack recvd.
21:59:01.700 [D] ots: {"id":7471108,"result":"ok"}.
21:59:01.700 [D] ots: send_cnt = 5[6], ack_cnt = 3[4,1], costtime = 2380[934,940]
21:59:01.710 [D] ots: event emit[id=11,txt=ots.keeplive,ext_len=0]
21:59:01.720 [D] ots: ots.keeplive[11] happened!
21:59:01.720 [W] ot: up session[id=7471108] not found (ot_up_rpc_delegate_finish,881)
21:59:01.730 [D] ots: recvd 39Bytes
21:59:01.740 [D] ots: req or ack recvd.
21:59:01.740 [D] ots: {"id":786432005,"result":"ok"}.
21:59:01.750 [D] ots: send_cnt = 5[6], ack_cnt = 4[5,2], costtime = 2380[934,940]
21:59:01.750 [D] ots: event emit[id=11,txt=ots.keeplive,ext_len=0]
21:59:01.760 [D] ots: ots.keeplive[11] happened!
21:59:01.770 [W] ot: up session[id=786432005] not found (ot_up_rpc_delegate_finish,881)
21:59:01.780 [D] ots: recvd 39Bytes
21:59:01.780 [D] ots: req or ack recvd.
21:59:01.790 [D] ots: {"id":552271880,"result":"ok"}.
21:59:01.790 [D] ots: send_cnt = 5[6], ack_cnt = 5[6,2], costtime = 4650[1067,1079]
21:59:01.800 [D] ots: event emit[id=11,txt=ots.keeplive,ext_len=0]
21:59:01.810 [D] ots: ots.keeplive[11] happened!
21:59:01.890 [D] tou: recv=get_down
21:59:01.890 [D] tou: send=down none
21:59:02.090 [D] tou: recv=get_down
21:59:02.090 [D] tou: send=down none
21:59:02.100 [D] tou: recv=net
21:59:02.100 [D] tou: send=cloud
21:59:02.170 [I] miio_monitor: work time = 16s, memory left = 68740
21:59:02.280 [D] tou: recv=get_down
21:59:02.280 [D] tou: send=down none
21:59:02.480 [D] tou: recv=get_down
21:59:02.480 [D] tou: send=down none
21:59:02.520 [D] ots: {"id":1657274383,"method":"event.miio_mode","params":[2],"retry":1,"timestamp":6}
21:59:02.680 [D] tou: recv=get_down
21:59:02.680 [D] tou: send=down none
21:59:02.820 [D] ots: recvd 40Bytes
21:59:02.820 [D] ots: req or ack recvd.
21:59:02.820 [D] ots: {"id":1657274383,"result":"ok"}.
21:59:02.820 [D] ots: send_cnt = 6[7], ack_cnt = 6[7,2], costtime = 4950[990,983]
21:59:02.830 [D] ots: event emit[id=11,txt=ots.keeplive,ext_len=0]
21:59:02.840 [D] ots: ots.keeplive[11] happened!
21:59:02.840 [D] miio_info: event.miio_mode sent
21:59:02.880 [D] tou: recv=get_down
21:59:02.880 [D] tou: send=down none
21:59:03.000 [D] tou: recv=net
21:59:03.000 [D] tou: send=cloud
21:59:03.080 [D] tou: recv=get_down
21:59:03.080 [D] tou: send=down none
21:59:03.170 [I] miio_monitor: work time = 17s, memory left = 68880
21:59:03.280 [D] tou: recv=get_down
21:59:03.280 [D] tou: send=down none
21:59:03.480 [D] tou: recv=get_down
21:59:03.480 [D] tou: send=down none
21:59:03.520 [D] ots: {"id":598212624,"method":"props","params":{"ota_progress":101,"ota_state":"idle"}}
21:59:03.680 [D] tou: recv=get_down
21:59:03.680 [D] tou: send=down none
21:59:03.740 [D] ots: recvd 39Bytes
21:59:03.740 [D] ots: req or ack recvd.
21:59:03.740 [D] ots: {"id":598212624,"result":"ok"}.
21:59:03.740 [D] ots: send_cnt = 7[8], ack_cnt = 7[8,2], costtime = 5170[913,906]
21:59:03.750 [D] ots: event emit[id=11,txt=ots.keeplive,ext_len=0]
21:59:03.760 [D] ots: ots.keeplive[11] happened!
21:59:03.880 [D] tou: recv=get_down
21:59:03.880 [D] tou: send=down none
21:59:03.900 [D] tou: recv=net
21:59:03.900 [D] tou: send=cloud
21:59:04.080 [D] tou: recv=get_down
21:59:04.080 [D] tou: send=down none
21:59:04.280 [D] tou: recv=get_down
21:59:04.280 [D] tou: send=down none
21:59:04.480 [D] tou: recv=get_down
21:59:04.480 [D] tou: send=down none
21:59:04.680 [D] tou: recv=get_down
21:59:04.680 [D] tou: send=down none
21:59:04.800 [D] tou: recv=net
21:59:04.800 [D] tou: send=cloud
21:59:04.880 [D] tou: recv=get_down
21:59:04.880 [D] tou: send=down none
21:59:05.080 [D] tou: recv=get_down
21:59:05.080 [D] tou: send=down none
21:59:05.270 [D] tou: recv=get_down
21:59:05.280 [D] tou: send=down none
21:59:05.470 [D] tou: recv=get_down
21:59:05.480 [D] tou: send=down none
21:59:05.670 [D] tou: recv=get_down
21:59:05.670 [D] tou: send=down none
21:59:05.690 [D] tou: recv=net
21:59:05.690 [D] tou: send=cloud
21:59:05.870 [D] tou: recv=get_down
21:59:05.870 [D] tou: send=down none
21:59:06.070 [D] tou: recv=get_down
21:59:06.070 [D] tou: send=down none
21:59:06.170 [I] miio_monitor: work time = 20s, memory left = 68880
21:59:06.270 [D] tou: recv=get_down
21:59:06.270 [D] tou: send=down none
21:59:06.470 [D] tou: recv=get_down
21:59:06.470 [D] tou: send=down none
21:59:06.590 [D] tou: recv=net
21:59:06.590 [D] tou: send=cloud
21:59:06.670 [D] tou: recv=get_down
21:59:06.670 [D] tou: send=down none
21:59:06.870 [D] tou: recv=get_down
21:59:06.870 [D] tou: send=down none
21:59:07.070 [D] tou: recv=get_down
21:59:07.070 [D] tou: send=down none
21:59:07.180 [I] ots: -->sync sent.
21:59:07.270 [D] tou: recv=get_down
21:59:07.270 [D] tou: send=down none
21:59:07.470 [D] tou: recv=get_down
21:59:07.470 [D] tou: send=down none
21:59:07.490 [D] tou: recv=net
21:59:07.490 [D] tou: send=cloud
21:59:07.640 [D] ots: recvd 24Bytes
21:59:07.640 [I] ots: <--sync ack.
21:59:07.640 [D] ots: sync costtime = 460
21:59:07.670 [D] tou: recv=get_down
21:59:07.670 [D] tou: send=down none
21:59:07.870 [D] tou: recv=get_down
21:59:07.870 [D] tou: send=down none
21:59:08.060 [D] tou: recv=get_down
21:59:08.070 [D] tou: send=down none
21:59:08.260 [D] tou: recv=get_down
21:59:08.260 [D] tou: send=down none
21:59:08.380 [D] tou: recv=net
21:59:08.380 [D] tou: send=cloud
21:59:08.460 [D] tou: recv=get_down
21:59:08.460 [D] tou: send=down none
21:59:08.660 [D] tou: recv=get_down
21:59:08.660 [D] tou: send=down none
21:59:08.860 [D] tou: recv=get_down
21:59:08.860 [D] tou: send=down none
21:59:09.060 [D] tou: recv=get_down
21:59:09.060 [D] tou: send=down none
21:59:09.260 [D] tou: recv=get_down
21:59:09.260 [D] tou: send=down none
21:59:09.280 [D] tou: recv=net
21:59:09.280 [D] tou: send=cloud
21:59:09.460 [D] tou: recv=get_down
21:59:09.460 [D] tou: send=down none
21:59:09.660 [D] tou: recv=get_down
21:59:09.660 [D] tou: send=down none
21:59:09.860 [D] tou: recv=get_down
21:59:09.860 [D] tou: send=down none
21:59:10.060 [D] tou: recv=get_down
21:59:10.060 [D] tou: send=down none
21:59:10.180 [D] tou: recv=net
21:59:10.180 [D] tou: send=cloud
21:59:10.260 [D] tou: recv=get_down
21:59:10.260 [D] tou: send=down none
21:59:10.460 [D] tou: recv=get_down
21:59:10.460 [D] tou: send=down none
21:59:10.660 [D] tou: recv=get_down
21:59:10.660 [D] tou: send=down none
21:59:10.860 [D] tou: recv=get_down
21:59:10.860 [D] tou: send=down none
21:59:11.060 [D] tou: recv=get_down
21:59:11.060 [D] tou: send=down none
21:59:11.070 [D] tou: recv=net
21:59:11.070 [D] tou: send=cloud
21:59:11.250 [D] tou: recv=get_down
21:59:11.260 [D] tou: send=down none
21:59:11.450 [D] tou: recv=get_down
21:59:11.450 [D] tou: send=down none
21:59:11.650 [D] tou: recv=get_down
21:59:11.650 [D] tou: send=down none
21:59:11.850 [D] tou: recv=get_down
21:59:11.850 [D] tou: send=down none
21:59:11.970 [D] tou: recv=net
21:59:11.970 [D] tou: send=cloud
21:59:12.050 [D] tou: recv=get_down
21:59:12.050 [D] tou: send=down none
21:59:12.250 [D] tou: recv=get_down
21:59:12.250 [D] tou: send=down none
21:59:12.450 [D] tou: recv=get_down
21:59:12.450 [D] tou: send=down none
21:59:12.650 [D] tou: recv=get_down
21:59:12.650 [D] tou: send=down none
21:59:12.850 [D] tou: recv=get_down
21:59:12.850 [D] tou: send=down none
21:59:12.870 [D] tou: recv=net
21:59:12.870 [D] tou: send=cloud
21:59:13.050 [D] tou: recv=get_down
21:59:13.050 [D] tou: send=down none
21:59:13.250 [D] tou: recv=get_down
21:59:13.250 [D] tou: send=down none
21:59:13.450 [D] tou: recv=get_down
21:59:13.450 [D] tou: send=down none
21:59:13.650 [D] tou: recv=get_down
21:59:13.650 [D] tou: send=down none
21:59:13.770 [D] tou: recv=net
21:59:13.770 [D] tou: send=cloud
21:59:13.850 [D] tou: recv=get_down
21:59:13.850 [D] tou: send=down none
21:59:14.050 [D] tou: recv=get_down
21:59:14.050 [D] tou: send=down none
21:59:14.240 [D] tou: recv=get_down
21:59:14.250 [D] tou: send=down none
21:59:14.440 [D] tou: recv=get_down
21:59:14.450 [D] tou: send=down none
21:59:14.640 [D] tou: recv=get_down
21:59:14.650 [D] tou: send=down none
21:59:14.660 [D] tou: recv=net
21:59:14.660 [D] tou: send=cloud
21:59:14.840 [D] tou: recv=get_down
21:59:14.840 [D] tou: send=down none
21:59:15.040 [D] tou: recv=get_down
21:59:15.040 [D] tou: send=down none
21:59:15.240 [D] tou: recv=get_down
21:59:15.240 [D] tou: send=down none
21:59:15.440 [D] tou: recv=get_down
21:59:15.440 [D] tou: send=down none
21:59:15.560 [D] tou: recv=net
21:59:15.560 [D] tou: send=cloud
21:59:15.640 [D] tou: recv=get_down
21:59:15.640 [D] tou: send=down none
21:59:15.840 [D] tou: recv=get_down
21:59:15.840 [D] tou: send=down none
21:59:16.040 [D] tou: recv=get_down
21:59:16.040 [D] tou: send=down none
21:59:16.170 [I] miio_monitor: work time = 30s, memory left = 68880
21:59:16.240 [D] tou: recv=get_down
21:59:16.240 [D] tou: send=down none
21:59:16.440 [D] tou: recv=get_down
21:59:16.440 [D] tou: send=down none
21:59:16.460 [D] tou: recv=net
21:59:16.460 [D] tou: send=cloud
21:59:16.640 [D] tou: recv=get_down
21:59:16.640 [D] tou: send=down none
21:59:16.840 [D] tou: recv=get_down
21:59:16.840 [D] tou: send=down none
21:59:17.040 [D] tou: recv=get_down
21:59:17.040 [D] tou: send=down none
21:59:17.240 [D] tou: recv=get_down
21:59:17.240 [D] tou: send=down none
21:59:17.350 [D] tou: recv=net
21:59:17.360 [D] tou: send=cloud
21:59:17.440 [D] tou: recv=get_down
21:59:17.440 [D] tou: send=down none
21:59:17.640 [D] tou: recv=get_down
21:59:17.640 [D] tou: send=down none
21:59:17.840 [D] tou: recv=get_down
21:59:17.840 [D] tou: send=down none
21:59:18.040 [D] tou: recv=get_down
21:59:18.040 [D] tou: send=down none
21:59:18.230 [D] tou: recv=get_down
21:59:18.240 [D] tou: send=down none
21:59:18.250 [D] tou: recv=net
21:59:18.250 [D] tou: send=cloud
21:59:18.430 [D] tou: recv=get_down
21:59:18.430 [D] tou: send=down none
21:59:18.630 [D] tou: recv=get_down
21:59:18.630 [D] tou: send=down none
21:59:18.830 [D] tou: recv=get_down
21:59:18.830 [D] tou: send=down none
21:59:19.030 [D] tou: recv=get_down
21:59:19.030 [D] tou: send=down none
21:59:19.150 [D] tou: recv=net
21:59:19.150 [D] tou: send=cloud
21:59:19.230 [D] tou: recv=get_down
21:59:19.230 [D] tou: send=down none
21:59:19.430 [D] tou: recv=get_down
21:59:19.430 [D] tou: send=down none
21:59:19.630 [D] tou: recv=get_down
21:59:19.630 [D] tou: send=down none
21:59:19.760 [I] ots: -->kplv sent.
21:59:19.830 [D] tou: recv=get_down
21:59:19.830 [D] tou: send=down none
21:59:20.030 [D] tou: recv=get_down
21:59:20.030 [D] tou: send=down none
21:59:20.050 [D] tou: recv=net
21:59:20.050 [D] tou: send=cloud
21:59:20.170 [I] miio_monitor: work time = 34s, memory left = 67312
21:59:20.230 [D] tou: recv=get_down
21:59:20.230 [D] tou: send=down none
21:59:20.430 [D] tou: recv=get_down
21:59:20.430 [D] tou: send=down none
21:59:20.520 [D] otu: [192.168.1.65:39715] talking, len=32
21:59:20.520 [W] otu: Token private!!. (otu_packet_handle,733)
21:59:20.540 [D] ots: recvd 8Bytes
21:59:20.540 [I] ots: <--kplv ack.
21:59:20.540 [D] ots: event emit[id=11,txt=ots.keeplive,ext_len=0]
21:59:20.540 [D] ots: ots.keeplive[11] happened!
21:59:20.550 [D] ots: keeplive costtime = 790
21:59:20.630 [D] tou: recv=get_down
21:59:20.630 [D] tou: send=down none
21:59:20.830 [D] tou: recv=get_down
21:59:20.830 [D] tou: send=down none
21:59:20.940 [D] tou: recv=net
21:59:20.940 [D] tou: send=cloud
21:59:21.020 [D] tou: recv=get_down
21:59:21.030 [D] tou: send=down none
21:59:21.170 [I] miio_monitor: work time = 35s, memory left = 68880
21:59:21.220 [D] tou: recv=get_down
21:59:21.220 [D] tou: send=down none
21:59:21.420 [D] tou: recv=get_down
21:59:21.430 [D] tou: send=down none
21:59:21.620 [D] tou: recv=get_down
21:59:21.630 [D] tou: send=down none
21:59:21.820 [D] tou: recv=get_down
21:59:21.820 [D] tou: send=down none
21:59:21.840 [D] tou: recv=net
21:59:21.840 [D] tou: send=cloud
21:59:22.020 [D] tou: recv=get_down
21:59:22.020 [D] tou: send=down none
21:59:22.220 [D] tou: recv=get_down
21:59:22.220 [D] tou: send=down none
21:59:22.420 [D] tou: recv=get_down
21:59:22.420 [D] tou: send=down none
21:59:22.620 [D] tou: recv=get_down
21:59:22.620 [D] tou: send=down none
21:59:22.740 [D] tou: recv=net
21:59:22.740 [D] tou: send=cloud
21:59:22.820 [D] tou: recv=get_down
21:59:22.820 [D] tou: send=down none
21:59:22.880 [D] otu: [192.168.1.65:46869] talking, len=32
21:59:22.880 [W] otu: Token private!!. (otu_packet_handle,733)
21:59:23.020 [D] tou: recv=get_down
21:59:23.020 [D] tou: send=down none
21:59:23.180 [I] ots: -->sync sent.
21:59:23.220 [D] tou: recv=get_down
21:59:23.220 [D] tou: send=down none
21:59:23.420 [D] tou: recv=get_down
21:59:23.420 [D] tou: send=down none
21:59:23.620 [D] tou: recv=get_down
21:59:23.620 [D] tou: send=down none
21:59:23.630 [D] tou: recv=net
21:59:23.630 [D] tou: send=cloud
21:59:23.820 [D] tou: recv=get_down
21:59:23.820 [D] tou: send=down none
21:59:24.010 [D] ots: recvd 24Bytes
21:59:24.010 [I] ots: <--sync ack.
21:59:24.010 [D] ots: sync costtime = 830
21:59:23.020 [D] tou: recv=get_down
21:59:23.020 [D] tou: send=down none
21:59:23.210 [D] tou: recv=get_down
21:59:23.220 [D] tou: send=down none
21:59:23.410 [D] tou: recv=get_down
21:59:23.410 [D] tou: send=down none
21:59:23.530 [D] tou: recv=net
21:59:23.530 [D] tou: send=cloud
21:59:23.610 [D] tou: recv=get_down
21:59:23.610 [D] tou: send=down none
21:59:23.810 [D] tou: recv=get_down
21:59:23.810 [D] tou: send=down none
21:59:24.010 [D] tou: recv=get_down
21:59:24.010 [D] tou: send=down none
21:59:24.210 [D] tou: recv=get_down
21:59:24.210 [D] tou: send=down none
21:59:24.410 [D] tou: recv=get_down
21:59:24.410 [D] tou: send=down none
21:59:24.430 [D] tou: recv=net
21:59:24.430 [D] tou: send=cloud
21:59:24.610 [D] tou: recv=get_down
21:59:24.610 [D] tou: send=down none
21:59:24.810 [D] tou: recv=get_down
21:59:24.810 [D] tou: send=down none
21:59:25.010 [D] tou: recv=get_down
21:59:25.010 [D] tou: send=down none
21:59:25.170 [I] miio_monitor: work time = 40s, memory left = 68880
21:59:25.210 [D] tou: recv=get_down
21:59:25.210 [D] tou: send=down none
21:59:25.330 [D] tou: recv=net
21:59:25.330 [D] tou: send=cloud
21:59:25.410 [D] tou: recv=get_down
21:59:25.410 [D] tou: send=down none
21:59:25.610 [D] tou: recv=get_down
21:59:25.610 [D] tou: send=down none
21:59:25.810 [D] tou: recv=get_down
21:59:25.810 [D] tou: send=down none
21:59:26.010 [D] tou: recv=get_down
21:59:26.010 [D] tou: send=down none
21:59:26.190 [D] otu: [192.168.1.65:42053] talking, len=32
21:59:26.190 [W] otu: Token private!!. (otu_packet_handle,733)
21:59:26.210 [D] tou: recv=get_down
21:59:26.210 [D] tou: send=down none
21:59:26.210 [D] otu: [192.168.1.65:43480] talking, len=80
21:59:26.210 [D] otu: local rpc packet.
21:59:26.220 [D] otu: {"id":6756,"method":"get_volume","params":[]}.
21:59:26.220 [D] otu: down rpc_local = 1
21:59:26.230 [D] tou: recv=net
21:59:26.230 [D] tou: send=cloud
21:59:26.230 [D] ot: get_volume[id=6756] is a ext method
21:59:26.240 [D] miio_ot: ext rpc recvd
21:59:26.250 [I] miio_instance: miio_ext_rpc_hook_default called
21:59:26.410 [D] tou: recv=get_down
21:59:26.410 [D] mcmd: ext rpc[id=6756]
21:59:26.410 [D] mcmd: rpc not found, call rpc_handle_default
21:59:26.410 [D] tou: send=down get_volume
21:59:26.430 [D] tou: recv=result 4
21:59:26.430 [D] mcmd: state=1, timeout=3820, ts=41410, now=41430
21:59:26.430 [D] otu: {"id":6756,"result":[4]}
21:59:26.440 [D] tou: send=ok
21:59:26.440 [D] otu: down rpcack_local = 1
21:59:26.480 [D] otu: [192.168.1.65:39515] talking, len=96
21:59:26.490 [D] otu: local rpc packet.
21:59:26.490 [D] otu: {"id":6757,"method":"get_switch_list","params":[]}.
21:59:26.500 [D] otu: down rpc_local = 2
21:59:26.500 [D] ot: get_switch_list[id=6757] is a ext method
21:59:26.510 [D] miio_ot: ext rpc recvd
21:59:26.510 [I] miio_instance: miio_ext_rpc_hook_default called
21:59:26.610 [D] tou: recv=get_down
21:59:26.610 [D] mcmd: ext rpc[id=6757]
21:59:26.610 [D] mcmd: rpc not found, call rpc_handle_default
21:59:26.610 [D] tou: send=down get_switch_list
21:59:26.630 [D] tou: recv=result 0,255,255,255,255,255,255,255,255,255
21:59:26.630 [D] mcmd: state=1, timeout=3890, ts=41610, now=41630
21:59:26.640 [D] otu: {"id":6757,"result":[0,255,255,255,255,255,255,255,255,255]}
21:59:26.640 [D] tou: send=ok
21:59:26.650 [D] otu: down rpcack_local = 2
21:59:26.810 [D] tou: recv=get_down
21:59:26.810 [D] tou: send=down none
21:59:27.010 [D] tou: recv=get_down
21:59:27.010 [D] tou: send=down none
21:59:27.130 [D] tou: recv=net
21:59:27.130 [D] tou: send=cloud
21:59:27.210 [D] tou: recv=get_down
21:59:27.210 [D] tou: send=down none
21:59:27.410 [D] tou: recv=get_down
21:59:27.410 [D] tou: send=down none
21:59:27.610 [D] tou: recv=get_down
21:59:27.610 [D] tou: send=down none
21:59:27.810 [D] tou: recv=get_down
21:59:27.810 [D] tou: send=down none
21:59:28.010 [D] tou: recv=get_down
21:59:28.010 [D] tou: send=down none
21:59:28.030 [D] tou: recv=net
21:59:28.030 [D] tou: send=cloud
21:59:28.210 [D] tou: recv=get_down
21:59:28.210 [D] tou: send=down none
21:59:28.410 [D] tou: recv=get_down
21:59:28.410 [D] tou: send=down none
21:59:28.610 [D] tou: recv=get_down
21:59:28.610 [D] tou: send=down none
21:59:28.810 [D] tou: recv=get_down
21:59:28.810 [D] tou: send=down none
21:59:28.920 [D] tou: recv=net
21:59:28.920 [D] tou: send=cloud
21:59:29.010 [D] tou: recv=get_down
21:59:29.010 [D] tou: send=down none
21:59:29.200 [D] tou: recv=get_down
21:59:29.210 [D] tou: send=down none
21:59:29.400 [D] tou: recv=get_down
21:59:29.410 [D] tou: send=down none
21:59:29.600 [D] tou: recv=get_down
21:59:29.600 [D] tou: send=down none
21:59:29.800 [D] tou: recv=get_down
21:59:29.810 [D] tou: send=down none
21:59:29.820 [D] tou: recv=net
21:59:29.820 [D] tou: send=cloud
21:59:30.000 [D] tou: recv=get_down
21:59:30.000 [D] tou: send=down none
21:59:30.200 [D] tou: recv=get_down
21:59:30.200 [D] tou: send=down none
21:59:30.400 [D] tou: recv=get_down
21:59:30.400 [D] tou: send=down none
21:59:30.590 [D] otu: [192.168.1.65:38796] talking, len=80
21:59:30.590 [D] otu: local rpc packet.
21:59:30.590 [D] otu: {"id":6758,"method":"set_volume","params":[0]}.
21:59:30.600 [D] otu: down rpc_local = 3
21:59:30.600 [D] tou: recv=get_down
21:59:30.610 [D] ot: set_volume[id=6758] is a ext method
21:59:30.610 [D] miio_ot: ext rpc recvd
21:59:30.620 [D] mcmd: ext rpc[id=6758]
21:59:30.620 [I] miio_instance: miio_ext_rpc_hook_default called
21:59:30.630 [D] mcmd: rpc not found, call rpc_handle_default
21:59:30.630 [D] tou: send=down set_volume 0
21:59:30.650 [D] tou: recv=result "ok"
21:59:30.650 [D] mcmd: state=1, timeout=3980, ts=45620, now=45650
21:59:30.650 [D] otu: {"id":6758,"result":["ok"]}
21:59:30.660 [D] tou: send=ok
21:59:30.660 [D] otu: down rpcack_local = 3
21:59:30.850 [D] tou: recv=props volume 0
21:59:30.850 [D] tou: send=ok
21:59:30.920 [D] tou: recv=net
21:59:30.920 [D] tou: send=cloud
21:59:31.000 [D] tou: recv=get_down
21:59:31.010 [D] tou: send=down none
21:59:31.200 [D] tou: recv=get_down
21:59:31.200 [D] tou: send=down none
21:59:31.400 [D] tou: recv=get_down
21:59:31.410 [D] tou: send=down none
21:59:31.520 [D] ots: {"id":873463882,"method":"props","params":{"volume":0}}
21:59:31.600 [D] tou: recv=get_down
21:59:31.600 [D] tou: send=down none
21:59:31.800 [D] tou: recv=get_down
21:59:31.800 [D] tou: send=down none
21:59:31.820 [D] tou: recv=net
21:59:31.820 [D] tou: send=cloud
21:59:32.000 [D] tou: recv=get_down
21:59:32.000 [D] tou: send=down none
21:59:32.170 [I] miio_monitor: work time = 47s, memory left = 67224
21:59:32.200 [D] tou: recv=get_down
21:59:32.200 [D] tou: send=down none
21:59:32.230 [D] ots: recvd 39Bytes
21:59:32.230 [D] ots: req or ack recvd.
21:59:32.230 [D] ots: {"id":873463882,"result":"ok"}.
21:59:32.230 [D] ots: send_cnt = 8[9], ack_cnt = 8[9,2], costtime = 5880[892,890]
21:59:32.240 [D] ots: event emit[id=11,txt=ots.keeplive,ext_len=0]
21:59:32.250 [D] ots: ots.keeplive[11] happened!
21:59:32.400 [D] tou: recv=get_down
21:59:32.400 [D] tou: send=down none
21:59:32.600 [D] tou: recv=get_down
21:59:32.600 [D] tou: send=down none
21:59:32.720 [D] tou: recv=net
21:59:32.720 [D] tou: send=cloud
21:59:32.800 [D] tou: recv=get_down
21:59:32.800 [D] tou: send=down none
21:59:33.000 [D] tou: recv=get_down
21:59:33.000 [D] tou: send=down none
21:59:33.170 [I] miio_monitor: work time = 48s, memory left = 68880
21:59:33.200 [D] tou: recv=get_down
21:59:33.200 [D] tou: send=down none
21:59:33.400 [D] tou: recv=get_down
21:59:33.400 [D] tou: send=down none
21:59:33.600 [D] tou: recv=get_down
21:59:33.600 [D] tou: send=down none
21:59:33.610 [D] tou: recv=net
21:59:33.610 [D] tou: send=cloud
21:59:33.800 [D] tou: recv=get_down
21:59:33.800 [D] tou: send=down none
21:59:34.000 [D] tou: recv=get_down
21:59:34.000 [D] tou: send=down none
21:59:34.190 [D] tou: recv=get_down
21:59:34.200 [D] tou: send=down none
21:59:34.390 [D] tou: recv=get_down
21:59:34.400 [D] tou: send=down none
21:59:34.510 [D] tou: recv=net
21:59:34.510 [D] tou: send=cloud
21:59:34.590 [D] tou: recv=get_down
21:59:34.590 [D] tou: send=down none
21:59:34.790 [D] tou: recv=get_down
21:59:34.790 [D] tou: send=down none
21:59:34.990 [D] tou: recv=get_down
21:59:34.990 [D] tou: send=down none
21:59:35.170 [I] miio_monitor: work time = 50s, memory left = 68880
21:59:35.190 [D] tou: recv=get_down
21:59:35.190 [D] tou: send=down none
21:59:35.390 [D] tou: recv=get_down
21:59:35.390 [D] tou: send=down none
21:59:35.410 [D] tou: recv=net
21:59:35.410 [D] tou: send=cloud
21:59:35.590 [D] tou: recv=get_down
21:59:35.590 [D] tou: send=down none
21:59:35.790 [D] tou: recv=get_down
21:59:35.790 [D] tou: send=down none
21:59:35.990 [D] tou: recv=get_down
21:59:35.990 [D] tou: send=down none
21:59:36.190 [D] tou: recv=get_down
21:59:36.190 [D] tou: send=down none
21:59:36.300 [D] tou: recv=net
21:59:36.310 [D] tou: send=cloud
21:59:36.390 [D] tou: recv=get_down
21:59:36.390 [D] tou: send=down none
21:59:36.590 [D] tou: recv=get_down
21:59:36.590 [D] tou: send=down none
21:59:36.790 [D] tou: recv=get_down
21:59:36.790 [D] tou: send=down none
21:59:36.980 [D] tou: recv=get_down
21:59:36.990 [D] tou: send=down none
21:59:37.180 [D] tou: recv=get_down
21:59:37.180 [D] tou: send=down none
21:59:37.200 [D] tou: recv=net
21:59:37.200 [D] tou: send=cloud
21:59:37.380 [D] tou: recv=get_down
21:59:37.380 [D] tou: send=down none
21:59:37.580 [D] tou: recv=get_down
21:59:37.580 [D] tou: send=down none
21:59:37.780 [D] tou: recv=get_down
21:59:37.780 [D] tou: send=down none
21:59:37.980 [D] tou: recv=get_down
21:59:37.980 [D] tou: send=down none
21:59:38.100 [D] tou: recv=net
21:59:38.100 [D] tou: send=cloud
21:59:38.180 [D] tou: recv=get_down
21:59:38.180 [D] tou: send=down none
21:59:38.380 [D] tou: recv=get_down
21:59:38.380 [D] tou: send=down none
21:59:38.580 [D] tou: recv=get_down
21:59:38.580 [D] tou: send=down none
21:59:38.780 [D] tou: recv=get_down
21:59:38.780 [D] tou: send=down none
21:59:38.980 [D] tou: recv=get_down
21:59:38.980 [D] tou: send=down none
21:59:39.000 [D] tou: recv=net
21:59:39.000 [D] tou: send=cloud
21:59:39.180 [D] tou: recv=get_down
21:59:39.180 [D] tou: send=down none
21:59:39.380 [D] tou: recv=get_down
21:59:39.380 [D] tou: send=down none
21:59:39.580 [D] tou: recv=get_down
21:59:39.580 [D] tou: send=down none
21:59:39.780 [D] tou: recv=get_down
21:59:39.780 [D] tou: send=down none
21:59:39.890 [D] tou: recv=net
21:59:39.890 [D] tou: send=cloud
21:59:39.970 [D] tou: recv=get_down
21:59:39.980 [D] tou: send=down none
21:59:40.170 [D] tou: recv=get_down
21:59:40.170 [D] tou: send=down none
21:59:40.310 [D] otu: [192.168.1.65:45522] talking, len=32
21:59:40.320 [W] otu: Token private!!. (otu_packet_handle,733)
21:59:40.370 [D] tou: recv=get_down
21:59:40.370 [D] tou: send=down none
21:59:40.570 [D] tou: recv=get_down
21:59:40.570 [D] tou: send=down none
21:59:40.770 [D] tou: recv=get_down
21:59:40.770 [D] tou: send=down none
21:59:40.790 [D] tou: recv=net
21:59:40.790 [D] tou: send=cloud
21:59:40.970 [D] tou: recv=get_down
21:59:40.970 [D] tou: send=down none
21:59:41.170 [D] tou: recv=get_down
21:59:41.170 [D] tou: send=down none
21:59:41.370 [D] tou: recv=get_down
21:59:41.370 [D] tou: send=down none
21:59:41.570 [D] tou: recv=get_down
21:59:41.570 [D] tou: send=down none
21:59:41.690 [D] tou: recv=net
21:59:41.690 [D] tou: send=cloud
21:59:41.770 [D] tou: recv=get_down
21:59:41.770 [D] tou: send=down none
21:59:41.970 [D] tou: recv=get_down
21:59:41.970 [D] tou: send=down none
21:59:42.170 [D] tou: recv=get_down
21:59:42.170 [D] tou: send=down none
21:59:42.370 [D] tou: recv=get_down
21:59:42.370 [D] tou: send=down none
21:59:42.570 [D] tou: recv=get_down
21:59:42.570 [D] tou: send=down none
21:59:42.580 [D] tou: recv=net
21:59:42.590 [D] tou: send=cloud
21:59:42.770 [D] tou: recv=get_down
21:59:42.770 [D] tou: send=down none
21:59:42.970 [D] tou: recv=get_down
21:59:42.970 [D] tou: send=down none
21:59:43.170 [D] tou: recv=get_down
21:59:43.170 [D] tou: send=down none
21:59:43.360 [D] tou: recv=get_down
21:59:43.370 [D] tou: send=down none
21:59:43.480 [D] tou: recv=net
21:59:43.480 [D] tou: send=cloud
21:59:43.560 [D] tou: recv=get_down
21:59:43.560 [D] tou: send=down none
21:59:43.760 [D] tou: recv=get_down
21:59:43.760 [D] tou: send=down none
21:59:43.960 [D] tou: recv=get_down
21:59:43.960 [D] tou: send=down none
21:59:44.160 [D] tou: recv=get_down
21:59:44.160 [D] tou: send=down none
21:59:44.360 [D] tou: recv=get_down
21:59:44.360 [D] tou: send=down none
21:59:44.380 [D] tou: recv=net
21:59:44.380 [D] tou: send=cloud
21:59:44.560 [D] tou: recv=get_down
21:59:44.560 [D] tou: send=down none
21:59:44.760 [D] tou: recv=get_down
21:59:44.760 [D] tou: send=down none
21:59:44.960 [D] tou: recv=get_down
21:59:44.960 [D] tou: send=down none
21:59:45.160 [D] tou: recv=get_down
21:59:45.160 [D] tou: send=down none
21:59:45.170 [I] miio_monitor: work time = 60s, memory left = 68880
21:59:45.240 [D] otu: [192.168.1.65:42158] talking, len=32
21:59:45.240 [W] otu: Token private!!. (otu_packet_handle,733)
21:59:45.250 [D] otu: [192.168.1.65:39017] talking, len=80
21:59:45.250 [D] otu: local rpc packet.
21:59:45.250 [D] otu: {"id":6761,"method":"set_volume","params":[3]}.
21:59:45.260 [D] otu: down rpc_local = 4
21:59:45.260 [D] ot: set_volume[id=6761] is a ext method
21:59:45.270 [D] miio_ot: ext rpc recvd
21:59:45.270 [D] tou: recv=net
21:59:45.280 [I] miio_instance: miio_ext_rpc_hook_default called
21:59:45.290 [D] tou: send=cloud
21:59:45.360 [D] tou: recv=get_down
21:59:45.360 [D] mcmd: ext rpc[id=6761]
21:59:45.360 [D] mcmd: rpc not found, call rpc_handle_default
21:59:45.360 [D] tou: send=down set_volume 3
21:59:45.380 [D] tou: recv=result "ok"
21:59:45.380 [D] mcmd: state=1, timeout=3900, ts=60360, now=60380
21:59:45.380 [D] otu: {"id":6761,"result":["ok"]}
21:59:45.380 [D] tou: send=ok
21:59:45.390 [D] otu: down rpcack_local = 4
21:59:45.600 [D] tou: recv=props volume 3
21:59:45.600 [D] tou: send=ok
21:59:45.780 [D] tou: recv=get_down
21:59:45.780 [D] tou: send=down none
21:59:45.980 [D] tou: recv=get_down
21:59:45.980 [D] tou: send=down none
21:59:46.180 [D] tou: recv=get_down
21:59:46.180 [D] tou: send=down none
21:59:46.380 [D] tou: recv=get_down
21:59:46.380 [D] tou: send=down none
21:59:46.400 [D] tou: recv=net
21:59:46.400 [D] tou: send=cloud
21:59:46.520 [D] ots: {"id":1966538856,"method":"props","params":{"volume":3}}
21:59:46.580 [D] tou: recv=get_down
21:59:46.580 [D] tou: send=down none
21:59:46.780 [D] tou: recv=get_down
21:59:46.780 [D] tou: send=down none
21:59:46.890 [D] ots: recvd 40Bytes
21:59:46.890 [D] ots: req or ack recvd.
21:59:46.890 [D] ots: {"id":1966538856,"result":"ok"}.
21:59:46.900 [D] ots: send_cnt = 9[10], ack_cnt = 9[10,2], costtime = 6260[840,835]
21:59:46.900 [D] ots: event emit[id=11,txt=ots.keeplive,ext_len=0]
21:59:46.910 [D] ots: ots.keeplive[11] happened!
21:59:46.980 [D] tou: recv=get_down
21:59:46.980 [D] tou: send=down none
21:59:47.180 [D] tou: recv=get_down
21:59:47.180 [D] tou: send=down none
21:59:47.290 [D] tou: recv=net
21:59:47.290 [D] tou: send=cloud
21:59:47.380 [D] tou: recv=get_down
21:59:47.380 [D] tou: send=down none
21:59:47.580 [D] tou: recv=get_down
21:59:47.580 [D] tou: send=down none
21:59:47.590 [D] otu: [192.168.1.65:42545] talking, len=80
21:59:47.590 [D] otu: local rpc packet.
21:59:47.590 [D] otu: {"id":6762,"method":"get_volume","params":[]}.
21:59:47.590 [D] otu: down rpc_local = 5
21:59:47.600 [D] ot: get_volume[id=6762] is a ext method
21:59:47.610 [D] miio_ot: ext rpc recvd
21:59:47.610 [I] miio_instance: miio_ext_rpc_hook_default called
21:59:47.770 [D] tou: recv=get_down
21:59:47.780 [D] mcmd: ext rpc[id=6762]
21:59:47.780 [D] mcmd: rpc not found, call rpc_handle_default
21:59:47.780 [D] tou: send=down get_volume
21:59:47.790 [D] tou: recv=result 3
21:59:47.790 [D] mcmd: state=1, timeout=3820, ts=62780, now=62790
21:59:47.800 [D] otu: {"id":6762,"result":[3]}
21:59:47.800 [D] tou: send=ok
21:59:47.810 [D] otu: down rpcack_local = 5
21:59:47.970 [D] tou: recv=get_down
21:59:47.980 [D] tou: send=down none
21:59:48.170 [D] tou: recv=get_down
21:59:48.170 [D] tou: send=down none
21:59:48.190 [D] tou: recv=net
21:59:48.190 [D] tou: send=cloud
21:59:48.210 [D] otu: [192.168.1.65:38296] talking, len=96
21:59:48.210 [D] otu: local rpc packet.
21:59:48.210 [D] otu: {"id":6763,"method":"get_switch_list","params":[]}.
21:59:48.220 [D] otu: down rpc_local = 6
21:59:48.220 [D] ot: get_switch_list[id=6763] is a ext method
21:59:48.230 [D] miio_ot: ext rpc recvd
21:59:48.230 [I] miio_instance: miio_ext_rpc_hook_default called
21:59:48.370 [D] tou: recv=get_down
21:59:48.370 [D] mcmd: ext rpc[id=6763]
21:59:48.370 [D] mcmd: rpc not found, call rpc_handle_default
21:59:48.380 [D] tou: send=down get_switch_list
21:59:48.400 [D] tou: recv=result 0,255,255,255,255,255,255,255,255,255
21:59:48.400 [D] mcmd: state=1, timeout=3850, ts=63370, now=63400
21:59:48.400 [D] otu: {"id":6763,"result":[0,255,255,255,255,255,255,255,255,255]}
21:59:48.410 [D] tou: send=ok
21:59:48.420 [D] otu: down rpcack_local = 6
21:59:48.580 [D] tou: recv=get_down
21:59:48.580 [D] tou: send=down none
21:59:48.780 [D] tou: recv=get_down
21:59:48.780 [D] tou: send=down none
21:59:48.980 [D] tou: recv=get_down
21:59:48.980 [D] tou: send=down none
21:59:49.100 [D] tou: recv=net
21:59:49.100 [D] tou: send=cloud
21:59:49.180 [D] tou: recv=get_down
21:59:49.180 [D] tou: send=down none
21:59:49.380 [D] tou: recv=get_down
21:59:49.380 [D] tou: send=down none
21:59:49.580 [D] tou: recv=get_down
21:59:49.580 [D] tou: send=down none
21:59:49.780 [D] tou: recv=get_down
21:59:49.780 [D] tou: send=down none
21:59:49.970 [D] tou: recv=get_down
21:59:49.980 [D] tou: send=down none
21:59:49.990 [D] tou: recv=net
21:59:49.990 [D] tou: send=cloud
21:59:50.170 [D] tou: recv=get_down
21:59:50.180 [D] tou: send=down none
21:59:50.350 [D] otu: [192.168.1.65:39403] talking, len=80
21:59:50.350 [D] otu: local rpc packet.
21:59:50.350 [D] otu: {"id":6764,"method":"set_volume","params":[2]}.
21:59:50.360 [D] otu: down rpc_local = 7
21:59:50.360 [D] ot: set_volume[id=6764] is a ext method
21:59:50.370 [D] miio_ot: ext rpc recvd
21:59:50.370 [D] tou: recv=get_down
21:59:50.380 [I] miio_instance: miio_ext_rpc_hook_default called
21:59:50.380 [D] mcmd: ext rpc[id=6764]
21:59:50.390 [D] mcmd: rpc not found, call rpc_handle_default
21:59:50.400 [D] tou: send=down set_volume 2
21:59:50.410 [D] tou: recv=result "ok"
21:59:50.410 [D] mcmd: state=1, timeout=3980, ts=65380, now=65410
21:59:50.410 [D] otu: {"id":6764,"result":["ok"]}
21:59:50.420 [D] tou: send=ok
21:59:50.430 [D] otu: down rpcack_local = 7
21:59:50.460 [D] otu: [192.168.1.65:43308] talking, len=80
21:59:50.460 [D] otu: local rpc packet.
21:59:50.470 [D] otu: {"id":6765,"method":"set_volume","params":[1]}.
21:59:50.470 [D] otu: down rpc_local = 8
21:59:50.480 [D] ot: set_volume[id=6765] is a ext method
21:59:50.480 [D] miio_ot: ext rpc recvd
21:59:50.490 [I] miio_instance: miio_ext_rpc_hook_default called
21:59:50.640 [D] tou: recv=props volume 2
21:59:50.640 [D] tou: send=ok
21:59:50.800 [D] tou: recv=get_down
21:59:50.800 [D] mcmd: ext rpc[id=6765]
21:59:50.800 [D] mcmd: rpc not found, call rpc_handle_default
21:59:50.810 [D] tou: send=down set_volume 1
21:59:50.820 [D] tou: recv=result "ok"
21:59:50.820 [D] mcmd: state=1, timeout=3680, ts=65800, now=65820
21:59:50.820 [D] otu: {"id":6765,"result":["ok"]}
21:59:50.830 [D] tou: send=ok
21:59:50.830 [D] otu: down rpcack_local = 8
21:59:51.040 [D] tou: recv=props volume 1
21:59:51.050 [D] tou: send=ok
21:59:51.070 [D] otu: [192.168.1.65:42260] talking, len=80
21:59:51.070 [D] otu: local rpc packet.
21:59:51.080 [D] otu: {"id":6766,"method":"set_volume","params":[0]}.
21:59:51.080 [D] otu: down rpc_local = 9
21:59:51.090 [D] ot: set_volume[id=6766] is a ext method
21:59:51.090 [D] miio_ot: ext rpc recvd
21:59:51.100 [I] miio_instance: miio_ext_rpc_hook_default called
21:59:51.170 [I] miio_monitor: work time = 66s, memory left = 68724
21:59:51.230 [D] tou: recv=get_down
21:59:51.230 [D] mcmd: ext rpc[id=6766]
21:59:51.230 [D] mcmd: rpc not found, call rpc_handle_default
21:59:51.230 [D] tou: send=down set_volume 0
21:59:51.240 [D] tou: recv=result "ok"
21:59:51.250 [D] mcmd: state=1, timeout=3860, ts=66230, now=66250
21:59:51.250 [D] otu: {"id":6766,"result":["ok"]}
21:59:51.250 [D] tou: send=ok
21:59:51.260 [D] otu: down rpcack_local = 9
21:59:51.520 [D] ots: {"id":1080885362,"method":"props","params":{"volume":1}}
21:59:51.520 [D] tou: recv=props volume 0
21:59:51.520 [D] tou: send=ok
21:59:51.620 [D] tou: recv=net
21:59:51.620 [D] tou: send=cloud
21:59:51.700 [D] tou: recv=get_down
21:59:51.700 [D] tou: send=down none
21:59:51.890 [D] ots: recvd 40Bytes
21:59:51.890 [D] ots: req or ack recvd.
21:59:51.890 [D] ots: {"id":1080885362,"result":"ok"}.
21:59:51.900 [D] ots: send_cnt = 10[11], ack_cnt = 10[11,2], costtime = 6640[794,789]
21:59:51.900 [D] tou: recv=get_down
21:59:51.910 [D] ots: event emit[id=11,txt=ots.keeplive,ext_len=0]
21:59:51.920 [D] tou: send=down none
21:59:51.920 [D] ots: ots.keeplive[11] happened!
21:59:52.100 [D] tou: recv=get_down
21:59:52.100 [D] tou: send=down none
21:59:52.170 [I] miio_monitor: work time = 67s, memory left = 68880
21:59:52.300 [D] tou: recv=get_down
21:59:52.300 [D] tou: send=down none
21:59:52.500 [D] tou: recv=get_down
21:59:52.500 [D] tou: send=down none
21:59:52.520 [D] tou: recv=net
21:59:52.520 [D] tou: send=cloud
21:59:52.700 [D] tou: recv=get_down
21:59:52.700 [D] tou: send=down none
21:59:52.710 [D] otu: [192.168.1.65:45790] talking, len=32
21:59:52.710 [W] otu: Token private!!. (otu_packet_handle,733)
21:59:52.810 [D] otu: [192.168.1.65:45535] talking, len=80
21:59:52.810 [D] otu: local rpc packet.
21:59:52.810 [D] otu: {"id":6767,"method":"get_volume","params":[]}.
21:59:52.820 [D] otu: down rpc_local = 10
21:59:52.820 [D] ot: get_volume[id=6767] is a ext method
21:59:52.830 [D] miio_ot: ext rpc recvd
21:59:52.830 [I] miio_instance: miio_ext_rpc_hook_default called
21:59:52.900 [D] tou: recv=get_down
21:59:52.900 [D] mcmd: ext rpc[id=6767]
21:59:52.900 [D] mcmd: rpc not found, call rpc_handle_default
21:59:52.900 [D] tou: send=down get_volume
21:59:52.920 [D] tou: recv=result 0
21:59:52.920 [D] mcmd: state=1, timeout=3920, ts=67900, now=67920
21:59:52.920 [D] otu: {"id":6767,"result":[0]}
21:59:52.930 [D] tou: send=ok
21:59:52.930 [D] otu: down rpcack_local = 10
21:59:53.010 [D] otu: [192.168.1.65:40809] talking, len=96
21:59:53.010 [D] otu: local rpc packet.
21:59:53.010 [D] otu: {"id":6768,"method":"get_switch_list","params":[]}.
21:59:53.020 [D] otu: down rpc_local = 11
21:59:53.030 [D] ot: get_switch_list[id=6768] is a ext method
21:59:53.030 [D] miio_ot: ext rpc recvd
21:59:53.040 [I] miio_instance: miio_ext_rpc_hook_default called
21:59:53.100 [D] tou: recv=get_down
21:59:53.100 [D] mcmd: ext rpc[id=6768]
21:59:53.100 [D] mcmd: rpc not found, call rpc_handle_default
21:59:53.100 [D] tou: send=down get_switch_list
21:59:53.120 [D] tou: recv=result 0,255,255,255,255,255,255,255,255,255
21:59:53.130 [D] mcmd: state=1, timeout=3930, ts=68100, now=68130
21:59:53.130 [D] otu: {"id":6768,"result":[0,255,255,255,255,255,255,255,255,255]}
21:59:53.140 [D] tou: send=ok
21:59:53.140 [D] otu: down rpcack_local = 11
21:59:53.310 [D] tou: recv=get_down
21:59:53.310 [D] tou: send=down none
21:59:53.420 [D] tou: recv=net
21:59:53.420 [D] tou: send=cloud
21:59:53.500 [D] tou: recv=get_down
21:59:53.510 [D] tou: send=down none
21:59:53.520 [D] ots: {"id":1835925622,"method":"props","params":{"volume":0}}
21:59:53.700 [D] tou: recv=get_down
21:59:53.710 [D] tou: send=down none
21:59:53.830 [D] ots: recvd 40Bytes
21:59:53.830 [D] ots: req or ack recvd.
21:59:53.830 [D] ots: {"id":1835925622,"result":"ok"}.
21:59:53.840 [D] ots: send_cnt = 11[12], ack_cnt = 11[12,2], costtime = 6960[746,741]
21:59:53.850 [D] ots: event emit[id=11,txt=ots.keeplive,ext_len=0]
21:59:53.850 [D] ots: ots.keeplive[11] happened!
21:59:53.900 [D] tou: recv=get_down
21:59:53.900 [D] tou: send=down none
21:59:54.100 [D] tou: recv=get_down
21:59:54.100 [D] tou: send=down none
21:59:54.180 [I] ots: -->sync sent.
21:59:54.300 [D] tou: recv=get_down
21:59:54.300 [D] tou: send=down none
21:59:54.320 [D] tou: recv=net
21:59:54.320 [D] tou: send=cloud
21:59:54.500 [D] tou: recv=get_down
21:59:54.500 [D] tou: send=down none
21:59:54.570 [D] ots: recvd 24Bytes
21:59:54.570 [I] ots: <--sync ack.
21:59:54.570 [D] ots: sync costtime = 390
21:59:55.700 [D] tou: recv=get_down
21:59:55.700 [D] tou: send=down none
21:59:55.740 [D] otu: [192.168.1.65:39569] talking, len=80
21:59:55.740 [D] otu: local rpc packet.
21:59:55.740 [D] otu: {"id":6769,"method":"get_volume","params":[]}.
21:59:55.750 [D] otu: down rpc_local = 12
21:59:55.750 [D] ot: get_volume[id=6769] is a ext method
21:59:55.760 [D] miio_ot: ext rpc recvd
21:59:55.760 [I] miio_instance: miio_ext_rpc_hook_default called
21:59:55.900 [D] tou: recv=get_down
21:59:55.900 [D] mcmd: ext rpc[id=6769]
21:59:55.900 [D] mcmd: rpc not found, call rpc_handle_default
21:59:55.910 [D] tou: send=down get_volume
21:59:55.920 [D] tou: recv=result 0
21:59:55.920 [D] mcmd: state=1, timeout=3850, ts=69900, now=69920
21:59:55.920 [D] otu: {"id":6769,"result":[0]}
21:59:55.930 [D] tou: send=ok
21:59:55.930 [D] otu: down rpcack_local = 12
21:59:55.970 [D] otu: [192.168.1.65:43333] talking, len=96
21:59:55.980 [D] otu: local rpc packet.
21:59:55.980 [D] otu: {"id":6770,"method":"get_switch_list","params":[]}.
21:59:55.980 [D] otu: down rpc_local = 13
21:59:55.990 [D] ot: get_switch_list[id=6770] is a ext method
21:59:55.990 [D] miio_ot: ext rpc recvd
21:59:56.000 [I] miio_instance: miio_ext_rpc_hook_default called
21:59:56.100 [D] tou: recv=get_down
21:59:56.100 [D] mcmd: ext rpc[id=6770]
21:59:56.100 [D] mcmd: rpc not found, call rpc_handle_default
21:59:56.110 [D] tou: send=down get_switch_list
21:59:56.130 [D] tou: recv=result 0,255,255,255,255,255,255,255,255,255
21:59:56.130 [D] mcmd: state=1, timeout=3890, ts=70100, now=70130
21:59:56.130 [D] otu: {"id":6770,"result":[0,255,255,255,255,255,255,255,255,255]}
21:59:56.140 [D] tou: send=ok
21:59:56.140 [D] otu: down rpcack_local = 13
21:59:56.170 [I] miio_monitor: work time = 70s, memory left = 68608
21:59:56.230 [D] tou: recv=net
21:59:56.230 [D] tou: send=cloud
21:59:56.310 [D] tou: recv=get_down
21:59:56.310 [D] tou: send=down none
21:59:56.510 [D] tou: recv=get_down
21:59:56.510 [D] tou: send=down none
21:59:56.710 [D] tou: recv=get_down
21:59:56.710 [D] tou: send=down none
21:59:56.910 [D] tou: recv=get_down
21:59:56.910 [D] tou: send=down none
21:59:57.100 [D] tou: recv=get_down
21:59:57.100 [D] tou: send=down none
21:59:57.120 [D] tou: recv=net
21:59:57.120 [D] tou: send=cloud
21:59:57.170 [I] miio_monitor: work time = 71s, memory left = 68880
21:59:57.300 [D] tou: recv=get_down
21:59:57.300 [D] tou: send=down none
21:59:57.500 [D] tou: recv=get_down
21:59:57.510 [D] tou: send=down none
21:59:57.700 [D] tou: recv=get_down
21:59:57.700 [D] tou: send=down none
21:59:57.900 [D] tou: recv=get_down
21:59:57.900 [D] tou: send=down none
21:59:58.020 [D] tou: recv=net
21:59:58.020 [D] tou: send=cloud
21:59:58.100 [D] tou: recv=get_down
21:59:58.100 [D] tou: send=down none
21:59:58.300 [D] tou: recv=get_down
21:59:58.310 [D] tou: send=down none
21:59:58.500 [D] tou: recv=get_down
21:59:58.500 [D] tou: send=down none
21:59:58.700 [D] tou: recv=get_down
21:59:58.700 [D] tou: send=down none
21:59:58.900 [D] tou: recv=get_down
21:59:58.900 [D] tou: send=down none
21:59:58.920 [D] tou: recv=net
21:59:58.920 [D] tou: send=cloud
21:59:59.100 [D] tou: recv=get_down
21:59:59.100 [D] tou: send=down none
21:59:59.300 [D] tou: recv=get_down
21:59:59.300 [D] tou: send=down none
21:59:59.500 [D] tou: recv=get_down
21:59:59.500 [D] tou: send=down none
21:59:59.700 [D] tou: recv=get_down
21:59:59.700 [D] tou: send=down none
21:59:59.810 [D] tou: recv=net
21:59:59.810 [D] tou: send=cloud
21:59:59.900 [D] tou: recv=get_down
21:59:59.900 [D] tou: send=down none
22:00:00.090 [D] tou: recv=get_down
22:00:00.100 [D] tou: send=down none
22:00:00.290 [D] tou: recv=get_down
22:00:00.290 [D] tou: send=down none
22:00:00.490 [D] tou: recv=get_down
22:00:00.490 [D] tou: send=down none
22:00:00.690 [D] tou: recv=get_down
22:00:00.690 [D] tou: send=down none
22:00:00.710 [D] tou: recv=net
22:00:00.710 [D] tou: send=cloud
22:00:00.890 [D] tou: recv=get_down
22:00:00.890 [D] tou: send=down none
22:00:01.090 [D] tou: recv=get_down
22:00:01.090 [D] tou: send=down none
22:00:01.290 [D] tou: recv=get_down
22:00:01.290 [D] tou: send=down none
22:00:01.490 [D] tou: recv=get_down
22:00:01.490 [D] tou: send=down none
22:00:01.610 [D] tou: recv=net
22:00:01.610 [D] tou: send=cloud
22:00:01.690 [D] tou: recv=get_down
22:00:01.690 [D] tou: send=down none
22:00:01.890 [D] tou: recv=get_down
22:00:01.890 [D] tou: send=down none
22:00:02.090 [D] tou: recv=get_down
22:00:02.090 [D] tou: send=down none
22:00:02.290 [D] tou: recv=get_down
22:00:02.290 [D] tou: send=down none
22:00:02.490 [D] tou: recv=get_down
22:00:02.490 [D] tou: send=down none
22:00:02.500 [D] tou: recv=net
22:00:02.500 [D] tou: send=cloud
22:00:02.690 [D] tou: recv=get_down
22:00:02.690 [D] tou: send=down none
22:00:02.880 [D] tou: recv=get_down
22:00:02.890 [D] tou: send=down none
22:00:03.080 [D] tou: recv=get_down
22:00:03.080 [D] tou: send=down none
22:00:03.280 [D] tou: recv=get_down
22:00:03.280 [D] tou: send=down none
22:00:03.400 [D] tou: recv=net
22:00:03.400 [D] tou: send=cloud
22:00:03.480 [D] tou: recv=get_down
22:00:03.490 [D] tou: send=down none
22:00:03.680 [D] tou: recv=get_down
22:00:03.690 [D] tou: send=down none
22:00:03.880 [D] tou: recv=get_down
22:00:03.880 [D] tou: send=down none
22:00:04.080 [D] tou: recv=get_down
22:00:04.080 [D] tou: send=down none
22:00:04.280 [D] tou: recv=get_down
22:00:04.280 [D] tou: send=down none
22:00:04.300 [D] tou: recv=net
22:00:04.300 [D] tou: send=cloud
22:00:04.480 [D] tou: recv=get_down
22:00:04.480 [D] tou: send=down none
22:00:04.680 [D] tou: recv=get_down
22:00:04.680 [D] tou: send=down none
22:00:04.880 [D] tou: recv=get_down
22:00:04.880 [D] tou: send=down none
22:00:05.080 [D] tou: recv=get_down
22:00:05.080 [D] tou: send=down none
22:00:05.200 [D] tou: recv=net
22:00:05.200 [D] tou: send=cloud
22:00:05.280 [D] tou: recv=get_down
22:00:05.280 [D] tou: send=down none
22:00:05.480 [D] tou: recv=get_down
22:00:05.480 [D] tou: send=down none
22:00:05.680 [D] tou: recv=get_down
22:00:05.680 [D] tou: send=down none
22:00:05.880 [D] tou: recv=get_down
22:00:05.880 [D] tou: send=down none
22:00:06.070 [D] tou: recv=get_down
22:00:06.080 [D] tou: send=down none
22:00:06.090 [D] tou: recv=net
22:00:06.090 [D] tou: send=cloud
22:00:06.170 [I] miio_monitor: work time = 80s, memory left = 68880
22:00:06.270 [D] tou: recv=get_down
22:00:06.270 [D] tou: send=down none
22:00:06.470 [D] tou: recv=get_down
22:00:06.470 [D] tou: send=down none
22:00:06.670 [D] tou: recv=get_down
22:00:06.670 [D] tou: send=down none
22:00:06.870 [D] tou: recv=get_down
22:00:06.870 [D] tou: send=down none
22:00:06.990 [D] tou: recv=net
22:00:06.990 [D] tou: send=cloud
22:00:07.070 [D] tou: recv=get_down
22:00:07.070 [D] tou: send=down none
22:00:07.270 [D] tou: recv=get_down
22:00:07.270 [D] tou: send=down none
22:00:07.470 [D] tou: recv=get_down
22:00:07.470 [D] tou: send=down none
22:00:07.670 [D] tou: recv=get_down
22:00:07.670 [D] tou: send=down none
22:00:07.870 [D] tou: recv=get_down
22:00:07.870 [D] tou: send=down none
22:00:07.890 [D] tou: recv=net
22:00:07.890 [D] tou: send=cloud
22:00:08.070 [D] tou: recv=get_down
22:00:08.070 [D] tou: send=down none
22:00:08.270 [D] tou: recv=get_down
22:00:08.270 [D] tou: send=down none
22:00:08.470 [D] tou: recv=get_down
22:00:08.470 [D] tou: send=down none
22:00:08.660 [D] tou: recv=get_down
22:00:08.670 [D] tou: send=down none
22:00:08.780 [D] tou: recv=net
22:00:08.780 [D] tou: send=cloud
22:00:08.860 [D] tou: recv=get_down
22:00:08.860 [D] tou: send=down none
22:00:09.060 [D] tou: recv=get_down
22:00:09.060 [D] tou: send=down none
22:00:09.310 [D] tou: recv=event switch_pressed_00
22:00:09.310 [D] ots: {"id":623509652,"method":"event.switch_pressed_00","params":[],"retry":0,"timestamp":1563199209}
22:00:09.320 [D] tou: send=ok
22:00:09.560 [D] tou: recv=event switch_trigger 0
22:00:09.560 [D] ots: {"id":316997783,"method":"event.switch_trigger","params":[0],"retry":0,"timestamp":1563199209}
22:00:09.570 [D] tou: send=ok
22:00:09.580 [D] ots: recvd 39Bytes
22:00:09.590 [D] ots: req or ack recvd.
22:00:09.590 [D] ots: {"id":623509652,"result":"ok"}.
22:00:09.590 [D] ots: send_cnt = 13[14], ack_cnt = 12[13,2], costtime = 7240[699,694]
22:00:09.600 [D] ots: event emit[id=11,txt=ots.keeplive,ext_len=0]
22:00:09.600 [D] ots: ots.keeplive[11] happened!
22:00:09.610 [D] miio_info: event.switch_pressed_00 sent
22:00:09.990 [D] ots: recvd 39Bytes
22:00:09.990 [D] ots: req or ack recvd.
22:00:09.990 [D] ots: {"id":316997783,"result":"ok"}.
22:00:09.990 [D] ots: send_cnt = 13[14], ack_cnt = 13[14,2], costtime = 7670[672,669]
22:00:10.000 [D] ots: event emit[id=11,txt=ots.keeplive,ext_len=0]
22:00:10.010 [D] ots: ots.keeplive[11] happened!
22:00:10.010 [D] miio_info: event.switch_trigger sent
22:00:10.490 [D] tou: recv=get_down
22:00:10.490 [D] tou: send=down none
22:00:10.490 [D] tou: recv=net
22:00:10.490 [D] tou: send=cloud
22:00:10.690 [D] tou: recv=get_down
22:00:10.690 [D] tou: send=down none
22:00:10.890 [D] tou: recv=get_down
22:00:10.890 [D] tou: send=down none
22:00:11.080 [D] tou: recv=get_down
22:00:11.090 [D] tou: send=down none
22:00:11.280 [D] tou: recv=get_down
22:00:11.280 [D] tou: send=down none
22:00:11.380 [D] tou: recv=net
22:00:11.380 [D] tou: send=cloud
22:00:11.480 [D] tou: recv=get_down
22:00:11.480 [D] tou: send=down none
22:00:11.680 [D] tou: recv=get_down
22:00:11.680 [D] tou: send=down none
22:00:11.880 [D] tou: recv=get_down
22:00:11.880 [D] tou: send=down none
22:00:12.040 [D] tou: recv=event switch_pressed_00
22:00:12.040 [D] ots: {"id":1963786396,"method":"event.switch_pressed_00","params":[],"retry":0,"timestamp":1563199212}
22:00:12.050 [D] tou: send=ok
22:00:12.170 [I] miio_monitor: work time = 86s, memory left = 67084
22:00:12.290 [D] tou: recv=event switch_trigger 0
22:00:12.290 [D] ots: {"id":1277362333,"method":"event.switch_trigger","params":[0],"retry":0,"timestamp":1563199212}
22:00:12.300 [D] tou: send=ok
22:00:12.350 [D] ots: recvd 40Bytes
22:00:12.350 [D] ots: req or ack recvd.
22:00:12.350 [D] ots: {"id":1963786396,"result":"ok"}.
22:00:12.350 [D] ots: send_cnt = 15[16], ack_cnt = 14[15,2], costtime = 7980[635,631]
22:00:12.360 [D] ots: event emit[id=11,txt=ots.keeplive,ext_len=0]
22:00:12.370 [D] ots: ots.keeplive[11] happened!
22:00:12.370 [D] miio_info: event.switch_pressed_00 sent
22:00:12.760 [D] ots: recvd 40Bytes
22:00:12.760 [D] ots: req or ack recvd.
22:00:12.760 [D] ots: {"id":1277362333,"result":"ok"}.
22:00:12.760 [D] ots: send_cnt = 15[16], ack_cnt = 15[16,2], costtime = 8450[618,616]
22:00:12.770 [D] ots: event emit[id=11,txt=ots.keeplive,ext_len=0]
22:00:12.780 [D] ots: ots.keeplive[11] happened!
22:00:12.780 [D] miio_info: event.switch_trigger sent
22:00:13.170 [I] miio_monitor: work time = 87s, memory left = 68880
22:00:13.210 [D] tou: recv=get_down
22:00:13.210 [D] tou: send=down none
22:00:13.210 [D] tou: recv=net
22:00:13.210 [D] tou: send=cloud
22:00:13.410 [D] tou: recv=get_down
22:00:13.410 [D] tou: send=down none
22:00:13.610 [D] tou: recv=get_down
22:00:13.610 [D] tou: send=down none
22:00:13.810 [D] tou: recv=get_down
22:00:13.810 [D] tou: send=down none
22:00:14.010 [D] tou: recv=get_down
22:00:14.010 [D] tou: send=down none
22:00:14.110 [D] tou: recv=net
22:00:14.110 [D] tou: send=cloud
22:00:14.210 [D] tou: recv=get_down
22:00:14.210 [D] tou: send=down none
22:00:14.320 [D] tou: recv=event switch_pressed_00
22:00:14.330 [D] ots: {"id":1917517986,"method":"event.switch_pressed_00","params":[],"retry":0,"timestamp":1563199214}
22:00:14.340 [D] tou: send=ok
22:00:14.580 [D] tou: recv=event switch_trigger 0
22:00:14.580 [D] ots: {"id":2088763557,"method":"event.switch_trigger","params":[0],"retry":0,"timestamp":1563199214}
22:00:14.580 [D] tou: send=ok
22:00:14.610 [D] ots: recvd 40Bytes
22:00:14.610 [D] ots: req or ack recvd.
22:00:14.610 [D] ots: {"id":1917517986,"result":"ok"}.
22:00:14.610 [D] ots: send_cnt = 17[18], ack_cnt = 16[17,2], costtime = 8730[584,580]
22:00:14.620 [D] ots: event emit[id=11,txt=ots.keeplive,ext_len=0]
22:00:14.630 [D] ots: ots.keeplive[11] happened!
22:00:14.630 [D] miio_info: event.switch_pressed_00 sent
22:00:15.110 [D] ots: recvd 40Bytes
22:00:15.110 [D] ots: req or ack recvd.
22:00:15.110 [D] ots: {"id":2088763557,"result":"ok"}.
22:00:15.110 [D] ots: send_cnt = 17[18], ack_cnt = 17[18,2], costtime = 9260[578,577]
22:00:15.120 [D] ots: event emit[id=11,txt=ots.keeplive,ext_len=0]
22:00:15.130 [D] ots: ots.keeplive[11] happened!
22:00:15.130 [D] miio_info: event.switch_trigger sent
22:00:15.510 [D] tou: recv=get_down
22:00:15.510 [D] tou: send=down none
22:00:15.510 [D] tou: recv=net
22:00:15.510 [D] tou: send=cloud
22:00:15.710 [D] tou: recv=get_down
22:00:15.710 [D] tou: send=down none
22:00:15.910 [D] tou: recv=get_down
22:00:15.910 [D] tou: send=down none
22:00:16.100 [D] tou: recv=get_down
22:00:16.110 [D] tou: send=down none
22:00:16.170 [I] miio_monitor: work time = 90s, memory left = 68880
22:00:16.300 [D] tou: recv=get_down
22:00:16.300 [D] tou: send=down none
22:00:16.400 [D] tou: recv=net
22:00:16.400 [D] tou: send=cloud
22:00:16.500 [D] tou: recv=get_down
22:00:16.500 [D] tou: send=down none
22:00:16.700 [D] tou: recv=get_down
22:00:16.700 [D] tou: send=down none
22:00:16.900 [D] tou: recv=get_down
22:00:16.900 [D] tou: send=down none
22:00:17.100 [D] tou: recv=get_down
22:00:17.100 [D] tou: send=down none
22:00:17.300 [D] tou: recv=get_down
22:00:17.300 [D] tou: send=down none
22:00:17.300 [D] tou: recv=net
22:00:17.300 [D] tou: send=cloud
22:00:17.500 [D] tou: recv=get_down
22:00:17.500 [D] tou: send=down none
22:00:17.700 [D] tou: recv=get_down
22:00:17.700 [D] tou: send=down none
22:00:17.900 [D] tou: recv=get_down
22:00:17.900 [D] tou: send=down none
22:00:18.100 [D] tou: recv=get_down
22:00:18.100 [D] tou: send=down none
22:00:18.200 [D] tou: recv=net
22:00:18.200 [D] tou: send=cloud
22:00:18.300 [D] tou: recv=get_down
22:00:18.300 [D] tou: send=down none
22:00:18.500 [D] tou: recv=get_down
22:00:18.500 [D] tou: send=down none
22:00:18.700 [D] tou: recv=get_down
22:00:18.700 [D] tou: send=down none
22:00:18.900 [D] tou: recv=get_down
22:00:18.900 [D] tou: send=down none
22:00:19.100 [D] tou: recv=get_down
22:00:19.100 [D] tou: send=down none
22:00:19.100 [D] tou: recv=net
22:00:19.100 [D] tou: send=cloud
22:00:19.290 [D] tou: recv=get_down
22:00:19.300 [D] tou: send=down none
22:00:19.500 [D] tou: recv=get_down
22:00:19.500 [D] tou: send=down none
22:00:19.690 [D] tou: recv=get_down
22:00:19.700 [D] tou: send=down none
22:00:19.890 [D] tou: recv=get_down
22:00:19.890 [D] tou: send=down none
22:00:19.990 [D] tou: recv=net
22:00:19.990 [D] tou: send=cloud
22:00:20.090 [D] tou: recv=get_down
22:00:20.090 [D] tou: send=down none
22:00:20.290 [D] tou: recv=get_down
22:00:20.290 [D] tou: send=down none
22:00:20.490 [D] tou: recv=get_down
22:00:20.490 [D] tou: send=down none
22:00:20.690 [D] tou: recv=get_down
22:00:20.690 [D] tou: send=down none
22:00:20.890 [D] tou: recv=get_down
22:00:20.890 [D] tou: send=down none
22:00:20.890 [D] tou: recv=net
22:00:20.890 [D] tou: send=cloud
22:00:21.090 [D] tou: recv=get_down
22:00:21.090 [D] tou: send=down none
22:00:21.290 [D] tou: recv=get_down
22:00:21.290 [D] tou: send=down none
22:00:21.490 [D] tou: recv=get_down
22:00:21.490 [D] tou: send=down none
22:00:21.690 [D] tou: recv=get_down
22:00:21.690 [D] tou: send=down none
22:00:21.790 [D] tou: recv=net
22:00:21.790 [D] tou: send=cloud
22:00:21.890 [D] tou: recv=get_down
22:00:21.890 [D] tou: send=down none
22:00:22.090 [D] tou: recv=get_down
22:00:22.090 [D] tou: send=down none
22:00:22.170 [D] miio_net: sta offline 0 times in last 900s
22:00:22.290 [D] tou: recv=get_down
22:00:22.290 [D] tou: send=down none
22:00:22.490 [D] tou: recv=get_down
22:00:22.490 [D] tou: send=down none
22:00:22.690 [D] tou: recv=get_down
22:00:22.690 [D] tou: send=down none
22:00:22.690 [D] tou: recv=net
22:00:22.690 [D] tou: send=cloud
22:00:22.890 [D] tou: recv=get_down
22:00:22.890 [D] tou: send=down none
22:00:23.080 [D] tou: recv=get_down
22:00:23.080 [D] tou: send=down none
22:00:23.280 [D] tou: recv=get_down
22:00:23.280 [D] tou: send=down none
22:00:23.480 [D] tou: recv=get_down
22:00:23.480 [D] tou: send=down none
22:00:23.580 [D] tou: recv=net
22:00:23.580 [D] tou: send=cloud
22:00:23.680 [D] tou: recv=get_down
22:00:23.680 [D] tou: send=down none
22:00:23.880 [D] tou: recv=get_down
22:00:23.880 [D] tou: send=down none
22:00:24.080 [D] tou: recv=get_down
22:00:24.080 [D] tou: send=down none
22:00:24.280 [D] tou: recv=get_down
22:00:24.280 [D] tou: send=down none
22:00:24.480 [D] tou: recv=get_down
22:00:24.480 [D] tou: send=down none
22:00:24.480 [D] tou: recv=net
22:00:24.480 [D] tou: send=cloud
22:00:24.680 [D] tou: recv=get_down
22:00:24.680 [D] tou: send=down none
22:00:24.880 [D] tou: recv=get_down
22:00:24.880 [D] tou: send=down none
22:00:25.080 [D] tou: recv=get_down
22:00:25.080 [D] tou: send=down none
22:00:25.280 [D] tou: recv=get_down
22:00:25.280 [D] tou: send=down none
22:00:25.380 [D] tou: recv=net
22:00:25.380 [D] tou: send=cloud
22:00:25.480 [D] tou: recv=get_down
22:00:25.480 [D] tou: send=down none
22:00:25.680 [D] tou: recv=get_down
22:00:25.680 [D] tou: send=down none
22:00:25.880 [D] tou: recv=get_down
22:00:25.880 [D] tou: send=down none
22:00:26.080 [D] tou: recv=get_down
22:00:26.080 [D] tou: send=down none
22:00:26.170 [I] miio_monitor: work time = 100s, memory left = 68880
22:00:26.280 [D] tou: recv=get_down
22:00:26.280 [D] tou: send=down none
22:00:26.280 [D] tou: recv=net
22:00:26.280 [D] tou: send=cloud
22:00:26.480 [D] tou: recv=get_down
22:00:26.480 [D] tou: send=down none
22:00:26.680 [D] tou: recv=get_down
22:00:26.680 [D] tou: send=down none
22:00:26.880 [D] tou: recv=get_down
22:00:26.880 [D] tou: send=down none
22:00:27.080 [D] tou: recv=get_down
22:00:27.080 [D] tou: send=down none
22:00:27.180 [D] tou: recv=net
22:00:27.180 [D] tou: send=cloud
22:00:27.280 [D] tou: recv=get_down
22:00:27.280 [D] tou: send=down none
22:00:27.480 [D] tou: recv=get_down
22:00:27.480 [D] tou: send=down none
22:00:27.680 [D] tou: recv=get_down
22:00:27.680 [D] tou: send=down none
22:00:27.880 [D] tou: recv=get_down
22:00:27.880 [D] tou: send=down none
22:00:28.080 [D] tou: recv=get_down
22:00:28.080 [D] tou: send=down none
22:00:28.080 [D] tou: recv=net
22:00:28.080 [D] tou: send=cloud
22:00:28.280 [D] tou: recv=get_down
22:00:28.280 [D] tou: send=down none
22:00:28.480 [D] tou: recv=get_down
22:00:28.480 [D] tou: send=down none
22:00:28.670 [D] tou: recv=get_down
22:00:28.680 [D] tou: send=down none
22:00:28.870 [D] tou: recv=get_down
22:00:28.870 [D] tou: send=down none
22:00:28.970 [D] tou: recv=net
22:00:28.970 [D] tou: send=cloud
22:00:29.070 [D] tou: recv=get_down
22:00:29.070 [D] tou: send=down none
22:00:29.270 [D] tou: recv=get_down
22:00:29.270 [D] tou: send=down none
22:00:29.470 [D] tou: recv=get_down
22:00:29.470 [D] tou: send=down none
22:00:29.670 [D] tou: recv=get_down
22:00:29.670 [D] tou: send=down none
22:00:29.870 [D] tou: recv=get_down
22:00:29.870 [D] tou: send=down none
22:00:29.870 [D] tou: recv=net
22:00:29.870 [D] tou: send=cloud
22:00:30.070 [D] tou: recv=get_down
22:00:30.070 [D] tou: send=down none
22:00:30.270 [D] tou: recv=get_down
22:00:30.270 [D] tou: send=down none
22:00:30.470 [D] tou: recv=get_down
22:00:30.470 [D] tou: send=down none
22:00:30.670 [D] tou: recv=get_down
22:00:30.670 [D] tou: send=down none
22:00:30.770 [D] tou: recv=net
22:00:30.770 [D] tou: send=cloud
22:00:30.870 [D] tou: recv=get_down
22:00:30.870 [D] tou: send=down none
22:00:31.070 [D] tou: recv=get_down
22:00:31.070 [D] tou: send=down none
22:00:31.130 [I] ots: -->kplv sent.
22:00:31.170 [I] miio_monitor: work time = 105s, memory left = 67068
22:00:31.270 [D] tou: recv=get_down
22:00:31.270 [D] tou: send=down none
22:00:31.460 [D] tou: recv=get_down
22:00:31.470 [D] tou: send=down none
22:00:31.670 [D] tou: recv=get_down
22:00:31.670 [D] tou: send=down none
22:00:31.670 [D] tou: recv=net
22:00:31.670 [D] tou: send=cloud
22:00:31.870 [D] tou: recv=get_down
22:00:31.870 [D] tou: send=down none
22:00:32.060 [D] tou: recv=get_down
22:00:32.070 [D] tou: send=down none
22:00:32.170 [I] miio_monitor: work time = 106s, memory left = 67312
22:00:32.260 [D] tou: recv=get_down
22:00:32.260 [D] tou: send=down none
22:00:32.460 [D] tou: recv=get_down
22:00:32.460 [D] tou: send=down none
22:00:32.560 [D] tou: recv=net
22:00:32.560 [D] tou: send=cloud
22:00:32.660 [D] tou: recv=get_down
22:00:32.660 [D] tou: send=down none
22:00:32.860 [D] tou: recv=get_down
22:00:32.860 [D] tou: send=down none
22:00:33.060 [D] tou: recv=get_down
22:00:33.060 [D] tou: send=down none
22:00:33.260 [D] tou: recv=get_down
22:00:33.260 [D] tou: send=down none
22:00:33.460 [D] tou: recv=get_down
22:00:33.460 [D] tou: send=down none
22:00:33.460 [D] tou: recv=net
22:00:33.460 [D] tou: send=cloud
22:00:33.660 [D] tou: recv=get_down
22:00:33.660 [D] tou: send=down none
22:00:33.850 [D] ots: recvd 8Bytes
22:00:33.850 [I] ots: <--kplv ack.
22:00:33.850 [D] ots: event emit[id=11,txt=ots.keeplive,ext_len=0]
22:00:33.850 [D] ots: ots.keeplive[11] happened!
22:00:33.860 [D] ots: keeplive costtime = 2730
22:00:33.860 [D] tou: recv=get_down
22:00:33.870 [D] tou: send=down none
22:00:34.060 [D] tou: recv=get_down
22:00:34.060 [D] tou: send=down none
22:00:34.170 [I] miio_monitor: work time = 108s, memory left = 68880
22:00:34.260 [D] tou: recv=get_down
22:00:34.260 [D] tou: send=down none
22:00:34.360 [D] tou: recv=net
22:00:34.360 [D] tou: send=cloud
22:00:34.460 [D] tou: recv=get_down
22:00:34.460 [D] tou: send=down none
22:00:34.660 [D] tou: recv=get_down
22:00:34.660 [D] tou: send=down none
22:00:34.850 [D] tou: recv=get_down
22:00:34.860 [D] tou: send=down none
22:00:35.050 [D] tou: recv=get_down
22:00:35.060 [D] tou: send=down none
22:00:35.250 [D] tou: recv=get_down
22:00:35.250 [D] tou: send=down none
22:00:35.250 [D] tou: recv=net
22:00:35.260 [D] tou: send=cloud
22:00:35.450 [D] tou: recv=get_down
22:00:35.450 [D] tou: send=down none
22:00:35.650 [D] tou: recv=get_down
22:00:35.650 [D] tou: send=down none
22:00:35.850 [D] tou: recv=get_down
22:00:35.850 [D] tou: send=down none
22:00:36.050 [D] tou: recv=get_down
22:00:36.050 [D] tou: send=down none
22:00:36.150 [D] tou: recv=net
22:00:36.150 [D] tou: send=cloud
22:00:36.170 [I] miio_monitor: work time = 110s, memory left = 68880
22:00:36.250 [D] tou: recv=get_down
22:00:36.250 [D] tou: send=down none
22:00:36.450 [D] tou: recv=get_down
22:00:36.450 [D] tou: send=down none
22:00:36.650 [D] tou: recv=get_down
22:00:36.650 [D] tou: send=down none
22:00:36.850 [D] tou: recv=get_down
22:00:36.850 [D] tou: send=down none
22:00:37.050 [D] tou: recv=get_down
22:00:37.050 [D] tou: send=down none
22:00:37.050 [D] tou: recv=net
22:00:37.050 [D] tou: send=cloud
22:00:37.240 [D] tou: recv=get_down
22:00:37.250 [D] tou: send=down none
22:00:37.440 [D] tou: recv=get_down
22:00:37.450 [D] tou: send=down none
22:00:37.650 [D] tou: recv=get_down
22:00:37.650 [D] tou: send=down none
22:00:37.840 [D] tou: recv=get_down
22:00:37.840 [D] tou: send=down none
22:00:37.940 [D] tou: recv=net
22:00:37.940 [D] tou: send=cloud
22:00:38.040 [D] tou: recv=get_down
22:00:38.040 [D] tou: send=down none
22:00:38.240 [D] tou: recv=get_down
22:00:38.240 [D] tou: send=down none
22:00:38.440 [D] tou: recv=get_down
22:00:38.440 [D] tou: send=down none
22:00:38.640 [D] tou: recv=get_down
22:00:38.640 [D] tou: send=down none
22:00:38.840 [D] tou: recv=get_down
22:00:38.840 [D] tou: send=down none
22:00:38.840 [D] tou: recv=net
22:00:38.840 [D] tou: send=cloud
`

[vampywiz17]

My doorbell is working, if you help me, what need to do, i really would like to help!

[rytilahti]

The subscribe is likely used for the cloud communication notifications, and thus out of scope for this project.