Implement just in time debug feature for runonphone

When the test being run crashes, runonphone will now retrieve the
registers and call stack for the crashing thread from the phone and save
to a crash log (compatible with d_exc crash logs, so existing tools can
be used to analyse the log)

To disable just in time debug, use --nocrashlog on the command line
To save the crash logs to a different location, use --crashlogpath <path>
   otherwise, they are saved to the working directory.

To convert the crash logs into human readable form, use the crash
analyser carbide plugin from symbian foundation; or another symbian tool
that can process d_exc style logs.

Reviewed-by: Thomas Zander

3 files changed, 186 insertions, 3 deletions

diff --git a/tools/runonphone/main.cpp b/tools/runonphone/main.cpp
index 885d029..dc83044 100644
--- a/tools/runonphone/main.cpp
+++ b/tools/runonphone/main.cpp
@@ -62,6 +62,8 @@ void printUsage(QTextStream& outstream, QString exeName)
             << "-v, --verbose                            show debugging output" << endl
             << "-q, --quiet                              hide progress messages" << endl
             << "-d, --download <remote file> <local file> copy file from phone to PC after running test" << endl
+            << "--nocrashlog                             Don't capture call stack if test crashes" << endl
+            << "--crashlogpath <dir>                     Path to save crash logs (default=working dir)" << endl
             << endl
             << "USB COM ports can usually be autodetected, use -p or -f to force a specific port." << endl
             << "If using System TRK, it is possible to copy the program directly to sys/bin on the phone." << endl
@@ -85,6 +87,8 @@ int main(int argc, char *argv[])
     QString downloadLocalFile;
     int loglevel=1;
     int timeout=0;
+    bool crashlog = true;
+    QString crashlogpath;
     QListIterator<QString> it(args);
     it.next(); //skip name of program
     while (it.hasNext()) {
@@ -126,6 +130,12 @@ int main(int argc, char *argv[])
                 loglevel=2;
             else if (arg == "--quiet" || arg == "-q")
                 loglevel=0;
+            else if (arg == "--nocrashlog")
+                crashlog = false;
+            else if (arg == "--crashlogpath") {
+                CHECK_PARAMETER_EXISTS
+                crashlogpath = it.next();
+            }
             else
                 errstream << "unknown command line option " << arg << endl;
         } else {
@@ -199,6 +209,8 @@ int main(int argc, char *argv[])
 
     TrkSignalHandler handler;
     handler.setLogLevel(loglevel);
+    handler.setCrashLogging(crashlog);
+    handler.setCrashLogPath(crashlogpath);
 
     QObject::connect(launcher.data(), SIGNAL(copyingStarted()), &handler, SLOT(copyingStarted()));
     QObject::connect(launcher.data(), SIGNAL(canNotConnect(const QString &)), &handler, SLOT(canNotConnect(const QString &)));
@@ -215,8 +227,12 @@ int main(int argc, char *argv[])
     QObject::connect(launcher.data(), SIGNAL(copyProgress(int)), &handler, SLOT(copyProgress(int)));
     QObject::connect(launcher.data(), SIGNAL(stateChanged(int)), &handler, SLOT(stateChanged(int)));
     QObject::connect(launcher.data(), SIGNAL(processStopped(uint,uint,uint,QString)), &handler, SLOT(stopped(uint,uint,uint,QString)));
+    QObject::connect(launcher.data(), SIGNAL(libraryLoaded(trk::Library)), &handler, SLOT(libraryLoaded(trk::Library)));
+    QObject::connect(launcher.data(), SIGNAL(libraryUnloaded(trk::Library)), &handler, SLOT(libraryUnloaded(trk::Library)));
+    QObject::connect(launcher.data(), SIGNAL(registersAndCallStackReadComplete(const QList<uint> &,const QByteArray &)), &handler, SLOT(registersAndCallStackReadComplete(const QList<uint> &,const QByteArray &)));
     QObject::connect(&handler, SIGNAL(resume(uint,uint)), launcher.data(), SLOT(resumeProcess(uint,uint)));
     QObject::connect(&handler, SIGNAL(terminate()), launcher.data(), SLOT(terminate()));
+    QObject::connect(&handler, SIGNAL(getRegistersAndCallStack(uint,uint)), launcher.data(), SLOT(getRegistersAndCallStack(uint,uint)));
     QObject::connect(launcher.data(), SIGNAL(finished()), &handler, SLOT(finished()));
 
     QTimer timer;
diff --git a/tools/runonphone/trksignalhandler.cpp b/tools/runonphone/trksignalhandler.cpp
index 2abf91f..b6d446f 100644
--- a/tools/runonphone/trksignalhandler.cpp
+++ b/tools/runonphone/trksignalhandler.cpp
@@ -42,7 +42,19 @@
 #include <QDebug>
 #include <QCoreApplication>
 #include <QObject>
+#include <QFile>
+#include <QDir>
 #include "trksignalhandler.h"
+#include "trkutils.h"
+
+class CrashState
+{
+public:
+    uint pid;
+    uint tid;
+    QString crashReason;
+    uint crashPC;
+};
 
 class TrkSignalHandlerPrivate
 {
@@ -55,6 +67,12 @@ private:
     QTextStream err;
     int loglevel;
     int lastpercent;
+    QList<trk::Library> libraries;
+    QFile crashlogtextfile;
+    QFile crashstackfile;
+    QList<CrashState> queuedCrashes;
+    QString crashlogPath;
+    bool crashlog;
 };
 
 void TrkSignalHandler::copyingStarted()
@@ -108,6 +126,7 @@ void TrkSignalHandler::startingApplication()
 
 void TrkSignalHandler::applicationRunning(uint pid)
 {
+    Q_UNUSED(pid)
     if (d->loglevel > 0)
         d->out << "Running..." << endl;
 }
@@ -155,13 +174,153 @@ void TrkSignalHandler::setLogLevel(int level)
     d->loglevel = level;
 }
 
+void TrkSignalHandler::setCrashLogging(bool enabled)
+{
+    d->crashlog = enabled;
+}
+
+void TrkSignalHandler::setCrashLogPath(QString path)
+{
+    d->crashlogPath = path;
+}
+
+bool lessThanCodeBase(const trk::Library& cs1, const trk::Library& cs2)
+{
+    return cs1.codeseg < cs2.codeseg;
+}
+
 void TrkSignalHandler::stopped(uint pc, uint pid, uint tid, const QString& reason)
 {
     d->err << "STOPPED: pc=" << hex << pc << " pid=" << pid
            << " tid=" << tid << dec << " - " << reason << endl;
-    // if it was a breakpoint, then we could continue with "emit resume(pid, tid);"
-    // since we have set no breakpoints, it will be a just in time debug of a panic / exception
-    emit terminate();
+
+    if (d->crashlog) {
+        CrashState cs;
+        cs.pid = pid;
+        cs.tid = tid;
+        cs.crashPC = pc;
+        cs.crashReason = reason;
+
+        d->queuedCrashes.append(cs);
+
+        if (d->queuedCrashes.count() == 1) {
+            d->err << "Fetching registers and stack..." << endl;
+            emit getRegistersAndCallStack(pid, tid);
+        }
+    }
+    else
+        emit resume(pid, tid);
+}
+
+void TrkSignalHandler::registersAndCallStackReadComplete(const QList<uint>& registers, const QByteArray& stack)
+{
+    CrashState cs = d->queuedCrashes.first();
+    QDir dir(d->crashlogPath);
+    d->crashlogtextfile.setFileName(dir.filePath(QString("d_exc_%1.txt").arg(cs.tid)));
+    d->crashstackfile.setFileName(dir.filePath(QString("d_exc_%1.stk").arg(cs.tid)));
+    d->crashlogtextfile.open(QIODevice::WriteOnly);
+    QTextStream crashlog(&d->crashlogtextfile);
+
+    crashlog << "-----------------------------------------------------------------------------" << endl;
+    crashlog << "EKA2 USER CRASH LOG" << endl;
+    crashlog << "Thread Name: " << QString("ProcessID-%1::ThreadID-%2").arg(cs.pid).arg(cs.tid) << endl;
+    crashlog << "Thread ID: " << cs.tid << endl;
+    //this is wrong, but TRK doesn't make stack limit available so we lie
+    crashlog << QString("User Stack %1-%2").arg(registers.at(13), 8, 16, QChar('0')).arg(registers.at(13) + stack.size(), 8, 16, QChar('0')) << endl;
+    //this is also wrong, but TRK doesn't give all information for exceptions
+    crashlog << QString("Panic: PC=%1 ").arg(cs.crashPC, 8, 16, QChar('0')) << cs.crashReason << endl;
+    crashlog << endl;
+    crashlog << "USER REGISTERS:" << endl;
+    crashlog << QString("CPSR=%1").arg(registers.at(16), 8, 16, QChar('0')) << endl;
+    for (int i=0;i<16;i+=4) {
+        crashlog << QString("r%1=%2 %3 %4 %5")
+            .arg(i, 2, 10, QChar('0'))
+            .arg(registers.at(i), 8, 16, QChar('0'))
+            .arg(registers.at(i+1), 8, 16, QChar('0'))
+            .arg(registers.at(i+2), 8, 16, QChar('0'))
+            .arg(registers.at(i+3), 8, 16, QChar('0')) << endl;
+    }
+    crashlog << endl;
+
+    //emit info for post mortem debug
+    qSort(d->libraries.begin(), d->libraries.end(), lessThanCodeBase);
+    d->err << "Code Segments:" << endl;
+    crashlog << "CODE SEGMENTS:" << endl;
+    for(int i=0; i<d->libraries.count(); i++) {
+        const trk::Library& seg = d->libraries.at(i);
+        if(seg.pid != cs.pid)
+            continue;
+        if (d->loglevel > 1) {
+            d->err << QString("Code: %1 Data: %2 Name: ")
+                .arg(seg.codeseg, 8, 16, QChar('0'))
+                .arg(seg.dataseg, 8, 16, QChar('0'))
+                << seg.name << endl;
+        }
+
+        //produce fake code segment end addresses since we don't get the real ones from TRK
+        uint end;
+        if (i+1 < d->libraries.count())
+            end = d->libraries.at(i+1).codeseg - 1;
+        else
+            end = 0xFFFFFFFF;
+
+        crashlog << QString("%1-%2 ")
+            .arg(seg.codeseg, 8, 16, QChar('0'))
+            .arg(end, 8, 16, QChar('0'))
+            << seg.name << endl;
+    }
+
+    d->crashlogtextfile.close();
+
+    if (d->loglevel > 1) {
+        d->err << "Registers:" << endl;
+        for (int i=0;i<16;i++) {
+            d->err << QString("R%1: %2 ").arg(i, 2, 10, QChar('0')).arg(registers.at(i), 8, 16, QChar('0'));
+            if (i % 4 == 3)
+                d->err << endl;
+        }
+        d->err << QString("CPSR: %1").arg(registers.at(16), 8, 16, QChar('0')) << endl;
+
+        d->err << "Stack:" << endl;
+        uint sp = registers.at(13);
+        for(int i=0; i<stack.size(); i+=16, sp+=16) {
+            d->err << QString("%1: ").arg(sp, 8, 16, QChar('0'));
+            d->err << trk::stringFromArray(stack.mid(i,16));
+            d->err << endl;
+        }
+    }
+    d->crashstackfile.open(QIODevice::WriteOnly);
+    d->crashstackfile.write(stack);
+    d->crashstackfile.close();
+
+    if (d->loglevel > 0)
+        d->err << "Crash logs saved to " << d->crashlogtextfile.fileName() << " & " << d->crashstackfile.fileName() << endl;
+
+    // resume the thread to allow Symbian OS to handle the panic normally.
+    // terminate when a non main thread is suspended reboots the phone (TRK bug)
+    emit resume(cs.pid, cs.tid);
+
+    //fetch next crashed thread
+    d->queuedCrashes.removeFirst();
+    if (d->queuedCrashes.count()) {
+        cs = d->queuedCrashes.first();
+        d->err << "Fetching registers and stack..." << endl;
+        emit getRegistersAndCallStack(cs.pid, cs.tid);
+    }
+
+}
+
+void TrkSignalHandler::libraryLoaded(const trk::Library &lib)
+{
+    d->libraries << lib;
+}
+
+void TrkSignalHandler::libraryUnloaded(const trk::Library &lib)
+{
+    for (QList<trk::Library>::iterator i = d->libraries.begin(); i != d->libraries.end(); i++) {
+        if((*i).name == lib.name && (*i).pid == lib.pid)
+            i = d->libraries.erase(i);
+    }
 }
 
 void TrkSignalHandler::timeout()
diff --git a/tools/runonphone/trksignalhandler.h b/tools/runonphone/trksignalhandler.h
index d31e46f..bfe2c3e 100644
--- a/tools/runonphone/trksignalhandler.h
+++ b/tools/runonphone/trksignalhandler.h
@@ -43,6 +43,7 @@
 #define TRKSIGNALHANDLER_H
 #include <QObject>
 #include <QString>
+#include "symbianutils/trkutils.h"
 
 class TrkSignalHandlerPrivate;
 class TrkSignalHandler : public QObject
@@ -66,13 +67,20 @@ public slots:
     void stateChanged(int);
     void stopped(uint pc, uint pid, uint tid, const QString& reason);
     void timeout();
+    void libraryLoaded(const trk::Library &lib);
+    void libraryUnloaded(const trk::Library &lib);
+    void registersAndCallStackReadComplete(const QList<uint>& registers, const QByteArray& stack);
 signals:
     void resume(uint pid, uint tid);
+    void stop(uint pid, uint tid);
     void terminate();
+    void getRegistersAndCallStack(uint pid, uint tid);
 public:
     TrkSignalHandler();
     ~TrkSignalHandler();
     void setLogLevel(int);
+    void setCrashLogging(bool);
+    void setCrashLogPath(QString);
 private:
     TrkSignalHandlerPrivate *d;
 };