Re: Reworked qt terminal is much faster – and fails to work on Mac

[sfeam <sf...@us...>]

On Sunday, 09 February 2014 12:29:34 PM Mojca Miklavec wrote:
> On Sun, Feb 9, 2014 at 12:11 PM, Mojca Miklavec wrote:
> > On Sun, Feb 9, 2014 at 1:19 AM, sfeam wrote:
> >> On Sunday, 09 February 2014 01:01:20 AM Mojca Miklavec wrote:
> >>> > Another possible test:
> >>> > Change the timeout value on line 259 from
> >>> >                qt->socket.waitForConnected(200);
> >>> > to
> >>> >                qt->socket.waitForConnected(-1);
> >>> >
> >>> > This could potentially cause gnuplot to hang, but it also might work
> >>>
> >>> Gnuplot runs at 99% CPU with or without that change (just gnuplot,

That makes very little sense to me, but see below.

> >>> gnuplot_qt doesn't consume any CPU at a
> >> gnuplot is spinning CPU cycles while waiting for a timeout?
> >> The OSX implementation must really suck.
> >> Anyhow if you can see the gnuplot_qt process but the waitForConnected
> >> fails to return that's probably a huge clue to what's gone wrong.
> >> Let me think about this for a while.
> >>
> >> I'm cc-ing Jérôme Lodewyck.  Maybe he can decipher the clue.
> >
> > I don't know if that's a clue or not, but if I run gdb and manually
> > press "n", only a single gnuplot_qt is started and gnuplot actually
> > returns to the console (if I simply run gnuplot, it runs at 99% CPU
> > "forever"). The first "plot sin(x)" doesn't show anything, but when I
> > plot something for the second time, the plot is actually shown.
> >
> > So maybe there's just a problem of wrong
> > timing/synchronisation/initialisation somewhere after all.
> >
> > The fact is that if I actually get to this point (by manually stepping
> > inside gdb), it works a lot better than it did with forking:
> > - printing doesn't crash
> > - there is no need for the dirty hack removeDockIcon()
> >   TransformProcessType(&psn, kProcessTransformToBackgroundApplication);
> >   to hide the nofunctional window


> According to a gdb a lot of that "infinite cycling" (when not properly
> connected) happens with
> 
> while (!receivedFontPropos)
>     qt->socket.waitForReadyRead(1000);
>     while (qt->socket.bytesAvailable() >= (int)sizeof(gp_event_t))
> }

It should not be possible for that while {} construction to gobble CPU.
It only wakes up and checks the socket once per second.
Unless (which I'm beginning to suspect) all the 1000 msec timeouts
are acting as NOOPs on OSX.  Could it really be that Qt on OSX 
doesn't implement event-driven waits? 

> And indeed if I change the timeout:
> 
> --- a/src/qtterminal/qt_term.cpp
> +++ b/src/qtterminal/qt_term.cpp
> @@ -251,7 +252,7
> 
>         // The QLocalSocket::waitForConnected does not respect the
> time out argument when the
>         // gnuplot_qt application is not yet started. To wait for it,
> we need to implement the timeout ourselves
> -       QDateTime timeout = QDateTime::currentDateTime().addMSecs(1000);
> +       QDateTime timeout = QDateTime::currentDateTime().addMSecs(10000);
>         do
>         {
>                 qt->socket.connectToServer(server);
> 
> it suddenly almost starts working. I'm saying almost because the first
> plot doesn't work, but the second one does.

Hence my suspicion that timeouts < 1000msec are not working.
I suggest you do a global search and replace for timeouts and make
sure they are all >1000 msec.

 
> Terminal type set to 'qt'
> gnuplot> plot sin(x) # nothing can be seen
> started detached process  "qtgnuplot31706"
> gnuplot> plot cos(x) # works
> gnuplot>
> 
> It seems that gnuplot gives up too quickly. And if it does give up,
> the second attempt to connect doesn't work properly, ends up with two
> instances of gnuplot_qt running (none of them gets closed etc).
> 
> The following is "sampling" of the running gnuplot at 99% CPU:
> 
> Call graph:
>     2510 Thread_2393718   DispatchQueue_1: com.apple.main-thread  (serial)
>     + 2510 start  (in gnuplot) + 52  [0x100011244]
>     +   2510 main  (in gnuplot) + 2796  [0x1000aa62c]  plot.c:672
>     +     2510 com_line  (in gnuplot) + 144  [0x100025140]  command.c:323
>     +       2510 do_line  (in gnuplot) + 1066  [0x10002559a]  command.c:411
>     +         2510 command  (in gnuplot) + 131  [0x100026283]  command.c:616
>     +           2510 plot_command  (in gnuplot) + 206  [0x100028d1e]
> command.c:1559
>     +             2510 plotrequest  (in gnuplot) + 1763  [0x1000abf83]
>  plot2d.c:273
>     +               2510 eval_plots  (in gnuplot) + 27828
> [0x1000c00c4]  plot2d.c:3259
>     +                 2510 do_plot  (in gnuplot) + 131  [0x100062843]
> graphics.c:517
>     +                   2510 term_start_plot  (in gnuplot) + 63
> [0x10011476f]  term.c:557
>     +                     2510 qt_graphics  (in gnuplot) + 669
> [0x1001da68d]  qt_term.cpp:480
>     +                       1582 qt_sendFont()  (in gnuplot) + 772
> [0x1001da264]  qt_term.cpp:424
>     +                       ! 962 QLocalSocket::bytesAvailable() const
>  (in QtNetwork) + 42  [0x1022520fa]
>     +                       ! : 646 QAbstractSocket::bytesAvailable()
> const  (in QtNetwork) + 16  [0x102245210]
>     +                       ! : | 646 QIODevice::bytesAvailable()
> const  (in QtCore) + 0,20,...  [0x1030389a0,0x1030389b4,...]
>     +                       ! : 248 QAbstractSocket::bytesAvailable()
> const  (in QtNetwork) + 0,16,...  [0x102245200,0x102245210,...]
>     +                       ! : 68
> DYLD-STUB$$QIODevice::bytesAvailable() const  (in QtNetwork) + 0
> [0x10226ca8a]
>     +                       ! 295 QLocalSocket::bytesAvailable() const
>  (in QtNetwork) + 16  [0x1022520e0]
>     +                       ! : 295 QIODevice::bytesAvailable() const
> (in QtCore) + 0,85,...  [0x1030389a0,0x1030389f5,...]
>     +                       ! 236 QLocalSocket::bytesAvailable() const
>  (in QtNetwork) + 6,16,...  [0x1022520d6,0x1022520e0,...]
>     +                       ! 89
> DYLD-STUB$$QIODevice::bytesAvailable() const  (in QtNetwork) + 0
> [0x10226ca8a]
>     +                       342 qt_sendFont()  (in gnuplot) + 737
> [0x1001da241]  qt_term.cpp:423
>     +                       ! 195 QLocalSocket::waitForReadyRead(int)
> (in QtNetwork) + 6,51,...  [0x1022526c6,0x1022526f3,...]
>     +                       ! 147 QLocalSocket::waitForReadyRead(int)
> (in QtNetwork) + 18  [0x1022526d2]
>     +                       !   147 QLocalSocket::state() const  (in
> QtNetwork) + 0,8  [0x10224aed0,0x10224aed8]
>     +                       180 qt_sendFont()  (in gnuplot) +
> 748,772,...  [0x1001da24c,0x1001da264,...]  qt_term.cpp:424
>     +                       118 qt_sendFont()  (in gnuplot) +
> 737,713,...  [0x1001da241,0x1001da229,...]  qt_term.cpp:423
>     +                       110
> DYLD-STUB$$QLocalSocket::waitForReadyRead(int)  (in gnuplot) + 0
> [0x1001e38b6]
>     +                       97
> DYLD-STUB$$QLocalSocket::bytesAvailable() const  (in gnuplot) + 0
> [0x1001e38ec]
>     +                       47 qt_sendFont()  (in gnuplot) + 695
> [0x1001da217]  qt_term.cpp:421
>     +                       34 qt_sendFont()  (in gnuplot) + 999
> [0x1001da347]  qt_term.cpp:437
>     2510 Thread_2393731   DispatchQueue_2:
> com.apple.libdispatch-manager  (serial)
>     + 2510 _dispatch_mgr_thread  (in libdispatch.dylib) + 54  [0x7fff8c328316]
>     +   2510 _dispatch_mgr_invoke  (in libdispatch.dylib) + 923
> [0x7fff8c329786]
>     +     2510 kevent  (in libsystem_kernel.dylib) + 10  [0x7fff8b5e27e6]
>     2510 Thread_2393735: QProcessManager
>       2510 thread_start  (in libsystem_c.dylib) + 13  [0x7fff89671b75]
>         2510 _pthread_start  (in libsystem_c.dylib) + 335  [0x7fff8966e8bf]
>           2510 QThreadPrivate::start(void*)  (in QtCore) + 504  [0x102fad238]
>             2510 QProcessManager::run()  (in QtCore) + 168  [0x10307d7b8]
>               2510 __select  (in libsystem_kernel.dylib) + 10  [0x7fff8b5e1df2]
> 
> Total number in stack (recursive counted multiple, when >=5):
> 
> Sort by top of stack, same collapsed (when >= 5):
>         __select  (in libsystem_kernel.dylib)        2510
>         kevent  (in libsystem_kernel.dylib)        2510
>         QIODevice::bytesAvailable() const  (in QtCore)        941
>         qt_sendFont()  (in gnuplot)        379
>         QAbstractSocket::bytesAvailable() const  (in QtNetwork)        248
>         QLocalSocket::bytesAvailable() const  (in QtNetwork)        236
>         QLocalSocket::waitForReadyRead(int)  (in QtNetwork)        195
>         DYLD-STUB$$QIODevice::bytesAvailable() const  (in QtNetwork)        157
>         QLocalSocket::state() const  (in QtNetwork)        147
>         DYLD-STUB$$QLocalSocket::waitForReadyRead(int)  (in gnuplot)        110
>         DYLD-STUB$$QLocalSocket::bytesAvailable() const  (in gnuplot)        97
> 
> Mojca

Finally a trace that makes sense in that it involves a recent change.
This bit belongs to the patch:

2014-01-26  Jérôme Lodewyck  <lod...@us...>

        * src/qtterminal/qt_term.cpp: Implement font metric caching. This solves
        a flickering issue when a large number of font changes are called (for
        example when rotating the world plot in world2.dem).

        * src/qtterminal/QtGnuplotInstance.*: New public function that sends a
        command to gnuplot and blocks until it receives the answer.

Can you back out just that one set of changes from current CVS and see
if that makes your qt terminal work?  If it doesn't, then add in the larger
timeouts and check again.   We can probably make this font-related stuff
work, but first let's try to disentangle it from any fork+exec+sync timing
problems.

	Ethan