helloSystem / launch

Command line tool to launch applications, will search for .app bundles and .AppDir directories in various directories, and will show launch errors in the GUI
BSD 2-Clause "Simplified" License
16 stars 6 forks source link

Programs launched with 'launch' crash if they try to use stderr after X seconds #4

Open probonopd opened 3 years ago

probonopd commented 3 years ago

With p.waitForFinished period set to 10 seconds, then the ping command will exit after 10 seconds, and only then show the output of the ping command fixed using p.setProcessChannelMode(QProcess::ForwardedChannels);

Once this is solved, set the time back to e.g., 3 seconds rather than 10.

probonopd commented 3 years ago

Update: Turns out that this has not been resolved entirely. I have updated the fist post above to reflect the current situation.

For a description on the intended behavior of the launch command, see its documentation.

Test case 1:

Test case 2:

Test case 2:

We need someone with a deep understanding of processes, threads, stdout, stderr, detaching, forking, exec'ing etc. to have a deep look at the code. Possibly a deeper understanding of how QProcess works (I suspect it is using threads internally?) is required, and possibly we need to replace it with a pure C/C++ solution?

Here is the code in question:

https://github.com/helloSystem/launch/blob/9273d38474b7d2f18fc0885b3649ed4487ff3a3a/src/main.cpp#L290-L326

Once the payload appliacation process gets detached, trying to write to stdout/stderr fails and leads to the crash?

Experimenting with

p.closeWriteChannel();

p.setProcessChannelMode(QProcess::SeparateChannels);
p.setStandardOutputFile("/dev/console");
p.setStandardErrorFile("/dev/stderr");

I could not get resolve this.

probonopd commented 3 years ago

Traces made like this:

sudo pkg install dtrace-toolkit
sudo kldload dtraceall
launch FeatherPad
# In another terminal: ps ax | grep featherpad
# Then use the PID of the featherpad process for the next command:
sudo dtruss -p 1886 -f

good.txt = when not launched through launch bad.txt = when launched through launch

probonopd commented 3 years ago

This is a minimal proof that the crash occurs when programs try to use qDebug() which tries to write to stderr:

#include <QCoreApplication>
#include <QTimer>
#include <qdebug.h>
#include <iostream>

int main(int argc, char *argv[])
{
    QCoreApplication a(argc, argv);

    QTimer* timer = new QTimer;
    QObject::connect(timer, &QTimer::timeout, [](){
        std::cout << "Test Stdout" << std::endl;
        // As soon as we do not comment the following line,
        // running this application through the test command
        // makes it exit/crash after 10 seconds
        qDebug() << "Test qDebug()";
    });
    timer->start(1000);

    return a.exec();
}

Test case:

probonopd commented 3 years ago

...and this is sudo truss -f launch testcase:

(...)
12317: write(1,"Test Stdout\n",12)               = 12 (0xc)
12317: write(2,"Test qDebug()\n",14)             = 14 (0xe)
12316: ppoll(0x7fffffffe3e0,0x4,0x7fffffffe370,0x0) = 1 (0x1)
12316: ioctl(12,FIONREAD,0x7fffffffe314)         = 0 (0x0)
12316: read(12,"Test qDebug()\n",14)             = 14 (0xe)
12316: ppoll(0x7fffffffe3e0,0x4,0x7fffffffe370,0x0) = 0 (0x0)
12316: write(7,"\^A",1)                          = 1 (0x1)
12316: write(7,"\^A",1)                          = 1 (0x1)
12316: close(12)                                 = 0 (0x0)
12316: close(9)                                  = 0 (0x0)
12316: close(16)                                 = 0 (0x0)
12316: poll({ 3/POLLIN|POLLOUT },1,-1)           = 1 (0x1)
12316: writev(3,[{"\^A\0\b\0\^E\0\M-@\^A/\^A\0\0\0"...,84}],1) = 84 (0x54)
12316: poll({ 3/POLLIN },1,-1)                   = 1 (0x1)
12316: recvmsg(3,{NULL,0,[{"\M-! \M^Q\^A\^E\0\M-@\^A\M-A\^A"...,4096}],1,{},0,0},0) = 32 (0x20)
12316: close(4)                                  = 0 (0x0)
12316: close(5)                                  = 0 (0x0)
12316: _umtx_op(0x802a861b8,UMTX_OP_NWAKE_PRIVATE,0x1,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bec20,UMTX_OP_WAIT_UINT_PRIVATE,0x0,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_UNLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_WRLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: openat(AT_FDCWD,"/lib/libgcc_s.so.1",O_RDONLY|O_CLOEXEC|O_VERIFY,00) = 4 (0x4)
12316: fstat(4,{ mode=-r--r--r-- ,inode=162989,size=102600,blksize=102912 }) = 0 (0x0)
12316: close(4)                                  = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_UNLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_RDLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_UNLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_WRLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_UNLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_RDLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_WRLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_UNLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_RDLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_UNLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_WRLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_UNLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_RDLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_UNLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_WRLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_UNLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_RDLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_UNLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_WRLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_UNLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: _umtx_op(0x8003bf200,UMTX_OP_RW_WRLOCK,0x0,0x0,0x0) = 0 (0x0)
12316: poll({ 3/POLLIN|POLLOUT },1,-1)           = 1 (0x1)
12316: writev(3,[{".\0\^B\0\^C\0\M-@\^A",8}],1)  = 8 (0x8)
12316: poll({ 3/POLLIN|POLLOUT },1,-1)           = 1 (0x1)
12316: writev(3,[{"<\0\^B\0\0\0\M-@\^A+\0\^A\0",12},{0x0,0},{0x802523cfa,0}],3) = 12 (0xc)
12316: poll({ 3/POLLIN },1,-1)                   = 1 (0x1)
12316: recvmsg(3,{NULL,0,[{"\^A\^A\M^U\^A\0\0\0\0\^F\0`\^B\0"...,4096}],1,{},0,0},0) = 32 (0x20)
12316: shutdown(3,SHUT_RDWR)                     = 0 (0x0)
12316: close(3)                                  = 0 (0x0)
12316: <thread 100788 exited>
12316: munmap(0x805078000,57344)                 = 0 (0x0)
12316: munmap(0x805086000,53248)                 = 0 (0x0)
12316: exit(0x0)
12316: process exit, rval = 0
12317: poll({ 3/POLLIN },1,996)                  = 0 (0x0)
Test Stdout
12317: write(1,"Test Stdout\n",12)               = 12 (0xc)
12317: write(2,"Test qDebug()\n",14)             ERR#32 'Broken pipe'
12317: SIGNAL 13 (SIGPIPE) code=SI_KERNEL
12317: process killed, signal = 13

12316 is launch, 12317 is testcase. 12316 exits (as it should), but then 12317 receives SIGNAL 13 as soon as it tries to write(2,"Test qDebug()\n",14).

How can I fix this in launch?

Full log (another run, so different PIDs): log.txt

probonopd commented 3 years ago

If we do this then we don't crash but we can't display the error in the GUI because it gets printed to stderr:

    p.setProgram(executable);
    args.pop_front();
    p.setArguments(args);
    QProcessEnvironment env = QProcessEnvironment::systemEnvironment();

    p.setProcessEnvironment(env);

    p.setProcessChannelMode(QProcess::ForwardedChannels); // Forward both channels onto the main process

    p.start();

    // Blocks until process has started
    if (!p.waitForStarted()) {
        QMessageBox::warning( nullptr, firstArg, "Could not launch\n" + firstArg );
        return(1);
    }

    // TODO: Now would be a good time to signal the Dock to start showing a bouncing the icon of the
    // application that is being launched, until the application has its own icon in the Dock

    p.waitForFinished(3 * 1000); // Blocks until process has finished or timeout occured (x seconds)
    // Errors occuring thereafter will not be reported to the user in a message box anymore.
    // This should cover most errors like missing libraries, missing interpreters, etc.

    if (p.state() == 0 and p.exitCode() != 0) {
        qDebug("Process is not running anymore and exit code was not 0");

        const QString error = p.readAllStandardError();
        if (!error.isEmpty()) {
            qDebug() << error;
            handleError(&p, error);
            return(p.exitCode());
        }
    } else {
        p.detach();
        return(0);
    }

    return(1);

setProcessChannelMode works only before p.start(). So that is a problem...

Is there a way to "duplicate" stderr, so that during the first X seconds we can print it on the console but also can somehow intercept/access it (e.g., using p.readAllStandardError(); or some other method) to show a text in an error message?

Something along those lines ("named pipe") may be needed? http://blog.debao.me/2013/07/redirect-current-processs-stdout-to-a-widget-such-as-qtextedit/

This seems to talk about a similar challenge but it is way over my head: https://stackoverflow.com/questions/44023742/redirect-stdout-stderr-using-dup2-then-resinstate-later