text_replace needs more time

[dsa-t]

On WSL2. saving the image in 3D viewer mostly doesn't work with my file path of length 115.

When looking at the VNC, it seemed like not enough time is given in text_replace for typing before pressing Enter key.

This is how I fixed it (xdotool doesn't seem to support something like --sync for keyboard):

ui_automation.py:

#         raise


def text_replace(string):
    """ Used to replace a text in an input text widget. """
    xdotool(['key', 'ctrl+a', 'type', string])
+   # The default delay between characters in xdotool is 12ms, add extra 300ms for safety.
+   time.sleep(len(string) * 0.012 + 0.3)


def clipboard_retrieve():

[dsa-t]

Now, I'm trying to generate 4096x4096 images and these delays aren't enough.

The file save dialog pops up early, while the image is still updating on the background (this is OpenGL rendering)

[set-soft]

I tried xdotool key --delay 500 H o l a on my system and it was synchronous. The command sent Hola and then finished.

I also tried: xdotool key --delay 500 H type --delay 500 o l a

I think this more related to the dialog needing to do something before we can send Return, not related to the length of the text. With 115 chars you are adding a 1.68 s delay, which looks too much for me. Can you check that a small delay, lets say 100 ms, is enough for the dialog to settle down?

Now about the 4kx4k image, this is huge ... I assume you are not using ray tracing because you mention OpenGL rendering, in this case we can't detect when KiCad finished. But you can always play with the time-out scale. The main problem is that KiCad developers doesn't seem to care about GUI automation, they don't use automatic regression tests, users are their testers. Every time I suggested to add something that a script could detect as an "end of task" they refused it because their focus is in interactive use. So we have a compromise between waiting too much, more reliable, but all users are impacted, and waiting an average time. People needing more time (huge projects, slow machines, etc.) can adjust the delay scale.

The 3D render is a case where no fix delay can be used. Times can range from ms to minutes. In the case of the ray tracing, where you can get really huge rendering times, we tried to implement a detection based on the CPU load. Is experimental, but seems to work, KiCad loads all CPUs to 100% during ray tracing. But this detection will fail if other process is also taking a lot of CPU.

[dsa-t]

Right, I think the system is too busy rendering the image to process key inputs so sometimes just the first characters appear.

How about extending the CPU load method to also work with OpenGL rendering? That seems to work. I doubt there will be such a CPU hogger as to leave just 5% to pcbnew.
And an OpenGL analogue of wait_rt could be added, as time scale is very broad.

The patch seems not to be necessary if we wait as above.

[dsa-t]

When trying to render with GALLIUM_DRIVER=softpipe, now I have an issue with the file dialog.

After waiting for CPU to settle down (that was about 4 minutes), the script tries to press Alt+F, Return, it does that 8 times every 3 seconds before the dialog finally opens.
Now, I'm waiting at "Wait for the image file creation" point (before pressing the Return for "Save"), but in the dialog there's only a couple of first characters entered (/mnt) and there's another dialog saying 'A file named "mn" already exists. Do you want to replace it?'

Seems like these Alt+F, Return presses leaked into the file dialog.

I guess I could increase the time scale to 10-15 here:

    logger.info('Saving the image')
    for retry in range(10):
        xdotool(['key', 'alt+f', 'Return'], id)
        found = True
        try:
            wait_for_window('File save dialog', '3D Image File Name', 3)
        except RuntimeError:  # pragma: no cover
            found = False
        if found:
            break

But I think it shouldn't hurt to increase this timeout (to 1 minute?).

---

Waiting for file also times out with softpipe and default time scale:

def wait_for_file_created_by_process(pid, file):
    global time_out_scale
    timeout = 15*time_out_scale
    process = psutil.Process(pid)
    DELAY = 0.2
    logger.debug('Waiting for file %s (pid %d) (timeout: %f)', file, pid, timeout)

[dsa-t]

So, in that case, approximately, waiting for dialog took 20.6 seconds.
Waiting for file took 52.6 seconds

I would want to avoid increasing the time scale to more than 2-3, at to not add additional delays elsewhere.

[set-soft]

Hi @dsa-t !

So, in that case, approximately, waiting for dialog took 20.6 seconds.

This shouldn't be necesary if we detect the end of the render, right? (added by 8b4649d)

Waiting for file took 52.6 seconds

The 4c1ad48 patch adds anothe 45 seconds (60 in total) if the file was created and still open.

Please check if these changes are enough.

[dsa-t]

This shouldn't be necesary if we detect the end of the render, right? (added by 8b4649d)

That's necessary, as the dialog is still slow to respond.

The 4c1ad48 patch adds anothe 45 seconds (60 in total) if the file was created and still open.

I don't think that would work correctly, as mostly the dialog itself is slow. The file is not open at that point I think.

[set-soft]

Hi @dsa-t !

Please check the mentioned patches and tell me where the time-outs fail.
If we detect the end of render and the end of file save the remaining timeouts should be small.

[dsa-t]

With softpipe and default time scale, it goes:

INFO:Saving the image
INFO:Waiting for "File save dialog" ...
...
INFO:Waiting for "File save dialog" ...
...
INFO:Waiting for "File save dialog" ...
...
INFO:Waiting for "File save dialog" ...
...
INFO:Pasting output file
INFO:Wait for the image file creation
...
RuntimeError: Timed out waiting for creation of <file>

I can see that the path is pasted only partially, as before. I think Alt+F, Return presses still leak into the dialog.

[set-soft]

Hi @dsa-t !
Did the render end detection work for OpenGL? The file save dialog was opened when pcbnew was consuming no CPU and the image was already finished?

[dsa-t]

Yes, the render end detection worked. Thanks for implemented that!

The second is true. Also, while the dialog opens, one CPU core is being loaded to 100%, because it probably needs to re-render the image in the background with the dialog.

[set-soft]

Hi @dsa-t !

I don't think that:

I think Alt+F, Return presses still leak into the dialog.

Because you see some text pasted. We can enlarge the following delay:

    # Wait before confirming the file name
    sleep(0.1*cfg.time_out_scale)

Or we could tell xdotool to send the text slower. I added a patch to scale the typing speed.
You can try adding a larger time-out scale just before the above code, calling:

    set_time_out_scale(XX)
    set_time_out_scale_f(XX)

So we can adjust the 0.1 seconds of delay and the 12 ms of typing delay.

[dsa-t]

I don't think that:

I think Alt+F, Return presses still leak into the dialog.

Well, this can be confirmed. With time scale 3 and -w:

...
INFO:Saving the image
INFO:Waiting for "File save dialog" ...
...
INFO:Waiting for "File save dialog" ...
...
INFO:Waiting for "File save dialog" ...
...
INFO:Pasting output file
Press a key

At this point, I see a default file name in the dialog, the save button is pressed, then the confirm dialog appears "A file named ".png" already exists. Do you want to replace it?"

Why did the Save activate there? I didn't press any keys.

[set-soft]

At this point, I see a default file name in the dialog, the save button is pressed, then the confirm dialog appears "A file named ".png" already exists. Do you want to replace it?"

Why did the Save activate there? I didn't press any keys.

Ok, but you reported:

I can see that the path is pasted only partially, as before. I think Alt+F, Return presses still leak into the dialog.

If you can see a partial paste then Alt+F and Return isn't the problem. But, if you see the default file name it can be the problem.

If Alt+F and Return is generating problems you should be able to avoid them enlarging the timeout scale. Currently the code sends Alt+F/Return and waits for 3 seconds (scalable). The code retries in case that the first try was lost. According to your log the code is trying 3 times, and a scale of 3. This is between 18 and 27 seconds of delay. After detecting the end of the render you need 20 seconds to get the dialog opened?

You also saw CPU usage during the dialog creation, we could try to detect this, does the CPU usage get low when the dialog is finally opened?

You could try the following patch:

--- a/src/pcbnew_do
+++ b/src/pcbnew_do
@@ -581,6 +581,8 @@ def capture_3d_view(cfg):
     logger.info('Saving the image')
     for retry in range(10):
         xdotool(['key', 'alt+f', 'Return'], id)
+        if (cfg.ray_tracing or cfg.use_rt_wait) and cfg.detect_rt:
+            wait_ray_tracer(cfg)
         found = True
         try:
             wait_for_window('File save dialog', '3D Image File Name', 3)

So we detect the CPU usage and wait before looking for the dialog

[set-soft]

Hi @dsa-t !
I'll be working on a new approach to detect KiCad activity, I'll be pushing experimental changes to a branch. They'll be oriented to KiCad 6 (not sure if I'll port them to KiCad 5).

[dsa-t]

Ok, so in the mean time I filed a bug report in mesa and it got fixed and released in Mesa 22.1.3, so there are less reasons to use softpipe now.
https://gitlab.freedesktop.org/mesa/mesa/-/issues/6665

The CPU detection is still useful even for llvmpipe renderer to detect when the zooming/panning finishes.

[set-soft]

If the technique I'm trying works we won't need to guess when KiCad finished anymore

[set-soft]

Hi @dsa-t !
The interposer mechanism now is working and merged with the git trunk.
The new mechanism monitors KiCad activity and should avoid sending events when KiCad is running or when a dialog is created/closed. Please try using it.
I'm closing this issue, if you find problems using the interposer mechanism please report the problem.