Subject: fvwm doing xsync reading almost every command

From: Dan Espen <[email-masked]>
Date: Fri, 11 Aug 2000 20:29:32 -0400

I've previously complained about fvwm taking forever to start up
when run remotely over a cable modem.  Fifteen minutes or more.

I've added debug logic that times every command executed by fvwm.
I find that commands that shouldn't take any time at all,
like "AddToFunction", take an average of 1/4 elapsed seconds.

A big chunk of that time is in WaitForButtonsUp where there are
a few X calls including calls to XSync, XAllowEvents, XQueryPointer,
XPending, etc.

I traced that 1/4 second down to functions.c ExecuteFunction() around
line 1035 where it has this:

  /* Only wait for an all-buttons-up condition after calls from
   * regular built-ins, not from complex-functions, menus or modules. */
  if(Module == -1)
    WaitForButtonsUp(True);

The condition "Module == -1" is true for just about every command.
Only blank lines and comments get away with zero measurable elapsed time.

For startup, the Module switch seems to originate in fvwm.c around line
639:

  if (num_config_commands > 0)
  {
    int i;
    for(i=0;i<num_config_commands;i++)
    {
      DoingCommandLine = True;
      ExecuteFunction(
	config_commands[i], NULL, &Event, C_ROOT, -1, EXPAND_COMMAND, NULL);
      free(config_commands[i]);
    }
    DoingCommandLine = False;
  } else {
    /* Run startup command file in 5 places: FVWM_USERDIR, FVWM_DATADIR,
       and for compatibility: ~/.fvwm2rc, $sysconfdir/system.fvwm2rc */
    if (
      !run_command_file( CatString3(fvwm_userdir, "/",       FVWMRC),
        &Event, NULL, C_ROOT, -1 ) &&
      !run_command_file( CatString3(home_dir,     "/",       FVWMRC),
        &Event, NULL, C_ROOT, -1 ) &&
      !run_command_file( CatString3(FVWM_DATADIR, "/",       FVWMRC),
        &Event, NULL, C_ROOT, -1 ) &&
      !run_command_file( CatString3(FVWM_DATADIR, "/system", FVWMRC),
        &Event, NULL, C_ROOT, -1 ) &&
      !run_command_file( CatString3(FVWM_CONFDIR, "/system", FVWMRC),
        &Event, NULL, C_ROOT, -1 ) )

All  those  "run_command_file"   and "ExecuteFunction"  commands   are
passing "-1" for the "Module" value causing all the XSync calls.  This
appears  to be the way fvwm  has worked since  at  least 2.2.  (2.2 is
also slow run this way.)

I changed all the above "-1" to another value with no obvious negative
consequences.  I don't know for sure what that does to startup time,
the first test seemed to show improvement.

I don't think thats the right fix for this.
It would seem to me, the decision about which commands need to be
XSync'd should be made based on the command, or possibly the command
and its arguments.

Any comments?

-- 
Dan Espen
444 Hoes Lane  Room RRC 1C-214             E-mail: [email-masked]
Piscataway, NJ 08854                       Phone: (732) 699-5570
--
Visit the official FVWM web page at <URL:http://www.fvwm.org/>.
To unsubscribe from the list, send "unsubscribe fvwm-workers" in the
body of a message to [email-masked].
To report problems, send mail to [email-masked]

---

From: Mikhael Goikhman <[email-masked]>
Date: Sat, 26 Aug 2000 20:41:10 +0300

> I've added debug logic that times every command executed by fvwm.

Since this logging is quite useful, can you please add #ifdef's and commit
your additions? I planned to create a 2/3 column table (start/end time in
milliseconds, command) myself, but seems that you already have this.

> like "AddToFunction", take an average of 1/4 elapsed seconds.

A really bad bug.

> XSync'd should be made based on the command, or possibly the command

I think, your fix (disallow WaitForButtonsUp for startup commands) is ok.
We grab a busy cursor during start-up commands anyway. Maybe to call
WaitForButtonsUp after that block.

Your suggestion of calling WaitForButtonsUp based on the command name
(I don't think parsing arguments is needed/possible) also can be used
to speed up the run time commands. Probably Dominik, who worked with
this function, can comment better on this suggestion after his vacation.

Regards,
Mikhael.

---

From: Dan Espen <[email-masked]>
Date: Sat, 26 Aug 2000 20:38:31 -0400

> milliseconds, command) myself, but seems that you already have this.

I originally added time, and I found it really  hard to spot big gaps.
Right now, its  printing elapsed milliseconds  from the previous debug
line.  A shortcoming of  my  implementation is  that the  elapsed time
applies  to  the previous line.   I'll  add it anyway,   I did find it
helpful.

> > like "AddToFunction", take an average of 1/4 elapsed seconds.

I'm seeing 2-3 minutes where I used to see 10 minutes.

When I get a chance, I'll clean it up and commit.