5 files changed, 35 insertions, 38 deletions

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<qint64> 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<QTime>::create();
                 timer->start();
                 auto job = KAsync::null<void>();
@@ -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<qint64> Pipeline::newEntity(void const *command, size_t size)
 {
-    Trace() << "Pipeline: New Entity";
     d->transactionItemCount++;
 
     {
@@ -159,19 +159,6 @@ KAsync::Job<qint64> Pipeline::newEntity(void const *command, size_t size)
 
     const bool replayToSource = createEntity->replayToSource();
     const QByteArray bufferType = QByteArray(reinterpret_cast<char const *>(createEntity->domainType()->Data()), createEntity->domainType()->size());
-    {
-        flatbuffers::Verifier verifyer(reinterpret_cast<const uint8_t *>(createEntity->delta()->Data()), createEntity->delta()->size());
-        if (!VerifyEntityBuffer(verifyer)) {
-            Warning() << "invalid buffer, not an entity buffer";
-            return KAsync::error<qint64>(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<qint64>(0);
-    }
-
     QByteArray key;
     if (createEntity->entityId()) {
         key = QByteArray(reinterpret_cast<char const *>(createEntity->entityId()->Data()), createEntity->entityId()->size());
@@ -184,8 +171,22 @@ KAsync::Job<qint64> 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<const uint8_t *>(createEntity->delta()->Data()), createEntity->delta()->size());
+        if (!VerifyEntityBuffer(verifyer)) {
+            Warning() << "invalid buffer, not an entity buffer";
+            return KAsync::error<qint64>(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<qint64>(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<qint64> Pipeline::newEntity(void const *command, size_t size)
 
     d->storeNewRevision(newRevision, fbb, bufferType, key);
 
-    Log() << "Pipeline: wrote entity: " << key << newRevision << bufferType;
     return KAsync::start<qint64>([newRevision]() { return newRevision; });
 }
 
 KAsync::Job<qint64> Pipeline::modifiedEntity(void const *command, size_t size)
 {
-    Trace() << "Pipeline: Modified Entity";
     d->transactionItemCount++;
 
     {
@@ -240,9 +239,9 @@ KAsync::Job<qint64> 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<char const *>(modifyEntity->domainType()->Data()), modifyEntity->domainType()->size());
     const QByteArray key = QByteArray(reinterpret_cast<char const *>(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<qint64>(0);
@@ -328,13 +327,11 @@ KAsync::Job<qint64> 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<qint64>([newRevision]() { return newRevision; });
 }
 
 KAsync::Job<qint64> Pipeline::deletedEntity(void const *command, size_t size)
 {
-    Trace() << "Pipeline: Deleted Entity";
     d->transactionItemCount++;
 
     {
@@ -349,6 +346,7 @@ KAsync::Job<qint64> Pipeline::deletedEntity(void const *command, size_t size)
     const bool replayToSource = deleteEntity->replayToSource();
     const QByteArray bufferType = QByteArray(reinterpret_cast<char const *>(deleteEntity->domainType()->Data()), deleteEntity->domainType()->size());
     const QByteArray key = QByteArray(reinterpret_cast<char const *>(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<qint64> 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<void> 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<QueuedCommand> &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
diff --git a/examples/imapresource/imapresource.cpp b/examples/imapresource/imapresource.cpp
index e01461d..a97f860 100644
--- a/examples/imapresource/imapresource.cpp
+++ b/examples/imapresource/imapresource.cpp
@@ -650,7 +650,7 @@ KAsync::Job<void> ImapResource::inspect(int inspectionType, const QByteArray &in
         const auto folder = entityStore->read<Sink::ApplicationDomain::Folder>(entityId);
 
         if (inspectionType == Sink::ResourceControl::Inspection::CacheIntegrityInspectionType) {
-            Warning() << "Inspecting cache integrity" << remoteId;
+            Log() << "Inspecting cache integrity" << remoteId;
 
             int expectedCount = 0;
             Index index("mail.index.folder", transaction);