Upgrade Hunt - day four & final

[Peter <pmc@citylink.dinoex.sub.org>]

The promised continuation...

On saturday I again buckled up to refine my profiling and identify
the cpu-hogging functions. And they came out to be
    help_echo_substitute_command_keys()
    Fwhere_is_internal()

But, looking into these functions, they are just lengthy functions
with lots of lispiness in them. Not easy to see a performace hog in
there.
So I came to the conclusion that there is no distinct performance
hog to be found, but rather some other thread would frequently
interrupt and slow things down in an evenly distributed way (which
was also a wrong conclusion, but it led back onto the right track).

So now, with all the printf inserted, lets get back to truss and
see which thread does what at what place (should have done that
earlier):

53999 103429: 8.661802081 0.000007980 sigprocmask(SIG_SETMASK,{ },0x0) = 0 (0x0)
53999 103429: 8.661850254 0.000007970 sigprocmask(SIG_BLOCK,{ SIGINT|SIGALRM },{ }) = 0 (0x0)
53999 103429: 8.661895521 0.000008179 ktimer_settime(0x3,0x1,0x8215da7c8,0x0) = 0 (0x0)
53999 103429: 8.661938691 0.000007984 sigprocmask(SIG_SETMASK,{ },0x0) = 0 (0x0)
53999 103429: 8.662007745 0.000011363 write(2,"PMc 1697366761485273: + parse_me"...,53) = 53 (0x35)
53999 103429: 8.662058629 0.000008297 write(2,"PMc 1697366761485330: + parse_me"...,43) = 43 (0x2b)
53999 103429: 8.662108232 0.000008263 write(2,"PMc 1697366761485380: + parse_me"...,43) = 43 (0x2b)
53999 103429: 8.662157594 0.000008250 write(2,"PMc 1697366761485429: + parse_me"...,43) = 43 (0x2b)
53999 103429: 8.662207699 0.000008283 write(2,"PMc 1697366761485479: + parse_me"...,43) = 43 (0x2b)
53999 103429: 8.662256946 0.000008279 write(2,"PMc 1697366761485528: + parse_me"...,45) = 45 (0x2d)
53999 103429: 8.662306245 0.000008248 write(2,"PMc 1697366761485578: + parse_me"...,45) = 45 (0x2d)
53999 103429: 8.662355398 0.000008292 write(2,"PMc 1697366761485627: + parse_me"...,45) = 45 (0x2d)
53999 103429: 8.662407964 0.000008268 sigprocmask(SIG_BLOCK,{ SIGINT|SIGALRM },{ }) = 0 (0x0)
53999 103429: 8.662456674 0.000011178 ktimer_settime(0x3,0x1,0x8215db608,0x0) = 0 (0x0)
53999 103429: 8.662500564 0.000008224 sigprocmask(SIG_SETMASK,{ },0x0) = 0 (0x0)

So here is both: my printf() and the strange ktimer/sigprocmask
loop, alternating. But: they happen in the SAME THREAD (column 2)!!
*shock* How does it do this? How does it switch context without asking
my kernel for permission first?

I started lldb again, and this time it happened to work - probably
things where now sanitized by sufficient calls to libc ;)
And in the backtrace things became clearer - this is a weirdly
fascinating construction of callbacks. In fact, the simple tasks
of displaying a menu calls into parsing the keymap definitions
(which can be user defined), which then calls into the appropriate
Lisp stuff, and then from there are backdoors that call into the
management functions (like setting timers).

And then it also became obvious why it runs that ktimer thing all the
time. I could see an occasional signal 23 (that is from the X server),
I could see signal 14 every two seconds - that is the internal timer
(and I couldn't find where these two seconds are configured, I would
have liked to slow that down, but didn't find it in atimer.[ch]), but
actually the signal processing goes on continuosely.

And that is because gobble_input() sets pending_signals = true, so
process_pending_signals() is called and sets it false again, and at
the next instant gobble_input() sets it true again.

Now to figure out what is called why in what sequence looked like
too heavy. So I went for the quick fix - this seems to affect only
GTK3, and that stuff is overcommitted anyway, so lets see how it
does without:

--- src/keyboard.c.orig 2023-06-22 13:49:11.000000000 +0200
+++ src/keyboard.c      2023-10-18 00:55:57.038605000 +0200
@@ -7415,7 +7415,9 @@
 
          if (input_blocked_p ())
            {
+#ifndef HAVE_GTK3
              pending_signals = true;
+#endif
              break;
            }

Works fine, no problems observed yet. I then started to complete
my default.el configurations and switched between some file and the
scratchbuffer hundreds of times via the menu, and, well, it works
now. That's what I wanted.


Concluding, I would say, emacs is very unfriendly to new users. All
the heavy lifting needs to take place in the beginning, when things
still work worst.