Thread overview
Is this a bug?
May 04, 2014
Alex
May 04, 2014
Mike Parker
May 04, 2014
monarch_dodra
May 04, 2014
Mike Parker
May 04, 2014
Alex
May 04, 2014
bearophile
May 05, 2014
Mike Parker
May 04, 2014
monarch_dodra
May 04, 2014
bearophile
May 04, 2014
Hello,

I am trying to use the std.log module that is here:

https://github.com/linkrope/log.d

And I encountered a segmentation fault using dmd 2.065 on a Linux 64 platform. The reduced test case is this:

//============================================================================
import std.stdio;
import std.log;

private class CHello {
	
	~this() {
		info("info - destructor"); //info, warning, error segfault; however, writefln works
	}
}

void main(string[] args) { CHello chello = new CHello(); }
//============================================================================

Is this a bug?
May 04, 2014
On 5/4/2014 6:42 PM, Alex wrote:
> Hello,
>
> I am trying to use the std.log module that is here:
>
> https://github.com/linkrope/log.d
>
> And I encountered a segmentation fault using dmd 2.065 on a Linux 64
> platform. The reduced test case is this:
>
> //============================================================================
>
> import std.stdio;
> import std.log;
>
> private class CHello {
>
>      ~this() {
>          info("info - destructor"); //info, warning, error segfault;
> however, writefln works
>      }
> }
>
> void main(string[] args) { CHello chello = new CHello(); }
> //============================================================================
>
>
> Is this a bug?

No, it is not a bug. It's a hazard of destructors in D.

Because of the GC, there are certain things you cannot rely on when it comes to destruction. One is that there is no guarantee that the destructor will ever be called during the lifetime of the app. The second, and likely the problem you're seeing, is that you cannot rely on the order of destruction.

If you look at the source for std.log, you'll see that info() ultimately (via some templating) maps to an instance of LogFilter, which is a class allocated on the GC heap in a module constructor. When the app exits, one of the last things DRuntime does is to terminate the GC (see rt_term in dmain2.d in the DRuntime source). The current implementation of the GC will run destructors on any objects still resident on the heap during termination. There is no way to guarantee the order in which those destructors will be run.

Most likely, what you're seeing is that the LogFilter instance referenced by the info template is being destroyed before the destructor on CHello is run. Therefore, you're referencing an invalid memory location.

The short of it is that you should never touch anything on that lives on the GC heap from inside a destructor -- there's no guarantee that it will still be alive when your destructor is run.
May 04, 2014
On Sunday, 4 May 2014 at 09:42:17 UTC, Alex wrote:
> Hello,
>
> I am trying to use the std.log module that is here:
>
> https://github.com/linkrope/log.d
>
> And I encountered a segmentation fault using dmd 2.065 on a Linux 64 platform. The reduced test case is this:
>
> //============================================================================
> import std.stdio;
> import std.log;
>
> private class CHello {
> 	
> 	~this() {
> 		info("info - destructor"); //info, warning, error segfault; however, writefln works
> 	}
> }
>
> void main(string[] args) { CHello chello = new CHello(); }
> //============================================================================
>
> Is this a bug?

Maybe, maybe not. As rule of thumb, you can't allocate during a GC cleaning cycles, and class destructors are usually called during a GC cleaning cycle.

This means it is usually unsafe to call *anything* that could potentially allocate in a destructor.

I don't know the details of the log module. AFAIK, the code itself doesn't *seem* to allocate anything to just log, but it does seem to use a singleton logger object.

Could you try to log a single "info" in your main, and see if it resolves the issue?

We'd need to contact the author directly too about this issue.
May 04, 2014
On Sunday, 4 May 2014 at 10:28:30 UTC, Mike Parker wrote:
> The current implementation of the GC will run destructors on any objects still resident on the heap during termination. There is no way to guarantee the order in which those destructors will be run.
>
> Most likely, what you're seeing is that the LogFilter instance referenced by the info template is being destroyed before the destructor on CHello is run. Therefore, you're referencing an invalid memory location.
>
> The short of it is that you should never touch anything on that lives on the GC heap from inside a destructor -- there's no guarantee that it will still be alive when your destructor is run.

Really??? I knew there was no guarantee in which order the destructor were run, but at the very least, I thought you had a guarantee of dependency ordering?

...

Then again, the GC can collect cycles, so...

Well dang. That's a bummer.
May 04, 2014
monarch_dodra:

> As rule of thumb, you can't allocate during a GC cleaning cycles, and class destructors are usually called during a GC cleaning cycle.
>
> This means it is usually unsafe to call *anything* that could potentially allocate in a destructor.

So it could be a good idea to have @nogc enforcement for class destructors ( assuming they don't go away).

Bye,
bearophile
May 04, 2014
On 5/4/2014 7:39 PM, monarch_dodra wrote:

>
> Really??? I knew there was no guarantee in which order the destructor
> were run, but at the very least, I thought you had a guarantee of
> dependency ordering?

"Furthermore, the order in which the garbage collector calls destructors for unreference objects is not specified. This means that when the garbage collector calls a destructor for an object of a class that has members that are references to garbage collected objects, those references may no longer be valid."

http://dlang.org/class.html#destructors

In this case, CHello does not maintain a reference to the object. But even if it did, the destruction is happening at app termination and all bets are off. My understanding is that gc.term just blows through all the objects still on the heap without any regard to who still references what.

> ...
>
> Then again, the GC can collect cycles, so...
>
> Well dang. That's a bummer.
May 04, 2014
On Sunday, 4 May 2014 at 10:28:30 UTC, Mike Parker wrote:
> On 5/4/2014 6:42 PM, Alex wrote:
>> Hello,
>>
>> I am trying to use the std.log module that is here:
>>
>> https://github.com/linkrope/log.d
>>
>> And I encountered a segmentation fault using dmd 2.065 on a Linux 64
>> platform. The reduced test case is this:
>>
>> //============================================================================
>>
>> import std.stdio;
>> import std.log;
>>
>> private class CHello {
>>
>>     ~this() {
>>         info("info - destructor"); //info, warning, error segfault;
>> however, writefln works
>>     }
>> }
>>
>> void main(string[] args) { CHello chello = new CHello(); }
>> //============================================================================
>>
>>
>> Is this a bug?
>
> No, it is not a bug. It's a hazard of destructors in D.
>
> Because of the GC, there are certain things you cannot rely on when it comes to destruction. One is that there is no guarantee that the destructor will ever be called during the lifetime of the app. The second, and likely the problem you're seeing, is that you cannot rely on the order of destruction.
>
> If you look at the source for std.log, you'll see that info() ultimately (via some templating) maps to an instance of LogFilter, which is a class allocated on the GC heap in a module constructor. When the app exits, one of the last things DRuntime does is to terminate the GC (see rt_term in dmain2.d in the DRuntime source). The current implementation of the GC will run destructors on any objects still resident on the heap during termination. There is no way to guarantee the order in which those destructors will be run.
>
> Most likely, what you're seeing is that the LogFilter instance referenced by the info template is being destroyed before the destructor on CHello is run. Therefore, you're referencing an invalid memory location.
>
> The short of it is that you should never touch anything on that lives on the GC heap from inside a destructor -- there's no guarantee that it will still be alive when your destructor is run.

Thank you, but I find it to be quite awkward. Why the compiler does not complain or, at least, give a more meaningful runtime error message? Is there any official std.log that is destructor-safe?
May 04, 2014
Alex:

> Why the compiler does not complain or,

I've just asked something related to this in the main D newsgroup, take a look there for answers. Today D has means to complain statically.
But I don't know the fate of D class destructors.

Bye,
bearophile
May 05, 2014
On 5/5/2014 5:40 AM, Alex wrote:

>
> Thank you, but I find it to be quite awkward. Why the compiler does not
> complain or, at least, give a more meaningful runtime error message? Is
> there any official std.log that is destructor-safe?

There is no official std.log at all.