From 22eee9e798f00f9e58d1dc0f1b893abee2582ba2 Mon Sep 17 00:00:00 2001 From: Christian Mollekopf Date: Mon, 20 Jun 2016 18:20:38 +0200 Subject: Made the log-level output a lot less noisy --- common/genericresource.cpp | 2 +- common/listener.cpp | 18 +++++++++--------- common/pipeline.cpp | 39 ++++++++++++++++++--------------------- common/resourceaccess.cpp | 12 ++++++------ 4 files changed, 34 insertions(+), 37 deletions(-) (limited to 'common') diff --git a/common/genericresource.cpp b/common/genericresource.cpp index d43eff7..c06c22a 100644 --- a/common/genericresource.cpp +++ b/common/genericresource.cpp @@ -114,7 +114,7 @@ private slots: KAsync::Job processQueuedCommand(const Sink::QueuedCommand *queuedCommand) { - Log() << "Processing command: " << Sink::Commands::name(queuedCommand->commandId()); + Trace() << "Processing command: " << Sink::Commands::name(queuedCommand->commandId()); // Throw command into appropriate pipeline switch (queuedCommand->commandId()) { case Sink::Commands::DeleteEntityCommand: diff --git a/common/listener.cpp b/common/listener.cpp index 6cbf40f..cb974cf 100644 --- a/common/listener.cpp +++ b/common/listener.cpp @@ -120,7 +120,7 @@ void Listener::closeAllConnections() void Listener::acceptConnection() { - Log() << "Accepting connection"; + Trace() << "Accepting connection"; QLocalSocket *socket = m_server->nextPendingConnection(); if (!socket) { @@ -239,7 +239,7 @@ void Listener::processCommand(int commandId, uint messageId, const QByteArray &c flatbuffers::Verifier verifier((const uint8_t *)commandBuffer.constData(), commandBuffer.size()); if (Sink::Commands::VerifySynchronizeBuffer(verifier)) { auto buffer = Sink::Commands::GetSynchronize(commandBuffer.constData()); - Log() << QString("\tSynchronize request (id %1) from %2").arg(messageId).arg(client.name); + Trace() << QString("Synchronize request (id %1) from %2").arg(messageId).arg(client.name); auto timer = QSharedPointer::create(); timer->start(); auto job = KAsync::null(); @@ -268,20 +268,20 @@ void Listener::processCommand(int commandId, uint messageId, const QByteArray &c case Sink::Commands::DeleteEntityCommand: case Sink::Commands::ModifyEntityCommand: case Sink::Commands::CreateEntityCommand: - Log() << "\tCommand id " << messageId << " of type \"" << Sink::Commands::name(commandId) << "\" from " << client.name; + Trace() << "Command id " << messageId << " of type \"" << Sink::Commands::name(commandId) << "\" from " << client.name; loadResource()->processCommand(commandId, commandBuffer); break; case Sink::Commands::ShutdownCommand: - Log() << QString("\tReceived shutdown command from %1").arg(client.name); + Log() << QString("Received shutdown command from %1").arg(client.name); // Immediately reject new connections m_server->close(); QTimer::singleShot(0, this, &Listener::quit); break; case Sink::Commands::PingCommand: - Log() << QString("\tReceived ping command from %1").arg(client.name); + Trace() << QString("Received ping command from %1").arg(client.name); break; case Sink::Commands::RevisionReplayedCommand: { - Log() << QString("\tReceived revision replayed command from %1").arg(client.name); + Trace() << QString("Received revision replayed command from %1").arg(client.name); flatbuffers::Verifier verifier((const uint8_t *)commandBuffer.constData(), commandBuffer.size()); if (Sink::Commands::VerifyRevisionReplayedBuffer(verifier)) { auto buffer = Sink::Commands::GetRevisionReplayed(commandBuffer.constData()); @@ -292,7 +292,7 @@ void Listener::processCommand(int commandId, uint messageId, const QByteArray &c loadResource()->setLowerBoundRevision(lowerBoundRevision()); } break; case Sink::Commands::RemoveFromDiskCommand: { - Log() << QString("\tReceived a remove from disk command from %1").arg(client.name); + Log() << QString("Received a remove from disk command from %1").arg(client.name); m_resource->removeDataFromDisk(); delete m_resource; m_resource = nullptr; @@ -300,7 +300,7 @@ void Listener::processCommand(int commandId, uint messageId, const QByteArray &c } break; default: if (commandId > Sink::Commands::CustomCommand) { - Log() << QString("\tReceived custom command from %1: ").arg(client.name) << commandId; + Log() << QString("Received custom command from %1: ").arg(client.name) << commandId; loadResource()->processCommand(commandId, commandBuffer); } else { success = false; @@ -365,7 +365,7 @@ bool Listener::processClientBuffer(Client &client) const QByteArray commandBuffer = client.commandBuffer.left(size); client.commandBuffer.remove(0, size); processCommand(commandId, messageId, commandBuffer, client, [this, messageId, commandId, socket, clientName](bool success) { - Log() << QString("\tCompleted command messageid %1 of type \"%2\" from %3").arg(messageId).arg(QString(Sink::Commands::name(commandId))).arg(clientName); + Trace() << QString("Completed command messageid %1 of type \"%2\" from %3").arg(messageId).arg(QString(Sink::Commands::name(commandId))).arg(clientName); if (socket) { sendCommandCompleted(socket.data(), messageId, success); } else { diff --git a/common/pipeline.cpp b/common/pipeline.cpp index 63a60ce..9813f60 100644 --- a/common/pipeline.cpp +++ b/common/pipeline.cpp @@ -63,6 +63,7 @@ public: void Pipeline::Private::storeNewRevision(qint64 newRevision, const flatbuffers::FlatBufferBuilder &fbb, const QByteArray &bufferType, const QByteArray &uid) { + Trace() << "Committing new revision: " << uid << newRevision; Storage::mainDatabase(transaction, bufferType) .write(Storage::assembleKey(uid, newRevision), BufferUtils::extractBuffer(fbb), [uid, newRevision](const Storage::Error &error) { Warning() << "Failed to write entity" << uid << newRevision; }); @@ -121,7 +122,7 @@ void Pipeline::commit() // } const auto revision = Storage::maxRevision(d->transaction); const auto elapsed = d->transactionTime.elapsed(); - Trace() << "Committing revision: " << revision << ":" << d->transactionItemCount << " items in: " << Log::TraceTime(elapsed) << " " + Log() << "Committing revision: " << revision << ":" << d->transactionItemCount << " items in: " << Log::TraceTime(elapsed) << " " << (double)elapsed / (double)qMax(d->transactionItemCount, 1) << "[ms/item]"; if (d->transaction) { d->transaction.commit(); @@ -145,7 +146,6 @@ Storage &Pipeline::storage() const KAsync::Job Pipeline::newEntity(void const *command, size_t size) { - Trace() << "Pipeline: New Entity"; d->transactionItemCount++; { @@ -159,19 +159,6 @@ KAsync::Job Pipeline::newEntity(void const *command, size_t size) const bool replayToSource = createEntity->replayToSource(); const QByteArray bufferType = QByteArray(reinterpret_cast(createEntity->domainType()->Data()), createEntity->domainType()->size()); - { - flatbuffers::Verifier verifyer(reinterpret_cast(createEntity->delta()->Data()), createEntity->delta()->size()); - if (!VerifyEntityBuffer(verifyer)) { - Warning() << "invalid buffer, not an entity buffer"; - return KAsync::error(0); - } - } - auto entity = GetEntity(createEntity->delta()->Data()); - if (!entity->resource()->size() && !entity->local()->size()) { - Warning() << "No local and no resource buffer while trying to create entity."; - return KAsync::error(0); - } - QByteArray key; if (createEntity->entityId()) { key = QByteArray(reinterpret_cast(createEntity->entityId()->Data()), createEntity->entityId()->size()); @@ -184,8 +171,22 @@ KAsync::Job Pipeline::newEntity(void const *command, size_t size) if (key.isEmpty()) { key = Sink::Storage::generateUid(); } + Log() << "New Entity. Type: " << bufferType << "uid: "<< key << " replayToSource: " << replayToSource; Q_ASSERT(!key.isEmpty()); + { + flatbuffers::Verifier verifyer(reinterpret_cast(createEntity->delta()->Data()), createEntity->delta()->size()); + if (!VerifyEntityBuffer(verifyer)) { + Warning() << "invalid buffer, not an entity buffer"; + return KAsync::error(0); + } + } + auto entity = GetEntity(createEntity->delta()->Data()); + if (!entity->resource()->size() && !entity->local()->size()) { + Warning() << "No local and no resource buffer while trying to create entity."; + return KAsync::error(0); + } + auto adaptorFactory = Sink::AdaptorFactoryRegistry::instance().getFactory(d->resourceType, bufferType); if (!adaptorFactory) { Warning() << "no adaptor factory for type " << bufferType; @@ -214,13 +215,11 @@ KAsync::Job Pipeline::newEntity(void const *command, size_t size) d->storeNewRevision(newRevision, fbb, bufferType, key); - Log() << "Pipeline: wrote entity: " << key << newRevision << bufferType; return KAsync::start([newRevision]() { return newRevision; }); } KAsync::Job Pipeline::modifiedEntity(void const *command, size_t size) { - Trace() << "Pipeline: Modified Entity"; d->transactionItemCount++; { @@ -240,9 +239,9 @@ KAsync::Job Pipeline::modifiedEntity(void const *command, size_t size) } const qint64 baseRevision = modifyEntity->revision(); const bool replayToSource = modifyEntity->replayToSource(); - // TODO rename modifyEntity->domainType to bufferType const QByteArray bufferType = QByteArray(reinterpret_cast(modifyEntity->domainType()->Data()), modifyEntity->domainType()->size()); const QByteArray key = QByteArray(reinterpret_cast(modifyEntity->entityId()->Data()), modifyEntity->entityId()->size()); + Log() << "Modified Entity. Type: " << bufferType << "uid: "<< key << " replayToSource: " << replayToSource; if (bufferType.isEmpty() || key.isEmpty()) { Warning() << "entity type or key " << bufferType << key; return KAsync::error(0); @@ -328,13 +327,11 @@ KAsync::Job Pipeline::modifiedEntity(void const *command, size_t size) adaptorFactory->createBuffer(newAdaptor, fbb, metadataFbb.GetBufferPointer(), metadataFbb.GetSize()); d->storeNewRevision(newRevision, fbb, bufferType, key); - Log() << "Pipeline: modified entity: " << key << newRevision << bufferType; return KAsync::start([newRevision]() { return newRevision; }); } KAsync::Job Pipeline::deletedEntity(void const *command, size_t size) { - Trace() << "Pipeline: Deleted Entity"; d->transactionItemCount++; { @@ -349,6 +346,7 @@ KAsync::Job Pipeline::deletedEntity(void const *command, size_t size) const bool replayToSource = deleteEntity->replayToSource(); const QByteArray bufferType = QByteArray(reinterpret_cast(deleteEntity->domainType()->Data()), deleteEntity->domainType()->size()); const QByteArray key = QByteArray(reinterpret_cast(deleteEntity->entityId()->Data()), deleteEntity->entityId()->size()); + Log() << "Deleted Entity. Type: " << bufferType << "uid: "<< key << " replayToSource: " << replayToSource; bool found = false; bool alreadyRemoved = false; @@ -411,7 +409,6 @@ KAsync::Job Pipeline::deletedEntity(void const *command, size_t size) [this](const Storage::Error &error) { ErrorMsg() << "Failed to find value in pipeline: " << error.message; }); d->storeNewRevision(newRevision, fbb, bufferType, key); - Log() << "Pipeline: deleted entity: " << newRevision; for (auto processor : d->processors[bufferType]) { processor->deletedEntity(key, newRevision, *current, d->transaction); diff --git a/common/resourceaccess.cpp b/common/resourceaccess.cpp index 5ad2018..d3bd85f 100644 --- a/common/resourceaccess.cpp +++ b/common/resourceaccess.cpp @@ -230,7 +230,7 @@ KAsync::Job ResourceAccess::Private::initializeSocket() ResourceAccess::ResourceAccess(const QByteArray &resourceInstanceIdentifier, const QByteArray &resourceType) : ResourceAccessInterface(), d(new Private(resourceType, resourceInstanceIdentifier, this)) { - Log() << "Starting access"; + Trace() << "Starting access"; } ResourceAccess::~ResourceAccess() @@ -415,7 +415,7 @@ void ResourceAccess::sendCommand(const QSharedPointer &command) // TODO: we should have a timeout for commands d->messageId++; const auto messageId = d->messageId; - Log() << QString("Sending command \"%1\" with messageId %2").arg(QString(Sink::Commands::name(command->commandId))).arg(d->messageId); + Trace() << QString("Sending command \"%1\" with messageId %2").arg(QString(Sink::Commands::name(command->commandId))).arg(d->messageId); Q_ASSERT(command->callback); registerCallback(d->messageId, [this, messageId, command](int errorCode, QString errorMessage) { Trace() << "Command complete " << messageId; @@ -456,7 +456,7 @@ void ResourceAccess::connected() return; } - Log() << QString("Connected: %1").arg(d->socket->fullServerName()); + Trace() << QString("Connected: %1").arg(d->socket->fullServerName()); { flatbuffers::FlatBufferBuilder fbb; @@ -533,7 +533,7 @@ bool ResourceAccess::processMessageBuffer() switch (commandId) { case Commands::RevisionUpdateCommand: { auto buffer = Commands::GetRevisionUpdate(d->partialMessageBuffer.constData() + headerSize); - Log() << QString("Revision updated to: %1").arg(buffer->revision()); + Trace() << QString("Revision updated to: %1").arg(buffer->revision()); Notification n; n.type = Sink::Commands::NotificationType::NotificationType_RevisionUpdate; emit notification(n); @@ -543,7 +543,7 @@ bool ResourceAccess::processMessageBuffer() } case Commands::CommandCompletionCommand: { auto buffer = Commands::GetCommandCompletion(d->partialMessageBuffer.constData() + headerSize); - Log() << QString("Command with messageId %1 completed %2").arg(buffer->id()).arg(buffer->success() ? "sucessfully" : "unsuccessfully"); + Trace() << QString("Command with messageId %1 completed %2").arg(buffer->id()).arg(buffer->success() ? "sucessfully" : "unsuccessfully"); d->completeCommands.insert(buffer->id(), buffer->success()); // The callbacks can result in this object getting destroyed directly, so we need to ensure we finish our work first @@ -558,7 +558,7 @@ bool ResourceAccess::processMessageBuffer() close(); break; case Sink::Commands::NotificationType::NotificationType_Inspection: { - Log() << "Received inspection notification."; + Trace() << "Received inspection notification."; Notification n; if (buffer->identifier()) { // Don't use fromRawData, the buffer is gone once we invoke emit notification -- cgit v1.2.3