2a91dad1f0
Up until now, nymea would generate EventTypes for every StateType as well as emit an Event (along with a StateChanged notification) for every change. This results in a lot of duplicated network traffic which is of not much use. The StateChanged notification contains all the information in the Event too and nymea:app actually never really used Events for state changes. This commit removes the events from the ThingClass, making it a lot smaller and stops emitting Events for state changes. As this is breaking the behavior, the JSONRPC API major version is bumped.
830 lines
32 KiB
C++
830 lines
32 KiB
C++
/* * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * *
|
|
*
|
|
* Copyright 2013 - 2020, nymea GmbH
|
|
* Contact: contact@nymea.io
|
|
*
|
|
* This file is part of nymea.
|
|
* This project including source code and documentation is protected by
|
|
* copyright law, and remains the property of nymea GmbH. All rights, including
|
|
* reproduction, publication, editing and translation, are reserved. The use of
|
|
* this project is subject to the terms of a license agreement to be concluded
|
|
* with nymea GmbH in accordance with the terms of use of nymea GmbH, available
|
|
* under https://nymea.io/license
|
|
*
|
|
* GNU General Public License Usage
|
|
* Alternatively, this project may be redistributed and/or modified under the
|
|
* terms of the GNU General Public License as published by the Free Software
|
|
* Foundation, GNU version 3. This project is distributed in the hope that it
|
|
* will be useful, but WITHOUT ANY WARRANTY; without even the implied warranty
|
|
* of MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU General
|
|
* Public License for more details.
|
|
*
|
|
* You should have received a copy of the GNU General Public License along with
|
|
* this project. If not, see <https://www.gnu.org/licenses/>.
|
|
*
|
|
* For any further details and any questions please contact us under
|
|
* contact@nymea.io or see our FAQ/Licensing Information on
|
|
* https://nymea.io/license/faq
|
|
*
|
|
* * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * * */
|
|
|
|
#include "nymeasettings.h"
|
|
#include "logengine.h"
|
|
#include "loggingcategories.h"
|
|
#include "logging.h"
|
|
#include "logvaluetool.h"
|
|
|
|
#include "integrations/thingmanager.h"
|
|
|
|
#include <QCoreApplication>
|
|
#include <QSqlDatabase>
|
|
#include <QSqlDriver>
|
|
#include <QSqlQuery>
|
|
#include <QSqlRecord>
|
|
#include <QSqlError>
|
|
#include <QMetaEnum>
|
|
#include <QDateTime>
|
|
#include <QFileInfo>
|
|
#include <QTime>
|
|
#include <QtConcurrent/QtConcurrent>
|
|
|
|
#define DB_SCHEMA_VERSION 4
|
|
|
|
namespace nymeaserver {
|
|
|
|
// IMPORTANT:
|
|
// DatabaseJobs run threaded, however, QSql is *not* threadsafe.
|
|
// It is crucial to *not* access m_db while the job queue is being processed.
|
|
// That is, entire setup of the DB must happen before processQueue() is called
|
|
// and teardown must happen only after the job queue is empty.
|
|
|
|
LogEngine::LogEngine(const QString &driver, const QString &dbName, const QString &hostname, const QString &username, const QString &password, int maxDBSize, QObject *parent):
|
|
QObject(parent),
|
|
m_username(username),
|
|
m_password(password),
|
|
m_dbMaxSize(maxDBSize)
|
|
{
|
|
m_db = QSqlDatabase::addDatabase(driver, "logs");
|
|
m_db.setDatabaseName(dbName);
|
|
m_db.setHostName(hostname);
|
|
m_trimSize = qRound(0.01 * m_dbMaxSize);
|
|
m_maxQueueLength = 1000;
|
|
|
|
qCDebug(dcLogEngine) << "Opening logging database" << m_db.databaseName() << "(Max size:" << m_dbMaxSize << "trim size:" << m_trimSize << ")";
|
|
|
|
if (!m_db.isValid()) {
|
|
qCWarning(dcLogEngine) << "Database not valid:" << m_db.lastError().driverText() << m_db.lastError().databaseText();
|
|
rotate(m_db.databaseName());
|
|
}
|
|
|
|
if (!initDB(username, password)) {
|
|
qCWarning(dcLogEngine()) << "Error initializing database. Trying to correct it.";
|
|
if (QFileInfo(m_db.databaseName()).exists()) {
|
|
rotate(m_db.databaseName());
|
|
if (!initDB(username, password)) {
|
|
qCWarning(dcLogEngine()) << "Error fixing log database. Giving up. Logs can't be stored.";
|
|
return;
|
|
}
|
|
}
|
|
}
|
|
|
|
connect(&m_jobWatcher, SIGNAL(finished()), this, SLOT(handleJobFinished()));
|
|
checkDBSize();
|
|
}
|
|
|
|
LogEngine::~LogEngine()
|
|
{
|
|
// Process the job queue before allowing to shut down
|
|
while (m_currentJob) {
|
|
qCDebug(dcLogEngine()) << "Waiting for job to finish... (" << m_jobQueue.count() << "jobs left in queue)";
|
|
m_jobWatcher.waitForFinished();
|
|
// Make sure that the job queue is processes
|
|
// We can't call processQueue ourselves because thread synchronisation is done via queued connections
|
|
qApp->processEvents();
|
|
}
|
|
qCDebug(dcLogEngine()) << "Closing Database";
|
|
m_db.close();
|
|
}
|
|
|
|
void LogEngine::setThingManager(ThingManager *thingManager)
|
|
{
|
|
m_thingManager = thingManager;
|
|
connect(thingManager, &ThingManager::eventTriggered, this, &LogEngine::logEvent);
|
|
connect(thingManager, &ThingManager::thingStateChanged, this, &LogEngine::logStateChange);
|
|
connect(thingManager, &ThingManager::actionExecuted, this, &LogEngine::logAction);
|
|
}
|
|
|
|
LogEntriesFetchJob *LogEngine::fetchLogEntries(const LogFilter &filter)
|
|
{
|
|
QList<LogEntry> results;
|
|
|
|
QString limitString;
|
|
if (filter.limit() >= 0) {
|
|
limitString.append(QString("LIMIT %1 ").arg(filter.limit()));
|
|
}
|
|
if (filter.offset() > 0) {
|
|
limitString.append(QString("OFFSET %1").arg(QString::number(filter.offset())));
|
|
}
|
|
|
|
QString queryString;
|
|
if (filter.isEmpty()) {
|
|
queryString = QString("SELECT * FROM entries ORDER BY timestamp DESC %1;").arg(limitString);
|
|
} else {
|
|
queryString = QString("SELECT * FROM entries WHERE %1 ORDER BY timestamp DESC %2;").arg(filter.queryString()).arg(limitString);
|
|
}
|
|
|
|
DatabaseJob *job = new DatabaseJob(m_db, queryString, filter.values());
|
|
LogEntriesFetchJob *fetchJob = new LogEntriesFetchJob(this);
|
|
|
|
connect(job, &DatabaseJob::finished, this, [job, fetchJob](){
|
|
fetchJob->deleteLater();
|
|
if (job->error().isValid()) {
|
|
qCWarning(dcLogEngine) << "Error fetching log entries. Driver error:" << job->error().driverText() << "Database error:" << job->error().databaseText();
|
|
fetchJob->finished();
|
|
return;
|
|
}
|
|
|
|
foreach (const QSqlRecord &result, job->results()) {
|
|
LogEntry entry(
|
|
QDateTime::fromMSecsSinceEpoch(result.value("timestamp").toLongLong()),
|
|
static_cast<Logging::LoggingLevel>(result.value("loggingLevel").toInt()),
|
|
static_cast<Logging::LoggingSource>(result.value("sourceType").toInt()),
|
|
result.value("errorCode").toInt());
|
|
entry.setTypeId(result.value("typeId").toUuid());
|
|
entry.setThingId(ThingId(result.value("thingId").toString()));
|
|
entry.setValue(result.value("value").toString());
|
|
entry.setEventType(static_cast<Logging::LoggingEventType>(result.value("loggingEventType").toInt()));
|
|
entry.setActive(result.value("active").toBool());
|
|
|
|
fetchJob->m_results.append(entry);
|
|
}
|
|
qCDebug(dcLogEngine) << "Fetched" << fetchJob->results().count() << "entries for db query:" << job->executedQuery();
|
|
fetchJob->finished();
|
|
});
|
|
|
|
enqueJob(job, true);
|
|
|
|
return fetchJob;
|
|
}
|
|
|
|
ThingsFetchJob *LogEngine::fetchThings()
|
|
{
|
|
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);
|
|
connect(job, &DatabaseJob::finished, this, [job, fetchJob](){
|
|
fetchJob->deleteLater();
|
|
if (job->error().type() != QSqlError::NoError) {
|
|
qCWarning(dcLogEngine()) << "Error fetching device entries from log database:" << job->error().driverText() << job->error().databaseText();
|
|
fetchJob->finished();
|
|
return;
|
|
}
|
|
|
|
foreach (const QSqlRecord &result, job->results()) {
|
|
fetchJob->m_results.append(ThingId(result.value("thingId").toUuid()));
|
|
}
|
|
fetchJob->finished();
|
|
});
|
|
enqueJob(job, true);
|
|
return fetchJob;
|
|
}
|
|
|
|
bool LogEngine::jobsRunning() const
|
|
{
|
|
return !m_jobQueue.isEmpty() || m_currentJob;
|
|
}
|
|
|
|
void LogEngine::setMaxLogEntries(int maxLogEntries, int trimSize)
|
|
{
|
|
m_dbMaxSize = maxLogEntries;
|
|
m_trimSize = trimSize;
|
|
trim();
|
|
}
|
|
|
|
void LogEngine::clearDatabase()
|
|
{
|
|
qCWarning(dcLogEngine) << "Clearing logging database.";
|
|
|
|
QString queryDeleteString = QString("DELETE FROM entries;");
|
|
|
|
DatabaseJob *job = new DatabaseJob(m_db, queryDeleteString);
|
|
|
|
connect(job, &DatabaseJob::finished, this, [this, job](){
|
|
if (job->error().type() != QSqlError::NoError) {
|
|
qCWarning(dcLogEngine) << "Error clearing log database. Driver error:" << job->error().driverText() << "Database error:" << job->error().databaseText();
|
|
return;
|
|
}
|
|
m_entryCount = 0;
|
|
emit logDatabaseUpdated();
|
|
});
|
|
|
|
enqueJob(job);
|
|
}
|
|
|
|
void LogEngine::logSystemEvent(const QDateTime &dateTime, bool active, Logging::LoggingLevel level)
|
|
{
|
|
qCDebug(dcLogEngine()) << "Logging system event:" << active;
|
|
LogEntry entry(dateTime, level, Logging::LoggingSourceSystem);
|
|
entry.setEventType(Logging::LoggingEventTypeActiveChange);
|
|
entry.setActive(active);
|
|
appendLogEntry(entry);
|
|
}
|
|
|
|
void LogEngine::logEvent(const Event &event)
|
|
{
|
|
if (!event.logged()) {
|
|
return;
|
|
}
|
|
|
|
QVariantList valueList;
|
|
foreach (const Param ¶m, event.params()) {
|
|
valueList << param.value();
|
|
}
|
|
|
|
LogEntry entry(Logging::LoggingSourceEvents);
|
|
entry.setTypeId(event.eventTypeId());
|
|
entry.setThingId(event.thingId());
|
|
if (valueList.count() == 1) {
|
|
entry.setValue(valueList.first());
|
|
} else {
|
|
entry.setValue(valueList);
|
|
}
|
|
appendLogEntry(entry);
|
|
}
|
|
|
|
void LogEngine::logStateChange(Thing *thing, const StateTypeId &stateTypeId, const QVariant &value)
|
|
{
|
|
if (!thing->loggedStateTypeIds().contains(stateTypeId)) {
|
|
return;
|
|
}
|
|
|
|
LogEntry entry(Logging::LoggingSourceStates);
|
|
entry.setTypeId(stateTypeId);
|
|
entry.setThingId(thing->id());
|
|
entry.setValue(value);
|
|
appendLogEntry(entry);
|
|
}
|
|
|
|
void LogEngine::logAction(const Action &action, Thing::ThingError status)
|
|
{
|
|
Logging::LoggingLevel level = status == Thing::ThingErrorNoError ? Logging::LoggingLevelInfo : Logging::LoggingLevelAlert;
|
|
LogEntry entry(QDateTime::currentDateTime(), level, Logging::LoggingSourceActions, status);
|
|
entry.setTypeId(action.actionTypeId());
|
|
entry.setThingId(action.thingId());
|
|
|
|
if (action.params().isEmpty()) {
|
|
entry.setValue(QVariant());
|
|
} else if (action.params().count() == 1) {
|
|
entry.setValue(action.params().first().value());
|
|
} else {
|
|
QVariantList valueList;
|
|
foreach (const Param ¶m, action.params()) {
|
|
valueList << param.value();
|
|
}
|
|
entry.setValue(valueList);
|
|
}
|
|
appendLogEntry(entry);
|
|
}
|
|
|
|
void LogEngine::logBrowserAction(const BrowserAction &browserAction, Logging::LoggingLevel level, int errorCode)
|
|
{
|
|
LogEntry entry(level, Logging::LoggingSourceBrowserActions, errorCode);
|
|
entry.setThingId(browserAction.thingId());
|
|
entry.setValue(browserAction.itemId());
|
|
appendLogEntry(entry);
|
|
}
|
|
|
|
void LogEngine::logBrowserItemAction(const BrowserItemAction &browserItemAction, Logging::LoggingLevel level, int errorCode)
|
|
{
|
|
LogEntry entry(level, Logging::LoggingSourceBrowserActions, errorCode);
|
|
entry.setThingId(browserItemAction.thingId());
|
|
entry.setTypeId(browserItemAction.actionTypeId());
|
|
entry.setValue(browserItemAction.itemId());
|
|
appendLogEntry(entry);
|
|
}
|
|
|
|
void LogEngine::logRuleTriggered(const Rule &rule)
|
|
{
|
|
LogEntry entry(Logging::LoggingSourceRules);
|
|
entry.setTypeId(rule.id());
|
|
entry.setEventType(Logging::LoggingEventTypeTrigger);
|
|
appendLogEntry(entry);
|
|
}
|
|
|
|
void LogEngine::logRuleActiveChanged(const Rule &rule)
|
|
{
|
|
LogEntry entry(Logging::LoggingSourceRules);
|
|
entry.setTypeId(rule.id());
|
|
entry.setActive(rule.active());
|
|
entry.setEventType(Logging::LoggingEventTypeActiveChange);
|
|
appendLogEntry(entry);
|
|
}
|
|
|
|
void LogEngine::logRuleEnabledChanged(const Rule &rule, const bool &enabled)
|
|
{
|
|
LogEntry entry(Logging::LoggingSourceRules);
|
|
entry.setTypeId(rule.id());
|
|
entry.setEventType(Logging::LoggingEventTypeEnabledChange);
|
|
entry.setActive(enabled);
|
|
appendLogEntry(entry);
|
|
}
|
|
|
|
void LogEngine::logRuleActionsExecuted(const Rule &rule)
|
|
{
|
|
LogEntry entry(Logging::LoggingSourceRules);
|
|
entry.setTypeId(rule.id());
|
|
entry.setEventType(Logging::LoggingEventTypeActionsExecuted);
|
|
appendLogEntry(entry);
|
|
}
|
|
|
|
void LogEngine::logRuleExitActionsExecuted(const Rule &rule)
|
|
{
|
|
LogEntry entry(Logging::LoggingSourceRules);
|
|
entry.setTypeId(rule.id());
|
|
entry.setEventType(Logging::LoggingEventTypeExitActionsExecuted);
|
|
appendLogEntry(entry);
|
|
}
|
|
|
|
void LogEngine::removeThingLogs(const ThingId &thingId)
|
|
{
|
|
qCDebug(dcLogEngine) << "Deleting log entries from device" << 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](){
|
|
if (job->error().type() != QSqlError::NoError) {
|
|
qCWarning(dcLogEngine) << "Error deleting log entries from device" << thingId.toString() << ". Driver error:" << job->error().driverText() << "Database error:" << job->error().databaseText();
|
|
return;
|
|
}
|
|
|
|
emit logDatabaseUpdated();
|
|
checkDBSize();
|
|
});
|
|
|
|
enqueJob(job);
|
|
}
|
|
|
|
void LogEngine::removeRuleLogs(const RuleId &ruleId)
|
|
{
|
|
qCDebug(dcLogEngine) << "Deleting log entries from rule" << ruleId.toString();
|
|
|
|
QString queryDeleteString = QString("DELETE FROM entries WHERE typeId = '%1';").arg(ruleId.toString());
|
|
|
|
DatabaseJob *job = new DatabaseJob(m_db, queryDeleteString);
|
|
|
|
connect(job, &DatabaseJob::finished, this, [this, job, ruleId](){
|
|
|
|
if (job->error().type() != QSqlError::NoError) {
|
|
qCWarning(dcLogEngine) << "Error deleting log entries from rule" << ruleId.toString() << ". Driver error:" << job->error().driverText() << "Database error:" << job->error().databaseText();
|
|
return;
|
|
}
|
|
|
|
emit logDatabaseUpdated();
|
|
checkDBSize();
|
|
});
|
|
|
|
enqueJob(job);
|
|
}
|
|
|
|
void LogEngine::appendLogEntry(const LogEntry &entry)
|
|
{
|
|
qCDebug(dcLogEngine()) << "Adding log entry:" << entry;
|
|
QString queryString = QString("INSERT INTO entries (timestamp, loggingEventType, loggingLevel, sourceType, typeId, thingId, value, active, errorCode) values (?, ?, ?, ?, ?, ?, ?, ?, ?);");
|
|
QVariantList bindValues;
|
|
bindValues.append(entry.timestamp().toMSecsSinceEpoch());
|
|
bindValues.append(entry.eventType());
|
|
bindValues.append(entry.level());
|
|
bindValues.append(entry.source());
|
|
bindValues.append(entry.typeId().toString());
|
|
bindValues.append(entry.thingId().toString());
|
|
bindValues.append(LogValueTool::convertVariantToString(entry.value()));
|
|
bindValues.append(entry.active());
|
|
bindValues.append(entry.errorCode());
|
|
|
|
DatabaseJob *job = new DatabaseJob(m_db, queryString, bindValues);
|
|
|
|
// Check for log flooding. If we are exceeding the queue we'll start flagging log events of a certain type.
|
|
// If we'll get more log events of the same type while the queue is still exceededd, we'll discard the old
|
|
// ones and queue up the new one instead. The most recent one is more important (i.e. we don't want to lose
|
|
// the last event in a series).
|
|
if (m_jobQueue.count() > m_maxQueueLength) {
|
|
if (!m_initialized) {
|
|
qCDebug(dcLogEngine()) << "Log DB not initialized and queue is full. Discarding log entry.";
|
|
delete job;
|
|
return;
|
|
}
|
|
qCDebug(dcLogEngine()) << "An excessive amount of data is being logged. (" << m_jobQueue.length() << "jobs in the queue)";
|
|
if (m_flaggedJobs.contains(entry.typeId().toString() + entry.thingId().toString())) {
|
|
if (m_flaggedJobs.value(entry.typeId().toString() + entry.thingId().toString()).count() > 10) {
|
|
qCWarning(dcLogEngine()) << "Discarding log entry because of excessive log flooding.";
|
|
DatabaseJob *job = m_flaggedJobs[entry.typeId().toString() + entry.thingId().toString()].takeFirst();
|
|
int jobIdx = m_jobQueue.indexOf(job);
|
|
m_jobQueue.takeAt(jobIdx)->deleteLater();
|
|
}
|
|
}
|
|
m_flaggedJobs[entry.typeId().toString() + entry.thingId().toString()].append(job);
|
|
}
|
|
|
|
connect(job, &DatabaseJob::finished, this, [this, job, entry](){
|
|
|
|
m_flaggedJobs[entry.typeId().toString() + entry.thingId().toString()].removeAll(job);
|
|
|
|
if (job->error().type() != QSqlError::NoError) {
|
|
qCWarning(dcLogEngine) << "Error writing log entry. Driver error:" << job->error().driverText() << "Database error:" << job->error().databaseText();
|
|
qCWarning(dcLogEngine) << entry;
|
|
m_dbMalformed = true;
|
|
return;
|
|
}
|
|
|
|
|
|
emit logEntryAdded(entry);
|
|
|
|
m_entryCount++;
|
|
trim();
|
|
});
|
|
|
|
enqueJob(job);
|
|
}
|
|
|
|
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 || 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;
|
|
}
|
|
m_entryCount = job->results().first().value(0).toInt();
|
|
});
|
|
enqueJob(job, true);
|
|
}
|
|
|
|
void LogEngine::trim()
|
|
{
|
|
if (m_dbMaxSize == -1 || m_entryCount < m_dbMaxSize) {
|
|
// No trimming required
|
|
return;
|
|
}
|
|
QDateTime startTime = QDateTime::currentDateTime();
|
|
|
|
QString queryDeleteString = QString("DELETE FROM entries WHERE ROWID IN (SELECT ROWID FROM entries ORDER BY timestamp DESC LIMIT -1 OFFSET %1);").arg(QString::number(m_dbMaxSize - m_trimSize));
|
|
|
|
DatabaseJob *deleteJob = new DatabaseJob(m_db, queryDeleteString);
|
|
|
|
connect(deleteJob, &DatabaseJob::finished, this, [this, deleteJob, startTime](){
|
|
if (deleteJob->error().type() != QSqlError::NoError) {
|
|
qCWarning(dcLogEngine) << "Error deleting oldest log entries to keep size. Driver error:" << deleteJob->error().driverText() << "Database error:" << deleteJob->error().databaseText();
|
|
}
|
|
qCDebug(dcLogEngine()) << "Ran housekeeping on log database in" << startTime.msecsTo(QDateTime::currentDateTime()) << "ms. (Deleted" << m_entryCount - (m_dbMaxSize - m_trimSize) << "entries)";
|
|
m_entryCount = m_dbMaxSize - m_trimSize;
|
|
|
|
emit logDatabaseUpdated();
|
|
});
|
|
|
|
qCDebug(dcLogEngine()) << "Scheduling housekeeping job.";
|
|
enqueJob(deleteJob, true);
|
|
}
|
|
|
|
void LogEngine::enqueJob(DatabaseJob *job, bool priority)
|
|
{
|
|
if (priority) {
|
|
m_jobQueue.prepend(job);
|
|
} else {
|
|
m_jobQueue.append(job);
|
|
}
|
|
qCDebug(dcLogEngine()) << "Scheduled job at position" << (priority ? 0 : m_jobQueue.count() - 1) << "(" << m_jobQueue.count() << "jobs in the queue)";
|
|
processQueue();
|
|
}
|
|
|
|
void LogEngine::processQueue()
|
|
{
|
|
if (!m_initialized) {
|
|
return;
|
|
}
|
|
|
|
if (m_jobQueue.isEmpty()) {
|
|
emit jobsRunningChanged();
|
|
return;
|
|
}
|
|
|
|
if (m_currentJob) {
|
|
return;
|
|
}
|
|
|
|
emit jobsRunningChanged();
|
|
|
|
if (m_dbMalformed) {
|
|
qCWarning(dcLogEngine()) << "Database is malformed. Trying to recover...";
|
|
m_db.close();
|
|
rotate(m_db.databaseName());
|
|
initDB(m_username, m_password);
|
|
m_dbMalformed = false;
|
|
}
|
|
|
|
|
|
DatabaseJob *job = m_jobQueue.takeFirst();
|
|
qCDebug(dcLogEngine()) << "Processing DB queue. (" << m_jobQueue.count() << "jobs left in queue," << m_entryCount << "entries in DB)";
|
|
m_currentJob = job;
|
|
|
|
QFuture<DatabaseJob*> future = QtConcurrent::run([job](){
|
|
QSqlQuery query(job->m_db);
|
|
query.prepare(job->m_queryString);
|
|
|
|
foreach (const QVariant &value, job->m_bindValues) {
|
|
query.addBindValue(value);
|
|
}
|
|
|
|
query.exec();
|
|
|
|
job->m_error = query.lastError();
|
|
job->m_executedQuery = query.executedQuery();
|
|
|
|
if (!query.lastError().isValid()) {
|
|
while (query.next()) {
|
|
job->m_results.append(query.record());
|
|
}
|
|
}
|
|
|
|
return job;
|
|
});
|
|
|
|
m_jobWatcher.setFuture(future);
|
|
}
|
|
|
|
void LogEngine::handleJobFinished()
|
|
{
|
|
DatabaseJob *job = m_jobWatcher.result();
|
|
job->finished();
|
|
job->deleteLater();
|
|
m_currentJob = nullptr;
|
|
|
|
qCDebug(dcLogEngine()) << "DB job finished. (" << m_entryCount << "entries in DB)";
|
|
processQueue();
|
|
}
|
|
|
|
void LogEngine::rotate(const QString &dbName)
|
|
{
|
|
int index = 1;
|
|
while (QFileInfo(QString("%1.%2").arg(dbName).arg(index)).exists()) {
|
|
index++;
|
|
}
|
|
qCDebug(dcLogEngine()) << "Backing up old database file to" << QString("%1.%2").arg(dbName).arg(index);
|
|
QFile f(dbName);
|
|
if (!f.rename(QString("%1.%2").arg(dbName).arg(index))) {
|
|
qCWarning(dcLogEngine()) << "Error backing up old database.";
|
|
} else {
|
|
qCDebug(dcLogEngine()) << "Successfully moved old database";
|
|
}
|
|
}
|
|
|
|
bool LogEngine::migrateDatabaseVersion3to4()
|
|
{
|
|
QSqlQuery renameQuery = m_db.exec("ALTER TABLE entries RENAME TO _entries_v3;");
|
|
if (m_db.lastError().isValid()) {
|
|
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);
|
|
|
|
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();
|
|
|
|
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));
|
|
if (m_db.lastError().isValid()) {
|
|
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 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)
|
|
{
|
|
m_db.close();
|
|
m_initialized = false;
|
|
bool opened = m_db.open(username, password);
|
|
if (!opened) {
|
|
qCWarning(dcLogEngine()) << "Can't open Log DB. Init failed.";
|
|
return false;
|
|
}
|
|
|
|
if (!m_db.tables().contains("metadata")) {
|
|
qCDebug(dcLogEngine()) << "Empty Database. Setting up metadata...";
|
|
m_db.exec("CREATE TABLE metadata (`key` VARCHAR(10), data VARCHAR(40));");
|
|
if (m_db.lastError().isValid()) {
|
|
qCWarning(dcLogEngine) << "Error initualizing database. Driver error:" << m_db.lastError().driverText() << "Database error:" << m_db.lastError().databaseText();
|
|
m_db.close();
|
|
return false;
|
|
}
|
|
m_db.exec(QString("INSERT INTO metadata (`key`, data) VALUES('version', '%1');").arg(DB_SCHEMA_VERSION));
|
|
}
|
|
|
|
QSqlQuery query = m_db.exec("SELECT data FROM metadata WHERE `key` = 'version';");
|
|
if (query.next()) {
|
|
int version = query.value("data").toInt();
|
|
|
|
// Migration from 3 -> 4
|
|
if (version == 3) {
|
|
if (!migrateDatabaseVersion3to4()) {
|
|
qCWarning(dcLogEngine()) << "Migration process failed.";
|
|
m_db.close();
|
|
return false;
|
|
} else {
|
|
// Successfully migrated
|
|
version = 4;
|
|
}
|
|
}
|
|
|
|
if (version != DB_SCHEMA_VERSION) {
|
|
qCWarning(dcLogEngine) << "Log schema version not matching! Schema upgrade not implemented for this version change.";
|
|
m_db.close();
|
|
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.";
|
|
m_db.close();
|
|
return false;
|
|
}
|
|
|
|
if (!m_db.tables().contains("sourceTypes")) {
|
|
m_db.exec("CREATE TABLE sourceTypes (id int, name varchar(20), PRIMARY KEY(id));");
|
|
//qCDebug(dcLogEngine) << m_db.lastError().databaseText();
|
|
QMetaEnum logTypes = Logging::staticMetaObject.enumerator(Logging::staticMetaObject.indexOfEnumerator("LoggingSource"));
|
|
Q_ASSERT_X(logTypes.isValid(), "LogEngine", "Logging has no enum LoggingSource");
|
|
for (int i = 0; i < logTypes.keyCount(); i++) {
|
|
m_db.exec(QString("INSERT INTO sourceTypes (id, name) VALUES(%1, '%2');").arg(i).arg(logTypes.key(i)));
|
|
}
|
|
}
|
|
|
|
if (!m_db.tables().contains("loggingEventTypes")) {
|
|
m_db.exec("CREATE TABLE loggingEventTypes (id int, name varchar(40), PRIMARY KEY(id));");
|
|
//qCDebug(dcLogEngine) << m_db.lastError().databaseText();
|
|
QMetaEnum logTypes = Logging::staticMetaObject.enumerator(Logging::staticMetaObject.indexOfEnumerator("LoggingEventType"));
|
|
Q_ASSERT_X(logTypes.isValid(), "LogEngine", "Logging has no enum LoggingEventType");
|
|
for (int i = 0; i < logTypes.keyCount(); i++) {
|
|
m_db.exec(QString("INSERT INTO loggingEventTypes (id, name) VALUES(%1, '%2');").arg(i).arg(logTypes.key(i)));
|
|
if (m_db.lastError().isValid()) {
|
|
qCWarning(dcLogEngine()) << "Failed to insert loggingEventTypes into DB. Driver error:" << m_db.lastError().driverText() << "Database error:" << m_db.lastError().databaseText();
|
|
}
|
|
}
|
|
}
|
|
|
|
if (!m_db.tables().contains("entries")) {
|
|
qCDebug(dcLogEngine()) << "No \"entries\" table in database. Creating it.";
|
|
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 creating log table in database. Driver error:" << m_db.lastError().driverText() << "Database error:" << m_db.lastError().databaseText();
|
|
m_db.close();
|
|
return false;
|
|
}
|
|
|
|
|
|
}
|
|
|
|
qCDebug(dcLogEngine) << "Initialized logging DB successfully. (maximum DB size:" << m_dbMaxSize << ")";
|
|
m_initialized = true;
|
|
return true;
|
|
}
|
|
|
|
}
|