2017-03-02 12:12:52 -06:00
|
|
|
/* -*- Mode: C++; tab-width: 4; indent-tabs-mode: nil; c-basic-offset: 4; fill-column: 100 -*- */
|
|
|
|
/*
|
|
|
|
* This Source Code Form is subject to the terms of the Mozilla Public
|
|
|
|
* License, v. 2.0. If a copy of the MPL was not distributed with this
|
|
|
|
* file, You can obtain one at http://mozilla.org/MPL/2.0/.
|
|
|
|
*/
|
|
|
|
|
2017-12-20 07:06:26 -06:00
|
|
|
#include <config.h>
|
2017-03-08 10:38:22 -06:00
|
|
|
|
2021-01-12 21:48:26 -06:00
|
|
|
#include "NetUtil.hpp"
|
2018-06-04 15:47:39 -05:00
|
|
|
#include "Socket.hpp"
|
|
|
|
|
|
|
|
#include <cstring>
|
2017-03-06 15:26:53 -06:00
|
|
|
#include <ctype.h>
|
2017-03-18 09:59:09 -05:00
|
|
|
#include <iomanip>
|
2021-03-24 15:10:04 -05:00
|
|
|
#include <memory>
|
2021-03-11 20:10:59 -06:00
|
|
|
#include <sstream>
|
2018-06-04 15:47:39 -05:00
|
|
|
#include <stdio.h>
|
2021-01-12 21:48:26 -06:00
|
|
|
#include <string>
|
2018-06-04 15:47:39 -05:00
|
|
|
#include <unistd.h>
|
wsd: faster jail setup via bind-mount
loolmount now works and supports mounting and
unmounting, plus numerous improvements,
refactoring, logging, etc.. When enabled,
binding improves the jail setup time by anywhere
from 2x to orders of magnitude (in docker, f.e.).
A new config entry mount_jail_tree controls
whether mounting is used or the old method of
linking/copying of jail contents. It is set to
true by default and falls back to linking/copying.
A test mount is done when the setting is enabled,
and if mounting fails, it's disabled to avoid noise.
Temporarily disabled for unit-tests until we can
cleanup lingering mounts after Jenkins aborts our
build job. In a future patch we will have mount/jail
cleanup as part of make.
The network/system files in /etc that need frequent
refreshing are now updated in systemplate to make
their most recent version available in the jails.
These files can change during the course of loolwsd
lifetime, and are unlikely to be updated in
systemplate after installation at all. We link to
them in the systemplate/etc directory, and if that
fails, we copy them before forking each kit
instance to have the latest.
This reworks the approach used to bind-mount the
jails and the templates such that the total is
now down to only three mounts: systemplate, lo, tmp.
As now systemplate and lotemplate are shared, they
must be mounted as readonly, this means that user/
must now be moved into tmp/user/ which is writable.
The mount-points must be recursive, because we mount
lo/ within the mount-point of systemplate (which is
the root of the jail). But because we (re)bind
recursively, and because both systemplate and
lotemplate are mounted for each jails, we need to
make them unbindable, so they wouldn't multiply the
mount-points for each jails (an explosive growth!)
Contrarywise, we don't want the mount-points to
be shared, because we don't expect to add/remove
mounts after a jail is created.
The random temp directory is now created and set
correctly, plus many logging and other improvements.
Change-Id: Iae3fda5e876cf47d2cae6669a87b5b826a8748df
Reviewed-on: https://gerrit.libreoffice.org/c/online/+/92829
Tested-by: Jenkins
Tested-by: Jenkins CollaboraOffice <jenkinscollaboraoffice@gmail.com>
Reviewed-by: Ashod Nakashian <ashnakash@gmail.com>
2020-04-09 08:02:58 -05:00
|
|
|
#include <sys/stat.h>
|
2019-03-30 16:07:58 -05:00
|
|
|
#include <sys/types.h>
|
2019-04-02 09:26:02 -05:00
|
|
|
#include <sys/un.h>
|
2020-11-08 09:42:15 -06:00
|
|
|
#ifdef __FreeBSD__
|
|
|
|
#include <sys/ucred.h>
|
|
|
|
#endif
|
2017-03-30 06:08:47 -05:00
|
|
|
|
2017-03-15 13:21:59 -05:00
|
|
|
#include <Poco/DateTime.h>
|
|
|
|
#include <Poco/DateTimeFormat.h>
|
|
|
|
#include <Poco/DateTimeFormatter.h>
|
2018-05-01 08:57:17 -05:00
|
|
|
#include <Poco/MemoryStream.h>
|
|
|
|
#include <Poco/Net/HTTPRequest.h>
|
2017-04-23 20:25:09 -05:00
|
|
|
#include <Poco/Net/HTTPResponse.h>
|
2018-05-04 11:47:33 -05:00
|
|
|
#include <Poco/URI.h>
|
2021-06-27 10:38:59 -05:00
|
|
|
#if ENABLE_SSL
|
|
|
|
#include <Poco/Net/X509Certificate.h>
|
|
|
|
#endif
|
2017-03-15 13:21:59 -05:00
|
|
|
|
2017-12-20 07:06:26 -06:00
|
|
|
#include <SigUtil.hpp>
|
2017-03-06 09:45:34 -06:00
|
|
|
#include "ServerSocket.hpp"
|
2021-01-10 08:59:36 -06:00
|
|
|
#if !MOBILEAPP && ENABLE_SSL
|
|
|
|
#include <net/SslSocket.hpp>
|
2021-06-28 23:15:04 -05:00
|
|
|
#include <openssl/x509v3.h>
|
2018-09-04 04:02:20 -05:00
|
|
|
#endif
|
2017-03-18 09:59:09 -05:00
|
|
|
#include "WebSocketHandler.hpp"
|
2021-03-21 08:25:41 -05:00
|
|
|
#include <net/HttpRequest.hpp>
|
2017-03-02 12:12:52 -06:00
|
|
|
|
2020-12-14 14:18:01 -06:00
|
|
|
// Bug in pre C++17 where static constexpr must be defined. Fixed in C++17.
|
|
|
|
constexpr std::chrono::microseconds SocketPoll::DefaultPollTimeoutMicroS;
|
2020-12-27 15:54:34 -06:00
|
|
|
constexpr std::chrono::microseconds WebSocketHandler::InitialPingDelayMicroS;
|
|
|
|
constexpr std::chrono::microseconds WebSocketHandler::PingFrequencyMicroS;
|
|
|
|
|
2017-05-14 20:42:10 -05:00
|
|
|
std::atomic<bool> SocketPoll::InhibitThreadChecks(false);
|
2017-04-05 11:58:52 -05:00
|
|
|
std::atomic<bool> Socket::InhibitThreadChecks(false);
|
2017-03-09 14:35:04 -06:00
|
|
|
|
2021-11-18 06:08:14 -06:00
|
|
|
#define SOCKET_ABSTRACT_UNIX_NAME "0coolwsd-"
|
2019-03-30 09:06:16 -05:00
|
|
|
|
2018-01-09 08:02:02 -06:00
|
|
|
int Socket::createSocket(Socket::Type type)
|
|
|
|
{
|
2019-02-12 05:16:40 -06:00
|
|
|
#if !MOBILEAPP
|
2019-04-01 07:18:23 -05:00
|
|
|
int domain = AF_UNSPEC;
|
2019-03-30 09:06:16 -05:00
|
|
|
switch (type)
|
|
|
|
{
|
|
|
|
case Type::IPv4: domain = AF_INET; break;
|
|
|
|
case Type::IPv6: domain = AF_INET6; break;
|
|
|
|
case Type::All: domain = AF_INET6; break;
|
|
|
|
case Type::Unix: domain = AF_UNIX; break;
|
2020-10-31 14:08:08 -05:00
|
|
|
default: assert(!"Unknown Socket::Type"); break;
|
2019-03-30 09:06:16 -05:00
|
|
|
}
|
2020-10-31 14:08:08 -05:00
|
|
|
|
2018-01-09 08:02:02 -06:00
|
|
|
return socket(domain, SOCK_STREAM | SOCK_NONBLOCK, 0);
|
2018-09-13 11:16:00 -05:00
|
|
|
#else
|
|
|
|
return fakeSocketSocket();
|
|
|
|
#endif
|
2018-01-09 08:02:02 -06:00
|
|
|
}
|
|
|
|
|
2020-12-08 07:21:32 -06:00
|
|
|
#if ENABLE_DEBUG
|
|
|
|
static std::atomic<long> socketErrorCount;
|
|
|
|
|
2021-02-28 12:15:12 -06:00
|
|
|
bool StreamSocket::simulateSocketError(bool read)
|
2020-12-08 07:21:32 -06:00
|
|
|
{
|
|
|
|
if ((socketErrorCount++ % 7) == 0)
|
|
|
|
{
|
2022-02-01 12:08:37 -06:00
|
|
|
LOG_TRC("Simulating socket error during " << (read ? "read." : "write."));
|
2020-12-08 07:21:32 -06:00
|
|
|
errno = EAGAIN;
|
|
|
|
return true;
|
|
|
|
}
|
2020-12-24 19:43:09 -06:00
|
|
|
|
|
|
|
return false;
|
2020-12-08 07:21:32 -06:00
|
|
|
}
|
2021-06-27 10:38:59 -05:00
|
|
|
#endif //ENABLE_DEBUG
|
|
|
|
|
|
|
|
#if ENABLE_SSL
|
2021-06-28 23:15:04 -05:00
|
|
|
static std::string X509_NAME_to_utf8(X509_NAME* name)
|
|
|
|
{
|
|
|
|
BIO* bio = BIO_new(BIO_s_mem());
|
|
|
|
X509_NAME_print_ex(bio, name, 0,
|
|
|
|
(ASN1_STRFLGS_RFC2253 | XN_FLAG_SEP_COMMA_PLUS | XN_FLAG_FN_SN |
|
|
|
|
XN_FLAG_DUMP_UNKNOWN_FIELDS) &
|
|
|
|
~ASN1_STRFLGS_ESC_MSB);
|
|
|
|
BUF_MEM* buf;
|
|
|
|
BIO_get_mem_ptr(bio, &buf);
|
|
|
|
std::string text = std::string(buf->data, buf->length);
|
|
|
|
BIO_free(bio);
|
|
|
|
return text;
|
|
|
|
}
|
|
|
|
|
2021-06-27 10:38:59 -05:00
|
|
|
bool SslStreamSocket::verifyCertificate()
|
|
|
|
{
|
2021-06-28 23:15:04 -05:00
|
|
|
if (_verification == ssl::CertificateVerification::Disabled || net::isLocalhost(hostname()))
|
2021-06-27 14:22:17 -05:00
|
|
|
{
|
|
|
|
return true;
|
|
|
|
}
|
|
|
|
|
2021-06-28 23:15:04 -05:00
|
|
|
LOG_TRC("Verifying certificate of [" << hostname() << ']');
|
2021-06-27 10:38:59 -05:00
|
|
|
X509* x509 = SSL_get_peer_certificate(_ssl);
|
|
|
|
if (x509)
|
|
|
|
{
|
2021-06-28 23:15:04 -05:00
|
|
|
// Dump cert info, for debugging only.
|
|
|
|
const std::string issuerName = X509_NAME_to_utf8(X509_get_issuer_name(x509));
|
|
|
|
const std::string subjectName = X509_NAME_to_utf8(X509_get_subject_name(x509));
|
|
|
|
std::string serialNumber;
|
|
|
|
BIGNUM* pBN = ASN1_INTEGER_to_BN(X509_get_serialNumber(const_cast<X509*>(x509)), 0);
|
|
|
|
if (pBN)
|
|
|
|
{
|
|
|
|
char* pSN = BN_bn2hex(pBN);
|
|
|
|
if (pSN)
|
|
|
|
{
|
|
|
|
serialNumber = pSN;
|
|
|
|
OPENSSL_free(pSN);
|
|
|
|
}
|
|
|
|
|
|
|
|
BN_free(pBN);
|
|
|
|
}
|
|
|
|
|
|
|
|
LOG_TRC("SSL cert issuer: " << issuerName << ", subject: " << subjectName
|
|
|
|
<< ", serial: " << serialNumber);
|
|
|
|
|
2021-06-27 10:38:59 -05:00
|
|
|
Poco::Net::X509Certificate cert(x509);
|
2021-06-28 23:15:04 -05:00
|
|
|
if (cert.verify(hostname()))
|
|
|
|
{
|
|
|
|
LOG_TRC("SSL cert verified for host [" << hostname() << ']');
|
|
|
|
return true;
|
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
LOG_INF("SSL cert failed verification for host [" << hostname() << ']');
|
|
|
|
return false;
|
|
|
|
}
|
2021-06-27 10:38:59 -05:00
|
|
|
}
|
|
|
|
|
2021-06-27 14:22:17 -05:00
|
|
|
// No certificate; acceptable only if verification is not strictly required.
|
|
|
|
return (_verification == ssl::CertificateVerification::IfProvided);
|
2021-06-27 10:38:59 -05:00
|
|
|
}
|
|
|
|
#endif //ENABLE_SSL
|
2020-12-08 07:21:32 -06:00
|
|
|
|
2017-03-03 15:18:27 -06:00
|
|
|
// help with initialization order
|
|
|
|
namespace {
|
|
|
|
std::vector<int> &getWakeupsArray()
|
|
|
|
{
|
|
|
|
static std::vector<int> pollWakeups;
|
|
|
|
return pollWakeups;
|
|
|
|
}
|
|
|
|
std::mutex &getPollWakeupsMutex()
|
|
|
|
{
|
|
|
|
static std::mutex pollWakeupsMutex;
|
|
|
|
return pollWakeupsMutex;
|
|
|
|
}
|
|
|
|
}
|
2017-03-02 12:12:52 -06:00
|
|
|
|
2022-02-16 16:22:18 -06:00
|
|
|
SocketPoll::SocketPoll(std::string threadName)
|
|
|
|
: _name(std::move(threadName)),
|
2021-07-29 03:57:04 -05:00
|
|
|
_pollStartIndex(0),
|
2017-03-09 13:23:21 -06:00
|
|
|
_stop(false),
|
2021-03-10 07:38:31 -06:00
|
|
|
_threadStarted(0),
|
2017-04-02 16:49:14 -05:00
|
|
|
_threadFinished(false),
|
2018-06-06 21:53:15 -05:00
|
|
|
_runOnClientThread(false),
|
2017-04-02 16:49:14 -05:00
|
|
|
_owner(std::this_thread::get_id())
|
2017-03-02 12:12:52 -06:00
|
|
|
{
|
2021-07-16 00:16:02 -05:00
|
|
|
ProfileZone profileZone("SocketPoll::SocketPoll");
|
|
|
|
|
2017-03-02 12:12:52 -06:00
|
|
|
// Create the wakeup fd.
|
2018-09-13 11:16:00 -05:00
|
|
|
if (
|
2019-02-12 05:16:40 -06:00
|
|
|
#if !MOBILEAPP
|
2018-09-13 11:16:00 -05:00
|
|
|
::pipe2(_wakeup, O_CLOEXEC | O_NONBLOCK) == -1
|
|
|
|
#else
|
|
|
|
fakeSocketPipe2(_wakeup) == -1
|
|
|
|
#endif
|
|
|
|
)
|
2017-03-02 12:12:52 -06:00
|
|
|
{
|
2017-03-28 00:07:07 -05:00
|
|
|
throw std::runtime_error("Failed to allocate pipe for SocketPoll [" + threadName + "] waking.");
|
2017-03-02 12:12:52 -06:00
|
|
|
}
|
2017-03-06 22:09:09 -06:00
|
|
|
|
2021-03-11 17:02:09 -06:00
|
|
|
LOG_DBG("New SocketPoll [" << _name << "] owned by " << Log::to_string(_owner));
|
|
|
|
|
2017-04-02 17:43:21 -05:00
|
|
|
std::lock_guard<std::mutex> lock(getPollWakeupsMutex());
|
|
|
|
getWakeupsArray().push_back(_wakeup[1]);
|
2017-03-02 12:12:52 -06:00
|
|
|
}
|
|
|
|
|
|
|
|
SocketPoll::~SocketPoll()
|
|
|
|
{
|
2022-02-01 12:08:37 -06:00
|
|
|
LOG_TRC("~SocketPoll [" << _name << "] destroying. Joining thread now.");
|
2021-03-11 17:02:09 -06:00
|
|
|
|
2017-03-31 11:28:20 -05:00
|
|
|
joinThread();
|
2017-03-06 22:09:09 -06:00
|
|
|
|
2017-03-17 13:56:59 -05:00
|
|
|
{
|
|
|
|
std::lock_guard<std::mutex> lock(getPollWakeupsMutex());
|
|
|
|
auto it = std::find(getWakeupsArray().begin(),
|
|
|
|
getWakeupsArray().end(),
|
|
|
|
_wakeup[1]);
|
2017-03-02 12:12:52 -06:00
|
|
|
|
2017-03-17 13:56:59 -05:00
|
|
|
if (it != getWakeupsArray().end())
|
|
|
|
getWakeupsArray().erase(it);
|
|
|
|
}
|
2017-03-03 15:18:27 -06:00
|
|
|
|
2019-02-12 05:16:40 -06:00
|
|
|
#if !MOBILEAPP
|
2017-03-17 13:56:59 -05:00
|
|
|
::close(_wakeup[0]);
|
|
|
|
::close(_wakeup[1]);
|
2018-09-13 11:16:00 -05:00
|
|
|
#else
|
|
|
|
fakeSocketClose(_wakeup[0]);
|
|
|
|
fakeSocketClose(_wakeup[1]);
|
|
|
|
#endif
|
2017-03-17 13:56:59 -05:00
|
|
|
_wakeup[0] = -1;
|
|
|
|
_wakeup[1] = -1;
|
2017-03-03 15:18:27 -06:00
|
|
|
}
|
|
|
|
|
2018-06-06 21:53:15 -05:00
|
|
|
bool SocketPoll::startThread()
|
2017-03-09 13:00:04 -06:00
|
|
|
{
|
2018-06-06 21:53:15 -05:00
|
|
|
assert(!_runOnClientThread);
|
|
|
|
|
2021-03-10 07:38:31 -06:00
|
|
|
// In a race, only the first gets in.
|
|
|
|
if (_threadStarted++ == 0)
|
2017-03-09 13:23:21 -06:00
|
|
|
{
|
2018-10-16 14:24:19 -05:00
|
|
|
_threadFinished = false;
|
|
|
|
_stop = false;
|
2017-03-19 12:22:12 -05:00
|
|
|
try
|
|
|
|
{
|
2021-03-11 17:02:09 -06:00
|
|
|
LOG_TRC("Creating thread for SocketPoll " << _name);
|
2017-03-19 12:22:12 -05:00
|
|
|
_thread = std::thread(&SocketPoll::pollingThreadEntry, this);
|
2018-06-06 21:53:15 -05:00
|
|
|
return true;
|
2017-03-19 12:22:12 -05:00
|
|
|
}
|
|
|
|
catch (const std::exception& exc)
|
|
|
|
{
|
2021-03-11 17:02:09 -06:00
|
|
|
LOG_ERR("Failed to start SocketPoll thread [" << _name << "]: " << exc.what());
|
2021-03-10 07:38:31 -06:00
|
|
|
_threadStarted = 0;
|
2017-03-19 12:22:12 -05:00
|
|
|
}
|
2017-03-09 13:23:21 -06:00
|
|
|
}
|
2021-03-11 20:31:54 -06:00
|
|
|
else if (isAlive())
|
|
|
|
{
|
|
|
|
// Most likely a programming error--use isAlive().
|
|
|
|
LOG_DBG("SocketPoll [" << _name << "] thread is already running.");
|
|
|
|
}
|
2021-03-10 07:38:31 -06:00
|
|
|
else
|
2021-03-11 20:31:54 -06:00
|
|
|
{
|
|
|
|
// This is most likely a programming error.
|
|
|
|
// There is no point in starting a new thread either,
|
|
|
|
// because the owner is unlikely to recover.
|
|
|
|
// If there is a valid use-case for restarting
|
|
|
|
// an expired thread, we should add a way to reset it.
|
|
|
|
LOG_ERR("SocketPoll [" << _name
|
|
|
|
<< "] thread has ran and finished. Will not start it again.");
|
|
|
|
}
|
2018-06-06 21:53:15 -05:00
|
|
|
|
|
|
|
return false;
|
2017-03-09 13:00:04 -06:00
|
|
|
}
|
|
|
|
|
2017-03-31 11:28:20 -05:00
|
|
|
void SocketPoll::joinThread()
|
|
|
|
{
|
2019-01-06 09:44:40 -06:00
|
|
|
if (isAlive())
|
|
|
|
{
|
|
|
|
addCallback([this]()
|
|
|
|
{
|
|
|
|
removeSockets();
|
|
|
|
});
|
|
|
|
stop();
|
|
|
|
}
|
|
|
|
|
2017-03-31 11:28:20 -05:00
|
|
|
if (_threadStarted && _thread.joinable())
|
|
|
|
{
|
|
|
|
if (_thread.get_id() == std::this_thread::get_id())
|
|
|
|
LOG_ERR("DEADLOCK PREVENTED: joining own thread!");
|
|
|
|
else
|
|
|
|
{
|
|
|
|
_thread.join();
|
2021-03-10 07:38:31 -06:00
|
|
|
_threadStarted = 0;
|
2017-03-31 11:28:20 -05:00
|
|
|
}
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
2018-09-13 01:31:52 -05:00
|
|
|
void SocketPoll::pollingThreadEntry()
|
|
|
|
{
|
|
|
|
try
|
|
|
|
{
|
|
|
|
Util::setThreadName(_name);
|
|
|
|
_owner = std::this_thread::get_id();
|
2019-09-29 22:32:45 -05:00
|
|
|
LOG_INF("Starting polling thread [" << _name << "] with thread affinity set to "
|
|
|
|
<< Log::to_string(_owner) << '.');
|
2018-09-13 01:31:52 -05:00
|
|
|
|
|
|
|
// Invoke the virtual implementation.
|
|
|
|
pollingThread();
|
|
|
|
|
|
|
|
// Release sockets.
|
|
|
|
_pollSockets.clear();
|
|
|
|
_newSockets.clear();
|
|
|
|
}
|
|
|
|
catch (const std::exception& exc)
|
|
|
|
{
|
|
|
|
LOG_ERR("Exception in polling thread [" << _name << "]: " << exc.what());
|
|
|
|
}
|
|
|
|
|
|
|
|
_threadFinished = true;
|
2019-09-29 22:32:45 -05:00
|
|
|
LOG_INF("Finished polling thread [" << _name << "].");
|
2018-09-13 01:31:52 -05:00
|
|
|
}
|
|
|
|
|
2020-04-10 06:34:15 -05:00
|
|
|
int SocketPoll::poll(int64_t timeoutMaxMicroS)
|
2020-04-09 08:43:51 -05:00
|
|
|
{
|
|
|
|
if (_runOnClientThread)
|
|
|
|
checkAndReThread();
|
|
|
|
else
|
|
|
|
assertCorrectThread();
|
|
|
|
|
2020-12-08 07:21:32 -06:00
|
|
|
#if ENABLE_DEBUG
|
|
|
|
// perturb - to rotate errors among several busy sockets.
|
|
|
|
socketErrorCount++;
|
|
|
|
#endif
|
|
|
|
|
2020-04-09 08:43:51 -05:00
|
|
|
std::chrono::steady_clock::time_point now =
|
|
|
|
std::chrono::steady_clock::now();
|
|
|
|
|
|
|
|
// The events to poll on change each spin of the loop.
|
2020-04-10 06:34:15 -05:00
|
|
|
setupPollFds(now, timeoutMaxMicroS);
|
2020-04-09 08:43:51 -05:00
|
|
|
const size_t size = _pollSockets.size();
|
|
|
|
|
|
|
|
int rc;
|
|
|
|
do
|
|
|
|
{
|
|
|
|
#if !MOBILEAPP
|
|
|
|
# if HAVE_PPOLL
|
|
|
|
LOG_TRC("ppoll start, timeoutMicroS: " << timeoutMaxMicroS << " size " << size);
|
|
|
|
timeoutMaxMicroS = std::max(timeoutMaxMicroS, (int64_t)0);
|
|
|
|
struct timespec timeout;
|
|
|
|
timeout.tv_sec = timeoutMaxMicroS / (1000 * 1000);
|
|
|
|
timeout.tv_nsec = (timeoutMaxMicroS % (1000 * 1000)) * 1000;
|
|
|
|
rc = ::ppoll(&_pollFds[0], size + 1, &timeout, nullptr);
|
|
|
|
# else
|
|
|
|
int timeoutMaxMs = (timeoutMaxMicroS + 9999) / 1000;
|
|
|
|
LOG_TRC("Legacy Poll start, timeoutMs: " << timeoutMaxMs);
|
|
|
|
rc = ::poll(&_pollFds[0], size + 1, std::max(timeoutMaxMs,0));
|
|
|
|
# endif
|
|
|
|
#else
|
|
|
|
LOG_TRC("SocketPoll Poll");
|
|
|
|
int timeoutMaxMs = (timeoutMaxMicroS + 9999) / 1000;
|
|
|
|
rc = fakeSocketPoll(&_pollFds[0], size + 1, std::max(timeoutMaxMs,0));
|
|
|
|
#endif
|
|
|
|
}
|
|
|
|
while (rc < 0 && errno == EINTR);
|
|
|
|
LOG_TRC("Poll completed with " << rc << " live polls max (" <<
|
|
|
|
timeoutMaxMicroS << "us)" << ((rc==0) ? "(timedout)" : ""));
|
|
|
|
|
|
|
|
// First process the wakeup pipe (always the last entry).
|
|
|
|
if (_pollFds[size].revents)
|
|
|
|
{
|
|
|
|
std::vector<CallbackFn> invoke;
|
|
|
|
{
|
|
|
|
std::lock_guard<std::mutex> lock(_mutex);
|
|
|
|
|
|
|
|
// Clear the data.
|
|
|
|
#if !MOBILEAPP
|
|
|
|
int dump = ::read(_wakeup[0], &dump, sizeof(dump));
|
|
|
|
#else
|
|
|
|
LOG_TRC("Wakeup pipe read");
|
|
|
|
int dump = fakeSocketRead(_wakeup[0], &dump, sizeof(dump));
|
|
|
|
#endif
|
|
|
|
// Copy the new sockets over and clear.
|
|
|
|
_pollSockets.insert(_pollSockets.end(),
|
|
|
|
_newSockets.begin(), _newSockets.end());
|
|
|
|
|
|
|
|
// Update thread ownership.
|
|
|
|
for (auto &i : _newSockets)
|
|
|
|
i->setThreadOwner(std::this_thread::get_id());
|
|
|
|
|
|
|
|
_newSockets.clear();
|
|
|
|
|
|
|
|
// Extract list of callbacks to process
|
|
|
|
std::swap(_newCallbacks, invoke);
|
|
|
|
}
|
|
|
|
|
|
|
|
for (const auto& callback : invoke)
|
|
|
|
{
|
|
|
|
try
|
|
|
|
{
|
|
|
|
callback();
|
|
|
|
}
|
|
|
|
catch (const std::exception& exc)
|
|
|
|
{
|
|
|
|
LOG_ERR("Exception while invoking poll [" << _name <<
|
|
|
|
"] callback: " << exc.what());
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
try
|
|
|
|
{
|
|
|
|
wakeupHook();
|
|
|
|
}
|
|
|
|
catch (const std::exception& exc)
|
|
|
|
{
|
|
|
|
LOG_ERR("Exception while invoking poll [" << _name <<
|
|
|
|
"] wakeup hook: " << exc.what());
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
// This should only happen when we're stopping.
|
2020-07-08 09:19:02 -05:00
|
|
|
|
|
|
|
// FIXME: A few dozen lines above we have potentially inserted new elements in _pollSockets, so
|
|
|
|
// clearly its size can now be larger than what it was when we came to this function, which got
|
|
|
|
// saved in the size variable.
|
|
|
|
|
2020-04-09 08:43:51 -05:00
|
|
|
if (_pollSockets.size() != size)
|
|
|
|
return rc;
|
|
|
|
|
|
|
|
// Fire the poll callbacks and remove dead fds.
|
|
|
|
std::chrono::steady_clock::time_point newNow =
|
|
|
|
std::chrono::steady_clock::now();
|
|
|
|
|
2021-07-29 03:57:04 -05:00
|
|
|
if (size > 0)
|
2020-04-09 08:43:51 -05:00
|
|
|
{
|
2021-07-29 03:57:04 -05:00
|
|
|
// We use the _pollStartIndex to start the polling at a different index each time. Do some
|
|
|
|
// sanity check first to handle the case where we removed one or several sockets last time.
|
|
|
|
if (_pollStartIndex > size - 1)
|
|
|
|
_pollStartIndex = size - 1;
|
|
|
|
|
|
|
|
std::vector<int> toErase;
|
|
|
|
|
|
|
|
size_t i = _pollStartIndex;
|
2022-03-18 20:45:44 -05:00
|
|
|
LOG_TRC("Starting handling poll results of "
|
|
|
|
<< _name << " #" << _pollFds[i].fd << " at index " << _pollStartIndex << " (of "
|
|
|
|
<< size << "): " << std::hex << _pollFds[i].revents << std::dec);
|
|
|
|
|
2021-07-29 03:57:04 -05:00
|
|
|
size_t previ = size;
|
|
|
|
while (previ != _pollStartIndex)
|
2020-04-09 08:43:51 -05:00
|
|
|
{
|
2021-07-29 03:57:04 -05:00
|
|
|
SocketDisposition disposition(_pollSockets[i]);
|
|
|
|
try
|
|
|
|
{
|
|
|
|
_pollSockets[i]->handlePoll(disposition, newNow,
|
|
|
|
_pollFds[i].revents);
|
|
|
|
}
|
|
|
|
catch (const std::exception& exc)
|
|
|
|
{
|
wsd: reduce debug and generally redundant logs
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>
2022-02-19 07:30:26 -06:00
|
|
|
LOG_ERR('#' << _pollFds[i].fd << " Error while handling poll at " << i << " in "
|
|
|
|
<< _name << ": " << exc.what());
|
2021-07-29 03:57:04 -05:00
|
|
|
disposition.setClosed();
|
|
|
|
rc = -1;
|
|
|
|
}
|
|
|
|
|
|
|
|
if (!disposition.isContinue())
|
|
|
|
toErase.push_back(i);
|
2020-04-09 08:43:51 -05:00
|
|
|
|
2021-07-29 03:57:04 -05:00
|
|
|
disposition.execute();
|
|
|
|
|
|
|
|
previ = i;
|
|
|
|
if (i == 0)
|
|
|
|
i = size - 1;
|
|
|
|
else
|
|
|
|
i--;
|
|
|
|
}
|
|
|
|
if (!toErase.empty())
|
2020-04-09 08:43:51 -05:00
|
|
|
{
|
2021-07-29 03:57:04 -05:00
|
|
|
std::sort(toErase.begin(), toErase.end(), [](int a, int b) { return a > b; });
|
|
|
|
for (int eraseIndex : toErase)
|
|
|
|
{
|
2022-02-01 12:08:37 -06:00
|
|
|
LOG_TRC("Removing socket #" << _pollFds[eraseIndex].fd << " (at " << eraseIndex
|
|
|
|
<< " of " << _pollSockets.size() << ") from " << _name);
|
2021-07-29 03:57:04 -05:00
|
|
|
_pollSockets.erase(_pollSockets.begin() + eraseIndex);
|
|
|
|
}
|
2020-04-09 08:43:51 -05:00
|
|
|
}
|
|
|
|
|
2021-07-29 03:57:04 -05:00
|
|
|
// In case we remved sockets the new _pollStartIndex might be out of bounds, but we check it
|
|
|
|
// before using it above anyway.
|
|
|
|
_pollStartIndex = (_pollStartIndex + 1) % size;
|
2020-04-09 08:43:51 -05:00
|
|
|
}
|
|
|
|
|
|
|
|
return rc;
|
|
|
|
}
|
|
|
|
|
2017-03-03 15:18:27 -06:00
|
|
|
void SocketPoll::wakeupWorld()
|
|
|
|
{
|
|
|
|
for (const auto& fd : getWakeupsArray())
|
|
|
|
wakeup(fd);
|
2017-03-02 12:12:52 -06:00
|
|
|
}
|
|
|
|
|
2019-03-31 06:34:24 -05:00
|
|
|
#if !MOBILEAPP
|
|
|
|
|
2021-03-24 14:05:27 -05:00
|
|
|
void SocketPoll::insertNewWebSocketSync(const Poco::URI& uri,
|
|
|
|
const std::shared_ptr<WebSocketHandler>& websocketHandler)
|
2018-05-04 11:47:33 -05:00
|
|
|
{
|
2021-03-24 14:05:27 -05:00
|
|
|
LOG_TRC("Connecting WS to " << uri.getHost());
|
|
|
|
|
2021-01-12 21:48:26 -06:00
|
|
|
const bool isSSL = uri.getScheme() != "ws";
|
2018-05-04 11:47:33 -05:00
|
|
|
#if !ENABLE_SSL
|
|
|
|
if (isSSL)
|
|
|
|
{
|
|
|
|
LOG_ERR("Error: wss for client websocket requested but SSL not compiled in.");
|
|
|
|
return;
|
|
|
|
}
|
|
|
|
#endif
|
|
|
|
|
2021-03-24 14:05:27 -05:00
|
|
|
http::Request req(uri.getPathAndQuery());
|
|
|
|
req.set("User-Foo", "Adminbits");
|
|
|
|
//FIXME: Why do we need the following here?
|
|
|
|
req.set("Accept-Language", "en");
|
|
|
|
req.set("Cache-Control", "no-cache");
|
|
|
|
req.set("Pragma", "no-cache");
|
|
|
|
|
|
|
|
const std::string port = std::to_string(uri.getPort());
|
|
|
|
if (websocketHandler->wsRequest(req, uri.getHost(), port, isSSL, *this))
|
|
|
|
{
|
|
|
|
LOG_DBG("Connected WS to " << uri.getHost());
|
|
|
|
}
|
|
|
|
else
|
2018-05-04 11:47:33 -05:00
|
|
|
{
|
2021-03-24 14:05:27 -05:00
|
|
|
LOG_ERR("Failed to connected WS to " << uri.getHost());
|
2018-05-04 11:47:33 -05:00
|
|
|
}
|
2019-03-30 09:06:16 -05:00
|
|
|
}
|
|
|
|
|
2022-02-22 16:55:00 -06:00
|
|
|
bool SocketPoll::insertNewUnixSocket(
|
2019-03-30 09:06:16 -05:00
|
|
|
const std::string &location,
|
|
|
|
const std::string &pathAndQuery,
|
2021-03-24 15:10:04 -05:00
|
|
|
const std::shared_ptr<WebSocketHandler>& websocketHandler,
|
2020-04-28 08:55:47 -05:00
|
|
|
const int shareFD)
|
2019-03-30 09:06:16 -05:00
|
|
|
{
|
2021-03-24 15:10:04 -05:00
|
|
|
LOG_DBG("Connecting to local UDS " << location);
|
|
|
|
const int fd = socket(AF_UNIX, SOCK_STREAM | SOCK_NONBLOCK, 0);
|
2019-03-30 09:06:16 -05:00
|
|
|
|
|
|
|
struct sockaddr_un addrunix;
|
|
|
|
std::memset(&addrunix, 0, sizeof(addrunix));
|
|
|
|
addrunix.sun_family = AF_UNIX;
|
2021-07-30 09:45:39 -05:00
|
|
|
#ifdef HAVE_ABSTRACT_UNIX_SOCKETS
|
2019-03-30 09:06:16 -05:00
|
|
|
addrunix.sun_path[0] = '\0'; // abstract name
|
2021-04-24 13:39:04 -05:00
|
|
|
#else
|
|
|
|
addrunix.sun_path[0] = '0';
|
|
|
|
#endif
|
2019-03-30 09:06:16 -05:00
|
|
|
memcpy(&addrunix.sun_path[1], location.c_str(), location.length());
|
|
|
|
|
2021-03-24 15:10:04 -05:00
|
|
|
const int res = connect(fd, (const struct sockaddr*)&addrunix, sizeof(addrunix));
|
2019-03-30 09:06:16 -05:00
|
|
|
if (fd < 0 || (res < 0 && errno != EINPROGRESS))
|
|
|
|
{
|
2022-02-22 16:55:00 -06:00
|
|
|
LOG_SYS("Failed to connect to unix socket at " << location);
|
2019-03-30 09:06:16 -05:00
|
|
|
::close(fd);
|
2022-02-22 16:55:00 -06:00
|
|
|
return false;
|
2021-03-24 15:10:04 -05:00
|
|
|
}
|
|
|
|
|
|
|
|
std::shared_ptr<StreamSocket> socket
|
2021-06-27 10:38:59 -05:00
|
|
|
= StreamSocket::create<StreamSocket>(std::string(), fd, true, websocketHandler);
|
2021-03-24 15:10:04 -05:00
|
|
|
if (!socket)
|
|
|
|
{
|
|
|
|
LOG_ERR("Failed to create socket unix socket at " << location);
|
2022-02-22 16:55:00 -06:00
|
|
|
return false;
|
2021-03-24 15:10:04 -05:00
|
|
|
}
|
|
|
|
|
|
|
|
LOG_DBG("Connected to local UDS " << location << " #" << socket->getFD());
|
|
|
|
|
|
|
|
http::Request req(pathAndQuery);
|
|
|
|
req.set("User-Foo", "Adminbits");
|
|
|
|
req.set("Sec-WebSocket-Key", websocketHandler->getWebSocketKey());
|
|
|
|
req.set("Sec-WebSocket-Version", "13");
|
|
|
|
//FIXME: Why do we need the following here?
|
|
|
|
req.set("Accept-Language", "en");
|
|
|
|
req.set("Cache-Control", "no-cache");
|
|
|
|
req.set("Pragma", "no-cache");
|
|
|
|
|
|
|
|
LOG_TRC("Requesting upgrade of websocket at path " << pathAndQuery << " #" << socket->getFD());
|
|
|
|
if (shareFD == -1)
|
|
|
|
{
|
|
|
|
socket->send(req);
|
2019-03-30 09:06:16 -05:00
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
2021-03-24 15:10:04 -05:00
|
|
|
Buffer buf;
|
2021-03-07 11:57:13 -06:00
|
|
|
req.writeData(buf, INT_MAX); // Write the whole request.
|
2021-03-24 15:10:04 -05:00
|
|
|
socket->sendFD(buf.getBlock(), buf.getBlockSize(), shareFD);
|
2019-03-30 09:06:16 -05:00
|
|
|
}
|
2021-03-24 15:10:04 -05:00
|
|
|
|
|
|
|
std::static_pointer_cast<ProtocolHandlerInterface>(websocketHandler)->onConnect(socket);
|
|
|
|
insertNewSocket(socket);
|
2021-06-01 15:51:12 -05:00
|
|
|
|
|
|
|
// We send lots of data back via this local UDS'
|
|
|
|
socket->setSocketBufferSize(Socket::MaximumSendBufferSize);
|
2022-02-22 16:55:00 -06:00
|
|
|
|
|
|
|
return true;
|
2019-03-30 09:06:16 -05:00
|
|
|
}
|
|
|
|
|
2019-03-31 06:34:24 -05:00
|
|
|
#else
|
|
|
|
|
2019-03-30 09:06:16 -05:00
|
|
|
void SocketPoll::insertNewFakeSocket(
|
|
|
|
int peerSocket,
|
2020-03-06 11:43:46 -06:00
|
|
|
const std::shared_ptr<ProtocolHandlerInterface>& websocketHandler)
|
2019-03-30 09:06:16 -05:00
|
|
|
{
|
2018-09-13 11:16:00 -05:00
|
|
|
LOG_INF("Connecting to " << peerSocket);
|
|
|
|
int fd = fakeSocketSocket();
|
|
|
|
int res = fakeSocketConnect(fd, peerSocket);
|
|
|
|
if (fd < 0 || (res < 0 && errno != EINPROGRESS))
|
|
|
|
{
|
|
|
|
LOG_ERR("Failed to connect to the 'wsd' socket");
|
|
|
|
fakeSocketClose(fd);
|
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
std::shared_ptr<StreamSocket> socket;
|
2021-06-27 10:38:59 -05:00
|
|
|
socket = StreamSocket::create<StreamSocket>(std::string(), fd, true, websocketHandler);
|
2018-09-13 11:16:00 -05:00
|
|
|
if (socket)
|
|
|
|
{
|
|
|
|
LOG_TRC("Sending 'hello' instead of HTTP GET for now");
|
|
|
|
socket->send("hello");
|
|
|
|
insertNewSocket(socket);
|
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
LOG_ERR("Failed to allocate socket for client websocket");
|
|
|
|
fakeSocketClose(fd);
|
|
|
|
}
|
|
|
|
}
|
2018-09-05 07:11:05 -05:00
|
|
|
}
|
2019-03-30 09:06:16 -05:00
|
|
|
#endif
|
2018-09-04 04:02:20 -05:00
|
|
|
|
2017-03-12 18:03:45 -05:00
|
|
|
void ServerSocket::dumpState(std::ostream& os)
|
2017-03-06 09:45:34 -06:00
|
|
|
{
|
2020-05-24 08:10:18 -05:00
|
|
|
os << '\t' << getFD() << "\t<accept>\n";
|
2017-03-06 09:45:34 -06:00
|
|
|
}
|
|
|
|
|
2017-05-05 05:51:43 -05:00
|
|
|
void SocketDisposition::execute()
|
|
|
|
{
|
|
|
|
// We should have hard ownership of this socket.
|
2019-05-10 10:45:01 -05:00
|
|
|
assert(_socket->getThreadOwner() == std::this_thread::get_id());
|
2017-05-05 05:51:43 -05:00
|
|
|
if (_socketMove)
|
2017-05-08 09:23:49 -05:00
|
|
|
{
|
|
|
|
// Drop pretentions of ownership before _socketMove.
|
2021-03-11 17:26:23 -06:00
|
|
|
_socket->resetThreadOwner();
|
2020-12-04 11:43:47 -06:00
|
|
|
|
|
|
|
if (!_toPoll) {
|
|
|
|
assert (isMove());
|
|
|
|
_socketMove(_socket);
|
|
|
|
} else {
|
|
|
|
assert (isTransfer());
|
|
|
|
// Ensure the thread is running before adding callback.
|
|
|
|
_toPoll->startThread();
|
|
|
|
auto pollCopy = _toPoll;
|
|
|
|
auto socket = _socket;
|
|
|
|
auto socketMoveFn = std::move(_socketMove);
|
|
|
|
_toPoll->addCallback([pollCopy, socket, socketMoveFn]()
|
|
|
|
{
|
|
|
|
pollCopy->insertNewSocket(socket);
|
|
|
|
socketMoveFn(socket);
|
|
|
|
});
|
|
|
|
}
|
|
|
|
_socketMove = nullptr;
|
|
|
|
_toPoll = nullptr;
|
2017-05-08 09:23:49 -05:00
|
|
|
}
|
2017-05-05 05:51:43 -05:00
|
|
|
}
|
|
|
|
|
2017-03-18 09:59:09 -05:00
|
|
|
void WebSocketHandler::dumpState(std::ostream& os)
|
|
|
|
{
|
2020-06-24 05:50:08 -05:00
|
|
|
os << (_shuttingDown ? "shutd " : "alive ");
|
|
|
|
#if !MOBILEAPP
|
|
|
|
os << std::setw(5) << _pingTimeUs/1000. << "ms ";
|
|
|
|
#endif
|
2017-03-18 09:59:09 -05:00
|
|
|
if (_wsPayload.size() > 0)
|
2021-03-11 12:12:20 -06:00
|
|
|
Util::dumpHex(os, _wsPayload, "\t\tws queued payload:\n", "\t\t");
|
2020-05-24 08:10:18 -05:00
|
|
|
os << '\n';
|
2020-03-21 09:27:15 -05:00
|
|
|
if (_msgHandler)
|
|
|
|
_msgHandler->dumpState(os);
|
2017-03-18 09:59:09 -05:00
|
|
|
}
|
|
|
|
|
2017-03-12 18:03:45 -05:00
|
|
|
void StreamSocket::dumpState(std::ostream& os)
|
2017-03-06 09:45:34 -06:00
|
|
|
{
|
2020-12-14 14:18:01 -06:00
|
|
|
int64_t timeoutMaxMicroS = SocketPoll::DefaultPollTimeoutMicroS.count();
|
|
|
|
const int events = getPollEvents(std::chrono::steady_clock::now(), timeoutMaxMicroS);
|
2020-05-24 08:10:18 -05:00
|
|
|
os << '\t' << getFD() << '\t' << events << '\t'
|
2021-07-07 19:21:43 -05:00
|
|
|
<< (ignoringInput() ? "ignore\t" : "process\t")
|
2020-05-24 08:10:18 -05:00
|
|
|
<< _inBuffer.size() << '\t' << _outBuffer.size() << '\t'
|
|
|
|
<< " r: " << _bytesRecvd << "\t w: " << _bytesSent << '\t'
|
|
|
|
<< clientAddress() << '\t';
|
2017-03-18 09:59:09 -05:00
|
|
|
_socketHandler->dumpState(os);
|
2017-03-06 15:26:53 -06:00
|
|
|
if (_inBuffer.size() > 0)
|
2021-03-11 12:12:20 -06:00
|
|
|
Util::dumpHex(os, _inBuffer, "\t\tinBuffer:\n", "\t\t");
|
2020-11-19 13:55:30 -06:00
|
|
|
_outBuffer.dumpHex(os, "\t\toutBuffer:\n", "\t\t");
|
2017-03-06 09:45:34 -06:00
|
|
|
}
|
|
|
|
|
2017-04-23 20:25:09 -05:00
|
|
|
void StreamSocket::send(Poco::Net::HTTPResponse& response)
|
|
|
|
{
|
2021-03-20 16:24:13 -05:00
|
|
|
response.set("Server", HTTP_SERVER_STRING);
|
2019-09-06 04:56:30 -05:00
|
|
|
response.set("Date", Util::getHttpTimeNow());
|
2017-04-23 20:25:09 -05:00
|
|
|
|
|
|
|
std::ostringstream oss;
|
|
|
|
response.write(oss);
|
|
|
|
|
|
|
|
send(oss.str());
|
|
|
|
}
|
|
|
|
|
2021-03-23 21:01:46 -05:00
|
|
|
bool StreamSocket::send(const http::Response& response)
|
2021-03-21 08:25:41 -05:00
|
|
|
{
|
2021-03-23 21:01:46 -05:00
|
|
|
if (response.writeData(_outBuffer))
|
|
|
|
{
|
|
|
|
flush();
|
|
|
|
return true;
|
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
shutdown();
|
|
|
|
return false;
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
bool StreamSocket::send(http::Request& request)
|
|
|
|
{
|
2021-03-07 11:57:13 -06:00
|
|
|
if (request.writeData(_outBuffer, getSendBufferCapacity()))
|
2021-03-23 21:01:46 -05:00
|
|
|
{
|
|
|
|
flush();
|
|
|
|
return true;
|
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
shutdown();
|
|
|
|
return false;
|
|
|
|
}
|
2021-03-21 08:25:41 -05:00
|
|
|
}
|
|
|
|
|
2021-04-29 11:33:15 -05:00
|
|
|
bool StreamSocket::sendAndShutdown(http::Response& response)
|
|
|
|
{
|
|
|
|
response.set("Connection", "close");
|
|
|
|
if (send(response))
|
|
|
|
{
|
|
|
|
shutdown();
|
|
|
|
return true;
|
|
|
|
}
|
|
|
|
|
|
|
|
return false;
|
|
|
|
}
|
|
|
|
|
2017-03-12 18:03:45 -05:00
|
|
|
void SocketPoll::dumpState(std::ostream& os)
|
2017-03-03 15:18:55 -06:00
|
|
|
{
|
2017-03-12 18:03:45 -05:00
|
|
|
// FIXME: NOT thread-safe! _pollSockets is modified from the polling thread!
|
2022-02-14 06:08:27 -06:00
|
|
|
os << "\n SocketPoll:";
|
|
|
|
os << "\n Poll [" << _pollSockets.size() << "] - wakeup r: "
|
2020-05-24 08:10:18 -05:00
|
|
|
<< _wakeup[0] << " w: " << _wakeup[1] << '\n';
|
2017-03-20 12:18:41 -05:00
|
|
|
if (_newCallbacks.size() > 0)
|
2020-05-24 08:10:18 -05:00
|
|
|
os << "\tcallbacks: " << _newCallbacks.size() << '\n';
|
2017-03-12 18:03:45 -05:00
|
|
|
os << "\tfd\tevents\trsize\twsize\n";
|
2022-02-14 06:08:27 -06:00
|
|
|
for (const auto &i : _pollSockets)
|
2017-03-12 18:03:45 -05:00
|
|
|
i->dumpState(os);
|
2017-03-03 15:18:55 -06:00
|
|
|
}
|
|
|
|
|
2018-01-09 08:02:02 -06:00
|
|
|
/// Returns true on success only.
|
|
|
|
bool ServerSocket::bind(Type type, int port)
|
|
|
|
{
|
2019-02-12 05:16:40 -06:00
|
|
|
#if !MOBILEAPP
|
2018-01-09 08:02:02 -06:00
|
|
|
// Enable address reuse to avoid stalling after
|
|
|
|
// recycling, when previous socket is TIME_WAIT.
|
|
|
|
//TODO: Might be worth refactoring out.
|
|
|
|
const int reuseAddress = 1;
|
|
|
|
constexpr unsigned int len = sizeof(reuseAddress);
|
|
|
|
::setsockopt(getFD(), SOL_SOCKET, SO_REUSEADDR, &reuseAddress, len);
|
|
|
|
|
|
|
|
int rc;
|
|
|
|
|
2019-03-30 09:06:16 -05:00
|
|
|
assert (_type != Socket::Type::Unix);
|
2018-01-09 08:02:02 -06:00
|
|
|
if (_type == Socket::Type::IPv4)
|
|
|
|
{
|
|
|
|
struct sockaddr_in addrv4;
|
|
|
|
std::memset(&addrv4, 0, sizeof(addrv4));
|
|
|
|
addrv4.sin_family = AF_INET;
|
|
|
|
addrv4.sin_port = htons(port);
|
|
|
|
if (type == Type::Public)
|
2018-10-03 06:25:36 -05:00
|
|
|
addrv4.sin_addr.s_addr = htonl(INADDR_ANY);
|
2018-01-09 08:02:02 -06:00
|
|
|
else
|
2018-10-03 06:25:36 -05:00
|
|
|
addrv4.sin_addr.s_addr = htonl(INADDR_LOOPBACK);
|
2018-01-09 08:02:02 -06:00
|
|
|
|
|
|
|
rc = ::bind(getFD(), (const sockaddr *)&addrv4, sizeof(addrv4));
|
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
struct sockaddr_in6 addrv6;
|
|
|
|
std::memset(&addrv6, 0, sizeof(addrv6));
|
|
|
|
addrv6.sin6_family = AF_INET6;
|
|
|
|
addrv6.sin6_port = htons(port);
|
|
|
|
if (type == Type::Public)
|
|
|
|
addrv6.sin6_addr = in6addr_any;
|
|
|
|
else
|
|
|
|
addrv6.sin6_addr = in6addr_loopback;
|
|
|
|
|
2021-03-10 07:29:25 -06:00
|
|
|
const int ipv6only = (_type == Socket::Type::All ? 0 : 1);
|
2018-01-09 08:02:02 -06:00
|
|
|
if (::setsockopt(getFD(), IPPROTO_IPV6, IPV6_V6ONLY, (char*)&ipv6only, sizeof(ipv6only)) == -1)
|
2021-03-10 07:29:25 -06:00
|
|
|
LOG_SYS('#' << getFD() << " Failed set ipv6 socket to " << ipv6only);
|
2018-01-09 08:02:02 -06:00
|
|
|
|
|
|
|
rc = ::bind(getFD(), (const sockaddr *)&addrv6, sizeof(addrv6));
|
|
|
|
}
|
|
|
|
|
|
|
|
if (rc)
|
2021-03-10 07:29:25 -06:00
|
|
|
LOG_SYS('#' << getFD() << " Failed to bind to: "
|
|
|
|
<< (_type == Socket::Type::IPv4 ? "IPv4" : "IPv6") << " port: " << port);
|
|
|
|
else
|
|
|
|
LOG_TRC('#' << getFD() << " bind to: " << (_type == Socket::Type::IPv4 ? "IPv4" : "IPv6")
|
|
|
|
<< " port: " << port);
|
2018-01-09 08:02:02 -06:00
|
|
|
|
|
|
|
return rc == 0;
|
2018-09-13 11:16:00 -05:00
|
|
|
#else
|
|
|
|
return true;
|
|
|
|
#endif
|
2018-01-09 08:02:02 -06:00
|
|
|
}
|
|
|
|
|
2019-03-30 16:07:58 -05:00
|
|
|
std::shared_ptr<Socket> ServerSocket::accept()
|
|
|
|
{
|
|
|
|
// Accept a connection (if any) and set it to non-blocking.
|
|
|
|
// There still need the client's address to filter request from POST(call from REST) here.
|
|
|
|
#if !MOBILEAPP
|
|
|
|
assert(_type != Socket::Type::Unix);
|
|
|
|
|
|
|
|
struct sockaddr_in6 clientInfo;
|
|
|
|
socklen_t addrlen = sizeof(clientInfo);
|
|
|
|
const int rc = ::accept4(getFD(), (struct sockaddr *)&clientInfo, &addrlen, SOCK_NONBLOCK);
|
|
|
|
#else
|
|
|
|
const int rc = fakeSocketAccept4(getFD());
|
|
|
|
#endif
|
2022-02-01 12:08:37 -06:00
|
|
|
LOG_TRC("Accepted socket #" << rc << ", creating socket object.");
|
2019-03-30 16:07:58 -05:00
|
|
|
try
|
|
|
|
{
|
|
|
|
// Create a socket object using the factory.
|
|
|
|
if (rc != -1)
|
|
|
|
{
|
2021-03-13 16:21:20 -06:00
|
|
|
std::shared_ptr<Socket> _socket = createSocketFromAccept(rc);
|
2019-03-30 16:07:58 -05:00
|
|
|
|
|
|
|
#if !MOBILEAPP
|
|
|
|
char addrstr[INET6_ADDRSTRLEN];
|
|
|
|
|
|
|
|
const void *inAddr;
|
|
|
|
if (clientInfo.sin6_family == AF_INET)
|
|
|
|
{
|
|
|
|
auto ipv4 = (struct sockaddr_in *)&clientInfo;
|
|
|
|
inAddr = &(ipv4->sin_addr);
|
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
auto ipv6 = (struct sockaddr_in6 *)&clientInfo;
|
|
|
|
inAddr = &(ipv6->sin6_addr);
|
|
|
|
}
|
|
|
|
|
|
|
|
inet_ntop(clientInfo.sin6_family, inAddr, addrstr, sizeof(addrstr));
|
|
|
|
_socket->setClientAddress(addrstr);
|
|
|
|
|
wsd: reduce debug and generally redundant logs
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>
2022-02-19 07:30:26 -06:00
|
|
|
LOG_TRC("Accepted socket #" << _socket->getFD() << " has family "
|
2022-02-01 12:08:37 -06:00
|
|
|
<< clientInfo.sin6_family << " address "
|
|
|
|
<< _socket->clientAddress());
|
2019-03-30 16:07:58 -05:00
|
|
|
#endif
|
|
|
|
return _socket;
|
|
|
|
}
|
|
|
|
return std::shared_ptr<Socket>(nullptr);
|
|
|
|
}
|
|
|
|
catch (const std::exception& ex)
|
|
|
|
{
|
2020-12-24 07:58:47 -06:00
|
|
|
LOG_ERR("Failed to create client socket #" << rc << ". Error: " << ex.what());
|
2019-03-30 16:07:58 -05:00
|
|
|
}
|
|
|
|
|
|
|
|
return nullptr;
|
|
|
|
}
|
|
|
|
|
2019-03-31 06:34:24 -05:00
|
|
|
#if !MOBILEAPP
|
|
|
|
|
2019-03-30 16:07:58 -05:00
|
|
|
int Socket::getPid() const
|
|
|
|
{
|
2020-11-08 09:42:15 -06:00
|
|
|
#ifdef __linux__
|
2019-03-30 16:07:58 -05:00
|
|
|
struct ucred creds;
|
|
|
|
socklen_t credSize = sizeof(struct ucred);
|
|
|
|
if (getsockopt(_fd, SOL_SOCKET, SO_PEERCRED, &creds, &credSize) < 0)
|
|
|
|
{
|
2021-03-10 07:29:25 -06:00
|
|
|
LOG_SYS("Failed to get pid via peer creds on " << _fd);
|
2019-03-30 16:07:58 -05:00
|
|
|
return -1;
|
|
|
|
}
|
|
|
|
return creds.pid;
|
2020-11-08 09:42:15 -06:00
|
|
|
#elif defined(__FreeBSD__)
|
|
|
|
struct xucred creds;
|
|
|
|
socklen_t credSize = sizeof(struct xucred);
|
2021-04-24 03:39:13 -05:00
|
|
|
if (getsockopt(_fd, SOL_LOCAL, LOCAL_PEERCRED, &creds, &credSize) < 0)
|
2020-11-08 09:42:15 -06:00
|
|
|
{
|
2021-03-10 07:29:25 -06:00
|
|
|
LOG_SYS("Failed to get pid via peer creds on " << _fd);
|
2020-11-08 09:42:15 -06:00
|
|
|
return -1;
|
|
|
|
}
|
|
|
|
return creds.cr_pid;
|
|
|
|
#else
|
|
|
|
#error Implement for your platform
|
|
|
|
#endif
|
2019-03-30 16:07:58 -05:00
|
|
|
}
|
|
|
|
|
2020-05-07 15:11:38 -05:00
|
|
|
// Does this socket come from the localhost ?
|
|
|
|
bool Socket::isLocal() const
|
|
|
|
{
|
|
|
|
if (_clientAddress.size() < 1)
|
|
|
|
return false;
|
|
|
|
if (_clientAddress[0] == '/') // Unix socket
|
|
|
|
return true;
|
|
|
|
if (_clientAddress == "::1")
|
|
|
|
return true;
|
|
|
|
return _clientAddress.rfind("127.0.0.", 0);
|
|
|
|
}
|
|
|
|
|
2019-03-30 16:07:58 -05:00
|
|
|
std::shared_ptr<Socket> LocalServerSocket::accept()
|
|
|
|
{
|
|
|
|
const int rc = ::accept4(getFD(), nullptr, nullptr, SOCK_NONBLOCK);
|
|
|
|
try
|
|
|
|
{
|
|
|
|
LOG_DBG("Accepted prisoner socket #" << rc << ", creating socket object.");
|
|
|
|
if (rc < 0)
|
|
|
|
return std::shared_ptr<Socket>(nullptr);
|
|
|
|
|
2021-03-13 16:21:20 -06:00
|
|
|
std::shared_ptr<Socket> _socket = createSocketFromAccept(rc);
|
2019-03-30 16:07:58 -05:00
|
|
|
// Sanity check this incoming socket
|
2020-11-08 09:42:15 -06:00
|
|
|
#ifndef __FreeBSD__
|
|
|
|
#define CREDS_UID(c) c.uid
|
|
|
|
#define CREDS_GID(c) c.gid
|
|
|
|
#define CREDS_PID(c) c.pid
|
2019-03-30 16:07:58 -05:00
|
|
|
struct ucred creds;
|
|
|
|
socklen_t credSize = sizeof(struct ucred);
|
2021-04-23 04:48:21 -05:00
|
|
|
if (getsockopt(rc, SOL_SOCKET, SO_PEERCRED, &creds, &credSize) < 0)
|
2019-03-30 16:07:58 -05:00
|
|
|
{
|
2021-04-23 04:48:21 -05:00
|
|
|
LOG_SYS("Failed to get peer creds on " << rc);
|
2019-03-30 16:07:58 -05:00
|
|
|
::close(rc);
|
|
|
|
return std::shared_ptr<Socket>(nullptr);
|
|
|
|
}
|
2020-11-08 09:42:15 -06:00
|
|
|
#else
|
|
|
|
#define CREDS_UID(c) c.cr_uid
|
|
|
|
#define CREDS_GID(c) c.cr_groups[0]
|
|
|
|
#define CREDS_PID(c) c.cr_pid
|
|
|
|
struct xucred creds;
|
|
|
|
socklen_t credSize = sizeof(struct xucred);
|
2021-04-24 03:39:13 -05:00
|
|
|
if (getsockopt(rc, SOL_LOCAL, LOCAL_PEERCRED, &creds, &credSize) < 0)
|
2020-11-08 09:42:15 -06:00
|
|
|
{
|
2021-04-23 04:48:21 -05:00
|
|
|
LOG_SYS("Failed to get peer creds on " << rc);
|
2020-11-08 09:42:15 -06:00
|
|
|
::close(rc);
|
|
|
|
return std::shared_ptr<Socket>(nullptr);
|
|
|
|
}
|
|
|
|
#endif
|
2019-03-30 16:07:58 -05:00
|
|
|
|
2019-04-01 04:56:15 -05:00
|
|
|
uid_t uid = getuid();
|
|
|
|
uid_t gid = getgid();
|
2020-11-08 09:42:15 -06:00
|
|
|
if (CREDS_UID(creds) != uid || CREDS_GID(creds) != gid)
|
2019-03-30 16:07:58 -05:00
|
|
|
{
|
|
|
|
LOG_ERR("Peercred mis-match on domain socket - closing connection. uid: " <<
|
2020-11-08 09:42:15 -06:00
|
|
|
CREDS_UID(creds) << "vs." << uid << " gid: " << CREDS_GID(creds) << "vs." << gid);
|
2019-03-30 16:07:58 -05:00
|
|
|
::close(rc);
|
|
|
|
return std::shared_ptr<Socket>(nullptr);
|
|
|
|
}
|
|
|
|
std::string addr("uds-to-pid-");
|
2020-11-08 09:42:15 -06:00
|
|
|
addr.append(std::to_string(CREDS_PID(creds)));
|
2019-03-30 16:07:58 -05:00
|
|
|
_socket->setClientAddress(addr);
|
|
|
|
|
|
|
|
LOG_DBG("Accepted socket is UDS - address " << addr <<
|
2020-11-08 09:42:15 -06:00
|
|
|
" and uid/gid " << CREDS_UID(creds) << '/' << CREDS_GID(creds));
|
2019-03-30 16:07:58 -05:00
|
|
|
return _socket;
|
|
|
|
}
|
|
|
|
catch (const std::exception& ex)
|
|
|
|
{
|
2020-12-24 07:58:47 -06:00
|
|
|
LOG_ERR("Failed to create client socket #" << rc << ". Error: " << ex.what());
|
2019-03-30 16:07:58 -05:00
|
|
|
return std::shared_ptr<Socket>(nullptr);
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
2019-03-30 09:06:16 -05:00
|
|
|
/// Returns true on success only.
|
|
|
|
std::string LocalServerSocket::bind()
|
|
|
|
{
|
|
|
|
int rc;
|
|
|
|
struct sockaddr_un addrunix;
|
2020-06-12 05:19:50 -05:00
|
|
|
|
|
|
|
// snap needs a specific socket name
|
|
|
|
std::string socketAbstractUnixName(SOCKET_ABSTRACT_UNIX_NAME);
|
|
|
|
const char* snapInstanceName = std::getenv("SNAP_INSTANCE_NAME");
|
|
|
|
if (snapInstanceName && snapInstanceName[0])
|
2021-11-18 06:08:14 -06:00
|
|
|
socketAbstractUnixName = std::string("0snap.") + snapInstanceName + ".coolwsd-";
|
2020-06-12 05:19:50 -05:00
|
|
|
|
2019-03-30 09:06:16 -05:00
|
|
|
do
|
|
|
|
{
|
|
|
|
std::memset(&addrunix, 0, sizeof(addrunix));
|
|
|
|
addrunix.sun_family = AF_UNIX;
|
2020-06-12 05:19:50 -05:00
|
|
|
std::memcpy(addrunix.sun_path, socketAbstractUnixName.c_str(), socketAbstractUnixName.length());
|
2021-07-30 09:45:39 -05:00
|
|
|
#ifdef HAVE_ABSTRACT_UNIX_SOCKETS
|
2019-03-30 09:06:16 -05:00
|
|
|
addrunix.sun_path[0] = '\0'; // abstract name
|
2021-04-24 13:39:04 -05:00
|
|
|
#endif
|
2019-03-30 09:06:16 -05:00
|
|
|
|
2021-03-10 07:29:25 -06:00
|
|
|
const std::string rand = Util::rng::getFilename(8);
|
2020-06-12 05:19:50 -05:00
|
|
|
memcpy(addrunix.sun_path + socketAbstractUnixName.length(), rand.c_str(), 8);
|
2019-03-30 09:06:16 -05:00
|
|
|
|
|
|
|
rc = ::bind(getFD(), (const sockaddr *)&addrunix, sizeof(struct sockaddr_un));
|
2021-03-10 07:29:25 -06:00
|
|
|
LOG_SYS('#' << getFD() << " Bind to location " << std::string(&addrunix.sun_path[1])
|
|
|
|
<< " result - " << rc);
|
2019-03-30 09:06:16 -05:00
|
|
|
} while (rc < 0 && errno == EADDRINUSE);
|
|
|
|
|
|
|
|
if (rc >= 0)
|
2021-07-30 09:53:18 -05:00
|
|
|
{
|
|
|
|
_name = std::string(&addrunix.sun_path[0]);
|
2019-03-30 09:06:16 -05:00
|
|
|
return std::string(&addrunix.sun_path[1]);
|
2021-07-30 09:53:18 -05:00
|
|
|
}
|
2019-03-31 06:34:24 -05:00
|
|
|
|
2021-03-10 07:29:25 -06:00
|
|
|
return std::string();
|
2019-03-30 09:06:16 -05:00
|
|
|
}
|
|
|
|
|
2021-12-30 07:36:48 -06:00
|
|
|
#ifndef HAVE_ABSTRACT_UNIX_SOCKETS
|
|
|
|
bool LocalServerSocket::link(std::string to)
|
|
|
|
{
|
|
|
|
_linkName = to;
|
|
|
|
return 0 == ::link(_name.c_str(), to.c_str());
|
|
|
|
}
|
|
|
|
#endif
|
|
|
|
|
2021-07-30 09:53:18 -05:00
|
|
|
LocalServerSocket::~LocalServerSocket()
|
|
|
|
{
|
|
|
|
#ifndef HAVE_ABSTRACT_UNIX_SOCKETS
|
|
|
|
::unlink(_name.c_str());
|
2021-12-30 07:36:48 -06:00
|
|
|
if (!_linkName.empty())
|
|
|
|
::unlink(_linkName.c_str());
|
2021-07-30 09:53:18 -05:00
|
|
|
#endif
|
|
|
|
}
|
|
|
|
|
2019-05-21 21:21:50 -05:00
|
|
|
// For a verbose life, tweak here:
|
|
|
|
#if 0
|
|
|
|
# define LOG_CHUNK(X) LOG_TRC(X)
|
|
|
|
#else
|
|
|
|
# define LOG_CHUNK(X)
|
|
|
|
#endif
|
|
|
|
|
2018-05-01 08:57:17 -05:00
|
|
|
bool StreamSocket::parseHeader(const char *clientName,
|
|
|
|
Poco::MemoryInputStream &message,
|
|
|
|
Poco::Net::HTTPRequest &request,
|
2019-05-21 21:21:50 -05:00
|
|
|
MessageMap *map)
|
2018-05-01 08:57:17 -05:00
|
|
|
{
|
2019-05-21 21:21:50 -05:00
|
|
|
assert(!map || (map->_headerSize == 0 && map->_messageSize == 0));
|
2018-05-01 08:57:17 -05:00
|
|
|
|
|
|
|
// Find the end of the header, if any.
|
|
|
|
static const std::string marker("\r\n\r\n");
|
|
|
|
auto itBody = std::search(_inBuffer.begin(), _inBuffer.end(),
|
|
|
|
marker.begin(), marker.end());
|
|
|
|
if (itBody == _inBuffer.end())
|
|
|
|
{
|
2022-04-03 13:54:27 -05:00
|
|
|
LOG_TRC('#' << getFD() << ": " << clientName
|
|
|
|
<< " doesn't have enough data for the header yet.");
|
2018-05-01 08:57:17 -05:00
|
|
|
return false;
|
|
|
|
}
|
|
|
|
|
|
|
|
// Skip the marker.
|
|
|
|
itBody += marker.size();
|
2019-05-21 21:21:50 -05:00
|
|
|
if (map) // a reasonable guess so far
|
|
|
|
{
|
|
|
|
map->_headerSize = static_cast<size_t>(itBody - _inBuffer.begin());
|
|
|
|
map->_messageSize = map->_headerSize;
|
|
|
|
}
|
2018-05-01 08:57:17 -05:00
|
|
|
|
|
|
|
try
|
|
|
|
{
|
|
|
|
request.read(message);
|
|
|
|
|
|
|
|
Log::StreamLogger logger = Log::info();
|
|
|
|
if (logger.enabled())
|
|
|
|
{
|
2020-05-24 08:10:18 -05:00
|
|
|
logger << '#' << getFD() << ": " << clientName << " HTTP Request: "
|
2018-05-01 08:57:17 -05:00
|
|
|
<< request.getMethod() << ' '
|
|
|
|
<< request.getURI() << ' '
|
|
|
|
<< request.getVersion();
|
|
|
|
|
|
|
|
for (const auto& it : request)
|
|
|
|
{
|
|
|
|
logger << " / " << it.first << ": " << it.second;
|
|
|
|
}
|
|
|
|
|
2022-04-17 08:31:09 -05:00
|
|
|
LOG_END(logger);
|
2018-05-01 08:57:17 -05:00
|
|
|
}
|
|
|
|
|
|
|
|
const std::streamsize contentLength = request.getContentLength();
|
|
|
|
const auto offset = itBody - _inBuffer.begin();
|
|
|
|
const std::streamsize available = _inBuffer.size() - offset;
|
|
|
|
|
|
|
|
if (contentLength != Poco::Net::HTTPMessage::UNKNOWN_CONTENT_LENGTH && available < contentLength)
|
|
|
|
{
|
2020-11-16 20:37:17 -06:00
|
|
|
LOG_DBG('#' << getFD() << ": Not enough content yet: ContentLength: " << contentLength
|
|
|
|
<< ", available: " << available);
|
2018-05-01 08:57:17 -05:00
|
|
|
return false;
|
|
|
|
}
|
2019-05-21 21:21:50 -05:00
|
|
|
if (map)
|
|
|
|
map->_messageSize += contentLength;
|
2019-05-21 20:54:12 -05:00
|
|
|
|
2019-09-19 09:08:45 -05:00
|
|
|
const std::string expect = request.get("Expect", "");
|
2021-03-22 15:58:35 -05:00
|
|
|
const bool getExpectContinue = Util::iequal(expect, "100-continue");
|
2019-07-08 11:20:19 -05:00
|
|
|
if (getExpectContinue && !_sentHTTPContinue)
|
2019-05-21 20:54:12 -05:00
|
|
|
{
|
2020-05-24 08:10:18 -05:00
|
|
|
LOG_TRC('#' << getFD() << " got Expect: 100-continue, sending Continue");
|
2019-05-21 20:54:12 -05:00
|
|
|
// FIXME: should validate authentication headers early too.
|
|
|
|
send("HTTP/1.1 100 Continue\r\n\r\n",
|
|
|
|
sizeof("HTTP/1.1 100 Continue\r\n\r\n") - 1);
|
|
|
|
_sentHTTPContinue = true;
|
|
|
|
}
|
2019-05-21 21:21:50 -05:00
|
|
|
|
|
|
|
if (request.getChunkedTransferEncoding())
|
|
|
|
{
|
|
|
|
// keep the header
|
|
|
|
if (map)
|
|
|
|
map->_spans.push_back(std::pair<size_t, size_t>(0, itBody - _inBuffer.begin()));
|
|
|
|
|
|
|
|
int chunk = 0;
|
|
|
|
while (itBody != _inBuffer.end())
|
|
|
|
{
|
|
|
|
auto chunkStart = itBody;
|
|
|
|
|
|
|
|
// skip whitespace
|
|
|
|
for (; itBody != _inBuffer.end() && isascii(*itBody) && isspace(*itBody); ++itBody)
|
|
|
|
; // skip.
|
|
|
|
|
|
|
|
// each chunk is preceeded by its length in hex.
|
|
|
|
size_t chunkLen = 0;
|
|
|
|
for (; itBody != _inBuffer.end(); ++itBody)
|
|
|
|
{
|
|
|
|
int digit = Util::hexDigitFromChar(*itBody);
|
|
|
|
if (digit >= 0)
|
|
|
|
chunkLen = chunkLen * 16 + digit;
|
|
|
|
else
|
|
|
|
break;
|
|
|
|
}
|
|
|
|
|
|
|
|
LOG_CHUNK("Chunk of length " << chunkLen);
|
|
|
|
|
|
|
|
for (; itBody != _inBuffer.end() && *itBody != '\n'; ++itBody)
|
|
|
|
; // skip to end of line
|
|
|
|
|
|
|
|
if (itBody != _inBuffer.end())
|
|
|
|
itBody++; /* \n */;
|
|
|
|
|
|
|
|
// skip the chunk.
|
|
|
|
auto chunkOffset = itBody - _inBuffer.begin();
|
|
|
|
auto chunkAvailable = _inBuffer.size() - chunkOffset;
|
|
|
|
|
|
|
|
if (chunkLen == 0) // we're complete.
|
|
|
|
{
|
|
|
|
map->_messageSize = chunkOffset;
|
|
|
|
return true;
|
|
|
|
}
|
|
|
|
|
|
|
|
if (chunkLen > chunkAvailable + 2)
|
|
|
|
{
|
|
|
|
LOG_DBG("Not enough content yet in chunk " << chunk <<
|
|
|
|
" starting at offset " << (chunkStart - _inBuffer.begin()) <<
|
|
|
|
" chunk len: " << chunkLen << ", available: " << chunkAvailable);
|
|
|
|
return false;
|
|
|
|
}
|
|
|
|
itBody += chunkLen;
|
|
|
|
|
|
|
|
map->_spans.push_back(std::pair<size_t,size_t>(chunkOffset, chunkLen));
|
|
|
|
|
|
|
|
if (*itBody != '\r' || *(itBody + 1) != '\n')
|
|
|
|
{
|
|
|
|
LOG_ERR("Missing \\r\\n at end of chunk " << chunk << " of length " << chunkLen);
|
|
|
|
LOG_CHUNK("Chunk " << chunk << " is: \n" << Util::dumpHex("", "", chunkStart, itBody + 1, false));
|
|
|
|
return false; // TODO: throw something sensible in this case
|
|
|
|
}
|
|
|
|
else
|
|
|
|
{
|
|
|
|
LOG_CHUNK("Chunk " << chunk << " is: \n" << Util::dumpHex("", "", chunkStart, itBody + 1, false));
|
|
|
|
}
|
|
|
|
|
|
|
|
itBody+=2;
|
|
|
|
chunk++;
|
|
|
|
}
|
|
|
|
LOG_TRC("Not enough chunks yet, so far " << chunk << " chunks of total length " << (itBody - _inBuffer.begin()));
|
|
|
|
return false;
|
|
|
|
}
|
2018-05-01 08:57:17 -05:00
|
|
|
}
|
2018-05-03 10:32:31 -05:00
|
|
|
catch (const Poco::Exception& exc)
|
|
|
|
{
|
2020-11-16 20:37:17 -06:00
|
|
|
LOG_DBG('#' << getFD() << ": parseHeader exception caught with " << _inBuffer.size()
|
|
|
|
<< " bytes: " << exc.displayText());
|
2018-05-03 10:32:31 -05:00
|
|
|
// Probably don't have enough data just yet.
|
|
|
|
// TODO: timeout if we never get enough.
|
|
|
|
return false;
|
|
|
|
}
|
2018-05-01 08:57:17 -05:00
|
|
|
catch (const std::exception& exc)
|
|
|
|
{
|
2020-11-16 20:37:17 -06:00
|
|
|
LOG_DBG('#' << getFD() << ": parseHeader std::exception caught with " << _inBuffer.size()
|
|
|
|
<< " bytes: " << exc.what());
|
2018-05-01 08:57:17 -05:00
|
|
|
// Probably don't have enough data just yet.
|
|
|
|
// TODO: timeout if we never get enough.
|
|
|
|
return false;
|
|
|
|
}
|
|
|
|
|
|
|
|
return true;
|
|
|
|
}
|
|
|
|
|
2019-05-21 21:21:50 -05:00
|
|
|
bool StreamSocket::compactChunks(MessageMap *map)
|
|
|
|
{
|
|
|
|
assert (map);
|
|
|
|
if (!map->_spans.size())
|
|
|
|
return false; // single message.
|
|
|
|
|
|
|
|
LOG_CHUNK("Pre-compact " << map->_spans.size() << " chunks: \n" <<
|
|
|
|
Util::dumpHex("", "", _inBuffer.begin(), _inBuffer.end(), false));
|
|
|
|
|
|
|
|
char *first = &_inBuffer[0];
|
|
|
|
char *dest = first;
|
|
|
|
for (auto &span : map->_spans)
|
|
|
|
{
|
|
|
|
std::memmove(dest, &_inBuffer[span.first], span.second);
|
|
|
|
dest += span.second;
|
|
|
|
}
|
|
|
|
|
|
|
|
// Erase the duplicate bits.
|
|
|
|
size_t newEnd = dest - first;
|
|
|
|
size_t gap = map->_messageSize - newEnd;
|
|
|
|
_inBuffer.erase(_inBuffer.begin() + newEnd, _inBuffer.begin() + map->_messageSize);
|
|
|
|
|
|
|
|
LOG_CHUNK("Post-compact with erase of " << newEnd << " to " << map->_messageSize << " giving: \n" <<
|
|
|
|
Util::dumpHex("", "", _inBuffer.begin(), _inBuffer.end(), false));
|
|
|
|
|
|
|
|
// shrink our size to fit
|
|
|
|
map->_messageSize -= gap;
|
|
|
|
|
2021-02-24 19:25:19 -06:00
|
|
|
#if ENABLE_DEBUG
|
2021-03-11 20:10:59 -06:00
|
|
|
std::ostringstream oss;
|
|
|
|
dumpState(oss);
|
|
|
|
LOG_TRC('#' << getFD() << " Socket state: " << oss.str());
|
2021-02-24 19:25:19 -06:00
|
|
|
#endif
|
2019-05-21 21:21:50 -05:00
|
|
|
|
|
|
|
return true;
|
|
|
|
}
|
|
|
|
|
2018-11-07 11:35:46 -06:00
|
|
|
bool StreamSocket::sniffSSL() const
|
|
|
|
{
|
2019-06-14 09:35:21 -05:00
|
|
|
// Only sniffing the first bytes of a socket.
|
2018-11-07 11:35:46 -06:00
|
|
|
if (_bytesSent > 0 || _bytesRecvd != _inBuffer.size() || _bytesRecvd < 6)
|
|
|
|
return false;
|
|
|
|
|
|
|
|
// 0x0000 16 03 01 02 00 01 00 01
|
|
|
|
return (_inBuffer[0] == 0x16 && // HANDSHAKE
|
|
|
|
_inBuffer[1] == 0x03 && // SSL 3.0 / TLS 1.x
|
|
|
|
_inBuffer[5] == 0x01); // Handshake: CLIENT_HELLO
|
|
|
|
}
|
|
|
|
|
2018-09-13 11:16:00 -05:00
|
|
|
#endif // !MOBILEAPP
|
|
|
|
|
2017-03-02 12:12:52 -06:00
|
|
|
/* vim:set shiftwidth=4 softtabstop=4 expandtab: */
|