Quiet SSL and HTTPClient debug

This commit is contained in:
me-no-dev 2017-09-29 20:31:45 +08:00
parent 7aa1913506
commit e72895b722
4 changed files with 70 additions and 71 deletions

View File

@ -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();
}
}

View File

@ -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;

View File

@ -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;
}

View File

@ -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;
}