I can crash program (core.exception.InvalidMemoryOperationError) by using __FUNCTION__ in a class ctor

[Steven Schveighoffer]

On 1/18/19 10:29 AM, James Blachly wrote:
> First, let me apologize for not being able to reduce this to a minimal 
> test case. I have tried to do so but was unsuccessful. Offending code, 
> and links to codebase at bottom.
> 
> TL;DR: I believe this is a compiler error. Please help me prove it, or 
> teach me where I've gone wrong.
> 
> ---
> 
> Briefly, I have a class, SAMRecord, that contains: a default 
> constructor, a non-default ctor, and a destructor, each of which for 
> debugging purposes emits a log-line that includes __FUNCTION__.
> 
> When the default ctor passes __FUNCTION__ to the log function, the 
> program will crash after about 15k or 30k objects are created when using 
> dmd or ldc2, respectively.  Further, if I change __FUNCTION__ to any 
> other string (except __MODULE__, which induces the same behavior), the 
> program operates flawlessly.
> 
> The error is:
> 
> core.exception.InvalidMemoryOperationError at src/core/exception.d(700): 
> Invalid memory operation
> 
> and is thrown at the the time that when under normal operation the GC 
> would start clearing out the old objects.
> 
> _Importantly, my code never calls the default constructor_ -- This part 
> puzzles me the most.
> 
> Additional data points:
> 1. I added a dummy log function to demonstrate it (likely?) not my 
> library code offending
> 2. adding assert statements into the default constructor seems to elide 
> the offending behaviour (i.e., I can leave the __FUNCTION__ in without 
> memory error)
> 3. Commenting out the usage of __FUNCTION__ in the non-default ctor, 
> which IS being used, does not prevent the error.
> 
> Overall, the error seems to be related to passing __FUNCTION__ out of 
> default class constructors, even when that constructor is not called 
> explicitly by user code. Altering compiler behavior by e.g. adding 
> assert(0) prevents the error. Thus, I conclude this is almost surely a 
> compiler error, but I would be glad to be proven wrong.
> 
> I would be happy to provide any more information, or to help develop an 
> appropriate minimal reproducible bug, if given appropriate guidance. 
> Otherwise, to replicate this you will need to install a C library. 
> Details below.
> 
> Thanks all in advance.
> James
> 
> ---
> DMD: v2.081.2
> LDC2: 1.11.0
> repository: https://github.com/blachlylab/dhtslib/
> commit: ee87434d0c48919aaa0ff6d04d6e0ca403564618 (current as of this post)
> requirement: htslib; https://github.com/samtools/htslib
> 
> To replicate:
> 1. Download any BAM file. (random BAM file: 
> https://www.encodeproject.org/files/ENCFF765NLQ/@@download/ENCFF765NLQ.bam 
> )
> 2. Update test/samreader.d to open your BAM file (sorry I have not 
> parameterized this, have been tearing hair about re this crash for hours)
> 3. `dub build -c sam_test && ./samreader`
> 
> Attempt at minimal reproducible test-case (that does NOT trigger the 
> error): repo/test/bug_minimal.d
> 
> Offending code section:
> (note that I wrote test_log as a substitute for hts_log_debug to prove 
> that the error is still triggered even when not calling library code)
> ```
> import core.stdc.stdlib: calloc, free;
> import std.format;
> import std.parallelism: totalCPUs;
> import std.stdio: writeln, writefln;
> import std.string: fromStringz, toStringz;
> 
> import dhtslib.htslib.hts: htsFile, hts_open, hts_close;
> import dhtslib.htslib.hts: hts_itr_t;
> import dhtslib.htslib.hts: seq_nt16_str;
> import dhtslib.htslib.hts: hts_set_threads;
> 
> import dhtslib.htslib.hts_log;
> import dhtslib.htslib.kstring;
> import dhtslib.htslib.sam;
> 
> void test_log(string ctx, string msg)
> {
>      import std.stdio;
>      stderr.writeln(ctx, msg);
> }
> 
> /**
> Encapsulates a SAM/BAM/CRAM record,
> using the bam1_t type for memory efficiency,
> and the htslib helper functions for speed.
> **/
> class SAMRecord {
>      ///
>      bam1_t *b;
> 
>      ///
>      this()
>      {
>          //debug(dhtslib_debug) hts_log_debug(__FUNCTION__, "ctor()"); 
> /// This line triggers memory error when __FUNCTION__, but not when 
> "Other string"
>          test_log(__FUNCTION__, "ctor()");   /// This line will also 
> trigger the memory error when __FUNCTION__, but not other strings
>          //writeln(__FUNCTION__);    // this will not trigger the memory 
> error
>          this.b = bam_init1();
>          //assert(0);                // This will elide(?) the memory error
>          //assert(1 == 2);           // This will elide(?) the memory error
>      }
>      ///
>      this(bam1_t *b)
>      {
>          debug(dhtslib_debug) hts_log_debug(__FUNCTION__, "ctor(bam1_t 
> *b)");
>          this.b = b;
>      }
>      ~this()
>      {
>          writeln("Record dtor");
>          debug(dhtslib_debug) hts_log_debug(__FUNCTION__, "dtor");
>          //bam_destroy1(this.b); // we don't own it!
>      }
> }
> ```


https://github.com/blachlylab/dhtslib/blob/master/source/dhtslib/htslib/hts_log.d#L94

That is your problem. toStringz is going to attempt to allocate using 
the GC. Allocating during a GC collection causes an 
InvalidMemoryOperationError.

Take that out of your destructor, and you should not cause that error.

Alternatively, fix the logger so it doesn't use the GC.

-Steve