Commit graph

828 commits

Author SHA1 Message Date
Ashod Nakashian
756560642f wsd: test: better polling in tests
Shorter waits to break the polling
loop when the test finishes and we
need to terminate.

Change-Id: I79d9d89675d0a37f25a03b265b3ae636a90e57d5
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-05-31 07:40:11 -04:00
Ashod Nakashian
155bc06e24 wsd: de-duplicate assertCorrectThread
This merges multiple implementations of
assertCorrectThread and simplifies its
usage.

Change-Id: I7be5dea62c6046fb0412d7f885fcbcc4b66e3fd9
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-05-22 09:34:29 -04:00
Ashod Nakashian
685e2fb0b8 wsd: http: return const& from const response getter
Change-Id: I5dc5282938a472148148d1dd6d009261bc09c7d6
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-05-22 09:34:29 -04:00
Ashod Nakashian
7ce18c8a13 wsd: http: cosmetic and log
Change-Id: I984ad71601b92b8042dc7984e7339f0804c8083b
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-05-22 09:34:29 -04:00
Ashod Nakashian
a6551462e2 wsd: http: improved http::Session::handleIncomingMessage
The normal path is now streamlined and error handling
is at the end. We also now always set the disposition
to closed and fire onDisconnect() when disconnected
or hit an error.

Change-Id: I984ad71601b92b8042dc7984e7339f0804c8083b
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-05-15 19:14:21 -04:00
Ashod Nakashian
d4b27f6643 killpoco: replace HTTP status codes
We use our own status codes, which
are type-safe and use streaming
operators to serialize and log.

Change-Id: I0eba7b16694866b5a79476a7ef4b1b78f7f9c176
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-05-11 07:21:42 -04:00
Ashod Nakashian
72cff36195 wsd: move streaming operator overloads
This is needed to correct overload
resolution of these operators.

Change-Id: I02c0859674efe112102a8d3833bfb0a30b1a6574
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-05-10 08:46:11 -04:00
Ashod Nakashian
0182af7a4a wsd: http: native support for logging http::Header
Change-Id: I8c34531e6f2616d98a4ee75fe8490d4ad25c45a9
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-05-10 08:46:11 -04:00
Ashod Nakashian
ff1657934a wsd: simplify log streaming
Change-Id: Id22de0bc06680f957e7475f142bcaf1131fdbdb9
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-05-10 08:46:11 -04:00
Ashod Nakashian
b556381406 wsd: return SSL_do_handshake error-codes unmodified
For some reason we only checked for the closed
socket case as failure and returned 0 in that case,
for error cases, we returned 1. Likely the API
had been modified in the early days, but this
return code was left lopsided.

This meant that even when the handshake failed, we
still called readIncomingData or writeOutgoindData,
depending on whether we wanted to read or write,
causing a rare race-condition.

When a client (HTTP request) connects to a server,
it needs to send the request, right after the
SSL handshake. SSL_do_handshake could need data
from the socket to complete the handshake. In such
a case it returns WANT_READ. Unfortunately,
because we always called SSL_read, the missing data
could have arrived between the SSL_do_handshake call
and the SSL_read call (a rather short duration, to
be sure, but an open window all the same).
SSL_read would of course read said data from the
socket and, since it still needs to finish the
handshake, will buffer it. It then returns the very
same error that the SSL_do_handshake returned:
WANT_READ. Of course we will oblige by polling with
POLLIN, which will time out (there is no more data
to come, and the server is waiting for *our* request
and has nothing to send us).

The only way this deadlock could break if
SSL_do_handshake was called (which will consume
the buffered data, return 1 to indicate handshake
has completed). Since we wouldn't call it unless
and until we get POLLIN, per WANT_READ, which won't
happen in this case. And since SSL_read doesn't call
SSL_do_handshake either, the request times out and
that's the end of it.

The fix is to not call SSL_read when the handshake
isn't complete and needs more data, which we do now.

Fortunately, we have very few SSL clients, outside
of unit-tests. Most notably the WOPI client. But
even then it's not a heavily used connection and
might not even be SSL-enabled (for LAN servers).

Change-Id: I04fd3dae151904194f3d7579dbf8c671b2580ffb
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-04-15 23:07:38 +01:00
Ashod Nakashian
49843a6af9 wsd: handle read failure on closed socket better
A rare edge-case happens when we have a socket
that is closed (and we get POLLHUP or POLLERR)
but upon reading the socket we get EAGAIN.

This was observed when simulating EAGAIN,
and it is possible that this is quite impossible
in practice (since we read only when we get
POLLIN), but at least for the unit-tests
we need to handle this case, so we don't
get random failures.

Change-Id: I77af1726066507af5d5ada68fe11b479a4e579e5
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-04-15 23:07:38 +01:00
Ashod Nakashian
2ea14b5221 wsd: reduce SocketPoll lock contention
We don't have to read the wakeup pipe
under a lock. So we no longer do.

Change-Id: I6bd724b9748add3022b4f9aa2268094b9818f3e5
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-04-15 23:07:38 +01:00
Ashod Nakashian
bbabcf52dc wsd: more tracing of socket and poll activity
Change-Id: Ia5cb6cfaf8108a9266b0a1daa55b0fbe1349177c
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-04-15 23:07:38 +01:00
Ashod Nakashian
896673c857 wsd: correct log argument order
Change-Id: I00cb3ccd740e8540341e45965cbe8460490acb8c
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-04-15 23:07:38 +01:00
Ashod Nakashian
587ba85aea wsd: always handle socket polls without skipping
We now always handle socket polls without skipping
when the number of sockets change. We verify the
socket FD of each socket before handlingPoll to
catch any violations of the preconditions.

This should avoid missing any events and also
handles timeouts better (which are checked
in handlePoll). It also protects against
unexpected modifications of the sockets, with
proper logging and assertion.

Change-Id: I5659eb57231a490e6c813e7a0222443b534713c6
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-04-14 18:02:14 +01:00
Ashod Nakashian
8facb429c2 wsd: make removeSockets private
Change-Id: I7171c67bbbe4682cf10e015e600fb25f03d4e5bb
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-04-14 18:02:14 +01:00
Ashod Nakashian
4968982a3d wsd: better merge new sockets into poll sockets
Change-Id: I4249ba4d35d8dfb2ff17c63af201276c77e2549b
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-04-14 18:02:14 +01:00
Ashod Nakashian
b82519400f wsd: update the poll round-robin index right before usage
Change-Id: I27f19c914449b689a530495681423a2906281698
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-04-14 18:02:14 +01:00
Ashod Nakashian
ec85f78458 wsd: drain the wakeup pipe on each read
Reading larger blocks should avoid having
the pipe back up when we accidentally
attempt more wakes than actual ones.

Change-Id: I7766230f60dbf069668ee7919f766e9093df7017
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-04-14 18:02:14 +01:00
Ashod Nakashian
7547e15d79 wsd: move pollingThread to private
There is no use-case for calling the
thread function of the SocketPoll
from outside.

Change-Id: Id8e87369494817aaab749d03d1cd4cd3724c2da1
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-04-14 11:30:14 +01:00
Ashod Nakashian
75dbe7af53 wsd: better scope locality
Change-Id: I49156505dfb855ce00815c6afabc762951fcc4c8
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-04-14 11:30:14 +01:00
Ashod Nakashian
4089302362 wsd: better socket logging
Change-Id: I31b64ce1f174896a3bcfa5cd620e0babd7f425d1
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-04-14 11:30:14 +01:00
Ashod Nakashian
3dbfce54d3 wsd: helper to dump the state of an object as a string
Change-Id: Ib49a47be2dc37663ef06ac80be981c9f3c029814
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-04-11 08:03:01 -04:00
Ashod Nakashian
f41ba11bad wsd: test: socket context logging
Change-Id: Ib3675985cf0e2d8864ed544d5e7c615d5fde2331
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-04-11 08:03:01 -04:00
Ashod Nakashian
bca82f50ee wsd: better logging of the current socket being handled
Change-Id: Ieca96a685f5cfea24fde7251806746408e0bfbf8
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-04-11 08:03:01 -04:00
Ashod Nakashian
9596d5a0ab wsd: http: set http::Request log context
Change-Id: Ic8b9c1e7526ebf2f7c69f47f1bd98fdb9fc471ce
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-03-14 15:46:48 +01:00
FedericoHeichou
985f284c89 Fix isLocal failing check with IPv4
Signed-off-by: FedericoHeichou <34757141+FedericoHeichou@users.noreply.github.com>
Change-Id: If6fa382102252908dac1fb80199bb332ce400aeb
2023-03-14 10:48:20 +01:00
Ashod Nakashian
9c39ebad1f wsd: string::empty() is clearer than size() == 0
Change-Id: If2e25d344b5718c35cb9ae7b7519010ee88f0f60
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-03-10 07:45:12 -05:00
Ashod Nakashian
29193de7cd wsd: improved socket creation/destruction logging
Change-Id: I3f2919b646aad4c7c8b2b464155066008fbe25ae
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-03-06 08:43:37 -05:00
Ashod Nakashian
903bb76c36 wsd: fix DEBUG_HTTP in HttpRequest
Change-Id: Iebc61b6632d33528ad362c943cb44cea56418b16
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-03-06 08:43:37 -05:00
Ashod Nakashian
e3deb96152 wsd: log the socket FD of http::Response
Change-Id: Ibd02ee6656f4db2e7b09e0b7702a6db55ec8269e
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-03-06 08:43:37 -05:00
Ashod Nakashian
8fac85b5c2 wsd: log the socket FD of http::Session
Change-Id: I9c0eb3fde6577185bce63277147a6a453311f1ec
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-03-06 08:43:37 -05:00
Ashod Nakashian
359017ef10 wsd: log the socket FD of PrisonerRequestDispatcher
Change-Id: I6a000e53d8baca231a2fb8f6df2251a4f57d9876
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-03-06 08:43:37 -05:00
Ashod Nakashian
547c97988a wsd: log the socket FD of WebSocketHandler
Change-Id: I5c06ae44437cac32fb726861a5bc49b149ecd0c4
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-03-06 08:43:37 -05:00
Ashod Nakashian
1dd2aba82d wsd: log the socket FD of ProtocolHandlerInterface
Change-Id: I362aca685f79868bdf685695d625a832eee02821
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-03-06 08:43:37 -05:00
Ashod Nakashian
da29e2c45d wsd: log the socket number of http::Request
Change-Id: Ia0d52b38a1da73ae92765169d5e5064015dc7f40
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-03-06 08:43:37 -05:00
Ashod Nakashian
0b4e9e071c wsd: minor improvements to socket logs
Change-Id: I4a07124e8adada4c7dbcf0a3b7b07ffa566c57d2
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-03-06 08:43:37 -05:00
Tor Lillqvist
31135177e4 Fix compiler warnings when building for WASM.
Signed-off-by: Tor Lillqvist <tml@collabora.com>
Change-Id: I0fd4fe36cece9caaeb076a0e91894890186706d0
2023-02-12 15:55:24 +01:00
Ashod Nakashian
44a27110e1 wsd: better logging
Change-Id: I98bc45d287c44beb10bfe6fbe02d208f37531515
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-01-27 08:44:53 -05:00
Ashod Nakashian
b9eb4111ae wsd: http: define named HTTP status codes
This replaces the hard-coded status-code
numbers with named compile-time constants.

Change-Id: Ibe678fb2c533b29efd696e4430f5377523eeb298
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2023-01-24 07:58:07 -05:00
Tor Lillqvist
49660dbb94 Fix error in conversion from microseconds to whole milliseconds
I had added some extra debugging output to the !MOBILEAPP branch to
log values of timeoutMaxMicroS and timeoutMaxMS and was wondering why
I saw things like:

    timeoutMaxMicroS=5000000 timeoutMaxMS=5009

and

    timeoutMaxMicroS=0 timeoutMaxMS=9

Signed-off-by: Tor Lillqvist <tml@collabora.com>
Change-Id: Iac8599ce5b00ef90d62eabc29c5d92858e276bb6
2023-01-03 11:54:17 +00:00
Ashod Nakashian
629ff27992 wsd: minor log improvements
Change-Id: I6dba0540310bb9cafc31a63e92da306eeff8953d
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2022-12-22 10:10:08 +01:00
Ashod Nakashian
b644904448 wsd: asyncRequest needs only wakeup its own poll thread
Apparently it woke up the world unnecessarily.

Change-Id: Iad65215da898b017860e7d7b803771f657a3e1ab
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2022-12-21 19:41:38 -05:00
Ashod Nakashian
53f8317e47 wsd: do not warn when waking up dead poll-thread at shutdown
When shutting down, SocketPoll threads asynchronously
stop and exit. This fundamental race means the warning
is useless and noisy.

Change-Id: I3ca9044c9a68689abb7e8f692fffd10509eadab6
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2022-12-21 19:41:38 -05:00
Ashod Nakashian
206de871fb wsd: send WS close frame only when we have a socket
sendCloseFrame does check for the socket to be
there, but it logs an error if it isn't because
it assumes we expect to have a socket.

Since we are shutting down, this code could
be triggered on destruction when we no
longer have the socket.

Change-Id: I622a24394632159aa71c1c21c33c0f8a2d5c6250
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2022-12-21 19:41:38 -05:00
Ashod Nakashian
cd980c9ba6 wsd: wait InitialPingDelayMicroS before first ping
It seems we were always pinging immediately on a
newly created WebSocket, even before upgrading to
WS, which logged a warning. That was because we
create the WebSocketHandler instance with a
timed-out lastPingSentTime.

Here we correctly set lastPingSentTime such that
it times out *after* InitialPingDelayMicroS has
elapsed. This gives it time to upgrade the
socket to WS and avoid the warning.

Change-Id: I6004348b9b4bd29f614d9e010fb7649da2bca338
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2022-12-21 19:41:38 -05:00
Ashod Nakashian
1b059bca0f wsd: better log levels
We no longer emit a fatal (FTL) log when
forced-exiting successfully.

Also, improved are some other logs to
better reflect the severity of the issue.

Change-Id: I22e79f685825f7ecd47cec76c9be9683deff2d55
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2022-12-21 19:41:38 -05:00
Ashod Nakashian
8bbf7717db wsd: change message logging level to trace
Messages are high-frequency events and logging
them at debug level is too noisy. Increase the
level to trace.

Debug level should produce legible entries that
outline the main activities, rather than log
each message. That is best done at trace level.

Change-Id: I722ab8b58e0adcab6ecb2f8c571966af0d952051
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2022-12-07 17:33:11 +03:00
Ashod Nakashian
a89ed3b535 wsd: test: correctly capture UnitBase in WebSocketHandler
The UnitBase reference must be a member of the class.

Change-Id: Ia0b10ccb7f0f3419470f014a23c7a48d3b390239
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2022-11-30 05:14:55 -05:00
Ashod Nakashian
1f0b5f5a16 wsd: avoid locking weak_ptr when possible
In WebSocketHandler, we often already have
locked the weak_ptr, so we can pass that
shared_ptr around.

Change-Id: Iaedceff0acbfd747bdf89771f9309ff6f6642b53
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
2022-11-29 03:45:32 -05:00