LablGTK app maxes out CPU

LablGTK app maxes out CPU

[Matt Gushee]

[I posted this to the LablGTK list last week, but have not received any
  responses, so here it is ...]

Hello all,

I have a program that I am developing in LablGTK, which has a 'daemon 
mode' such that the app runs in the background without displaying the 
GUI until the user 'starts' it--which in practice means waking it up; 
then when the user 'quits', it really means just hiding the GUI and 
waiting for the next invocation.

Commands are passed to the daemon by means of a named pipe, and 
GMain.Io.add_watch is used to cause the daemon to read the pipe (code 
below). Now, I thought this would prevent the app from monopolizing the 
CPU, but apparently it does not. When the app is started but before the 
GUI is displayed for the first time, CPU usage is negligible, but as 
soon as the GUI is displayed, the app starts using all available CPU 
time, and it continues to do so as long as it runs, whether the GUI is 
displayed or not. So I wonder if there's something more I need to do to 
keep the app well-behaved (BTW, it should never require much CPU time. 
It's a lightweight file manager, and is graphical only in the sense that 
it is a GUI app--it uses no icons or other images).

Here's the relevant code:

     method daemon_setup () =
       self#int_add_panel ~go:true ();
       is_daemon <- true;
       msg_pipe <- Filename.concat Util.temp_user_dir "message.pipe";
       if not (Sys.file_exists Util.temp_user_dir) then
         Unix.mkdir Util.temp_user_dir 0o755
       else if Sys.file_exists msg_pipe then
         Unix.unlink msg_pipe;
       Unix.mkfifo msg_pipe 0o600;
       msg_fd <-
         (* Unix.openfile msg_pipe [Unix.O_RDONLY; Unix.O_NONBLOCK] 
0o600; *)
         Unix.openfile msg_pipe [Unix.O_RDONLY] 0o600;
       let chan = GMain.Io.channel_of_descr msg_fd in
       let watcher _ =
         let cmdbuf = Buffer.create 4
         and temp = " " in
         let rec read_input ready =
           let nchars = GMain.Io.read chan ~buf:temp ~pos:0 ~len:1 in
           if nchars = 0 then ()
           else
             match temp with
             | "%" -> read_input true
             | "\n" -> read_input false
             | s when ready -> (Buffer.add_string cmdbuf s; read_input true)
             | _ -> read_input false
         and do_command cmdstring =
           match cmdstring with
           | "show" -> self#show ()
           | "hide" -> self#hide ()
           | "quit" -> self#really_quit ()
           | "hup" -> self#hup ()
           | cs -> self#warn ("Unknown command: " ^ cs) in
         read_input false;
         do_command (Buffer.contents cmdbuf);
         true in
       ignore (GMain.Io.add_watch ~cond:[`IN] ~callback:watcher chan)


Any suggestions?

-- 
Matt Gushee
: Bantam - lightweight file manager : matt.gushee.net/software/bantam/ :
: RASCL's A Simple Configuration Language :     matt.gushee.net/rascl/ :

Re: [Caml-list] LablGTK app maxes out CPU

[Matt Gushee]

Matt Gushee wrote:

 > GMain.Io.add_watch is used to cause the daemon to read the pipe (code
 > below). Now, I thought this would prevent the app from monopolizing
 > the CPU, but apparently it does not. When the app is started but
 > before the GUI is displayed for the first time, CPU usage is
 > negligible, but as soon as the GUI is displayed, the app starts using
 > all available CPU time,

Oh, wait. I now remember that GMain.Io.add_watch has the optional ?prio 
argument. Would setting the watch function to a low priority help? If 
so, what would be a reasonable value?

-- 
Matt Gushee
: Bantam - lightweight file manager : matt.gushee.net/software/bantam/ :
: RASCL's A Simple Configuration Language :     matt.gushee.net/rascl/ :

Re: [Caml-list] LablGTK app maxes out CPU

[Eric Cooper]

On Tue, Jul 04, 2006 at 12:30:11PM -0600, Matt Gushee wrote:
> [...]
> When the app is started but before the 
> GUI is displayed for the first time, CPU usage is negligible, but as 
> soon as the GUI is displayed, the app starts using all available CPU 
> time, and it continues to do so as long as it runs, whether the GUI is 
> displayed or not. So I wonder if there's something more I need to do to 
> keep the app well-behaved (BTW, it should never require much CPU time. 
> It's a lightweight file manager, and is graphical only in the sense that 
> it is a GUI app--it uses no icons or other images).

Try making the fd nonblocking before you create the glib channel:
    Unix.set_nonblock msg_fd;

-- 
Eric Cooper             e c c @ c m u . e d u

Re: [Caml-list] LablGTK app maxes out CPU

[Matt Gushee]

Eric Cooper wrote:
> On Tue, Jul 04, 2006 at 12:30:11PM -0600, Matt Gushee wrote:
>> [...]
>> When the app is started but before the 
>> GUI is displayed for the first time, CPU usage is negligible, but as 
>> soon as the GUI is displayed, the app starts using all available CPU 
>> time, and it continues to do so as long as it runs, whether the GUI is 
>> displayed or not. So I wonder if there's something more I need to do to 
>> keep the app well-behaved (BTW, it should never require much CPU time. 
>> It's a lightweight file manager, and is graphical only in the sense that 
>> it is a GUI app--it uses no icons or other images).
> 
> Try making the fd nonblocking before you create the glib channel:
>     Unix.set_nonblock msg_fd;

That's how it was originally. But if you look again at my code, you can 
see that the version with Unix.O_NONBLOCK is commented out. That's 
because on one of my machines (the one with a newer version of GTK and 
LablGTK, I believe), I got exceptions every time the program tried to 
read the input. I don't fully understand why, but making the channel 
non-non-blocking eliminated the errors. It doesn't make sense to 
me--based on my limited knowledge of how POSIX I/O works, the channel 
really *should* be non-blocking. But I have no idea what kind of magic 
Glib is doing behind the scenes.

-- 
Matt Gushee
: Bantam - lightweight file manager : matt.gushee.net/software/bantam/ :
: RASCL's A Simple Configuration Language :     matt.gushee.net/rascl/ :

Re: [Caml-list] LablGTK app maxes out CPU

[Eric Cooper]

On Tue, Jul 04, 2006 at 02:00:46PM -0600, Matt Gushee wrote:
> Eric Cooper wrote:
> >Try making the fd nonblocking before you create the glib channel:
> >    Unix.set_nonblock msg_fd;
> 
> That's how it was originally. But if you look again at my code, you can 
> see that the version with Unix.O_NONBLOCK is commented out. That's 
> because on one of my machines (the one with a newer version of GTK and 
> LablGTK, I believe), I got exceptions every time the program tried to 
> read the input.

Right, me too.  I use code like this to read from the channel inside
the watcher:

let try_read chan ~buf ~pos ~len =
  try Some (Glib.Io.read chan ~buf ~pos ~len)
  with Glib.GError "g_io_channel_read: G_IO_ERROR_AGAIN" -> None

-- 
Eric Cooper             e c c @ c m u . e d u

Re: [Caml-list] LablGTK app maxes out CPU

[Matt Gushee]

Eric Cooper wrote:

 >> That's how it was originally. But if you look again at my code, you 
can see that the version with Unix.O_NONBLOCK is commented out. That's 
because on one of my machines (the one with a newer version of GTK and 
LablGTK, I believe), I got exceptions every time the program tried to 
read the input.
 >
 > Right, me too.  I use code like this to read from the channel inside
 > the watcher:
 >
 > let try_read chan ~buf ~pos ~len =
 >   try Some (Glib.Io.read chan ~buf ~pos ~len)
 >   with Glib.GError "g_io_channel_read: G_IO_ERROR_AGAIN" -> None

Thanks for the tip. This does indeed eliminate the errors with a 
non-blocking channel. But I still get excessive CPU usage. I have also 
tried setting the priority on add_watch (both `DEFAULT_IDLE and `LOW). 
Nothing seems to make any difference. It's true that my app does allow 
other programs to grab a significant amount of CPU time when they need 
it. But when my app is idle and not much else is running, 'top' shows it 
using over 90% of the CPU. That's certainly not normal, and I would 
think very undesirable.

A 'sleep' call might help, but the standard Unix.sleep only accepts 
1-second increments, which is undesirable. But I can try a wrapper for 
usleep() ... unless someone has a better idea.

-- 
Matt Gushee
: Bantam - lightweight file manager : matt.gushee.net/software/bantam/ :
: RASCL's A Simple Configuration Language :     matt.gushee.net/rascl/ :

Re: [Caml-list] LablGTK app maxes out CPU

[Matt Gushee]

malc wrote:

>> A 'sleep' call might help, but the standard Unix.sleep only accepts 
>> 1-second increments, which is undesirable. But I can try a wrapper for 
>> usleep() ... unless someone has a better idea.
> 
> Disregarding the fact that one should go for a "real" solution,
> Unix.select [] [] [] subsecond_timeout is a "portable" way to
> do this.

Well, that's clever! Thanks for the kludge :-)

-- 
Matt Gushee
: Bantam - lightweight file manager : matt.gushee.net/software/bantam/ :
: RASCL's A Simple Configuration Language :     matt.gushee.net/rascl/ :

Re: [Caml-list] LablGTK app maxes out CPU

[Matt Gushee]

Matt Gushee wrote:

> Nothing seems to make any difference. It's true that my app does allow 
> other programs to grab a significant amount of CPU time when they need 
> it. But when my app is idle and not much else is running, 'top' shows it 
> using over 90% of the CPU. That's certainly not normal, and I would 
> think very undesirable.
> 
> A 'sleep' call might help, but the standard Unix.sleep only accepts 
> 1-second increments, which is undesirable. But I can try a wrapper for 
> usleep() ... unless someone has a better idea.

Argh! This is getting really frustrating ...

I added a custom sleep function, and called it to sleep for 0.3 seconds 
whenever there is no input to read. That should hugely reduce the 
frequency of attempts to read the FIFO, while not introducing much of a 
delay in response to commands. I tried both implementations, by the way: 
both the usleep wrapper and the Unix.select hack.

It doesn't make any difference.

BTW, I did check the app in non-daemon mode, and CPU usage is quite 
modest, as I would expect. And the only real difference between normal 
and daemon mode is this Io watching thing.

-- 
Matt Gushee
: Bantam - lightweight file manager : matt.gushee.net/software/bantam/ :
: RASCL's A Simple Configuration Language :     matt.gushee.net/rascl/ :

Re: [Caml-list] LablGTK app maxes out CPU

[Jerome Vouillon]

On Wed, Jul 05, 2006 at 05:24:54PM -0600, Matt Gushee wrote:
[...]
> Thanks for the tip. This does indeed eliminate the errors with a 
> non-blocking channel. But I still get excessive CPU usage. I have also 
> tried setting the priority on add_watch (both `DEFAULT_IDLE and `LOW). 
> Nothing seems to make any difference. It's true that my app does allow 
> other programs to grab a significant amount of CPU time when they need 
> it. But when my app is idle and not much else is running, 'top' shows it 
> using over 90% of the CPU. That's certainly not normal, and I would 
> think very undesirable.

You should try to run your program with the strace program, which
traces system calls.  This will tell you why your program runs
continuously rather than waiting for I/Os.

-- Jerome

Re: [Caml-list] LablGTK app maxes out CPU

[Matt Gushee]

Jerome Vouillon wrote:

> You should try to run your program with the strace program, which
> traces system calls.  This will tell you why your program runs
> continuously rather than waiting for I/Os.

Yes, if I know what to look for. I've used strace numerous times, but 
haven't often been able to interpret the output. Any suggestions about that?

-- 
Matt Gushee
: Bantam - lightweight file manager : matt.gushee.net/software/bantam/ :
: RASCL's A Simple Configuration Language :     matt.gushee.net/rascl/ :

Re: [Caml-list] LablGTK app maxes out CPU

[Matt Gushee]

Jerome Vouillon wrote:

> You should try to run your program with the strace program, which
> traces system calls.  This will tell you why your program runs
> continuously rather than waiting for I/Os.

Okay, I've done the strace. I found something that appears to be 
significant, but I don't really understand it. After the GUI is 
displayed, there are a number of GTK library calls, and then some 
searches for various resources--locale files, fonts, icons--and then this:

poll([{fd=3, events=POLLIN}], 1, 0)     = 0
write(3, "\1\30\r\0\3\0\340\0D\0\0\0\0\0\0\0\251\0\244\1\0\0\1\0"..., 
2132) = 2132
ioctl(3, FIONREAD, [1184])              = 0
read(3, "\34\317N\0\3\0\340\0\31\1\0\0\376\331]E\0\330]Ex\202\37"..., 
1184) = 1184
poll([{fd=3, events=POLLIN}], 1, 0)     = 0
poll([{fd=3, events=POLLIN}], 1, 0)     = 0
poll([{fd=3, events=POLLIN}], 1, 0)     = 0
poll([{fd=3, events=POLLIN}], 1, 0)     = 0
poll([{fd=3, events=POLLIN}], 1, 0)     = 0
poll([{fd=3, events=POLLIN}], 1, 0)     = 0
poll([{fd=3, events=POLLIN}], 1, 0)     = 0
poll([{fd=3, events=POLLIN}], 1, 0)     = 0
poll([{fd=3, events=POLLIN}], 1, 0)     = 0
ioctl(3, FIONREAD, [0])                 = 0
poll([{fd=3, events=POLLIN}], 1, 0)     = 0
ioctl(3, FIONREAD, [0])                 = 0
poll([{fd=3, events=POLLIN}], 1, 0)     = 0
write(3, "5\30\4\0&\0\340\0\36\0\340\0\245\0\20\0\230\4\5\0\'\0\340"..., 
13780) = 13780
ioctl(3, FIONREAD, [0])                 = 0
poll([{fd=3, events=POLLIN}], 1, 0)     = 0
ioctl(3, FIONREAD, [0])                 = 0
poll([{fd=3, events=POLLIN}, {fd=7, events=POLLIN, revents=POLLHUP}], 2, 
-1) = 1

The last two lines are then repeated around 18000 times (identically 
each time, as far as I can see), until the 'quit' command is received. 
This takes place over a span of perhaps 30 seconds of real time. So 
pretty clearly this is the CPU-eating behavior, but I still can't see 
what is triggering it. By the way, FD #7 is my FIFO.

Well, based on the above, I tried adding a second watch function:

   let hup_watcher _ = Util.sleep 0.25; true in
   (* ... unrelated code omitted ... *)
   ignore (GMain.Io.add_watch ~cond:[`HUP] ~callback:hup_watcher chan)

Finally, this produces a change in behavior--but not quite what I need. 
CPU usage is under control, but now the GUI fails to display completely: 
the main window appears, with the outine of the TreeView widget it is 
supposed to have, but the contents are never displayed.

-- 
Matt Gushee
: Bantam - lightweight file manager : matt.gushee.net/software/bantam/ :
: RASCL's A Simple Configuration Language :     matt.gushee.net/rascl/ :

SOLVED -- Re: [Caml-list] LablGTK app maxes out CPU

[Matt Gushee]

Matt Gushee wrote:

> Well, based on the above, I tried adding a second watch function:
> 
>   let hup_watcher _ = Util.sleep 0.25; true in
>   (* ... unrelated code omitted ... *)
>   ignore (GMain.Io.add_watch ~cond:[`HUP] ~callback:hup_watcher chan)
> 
> Finally, this produces a change in behavior--but not quite what I need. 
> CPU usage is under control, but now the GUI fails to display completely: 
> the main window appears, with the outine of the TreeView widget it is 
> supposed to have, but the contents are never displayed.

I was on the right track with the above--I just needed to set the 
hup_watcher to a lower priority, e.g.

   let low_priority = Glib.int_of_priority `LOW in
   ....
   ignore (GMain.Io.add_watch ~prio:low_priority ~cond:[`HUP]
     ~callback:hup_watcher chan)

I'm not sure whether `LOW or `DEFAULT_IDLE is best, but both seem to 
produce good results.

Many thanks to those who helped.

-- 
Matt Gushee
: Bantam - lightweight file manager : matt.gushee.net/software/bantam/ :
: RASCL's A Simple Configuration Language :     matt.gushee.net/rascl/ :

Re: [Caml-list] LablGTK app maxes out CPU

[Jerome Vouillon]

On Thu, Jul 06, 2006 at 05:51:05PM -0600, Matt Gushee wrote:
> Okay, I've done the strace. I found something that appears to be 
> significant, but I don't really understand it. After the GUI is 
> displayed, there are a number of GTK library calls, and then some 
> searches for various resources--locale files, fonts, icons--and then this:
[...]
> poll([{fd=3, events=POLLIN}, {fd=7, events=POLLIN, revents=POLLHUP}], 2, 
> -1) = 1
> 
> The last two lines are then repeated around 18000 times (identically 
> each time, as far as I can see), until the 'quit' command is received. 
> This takes place over a span of perhaps 30 seconds of real time. So 
> pretty clearly this is the CPU-eating behavior, but I still can't see 
> what is triggering it. By the way, FD #7 is my FIFO.

The POLLHUP events means that the other side of the FIFO has been
closed.  Thus, you should stop listening on the FIFO.  To be portable,
you should also stop listening when you receive a POLLIN event but
there is nothing to be read.  (Mac OS, for instance, returns POLLIN
when Linux would return POLLHUP.)

-- Jerome