Hi,
This problem has been driving me nuts for a few days. About a week ago, I noticed that my photon would periodically lose the cloud connection, but eventually reconnect. However, it got worse and worse. So I set about to find out why.
I commented out all my code and then finally just wrote the most basic program I could, and it still persists. The symptoms are:
- Boot up
- Run Setup
- Start loop - the only thing loop does is log an info message once a minute and check for cloud connectivity.
- Loop runs happily for a time: anywhere from ~20 secs to about ~72 secs and then detects that the cloud has disconnected.
- Once a disconnect is detected, it prints out the current WiFi settings, records time statistics, and waits for the cloud to reconnect.
- A reconnect eventually happens, but it can take a few secs (10 or so) to many secs (more than 60)
- After reconnect, the loop continues.
I've noticed that the DNS setting is always 0.0.0.0 whether I use DHCP to assign the address, or use static. The log seems to indicate that it can't resolve the particle server, but after it resets the WLAN it can connect. But it can only connect once, the next attempt will have the same resolving issue.
Any ideas on why this is occurring? Why won't the FW accept a DNS setting? I've tried my ISP address, Google's public DNS, and even a DNS I setup on my local net. Same issue occurs. I've also tried 2 different Photons just to see if a had a bad one, but they both act the same. Both are using the latest stable FW. I'm using an external antenna.
My network is all enterprise gear (Ubiquiti and Cisco) and hasn't changed in months. All other devices are working fine. In fact, the Photon's were rock solid until a week or so ago.
I've seen a few other threads that were similar, and I tried some of the suggestions in them. Nothing worked. Any thoughts? Right now these Photon devices are effectively unusable.
Code and logs below.
Thanks,
-john
Here is the code:
#include "Particle.h" #include "application.h" //needed for all Particle libraries
STARTUP(WiFi.selectAntenna(ANT_EXTERNAL));
// Set the System modes SYSTEM_MODE(AUTOMATIC); SYSTEM_THREAD(ENABLED);
SerialLogHandler logHandler;
void getWIFI(void);
unsigned long pubsecTime = 0; unsigned long wifiDownCount = 0;
unsigned long uptime = 0; unsigned long uptimeMin = 999999; unsigned long uptimeMax = 0; unsigned long accumUpTime = 0;
unsigned long connTime = 0; unsigned long connTimeMin = 999999; unsigned long connTimeMax = 0; unsigned long accumConnTime = 0; unsigned long avgUptime = 0; unsigned long avgConnTime = 0;
//--------------------------------------------------------------- void setup() { Logger log("Setup"); Serial.begin(9600); // open serial over USB at 9600 baud
Time.zone(-7); // Set the Time Zone.
delay(10000); // Wait a bit for the serial port to connect
Serial.println(" "); Log.info("Starting up: %d:%d:%d", Time.hour(), Time.minute(), Time.second()); Serial.println(" ");
IPAddress myAddress(192,168,1,80); IPAddress netmask(255,255,255,0); IPAddress gateway(192,168,1,1);
IPAddress dns(196,168,1,9); // local DNS Server WiFi.setStaticIP(myAddress, netmask, gateway, dns); WiFi.useStaticIP(); waitUntil(WiFi.ready); waitUntil(Particle.connected); Particle.process();
Serial.println(" "); for (int i = 0; i < 60; i++) // loop for a minute to get the reason for the last reset { if (Particle.connected()) { switch (System.resetReason()) { case RESET_REASON_PIN_RESET: Log.info("Reset Reason: PIN_RESET" ); break; case RESET_REASON_POWER_MANAGEMENT: Log.info("Reset Reason: POWER_MANAGEMENT" ); break; case RESET_REASON_POWER_DOWN: Log.info("Reset Reason: POWER_DOWN" ); break; case RESET_REASON_POWER_BROWNOUT: Log.info("Reset Reason: POWER_BROWNOUT" ); break; case RESET_REASON_WATCHDOG: Log.info("Reset Reason: WATCHDOG" ); break; case RESET_REASON_UPDATE: Log.info("Reset Reason: UPDATE" ); break; case RESET_REASON_UPDATE_TIMEOUT: Log.info("Reset Reason: UPDATE_TIMEOUT" ); break; case RESET_REASON_FACTORY_RESET: Log.info("Reset Reason: FACTORY_RESET" ); break; case RESET_REASON_SAFE_MODE: Log.info("Reset Reason: SAFE_MODE" ); break; case RESET_REASON_DFU_MODE: Log.info("Reset Reason: DFU_MODE" ); break; case RESET_REASON_PANIC: Log.info("Reset Reason: PANIC" ); break; case RESET_REASON_USER: Log.info("Setup-> Reset Reason: USER" ); break; case RESET_REASON_UNKNOWN: case RESET_REASON_NONE: default: Log.info("Reset Reason: UNKNOWN/NONE"); }
break; } else { Log.error("Could not connect to cloud"); Particle.connect(); waitUntil(Particle.connected); delay(1000); } } Serial.println(" ");
Particle.process(); getWIFI(); // dump the wifi info
pubsecTime = Time.now(); // initiallize pub timer uptime = Time.now(); Serial.println(" "); Log.info("Finished Setup"); Serial.println(" "); }
//--------------------------------------------------------------- void loop() { Logger log("Main Loop"); Particle.process();
if( (Time.now() - pubsecTime) > 60 ) { Serial.println(" "); Log.info("Pub Time: %u", (Time.now() - pubsecTime)); Serial.println(" "); pubsecTime = Time.now(); }
if (!Particle.connected()) // if we aren't connected, wait until we are... { wifiDownCount++;
Serial.println(" "); Log.error("Number of WiFi down time occurances: %u", wifiDownCount); Serial.println(" "); uptime = Time.now() - uptime; accumUpTime += uptime; avgUptime = accumUpTime / wifiDownCount;
if(uptime < uptimeMin) uptimeMin = uptime; if(uptime > uptimeMax) uptimeMax = uptime;
Serial.println(" "); Log.error("Secs of uptime: %u", uptime); Log.error("Avg secs of uptime: %u", avgUptime); Log.error("Min secs of uptime: %u", uptimeMin); Log.error("Max secs of uptime: %u", uptimeMax); Serial.println(" ");
getWIFI(); connTime = Time.now();
Serial.println(" "); Log.error("Waiting for WiFi be ready"); Serial.println(" "); waitUntil(WiFi.ready);
Serial.println(" "); Log.error("Waiting to connect to Cloud"); Serial.println(" "); waitUntil(Particle.connected);
connTime = Time.now() - connTime; accumConnTime += connTime; avgConnTime = accumConnTime / wifiDownCount;
if(connTime < connTimeMin) connTimeMin = connTime; if(connTime > connTimeMax) connTimeMax = connTime;
Serial.println(" "); Log.error("Reconnect time: %u", connTime); Log.error("Avg Reconnect time: %u", avgConnTime); Log.error("Min secs of Reconnect time: %u", connTimeMin); Log.error("Max secs of Reconnect time: %u", connTimeMax); Serial.println(" ");
uptime = Time.now();
} }
void getWIFI(void) { Logger log("WiFi Info"); byte bssid[6]; byte mac[6]; IPAddress myIP;
WiFi.BSSID(bssid); WiFi.macAddress(mac); Serial.println(" ");
Log.info("<------------- WiFi Info ------------>"); Log.info("WiFi RSSI: %d dB", WiFi.RSSI()); Log.info("WiFi SSID: %s", WiFi.SSID());
myIP = WiFi.localIP(); Log.info("WiFi IP: %d.%d.%d.%d", myIP[0], myIP[1], myIP[2], myIP[3]);
myIP = WiFi.subnetMask(); Log.info("WiFi MASK: %d.%d.%d.%d", myIP[0], myIP[1], myIP[2], myIP[3]);
myIP = WiFi.gatewayIP(); Log.info("WiFi Gateway: %d.%d.%d.%d", myIP[0], myIP[1], myIP[2], myIP[3]);
myIP = WiFi.dnsServerIP(); Log.info("WiFi DNS: %d.%d.%d.%d", myIP[0], myIP[1], myIP[2], myIP[3]);
Log.info("WiFi BSSID: %0X:%0X:%0X:%0X:%0X:%0X", bssid[0], bssid[1], bssid[2], bssid[3], bssid[4], bssid[5]); Log.info("WiFi MAC: %0X:%0X:%0X:%0X:%0X:%0X", mac[0], mac[1], mac[2], mac[3], mac[4], mac[5]);
Serial.println(" "); }
Here is a snap shot of the serial log:
[Connected] 0000006405 [system] INFO: Resolved host device.spark.io to 107.22.156.56 0000006483 [system] INFO: connected to cloud 107.22.156.56:5683 0000006483 [system] INFO: Cloud socket connected 0000006483 [system] INFO: Starting handshake: presense_announce=1 0000006483 [comm.sparkprotocol.handshake] INFO: Started: Receive nonce 0000006563 [comm.sparkprotocol.handshake] INFO: Encrypting handshake nonce 0000006611 [comm.sparkprotocol.handshake] INFO: Sending encrypted nonce 0000006612 [comm.sparkprotocol.handshake] INFO: Receive key 0000006690 [comm.sparkprotocol.handshake] INFO: Setting key 0000006880 [comm.sparkprotocol.handshake] INFO: Sending HELLO message 0000006880 [comm.sparkprotocol.handshake] INFO: Receiving HELLO response 0000006953 [comm.sparkprotocol.handshake] INFO: Completed 0000006954 [system] INFO: Send spark/hardware/max_binary event 0000006954 [system] INFO: spark/hardware/ota_chunk_size event 0000006954 [system] INFO: Send spark/device/last_reset event 0000006955 [system] INFO: Send subscriptions 0000006955 [comm.sparkprotocol] INFO: Sending TIME request 0000006957 [system] INFO: Cloud connected 0000007258 [comm.sparkprotocol] INFO: Received TIME response: 1501646188 0000008267 [comm.sparkprotocol] INFO: Sending A describe message 0000008382 [comm.sparkprotocol] INFO: Sending S describe message 0000010043 [app] INFO: Starting up: 20:56:30 0000010043 [app] INFO: Reset Reason: DFU_MODE 0000010043 [app] INFO: <------------- WiFi Info ------------> 0000010044 [app] INFO: WiFi RSSI: -35 dB 0000010045 [app] INFO: WiFi SSID: Oenone 0000010045 [app] INFO: WiFi IP: 192.168.1.80 0000010045 [app] INFO: WiFi MASK: 255.255.255.0 0000010045 [app] INFO: WiFi Gateway: 192.168.1.1 0000010045 [app] INFO: WiFi DNS: 0.0.0.0 0000010046 [app] INFO: WiFi BSSID: DC:9F:DB:1C:5:41 0000010046 [app] INFO: WiFi MAC: 6C:B:84:59:46:1C 0000010047 [app] INFO: Finished Setup 0000048684 [comm.sparkprotocol] WARN: ping ACK not received 0000048684 [system] WARN: Communication loop error, closing cloud socket 0000048686 [app] ERROR: Number of WiFi down time occurances: 1 0000048686 [app] ERROR: Secs of uptime: 39 0000048686 [app] ERROR: Avg secs of uptime: 39 0000048687 [app] ERROR: Min secs of uptime: 39 0000048687 [app] ERROR: Max secs of uptime: 39 0000048687 [app] INFO: <------------- WiFi Info ------------> 0000048688 [app] INFO: WiFi RSSI: -39 dB 0000048688 [app] INFO: WiFi SSID: Oenone 0000048688 [app] INFO: WiFi IP: 192.168.1.80 0000048689 [app] INFO: WiFi MASK: 255.255.255.0 0000048689 [app] INFO: WiFi Gateway: 192.168.1.1 0000048689 [app] INFO: WiFi DNS: 0.0.0.0 0000048690 [app] INFO: WiFi BSSID: DC:9F:DB:1C:5:41 0000048690 [app] INFO: WiFi MAC: 6C:B:84:59:46:1C 0000048690 [app] ERROR: Waiting for WiFi be ready 0000048691 [app] ERROR: Waiting to connect to Cloud 0000048786 [system] INFO: Cloud: connecting 0000048787 [system] INFO: Read Server Address = type:1,domain:device.spark.io 0000063817 [system] ERROR: Cloud: unable to resolve IP for device.spark.io 0000063817 [system] WARN: Cloud socket connection failed: -1 0000068821 [system] WARN: Internet Test Failed! 0000068821 [system] WARN: Resetting WLAN due to 2 failed connect attempts 0000068821 [system] WARN: Handling cloud error: 2 0000068921 [system] WARN: Resetting WLAN due to SPARK_WLAN_RESET 0000069024 [hal.wlan] INFO: Using external antenna 0000069026 [system] INFO: ARM_WLAN_WD 1 0000069729 [system] INFO: ARM_WLAN_WD 2 0000069729 [hal.wlan] INFO: Bringing WiFi interface up with static IP 0000069733 [system] INFO: CLR_WLAN_WD 1, DHCP success 0000069735 [system] INFO: Cloud: connecting 0000069735 [system] INFO: Read Server Address = type:1,domain:device.spark.io 0000069768 [system] INFO: Resolved host device.spark.io to 34.224.22.50 0000069842 [system] INFO: connected to cloud 34.224.22.50:5683 0000069844 [system] INFO: Cloud socket connected 0000069844 [system] INFO: Starting handshake: presense_announce=1 0000069844 [comm.sparkprotocol.handshake] INFO: Started: Receive nonce 0000069918 [comm.sparkprotocol.handshake] INFO: Encrypting handshake nonce 0000070012 [comm.sparkprotocol.handshake] INFO: Sending encrypted nonce 0000070014 [comm.sparkprotocol.handshake] INFO: Receive key 0000070094 [comm.sparkprotocol.handshake] INFO: Setting key 0000070474 [comm.sparkprotocol.handshake] INFO: Sending HELLO message 0000070475 [comm.sparkprotocol.handshake] INFO: Receiving HELLO response 0000070550 [comm.sparkprotocol.handshake] INFO: Completed 0000070550 [system] INFO: Send spark/hardware/max_binary event 0000070551 [system] INFO: spark/hardware/ota_chunk_size event 0000070558 [system] INFO: Send subscriptions 0000070559 [comm.sparkprotocol] INFO: Sending TIME request 0000070561 [system] INFO: Cloud connected 0000070561 [app] ERROR: Reconnect time: 22 0000070561 [app] ERROR: Avg Reconnect time: 22 0000070561 [app] ERROR: Min secs of Reconnect time: 22 0000070561 [app] ERROR: Max secs of Reconnect time: 22 0000070562 [app] INFO: Pub Time: 61 0000070865 [comm.sparkprotocol] INFO: Received TIME response: 1501646251 0000071875 [comm.sparkprotocol] INFO: Sending A describe message 0000072007 [comm.sparkprotocol] INFO: Sending S describe message 0000097158 [comm.sparkprotocol] WARN: ping ACK not received 0000097158 [system] WARN: Communication loop error, closing cloud socket 0000097158 [app] ERROR: Number of WiFi down time occurances: 2 0000097159 [app] ERROR: Secs of uptime: 26 0000097159 [app] ERROR: Avg secs of uptime: 32 0000097159 [app] ERROR: Min secs of uptime: 26 0000097159 [app] ERROR: Max secs of uptime: 39 0000097160 [app] INFO: <------------- WiFi Info ------------> 0000097160 [app] INFO: WiFi RSSI: -38 dB 0000097160 [app] INFO: WiFi SSID: Oenone 0000097161 [app] INFO: WiFi IP: 192.168.1.80 0000097161 [app] INFO: WiFi MASK: 255.255.255.0 0000097161 [app] INFO: WiFi Gateway: 192.168.1.1 0000097162 [app] INFO: WiFi DNS: 0.0.0.0 0000097162 [app] INFO: WiFi BSSID: DC:9F:DB:1C:5:41 0000097162 [app] INFO: WiFi MAC: 6C:B:84:59:46:1C 0000097162 [app] ERROR: Waiting for WiFi be ready 0000097163 [app] ERROR: Waiting to connect to Cloud 0000097258 [system] INFO: Cloud: connecting 0000097259 [system] INFO: Read Server Address = type:1,domain:device.spark.io 0000112289 [system] ERROR: Cloud: unable to resolve IP for device.spark.io 0000112289 [system] WARN: Cloud socket connection failed: -1 0000117295 [system] WARN: Internet Test Failed! 0000117295 [system] WARN: Resetting WLAN due to 2 failed connect attempts 0000117295 [system] WARN: Handling cloud error: 2 0000117397 [system] WARN: Resetting WLAN due to SPARK_WLAN_RESET 0000117500 [hal.wlan] INFO: Using external antenna 0000117502 [system] INFO: ARM_WLAN_WD 1 0000118166 [system] INFO: ARM_WLAN_WD 2 0000118166 [hal.wlan] INFO: Bringing WiFi interface up with static IP 0000118169 [system] INFO: CLR_WLAN_WD 1, DHCP success 0000118171 [system] INFO: Cloud: connecting 0000118171 [system] INFO: Read Server Address = type:1,domain:device.spark.io 0000118403 [system] INFO: Resolved host device.spark.io to 107.22.156.56 0000118478 [system] INFO: connected to cloud 107.22.156.56:5683 0000118480 [system] INFO: Cloud socket connected 0000118480 [system] INFO: Starting handshake: presense_announce=1 0000118482 [comm.sparkprotocol.handshake] INFO: Started: Receive nonce 0000118554 [comm.sparkprotocol.handshake] INFO: Encrypting handshake nonce 0000118648 [comm.sparkprotocol.handshake] INFO: Sending encrypted nonce 0000118648 [comm.sparkprotocol.handshake] INFO: Receive key 0000118729 [comm.sparkprotocol.handshake] INFO: Setting key 0000119108 [comm.sparkprotocol.handshake] INFO: Sending HELLO message 0000119111 [comm.sparkprotocol.handshake] INFO: Receiving HELLO response 0000119185 [comm.sparkprotocol.handshake] INFO: Completed 0000119185 [system] INFO: Send spark/hardware/max_binary event 0000119186 [system] INFO: spark/hardware/ota_chunk_size event 0000119194 [system] INFO: Send subscriptions 0000119195 [comm.sparkprotocol] INFO: Sending TIME request 0000119197 [system] INFO: Cloud connected 0000119197 [app] ERROR: Reconnect time: 22 0000119197 [app] ERROR: Avg Reconnect time: 22 0000119198 [app] ERROR: Min secs of Reconnect time: 22 0000119198 [app] ERROR: Max secs of Reconnect time: 22 0000119501 [comm.sparkprotocol] INFO: Received TIME response: 1501646300 0000120511 [comm.sparkprotocol] INFO: Sending A describe message 0000120643 [comm.sparkprotocol] INFO: Sending S describe message 0000131500 [app] INFO: Pub Time: 61 0000160947 [comm.sparkprotocol] WARN: ping ACK not received 0000160947 [system] WARN: Communication loop error, closing cloud socket 0000160947 [app] ERROR: Number of WiFi down time occurances: 3 0000160948 [app] ERROR: Secs of uptime: 42 0000160948 [app] ERROR: Avg secs of uptime: 35 0000160948 [app] ERROR: Min secs of uptime: 26 0000160948 [app] ERROR: Max secs of uptime: 42 0000160949 [app] INFO: <------------- WiFi Info ------------> 0000160949 [app] INFO: WiFi RSSI: -33 dB 0000160949 [app] INFO: WiFi SSID: Oenone 0000160950 [app] INFO: WiFi IP: 192.168.1.80 0000160950 [app] INFO: WiFi MASK: 255.255.255.0 0000160950 [app] INFO: WiFi Gateway: 192.168.1.1 0000160950 [app] INFO: WiFi DNS: 0.0.0.0 0000160951 [app] INFO: WiFi BSSID: DC:9F:DB:1C:5:41 0000160951 [app] INFO: WiFi MAC: 6C:B:84:59:46:1C 0000160951 [app] ERROR: Waiting for WiFi be ready 0000160951 [app] ERROR: Waiting to connect to Cloud 0000161047 [system] INFO: Cloud: connecting 0000161048 [system] INFO: Read Server Address = type:1,domain:device.spark.io 0000176078 [system] ERROR: Cloud: unable to resolve IP for device.spark.io 0000176078 [system] WARN: Cloud socket connection failed: -1 0000181084 [system] WARN: Internet Test Failed! 0000181084 [system] WARN: Resetting WLAN due to 2 failed connect attempts 0000181084 [system] WARN: Handling cloud error: 2 0000181186 [system] WARN: Resetting WLAN due to SPARK_WLAN_RESET 0000181289 [hal.wlan] INFO: Using external antenna 0000181291 [system] INFO: ARM_WLAN_WD 1 0000181962 [system] INFO: ARM_WLAN_WD 2 0000181962 [hal.wlan] INFO: Bringing WiFi interface up with static IP 0000181965 [system] INFO: CLR_WLAN_WD 1, DHCP success 0000181967 [system] INFO: Cloud: connecting 0000181967 [system] INFO: Read Server Address = type:1,domain:device.spark.io 0000182005 [system] INFO: Resolved host device.spark.io to 107.22.28.43 0000182079 [system] INFO: connected to cloud 107.22.28.43:5683 0000182079 [system] INFO: Cloud socket connected 0000182079 [system] INFO: Starting handshake: presense_announce=1 0000182081 [comm.sparkprotocol.handshake] INFO: Started: Receive nonce 0000182154 [comm.sparkprotocol.handshake] INFO: Encrypting handshake nonce 0000182246 [comm.sparkprotocol.handshake] INFO: Sending encrypted nonce 0000182248 [comm.sparkprotocol.handshake] INFO: Receive key 0000182328 [comm.sparkprotocol.handshake] INFO: Setting key 0000182708 [comm.sparkprotocol.handshake] INFO: Sending HELLO message 0000182709 [comm.sparkprotocol.handshake] INFO: Receiving HELLO response 0000182782 [comm.sparkprotocol.handshake] INFO: Completed 0000182782 [system] INFO: Send spark/hardware/max_binary event 0000182783 [system] INFO: spark/hardware/ota_chunk_size event 0000182790 [system] INFO: Send subscriptions 0000182791 [comm.sparkprotocol] INFO: Sending TIME request 0000182793 [system] INFO: Cloud connected 0000182793 [app] ERROR: Reconnect time: 22 0000182793 [app] ERROR: Avg Reconnect time: 22 0000182794 [app] ERROR: Min secs of Reconnect time: 22 0000182794 [app] ERROR: Max secs of Reconnect time: 22 0000183097 [comm.sparkprotocol] INFO: Received TIME response: 1501646364 0000184107 [comm.sparkprotocol] INFO: Sending A describe message 0000184239 [comm.sparkprotocol] INFO: Sending S describe message 0000192097 [app] INFO: Pub Time: 61 0000224541 [comm.sparkprotocol] WARN: ping ACK not received 0000224541 [system] WARN: Communication loop error, closing cloud socket 0000224541 [app] ERROR: Number of WiFi down time occurances: 4 0000224542 [app] ERROR: Secs of uptime: 42 0000224542 [app] ERROR: Avg secs of uptime: 37 0000224542 [app] ERROR: Min secs of uptime: 26 0000224542 [app] ERROR: Max secs of uptime: 42 0000224543 [app] INFO: <------------- WiFi Info ------------> 0000224543 [app] INFO: WiFi RSSI: -34 dB 0000224543 [app] INFO: WiFi SSID: Oenone 0000224544 [app] INFO: WiFi IP: 192.168.1.80 0000224544 [app] INFO: WiFi MASK: 255.255.255.0 0000224545 [app] INFO: WiFi Gateway: 192.168.1.1 0000224545 [app] INFO: WiFi DNS: 0.0.0.0 0000224545 [app] INFO: WiFi BSSID: DC:9F:DB:1C:5:41 0000224546 [app] INFO: WiFi MAC: 6C:B:84:59:46:1C 0000224546 [app] ERROR: Waiting for WiFi be ready 0000224546 [app] ERROR: Waiting to connect to Cloud 0000224641 [system] INFO: Cloud: connecting 0000224642 [system] INFO: Read Server Address = type:1,domain:device.spark.io 0000239671 [system] ERROR: Cloud: unable to resolve IP for device.spark.io 0000239671 [system] WARN: Cloud socket connection failed: -1 0000244677 [system] WARN: Internet Test Failed! 0000244677 [system] WARN: Resetting WLAN due to 2 failed connect attempts 0000244677 [system] WARN: Handling cloud error: 2 0000244779 [system] WARN: Resetting WLAN due to SPARK_WLAN_RESET 0000244882 [hal.wlan] INFO: Using external antenna 0000244884 [system] INFO: ARM_WLAN_WD 1 0000245554 [system] INFO: ARM_WLAN_WD 2 0000245554 [hal.wlan] INFO: Bringing WiFi interface up with static IP 0000245557 [system] INFO: CLR_WLAN_WD 1, DHCP success 0000245559 [system] INFO: Cloud: connecting 0000245559 [system] INFO: Read Server Address = type:1,domain:device.spark.io 0000245590 [system] INFO: Resolved host device.spark.io to 52.91.51.61 0000245664 [system] INFO: connected to cloud 52.91.51.61:5683 0000245664 [system] INFO: Cloud socket connected 0000245664 [system] INFO: Starting handshake: presense_announce=1 0000245666 [comm.sparkprotocol.handshake] INFO: Started: Receive nonce 0000245737 [comm.sparkprotocol.handshake] INFO: Encrypting handshake nonce 0000245829 [comm.sparkprotocol.handshake] INFO: Sending encrypted nonce 0000245829 [comm.sparkprotocol.handshake] INFO: Receive key 0000245908 [comm.sparkprotocol.handshake] INFO: Setting key 0000246284 [comm.sparkprotocol.handshake] INFO: Sending HELLO message 0000246286 [comm.sparkprotocol.handshake] INFO: Receiving HELLO response 0000246358 [comm.sparkprotocol.handshake] INFO: Completed 0000246358 [system] INFO: Send spark/hardware/max_binary event 0000246359 [system] INFO: spark/hardware/ota_chunk_size event 0000246366 [system] INFO: Send subscriptions 0000246367 [comm.sparkprotocol] INFO: Sending TIME request 0000246369 [system] INFO: Cloud connected 0000246369 [app] ERROR: Reconnect time: 22 0000246369 [app] ERROR: Avg Reconnect time: 22 0000246370 [app] ERROR: Min secs of Reconnect time: 22 0000246370 [app] ERROR: Max secs of Reconnect time: 22 0000246673 [comm.sparkprotocol] INFO: Received TIME response: 1501646427 0000247683 [comm.sparkprotocol] INFO: Sending A describe message 0000247816 [comm.sparkprotocol] INFO: Sending S describe message 0000253673 [app] INFO: Pub Time: 61 0000288118 [comm.sparkprotocol] WARN: ping ACK not received 0000288118 [system] WARN: Communication loop error, closing cloud socket 0000288118 [app] ERROR: Number of WiFi down time occurances: 5 0000288119 [app] ERROR: Secs of uptime: 41 0000288119 [app] ERROR: Avg secs of uptime: 38 0000288119 [app] ERROR: Min secs of uptime: 26 0000288119 [app] ERROR: Max secs of uptime: 42 0000288120 [app] INFO: <------------- WiFi Info ------------> 0000288120 [app] INFO: WiFi RSSI: -33 dB 0000288120 [app] INFO: WiFi SSID: Oenone 0000288121 [app] INFO: WiFi IP: 192.168.1.80 0000288121 [app] INFO: WiFi MASK: 255.255.255.0 0000288121 [app] INFO: WiFi Gateway: 192.168.1.1 0000288122 [app] INFO: WiFi DNS: 0.0.0.0 0000288122 [app] INFO: WiFi BSSID: DC:9F:DB:1C:5:41 0000288122 [app] INFO: WiFi MAC: 6C:B:84:59:46:1C 0000288122 [app] ERROR: Waiting for WiFi be ready 0000288123 [app] ERROR: Waiting to connect to Cloud 0000288218 [system] INFO: Cloud: connecting 0000288219 [system] INFO: Read Server Address = type:1,domain:device.spark.io 0000303249 [system] ERROR: Cloud: unable to resolve IP for device.spark.io 0000303249 [system] WARN: Cloud socket connection failed: -1 0000308255 [system] WARN: Internet Test Failed! 0000308255 [system] WARN: Resetting WLAN due to 2 failed connect attempts 0000308255 [system] WARN: Handling cloud error: 2 0000308357 [system] WARN: Resetting WLAN due to SPARK_WLAN_RESET 0000308460 [hal.wlan] INFO: Using external antenna 0000308462 [system] INFO: ARM_WLAN_WD 1 0000309146 [system] INFO: ARM_WLAN_WD 2 0000309146 [hal.wlan] INFO: Bringing WiFi interface up with static IP 0000309149 [system] INFO: CLR_WLAN_WD 1, DHCP success 0000309151 [system] INFO: Cloud: connecting 0000309151 [system] INFO: Read Server Address = type:1,domain:device.spark.io 0000309215 [system] INFO: Resolved host device.spark.io to 52.90.147.116 0000309290 [system] INFO: connected to cloud 52.90.147.116:5683 0000309290 [system] INFO: Cloud socket connected 0000309290 [system] INFO: Starting handshake: presense_announce=1 0000309292 [comm.sparkprotocol.handshake] INFO: Started: Receive nonce 0000309365 [comm.sparkprotocol.handshake] INFO: Encrypting handshake nonce 0000309457 [comm.sparkprotocol.handshake] INFO: Sending encrypted nonce 0000309457 [comm.sparkprotocol.handshake] INFO: Receive key 0000309540 [comm.sparkprotocol.handshake] INFO: Setting key 0000309916 [comm.sparkprotocol.handshake] INFO: Sending HELLO message 0000309919 [comm.sparkprotocol.handshake] INFO: Receiving HELLO response 0000309992 [comm.sparkprotocol.handshake] INFO: Completed 0000309992 [system] INFO: Send spark/hardware/max_binary event 0000309993 [system] INFO: spark/hardware/ota_chunk_size event 0000310000 [system] INFO: Send subscriptions 0000310001 [comm.sparkprotocol] INFO: Sending TIME request 0000310003 [system] INFO: Cloud connected 0000310003 [app] ERROR: Reconnect time: 22 0000310003 [app] ERROR: Avg Reconnect time: 22 0000310004 [app] ERROR: Min secs of Reconnect time: 22 0000310004 [app] ERROR: Max secs of Reconnect time: 22 0000310307 [comm.sparkprotocol] INFO: Received TIME response: 1501646491 0000311317 [comm.sparkprotocol] INFO: Sending A describe message 0000311449 [comm.sparkprotocol] INFO: Sending S describe message