From aa4407e332f62f2cb24dd8e8fb41d2469efba1fb Mon Sep 17 00:00:00 2001 From: Vikas Pachdha Date: Mon, 18 Jun 2018 11:49:14 +0200 Subject: [PATCH] Android: add logging for build and run Change-Id: Idca5a45713762aa9e2861dcc58c3bbd96cbe687e Reviewed-by: hjk --- src/plugins/android/androidbuildapkstep.cpp | 10 ++++- src/plugins/android/androiddebugsupport.cpp | 25 +++++++++-- src/plugins/android/androiddeployqtstep.cpp | 25 +++++++++-- src/plugins/android/androidmanager.cpp | 9 ++++ src/plugins/android/androidrunner.cpp | 11 ++++- src/plugins/android/androidrunnerworker.cpp | 47 ++++++++++++++++++--- 6 files changed, 112 insertions(+), 15 deletions(-) diff --git a/src/plugins/android/androidbuildapkstep.cpp b/src/plugins/android/androidbuildapkstep.cpp index c3171659eb8..91cd0d440f1 100644 --- a/src/plugins/android/androidbuildapkstep.cpp +++ b/src/plugins/android/androidbuildapkstep.cpp @@ -52,6 +52,7 @@ #include #include #include +#include #include #include #include @@ -60,6 +61,9 @@ #include using namespace ProjectExplorer; +namespace { +Q_LOGGING_CATEGORY(buildapkstepLog, "qtc.android.build.androidbuildapkstep") +} namespace Android { using namespace Internal; @@ -125,9 +129,12 @@ bool AndroidBuildApkStep::init(QList &earlierSteps) ProjectExplorer::BuildConfiguration *bc = buildConfiguration(); if (m_signPackage) { + qCDebug(buildapkstepLog) << "Signing enabled"; // check keystore and certificate passwords - if (!verifyKeystorePassword() || !verifyCertificatePassword()) + if (!verifyKeystorePassword() || !verifyCertificatePassword()) { + qCDebug(buildapkstepLog) << "Init failed. Keystore/Certificate password verification failed."; return false; + } if (bc->buildType() != ProjectExplorer::BuildConfiguration::Release) emit addOutput(tr("Warning: Signing a debug or profile package."), @@ -173,6 +180,7 @@ bool AndroidBuildApkStep::init(QList &earlierSteps) m_openPackageLocationForRun = m_openPackageLocation; m_apkPath = qtSupport->apkPath(target()).toString(); + qCDebug(buildapkstepLog) << "APK path:" << m_apkPath; if (!AbstractProcessStep::init(earlierSteps)) return false; diff --git a/src/plugins/android/androiddebugsupport.cpp b/src/plugins/android/androiddebugsupport.cpp index 475643eddd5..0046772f897 100644 --- a/src/plugins/android/androiddebugsupport.cpp +++ b/src/plugins/android/androiddebugsupport.cpp @@ -44,6 +44,11 @@ #include #include +#include + +namespace { +Q_LOGGING_CATEGORY(androidDebugSupportLog, "qtc.android.run.androiddebugsupport") +} using namespace Debugger; using namespace ProjectExplorer; @@ -110,33 +115,44 @@ void AndroidDebugSupport::start() Kit *kit = target->kit(); setStartMode(AttachToRemoteServer); - setRunControlName(AndroidManager::packageName(target)); + const QString packageName = AndroidManager::packageName(target); + setRunControlName(packageName); setUseContinueInsteadOfRun(true); setAttachPid(m_runner->pid()); + qCDebug(androidDebugSupportLog) << "Start. Package name: " << packageName + << "PID: " << m_runner->pid().pid(); if (!Utils::HostOsInfo::isWindowsHost() && AndroidConfigurations::currentConfig().ndkVersion() >= QVersionNumber(11, 0, 0)) { + qCDebug(androidDebugSupportLog) << "UseTargetAsync: " << true; setUseTargetAsync(true); } QtSupport::BaseQtVersion *qtVersion = QtSupport::QtKitInformation::qtVersion(kit); if (isCppDebugging()) { + qCDebug(androidDebugSupportLog) << "C++ debugging enabled"; AndroidQtSupport *qtSupport = AndroidManager::androidQtSupport(target); QStringList solibSearchPath = qtSupport->soLibSearchPath(target); solibSearchPath.append(qtSoPaths(qtVersion)); solibSearchPath.append(uniquePaths(qtSupport->targetData(Android::Constants::AndroidExtraLibs, target))); setSolibSearchPath(solibSearchPath); + qCDebug(androidDebugSupportLog) << "SoLibSearchPath: "<activeBuildConfiguration()->buildDirectory().toString() + "/app_process"); setSkipExecutableValidation(true); setUseExtendedRemote(true); setRemoteChannel(":" + m_runner->gdbServerPort().toString()); - setSysRoot(AndroidConfigurations::currentConfig().ndkLocation().appendPath("platforms") - .appendPath(QString("android-%1").arg(AndroidManager::minimumSDK(target))) - .appendPath(toNdkArch(AndroidManager::targetArch(target))).toString()); + + QString sysRoot = AndroidConfigurations::currentConfig().ndkLocation().appendPath("platforms") + .appendPath(QString("android-%1").arg(AndroidManager::minimumSDK(target))) + .appendPath(toNdkArch(AndroidManager::targetArch(target))).toString(); + setSysRoot(sysRoot); + qCDebug(androidDebugSupportLog) << "Sysroot: " << sysRoot; } if (isQmlDebugging()) { + qCDebug(androidDebugSupportLog) << "QML debugging enabled. QML server: " + << m_runner->qmlServer().toDisplayString(); setQmlServer(m_runner->qmlServer()); //TODO: Not sure if these are the right paths. if (qtVersion) @@ -148,6 +164,7 @@ void AndroidDebugSupport::start() void AndroidDebugSupport::stop() { + qCDebug(androidDebugSupportLog) << "Stop"; DebuggerRunTool::stop(); } diff --git a/src/plugins/android/androiddeployqtstep.cpp b/src/plugins/android/androiddeployqtstep.cpp index f4d878db62f..980fb3f91da 100644 --- a/src/plugins/android/androiddeployqtstep.cpp +++ b/src/plugins/android/androiddeployqtstep.cpp @@ -55,12 +55,17 @@ #include #include +#include using namespace ProjectExplorer; using namespace Android; using namespace Android::Internal; +namespace { +Q_LOGGING_CATEGORY(deployStepLog, "qtc.android.build.androiddeployqtstep") +} + const QLatin1String UninstallPreviousPackageKey("UninstallPreviousPackage"); const QLatin1String InstallFailedInconsistentCertificatesString("INSTALL_PARSE_FAILED_INCONSISTENT_CERTIFICATES"); const QLatin1String InstallFailedUpdateIncompatible("INSTALL_FAILED_UPDATE_INCOMPATIBLE"); @@ -133,6 +138,7 @@ bool AndroidDeployQtStep::init(QList &earlierSteps) m_avdName = info.avdname; m_serialNumber = info.serialNumber; + qCDebug(deployStepLog) << "AVD:" << m_avdName << "Device Serial:" << m_serialNumber; ProjectExplorer::BuildConfiguration *bc = buildConfiguration(); m_filesToPull.clear(); @@ -140,11 +146,16 @@ bool AndroidDeployQtStep::init(QList &earlierSteps) if (bc && !buildDir.endsWith("/")) { buildDir += "/"; } + + ProjectExplorer::ToolChain *tc = ProjectExplorer::ToolChainKitInformation::toolChain( + target()->kit(), ProjectExplorer::Constants::CXX_LANGUAGE_ID); + qCDebug(deployStepLog) << "Device CPU ABI: " << info.cpuAbi.join(", "); + qCDebug(deployStepLog) << "TC ABI: " << (tc ? tc->targetAbi().toString() : "No Toolchain"); + QString linkerName("linker"); QString libDirName("lib"); if (info.cpuAbi.contains(QLatin1String("arm64-v8a")) || info.cpuAbi.contains(QLatin1String("x86_64"))) { - ProjectExplorer::ToolChain *tc = ProjectExplorer::ToolChainKitInformation::toolChain(target()->kit(), ProjectExplorer::Constants::CXX_LANGUAGE_ID); if (tc && tc->targetAbi().wordWidth() == 64) { m_filesToPull["/system/bin/app_process64"] = buildDir + "app_process"; libDirName = "lib64"; @@ -160,10 +171,12 @@ bool AndroidDeployQtStep::init(QList &earlierSteps) m_filesToPull["/system/bin/" + linkerName] = buildDir + linkerName; m_filesToPull["/system/" + libDirName + "/libc.so"] = buildDir + "libc.so"; + qCDebug(deployStepLog) << "Files to pull from device:"; + for (auto itr = m_filesToPull.constBegin(); itr != m_filesToPull.constEnd(); ++itr) + qCDebug(deployStepLog) << itr.key() << "to" << itr.value(); AndroidManager::setDeviceSerialNumber(target(), m_serialNumber); AndroidManager::setDeviceApiLevel(target(), info.sdk); - QtSupport::BaseQtVersion *version = QtSupport::QtKitInformation::qtVersion(target()->kit()); if (!version) return false; @@ -181,6 +194,7 @@ bool AndroidDeployQtStep::init(QList &earlierSteps) emit addOutput(tr("Cannot find the androiddeployqt tool."), OutputFormat::Stderr); return false; } + qCDebug(deployStepLog) << "Using androiddeployqt"; if (!m_command.endsWith(QLatin1Char('/'))) m_command += QLatin1Char('/'); m_command += Utils::HostOsInfo::withExecutableSuffix(QLatin1String("androiddeployqt")); @@ -200,6 +214,7 @@ bool AndroidDeployQtStep::init(QList &earlierSteps) } Utils::QtcProcess::addArg(&m_androiddeployqtArgs, jsonFile); if (androidBuildApkStep && androidBuildApkStep->useMinistro()) { + qCDebug(deployStepLog) << "Using ministro"; Utils::QtcProcess::addArg(&m_androiddeployqtArgs, QLatin1String("--deployment")); Utils::QtcProcess::addArg(&m_androiddeployqtArgs, QLatin1String("ministro")); } @@ -248,6 +263,7 @@ AndroidDeployQtStep::DeployErrorCode AndroidDeployQtStep::runDeploy(QFutureInter } } else { if (m_uninstallPreviousPackageRun) { + qCDebug(deployStepLog) << "Uninstalling previous package"; const QString packageName = AndroidManager::packageName(m_manifestName); if (packageName.isEmpty()) { emit addOutput(tr("Cannot find the package name."), OutputFormat::Stderr); @@ -313,7 +329,7 @@ AndroidDeployQtStep::DeployErrorCode AndroidDeployQtStep::runDeploy(QFutureInter QProcess::ExitStatus exitStatus = m_process->exitStatus(); int exitCode = m_process->exitCode(); delete m_process; - m_process = 0; + m_process = nullptr; if (exitStatus == QProcess::NormalExit && exitCode == 0) { emit addOutput(tr("The process \"%1\" exited normally.").arg(m_command), @@ -374,6 +390,7 @@ void AndroidDeployQtStep::slotAskForUninstall(DeployErrorCode errorCode) void AndroidDeployQtStep::slotSetSerialNumber(const QString &serialNumber) { + qCDebug(deployStepLog) << "Target device serial number change:" << serialNumber; AndroidManager::setDeviceSerialNumber(target(), serialNumber); } @@ -381,6 +398,7 @@ void AndroidDeployQtStep::run(QFutureInterface &fi) { if (!m_avdName.isEmpty()) { QString serialNumber = AndroidAvdManager().waitForAvd(m_avdName, fi); + qCDebug(deployStepLog) << "Deploying to AVD:" << m_avdName << serialNumber; if (serialNumber.isEmpty()) { reportRunResult(fi, false); return; @@ -390,6 +408,7 @@ void AndroidDeployQtStep::run(QFutureInterface &fi) } if (!buildConfiguration()) { // nothing to deploy + qCDebug(deployStepLog) << "Skip deployment. No build configuration. (e.g. *.qmlproject)"; reportRunResult(fi, true); return; } diff --git a/src/plugins/android/androidmanager.cpp b/src/plugins/android/androidmanager.cpp index 74e35bdf2c4..2d10f766ce6 100644 --- a/src/plugins/android/androidmanager.cpp +++ b/src/plugins/android/androidmanager.cpp @@ -54,6 +54,7 @@ #include #include #include +#include #include #include #include @@ -61,6 +62,10 @@ #include #include +namespace { +Q_LOGGING_CATEGORY(androidManagerLog, "qtc.android.androidManager") +} + namespace { const QLatin1String AndroidManifestName("AndroidManifest.xml"); const QLatin1String AndroidDefaultPropertiesName("project.properties"); @@ -243,6 +248,8 @@ QString AndroidManager::deviceSerialNumber(ProjectExplorer::Target *target) void AndroidManager::setDeviceSerialNumber(ProjectExplorer::Target *target, const QString &deviceSerialNumber) { + qCDebug(androidManagerLog) << "Device serial for the target changed" + << target->displayName() << deviceSerialNumber; target->setNamedSettings(AndroidDeviceSn, deviceSerialNumber); } @@ -253,6 +260,8 @@ int AndroidManager::deviceApiLevel(ProjectExplorer::Target *target) void AndroidManager::setDeviceApiLevel(ProjectExplorer::Target *target, int level) { + qCDebug(androidManagerLog) << "Device API level for the target changed" + << target->displayName() << level; target->setNamedSettings(ApiLevelKey, level); } diff --git a/src/plugins/android/androidrunner.cpp b/src/plugins/android/androidrunner.cpp index 4ea111aeb3b..eb40d07f739 100644 --- a/src/plugins/android/androidrunner.cpp +++ b/src/plugins/android/androidrunner.cpp @@ -41,6 +41,12 @@ #include #include +#include + +namespace { +Q_LOGGING_CATEGORY(androidRunnerLog, "qtc.android.run.androidrunner") +} + using namespace ProjectExplorer; using namespace Utils; @@ -130,8 +136,11 @@ AndroidRunner::AndroidRunner(RunControl *runControl, QString intent = intentName.isEmpty() ? AndroidManager::intentName(m_target) : intentName; m_packageName = intent.left(intent.indexOf('/')); + qCDebug(androidRunnerLog) << "Intent name:" << intent << "Package name" << m_packageName; const int apiLevel = AndroidManager::deviceApiLevel(m_target); + qCDebug(androidRunnerLog) << "Device API:" << apiLevel; + m_worker.reset(new AndroidRunnerWorker(this, m_packageName)); m_worker->setIntentName(intent); m_worker->setIsPreNougat(apiLevel <= 23); @@ -168,7 +177,7 @@ AndroidRunner::~AndroidRunner() void AndroidRunner::start() { if (!ProjectExplorerPlugin::projectExplorerSettings().deployBeforeRun) { - // User choose to run the app without deployment. Start the AVD if not running. + qCDebug(androidRunnerLog) << "Run without deployment"; launchAVD(); if (!m_launchedAVDName.isEmpty()) { m_checkAVDTimer.start(); diff --git a/src/plugins/android/androidrunnerworker.cpp b/src/plugins/android/androidrunnerworker.cpp index d4bb5cc899c..a7b39abd728 100644 --- a/src/plugins/android/androidrunnerworker.cpp +++ b/src/plugins/android/androidrunnerworker.cpp @@ -40,11 +40,16 @@ #include #include +#include #include #include #include +namespace { +Q_LOGGING_CATEGORY(androidRunWorkerLog, "qtc.android.run.androidrunnerworker") +} + using namespace std; using namespace std::placeholders; using namespace ProjectExplorer; @@ -105,6 +110,7 @@ static void findProcessPID(QFutureInterface &fi, const QString &adbPath, QStringList selector, const QString &packageName, bool preNougat) { + qCDebug(androidRunWorkerLog) << "Finding PID. PreNougat:" << preNougat; if (packageName.isEmpty()) return; @@ -125,17 +131,20 @@ static void findProcessPID(QFutureInterface &fi, const QString &adbPath, } } while (processPID == -1 && !isTimedOut(start) && !fi.isCanceled()); + qCDebug(androidRunWorkerLog) << "PID found:" << processPID; if (!fi.isCanceled()) fi.reportResult(processPID); } static void deleter(QProcess *p) { + qCDebug(androidRunWorkerLog) << "Killing process:" << p->objectName(); p->terminate(); if (!p->waitForFinished(1000)) { p->kill(); p->waitForFinished(); } + qCDebug(androidRunWorkerLog) << "Done killing process:" << p->objectName(); // Might get deleted from its own signal handler. p->deleteLater(); } @@ -165,6 +174,7 @@ AndroidRunnerWorker::AndroidRunnerWorker(RunWorker *runner, const QString &packa m_localGdbServerPort = Utils::Port(5039); QTC_CHECK(m_localGdbServerPort.isValid()); if (m_qmlDebugServices != QmlDebug::NoQmlDebugServices) { + qCDebug(androidRunWorkerLog) << "QML debugging enabled"; QTcpServer server; QTC_ASSERT(server.listen(QHostAddress::LocalHost) || server.listen(QHostAddress::LocalHostIPv6), @@ -172,6 +182,7 @@ AndroidRunnerWorker::AndroidRunnerWorker(RunWorker *runner, const QString &packa m_qmlServer.setScheme(Utils::urlTcpScheme()); m_qmlServer.setHost(server.serverAddress().toString()); m_qmlServer.setPort(server.serverPort()); + qCDebug(androidRunWorkerLog) << "QML server:" << m_qmlServer.toDisplayString(); } m_adb = AndroidConfigurations::currentConfig().adbToolPath().toString(); m_localJdbServerPort = Utils::Port(5038); @@ -197,6 +208,12 @@ AndroidRunnerWorker::AndroidRunnerWorker(RunWorker *runner, const QString &packa } for (const QString &shellCmd : runner->recordedData(Constants::ANDROID_POSTFINISHSHELLCMDLIST).toStringList()) m_afterFinishAdbCommands.append(QString("shell %1").arg(shellCmd)); + + qCDebug(androidRunWorkerLog) << "Device Serial:" << m_deviceSerialNumber + << "API level:" << m_apiLevel + << "Extra Start Args:" << m_amStartExtraArgs + << "Before Start ADB cmds:" << m_beforeStartAdbCommands + << "After finish ADB cmds:" << m_afterFinishAdbCommands; } AndroidRunnerWorker::~AndroidRunnerWorker() @@ -232,12 +249,16 @@ bool AndroidRunnerWorker::adbShellAmNeedsQuotes() bool AndroidRunnerWorker::runAdb(const QStringList &args, int timeoutS) { + QStringList adbArgs = selector() + args; + qCDebug(androidRunWorkerLog) << "ADB command: " << m_adb << adbArgs.join(' '); Utils::SynchronousProcess adb; adb.setTimeoutS(timeoutS); - Utils::SynchronousProcessResponse response = adb.run(m_adb, selector() + args); + Utils::SynchronousProcessResponse response = adb.run(m_adb, adbArgs); m_lastRunAdbError = response.exitMessage(m_adb, timeoutS); m_lastRunAdbRawOutput = response.allRawOutput(); - return response.result == Utils::SynchronousProcessResponse::Finished; + bool success = response.result == Utils::SynchronousProcessResponse::Finished; + qCDebug(androidRunWorkerLog) << "ADB command result:" << success << response.allRawOutput(); + return success; } void AndroidRunnerWorker::adbKill(qint64 pid) @@ -343,6 +364,8 @@ void AndroidRunnerWorker::setAndroidDeviceInfo(const AndroidDeviceInfo &info) { m_deviceSerialNumber = info.serialNumber; m_apiLevel = info.sdk; + qCDebug(androidRunWorkerLog) << "Android Device Info changed" + << m_deviceSerialNumber << m_apiLevel; } void AndroidRunnerWorker::asyncStartHelper() @@ -359,7 +382,7 @@ void AndroidRunnerWorker::asyncStartHelper() logcatProcess->start(m_adb, selector() << "logcat"); QTC_ASSERT(!m_adbLogcatProcess, /**/); m_adbLogcatProcess = std::move(logcatProcess); - + m_adbLogcatProcess->setObjectName("AdbLogcatProcess"); for (const QString &entry : m_beforeStartAdbCommands) runAdb(entry.split(' ', QString::SkipEmptyParts)); @@ -405,6 +428,7 @@ void AndroidRunnerWorker::asyncStartHelper() return; } m_gdbServerProcess = std::move(gdbServerProcess); + m_gdbServerProcess->setObjectName("GdbServerProcess"); QStringList removeForward{"forward", "--remove", "tcp:" + m_localGdbServerPort.toString()}; runAdb(removeForward); if (!runAdb({"forward", "tcp:" + m_localGdbServerPort.toString(), @@ -489,20 +513,24 @@ void AndroidRunnerWorker::handleJdbWaiting() else jdbPath.appendPath("jdb"); + QStringList jdbArgs("-connect"); + jdbArgs << QString("com.sun.jdi.SocketAttach:hostname=localhost,port=%1") + .arg(m_localJdbServerPort.toString()); + qCDebug(androidRunWorkerLog) << "Starting JDB:" << jdbPath << jdbArgs.join(' '); std::unique_ptr jdbProcess(new QProcess, &deleter); jdbProcess->setProcessChannelMode(QProcess::MergedChannels); - jdbProcess->start(jdbPath.toString(), QStringList() << "-connect" << - QString("com.sun.jdi.SocketAttach:hostname=localhost,port=%1") - .arg(m_localJdbServerPort.toString())); + jdbProcess->start(jdbPath.toString(), jdbArgs); if (!jdbProcess->waitForStarted()) { emit remoteProcessFinished(tr("Failed to start jdb")); return; } m_jdbProcess = std::move(jdbProcess); + m_jdbProcess->setObjectName("JdbProcess"); } void AndroidRunnerWorker::handleJdbSettled() { + qCDebug(androidRunWorkerLog) << "Handle JDB settled"; auto waitForCommand = [&]() { for (int i= 0; i < 5 && m_jdbProcess->state() == QProcess::Running; ++i) { m_jdbProcess->waitForReadyRead(500); @@ -523,10 +551,12 @@ void AndroidRunnerWorker::handleJdbSettled() if (!m_jdbProcess->waitForFinished(5000)) { m_jdbProcess->terminate(); if (!m_jdbProcess->waitForFinished(5000)) { + qCDebug(androidRunWorkerLog) << "Killing JDB process"; m_jdbProcess->kill(); m_jdbProcess->waitForFinished(); } } else if (m_jdbProcess->exitStatus() == QProcess::NormalExit && m_jdbProcess->exitCode() == 0) { + qCDebug(androidRunWorkerLog) << "JDB settled"; return; } } @@ -538,6 +568,8 @@ void AndroidRunnerWorker::onProcessIdChanged(qint64 pid) { // Don't write to m_psProc from a different thread QTC_ASSERT(QThread::currentThread() == thread(), return); + qCDebug(androidRunWorkerLog) << "Process ID changed from:" << m_processPID + << "to:" << pid; m_processPID = pid; if (pid == -1) { emit remoteProcessFinished(QLatin1String("\n\n") + tr("\"%1\" died.") @@ -558,6 +590,7 @@ void AndroidRunnerWorker::onProcessIdChanged(qint64 pid) logcatReadStandardOutput(); QTC_ASSERT(!m_psIsAlive, /**/); m_psIsAlive.reset(new QProcess); + m_psIsAlive->setObjectName("IsAliveProcess"); m_psIsAlive->setProcessChannelMode(QProcess::MergedChannels); connect(m_psIsAlive.get(), static_cast(&QProcess::finished), this, bind(&AndroidRunnerWorker::onProcessIdChanged, this, -1)); @@ -569,6 +602,8 @@ void AndroidRunnerWorker::onProcessIdChanged(qint64 pid) void AndroidRunnerWorker::setExtraEnvVars(const Utils::Environment &extraEnvVars) { m_extraEnvVars = extraEnvVars; + qCDebug(androidRunWorkerLog) << "Settings extra env:" + << extraEnvVars.toStringList(); } void AndroidRunnerWorker::setExtraAppParams(const QString &extraAppParams)