net/Socket.cpp | 14 ++++++++++++-- net/Socket.hpp | 9 +++++---- net/WebSocketHandler.hpp | 30 +++++++++++++++++++++++------- wsd/ClientSession.cpp | 12 ++++++++++++ wsd/ClientSession.hpp | 2 ++ wsd/DocumentBroker.cpp | 7 ++++++- 6 files changed, 60 insertions(+), 14 deletions(-)
New commits: commit 50661924b7eb23ca0e67ce4298e997e1c30db481 Author: Michael Meeks <[email protected]> Date: Sat Mar 18 14:59:09 2017 +0000 Dump much more ClientSession state, and also websocket latency. diff --git a/net/Socket.cpp b/net/Socket.cpp index 16deba99..7d165bb9 100644 --- a/net/Socket.cpp +++ b/net/Socket.cpp @@ -11,6 +11,7 @@ #include <stdio.h> #include <ctype.h> +#include <iomanip> #include <Poco/DateTime.h> #include <Poco/DateTimeFormat.h> @@ -19,6 +20,7 @@ #include "SigUtil.hpp" #include "Socket.hpp" #include "ServerSocket.hpp" +#include "WebSocketHandler.hpp" int SocketPoll::DefaultPollTimeoutMs = 5000; @@ -134,13 +136,21 @@ void dump_hex (const char *legend, const char *prefix, std::vector<char> buffer) } // namespace +void WebSocketHandler::dumpState(std::ostream& os) +{ + os << (_shuttingDown ? "shutd " : "alive ") + << std::setw(5) << 1.0*_pingTimeUs/1000 << "ms "; + if (_wsPayload.size() > 0) + dump_hex("\t\tws queued payload:\n", "\t\t", _wsPayload); +} + void StreamSocket::dumpState(std::ostream& os) { int timeoutMaxMs = SocketPoll::DefaultPollTimeoutMs; int events = getPollEvents(std::chrono::steady_clock::now(), timeoutMaxMs); os << "\t" << getFD() << "\t" << events << "\t" - << _inBuffer.size() << "\t" << _outBuffer.size() << "\t" - << "\n"; + << _inBuffer.size() << "\t" << _outBuffer.size() << "\t"; + _socketHandler->dumpState(os); if (_inBuffer.size() > 0) dump_hex("\t\tinBuffer:\n", "\t\t", _inBuffer); if (_outBuffer.size() > 0) diff --git a/net/Socket.hpp b/net/Socket.hpp index e88cae8c..50e84a39 100644 --- a/net/Socket.hpp +++ b/net/Socket.hpp @@ -532,9 +532,10 @@ public: /// Called when the is disconnected and will be destroyed. /// Will be called exactly once. - virtual void onDisconnect() - { - } + virtual void onDisconnect() {} + + /// Append pretty printed internal state to a line + virtual void dumpState(std::ostream& os) { os << "\n"; } }; /// A plain, non-blocking, data streaming socket. diff --git a/net/WebSocketHandler.hpp b/net/WebSocketHandler.hpp index 0438de0c..8bdd04f6 100644 --- a/net/WebSocketHandler.hpp +++ b/net/WebSocketHandler.hpp @@ -374,6 +374,8 @@ protected: { } + void dumpState(std::ostream& os) override; + private: /// To make the protected 'computeAccept' accessible. class PublicComputeAccept : public Poco::Net::WebSocket diff --git a/wsd/ClientSession.cpp b/wsd/ClientSession.cpp index 2cb10ba9..83024cfd 100644 --- a/wsd/ClientSession.cpp +++ b/wsd/ClientSession.cpp @@ -752,4 +752,16 @@ void ClientSession::onDisconnect() } } +void ClientSession::dumpState(std::ostream& os) +{ + Session::dumpState(os); + + os << "\t\tisReadOnly: " << _isReadOnly + << "\n\t\tisDocumentOwner: " << _isDocumentOwner + << "\n\t\tisLoaded: " << _isLoaded + << "\n\t\tstop: " <<_stop + << "\n"; +} + + /* vim:set shiftwidth=4 softtabstop=4 expandtab: */ diff --git a/wsd/ClientSession.hpp b/wsd/ClientSession.hpp index 46fd8c58..90558b72 100644 --- a/wsd/ClientSession.hpp +++ b/wsd/ClientSession.hpp @@ -153,6 +153,8 @@ private: /// Eg. in readonly mode only few messages should be allowed bool filterMessage(const std::string& msg) const; + void dumpState(std::ostream& os) override; + private: std::weak_ptr<DocumentBroker> _docBroker; diff --git a/wsd/DocumentBroker.cpp b/wsd/DocumentBroker.cpp index e6ddb30c..10a89233 100644 --- a/wsd/DocumentBroker.cpp +++ b/wsd/DocumentBroker.cpp @@ -1308,7 +1308,7 @@ void DocumentBroker::dumpState(std::ostream& os) { std::unique_lock<std::mutex> lock(_mutex); - os << " Broker: " << _filename; + os << " Broker: " << _filename << " pid: " << getPid(); if (_markToDestroy) os << " *** Marked to destroy ***"; else @@ -1319,12 +1319,17 @@ void DocumentBroker::dumpState(std::ostream& os) os << "\n still loading..."; os << "\n modified?: " << _isModified; os << "\n jail id: " << _jailId; + os << "\n filename: " << _filename; os << "\n public uri: " << _uriPublic.toString(); os << "\n jailed uri: " << _uriJailed.toString(); os << "\n doc key: " << _docKey; os << "\n num sessions: " << getSessionsCount(); os << "\n new sessions: " << _newSessions.size(); os << "\n last editable?: " << _lastEditableSession; + std::time_t t = std::chrono::system_clock::to_time_t( + std::chrono::system_clock::now() + + (_lastSaveTime - std::chrono::steady_clock::now())); + os << "\n last saved: " << std::ctime(&t); os << "\n cursor " << _cursorPosX << ", " << _cursorPosY << "( " << _cursorWidth << "," << _cursorHeight << ")\n"; commit 0d8809f0caaafadc3f44cf3802cff971768de65c Author: Michael Meeks <[email protected]> Date: Sat Mar 18 14:44:07 2017 +0000 Get warning logic right on wakeup socket. diff --git a/net/Socket.hpp b/net/Socket.hpp index 37b9478c..e88cae8c 100644 --- a/net/Socket.hpp +++ b/net/Socket.hpp @@ -374,7 +374,7 @@ public: rc = ::write(fd, "w", 1); } while (rc == -1 && errno == EINTR); - if (rc != -1 || errno == EAGAIN || errno == EWOULDBLOCK) + if (rc == -1 && errno != EAGAIN && errno != EWOULDBLOCK) LOG_WRN("wakeup socket #" << fd << " is closd at wakeup? error: " << errno); } commit b8b5cc2069f2e4c1c95d16fe932d30554e6b4228 Author: Michael Meeks <[email protected]> Date: Sat Mar 18 14:39:49 2017 +0000 Shorten time to send first ping - to assess socket latency. Also ensure we never send a ping on a non-upgraded websocket. diff --git a/net/WebSocketHandler.hpp b/net/WebSocketHandler.hpp index bb6af23b..0438de0c 100644 --- a/net/WebSocketHandler.hpp +++ b/net/WebSocketHandler.hpp @@ -23,6 +23,7 @@ protected: // The socket that owns us (we can't own it). std::weak_ptr<StreamSocket> _socket; + const int InitialPingDelayMs = 25; const int PingFrequencyMs = 18 * 1000; std::chrono::steady_clock::time_point _pingSent; int _pingTimeUs; @@ -50,7 +51,9 @@ public: WebSocketHandler(const std::weak_ptr<StreamSocket>& socket, const Poco::Net::HTTPRequest& request) : _socket(socket), - _pingSent(std::chrono::steady_clock::now()), + _pingSent(std::chrono::steady_clock::now() - + std::chrono::milliseconds(PingFrequencyMs) - + std::chrono::milliseconds(InitialPingDelayMs)), _pingTimeUs(0), _shuttingDown(false), _wsState(WSState::HTTP) @@ -250,18 +253,28 @@ public: return POLLIN; } + /// Send a ping message + void sendPing(std::chrono::steady_clock::time_point now) + { + // Must not send this before we're upgraded. + if (_wsState == WSState::WS) + { + LOG_WRN("Attempted ping on non-upgraded websocket!"); + return; + } + LOG_TRC("Send ping message"); + // FIXME: allow an empty payload. + sendMessage("", 1, WSOpCode::Ping, false); + _pingSent = now; + } + /// Do we need to handle a timeout ? void checkTimeout(std::chrono::steady_clock::time_point now) override { int timeSincePingMs = std::chrono::duration_cast<std::chrono::milliseconds>(now - _pingSent).count(); if (timeSincePingMs >= PingFrequencyMs) - { - LOG_TRC("Send ping message"); - // FIXME: allow an empty payload. - sendMessage("", 1, WSOpCode::Ping, false); - _pingSent = now; - } + sendPing(now); } /// By default rely on the socket buffer. @@ -403,6 +416,7 @@ protected: socket->send(oss.str()); _wsState = WSState::WS; + sendPing(std::chrono::steady_clock::now()); } }; _______________________________________________ Libreoffice-commits mailing list [email protected] https://lists.freedesktop.org/mailman/listinfo/libreoffice-commits
