PR Review & Testing

- Increase throughput of WS example
- Remove \n at the end of log line
- Fix status that was incorrectly kept to 0 even when all bytes acked
- Added traces in sent method

Author: mathieucarbou

examples/WebSocket/WebSocket.ino

@@ -167,9 +167,13 @@ void setup() {
   server.begin();
 }
 
-static uint32_t lastWS = 0;
-static uint32_t deltaWS = 500;
+#ifdef ESP32
+static const uint32_t deltaWS = 50;
+#else
+static const uint32_t deltaWS = 200;
+#endif
 
+static uint32_t lastWS = 0;
 static uint32_t lastHeap = 0;
 
 void loop() {
@@ -186,6 +190,10 @@ void loop() {
     // this can be called to also set a soft limit on the number of connected clients
     ws.cleanupClients(2);  // no more than 2 clients
 
+    // ping twice (2 control frames)
+    ws.pingAll();
+    ws.pingAll();
+
 #ifdef ESP32
     Serial.printf("Free heap: %" PRIu32 "\n", ESP.getFreeHeap());
 #endif

src/AsyncWebSocket.cpp

@@ -166,64 +166,65 @@ AsyncWebSocketMessage::AsyncWebSocketMessage(AsyncWebSocketSharedBuffer buffer,
 
 size_t AsyncWebSocketMessage::ack(size_t len, uint32_t time) {
   (void)time;
-  const size_t pending = _ack - _acked;
-  const size_t received = std::min(len, pending);
-  _acked += received;
-  if (_sent >= _WSbuffer->size() && !pending) {
+  const size_t pending = std::min(len, _ack - _acked);
+  _acked += pending;
+  if (_sent >= _WSbuffer->size() && _acked >= _ack) {
     _status = WS_MSG_SENT;
   }
-  async_ws_log_v("status: %d, ack: %u/%u\n", static_cast<int>(_status), _acked, _ack);
-  return len - received;
+  async_ws_log_v("msg code: %" PRIu8 ", ack: %u/%u, remain=%u/%u, status: %d", _opcode, _acked, _ack, len - pending, len, static_cast<int>(_status));
+  return len - pending;
 }
 
 size_t AsyncWebSocketMessage::send(AsyncClient *client) {
   if (!client) {
+    async_ws_log_v("No client");
     return 0;
   }
 
   if (_status != WS_MSG_SENDING) {
+    async_ws_log_v("C[%" PRIu16 "] Wrong status: got: %d, expected: %d", client->remotePort(), static_cast<int>(_status), static_cast<int>(WS_MSG_SENDING));
     return 0;
   }
 
   if (_sent == _WSbuffer->size()) {
     if (_acked == _ack) {
       _status = WS_MSG_SENT;
     }
+    async_ws_log_v("C[%" PRIu16 "] Already sent: %u/%u", client->remotePort(), _sent, _WSbuffer->size());
     return 0;
   }
   if (_sent > _WSbuffer->size()) {
     _status = WS_MSG_ERROR;
-    // ets_printf("E: %u > %u\n", _sent, _WSbuffer->length());
+    async_ws_log_v("C[%" PRIu16 "] Error, sent more: %u/%u", client->remotePort(), _sent, _WSbuffer->size());
     return 0;
   }
 
   size_t toSend = _WSbuffer->size() - _sent;
   const size_t window = webSocketSendFrameWindow(client);
 
-  // not enough space in lwip buffer ? 
+  // not enough space in lwip buffer ?
   if (!window) {
+    async_ws_log_v("C[%" PRIu16 "] No space left to send more data: acked: %u, sent: %u, remaining: %u", client->remotePort(), _acked, _sent, toSend);
     return 0;
   }
-  
+
   toSend = std::min(toSend, window);
 
   _sent += toSend;
   _ack += toSend + ((toSend < 126) ? 2 : 4) + (_mask * 4);
 
-  // ets_printf("W: %u %u\n", _sent - toSend, toSend);
-
   bool final = (_sent == _WSbuffer->size());
   uint8_t *dPtr = (uint8_t *)(_WSbuffer->data() + (_sent - toSend));
   uint8_t opCode = (toSend && _sent == toSend) ? _opcode : (uint8_t)WS_CONTINUATION;
 
   size_t sent = webSocketSendFrame(client, final, opCode, _mask, dPtr, toSend);
   _status = WS_MSG_SENDING;
   if (toSend && sent != toSend) {
-    // ets_printf("E: %u != %u\n", toSend, sent);
     _sent -= (toSend - sent);
     _ack -= (toSend - sent);
   }
-  // ets_printf("S: %u %u\n", _sent, sent);
+
+  async_ws_log_v("C[%" PRIu16 "] Sent %u/%u, ack: %u/%u, final: %d", client->remotePort(), _sent, _WSbuffer->size(), _acked, _ack, final);
   return sent;
 }
 
@@ -345,7 +346,6 @@ void AsyncWebSocketClient::_onAck(size_t len, uint32_t time) {
   _runQueue();
 }
 
-
 void AsyncWebSocketClient::_onPoll() {
   if (!_client) {
     return;
@@ -375,22 +375,22 @@ void AsyncWebSocketClient::_runQueue() {
   if (!_controlQueue.empty() && !_controlQueue.front().finished() && (_messageQueue.empty() || _messageQueue.front().betweenFrames())
       && webSocketSendFrameWindow(_client) > (size_t)(_controlQueue.front().len() - 1)) {
     _controlQueue.front().send(_client);
-  } 
-  
+  }
+
   if (webSocketSendFrameWindow(_client)) {
     for (auto &msg : _messageQueue) {
       if (msg._remainingBytesToSend()) {
         msg.send(_client);
       }
-      
+
       // If we haven't finished sending this message, we must stop here to preserve WebSocket ordering.
       // We can only pipeline subsequent messages if the current one is fully passed to TCP buffer.
       if (msg._remainingBytesToSend()) {
         break;
       }
-      
+
       // not enough space for another message
-      if(!webSocketSendFrameWindow(_client)) {
+      if (!webSocketSendFrameWindow(_client)) {
         return;
       }
     }

src/AsyncWebSocket.h

@@ -185,7 +185,7 @@ class AsyncWebSocketMessageBuffer {
 
 class AsyncWebSocketMessage {
   friend AsyncWebSocketClient;
-  
+
 private:
   size_t _remainingBytesToSend() const {
     return _WSbuffer->size() - _sent;
@@ -208,7 +208,7 @@ class AsyncWebSocketMessage {
   bool betweenFrames() const {
     return _acked == _ack;
   }
-  
+
   size_t ack(size_t len, uint32_t time);
   size_t send(AsyncClient *client);
 };