Copyright © https://mongoose-os.com

Mongoose OS Forum

frame

ESP8266 to Amazon IOT Connection issues

callumqcallumq New Zealand
edited September 10 in Mongoose OS

Hey everyone,
I am trying to evaluate using Mongoose OS for a smart home product I am developing based on the ESP8266 platform. I am using a NodeMCU currently to test this implementation.
I am currently trying to complete the device shadow example from the documentation https://mongoose-os.com/docs/cloud/aws.md
However I am having some issues with the ESP not holding a connection to the Amazon IOT server. The ESP is able to authenticate correctly during IOT provisioning but then during running I am getting this output (with debug level 3)

[Sep 10 14:20:40.079] mgos_aws_shadow_init Device shadow name: esp8266_04F470 (token b4124843)
[Sep 10 14:20:40.086] mgos_event_trigger   ev MOS0 triggered 2 handlers
[Sep 10 14:20:40.091] mgos_upd_boot_finish 1 0
[Sep 10 14:20:40.101] mongoose_poll        New heap free LWM: 32496
[Sep 10 14:20:40.105] mgos_event_trigger   ev WFI1 triggered 0 handlers
[Sep 10 14:20:40.111] mg_rpc_ev_handler    0x3fff0e84 CHAN OPEN (loopback)
[Sep 10 14:20:40.114] mgos_event_trigger   ev RPC0 triggered 0 handlers
[Sep 10 14:20:40.121] mgos_net_on_change_c WiFi STA: connecting
[Sep 10 14:20:40.125] mgos_event_trigger   ev NET1 triggered 3 handlers
[Sep 10 14:20:42.834] scandone
[Sep 10 14:20:43.720] state: 0 -> 2 (b0)
[Sep 10 14:20:43.732] state: 2 -> 3 (0)
[Sep 10 14:20:43.735] state: 3 -> 5 (10)
[Sep 10 14:20:43.735] add 0
[Sep 10 14:20:43.736] aid 1
[Sep 10 14:20:43.736] cnt 
[Sep 10 14:20:43.766] 
[Sep 10 14:20:43.766] connected with WIFI, channel 1
[Sep 10 14:20:43.768] dhcp client start...
[Sep 10 14:20:43.768] mgos_event_trigger   ev WFI2 triggered 0 handlers
[Sep 10 14:20:43.775] mgos_net_on_change_c WiFi STA: connected
[Sep 10 14:20:43.779] mgos_event_trigger   ev NET2 triggered 3 handlers
[Sep 10 14:20:46.320] ip:,mask:255.255.255.0,gw:
[Sep 10 14:20:46.323] mgos_event_trigger   ev WFI3 triggered 0 handlers
[Sep 10 14:20:46.331] mgos_net_on_change_c WiFi STA: ready, IP [IP info here]
[Sep 10 14:20:46.340] mgos_sntp_retry      SNTP next query in 998 ms
[Sep 10 14:20:46.343] mgos_mqtt_global_con MQTT connecting to ap3nbary6nlff.iot.us-west-2.amazonaws.com:8883
[Sep 10 14:20:46.353] mg_connect_opt       0x3fff221c ap3nbary6nlff.iot.us-west-2.amazonaws.com:8883 aws-esp8266_04F470.crt.pem,aws-esp8266_04F470.key.pem,ca.pem
[Sep 10 14:20:46.367] find_mount_by_path   aws-esp8266_04F470.crt.pem -> /aws-esp8266_04F470.crt.pem pl 1 -> 1 0x3fff0344
[Sep 10 14:20:46.376] mgos_vfs_open        aws-esp8266_04F470.crt.pem 0x0 0x1b6 => 0x3fff0344 aws-esp8266_04F470.crt.pem 1 => 257 (refs -4)
[Sep 10 14:20:46.385] mgos_vfs_fstat       257 => 0x3fff0344:1 => 0 (size 1141)
[Sep 10 14:20:46.391] mgos_vfs_fstat       257 => 0x3fff0344:1 => 0 (size 1141)
[Sep 10 14:20:46.397] mgos_vfs_lseek       257 0 1 => 0x3fff0344:1 => 0
[Sep 10 14:20:46.400] mgos_vfs_lseek       257 1024 0 => 0x3fff0344:1 => 1024
[Sep 10 14:20:46.406] mgos_vfs_lseek       257 0 0 => 0x3fff0344:1 => 0
[Sep 10 14:20:46.412] mgos_vfs_close       257 => 0x3fff0344:1 => 0 (refs -5)
[Sep 10 14:20:46.426] find_mount_by_path   aws-esp8266_04F470.key.pem -> /aws-esp8266_04F470.key.pem pl 1 -> 1 0x3fff0344
[Sep 10 14:20:46.435] mgos_vfs_open        aws-esp8266_04F470.key.pem 0x0 0x1b6 => 0x3fff0344 aws-esp8266_04F470.key.pem 1 => 257 (refs -4)
[Sep 10 14:20:46.444] mgos_vfs_fstat       257 => 0x3fff0344:1 => 0 (size 227)
[Sep 10 14:20:46.450] mgos_vfs_fstat       257 => 0x3fff0344:1 => 0 (size 227)
[Sep 10 14:20:46.456] mgos_vfs_lseek       257 0 1 => 0x3fff0344:1 => 0
[Sep 10 14:20:46.459] mgos_vfs_lseek       257 0 0 => 0x3fff0344:1 => 0
[Sep 10 14:20:46.465] mgos_vfs_close       257 => 0x3fff0344:1 => 0 (refs -5)
[Sep 10 14:20:46.476] find_mount_by_path   ca.pem -> /ca.pem pl 1 -> 1 0x3fff0344
[Sep 10 14:20:46.485] mgos_vfs_open        ca.pem 0x0 0x1b6 => 0x3fff0344 ca.pem 1 => 257 (refs -4)
[Sep 10 14:20:46.491] mgos_vfs_close       257 => 0x3fff0344:1 => 0 (refs -5)
[Sep 10 14:20:46.499] mg_connect_opt       0x3fff41ac udp://8.8.8.8:53 -,-,-
[Sep 10 14:20:46.502] mg_do_connect        0x3fff41ac udp://8.8.8.8:53
[Sep 10 14:20:46.508] mgos_event_trigger   ev NET3 triggered 3 handlers
[Sep 10 14:20:46.516] mg_if_connect_cb     0x3fff41ac udp://8.8.8.8:53 -> 0
[Sep 10 14:20:46.524] mongoose_poll        New heap free LWM: 29512
[Sep 10 14:20:46.529] mg_rpc_ev_handler    0x3fff0e84 CHAN OPEN (loopback)
[Sep 10 14:20:46.533] mgos_event_trigger   ev RPC0 triggered 0 handlers
[Sep 10 14:20:47.344] mg_connect_opt       0x3fff20ec udp://time.google.com:123 -,-,-
[Sep 10 14:20:47.350] mg_connect_opt       0x3fff3024 udp://8.8.8.8:53 -,-,-
[Sep 10 14:20:47.354] mg_do_connect        0x3fff3024 udp://8.8.8.8:53
[Sep 10 14:20:47.359] mgos_sntp_query      SNTP query to time.google.com
[Sep 10 14:20:47.363] mgos_sntp_retry      SNTP next query in 2181 ms
[Sep 10 14:20:47.371] mg_if_connect_cb     0x3fff3024 udp://8.8.8.8:53 -> 0
[Sep 10 14:20:47.378] mongoose_poll        New heap free LWM: 28096
[Sep 10 14:20:47.426] mg_do_connect        0x3fff20ec udp://216.239.35.8:123
[Sep 10 14:20:47.430] mg_if_connect_cb     0x3fff20ec udp://216.239.35.8:123 -> 0
[Sep 10 14:20:47.435] mgos_sntp_ev         SNTP sent query to 216.239.35.8
[Sep 10 14:20:47.489] mgos_sntp_ev         SNTP reply from 216.239.35.8: time 1536582048.230839, local 8.759418, delta 1536582039.471421
[Sep 10 14:20:47.499] mgos_event_trigger   ev MOS3 triggered 3 handlers
[Sep 10 14:20:47.505] mgos_sntp_ev         SNTP close
[Sep 10 14:20:47.508] mgos_sntp_retry      SNTP next query in 6632198 ms
[Sep 10 14:20:47.532] mg_do_connect        0x3fff221c tcp://54.149.210.78:8883
[Sep 10 14:20:47.794] mg_if_connect_cb     0x3fff221c tcp://54.149.210.78:8883 -> 0
[Sep 10 14:20:47.804] mg_ssl_handshake     0x3fff221c 0 res -1
[Sep 10 14:20:47.814] mgos_mqtt_ev         MQTT Disconnect
[Sep 10 14:20:47.818] mqtt_global_reconnec MQTT connecting after 1861 ms

From here the printout continues to loop through MQTT disconnect and reconnecting. Any help would be much appreciated.
Thanks,
Callum

Comments

  • callumqcallumq New Zealand
    edited September 11

    I have tried another test today using the following code in the init.js function trying to just simply publish to the amazon IOT mqtt topic.

    load('api_config.js');
    load('api_mqtt.js');
    load('api_sys.js');
    load('api_timer.js');
    load('api_gpio.js');
    
    let topic = 'metrics/' + Cfg.get('device.id');
    let led = Cfg.get('pins.led');  // Built-in LED GPIO number
    let state = false;
    
    Timer.set(1000 /* milliseconds */, Timer.REPEAT, function() {
      let msg = JSON.stringify({free: Sys.free_ram(), total: Sys.total_ram()});
      GPIO.set_mode(led, GPIO.MODE_OUTPUT);
      state = !state;
      GPIO.write(led, state);
      print(topic, '->', msg);
      MQTT.pub(topic, msg);
    }, null);
    

    The output from the terminal using debug level 3 is as follows. Im not quite understanding why the esp8266 is unable to connect to the Amazon IOT server correctly after it succesfully provisions using the dashboard and I can see the thing appear in IOT core dashboard

    [Sep 11 10:55:26.434] metrics/esp8266_04F470 -> {"total":51648,"free":35960} 
    [Sep 11 10:55:27.436] metrics/esp8266_04F470 -> {"total":51648,"free":35700} 
    [Sep 11 10:55:28.438] metrics/esp8266_04F470 -> {"total":51648,"free":35960} 
    [Sep 11 10:55:29.438] metrics/esp8266_04F470 -> {"total":51648,"free":35700} 
    [Sep 11 10:55:30.438] metrics/esp8266_04F470 -> {"total":51648,"free":35960} 
    [Sep 11 10:55:31.437] metrics/esp8266_04F470 -> {"total":51648,"free":35700} 
    [Sep 11 10:55:32.439] metrics/esp8266_04F470 -> {"total":51648,"free":35960} 
    [Sep 11 10:55:33.438] metrics/esp8266_04F470 -> {"total":51648,"free":35700} 
    [Sep 11 10:55:34.437] metrics/esp8266_04F470 -> {"total":51648,"free":35960} 
    [Sep 11 10:55:35.438] metrics/esp8266_04F470 -> {"total":51648,"free":35700} 
    [Sep 11 10:55:36.437] metrics/esp8266_04F470 -> {"total":51648,"free":35960} 
    [Sep 11 10:55:37.122] mgos_mqtt_global_con MQTT connecting to ap3nbary6nlff.iot.us-west-2.amazonaws.com:8883
    [Sep 11 10:55:37.131] mg_connect_opt       0x3ffef74c ap3nbary6nlff.iot.us-west-2.amazonaws.com:8883 aws-esp8266_04F470.crt.pem,aws-esp8266_04F470.key.pem,ca.pem
    [Sep 11 10:55:37.144] find_mount_by_path   aws-esp8266_04F470.crt.pem -> /aws-esp8266_04F470.crt.pem pl 1 -> 1 0x3fff0344
    [Sep 11 10:55:37.158] mgos_vfs_open        aws-esp8266_04F470.crt.pem 0x0 0x1b6 => 0x3fff0344 aws-esp8266_04F470.crt.pem 1 => 257 (refs -6)
    [Sep 11 10:55:37.167] mgos_vfs_fstat       257 => 0x3fff0344:1 => 0 (size 1141)
    [Sep 11 10:55:37.173] mgos_vfs_fstat       257 => 0x3fff0344:1 => 0 (size 1141)
    [Sep 11 10:55:37.179] mgos_vfs_lseek       257 0 1 => 0x3fff0344:1 => 0
    [Sep 11 10:55:37.182] mgos_vfs_lseek       257 1024 0 => 0x3fff0344:1 => 1024
    [Sep 11 10:55:37.188] mgos_vfs_lseek       257 0 0 => 0x3fff0344:1 => 0
    [Sep 11 10:55:37.194] mgos_vfs_close       257 => 0x3fff0344:1 => 0 (refs -7)
    [Sep 11 10:55:37.208] find_mount_by_path   aws-esp8266_04F470.key.pem -> /aws-esp8266_04F470.key.pem pl 1 -> 1 0x3fff0344
    [Sep 11 10:55:37.217] mgos_vfs_open        aws-esp8266_04F470.key.pem 0x0 0x1b6 => 0x3fff0344 aws-esp8266_04F470.key.pem 1 => 257 (refs -6)
    [Sep 11 10:55:37.226] mgos_vfs_fstat       257 => 0x3fff0344:1 => 0 (size 227)
    [Sep 11 10:55:37.232] mgos_vfs_fstat       257 => 0x3fff0344:1 => 0 (size 227)
    [Sep 11 10:55:37.238] mgos_vfs_lseek       257 0 1 => 0x3fff0344:1 => 0
    [Sep 11 10:55:37.241] mgos_vfs_lseek       257 0 0 => 0x3fff0344:1 => 0
    [Sep 11 10:55:37.247] mgos_vfs_close       257 => 0x3fff0344:1 => 0 (refs -7)
    [Sep 11 10:55:37.258] find_mount_by_path   ca.pem -> /ca.pem pl 1 -> 1 0x3fff0344
    [Sep 11 10:55:37.267] mgos_vfs_open        ca.pem 0x0 0x1b6 => 0x3fff0344 ca.pem 1 => 257 (refs -6)
    [Sep 11 10:55:37.273] mgos_vfs_close       257 => 0x3fff0344:1 => 0 (refs -7)
    [Sep 11 10:55:37.282] mg_connect_opt       0x3fff3d9c udp://8.8.8.8:53 -,-,-
    [Sep 11 10:55:37.285] mg_do_connect        0x3fff3d9c udp://8.8.8.8:53
    [Sep 11 10:55:37.296] mg_if_connect_cb     0x3fff3d9c udp://8.8.8.8:53 -> 0
    [Sep 11 10:55:37.348] mg_do_connect        0x3ffef74c tcp://34.216.128.118:8883
    [Sep 11 10:55:37.437] metrics/esp8266_04F470 -> {"total":51648,"free":30484} 
    [Sep 11 10:55:37.610] mg_if_connect_cb     0x3ffef74c tcp://34.216.128.118:8883 -> 0
    [Sep 11 10:55:37.619] mg_ssl_handshake     0x3ffef74c 0 res -1
    [Sep 11 10:55:37.636] mgos_mqtt_ev         MQTT Disconnect
    [Sep 11 10:55:37.641] mqtt_global_reconnec MQTT connecting after 35071 ms
    [Sep 11 10:55:38.439] metrics/esp8266_04F470 -> {"total":51648,"free":35960} 
    [Sep 11 10:55:39.437] metrics/esp8266_04F470 -> {"total":51648,"free":35700}

    Thanks again,
    Callum

Sign In or Register to comment.