From c9aeb8896ae578515c217b9a08988156b4d62f1e Mon Sep 17 00:00:00 2001 From: Christian Mollekopf Date: Thu, 26 Mar 2015 09:44:00 +0100 Subject: Resource crashhandler and logging facilities. --- common/CMakeLists.txt | 1 + common/log.cpp | 70 +++++++++++++++++++++++++++++++++++++++++++++++ common/log.h | 17 ++++++++++++ common/resourceaccess.cpp | 5 ++-- synchronizer/listener.cpp | 62 +++++++++++++++++++++-------------------- synchronizer/listener.h | 1 - synchronizer/main.cpp | 14 ++++++++-- 7 files changed, 135 insertions(+), 35 deletions(-) create mode 100644 common/log.cpp create mode 100644 common/log.h diff --git a/common/CMakeLists.txt b/common/CMakeLists.txt index 429bad7..656f987 100644 --- a/common/CMakeLists.txt +++ b/common/CMakeLists.txt @@ -23,6 +23,7 @@ else (STORAGE_unqlite) endif (STORAGE_unqlite) set(command_SRCS + log.cpp entitybuffer.cpp clientapi.cpp commands.cpp diff --git a/common/log.cpp b/common/log.cpp new file mode 100644 index 0000000..1d93404 --- /dev/null +++ b/common/log.cpp @@ -0,0 +1,70 @@ +#include "log.h" + +#include +#include +#include +#include +#include + +class DebugStream: public QIODevice +{ +public: + QString m_location; + DebugStream() + : QIODevice() + { + open(WriteOnly); + } + virtual ~DebugStream(){}; + + bool isSequential() const { return true; } + qint64 readData(char *, qint64) { return 0; /* eof */ } + qint64 readLineData(char *, qint64) { return 0; /* eof */ } + qint64 writeData(const char *data, qint64 len) + { + const QByteArray buf = QByteArray::fromRawData(data, len); + // if (!qgetenv("IMAP_TRACE").isEmpty()) { + // qt_message_output(QtDebugMsg, buf.trimmed().constData()); + std::cout << buf.trimmed().constData() << std::endl; + // } + return len; + } +private: + Q_DISABLE_COPY(DebugStream) +}; + +QDebug debugStream(DebugLevel debugLevel, int line, const char* file, const char* function) +{ + static DebugStream stream; + QDebug debug(&stream); + + static QByteArray programName; + if (programName.isEmpty()) { + if (QCoreApplication::instance()) + programName = QCoreApplication::instance()->applicationName().toLocal8Bit(); + else + programName = ""; + } + + QString prefix; + switch (debugLevel) { + case DebugLevel::Trace: + prefix = "Trace:"; + break; + case DebugLevel::Log: + prefix = "Log:"; + break; + case DebugLevel::Warning: + prefix = "Warning:"; + break; + case DebugLevel::Error: + prefix = "Error:"; + break; + default: + break; + }; + + debug << prefix + QString(" %1(%2) %3:").arg(QString::fromLatin1(programName)).arg(unsigned(getpid())).arg(function) /* << file << ":" << line */; + + return debug; +} diff --git a/common/log.h b/common/log.h new file mode 100644 index 0000000..8d3dc75 --- /dev/null +++ b/common/log.h @@ -0,0 +1,17 @@ +#pragma once + +#include + +enum DebugLevel { + Trace, + Log, + Warning, + Error +}; + +QDebug debugStream(DebugLevel debugLevel, int line, const char* file, const char* function); + +#define Trace() debugStream(DebugLevel::Trace, __LINE__, __FILE__, Q_FUNC_INFO) +#define Log() debugStream(DebugLevel::Log, __LINE__, __FILE__, Q_FUNC_INFO) +#define Warning() debugStream(DebugLevel::Warning, __LINE__, __FILE__, Q_FUNC_INFO) +#define Error() debugStream(DebugLevel::Error, __LINE__, __FILE__, Q_FUNC_INFO) diff --git a/common/resourceaccess.cpp b/common/resourceaccess.cpp index ffe716b..59cbece 100644 --- a/common/resourceaccess.cpp +++ b/common/resourceaccess.cpp @@ -20,12 +20,12 @@ #include "resourceaccess.h" -#include "common/console.h" #include "common/commands.h" #include "common/commandcompletion_generated.h" #include "common/handshake_generated.h" #include "common/revisionupdate_generated.h" #include "common/synchronize_generated.h" +#include "log.h" #include #include @@ -343,8 +343,7 @@ void ResourceAccess::callCallbacks(int id) void ResourceAccess::log(const QString &message) { - qDebug() << d->resourceName + ": " + message; - // Console::main()->log(d->resourceName + ": " + message); + Log() << d->resourceName + ": " + message; } } diff --git a/synchronizer/listener.cpp b/synchronizer/listener.cpp index d191bb8..2bc6be0 100644 --- a/synchronizer/listener.cpp +++ b/synchronizer/listener.cpp @@ -23,6 +23,7 @@ #include "common/console.h" #include "common/commands.h" #include "common/resource.h" +#include "common/log.h" // commands #include "common/commandcompletion_generated.h" @@ -46,18 +47,18 @@ Listener::Listener(const QString &resourceName, QObject *parent) this, &Listener::refreshRevision); connect(m_server, &QLocalServer::newConnection, this, &Listener::acceptConnection); - log(QString("Trying to open %1").arg(resourceName)); + Log() << QString("Trying to open %1").arg(resourceName); if (!m_server->listen(resourceName)) { // FIXME: multiple starts need to be handled here m_server->removeServer(resourceName); if (!m_server->listen(resourceName)) { - log("Utter failure to start server"); + Warning() << "Utter failure to start server"; exit(-1); } } if (m_server->isListening()) { - log(QString("Listening on %1").arg(m_server->serverName())); + Log() << QString("Listening on %1").arg(m_server->serverName()); } m_checkConnectionsTimer = new QTimer; @@ -65,7 +66,7 @@ Listener::Listener(const QString &resourceName, QObject *parent) m_checkConnectionsTimer->setInterval(1000); connect(m_checkConnectionsTimer, &QTimer::timeout, [this]() { if (m_connections.isEmpty()) { - log(QString("No connections, shutting down.")); + Log() << QString("No connections, shutting down."); m_server->close(); emit noClients(); } @@ -98,14 +99,14 @@ void Listener::closeAllConnections() void Listener::acceptConnection() { - log(QString("Accepting connection")); + Log() << QString("Accepting connection"); QLocalSocket *socket = m_server->nextPendingConnection(); if (!socket) { return; } - log("Got a connection"); + Log() << "Got a connection"; Client client("Unknown Client", socket); connect(socket, &QIODevice::readyRead, this, &Listener::readFromSocket); @@ -123,16 +124,20 @@ void Listener::clientDropped() return; } - log("Dropping connection..."); + bool dropped = false; QMutableVectorIterator it(m_connections); while (it.hasNext()) { const Client &client = it.next(); if (client.socket == socket) { - log(QString(" dropped... %1").arg(client.name)); + dropped = true; + Log() << QString("Dropped connection: %1").arg(client.name) << socket; it.remove(); break; } } + if (!dropped) { + Warning() << "Failed to find connection for disconnected socket: " << socket; + } checkConnections(); } @@ -149,7 +154,7 @@ void Listener::readFromSocket() return; } - log("Reading from socket..."); + Log() << "Reading from socket..."; for (Client &client: m_connections) { if (client.socket == socket) { client.commandBuffer += socket->readAll(); @@ -193,7 +198,7 @@ void Listener::processCommand(int commandId, uint messageId, Client &client, uin client.name = buffer->name()->c_str(); sendCurrentRevision(client); } else { - qWarning() << "received invalid command"; + Warning() << "received invalid command"; } break; } @@ -201,10 +206,10 @@ void Listener::processCommand(int commandId, uint messageId, Client &client, uin flatbuffers::Verifier verifier((const uint8_t *)client.commandBuffer.constData(), size); if (Akonadi2::VerifySynchronizeBuffer(verifier)) { auto buffer = Akonadi2::GetSynchronize(client.commandBuffer.constData()); - log(QString("\tSynchronize request (id %1) from %2").arg(messageId).arg(client.name)); + Log() << QString("\tSynchronize request (id %1) from %2").arg(messageId).arg(client.name); loadResource(); if (!m_resource) { - qWarning() << "No resource loaded"; + Warning() << "No resource loaded"; break; } //TODO a more elegant composition of jobs should be possible @@ -229,7 +234,7 @@ void Listener::processCommand(int commandId, uint messageId, Client &client, uin } return; } else { - qWarning() << "received invalid command"; + Warning() << "received invalid command"; } break; } @@ -237,14 +242,14 @@ void Listener::processCommand(int commandId, uint messageId, Client &client, uin case Akonadi2::Commands::DeleteEntityCommand: case Akonadi2::Commands::ModifyEntityCommand: case Akonadi2::Commands::CreateEntityCommand: - log(QString("\tCommand id %1 of type %2 from %3").arg(messageId).arg(commandId).arg(client.name)); + Log() << QString("\tCommand id %1 of type %2 from %3").arg(messageId).arg(commandId).arg(client.name); loadResource(); if (m_resource) { m_resource->processCommand(commandId, client.commandBuffer, size, m_pipeline); } break; case Akonadi2::Commands::ShutdownCommand: - log(QString("\tReceived shutdown command from %1").arg(client.name)); + Log() << QString("\tReceived shutdown command from %1").arg(client.name); callback(); m_server->close(); emit noClients(); @@ -279,10 +284,15 @@ bool Listener::processClientBuffer(Client &client) if (size <= uint(client.commandBuffer.size() - headerSize)) { client.commandBuffer.remove(0, headerSize); - processCommand(commandId, messageId, client, size, [this, messageId, commandId, &client]() { - log(QString("\tCompleted command messageid %1 of type %2 from %3").arg(messageId).arg(commandId).arg(client.name)); - //FIXME, client needs to become a shared pointer and not a reference, or we have to search through m_connections everytime. - sendCommandCompleted(client, messageId); + auto socket = QPointer(client.socket); + auto clientName = client.name; + processCommand(commandId, messageId, client, size, [this, messageId, commandId, socket, clientName]() { + Log() << QString("\tCompleted command messageid %1 of type %2 from %3").arg(messageId).arg(commandId).arg(clientName); + if (socket) { + sendCommandCompleted(socket.data(), messageId); + } else { + Log() << QString("Socket became invalid before we could send a response. client: %1").arg(clientName); + } }); client.commandBuffer.remove(0, size); @@ -346,21 +356,15 @@ void Listener::loadResource() Akonadi2::ResourceFactory *resourceFactory = Akonadi2::ResourceFactory::load(m_resourceName); if (resourceFactory) { m_resource = resourceFactory->createResource(); - log(QString("Resource factory: %1").arg((qlonglong)resourceFactory)); - log(QString("\tResource: %1").arg((qlonglong)m_resource)); + Log() << QString("Resource factory: %1").arg((qlonglong)resourceFactory); + Log() << QString("\tResource: %1").arg((qlonglong)m_resource); //TODO: this doesn't really list all the facades .. fix - log(QString("\tFacades: %1").arg(Akonadi2::FacadeFactory::instance().getFacade(m_resourceName)->type())); + Log() << QString("\tFacades: %1").arg(Akonadi2::FacadeFactory::instance().getFacade(m_resourceName)->type()); m_resource->configurePipeline(m_pipeline); } else { - log(QString("Failed to load resource %1").arg(m_resourceName)); + Warning() << QString("Failed to load resource %1").arg(m_resourceName); } //TODO: on failure ... what? //Enter broken state? } -void Listener::log(const QString &message) -{ - qDebug() << "Listener: " << message; - // Akonadi2::Console::main()->log("Listener: " + message); -} - diff --git a/synchronizer/listener.h b/synchronizer/listener.h index f1241c7..ee73766 100644 --- a/synchronizer/listener.h +++ b/synchronizer/listener.h @@ -82,7 +82,6 @@ private: void sendCommandCompleted(Client &client, uint messageId); void updateClientsWithRevision(); void loadResource(); - void log(const QString &); QLocalServer *m_server; QVector m_connections; diff --git a/synchronizer/main.cpp b/synchronizer/main.cpp index 86e1497..587f96a 100644 --- a/synchronizer/main.cpp +++ b/synchronizer/main.cpp @@ -19,15 +19,25 @@ #include -#include "common/console.h" +#include + #include "listener.h" +#include "log.h" + +void crashHandler(int sig) { + std::fprintf(stderr, "Error: signal %d\n", sig); + std::system("exec xterm -e gdb -p \"$PPID\""); + std::abort(); +} int main(int argc, char *argv[]) { + //For crashes + signal(SIGSEGV, crashHandler); QApplication app(argc, argv); if (argc < 2) { - qWarning() << "Not enough args passed, no resource loaded."; + Warning() << "Not enough args passed, no resource loaded."; return app.exec(); } -- cgit v1.2.3