dirkwhoffmann / vAmiga

vAmiga is a user-friendly Amiga 500, 1000, 2000 emulator for macOS
https://dirkwhoffmann.github.io/vAmiga
Other
293 stars 24 forks source link

Terminator 2 terminates the emulator #773

Closed dirkwhoffmann closed 1 year ago

dirkwhoffmann commented 1 year ago

In v2.2.1, T2 crashes after the title screen. Moira's code for catching double address errors is apparently not working as expected:

Bildschirm­foto 2022-12-29 um 14 01 37

Work items:

dirkwhoffmann commented 1 year ago

One more thing: The reason why I run the game in the first place was to play around with some drive parameters. We already know that the title screen looks fine with getStepReadDelay() returning MSEC(8). However, this value is outside the specs. When changing the value to MSEC(3), the title screen is corrupted:

Bildschirm­foto 2022-12-29 um 13 53 32

Now, I've added some code that shifts the tracks against each other after MFM encoding:

void
FloppyDisk::encodeDisk(const FloppyFile &file)
{
    assert(file.getDiameter() == getDiameter());

    // Start with an unformatted disk
    clearDisk();

    // Call the MFM encoder
    file.encodeDisk(*this);

    shiftTracks(10);
}

void
FloppyDisk::shiftTracks(isize offset)
{
    u8 spare[2 * 32768];

    for (Track t = 0; t < 168; t++) {

        isize len = length.track[t];

        memcpy(spare, data.track[t], len);
        memcpy(spare + len, data.track[t], len);
        memcpy(data.track[t], spare + (len + t * offset) % len, len);
    }
}

With a shift of 10 bytes per track, the title screen looks fine with a MSEC(3) delay:

Bildschirm­foto 2022-12-29 um 14 03 17

@mithrendal: I've changed my mind since my previous post about this game. It would indeed be interesting to see if the game works on real hardware. If the title screen comes up correctly, we know nothing, but if the title screen comes up corrupted, the mystery would be solved.

BTW, the game is known to use a brittle disk loader. Toni had mentioned T2 as an example at some point.

mras0 commented 1 year ago

Regarding the 3ms value, I've done some more reading (looking e.g. at Ross's well written/commented "ocean loader"). 3ms is indeed the time to wait between step pulses, but he also takes into account the head settling time before reading (15ms)! Which makes sense, the head can move quite fast, but it takes some extra time before it can start reading data properly.

I can see that it's configurable for some gotek firmware (head-settle-ms = 0-255 (12*) - Milliseconds from head-step start to RDATA active). Judging by the data we got from mithrendal's A1000 yesterday it must be quite a bit lower there (or my test is wrong). If my math isn't too far off it should on average take ~8-9ms to reach a sync word, but there we saw 9-12ms sync time after stepping (implying basically no delay).

mithrendal commented 1 year ago

It loads around 15 seconds with this screen.

A7FD56E4-B6C1-47A5-ACC7-0FBD821077FB

And then this comes

3BCB8F83-030C-4D07-97C3-6643F7675F0B

Afterwards drive makes strange noises and it goes completely weird… monitor gets no signal and then this

87C72C35-5D5E-44C7-B481-CF9044F8C192

on unmodified A1000 512Kb

dirkwhoffmann commented 1 year ago

head-settle-ms = 0-255 (12*) - Milliseconds from head-step start to RDATA active

The head-settle time is basically what getStepReadDelay() emulates, right?

@mithrendal: Thanks for running Terminator on the real machine! When run in vAmiga with 512 KB + 0 KB Slow + 0 KB Ram, it mimics what we see on the A1000:

Bildschirm­foto 2022-12-30 um 10 23 00
dirkwhoffmann commented 1 year ago

Work items: Fix Moira

The crash was due to a misaligned address fault exception vector. The resulting double-fault hadn't been catched properly. With the latest code, the emulator does no longer crash and correctly signals the double-fault in the status bar.

Bildschirm­foto 2022-12-30 um 11 24 04

Find out why the game produces this kind of error (I remember playing it).

It only crashed, because I used an unusual memory config (1024 KB + 0 KB + 8 MB). The game seems to require a standard memory config such as 512 KB + 512 KB + 0 KB:

Bildschirm­foto 2022-12-30 um 10 20 49
mras0 commented 1 year ago

head-settle-ms = 0-255 (12*) - Milliseconds from head-step start to RDATA active

The head-settle time is basically what getStepReadDelay() emulates, right?

I think so. Tried looking at the WinUAE source code, but so far haven't found the equivalent value.

It only crashed, because I used an unusual memory config (1024 KB + 0 KB + 8 MB). The game seems to require a standard memory config such as 512 KB + 512 KB + 0 KB:

The game requires 1MB and its memory allocation routine (at $70a4e) is crazy, and doesn't do any checking. It tries to allocate 512K chip mem, then discards the result, allocates $3000 bytes then ands then result with $f80000 and uses that for its data buffer, finally it allocates $7d000 bytes and discards that result as well! (Not sure why that doesn't work for that config, but it's the same in WinUAE so not worth looking into).

Regarding the corrupted image, it's kind of weird as I can't get that to happen in WinUAE despite changing disk speed (turbo/800% etc. works fine). The loader is a very widely used one from RNC starting from $70000 (Here's an annotated version I made when I was debugging an issue in my own emulator. It's probably not fully correct, but should show the gist: RNLoader_Annotated.asm.txt). One thing it does different than most other loaders is that starts by doing a short read of just a sector header ($40 bytes in what I call SearchForSector), decodes the information and uses the information to avoid reading the gap, i.e. if the header says that 3 sectors remains before the gap it reads 2 sectors [since it just missed the current one] and then 9 sectors.

It has an init routine at $7098a that apart from the weird allocation stuff also reads some data into memory. First it reads one sector ($28) to $800. This appears to hold (sector,length) word pairs of where data is stored on the disk. At $930 it finds the sector/length of for title screen code ($057d/$0038), which is then loaded to $71a00, and then it jumps here:

TitleScreen ; $00071a00
    LEA.L   dat_00071c9c, A0
    LEA.L   dat_00060000, A1
    BSR.W   UnpackRNC
    MOVE.W  #$001f, D7
    LEA.L   TrackBuffer+$0872, A0 ; !!! TrackBuffer=$78000
    MOVEA.L (A7)+, A1 ; A1=$000708c8 (palette part of copperlist, prepared by init routine)
.UpdatePalette ; $00071a1c
    MOVE.W  (A0)+, D0
    MOVE.W  D0, (A1)
    ADDQ.W  #$04, A1
    DBF.W   D7, .UpdatePalette

It's expecting the palette data to be at $78872 which makes sense as it's located in sector 1460 ($5b4) at offset 114. Sector 1460 is the last one read ($57d+$38-1) so it should go to $71a00+512*$37=$78800. This overlaps the TrackBuffer (which starts at $78000) though, but maybe the loader should handle that?

With getStepReadDelay = 8ms I see:

Starting disk read track=132 bytes=$40 dskpt=$078406 Starting disk read track=132 bytes=$880 dskpt=$078406 Starting disk read track=132 bytes=$2640 dskpt=$078C86

And getStepReadDelay = 3ms:

Starting disk read track=132 bytes=$40 dskpt=$078406 Starting disk read track=132 bytes=$1100 dskpt=$078406 Starting disk read track=132 bytes=$1DC0 dskpt=$079506

Which doesn't immediately look suspicious, but maybe the code is broken, just seems weird that it never seems to be an issue in WinUAE (at least the couple of times I've tried it). If the code is wrong I'd expect it to happen with pretty high frequency.

mras0 commented 1 year ago

Bit more logging:

3ms:

Starting disk read pos=132 bytes=$40 dskpt=$078406 offset=$1C42
Starting disk read pos=132 bytes=$1100 dskpt=$078406 offset=$2082
Blitdecode A=078440, B=078640 D=078600
Blitdecode A=078880, B=078A80 D=078800
Starting disk read pos=132 bytes=$1DC0 dskpt=$079506 offset=$2C2
Blitdecode A=079540, B=079740 D=077800
Blitdecode A=079980, B=079B80 D=077A00
Blitdecode A=079DC0, B=079FC0 D=077C00
Blitdecode A=07A200, B=07A400 D=077E00
Blitdecode A=07A640, B=07A840 D=078000
Blitdecode A=07AA80, B=07AC80 D=078200
Blitdecode A=07AEC0, B=07B0C0 D=078400

8ms:

Starting disk read pos=132 bytes=$40 dskpt=$078406 offset=$24C2
Starting disk read pos=132 bytes=$880 dskpt=$078406 offset=$2902
Starting disk read pos=132 bytes=$2640 dskpt=$078C86 offset=$2C2
Blitdecode A=078CC0, B=078EC0 D=077800
Blitdecode A=079100, B=079300 D=077A00
Blitdecode A=079540, B=079740 D=077C00
Blitdecode A=079980, B=079B80 D=077E00
Blitdecode A=079DC0, B=079FC0 D=078000
Blitdecode A=07A200, B=07A400 D=078200
Blitdecode A=07A640, B=07A840 D=078400
Blitdecode A=07AA80, B=07AC80 D=078600
Blitdecode A=07AEC0, B=07B0C0 D=078800

(Note Blitdecode is a reverse blit, I've printed the ending addresses).

So in the 3ms case it ends up overwriting the it's input data when decoding the MFM data. Forcing a similar MFM position in WinUAE for that track: image

Still odd that I can't get it to occur "naturally" though.

mras0 commented 1 year ago

Final (maybe :)) update on my findings:

It's still an open question why this doesn't happen more often IRL/in WinUAE. The way the reading is done will sort of force some disk orientations to become more unlikely/impossible, so maybe with perfectly mastered disk and fairly consistent drive timing it never occured for with the original game disks? If timings end up mostly consistant you'd notice it quickly with a pirated game, and would probably chalk it up to a bad copy, redo it and it likely would work.

In summary:

dirkwhoffmann commented 1 year ago

Final (maybe :)) update on my findings:

Awesome analysis. Thank you so much!

The value ofFloppyDrive.head.offset is slightly annoying with its implied offset of 700 bytes

I don't remember where the line

    u8 *p = disk.data.track[t] + 700 + (s * 1088);

comes from. Maybe I've seen the 700 somewhere else or it's a leftover of some experimental coding from the early days of vAmiga. I'll change it to

    u8 *p = disk.data.track[t] + (s * 1088);
dirkwhoffmann commented 1 year ago

I've reduced the head-settle time to 2 msec.

In order to not break T2 in vAmiga, I've done something I usually hate to do 🙈:

void
FloppyDisk::encodeDisk(const FloppyFile &file)
{
    assert(file.getDiameter() == getDiameter());

    // Start with an unformatted disk
    clearDisk();

    // Call the MFM encoder
    file.encodeDisk(*this);

    // Rectify the track alignment

    /* By default, all tracks are arranged to start at the same offset position.
     * Some disks, however, are known to require a different alignment to work
     * in vAmiga. We check for these disks and align the tracks accordingly.
     */
    switch (file.crc32()) {

        case 0x4db280dd:    // T2 - The Arcade Game (1993)(Virgin)[cr FLT].adf
        case 0xb41e9935:    // T2 - The Arcade Game (1993)(Virgin)[cr FLT](Disk 1 of 2).adf
        case 0x889f7bbe:    // T2 - The Arcade Game (1993)(Virgin)[cr FLT](Disk 1 of 2)[t +4 MST].adf

            shiftTracks(20);
            break;
    }
}

This reminds me on a famous quote from Joel Spolsky:

I first heard about this from one of the developers of the hit game SimCity, who told me that there was a critical bug in his application: it used memory right after freeing it, a major no-no that happened to work OK on DOS but would not work under Windows where memory that is freed is likely to be snatched up by another running application right away. The testers on the Windows team were going through various popular applications, testing them to make sure they worked OK, but SimCity kept crashing. They reported this to the Windows developers, who disassembled SimCity, stepped through it in a debugger, found the bug, and added special code that checked if SimCity was running, and if it did, ran the memory allocator in a special mode in which you could still use memory after freeing it.

I quote this in my book on software-quality as an example of questionable software design 🙄.

mras0 commented 1 year ago

Maybe I've seen the 700 somewhere else or it's a leftover of some experimental coding from the early days of vAmiga.

It makes sense if you've looked at any code that MFM encodes data, and writes it to a disk. The gap has to be at the start of the track buffer since the write is expected to wrap around by some amount depending on drive speed, and you the gap part is expected to be partially overwritten. (A lesson I had to relearn for the disktiming test). 700 is just 12668 (trackLength) - 1088*11, so that also makes sense (also avoids a special case for track 0 in the adjustment of the 0xAAAA word at the start of the sector).

I've reduced the head-settle time to 2 msec.

FWIW manuals for some compatible drives (from http://jope.fi/drives/) e.g. http://jope.fi/drives/HW_HF_C929_C940_C991_Rev-A.pdf gives a maximum head settling time of 15ms (+3ms for the normal stepping time) same for this Chinon drive. The 12ms gotek uses is probably not a bad value, but 2ms is of course still in spec and would give faster disk access.

dirkwhoffmann commented 1 year ago

I've replaced function getStepReadDelay by two new ones:

Cycle
FloppyDrive::getTrackToTrackDelay() const
{
    switch (config.mechanics) {

        case MECHANICS_NONE:    return 0;
        case MECHANICS_A1010:   return MSEC(3);

        default:
            fatalError;
    }
}

Cycle
FloppyDrive::getHeadSettleTime() const
{
    switch (config.mechanics) {

        case MECHANICS_NONE:    return 0;
        case MECHANICS_A1010:   return MSEC(9);

        default:
            fatalError;
    }
}

After switching tracks, the drive will read garbage for getTrackToTrackDelay() + getHeadSettleTime() cycles. With the A1010 profile, this results in 12 msec which is what the Gotek uses. We can always add new profiles if needed.

dirkwhoffmann commented 1 year ago

Fixed in v2.3