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

probonopd · 2020-11-22T21:36:32Z

When an application is launched through the launch command, then it will exit as soon as it wants to print something to stdout and/or stderr after the p.waitForFinished period has elapsed
~~No output is printed to stdout at all before the p.waitForFinished period has elapsed~~ fixed using p.setProcessChannelMode(QProcess::ForwardedChannels);
If launch Menu is used to launch the global menu bar, then it will exit if the p.waitForFinished period has elapsed and the user then selects any menu item from the System menu (but not from some other menus). Possibly because selecting commands from the System menu makes liberal use of qDebug() to print debug information to the console?
If qpdf is launched with the launch command, then it will exit after the p.waitForFinished period (when set to 3 seconds, possibly because around 3 seconds it wants to write QKqueueFileSystemWatcherEngine::addPaths: open: No such file or directory to stderr). Why? (Setting a longer p.waitForFinished period might do away with this immediate crash because then the QKqueueFileSystemWatcherEngine::addPaths: open: No such file or directory is already written to stderr?)

~~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.

The text was updated successfully, but these errors were encountered:

probonopd · 2021-01-24T10:21:17Z

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:

launch featherpad - FeatherPad opens
Wait for 10 seconds
As a regular user, open a file owned by root
Make an edit
Try to save
Featherpad should not crash (currrently it does!)

Test case 2:

launch shotcut
Wait for 10 seconds
Try to open a mlt file
Shotcut should not crash (currrently it does!)

Test case 2:

launch Menu
Wait for 10 seconds
Select commands from th System menu
Menu should not crash (currrently it does!)

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:

launch/src/main.cpp

Lines 290 to 326 in 9273d38

    
           p.setProgram(executable); 
        
           args.pop_front(); 
        
           p.setArguments(args); 
        
           QProcessEnvironment env = QProcessEnvironment::systemEnvironment(); 
        
           // env.insert("QT_SCALE_FACTOR", "2"); 
        
           p.setProcessEnvironment(env); 
        
           p.setProcessChannelMode(QProcess::ForwardedOutputChannel); // Forward standard output 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(10 * 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.setProcessChannelMode(QProcess::ForwardedChannels); // Forward standard error onto the main process as well 
        
               p.detach(); 
        
               return(0); 
        
           }

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 · 2021-01-25T18:45:09Z

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 · 2021-01-26T19:46:51Z

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:

launch testcase
Wait for 10 seconds
ps ax | grep testcase - the process is no longer running (but it should)

probonopd · 2021-01-26T19:48:26Z

...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 · 2021-01-26T20:48:43Z

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

probonopd added bug Something isn't working help wanted Extra attention is needed labels Nov 22, 2020

probonopd referenced this issue in helloSystem/ISO Nov 22, 2020

Workaround for #4

d5edb40

probonopd closed this as completed in 9273d38 Jan 10, 2021

probonopd reopened this Jan 24, 2021

probonopd mentioned this issue Jan 24, 2021

Documentation, Browser and other actions fail; Falkon missing from 0.4.0 (OD18) helloSystem/ISO#112

Closed

probonopd changed the title ~~Launched programs behave strangely and may exit after p.waitForFinished period has elapsed~~ Programs launched with 'launch' crash if they try to use stderr after X seconds Jan 26, 2021

probonopd added a commit that referenced this issue Jan 26, 2021

Temporary workaround for #4; needs to be done properly

1384d20

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

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

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

probonopd commented Nov 22, 2020 •

edited

Loading

probonopd commented Jan 24, 2021 •

edited

Loading

probonopd commented Jan 25, 2021

probonopd commented Jan 26, 2021 •

edited

Loading

probonopd commented Jan 26, 2021 •

edited

Loading

probonopd commented Jan 26, 2021 •

edited

Loading

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

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

Comments

probonopd commented Nov 22, 2020 • edited Loading

probonopd commented Jan 24, 2021 • edited Loading

probonopd commented Jan 25, 2021

probonopd commented Jan 26, 2021 • edited Loading

probonopd commented Jan 26, 2021 • edited Loading

probonopd commented Jan 26, 2021 • edited Loading

probonopd commented Nov 22, 2020 •

edited

Loading

probonopd commented Jan 24, 2021 •

edited

Loading

probonopd commented Jan 26, 2021 •

edited

Loading

probonopd commented Jan 26, 2021 •

edited

Loading

probonopd commented Jan 26, 2021 •

edited

Loading