ESP8266 connect fixes (#605)

* ESP8266 Connection Fixes

* Update client.py

* Update mqtt_client.cpp

* Update mqtt_client.cpp

* Fix ping

* Async dump config

* Update base image to 1.7.0

* Update helpers.py

* Updates

* Update Dockerfile.lint

.gitlab-ci.yml

@@ -3,7 +3,7 @@
 variables:
   DOCKER_DRIVER: overlay2
   DOCKER_HOST: tcp://docker:2375/
-  BASE_VERSION: '1.5.1'
+  BASE_VERSION: '1.7.0'
   TZ: UTC
 
 stages:

docker/Dockerfile

@@ -1,4 +1,4 @@
-ARG BUILD_FROM=esphome/esphome-base-amd64:1.5.1
+ARG BUILD_FROM=esphome/esphome-base-amd64:1.7.0
 FROM ${BUILD_FROM}
 
 COPY . .

docker/Dockerfile.lint

@@ -1,4 +1,4 @@
-FROM esphome/esphome-base-amd64:1.5.1
+FROM esphome/esphome-base-amd64:1.7.0
 
 RUN \
     apt-get update \
@@ -12,7 +12,7 @@ RUN \
         /var/lib/apt/lists/*
 
 COPY requirements_test.txt /requirements_test.txt
-RUN pip2 install -r /requirements_test.txt
+RUN pip2 install --no-cache-dir wheel && pip2 install --no-cache-dir -r /requirements_test.txt
 
 VOLUME ["/esphome"]
 WORKDIR /esphome

esphome/api/client.py

@@ -108,7 +108,6 @@ class APIClient(threading.Thread):
         self._message_handlers = []
         self._keepalive = 5
         self._ping_timer = None
-        self._refresh_ping()
 
         self.on_disconnect = None
         self.on_connect = None
@@ -132,8 +131,8 @@ class APIClient(threading.Thread):
             if self._connected:
                 try:
                     self.ping()
-                except APIConnectionError:
-                    self._fatal_error()
+                except APIConnectionError as err:
+                    self._fatal_error(err)
                 else:
                     self._refresh_ping()
 
@@ -175,7 +174,7 @@ class APIClient(threading.Thread):
             raise APIConnectionError("You need to call start() first!")
 
         if self._connected:
-            raise APIConnectionError("Already connected!")
+            self.disconnect(on_disconnect=False)
 
         try:
             ip = resolve_ip_address(self._address)
@@ -193,8 +192,9 @@ class APIClient(threading.Thread):
         try:
             self._socket.connect((ip, self._port))
         except socket.error as err:
-            self._fatal_error()
-            raise APIConnectionError("Error connecting to {}: {}".format(ip, err))
+            err = APIConnectionError("Error connecting to {}: {}".format(ip, err))
+            self._fatal_error(err)
+            raise err
         self._socket.settimeout(0.1)
 
         self._socket_open_event.set()
@@ -204,18 +204,20 @@ class APIClient(threading.Thread):
         try:
             resp = self._send_message_await_response(hello, pb.HelloResponse)
         except APIConnectionError as err:
-            self._fatal_error()
+            self._fatal_error(err)
             raise err
         _LOGGER.debug("Successfully connected to %s ('%s' API=%s.%s)", self._address,
                       resp.server_info, resp.api_version_major, resp.api_version_minor)
         self._connected = True
+        self._refresh_ping()
         if self.on_connect is not None:
             self.on_connect()
 
     def _check_connected(self):
         if not self._connected:
-            self._fatal_error()
-            raise APIConnectionError("Must be connected!")
+            err = APIConnectionError("Must be connected!")
+            self._fatal_error(err)
+            raise err
 
     def login(self):
         self._check_connected()
@@ -233,13 +235,13 @@ class APIClient(threading.Thread):
         if self.on_login is not None:
             self.on_login()
 
-    def _fatal_error(self):
+    def _fatal_error(self, err):
         was_connected = self._connected
 
         self._close_socket()
 
         if was_connected and self.on_disconnect is not None:
-            self.on_disconnect()
+            self.on_disconnect(err)
 
     def _write(self, data):  # type: (bytes) -> None
         if self._socket is None:
@@ -250,8 +252,9 @@ class APIClient(threading.Thread):
             try:
                 self._socket.sendall(data)
             except socket.error as err:
-                self._fatal_error()
-                raise APIConnectionError("Error while writing data: {}".format(err))
+                err = APIConnectionError("Error while writing data: {}".format(err))
+                self._fatal_error(err)
+                raise err
 
     def _send_message(self, msg):
         # type: (message.Message) -> None
@@ -271,7 +274,6 @@ class APIClient(threading.Thread):
         req += _varuint_to_bytes(message_type)
         req += encoded
         self._write(req)
-        self._refresh_ping()
 
     def _send_message_await_response_complex(self, send_msg, do_append, do_stop, timeout=1):
         event = threading.Event()
@@ -309,7 +311,7 @@ class APIClient(threading.Thread):
         self._check_connected()
         return self._send_message_await_response(pb.PingRequest(), pb.PingResponse)
 
-    def disconnect(self):
+    def disconnect(self, on_disconnect=True):
         self._check_connected()
 
         try:
@@ -318,7 +320,7 @@ class APIClient(threading.Thread):
             pass
         self._close_socket()
 
-        if self.on_disconnect is not None:
+        if self.on_disconnect is not None and on_disconnect:
             self.on_disconnect()
 
     def _check_authenticated(self):
@@ -387,7 +389,6 @@ class APIClient(threading.Thread):
         for msg_handler in self._message_handlers[:]:
             msg_handler(msg)
         self._handle_internal_messages(msg)
-        self._refresh_ping()
 
     def run(self):
         self._running_event.set()
@@ -399,7 +400,7 @@ class APIClient(threading.Thread):
                     break
                 if self._connected:
                     _LOGGER.error("Error while reading incoming messages: %s", err)
-                    self._fatal_error()
+                    self._fatal_error(err)
         self._running_event.clear()
 
     def _handle_internal_messages(self, msg):
@@ -431,12 +432,12 @@ def run_logs(config, address):
 
     has_connects = []
 
-    def try_connect(tries=0, is_disconnect=True):
+    def try_connect(err, tries=0):
         if stopping:
             return
 
-        if is_disconnect:
-            _LOGGER.warning(u"Disconnected from API.")
+        if err:
+            _LOGGER.warning(u"Disconnected from API: %s", err)
 
         while retry_timer:
             retry_timer.pop(0).cancel()
@@ -445,8 +446,8 @@ def run_logs(config, address):
         try:
             cli.connect()
             cli.login()
-        except APIConnectionError as err:  # noqa
-            error = err
+        except APIConnectionError as err2:  # noqa
+            error = err2
 
         if error is None:
             _LOGGER.info("Successfully connected to %s", address)
@@ -460,7 +461,7 @@ def run_logs(config, address):
         else:
             _LOGGER.warning(u"Couldn't connect to API (%s). Trying to reconnect in %s seconds",
                             error, wait_time)
-        timer = threading.Timer(wait_time, functools.partial(try_connect, tries + 1, is_disconnect))
+        timer = threading.Timer(wait_time, functools.partial(try_connect, None, tries + 1))
         timer.start()
         retry_timer.append(timer)
 
@@ -484,7 +485,7 @@ def run_logs(config, address):
     cli.start()
 
     try:
-        try_connect(is_disconnect=False)
+        try_connect(None)
         while True:
             time.sleep(1)
     except KeyboardInterrupt:

esphome/components/api/api_server.cpp

@@ -712,12 +712,12 @@ bool APIConnection::send_buffer(APIMessageType type) {
   size_t needed_space = this->send_buffer_.size() + header_len;
 
   if (needed_space > this->client_->space()) {
-    delay(5);
+    delay(0);
     if (needed_space > this->client_->space()) {
       if (type != APIMessageType::SUBSCRIBE_LOGS_RESPONSE) {
         ESP_LOGV(TAG, "Cannot send message because of TCP buffer space");
       }
-      delay(5);
+      delay(0);
       return false;
     }
   }

esphome/components/mqtt/mqtt_client.cpp

@@ -360,18 +360,19 @@ bool MQTTClientComponent::publish(const std::string &topic, const char *payload,
   }
   bool logging_topic = topic == this->log_message_.topic;
   uint16_t ret = this->mqtt_client_.publish(topic.c_str(), qos, retain, payload, payload_length);
-  yield();
+  delay(0);
   if (ret == 0 && !logging_topic && this->is_connected()) {
-    delay(5);
+    delay(0);
     ret = this->mqtt_client_.publish(topic.c_str(), qos, retain, payload, payload_length);
-    yield();
+    delay(0);
   }
 
   if (!logging_topic) {
     if (ret != 0) {
       ESP_LOGV(TAG, "Publish(topic='%s' payload='%s' retain=%d)", topic.c_str(), payload, retain);
     } else {
-      ESP_LOGW(TAG, "Publish failed for topic='%s' will retry later..", topic.c_str());
+      ESP_LOGV(TAG, "Publish failed for topic='%s' (len=%u). will retry later..", topic.c_str(),
+               payload_length);  // NOLINT
       this->status_momentary_warning("publish", 1000);
     }
   }

esphome/components/wifi/wifi_component.cpp

@@ -421,6 +421,7 @@ void WiFiComponent::check_connecting_finished() {
 }
 
 void WiFiComponent::retry_connect() {
+  delay(10);
   if (this->num_retried_ > 5 || this->error_from_callback_) {
     // If retry failed for more than 5 times, let's restart STA
     ESP_LOGW(TAG, "Restarting WiFi adapter...");

esphome/components/wifi/wifi_component_esp8266.cpp

@@ -330,7 +330,6 @@ const char *get_disconnect_reason_str(uint8_t reason) {
 }
 
 void WiFiComponent::wifi_event_callback(System_Event_t *event) {
-#ifdef ESPHOME_LOG_HAS_VERBOSE
   // TODO: this callback is called while in cont context, so delay will fail
   // We need to defer the log messages until we're out of this context
   // only affects verbose log level
@@ -351,7 +350,7 @@ void WiFiComponent::wifi_event_callback(System_Event_t *event) {
       char buf[33];
       memcpy(buf, it.ssid, it.ssid_len);
       buf[it.ssid_len] = '\0';
-      ESP_LOGV(TAG, "Event: Disconnected ssid='%s' bssid=%s reason='%s'", buf, format_mac_addr(it.bssid).c_str(),
+      ESP_LOGW(TAG, "Event: Disconnected ssid='%s' bssid=%s reason='%s'", buf, format_mac_addr(it.bssid).c_str(),
                get_disconnect_reason_str(it.reason));
       break;
     }
@@ -403,7 +402,6 @@ void WiFiComponent::wifi_event_callback(System_Event_t *event) {
     default:
       break;
   }
-#endif
 
   if (event->event == EVENT_STAMODE_DISCONNECTED) {
     global_wifi_component->error_from_callback_ = true;

esphome/core/application.cpp

@@ -57,14 +57,7 @@ void Application::setup() {
   }
 
   ESP_LOGI(TAG, "setup() finished successfully!");
-  this->dump_config();
-}
-void Application::dump_config() {
-  ESP_LOGI(TAG, "esphome version " ESPHOME_VERSION " compiled on %s", this->compilation_time_.c_str());
-
-  for (auto component : this->components_) {
-    component->dump_config();
-  }
+  this->schedule_dump_config();
 }
 void Application::loop() {
   uint32_t new_app_state = 0;
@@ -97,9 +90,13 @@ void Application::loop() {
   }
   this->last_loop_ = now;
 
-  if (this->dump_config_scheduled_) {
-    this->dump_config();
-    this->dump_config_scheduled_ = false;
+  if (this->dump_config_at_ >= 0 && this->dump_config_at_ < this->components_.size()) {
+    if (this->dump_config_at_ == 0) {
+      ESP_LOGI(TAG, "esphome version " ESPHOME_VERSION " compiled on %s", this->compilation_time_.c_str());
+    }
+
+    this->components_[this->dump_config_at_]->dump_config();
+    this->dump_config_at_++;
   }
 }
 

esphome/core/application.h

@@ -109,8 +109,7 @@ class Application {
    */
   void set_loop_interval(uint32_t loop_interval) { this->loop_interval_ = loop_interval; }
 
-  void dump_config();
-  void schedule_dump_config() { this->dump_config_scheduled_ = true; }
+  void schedule_dump_config() { this->dump_config_at_ = 0; }
 
   void feed_wdt();
 
@@ -234,7 +233,7 @@ class Application {
   std::string compilation_time_;
   uint32_t last_loop_{0};
   uint32_t loop_interval_{16};
-  bool dump_config_scheduled_{false};
+  int dump_config_at_{-1};
   uint32_t app_state_{0};
 };
 

esphome/core_config.py

@@ -61,7 +61,7 @@ PLATFORMIO_ESP32_LUT = {
     '1.0.0': 'espressif32@1.4.0',
     '1.0.1': 'espressif32@1.6.0',
     '1.0.2': 'espressif32@1.8.0',
-    'RECOMMENDED': 'espressif32@1.6.0',
+    'RECOMMENDED': 'espressif32@1.8.0',
     'LATEST': 'espressif32',
     'DEV': ARDUINO_VERSION_ESP32_DEV,
 }

esphome/helpers.py

@@ -127,15 +127,20 @@ def resolve_ip_address(host):
     from esphome.core import EsphomeError
     import socket
 
-    try:
-        ip = socket.gethostbyname(host)
-    except socket.error as err:
-        if host.endswith('.local'):
-            ip = _resolve_with_zeroconf(host)
-        else:
-            raise EsphomeError("Error resolving IP address: {}".format(err))
+    errs = []
 
-    return ip
+    if host.endswith('.local'):
+        try:
+            return _resolve_with_zeroconf(host)
+        except EsphomeError as err:
+            errs.append(str(err))
+
+    try:
+        return socket.gethostbyname(host)
+    except socket.error as err:
+        errs.append(str(err))
+        raise EsphomeError("Error resolving IP address: {}"
+                           "".format(', '.join(errs)))
 
 
 def get_bool_env(var, default=False):

script/lint-python

@@ -56,7 +56,7 @@ def main():
     print("Running flake8...")
     log = get_output(*cmd)
     for line in log.splitlines():
-        line = line.split(':')
+        line = line.split(':', 4)
         if len(line) < 4:
             continue
         file_ = line[0]
@@ -69,12 +69,12 @@ def main():
     print("Running pylint...")
     log = get_output(*cmd)
     for line in log.splitlines():
-        line = line.split(':')
+        line = line.split(':', 3)
         if len(line) < 3:
             continue
         file_ = line[0]
         linno = line[1]
-        msg = (u':'.join(line[3:])).strip()
+        msg = (u':'.join(line[2:])).strip()
         print_error(file_, linno, msg)
         errors += 1