Webserver library - fix logging (#2355) (#2359)

* Webserver fix logging (#1)

* Change logging to use esp32-hal-log.h

fixes #2355

* adjust log parameter output positions, reduce lines

The DEBUG_ESP method used less lines than I originally set `log_v` to use when displaying the details of the received params ("@" and "=" indexes, and File info on a single line)
This commit is contained in:
Neal MIller 2019-01-22 03:30:10 -06:00 committed by Me No Dev
parent 8cbc60edbc
commit 29d59876b4
2 changed files with 35 additions and 148 deletions

View File

@ -20,18 +20,12 @@
*/ */
#include <Arduino.h> #include <Arduino.h>
#include <esp32-hal-log.h>
#include "WiFiServer.h" #include "WiFiServer.h"
#include "WiFiClient.h" #include "WiFiClient.h"
#include "WebServer.h" #include "WebServer.h"
#include "detail/mimetable.h" #include "detail/mimetable.h"
//#define DEBUG_ESP_HTTP_SERVER
#ifdef DEBUG_ESP_PORT
#define DEBUG_OUTPUT DEBUG_ESP_PORT
#else
#define DEBUG_OUTPUT Serial
#endif
#ifndef WEBSERVER_MAX_POST_ARGS #ifndef WEBSERVER_MAX_POST_ARGS
#define WEBSERVER_MAX_POST_ARGS 32 #define WEBSERVER_MAX_POST_ARGS 32
#endif #endif
@ -85,10 +79,7 @@ bool WebServer::_parseRequest(WiFiClient& client) {
int addr_start = req.indexOf(' '); int addr_start = req.indexOf(' ');
int addr_end = req.indexOf(' ', addr_start + 1); int addr_end = req.indexOf(' ', addr_start + 1);
if (addr_start == -1 || addr_end == -1) { if (addr_start == -1 || addr_end == -1) {
#ifdef DEBUG_ESP_HTTP_SERVER log_e("Invalid request: %s", req.c_str());
DEBUG_OUTPUT.print("Invalid request: ");
DEBUG_OUTPUT.println(req);
#endif
return false; return false;
} }
@ -119,14 +110,7 @@ bool WebServer::_parseRequest(WiFiClient& client) {
} }
_currentMethod = method; _currentMethod = method;
#ifdef DEBUG_ESP_HTTP_SERVER log_v("method: %s url: %s search: %s", methodStr.c_str(), url.c_str(), searchStr.c_str());
DEBUG_OUTPUT.print("method: ");
DEBUG_OUTPUT.print(methodStr);
DEBUG_OUTPUT.print(" url: ");
DEBUG_OUTPUT.print(url);
DEBUG_OUTPUT.print(" search: ");
DEBUG_OUTPUT.println(searchStr);
#endif
//attach handler //attach handler
RequestHandler* handler; RequestHandler* handler;
@ -159,12 +143,8 @@ bool WebServer::_parseRequest(WiFiClient& client) {
headerValue.trim(); headerValue.trim();
_collectHeader(headerName.c_str(),headerValue.c_str()); _collectHeader(headerName.c_str(),headerValue.c_str());
#ifdef DEBUG_ESP_HTTP_SERVER log_v("headerName: %s", headerName.c_str());
DEBUG_OUTPUT.print("headerName: "); log_v("headerValue: %s", headerValue.c_str());
DEBUG_OUTPUT.println(headerName);
DEBUG_OUTPUT.print("headerValue: ");
DEBUG_OUTPUT.println(headerValue);
#endif
if (headerName.equalsIgnoreCase(FPSTR(Content_Type))){ if (headerName.equalsIgnoreCase(FPSTR(Content_Type))){
using namespace mime; using namespace mime;
@ -206,10 +186,7 @@ bool WebServer::_parseRequest(WiFiClient& client) {
arg.value = String(plainBuf); arg.value = String(plainBuf);
} }
#ifdef DEBUG_ESP_HTTP_SERVER log_v("Plain: %s", plainBuf);
DEBUG_OUTPUT.print("Plain: ");
DEBUG_OUTPUT.println(plainBuf);
#endif
free(plainBuf); free(plainBuf);
} else { } else {
// No content - but we can still have arguments in the URL. // No content - but we can still have arguments in the URL.
@ -239,12 +216,8 @@ bool WebServer::_parseRequest(WiFiClient& client) {
headerValue = req.substring(headerDiv + 2); headerValue = req.substring(headerDiv + 2);
_collectHeader(headerName.c_str(),headerValue.c_str()); _collectHeader(headerName.c_str(),headerValue.c_str());
#ifdef DEBUG_ESP_HTTP_SERVER log_v("headerName: %s", headerName.c_str());
DEBUG_OUTPUT.print("headerName: "); log_v("headerValue: %s", headerValue.c_str());
DEBUG_OUTPUT.println(headerName);
DEBUG_OUTPUT.print("headerValue: ");
DEBUG_OUTPUT.println(headerValue);
#endif
if (headerName.equalsIgnoreCase("Host")){ if (headerName.equalsIgnoreCase("Host")){
_hostHeader = headerValue; _hostHeader = headerValue;
@ -254,12 +227,8 @@ bool WebServer::_parseRequest(WiFiClient& client) {
} }
client.flush(); client.flush();
#ifdef DEBUG_ESP_HTTP_SERVER log_v("Request: %s", url.c_str());
DEBUG_OUTPUT.print("Request: "); log_v(" Arguments: %s", searchStr.c_str());
DEBUG_OUTPUT.println(url);
DEBUG_OUTPUT.print(" Arguments: ");
DEBUG_OUTPUT.println(searchStr);
#endif
return true; return true;
} }
@ -275,10 +244,7 @@ bool WebServer::_collectHeader(const char* headerName, const char* headerValue)
} }
void WebServer::_parseArguments(String data) { void WebServer::_parseArguments(String data) {
#ifdef DEBUG_ESP_HTTP_SERVER log_v("args: %s", data.c_str());
DEBUG_OUTPUT.print("args: ");
DEBUG_OUTPUT.println(data);
#endif
if (_currentArgs) if (_currentArgs)
delete[] _currentArgs; delete[] _currentArgs;
_currentArgs = 0; _currentArgs = 0;
@ -296,10 +262,7 @@ void WebServer::_parseArguments(String data) {
++i; ++i;
++_currentArgCount; ++_currentArgCount;
} }
#ifdef DEBUG_ESP_HTTP_SERVER log_v("args count: %d", _currentArgCount);
DEBUG_OUTPUT.print("args count: ");
DEBUG_OUTPUT.println(_currentArgCount);
#endif
_currentArgs = new RequestArgument[_currentArgCount+1]; _currentArgs = new RequestArgument[_currentArgCount+1];
int pos = 0; int pos = 0;
@ -307,19 +270,9 @@ void WebServer::_parseArguments(String data) {
for (iarg = 0; iarg < _currentArgCount;) { for (iarg = 0; iarg < _currentArgCount;) {
int equal_sign_index = data.indexOf('=', pos); int equal_sign_index = data.indexOf('=', pos);
int next_arg_index = data.indexOf('&', pos); int next_arg_index = data.indexOf('&', pos);
#ifdef DEBUG_ESP_HTTP_SERVER log_v("pos %d =@%d &@%d", pos, equal_sign_index, next_arg_index);
DEBUG_OUTPUT.print("pos ");
DEBUG_OUTPUT.print(pos);
DEBUG_OUTPUT.print("=@ ");
DEBUG_OUTPUT.print(equal_sign_index);
DEBUG_OUTPUT.print(" &@ ");
DEBUG_OUTPUT.println(next_arg_index);
#endif
if ((equal_sign_index == -1) || ((equal_sign_index > next_arg_index) && (next_arg_index != -1))) { if ((equal_sign_index == -1) || ((equal_sign_index > next_arg_index) && (next_arg_index != -1))) {
#ifdef DEBUG_ESP_HTTP_SERVER log_e("arg missing value: %d", iarg);
DEBUG_OUTPUT.print("arg missing value: ");
DEBUG_OUTPUT.println(iarg);
#endif
if (next_arg_index == -1) if (next_arg_index == -1)
break; break;
pos = next_arg_index + 1; pos = next_arg_index + 1;
@ -328,24 +281,14 @@ void WebServer::_parseArguments(String data) {
RequestArgument& arg = _currentArgs[iarg]; RequestArgument& arg = _currentArgs[iarg];
arg.key = urlDecode(data.substring(pos, equal_sign_index)); arg.key = urlDecode(data.substring(pos, equal_sign_index));
arg.value = urlDecode(data.substring(equal_sign_index + 1, next_arg_index)); arg.value = urlDecode(data.substring(equal_sign_index + 1, next_arg_index));
#ifdef DEBUG_ESP_HTTP_SERVER log_v("arg %d key: %s value: %s", iarg, arg.key.c_str(), arg.value.c_str());
DEBUG_OUTPUT.print("arg ");
DEBUG_OUTPUT.print(iarg);
DEBUG_OUTPUT.print(" key: ");
DEBUG_OUTPUT.print(arg.key);
DEBUG_OUTPUT.print(" value: ");
DEBUG_OUTPUT.println(arg.value);
#endif
++iarg; ++iarg;
if (next_arg_index == -1) if (next_arg_index == -1)
break; break;
pos = next_arg_index + 1; pos = next_arg_index + 1;
} }
_currentArgCount = iarg; _currentArgCount = iarg;
#ifdef DEBUG_ESP_HTTP_SERVER log_v("args count: %d", _currentArgCount);
DEBUG_OUTPUT.print("args count: ");
DEBUG_OUTPUT.println(_currentArgCount);
#endif
} }
@ -371,12 +314,7 @@ int WebServer::_uploadReadByte(WiFiClient& client){
bool WebServer::_parseForm(WiFiClient& client, String boundary, uint32_t len){ bool WebServer::_parseForm(WiFiClient& client, String boundary, uint32_t len){
(void) len; (void) len;
#ifdef DEBUG_ESP_HTTP_SERVER log_v("Parse Form: Boundary: %s Length: %d", boundary.c_str(), len);
DEBUG_OUTPUT.print("Parse Form: Boundary: ");
DEBUG_OUTPUT.print(boundary);
DEBUG_OUTPUT.print(" Length: ");
DEBUG_OUTPUT.println(len);
#endif
String line; String line;
int retry = 0; int retry = 0;
do { do {
@ -410,18 +348,12 @@ bool WebServer::_parseForm(WiFiClient& client, String boundary, uint32_t len){
argFilename = argName.substring(nameStart+2, argName.length() - 1); argFilename = argName.substring(nameStart+2, argName.length() - 1);
argName = argName.substring(0, argName.indexOf('"')); argName = argName.substring(0, argName.indexOf('"'));
argIsFile = true; argIsFile = true;
#ifdef DEBUG_ESP_HTTP_SERVER log_v("PostArg FileName: %s",argFilename.c_str());
DEBUG_OUTPUT.print("PostArg FileName: ");
DEBUG_OUTPUT.println(argFilename);
#endif
//use GET to set the filename if uploading using blob //use GET to set the filename if uploading using blob
if (argFilename == F("blob") && hasArg(FPSTR(filename))) if (argFilename == F("blob") && hasArg(FPSTR(filename)))
argFilename = arg(FPSTR(filename)); argFilename = arg(FPSTR(filename));
} }
#ifdef DEBUG_ESP_HTTP_SERVER log_v("PostArg Name: %s", argName.c_str());
DEBUG_OUTPUT.print("PostArg Name: ");
DEBUG_OUTPUT.println(argName);
#endif
using namespace mime; using namespace mime;
argType = FPSTR(mimeTable[txt].mimeType); argType = FPSTR(mimeTable[txt].mimeType);
line = client.readStringUntil('\r'); line = client.readStringUntil('\r');
@ -432,10 +364,7 @@ bool WebServer::_parseForm(WiFiClient& client, String boundary, uint32_t len){
client.readStringUntil('\r'); client.readStringUntil('\r');
client.readStringUntil('\n'); client.readStringUntil('\n');
} }
#ifdef DEBUG_ESP_HTTP_SERVER log_v("PostArg Type: %s", argType.c_str());
DEBUG_OUTPUT.print("PostArg Type: ");
DEBUG_OUTPUT.println(argType);
#endif
if (!argIsFile){ if (!argIsFile){
while(1){ while(1){
line = client.readStringUntil('\r'); line = client.readStringUntil('\r');
@ -444,20 +373,14 @@ bool WebServer::_parseForm(WiFiClient& client, String boundary, uint32_t len){
if (argValue.length() > 0) argValue += "\n"; if (argValue.length() > 0) argValue += "\n";
argValue += line; argValue += line;
} }
#ifdef DEBUG_ESP_HTTP_SERVER log_v("PostArg Value: %s", argValue.c_str());
DEBUG_OUTPUT.print("PostArg Value: ");
DEBUG_OUTPUT.println(argValue);
DEBUG_OUTPUT.println();
#endif
RequestArgument& arg = _postArgs[_postArgsLen++]; RequestArgument& arg = _postArgs[_postArgsLen++];
arg.key = argName; arg.key = argName;
arg.value = argValue; arg.value = argValue;
if (line == ("--"+boundary+"--")){ if (line == ("--"+boundary+"--")){
#ifdef DEBUG_ESP_HTTP_SERVER log_v("Done Parsing POST");
DEBUG_OUTPUT.println("Done Parsing POST");
#endif
break; break;
} }
} else { } else {
@ -468,12 +391,7 @@ bool WebServer::_parseForm(WiFiClient& client, String boundary, uint32_t len){
_currentUpload->type = argType; _currentUpload->type = argType;
_currentUpload->totalSize = 0; _currentUpload->totalSize = 0;
_currentUpload->currentSize = 0; _currentUpload->currentSize = 0;
#ifdef DEBUG_ESP_HTTP_SERVER log_v("Start File: %s Type: %s", _currentUpload->filename.c_str(), _currentUpload->type.c_str());
DEBUG_OUTPUT.print("Start File: ");
DEBUG_OUTPUT.print(_currentUpload->filename);
DEBUG_OUTPUT.print(" Type: ");
DEBUG_OUTPUT.println(_currentUpload->type);
#endif
if(_currentHandler && _currentHandler->canUpload(_currentUri)) if(_currentHandler && _currentHandler->canUpload(_currentUri))
_currentHandler->upload(*this, _currentUri, *_currentUpload); _currentHandler->upload(*this, _currentUri, *_currentUpload);
_currentUpload->status = UPLOAD_FILE_WRITE; _currentUpload->status = UPLOAD_FILE_WRITE;
@ -518,20 +436,11 @@ readfile:
_currentUpload->status = UPLOAD_FILE_END; _currentUpload->status = UPLOAD_FILE_END;
if(_currentHandler && _currentHandler->canUpload(_currentUri)) if(_currentHandler && _currentHandler->canUpload(_currentUri))
_currentHandler->upload(*this, _currentUri, *_currentUpload); _currentHandler->upload(*this, _currentUri, *_currentUpload);
#ifdef DEBUG_ESP_HTTP_SERVER log_v("End File: %s Type: %s Size: %d", _currentUpload->filename.c_str(), _currentUpload->type.c_str(), _currentUpload->totalSize);
DEBUG_OUTPUT.print("End File: ");
DEBUG_OUTPUT.print(_currentUpload->filename);
DEBUG_OUTPUT.print(" Type: ");
DEBUG_OUTPUT.print(_currentUpload->type);
DEBUG_OUTPUT.print(" Size: ");
DEBUG_OUTPUT.println(_currentUpload->totalSize);
#endif
line = client.readStringUntil(0x0D); line = client.readStringUntil(0x0D);
client.readStringUntil(0x0A); client.readStringUntil(0x0A);
if (line == "--"){ if (line == "--"){
#ifdef DEBUG_ESP_HTTP_SERVER log_v("Done Parsing POST");
DEBUG_OUTPUT.println("Done Parsing POST");
#endif
break; break;
} }
continue; continue;
@ -579,10 +488,7 @@ readfile:
} }
return true; return true;
} }
#ifdef DEBUG_ESP_HTTP_SERVER log_e("Error: line: %s", line.c_str());
DEBUG_OUTPUT.print("Error: line: ");
DEBUG_OUTPUT.println(line);
#endif
return false; return false;
} }

View File

@ -22,6 +22,7 @@
#include <Arduino.h> #include <Arduino.h>
#include <esp32-hal-log.h>
#include <libb64/cencode.h> #include <libb64/cencode.h>
#include "WiFiServer.h" #include "WiFiServer.h"
#include "WiFiClient.h" #include "WiFiClient.h"
@ -30,12 +31,6 @@
#include "detail/RequestHandlersImpl.h" #include "detail/RequestHandlersImpl.h"
#include "mbedtls/md5.h" #include "mbedtls/md5.h"
//#define DEBUG_ESP_HTTP_SERVER
#ifdef DEBUG_ESP_PORT
#define DEBUG_OUTPUT DEBUG_ESP_PORT
#else
#define DEBUG_OUTPUT Serial
#endif
static const char AUTHORIZATION_HEADER[] = "Authorization"; static const char AUTHORIZATION_HEADER[] = "Authorization";
static const char qop_auth[] = "qop=auth"; static const char qop_auth[] = "qop=auth";
@ -163,9 +158,7 @@ bool WebServer::authenticate(const char * username, const char * password){
delete[] encoded; delete[] encoded;
} else if(authReq.startsWith(F("Digest"))) { } else if(authReq.startsWith(F("Digest"))) {
authReq = authReq.substring(7); authReq = authReq.substring(7);
#ifdef DEBUG_ESP_HTTP_SERVER log_v("%s", authReq.c_str());
DEBUG_OUTPUT.println(authReq);
#endif
String _username = _extractParam(authReq,F("username=\"")); String _username = _extractParam(authReq,F("username=\""));
if(!_username.length() || _username != String(username)) { if(!_username.length() || _username != String(username)) {
authReq = ""; authReq = "";
@ -193,9 +186,7 @@ bool WebServer::authenticate(const char * username, const char * password){
_cnonce = _extractParam(authReq, F("cnonce=\"")); _cnonce = _extractParam(authReq, F("cnonce=\""));
} }
String _H1 = md5str(String(username) + ':' + _realm + ':' + String(password)); String _H1 = md5str(String(username) + ':' + _realm + ':' + String(password));
#ifdef DEBUG_ESP_HTTP_SERVER log_v("Hash of user:realm:pass=%s", _H1.c_str());
DEBUG_OUTPUT.println("Hash of user:realm:pass=" + _H1);
#endif
String _H2 = ""; String _H2 = "";
if(_currentMethod == HTTP_GET){ if(_currentMethod == HTTP_GET){
_H2 = md5str(String(F("GET:")) + _uri); _H2 = md5str(String(F("GET:")) + _uri);
@ -208,18 +199,14 @@ bool WebServer::authenticate(const char * username, const char * password){
}else{ }else{
_H2 = md5str(String(F("GET:")) + _uri); _H2 = md5str(String(F("GET:")) + _uri);
} }
#ifdef DEBUG_ESP_HTTP_SERVER log_v("Hash of GET:uri=%s", _H2.c_str());
DEBUG_OUTPUT.println("Hash of GET:uri=" + _H2);
#endif
String _responsecheck = ""; String _responsecheck = "";
if(authReq.indexOf(FPSTR(qop_auth)) != -1) { if(authReq.indexOf(FPSTR(qop_auth)) != -1) {
_responsecheck = md5str(_H1 + ':' + _nonce + ':' + _nc + ':' + _cnonce + F(":auth:") + _H2); _responsecheck = md5str(_H1 + ':' + _nonce + ':' + _nc + ':' + _cnonce + F(":auth:") + _H2);
} else { } else {
_responsecheck = md5str(_H1 + ':' + _nonce + ':' + _H2); _responsecheck = md5str(_H1 + ':' + _nonce + ':' + _H2);
} }
#ifdef DEBUG_ESP_HTTP_SERVER log_v("The Proper response=%s", _responsecheck.c_str());
DEBUG_OUTPUT.println("The Proper response=" +_responsecheck);
#endif
if(_response == _responsecheck){ if(_response == _responsecheck){
authReq = ""; authReq = "";
return true; return true;
@ -294,9 +281,7 @@ void WebServer::handleClient() {
return; return;
} }
#ifdef DEBUG_ESP_HTTP_SERVER log_v("New client");
DEBUG_OUTPUT.println("New client");
#endif
_currentClient = client; _currentClient = client;
_currentStatus = HC_WAIT_READ; _currentStatus = HC_WAIT_READ;
@ -614,17 +599,13 @@ void WebServer::onNotFound(THandlerFunction fn) {
void WebServer::_handleRequest() { void WebServer::_handleRequest() {
bool handled = false; bool handled = false;
if (!_currentHandler){ if (!_currentHandler){
#ifdef DEBUG_ESP_HTTP_SERVER log_e("request handler not found");
DEBUG_OUTPUT.println("request handler not found");
#endif
} }
else { else {
handled = _currentHandler->handle(*this, _currentMethod, _currentUri); handled = _currentHandler->handle(*this, _currentMethod, _currentUri);
#ifdef DEBUG_ESP_HTTP_SERVER
if (!handled) { if (!handled) {
DEBUG_OUTPUT.println("request handler failed to handle request"); log_e("request handler failed to handle request");
} }
#endif
} }
if (!handled && _notFoundHandler) { if (!handled && _notFoundHandler) {
_notFoundHandler(); _notFoundHandler();