#2080 Startup delays

[Geert Verschueren]

Hello,

For a while I'm experiencing some big delays with the windows GTK3 version.

The old vice 3.2 starts in 2 seconds

GTK3 3.3, 3.6 & 3.8 need about 9 seconds.

It seems to be stuck for 3-4 seconds between these log lines:

initializing with width, height: 704 x 507
Created render thread 0

There was an additional 2-3 seconds delay when the window appeared until it got to the AR6 menu.
That appears to be the sound init.
When I disable the sound this delay goes away so it went from 9 to 6 seconds.
Changing it from dx to something else with sound enabled doesn't help.

Groepaz adviced me to test the SDL 3.8 version aswell.

But that one starts in 2 seconds.

I disabled webcam, microphone etc aswell as I was told it could also cause delays but that didn't change anything.

Is there anything else that I can try?

OS: Windows 10
Laptop is an older i5 with 16 gig and half of it free (i5-3230M with Intel® HD Graphics 4000)

[Geert Verschueren]

Thanks for the 3.9 update so another reason to check things out ;)

And I found some oddity.

The GTK version has the 3 seconds delay at the gfx init and needs 5 seconds to reach the AR6 menu.

The SDL version has no such delay and reaches the AR6 menu in 1.5-2 seconds.

Maybe it's worth comparing both init routines as there seems to be some differences.

[gpz]

It only happens on windows... so must be some GTK stuff causing this delay.

[compyx]

Could be DirectX as well? I've also noticed Windows tends to scan the executables of VICE for malware/viruses, causing delays (at least on a Win11 laptop).

[Geert Verschueren]

The SDL version also uses directX, not?

Then why isn't there any delay on that one?

Is there some more logging that I can enable than what I see passing by in the console window?

[compyx]

I assume SDL uses DirectX on Windows, yes, but perhaps it's something we're doing with DirectX that causes a delay.

There's no additional logging available that will show what's happening during boot, we'd have to run a debugger or add some logging ourselves.

[dqh]

lack of code-signing might be related too

[compyx]

I've tried to reproduce this, adding a lot of logging via printf() and GetSystemTime(), but on the machine I tried this x64sc starts quickly (~0.3 seconds until x64sc is ready and the emulated machine boots).

Windows 11 Pro, Lenovo ThinkPad T490s, i5-8365U @1.60Ghz (jumps to 4.0Ghz according to Task Manager when running x64sc)

GetSystemTime: 09:49:04.0235: main_program(): Initializing VICE thread
GetSystemTime: 09:49:04.0235: main_program(): Setting OpenMP wait policy
GetSystemTime: 09:49:04.0235: main_program(): Calling lib_init()
GetSystemTime: 09:49:04.0235: main_program(): Parsing command line
GetSystemTime: 09:49:04.0235: main_program(): Calling archdep_init()
GetSystemTime: 09:49:04.0237: main_program(): Calling tick_init()
GetSystemTime: 09:49:04.0237: main_program(): Calling maincpu_early_init()
GetSystemTime: 09:49:04.0238: main_program(): Calling machine_setup_context()
GetSystemTime: 09:49:04.0238: main_program(): Calling drive_setup_context()
GetSystemTime: 09:49:04.0238: main_program(): Calling machine_early_init()
GetSystemTime: 09:49:04.0238: main_program(): Calling sysfile_init()
GetSystemTime: 09:49:04.0245: main_program(): Calling gfxoutput_early_init()
GetSystemTime: 09:49:04.0245: main_program(): Calling gfxoutput_resources_init() and gfxoutput_cmdline_init()
GetSystemTime: 09:49:04.0245: main_program(): Calling resources_set_defaults()
GetSystemTime: 09:49:04.0248: main_program(): Calling ui_actions_init()
GetSystemTime: 09:49:04.0248: main_program(): Calling ui_hotkeys_resources_init()
GetSystemTime: 09:49:04.0248: main_program(): Calling ui_hotkeys_cmdline_init()
GetSystemTime: 09:49:04.0248: main_program(): Calling ui_init_with_args()
GetSystemTime: 09:49:04.0248: ui_init_with_args(): Calling gtk_init()
GetSystemTime: 09:49:04.0276: main_program(): Loading resources from vice.ini or setting to default
GetSystemTime: 09:49:04.0276: main_program(): Calling log_init()
GetSystemTime: 09:49:04.0319: ui_init(): Calling uidata_init()
GetSystemTime: 09:49:04.0319: ui_init(): Calling archdep_register_cbmfont()
GetSystemTime: 09:49:04.0322: ui_init(): Calling ui_statusbar_init()
GetSystemTime: 09:49:04.0324: main_program(): Calling video_init()
GetSystemTime: 09:49:04.0324: main_program(): Calling initcmdline_check_psid()
GetSystemTime: 09:49:04.0324: main_program(): Calling init_main()
GetSystemTime: 09:49:04.0344: machine_window_create(): Called
GetSystemTime: 09:49:04.0344: vice_directx_initialise_canvas(): Called
GetSystemTime: 09:49:04.0344: vice_directx_initialise_canvas(): Done
GetSystemTime: 09:49:04.0350: machine_window_create(): Done
GetSystemTime: 09:49:04.0500: on_widget_realized(): Called
GetSystemTime: 09:49:04.0500: on_widget_realized(): Calling CreateWindowEx()
GetSystemTime: 09:49:04.0501: on_widget_realized(): Making cntext available to windowproc
GetSystemTime: 09:49:04.0501: on_widget_realized(): Calling ShowWindow()
GetSystemTime: 09:49:04.0501: on_widget_realized(): Calling render_queue_create()
GetSystemTime: 09:49:04.0501: on_widget_realized(): Calling render_thread_create()
GetSystemTime: 09:49:04.0501: render_thread_create(): Called
GetSystemTime: 09:49:04.0501: render_thread_create(): Done
GetSystemTime: 09:49:04.0543: ui_init_finalize(): Called
GetSystemTime: 09:49:04.0543: ui_init_finalize(): Registering UI Actions
GetSystemTime: 09:49:04.0543: ui_init_finalize(): Calling ui_hotkeys_init()
GetSystemTime: 09:49:04.0545: ui_init_finalize(): Setting up UI state for UI actions
GetSystemTime: 09:49:04.0545: main_program(): Lauching main thread
GetSystemTime: 09:49:04.0546: main_loop_forever(): Calling maincpu_mainloop()

I also tried one of our github builds (these have slightly less optimizations), but the startup time is about the same.

Next time I have access to a Windows machine (and some free time) I'll try to rework the logging calls into writes to a specific file and create a build for others to test.