core: Display problem step if storage setup fails
[quassel.git] / src / core / abstractsqlstorage.cpp
1 /***************************************************************************
2  *   Copyright (C) 2005-2019 by the Quassel Project                        *
3  *   devel@quassel-irc.org                                                 *
4  *                                                                         *
5  *   This program is free software; you can redistribute it and/or modify  *
6  *   it under the terms of the GNU General Public License as published by  *
7  *   the Free Software Foundation; either version 2 of the License, or     *
8  *   (at your option) version 3.                                           *
9  *                                                                         *
10  *   This program is distributed in the hope that it will be useful,       *
11  *   but WITHOUT ANY WARRANTY; without even the implied warranty of        *
12  *   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the         *
13  *   GNU General Public License for more details.                          *
14  *                                                                         *
15  *   You should have received a copy of the GNU General Public License     *
16  *   along with this program; if not, write to the                         *
17  *   Free Software Foundation, Inc.,                                       *
18  *   51 Franklin Street, Fifth Floor, Boston, MA  02110-1301, USA.         *
19  ***************************************************************************/
20
21 #include "abstractsqlstorage.h"
22
23 #include <QMutexLocker>
24 #include <QSqlDriver>
25 #include <QSqlError>
26 #include <QSqlField>
27 #include <QSqlQuery>
28
29 #include "quassel.h"
30
31 int AbstractSqlStorage::_nextConnectionId = 0;
32 AbstractSqlStorage::AbstractSqlStorage(QObject* parent)
33     : Storage(parent)
34 {}
35
36 AbstractSqlStorage::~AbstractSqlStorage()
37 {
38     // disconnect the connections, so their deletion is no longer interessting for us
39     QHash<QThread*, Connection*>::iterator conIter;
40     for (conIter = _connectionPool.begin(); conIter != _connectionPool.end(); ++conIter) {
41         QSqlDatabase::removeDatabase(conIter.value()->name());
42         disconnect(conIter.value(), nullptr, this, nullptr);
43     }
44 }
45
46 QSqlDatabase AbstractSqlStorage::logDb()
47 {
48     if (!_connectionPool.contains(QThread::currentThread()))
49         addConnectionToPool();
50
51     QSqlDatabase db = QSqlDatabase::database(_connectionPool[QThread::currentThread()]->name(), false);
52
53     if (!db.isOpen()) {
54         qWarning() << "Database connection" << displayName() << "for thread" << QThread::currentThread()
55                    << "was lost, attempting to reconnect...";
56         dbConnect(db);
57     }
58
59     return db;
60 }
61
62 void AbstractSqlStorage::addConnectionToPool()
63 {
64     QMutexLocker locker(&_connectionPoolMutex);
65     // we have to recheck if the connection pool already contains a connection for
66     // this thread. Since now (after the lock) we can only tell for sure
67     if (_connectionPool.contains(QThread::currentThread()))
68         return;
69
70     QThread* currentThread = QThread::currentThread();
71
72     int connectionId = _nextConnectionId++;
73
74     Connection* connection = new Connection(QLatin1String(QString("quassel_%1_con_%2").arg(driverName()).arg(connectionId).toLatin1()));
75     connection->moveToThread(currentThread);
76     connect(this, &QObject::destroyed, connection, &QObject::deleteLater);
77     connect(currentThread, &QObject::destroyed, connection, &QObject::deleteLater);
78     connect(connection, &QObject::destroyed, this, &AbstractSqlStorage::connectionDestroyed);
79     _connectionPool[currentThread] = connection;
80
81     QSqlDatabase db = QSqlDatabase::addDatabase(driverName(), connection->name());
82     db.setDatabaseName(databaseName());
83
84     if (!hostName().isEmpty())
85         db.setHostName(hostName());
86
87     if (port() != -1)
88         db.setPort(port());
89
90     if (!userName().isEmpty()) {
91         db.setUserName(userName());
92         db.setPassword(password());
93     }
94
95     dbConnect(db);
96 }
97
98 void AbstractSqlStorage::dbConnect(QSqlDatabase& db)
99 {
100     if (!db.open()) {
101         qWarning() << "Unable to open database" << displayName() << "for thread" << QThread::currentThread();
102         qWarning() << "-" << db.lastError().text();
103     }
104     else {
105         if (!initDbSession(db)) {
106             qWarning() << "Unable to initialize database" << displayName() << "for thread" << QThread::currentThread();
107             db.close();
108         }
109     }
110 }
111
112 Storage::State AbstractSqlStorage::init(const QVariantMap& settings, const QProcessEnvironment& environment, bool loadFromEnvironment)
113 {
114     setConnectionProperties(settings, environment, loadFromEnvironment);
115
116     _debug = Quassel::isOptionSet("debug");
117
118     QSqlDatabase db = logDb();
119     if (!db.isValid() || !db.isOpen())
120         return NotAvailable;
121
122     if (installedSchemaVersion() == -1) {
123         qCritical() << "Storage Schema is missing!";
124         return NeedsSetup;
125     }
126
127     if (installedSchemaVersion() > schemaVersion()) {
128         qCritical() << "Installed Schema is newer then any known Version.";
129         return NotAvailable;
130     }
131
132     if (installedSchemaVersion() < schemaVersion()) {
133         qInfo() << qPrintable(tr("Installed database schema (version %1) is not up to date. Upgrading to "
134                                   "version %2...  This may take a while for major upgrades.")
135                                    .arg(installedSchemaVersion())
136                                    .arg(schemaVersion()));
137         emit dbUpgradeInProgress(true);
138         auto upgradeResult = upgradeDb();
139         emit dbUpgradeInProgress(false);
140         if (!upgradeResult) {
141             qWarning() << qPrintable(tr("Upgrade failed..."));
142             return NotAvailable;
143         }
144         // Add a message when migration succeeds to avoid confusing folks by implying the schema upgrade failed if
145         // later functionality does not work.
146         qInfo() << qPrintable(tr("Installed database schema successfully upgraded to version %1.").arg(schemaVersion()));
147     }
148
149     qInfo() << qPrintable(displayName()) << "storage backend is ready. Schema version:" << installedSchemaVersion();
150     return IsReady;
151 }
152
153 QString AbstractSqlStorage::queryString(const QString& queryName, int version)
154 {
155     QFileInfo queryInfo;
156
157     // The current schema is stored in the root folder, while upgrade queries are stored in the
158     // 'versions/##' subfolders.
159     if (version == 0) {
160         // Use the current SQL schema, not a versioned request
161         queryInfo = QFileInfo(QString(":/SQL/%1/%2.sql").arg(displayName()).arg(queryName));
162         // If version is needed later, get it via version = schemaVersion();
163     }
164     else {
165         // Use the specified schema version, not the general folder
166         queryInfo = QFileInfo(QString(":/SQL/%1/version/%2/%3.sql").arg(displayName()).arg(version).arg(queryName));
167     }
168
169     if (!queryInfo.exists() || !queryInfo.isFile() || !queryInfo.isReadable()) {
170         qCritical() << "Unable to read SQL-Query" << queryName << "for engine" << displayName();
171         return QString();
172     }
173
174     QFile queryFile(queryInfo.filePath());
175     if (!queryFile.open(QIODevice::ReadOnly | QIODevice::Text))
176         return QString();
177     QString query = QTextStream(&queryFile).readAll();
178     queryFile.close();
179
180     return query.trimmed();
181 }
182
183 QList<AbstractSqlStorage::SqlQueryResource> AbstractSqlStorage::setupQueries()
184 {
185     QList<SqlQueryResource> queries;
186     // The current schema is stored in the root folder, including setup scripts.
187     QDir dir = QDir(QString(":/SQL/%1/").arg(displayName()));
188     foreach (QFileInfo fileInfo, dir.entryInfoList(QStringList() << "setup*", QDir::NoFilter, QDir::Name)) {
189         queries << SqlQueryResource(queryString(fileInfo.baseName()), fileInfo.baseName());
190     }
191     return queries;
192 }
193
194 bool AbstractSqlStorage::setup(const QVariantMap& settings, const QProcessEnvironment& environment, bool loadFromEnvironment)
195 {
196     setConnectionProperties(settings, environment, loadFromEnvironment);
197     QSqlDatabase db = logDb();
198     if (!db.isOpen()) {
199         qCritical() << "Unable to setup Logging Backend!";
200         return false;
201     }
202
203     db.transaction();
204     foreach (auto queryResource, setupQueries()) {
205         QSqlQuery query = db.exec(queryResource.queryString);
206         if (!watchQuery(query)) {
207             qCritical() << qPrintable(QString("Unable to setup Logging Backend!  Setup query failed (step: %1).")
208                                       .arg(queryResource.queryFilename));
209             db.rollback();
210             return false;
211         }
212     }
213     bool success = setupSchemaVersion(schemaVersion());
214     if (success)
215         db.commit();
216     else
217         db.rollback();
218     return success;
219 }
220
221 QList<AbstractSqlStorage::SqlQueryResource> AbstractSqlStorage::upgradeQueries(int version)
222 {
223     QList<SqlQueryResource> queries;
224     // Upgrade queries are stored in the 'version/##' subfolders.
225     QDir dir = QDir(QString(":/SQL/%1/version/%2/").arg(displayName()).arg(version));
226     foreach (QFileInfo fileInfo, dir.entryInfoList(QStringList() << "upgrade*", QDir::NoFilter, QDir::Name)) {
227         queries << SqlQueryResource(queryString(fileInfo.baseName(), version), fileInfo.baseName());
228     }
229     return queries;
230 }
231
232 bool AbstractSqlStorage::upgradeDb()
233 {
234     if (schemaVersion() <= installedSchemaVersion())
235         return true;
236
237     QSqlDatabase db = logDb();
238
239     // TODO: For databases that support it (e.g. almost only PostgreSQL), wrap upgrades in a
240     // transaction.  This will need careful testing of potential additional space requirements and
241     // any database modifications that might not be allowed in a transaction.
242
243     // Check if we're resuming an interrupted multi-step upgrade: is an upgrade step stored?
244     const QString previousLaunchUpgradeStep = schemaVersionUpgradeStep();
245     bool resumingUpgrade = !previousLaunchUpgradeStep.isEmpty();
246
247     for (int ver = installedSchemaVersion() + 1; ver <= schemaVersion(); ver++) {
248         foreach (auto queryResource, upgradeQueries(ver)) {
249             if (resumingUpgrade) {
250                 // An upgrade was interrupted.  Check if this matches the the last successful query.
251                 if (previousLaunchUpgradeStep == queryResource.queryFilename) {
252                     // Found the matching query!
253                     qInfo() << qPrintable(QString("Resuming interrupted upgrade for schema version %1 (last step: %2)")
254                                           .arg(QString::number(ver), previousLaunchUpgradeStep));
255
256                     // Stop searching for queries
257                     resumingUpgrade = false;
258                     // Continue past the previous query with the next not-yet-tried query
259                     continue;
260                 }
261                 else {
262                     // Not yet matched, keep looking
263                     continue;
264                 }
265             }
266
267             // Run the upgrade query
268             QSqlQuery query = db.exec(queryResource.queryString);
269             if (!watchQuery(query)) {
270                 // Individual upgrade query failed, bail out
271                 qCritical() << qPrintable(QString("Unable to upgrade Logging Backend!  Upgrade query in schema version %1 failed (step: %2).")
272                                           .arg(QString::number(ver), queryResource.queryFilename));
273                 return false;
274             }
275             else {
276                 // Mark as successful
277                 setSchemaVersionUpgradeStep(queryResource.queryFilename);
278             }
279         }
280
281         if (resumingUpgrade) {
282             // Something went wrong and the last successful SQL query to resume from couldn't be
283             // found.
284             // 1.  The storage of successful query glitched, or the database was manually changed
285             // 2.  Quassel changed the filenames of upgrade queries, and the local Quassel core
286             //     version was replaced during an interrupted schema upgrade
287             //
288             // Both are unlikely, but it's a good idea to handle it anyways.
289
290             qCritical() << qPrintable(QString("Unable to resume interrupted upgrade in Logging "
291                                               "Backend!  Missing upgrade step in schema version %1 "
292                                               "(expected step: %2)")
293                                       .arg(QString::number(ver), previousLaunchUpgradeStep));
294             return false;
295         }
296
297         // Update the schema version for each intermediate step and mark the step as done.  This
298         // ensures that any interrupted upgrades have a greater chance of resuming correctly after
299         // core restart.
300         //
301         // Almost all databases make single queries atomic (fully works or fully fails, no partial),
302         // and with many of the longest migrations being a single query, this makes upgrade
303         // interruptions much more likely to leave the database in a valid intermediate schema
304         // version.
305         if (!updateSchemaVersion(ver, true)) {
306             // Updating the schema version failed, bail out
307             qCritical() << "Unable to upgrade Logging Backend!  Setting schema version" << ver << "failed.";
308             return false;
309         }
310     }
311
312     // Update the schema version for the final step.  Split this out to offer more informative
313     // logging (though setting schema version really should not fail).
314     if (!updateSchemaVersion(schemaVersion())) {
315         // Updating the final schema version failed, bail out
316         qCritical() << "Unable to upgrade Logging Backend!  Setting final schema version" << schemaVersion() << "failed.";
317         return false;
318     }
319
320     // If we made it here, everything seems to have worked!
321     return true;
322 }
323
324 int AbstractSqlStorage::schemaVersion()
325 {
326     // returns the newest Schema Version!
327     // not the currently used one! (though it can be the same)
328     if (_schemaVersion > 0)
329         return _schemaVersion;
330
331     int version;
332     bool ok;
333     // Schema versions are stored in the 'version/##' subfolders.
334     QDir dir = QDir(QString(":/SQL/%1/version/").arg(displayName()));
335     foreach (QFileInfo fileInfo, dir.entryInfoList()) {
336         if (!fileInfo.isDir())
337             continue;
338
339         version = fileInfo.fileName().toInt(&ok);
340         if (!ok)
341             continue;
342
343         if (version > _schemaVersion)
344             _schemaVersion = version;
345     }
346     return _schemaVersion;
347 }
348
349
350 QString AbstractSqlStorage::schemaVersionUpgradeStep()
351 {
352     // By default, assume there's no pending upgrade
353     return {};
354 }
355
356
357 bool AbstractSqlStorage::watchQuery(QSqlQuery& query)
358 {
359     bool queryError = query.lastError().isValid();
360     if (queryError || _debug) {
361         if (queryError)
362             qCritical() << "unhandled Error in QSqlQuery!";
363         qCritical() << "                  last Query:\n" << qPrintable(query.lastQuery());
364         qCritical() << "              executed Query:\n" << qPrintable(query.executedQuery());
365         QVariantMap boundValues = query.boundValues();
366         QStringList valueStrings;
367         QVariantMap::const_iterator iter;
368         for (iter = boundValues.constBegin(); iter != boundValues.constEnd(); ++iter) {
369             QString value;
370             QSqlField field;
371             if (query.driver()) {
372                 // let the driver do the formatting
373                 field.setType(iter.value().type());
374                 if (iter.value().isNull())
375                     field.clear();
376                 else
377                     field.setValue(iter.value());
378                 value = query.driver()->formatValue(field);
379             }
380             else {
381                 switch (iter.value().type()) {
382                 case QVariant::Invalid:
383                     value = "NULL";
384                     break;
385                 case QVariant::Int:
386                     value = iter.value().toString();
387                     break;
388                 default:
389                     value = QString("'%1'").arg(iter.value().toString());
390                 }
391             }
392             valueStrings << QString("%1=%2").arg(iter.key(), value);
393         }
394         qCritical() << "                bound Values:" << qPrintable(valueStrings.join(", "));
395         qCritical() << "                Error Number:" << query.lastError().number();
396         qCritical() << "               Error Message:" << qPrintable(query.lastError().text());
397         qCritical() << "              Driver Message:" << qPrintable(query.lastError().driverText());
398         qCritical() << "                  DB Message:" << qPrintable(query.lastError().databaseText());
399
400         return !queryError;
401     }
402     return true;
403 }
404
405 void AbstractSqlStorage::connectionDestroyed()
406 {
407     QMutexLocker locker(&_connectionPoolMutex);
408     _connectionPool.remove(sender()->thread());
409 }
410
411 // ========================================
412 //  AbstractSqlStorage::Connection
413 // ========================================
414 AbstractSqlStorage::Connection::Connection(const QString& name, QObject* parent)
415     : QObject(parent)
416     , _name(name.toLatin1())
417 {}
418
419 AbstractSqlStorage::Connection::~Connection()
420 {
421     {
422         QSqlDatabase db = QSqlDatabase::database(name(), false);
423         if (db.isOpen()) {
424             db.commit();
425             db.close();
426         }
427     }
428     QSqlDatabase::removeDatabase(name());
429 }
430
431 // ========================================
432 //  AbstractSqlMigrator
433 // ========================================
434
435 void AbstractSqlMigrator::newQuery(const QString& query, QSqlDatabase db)
436 {
437     Q_ASSERT(!_query);
438     _query = new QSqlQuery(db);
439     _query->prepare(query);
440 }
441
442 void AbstractSqlMigrator::resetQuery()
443 {
444     delete _query;
445     _query = nullptr;
446 }
447
448 bool AbstractSqlMigrator::exec()
449 {
450     Q_ASSERT(_query);
451     _query->exec();
452     return !_query->lastError().isValid();
453 }
454
455 QString AbstractSqlMigrator::migrationObject(MigrationObject moType)
456 {
457     switch (moType) {
458     case QuasselUser:
459         return "QuasselUser";
460     case Sender:
461         return "Sender";
462     case Identity:
463         return "Identity";
464     case IdentityNick:
465         return "IdentityNick";
466     case Network:
467         return "Network";
468     case Buffer:
469         return "Buffer";
470     case Backlog:
471         return "Backlog";
472     case IrcServer:
473         return "IrcServer";
474     case UserSetting:
475         return "UserSetting";
476     case CoreState:
477         return "CoreState";
478     };
479     return QString();
480 }
481
482 QVariantList AbstractSqlMigrator::boundValues()
483 {
484     QVariantList values;
485     if (!_query)
486         return values;
487
488     int numValues = _query->boundValues().count();
489     for (int i = 0; i < numValues; i++) {
490         values << _query->boundValue(i);
491     }
492     return values;
493 }
494
495 void AbstractSqlMigrator::dumpStatus()
496 {
497     qWarning() << "  executed Query:";
498     qWarning() << qPrintable(executedQuery());
499     qWarning() << "  bound Values:";
500     QList<QVariant> list = boundValues();
501     for (int i = 0; i < list.size(); ++i)
502         qWarning() << i << ": " << list.at(i).toString().toLatin1().data();
503     qWarning() << "  Error Number:" << lastError().number();
504     qWarning() << "  Error Message:" << lastError().text();
505 }
506
507 // ========================================
508 //  AbstractSqlMigrationReader
509 // ========================================
510 AbstractSqlMigrationReader::AbstractSqlMigrationReader()
511     : AbstractSqlMigrator()
512 {}
513
514 bool AbstractSqlMigrationReader::migrateTo(AbstractSqlMigrationWriter* writer)
515 {
516     if (!transaction()) {
517         qWarning() << "AbstractSqlMigrationReader::migrateTo(): unable to start reader's transaction!";
518         return false;
519     }
520     if (!writer->transaction()) {
521         qWarning() << "AbstractSqlMigrationReader::migrateTo(): unable to start writer's transaction!";
522         rollback();  // close the reader transaction;
523         return false;
524     }
525
526     _writer = writer;
527
528     // due to the incompatibility across Migration objects we can't run this in a loop... :/
529     QuasselUserMO quasselUserMo;
530     if (!transferMo(QuasselUser, quasselUserMo))
531         return false;
532
533     IdentityMO identityMo;
534     if (!transferMo(Identity, identityMo))
535         return false;
536
537     IdentityNickMO identityNickMo;
538     if (!transferMo(IdentityNick, identityNickMo))
539         return false;
540
541     NetworkMO networkMo;
542     if (!transferMo(Network, networkMo))
543         return false;
544
545     BufferMO bufferMo;
546     if (!transferMo(Buffer, bufferMo))
547         return false;
548
549     SenderMO senderMo;
550     if (!transferMo(Sender, senderMo))
551         return false;
552
553     BacklogMO backlogMo;
554     if (!transferMo(Backlog, backlogMo))
555         return false;
556
557     IrcServerMO ircServerMo;
558     if (!transferMo(IrcServer, ircServerMo))
559         return false;
560
561     UserSettingMO userSettingMo;
562     if (!transferMo(UserSetting, userSettingMo))
563         return false;
564
565     CoreStateMO coreStateMO;
566     if (!transferMo(CoreState, coreStateMO))
567         return false;
568
569     if (!_writer->postProcess())
570         abortMigration();
571     return finalizeMigration();
572 }
573
574 void AbstractSqlMigrationReader::abortMigration(const QString& errorMsg)
575 {
576     qWarning() << "Migration Failed!";
577     if (!errorMsg.isNull()) {
578         qWarning() << qPrintable(errorMsg);
579     }
580     if (lastError().isValid()) {
581         qWarning() << "ReaderError:";
582         dumpStatus();
583     }
584
585     if (_writer->lastError().isValid()) {
586         qWarning() << "WriterError:";
587         _writer->dumpStatus();
588     }
589
590     rollback();
591     _writer->rollback();
592     _writer = nullptr;
593 }
594
595 bool AbstractSqlMigrationReader::finalizeMigration()
596 {
597     resetQuery();
598     _writer->resetQuery();
599
600     commit();
601     if (!_writer->commit()) {
602         _writer = nullptr;
603         return false;
604     }
605     _writer = nullptr;
606     return true;
607 }
608
609 template<typename T>
610 bool AbstractSqlMigrationReader::transferMo(MigrationObject moType, T& mo)
611 {
612     resetQuery();
613     _writer->resetQuery();
614
615     if (!prepareQuery(moType)) {
616         abortMigration(QString("AbstractSqlMigrationReader::migrateTo(): unable to prepare reader query of type %1!")
617                            .arg(AbstractSqlMigrator::migrationObject(moType)));
618         return false;
619     }
620     if (!_writer->prepareQuery(moType)) {
621         abortMigration(QString("AbstractSqlMigrationReader::migrateTo(): unable to prepare writer query of type %1!")
622                            .arg(AbstractSqlMigrator::migrationObject(moType)));
623         return false;
624     }
625
626     qDebug() << qPrintable(QString("Transferring %1...").arg(AbstractSqlMigrator::migrationObject(moType)));
627     int i = 0;
628     QFile file;
629     file.open(stdout, QIODevice::WriteOnly);
630
631     while (readMo(mo)) {
632         if (!_writer->writeMo(mo)) {
633             abortMigration(QString("AbstractSqlMigrationReader::transferMo(): unable to transfer Migratable Object of type %1!")
634                                .arg(AbstractSqlMigrator::migrationObject(moType)));
635             return false;
636         }
637         i++;
638         if (i % 1000 == 0) {
639             file.write("*");
640             file.flush();
641         }
642     }
643     if (i > 1000) {
644         file.write("\n");
645         file.flush();
646     }
647
648     qDebug() << "Done.";
649     return true;
650 }
651
652 uint qHash(const SenderData& key)
653 {
654     return qHash(QString(key.sender + "\n" + key.realname + "\n" + key.avatarurl));
655 }
656
657 bool operator==(const SenderData& a, const SenderData& b)
658 {
659     return a.sender == b.sender && a.realname == b.realname && a.avatarurl == b.avatarurl;
660 }