Singleton Logging Class Crash

Singletons ... there's something I'm not getting right!  I thought I was playing it safe...

What am I buggering up?  It doesn't crash all the time.  Below you can see writeLog(..) called from the constructor of the plugin.  This calls a static function logDebug(...) which checks that the singleton hasn't been deleted with DeletedAtShutdown, and presuming it gets a valid pointer then calls writeLog(..) which attempts to write to the file. 

Now my questions and assumptions are: 

  • That when getInstance() is called for the first time it creates an object and the constructor is called. 
  • That after that point the member variable File log is valid. 
  • That therefore when writeLog gets called the object should be valid and there shouldn't be a crash. 

Perhaps there's some threading issue I've not got my head around here...where the constructor is being called by one thread and then writeLog is called by a different one?  Is that a possiblility? And fixable with a lock ...

(Also - any idea why logDebug(...) doesn't show up in the stack trace? ...)

Symptom

This happened once:

Thread 0 Crashed:: Dispatch queue: com.apple.main-thread
0   com.credland.bigkick              0x00000001170664bb juce::FileOutputStream::FileOutputStream(juce::File const&, unsigned long) + 107
1   com.credland.bigkick              0x0000000117064b4c juce::File::appendText(juce::String const&, bool, bool) const + 44
2   com.credland.bigkick              0x0000000116fbf754 PluginLogs::writeLog(juce::String const&, juce::String const&) + 196
3   com.credland.bigkick              0x0000000116fe6280 ProcessorParameterStore::ProcessorParameterStore(PresetVersionTranslator*) + 720
4   com.credland.bigkick              0x0000000116ff39fd CredlandKick1331AudioProcessor::CredlandKick1331AudioProcessor() + 77
5   com.credland.bigkick              0x0000000116ff495c createPluginFilter() + 28
6   com.credland.bigkick              0x00000001171990f0 createPluginFilterOfType(juce::AudioProcessor::WrapperType) + 16
7   com.credland.bigkick              0x00000001170071a1 JuceAU::JuceAU(ComponentInstanceRecord*) + 273
8   com.credland.bigkick              0x0000000117007068 APFactory<AUMIDILookup, JuceAU>::Construct(void*, ComponentInstanceRecord*) + 24
9   com.credland.bigkick              0x0000000116fff3be ComponentBase::AP_Open(void*, ComponentInstanceRecord*) + 78


Crashed Thread:  0  Dispatch queue: com.apple.main-thread
Exception Type:  EXC_BAD_ACCESS (SIGSEGV)
Exception Codes: KERN_INVALID_ADDRESS at 0x00000002636d6463
 

 

class PluginLogs :

public DeletedAtShutdown {

public:

    juce_DeclareSingleton(PluginLogs, true);

    PluginLogs() {

        log = JCF::getSettingsFolder().getChildFile("credland.log");

        

        if (!log.hasWriteAccess())

            AlertWindow::showMessageBox(AlertWindow::AlertIconType::WarningIcon, "Warning", "No write access to " + log.getFullPathName() + ". You may want to check that this folder exists and the permissions are correct.  The plugin will need to write to this location to save presets.");

        

        isLogging = log.existsAsFile();

    }


    static void logError(const String & ref, const String & s) {

        PluginLogs * l = PluginLogs::getInstance();

        if (l == nullptr) return;

        l->writeLog(ref, " ERROR: " + s);

    }

    

    static void logDebug(const String & ref, const String & s) {

        PluginLogs * l = PluginLogs::getInstance();

        if (l == nullptr) return;

        l->writeLog(ref, " DEBUG: " + s);

    }

    

private:

    void writeLog(const String & ref, const String & s) {

        DBG(s);

        if (!isLogging) return;

        Time t = Time::getCurrentTime();

        log.appendText(t.toString(true, true, true, true) +

                       ":[" +

                       ref +

                       "] " +

                       s +

                       "\n");

    }

    

    bool isLogging;

    File log;

    

};

In a plugin I'd recommend using SharedResourcePointer instead of singletons.

(But maybe it's just that you're not calling clearSingletonInstance() ?)

Okay - 

That's a pretty good point.  I'm not sure how it would be being deleted through other than by the DeletedAtShutdown class.

Do you thnk there's a race condition involving multiple threads there as well? 

The advantage of SharedResourcePointer is about reducing resource load when there aren't any instances of the plugin actually running I think - rather than tackling this kind of problem? Though obviously it might just make the problem go away :)

 

 

Well, I'm ruling out my threading theory as the cause of this problem.  Tried it in several hosts and all the calls to that are on the same thread.  And looking at the JUCE singleton macro that looks pretty robust. 

It crashed once again, in Au Lab this time, with the same problem though.  Meh! 

Ah - new clue.  It hit an assertation in the juce_declareSingleton constructor this morning.

I presume the briliantly titled and slightly french sounding: jassert (! problem); 

This was after it had already started logging. So, as it was already logging it must have hit this: 

(doNotRecreateAfterDeletion) && createdOnceAlready);

Which is interesting.  Obviously doNotRecreateAfterDeletion was the wrong choice :) Not sure that explains my previous crash mind you. 

What cases deleteAll(..) in DeletedAtShutdown to be called? 

Well you set the flag that indicates the singleton should not be re-created after it's deleted. So if you have code which tries to delete/recreate it, in which case unless you check, you'll be calling a null pointer. This is one of many reasons to avoid singletons in a plugin, and use SharedResourcePointers instead.

I was checking the pointer!

The public methods which are called to send logs are static and all do: 

if (l == nullptr) return;

However I suppose there's a possibility that the pointer was valid, then whatever causes DeletedAtShutdown::deleteAll() to be called happened in parallel. 

Appreciate that SharedResourcePointers might fix that, but I'm annoyed with myself for not understanding exactly what's happening here!

As Jules said, you're not calling clearSingletonInstance() in the destructor so the pointer that you subsequently check will be dangling?

Dave - Yes.  Of course. You are right.  Jules is right.

I'd read this line: 

It's also a very good idea to also add the call clearSingletonInstance() in your class's destructor, in case it is deleted by other means than deleteInstance()

Yesterday in too much of a hurry and in my mind had translated deleteInstance() into DeletedAtShutdown.  But DeletedAtShutdown knows nothing about the singleton features. 

Mystery solved. 

I can go back to double-clicks and Window XP now ... :)