Add filename and line number back to esp log

Previously security eFuses were only burnt if the flash was not encrypted
yet.
To enhance robustness of the security eFuse settings their correct setup
should be verified on each bootup. Else it would be possible for an
already encrypted ESP to be reflashed with firmware containing updated,
more restrictive eFuse settings without them ever being applied.
Additionally this change enables easy, secure use of ESPs with host sidee
flash preencryption. Flash preencryption by the host computer performing
the programming procedure can speed up the programming process by a great
deal since the flash no longer needs to be read, erased and written again
by the bootloader self-encryption routines. Additionally it avoids
bricking of ESPs through interruption of the self-ecnryption procedure.
Without this change the host would have to set up all fuses in the ESP
correctly by itself, duplicating the fuse configuration code already
present in the bootloader and creating additional maintenance burden for
the host software if anything about the fuse setup logic changes.
This commit changes the security eFuse configuration logic to always burn
any configured security eFuses on bootup, regardless of current flash
encryption status.

components/bootloader_support/src/bootloader_utility.c

@@ -717,7 +717,25 @@ static void load_image(const esp_image_metadata_t *image_data)
      */
     ESP_LOGI(TAG, "Checking flash encryption...");
     bool flash_encryption_enabled = esp_flash_encrypt_state();
-    if (!flash_encryption_enabled) {
+    if (flash_encryption_enabled) {
+#if BOOTLOADER_BUILD
+        /* Ensure security eFuses are burnt */
+        esp_efuse_batch_write_begin();
+        esp_err_t err = esp_flash_encryption_enable_secure_features();
+        if (err != ESP_OK) {
+            ESP_LOGE(TAG, "Error setting security eFuses (err=0x%x).", err);
+            esp_efuse_batch_write_cancel();
+            return;
+        }
+
+        err = esp_efuse_batch_write_commit();
+        if (err != ESP_OK) {
+            ESP_LOGE(TAG, "Error programming security eFuses (err=0x%x).", err);
+            return;
+        }
+        ESP_LOGI(TAG, "Security eFuses are burnt");
+#endif // BOOTLOADER_BUILD
+    } else {
 #ifdef CONFIG_SECURE_FLASH_REQUIRE_ALREADY_ENABLED
         ESP_LOGE(TAG, "flash encryption is not enabled, and SECURE_FLASH_REQUIRE_ALREADY_ENABLED is set, refusing to boot.");
         return;

components/esp-tls/esp_tls.c

@@ -129,7 +129,7 @@ static ssize_t tcp_read(esp_tls_t *tls, char *data, size_t datalen)
 
 static ssize_t tcp_write(esp_tls_t *tls, const char *data, size_t datalen)
 {
-    return send(tls->sockfd, data, datalen, 0);
+    return send(tls->sockfd, data, datalen, MSG_MORE);
 }
 
 ssize_t esp_tls_conn_read(esp_tls_t *tls, void  *data, size_t datalen)

components/esp-tls/esp_tls_mbedtls.c

@@ -681,6 +681,7 @@ static esp_err_t set_server_config(esp_tls_cfg_server_t *cfg, esp_tls_t *tls)
         if (esp_ret != ESP_OK) {
             return esp_ret;
         }
+        mbedtls_ssl_conf_authmode(&tls->conf, MBEDTLS_SSL_VERIFY_OPTIONAL);
     } else {
 #ifdef CONFIG_ESP_TLS_SERVER_MIN_AUTH_MODE_OPTIONAL
         mbedtls_ssl_conf_authmode(&tls->conf, MBEDTLS_SSL_VERIFY_OPTIONAL);

components/esp_driver_spi/include/driver/spi_master.h

@@ -407,6 +407,9 @@ int spi_get_freq_limit(bool gpio_is_used, int input_delay_ns);
  */
 esp_err_t spi_bus_get_max_transaction_len(spi_host_device_t host_id, size_t *max_bytes);
 
+intr_handle_t spi_bus_get_intr(spi_host_device_t host);
+void spi_dma_reset_start(spi_device_handle_t handle);
+
 #ifdef __cplusplus
 }
 #endif

components/esp_driver_spi/src/gpspi/spi_master.c

@@ -721,6 +721,22 @@ static void SPI_MASTER_ISR_ATTR spi_bus_intr_disable(void *host)
 #define spi_dma_start(chan, addr)   gdma_start(chan, (intptr_t)(addr))
 #endif
 
+void SPI_MASTER_ISR_ATTR spi_dma_reset_start(spi_device_handle_t handle){
+    spi_host_t *host = handle->host;
+    spi_hal_context_t *hal = &(host->hal);
+
+    const spi_dma_ctx_t *dma_ctx = host->dma_ctx;
+
+    spi_dma_reset(dma_ctx->rx_dma_chan);
+    spi_hal_hw_prepare_rx(hal->hw);
+    spi_dma_start(dma_ctx->rx_dma_chan, dma_ctx->dmadesc_rx);
+
+
+    spi_dma_reset(dma_ctx->tx_dma_chan);
+    spi_hal_hw_prepare_tx(hal->hw);
+    spi_dma_start(dma_ctx->tx_dma_chan, dma_ctx->dmadesc_tx);
+}
+
 static void SPI_MASTER_ISR_ATTR s_spi_dma_prepare_data(spi_host_t *host, spi_hal_context_t *hal, const spi_hal_dev_config_t *dev, const spi_hal_trans_config_t *trans)
 {
     const spi_dma_ctx_t *dma_ctx = host->dma_ctx;
@@ -1510,6 +1526,10 @@ esp_err_t spi_bus_get_max_transaction_len(spi_host_device_t host_id, size_t *max
     return ESP_OK;
 }
 
+intr_handle_t spi_bus_get_intr(spi_host_device_t host) {
+    return bus_driver_ctx[host]->intr;
+}
+
 #if SOC_SPI_SCT_SUPPORTED
 
 /*-----------------------------------------------------------

components/esp_http_client/esp_http_client.c

@@ -272,7 +272,8 @@ static int http_on_header_value(http_parser *parser, const char *at, size_t leng
     } else if (strcasecmp(client->current_header_key, "Transfer-Encoding") == 0
                && memcmp(at, "chunked", length) == 0) {
         client->response->is_chunked = true;
-    } else if (strcasecmp(client->current_header_key, "WWW-Authenticate") == 0) {
+    } else if (strcasecmp(client->current_header_key, "WWW-Authenticate") == 0 ||
+               strcasecmp(client->current_header_key, "X-WWW-Authenticate") == 0) {
         HTTP_RET_ON_FALSE_DBG(http_utils_append_string(&client->auth_header, at, length), -1, TAG, "Failed to append string");
     }
     HTTP_RET_ON_FALSE_DBG(http_utils_append_string(&client->current_header_value, at, length), -1, TAG, "Failed to append string");
@@ -1366,7 +1367,7 @@ int esp_http_client_read(esp_http_client_handle_t client, char *buffer, int len)
 esp_err_t esp_http_client_perform(esp_http_client_handle_t client)
 {
     esp_err_t err;
-    do {
+    //do {
         if (client->process_again) {
             esp_http_client_prepare(client);
         }
@@ -1474,8 +1475,9 @@ esp_err_t esp_http_client_perform(esp_http_client_handle_t client)
                 default:
                 break;
         }
-    } while (client->process_again);
-    return ESP_OK;
+    //} while (client->process_again);
+    //return ESP_OK;
+    return client->process_again ? ESP_ERR_HTTP_EAGAIN : ESP_OK;
 }
 
 int64_t esp_http_client_fetch_headers(esp_http_client_handle_t client)

components/esp_http_server/src/httpd_txrx.c

@@ -56,7 +56,7 @@ int httpd_send(httpd_req_t *r, const char *buf, size_t buf_len)
     }
 
     struct httpd_req_aux *ra = r->aux;
-    int ret = ra->sd->send_fn(ra->sd->handle, ra->sd->fd, buf, buf_len, 0);
+    int ret = ra->sd->send_fn(ra->sd->handle, ra->sd->fd, buf, buf_len, MSG_MORE);
     if (ret < 0) {
         ESP_LOGD(TAG, LOG_FMT("error in send_fn"));
         return ret;
@@ -70,7 +70,7 @@ static esp_err_t httpd_send_all(httpd_req_t *r, const char *buf, size_t buf_len)
     int ret;
 
     while (buf_len > 0) {
-        ret = ra->sd->send_fn(ra->sd->handle, ra->sd->fd, buf, buf_len, 0);
+        ret = ra->sd->send_fn(ra->sd->handle, ra->sd->fd, buf, buf_len, MSG_MORE);
         if (ret < 0) {
             ESP_LOGD(TAG, LOG_FMT("error in send_fn"));
             return ESP_FAIL;

components/esp_http_server/src/httpd_uri.c

@@ -294,10 +294,31 @@ esp_err_t httpd_uri(struct httpd_data *hd)
 
     /* If URI with method not found, respond with error code */
     if (uri == NULL) {
+
         switch (err) {
             case HTTPD_404_NOT_FOUND:
-                ESP_LOGW(TAG, LOG_FMT("URI '%s' not found"), req->uri);
+            {
+                char ipstr[INET6_ADDRSTRLEN] = "UNKNOWN";
+
+                const int sockfd = httpd_req_to_sockfd(req);
+
+                if (sockfd < 0)
+                    ESP_LOGW(TAG, "httpd_req_to_sockfd() failed with %i", sockfd);
+                else
+                {
+                    struct sockaddr_in6 addr;   // esp_http_server uses IPv6 addressing
+                    socklen_t addr_size = sizeof(addr);
+                    const int result = getpeername(sockfd, (struct sockaddr *)&addr, &addr_size);
+
+                    if (result < 0)
+                        ESP_LOGW(TAG, "getpeername() failed with %i", result);
+                    else
+                        inet_ntop(AF_INET, &addr.sin6_addr.un.u32_addr[3], ipstr, sizeof(ipstr));
+                }
+
+                ESP_LOGW(TAG, LOG_FMT("URI '%s' not found for %s"), req->uri, ipstr);
                 return httpd_req_handle_err(req, HTTPD_404_NOT_FOUND);
+            }
             case HTTPD_405_METHOD_NOT_ALLOWED:
                 ESP_LOGW(TAG, LOG_FMT("Method '%d' not allowed for URI '%s'"),
                          req->method, req->uri);

components/esp_http_server/src/httpd_ws.c

@@ -445,14 +445,14 @@ esp_err_t httpd_ws_send_frame_async(httpd_handle_t hd, int fd, httpd_ws_frame_t
     }
 
     /* Send off header */
-    if (sess->send_fn(hd, fd, (const char *)header_buf, tx_len, 0) < 0) {
+    if (sess->send_fn(hd, fd, (const char *)header_buf, tx_len, MSG_MORE) < 0) {
         ESP_LOGW(TAG, LOG_FMT("Failed to send WS header"));
         return ESP_FAIL;
     }
 
     /* Send off payload */
     if(frame->len > 0 && frame->payload != NULL) {
-        if (sess->send_fn(hd, fd, (const char *)frame->payload, frame->len, 0) < 0) {
+        if (sess->send_fn(hd, fd, (const char *)frame->payload, frame->len, MSG_MORE) < 0) {
             ESP_LOGW(TAG, LOG_FMT("Failed to send WS payload"));
             return ESP_FAIL;
         }

components/esp_netif/include/esp_netif_ppp.h

@@ -8,6 +8,8 @@
 #ifndef _ESP_NETIF_PPP_H_
 #define _ESP_NETIF_PPP_H_
 
+#include "esp_netif_types.h"
+
 #ifdef __cplusplus
 extern "C" {
 #endif

components/espcoredump/include_core_dump/esp_core_dump_types.h

@@ -19,7 +19,7 @@ extern "C" {
 #include "core_dump_checksum.h"
 
 #if CONFIG_ESP_COREDUMP_LOGS
-#define ESP_COREDUMP_LOG( level, format, ... )  if (LOG_LOCAL_LEVEL >= level)   { esp_rom_printf((format), esp_log_early_timestamp(), (const char *)TAG, ##__VA_ARGS__); }
+#define ESP_COREDUMP_LOG( level, format, ... )  if (LOG_LOCAL_LEVEL >= level)   { esp_rom_printf(format, esp_log_early_timestamp(), (const char *)TAG, ##__VA_ARGS__); }
 #else
 #define ESP_COREDUMP_LOG( level, format, ... )  // dummy define doing nothing
 #endif

components/log/include/esp_log_format.h

@@ -11,8 +11,12 @@ extern "C" {
 #endif
 
 /** @cond */
+
+#define ESP_LOG_STRINGIFY2(x) #x
+#define ESP_LOG_STRINGIFY(x) ESP_LOG_STRINGIFY2(x)
+
 // For backward compatibility (these macros are not used in the log v2).
-#define LOG_FORMAT(letter, format)  LOG_COLOR_ ## letter #letter " (%" PRIu32 ") %s: " format LOG_RESET_COLOR "\n"
+#define LOG_FORMAT(letter, format)  LOG_COLOR_ ## letter #letter " %s:" ESP_LOG_STRINGIFY(__LINE__) " (%" PRIu32 ") %s: " format LOG_RESET_COLOR "\n", (__builtin_strrchr(__FILE__, '/') ? __builtin_strrchr(__FILE__, '/') + 1 : __FILE__)
 #define _ESP_LOG_DRAM_LOG_FORMAT(letter, format)  DRAM_STR(#letter " %s: " format "\n")
 #define LOG_SYSTEM_TIME_FORMAT(letter, format)  LOG_COLOR_ ## letter #letter " (%s) %s: " format LOG_RESET_COLOR "\n"
 /** @endcond */

components/soc/esp32/register/soc/emac_ext_struct.h

@@ -11,7 +11,7 @@ extern "C" {
 
 #include <stdint.h>
 
-typedef struct emac_ext_dev_s {
+typedef volatile struct emac_ext_dev_s {
     volatile union {
         struct {
             uint32_t div_num : 4;

components/tcp_transport/include/esp_transport_ws.h

@@ -14,6 +14,14 @@
 extern "C" {
 #endif
 
+// Features supported
+#define ESP_TRANSPORT_WS_STORE_RESPONSE_HEADERS     1
+
+// this define will also be used for optimized websocket sends with the
+// optimized version to prepend the required space for the websocket
+// header
+#define MAX_WEBSOCKET_HEADER_SIZE   16
+
 typedef enum ws_transport_opcodes {
     WS_TRANSPORT_OPCODES_CONT =  0x00,
     WS_TRANSPORT_OPCODES_TEXT =  0x01,
@@ -139,6 +147,37 @@ esp_err_t esp_transport_ws_set_config(esp_transport_handle_t t, const esp_transp
  */
 int esp_transport_ws_send_raw(esp_transport_handle_t t, ws_transport_opcodes_t opcode, const char *b, int len, int timeout_ms);
 
+/**
+ * @brief               Sends websocket raw message with custom opcode and payload in a optimized way
+ *
+ * This method is similar to esp_transport_ws_send_raw(), but
+ * it assumes, that the first MAX_WEBSOCKET_HEADER_SIZE bytes
+ * of the buffer should not be sent and should rather be used
+ * for the required websocket header itself. This is done to
+ * have a single TCP packet for header and payload and to avoid
+ * copying and allocating additional resources. The first
+ * MAX_WEBSOCKET_HEADER_SIZE bytes should not be initialized in
+ * any specific way, and the return value (length) will also
+ * include the MAX_WEBSOCKET_HEADER_SIZE byte extra buffer.
+ *
+ * Note that generic esp_transport_write for ws handle sends
+ * binary massages by default if size is > 0 and
+ * ping message if message size is set to 0.
+ * This API is provided to support explicit messages with arbitrary opcode,
+ * should it be PING, PONG or TEXT message with arbitrary data.
+ *
+ * @param[in]  t           Websocket transport handle
+ * @param[in]  opcode      ws operation code
+ * @param[in]  buffer      The buffer
+ * @param[in]  len         The length
+ * @param[in]  timeout_ms  The timeout milliseconds (-1 indicates block forever)
+ *
+ * @return
+ *  - Number of bytes was written
+ *  - (-1) if there are any errors, should check errno
+ */
+int esp_transport_ws_send_raw_optimized(esp_transport_handle_t t, ws_transport_opcodes_t opcode, const char *b, int len, int timeout_ms);
+
 /**
  * @brief               Returns websocket fin flag for last received data
  *

components/tcp_transport/transport_ssl.c

@@ -249,7 +249,7 @@ static int tcp_write(esp_transport_handle_t t, const char *buffer, int len, int
         ESP_LOGW(TAG, "Poll timeout or error, errno=%s, fd=%d, timeout_ms=%d", strerror(errno), ssl->sockfd, timeout_ms);
         return poll;
     }
-    int ret = send(ssl->sockfd, (const unsigned char *) buffer, len, 0);
+    int ret = send(ssl->sockfd, (const unsigned char *) buffer, len, MSG_MORE);
     if (ret < 0) {
         ESP_LOGE(TAG, "tcp_write error, errno=%s", strerror(errno));
         esp_transport_capture_errno(t, errno);

components/tcp_transport/transport_ws.c

@@ -420,6 +420,92 @@ static int _ws_write(esp_transport_handle_t t, int opcode, int mask_flag, const
     return ret;
 }
 
+// This method is similar to _ws_write() but it assumes, that the first 16 bytes of the buffer should not be sent and
+// should rather be used for the required websocket header itself. This is done to have a single TCP packet for header
+// and payload and to avoid copying and allocating additional resources. The first 16 bytes should not be initialized
+// in any specific way, and the return value (length) will also include the 16 byte extra buffer.
+static int _ws_write_optimized(esp_transport_handle_t t, int opcode, int mask_flag, const char *b, int len, int timeout_ms)
+{
+    assert(len >= MAX_WEBSOCKET_HEADER_SIZE);
+
+    transport_ws_t *ws = esp_transport_get_context_data(t);
+    char *buffer = (char *)b;
+    char *ws_header;
+//    char *mask;
+    int header_len = 0; //, i;
+
+    int poll_write;
+    if ((poll_write = esp_transport_poll_write(ws->parent, timeout_ms)) <= 0) {
+        ESP_LOGE(TAG, "Error transport_poll_write %i", poll_write);
+        return poll_write;
+    }
+
+    int len2 = len - MAX_WEBSOCKET_HEADER_SIZE;
+    if (len2 <= 125) {
+        ws_header = buffer+MAX_WEBSOCKET_HEADER_SIZE-2-4;
+        ws_header[header_len++] = opcode;
+        ws_header[header_len++] = (uint8_t)(len2 | mask_flag);
+    } else if (len2 < 65536) {
+        ws_header = buffer+MAX_WEBSOCKET_HEADER_SIZE-4-4;
+        ws_header[header_len++] = opcode;
+        ws_header[header_len++] = WS_SIZE16 | mask_flag;
+        ws_header[header_len++] = (uint8_t)(len2 >> 8);
+        ws_header[header_len++] = (uint8_t)(len2 & 0xFF);
+    } else {
+        ws_header = buffer+MAX_WEBSOCKET_HEADER_SIZE-10-4;
+        ws_header[header_len++] = opcode;
+        ws_header[header_len++] = WS_SIZE64 | mask_flag;
+        /* Support maximum 4 bytes length */
+        ws_header[header_len++] = 0; //(uint8_t)((len >> 56) & 0xFF);
+        ws_header[header_len++] = 0; //(uint8_t)((len >> 48) & 0xFF);
+        ws_header[header_len++] = 0; //(uint8_t)((len >> 40) & 0xFF);
+        ws_header[header_len++] = 0; //(uint8_t)((len >> 32) & 0xFF);
+        ws_header[header_len++] = (uint8_t)((len2 >> 24) & 0xFF);
+        ws_header[header_len++] = (uint8_t)((len2 >> 16) & 0xFF);
+        ws_header[header_len++] = (uint8_t)((len2 >> 8) & 0xFF);
+        ws_header[header_len++] = (uint8_t)((len2 >> 0) & 0xFF);
+    }
+
+    if (mask_flag) {
+        ws_header[header_len++] = 0;
+        ws_header[header_len++] = 0;
+        ws_header[header_len++] = 0;
+        ws_header[header_len++] = 0;
+//        mask = &ws_header[header_len];
+//        mask = 0;
+//        ssize_t rc;
+//        if ((rc = getrandom(ws_header + header_len, 4, 0)) < 0) {
+//            ESP_LOGD(TAG, "getrandom() returned %zd", rc);
+//            return -1;
+//        }
+//        header_len += 4;
+
+//        for (i = MAX_WEBSOCKET_HEADER_SIZE; i < len; ++i) {
+//            buffer[i] = (buffer[i] ^ mask[i % 4]);
+//        }
+    }
+
+//    if (esp_transport_write(ws->parent, ws_header, len - MAX_WEBSOCKET_HEADER_SIZE + header_len, timeout_ms) != header_len) {
+//        ESP_LOGE(TAG, "Error write header");
+//        return -1;
+//    }
+//    if (len == 0) {
+//        return 0;
+//    }
+
+    int ret = esp_transport_write(ws->parent, ws_header, len - MAX_WEBSOCKET_HEADER_SIZE + header_len, timeout_ms);
+//    ESP_LOGI(TAG, "len=%d header_len=%d total_size=%d sent=%d", len, header_len, len - MAX_WEBSOCKET_HEADER_SIZE + header_len, ret);
+    // in case of masked transport we have to revert back to the original data, as ws layer
+    // does not create its own copy of data to be sent
+    if (mask_flag) {
+//        mask = &ws_header[header_len - 4];
+//        for (i = 0; i < len; ++i) {
+//            buffer[i] = (buffer[i] ^ mask[i % 4]);
+//        }
+    }
+    return ret + (ws_header - buffer);
+}
+
 int esp_transport_ws_send_raw(esp_transport_handle_t t, ws_transport_opcodes_t opcode, const char *b, int len, int timeout_ms)
 {
     uint8_t op_code = ws_get_bin_opcode(opcode);
@@ -431,6 +517,17 @@ int esp_transport_ws_send_raw(esp_transport_handle_t t, ws_transport_opcodes_t o
     return _ws_write(t, op_code, WS_MASK, b, len, timeout_ms);
 }
 
+int esp_transport_ws_send_raw_optimized(esp_transport_handle_t t, ws_transport_opcodes_t opcode, const char *b, int len, int timeout_ms)
+{
+    uint8_t op_code = ws_get_bin_opcode(opcode);
+    if (t == NULL) {
+        ESP_LOGE(TAG, "Transport must be a valid ws handle");
+        return ESP_ERR_INVALID_ARG;
+    }
+    ESP_LOGD(TAG, "Sending raw ws message with opcode %d", op_code);
+    return _ws_write_optimized(t, op_code, WS_MASK, b, len, timeout_ms);
+}
+
 static int ws_write(esp_transport_handle_t t, const char *b, int len, int timeout_ms)
 {
     if (len == 0) {