From bb30a451b32aca0c9a61761c48f71f8a8140646e Mon Sep 17 00:00:00 2001 From: Michael Zanetti Date: Mon, 20 Apr 2020 13:04:13 +0200 Subject: [PATCH] New DB schema version * Store plaintext values in log db again * Use msecs precision instead of secs * rename column deviceId to thingId --- libnymea-core/logging/logengine.cpp | 259 +++++++++++------- libnymea-core/logging/logengine.h | 10 +- libnymea-core/logging/logfilter.cpp | 12 +- libnymea-core/logging/logfilter.h | 2 +- libnymea-core/nymeacore.cpp | 16 +- tests/auto/logging/testlogging.cpp | 120 ++++---- .../loggingloading/testloggingloading.cpp | 67 ----- 7 files changed, 243 insertions(+), 243 deletions(-) diff --git a/libnymea-core/logging/logengine.cpp b/libnymea-core/logging/logengine.cpp index 318e9aaa..74639208 100644 --- a/libnymea-core/logging/logengine.cpp +++ b/libnymea-core/logging/logengine.cpp @@ -46,7 +46,7 @@ #include #include -#define DB_SCHEMA_VERSION 3 +#define DB_SCHEMA_VERSION 4 namespace nymeaserver { @@ -136,13 +136,13 @@ LogEntriesFetchJob *LogEngine::fetchLogEntries(const LogFilter &filter) foreach (const QSqlRecord &result, job->results()) { LogEntry entry( - QDateTime::fromTime_t(result.value("timestamp").toUInt()), + QDateTime::fromMSecsSinceEpoch(result.value("timestamp").toLongLong()), static_cast(result.value("loggingLevel").toInt()), static_cast(result.value("sourceType").toInt()), result.value("errorCode").toInt()); entry.setTypeId(result.value("typeId").toUuid()); - entry.setThingId(ThingId(result.value("deviceId").toString())); - entry.setValue(LogValueTool::convertVariantToString(LogValueTool::deserializeValue(result.value("value").toString()))); + entry.setThingId(ThingId(result.value("thingId").toString())); + entry.setValue(result.value("value").toString()); entry.setEventType(static_cast(result.value("loggingEventType").toInt())); entry.setActive(result.value("active").toBool()); @@ -157,9 +157,9 @@ LogEntriesFetchJob *LogEngine::fetchLogEntries(const LogFilter &filter) return fetchJob; } -ThingsFetchJob *LogEngine::fetchDevices() +ThingsFetchJob *LogEngine::fetchThings() { - QString queryString = QString("SELECT deviceId FROM entries WHERE deviceId != \"%1\" GROUP BY deviceId;").arg(QUuid().toString()); + QString queryString = QString("SELECT thingId FROM entries WHERE thingId != \"%1\" GROUP BY thingId;").arg(QUuid().toString()); DatabaseJob *job = new DatabaseJob(m_db, queryString); ThingsFetchJob *fetchJob = new ThingsFetchJob(this); @@ -172,7 +172,7 @@ ThingsFetchJob *LogEngine::fetchDevices() } foreach (const QSqlRecord &result, job->results()) { - fetchJob->m_results.append(ThingId(result.value("deviceId").toUuid())); + fetchJob->m_results.append(ThingId(result.value("thingId").toUuid())); } fetchJob->finished(); }); @@ -192,10 +192,9 @@ void LogEngine::setMaxLogEntries(int maxLogEntries, int trimSize) trim(); } -/*! Removes all entries from the database. This method will be used for the tests. */ void LogEngine::clearDatabase() { - qCWarning(dcLogEngine) << "Clear logging database."; + qCWarning(dcLogEngine) << "Clearing logging database."; QString queryDeleteString = QString("DELETE FROM entries;"); @@ -203,7 +202,7 @@ void LogEngine::clearDatabase() connect(job, &DatabaseJob::finished, this, [this, job](){ if (job->error().type() != QSqlError::NoError) { - qCWarning(dcLogEngine) << "Could not clear logging database. Driver error:" << job->error().driverText() << "Database error:" << job->error().databaseText(); + qCWarning(dcLogEngine) << "Error clearing log database. Driver error:" << job->error().driverText() << "Database error:" << job->error().databaseText(); return; } m_entryCount = 0; @@ -329,11 +328,11 @@ void LogEngine::logRuleExitActionsExecuted(const Rule &rule) appendLogEntry(entry); } -void LogEngine::removeDeviceLogs(const ThingId &thingId) +void LogEngine::removeThingLogs(const ThingId &thingId) { qCDebug(dcLogEngine) << "Deleting log entries from device" << thingId.toString(); - QString queryDeleteString = QString("DELETE FROM entries WHERE deviceId = '%1';").arg(thingId.toString()); + QString queryDeleteString = QString("DELETE FROM entries WHERE thingId = '%1';").arg(thingId.toString()); DatabaseJob *job = new DatabaseJob(m_db, queryDeleteString); connect(job, &DatabaseJob::finished, this, [this, job, thingId](){ @@ -373,14 +372,14 @@ void LogEngine::removeRuleLogs(const RuleId &ruleId) void LogEngine::appendLogEntry(const LogEntry &entry) { - QString queryString = QString("INSERT INTO entries (timestamp, loggingEventType, loggingLevel, sourceType, typeId, deviceId, value, active, errorCode) values ('%1', '%2', '%3', '%4', '%5', '%6', '%7', '%8', '%9');") - .arg(entry.timestamp().toTime_t()) + QString queryString = QString("INSERT INTO entries (timestamp, loggingEventType, loggingLevel, sourceType, typeId, thingId, value, active, errorCode) values ('%1', '%2', '%3', '%4', '%5', '%6', '%7', '%8', '%9');") + .arg(entry.timestamp().toMSecsSinceEpoch()) .arg(entry.eventType()) .arg(entry.level()) .arg(entry.source()) .arg(entry.typeId().toString()) .arg(entry.thingId().toString()) - .arg(LogValueTool::serializeValue(entry.value())) + .arg(entry.value().toString()) .arg(entry.active()) .arg(entry.errorCode()); @@ -428,7 +427,7 @@ void LogEngine::checkDBSize() { DatabaseJob *job = new DatabaseJob(m_db, "SELECT COUNT(*) FROM entries;"); connect(job, &DatabaseJob::finished, this, [this, job](){ - if (job->error().type() != QSqlError::NoError) { + if (job->error().type() != QSqlError::NoError || job->results().count() == 0) { qCWarning(dcLogEngine()) << "Error fetching log DB size. Driver error:" << job->error().driverText() << "Database error:" << job->error().databaseText(); m_entryCount = 0; return; @@ -477,6 +476,10 @@ void LogEngine::enqueJob(DatabaseJob *job, bool priority) void LogEngine::processQueue() { + if (!m_initialized) { + return; + } + if (m_jobQueue.isEmpty()) { emit jobsRunningChanged(); return; @@ -506,7 +509,7 @@ void LogEngine::processQueue() query.prepare(job->m_queryString); foreach (const QString &value, job->m_bindValues) { - query.addBindValue(LogValueTool::serializeValue(value)); + query.addBindValue(value); } query.exec(); @@ -552,84 +555,141 @@ void LogEngine::rotate(const QString &dbName) } } -bool LogEngine::migrateDatabaseVersion2to3() +bool LogEngine::migrateDatabaseVersion3to4() { - // Changelog: serialize values of logentries in order to prevent typecast errors - qCDebug(dcLogEngine()) << "Start migration of log database from version 2 to version 3"; - - QDateTime startTime = QDateTime::currentDateTime(); - - int migrationCounter = 0; - int migrationProgress = 0; - int entryCount = 0; - - // Count entries we have to migrate - QString queryString = "SELECT COUNT(*) FROM entries WHERE value != '';"; - QSqlQuery countQuery = m_db.exec(queryString); - if (m_db.lastError().type() != QSqlError::NoError) { - qCWarning(dcLogEngine()) << "Failed to query entry count in db:" << m_db.lastError().databaseText(); - return false; - } - if (!countQuery.first()) { - qCWarning(dcLogEngine()) << "Migration: Failed retrieving entry count."; - return false; - } - entryCount = countQuery.value(0).toInt(); - - qCDebug(dcLogEngine()) << "Found" << entryCount << "entries to migrate."; - - // Select all entries - QSqlQuery selectQuery = m_db.exec("SELECT * FROM entries;"); + QSqlQuery renameQuery = m_db.exec("ALTER TABLE entries RENAME TO _entries_v3;"); if (m_db.lastError().isValid()) { - qCWarning(dcLogEngine) << "Error migrating database verion 2 -> 3. Driver error:" << m_db.lastError().driverText() << "Database error:" << m_db.lastError().databaseText(); + qCWarning(dcLogEngine) << "Error migrating database verion 3 -> 4 (renaming table). Driver error:" << m_db.lastError().driverText() << "Database error:" << m_db.lastError().databaseText(); return false; } + qCDebug(dcLogEngine()) << "Renamed entries table to entries_v3:" << m_db.lastError().text(); + m_db.close(); + m_db.open(m_username, m_password); - // Migrate all selected entries - while (selectQuery.next()) { - QString oldValue = selectQuery.value("value").toString(); - QString newValue = LogValueTool::serializeValue(QVariant(oldValue)); - if (oldValue.isEmpty()) - continue; - - QString updateCall = QString("UPDATE entries SET value = '%1' WHERE timestamp = '%2' AND loggingLevel = '%3' AND sourceType = '%4' AND errorCode = '%5' AND typeId = '%6' AND deviceId = '%7' AND value = '%8' AND loggingEventType = '%9'AND active = '%10';") - .arg(newValue) - .arg(selectQuery.value("timestamp").toLongLong()) - .arg(selectQuery.value("loggingLevel").toInt()) - .arg(selectQuery.value("sourceType").toInt()) - .arg(selectQuery.value("errorCode").toInt()) - .arg(selectQuery.value("typeId").toUuid().toString()) - .arg(selectQuery.value("deviceId").toString()) - .arg(selectQuery.value("value").toString()) - .arg(selectQuery.value("loggingEventType").toInt()) - .arg(selectQuery.value("active").toBool()); - - m_db.exec(updateCall); - if (m_db.lastError().isValid()) { - qCWarning(dcLogEngine) << "Error migrating database verion 2 -> 3. Driver error:" << m_db.lastError().driverText() << "Database error:" << m_db.lastError().databaseText(); - return false; - } - - migrationCounter++; - - double percentage = migrationCounter * 100.0 / entryCount; - if (qRound(percentage) != migrationProgress) { - migrationProgress = qRound(percentage); - qCDebug(dcLogEngine()) << QString("Migration progress: %1\%").arg(migrationProgress).toLatin1().data(); - } + QSqlQuery createQuery = m_db.exec("CREATE TABLE entries " + "(" + "timestamp BIGINT," + "loggingLevel INT," + "sourceType INT," + "typeId VARCHAR(38)," + "thingId VARCHAR(38)," + "value VARCHAR(100)," + "loggingEventType INT," + "active BOOL," + "errorCode INT," + "FOREIGN KEY(sourceType) REFERENCES sourceTypes(id)," + "FOREIGN KEY(loggingEventType) REFERENCES loggingEventTypes(id)" + ");"); + if (m_db.lastError().isValid()) { + qCWarning(dcLogEngine) << "Error migrating database verion 3 -> 4 (creating new table). Driver error:" << m_db.lastError().driverText() << "Database error:" << m_db.lastError().databaseText(); + return false; } + qCDebug(dcLogEngine()) << "Created new entries table:" << m_db.lastError().text(); - QTime runTime = QTime(0,0,0,0).addMSecs(startTime.msecsTo(QDateTime::currentDateTime())); - qCDebug(dcLogEngine()) << "Migration of" << migrationCounter << "done in" << runTime.toString("mm:ss.zzz"); qCDebug(dcLogEngine()) << "Updating database version to" << DB_SCHEMA_VERSION; - m_db.exec(QString("UPDATE metadata SET data = %1 WHERE key = 'version';").arg(DB_SCHEMA_VERSION)); + m_db.exec(QString("UPDATE metadata SET data = %1 WHERE `key` = 'version';").arg(DB_SCHEMA_VERSION)); if (m_db.lastError().isValid()) { - qCWarning(dcLogEngine) << "Error updating database verion 2 -> 3. Driver error:" << m_db.lastError().driverText() << "Database error:" << m_db.lastError().databaseText(); + qCWarning(dcLogEngine) << "Error updating database verion 3 -> 4. Driver error:" << m_db.lastError().driverText() << "Database error:" << m_db.lastError().databaseText(); return false; } - qCDebug(dcLogEngine()) << "Migrated" << migrationCounter << "entries from database verion 2 -> 3 successfully."; + qCDebug(dcLogEngine()) << "Migrated database schema from version 3 to 4."; + return true; + +} + +void LogEngine::migrateEntries3to4() +{ + QString selectQuery = QString("SELECT * FROM _entries_v3;"); + + DatabaseJob *job = new DatabaseJob(m_db, selectQuery); + + connect(job, &DatabaseJob::finished, this, [this, job](){ + + if (job->error().type() != QSqlError::NoError) { + qCWarning(dcLogEngine) << "Error fetching entries to migrate. Driver error:" << job->error().driverText() << "Database error:" << job->error().databaseText(); + m_dbMalformed = true; + return; + } + + if (job->results().isEmpty()) { + qCDebug(dcLogEngine()) << "No items to migrate from schema 3 to 4 remaining."; + finalizeMigration3To4(); + return; + } + + int count = job->results().count(); + + QSqlRecord result = job->results().first(); + QString encodedValue = result.value("value").toByteArray(); + QString decodedValue = LogValueTool::convertVariantToString(LogValueTool::deserializeValue(encodedValue)); + + QString insertCall = QString("INSERT INTO entries (timestamp, loggingEventType, loggingLevel, sourceType, typeId, thingId, value, active, errorCode) values ('%1', '%2', '%3', '%4', '%5', '%6', '%7', '%8', '%9');") + .arg(result.value("timestamp").toLongLong() * 1000) + .arg(result.value("loggingEventType").toInt()) + .arg(result.value("loggingLevel").toInt()) + .arg(result.value("sourceType").toInt()) + .arg(result.value("typeId").toString()) + .arg(result.value("deviceId").toString()) + .arg(decodedValue) + .arg(result.value("active").toBool()) + .arg(result.value("errorCode").toInt()); + + DatabaseJob *insertJob = new DatabaseJob(m_db, insertCall); + connect(insertJob, &DatabaseJob::finished, this, [this, insertJob, count, result](){ + if (insertJob->error().type() != QSqlError::NoError) { + qCWarning(dcLogEngine) << "Error fetching entries to migrate. Driver error:" << insertJob->error().driverText() << "Database error:" << insertJob->error().databaseText(); + m_dbMalformed = true; + return; + } + + QString deleteCall = QString("DELETE FROM _entries_v3 WHERE timestamp = '%1' AND loggingEventType = '%2' AND loggingLevel = '%3' AND sourceType = '%4' AND typeId = '%5' AND deviceId = '%6' AND value = '%7' AND active = '%8' AND errorCode = '%9';") + .arg(result.value("timestamp").toLongLong()) + .arg(result.value("loggingEventType").toInt()) + .arg(result.value("loggingLevel").toInt()) + .arg(result.value("sourceType").toInt()) + .arg(result.value("typeId").toString()) + .arg(result.value("deviceId").toString()) + .arg(result.value("value").toString()) + .arg(result.value("active").toBool()) + .arg(result.value("errorCode").toInt()); + + DatabaseJob *deleteJob = new DatabaseJob(m_db, deleteCall); + connect(deleteJob, &DatabaseJob::finished, this, [this, deleteJob, count, result](){ + if (deleteJob->error().type() != QSqlError::NoError) { + qCWarning(dcLogEngine) << "Error deleting old entry during migration. Driver error:" << deleteJob->error().driverText() << "Database error:" << deleteJob->error().databaseText(); + finalizeMigration3To4(); + return; + } + + qCDebug(dcLogEngine()) << "Migrated log entry from version 3 to 4." << (count - 1) << "items left to migrate"; + if (count - 1 > 0) { + migrateEntries3to4(); + } else { + finalizeMigration3To4(); + } + }); + enqueJob(deleteJob); + }); + enqueJob(insertJob); + }); + enqueJob(job); +} + +void LogEngine::finalizeMigration3To4() +{ + qCDebug(dcLogEngine()) << "Finalizing migration of database version 3 to 4."; + QString selectQuery = QString("DROP TABLE _entries_v3;"); + DatabaseJob *job = new DatabaseJob(m_db, selectQuery); + enqueJob(job); + connect(job, &DatabaseJob::finished, this, [job](){ + + if (job->error().type() != QSqlError::NoError) { + qCWarning(dcLogEngine) << "Error finalizing migration from 3 to 4 (drop entries_v3). Driver error:" << job->error().driverText() << "Database error:" << job->error().databaseText(); + return; + } + }); } bool LogEngine::initDB(const QString &username, const QString &password) @@ -655,21 +715,27 @@ bool LogEngine::initDB(const QString &username, const QString &password) if (query.next()) { int version = query.value("data").toInt(); - // Migration from 2 -> 3 (serialize values in order to store QVariant information) - if (DB_SCHEMA_VERSION == 3 && version == 2) { - if (!migrateDatabaseVersion2to3()) { + // Migration from 3 -> 4 + if (version == 3) { + if (!migrateDatabaseVersion3to4()) { qCWarning(dcLogEngine()) << "Migration process failed."; return false; } else { // Successfully migrated - version = DB_SCHEMA_VERSION; + version = 4; } } if (version != DB_SCHEMA_VERSION) { - qCWarning(dcLogEngine) << "Log schema version not matching! Schema upgrade not implemented yet. Logging might fail."; + qCWarning(dcLogEngine) << "Log schema version not matching! Schema upgrade not implemented for this version change."; + return false; } else { qCDebug(dcLogEngine) << QString("Log database schema version \"%1\" matches").arg(DB_SCHEMA_VERSION).toLatin1().data(); + // If there is still a deviceId column, schedule items to be migrated in the + // background with low priority as this might take hours + if (m_db.tables().contains("_entries_v3")) { + migrateEntries3to4(); + } } } else { qCWarning(dcLogEngine) << "Broken log database. Version not found in metadata table."; @@ -703,15 +769,15 @@ bool LogEngine::initDB(const QString &username, const QString &password) qCDebug(dcLogEngine()) << "No \"entries\" table in database. Creating it."; m_db.exec("CREATE TABLE entries " "(" - "timestamp int," - "loggingLevel int," - "sourceType int," - "typeId varchar(38)," - "deviceId varchar(38)," - "value varchar(100)," - "loggingEventType int," - "active bool," - "errorCode int," + "timestamp BIGINT," + "loggingLevel INT," + "sourceType INT," + "typeId VARCHAR(38)," + "thingId VARCHAR(38)," + "value VARCHAR(100)," + "loggingEventType INT," + "active BOOL," + "errorCode INT," "FOREIGN KEY(sourceType) REFERENCES sourceTypes(id)," "FOREIGN KEY(loggingEventType) REFERENCES loggingEventTypes(id)" ");"); @@ -725,6 +791,7 @@ bool LogEngine::initDB(const QString &username, const QString &password) } qCDebug(dcLogEngine) << "Initialized logging DB successfully. (maximum DB size:" << m_dbMaxSize << ")"; + m_initialized = true; return true; } diff --git a/libnymea-core/logging/logengine.h b/libnymea-core/logging/logengine.h index 7fd27243..ac4ee921 100644 --- a/libnymea-core/logging/logengine.h +++ b/libnymea-core/logging/logengine.h @@ -61,7 +61,7 @@ public: ~LogEngine(); LogEntriesFetchJob *fetchLogEntries(const LogFilter &filter = LogFilter()); - ThingsFetchJob *fetchDevices(); + ThingsFetchJob *fetchThings(); bool jobsRunning() const; @@ -78,7 +78,7 @@ public: void logRuleEnabledChanged(const Rule &rule, const bool &enabled); void logRuleActionsExecuted(const Rule &rule); void logRuleExitActionsExecuted(const Rule &rule); - void removeDeviceLogs(const ThingId &thingId); + void removeThingLogs(const ThingId &thingId); void removeRuleLogs(const RuleId &ruleId); signals: @@ -92,8 +92,9 @@ private: void appendLogEntry(const LogEntry &entry); void rotate(const QString &dbName); - - bool migrateDatabaseVersion2to3(); + bool migrateDatabaseVersion3to4(); + void migrateEntries3to4(); + void finalizeMigration3To4(); private slots: void checkDBSize(); @@ -110,6 +111,7 @@ private: int m_dbMaxSize; int m_trimSize; int m_entryCount = 0; + bool m_initialized = false; bool m_dbMalformed = false; // When maxQueueLength is exceeded, jobs will be flagged and discarded if this source logs more events diff --git a/libnymea-core/logging/logfilter.cpp b/libnymea-core/logging/logfilter.cpp index 4ffb3b9a..55d9c88e 100644 --- a/libnymea-core/logging/logfilter.cpp +++ b/libnymea-core/logging/logfilter.cpp @@ -85,7 +85,7 @@ QString LogFilter::queryString() const if (!query.isEmpty() && !thingIds().isEmpty()) { query.append("AND "); } - query.append(createDeviceIdString()); + query.append(createThingIdString()); if (!query.isEmpty() && !values().isEmpty()) { query.append("AND "); @@ -161,7 +161,7 @@ QList LogFilter::typeIds() const return m_typeIds; } -/*! Add a new \a deviceId to this \l{LogFilter}. */ +/*! Add a new \a thingId to this \l{LogFilter}. */ void LogFilter::addThingId(const ThingId &thingId) { if (!m_thingIds.contains(thingId)) @@ -366,16 +366,16 @@ QString LogFilter::createTypeIdsString() const return query; } -QString LogFilter::createDeviceIdString() const +QString LogFilter::createThingIdString() const { QString query; if (!m_thingIds.isEmpty()) { if (m_thingIds.count() == 1) { - query.append(QString("deviceId = '%1' ").arg(m_thingIds.first().toString())); + query.append(QString("thingId = '%1' ").arg(m_thingIds.first().toString())); } else { query.append("( "); foreach (const ThingId &thingId, m_thingIds) { - query.append(QString("deviceId = '%1' ").arg(thingId.toString())); + query.append(QString("thingId = '%1' ").arg(thingId.toString())); if (thingId != m_thingIds.last()) query.append("OR "); } @@ -387,8 +387,6 @@ QString LogFilter::createDeviceIdString() const QString LogFilter::createValuesString() const { - // FIXME: check how to filter for serialized values - QString query; if (!m_values.isEmpty()) { if (m_values.count() == 1) { diff --git a/libnymea-core/logging/logfilter.h b/libnymea-core/logging/logfilter.h index f89cd9eb..72ab5294 100644 --- a/libnymea-core/logging/logfilter.h +++ b/libnymea-core/logging/logfilter.h @@ -96,7 +96,7 @@ private: QString createLevelsString() const; QString createEventTypesString() const; QString createTypeIdsString() const; - QString createDeviceIdString() const; + QString createThingIdString() const; QString createValuesString() const; }; diff --git a/libnymea-core/nymeacore.cpp b/libnymea-core/nymeacore.cpp index ae246218..7da7a0cd 100644 --- a/libnymea-core/nymeacore.cpp +++ b/libnymea-core/nymeacore.cpp @@ -284,14 +284,14 @@ QPair > NymeaCore::removeConfiguredThing(const foreach (Thing *d, childs) { Thing::ThingError removeError = m_thingManager->removeConfiguredThing(d->id()); if (removeError == Thing::ThingErrorNoError) { - m_logger->removeDeviceLogs(d->id()); + m_logger->removeThingLogs(d->id()); } } // delete the things Thing::ThingError removeError = m_thingManager->removeConfiguredThing(thingId); if (removeError == Thing::ThingErrorNoError) { - m_logger->removeDeviceLogs(thingId); + m_logger->removeThingLogs(thingId); } return QPair > (Thing::ThingErrorNoError, QList()); @@ -358,14 +358,14 @@ Thing::ThingError NymeaCore::removeConfiguredThing(const ThingId &thingId, const foreach (Thing *d, childs) { Thing::ThingError removeError = m_thingManager->removeConfiguredThing(d->id()); if (removeError == Thing::ThingErrorNoError) { - m_logger->removeDeviceLogs(d->id()); + m_logger->removeThingLogs(d->id()); } } // delete the things Thing::ThingError removeError = m_thingManager->removeConfiguredThing(thingId); if (removeError == Thing::ThingErrorNoError) { - m_logger->removeDeviceLogs(thingId); + m_logger->removeThingLogs(thingId); } return removeError; @@ -837,14 +837,14 @@ void NymeaCore::onThingDisappeared(const ThingId &thingId) foreach (Thing *d, childs) { Thing::ThingError removeError = m_thingManager->removeConfiguredThing(d->id()); if (removeError == Thing::ThingErrorNoError) { - m_logger->removeDeviceLogs(d->id()); + m_logger->removeThingLogs(d->id()); } } // delete the thing Thing::ThingError removeError = m_thingManager->removeConfiguredThing(thingId); if (removeError == Thing::ThingErrorNoError) { - m_logger->removeDeviceLogs(thingId); + m_logger->removeThingLogs(thingId); } } @@ -859,12 +859,12 @@ void NymeaCore::thingManagerLoaded() // Do some houskeeping... qCDebug(dcApplication()) << "Starting housekeeping..."; QDateTime startTime = QDateTime::currentDateTime(); - ThingsFetchJob *job = m_logger->fetchDevices(); + ThingsFetchJob *job = m_logger->fetchThings(); connect(job, &ThingsFetchJob::finished, m_thingManager, [this, job, startTime](){ foreach (const ThingId &thingId, job->results()) { if (!m_thingManager->findConfiguredThing(thingId)) { qCDebug(dcApplication()) << "Cleaning stale thing entries from log DB for thing id" << thingId; - m_logger->removeDeviceLogs(thingId); + m_logger->removeThingLogs(thingId); } } qCDebug(dcApplication()) << "Housekeeping done in" << startTime.msecsTo(QDateTime::currentDateTime()) << "ms."; diff --git a/tests/auto/logging/testlogging.cpp b/tests/auto/logging/testlogging.cpp index b7b562e0..10045f6d 100644 --- a/tests/auto/logging/testlogging.cpp +++ b/tests/auto/logging/testlogging.cpp @@ -75,7 +75,7 @@ private slots: void actionLog(); - void deviceLogs(); + void thingLogs(); void testDoubleValues(); @@ -84,7 +84,7 @@ private slots: void testLimits(); // this has to be the last test - void removeDevice(); + void removeThing(); }; void TestLogging::initTestCase() @@ -294,7 +294,7 @@ void TestLogging::eventLogs() qDebug() << "got" << loggEntryAddedVariants.count() << "Logging.LogEntryAdded"; foreach (const QVariant &loggEntryAddedVariant, loggEntryAddedVariants) { QVariantMap logEntry = loggEntryAddedVariant.toMap().value("params").toMap().value("logEntry").toMap(); - if (logEntry.value("deviceId").toUuid() == device->id()) { + if (logEntry.value("thingId").toUuid() == device->id()) { found = true; // Make sure the notification contains all the stuff we expect QCOMPARE(logEntry.value("typeId").toUuid().toString(), mockEvent1EventTypeId.toString()); @@ -311,7 +311,7 @@ void TestLogging::eventLogs() // get this logentry with filter QVariantMap params; - params.insert("deviceIds", QVariantList() << device->id()); + params.insert("thingIds", QVariantList() << device->id()); params.insert("loggingSources", QVariantList() << enumValueName(Logging::LoggingSourceEvents)); params.insert("eventTypes", QVariantList() << enumValueName(Logging::LoggingEventTypeTrigger)); params.insert("typeIds", QVariantList() << mockEvent1EventTypeId); @@ -367,7 +367,7 @@ void TestLogging::actionLog() bool found = false; foreach (const QVariant &loggEntryAddedVariant, logEntryAddedVariants) { QVariantMap logEntry = loggEntryAddedVariant.toMap().value("params").toMap().value("logEntry").toMap(); - if (logEntry.value("deviceId").toUuid() == m_mockThingId) { + if (logEntry.value("thingId").toUuid() == m_mockThingId) { found = true; // Make sure the notification contains all the stuff we expect QCOMPARE(logEntry.value("typeId").toUuid().toString(), mockWithParamsActionTypeId.toString()); @@ -383,9 +383,9 @@ void TestLogging::actionLog() // EXECUTE without params params.clear(); clientSpy.clear(); params.insert("actionTypeId", mockWithoutParamsActionTypeId); - params.insert("deviceId", m_mockThingId); - response = injectAndWait("Actions.ExecuteAction", params); - verifyDeviceError(response); + params.insert("thingId", m_mockThingId); + response = injectAndWait("Integrations.ExecuteAction", params); + verifyThingError(response); clientSpy.wait(200); @@ -394,7 +394,7 @@ void TestLogging::actionLog() // get this logentry with filter params.clear(); - params.insert("deviceIds", QVariantList() << m_mockThingId); + params.insert("thingIds", QVariantList() << m_mockThingId); params.insert("loggingSources", QVariantList() << enumValueName(Logging::LoggingSourceActions)); params.insert("eventTypes", QVariantList() << enumValueName(Logging::LoggingEventTypeTrigger)); @@ -410,9 +410,9 @@ void TestLogging::actionLog() // EXECUTE broken action params.clear(); clientSpy.clear(); params.insert("actionTypeId", mockFailingActionTypeId); - params.insert("deviceId", m_mockThingId); - response = injectAndWait("Actions.ExecuteAction", params); - verifyDeviceError(response, Thing::ThingErrorSetupFailed); + params.insert("thingId", m_mockThingId); + response = injectAndWait("Integrations.ExecuteAction", params); + verifyThingError(response, Thing::ThingErrorSetupFailed); clientSpy.wait(200); @@ -422,7 +422,7 @@ void TestLogging::actionLog() found = false; foreach (const QVariant &loggEntryAddedVariant, logEntryAddedVariants) { QVariantMap logEntry = loggEntryAddedVariant.toMap().value("params").toMap().value("logEntry").toMap(); - if (logEntry.value("deviceId").toUuid() == m_mockThingId) { + if (logEntry.value("thingId").toUuid() == m_mockThingId) { found = true; // Make sure the notification contains all the stuff we expect QCOMPARE(logEntry.value("typeId").toUuid().toString(), mockFailingActionTypeId.toString()); @@ -438,7 +438,7 @@ void TestLogging::actionLog() // get this logentry with filter params.clear(); - params.insert("deviceIds", QVariantList() << m_mockThingId); + params.insert("thingIds", QVariantList() << m_mockThingId); params.insert("loggingSources", QVariantList() << enumValueName(Logging::LoggingSourceActions)); params.insert("eventTypes", QVariantList() << enumValueName(Logging::LoggingEventTypeTrigger)); @@ -453,7 +453,7 @@ void TestLogging::actionLog() // check different filters params.clear(); - params.insert("deviceIds", QVariantList() << m_mockThingId); + params.insert("thingIds", QVariantList() << m_mockThingId); params.insert("loggingSources", QVariantList() << enumValueName(Logging::LoggingSourceActions)); params.insert("eventTypes", QVariantList() << enumValueName(Logging::LoggingEventTypeTrigger)); params.insert("typeIds", QVariantList() << mockWithoutParamsActionTypeId); @@ -465,7 +465,7 @@ void TestLogging::actionLog() QVERIFY2(!logEntries.isEmpty(), "No logs received"); params.clear(); - params.insert("deviceIds", QVariantList() << m_mockThingId); + params.insert("thingIds", QVariantList() << m_mockThingId); params.insert("loggingSources", QVariantList() << enumValueName(Logging::LoggingSourceActions)); params.insert("eventTypes", QVariantList() << enumValueName(Logging::LoggingEventTypeTrigger)); params.insert("typeIds", QVariantList() << mockWithoutParamsActionTypeId << mockWithParamsActionTypeId << mockFailingActionTypeId); @@ -480,21 +480,21 @@ void TestLogging::actionLog() QCOMPARE(disableNotifications(), true); } -void TestLogging::deviceLogs() +void TestLogging::thingLogs() { QVariantMap params; - params.insert("deviceClassId", parentMockThingClassId); - params.insert("name", "Parent device"); + params.insert("thingClassId", parentMockThingClassId); + params.insert("name", "Parent thing"); - QVariant response = injectAndWait("Devices.AddConfiguredDevice", params); - verifyDeviceError(response); + QVariant response = injectAndWait("Integrations.AddThing", params); + verifyThingError(response); - ThingId deviceId = ThingId(response.toMap().value("params").toMap().value("deviceId").toString()); - QVERIFY(!deviceId.isNull()); + ThingId thingId = ThingId(response.toMap().value("params").toMap().value("thingId").toString()); + QVERIFY(!thingId.isNull()); // get this logentry with filter params.clear(); - params.insert("deviceIds", QVariantList() << m_mockThingId << deviceId); + params.insert("thingIds", QVariantList() << m_mockThingId << thingId); params.insert("loggingSources", QVariantList() << enumValueName(Logging::LoggingSourceActions) << enumValueName(Logging::LoggingSourceEvents) << enumValueName(Logging::LoggingSourceStates)); @@ -530,21 +530,21 @@ void TestLogging::testDoubleValues() discoveryParams.append(resultCountParam); QVariantMap params; - params.insert("deviceClassId", displayPinMockThingClassId); + params.insert("thingClassId", displayPinMockThingClassId); params.insert("discoveryParams", discoveryParams); - QVariant response = injectAndWait("Devices.GetDiscoveredDevices", params); + QVariant response = injectAndWait("Integrations.DiscoverThings", params); - verifyDeviceError(response, Thing::ThingErrorNoError); + verifyThingError(response, Thing::ThingErrorNoError); // Pair device - ThingDescriptorId descriptorId = ThingDescriptorId(response.toMap().value("params").toMap().value("deviceDescriptors").toList().first().toMap().value("id").toString()); + ThingDescriptorId descriptorId = ThingDescriptorId(response.toMap().value("params").toMap().value("thingDescriptors").toList().first().toMap().value("id").toString()); params.clear(); - params.insert("deviceClassId", displayPinMockThingClassId); + params.insert("thingClassId", displayPinMockThingClassId); params.insert("name", "Display pin mock device"); - params.insert("deviceDescriptorId", descriptorId.toString()); - response = injectAndWait("Devices.PairDevice", params); + params.insert("thingDescriptorId", descriptorId.toString()); + response = injectAndWait("Integrations.PairThing", params); - verifyDeviceError(response); + verifyThingError(response); PairingTransactionId pairingTransactionId(response.toMap().value("params").toMap().value("pairingTransactionId").toString()); QString displayMessage = response.toMap().value("params").toMap().value("displayMessage").toString(); @@ -554,11 +554,11 @@ void TestLogging::testDoubleValues() params.clear(); params.insert("pairingTransactionId", pairingTransactionId.toString()); params.insert("secret", "243681"); - response = injectAndWait("Devices.ConfirmPairing", params); + response = injectAndWait("Integrations.ConfirmPairing", params); - verifyDeviceError(response); + verifyThingError(response); - ThingId deviceId(response.toMap().value("params").toMap().value("deviceId").toString()); + ThingId thingId(response.toMap().value("params").toMap().value("thingId").toString()); QSignalSpy notificationSpy(m_mockTcpServer, SIGNAL(outgoingData(QUuid,QByteArray))); @@ -569,12 +569,12 @@ void TestLogging::testDoubleValues() actionParam.insert("value", value); params.clear(); response.clear(); - params.insert("deviceId", deviceId); + params.insert("thingId", thingId); params.insert("actionTypeId", displayPinMockDoubleActionTypeId.toString()); params.insert("params", QVariantList() << actionParam); - response = injectAndWait("Actions.ExecuteAction", params); - verifyDeviceError(response); + response = injectAndWait("Integrations.ExecuteAction", params); + verifyThingError(response); notificationSpy.wait(); QVariantList logNotificationsList = checkNotifications(notificationSpy, "Logging.LogEntryAdded"); @@ -606,25 +606,25 @@ void TestLogging::testDoubleValues() // Remove device params.clear(); - params.insert("deviceId", deviceId.toString()); - response = injectAndWait("Devices.RemoveConfiguredDevice", params); - verifyDeviceError(response); + params.insert("thingId", thingId.toString()); + response = injectAndWait("Integrations.RemoveThing", params); + verifyThingError(response); } void TestLogging::testHouseKeeping() { QVariantMap params; - params.insert("deviceClassId", mockThingClassId); + params.insert("thingClassId", mockThingClassId); params.insert("name", "TestDeviceToBeRemoved"); - QVariantList deviceParams; + QVariantList thingParams; QVariantMap httpParam; httpParam.insert("paramTypeId", mockThingHttpportParamTypeId); httpParam.insert("value", 6667); - deviceParams.append(httpParam); - params.insert("deviceParams", deviceParams); - QVariant response = injectAndWait("Devices.AddConfiguredDevice", params); - ThingId deviceId = ThingId(response.toMap().value("params").toMap().value("deviceId").toUuid()); - QVERIFY2(!deviceId.isNull(), "Something went wrong creating the device for testing."); + thingParams.append(httpParam); + params.insert("thingParams", thingParams); + QVariant response = injectAndWait("Integrations.AddThing", params); + ThingId thingId = ThingId(response.toMap().value("params").toMap().value("thingId").toUuid()); + QVERIFY2(!thingId.isNull(), "Something went wrong creating the thing for testing."); // Trigger something that creates a logging entry QNetworkAccessManager nam; @@ -637,14 +637,14 @@ void TestLogging::testHouseKeeping() waitForDBSync(); params.clear(); - params.insert("deviceIds", QVariantList() << deviceId); + params.insert("thingIds", QVariantList() << thingId); response = injectAndWait("Logging.GetLogEntries", params); QVERIFY2(response.toMap().value("params").toMap().value("logEntries").toList().count() > 0, "Couldn't find state change event in log..."); // Manually delete this device from config NymeaSettings settings(NymeaSettings::SettingsRoleThings); settings.beginGroup("ThingConfig"); - settings.remove(deviceId.toString()); + settings.remove(thingId.toString()); settings.endGroup(); restartServer(); @@ -652,7 +652,7 @@ void TestLogging::testHouseKeeping() waitForDBSync(); params.clear(); - params.insert("deviceIds", QVariantList() << deviceId); + params.insert("thingIds", QVariantList() << thingId); response = injectAndWait("Logging.GetLogEntries", params); qCDebug(dcTests()) << qUtf8Printable(QJsonDocument::fromVariant(response).toJson()); QVERIFY2(response.toMap().value("status").toString() == QString("success"), "GetLogEntries failed"); @@ -676,12 +676,12 @@ void TestLogging::testLimits() QVariantMap params; params.insert("actionTypeId", mockWithParamsActionTypeId); - params.insert("deviceId", m_mockThingId); + params.insert("thingId", m_mockThingId); params.insert("params", actionParams); // EXECUTE with params - QVariant response = injectAndWait("Actions.ExecuteAction", params); - verifyDeviceError(response); + QVariant response = injectAndWait("Integrations.ExecuteAction", params); + verifyThingError(response); } waitForDBSync(); @@ -711,14 +711,14 @@ void TestLogging::testLimits() QCOMPARE(response.value("params").toMap().value("logEntries").toList().count(), 10); } -void TestLogging::removeDevice() +void TestLogging::removeThing() { // enable notifications enableNotifications({"Logging"}); // get this logentry with filter QVariantMap params; - params.insert("deviceIds", QVariantList() << m_mockThingId); + params.insert("thingIds", QVariantList() << m_mockThingId); QVariant response = injectAndWait("Logging.GetLogEntries", params); verifyLoggingError(response); QVariantList logEntries = response.toMap().value("params").toMap().value("logEntries").toList(); @@ -728,9 +728,9 @@ void TestLogging::removeDevice() // Remove the device params.clear(); - params.insert("deviceId", m_mockThingId); - response = injectAndWait("Devices.RemoveConfiguredDevice", params); - verifyDeviceError(response); + params.insert("thingId", m_mockThingId); + response = injectAndWait("Integrations.RemoveThing", params); + verifyThingError(response); clientSpy.wait(200); QVariant notification = checkNotification(clientSpy, "Logging.LogDatabaseUpdated"); @@ -738,7 +738,7 @@ void TestLogging::removeDevice() // verify that the logs from this device where removed from the db params.clear(); - params.insert("deviceIds", QVariantList() << m_mockThingId); + params.insert("thingIds", QVariantList() << m_mockThingId); response = injectAndWait("Logging.GetLogEntries", params); verifyLoggingError(response); logEntries = response.toMap().value("params").toMap().value("logEntries").toList(); diff --git a/tests/auto/loggingloading/testloggingloading.cpp b/tests/auto/loggingloading/testloggingloading.cpp index 7ca56f75..9fb64de1 100644 --- a/tests/auto/loggingloading/testloggingloading.cpp +++ b/tests/auto/loggingloading/testloggingloading.cpp @@ -45,11 +45,7 @@ protected slots: void initTestCase(); private slots: - void testLogMigration(); void testLogfileRotation(); - - void databaseSerializationTest_data(); - void databaseSerializationTest(); }; TestLoggingLoading::TestLoggingLoading(QObject *parent): QObject(parent) @@ -65,28 +61,6 @@ void TestLoggingLoading::initTestCase() QCoreApplication::instance()->setOrganizationName("nymea-test"); } -void TestLoggingLoading::testLogMigration() -{ - // Create LogEngine with log db from resource file - QString temporaryDbName = "/tmp/nymea-test/nymead-v2.sqlite"; - - if (QFile::exists(temporaryDbName)) - QVERIFY(QFile(temporaryDbName).remove()); - - // Copy v2 log db from resources to default settings path and set permissions - qDebug() << "Copy logdb v2 to" << temporaryDbName; - QVERIFY(QFile::copy(":/nymead-v2.sqlite", temporaryDbName)); - QVERIFY(QFile::setPermissions(temporaryDbName, QFile::ReadOwner | QFile::WriteOwner | QFile::ReadGroup | QFile::ReadOther)); - - LogEngine *logEngine = new LogEngine("QSQLITE", temporaryDbName); - // Check there is no rotated logfile - QVERIFY(!QFile::exists(temporaryDbName + ".1")); - - delete logEngine; - - QVERIFY(QFile(temporaryDbName).remove()); -} - void TestLoggingLoading::testLogfileRotation() { // Create LogEngine with log db from resource file @@ -115,46 +89,5 @@ void TestLoggingLoading::testLogfileRotation() QVERIFY(QFile(rotatedDbName).remove()); } -void TestLoggingLoading::databaseSerializationTest_data() -{ - QUuid uuid = QUuid("3782732b-61b4-48e8-8d6d-b5205159d7cd"); - - QVariantMap variantMap; - variantMap.insert("string", "value"); - variantMap.insert("int", 5); - variantMap.insert("double", 3.14); - variantMap.insert("uuid", uuid); - - QVariantList variantList; - variantList.append(variantMap); - variantList.append("String"); - variantList.append(3.14); - variantList.append(uuid); - - QTest::addColumn("value"); - - QTest::newRow("QString") << QVariant(QString("Hello")); - QTest::newRow("Integer") << QVariant((int)2); - QTest::newRow("Double") << QVariant((double)2.34); - QTest::newRow("Float") << QVariant((float)2.34); - QTest::newRow("QColor") << QVariant(QColor(0,255,128)); - QTest::newRow("QByteArray") << QVariant(QByteArray::fromHex("01FF332F762A")); - QTest::newRow("QUuid") << QVariant(uuid); - QTest::newRow("QVariantMap") << QVariant(variantMap); - QTest::newRow("QVariantList") << QVariant(variantList); -} - -void TestLoggingLoading::databaseSerializationTest() -{ - QFETCH(QVariant, value); - - QString serializedValue = LogValueTool::serializeValue(value); - QVariant deserializedValue = LogValueTool::deserializeValue(serializedValue); - - qDebug() << "Stored:" << value; - qDebug() << "Loaded:" << deserializedValue; - QCOMPARE(deserializedValue, value); -} - #include "testloggingloading.moc" QTEST_MAIN(TestLoggingLoading)