From 217a05f9402177862144031202c7e92124fd6d3f Mon Sep 17 00:00:00 2001 From: Uwe Klotz Date: Sun, 27 May 2018 19:06:54 +0200 Subject: [PATCH 1/6] Raise some log levels from debug to info/warning --- plugins/soundsourcewv/soundsourcewv.cpp | 2 +- src/library/dao/settingsdao.cpp | 2 +- src/sources/soundsourcemp3.cpp | 4 ++-- src/sources/soundsourcepluginlibrary.cpp | 2 +- src/sources/soundsourceproxy.cpp | 4 ++-- src/track/track.cpp | 2 +- src/track/trackmetadatataglib.cpp | 2 +- src/util/db/dbconnection.cpp | 4 ++-- 8 files changed, 11 insertions(+), 11 deletions(-) diff --git a/plugins/soundsourcewv/soundsourcewv.cpp b/plugins/soundsourcewv/soundsourcewv.cpp index 5d5c5b1c08..9d3a4f58c6 100644 --- a/plugins/soundsourcewv/soundsourcewv.cpp +++ b/plugins/soundsourcewv/soundsourcewv.cpp @@ -62,7 +62,7 @@ SoundSource::OpenResult SoundSourceWV::tryOpen( m_wpc = WavpackOpenFileInputEx(&s_streamReader, m_pWVFile, m_pWVCFile, msg, openFlags, 0); if (!m_wpc) { - kLogger.debug() << "failed to open file : " << msg; + kLogger.warning() << "failed to open file : " << msg; return OpenResult::Failed; } diff --git a/src/library/dao/settingsdao.cpp b/src/library/dao/settingsdao.cpp index 148409ab22..9f4a7ed19f 100644 --- a/src/library/dao/settingsdao.cpp +++ b/src/library/dao/settingsdao.cpp @@ -32,7 +32,7 @@ QString SettingsDAO::getValue(const QString& name, QString defaultValue) const { } else { // Prepare is expected to fail for a fresh database // when the schema is still empty! - kLogger.debug() + kLogger.info() << "Failed to prepare query:" << "Returning default value" << defaultValue diff --git a/src/sources/soundsourcemp3.cpp b/src/sources/soundsourcemp3.cpp index bce9186f95..84c5483f48 100644 --- a/src/sources/soundsourcemp3.cpp +++ b/src/sources/soundsourcemp3.cpp @@ -630,7 +630,7 @@ ReadableSampleFrames SoundSourceMp3::readSampleFramesClamped( #ifndef QT_NO_DEBUG_OUTPUT const SINT madFrameChannelCount = MAD_NCHANNELS(&m_madFrame.header); if (madFrameChannelCount != channelCount()) { - kLogger.debug() << "MP3 frame header with mismatching number of channels" + kLogger.warning() << "MP3 frame header with mismatching number of channels" << madFrameChannelCount << "<>" << channelCount(); } #endif @@ -640,7 +640,7 @@ ReadableSampleFrames SoundSourceMp3::readSampleFramesClamped( #ifndef QT_NO_DEBUG_OUTPUT const SINT madSynthSampleRate = m_madSynth.pcm.samplerate; if (madSynthSampleRate != sampleRate()) { - kLogger.debug() << "Reading MP3 data with different sample rate" + kLogger.warning() << "Reading MP3 data with different sample rate" << madSynthSampleRate << "<>" << sampleRate(); } #endif diff --git a/src/sources/soundsourcepluginlibrary.cpp b/src/sources/soundsourcepluginlibrary.cpp index 7270a039c2..c0ab472710 100644 --- a/src/sources/soundsourcepluginlibrary.cpp +++ b/src/sources/soundsourcepluginlibrary.cpp @@ -49,7 +49,7 @@ bool SoundSourcePluginLibrary::init() { << ":" << m_library.errorString(); return false; } - kLogger.debug() << "Dynamically loaded plugin library" + kLogger.info() << "Dynamically loaded plugin library" << m_library.fileName(); SoundSourcePluginAPI_getVersionFunc getVersionFunc = (SoundSourcePluginAPI_getVersionFunc) diff --git a/src/sources/soundsourceproxy.cpp b/src/sources/soundsourceproxy.cpp index 4dbe1b4765..1d3433523c 100644 --- a/src/sources/soundsourceproxy.cpp +++ b/src/sources/soundsourceproxy.cpp @@ -55,7 +55,7 @@ QList getSoundSourcePluginDirectories() { const QString& pluginPath = CmdlineArgs::Instance().getPluginPath(); if (!pluginPath.isEmpty()) { - kLogger.debug() << "Adding plugin path from commandline arg:" << pluginPath; + kLogger.info() << "Adding plugin path from commandline arg:" << pluginPath; pluginDirs << QDir(pluginPath); } @@ -186,7 +186,7 @@ void SoundSourceProxy::loadPlugins() { // that have been registered before (see above)! const QList pluginDirs(getSoundSourcePluginDirectories()); for (const auto& pluginDir: pluginDirs) { - kLogger.debug() << "Loading SoundSource plugins" << pluginDir.path(); + kLogger.info() << "Loading SoundSource plugins" << pluginDir.path(); const QStringList files(pluginDir.entryList( SOUND_SOURCE_PLUGIN_FILENAME_PATTERN, QDir::Files | QDir::NoDotAndDotDot)); diff --git a/src/track/track.cpp b/src/track/track.cpp index 4c114cd4d6..8f4a0dc087 100644 --- a/src/track/track.cpp +++ b/src/track/track.cpp @@ -1007,7 +1007,7 @@ Track::ExportMetadataResult Track::exportMetadata( // must be exported explicitly once. This ensures that we don't // overwrite existing file tags with completely different // information. - kLogger.debug() + kLogger.info() << "Skip exporting of unsynchronized track metadata:" << getLocation(); return ExportMetadataResult::Skipped; diff --git a/src/track/trackmetadatataglib.cpp b/src/track/trackmetadatataglib.cpp index 2615ae5bb6..21e84ed6c1 100644 --- a/src/track/trackmetadatataglib.cpp +++ b/src/track/trackmetadatataglib.cpp @@ -249,7 +249,7 @@ bool parseReplayGainGain( // the replay gain. if (ratio == ReplayGain::kRatio0dB) { // special case - kLogger.debug() << "Ignoring possibly undefined gain:" << dbGain; + kLogger.info() << "Ignoring possibly undefined gain:" << dbGain; ratio = ReplayGain::kRatioUndefined; } pReplayGain->setRatio(ratio); diff --git a/src/util/db/dbconnection.cpp b/src/util/db/dbconnection.cpp index d34f818478..98a43d6b42 100644 --- a/src/util/db/dbconnection.cpp +++ b/src/util/db/dbconnection.cpp @@ -25,7 +25,7 @@ const mixxx::Logger kLogger("DbConnection"); QSqlDatabase createDatabase( const DbConnection::Params& params, const QString connectionName) { - kLogger.debug() + kLogger.info() << "Available drivers for database connections:" << QSqlDatabase::drivers(); @@ -233,7 +233,7 @@ bool initDatabase(QSqlDatabase database) { #ifdef __SQLITE3__ QVariant v = database.driver()->handle(); VERIFY_OR_DEBUG_ASSERT(v.isValid()) { - kLogger.debug() << "Driver handle is invalid"; + kLogger.warning() << "Driver handle is invalid"; return false; // abort } if (strcmp(v.typeName(), "sqlite3*") != 0) { From 012421669b6c773d800c7bb457d91daa97d011df Mon Sep 17 00:00:00 2001 From: Uwe Klotz Date: Sun, 27 May 2018 19:08:19 +0200 Subject: [PATCH 2/6] Lower log level for non-critical MP3 decoding errors --- src/sources/soundsourcemp3.cpp | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/sources/soundsourcemp3.cpp b/src/sources/soundsourcemp3.cpp index 84c5483f48..9f5e684e1f 100644 --- a/src/sources/soundsourcemp3.cpp +++ b/src/sources/soundsourcemp3.cpp @@ -612,7 +612,7 @@ ReadableSampleFrames SoundSourceMp3::readSampleFramesClamped( kLogger.debug() << "Recoverable MP3 frame decoding error:" << mad_stream_errorstr(&m_madStream); } else { - kLogger.warning() << "Recoverable MP3 frame decoding error:" + kLogger.info() << "Recoverable MP3 frame decoding error:" << mad_stream_errorstr(&m_madStream); } } From 2fd6df0b258dc8dd4bb30da0b8781286d4aac09d Mon Sep 17 00:00:00 2001 From: Uwe Klotz Date: Sun, 27 May 2018 19:09:08 +0200 Subject: [PATCH 3/6] Only log debug messages if debug logging is enabled --- src/database/schemamanager.cpp | 8 +++++--- src/library/coverartcache.cpp | 14 +++++++++++--- src/library/crate/cratestorage.cpp | 30 ++++++++++++++++++++---------- src/library/trackcollection.cpp | 4 +++- src/sources/metadatasourcetaglib.cpp | 28 +++++++++++++++++----------- src/sources/soundsourcemp3.cpp | 15 +++++++++++---- src/sources/soundsourceproxy.cpp | 34 ++++++++++++++++++++-------------- src/track/track.cpp | 20 +++++++++++++------- src/track/trackmetadatataglib.cpp | 21 ++++++++++++++------- src/util/db/dbconnection.cpp | 16 ++++++++++------ src/util/db/dbconnectionpooled.cpp | 8 +++++--- src/util/db/sqltransaction.cpp | 24 +++++++++++++++--------- 12 files changed, 144 insertions(+), 78 deletions(-) diff --git a/src/database/schemamanager.cpp b/src/database/schemamanager.cpp index 2e678fc8e1..1e2e2122d7 100644 --- a/src/database/schemamanager.cpp +++ b/src/database/schemamanager.cpp @@ -99,9 +99,11 @@ SchemaManager::Result SchemaManager::upgradeToSchemaVersion( } } - kLogger.debug() - << "Loading database schema migrations from" - << schemaFilename; + if (kLogger.debugEnabled()) { + kLogger.debug() + << "Loading database schema migrations from" + << schemaFilename; + } QDomElement schemaRoot = XmlParse::openXMLFile(schemaFilename, "schema"); if (schemaRoot.isNull()) { kLogger.critical() diff --git a/src/library/coverartcache.cpp b/src/library/coverartcache.cpp index e76168422d..aa19e1506f 100644 --- a/src/library/coverartcache.cpp +++ b/src/library/coverartcache.cpp @@ -194,15 +194,23 @@ void CoverArtCache::requestGuessCover(TrackPointer pTrack) { void CoverArtCache::guessCover(TrackPointer pTrack) { if (pTrack) { - kLogger.debug() << "Guessing cover art for" << pTrack->getLocation(); + if (kLogger.debugEnabled()) { + kLogger.debug() + << "Guessing cover art for" + << pTrack->getLocation(); + } CoverInfo cover = CoverArtUtils::guessCoverInfo(*pTrack); pTrack->setCoverInfo(cover); } } void CoverArtCache::guessCovers(QList tracks) { - kLogger.debug() << "Guessing cover art for" - << tracks.size() << "tracks"; + if (kLogger.debugEnabled()) { + kLogger.debug() + << "Guessing cover art for" + << tracks.size() + << "tracks"; + } foreach (TrackPointer pTrack, tracks) { guessCover(pTrack); } diff --git a/src/library/crate/cratestorage.cpp b/src/library/crate/cratestorage.cpp index 05afdfcde2..8260f8cb0a 100644 --- a/src/library/crate/cratestorage.cpp +++ b/src/library/crate/cratestorage.cpp @@ -303,8 +303,11 @@ bool CrateStorage::readCrateByName(const QString& name, Crate* pCrate) const { } return true; } else { - kLogger.debug() - << "Crate not found by name:" << name; + if (kLogger.debugEnabled()) { + kLogger.debug() + << "Crate not found by name:" + << name; + } } } return false; @@ -647,8 +650,11 @@ bool CrateStorage::onDeletingCrate( return false; } if (query.numRowsAffected() <= 0) { - kLogger.debug() - << "Deleting empty crate with id" << crateId; + if (kLogger.debugEnabled()) { + kLogger.debug() + << "Deleting empty crate with id" + << crateId; + } } } { @@ -697,9 +703,11 @@ bool CrateStorage::onAddingCrateTracks( } if (query.numRowsAffected() == 0) { // track is already in crate - kLogger.debug() - << "Track" << trackId - << "not added to crate" << crateId; + if (kLogger.debugEnabled()) { + kLogger.debug() + << "Track" << trackId + << "not added to crate" << crateId; + } } else { DEBUG_ASSERT(query.numRowsAffected() == 1); } @@ -729,9 +737,11 @@ bool CrateStorage::onRemovingCrateTracks( } if (query.numRowsAffected() == 0) { // track not found in crate - kLogger.debug() - << "Track" << trackId - << "not removed from crate" << crateId; + if (kLogger.debugEnabled()) { + kLogger.debug() + << "Track" << trackId + << "not removed from crate" << crateId; + } } else { DEBUG_ASSERT(query.numRowsAffected() == 1); } diff --git a/src/library/trackcollection.cpp b/src/library/trackcollection.cpp index 1981fb781c..62c0b64ab4 100644 --- a/src/library/trackcollection.cpp +++ b/src/library/trackcollection.cpp @@ -24,7 +24,9 @@ TrackCollection::TrackCollection( } TrackCollection::~TrackCollection() { - kLogger.debug() << "~TrackCollection()"; + if (kLogger.debugEnabled()) { + kLogger.debug() << "~TrackCollection()"; + } // The database should have been detached earlier DEBUG_ASSERT(!m_database.isOpen()); } diff --git a/src/sources/metadatasourcetaglib.cpp b/src/sources/metadatasourcetaglib.cpp index 91b3277a9b..de617b618c 100644 --- a/src/sources/metadatasourcetaglib.cpp +++ b/src/sources/metadatasourcetaglib.cpp @@ -112,10 +112,12 @@ MetadataSourceTagLib::importTrackMetadataAndCoverImage( << "with type" << m_fileType; return afterImport(ImportResult::Unavailable); } - kLogger.trace() << "Importing" - << ((pTrackMetadata && pCoverImage) ? "track metadata and cover art" : (pTrackMetadata ? "track metadata" : "cover art")) - << "from file" << m_fileName - << "with type" << m_fileType; + if (kLogger.traceEnabled()) { + kLogger.trace() << "Importing" + << ((pTrackMetadata && pCoverImage) ? "track metadata and cover art" : (pTrackMetadata ? "track metadata" : "cover art")) + << "from file" << m_fileName + << "with type" << m_fileType; + } // Rationale: If a file contains different types of tags only // a single type of tag will be read. Tag types are read in a @@ -326,10 +328,12 @@ MetadataSourceTagLib::importTrackMetadataAndCoverImage( return afterImport(ImportResult::Failed); } - kLogger.debug() - << "No track metadata or cover art found" - << "in file" << m_fileName - << "with type" << m_fileType; + if (kLogger.debugEnabled()) { + kLogger.debug() + << "No track metadata or cover art found" + << "in file" << m_fileName + << "with type" << m_fileType; + } return afterImport(ImportResult::Unavailable); } @@ -745,9 +749,11 @@ class SafelyWritableFile final { std::pair MetadataSourceTagLib::exportTrackMetadata( const TrackMetadata& trackMetadata) const { - kLogger.debug() << "Exporting track metadata" - << "into file" << m_fileName - << "with type" << m_fileType; + if (kLogger.debugEnabled()) { + kLogger.debug() << "Exporting track metadata" + << "into file" << m_fileName + << "with type" << m_fileType; + } SafelyWritableFile safelyWritableFile(m_fileName, kExportTrackMetadataIntoTemporaryFile); diff --git a/src/sources/soundsourcemp3.cpp b/src/sources/soundsourcemp3.cpp index 9f5e684e1f..8a79f863b3 100644 --- a/src/sources/soundsourcemp3.cpp +++ b/src/sources/soundsourcemp3.cpp @@ -393,7 +393,9 @@ void SoundSourceMp3::close() { void SoundSourceMp3::restartDecoding( const SeekFrameType& seekFrame) { - kLogger.debug() << "restartDecoding @" << seekFrame.frameIndex; + if (kLogger.debugEnabled()) { + kLogger.debug() << "restartDecoding @" << seekFrame.frameIndex; + } // Discard decoded output m_madSynthCount = 0; @@ -609,8 +611,11 @@ ReadableSampleFrames SoundSourceMp3::readSampleFramesClamped( // Don't bother the user with warnings from recoverable // errors while skipping decoded samples or that even // might occur for files that are perfectly ok. - kLogger.debug() << "Recoverable MP3 frame decoding error:" - << mad_stream_errorstr(&m_madStream); + if (kLogger.debugEnabled()) { + kLogger.debug() + << "Recoverable MP3 frame decoding error:" + << mad_stream_errorstr(&m_madStream); + } } else { kLogger.info() << "Recoverable MP3 frame decoding error:" << mad_stream_errorstr(&m_madStream); @@ -620,7 +625,9 @@ ReadableSampleFrames SoundSourceMp3::readSampleFramesClamped( } } if (pMadThisFrame == m_madStream.this_frame) { - kLogger.debug() << "Retry decoding MP3 frame @" << m_curFrameIndex; + if (kLogger.debugEnabled()) { + kLogger.debug() << "Retry decoding MP3 frame @" << m_curFrameIndex; + } // Retry decoding continue; } diff --git a/src/sources/soundsourceproxy.cpp b/src/sources/soundsourceproxy.cpp index 1d3433523c..3431ac3fcd 100644 --- a/src/sources/soundsourceproxy.cpp +++ b/src/sources/soundsourceproxy.cpp @@ -402,12 +402,14 @@ void SoundSourceProxy::initSoundSource() { // ...and continue loop DEBUG_ASSERT(!m_pSoundSource); } else { - kLogger.debug() << "SoundSourceProvider" - << pProvider->getName() - << "created a SoundSource for file" - << getUrl().toString() - << "of type" - << m_pSoundSource->getType(); + if (kLogger.debugEnabled()) { + kLogger.debug() << "SoundSourceProvider" + << pProvider->getName() + << "created a SoundSource for file" + << getUrl().toString() + << "of type" + << m_pSoundSource->getType(); + } } } } @@ -618,12 +620,14 @@ mixxx::AudioSourcePointer SoundSourceProxy::openAudioSource(const mixxx::AudioSo DEBUG_ASSERT(m_pTrack); auto openMode = mixxx::SoundSource::OpenMode::Strict; while (m_pSoundSource && !m_pAudioSource) { - kLogger.debug() << "Opening file" - << getUrl().toString() - << "with provider" - << getSoundSourceProvider()->getName() - << "using mode" - << openMode; + if (kLogger.debugEnabled()) { + kLogger.debug() << "Opening file" + << getUrl().toString() + << "with provider" + << getSoundSourceProvider()->getName() + << "using mode" + << openMode; + } const mixxx::SoundSource::OpenResult openResult = m_pSoundSource->open(openMode, params); if ((openResult == mixxx::SoundSource::OpenResult::Aborted) || @@ -695,7 +699,9 @@ void SoundSourceProxy::closeAudioSource() { DEBUG_ASSERT(m_pSoundSource); m_pSoundSource->close(); m_pAudioSource = mixxx::AudioSourcePointer(); - kLogger.debug() << "Closed AudioSource for file" - << getUrl().toString(); + if (kLogger.debugEnabled()) { + kLogger.debug() << "Closed AudioSource for file" + << getUrl().toString(); + } } } diff --git a/src/track/track.cpp b/src/track/track.cpp index 8f4a0dc087..1da3ed8ee7 100644 --- a/src/track/track.cpp +++ b/src/track/track.cpp @@ -306,7 +306,9 @@ double Track::setBpm(double bpmValue) { // Continue with the regular case if (m_pBeats->getBpm() != bpmValue) { - kLogger.debug() << "Updating BPM:" << getLocation(); + if (kLogger.debugEnabled()) { + kLogger.debug() << "Updating BPM:" << getLocation(); + } m_pBeats->setBpm(bpmValue); markDirtyAndUnlock(&lock); // Tell the GUI to update the bpm label... @@ -1052,9 +1054,11 @@ Track::ExportMetadataResult Track::exportMetadata( if (!m_record.getMetadata().hasBeenModifiedAfterImport(importedFromFile)) { // The file tags are in-sync with the track's metadata and don't need // to be updated. - kLogger.debug() - << "Skip exporting of unmodified track metadata into file:" - << getLocation(); + if (kLogger.debugEnabled()) { + kLogger.debug() + << "Skip exporting of unmodified track metadata into file:" + << getLocation(); + } return ExportMetadataResult::Skipped; } } else { @@ -1085,9 +1089,11 @@ Track::ExportMetadataResult Track::exportMetadata( DEBUG_ASSERT(!trackMetadataExported.second.isNull()); //pTrack->setMetadataSynchronized(trackMetadataExported.second); m_record.setMetadataSynchronized(!trackMetadataExported.second.isNull()); - kLogger.debug() - << "Exported track metadata:" - << getLocation(); + if (kLogger.debugEnabled()) { + kLogger.debug() + << "Exported track metadata:" + << getLocation(); + } return ExportMetadataResult::Succeeded; } else { kLogger.warning() diff --git a/src/track/trackmetadatataglib.cpp b/src/track/trackmetadatataglib.cpp index 21e84ed6c1..0f0aa01b61 100644 --- a/src/track/trackmetadatataglib.cpp +++ b/src/track/trackmetadatataglib.cpp @@ -564,7 +564,11 @@ int removeUserTextIdentificationFrames( toQString(pFrame->description())); if (0 == frameDescription.compare( description, Qt::CaseInsensitive)) { - kLogger.debug() << "Removing ID3v2 TXXX frame:" << toQString(pFrame->description()); + if (kLogger.debugEnabled()) { + kLogger.debug() + << "Removing ID3v2 TXXX frame:" + << toQString(pFrame->description()); + } // After removing a frame the result of frameListMap() // is no longer valid!! pTag->removeFrame(pFrame, false); // remove an unowned frame @@ -838,7 +842,9 @@ bool readAudioProperties( QImage importCoverImageFromVorbisCommentPictureList( const TagLib::List& pictures) { if (pictures.isEmpty()) { - kLogger.debug() << "VorbisComment picture list is empty"; + if (kLogger.debugEnabled()) { + kLogger.debug() << "VorbisComment picture list is empty"; + } return QImage(); } @@ -883,8 +889,9 @@ void importCoverImageFromID3v2Tag(QImage* pCoverArt, const TagLib::ID3v2::Tag& t const auto iterAPIC = tag.frameListMap().find("APIC"); if ((iterAPIC == tag.frameListMap().end()) || iterAPIC->second.isEmpty()) { - kLogger.debug() - << "No cover art: None or empty list of ID3v2 APIC frames"; + if (kLogger.debugEnabled()) { + kLogger.debug() << "No cover art: None or empty list of ID3v2 APIC frames"; + } return; // abort } @@ -1026,9 +1033,9 @@ void importCoverImageFromVorbisCommentTag(QImage* pCoverArt, TagLib::Ogg::XiphCo } } } - - kLogger.debug() - << "No cover art found in VorbisComment tag"; + if (kLogger.debugEnabled()) { + kLogger.debug() << "No cover art found in VorbisComment tag"; + } } void importCoverImageFromMP4Tag(QImage* pCoverArt, const TagLib::MP4::Tag& tag) { diff --git a/src/util/db/dbconnection.cpp b/src/util/db/dbconnection.cpp index 98a43d6b42..ee78dfec0f 100644 --- a/src/util/db/dbconnection.cpp +++ b/src/util/db/dbconnection.cpp @@ -313,9 +313,11 @@ DbConnection::~DbConnection() { } bool DbConnection::open() { - kLogger.debug() - << "Opening database connection" - << *this; + if (kLogger.debugEnabled()) { + kLogger.debug() + << "Opening database connection" + << *this; + } if (!m_sqlDatabase.open()) { kLogger.warning() << "Failed to open database connection" @@ -343,9 +345,11 @@ void DbConnection::close() { << "Rolled back open transaction before closing database connection:" << *this; } - kLogger.debug() - << "Closing database connection:" - << *this; + if (kLogger.debugEnabled()) { + kLogger.debug() + << "Closing database connection:" + << *this; + } m_sqlDatabase.close(); } } diff --git a/src/util/db/dbconnectionpooled.cpp b/src/util/db/dbconnectionpooled.cpp index cf74c4d2d5..33369511eb 100644 --- a/src/util/db/dbconnectionpooled.cpp +++ b/src/util/db/dbconnectionpooled.cpp @@ -26,9 +26,11 @@ DbConnectionPooled::operator QSqlDatabase() const { << "Thread-local database connection not found"; return QSqlDatabase(); // abort } - kLogger.debug() - << "Found thread-local database connection" - << *pDbConnection;; + if (kLogger.debugEnabled()) { + kLogger.debug() + << "Found thread-local database connection" + << *pDbConnection;; + } return *pDbConnection; } diff --git a/src/util/db/sqltransaction.cpp b/src/util/db/sqltransaction.cpp index 463637743c..c6ae4fe108 100644 --- a/src/util/db/sqltransaction.cpp +++ b/src/util/db/sqltransaction.cpp @@ -18,9 +18,11 @@ bool beginTransaction(QSqlDatabase database) { return false; } if (database.transaction()) { - kLogger.debug() - << "Started new SQL database transaction on" - << database.connectionName(); + if (kLogger.debugEnabled()) { + kLogger.debug() + << "Started new SQL database transaction on" + << database.connectionName(); + } return true; } else { kLogger.warning() @@ -63,9 +65,11 @@ bool SqlTransaction::commit() { return false; } if (m_database.commit()) { - kLogger.debug() - << "Committed SQL database transaction on" - << m_database.connectionName(); + if (kLogger.debugEnabled()) { + kLogger.debug() + << "Committed SQL database transaction on" + << m_database.connectionName(); + } release(); // commit/rollback only once return true; } else { @@ -84,9 +88,11 @@ bool SqlTransaction::rollback() { return false; } if (m_database.rollback()) { - kLogger.debug() - << "Rolled back SQL database transaction on" - << m_database.connectionName(); + if (kLogger.debugEnabled()) { + kLogger.debug() + << "Rolled back SQL database transaction on" + << m_database.connectionName(); + } release(); // commit/rollback only once return true; } else { From 84a40ba879b63636efa9d09d6a2cace2fc22fff0 Mon Sep 17 00:00:00 2001 From: Uwe Klotz Date: Mon, 28 May 2018 09:57:53 +0200 Subject: [PATCH 4/6] Re-enable file related logs --- src/sources/metadatasourcetaglib.cpp | 11 ++++++----- src/sources/soundsourceproxy.cpp | 17 +++++++++-------- 2 files changed, 15 insertions(+), 13 deletions(-) diff --git a/src/sources/metadatasourcetaglib.cpp b/src/sources/metadatasourcetaglib.cpp index de617b618c..0b68ef8af6 100644 --- a/src/sources/metadatasourcetaglib.cpp +++ b/src/sources/metadatasourcetaglib.cpp @@ -749,11 +749,12 @@ class SafelyWritableFile final { std::pair MetadataSourceTagLib::exportTrackMetadata( const TrackMetadata& trackMetadata) const { - if (kLogger.debugEnabled()) { - kLogger.debug() << "Exporting track metadata" - << "into file" << m_fileName - << "with type" << m_fileType; - } + // NOTE(uklotzde): Log unconditionally (with debug level) to + // identify files in the log file that might have caused a + // crash while exporting metadata. + kLogger.debug() << "Exporting track metadata" + << "into file" << m_fileName + << "with type" << m_fileType; SafelyWritableFile safelyWritableFile(m_fileName, kExportTrackMetadataIntoTemporaryFile); diff --git a/src/sources/soundsourceproxy.cpp b/src/sources/soundsourceproxy.cpp index 3431ac3fcd..145303eaf2 100644 --- a/src/sources/soundsourceproxy.cpp +++ b/src/sources/soundsourceproxy.cpp @@ -620,14 +620,15 @@ mixxx::AudioSourcePointer SoundSourceProxy::openAudioSource(const mixxx::AudioSo DEBUG_ASSERT(m_pTrack); auto openMode = mixxx::SoundSource::OpenMode::Strict; while (m_pSoundSource && !m_pAudioSource) { - if (kLogger.debugEnabled()) { - kLogger.debug() << "Opening file" - << getUrl().toString() - << "with provider" - << getSoundSourceProvider()->getName() - << "using mode" - << openMode; - } + // NOTE(uklotzde): Log unconditionally (with debug level) to + // identify files in the log file that might have caused a + // crash while importing metadata or decoding audio subsequently. + kLogger.debug() << "Opening file" + << getUrl().toString() + << "with provider" + << getSoundSourceProvider()->getName() + << "using mode" + << openMode; const mixxx::SoundSource::OpenResult openResult = m_pSoundSource->open(openMode, params); if ((openResult == mixxx::SoundSource::OpenResult::Aborted) || From 2442f53bd40130fa2ad23c7b3323631af43ec86c Mon Sep 17 00:00:00 2001 From: Uwe Klotz Date: Sat, 2 Jun 2018 19:22:07 +0200 Subject: [PATCH 5/6] Fix propagation of log levels into plugins with an ugly hack The configured log levels have to be propagated into the plugins upon initialization! This was already broken before I submitted the previous changes that finally broke the plugin build on macOS. --- plugins/soundsourcem4a/soundsourcem4a.cpp | 9 ++++++++- plugins/soundsourcem4a/soundsourcem4a.h | 2 +- .../soundsourcemediafoundation.cpp | 9 ++++++++- .../soundsourcemediafoundation.h | 2 +- plugins/soundsourcewv/soundsourcewv.cpp | 9 ++++++++- plugins/soundsourcewv/soundsourcewv.h | 2 +- src/sources/soundsourcepluginapi.h | 3 ++- src/sources/soundsourcepluginlibrary.cpp | 2 +- src/util/logging.cpp | 8 ++++---- src/util/logging.h | 14 +++++++++----- 10 files changed, 43 insertions(+), 17 deletions(-) diff --git a/plugins/soundsourcem4a/soundsourcem4a.cpp b/plugins/soundsourcem4a/soundsourcem4a.cpp index f0a5e15c92..192cc7f132 100644 --- a/plugins/soundsourcem4a/soundsourcem4a.cpp +++ b/plugins/soundsourcem4a/soundsourcem4a.cpp @@ -22,6 +22,11 @@ typedef unsigned long SAMPLERATE_TYPE; namespace mixxx { +// TODO(XXX): Remove this ugly "extern" hack after getting rid of +// the broken plugin architecture. +LogLevel g_logLevel; +LogLevel g_logFlushLevel; + namespace { const Logger kLogger("SoundSourceM4A"); @@ -617,9 +622,11 @@ SoundSourcePointer SoundSourceProviderM4A::newSoundSource(const QUrl& url) { } // namespace mixxx extern "C" MIXXX_SOUNDSOURCEPLUGINAPI_EXPORT -mixxx::SoundSourceProvider* Mixxx_SoundSourcePluginAPI_createSoundSourceProvider() { +mixxx::SoundSourceProvider* Mixxx_SoundSourcePluginAPI_createSoundSourceProvider(int logLevel, int logFlushLevel) { // SoundSourceProviderM4A is stateless and a single instance // can safely be shared + mixxx::g_logLevel = static_cast(logLevel); + mixxx::g_logFlushLevel = static_cast(logFlushLevel); static mixxx::SoundSourceProviderM4A singleton; return &singleton; } diff --git a/plugins/soundsourcem4a/soundsourcem4a.h b/plugins/soundsourcem4a/soundsourcem4a.h index 0ef84a9ac5..98dc47f15c 100644 --- a/plugins/soundsourcem4a/soundsourcem4a.h +++ b/plugins/soundsourcem4a/soundsourcem4a.h @@ -74,7 +74,7 @@ class SoundSourceProviderM4A: public SoundSourceProvider { } // namespace mixxx extern "C" MIXXX_SOUNDSOURCEPLUGINAPI_EXPORT -mixxx::SoundSourceProvider* Mixxx_SoundSourcePluginAPI_createSoundSourceProvider(); +mixxx::SoundSourceProvider* Mixxx_SoundSourcePluginAPI_createSoundSourceProvider(int logLevel, int logFlushLevel); extern "C" MIXXX_SOUNDSOURCEPLUGINAPI_EXPORT void Mixxx_SoundSourcePluginAPI_destroySoundSourceProvider(mixxx::SoundSourceProvider*); diff --git a/plugins/soundsourcemediafoundation/soundsourcemediafoundation.cpp b/plugins/soundsourcemediafoundation/soundsourcemediafoundation.cpp index 8eac78220d..c1a751b948 100755 --- a/plugins/soundsourcemediafoundation/soundsourcemediafoundation.cpp +++ b/plugins/soundsourcemediafoundation/soundsourcemediafoundation.cpp @@ -43,6 +43,11 @@ template static void safeRelease(T **ppT) { namespace mixxx { +// TODO(XXX): Remove this ugly "extern" hack after getting rid of +// the broken plugin architecture. +LogLevel g_logLevel; +LogLevel g_logFlushLevel; + SoundSourceMediaFoundation::SoundSourceMediaFoundation(const QUrl& url) : SoundSourcePlugin(url, "m4a"), m_hrCoInitialize(E_FAIL), @@ -803,9 +808,11 @@ SoundSourcePointer SoundSourceProviderMediaFoundation::newSoundSource(const QUrl } // namespace mixxx extern "C" MIXXX_SOUNDSOURCEPLUGINAPI_EXPORT -mixxx::SoundSourceProvider* Mixxx_SoundSourcePluginAPI_createSoundSourceProvider() { +mixxx::SoundSourceProvider* Mixxx_SoundSourcePluginAPI_createSoundSourceProvider(int logLevel, int logFlushLevel) { // SoundSourceProviderMediaFoundation is stateless and a single instance // can safely be shared + mixxx::g_logLevel = static_cast(logLevel); + mixxx::g_logFlushLevel = static_cast(logFlushLevel); static mixxx::SoundSourceProviderMediaFoundation singleton; return &singleton; } diff --git a/plugins/soundsourcemediafoundation/soundsourcemediafoundation.h b/plugins/soundsourcemediafoundation/soundsourcemediafoundation.h index e9a8d608f1..e299408cb9 100755 --- a/plugins/soundsourcemediafoundation/soundsourcemediafoundation.h +++ b/plugins/soundsourcemediafoundation/soundsourcemediafoundation.h @@ -101,7 +101,7 @@ class SoundSourceProviderMediaFoundation: public SoundSourceProvider { extern "C" MIXXX_SOUNDSOURCEPLUGINAPI_EXPORT -mixxx::SoundSourceProvider* Mixxx_SoundSourcePluginAPI_createSoundSourceProvider(); +mixxx::SoundSourceProvider* Mixxx_SoundSourcePluginAPI_createSoundSourceProvider(int logLevel, int logFlushLevel); extern "C" MIXXX_SOUNDSOURCEPLUGINAPI_EXPORT void Mixxx_SoundSourcePluginAPI_destroySoundSourceProvider(mixxx::SoundSourceProvider*); diff --git a/plugins/soundsourcewv/soundsourcewv.cpp b/plugins/soundsourcewv/soundsourcewv.cpp index 9d3a4f58c6..e69babfa4c 100644 --- a/plugins/soundsourcewv/soundsourcewv.cpp +++ b/plugins/soundsourcewv/soundsourcewv.cpp @@ -6,6 +6,11 @@ namespace mixxx { +// TODO(XXX): Remove this ugly "extern" hack after getting rid of +// the broken plugin architecture. +LogLevel g_logLevel; +LogLevel g_logFlushLevel; + namespace { const Logger kLogger("SoundSourceWV"); @@ -267,9 +272,11 @@ int32_t SoundSourceWV::WriteBytesCallback(void* id, void* data, int32_t bcount) } // namespace mixxx extern "C" MIXXX_SOUNDSOURCEPLUGINAPI_EXPORT -mixxx::SoundSourceProvider* Mixxx_SoundSourcePluginAPI_createSoundSourceProvider() { +mixxx::SoundSourceProvider* Mixxx_SoundSourcePluginAPI_createSoundSourceProvider(int logLevel, int logFlushLevel) { // SoundSourceProviderWV is stateless and a single instance // can safely be shared + mixxx::g_logLevel = static_cast(logLevel); + mixxx::g_logFlushLevel = static_cast(logFlushLevel); static mixxx::SoundSourceProviderWV singleton; return &singleton; } diff --git a/plugins/soundsourcewv/soundsourcewv.h b/plugins/soundsourcewv/soundsourcewv.h index 7ce6f340b6..7c2144101d 100644 --- a/plugins/soundsourcewv/soundsourcewv.h +++ b/plugins/soundsourcewv/soundsourcewv.h @@ -55,7 +55,7 @@ class SoundSourceProviderWV: public SoundSourceProvider { } // namespace mixxx extern "C" MIXXX_SOUNDSOURCEPLUGINAPI_EXPORT -mixxx::SoundSourceProvider* Mixxx_SoundSourcePluginAPI_createSoundSourceProvider(); +mixxx::SoundSourceProvider* Mixxx_SoundSourcePluginAPI_createSoundSourceProvider(int logLevel, int logFlushLevel); extern "C" MIXXX_SOUNDSOURCEPLUGINAPI_EXPORT void Mixxx_SoundSourcePluginAPI_destroySoundSourceProvider(mixxx::SoundSourceProvider*); diff --git a/src/sources/soundsourcepluginapi.h b/src/sources/soundsourcepluginapi.h index d85487f8b6..ccb513bbb6 100644 --- a/src/sources/soundsourcepluginapi.h +++ b/src/sources/soundsourcepluginapi.h @@ -3,6 +3,7 @@ #define MIXXX_SOUNDSOURCEPLUGINAPI_VERSION 17 // SoundSource Plugin API version history: +// 18 - Mixxx 2.1.1 - Add log level parameters for plugin initialization // 17 - Mixxx 2.1.0 - Bump version number after ABI breaking changes (lp1737815) // 16 - Mixxx 2.1.0 - Support 2 different modes for opening files // 15 - Mixxx 2.1.0 - AudioSource v2 @@ -44,7 +45,7 @@ typedef int (*SoundSourcePluginAPI_getVersionFunc)(); const char * const SoundSourcePluginAPI_getVersionFuncName = "Mixxx_SoundSourcePluginAPI_getVersion"; // extern "C" MIXXX_SOUNDSOURCEPLUGINAPI_EXPORT SoundSourceProvider* Mixxx_SoundSourcePluginAPI_createSoundSourceProvider() -typedef SoundSourceProvider* (*SoundSourcePluginAPI_createSoundSourceProviderFunc)(); +typedef SoundSourceProvider* (*SoundSourcePluginAPI_createSoundSourceProviderFunc)(int logLevel, int logFlushLevel); const char* const SoundSourcePluginAPI_createSoundSourceProviderFuncName = "Mixxx_SoundSourcePluginAPI_createSoundSourceProvider"; // extern "C" MIXXX_SOUNDSOURCEPLUGINAPI_EXPORT void Mixxx_SoundSourcePluginAPI_destroySoundSourceProvider(mixxx::SoundSourceProvider*) diff --git a/src/sources/soundsourcepluginlibrary.cpp b/src/sources/soundsourcepluginlibrary.cpp index c0ab472710..c91551ed93 100644 --- a/src/sources/soundsourcepluginlibrary.cpp +++ b/src/sources/soundsourcepluginlibrary.cpp @@ -91,7 +91,7 @@ bool SoundSourcePluginLibrary::init() { } m_pSoundSourceProvider = SoundSourceProviderPointer( - (*createSoundSourceProviderFunc)(), + (*createSoundSourceProviderFunc)(static_cast(g_logLevel), static_cast(g_logFlushLevel)), destroySoundSourceProviderFunc); if (m_pSoundSourceProvider) { return true; diff --git a/src/util/logging.cpp b/src/util/logging.cpp index affd2c08b4..9c044a5b0c 100644 --- a/src/util/logging.cpp +++ b/src/util/logging.cpp @@ -21,8 +21,8 @@ namespace mixxx { // Initialize the log level with the default value -LogLevel Logging::s_logLevel = kLogLevelDefault; -LogLevel Logging::s_logFlushLevel = kLogFlushLevelDefault; +LogLevel g_logLevel = kLogLevelDefault; +LogLevel g_logFlushLevel = kLogFlushLevelDefault; namespace { @@ -189,8 +189,8 @@ void Logging::initialize(const QDir& settingsDir, return; } - s_logLevel = logLevel; - s_logFlushLevel = logFlushLevel; + g_logLevel = logLevel; + g_logFlushLevel = logFlushLevel; QString logFileName; diff --git a/src/util/logging.h b/src/util/logging.h index e55ac5fb99..306b0a13c6 100644 --- a/src/util/logging.h +++ b/src/util/logging.h @@ -17,6 +17,13 @@ enum class LogLevel { constexpr LogLevel kLogLevelDefault = LogLevel::Warning; constexpr LogLevel kLogFlushLevelDefault = LogLevel::Critical; +// Almost constant, i.e. initialized once at startup +// TODO(XXX): Remove this ugly "extern" hack after getting rid of +// the broken plugin architecture. Both globals should (again) +// become static members of the class Logging. +extern LogLevel g_logLevel; +extern LogLevel g_logFlushLevel; + class Logging { public: // These are not thread safe. Only call them on Mixxx startup and shutdown. @@ -29,10 +36,10 @@ class Logging { static void flushLogFile(); static bool enabled(LogLevel logLevel) { - return s_logLevel >= logLevel; + return g_logLevel >= logLevel; } static bool flushing(LogLevel logFlushLevel) { - return s_logFlushLevel >= logFlushLevel; + return g_logFlushLevel >= logFlushLevel; } static bool traceEnabled() { return enabled(LogLevel::Trace); @@ -46,9 +53,6 @@ class Logging { private: Logging() = delete; - - static LogLevel s_logLevel; - static LogLevel s_logFlushLevel; }; } // namespace mixxx From 3c9974b9fddb4c04f84ff0a6cb52df6a6fc82b23 Mon Sep 17 00:00:00 2001 From: Uwe Klotz Date: Sun, 3 Jun 2018 01:06:54 +0200 Subject: [PATCH 6/6] Bump API version (now actually) --- src/sources/soundsourcepluginapi.h | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/sources/soundsourcepluginapi.h b/src/sources/soundsourcepluginapi.h index ccb513bbb6..5b6d9a97d4 100644 --- a/src/sources/soundsourcepluginapi.h +++ b/src/sources/soundsourcepluginapi.h @@ -1,7 +1,7 @@ #ifndef MIXXX_SOUNDSOURCEPLUGINAPI_H #define MIXXX_SOUNDSOURCEPLUGINAPI_H -#define MIXXX_SOUNDSOURCEPLUGINAPI_VERSION 17 +#define MIXXX_SOUNDSOURCEPLUGINAPI_VERSION 18 // SoundSource Plugin API version history: // 18 - Mixxx 2.1.1 - Add log level parameters for plugin initialization // 17 - Mixxx 2.1.0 - Bump version number after ABI breaking changes (lp1737815)