Platform: Ubuntu 18.04
aliyun/iotkit: RELEASED_V2_1_20180320
Test code: sample/ota/ota_mqtt-example.c
Description
Hi,
I am testing aliyun OTA function. On IoT Platform Console, I've launched OTA process and run ota_mqtt-example on my Ubuntu 18.04. According to the log, topic /ota/device/upgrade/a1SaLQJIZzr/tRigXE0ATjmiyJlv6aPp! is subscribed, but upgrade notification from OTA server is received instantly before the corresponding SUBACK packet. I know upgrade notification callback handler won't be ready until SUBACK is received, so the upgrade notification from OTA server is not handled.
[inf] iotx_device_info_init(40): device_info created successfully!
[dbg] iotx_device_info_set(50): start to set device info!
[dbg] iotx_device_info_set(64): device_info set successfully!
[dbg] guider_print_dev_guider_info(271): ....................................................
[dbg] guider_print_dev_guider_info(272): ProductKey : a1SaLQJIZzr
[dbg] guider_print_dev_guider_info(273): DeviceName : tRigXE0ATjmiyJlv6aPp
[dbg] guider_print_dev_guider_info(274): DeviceID : a1SaLQJIZzr.tRigXE0ATjmiyJlv6aPp
[dbg] guider_print_dev_guider_info(276): ....................................................
[dbg] guider_print_dev_guider_info(277): PartnerID Buf : ,partner_id=example.demo.partner-id
[dbg] guider_print_dev_guider_info(278): ModuleID Buf : ,module_id=example.demo.module-id
[dbg] guider_print_dev_guider_info(279): Guider URL :
[dbg] guider_print_dev_guider_info(281): Guider SecMode : 2 (TLS + Direct)
[dbg] guider_print_dev_guider_info(283): Guider Timestamp : 2524608000000
[dbg] guider_print_dev_guider_info(284): ....................................................
[dbg] guider_print_dev_guider_info(290): ....................................................
[dbg] guider_print_conn_info(248): -----------------------------------------
[dbg] guider_print_conn_info(249): Host : a1SaLQJIZzr.iot-as-mqtt.cn-shanghai.aliyuncs.com
[dbg] guider_print_conn_info(250): Port : 1883
[dbg] guider_print_conn_info(253): ClientID : a1SaLQJIZzr.tRigXE0ATjmiyJlv6aPp|securemode=2,timestamp=2524608000000,signmethod=hmacsha1,gw=0,ext=0,partner_id=example.demo.partner-id,module_id=example.demo.module-id|
[dbg] guider_print_conn_info(255): TLS PubKey : 0x56024c3784a1 ('-----BEGIN CERTI ...')
[dbg] guider_print_conn_info(258): -----------------------------------------
[inf] iotx_mc_init(1703): MQTT init success!
[inf] _ssl_client_init(176): Loading the CA root certificate ...
cert. version : 3
serial number : 04:00:00:00:00:01:15:4B:5A:C3:94
issuer name : C=BE, O=GlobalSign nv-sa, OU=Root CA, CN=GlobalSign Root CA
subject name : C=BE, O=GlobalSign nv-sa, OU=Root CA, CN=GlobalSign Root CA
issued on : 1998-09-01 12:00:00
expires on : 2028-01-28 12:00:00
signed using : RSA with SHA1
RSA key size : 2048 bits
basic constraints : CA=true
key usage : Key Cert Sign, CRL Sign
[inf] _ssl_parse_crt(144): crt content:451
[inf] _ssl_client_init(184): ok (0 skipped)
[inf] _TLSConnectNetwork(346): Connecting to /a1SaLQJIZzr.iot-as-mqtt.cn-shanghai.aliyuncs.com/1883...
[inf] mbedtls_net_connect_timeout(291): setsockopt SO_SNDTIMEO timeout: 10s
[inf] _TLSConnectNetwork(359): ok
[inf] _TLSConnectNetwork(364): . Setting up the SSL/TLS structure...
[inf] _TLSConnectNetwork(374): ok
[inf] _TLSConnectNetwork(409): Performing the SSL/TLS handshake...
[inf] _TLSConnectNetwork(417): ok
[inf] _TLSConnectNetwork(421): . Verifying peer X.509 certificate..
[inf] _real_confirm(93): certificate verification result: 0x00
[inf] iotx_mc_connect(2035): mqtt connect success!
[dbg] iotx_mc_report_mid(2259): MID Report: started in MQTT
[dbg] iotx_mc_report_mid(2276): MID Report: json data = '{"id":"a1SaLQJIZzr_tRigXE0ATjmiyJlv6aPp_mid","params":{"_sys_device_mid":"example.demo.module-id","_sys_device_pid":"example.demo.partner-id"}}'
[dbg] iotx_mc_report_mid(2292): MID Report: topic name = '/sys/a1SaLQJIZzr/tRigXE0ATjmiyJlv6aPp/thing/status/update'
[dbg] iotx_mc_report_mid(2309): MID Report: finished, IOT_MQTT_Publish() = 0
[inf] iotx_mc_subscribe(1388): mqtt subscribe success,topic = /ota/device/request/a1SaLQJIZzr/tRigXE0ATjmiyJlv6aPp!
[inf] iotx_mc_subscribe(1388): mqtt subscribe success,topic = /ota/device/upgrade/a1SaLQJIZzr/tRigXE0ATjmiyJlv6aPp!
[inf] iotx_mc_subscribe(1388): mqtt subscribe success,topic = /sys/a1SaLQJIZzr/tRigXE0ATjmiyJlv6aPp/thing/config/get_reply!
[inf] iotx_mc_subscribe(1388): mqtt subscribe success,topic = /sys/a1SaLQJIZzr/tRigXE0ATjmiyJlv6aPp/thing/config/push!
mqtt_client|227 :: wait ota upgrade command....
[dbg] iotx_mc_cycle(1277): PUBLISH
[dbg] iotx_mc_handle_recv_PUBLISH(1091): Packet Ident : 00000000
[dbg] iotx_mc_handle_recv_PUBLISH(1092): Topic Length : 52
[dbg] iotx_mc_handle_recv_PUBLISH(1096): Topic Name : /ota/device/upgrade/a1SaLQJIZzr/tRigXE0ATjmiyJlv6aPp
[dbg] iotx_mc_handle_recv_PUBLISH(1099): Payload Len/Room : 415 / 1991
[dbg] iotx_mc_handle_recv_PUBLISH(1100): Receive Buflen : 2048
[dbg] iotx_mc_handle_recv_PUBLISH(1111): delivering msg ...
[dbg] iotx_mc_deliver_message(887): NO matching any topic, call default handle function
event_handle|128 :: topic message arrived but without any related handle: topic=/ota/device/upgrade/a1SaLQJIZzr/tRigXE0ATjmiyJlv6aPp, topic_msg={"code":"1000","data":{"size":215726,"sign":"44026fa64dc282b028fdab1a648feb83","version":"v0.00.002","url":"https://iotx-ota.oss-cn-shanghai.aliyuncs.com/ota/8791c2e123f98856450f16fcf2715dc9/cjnwqf8cl0002267qxtkqm2ex.gz?Expires=1540980615&OSSAccessKeyId=cS8uRRy54RszYWna&Signature=%2Btl6bwXX1cTeUGsa7udx7a5KjuQ%3D","signMethod":"Md5","md5":"44026fa64dc282b028fdab1a648feb83"},"id":1540978815677,"message":"success"}
[dbg] iotx_mc_cycle(1269): SUBACK
event_handle|088 :: subscribe success, packet-id=3
[dbg] iotx_mc_cycle(1269): SUBACK
event_handle|088 :: subscribe success, packet-id=4
[dbg] iotx_mc_cycle(1269): SUBACK
event_handle|088 :: subscribe success, packet-id=2
[dbg] iotx_mc_cycle(1269): SUBACK
event_handle|088 :: subscribe success, packet-id=1
[dbg] iotx_mc_cycle(1260): PUBACK
event_handle|112 :: publish success, packet-id=5
mqtt_client|227 :: wait ota upgrade command....
mqtt_client|227 :: wait ota upgrade command....
mqtt_client|227 :: wait ota upgrade command....
mqtt_client|227 :: wait ota upgrade command....
Environment
Platform: Ubuntu 18.04 aliyun/iotkit: RELEASED_V2_1_20180320 Test code: sample/ota/ota_mqtt-example.c
Description
Hi,
I am testing aliyun OTA function. On IoT Platform Console, I've launched OTA process and run
ota_mqtt-exampleon my Ubuntu 18.04. According to the log, topic/ota/device/upgrade/a1SaLQJIZzr/tRigXE0ATjmiyJlv6aPp!is subscribed, but upgrade notification from OTA server is received instantly before the corresponding SUBACK packet. I know upgrade notification callback handler won't be ready until SUBACK is received, so the upgrade notification from OTA server is not handled.[inf] iotx_device_info_init(40): device_info created successfully! [dbg] iotx_device_info_set(50): start to set device info! [dbg] iotx_device_info_set(64): device_info set successfully! [dbg] guider_print_dev_guider_info(271): .................................................... [dbg] guider_print_dev_guider_info(272): ProductKey : a1SaLQJIZzr [dbg] guider_print_dev_guider_info(273): DeviceName : tRigXE0ATjmiyJlv6aPp [dbg] guider_print_dev_guider_info(274): DeviceID : a1SaLQJIZzr.tRigXE0ATjmiyJlv6aPp [dbg] guider_print_dev_guider_info(276): .................................................... [dbg] guider_print_dev_guider_info(277): PartnerID Buf : ,partner_id=example.demo.partner-id [dbg] guider_print_dev_guider_info(278): ModuleID Buf : ,module_id=example.demo.module-id [dbg] guider_print_dev_guider_info(279): Guider URL : [dbg] guider_print_dev_guider_info(281): Guider SecMode : 2 (TLS + Direct) [dbg] guider_print_dev_guider_info(283): Guider Timestamp : 2524608000000 [dbg] guider_print_dev_guider_info(284): .................................................... [dbg] guider_print_dev_guider_info(290): .................................................... [dbg] guider_print_conn_info(248): ----------------------------------------- [dbg] guider_print_conn_info(249): Host : a1SaLQJIZzr.iot-as-mqtt.cn-shanghai.aliyuncs.com [dbg] guider_print_conn_info(250): Port : 1883 [dbg] guider_print_conn_info(253): ClientID : a1SaLQJIZzr.tRigXE0ATjmiyJlv6aPp|securemode=2,timestamp=2524608000000,signmethod=hmacsha1,gw=0,ext=0,partner_id=example.demo.partner-id,module_id=example.demo.module-id| [dbg] guider_print_conn_info(255): TLS PubKey : 0x56024c3784a1 ('-----BEGIN CERTI ...') [dbg] guider_print_conn_info(258): ----------------------------------------- [inf] iotx_mc_init(1703): MQTT init success! [inf] _ssl_client_init(176): Loading the CA root certificate ... cert. version : 3 serial number : 04:00:00:00:00:01:15:4B:5A:C3:94 issuer name : C=BE, O=GlobalSign nv-sa, OU=Root CA, CN=GlobalSign Root CA subject name : C=BE, O=GlobalSign nv-sa, OU=Root CA, CN=GlobalSign Root CA issued on : 1998-09-01 12:00:00 expires on : 2028-01-28 12:00:00 signed using : RSA with SHA1 RSA key size : 2048 bits basic constraints : CA=true key usage : Key Cert Sign, CRL Sign [inf] _ssl_parse_crt(144): crt content:451 [inf] _ssl_client_init(184): ok (0 skipped) [inf] _TLSConnectNetwork(346): Connecting to /a1SaLQJIZzr.iot-as-mqtt.cn-shanghai.aliyuncs.com/1883... [inf] mbedtls_net_connect_timeout(291): setsockopt SO_SNDTIMEO timeout: 10s [inf] _TLSConnectNetwork(359): ok [inf] _TLSConnectNetwork(364): . Setting up the SSL/TLS structure... [inf] _TLSConnectNetwork(374): ok [inf] _TLSConnectNetwork(409): Performing the SSL/TLS handshake... [inf] _TLSConnectNetwork(417): ok [inf] _TLSConnectNetwork(421): . Verifying peer X.509 certificate.. [inf] _real_confirm(93): certificate verification result: 0x00 [inf] iotx_mc_connect(2035): mqtt connect success! [dbg] iotx_mc_report_mid(2259): MID Report: started in MQTT [dbg] iotx_mc_report_mid(2276): MID Report: json data = '{"id":"a1SaLQJIZzr_tRigXE0ATjmiyJlv6aPp_mid","params":{"_sys_device_mid":"example.demo.module-id","_sys_device_pid":"example.demo.partner-id"}}' [dbg] iotx_mc_report_mid(2292): MID Report: topic name = '/sys/a1SaLQJIZzr/tRigXE0ATjmiyJlv6aPp/thing/status/update' [dbg] iotx_mc_report_mid(2309): MID Report: finished, IOT_MQTT_Publish() = 0 [inf] iotx_mc_subscribe(1388): mqtt subscribe success,topic = /ota/device/request/a1SaLQJIZzr/tRigXE0ATjmiyJlv6aPp! [inf] iotx_mc_subscribe(1388): mqtt subscribe success,topic = /ota/device/upgrade/a1SaLQJIZzr/tRigXE0ATjmiyJlv6aPp! [inf] iotx_mc_subscribe(1388): mqtt subscribe success,topic = /sys/a1SaLQJIZzr/tRigXE0ATjmiyJlv6aPp/thing/config/get_reply! [inf] iotx_mc_subscribe(1388): mqtt subscribe success,topic = /sys/a1SaLQJIZzr/tRigXE0ATjmiyJlv6aPp/thing/config/push! mqtt_client|227 :: wait ota upgrade command.... [dbg] iotx_mc_cycle(1277): PUBLISH [dbg] iotx_mc_handle_recv_PUBLISH(1091): Packet Ident : 00000000 [dbg] iotx_mc_handle_recv_PUBLISH(1092): Topic Length : 52 [dbg] iotx_mc_handle_recv_PUBLISH(1096): Topic Name : /ota/device/upgrade/a1SaLQJIZzr/tRigXE0ATjmiyJlv6aPp [dbg] iotx_mc_handle_recv_PUBLISH(1099): Payload Len/Room : 415 / 1991 [dbg] iotx_mc_handle_recv_PUBLISH(1100): Receive Buflen : 2048 [dbg] iotx_mc_handle_recv_PUBLISH(1111): delivering msg ... [dbg] iotx_mc_deliver_message(887): NO matching any topic, call default handle function event_handle|128 :: topic message arrived but without any related handle: topic=/ota/device/upgrade/a1SaLQJIZzr/tRigXE0ATjmiyJlv6aPp, topic_msg={"code":"1000","data":{"size":215726,"sign":"44026fa64dc282b028fdab1a648feb83","version":"v0.00.002","url":"https://iotx-ota.oss-cn-shanghai.aliyuncs.com/ota/8791c2e123f98856450f16fcf2715dc9/cjnwqf8cl0002267qxtkqm2ex.gz?Expires=1540980615&OSSAccessKeyId=cS8uRRy54RszYWna&Signature=%2Btl6bwXX1cTeUGsa7udx7a5KjuQ%3D","signMethod":"Md5","md5":"44026fa64dc282b028fdab1a648feb83"},"id":1540978815677,"message":"success"} [dbg] iotx_mc_cycle(1269): SUBACK event_handle|088 :: subscribe success, packet-id=3 [dbg] iotx_mc_cycle(1269): SUBACK event_handle|088 :: subscribe success, packet-id=4 [dbg] iotx_mc_cycle(1269): SUBACK event_handle|088 :: subscribe success, packet-id=2 [dbg] iotx_mc_cycle(1269): SUBACK event_handle|088 :: subscribe success, packet-id=1 [dbg] iotx_mc_cycle(1260): PUBACK event_handle|112 :: publish success, packet-id=5 mqtt_client|227 :: wait ota upgrade command.... mqtt_client|227 :: wait ota upgrade command.... mqtt_client|227 :: wait ota upgrade command.... mqtt_client|227 :: wait ota upgrade command....