OpenTESArena crashes when using a release build of WildMIDI

[Allofich]

Link to the original issue afritz1/OpenTESArena#69.

OpenTESArena uses WildMidi. If run with a Debug or RelWithDebugInfo build of WildMIDI, no crash happens, but if run with a Release build, a crash always happens. Only tested on Windows 7, 64-bit.

Steps to reproduce crash:
First you need OpenTESArena running with MIDI.
It requires a copy of The Elder Scrolls: Arena (the free, floppy-disk version released by Bethesda Softworks) to be installed. It's easy to find. Next,

1. Download the latest OpenTESArena release (https://github.com/afritz1/OpenTESArena/releases).
2. Get the eawpats MIDI sound patch library:
   https://github.com/afritz1/OpenTESArena/releases/download/opentesarena-0.1.0/eawpats.zip
   or
   https://github.com/afritz1/OpenTESArena/releases/download/opentesarena-0.1.0/eawpats.tar.gz
   and put the extracted contents into the OpenTESArena data folder.

Make sure you set the path to your installation of Arena in the OpenTESArena options file. The easiest thing to do if you just want to quickly get the game up and running is to directly modify the default in the options-default.txt in the OpenTESArena options folder.

Try the game, it will run fine.
Now replace the supplied wildmidi_dynamic.dll, which I think is a RelWithDebugInfo build, with a Release build of WildMIDI. (As of this writing the latest commit is b008d78)

Start the game. It is fine until you try to leave the title menu to start the game, for example by clicking "Test" at the bottom of the screen, or when you exit the game. For information on the code in OpenTESArena involved in the crash and the specific line in the WildMIDI code that the program crashes on, please see the issue over at OpenTESArena I linked to above. It seems it may have something to do with _WM_do_meta_copyright.

[sezero]

Might (or might not) be a double free()??

Can you give us the midi file, so that we can test and reproduce without
having to setup OpenTESArena?

[afritz1]

Thanks for writing this up, @Allofich. Just to add some more information, I think this is just an issue with the Windows build of WildMIDI, and assuming that WildMIDI is calling free() correctly, the only cause of the problem is that there's a mismatch with MSVC libraries being used (MSVCP80.DLL vs. MSVCP140.DLL), causing the application to have problems when trying to free a block on the heap. It's just a shot in the dark though.

This crash also happens when a song finishes in the console, but only when I use WildMIDI's build. When I compile WildMIDI myself with RelWithDebInfo and Visual Studio 2015, the console doesn't crash when a song finishes.

Edit: @sezero, the MIDI files are available in issue #149. It's not just .XMI and .XFM files that cause WildMIDI to crash on free, though (also .MID files converted by WildMIDI).

[sezero]

MSVCP80.DLL and MSVCP140.DLL are not supposed to mix: issue
should be something else. We are either double free()ing, or overwriting
a pointer, or vs2005 is miscompiling something.

I can't crash it on linux by running under valgrind.

Can you make it crash if you build current git master branch with
your own Visual Studio as a Release build?

[Allofich]

Can you make it crash if you build current git master branch with
your own Visual Studio as a Release build?

You mean make a release build of current git master branch of WildMIDI? Yes, it crashes for me, using the built .dll with OpenTESArena.

Also the MIDI I was having a problem with was PERCNTRO.XMI, different from the ones afritz1 linked to, but I tried those (OVERSNOW.XMI, SUNNYDAY.XMI, VISION.XMI) and they have the same problem.

In all cases the crash happens at

wildmidi/src/internal_midi.c

Line 1938 in b008d78

free(mdi->events[i].event_data.data.string);

OpenTESArena calls WildMidi_Close(), and WildMidi_Close() calls _WM_freeMDI() which then crashes at the above line.

[sezero]

I put a debug print in there, like:

diff --git a/src/internal_midi.c b/src/internal_midi.c
index e74c24b..beeb57c 100644
--- a/src/internal_midi.c
+++ b/src/internal_midi.c
@@ -1945,6 +1945,7 @@ void _WM_freeMDI(struct _mdi *mdi) {
                 free(mdi->events[i].event_data.data.string);
             } else if (mdi->events[i].do_event == _WM_do_meta_copyright) {
                 free(mdi->events[i].event_data.data.string);
+                printf("free()d copyright string\n");
             } else if (mdi->events[i].do_event == _WM_do_meta_trackname) {
                 free(mdi->events[i].event_data.data.string);
             } else if (mdi->events[i].do_event == _WM_do_meta_instrumentname) {

With either of OVERSNOW.XMI, SUNNYDAY.XMI and VISION.XMI, I don't ever
hit that print..

[sezero]

@psi29a: can you reproduce this in a simple way?

[sezero]

@Allofich: can you crash your built dll if you play those XMI files
using the newly built wildmidi.exe instead of opentesarena?

[psi29a]

@sezero I'll see if I can repro this on Linux (release/debug builds). I don't have a windows box to test sadly.

[sezero]

My tests were on linux, btw: I failed to reproduce using wildmidi-only.
Hope that you have better luck.

BTW, I pushed db42139: there was a duplicated check in there.
Irrelevant to this issue, but still.

[sezero]

I am not good with C++ so this may sound stupid, but, does setting
mSong to NULL in OpenTESArena after closing it help at all?? E.g.:

diff --git a/OpenTESArena/src/Media/WildMidi.cpp b/OpenTESArena/src/Media/WildMidi.cpp
index dabc096..be019b9 100644
--- a/OpenTESArena/src/Media/WildMidi.cpp
+++ b/OpenTESArena/src/Media/WildMidi.cpp
@@ -34,6 +34,7 @@ namespace
        WildMidiSong::~WildMidiSong()
        {
                WildMidi_Close(mSong);
+               mSong = nullptr;
        }
 
        void WildMidiSong::getFormat(int *sampleRate)

[Allofich]

can you crash your built dll if you play those XMI files
using the newly built wildmidi.exe instead of opentesarena?

I tried it now. I have never used the wildmidi.exe player before so I'm not sure about how to set up .pat sounds for it. However even without those it can silently "play" OVERSNOW.XMI, which I am using as a test. ~~~There is no crash on exit. However for me it does use the line I mentioned above, many times in fact. I have fprintf commands around that line and on closing OVERSNOW.XMI they are printed 21 times.~~~
Edit: Sorry, careless error. I forgot I had commented out the crashing line yesterday. I rebuilt wildmidi.exe with the line restored, and it crashed there, when closing OVERSNOW.XMI.

By the way using the wildmidi.exe from the releases page it complains that the .XMI file is not a MIDI file, but with the one I built from source it can play silently as I described above.

I am not good with C++ so this may sound stupid, but, does setting
mSong to NULL in OpenTESArena after closing it help at all?? E.g.:

I'll try this next.
Edit: Still crashes. As it should, since the crash happens before that line could be reached anyway.

[Allofich]

So anyway, since I have a crash on the same line with a release build of wildmidi.exe when closing OVERSNOW.XMI in Windows7 64-bit, and it seems sezero on Linux does not, it seems to confirm that:

• The problem has a relation to the OS being used
• The problem is in WildMIDI (or something related to being on Windows or non-Linux), not in OpenTESArena

[Allofich]

Did a test. I added fprintf statements for the number of events and the event types in that section of crashing code, like

if (mdi->event_count != 0) {
        for (i = 0; i < mdi->event_count; i++) {
            /* Free up the string event storage */
            fprintf(stdout, "event_count %d", mdi->event_count);
            if (mdi->events[i].do_event == _WM_do_meta_text) {
                fprintf(stdout, "_WM_do_meta_text");
                free(mdi->events[i].event_data.data.string);
            } else if (mdi->events[i].do_event == _WM_do_meta_text) {
                free(mdi->events[i].event_data.data.string);
            } else if (mdi->events[i].do_event == _WM_do_meta_copyright) {
                fprintf(stdout, "_WM_do_meta_copyright");
                free(mdi->events[i].event_data.data.string);
            } else if (mdi->events[i].do_event == _WM_do_meta_trackname) {
                fprintf(stdout, "_WM_do_meta_trackname");
                free(mdi->events[i].event_data.data.string);
            } else if (mdi->events[i].do_event == _WM_do_meta_instrumentname) {
                fprintf(stdout, "_WM_do_meta_instrumentname");
                free(mdi->events[i].event_data.data.string);
            } else if (mdi->events[i].do_event == _WM_do_meta_lyric) {
                fprintf(stdout, "_WM_do_meta_lyric");
                free(mdi->events[i].event_data.data.string);
            } else if (mdi->events[i].do_event == _WM_do_meta_marker) {
                fprintf(stdout, "_WM_do_meta_marker");
                free(mdi->events[i].event_data.data.string);
            } else if (mdi->events[i].do_event == _WM_do_meta_cuepoint) {
                fprintf(stdout, "_WM_do_meta_cuepoint");
                free(mdi->events[i].event_data.data.string);
            }
        }
    }

Result for OVERSNOW.XMI was
event_count 4503_WM_do_meta_copyright then crash.
Result for SUNNYDAY.XMI was
event_count 2425_WM_do_meta_copyright then crash.
Result for VISION.XMI was
event_count 1463_WM_do_meta_copyright then crash.

Looks like it crashes on the first event in each case, which is always _WM_do_meta_copyright.

[sezero]

@Allofich: does the mingw build from wildmidi-0.4.2-win64 (or -win32) release
work properly (wildmidi.exe + libWildMidi.dll) for you, instead of the msvc build?

If it works properly, it has something to do with MSVC?? And it sohould not be
limited to VS2005, because you said you own build using msvc crashes.
(What MSVC version are you using?)

[Allofich]

does the mingw build from wildmidi-0.4.2-win64 (or -win32) release
work properly (wildmidi.exe + libWildMidi.dll) for you, instead of the msvc build?

The mingw build is the one in the main folder (not the msvc folder) when I extract wildmidi-0.3.13-win64.zip, right?

But as I said above, I cannot play the MIDI, because it says ERROR Not a midi file, unlike the wildmidi.exe produced by building from source. How can I play it?

(What MSVC version are you using?)

Visual Studio 2015. Specifically:
Microsoft Visual Studio Community 2015
Version 14.0.25431.01 Update 3

[sezero]

The mingw build is the one in the main folder (not the msvc folder) when I
extract wildmidi-0.3.13-win64.zip, right?

0.3.x series don't have xmi support. Try with wildmidi-0.4.2-win64.zip instead.

[Allofich]

0.3.x series don't have xmi support. Try with wildmidi-0.4.2-win64.zip instead.

Oh, I downloaded just the first one I saw at the top of the page because I thought it was newest. 0.4.2 works, and there is no crash with the mingw build! It does crash with the msvc build in that package.

[psi29a]

So it is msvc related?

[sezero]

[...] no crash with the mingw build! It does crash with the msvc build [...]

So, MSVC is allergic to and/or miscompiling something. Affected MSVC versions
known so far are 2005 (which I used in release builds) and 2015 (which Allofich
uses.)

I can't see anything wrong by just following the code, so I don't know what it
is yet.

[Allofich]

Seems so. Also, back to afritz1's comment:

assuming that WildMIDI is calling free() correctly, the only cause of the problem is that there's a mismatch with MSVC libraries being used (MSVCP80.DLL vs. MSVCP140.DLL), causing the application to have problems when trying to free a block on the heap.

sezero responded:

MSVCP80.DLL and MSVCP140.DLL are not supposed to mix: issue
should be something else.

but I think afritz1 was also saying they are not supposed to mix. He suggested in the original thread over at OpenTESArena's issue tracker:

I'm not sure how the WildMIDI releases could fix this other than maybe linking against a newer MSVC runtime (like MSVCR120.dll instead of MSVCR80.dll), because using the .dll that comes with the release causes the crash.

[Allofich]

To be honest I don't quite understand what he was saying, though. If he means that mismatch is between the .dll used in OpenTESArena and WildMIDI then that is probably not the issue, since WildMIDI crashes on its own.

[sezero]

That your own wildmidi_dynamic.dll build using VS2015 is crashing
voids the possibility of clashing ms runtime dlls.

[Allofich]

That your own wildmidi_dynamic.dll build using VS2015 is crashing
voids the possibility of clashing ms runtime dlls.

Ok, thanks. I thought that should be the case.

[sezero]

Besides, I can happily lose the MSVC builds in future builds:
I can provide only dlls, only built by gcc (mingw) and provide a
simple import lib along with it, and drop the static msvc builds.

[sezero]

In any case, I will test myself on windows soon, using MSVC (I have 2005 and 2017).

[Allofich]

Besides, I can happily lose the MSVC builds in future builds:
I can provide only dlls, only built by gcc (mingw) and provide a
simple import lib along with it, and drop the static msvc builds.

Oh, well, I will leave that to @afritz1 to comment about, since OpenTESArena is his project.

[Allofich]

In any case, I will test myself on windows soon, using MSVC (I have 2005 and 2017).

Ok. I think it would be best if the problem could be fixed for MSVC, but I will leave it to you.

[sezero]

I built the current master branch for win64 using vs2017 (release build.)
I got the eawpats.zip you linked above, and I ran:
wildmidi.exe -c timidity.cfg -o 1.wav VISION.XMI

When it reaches completion, it pauses noticeably, and just 'exits',
but without printing the line Finishing and closing wav output as it
should have. (This was on Win10 version 1803 build 17134.48)
Same behavior if built for win32 (x86). Did not attempt to debug.

The mingw-w64-built 0.4.2 version behaves properly.

[psi29a]

valgrind it! Can we use wine and valgrind to get to the bottom of this? (gdb?)

[sezero]

valgrind it!

I wish :) No valgrind for windows, and I don't know whether
there are any equivalents of it.

Can we use wine and valgrind to get to the bottom of this? (gdb?)

Don't know, never ever tried such a thing, be my guest :)

[Allofich]

Just to let you know, Visual Studio's "Code Analysis" (built-in static analysis) includes a number of warnings about possible dereferencing of null pointers, etc., including in code in the neighborhood of the problem area. I don't know the severity of these warnings, whether they are false positives or the like, but I've tried running Code Analysis on a few different projects and I don't recall ever seeing this many warnings about potential memory problems, so it may at least be worth looking at. For reference, here is the output (using latest master branch):

c:\wildmidi\src\wm_error.c(96): warning C6387: 'errorstring' could be '0':  this does not adhere to the specification for the function 'sprintf'. 
c:\wildmidi\src\wm_error.c(101): warning C6011: Dereferencing NULL pointer 'errorstring'. See line 96 for an earlier location where this can occur
c:\wildmidi\src\wm_error.c(110): warning C6387: 'errorstring' could be '0':  this does not adhere to the specification for the function 'vsprintf'. 
c:\wildmidi\src\wm_error.c(112): warning C6011: Dereferencing NULL pointer 'errorstring'. See line 110 for an earlier location where this can occur
c:\wildmidi\src\file_io.c(275): warning C6386: Buffer overrun while writing to 'data':  the writable size is '*size+1' bytes, but '*size' bytes might be written.
c:\wildmidi\src\wildmidi_lib.c(155): warning C6011: Dereferencing NULL pointer 't'. 
c:\wildmidi\src\wildmidi_lib.c(231): warning C6001: Using uninitialized memory '*tmp_sample'.
c:\wildmidi\src\wildmidi_lib.c(331): warning C6308: 'realloc' might return null pointer: assigning null pointer to 'token_data', which is passed as an argument to 'realloc', will cause the original memory block to be leaked.
c:\wildmidi\src\wildmidi_lib.c(348): warning C6308: 'realloc' might return null pointer: assigning null pointer to 'token_data', which is passed as an argument to 'realloc', will cause the original memory block to be leaked.
c:\wildmidi\src\wildmidi_lib.c(847): warning C6308: 'realloc' might return null pointer: assigning null pointer to 'mdi->mix_buffer', which is passed as an argument to 'realloc', will cause the original memory block to be leaked.
c:\wildmidi\src\wildmidi_lib.c(1165): warning C6308: 'realloc' might return null pointer: assigning null pointer to 'mdi->mix_buffer', which is passed as an argument to 'realloc', will cause the original memory block to be leaked.
c:\wildmidi\src\wildmidi_lib.c(1907): warning C6011: Dereferencing NULL pointer 'event->do_event'. 
c:\wildmidi\src\internal_midi.c(551): warning C6308: 'realloc' might return null pointer: assigning null pointer to 'mdi->events', which is passed as an argument to 'realloc', will cause the original memory block to be leaked.
c:\wildmidi\src\internal_midi.c(1876): warning C6387: 'mdi' could be '0':  this does not adhere to the specification for the function 'memset'. 
c:\wildmidi\src\internal_midi.c(1878): warning C6011: Dereferencing NULL pointer 'mdi'. See line 1876 for an earlier location where this can occur
c:\wildmidi\src\internal_midi.c(2101): warning C6308: 'realloc' might return null pointer: assigning null pointer to 'mdi->extra_info.copyright', which is passed as an argument to 'realloc', will cause the original memory block to be leaked.
c:\wildmidi\src\internal_midi.c(2368): warning C6387: 'sysex_store' could be '0':  this does not adhere to the specification for the function 'memcpy'. 
c:\wildmidi\src\internal_midi.c(2370): warning C6011: Dereferencing NULL pointer 'sysex_store'. See line 2368 for an earlier location where this can occur
c:\wildmidi\src\internal_midi.c(2372): warning C6387: 'sysex_store' could be '0':  this does not adhere to the specification for the function 'memcmp'. See line 2368 for an earlier location where this can occur
c:\wildmidi\src\patches.c(96): warning C6308: 'realloc' might return null pointer: assigning null pointer to 'mdi->patches', which is passed as an argument to 'realloc', will cause the original memory block to be leaked.
c:\wildmidi\src\patches.c(98): warning C28182: Dereferencing NULL pointer. 'mdi->patches' contains the same NULL value as 'realloc()`96' did. 
c:\wildmidi\src\f_midi.c(951): warning C6308: 'realloc' might return null pointer: assigning null pointer to '*out', which is passed as an argument to 'realloc', will cause the original memory block to be leaked.
c:\wildmidi\src\mus2mid.c(136): warning C6308: 'realloc' might return null pointer: assigning null pointer to 'ctx->dst', which is passed as an argument to 'realloc', will cause the original memory block to be leaked.
c:\wildmidi\src\xmi2mid.c(125): warning C6308: 'realloc' might return null pointer: assigning null pointer to 'ctx->dst', which is passed as an argument to 'realloc', will cause the original memory block to be leaked.
c:\wildmidi\src\xmi2mid.c(564): warning C6011: Dereferencing NULL pointer 'event'. 
c:\wildmidi\src\xmi2mid.c(576): warning C6011: Dereferencing NULL pointer 'ctx->current'. 

There are other warnings as well, but these are the most interesting ones. I haven't examined these, but who knows, maybe addressing something in here will solve something that is tripping up MSVC, or maybe there is something worth fixing for all platforms.

[afritz1]

I tried the MinGW build of WildMIDI 0.4.2 and songs finish as expected, so that's more evidence that it's a problem between WildMIDI and MSVC (or more WildMIDI because MSVC runtime conflicts were ruled out).

Allofich said: To be honest I don't quite understand what he was saying, though. If he means that mismatch is between the .dll used in OpenTESArena and WildMIDI then that is probably not the issue, since WildMIDI crashes on its own.

I guess I was a little unclear there. My point was that having WildMIDI built with a newer MSVC version might fix the problem, but it seems that's not the case, so no worries. WildMIDI does crash on its own, so it can't be a .dll mismatch.

@sezero, it's fine if you don't have MSVC builds anymore since WildMIDI is pretty easy to download and build, but it would be better if we can help you get to the bottom of this issue. Maybe that pause you're seeing is Windows silently writing a memory dump somewhere? Just a guess.

[sezero]

Built for win32 (x86) using Open Watcom 1.9, and the result behaves OK too. Hrmph..

[sezero]

it would be better if we can help you get to the bottom of this issue.

Indeed, I'd like that very much (I'm a hopeless perfectionist, so I
don't like being incomplete..)

Maybe that pause you're seeing is Windows silently writing a memory
dump somewhere?

Possibly, I don't know.

[psi29a]

I just used wildmidi-0.4.2-win64/msvc/wildmidi.exe under wine and I'm not able to reproduce the problem.

[psi29a]

I'm using L"Microsoft.VC80.CRT" (8.0.50727.6195)

[Allofich]

I did more investigation and found something interesting.

The .XMI files were crashing on:

else if (mdi->events[i].do_event == _WM_do_meta_copyright) {
                    free(mdi->events[i].event_data.data.string);
}

However, I checked the .XMI file for what events were being created while processing it, and _WM_do_meta_copyright was not among them. The first event was _WM_do_midi_divisions, yet
if (mdi->events[i].do_event == _WM_do_meta_copyright) was being evaluated true.

I then thought to check whether (_WM_do_midi_divisions == _WM_do_meta_copyright) would be evaluated true, and it was in the Release build but not the RelWithDebugInfo build.

Both of these functions are only "placeholders" as they are commented. They have the same parameters and the same bodies of WMIDI_UNUSED(data); and WMIDI_UNUSED(mdi);

Changing the _WM_do_meta_copyright function by copying in the contents of a non-placeholder (I used the content of _WM_do_meta_lyric) caused if (mdi->events[i].do_event == _WM_do_meta_copyright) to evaluate to false, and the crash to happen at the next placeholder function in these else if statements. Adding in the _WM_do_meta_lyric content to all of the placeholders, they were all passed over and no crash happened.

So it seems the Release build treats all of these empty functions as equal, leading to the crash. I haven't looked into it but I assume that, for example, _WM_do_midi_divisions should not call free() in _WM_freeMDI, since it is not among the if statements, but because the Release build considers it the same as those placeholders, free() does get called, and a crash happens. Seems like ways to stop the crash are to somehow ensure that the functions are seen as different, to identify the events that need free() in some other way than the event function, etc.

[psi29a]

Nice find!

So this is an over-optimization by the msvc compiler?

[sezero]

However, I checked the .XMI file for what events were being created while processing it,
and _WM_do_meta_copyright was not among them.

Yeah, I told you so: #192 (comment)

Maybe this has something to do with linkage???

[sezero]

So this is an over-optimization by the msvc compiler?

Huh, not impossible

[sezero]

Why don't we add an event_type member to the struct and compare that
instead of comparing the function pointers? Do you think that it would help?

[sezero]

Can you guys review and test the new 'bug192' branch?

[psi29a]

@sezero that's a lot cleaner...

[sezero]

Just tested on Windows using VS2017, the new 'bug192' branch runs OK for me.

[psi29a]

@Allofich and @afritz1 can you please test?

[afritz1]

I downloaded the bug192 branch, built it with VS2015 (x64 and x86) in Release, ran it both in the console and linked with OpenTESArena, and it doesn't crash when a song is freed! Everything seems to be working with the Release build. What a strange bug with function pointer optimization.

[sezero]

OK, then. Changes merged to master as of da69848

Closing as fixed. Thanks for the report and identifying the root cause.

[psi29a]

Thanks for reporting and digging into the problem! :)

[Allofich]

The latest master branch works fine for me as well. Thanks for the fix!

[chrisisonwildcode]

I'm in the process of setting up a windows10 machine for development and testing. Would of been done by now except I had to get the first one replaced after it failed. Will also be V'boxing ubuntu and freebsd.

So scrolling up ... and down, as well as checking the commits. Gah I dislike optimisation bugs.

While I like how this problem was fixed I gotta ask, if MSVC was combining simular functions, would a simpler work around be done by adding like an char _WM_someuniquename = some unique value; to each of the functions in internal_midi.c?

[sezero]

would a simpler work around be done by adding like an
char _WM_someuniquename = some unique value;
to each of the functions in internal_midi.c?

I might have been simpler, perhaps, but I felt that the current
solution is cleaner (is it not?)

[psi29a]

I think the current way is cleaner, it's pretty much why a switch statement exists. :)