Experimental: Log & Visualize Plugin Processing Times


#1

For a recent proof of concept, I wrote a class to help inspecting multithreading & timing issues in plugins. This might be useful for anyone else who is struggling with concurrency or performance issues in a plugin or AudioProcessorGraph.

To use this class, add the files from the zip to your project, and add these declarations and initializations to your AudioProcessor classes:

class YourPluginEditor : public AudioProcessor
{
public:
    YourPluginEditor()
      : profiler(this)
    {
        
    }

    void prepareToPlay(double sampleRate, int estimatedSamplesPerBlock)
    {
        PluginProfiler::PrepareLogger logger (profiler, sampleRate, estimatedSamplesPerBlock);
        
    }

    void processBlock(AudioSampleBuffer& buffer, MidiBuffer& midiMessages)
    {
        PluginProfiler::BlockLogger logger (profiler, buffer);

    }

    void releaseResources()
    {
        PluginProfiler::ReleaseLogger logger (profiler);

    }

    // ...

private:
    PluginProfiler profiler;
};

Then watch your desktop getting spammed with PluginCallback.xml files as soon as you load your plugin(s). You’ll need to close the project / host before viewing the logs to avoid invalid xml files.

After copying the PluginCallback.xsl file to your desktop, open the xml file in Firefox and give it a few seconds to apply the stylesheet. Try to keep the log file below 10mb by having your plugins loaded just as long as neccessary.

When the xslt transformation is finally done, you should see a table with one column for each AudioProcessor instance, and a vertical time axis. Each call to prepare/process/release shows up as a rectangle with the height corresponding to the amount of time spend in the method. Hovering over each entry will list all properties logged for this event.

The log files get big pretty fast, so you’ll want to #define the JUSP_DISABLE_PLUGIN_PROFILER macro on regular builds to turn off all logging conveniently.

This is still in an experimental stage, and I only tested it in Live and Cubase so far, but let’s hope it’ll be also useful in other scenarios.

If it doesn’t work for you, please let me know of any problems - the PluginProfilerLog.txt that is also written to the desktop should contain some info about the lifecycle of the SharedLoggingThread that collects and logs the events from all plugin instances (which is the most likely reason for problems). I’d also love to hear some opinions if the overhead on the audio thread can be further reduced!