Myst ME crashes when dropping key in stoneship age

[clbr]

Using scummvm 2.1.0 release tarball, Myst Masterpiece Edition (from a bonus cd in a Sony cdr spindle) crashes with this message:

scummvm: ./common/array.h:192: T& Common::Array<T>::operator[](uint) [with T = Common::QuickTimeParser::EditListEntry]: Assertion `idx < _size' failed.

My binary is stripped, so gdb backtrace has nothing useful.

Repro steps from the attached save:

• turn around
• go to the lighthouse thing
• look down
• click on the key

There seem to be no relevant Mohawk commits since the 2.1.0 release that could address this crash, so probably applies to today's git.

[clbr]

Myst save in the stoneship age, close to the crash point

[clbr]

Oh, this is on 64-bit Linux, SDL version.

ScummVM 2.1.0 (Jan 27 2020 12:45:58)
Features compiled in: Vorbis MP3 ALSA SEQ TiMidity RGB zLib Theora AAC FreeType2 JPEG PNG libcurl

[bgK]

Hi,

Thank you for your report. This looks like an issue related to reading a video file. Could you please check the files were copied without error from your CD? Could you also please post here the md5 of the files in your qtw/stone folder. And check the file key.mov plays correctly with ffplay. Here are my md5s for comparison:

6b82288184fa9435f020562118a8a5f9 ACHHOLO.MOV
1124da0f53af508f335e0e3dfc093e26 ACHOLOCN.MOV
98b1c44ed475cab8756690a07c1b9d26 BKROOM.MOV
19bdeac82e4311dab5ad5775ec94653f GENERATR.MOV
f64347a58be6c4b27b18c8caa91d8549 KEYCHEST.MOV
3b5ee6da31473dd69ab0821f61b7d695 KEYDRY.MOV
9949418ec43afc619998093cf47122e7 KEY.MOV
e8b89ef00c43eaa28fb1f4433f9bde64 LIGSPIG.MOV
e1822e911fc66b03a94fb2d82c0bf897 MYSTLIB.MOV
8651c3ebabde7d10e02074eb49e65da1 OPENLOC.MOV
b84b04d498d69a2bb98ef8292e5fec16 SIRSDSK.MOV
b5d269a7f390e3e72f0b6d2c12be5360 SIRSPHEE.MOV
e4c156aa666adaf8f911ba9a01d5f87f SIRSPHWW.MOV
c6838607202c1be7a581b853fa78b06f TUNADOWN.MOV
af19f0ff6becdd3d3baec5cf01702e7e TUNAUP.MOV
a93347db9751ebba7f853ba28b21cf54 TUNCDOWN.MOV
b380bef8fb87c2d80dced7f2b8531236 TUNCUP.MOV

[clbr]

The md5sums in that dir match yours perfectly, and KEY.MOV plays perfect in mplayer. However I see that video ingame too, the crash happens when the video ends (or in its last frames, hard to tell).

[bgK]

The QuickTime certainly had bugs before. However it's quite tricky. I'll need more information and ideally a way to reproduce the issue. Is it possible for you to make a debug build and get a proper backtrace?

[clbr]

Yes, I can do a debug build soon, maybe tomorrow. I take you can't repro with my save above?

[bgK]

No, I can't repro neither with v2.1.0 nor master.

[clbr]

Here's gdb bt from today's master (8a8336328e8)

scummvm: ./common/array.h:192: T& Common::Array<T>::operator[](uint) [with T = Common::QuickTimeParser::EditListEntry]: Assertion `idx < _size' failed.

Program received signal SIGABRT, Aborted.
0x00007ffff45eb095 in raise () from /lib/libc.so.6
(gdb) bt full
#0  0x00007ffff45eb095 in raise () from /lib/libc.so.6
No symbol table info available.
#1  0x00007ffff45ec540 in abort () from /lib/libc.so.6
No symbol table info available.
#2  0x00007ffff45e468f in __assert_fail () from /lib/libc.so.6
No symbol table info available.
#3  0x000000000055531b in operator[] (idx=<optimized out>, this=<optimized out>)
    at ./common/array.h:192
No locals.
#4  Video::QuickTimeDecoder::VideoTrackHandler::seek (this=0xb36e90, requestedTime=...)
    at video/qt_decoder.cpp:372
        convertedFrames = 450
        time = {_secs = -13184, _numFrames = 32767, _framerate = 11761968, _framerateFactor = 0}
        __PRETTY_FUNCTION__ = "virtual bool Video::QuickTimeDecoder::VideoTrackHandler::seek(const Audio::Timestamp&)"
#5  0x0000000000557cf0 in Video::VideoDecoder::seekIntern (this=0xb369f0, time=...)
    at video/video_decoder.cpp:503
        it = 0xf3a9b0
#6  0x0000000000557870 in Video::VideoDecoder::seek (this=0xb369f0, time=...)
    at video/video_decoder.cpp:362
No locals.
#7  0x000000000045e296 in Mohawk::MystAreaVideo::playMovie (this=0xb37930)
    at engines/mohawk/myst_areas.cpp:251
        rate = {_num = -1, _denom = 1}
        handle = {<Common::SafeBool<Common::SharedPtr<Mohawk::VideoEntry>, Common::impl::no_base<Common::SharedPtr<Mohawk::VideoEntry> > >> = {<Common::impl::no_base<Common::SharedPtr<Mohawk::VideoEntry> >> = {<No data fields>}, <No data fields>}, _refCount = 0xf28800, _deletion = 0xf3b780,
          _pointer = 0xfff310}
#8  0x000000000046f3a4 in Mohawk::MystScriptParser::o_triggerMovie (this=<optimized out>,
    var=<optimized out>, args=...) at engines/mohawk/myst_scripts.cpp:455
        direction = -1
        resource = 0x59b9
#9  0x000000000046da78 in Mohawk::MystScriptParser::runOpcode (this=0xb37db0, op=<optimized out>,
    var=22969, args=...) at engines/mohawk/myst_scripts.cpp:195
        i = <optimized out>
#10 0x000000000046db2f in Mohawk::MystScriptParser::runScript (this=0xb37db0, script=...,
    invokingResource=0xb37930) at engines/mohawk/myst_scripts.cpp:179
        entry = @0xb37b98: {type = Mohawk::kMystScriptNormal, resourceId = 0, opcode = 9, var = 0,
          args = {_capacity = 1, _size = 1, _storage = 0xfa6a50}, u1 = 0}
        i = 2
#11 0x000000000045f5aa in Mohawk::MystAreaAction::handleMouseUp (this=0x6)
    at engines/mohawk/myst_areas.cpp:153
No locals.
#12 0x000000000046423f in Mohawk::MystCard::updateResourcesForInput (this=0xb5e9a0, mouse=...,
    mouseClicked=false, mouseMoved=false) at engines/mohawk/myst_card.cpp:384
No locals.
#13 0x000000000045c00e in Mohawk::MohawkEngine_Myst::doFrame (this=0xffc690)
    at engines/mohawk/myst.cpp:660
        mousePos = {x = 308, y = 281}
---Type <return> to continue, or q <return> to quit---
        event = {type = Common::EVENT_CUSTOM_ENGINE_ACTION_END, kbdRepeat = false, kbd = {
            keycode = Common::KEYCODE_INVALID, ascii = 0, flags = 0 '\000'}, mouse = {x = 308,
            y = 281}, customType = 2, path = {static npos = 4294967295,
            static _builtinCapacity = 20, _size = 0, _str = 0x7fffffffce38 "", {
              _storage = "\000Ûÿ\000\000\000\000\000\004\000\000\000\b\020\b\000 µE", _extern = {
                _refCount = 0xffdb00, _capacity = 4}}}, joystick = {axis = 0 '\000', position = 0,
            button = 0 '\000'}}
#14 0x000000000045c938 in Mohawk::MohawkEngine_Myst::run (this=0x59b9)
    at engines/mohawk/myst.cpp:450
No locals.
#15 0x000000000040e624 in runGame () at base/main.cpp:295
No locals.
#16 0x000000000040fc82 in scummvm_main (argc=<optimized out>, argv=<optimized out>)
    at base/main.cpp:554
        result = {_code = Common::kNoError, _desc = {static npos = 4294967295,
            static _builtinCapacity = 20, _size = 0, _str = 0x0, {
              _storage = '\000' <repeats 19 times>, _extern = {_refCount = 0x0, _capacity = 0}}}}
        chainedGame = {static npos = 4294967295, static _builtinCapacity = 20, _size = 4094842584,
          _str = 0x0, {_storage = '\000' <repeats 19 times>, _extern = {_refCount = 0x0,
              _capacity = 0}}}
        saveSlot = 0
        plugin = 0xa66390
        specialDebug = {static npos = 4294967295, static _builtinCapacity = 20, _size = 0,
          _str = 0x7fffffffe3f0 "", {_storage = '\000' <repeats 16 times>, "påÿÿ", _extern = {
              _refCount = 0x0, _capacity = 0}}}
        command = {static npos = 4294967295, static _builtinCapacity = 20, _size = 0,
          _str = 0x7fffffffe3c0 "", {_storage = "\000àþ÷ÿ\177\000\000µLbôÿ\177\000\000;\000\000",
            _extern = {_refCount = 0x7ffff7fee000, _capacity = 4100082869}}}
        settings = {
          _nodePool = {<Common::FixedSizeMemoryPool<80ul, 10ul>> = {<Common::MemoryPool> = {
                _chunkSize = 80, _pages = {_capacity = 0, _size = 0, _storage = 0x0},
                _next = 0x7fffffffd868, _chunksPerPage = 8},
              _storage = "¸Øÿÿÿ\177", '\000' <repeats 74 times>, "\bÙÿÿÿ\177", '\000' <repeats 74 times>, "XÙÿÿÿ\177", '\000' <repeats 74 times>...}, <No data fields>}, _defaultVal = {
            static npos = 4294967295, static _builtinCapacity = 20, _size = 0,
            _str = 0x7fffffffdb98 "", {_storage = '\000' <repeats 19 times>, _extern = {
                _refCount = 0x0, _capacity = 0}}}, _storage = 0xa07690, _mask = 15, _size = 0,
          _deleted = 0, _hash = {<No data fields>}, _equal = {<No data fields>}}
        res = {_code = Common::kNoError, _desc = {static npos = 4294967295,
            static _builtinCapacity = 20, _size = 8, _str = 0x7fffffffdc18 "No error", {
              _storage = "No error\000rror\000\000\000\000\000\000", _extern = {
                _refCount = 0x726f727265206f4e, _capacity = 1869771264}}}}
        __PRETTY_FUNCTION__ = "int scummvm_main(int, const char* const*)"
#17 0x000000000040c875 in main (argc=1, argv=0x7fffffffe578)
    at backends/platform/sdl/posix/posix-main.cpp:45
        res = <optimized out>
        __PRETTY_FUNCTION__ = "int main(int, char**)"
(gdb) qui

I also ran it under valgrind. Valgrind said nothing related before the assert crash (some Conditional jump or move depends on uninitialised value in the initial game picker GUI).

[clbr]

Some more info.

(gdb)
#4  Video::QuickTimeDecoder::VideoTrackHandler::seek (this=0x1204c30, requestedTime=...)
    at video/qt_decoder.cpp:372
372                     while (!atLastEdit() && _parent->editList[_curEdit].mediaTime == -1)
(gdb) p requestedTime
$1 = (const Audio::Timestamp &) @0x7fffffffcc70: {_secs = 0, _numFrames = 2250, _framerate = 3000,
  _framerateFactor = 5}
(gdb) p _parent->editList
$2 = {_capacity = 1, _size = 1, _storage = 0xb3bea0}
(gdb) p _curEdit
$3 = 1

...

#7  0x000000000045e296 in Mohawk::MystAreaVideo::playMovie (this=0xf47460)
    at engines/mohawk/myst_areas.cpp:251
(gdb) p _videoFile
$7 = {static npos = 4294967295, static _builtinCapacity = 20, _size = 17,
  _str = 0xf474a8 "qtw/stone/key.mov", {_storage = "qtw/stone/key.mov\000\000", _extern = {
      _refCount = 0x6e6f74732f777471, _capacity = 1701523301}}}

[clbr]

Looks like a possible compiler bug, as adding printfs makes it go away. Compiling video/qt_decoder.cpp with -O1 or -O3 does not trigger it, only the default -O2 does. The compiler used is old, gcc 4.2.2.

[bgK]

Should we keep investigating?

[clbr]

I think you can close this, though could be nice to check for such bugs in configure. I could play a couple more ages in Myst with the -O3 built file fine.

[bgK]

Ok, thanks. To be fair I'm unsure how we could test for that. Closing.