A corner case where read doesn't return 0
on a closed socket can result in a stuck
state where we attempt to read when we
do get ECONNRESET (which we didn't check
on reads).
This makes the interface of readIncomingData
the same as writeOutgoingData by returning
the actual return value of the read syscall.
So now we handle both return 0 as well as
error codes returned on failed calls.
The logic hasn't changed, just that now
we handle errors better and similar to the
write case.
Change-Id: I0b38a63da4e6c92a482948478d5d8d446e0b8b58
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
This enables code that was protected with
EnableExperimental in the socket logic (and one
case in DocBroker). These changes are now deemed
safe to enable permanently.
Change-Id: Ie62f5d7bd281ade90f38d654b51b104b8d1f14bc
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
Without knowing whether the write succeeded
or failed, we cannot trust errno has our
error or some earlier and unrelated error.
This was caught when there were two sockets,
one of which disconnected. The write to the
disconnected one returned -1 and set errno
to ECONNRESET. We subsequently wrote to the
second socket, which succeeded. However,
because errno wasn't reset, and since
writeOutgoingData didn't return anything
to indicate the success, errno's ECONNRESET
value meant the second socket was also
disconnected, which was incorrect.
writeOutgoingData now returns the last return
value from writeData so we can make informed
decision as to whether to check errno or not.
Also, to avoid incorrecly propagating errno,
we now capture errno only when readData and
writeData return -1. This has the nice
side-effect that we reset errno to 0 when
no errors occur during our call.
Change-Id: I911b31390f37cc71938bc4a6ae75393dbf24bb9d
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
Since both implementations are identical, there
really is no benefit to having two version.
Change-Id: I4a5288243291c0d5706df8e8870b918fab425317
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
The last burst of data arrives with POLLHUP.
If during the read we hit any errors, including
EAGAIN, for whatever reason, we may lose the
data if we don't attempt reading again later.
The only way to guarantee that we do not have
any more data to read, when we get POLLHUP,
is to poll until we either get no POLLIN or
read returns 0 indicating the socket is closed,
Oddly, read(2) sometimes returns 0 without
POLLHUP ever being set, and sometimes we
do get POLLHUP while POLLIN still set. This
implies that poll and read aren't consistent
in how they detect and report the close
condition. Luckily, with this patch we can
handle all cases without any complications.
This was caught through simulateSocketError,
which when it injects EAGAIN on the very
last read, when the socket is closed, causes
error as the response is partially or
completely lost (because we never read it).
The behavioral change should only be
observable with EnableExperimental.
Change-Id: I77260f98d5dd5050c5f9b202b9effd501191336b
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
This extends the detection of connection termination
for writes via ECONNRESET and EPIPE.
For some reason ECONNRESET was not detected.
This patch avoids extra polling to detect connection
termination and makes the cleanup faster.
The changes are guarded by EnableExperimental to avoid
any unexpected change of behavior.
Change-Id: I2ae3803f025d3cf756f86460e47aedc984249509
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
Since the hostname argument is passed
to both the base class of SslStreamSocket
and SSL_set_tlsext_host_name, and since
the base class's getter, also called
hostname(), is hidden by the argument,
we cannot move it.
An empty hostname can result in 403 Forbidden
from the server due to missing Server Name
Indication (SNI).
Change-Id: I27990f64f17ec3c81a4dd543a078807629cd0c20
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
And improved socket logging in general while
making them more consistent.
Change-Id: I1ed7f2561476ca5370af91079d5d616804396f8e
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
While SSL is handshaking, there can be no general
application data communication. During that early
stage of connecting we have data to send (the
request, headers, etc.) and so we poll on POLLOUT.
Naturally, we also always want to poll on POLLIN,
because we can never know when there is data to
read (especially true for web-sockets).
The problem is when SSL will not send data just
yet because it is handshaking. It is typically
waiting for handshake negotiation data to read,
so when we POLLOUT, poll immediately returns, but
writing (via SSL_write) fails with WANTS_READ
error. This goes on in a busy-loop until the
negotiation data is available for read and the
handshake is completed. Very inefficient.
The solution is to poll on whatever SSL needs
during the handshake, exclusively. Once the
handshake is complete, we poll on whatever we
need. However, SSL can renegotiate at any time,
so we also merge with what it needs.
In addition, we avoid the unnecessary read when
poll doesn't give us POLLIN in revents, since the
read will more likely than not fail (except in
the rare case when data becomes available in the
interim). Notice that SSL_read will return
SSL_WANTS_READ when there is no data, which
is misleading (since SSL isn't in need of data to
read at all, nor are we, for that matter).
Best not to do noisy reads unnecessarily.
These changes are disabled by default and can
be enabled via the experimental_features option.
Change-Id: I6a7ed7d871ed257b30062cc720a8b8c7acbab3b7
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
This prevents the kit from becoming a zombie
when it has an early failure to connect to WSD.
Change-Id: I4e8203b2cc3d80822308236e5b47be0c0c96e9ae
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
In 'debug' log-level we expect a detailed, but
still readable output. Having one area with
disproportionately large number of logs reduces
the overall utility of the log output.
This patch reduces a number of redundant log
entries, including errors that are already
logged. It also reduces the level of some
others from 'information' to 'debug' and
from 'debug' to 'trace'.
The goal is to make 'debug' level as useful as
possible to read the progress and be able to
understand what was going on, such that one is
able to decide which area to dig deeper into.
Then, trace level could be used to get more
insight into that area, if necessary. For
example, when investigating a test failure,
one first enables 'debug' logs and reads through.
Once a section between two debug entries is
identified as being of interest, enabling 'trace'
level logs becomes more productive as it's
now possible to easily reach the first DBG
entry and read through until the second one.
It's unfortunate that we don't have per-area
control for enabling/disabling logs, so it
is common to see more and more 'debug' log
entries added all around, making logs
less and less readable.
It is also a limitation of the levels we have
that we really only have 3 usable levels:
one, two, many. That is, 'information' for
the most important events, 'debug' for
technical details needed to investigate issues,
and 'trace' for everything else. ('warning'
and 'error' aren't really 'levels'; they have
semantics that makes them special-cases.)
So we have to avoid degrading one into the
other, or have differences without distinction.
If any of these entries are needed to be
displayed more frequently, changing them
back to 'debug' or even 'information' should
be done. Though for me they seem special
cases that don't benefit most log readings.
Change-Id: Id2c6a9dc027483b81a066b0b4b50a298c5eff449
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
Now the remaining tests that didn't have a name
get one and the logs are unified between old-
and new-style tests. Mostly.
This makes sure that all logs and assertions
properly log the test name and make test
failures easier to debug and fix.
Change-Id: Id159ffacc81642a6ec594c5143498408adab67cf
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
This reduces some logs from debug to trace,
especially in Socket where the amount of
activity is high, but the logs in question
don't add value in debug level.
Also supressed an error when superfluous.
This makes debug-level logs much more readable
and relevant to the main events.
Change-Id: Ie2698b56f320d15a09060cf2877477d9da0e1582
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
Don't stop processing all messages when one caused an exception.
Try/catch where messages are processed in the loop so we don't
ignore other messages:
* handleTCPStream
* handleIncomingMessage
Signed-off-by: Szymon Kłos <szymon.klos@collabora.com>
Change-Id: Idb8c9cf72a7912e7e508e429821b4ee32c9b122b
SteamSocket::eraseFirstInputBytes() removes from the beginning
of std::vector, which is generally slow. If the buffer becomes
too big, which it may under a load, then the function will get
slow, which in turn will likely lead to the buffer getting even
bigger because of accumulated backlog.
The Buffer class is optimized for removal at the beginning,
so use it instead of std::vector, including some API additions
for it to be an in-place replacement where it's used.
Signed-off-by: Luboš Luňák <l.lunak@collabora.com>
Change-Id: I4cf7ec56c908c7d3df391dc3f8e230ad32abb162
We don't want to always start with the most recently added socket.
Signed-off-by: Tor Lillqvist <tml@collabora.com>
Change-Id: Ic4b4bf6c19c5d119e6e6f9b398789a4c77b47a10
Also clear its input buffer explicitly.
Change-Id: I8badbb96d98eaf10433a65fcfd13b0d6d5893594
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
Ignore input in a somewhat gentler way.
Signed-off-by: Michael Meeks <michael.meeks@collabora.com>
Change-Id: I758302dc3bb1aa87f9fbfa726f73f4b9339e08c2
...Thread.
Conflicts:
net/Socket.hpp
net/SslSocket.hpp
Signed-off-by: Dennis Francis <dennis.francis@collabora.com>
Change-Id: I92b8f4b52e7bd60b69305c1916eed8a14a4c1560
This can be used to accelerate unit tests by allowing us to ensure
that all pending work is done between a 'processtoidle' message being
sent and an 'idle' being returned. This can be much faster than waiting
a defined length of time.
Change-Id: I6d96de205d1fd34a22e0ddbd2709bf806a97b33c
Signed-off-by: Michael Meeks <michael.meeks@collabora.com>
While we are processing data in the poll handler, we can have
another helpful thread from the core sending things to us:
loolforkit(Socket::assertCorrectThread(char const*, int))
loolforkit(WebSocketHandler::sendFrame(std::shared_ptr<StreamSocket> const&, char const*, unsigned long, unsigned char, bool) const)
loolforkit(WebSocketHandler::sendMessage(char const*, unsigned long, WSOpCode, bool) const)
loolforkit(Document::postMessage(char const*, int, WSOpCode) const)
loolforkit(Document::sendFrame(char const*, int, WSOpCode))
loolforkit(ChildSession::sendTextFrame(char const*, int))
loolforkit(ChildSession::loKitCallback(int, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&))
loolforkit(Document::GlobalCallback(int, char const*, void*))
/core/instdir/program/libsofficeapp.so()
/core/instdir/program/../program/libfwklo.so()
/core/instdir/program/libscfiltlo.so()
/core/instdir/program/libexpwraplo.so()
/core/instdir/program/libooxlo.so(oox::core::FastParser::parseStream(com::sun:⭐:xml::sax::InputSource const&, bool))
/core/instdir/program/libooxlo.so(oox::core::FastParser::parseStream(com::sun:⭐:uno::Reference<com::sun:⭐:io::XInputStream> const&, rtl::OUString const&))
/core/instdir/program/libooxlo.so(oox::core::XmlFilterBase::importFragment(rtl::Reference<oox::core::FragmentHandler> const&, oox::core::FastParser&))
/core/instdir/program/libscfiltlo.so()
/core/instdir/program/libcomphelper.so(comphelper::ThreadTask::exec())
/core/instdir/program/libcomphelper.so()
/core/instdir/program/libuno_salhelpergcc3.so.3(salhelper::Thread::run())
/core/instdir/program/libuno_salhelpergcc3.so.3()
/core/instdir/program/libuno_sal.so.3()
/lib/x86_64-linux-gnu/libpthread.so.0()
/lib/x86_64-linux-gnu/libc.so.6(clone)
This is most likely from eg. threaded parsing of various file formats,
or progress messages while loading / saving, sent while the SolarMutex
is locked.
We assume that:
+ there will only ever be one thread running inside kitPoll
this is enforced by vcl/headless.
+ and so, we can safely mutate SocketPoll and Socket buffer
state from this thread.
+ there are only two entry points for callbacks from threads
in core - which are both instrumented, and if necessary
their work is shifted to this thread.
Memory corruptions matching the above trace, suggesting that
multiple writes have collided between kitPoll and an event
callback have been seen in the wild.
Change-Id: I5b084cbfec1ea326b6e17c9e5590a8c8e35b3854
Signed-off-by: Michael Meeks <michael.meeks@collabora.com>
net/HttpRequest.cpp:126:19: error: declaration of 'end' shadows a member of 'this' [-Werror=shadow]
kit/Kit.cpp:163:29: error: missing initializer for member 'statfs::f_bsize' [-Werror=missing-field-initializers]
kit/Kit.cpp:171:14: error: 'OVERLAYFS_SUPER_MAGIC' was not declared in this scope
Signed-off-by: Miklos Vajna <vmiklos@collabora.com>
Change-Id: Ibbd35ab5af3adad403ed22a0aeb70917b9e21970
When writing to the socket, it's always more efficient
to fill the buffer up to the hardware limit for each
write. This is doubly important for efficiency with
SSL, due to the overhead of encrypting multiple
small buffers instead of one large one.
Currently we don't write more than one message
at a time, primarily due to limitations in
the Poco sockets in the unit-tests, which
have a hard time consuming multiple WS frames
with a single poll (subsequent calls to poll
doesn't enter signalled state until new data
arrives, possibly because the data is read and
buffered internally, making the whole scheme
of using poll unreliable and meaningless).
Change-Id: Ic2e2cf1babfb5ab4116efd93f392977ba234d92b
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
Since it's most efficent to send full blocks at
once (especially so when SSL encryption is done),
we now perform write when the buffer has fewer
than the send-buffer-size bytes. Previously,
we were only getting more data to write to the
socket when the buffer was completely empty,
potentially wasting valuable opportunity to
write more data to the socket while we're at it.
Change-Id: I69a18a042dc2e551ebc5e1af40dae091da3f3d13
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
This makes it simpler to call poll repeatedly
within a given timeout, by first calculating
the deadline and passing it to poll to handle
the math.
Change-Id: I7a9311286ec368c853de40f10523b7b98c8f8106
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
Now that the WebSocket functionality is available in
WebSocketHandler, we can cleanup Socket.
Change-Id: Ia3703ab5a2f00fb835eb80493bc400a91dabefad
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
Improved handling of http::Request and http::Response
in Socket directly with better error handling and
automatic socket shutdown on error.
We shouldn't need to manually serialize into the
socket's buffer when sending a Request or Response.
Change-Id: I6dfcd2fe4f6b88cd2fa8c749045ce25a8c52fe9a
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
We shouldn't need to erase from the in-buffer manually
anywhere. This utility encapsulates this functionality
well and protects against off-by-one errors.
Change-Id: I53616444ac9811a1e22d23d96a9cac8965b8518b
Signed-off-by: Ashod Nakashian <ashod.nakashian@collabora.co.uk>
