From da2b049e248c1ad7efeb53685158a205335e4e36 Mon Sep 17 00:00:00 2001 From: Christian Mollekopf Date: Thu, 7 Jul 2016 22:23:49 +0200 Subject: A new debug system. Instead of a single #define as debug area the new system allows for an identifier for each debug message with the structure component.area. The component is a dot separated identifier of the runtime component, such as the process or the plugin. The area is the code component, and can be as such defined at compiletime. The idea of this system is that it becomes possible to i.e. look at the output of all messages in the query subsystem of a specific resource (something that happens in the client process, but in the resource-specific subcomponent). The new macros are supposed to be less likely to clash with other names, hence the new names. --- common/changereplay.cpp | 27 +++++----- common/configstore.cpp | 8 +-- common/domain/applicationdomaintype.cpp | 8 +-- common/domain/folder.cpp | 4 +- common/domain/mail.cpp | 4 +- common/domainadaptor.h | 15 +++--- common/entityreader.cpp | 50 +++++++++--------- common/facade.cpp | 9 ++-- common/facade.h | 3 ++ common/genericresource.cpp | 44 +++++++-------- common/genericresource.h | 3 ++ common/index.cpp | 9 ++-- common/index.h | 2 + common/listener.cpp | 65 +++++++++++------------ common/listener.h | 2 + common/log.cpp | 45 +++++++++------- common/log.h | 25 +++++---- common/mailpreprocessor.cpp | 18 ++++--- common/messagequeue.cpp | 6 ++- common/modelresult.cpp | 19 ++++--- common/pipeline.cpp | 71 ++++++++++++------------- common/queryrunner.cpp | 41 +++++++------- common/queryrunner.h | 4 +- common/remoteidmap.cpp | 4 +- common/resourceaccess.cpp | 94 ++++++++++++++++----------------- common/resourceaccess.h | 4 ++ common/resourcecontrol.cpp | 21 ++++---- common/resourcefacade.cpp | 18 ++++--- common/sourcewriteback.cpp | 24 +++++---- common/specialpurposepreprocessor.cpp | 4 +- common/storage_common.cpp | 12 +++-- common/storage_lmdb.cpp | 28 +++++----- common/store.cpp | 55 ++++++++++--------- common/synchronizer.cpp | 38 ++++++------- common/test.cpp | 10 ++-- common/typeindex.cpp | 21 ++++---- 36 files changed, 420 insertions(+), 395 deletions(-) (limited to 'common') diff --git a/common/changereplay.cpp b/common/changereplay.cpp index 78c0ff5..99bbaab 100644 --- a/common/changereplay.cpp +++ b/common/changereplay.cpp @@ -26,13 +26,12 @@ using namespace Sink; -#undef DEBUG_AREA -#define DEBUG_AREA "resource.changereplay" +SINK_DEBUG_AREA("changereplay"); ChangeReplay::ChangeReplay(const QByteArray &resourceName) : mStorage(storageLocation(), resourceName, Storage::ReadOnly), mChangeReplayStore(storageLocation(), resourceName + ".changereplay", Storage::ReadWrite), mReplayInProgress(false) { - Trace() << "Created change replay: " << resourceName; + SinkTrace() << "Created change replay: " << resourceName; } qint64 ChangeReplay::getLastReplayedRevision() @@ -51,10 +50,10 @@ qint64 ChangeReplay::getLastReplayedRevision() bool ChangeReplay::allChangesReplayed() { const qint64 topRevision = Storage::maxRevision(mStorage.createTransaction(Storage::ReadOnly, [](const Sink::Storage::Error &error) { - Warning() << error.message; + SinkWarning() << error.message; })); const qint64 lastReplayedRevision = getLastReplayedRevision(); - Trace() << "All changes replayed " << topRevision << lastReplayedRevision; + SinkTrace() << "All changes replayed " << topRevision << lastReplayedRevision; return (lastReplayedRevision >= topRevision); } @@ -62,10 +61,10 @@ KAsync::Job ChangeReplay::replayNextRevision() { mReplayInProgress = true; auto mainStoreTransaction = mStorage.createTransaction(Storage::ReadOnly, [](const Sink::Storage::Error &error) { - Warning() << error.message; + SinkWarning() << error.message; }); auto replayStoreTransaction = mChangeReplayStore.createTransaction(Storage::ReadOnly, [](const Sink::Storage::Error &error) { - Warning() << error.message; + SinkWarning() << error.message; }); qint64 lastReplayedRevision = 0; replayStoreTransaction.openDatabase().scan("lastReplayedRevision", @@ -78,14 +77,14 @@ KAsync::Job ChangeReplay::replayNextRevision() auto recordReplayedRevision = [this](qint64 revision) { auto replayStoreTransaction = mChangeReplayStore.createTransaction(Storage::ReadWrite, [](const Sink::Storage::Error &error) { - Warning() << error.message; + SinkWarning() << error.message; }); replayStoreTransaction.openDatabase().write("lastReplayedRevision", QByteArray::number(revision)); replayStoreTransaction.commit(); }; if (lastReplayedRevision < topRevision) { - Trace() << "Changereplay from " << lastReplayedRevision << " to " << topRevision; + SinkTrace() << "Changereplay from " << lastReplayedRevision << " to " << topRevision; emit replayingChanges(); qint64 revision = lastReplayedRevision + 1; const auto uid = Storage::getUidFromRevision(mainStoreTransaction, revision); @@ -95,25 +94,25 @@ KAsync::Job ChangeReplay::replayNextRevision() Storage::mainDatabase(mainStoreTransaction, type) .scan(key, [&lastReplayedRevision, type, this, &replayJob](const QByteArray &key, const QByteArray &value) -> bool { - Trace() << "Replaying " << key; + SinkTrace() << "Replaying " << key; replayJob = replay(type, key, value); return false; }, - [key](const Storage::Error &) { ErrorMsg() << "Failed to replay change " << key; }); + [key](const Storage::Error &) { SinkError() << "Failed to replay change " << key; }); return replayJob.then([this, revision, recordReplayedRevision]() { - Trace() << "Replayed until " << revision; + SinkTrace() << "Replayed until " << revision; recordReplayedRevision(revision); //replay until we're done replayNextRevision().exec(); }, [this, revision, recordReplayedRevision](int, QString) { - Trace() << "Change replay failed" << revision; + SinkTrace() << "Change replay failed" << revision; //We're probably not online or so, so postpone retrying mReplayInProgress = false; emit changesReplayed(); }); } else { - Trace() << "No changes to replay"; + SinkTrace() << "No changes to replay"; mReplayInProgress = false; emit changesReplayed(); } diff --git a/common/configstore.cpp b/common/configstore.cpp index a8469ba..c8809ea 100644 --- a/common/configstore.cpp +++ b/common/configstore.cpp @@ -24,6 +24,8 @@ #include #include +SINK_DEBUG_AREA("configstore") + static QSharedPointer getConfig(const QByteArray &identifier) { return QSharedPointer::create(QStandardPaths::writableLocation(QStandardPaths::GenericDataLocation) + "/sink/" + identifier + ".ini", QSettings::IniFormat); @@ -50,7 +52,7 @@ QMap ConfigStore::getEntries() void ConfigStore::add(const QByteArray &identifier, const QByteArray &type) { - Trace() << "Adding " << identifier; + SinkTrace() << "Adding " << identifier; mConfig->beginGroup(QString::fromLatin1(identifier)); mConfig->setValue("type", type); mConfig->endGroup(); @@ -59,7 +61,7 @@ void ConfigStore::add(const QByteArray &identifier, const QByteArray &type) void ConfigStore::remove(const QByteArray &identifier) { - Trace() << "Removing " << identifier; + SinkTrace() << "Removing " << identifier; mConfig->beginGroup(QString::fromLatin1(identifier)); mConfig->remove(""); mConfig->endGroup(); @@ -75,7 +77,7 @@ void ConfigStore::clear() void ConfigStore::modify(const QByteArray &identifier, const QMap &configuration) { - Trace() << "Modifying " << identifier; + SinkTrace() << "Modifying " << identifier; auto config = getConfig(identifier); config->clear(); for (const auto &key : configuration.keys()) { diff --git a/common/domain/applicationdomaintype.cpp b/common/domain/applicationdomaintype.cpp index 44eeb13..57919ff 100644 --- a/common/domain/applicationdomaintype.cpp +++ b/common/domain/applicationdomaintype.cpp @@ -24,6 +24,8 @@ #include "storage.h" //for generateUid() #include +SINK_DEBUG_AREA("applicationdomaintype"); + namespace Sink { namespace ApplicationDomain { @@ -82,7 +84,7 @@ QVariant ApplicationDomainType::getProperty(const QByteArray &key) const { Q_ASSERT(mAdaptor); if (!mAdaptor->availableProperties().contains(key)) { - Warning() << "No such property available " << key; + SinkWarning() << "No such property available " << key; } return mAdaptor->getProperty(key); } @@ -105,7 +107,7 @@ QByteArray ApplicationDomainType::getBlobProperty(const QByteArray &key) const const auto path = getProperty(key).toByteArray(); QFile file(path); if (!file.open(QIODevice::ReadOnly)) { - ErrorMsg() << "Failed to open the file: " << file.errorString() << path; + SinkError() << "Failed to open the file: " << file.errorString() << path; return QByteArray(); } return file.readAll(); @@ -116,7 +118,7 @@ void ApplicationDomainType::setBlobProperty(const QByteArray &key, const QByteAr const auto path = Sink::temporaryFileLocation() + "/" + QUuid::createUuid().toString(); QFile file(path); if (!file.open(QIODevice::WriteOnly)) { - ErrorMsg() << "Failed to open the file: " << file.errorString() << path; + SinkError() << "Failed to open the file: " << file.errorString() << path; return; } file.write(value); diff --git a/common/domain/folder.cpp b/common/domain/folder.cpp index 309ca3f..ddb0c10 100644 --- a/common/domain/folder.cpp +++ b/common/domain/folder.cpp @@ -35,6 +35,8 @@ #include "folder_generated.h" +SINK_DEBUG_AREA("folder"); + static QMutex sMutex; using namespace Sink::ApplicationDomain; @@ -58,7 +60,7 @@ ResultSet TypeImplementation::queryIndexes(const Sink::Query &query, con void TypeImplementation::index(const QByteArray &identifier, const BufferAdaptor &bufferAdaptor, Sink::Storage::Transaction &transaction) { - Trace() << "Indexing " << identifier; + SinkTrace() << "Indexing " << identifier; getIndex().add(identifier, bufferAdaptor, transaction); } diff --git a/common/domain/mail.cpp b/common/domain/mail.cpp index 5b35a9a..13e1305 100644 --- a/common/domain/mail.cpp +++ b/common/domain/mail.cpp @@ -35,6 +35,8 @@ #include "mail_generated.h" +SINK_DEBUG_AREA("mail"); + static QMutex sMutex; using namespace Sink::ApplicationDomain; @@ -63,7 +65,7 @@ ResultSet TypeImplementation::queryIndexes(const Sink::Query &query, const void TypeImplementation::index(const QByteArray &identifier, const BufferAdaptor &bufferAdaptor, Sink::Storage::Transaction &transaction) { - Trace() << "Indexing " << identifier; + SinkTrace() << "Indexing " << identifier; getIndex().add(identifier, bufferAdaptor, transaction); } diff --git a/common/domainadaptor.h b/common/domainadaptor.h index 8ac8171..25448f3 100644 --- a/common/domainadaptor.h +++ b/common/domainadaptor.h @@ -47,12 +47,12 @@ createBufferPart(const Sink::ApplicationDomain::ApplicationDomainType &domainObj // First create a primitives such as strings using the mappings QList> propertiesToAddToResource; for (const auto &property : domainObject.changedProperties()) { - // Trace() << "copying property " << property; + // SinkTrace() << "copying property " << property; const auto value = domainObject.getProperty(property); if (mapper.hasMapping(property)) { mapper.setProperty(property, domainObject.getProperty(property), propertiesToAddToResource, fbb); } else { - // Trace() << "no mapping for property available " << property; + // SinkTrace() << "no mapping for property available " << property; } } @@ -79,7 +79,7 @@ static void createBufferPartBuffer(const Sink::ApplicationDomain::ApplicationDom fbb.Finish(pos, "AKFB"); flatbuffers::Verifier verifier(fbb.GetBufferPointer(), fbb.GetSize()); if (!verifier.VerifyBuffer()) { - Warning() << "Created invalid uffer"; + SinkWarning_(0, "bufferadaptor") << "Created invalid uffer"; } } @@ -89,6 +89,7 @@ static void createBufferPartBuffer(const Sink::ApplicationDomain::ApplicationDom template class GenericBufferAdaptor : public Sink::ApplicationDomain::BufferAdaptor { + SINK_DEBUG_AREA("bufferadaptor") public: GenericBufferAdaptor() : BufferAdaptor() { @@ -96,7 +97,7 @@ public: virtual void setProperty(const QByteArray &key, const QVariant &value) Q_DECL_OVERRIDE { - Warning() << "Can't set property " << key; + SinkWarning() << "Can't set property " << key; Q_ASSERT(false); } @@ -107,7 +108,7 @@ public: } else if (mLocalBuffer && mLocalMapper->hasMapping(key)) { return mLocalMapper->getProperty(key, mLocalBuffer); } - Warning() << "No mapping available for key " << key << mLocalBuffer << mResourceBuffer; + SinkWarning() << "No mapping available for key " << key << mLocalBuffer << mResourceBuffer; return QVariant(); } @@ -168,13 +169,13 @@ public: { flatbuffers::FlatBufferBuilder localFbb; if (mLocalWriteMapper) { - // Trace() << "Creating local buffer part"; + // SinkTrace() << "Creating local buffer part"; createBufferPartBuffer(domainObject, localFbb, *mLocalWriteMapper); } flatbuffers::FlatBufferBuilder resFbb; if (mResourceWriteMapper) { - // Trace() << "Creating resouce buffer part"; + // SinkTrace() << "Creating resouce buffer part"; createBufferPartBuffer(domainObject, resFbb, *mResourceWriteMapper); } diff --git a/common/entityreader.cpp b/common/entityreader.cpp index c15f73f..411e7e4 100644 --- a/common/entityreader.cpp +++ b/common/entityreader.cpp @@ -23,6 +23,8 @@ #include "storage.h" #include "query.h" +SINK_DEBUG_AREA("entityreader") + using namespace Sink; QSharedPointer EntityReaderUtils::getLatest(const Sink::Storage::NamedDatabase &db, const QByteArray &uid, DomainTypeAdaptorFactoryInterface &adaptorFactory, qint64 &retrievedRevision) @@ -32,15 +34,15 @@ QSharedPointer EntityReaderUtils::getLat [¤t, &adaptorFactory, &retrievedRevision](const QByteArray &key, const QByteArray &data) -> bool { Sink::EntityBuffer buffer(const_cast(data.data()), data.size()); if (!buffer.isValid()) { - Warning() << "Read invalid buffer from disk"; + SinkWarning() << "Read invalid buffer from disk"; } else { - Trace() << "Found value " << key; + SinkTrace() << "Found value " << key; current = adaptorFactory.createAdaptor(buffer.entity()); retrievedRevision = Sink::Storage::revisionFromKey(key); } return false; }, - [](const Sink::Storage::Error &error) { Warning() << "Failed to read current value from storage: " << error.message; }); + [](const Sink::Storage::Error &error) { SinkWarning() << "Failed to read current value from storage: " << error.message; }); return current; } @@ -51,14 +53,14 @@ QSharedPointer EntityReaderUtils::get(co [¤t, &adaptorFactory, &retrievedRevision](const QByteArray &key, const QByteArray &data) -> bool { Sink::EntityBuffer buffer(const_cast(data.data()), data.size()); if (!buffer.isValid()) { - Warning() << "Read invalid buffer from disk"; + SinkWarning() << "Read invalid buffer from disk"; } else { current = adaptorFactory.createAdaptor(buffer.entity()); retrievedRevision = Sink::Storage::revisionFromKey(key); } return false; }, - [](const Sink::Storage::Error &error) { Warning() << "Failed to read current value from storage: " << error.message; }); + [](const Sink::Storage::Error &error) { SinkWarning() << "Failed to read current value from storage: " << error.message; }); return current; } @@ -74,7 +76,7 @@ QSharedPointer EntityReaderUtils::getPre } return true; }, - [](const Sink::Storage::Error &error) { Warning() << "Failed to read current value from storage: " << error.message; }, true); + [](const Sink::Storage::Error &error) { SinkWarning() << "Failed to read current value from storage: " << error.message; }, true); return get(db, Sink::Storage::assembleKey(uid, latestRevision), adaptorFactory, retrievedRevision); } @@ -86,7 +88,7 @@ EntityReader::EntityReader(const QByteArray &resourceType, const QBy mDomainTypeAdaptorFactory(*mDomainTypeAdaptorFactoryPtr) { Q_ASSERT(!resourceType.isEmpty()); - Trace() << "resourceType " << resourceType; + SinkTrace() << "resourceType " << resourceType; Q_ASSERT(mDomainTypeAdaptorFactoryPtr); } @@ -165,13 +167,13 @@ void EntityReader::readEntity(const Sink::Storage::NamedDatabase &db resultCallback(DomainType::Ptr::create(mResourceInstanceIdentifier, Sink::Storage::uidFromKey(key), revision, adaptor), operation); return false; }, - [&](const Sink::Storage::Error &error) { Warning() << "Error during query: " << error.message << key; }); + [&](const Sink::Storage::Error &error) { SinkWarning() << "Error during query: " << error.message << key; }); } static inline ResultSet fullScan(const Sink::Storage::Transaction &transaction, const QByteArray &bufferType) { // TODO use a result set with an iterator, to read values on demand - Trace() << "Looking for : " << bufferType; + SinkTrace() << "Looking for : " << bufferType; //The scan can return duplicate results if we have multiple revisions, so we use a set to deduplicate. QSet keys; Storage::mainDatabase(transaction, bufferType) @@ -179,14 +181,14 @@ static inline ResultSet fullScan(const Sink::Storage::Transaction &transaction, [&](const QByteArray &key, const QByteArray &value) -> bool { if (keys.contains(Sink::Storage::uidFromKey(key))) { //Not something that should persist if the replay works, so we keep a message for now. - Trace() << "Multiple revisions for key: " << key; + SinkTrace() << "Multiple revisions for key: " << key; } keys << Sink::Storage::uidFromKey(key); return true; }, - [](const Sink::Storage::Error &error) { Warning() << "Error during query: " << error.message; }); + [](const Sink::Storage::Error &error) { SinkWarning() << "Error during query: " << error.message; }); - Trace() << "Full scan retrieved " << keys.size() << " results."; + SinkTrace() << "Full scan retrieved " << keys.size() << " results."; return ResultSet(keys.toList().toVector()); } @@ -224,7 +226,7 @@ ResultSet EntityReader::loadIncrementalResultSet(qint64 baseRevision while (*revisionCounter <= topRevision) { const auto uid = Sink::Storage::getUidFromRevision(mTransaction, *revisionCounter); const auto type = Sink::Storage::getTypeFromRevision(mTransaction, *revisionCounter); - // Trace() << "Revision" << *revisionCounter << type << uid; + // SinkTrace() << "Revision" << *revisionCounter << type << uid; Q_ASSERT(!uid.isEmpty()); Q_ASSERT(!type.isEmpty()); if (type != bufferType) { @@ -236,7 +238,7 @@ ResultSet EntityReader::loadIncrementalResultSet(qint64 baseRevision *revisionCounter += 1; return key; } - Trace() << "Finished reading incremental result set:" << *revisionCounter; + SinkTrace() << "Finished reading incremental result set:" << *revisionCounter; // We're done return QByteArray(); }); @@ -248,7 +250,7 @@ ResultSet EntityReader::filterAndSortSet(ResultSet &resultSet, const { const bool sortingRequired = !sortProperty.isEmpty(); if (initialQuery && sortingRequired) { - Trace() << "Sorting the resultset in memory according to property: " << sortProperty; + SinkTrace() << "Sorting the resultset in memory according to property: " << sortProperty; // Sort the complete set by reading the sort property and filling into a sorted map auto sortedMap = QSharedPointer>::create(); while (resultSet.next()) { @@ -271,7 +273,7 @@ ResultSet EntityReader::filterAndSortSet(ResultSet &resultSet, const }); } - Trace() << "Sorted " << sortedMap->size() << " values."; + SinkTrace() << "Sorted " << sortedMap->size() << " values."; auto iterator = QSharedPointer>::create(*sortedMap); ResultSet::ValueGenerator generator = [this, iterator, sortedMap, &db, filter, initialQuery]( std::function callback) -> bool { @@ -330,11 +332,11 @@ QPair EntityReader::load(const Sink::Query &query, c QSet remainingFilters; QByteArray remainingSorting; auto resultSet = baseSetRetriever(remainingFilters, remainingSorting); - Trace() << "Base set retrieved. " << Log::TraceTime(time.elapsed()); + SinkTrace() << "Base set retrieved. " << Log::TraceTime(time.elapsed()); auto filteredSet = filterAndSortSet(resultSet, getFilter(remainingFilters, query), db, initialQuery, remainingSorting); - Trace() << "Filtered set retrieved. " << Log::TraceTime(time.elapsed()); + SinkTrace() << "Filtered set retrieved. " << Log::TraceTime(time.elapsed()); auto replayedEntities = replaySet(filteredSet, offset, batchSize, callback); - // Trace() << "Filtered set replayed. " << Log::TraceTime(time.elapsed()); + // SinkTrace() << "Filtered set replayed. " << Log::TraceTime(time.elapsed()); return qMakePair(Sink::Storage::maxRevision(mTransaction), replayedEntities); } @@ -346,7 +348,7 @@ QPair EntityReader::executeInitialQuery(const Sink:: auto revisionAndReplayedEntities = load(query, [&](QSet &remainingFilters, QByteArray &remainingSorting) -> ResultSet { return loadInitialResultSet(query, remainingFilters, remainingSorting); }, true, offset, batchsize, callback); - Trace() << "Initial query took: " << Log::TraceTime(time.elapsed()); + SinkTrace() << "Initial query took: " << Log::TraceTime(time.elapsed()); return revisionAndReplayedEntities; } @@ -359,7 +361,7 @@ QPair EntityReader::executeIncrementalQuery(const Si auto revisionAndReplayedEntities = load(query, [&](QSet &remainingFilters, QByteArray &remainingSorting) -> ResultSet { return loadIncrementalResultSet(baseRevision, query, remainingFilters); }, false, 0, 0, callback); - Trace() << "Initial query took: " << Log::TraceTime(time.elapsed()); + SinkTrace() << "Initial query took: " << Log::TraceTime(time.elapsed()); return revisionAndReplayedEntities; } @@ -377,7 +379,7 @@ EntityReader::getFilter(const QSet remainingFilters, con const auto property = domainObject->getProperty(filterProperty); const auto comparator = query.propertyFilter.value(filterProperty); if (!comparator.matches(property)) { - Trace() << "Filtering entity due to property mismatch on filter: " << filterProperty << property << ":" << comparator.value; + SinkTrace() << "Filtering entity due to property mismatch on filter: " << filterProperty << property << ":" << comparator.value; return false; } } @@ -388,7 +390,7 @@ EntityReader::getFilter(const QSet remainingFilters, con template qint64 EntityReader::replaySet(ResultSet &resultSet, int offset, int batchSize, const std::function &callback) { - Trace() << "Skipping over " << offset << " results"; + SinkTrace() << "Skipping over " << offset << " results"; resultSet.skip(offset); int counter = 0; while (!batchSize || (counter < batchSize)) { @@ -401,7 +403,7 @@ qint64 EntityReader::replaySet(ResultSet &resultSet, int offset, int break; } }; - Trace() << "Replayed " << counter << " results." + SinkTrace() << "Replayed " << counter << " results." << "Limit " << batchSize; return counter; } diff --git a/common/facade.cpp b/common/facade.cpp index 2660300..72f7414 100644 --- a/common/facade.cpp +++ b/common/facade.cpp @@ -30,9 +30,6 @@ using namespace Sink; -#undef DEBUG_AREA -#define DEBUG_AREA "client.facade" - template GenericFacade::GenericFacade( const QByteArray &resourceIdentifier, const DomainTypeAdaptorFactoryInterface::Ptr &adaptorFactory, const QSharedPointer resourceAccess) @@ -59,7 +56,7 @@ template KAsync::Job GenericFacade::create(const DomainType &domainObject) { if (!mDomainTypeAdaptorFactory) { - Warning() << "No domain type adaptor factory available"; + SinkWarning() << "No domain type adaptor factory available"; return KAsync::error(); } flatbuffers::FlatBufferBuilder entityFbb; @@ -71,10 +68,10 @@ template KAsync::Job GenericFacade::modify(const DomainType &domainObject) { if (!mDomainTypeAdaptorFactory) { - Warning() << "No domain type adaptor factory available"; + SinkWarning() << "No domain type adaptor factory available"; return KAsync::error(); } - Trace() << "Modifying entity: " << domainObject.identifier() << domainObject.changedProperties(); + SinkTrace() << "Modifying entity: " << domainObject.identifier() << domainObject.changedProperties(); flatbuffers::FlatBufferBuilder entityFbb; mDomainTypeAdaptorFactory->createBuffer(domainObject, entityFbb); return mResourceAccess->sendModifyCommand(domainObject.identifier(), domainObject.revision(), bufferTypeForDomainType(), QByteArrayList(), BufferUtils::extractBuffer(entityFbb), domainObject.changedProperties()); diff --git a/common/facade.h b/common/facade.h index 658ccb8..b193580 100644 --- a/common/facade.h +++ b/common/facade.h @@ -46,6 +46,9 @@ namespace Sink { template class SINK_EXPORT GenericFacade : public Sink::StoreFacade { +protected: + SINK_DEBUG_AREA("facade") + SINK_DEBUG_COMPONENT(mResourceInstanceIdentifier) public: /** * Create a new GenericFacade diff --git a/common/genericresource.cpp b/common/genericresource.cpp index ed7dd46..7136882 100644 --- a/common/genericresource.cpp +++ b/common/genericresource.cpp @@ -46,9 +46,6 @@ static int sCommitInterval = 10; using namespace Sink; -#undef DEBUG_AREA -#define DEBUG_AREA "resource.commandprocessor" - /** * Drives the pipeline using the output from all command queues */ @@ -56,12 +53,13 @@ class CommandProcessor : public QObject { Q_OBJECT typedef std::function(void const *, size_t)> InspectionFunction; + SINK_DEBUG_AREA("commandprocessor") public: CommandProcessor(Sink::Pipeline *pipeline, QList commandQueues) : QObject(), mPipeline(pipeline), mCommandQueues(commandQueues), mProcessingLock(false) { mLowerBoundRevision = Storage::maxRevision(mPipeline->storage().createTransaction(Storage::ReadOnly, [](const Sink::Storage::Error &error) { - Warning() << error.message; + SinkWarning() << error.message; })); for (auto queue : mCommandQueues) { @@ -80,7 +78,6 @@ public: mInspect = f; } - signals: void error(int errorCode, const QString &errorMessage); @@ -114,7 +111,7 @@ private slots: KAsync::Job processQueuedCommand(const Sink::QueuedCommand *queuedCommand) { - Trace() << "Processing command: " << Sink::Commands::name(queuedCommand->commandId()); + SinkTrace() << "Processing command: " << Sink::Commands::name(queuedCommand->commandId()); // Throw command into appropriate pipeline switch (queuedCommand->commandId()) { case Sink::Commands::DeleteEntityCommand: @@ -138,21 +135,21 @@ private slots: { flatbuffers::Verifier verifyer(reinterpret_cast(data.constData()), data.size()); if (!Sink::VerifyQueuedCommandBuffer(verifyer)) { - Warning() << "invalid buffer"; + SinkWarning() << "invalid buffer"; // return KAsync::error(1, "Invalid Buffer"); } auto queuedCommand = Sink::GetQueuedCommand(data.constData()); const auto commandId = queuedCommand->commandId(); - Trace() << "Dequeued Command: " << Sink::Commands::name(commandId); + SinkTrace() << "Dequeued Command: " << Sink::Commands::name(commandId); return processQueuedCommand(queuedCommand) .then( - [commandId](qint64 createdRevision) -> qint64 { - Trace() << "Command pipeline processed: " << Sink::Commands::name(commandId); + [this, commandId](qint64 createdRevision) -> qint64 { + SinkTrace() << "Command pipeline processed: " << Sink::Commands::name(commandId); return createdRevision; }, [](int errorCode, QString errorMessage) { // FIXME propagate error, we didn't handle it - Warning() << "Error while processing queue command: " << errorMessage; + SinkWarning() << "Error while processing queue command: " << errorMessage; }); } @@ -169,7 +166,7 @@ private slots: return KAsync::start([this, data, time](KAsync::Future &future) { processQueuedCommand(data) .then([&future, this, time](qint64 createdRevision) { - Trace() << "Created revision " << createdRevision << ". Processing took: " << Log::TraceTime(time->elapsed()); + SinkTrace() << "Created revision " << createdRevision << ". Processing took: " << Log::TraceTime(time->elapsed()); future.setFinished(); }) .exec(); @@ -178,7 +175,7 @@ private slots: .then([&future, queue]() { future.setFinished(); }, [&future](int i, QString error) { if (i != MessageQueue::ErrorCodes::NoMessageFound) { - Warning() << "Error while getting message from messagequeue: " << error; + SinkWarning() << "Error while getting message from messagequeue: " << error; } future.setFinished(); }) @@ -192,12 +189,12 @@ private slots: auto time = QSharedPointer::create(); time->start(); mPipeline->startTransaction(); - Trace() << "Cleaning up from " << mPipeline->cleanedUpRevision() + 1 << " to " << mLowerBoundRevision; + SinkTrace() << "Cleaning up from " << mPipeline->cleanedUpRevision() + 1 << " to " << mLowerBoundRevision; for (qint64 revision = mPipeline->cleanedUpRevision() + 1; revision <= mLowerBoundRevision; revision++) { mPipeline->cleanupRevision(revision); } mPipeline->commit(); - Trace() << "Cleanup done." << Log::TraceTime(time->elapsed()); + SinkTrace() << "Cleanup done." << Log::TraceTime(time->elapsed()); // Go through all message queues auto it = QSharedPointer>::create(mCommandQueues); @@ -208,8 +205,8 @@ private slots: auto queue = it->next(); processQueue(queue) - .then([&future, time]() { - Trace() << "Queue processed." << Log::TraceTime(time->elapsed()); + .then([this, &future, time]() { + SinkTrace() << "Queue processed." << Log::TraceTime(time->elapsed()); future.setFinished(); }) .exec(); @@ -226,9 +223,6 @@ private: InspectionFunction mInspect; }; -#undef DEBUG_AREA -#define DEBUG_AREA "resource" - GenericResource::GenericResource(const QByteArray &resourceType, const QByteArray &resourceInstanceIdentifier, const QSharedPointer &pipeline ) : Sink::Resource(), mUserQueue(Sink::storageLocation(), resourceInstanceIdentifier + ".userqueue"), @@ -301,7 +295,7 @@ GenericResource::~GenericResource() KAsync::Job GenericResource::inspect( int inspectionType, const QByteArray &inspectionId, const QByteArray &domainType, const QByteArray &entityId, const QByteArray &property, const QVariant &expectedValue) { - Warning() << "Inspection not implemented"; + SinkWarning() << "Inspection not implemented"; return KAsync::null(); } @@ -363,7 +357,7 @@ void GenericResource::setupChangereplay(const QSharedPointer &chan void GenericResource::removeDataFromDisk() { - Log() << "Removing the resource from disk: " << mResourceInstanceIdentifier; + SinkLog() << "Removing the resource from disk: " << mResourceInstanceIdentifier; //Ensure we have no transaction or databases open mSynchronizer.clear(); mChangeReplay.clear(); @@ -391,7 +385,7 @@ qint64 GenericResource::diskUsage(const QByteArray &instanceIdentifier) void GenericResource::onProcessorError(int errorCode, const QString &errorMessage) { - Warning() << "Received error from Processor: " << errorCode << errorMessage; + SinkWarning() << "Received error from Processor: " << errorCode << errorMessage; mError = errorCode; } @@ -435,12 +429,12 @@ KAsync::Job GenericResource::synchronizeWithSource() n.code = Sink::ApplicationDomain::BusyStatus; emit notify(n); - Log() << " Synchronizing"; + SinkLog() << " Synchronizing"; // Changereplay would deadlock otherwise when trying to open the synchronization store enableChangeReplay(false); mSynchronizer->synchronize() .then([this, &future]() { - Log() << "Done Synchronizing"; + SinkLog() << "Done Synchronizing"; Sink::Notification n; n.id = "sync"; n.type = Sink::Notification::Status; diff --git a/common/genericresource.h b/common/genericresource.h index 2254172..25892ca 100644 --- a/common/genericresource.h +++ b/common/genericresource.h @@ -40,6 +40,9 @@ class Synchronizer; */ class SINK_EXPORT GenericResource : public Resource { +protected: + SINK_DEBUG_AREA("resource") + SINK_DEBUG_COMPONENT(mResourceInstanceIdentifier) public: GenericResource(const QByteArray &resourceType, const QByteArray &resourceInstanceIdentifier, const QSharedPointer &pipeline); virtual ~GenericResource(); diff --git a/common/index.cpp b/common/index.cpp index 151f7af..beed45c 100644 --- a/common/index.cpp +++ b/common/index.cpp @@ -2,8 +2,7 @@ #include "log.h" -#undef Trace -#define Trace() Trace_area("index." + mName.toLatin1()) +SINK_DEBUG_AREA("index") Index::Index(const QString &storageRoot, const QString &name, Sink::Storage::AccessMode mode) : mTransaction(Sink::Storage(storageRoot, name, mode).createTransaction(mode)), @@ -34,8 +33,8 @@ void Index::lookup(const QByteArray &key, const std::function #include #include "storage.h" +#include "log.h" /** * An index for value pairs. @@ -43,4 +44,5 @@ private: Sink::Storage::Transaction mTransaction; Sink::Storage::NamedDatabase mDb; QString mName; + SINK_DEBUG_COMPONENT(mName.toLatin1()) }; diff --git a/common/listener.cpp b/common/listener.cpp index af8eaa2..2c5c1df 100644 --- a/common/listener.cpp +++ b/common/listener.cpp @@ -39,9 +39,6 @@ #include #include -#undef DEBUG_AREA -#define DEBUG_AREA "resource.communication" - Listener::Listener(const QByteArray &resourceInstanceIdentifier, const QByteArray &resourceType, QObject *parent) : QObject(parent), m_server(new QLocalServer(this)), @@ -51,18 +48,18 @@ Listener::Listener(const QByteArray &resourceInstanceIdentifier, const QByteArra m_messageId(0) { connect(m_server.get(), &QLocalServer::newConnection, this, &Listener::acceptConnection); - Trace() << "Trying to open " << m_resourceInstanceIdentifier; + SinkTrace() << "Trying to open " << m_resourceInstanceIdentifier; if (!m_server->listen(QString::fromLatin1(m_resourceInstanceIdentifier))) { m_server->removeServer(m_resourceInstanceIdentifier); if (!m_server->listen(QString::fromLatin1(m_resourceInstanceIdentifier))) { - Warning() << "Utter failure to start server"; + SinkWarning() << "Utter failure to start server"; exit(-1); } } if (m_server->isListening()) { - Log() << QString("Listening on %1").arg(m_server->serverName()); + SinkLog() << QString("Listening on %1").arg(m_server->serverName()); } m_checkConnectionsTimer = std::unique_ptr(new QTimer); @@ -70,7 +67,7 @@ Listener::Listener(const QByteArray &resourceInstanceIdentifier, const QByteArra m_checkConnectionsTimer->setInterval(1000); connect(m_checkConnectionsTimer.get(), &QTimer::timeout, [this]() { if (m_connections.isEmpty()) { - Log() << QString("No connections, shutting down."); + SinkLog() << QString("No connections, shutting down."); quit(); } }); @@ -91,7 +88,7 @@ void Listener::emergencyAbortAllConnections() { for (Client &client : m_connections) { if (client.socket) { - Warning() << "Sending panic"; + SinkWarning() << "Sending panic"; client.socket->write("PANIC"); client.socket->waitForBytesWritten(); disconnect(client.socket, 0, this, 0); @@ -120,11 +117,11 @@ void Listener::closeAllConnections() void Listener::acceptConnection() { - Trace() << "Accepting connection"; + SinkTrace() << "Accepting connection"; QLocalSocket *socket = m_server->nextPendingConnection(); if (!socket) { - Warning() << "Accepted connection but didn't get a socket for it"; + SinkWarning() << "Accepted connection but didn't get a socket for it"; return; } @@ -156,13 +153,13 @@ void Listener::clientDropped() const Client &client = it.next(); if (client.socket == socket) { dropped = true; - Log() << QString("Dropped connection: %1").arg(client.name) << socket; + SinkLog() << QString("Dropped connection: %1").arg(client.name) << socket; it.remove(); break; } } if (!dropped) { - Warning() << "Failed to find connection for disconnected socket: " << socket; + SinkWarning() << "Failed to find connection for disconnected socket: " << socket; } checkConnections(); @@ -188,7 +185,7 @@ void Listener::onDataAvailable() void Listener::readFromSocket(QLocalSocket *socket) { - Trace() << "Reading from socket..."; + SinkTrace() << "Reading from socket..."; for (Client &client : m_connections) { if (client.socket == socket) { client.commandBuffer += socket->readAll(); @@ -231,7 +228,7 @@ void Listener::processCommand(int commandId, uint messageId, const QByteArray &c auto buffer = Sink::Commands::GetHandshake(commandBuffer.constData()); client.name = buffer->name()->c_str(); } else { - Warning() << "received invalid command"; + SinkWarning() << "received invalid command"; } break; } @@ -239,7 +236,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()); - Trace() << QString("Synchronize request (id %1) from %2").arg(messageId).arg(client.name); + SinkTrace() << QString("Synchronize request (id %1) from %2").arg(messageId).arg(client.name); auto timer = QSharedPointer::create(); timer->start(); auto job = KAsync::null(); @@ -250,16 +247,16 @@ void Listener::processCommand(int commandId, uint messageId, const QByteArray &c job = job.then(loadResource().processAllMessages()); } job.then([callback, timer]() { - Trace() << "Sync took " << Sink::Log::TraceTime(timer->elapsed()); + SinkTrace() << "Sync took " << Sink::Log::TraceTime(timer->elapsed()); callback(true); }, [callback](int errorCode, const QString &msg) { - Warning() << "Sync failed: " << msg; + SinkWarning() << "Sync failed: " << msg; callback(false); }) .exec(); return; } else { - Warning() << "received invalid command"; + SinkWarning() << "received invalid command"; } break; } @@ -268,31 +265,31 @@ void Listener::processCommand(int commandId, uint messageId, const QByteArray &c case Sink::Commands::DeleteEntityCommand: case Sink::Commands::ModifyEntityCommand: case Sink::Commands::CreateEntityCommand: - Trace() << "Command id " << messageId << " of type \"" << Sink::Commands::name(commandId) << "\" from " << client.name; + SinkTrace() << "Command id " << messageId << " of type \"" << Sink::Commands::name(commandId) << "\" from " << client.name; loadResource().processCommand(commandId, commandBuffer); break; case Sink::Commands::ShutdownCommand: - Log() << QString("Received shutdown command from %1").arg(client.name); + SinkLog() << 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: - Trace() << QString("Received ping command from %1").arg(client.name); + SinkTrace() << QString("Received ping command from %1").arg(client.name); break; case Sink::Commands::RevisionReplayedCommand: { - Trace() << QString("Received revision replayed command from %1").arg(client.name); + SinkTrace() << 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()); client.currentRevision = buffer->revision(); } else { - Warning() << "received invalid command"; + SinkWarning() << "received invalid command"; } loadResource().setLowerBoundRevision(lowerBoundRevision()); } break; case Sink::Commands::RemoveFromDiskCommand: { - Log() << QString("Received a remove from disk command from %1").arg(client.name); + SinkLog() << QString("Received a remove from disk command from %1").arg(client.name); m_resource.reset(nullptr); loadResource().removeDataFromDisk(); m_server->close(); @@ -300,11 +297,11 @@ void Listener::processCommand(int commandId, uint messageId, const QByteArray &c } break; default: if (commandId > Sink::Commands::CustomCommand) { - Log() << QString("Received custom command from %1: ").arg(client.name) << commandId; + SinkLog() << QString("Received custom command from %1: ").arg(client.name) << commandId; loadResource().processCommand(commandId, commandBuffer); } else { success = false; - ErrorMsg() << QString("\tReceived invalid command from %1: ").arg(client.name) << commandId; + SinkError() << QString("\tReceived invalid command from %1: ").arg(client.name) << commandId; } break; } @@ -352,7 +349,7 @@ bool Listener::processClientBuffer(Client &client) const uint messageId = *(uint *)client.commandBuffer.constData(); const int commandId = *(int *)(client.commandBuffer.constData() + sizeof(uint)); const uint size = *(uint *)(client.commandBuffer.constData() + sizeof(int) + sizeof(uint)); - Trace() << "Received message. Id:" << messageId << " CommandId: " << commandId << " Size: " << size; + SinkTrace() << "Received message. Id:" << messageId << " CommandId: " << commandId << " Size: " << size; // TODO: reject messages above a certain size? @@ -365,11 +362,11 @@ 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) { - Trace() << QString("Completed command messageid %1 of type \"%2\" from %3").arg(messageId).arg(QString(Sink::Commands::name(commandId))).arg(clientName); + SinkTrace() << 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 { - Log() << QString("Socket became invalid before we could send a response. client: %1").arg(clientName); + SinkLog() << QString("Socket became invalid before we could send a response. client: %1").arg(clientName); } }); @@ -406,7 +403,7 @@ void Listener::updateClientsWithRevision(qint64 revision) continue; } - Trace() << "Sending revision update for " << client.name << revision; + SinkTrace() << "Sending revision update for " << client.name << revision; Sink::Commands::write(client.socket, ++m_messageId, Sink::Commands::RevisionUpdateCommand, m_fbb); } m_fbb.Clear(); @@ -437,15 +434,15 @@ Sink::Resource &Listener::loadResource() if (Sink::ResourceFactory *resourceFactory = Sink::ResourceFactory::load(m_resourceName)) { m_resource = std::unique_ptr(resourceFactory->createResource(m_resourceInstanceIdentifier)); if (!m_resource) { - ErrorMsg() << "Failed to instantiate the resource " << m_resourceName; + SinkError() << "Failed to instantiate the resource " << m_resourceName; m_resource = std::unique_ptr(new Sink::Resource); } - Trace() << QString("Resource factory: %1").arg((qlonglong)resourceFactory); - Trace() << QString("\tResource: %1").arg((qlonglong)m_resource.get()); + SinkTrace() << QString("Resource factory: %1").arg((qlonglong)resourceFactory); + SinkTrace() << QString("\tResource: %1").arg((qlonglong)m_resource.get()); connect(m_resource.get(), &Sink::Resource::revisionUpdated, this, &Listener::refreshRevision); connect(m_resource.get(), &Sink::Resource::notify, this, &Listener::notify); } else { - ErrorMsg() << "Failed to load resource " << m_resourceName; + SinkError() << "Failed to load resource " << m_resourceName; m_resource = std::unique_ptr(new Sink::Resource); } } diff --git a/common/listener.h b/common/listener.h index 67d76e9..d6c537a 100644 --- a/common/listener.h +++ b/common/listener.h @@ -25,6 +25,7 @@ #include #include #include +#include namespace Sink { class Resource; @@ -54,6 +55,7 @@ public: class SINK_EXPORT Listener : public QObject { Q_OBJECT + SINK_DEBUG_AREA("communication") public: Listener(const QByteArray &resourceName, const QByteArray &resourceType, QObject *parent = 0); diff --git a/common/log.cpp b/common/log.cpp index 83cdc8a..821df06 100644 --- a/common/log.cpp +++ b/common/log.cpp @@ -238,27 +238,34 @@ static bool caseInsensitiveContains(const QByteArray &pattern, const QByteArrayL return false; } -QDebug Sink::Log::debugStream(DebugLevel debugLevel, int line, const char *file, const char *function, const char *debugArea) +QDebug Sink::Log::debugStream(DebugLevel debugLevel, int line, const char *file, const char *function, const char *debugArea, const char *debugComponent) { static NullStream nullstream; if (debugLevel < debugOutputLevel()) { return QDebug(&nullstream); } - auto areas = debugOutputFilter(Sink::Log::Area); - if (debugArea && !areas.isEmpty()) { - if (!containsItemStartingWith(debugArea, areas)) { - return QDebug(&nullstream); - } + if (sPrimaryComponent.isEmpty()) { + sPrimaryComponent = getProgramName(); } - static QByteArray programName = getProgramName(); + QString fullDebugArea = sPrimaryComponent + "."+ QString::fromLatin1(debugComponent) + "." + QString::fromLatin1(debugArea); - auto filter = debugOutputFilter(Sink::Log::ApplicationName); - if (!filter.isEmpty() && !filter.contains(programName)) { - if (!containsItemStartingWith(programName, filter)) { + //TODO add to autocompletion + + auto areas = debugOutputFilter(Sink::Log::Area); + if (!areas.isEmpty()) { + if (!containsItemStartingWith(fullDebugArea.toUtf8(), areas)) { return QDebug(&nullstream); } } + // static QByteArray programName = getProgramName(); + // + // auto filter = debugOutputFilter(Sink::Log::ApplicationName); + // if (!filter.isEmpty() && !filter.contains(programName)) { + // if (!containsItemStartingWith(programName, filter)) { + // return QDebug(&nullstream); + // } + // } QString prefix; int prefixColorCode = ANSI_Colors::DoNothing; @@ -299,19 +306,17 @@ QDebug Sink::Log::debugStream(DebugLevel debugLevel, int line, const char *file, } if (showProgram) { int width = 10; - output += QString(" %1(%2)").arg(QString::fromLatin1(programName).leftJustified(width, ' ', true)).arg(unsigned(getpid())).rightJustified(width + 8, ' '); + output += QString(" %1(%2)").arg(QString::fromLatin1(getProgramName()).leftJustified(width, ' ', true)).arg(unsigned(getpid())).rightJustified(width + 8, ' '); } - if (debugArea) { - if (useColor) { - output += colorCommand(QList() << ANSI_Colors::Bold << prefixColorCode); - } - output += QString(" %1 ").arg(QString::fromLatin1(debugArea).leftJustified(25, ' ', true)); - if (useColor) { - output += resetColor; - } + if (useColor) { + output += colorCommand(QList() << ANSI_Colors::Bold << prefixColorCode); + } + output += QString(" %1 ").arg(fullDebugArea.leftJustified(25, ' ', true)); + if (useColor) { + output += resetColor; } if (showFunction) { - output += QString(" %3").arg(QString::fromLatin1(function).leftJustified(25, ' ', true)); + output += QString(" %3").arg(fullDebugArea.leftJustified(25, ' ', true)); } if (showLocation) { const auto filename = QString::fromLatin1(file).split('/').last(); diff --git a/common/log.h b/common/log.h index 36b8efe..d801ed9 100644 --- a/common/log.h +++ b/common/log.h @@ -57,7 +57,7 @@ QByteArrayList SINK_EXPORT debugOutputFilter(FilterType type); void SINK_EXPORT setDebugOutputFields(const QByteArrayList &filter); QByteArrayList SINK_EXPORT debugOutputFields(); -QDebug SINK_EXPORT debugStream(DebugLevel debugLevel, int line, const char *file, const char *function, const char *debugArea = 0); +QDebug SINK_EXPORT debugStream(DebugLevel debugLevel, int line, const char *file, const char *function, const char *debugArea = 0, const char *debugComponent = 0); struct SINK_EXPORT TraceTime { @@ -73,18 +73,23 @@ inline QDebug SINK_EXPORT operator<<(QDebug d, const TraceTime &time) } } -#define DEBUG_AREA nullptr - -#define Trace_() Sink::Log::debugStream(Sink::Log::DebugLevel::Trace, __LINE__, __FILE__, Q_FUNC_INFO) -#define Log_() Sink::Log::debugStream(Sink::Log::DebugLevel::Log, __LINE__, __FILE__, Q_FUNC_INFO) +static const char *getComponentName() { return nullptr; } #define Trace_area(AREA) Sink::Log::debugStream(Sink::Log::DebugLevel::Trace, __LINE__, __FILE__, Q_FUNC_INFO, AREA) #define Log_area(AREA) Sink::Log::debugStream(Sink::Log::DebugLevel::Log, __LINE__, __FILE__, Q_FUNC_INFO, AREA) #define Warning_area(AREA) Sink::Log::debugStream(Sink::Log::DebugLevel::Warning, __LINE__, __FILE__, Q_FUNC_INFO, AREA) #define Error_area(AREA) Sink::Log::debugStream(Sink::Log::DebugLevel::Error, __LINE__, __FILE__, Q_FUNC_INFO, AREA) -#define Trace() Sink::Log::debugStream(Sink::Log::DebugLevel::Trace, __LINE__, __FILE__, Q_FUNC_INFO, DEBUG_AREA) -#define Log() Sink::Log::debugStream(Sink::Log::DebugLevel::Log, __LINE__, __FILE__, Q_FUNC_INFO, DEBUG_AREA) -#define Warning() Sink::Log::debugStream(Sink::Log::DebugLevel::Warning, __LINE__, __FILE__, Q_FUNC_INFO, DEBUG_AREA) -// FIXME Error clashes with Storage::Error and MessageQueue::Error -#define ErrorMsg() Sink::Log::debugStream(Sink::Log::DebugLevel::Error, __LINE__, __FILE__, Q_FUNC_INFO, DEBUG_AREA) +#define SinkTrace_(COMPONENT, AREA) Sink::Log::debugStream(Sink::Log::DebugLevel::Trace, __LINE__, __FILE__, Q_FUNC_INFO, AREA, COMPONENT) +#define SinkLog_(COMPONENT, AREA) Sink::Log::debugStream(Sink::Log::DebugLevel::Log, __LINE__, __FILE__, Q_FUNC_INFO, AREA, COMPONENT) +#define SinkWarning_(COMPONENT, AREA) Sink::Log::debugStream(Sink::Log::DebugLevel::Warning, __LINE__, __FILE__, Q_FUNC_INFO, AREA, COMPONENT) +#define SinkError_(COMPONENT, AREA) Sink::Log::debugStream(Sink::Log::DebugLevel::Error, __LINE__, __FILE__, Q_FUNC_INFO, AREA, COMPONENT) + +#define SinkTrace() Sink::Log::debugStream(Sink::Log::DebugLevel::Trace, __LINE__, __FILE__, Q_FUNC_INFO, s_sinkDebugArea, getComponentName()) +#define SinkLog() Sink::Log::debugStream(Sink::Log::DebugLevel::Log, __LINE__, __FILE__, Q_FUNC_INFO, s_sinkDebugArea, getComponentName()) +#define SinkWarning() Sink::Log::debugStream(Sink::Log::DebugLevel::Warning, __LINE__, __FILE__, Q_FUNC_INFO, s_sinkDebugArea, getComponentName()) +#define SinkError() Sink::Log::debugStream(Sink::Log::DebugLevel::Error, __LINE__, __FILE__, Q_FUNC_INFO, s_sinkDebugArea, getComponentName()) + +#define SINK_DEBUG_AREA(AREA) static constexpr const char* s_sinkDebugArea{AREA}; +#define SINK_DEBUG_COMPONENT(COMPONENT) const char* getComponentName() const { return COMPONENT; }; +#define SINK_DEBUG_COMPONENT_STATIC(COMPONENT) static const char* getComponentName() { return COMPONENT; }; diff --git a/common/mailpreprocessor.cpp b/common/mailpreprocessor.cpp index c38035e..2863ad4 100644 --- a/common/mailpreprocessor.cpp +++ b/common/mailpreprocessor.cpp @@ -29,6 +29,8 @@ using namespace Sink; +SINK_DEBUG_AREA("mailpreprocessor") + QString MailPropertyExtractor::getFilePathFromMimeMessagePath(const QString &s) const { return s; @@ -38,23 +40,23 @@ void MailPropertyExtractor::updatedIndexedProperties(Sink::ApplicationDomain::Ma { const auto mimeMessagePath = getFilePathFromMimeMessagePath(mail.getMimeMessagePath()); if (mimeMessagePath.isNull()) { - Trace() << "No mime message"; + SinkTrace() << "No mime message"; return; } - Trace() << "Updating indexed properties " << mimeMessagePath; + SinkTrace() << "Updating indexed properties " << mimeMessagePath; QFile f(mimeMessagePath); if (!f.open(QIODevice::ReadOnly)) { - Warning() << "Failed to open the file: " << mimeMessagePath; + SinkWarning() << "Failed to open the file: " << mimeMessagePath; return; } if (!f.size()) { - Warning() << "The file is empty."; + SinkWarning() << "The file is empty."; return; } const auto mappedSize = qMin((qint64)8000, f.size()); auto mapped = f.map(0, mappedSize); if (!mapped) { - Warning() << "Failed to map the file: " << f.errorString(); + SinkWarning() << "Failed to map the file: " << f.errorString(); return; } @@ -89,15 +91,15 @@ QString MimeMessageMover::moveMessage(const QString &oldPath, const Sink::Applic const auto filePath = directory + "/" + mail.identifier(); if (oldPath != filePath) { if (!QDir().mkpath(directory)) { - Warning() << "Failed to create the directory: " << directory; + SinkWarning() << "Failed to create the directory: " << directory; } QFile::remove(filePath); QFile origFile(oldPath); if (!origFile.open(QIODevice::ReadWrite)) { - Warning() << "Failed to open the original file with write rights: " << origFile.errorString(); + SinkWarning() << "Failed to open the original file with write rights: " << origFile.errorString(); } if (!origFile.rename(filePath)) { - Warning() << "Failed to move the file from: " << oldPath << " to " << filePath << ". " << origFile.errorString(); + SinkWarning() << "Failed to move the file from: " << oldPath << " to " << filePath << ". " << origFile.errorString(); } origFile.close(); return filePath; diff --git a/common/messagequeue.cpp b/common/messagequeue.cpp index b9f11f8..a6e44e3 100644 --- a/common/messagequeue.cpp +++ b/common/messagequeue.cpp @@ -3,6 +3,8 @@ #include #include +SINK_DEBUG_AREA("messagequeue") + static KAsync::Job waitForCompletion(QList> &futures) { auto context = new QObject; @@ -128,7 +130,7 @@ KAsync::Job MessageQueue::dequeueBatch(int maxBatchSize, const std::functi return false; }, [](const Sink::Storage::Error &error) { - ErrorMsg() << "Error while retrieving value" << error.message; + SinkError() << "Error while retrieving value" << error.message; // errorHandler(Error(error.store, error.code, error.message)); }); @@ -164,7 +166,7 @@ bool MessageQueue::isEmpty() } return true; }, - [](const Sink::Storage::Error &error) { ErrorMsg() << "Error while checking if empty" << error.message; }); + [](const Sink::Storage::Error &error) { SinkError() << "Error while checking if empty" << error.message; }); } return count == 0; } diff --git a/common/modelresult.cpp b/common/modelresult.cpp index 3778d4d..56a39ee 100644 --- a/common/modelresult.cpp +++ b/common/modelresult.cpp @@ -25,8 +25,7 @@ #include "domain/folder.h" #include "log.h" -#undef DEBUG_AREA -#define DEBUG_AREA "client.modelresult" +SINK_DEBUG_AREA("modelresult") static uint qHash(const Sink::ApplicationDomain::ApplicationDomainType &type) { @@ -123,7 +122,7 @@ QModelIndex ModelResult::index(int row, int column, const QModelIndex &p const auto childId = list.at(row); return createIndex(row, column, childId); } - Warning() << "Index not available " << row << column << parent; + SinkWarning() << "Index not available " << row << column << parent; Q_ASSERT(false); return QModelIndex(); } @@ -174,7 +173,7 @@ bool ModelResult::canFetchMore(const QModelIndex &parent) const template void ModelResult::fetchMore(const QModelIndex &parent) { - Trace() << "Fetching more: " << parent; + SinkTrace() << "Fetching more: " << parent; fetchEntities(parent); } @@ -185,7 +184,7 @@ void ModelResult::add(const Ptr &value) const auto id = parentId(value); // Ignore updates we get before the initial fetch is done if (!mEntityChildrenFetched.contains(id)) { - Trace() << "Too early" << id; + SinkTrace() << "Too early" << id; return; } auto parent = createIndexFromId(id); @@ -198,7 +197,7 @@ void ModelResult::add(const Ptr &value) } } if (mEntities.contains(childId)) { - Warning() << "Entity already in model " << value->identifier(); + SinkWarning() << "Entity already in model " << value->identifier(); return; } // qDebug() << "Inserting rows " << index << parent; @@ -234,18 +233,18 @@ void ModelResult::fetchEntities(const QModelIndex &parent) const auto id = getIdentifier(parent); mEntityChildrenFetchComplete.remove(id); mEntityChildrenFetched.insert(id); - Trace() << "Loading child entities of parent " << id; + SinkTrace() << "Loading child entities of parent " << id; if (loadEntities) { loadEntities(parent.data(DomainObjectRole).template value()); } else { - Warning() << "No way to fetch entities"; + SinkWarning() << "No way to fetch entities"; } } template void ModelResult::setFetcher(const std::function &fetcher) { - Trace() << "Setting fetcher"; + SinkTrace() << "Setting fetcher"; loadEntities = fetcher; } @@ -270,7 +269,7 @@ void ModelResult::setEmitter(const typename Sink::ResultEmitter::Pt }); }); emitter->onInitialResultSetComplete([this](const Ptr &parent) { - Trace() << "Initial result set complete"; + SinkTrace() << "Initial result set complete"; const qint64 parentId = parent ? qHash(*parent) : 0; const auto parentIndex = createIndexFromId(parentId); mEntityChildrenFetchComplete.insert(parentId); diff --git a/common/pipeline.cpp b/common/pipeline.cpp index 034f913..f1a4a32 100644 --- a/common/pipeline.cpp +++ b/common/pipeline.cpp @@ -38,8 +38,7 @@ #include "definitions.h" #include "bufferutils.h" -#undef DEBUG_AREA -#define DEBUG_AREA "resource.pipeline" +SINK_DEBUG_AREA("pipeline") namespace Sink { @@ -63,10 +62,10 @@ public: void Pipeline::Private::storeNewRevision(qint64 newRevision, const flatbuffers::FlatBufferBuilder &fbb, const QByteArray &bufferType, const QByteArray &uid) { - Trace() << "Committing new revision: " << uid << newRevision; + SinkTrace() << "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; }); + [uid, newRevision](const Storage::Error &error) { SinkWarning() << "Failed to write entity" << uid << newRevision; }); revisionChanged = true; Storage::setMaxRevision(transaction, newRevision); Storage::recordRevision(transaction, newRevision, uid, bufferType); @@ -107,11 +106,11 @@ void Pipeline::startTransaction() if (d->transaction) { return; } - Trace() << "Starting transaction."; + SinkTrace() << "Starting transaction."; d->transactionTime.start(); d->transactionItemCount = 0; d->transaction = storage().createTransaction(Storage::ReadWrite, [](const Sink::Storage::Error &error) { - Warning() << error.message; + SinkWarning() << error.message; }); //FIXME this is a temporary measure to recover from a failure to open the named databases correctly. @@ -119,9 +118,9 @@ void Pipeline::startTransaction() //It seems like the validateNamedDatabase calls actually stops the mdb_put failures during sync... if (d->storage.exists()) { while (!d->transaction.validateNamedDatabases()) { - Warning() << "Opened an invalid transaction!!!!!!"; + SinkWarning() << "Opened an invalid transaction!!!!!!"; d->transaction = std::move(storage().createTransaction(Storage::ReadWrite, [](const Sink::Storage::Error &error) { - Warning() << error.message; + SinkWarning() << error.message; })); } } @@ -141,7 +140,7 @@ void Pipeline::commit() } const auto revision = Storage::maxRevision(d->transaction); const auto elapsed = d->transactionTime.elapsed(); - Log() << "Committing revision: " << revision << ":" << d->transactionItemCount << " items in: " << Log::TraceTime(elapsed) << " " + SinkLog() << "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(); @@ -170,7 +169,7 @@ KAsync::Job Pipeline::newEntity(void const *command, size_t size) { flatbuffers::Verifier verifyer(reinterpret_cast(command), size); if (!Commands::VerifyCreateEntityBuffer(verifyer)) { - Warning() << "invalid buffer, not a create entity buffer"; + SinkWarning() << "invalid buffer, not a create entity buffer"; return KAsync::error(0); } } @@ -182,7 +181,7 @@ KAsync::Job Pipeline::newEntity(void const *command, size_t size) if (createEntity->entityId()) { key = QByteArray(reinterpret_cast(createEntity->entityId()->Data()), createEntity->entityId()->size()); if (Storage::mainDatabase(d->transaction, bufferType).contains(key)) { - ErrorMsg() << "An entity with this id already exists: " << key; + SinkError() << "An entity with this id already exists: " << key; return KAsync::error(0); } } @@ -190,25 +189,25 @@ 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; + SinkLog() << "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"; + SinkWarning() << "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."; + SinkWarning() << "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; + SinkWarning() << "no adaptor factory for type " << bufferType; return KAsync::error(0); } @@ -244,7 +243,7 @@ KAsync::Job Pipeline::modifiedEntity(void const *command, size_t size) { flatbuffers::Verifier verifyer(reinterpret_cast(command), size); if (!Commands::VerifyModifyEntityBuffer(verifyer)) { - Warning() << "invalid buffer, not a modify entity buffer"; + SinkWarning() << "invalid buffer, not a modify entity buffer"; return KAsync::error(0); } } @@ -254,21 +253,21 @@ KAsync::Job Pipeline::modifiedEntity(void const *command, size_t size) if (modifyEntity->modifiedProperties()) { changeset = BufferUtils::fromVector(*modifyEntity->modifiedProperties()); } else { - Warning() << "No changeset available"; + SinkWarning() << "No changeset available"; } const qint64 baseRevision = modifyEntity->revision(); const bool replayToSource = modifyEntity->replayToSource(); 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; + SinkLog() << "Modified Entity. Type: " << bufferType << "uid: "<< key << " replayToSource: " << replayToSource; if (bufferType.isEmpty() || key.isEmpty()) { - Warning() << "entity type or key " << bufferType << key; + SinkWarning() << "entity type or key " << bufferType << key; return KAsync::error(0); } { flatbuffers::Verifier verifyer(reinterpret_cast(modifyEntity->delta()->Data()), modifyEntity->delta()->size()); if (!VerifyEntityBuffer(verifyer)) { - Warning() << "invalid buffer, not an entity buffer"; + SinkWarning() << "invalid buffer, not an entity buffer"; return KAsync::error(0); } } @@ -276,7 +275,7 @@ KAsync::Job Pipeline::modifiedEntity(void const *command, size_t size) // TODO use only readPropertyMapper and writePropertyMapper auto adaptorFactory = Sink::AdaptorFactoryRegistry::instance().getFactory(d->resourceType, bufferType); if (!adaptorFactory) { - Warning() << "no adaptor factory for type " << bufferType; + SinkWarning() << "no adaptor factory for type " << bufferType; return KAsync::error(0); } @@ -290,16 +289,16 @@ KAsync::Job Pipeline::modifiedEntity(void const *command, size_t size) [¤t, adaptorFactory](const QByteArray &key, const QByteArray &data) -> bool { EntityBuffer buffer(const_cast(data.data()), data.size()); if (!buffer.isValid()) { - Warning() << "Read invalid buffer from disk"; + SinkWarning() << "Read invalid buffer from disk"; } else { current = adaptorFactory->createAdaptor(buffer.entity()); } return false; }, - [baseRevision](const Storage::Error &error) { Warning() << "Failed to read old revision from storage: " << error.message << "Revision: " << baseRevision; }); + [baseRevision](const Storage::Error &error) { SinkWarning() << "Failed to read old revision from storage: " << error.message << "Revision: " << baseRevision; }); if (!current) { - Warning() << "Failed to read local value " << key; + SinkWarning() << "Failed to read local value " << key; return KAsync::error(0); } @@ -307,7 +306,7 @@ KAsync::Job Pipeline::modifiedEntity(void const *command, size_t size) // Apply diff // FIXME only apply the properties that are available in the buffer - Trace() << "Applying changed properties: " << changeset; + SinkTrace() << "Applying changed properties: " << changeset; for (const auto &property : changeset) { const auto value = diff->getProperty(property); if (value.isValid()) { @@ -357,7 +356,7 @@ KAsync::Job Pipeline::deletedEntity(void const *command, size_t size) { flatbuffers::Verifier verifyer(reinterpret_cast(command), size); if (!Commands::VerifyDeleteEntityBuffer(verifyer)) { - Warning() << "invalid buffer, not a delete entity buffer"; + SinkWarning() << "invalid buffer, not a delete entity buffer"; return KAsync::error(0); } } @@ -366,7 +365,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; + SinkLog() << "Deleted Entity. Type: " << bufferType << "uid: "<< key << " replayToSource: " << replayToSource; bool found = false; bool alreadyRemoved = false; @@ -383,14 +382,14 @@ KAsync::Job Pipeline::deletedEntity(void const *command, size_t size) } return false; }, - [](const Storage::Error &error) { Warning() << "Failed to read old revision from storage: " << error.message; }); + [](const Storage::Error &error) { SinkWarning() << "Failed to read old revision from storage: " << error.message; }); if (!found) { - Warning() << "Failed to find entity " << key; + SinkWarning() << "Failed to find entity " << key; return KAsync::error(0); } if (alreadyRemoved) { - Warning() << "Entity is already removed " << key; + SinkWarning() << "Entity is already removed " << key; return KAsync::error(0); } @@ -410,7 +409,7 @@ KAsync::Job Pipeline::deletedEntity(void const *command, size_t size) auto adaptorFactory = Sink::AdaptorFactoryRegistry::instance().getFactory(d->resourceType, bufferType); if (!adaptorFactory) { - Warning() << "no adaptor factory for type " << bufferType; + SinkWarning() << "no adaptor factory for type " << bufferType; return KAsync::error(0); } @@ -420,13 +419,13 @@ KAsync::Job Pipeline::deletedEntity(void const *command, size_t size) [this, bufferType, newRevision, adaptorFactory, key, ¤t](const QByteArray &, const QByteArray &data) -> bool { EntityBuffer buffer(const_cast(data.data()), data.size()); if (!buffer.isValid()) { - Warning() << "Read invalid buffer from disk"; + SinkWarning() << "Read invalid buffer from disk"; } else { current = adaptorFactory->createAdaptor(buffer.entity()); } return false; }, - [this](const Storage::Error &error) { ErrorMsg() << "Failed to find value in pipeline: " << error.message; }); + [this](const Storage::Error &error) { SinkError() << "Failed to find value in pipeline: " << error.message; }); d->storeNewRevision(newRevision, fbb, bufferType, key); @@ -442,13 +441,13 @@ void Pipeline::cleanupRevision(qint64 revision) d->revisionChanged = true; const auto uid = Storage::getUidFromRevision(d->transaction, revision); const auto bufferType = Storage::getTypeFromRevision(d->transaction, revision); - Trace() << "Cleaning up revision " << revision << uid << bufferType; + SinkTrace() << "Cleaning up revision " << revision << uid << bufferType; Storage::mainDatabase(d->transaction, bufferType) .scan(uid, [&](const QByteArray &key, const QByteArray &data) -> bool { EntityBuffer buffer(const_cast(data.data()), data.size()); if (!buffer.isValid()) { - Warning() << "Read invalid buffer from disk"; + SinkWarning() << "Read invalid buffer from disk"; } else { const auto metadata = flatbuffers::GetRoot(buffer.metadataBuffer()); const qint64 rev = metadata->revision(); @@ -461,7 +460,7 @@ void Pipeline::cleanupRevision(qint64 revision) return true; }, - [](const Storage::Error &error) { Warning() << "Error while reading: " << error.message; }, true); + [](const Storage::Error &error) { SinkWarning() << "Error while reading: " << error.message; }, true); Storage::setCleanedUpRevision(d->transaction, revision); } diff --git a/common/queryrunner.cpp b/common/queryrunner.cpp index 0be2ae1..2e2e96d 100644 --- a/common/queryrunner.cpp +++ b/common/queryrunner.cpp @@ -29,8 +29,7 @@ #include "asyncutils.h" #include "entityreader.h" -#undef DEBUG_AREA -#define DEBUG_AREA "client.queryrunner" +SINK_DEBUG_AREA("queryrunner") using namespace Sink; @@ -43,6 +42,8 @@ using namespace Sink; template class QueryWorker : public QObject { + // SINK_DEBUG_COMPONENT(mResourceInstanceIdentifier, mId) + SINK_DEBUG_COMPONENT(mResourceInstanceIdentifier) public: QueryWorker(const Sink::Query &query, const QByteArray &instanceIdentifier, const DomainTypeAdaptorFactoryInterface::Ptr &, const QByteArray &bufferType, const QueryRunnerBase::ResultTransformation &transformation); @@ -61,22 +62,19 @@ private: QByteArray mId; //Used for identification in debug output }; -#undef Trace -#define Trace() Trace_area(DEBUG_AREA) - template QueryRunner::QueryRunner(const Sink::Query &query, const Sink::ResourceAccessInterface::Ptr &resourceAccess, const QByteArray &instanceIdentifier, const DomainTypeAdaptorFactoryInterface::Ptr &factory, const QByteArray &bufferType) : QueryRunnerBase(), mResourceAccess(resourceAccess), mResultProvider(new ResultProvider), mBatchSize(query.limit) { - Trace() << "Starting query"; + SinkTrace() << "Starting query"; if (query.limit && query.sortProperty.isEmpty()) { - Warning() << "A limited query without sorting is typically a bad idea."; + SinkWarning() << "A limited query without sorting is typically a bad idea."; } // We delegate loading of initial data to the result provider, so it can decide for itself what it needs to load. mResultProvider->setFetcher([=](const typename DomainType::Ptr &parent) { const QByteArray parentId = parent ? parent->identifier() : QByteArray(); - Trace() << "Running fetcher. Offset: " << mOffset[parentId] << " Batchsize: " << mBatchSize; + SinkTrace() << "Running fetcher. Offset: " << mOffset[parentId] << " Batchsize: " << mBatchSize; auto resultProvider = mResultProvider; if (query.synchronousQuery) { QueryWorker worker(query, instanceIdentifier, factory, bufferType, mResultTransformation); @@ -131,7 +129,7 @@ QueryRunner::QueryRunner(const Sink::Query &query, const Sink::Resou template QueryRunner::~QueryRunner() { - Trace() << "Stopped query"; + SinkTrace() << "Stopped query"; } template @@ -147,21 +145,18 @@ typename Sink::ResultEmitter::Ptr QueryRunner QueryWorker::QueryWorker(const Sink::Query &query, const QByteArray &instanceIdentifier, const DomainTypeAdaptorFactoryInterface::Ptr &factory, const QByteArray &bufferType, const QueryRunnerBase::ResultTransformation &transformation) : QObject(), mResultTransformation(transformation), mDomainTypeAdaptorFactory(factory), mResourceInstanceIdentifier(instanceIdentifier), mId(QUuid::createUuid().toByteArray()) { - Trace() << "Starting query worker"; + SinkTrace() << "Starting query worker"; } template QueryWorker::~QueryWorker() { - Trace() << "Stopped query worker"; + SinkTrace() << "Stopped query worker"; } template @@ -174,15 +169,15 @@ std::function QueryWork } switch (operation) { case Sink::Operation_Creation: - // Trace() << "Got creation"; + // SinkTrace() << "Got creation"; resultProvider.add(valueCopy); break; case Sink::Operation_Modification: - // Trace() << "Got modification"; + // SinkTrace() << "Got modification"; resultProvider.modify(valueCopy); break; case Sink::Operation_Removal: - // Trace() << "Got removal"; + // SinkTrace() << "Got removal"; resultProvider.remove(valueCopy); break; } @@ -200,7 +195,7 @@ QPair QueryWorker::executeIncrementalQuery(const Sin Sink::EntityReader reader(*mDomainTypeAdaptorFactory, mResourceInstanceIdentifier, transaction); auto revisionAndReplayedEntities = reader.executeIncrementalQuery(query, resultProvider.revision(), resultProviderCallback(query, resultProvider)); - Trace() << "Incremental query took: " << Log::TraceTime(time.elapsed()); + SinkTrace() << "Incremental query took: " << Log::TraceTime(time.elapsed()); return revisionAndReplayedEntities; } @@ -212,10 +207,10 @@ Storage::Transaction QueryWorker::getTransaction() Sink::Storage storage(Sink::storageLocation(), mResourceInstanceIdentifier); if (!storage.exists()) { //This is not an error if the resource wasn't started before - Log() << "Store doesn't exist: " << mResourceInstanceIdentifier; + SinkLog() << "Store doesn't exist: " << mResourceInstanceIdentifier; return Sink::Storage::Transaction(); } - storage.setDefaultErrorHandler([](const Sink::Storage::Error &error) { Warning() << "Error during query: " << error.store << error.message; }); + storage.setDefaultErrorHandler([this](const Sink::Storage::Error &error) { SinkWarning() << "Error during query: " << error.store << error.message; }); transaction = storage.createTransaction(Sink::Storage::ReadOnly); } @@ -238,10 +233,10 @@ QPair QueryWorker::executeInitialQuery( auto modifiedQuery = query; if (!query.parentProperty.isEmpty()) { if (parent) { - Trace() << "Running initial query for parent:" << parent->identifier(); + SinkTrace() << "Running initial query for parent:" << parent->identifier(); modifiedQuery.propertyFilter.insert(query.parentProperty, Query::Comparator(parent->identifier())); } else { - Trace() << "Running initial query for toplevel"; + SinkTrace() << "Running initial query for toplevel"; modifiedQuery.propertyFilter.insert(query.parentProperty, Query::Comparator(QVariant())); } } @@ -250,7 +245,7 @@ QPair QueryWorker::executeInitialQuery( Sink::EntityReader reader(*mDomainTypeAdaptorFactory, mResourceInstanceIdentifier, transaction); auto revisionAndReplayedEntities = reader.executeInitialQuery(modifiedQuery, offset, batchsize, resultProviderCallback(query, resultProvider)); - Trace() << "Initial query took: " << Log::TraceTime(time.elapsed()); + SinkTrace() << "Initial query took: " << Log::TraceTime(time.elapsed()); return revisionAndReplayedEntities; } diff --git a/common/queryrunner.h b/common/queryrunner.h index e6d5a54..155528e 100644 --- a/common/queryrunner.h +++ b/common/queryrunner.h @@ -32,6 +32,8 @@ class QueryRunnerBase : public QObject { Q_OBJECT +protected: + SINK_DEBUG_AREA("queryrunner") public: typedef std::function ResultTransformation; @@ -52,7 +54,7 @@ protected slots: */ void revisionChanged(qint64 newRevision) { - Trace() << "New revision: " << newRevision; + SinkTrace() << "New revision: " << newRevision; run().exec(); } diff --git a/common/remoteidmap.cpp b/common/remoteidmap.cpp index bbcd641..20a054d 100644 --- a/common/remoteidmap.cpp +++ b/common/remoteidmap.cpp @@ -25,6 +25,8 @@ using namespace Sink; +SINK_DEBUG_AREA("remoteidmap") + RemoteIdMap::RemoteIdMap(Sink::Storage::Transaction &transaction) : mTransaction(transaction) { @@ -67,7 +69,7 @@ QByteArray RemoteIdMap::resolveLocalId(const QByteArray &bufferType, const QByte { QByteArray remoteId = Index("localid.mapping." + bufferType, mTransaction).lookup(localId); if (remoteId.isEmpty()) { - Warning() << "Couldn't find the remote id for " << localId; + SinkWarning() << "Couldn't find the remote id for " << localId; return QByteArray(); } return remoteId; diff --git a/common/resourceaccess.cpp b/common/resourceaccess.cpp index 93f97e8..c878143 100644 --- a/common/resourceaccess.cpp +++ b/common/resourceaccess.cpp @@ -44,12 +44,6 @@ #include #include -#undef Trace -#define TracePrivate() Trace_area("client.communication." + resourceInstanceIdentifier) -#define Trace() Trace_area("client.communication." + d->resourceInstanceIdentifier) -#undef Log -#define Log() Log_area("client.communication." + d->resourceInstanceIdentifier) - static void queuedInvoke(const std::function &f, QObject *context = 0) { auto timer = QSharedPointer::create(); @@ -100,8 +94,10 @@ public: QHash completeCommands; uint messageId; bool openingSocket; + SINK_DEBUG_COMPONENT(resourceInstanceIdentifier) }; + ResourceAccess::Private::Private(const QByteArray &name, const QByteArray &instanceIdentifier, ResourceAccess *q) : resourceName(name), resourceInstanceIdentifier(instanceIdentifier), messageId(0), openingSocket(false) { @@ -111,7 +107,7 @@ void ResourceAccess::Private::abortPendingOperations() { callCallbacks(); if (!resultHandler.isEmpty()) { - Warning() << "Aborting pending operations " << resultHandler.keys(); + SinkWarning() << "Aborting pending operations " << resultHandler.keys(); } auto handlers = resultHandler.values(); resultHandler.clear(); @@ -165,7 +161,7 @@ KAsync::Job ResourceAccess::Private::tryToConnect() auto counter = QSharedPointer::create(0); return KAsync::dowhile([this]() -> bool { return !socket; }, [this, counter](KAsync::Future &future) { - TracePrivate() << "Loop"; + SinkTrace() << "Loop"; connectToServer(resourceInstanceIdentifier) .then>( [this, &future](const QSharedPointer &s) { @@ -178,7 +174,7 @@ KAsync::Job ResourceAccess::Private::tryToConnect() static int timeout = 500; static int maxRetries = timeout / waitTime; if (*counter > maxRetries) { - TracePrivate() << "Giving up"; + SinkTrace() << "Giving up"; future.setError(-1, "Failed to connect to socket"); } else { KAsync::wait(waitTime).then([&future]() { future.setFinished(); }).exec(); @@ -192,17 +188,17 @@ KAsync::Job ResourceAccess::Private::tryToConnect() KAsync::Job ResourceAccess::Private::initializeSocket() { return KAsync::start([this](KAsync::Future &future) { - TracePrivate() << "Trying to connect"; + SinkTrace() << "Trying to connect"; connectToServer(resourceInstanceIdentifier) .then>( [this, &future](const QSharedPointer &s) { - TracePrivate() << "Connected to resource, without having to start it."; + SinkTrace() << "Connected to resource, without having to start it."; Q_ASSERT(s); socket = s; future.setFinished(); }, [this, &future](int errorCode, const QString &errorString) { - TracePrivate() << "Failed to connect, starting resource"; + SinkTrace() << "Failed to connect, starting resource"; // We failed to connect, so let's start the resource QStringList args; if (Sink::Test::testModeEnabled()) { @@ -211,16 +207,16 @@ KAsync::Job ResourceAccess::Private::initializeSocket() args << resourceInstanceIdentifier << resourceName; qint64 pid = 0; if (QProcess::startDetached("sink_synchronizer", args, QDir::homePath(), &pid)) { - TracePrivate() << "Started resource " << pid; + SinkTrace() << "Started resource " << pid; tryToConnect() .then([&future]() { future.setFinished(); }, [this, &future](int errorCode, const QString &errorString) { - Warning() << "Failed to connect to started resource"; + SinkWarning() << "Failed to connect to started resource"; future.setError(errorCode, errorString); }) .exec(); } else { - Warning() << "Failed to start resource"; + SinkWarning() << "Failed to start resource"; } }) .exec(); @@ -231,14 +227,14 @@ ResourceAccess::ResourceAccess(const QByteArray &resourceInstanceIdentifier, con : ResourceAccessInterface(), d(new Private(resourceType, resourceInstanceIdentifier, this)) { mResourceStatus = Sink::ApplicationDomain::OfflineStatus; - Trace() << "Starting access"; + SinkTrace() << "Starting access"; } ResourceAccess::~ResourceAccess() { - Log() << "Closing access"; + SinkLog() << "Closing access"; if (!d->resultHandler.isEmpty()) { - Warning() << "Left jobs running while shutting down ResourceAccess: " << d->resultHandler.keys(); + SinkWarning() << "Left jobs running while shutting down ResourceAccess: " << d->resultHandler.keys(); } } @@ -295,7 +291,7 @@ KAsync::Job ResourceAccess::sendCommand(int commandId, flatbuffers::FlatBu KAsync::Job ResourceAccess::synchronizeResource(bool sourceSync, bool localSync) { - Trace() << "Sending synchronize command: " << sourceSync << localSync; + SinkTrace() << "Sending synchronize command: " << sourceSync << localSync; flatbuffers::FlatBufferBuilder fbb; auto command = Sink::Commands::CreateSynchronize(fbb, sourceSync, localSync); Sink::Commands::FinishSynchronizeBuffer(fbb, command); @@ -376,7 +372,7 @@ ResourceAccess::sendInspectionCommand(int inspectionType, const QByteArray &insp void ResourceAccess::open() { if (d->socket && d->socket->isValid()) { - // Trace() << "Socket valid, so not opening again"; + // SinkTrace() << "Socket valid, so not opening again"; return; } if (d->openingSocket) { @@ -388,7 +384,7 @@ void ResourceAccess::open() d->initializeSocket() .then( [this, time]() { - Trace() << "Socket is initialized." << Log::TraceTime(time->elapsed()); + SinkTrace() << "Socket is initialized." << Log::TraceTime(time->elapsed()); d->openingSocket = false; QObject::connect(d->socket.data(), &QLocalSocket::disconnected, this, &ResourceAccess::disconnected); QObject::connect(d->socket.data(), SIGNAL(error(QLocalSocket::LocalSocketError)), this, SLOT(connectionError(QLocalSocket::LocalSocketError))); @@ -397,16 +393,16 @@ void ResourceAccess::open() }, [this](int error, const QString &errorString) { d->openingSocket = false; - Warning() << "Failed to initialize socket " << errorString; + SinkWarning() << "Failed to initialize socket " << errorString; }) .exec(); } void ResourceAccess::close() { - Log() << QString("Closing %1").arg(d->socket->fullServerName()); - Trace() << "Pending commands: " << d->pendingCommands.size(); - Trace() << "Queued commands: " << d->commandQueue.size(); + SinkLog() << QString("Closing %1").arg(d->socket->fullServerName()); + SinkTrace() << "Pending commands: " << d->pendingCommands.size(); + SinkTrace() << "Queued commands: " << d->commandQueue.size(); d->socket->close(); } @@ -416,10 +412,10 @@ void ResourceAccess::sendCommand(const QSharedPointer &command) // TODO: we should have a timeout for commands d->messageId++; const auto messageId = d->messageId; - Trace() << QString("Sending command \"%1\" with messageId %2").arg(QString(Sink::Commands::name(command->commandId))).arg(d->messageId); + SinkTrace() << 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; + SinkTrace() << "Command complete " << messageId; d->pendingCommands.remove(messageId); command->callback(errorCode, errorMessage); }); @@ -431,8 +427,8 @@ void ResourceAccess::sendCommand(const QSharedPointer &command) void ResourceAccess::processCommandQueue() { // TODO: serialize instead of blast them all through the socket? - Trace() << "We have " << d->commandQueue.size() << " queued commands"; - Trace() << "Pending commands: " << d->pendingCommands.size(); + SinkTrace() << "We have " << d->commandQueue.size() << " queued commands"; + SinkTrace() << "Pending commands: " << d->pendingCommands.size(); for (auto command : d->commandQueue) { sendCommand(command); } @@ -441,9 +437,9 @@ void ResourceAccess::processCommandQueue() void ResourceAccess::processPendingCommandQueue() { - Trace() << "We have " << d->pendingCommands.size() << " pending commands"; + SinkTrace() << "We have " << d->pendingCommands.size() << " pending commands"; for (auto command : d->pendingCommands) { - Trace() << "Reenquing command " << command->commandId; + SinkTrace() << "Reenquing command " << command->commandId; d->commandQueue << command; } d->pendingCommands.clear(); @@ -453,11 +449,11 @@ void ResourceAccess::processPendingCommandQueue() void ResourceAccess::connected() { if (!isReady()) { - Trace() << "Connected but not ready?"; + SinkTrace() << "Connected but not ready?"; return; } - Trace() << QString("Connected: %1").arg(d->socket->fullServerName()); + SinkTrace() << QString("Connected: %1").arg(d->socket->fullServerName()); { flatbuffers::FlatBufferBuilder fbb; @@ -477,7 +473,7 @@ void ResourceAccess::connected() void ResourceAccess::disconnected() { - Log() << QString("Disconnected from %1").arg(d->socket->fullServerName()); + SinkLog() << QString("Disconnected from %1").arg(d->socket->fullServerName()); d->socket->close(); emit ready(false); } @@ -486,15 +482,15 @@ void ResourceAccess::connectionError(QLocalSocket::LocalSocketError error) { const bool resourceCrashed = d->partialMessageBuffer.contains("PANIC"); if (resourceCrashed) { - ErrorMsg() << "The resource crashed!"; + SinkError() << "The resource crashed!"; d->abortPendingOperations(); } else if (error == QLocalSocket::PeerClosedError) { - Log() << "The resource closed the connection."; + SinkLog() << "The resource closed the connection."; d->abortPendingOperations(); } else { - Warning() << QString("Connection error: %1 : %2").arg(error).arg(d->socket->errorString()); + SinkWarning() << QString("Connection error: %1 : %2").arg(error).arg(d->socket->errorString()); if (d->pendingCommands.size()) { - Trace() << "Reconnecting due to pending operations: " << d->pendingCommands.size(); + SinkTrace() << "Reconnecting due to pending operations: " << d->pendingCommands.size(); open(); } } @@ -503,7 +499,7 @@ void ResourceAccess::connectionError(QLocalSocket::LocalSocketError error) void ResourceAccess::readResourceMessage() { if (!d->socket || !d->socket->isValid()) { - Warning() << "No socket available"; + SinkWarning() << "No socket available"; return; } @@ -534,7 +530,7 @@ bool ResourceAccess::processMessageBuffer() { static const int headerSize = Commands::headerSize(); if (d->partialMessageBuffer.size() < headerSize) { - Warning() << "command too small"; + SinkWarning() << "command too small"; return false; } @@ -543,14 +539,14 @@ bool ResourceAccess::processMessageBuffer() const uint size = *(int *)(d->partialMessageBuffer.constData() + sizeof(int) + sizeof(uint)); if (size > (uint)(d->partialMessageBuffer.size() - headerSize)) { - Warning() << "command too small"; + SinkWarning() << "command too small"; return false; } switch (commandId) { case Commands::RevisionUpdateCommand: { auto buffer = Commands::GetRevisionUpdate(d->partialMessageBuffer.constData() + headerSize); - Trace() << QString("Revision updated to: %1").arg(buffer->revision()); + SinkTrace() << QString("Revision updated to: %1").arg(buffer->revision()); Notification n; n.type = Sink::Notification::RevisionUpdate; emit notification(n); @@ -560,7 +556,7 @@ bool ResourceAccess::processMessageBuffer() } case Commands::CommandCompletionCommand: { auto buffer = Commands::GetCommandCompletion(d->partialMessageBuffer.constData() + headerSize); - Trace() << QString("Command with messageId %1 completed %2").arg(buffer->id()).arg(buffer->success() ? "sucessfully" : "unsuccessfully"); + SinkTrace() << 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 @@ -571,33 +567,33 @@ bool ResourceAccess::processMessageBuffer() auto buffer = Commands::GetNotification(d->partialMessageBuffer.constData() + headerSize); switch (buffer->type()) { case Sink::Notification::Shutdown: - Log() << "Received shutdown notification."; + SinkLog() << "Received shutdown notification."; close(); break; case Sink::Notification::Inspection: { - Trace() << "Received inspection notification."; + SinkTrace() << "Received inspection notification."; auto n = getNotification(buffer); // The callbacks can result in this object getting destroyed directly, so we need to ensure we finish our work first queuedInvoke([=]() { emit notification(n); }, this); } break; case Sink::Notification::Status: if (mResourceStatus == buffer->code()) { - Trace() << "Got an unnecessary status notification"; + SinkTrace() << "Got an unnecessary status notification"; break; } mResourceStatus = buffer->code(); - Trace() << "Updated status: " << mResourceStatus; + SinkTrace() << "Updated status: " << mResourceStatus; [[clang::fallthrough]]; case Sink::Notification::Warning: [[clang::fallthrough]]; case Sink::Notification::Progress: { auto n = getNotification(buffer); - Trace() << "Received notification: " << n.type; + SinkTrace() << "Received notification: " << n.type; emit notification(n); } break; case Sink::Notification::RevisionUpdate: default: - Warning() << "Received unknown notification: " << buffer->type(); + SinkWarning() << "Received unknown notification: " << buffer->type(); break; } break; diff --git a/common/resourceaccess.h b/common/resourceaccess.h index 47b848e..5d66246 100644 --- a/common/resourceaccess.h +++ b/common/resourceaccess.h @@ -29,6 +29,7 @@ #include #include "notification.h" +#include "log.h" namespace Sink { @@ -93,6 +94,7 @@ protected: class SINK_EXPORT ResourceAccess : public ResourceAccessInterface { Q_OBJECT + SINK_DEBUG_AREA("communication") public: typedef QSharedPointer Ptr; @@ -138,6 +140,7 @@ private: class Private; Private *const d; + // SINK_DEBUG_COMPONENT(d->resourceInstanceIdentifier) }; /** @@ -147,6 +150,7 @@ private: */ class SINK_EXPORT ResourceAccessFactory { + SINK_DEBUG_AREA("ResourceAccessFactory") public: static ResourceAccessFactory &instance(); Sink::ResourceAccess::Ptr getAccess(const QByteArray &instanceIdentifier, const QByteArray resourceType); diff --git a/common/resourcecontrol.cpp b/common/resourcecontrol.cpp index 5c2cd06..7d092a4 100644 --- a/common/resourcecontrol.cpp +++ b/common/resourcecontrol.cpp @@ -30,14 +30,13 @@ #include "log.h" #include "notifier.h" -#undef DEBUG_AREA -#define DEBUG_AREA "client.resourcecontrol" +SINK_DEBUG_AREA("resourcecontrol") namespace Sink { KAsync::Job ResourceControl::shutdown(const QByteArray &identifier) { - Trace() << "shutdown " << identifier; + SinkTrace() << "shutdown " << identifier; auto time = QSharedPointer::create(); time->start(); return ResourceAccess::connectToServer(identifier) @@ -50,33 +49,33 @@ KAsync::Job ResourceControl::shutdown(const QByteArray &identifier) resourceAccess->sendCommand(Sink::Commands::ShutdownCommand) .then([&future, resourceAccess, time]() { resourceAccess->close(); - Trace() << "Shutdown complete." << Log::TraceTime(time->elapsed()); + SinkTrace() << "Shutdown complete." << Log::TraceTime(time->elapsed()); future.setFinished(); }) .exec(); }, [](int, const QString &) { - Trace() << "Resource is already closed."; + SinkTrace() << "Resource is already closed."; // Resource isn't started, nothing to shutdown }); } KAsync::Job ResourceControl::start(const QByteArray &identifier) { - Trace() << "start " << identifier; + SinkTrace() << "start " << identifier; auto time = QSharedPointer::create(); time->start(); auto resourceAccess = ResourceAccessFactory::instance().getAccess(identifier, ResourceConfig::getResourceType(identifier)); resourceAccess->open(); - return resourceAccess->sendCommand(Sink::Commands::PingCommand).then([resourceAccess, time]() { Trace() << "Start complete." << Log::TraceTime(time->elapsed()); }); + return resourceAccess->sendCommand(Sink::Commands::PingCommand).then([resourceAccess, time]() { SinkTrace() << "Start complete." << Log::TraceTime(time->elapsed()); }); } KAsync::Job ResourceControl::flushMessageQueue(const QByteArrayList &resourceIdentifier) { - Trace() << "flushMessageQueue" << resourceIdentifier; + SinkTrace() << "flushMessageQueue" << resourceIdentifier; return KAsync::iterate(resourceIdentifier) .template each([](const QByteArray &resource, KAsync::Future &future) { - Trace() << "Flushing message queue " << resource; + SinkTrace() << "Flushing message queue " << resource; auto resourceAccess = ResourceAccessFactory::instance().getAccess(resource, ResourceConfig::getResourceType(resource)); resourceAccess->open(); resourceAccess->synchronizeResource(false, true).then([&future, resourceAccess]() { future.setFinished(); }).exec(); @@ -95,7 +94,7 @@ KAsync::Job ResourceControl::inspect(const Inspection &inspectionCommand) auto time = QSharedPointer::create(); time->start(); - Trace() << "Sending inspection " << resource; + SinkTrace() << "Sending inspection " << resource; auto resourceAccess = ResourceAccessFactory::instance().getAccess(resource, ResourceConfig::getResourceType(resource)); resourceAccess->open(); auto notifier = QSharedPointer::create(resourceAccess); @@ -104,7 +103,7 @@ KAsync::Job ResourceControl::inspect(const Inspection &inspectionCommand) .template then([resourceAccess, notifier, id, time](KAsync::Future &future) { notifier->registerHandler([&future, id, time](const Notification ¬ification) { if (notification.id == id) { - Trace() << "Inspection complete." << Log::TraceTime(time->elapsed()); + SinkTrace() << "Inspection complete." << Log::TraceTime(time->elapsed()); if (notification.code) { future.setError(-1, "Inspection returned an error: " + notification.message); } else { diff --git a/common/resourcefacade.cpp b/common/resourcefacade.cpp index 0bcc6b9..bdb5841 100644 --- a/common/resourcefacade.cpp +++ b/common/resourcefacade.cpp @@ -28,6 +28,8 @@ using namespace Sink; +SINK_DEBUG_AREA("ResourceFacade") + template ConfigNotifier LocalStorageFacade::sConfigNotifier; @@ -67,7 +69,7 @@ LocalStorageQueryRunner::LocalStorageQueryRunner(const Query &query, const auto type = entries.value(res); if (query.propertyFilter.contains("type") && query.propertyFilter.value("type").value.toByteArray() != type) { - Trace() << "Skipping due to type."; + SinkTrace() << "Skipping due to type."; continue; } if (!query.ids.isEmpty() && !query.ids.contains(res)) { @@ -75,10 +77,10 @@ LocalStorageQueryRunner::LocalStorageQueryRunner(const Query &query, } const auto configurationValues = mConfigStore.get(res); if (!matchesFilter(query.propertyFilter, configurationValues)){ - Trace() << "Skipping due to filter."; + SinkTrace() << "Skipping due to filter."; continue; } - Trace() << "Found match " << res; + SinkTrace() << "Found match " << res; auto entity = readFromConfig(mConfigStore, res, type); updateStatus(*entity); mResultProvider->add(entity); @@ -137,7 +139,7 @@ void LocalStorageQueryRunner::setStatusUpdater(const std::function void LocalStorageQueryRunner::statusChanged(const QByteArray &identifier) { - Trace() << "Status changed " << identifier; + SinkTrace() << "Status changed " << identifier; auto entity = readFromConfig(mConfigStore, identifier, ApplicationDomain::getTypeName()); updateStatus(*entity); mResultProvider->modify(entity); @@ -195,7 +197,7 @@ KAsync::Job LocalStorageFacade::modify(const DomainType &domai return KAsync::start([domainObject, this]() { const QByteArray identifier = domainObject.identifier(); if (identifier.isEmpty()) { - Warning() << "We need an \"identifier\" property to identify the entity to configure."; + SinkWarning() << "We need an \"identifier\" property to identify the entity to configure."; return; } auto changedProperties = domainObject.changedProperties(); @@ -221,10 +223,10 @@ KAsync::Job LocalStorageFacade::remove(const DomainType &domai return KAsync::start([domainObject, this]() { const QByteArray identifier = domainObject.identifier(); if (identifier.isEmpty()) { - Warning() << "We need an \"identifier\" property to identify the entity to configure"; + SinkWarning() << "We need an \"identifier\" property to identify the entity to configure"; return; } - Trace() << "Removing: " << identifier; + SinkTrace() << "Removing: " << identifier; mConfigStore.remove(identifier); sConfigNotifier.remove(QSharedPointer::create(domainObject)); }); @@ -259,7 +261,7 @@ QPair, typename Sink::ResultEmittercontains(resource.identifier())) { auto ret = QObject::connect(resourceAccess.data(), &ResourceAccess::notification, runner->guard(), [resource, runner, resourceAccess](const Notification ¬ification) { - Trace() << "Received notification in facade: " << notification.type; + SinkTrace() << "Received notification in facade: " << notification.type; if (notification.type == Notification::Status) { runner->statusChanged(resource.identifier()); } diff --git a/common/sourcewriteback.cpp b/common/sourcewriteback.cpp index a277606..7d21ea6 100644 --- a/common/sourcewriteback.cpp +++ b/common/sourcewriteback.cpp @@ -26,6 +26,8 @@ #define ENTITY_TYPE_MAIL "mail" #define ENTITY_TYPE_FOLDER "folder" +SINK_DEBUG_AREA("sourcewriteback") + using namespace Sink; SourceWriteBack::SourceWriteBack(const QByteArray &resourceType, const QByteArray &resourceInstanceIdentifier) @@ -55,14 +57,14 @@ RemoteIdMap &SourceWriteBack::syncStore() KAsync::Job SourceWriteBack::replay(const QByteArray &type, const QByteArray &key, const QByteArray &value) { - Trace() << "Replaying" << type << key; + SinkTrace() << "Replaying" << type << key; Sink::EntityBuffer buffer(value); const Sink::Entity &entity = buffer.entity(); const auto metadataBuffer = Sink::EntityBuffer::readBuffer(entity.metadata()); Q_ASSERT(metadataBuffer); if (!metadataBuffer->replayToSource()) { - Trace() << "Change is coming from the source"; + SinkTrace() << "Change is coming from the source"; return KAsync::null(); } Q_ASSERT(!mSyncStore); @@ -81,11 +83,11 @@ KAsync::Job SourceWriteBack::replay(const QByteArray &type, const QByteArr if (operation != Sink::Operation_Creation) { oldRemoteId = syncStore().resolveLocalId(type, uid); if (oldRemoteId.isEmpty()) { - Warning() << "Couldn't find the remote id for: " << type << uid; + SinkWarning() << "Couldn't find the remote id for: " << type << uid; return KAsync::error(1, "Couldn't find the remote id."); } } - Trace() << "Replaying " << key << type << uid << oldRemoteId; + SinkTrace() << "Replaying " << key << type << uid << oldRemoteId; KAsync::Job job = KAsync::null(); if (type == ENTITY_TYPE_FOLDER) { @@ -98,24 +100,24 @@ KAsync::Job SourceWriteBack::replay(const QByteArray &type, const QByteArr return job.then([this, operation, type, uid, oldRemoteId](const QByteArray &remoteId) { if (operation == Sink::Operation_Creation) { - Trace() << "Replayed creation with remote id: " << remoteId; + SinkTrace() << "Replayed creation with remote id: " << remoteId; if (remoteId.isEmpty()) { - Warning() << "Returned an empty remoteId from the creation"; + SinkWarning() << "Returned an empty remoteId from the creation"; } else { syncStore().recordRemoteId(type, uid, remoteId); } } else if (operation == Sink::Operation_Modification) { - Trace() << "Replayed modification with remote id: " << remoteId; + SinkTrace() << "Replayed modification with remote id: " << remoteId; if (remoteId.isEmpty()) { - Warning() << "Returned an empty remoteId from the creation"; + SinkWarning() << "Returned an empty remoteId from the creation"; } else { syncStore().updateRemoteId(type, uid, remoteId); } } else if (operation == Sink::Operation_Removal) { - Trace() << "Replayed removal with remote id: " << oldRemoteId; + SinkTrace() << "Replayed removal with remote id: " << oldRemoteId; syncStore().removeRemoteId(type, uid, oldRemoteId); } else { - ErrorMsg() << "Unkown operation" << operation; + SinkError() << "Unkown operation" << operation; } mSyncStore.clear(); @@ -123,7 +125,7 @@ KAsync::Job SourceWriteBack::replay(const QByteArray &type, const QByteArr mTransaction.abort(); mSyncTransaction.commit(); }, [this](int errorCode, const QString &errorMessage) { - Warning() << "Failed to replay change: " << errorMessage; + SinkWarning() << "Failed to replay change: " << errorMessage; mSyncStore.clear(); mEntityStore.clear(); mTransaction.abort(); diff --git a/common/specialpurposepreprocessor.cpp b/common/specialpurposepreprocessor.cpp index 2892105..0985880 100644 --- a/common/specialpurposepreprocessor.cpp +++ b/common/specialpurposepreprocessor.cpp @@ -5,6 +5,8 @@ using namespace Sink; +SINK_DEBUG_AREA("SpecialPurposeProcessor") + static QHash specialPurposeFolders() { QHash hash; @@ -53,7 +55,7 @@ QByteArray SpecialPurposeProcessor::ensureFolder(Sink::Storage::Transaction &tra return false; }); if (!mSpecialPurposeFolders.contains(specialPurpose)) { - Trace() << "Failed to find a drafts folder, creating a new one"; + SinkTrace() << "Failed to find a drafts folder, creating a new one"; auto folder = ApplicationDomain::Folder::create(mResourceInstanceIdentifier); folder.setSpecialPurpose(QByteArrayList() << specialPurpose); folder.setName(sSpecialPurposeFolders.value(specialPurpose)); diff --git a/common/storage_common.cpp b/common/storage_common.cpp index 6982a4c..1f2594e 100644 --- a/common/storage_common.cpp +++ b/common/storage_common.cpp @@ -24,6 +24,8 @@ #include "log.h" #include +SINK_DEBUG_AREA("storage") + namespace Sink { static const char *s_internalPrefix = "__internal"; @@ -31,7 +33,7 @@ static const int s_internalPrefixSize = strlen(s_internalPrefix); void errorHandler(const Storage::Error &error) { - Warning() << "Database error in " << error.store << ", code " << error.code << ", message: " << error.message; + SinkWarning() << "Database error in " << error.store << ", code " << error.code << ", message: " << error.message; } std::function Storage::basicErrorHandler() @@ -67,7 +69,7 @@ qint64 Storage::maxRevision(const Sink::Storage::Transaction &transaction) }, [](const Error &error) { if (error.code != Sink::Storage::NotFound) { - Warning() << "Coultn'd find the maximum revision."; + SinkWarning() << "Coultn'd find the maximum revision."; } }); return r; @@ -88,7 +90,7 @@ qint64 Storage::cleanedUpRevision(const Sink::Storage::Transaction &transaction) }, [](const Error &error) { if (error.code != Sink::Storage::NotFound) { - Warning() << "Coultn'd find the maximum revision."; + SinkWarning() << "Coultn'd find the maximum revision."; } }); return r; @@ -103,7 +105,7 @@ QByteArray Storage::getUidFromRevision(const Sink::Storage::Transaction &transac uid = value; return false; }, - [revision](const Error &error) { Warning() << "Coultn'd find uid for revision: " << revision << error.message; }); + [revision](const Error &error) { SinkWarning() << "Coultn'd find uid for revision: " << revision << error.message; }); return uid; } @@ -116,7 +118,7 @@ QByteArray Storage::getTypeFromRevision(const Sink::Storage::Transaction &transa type = value; return false; }, - [revision](const Error &error) { Warning() << "Coultn'd find type for revision " << revision; }); + [revision](const Error &error) { SinkWarning() << "Coultn'd find type for revision " << revision; }); return type; } diff --git a/common/storage_lmdb.cpp b/common/storage_lmdb.cpp index 352e250..79f4465 100644 --- a/common/storage_lmdb.cpp +++ b/common/storage_lmdb.cpp @@ -34,10 +34,8 @@ #include #include "log.h" -#undef Trace -#define Trace() Trace_area("storage." + d->storageRoot.toLatin1() + '/' + d->name.toLatin1()) -#undef Warning -#define Warning() Warning_area("storage") +SINK_DEBUG_AREA("storage") +// SINK_DEBUG_COMPONENT(d->storageRoot.toLatin1() + '/' + d->name.toLatin1()) namespace Sink { @@ -354,7 +352,7 @@ qint64 Storage::NamedDatabase::getSize() MDB_stat stat; rc = mdb_stat(d->transaction, d->dbi, &stat); if (rc) { - Warning() << "Something went wrong " << QByteArray(mdb_strerror(rc)); + SinkWarning() << "Something went wrong " << QByteArray(mdb_strerror(rc)); } // std::cout << "overflow_pages: " << stat.ms_overflow_pages << std::endl; // std::cout << "page size: " << stat.ms_psize << std::endl; @@ -482,7 +480,7 @@ static bool ensureCorrectDb(Storage::NamedDatabase &database, const QByteArray & bool openedTheWrongDatabase = false; auto count = database.scan("__internal_dbname", [db, &openedTheWrongDatabase](const QByteArray &key, const QByteArray &value) ->bool { if (value != db) { - Warning() << "Opened the wrong database, got " << value << " instead of " << db; + SinkWarning() << "Opened the wrong database, got " << value << " instead of " << db; openedTheWrongDatabase = true; } return false; @@ -505,7 +503,7 @@ bool Storage::Transaction::validateNamedDatabases() for (const auto &dbName : databases) { auto db = openDatabase(dbName); if (!db) { - Warning() << "Failed to open the database: " << dbName; + SinkWarning() << "Failed to open the database: " << dbName; return false; } } @@ -527,7 +525,7 @@ Storage::NamedDatabase Storage::Transaction::openDatabase(const QByteArray &db, } auto database = Storage::NamedDatabase(p); if (!ensureCorrectDb(database, db, d->requestedRead)) { - Warning() << "Failed to open the database" << db; + SinkWarning() << "Failed to open the database" << db; return Storage::NamedDatabase(); } return database; @@ -536,7 +534,7 @@ Storage::NamedDatabase Storage::Transaction::openDatabase(const QByteArray &db, QList Storage::Transaction::getDatabaseNames() const { if (!d) { - Warning() << "Invalid transaction"; + SinkWarning() << "Invalid transaction"; return QList(); } @@ -559,12 +557,12 @@ QList Storage::Transaction::getDatabaseNames() const rc = 0; } if (rc) { - Warning() << "Failed to get a value" << rc; + SinkWarning() << "Failed to get a value" << rc; } } mdb_cursor_close(cursor); } else { - Warning() << "Failed to open db" << rc << QByteArray(mdb_strerror(rc)); + SinkWarning() << "Failed to open db" << rc << QByteArray(mdb_strerror(rc)); } return list; } @@ -611,7 +609,7 @@ Storage::Private::Private(const QString &s, const QString &n, AccessMode m) : st int rc = 0; if ((rc = mdb_env_create(&env))) { // TODO: handle error - Warning() << "mdb_env_create: " << rc << " " << mdb_strerror(rc); + SinkWarning() << "mdb_env_create: " << rc << " " << mdb_strerror(rc); } else { mdb_env_set_maxdbs(env, 50); unsigned int flags = MDB_NOTLS; @@ -619,7 +617,7 @@ Storage::Private::Private(const QString &s, const QString &n, AccessMode m) : st flags |= MDB_RDONLY; } if ((rc = mdb_env_open(env, fullPath.toStdString().data(), flags, 0664))) { - Warning() << "mdb_env_open: " << rc << " " << mdb_strerror(rc); + SinkWarning() << "mdb_env_open: " << rc << " " << mdb_strerror(rc); mdb_env_close(env); env = 0; } else { @@ -681,7 +679,7 @@ qint64 Storage::diskUsage() const { QFileInfo info(d->storageRoot + '/' + d->name + "/data.mdb"); if (!info.exists()) { - Warning() << "Tried to get filesize for non-existant file: " << info.path(); + SinkWarning() << "Tried to get filesize for non-existant file: " << info.path(); } return info.size(); } @@ -691,7 +689,7 @@ void Storage::removeFromDisk() const const QString fullPath(d->storageRoot + '/' + d->name); QMutexLocker locker(&d->sMutex); QDir dir(fullPath); - Trace() << "Removing database from disk: " << fullPath; + SinkTrace() << "Removing database from disk: " << fullPath; if (!dir.removeRecursively()) { Error error(d->name.toLatin1(), ErrorCodes::GenericError, QString("Failed to remove directory %1 %2").arg(d->storageRoot).arg(d->name).toLatin1()); defaultErrorHandler()(error); diff --git a/common/store.cpp b/common/store.cpp index 1162a18..a58287b 100644 --- a/common/store.cpp +++ b/common/store.cpp @@ -36,8 +36,7 @@ #include "storage.h" #include "log.h" -#undef DEBUG_AREA -#define DEBUG_AREA "client.store" +SINK_DEBUG_AREA("store") namespace Sink { @@ -88,24 +87,24 @@ static QMap getResources(const QList &resour } resources.insert(res, configuredResources.value(res)); } else { - Warning() << "Resource is not existing: " << res; + SinkWarning() << "Resource is not existing: " << res; } } } - Trace() << "Found resources: " << resources; + SinkTrace() << "Found resources: " << resources; return resources; } template QSharedPointer Store::loadModel(Query query) { - Trace() << "Query: " << ApplicationDomain::getTypeName(); - Trace() << " Requested: " << query.requestedProperties; - Trace() << " Filter: " << query.propertyFilter; - Trace() << " Parent: " << query.parentProperty; - Trace() << " Ids: " << query.ids; - Trace() << " IsLive: " << query.liveQuery; - Trace() << " Sorting: " << query.sortProperty; + SinkTrace() << "Query: " << ApplicationDomain::getTypeName(); + SinkTrace() << " Requested: " << query.requestedProperties; + SinkTrace() << " Filter: " << query.propertyFilter; + SinkTrace() << " Parent: " << query.parentProperty; + SinkTrace() << " Ids: " << query.ids; + SinkTrace() << " IsLive: " << query.liveQuery; + SinkTrace() << " Sorting: " << query.sortProperty; auto model = QSharedPointer>::create(query, query.requestedProperties); //* Client defines lifetime of model @@ -123,16 +122,16 @@ QSharedPointer Store::loadModel(Query query) const auto resourceType = resources.value(resourceInstanceIdentifier); auto facade = FacadeFactory::instance().getFacade(resourceType, resourceInstanceIdentifier); if (facade) { - Trace() << "Trying to fetch from resource " << resourceInstanceIdentifier; + SinkTrace() << "Trying to fetch from resource " << resourceInstanceIdentifier; auto result = facade->load(query); if (result.second) { aggregatingEmitter->addEmitter(result.second); } else { - Warning() << "Null emitter for resource " << resourceInstanceIdentifier; + SinkWarning() << "Null emitter for resource " << resourceInstanceIdentifier; } result.first.template then([&future]() { future.setFinished(); }).exec(); } else { - Trace() << "Couldn' find a facade for " << resourceInstanceIdentifier; + SinkTrace() << "Couldn' find a facade for " << resourceInstanceIdentifier; // Ignore the error and carry on future.setFinished(); } @@ -164,7 +163,7 @@ KAsync::Job Store::create(const DomainType &domainObject) { // Potentially move to separate thread as well auto facade = getFacade(domainObject.resourceInstanceIdentifier()); - return facade->create(domainObject).template then([facade]() {}, [](int errorCode, const QString &error) { Warning() << "Failed to create"; }); + return facade->create(domainObject).template then([facade]() {}, [](int errorCode, const QString &error) { SinkWarning() << "Failed to create"; }); } template @@ -172,7 +171,7 @@ KAsync::Job Store::modify(const DomainType &domainObject) { // Potentially move to separate thread as well auto facade = getFacade(domainObject.resourceInstanceIdentifier()); - return facade->modify(domainObject).template then([facade]() {}, [](int errorCode, const QString &error) { Warning() << "Failed to modify"; }); + return facade->modify(domainObject).template then([facade]() {}, [](int errorCode, const QString &error) { SinkWarning() << "Failed to modify"; }); } template @@ -180,7 +179,7 @@ KAsync::Job Store::remove(const DomainType &domainObject) { // Potentially move to separate thread as well auto facade = getFacade(domainObject.resourceInstanceIdentifier()); - return facade->remove(domainObject).template then([facade]() {}, [](int errorCode, const QString &error) { Warning() << "Failed to remove"; }); + return facade->remove(domainObject).template then([facade]() {}, [](int errorCode, const QString &error) { SinkWarning() << "Failed to remove"; }); } KAsync::Job Store::removeDataFromDisk(const QByteArray &identifier) @@ -188,28 +187,28 @@ KAsync::Job Store::removeDataFromDisk(const QByteArray &identifier) // All databases are going to become invalid, nuke the environments // TODO: all clients should react to a notification the resource Sink::Storage::clearEnv(); - Trace() << "Remove data from disk " << identifier; + SinkTrace() << "Remove data from disk " << identifier; auto time = QSharedPointer::create(); time->start(); auto resourceAccess = ResourceAccessFactory::instance().getAccess(identifier, ResourceConfig::getResourceType(identifier)); resourceAccess->open(); return resourceAccess->sendCommand(Sink::Commands::RemoveFromDiskCommand) - .then([resourceAccess, time]() { Trace() << "Remove from disk complete." << Log::TraceTime(time->elapsed()); }); + .then([resourceAccess, time]() { SinkTrace() << "Remove from disk complete." << Log::TraceTime(time->elapsed()); }); } KAsync::Job Store::synchronize(const Sink::Query &query) { - Trace() << "synchronize" << query.resources; + SinkTrace() << "synchronize" << query.resources; auto resources = getResources(query.resources, query.accounts).keys(); //FIXME only necessary because each doesn't propagate errors auto error = new bool; return KAsync::iterate(resources) .template each([query, error](const QByteArray &resource, KAsync::Future &future) { - Trace() << "Synchronizing " << resource; + SinkTrace() << "Synchronizing " << resource; auto resourceAccess = ResourceAccessFactory::instance().getAccess(resource, ResourceConfig::getResourceType(resource)); resourceAccess->open(); - resourceAccess->synchronizeResource(true, false).then([resourceAccess, &future]() {Trace() << "synced."; future.setFinished(); }, - [&future, error](int errorCode, QString msg) { *error = true; Warning() << "Error during sync."; future.setError(errorCode, msg); }).exec(); + resourceAccess->synchronizeResource(true, false).then([resourceAccess, &future]() {SinkTrace() << "synced."; future.setFinished(); }, + [&future, error](int errorCode, QString msg) { *error = true; SinkWarning() << "Error during sync."; future.setError(errorCode, msg); }).exec(); }).then([error](KAsync::Future &future) { if (*error) { future.setError(1, "Error during sync."); @@ -306,25 +305,25 @@ QList Store::read(const Sink::Query &q) auto resources = getResources(query.resources, query.accounts, ApplicationDomain::getTypeName()); auto aggregatingEmitter = AggregatingResultEmitter::Ptr::create(); aggregatingEmitter->onAdded([&list](const typename DomainType::Ptr &value){ - Trace() << "Found value: " << value->identifier(); + SinkTrace() << "Found value: " << value->identifier(); list << *value; }); for (const auto resourceInstanceIdentifier : resources.keys()) { const auto resourceType = resources.value(resourceInstanceIdentifier); - Trace() << "Looking for " << resourceType << resourceInstanceIdentifier; + SinkTrace() << "Looking for " << resourceType << resourceInstanceIdentifier; auto facade = FacadeFactory::instance().getFacade(resourceType, resourceInstanceIdentifier); if (facade) { - Trace() << "Trying to fetch from resource " << resourceInstanceIdentifier; + SinkTrace() << "Trying to fetch from resource " << resourceInstanceIdentifier; auto result = facade->load(query); if (result.second) { aggregatingEmitter->addEmitter(result.second); } else { - Warning() << "Null emitter for resource " << resourceInstanceIdentifier; + SinkWarning() << "Null emitter for resource " << resourceInstanceIdentifier; } result.first.exec(); aggregatingEmitter->fetch(typename DomainType::Ptr()); } else { - Trace() << "Couldn't find a facade for " << resourceInstanceIdentifier; + SinkTrace() << "Couldn't find a facade for " << resourceInstanceIdentifier; // Ignore the error and carry on } } diff --git a/common/synchronizer.cpp b/common/synchronizer.cpp index 1374d00..2d4fb8d 100644 --- a/common/synchronizer.cpp +++ b/common/synchronizer.cpp @@ -29,6 +29,8 @@ #include "modifyentity_generated.h" #include "deleteentity_generated.h" +SINK_DEBUG_AREA("synchronizer") + using namespace Sink; Synchronizer::Synchronizer(const QByteArray &resourceType, const QByteArray &resourceInstanceIdentifier) @@ -37,7 +39,7 @@ Synchronizer::Synchronizer(const QByteArray &resourceType, const QByteArray &res mResourceType(resourceType), mResourceInstanceIdentifier(resourceInstanceIdentifier) { - Trace() << "Starting synchronizer: " << resourceType << resourceInstanceIdentifier; + SinkTrace() << "Starting synchronizer: " << resourceType << resourceInstanceIdentifier; } Synchronizer::~Synchronizer() @@ -129,11 +131,11 @@ void Synchronizer::scanForRemovals(const QByteArray &bufferType, const std::func entryGenerator([this, bufferType, &exists](const QByteArray &key) { auto sinkId = Sink::Storage::uidFromKey(key); const auto remoteId = syncStore().resolveLocalId(bufferType, sinkId); - Trace() << "Checking for removal " << key << remoteId; + SinkTrace() << "Checking for removal " << key << remoteId; // If we have no remoteId, the entity hasn't been replayed to the source yet if (!remoteId.isEmpty()) { if (!exists(remoteId)) { - Trace() << "Found a removed entity: " << sinkId; + SinkTrace() << "Found a removed entity: " << sinkId; deleteEntity(sinkId, Sink::Storage::maxRevision(transaction()), bufferType, [this](const QByteArray &buffer) { enqueueCommand(Sink::Commands::DeleteEntityCommand, buffer); }); } @@ -143,14 +145,14 @@ void Synchronizer::scanForRemovals(const QByteArray &bufferType, const std::func void Synchronizer::createOrModify(const QByteArray &bufferType, const QByteArray &remoteId, const Sink::ApplicationDomain::ApplicationDomainType &entity) { - Trace() << "Create or modify" << bufferType << remoteId; + SinkTrace() << "Create or modify" << bufferType << remoteId; auto mainDatabase = Storage::mainDatabase(transaction(), bufferType); const auto sinkId = syncStore().resolveRemoteId(bufferType, remoteId); const auto found = mainDatabase.contains(sinkId); auto adaptorFactory = Sink::AdaptorFactoryRegistry::instance().getFactory(mResourceType, bufferType); Q_ASSERT(adaptorFactory); if (!found) { - Trace() << "Found a new entity: " << remoteId; + SinkTrace() << "Found a new entity: " << remoteId; createEntity( sinkId, bufferType, entity, *adaptorFactory, [this](const QByteArray &buffer) { enqueueCommand(Sink::Commands::CreateEntityCommand, buffer); }); } else { // modification @@ -159,17 +161,17 @@ void Synchronizer::createOrModify(const QByteArray &bufferType, const QByteArray bool changed = false; for (const auto &property : entity.changedProperties()) { if (entity.getProperty(property) != current->getProperty(property)) { - Trace() << "Property changed " << sinkId << property; + SinkTrace() << "Property changed " << sinkId << property; changed = true; } } if (changed) { - Trace() << "Found a modified entity: " << remoteId; + SinkTrace() << "Found a modified entity: " << remoteId; modifyEntity(sinkId, Sink::Storage::maxRevision(transaction()), bufferType, entity, *adaptorFactory, [this](const QByteArray &buffer) { enqueueCommand(Sink::Commands::ModifyEntityCommand, buffer); }); } } else { - Warning() << "Failed to get current entity"; + SinkWarning() << "Failed to get current entity"; } } } @@ -178,7 +180,7 @@ template void Synchronizer::createOrModify(const QByteArray &bufferType, const QByteArray &remoteId, const DomainType &entity, const QHash &mergeCriteria) { - Trace() << "Create or modify" << bufferType << remoteId; + SinkTrace() << "Create or modify" << bufferType << remoteId; auto mainDatabase = Storage::mainDatabase(transaction(), bufferType); const auto sinkId = syncStore().resolveRemoteId(bufferType, remoteId); const auto found = mainDatabase.contains(sinkId); @@ -192,17 +194,17 @@ void Synchronizer::createOrModify(const QByteArray &bufferType, const QByteArray reader.query(query, [this, bufferType, remoteId, &merge](const DomainType &o) -> bool{ merge = true; - Trace() << "Merging local entity with remote entity: " << o.identifier() << remoteId; + SinkTrace() << "Merging local entity with remote entity: " << o.identifier() << remoteId; syncStore().recordRemoteId(bufferType, o.identifier(), remoteId); return false; }); if (!merge) { - Trace() << "Found a new entity: " << remoteId; + SinkTrace() << "Found a new entity: " << remoteId; createEntity( sinkId, bufferType, entity, *adaptorFactory, [this](const QByteArray &buffer) { enqueueCommand(Sink::Commands::CreateEntityCommand, buffer); }); } } else { - Trace() << "Found a new entity: " << remoteId; + SinkTrace() << "Found a new entity: " << remoteId; createEntity( sinkId, bufferType, entity, *adaptorFactory, [this](const QByteArray &buffer) { enqueueCommand(Sink::Commands::CreateEntityCommand, buffer); }); } @@ -212,17 +214,17 @@ void Synchronizer::createOrModify(const QByteArray &bufferType, const QByteArray bool changed = false; for (const auto &property : entity.changedProperties()) { if (entity.getProperty(property) != current->getProperty(property)) { - Trace() << "Property changed " << sinkId << property; + SinkTrace() << "Property changed " << sinkId << property; changed = true; } } if (changed) { - Trace() << "Found a modified entity: " << remoteId; + SinkTrace() << "Found a modified entity: " << remoteId; modifyEntity(sinkId, Sink::Storage::maxRevision(transaction()), bufferType, entity, *adaptorFactory, [this](const QByteArray &buffer) { enqueueCommand(Sink::Commands::ModifyEntityCommand, buffer); }); } } else { - Warning() << "Failed to get current entity"; + SinkWarning() << "Failed to get current entity"; } } } @@ -239,7 +241,7 @@ void Synchronizer::modify(const DomainType &entity) KAsync::Job Synchronizer::synchronize() { - Trace() << "Synchronizing"; + SinkTrace() << "Synchronizing"; mSyncInProgress = true; mMessageQueue->startTransaction(); return synchronizeWithSource().then([this]() { @@ -265,7 +267,7 @@ void Synchronizer::commit() Sink::Storage::Transaction &Synchronizer::transaction() { if (!mTransaction) { - Trace() << "Starting transaction"; + SinkTrace() << "Starting transaction"; mTransaction = mStorage.createTransaction(Sink::Storage::ReadOnly); } return mTransaction; @@ -274,7 +276,7 @@ Sink::Storage::Transaction &Synchronizer::transaction() Sink::Storage::Transaction &Synchronizer::syncTransaction() { if (!mSyncTransaction) { - Trace() << "Starting transaction"; + SinkTrace() << "Starting transaction"; mSyncTransaction = mSyncStorage.createTransaction(Sink::Storage::ReadWrite); } return mSyncTransaction; diff --git a/common/test.cpp b/common/test.cpp index c7d84cc..99e51c8 100644 --- a/common/test.cpp +++ b/common/test.cpp @@ -28,6 +28,8 @@ #include "query.h" #include "resourceconfig.h" +SINK_DEBUG_AREA("test") + using namespace Sink; void Sink::Test::initTest() @@ -103,7 +105,7 @@ public: { auto resultProvider = new Sink::ResultProvider(); resultProvider->onDone([resultProvider]() { - Trace() << "Result provider is done"; + SinkTrace() << "Result provider is done"; delete resultProvider; }); // We have to do it this way, otherwise we're not setting the fetcher right @@ -111,11 +113,11 @@ public: resultProvider->setFetcher([query, resultProvider, this](const typename T::Ptr &parent) { if (parent) { - Trace() << "Running the fetcher " << parent->identifier(); + SinkTrace() << "Running the fetcher " << parent->identifier(); } else { - Trace() << "Running the fetcher."; + SinkTrace() << "Running the fetcher."; } - Trace() << "-------------------------."; + SinkTrace() << "-------------------------."; for (const auto &res : mTestAccount->entities()) { qDebug() << "Parent filter " << query.propertyFilter.value("parent").value.toByteArray() << res->identifier() << res->getProperty("parent").toByteArray(); auto parentProperty = res->getProperty("parent").toByteArray(); diff --git a/common/typeindex.cpp b/common/typeindex.cpp index 05bbf5c..78195d3 100644 --- a/common/typeindex.cpp +++ b/common/typeindex.cpp @@ -22,8 +22,7 @@ #include "index.h" #include -#undef DEBUG_AREA -#define DEBUG_AREA "common.typeindex" +SINK_DEBUG_AREA("typeindex") static QByteArray getByteArray(const QVariant &value) { @@ -63,7 +62,7 @@ template <> void TypeIndex::addProperty(const QByteArray &property) { auto indexer = [this, property](const QByteArray &identifier, const QVariant &value, Sink::Storage::Transaction &transaction) { - // Trace() << "Indexing " << mType + ".index." + property << value.toByteArray(); + // SinkTrace() << "Indexing " << mType + ".index." + property << value.toByteArray(); Index(indexName(property), transaction).add(getByteArray(value), identifier); }; mIndexer.insert(property, indexer); @@ -74,7 +73,7 @@ template <> void TypeIndex::addProperty(const QByteArray &property) { auto indexer = [this, property](const QByteArray &identifier, const QVariant &value, Sink::Storage::Transaction &transaction) { - // Trace() << "Indexing " << mType + ".index." + property << value.toByteArray(); + // SinkTrace() << "Indexing " << mType + ".index." + property << value.toByteArray(); Index(indexName(property), transaction).add(getByteArray(value), identifier); }; mIndexer.insert(property, indexer); @@ -85,7 +84,7 @@ template <> void TypeIndex::addProperty(const QByteArray &property) { auto indexer = [this, property](const QByteArray &identifier, const QVariant &value, Sink::Storage::Transaction &transaction) { - // Trace() << "Indexing " << mType + ".index." + property << date.toString(); + // SinkTrace() << "Indexing " << mType + ".index." + property << date.toString(); Index(indexName(property), transaction).add(getByteArray(value), identifier); }; mIndexer.insert(property, indexer); @@ -143,12 +142,12 @@ ResultSet TypeIndex::query(const Sink::Query &query, QSet &appliedFi if (query.propertyFilter.contains(it.key()) && query.sortProperty == it.value()) { Index index(indexName(it.key(), it.value()), transaction); const auto lookupKey = getByteArray(query.propertyFilter.value(it.key()).value); - Trace() << "looking for " << lookupKey; + SinkTrace() << "looking for " << lookupKey; index.lookup(lookupKey, [&](const QByteArray &value) { keys << value; }, - [it](const Index::Error &error) { Warning() << "Error in index: " << error.message << it.key() << it.value(); }, true); + [it](const Index::Error &error) { SinkWarning() << "Error in index: " << error.message << it.key() << it.value(); }, true); appliedFilters << it.key(); appliedSorting = it.value(); - Trace() << "Index lookup on " << it.key() << it.value() << " found " << keys.size() << " keys."; + SinkTrace() << "Index lookup on " << it.key() << it.value() << " found " << keys.size() << " keys."; return ResultSet(keys); } } @@ -157,12 +156,12 @@ ResultSet TypeIndex::query(const Sink::Query &query, QSet &appliedFi Index index(indexName(property), transaction); const auto lookupKey = getByteArray(query.propertyFilter.value(property).value); index.lookup( - lookupKey, [&](const QByteArray &value) { keys << value; }, [property](const Index::Error &error) { Warning() << "Error in index: " << error.message << property; }); + lookupKey, [&](const QByteArray &value) { keys << value; }, [property](const Index::Error &error) { SinkWarning() << "Error in index: " << error.message << property; }); appliedFilters << property; - Trace() << "Index lookup on " << property << " found " << keys.size() << " keys."; + SinkTrace() << "Index lookup on " << property << " found " << keys.size() << " keys."; return ResultSet(keys); } } - Trace() << "No matching index"; + SinkTrace() << "No matching index"; return ResultSet(keys); } -- cgit v1.2.3