Chris@2: /* -*- c-basic-offset: 4 indent-tabs-mode: nil -*-  vi:set ts=8 sts=4 sw=4: */
Chris@5: /*
Chris@40:   Copyright (c) 2016-2018 Queen Mary, University of London
Chris@5: 
Chris@19:   Permission is hereby granted, free of charge, to any person
Chris@19:   obtaining a copy of this software and associated documentation
Chris@19:   files (the "Software"), to deal in the Software without
Chris@19:   restriction, including without limitation the rights to use, copy,
Chris@19:   modify, merge, publish, distribute, sublicense, and/or sell copies
Chris@19:   of the Software, and to permit persons to whom the Software is
Chris@19:   furnished to do so, subject to the following conditions:
Chris@5: 
Chris@19:   The above copyright notice and this permission notice shall be
Chris@19:   included in all copies or substantial portions of the Software.
Chris@5: 
Chris@19:   THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND,
Chris@19:   EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
Chris@19:   MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND
Chris@19:   NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR ANY
Chris@19:   CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF
Chris@19:   CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION
Chris@19:   WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.
Chris@5: 
Chris@19:   Except as contained in this notice, the names of the Centre for
Chris@19:   Digital Music and Queen Mary, University of London shall not be
Chris@19:   used in advertising or otherwise to promote the sale, use or other
Chris@19:   dealings in this Software without prior written authorization.
Chris@5: */
Chris@2: 
Chris@2: #include "plugincandidates.h"
Chris@2: 
Chris@40: #include "../version.h"
Chris@40: 
Chris@2: #include <set>
Chris@2: #include <stdexcept>
Chris@2: #include <iostream>
Chris@2: 
Chris@2: #include <QProcess>
Chris@2: #include <QDir>
Chris@61: #include <QElapsedTimer>
Chris@2: 
Chris@4: #if defined(_WIN32)
Chris@2: #define PLUGIN_GLOB "*.dll"
Chris@4: #elif defined(__APPLE__)
Chris@2: #define PLUGIN_GLOB "*.dylib *.so"
Chris@2: #else
Chris@2: #define PLUGIN_GLOB "*.so"
Chris@2: #endif
Chris@2: 
Chris@2: using namespace std;
Chris@2: 
Chris@2: PluginCandidates::PluginCandidates(string helperExecutableName) :
Chris@6:     m_helper(helperExecutableName),
Chris@53:     m_logCallback(nullptr)
Chris@2: {
Chris@2: }
Chris@2: 
Chris@6: void
Chris@6: PluginCandidates::setLogCallback(LogCallback *cb)
Chris@6: {
Chris@6:     m_logCallback = cb;
Chris@6: }
Chris@6: 
Chris@2: vector<string>
Chris@4: PluginCandidates::getCandidateLibrariesFor(string tag) const
Chris@2: {
Chris@4:     if (m_candidates.find(tag) == m_candidates.end()) return {};
Chris@4:     else return m_candidates.at(tag);
Chris@2: }
Chris@2: 
Chris@2: vector<PluginCandidates::FailureRec>
Chris@4: PluginCandidates::getFailedLibrariesFor(string tag) const
Chris@2: {
Chris@4:     if (m_failures.find(tag) == m_failures.end()) return {};
Chris@4:     else return m_failures.at(tag);
Chris@2: }
Chris@2: 
Chris@6: void
Chris@6: PluginCandidates::log(string message)
Chris@6: {
Chris@24:     if (m_logCallback) {
Chris@24:         m_logCallback->log("PluginCandidates: " + message);
Chris@24:     } else {
Chris@24:         cerr << "PluginCandidates: " << message << endl;
Chris@24:     }
Chris@6: }
Chris@6: 
Chris@2: vector<string>
Chris@2: PluginCandidates::getLibrariesInPath(vector<string> path)
Chris@2: {
Chris@2:     vector<string> candidates;
Chris@2: 
Chris@2:     for (string dirname: path) {
Chris@2: 
Chris@55:         log("Scanning directory " + dirname);
Chris@2: 
Chris@2:         QDir dir(dirname.c_str(), PLUGIN_GLOB,
Chris@19:                  QDir::Name | QDir::IgnoreCase,
Chris@19:                  QDir::Files | QDir::Readable);
Chris@2: 
Chris@19:         for (unsigned int i = 0; i < dir.count(); ++i) {
Chris@2:             QString soname = dir.filePath(dir[i]);
Chris@11:             // NB this means the library names passed to the helper
Chris@11:             // are UTF-8 encoded
Chris@2:             candidates.push_back(soname.toStdString());
Chris@2:         }
Chris@2:     }
Chris@2: 
Chris@2:     return candidates;
Chris@2: }
Chris@2: 
Chris@2: void
Chris@2: PluginCandidates::scan(string tag,
Chris@19:                        vector<string> pluginPath,
Chris@19:                        string descriptorSymbolName)
Chris@2: {
Chris@40:     string helperVersion = getHelperCompatibilityVersion();
Chris@40:     if (helperVersion != CHECKER_COMPATIBILITY_VERSION) {
Chris@55:         log("Wrong plugin checker helper version found: expected v" +
Chris@40:             string(CHECKER_COMPATIBILITY_VERSION) + ", found v" +
Chris@40:             helperVersion);
Chris@43:         throw runtime_error("wrong version of plugin load helper found");
Chris@40:     }
Chris@40:     
Chris@2:     vector<string> libraries = getLibrariesInPath(pluginPath);
Chris@2:     vector<string> remaining = libraries;
Chris@2: 
Chris@2:     int runlimit = 20;
Chris@2:     int runcount = 0;
Chris@2:     
Chris@2:     vector<string> result;
Chris@2:     
Chris@2:     while (result.size() < libraries.size() && runcount < runlimit) {
Chris@19:         vector<string> output = runHelper(remaining, descriptorSymbolName);
Chris@19:         result.insert(result.end(), output.begin(), output.end());
Chris@19:         int shortfall = int(remaining.size()) - int(output.size());
Chris@19:         if (shortfall > 0) {
Chris@19:             // Helper bailed out for some reason presumably associated
Chris@19:             // with the plugin following the last one it reported
Chris@19:             // on. Add a failure entry for that one and continue with
Chris@19:             // the following ones.
Chris@6:             string failed = *(remaining.rbegin() + shortfall - 1);
Chris@55:             log("Helper output ended before result for plugin " + failed);
Chris@19:             result.push_back("FAILURE|" + failed + "|Plugin load check failed or timed out");
Chris@4:             remaining = vector<string>
Chris@4:                 (remaining.rbegin(), remaining.rbegin() + shortfall - 1);
Chris@19:         }
Chris@19:         ++runcount;
Chris@2:     }
Chris@2: 
Chris@2:     recordResult(tag, result);
Chris@2: }
Chris@2: 
Chris@40: string
Chris@40: PluginCandidates::getHelperCompatibilityVersion()
Chris@2: {
Chris@2:     QProcess process;
Chris@2:     process.setReadChannel(QProcess::StandardOutput);
Chris@4:     process.setProcessChannelMode(QProcess::ForwardedErrorChannel);
Chris@40:     process.start(m_helper.c_str(), { "--version" });
Chris@40: 
Chris@2:     if (!process.waitForStarted()) {
cannam@13:         QProcess::ProcessError err = process.error();
cannam@13:         if (err == QProcess::FailedToStart) {
cannam@13:             std::cerr << "Unable to start helper process " << m_helper
cannam@13:                       << std::endl;
cannam@13:         } else if (err == QProcess::Crashed) {
cannam@13:             std::cerr << "Helper process " << m_helper
cannam@13:                       << " crashed on startup" << std::endl;
cannam@13:         } else {
cannam@13:             std::cerr << "Helper process " << m_helper
cannam@13:                       << " failed on startup with error code "
cannam@13:                       << err << std::endl;
cannam@13:         }
Chris@19:         throw runtime_error("plugin load helper failed to start");
Chris@2:     }
Chris@40:     process.waitForFinished();
Chris@40: 
Chris@40:     QByteArray output = process.readAllStandardOutput();
Chris@40:     while (output.endsWith('\n') || output.endsWith('\r')) {
Chris@40:         output.chop(1);
Chris@40:     }
Chris@40: 
Chris@44:     string versionString = QString(output).toStdString();
Chris@55:     log("Read version string from helper: " + versionString);
Chris@40:     return versionString;
Chris@40: }
Chris@40: 
Chris@40: vector<string>
Chris@40: PluginCandidates::runHelper(vector<string> libraries, string descriptor)
Chris@40: {
Chris@40:     vector<string> output;
Chris@40: 
Chris@55:     log("Running helper " + m_helper + " with following library list:");
Chris@40:     for (auto &lib: libraries) log(lib);
Chris@40: 
Chris@40:     QProcess process;
Chris@40:     process.setReadChannel(QProcess::StandardOutput);
Chris@55: 
Chris@55:     if (m_logCallback) {
Chris@55:         log("Log callback is set: using separate-channels mode to gather stderr");
Chris@55:         process.setProcessChannelMode(QProcess::SeparateChannels);
Chris@55:     } else {
Chris@55:         process.setProcessChannelMode(QProcess::ForwardedErrorChannel);
Chris@55:     }
Chris@55:     
Chris@40:     process.start(m_helper.c_str(), { descriptor.c_str() });
Chris@40:     
Chris@40:     if (!process.waitForStarted()) {
Chris@40:         QProcess::ProcessError err = process.error();
Chris@40:         if (err == QProcess::FailedToStart) {
Chris@40:             std::cerr << "Unable to start helper process " << m_helper
Chris@40:                       << std::endl;
Chris@40:         } else if (err == QProcess::Crashed) {
Chris@40:             std::cerr << "Helper process " << m_helper
Chris@40:                       << " crashed on startup" << std::endl;
Chris@40:         } else {
Chris@40:             std::cerr << "Helper process " << m_helper
Chris@40:                       << " failed on startup with error code "
Chris@40:                       << err << std::endl;
Chris@40:         }
Chris@55:         logErrors(&process);
Chris@40:         throw runtime_error("plugin load helper failed to start");
Chris@40:     }
Chris@55: 
Chris@55:     log("Helper " + m_helper + " started OK");
Chris@55:     logErrors(&process);
Chris@40:     
Chris@2:     for (auto &lib: libraries) {
Chris@19:         process.write(lib.c_str(), lib.size());
Chris@19:         process.write("\n", 1);
Chris@2:     }
Chris@2: 
Chris@61:     QElapsedTimer t;
Chris@6:     t.start();
Chris@33:     int timeout = 15000; // ms
Chris@6: 
Chris@12:     const int buflen = 4096;
Chris@4:     bool done = false;
Chris@4:     
Chris@4:     while (!done) {
Chris@19:         char buf[buflen];
Chris@19:         qint64 linelen = process.readLine(buf, buflen);
Chris@4:         if (linelen > 0) {
Chris@4:             output.push_back(buf);
Chris@4:             done = (output.size() == libraries.size());
Chris@4:         } else if (linelen < 0) {
Chris@4:             // error case
Chris@55:             log("Received error code while reading from helper");
Chris@4:             done = true;
Chris@19:         } else {
Chris@4:             // no error, but no line read (could just be between
Chris@4:             // lines, or could be eof)
Chris@4:             done = (process.state() == QProcess::NotRunning);
Chris@6:             if (!done) {
Chris@6:                 if (t.elapsed() > timeout) {
Chris@6:                     // this is purely an emergency measure
Chris@55:                     log("Timeout: helper took too long, killing it");
Chris@6:                     process.kill();
Chris@6:                     done = true;
Chris@6:                 } else {
Chris@6:                     process.waitForReadyRead(200);
Chris@6:                 }
Chris@6:             }
Chris@2:         }
Chris@55:         logErrors(&process);
Chris@4:     }
Chris@4: 
Chris@4:     if (process.state() != QProcess::NotRunning) {
Chris@4:         process.close();
Chris@4:         process.waitForFinished();
Chris@55:         logErrors(&process);
Chris@4:     }
cannam@13: 
Chris@55:     log("Helper completed");
cannam@13:     
Chris@2:     return output;
Chris@2: }
Chris@2: 
Chris@2: void
Chris@55: PluginCandidates::logErrors(QProcess *p)
Chris@55: {
Chris@55:     p->setReadChannel(QProcess::StandardError);
Chris@55: 
Chris@55:     qint64 byteCount = p->bytesAvailable();
Chris@55:     if (byteCount == 0) {
Chris@55:         p->setReadChannel(QProcess::StandardOutput);
Chris@55:         return;
Chris@55:     }
Chris@55: 
Chris@55:     QByteArray buffer = p->read(byteCount);
Chris@55:     while (buffer.endsWith('\n') || buffer.endsWith('\r')) {
Chris@55:         buffer.chop(1);
Chris@55:     }
Chris@55:     std::string str(buffer.constData(), buffer.size());
Chris@55:     log("Helper stderr output follows:\n" + str);
Chris@55:     log("Helper stderr output ends");
Chris@55:     
Chris@55:     p->setReadChannel(QProcess::StandardOutput);
Chris@55: }
Chris@55: 
Chris@55: void
Chris@2: PluginCandidates::recordResult(string tag, vector<string> result)
Chris@2: {
Chris@4:     for (auto &r: result) {
Chris@4: 
Chris@4:         QString s(r.c_str());
Chris@4:         QStringList bits = s.split("|");
Chris@6: 
Chris@55:         log(("Read output line from helper: " + s.trimmed()).toStdString());
Chris@6:         
Chris@4:         if (bits.size() < 2 || bits.size() > 3) {
Chris@55:             log("Invalid output line (wrong number of |-separated fields)");
Chris@4:             continue;
Chris@4:         }
Chris@4: 
Chris@4:         string status = bits[0].toStdString();
Chris@4:         
Chris@4:         string library = bits[1].toStdString();
Chris@40:         if (bits.size() == 2) {
Chris@40:             library = bits[1].trimmed().toStdString();
Chris@40:         }
Chris@4: 
Chris@4:         if (status == "SUCCESS") {
Chris@4:             m_candidates[tag].push_back(library);
Chris@4: 
Chris@4:         } else if (status == "FAILURE") {
Chris@40:         
Chris@40:             QString messageAndCode = "";
Chris@40:             if (bits.size() > 2) {
Chris@40:                 messageAndCode = bits[2].trimmed();
Chris@40:             }
Chris@40: 
Chris@40:             PluginCheckCode code = PluginCheckCode::FAIL_OTHER;
Chris@40:             string message = "";
Chris@40: 
Chris@40:             QRegExp codeRE("^(.*) *\\[([0-9]+)\\]$");
Chris@40:             if (codeRE.exactMatch(messageAndCode)) {
Chris@40:                 QStringList caps(codeRE.capturedTexts());
Chris@40:                 if (caps.length() == 3) {
Chris@40:                     message = caps[1].toStdString();
Chris@40:                     code = PluginCheckCode(caps[2].toInt());
Chris@55:                     log("Split failure report into message and failure code "
Chris@40:                         + caps[2].toStdString());
Chris@40:                 } else {
Chris@55:                     log("Unable to split out failure code from report");
Chris@40:                 }
Chris@40:             } else {
Chris@55:                 log("Failure message does not give a failure code");
Chris@40:             }
Chris@40: 
Chris@40:             if (message == "") {
Chris@40:                 message = messageAndCode.toStdString();
Chris@40:             }
Chris@40: 
Chris@40:             m_failures[tag].push_back({ library, code, message });
Chris@4: 
Chris@4:         } else {
Chris@55:             log("Unexpected status \"" + status + "\" in output line");
Chris@4:         }
Chris@4:     }
Chris@2: }
Chris@2: