From e72895b7224e4f34c7727491017023433d885df5 Mon Sep 17 00:00:00 2001 From: me-no-dev Date: Fri, 29 Sep 2017 20:31:45 +0800 Subject: [PATCH] Quiet SSL and HTTPClient debug --- libraries/HTTPClient/src/HTTPClient.cpp | 92 +++++++++---------- libraries/HTTPClient/src/HTTPClient.h | 1 + libraries/WiFi/src/WiFiClient.cpp | 2 +- libraries/WiFiClientSecure/src/ssl_client.cpp | 46 +++++----- 4 files changed, 70 insertions(+), 71 deletions(-) diff --git a/libraries/HTTPClient/src/HTTPClient.cpp b/libraries/HTTPClient/src/HTTPClient.cpp index 1e103857..8b82bbe0 100644 --- a/libraries/HTTPClient/src/HTTPClient.cpp +++ b/libraries/HTTPClient/src/HTTPClient.cpp @@ -110,6 +110,7 @@ bool HTTPClient::begin(String url, const char* CAcert) if (!beginInternal(url, "https")) { return false; } + _secure = true; _transportTraits = TransportTraitsPtr(new TLSTraits(CAcert)); return true; } @@ -121,13 +122,10 @@ bool HTTPClient::begin(String url, const char* CAcert) bool HTTPClient::begin(String url) { - if (beginInternal(url, "https")) { - return begin(url, (const char*)NULL); - } _transportTraits.reset(nullptr); _port = 80; if (!beginInternal(url, "http")) { - return false; + return begin(url, (const char*)NULL); } _transportTraits = TransportTraitsPtr(new TransportTraits()); return true; @@ -135,20 +133,19 @@ bool HTTPClient::begin(String url) bool HTTPClient::beginInternal(String url, const char* expectedProtocol) { - log_d("[HTTP-Client][begin] url: %s", url.c_str()); - bool hasPort = false; + log_v("url: %s", url.c_str()); clear(); // check for : (http: or https: int index = url.indexOf(':'); if(index < 0) { - log_d("[HTTP-Client][begin] failed to parse protocol"); + log_e("failed to parse protocol"); return false; } _protocol = url.substring(0, index); if (_protocol != expectedProtocol) { - log_d("[HTTP-Client][begin] unexpected protocol: %s, expected %s", _protocol.c_str(), expectedProtocol); + log_w("unexpected protocol: %s, expected %s", _protocol.c_str(), expectedProtocol); return false; } @@ -177,7 +174,7 @@ bool HTTPClient::beginInternal(String url, const char* expectedProtocol) _host = host; } _uri = url; - log_d("[HTTP-Client][begin] host: %s port: %d url: %s", _host.c_str(), _port, _uri.c_str()); + log_d("host: %s port: %d url: %s", _host.c_str(), _port, _uri.c_str()); return true; } @@ -188,7 +185,7 @@ bool HTTPClient::begin(String host, uint16_t port, String uri) _port = port; _uri = uri; _transportTraits = TransportTraitsPtr(new TransportTraits()); - log_d("[HTTP-Client][begin] host: %s port: %d uri: %s", host.c_str(), port, uri.c_str()); + log_d("host: %s port: %d uri: %s", host.c_str(), port, uri.c_str()); return true; } @@ -203,7 +200,6 @@ bool HTTPClient::begin(String host, uint16_t port, String uri, const char* CAcer return false; } _transportTraits = TransportTraitsPtr(new TLSTraits(CAcert)); - //log_d("[HTTP-Client][begin] host: %s port: %d url: %s httpsFingerprint: %s", host.c_str(), port, uri.c_str(), httpsFingerprint.c_str()); return true; } @@ -215,19 +211,19 @@ void HTTPClient::end(void) { if(connected()) { if(_tcp->available() > 0) { - log_d("[HTTP-Client][end] still data in buffer (%d), clean up.", _tcp->available()); + log_d("still data in buffer (%d), clean up.", _tcp->available()); while(_tcp->available() > 0) { _tcp->read(); } } if(_reuse && _canReuse) { - log_d("[HTTP-Client][end] tcp keep open for reuse"); + log_d("tcp keep open for reuse"); } else { - log_d("[HTTP-Client][end] tcp stop"); + log_d("tcp stop"); _tcp->stop(); } } else { - log_d("[HTTP-Client][end] tcp is closed"); + log_v("tcp is closed"); } } @@ -295,7 +291,7 @@ void HTTPClient::setAuthorization(const char * auth) void HTTPClient::setTimeout(uint16_t timeout) { _tcpTimeout = timeout; - if(connected()) { + if(connected() && !_secure) { _tcp->setTimeout(timeout); } } @@ -468,11 +464,11 @@ int HTTPClient::sendRequest(const char * type, Stream * stream, size_t size) // are all Bytes a writen to stream ? if(bytesWrite != bytesRead) { - log_d("[HTTP-Client][sendRequest] short write, asked for %d but got %d retry...", bytesRead, bytesWrite); + log_d("short write, asked for %d but got %d retry...", bytesRead, bytesWrite); // check for write error if(_tcp->getWriteError()) { - log_d("[HTTP-Client][sendRequest] stream write error %d", _tcp->getWriteError()); + log_d("stream write error %d", _tcp->getWriteError()); //reset write error for retry _tcp->clearWriteError(); @@ -489,7 +485,7 @@ int HTTPClient::sendRequest(const char * type, Stream * stream, size_t size) if(bytesWrite != leftBytes) { // failed again - log_d("[HTTP-Client][sendRequest] short write, asked for %d but got %d failed.", leftBytes, bytesWrite); + log_d("short write, asked for %d but got %d failed.", leftBytes, bytesWrite); free(buff); return returnError(HTTPC_ERROR_SEND_PAYLOAD_FAILED); } @@ -497,7 +493,7 @@ int HTTPClient::sendRequest(const char * type, Stream * stream, size_t size) // check for write error if(_tcp->getWriteError()) { - log_d("[HTTP-Client][sendRequest] stream write error %d", _tcp->getWriteError()); + log_d("stream write error %d", _tcp->getWriteError()); free(buff); return returnError(HTTPC_ERROR_SEND_PAYLOAD_FAILED); } @@ -516,15 +512,15 @@ int HTTPClient::sendRequest(const char * type, Stream * stream, size_t size) free(buff); if(size && (int) size != bytesWritten) { - log_d("[HTTP-Client][sendRequest] Stream payload bytesWritten %d and size %d mismatch!.", bytesWritten, size); - log_d("[HTTP-Client][sendRequest] ERROR SEND PAYLOAD FAILED!"); + log_d("Stream payload bytesWritten %d and size %d mismatch!.", bytesWritten, size); + log_d("ERROR SEND PAYLOAD FAILED!"); return returnError(HTTPC_ERROR_SEND_PAYLOAD_FAILED); } else { - log_d("[HTTP-Client][sendRequest] Stream payload written: %d", bytesWritten); + log_d("Stream payload written: %d", bytesWritten); } } else { - log_d("[HTTP-Client][sendRequest] too less ram! need %d", HTTP_TCP_BUFFER_SIZE); + log_d("too less ram! need %d", HTTP_TCP_BUFFER_SIZE); return returnError(HTTPC_ERROR_TOO_LESS_RAM); } @@ -551,7 +547,7 @@ WiFiClient& HTTPClient::getStream(void) return *_tcp; } - log_d("[HTTP-Client] getStream: not connected"); + log_d("getStream: not connected"); static WiFiClient empty; return empty; } @@ -566,7 +562,7 @@ WiFiClient* HTTPClient::getStreamPtr(void) return _tcp.get(); } - log_d("[HTTP-Client] getStreamPtr: not connected"); + log_d("getStreamPtr: not connected"); return nullptr; } @@ -614,7 +610,7 @@ int HTTPClient::writeToStream(Stream * stream) // read size of chunk len = (uint32_t) strtol((const char *) chunkHeader.c_str(), NULL, 16); size += len; - log_d("[HTTP-Client] read chunk len: %d", len); + log_d(" read chunk len: %d", len); // data left? if(len > 0) { @@ -666,7 +662,7 @@ String HTTPClient::getString(void) if(_size) { // try to reserve needed memmory if(!sstring.reserve((_size + 1))) { - log_d("[HTTP-Client][getString] not enough memory to reserve a string! need: %d", (_size + 1)); + log_d("not enough memory to reserve a string! need: %d", (_size + 1)); return ""; } } @@ -807,7 +803,7 @@ bool HTTPClient::connect(void) { if(connected()) { - log_d("[HTTP-Client] connect. already connected, try reuse!"); + log_d("already connected, try reuse!"); while(_tcp->available() > 0) { _tcp->read(); } @@ -815,7 +811,7 @@ bool HTTPClient::connect(void) } if (!_transportTraits) { - log_d("[HTTP-Client] connect: HTTPClient::begin was not called or returned error"); + log_d("HTTPClient::begin was not called or returned error"); return false; } @@ -823,20 +819,20 @@ bool HTTPClient::connect(void) if (!_transportTraits->verify(*_tcp, _host.c_str())) { - log_d("[HTTP-Client] transport level verify failed"); + log_d("transport level verify failed"); _tcp->stop(); return false; } if(!_tcp->connect(_host.c_str(), _port)) { - log_d("[HTTP-Client] failed connect to %s:%u", _host.c_str(), _port); + log_d("failed connect to %s:%u", _host.c_str(), _port); return false; } - log_d("[HTTP-Client] connected to %s:%u", _host.c_str(), _port); + log_d(" connected to %s:%u", _host.c_str(), _port); // set Timeout for readBytesUntil and readStringUntil - _tcp->setTimeout(_tcpTimeout); + setTimeout(_tcpTimeout); /* #ifdef ESP8266 _tcp->setNoDelay(true); @@ -921,7 +917,7 @@ int HTTPClient::handleHeaderResponse() lastDataTime = millis(); - log_d("[HTTP-Client][handleHeaderResponse] RX: '%s'", headerLine.c_str()); + log_v("RX: '%s'", headerLine.c_str()); if(headerLine.startsWith("HTTP/1.")) { _returnCode = headerLine.substring(9, headerLine.indexOf(' ', 9)).toInt(); @@ -951,14 +947,14 @@ int HTTPClient::handleHeaderResponse() } if(headerLine == "") { - log_d("[HTTP-Client][handleHeaderResponse] code: %d", _returnCode); + log_d("code: %d", _returnCode); if(_size > 0) { - log_d("[HTTP-Client][handleHeaderResponse] size: %d", _size); + log_d("size: %d", _size); } if(transferEncoding.length() > 0) { - log_d("[HTTP-Client][handleHeaderResponse] Transfer-Encoding: %s", transferEncoding.c_str()); + log_d("Transfer-Encoding: %s", transferEncoding.c_str()); if(transferEncoding.equalsIgnoreCase("chunked")) { _transferEncoding = HTTPC_TE_CHUNKED; } else { @@ -971,7 +967,7 @@ int HTTPClient::handleHeaderResponse() if(_returnCode) { return _returnCode; } else { - log_d("[HTTP-Client][handleHeaderResponse] Remote host is not an HTTP Server!"); + log_d("Remote host is not an HTTP Server!"); return HTTPC_ERROR_NO_HTTP_SERVER; } } @@ -1037,11 +1033,11 @@ int HTTPClient::writeToStreamDataBlock(Stream * stream, int size) // are all Bytes a writen to stream ? if(bytesWrite != bytesRead) { - log_d("[HTTP-Client][writeToStream] short write asked for %d but got %d retry...", bytesRead, bytesWrite); + log_d("short write asked for %d but got %d retry...", bytesRead, bytesWrite); // check for write error if(stream->getWriteError()) { - log_d("[HTTP-Client][writeToStreamDataBlock] stream write error %d", stream->getWriteError()); + log_d("stream write error %d", stream->getWriteError()); //reset write error for retry stream->clearWriteError(); @@ -1058,7 +1054,7 @@ int HTTPClient::writeToStreamDataBlock(Stream * stream, int size) if(bytesWrite != leftBytes) { // failed again - log_d("[HTTP-Client][writeToStream] short write asked for %d but got %d failed.", leftBytes, bytesWrite); + log_w("short write asked for %d but got %d failed.", leftBytes, bytesWrite); free(buff); return HTTPC_ERROR_STREAM_WRITE; } @@ -1066,7 +1062,7 @@ int HTTPClient::writeToStreamDataBlock(Stream * stream, int size) // check for write error if(stream->getWriteError()) { - log_d("[HTTP-Client][writeToStreamDataBlock] stream write error %d", stream->getWriteError()); + log_w("stream write error %d", stream->getWriteError()); free(buff); return HTTPC_ERROR_STREAM_WRITE; } @@ -1084,15 +1080,15 @@ int HTTPClient::writeToStreamDataBlock(Stream * stream, int size) free(buff); - log_d("[HTTP-Client][writeToStreamDataBlock] connection closed or file end (written: %d).", bytesWritten); + log_d("connection closed or file end (written: %d).", bytesWritten); if((size > 0) && (size != bytesWritten)) { - log_d("[HTTP-Client][writeToStreamDataBlock] bytesWritten %d and size %d mismatch!.", bytesWritten, size); + log_d("bytesWritten %d and size %d mismatch!.", bytesWritten, size); return HTTPC_ERROR_STREAM_WRITE; } } else { - log_d("[HTTP-Client][writeToStreamDataBlock] too less ram! need %d", HTTP_TCP_BUFFER_SIZE); + log_w("too less ram! need %d", HTTP_TCP_BUFFER_SIZE); return HTTPC_ERROR_TOO_LESS_RAM; } @@ -1107,9 +1103,9 @@ int HTTPClient::writeToStreamDataBlock(Stream * stream, int size) int HTTPClient::returnError(int error) { if(error < 0) { - log_d("[HTTP-Client][returnError] error(%d): %s", error, errorToString(error).c_str()); + log_w("error(%d): %s", error, errorToString(error).c_str()); if(connected()) { - log_d("[HTTP-Client][returnError] tcp stop"); + log_d("tcp stop"); _tcp->stop(); } } diff --git a/libraries/HTTPClient/src/HTTPClient.h b/libraries/HTTPClient/src/HTTPClient.h index 6f27b0f5..2104fb0c 100644 --- a/libraries/HTTPClient/src/HTTPClient.h +++ b/libraries/HTTPClient/src/HTTPClient.h @@ -196,6 +196,7 @@ protected: bool _reuse = false; uint16_t _tcpTimeout = HTTPCLIENT_DEFAULT_TCP_TIMEOUT; bool _useHTTP10 = false; + bool _secure = false; String _uri; String _protocol; diff --git a/libraries/WiFi/src/WiFiClient.cpp b/libraries/WiFi/src/WiFiClient.cpp index 336f12b0..95c63c29 100644 --- a/libraries/WiFi/src/WiFiClient.cpp +++ b/libraries/WiFi/src/WiFiClient.cpp @@ -118,7 +118,7 @@ int WiFiClient::setSocketOption(int option, char* value, size_t len) { int res = setsockopt(fd(), SOL_SOCKET, option, value, len); if(res < 0) { - log_e("%d", errno); + log_e("%X : %d", option, errno); } return res; } diff --git a/libraries/WiFiClientSecure/src/ssl_client.cpp b/libraries/WiFiClientSecure/src/ssl_client.cpp index 124daaa2..a96b06ea 100644 --- a/libraries/WiFiClientSecure/src/ssl_client.cpp +++ b/libraries/WiFiClientSecure/src/ssl_client.cpp @@ -19,6 +19,9 @@ const char *pers = "esp32-tls"; static int handle_error(int err) { + if(err == -30848){ + return err; + } #ifdef MBEDTLS_ERROR_C char error_buf[100]; mbedtls_strerror(err, error_buf, 100); @@ -42,9 +45,9 @@ int start_ssl_client(sslclient_context *ssl_client, const char *host, uint32_t p char buf[512]; int ret, flags, len, timeout; int enable = 1; - log_i("Free heap before TLS %u", xPortGetFreeHeapSize()); + log_v("Free heap before TLS %u", xPortGetFreeHeapSize()); - log_i("Starting socket"); + log_v("Starting socket"); ssl_client->socket = -1; ssl_client->socket = lwip_socket(AF_INET, SOCK_STREAM, IPPROTO_TCP); @@ -79,7 +82,7 @@ int start_ssl_client(sslclient_context *ssl_client, const char *host, uint32_t p fcntl( ssl_client->socket, F_SETFL, fcntl( ssl_client->socket, F_GETFL, 0 ) | O_NONBLOCK ); - log_i("Seeding the random number generator"); + log_v("Seeding the random number generator"); mbedtls_entropy_init(&ssl_client->entropy_ctx); ret = mbedtls_ctr_drbg_seed(&ssl_client->drbg_ctx, mbedtls_entropy_func, @@ -88,7 +91,7 @@ int start_ssl_client(sslclient_context *ssl_client, const char *host, uint32_t p return handle_error(ret); } - log_i("Setting up the SSL/TLS structure..."); + log_v("Setting up the SSL/TLS structure..."); if ((ret = mbedtls_ssl_config_defaults(&ssl_client->ssl_conf, MBEDTLS_SSL_IS_CLIENT, @@ -101,7 +104,7 @@ int start_ssl_client(sslclient_context *ssl_client, const char *host, uint32_t p // MBEDTLS_SSL_VERIFY_NONE if not. if (rootCABuff != NULL) { - log_i("Loading CA cert"); + log_v("Loading CA cert"); mbedtls_x509_crt_init(&ssl_client->ca_cert); mbedtls_ssl_conf_authmode(&ssl_client->ssl_conf, MBEDTLS_SSL_VERIFY_REQUIRED); ret = mbedtls_x509_crt_parse(&ssl_client->ca_cert, (const unsigned char *)rootCABuff, strlen(rootCABuff) + 1); @@ -119,14 +122,14 @@ int start_ssl_client(sslclient_context *ssl_client, const char *host, uint32_t p mbedtls_x509_crt_init(&ssl_client->client_cert); mbedtls_pk_init(&ssl_client->client_key); - log_i("Loading CRT cert"); + log_v("Loading CRT cert"); ret = mbedtls_x509_crt_parse(&ssl_client->client_cert, (const unsigned char *)cli_cert, strlen(cli_cert) + 1); if (ret < 0) { return handle_error(ret); } - log_i("Loading private key"); + log_v("Loading private key"); ret = mbedtls_pk_parse_key(&ssl_client->client_key, (const unsigned char *)cli_key, strlen(cli_key) + 1, NULL, 0); if (ret != 0) { @@ -136,7 +139,7 @@ int start_ssl_client(sslclient_context *ssl_client, const char *host, uint32_t p mbedtls_ssl_conf_own_cert(&ssl_client->ssl_conf, &ssl_client->client_cert, &ssl_client->client_key); } - log_i("Setting hostname for TLS session..."); + log_v("Setting hostname for TLS session..."); // Hostname set here should match CN in server certificate if((ret = mbedtls_ssl_set_hostname(&ssl_client->ssl_ctx, host)) != 0){ @@ -151,7 +154,7 @@ int start_ssl_client(sslclient_context *ssl_client, const char *host, uint32_t p mbedtls_ssl_set_bio(&ssl_client->ssl_ctx, &ssl_client->socket, mbedtls_net_send, mbedtls_net_recv, NULL ); - log_i("Performing the SSL/TLS handshake..."); + log_v("Performing the SSL/TLS handshake..."); while ((ret = mbedtls_ssl_handshake(&ssl_client->ssl_ctx)) != 0) { if (ret != MBEDTLS_ERR_SSL_WANT_READ && ret != MBEDTLS_ERR_SSL_WANT_WRITE) { @@ -161,25 +164,24 @@ int start_ssl_client(sslclient_context *ssl_client, const char *host, uint32_t p if (cli_cert != NULL && cli_key != NULL) { - log_i("Protocol is %s Ciphersuite is %s", mbedtls_ssl_get_version(&ssl_client->ssl_ctx), mbedtls_ssl_get_ciphersuite(&ssl_client->ssl_ctx)); + log_d("Protocol is %s Ciphersuite is %s", mbedtls_ssl_get_version(&ssl_client->ssl_ctx), mbedtls_ssl_get_ciphersuite(&ssl_client->ssl_ctx)); if ((ret = mbedtls_ssl_get_record_expansion(&ssl_client->ssl_ctx)) >= 0) { - log_i("Record expansion is %d", ret); + log_d("Record expansion is %d", ret); } else { - log_i("Record expansion is unknown (compression)"); + log_w("Record expansion is unknown (compression)"); } } - log_i("Verifying peer X.509 certificate..."); + log_v("Verifying peer X.509 certificate..."); if ((flags = mbedtls_ssl_get_verify_result(&ssl_client->ssl_ctx)) != 0) { - log_e("Failed to verify peer certificate!"); bzero(buf, sizeof(buf)); mbedtls_x509_crt_verify_info(buf, sizeof(buf), " ! ", flags); - log_e("verification info: %s", buf); + log_e("Failed to verify peer certificate! verification info: %s", buf); stop_ssl_socket(ssl_client, rootCABuff, cli_cert, cli_key); //It's not safe continue. return handle_error(ret); } else { - log_i("Certificate verified."); + log_v("Certificate verified."); } if (rootCABuff != NULL) { @@ -194,7 +196,7 @@ int start_ssl_client(sslclient_context *ssl_client, const char *host, uint32_t p mbedtls_pk_free(&ssl_client->client_key); } - log_i("Free heap after TLS %u", xPortGetFreeHeapSize()); + log_v("Free heap after TLS %u", xPortGetFreeHeapSize()); return ssl_client->socket; } @@ -202,7 +204,7 @@ int start_ssl_client(sslclient_context *ssl_client, const char *host, uint32_t p void stop_ssl_socket(sslclient_context *ssl_client, const char *rootCABuff, const char *cli_cert, const char *cli_key) { - log_i("Cleaning SSL connection."); + log_v("Cleaning SSL connection."); if (ssl_client->socket >= 0) { close(ssl_client->socket); @@ -233,7 +235,7 @@ int data_to_read(sslclient_context *ssl_client) int send_ssl_data(sslclient_context *ssl_client, const uint8_t *data, uint16_t len) { - //log_i("Writing HTTP request..."); //for low level debug + log_v("Writing HTTP request..."); //for low level debug int ret = -1; while ((ret = mbedtls_ssl_write(&ssl_client->ssl_ctx, data, len)) <= 0) { @@ -243,18 +245,18 @@ int send_ssl_data(sslclient_context *ssl_client, const uint8_t *data, uint16_t l } len = ret; - //log_i("%d bytes written", len); //for low level debug + log_v("%d bytes written", len); //for low level debug return ret; } int get_ssl_receive(sslclient_context *ssl_client, uint8_t *data, int length) { - //log_i( "Reading HTTP response..."); //for low level debug + //log_d( "Reading HTTP response..."); //for low level debug int ret = -1; ret = mbedtls_ssl_read(&ssl_client->ssl_ctx, data, length); - //log_i( "%d bytes readed", ret); //for low level debug + log_v( "%d bytes read", ret); //for low level debug return ret; }