I have only just discovered how to enable Allegro logging within my game - I must have missed that part of the docs when I read them originally. I just had a problem with my game which required me to set up logging. I previously didn't have an allegro.cfg file.

What I'm finding now is that with the trace level set to 'warn', the game is not playable. It starts up without any music on the main menu, then it freezes the moment I try to play a sound effect.

This is what I see if I break into it:

al_attach_sample_instance_to_mixer(instance,mixers[Category::SFX]);
--> al_set_sample_instance_playing(instance, true);

I also find that the game takes forever to start up if the trace level is set to 'info', because it tries dozens of display formats and waits 10 seconds between each one (d3d_create_display_internals - WaitForSingleObject(params.AckEvent, 10*1000)) - it's unclear from the code why the trace level affects this.

Yikes, that doesn't sound good. How do you enable the tracing, just via the system config/allegro5.cfg? Are you using any multithreading?

Yes, by changing the trace level in allegro.cfg. There are threads for fading out sound effects, and for music.

Eagle logging is thread safe. You could pipe allegro output to Eagle, and get a sane log back.

Scratch that. Deadlock in window creation. That's odd. My MSAA test program freezes waiting forever for a signal from the d3d_display_thread_proc, which is never launched, and the thread is never created to acknowledge it.

That's in DEBUG mode with all logging piped to EagleLog(), which is thread safe. It stops after enumerating formats, and trying to create the first one, in d3d_create_display_internal. It waits forever for the thread to signal.

It runs a detached thread to run d3d_display_thread_proc, which would send the signal to ACKnowledge the event.

Yeah, I suppose it's possible that our logging has bad performance/race conditions in a multi-threaded context (not obviously though, we have mutexes and such). Could try using al_register_trace_handler to set an empty handler and see if that helps.

Detached threads aren't protected by a CriticalSection any longer after al_run_detached_thread calls al_thread_detach.

If that matters. Also, the return value of beginthreadex is being ignored.

Also, my code is hanging with one thread waiting on ConsoleOutputW

EDIT
If I use allegro5.cfg and set trace to 'debug' or 'info' it hangs trying to create the display thread. If I set trace to 'warn' it hangs later, and if I set trace to 'none' it works fine.

EDIT2
Allegro is hanging in an ALLEGRO_INFO call during a call to _al_mutex_lock on line 245 of src/debug.c.

Why would allegro locking its own private mutex cause a deadlock in my code? It should lock allegro's log mutex and then lock my logging mutex in EagleLog() and output normally.

EDIT3
After some debugging, I discovered that the CRITICAL_SECTION used by allegro's log handler is owned by the MAIN thread.

I tried to fix it by adding in an _al_mutex_unlock call but nothing changed.

al_trace_suffix is missing a mutex unlock call when a user trace handler is being used.

However, the CRITICAL_SECTION is still messed up. When I print it out in GDB before the call to al_trace_prefix completes, these are the values it holds :

(gdb) p *(trace_info.trace_mutex.cs)
$1 = {DebugInfo = 0xffffffff, LockCount = -2, RecursionCount = 176, OwningThread = 0x4750, LockSemaphore = 0x0, SpinCount = 33556432}

Thread 0x4750 is MAIN, and Allegro is inside its own thread when it calls the allegro trace handler. The lock on the critical section shouldn't be held at all, and the recursion count indicates something is really wrong.

It took me all morning just to figure that out, and my fix doesn't work to lessen the recursion count or the lock held by main.

UPDATE
My fix DOES work, at least for my problem. I was linking to an old version of allegro.

Here's a patch to fix the resource leak :

--- C:/Users/Marc/AppData/Local/Temp/TortoiseGit/debug-619c69e3.002.c   Thu May 13 11:18:03 2021
+++ E:/usr/libs/Allegro52X/src/debug.c  Wed May 12 11:20:57 2021
@@ -300,6 +300,7 @@
    if (_al_user_trace_handler) {
       _al_user_trace_handler(static_trace_buffer);
       static_trace_buffer[0] = '\0';
+      _al_mutex_unlock(&trace_info.trace_mutex);
       return;
    }

Thanks Edgar, this is now fixed.

As well, the flickering problem should be fixed by your patch too. That doesn't explain the long startup problem the OP is having though.

I updated to the latest Allegro and I'm not seeing the delay issue any more (although I may have changed something else).