Read disc data asynchronously in a new thread #2149

JosJuice · 2015-02-28T15:33:13Z

DVDInterface inserts a delay when executing commands so that loading times will be similar to ones on consoles. During the delay, the CPU thread continues emulating the CPU. DVDInterface schedules a CoreTiming event so that it can execute the command after the delay. Executing the command involves reading data from the hard drive, a somewhat slow process... And it's happening on the CPU thread, so once the CoreTiming event starts running, CPU emulation needs to wait until DVDInterface is done.

This PR creates a new thread that reads data from the hard drive (and decompresses it, if a compressed disc image format is used) during the delay while the CPU thread is emulating the CPU. Copying the data to the emulated RAM is not done in this new thread; it's done in a CoreTiming event like before, so this PR shouldn't change the timing from the emulated system's point of view, and everything should still be deterministic. It could be useful to have an option to copy to RAM immediately after the data has been read, but I'm going to save that for a future PR.

@JMC47 Could you test the performance of this in a place where a lot of data is being read from the disc? FMVs, maybe? Make sure to have SUDTR off, because this isn't going to improve the performance of SUDTR. The difference in performance should be bigger if the ISO is on a slow storage device.

magumagu · 2015-03-03T05:42:33Z

It would be nice to have some sort of logging so we can compare how long a read takes in emulated time vs. real time it took.

JosJuice · 2015-03-03T06:32:02Z

With something like DEBUG_LOG? Sure, I can do that.

JosJuice · 2015-03-03T15:39:20Z

I've added logging (enable DVDInterface and Debug to see it), but the precision is apparently limited to 1 ms. Is std::chrono::steady_clock always this bad, or is it just a Windows problem? Are there any better options?

nrnilsen · 2015-03-03T16:06:45Z

std::chrono::duration_caststd::chrono::microseconds ---> std::chrono::duration_caststd::chrono::nanoseconds perhaps? ref

Source/Core/Core/HW/DVDThread.cpp

+static std::thread g_DVD_thread;
+static std::mutex g_DVD_mutex;
+static std::condition_variable g_DVD_condition_working;
+static bool g_DVD_working = false;


JosJuice · 2015-03-03T16:19:08Z

The result when changing microseconds to nanoseconds is pretty much the same, except 1000 times larger.

magumagu · 2015-03-03T18:46:53Z

Common::Timer::GetTimeUs() has higher resolution.

JosJuice · 2015-03-03T19:01:18Z

That works well. Thanks!

JMC47 · 2015-03-04T00:49:31Z

I did test this a bit. I'm not sure if it was random, but when loading Metroid Prime (saved at the ship) I saw Samus already standing outside of the ship when it first loaded, then the cutscene played with her getting out of the ship. Maybe that can happen in master too, or maybe it can even happen on console.

Otherwise, performance seemed fine.

JosJuice · 2015-03-06T19:12:03Z

I've also been testing Metroid Prime a bit, and I've found an obvious issue that seems to be consistently reproducible. First, start the game (GM8E01) as usual, then press Start+B+X to restart the game. Dolphin will display the following two panic alerts:

Unknown Pointer 0x01800000 PC 0x813008ac LR 0x813006ac
Invalid range in CopyToEmu. 14a0 bytes to 0x017feb60

After dismissing them, the game appears to be working normally at first, but there are several problems. When selecting a save file, the background music disappears. Once in-game, all audio is gone, and the HUD except for the health meter is also gone. The game also spawns you in the wrong room. My save was at the first save station in Phazon Mines, but I didn't start there. I started at the elevator going into Phazon Mines, with the elevator cutscene playing instead of the save station cutscene. When heading into the next room, the game acted as if it was my first time there, with the new area cutscene playing and the pirates present. My items and map were intact, though.

The CopyToEmu that triggers the panic alert is indeed the one in DVDThread. That CopyToEmu is pretty much the only thing that this PR changes in the DI-CPU interface. Earlier, DVDInterface used GetPointer and then asked DiscIO to write to that pointer. DVDThread now has its own buffer that it asks DiscIO to write to, and then it uses CopyToEmu at the end. I assume that the GetPointer method skips some error checking and thus somehow works, but I really don't know much more than that. It's technically possible to change DVDThread's code back to GetPointer plus a memcpy, but from what I understand, that's bad to do... Does anyone know what to do with this?

magumagu · 2015-03-06T19:21:21Z

That's a bug in CopyToEmu: the range ending at 0x01800000 is valid (even though 0x01800000 itself can't be dereferenced). I guess in GetPointer(), address < REALRAM_SIZE should be address <= REALRAM_SIZE.

JosJuice · 2015-03-06T19:38:11Z

That seems to do the trick. I've added a commit with that fix.

Source/Core/Core/HW/DVDThread.cpp

+	CoreTiming::ScheduleEvent_Immediate(s_callback_event_type, DVDInterface::INT_TCINT);
+}
+
+void DVDThread()


Source/Core/Core/HW/Memmap.cpp

-	        GetPointer(address + u32(size)) != nullptr &&
-	        size < EXRAM_SIZE); // Make sure we don't have a range spanning seperate 2 banks
+	        GetPointer(address + u32(size) - 1) != nullptr &&
+	        size <= EXRAM_SIZE); // Make sure we don't have a range spanning 2 separate banks


Source/Core/Core/HW/DVDThread.cpp

+	          Common::Timer::GetTimeUs() - s_realtime_started_us,
+	          (CoreTiming::GetTicks() - s_time_read_started) / (SystemTimers::GetTicksPerSecond() / 1000 / 1000));
+
+	while (!s_DVD_success)


degasus · 2015-11-09T17:27:55Z

I've checked out the "native" OS ways to do this on linux: There is the AIO framework which sounds like exactly what we want here, but with lots of pitfalls. eg the read must match the block size, ..., and the worst, those IOs bypass the cache. Still possible, but I'm not sure if this fits well.
The other way is the official posix way. But glibc will just spawn a new thread per IO request. So using our own worker thread should be much faster.

I have no clue about windows, but this sounds like just a generic implementation with a worker thread might be very fine...

Source/Core/Core/HW/DVDThread.cpp

+{
+	WaitUntilIdle();
+
+	DEBUG_LOG(DVDINTERFACE, "Disc has been read. Real time: %llu us. Real time including delay: %llu us. Emulated time including delay: %llu us.",


degasus · 2015-11-12T00:12:16Z

I've tested this code quite a bit today, and it seems to work just great. I didn't expect dolphin to be blocked for 10ms often just for disk access, but we are. At least here on my hard disk.

To be honest, I guess it may also be worth to delay it even more, eg as long as the real harddisk need.

Source/Core/Core/HW/DVDThread.cpp

+	}
+
+	if (s_DVD_success)
+		Memory::CopyToEmu(s_output_address, s_DVD_buffer.data(), s_length);


degasus · 2015-11-16T18:05:52Z

LGTM

Source/Core/Core/HW/DVDThread.cpp

+	{
+		// Asking "Do you want to retry?" would be more user friendly,
+		// but if panic alerts are turned off, the answer is automatically Yes,
+		// and we don't want an infinite loop where ReadFromDisc always fails...


This gives the CPU thread more time to do CPU things.

ValidCopyRange incorrectly returned false and stopped a CopyToEmu when pressing B+X+Start in some GameCube games (for instance Metroid Prime) after the DVD thread was implemented

It was previously an important part of DVDInterface, but since its usage there was replaced with DVDThread, the only remaining uses of it are in Boot and Boot_BS2Emu.

Read disc data asynchronously in a new thread

dolphin-emu-bot · 2015-11-17T09:23:23Z

FifoCI detected that this change impacts graphical rendering. Here are the behavior differences detected by the system:

cel-damage-lighting on ogl-lin-intel: failed to render
DKCR-Char on ogl-lin-intel: failed to render
mp3-bloom on ogl-lin-intel: failed to render
nsmbw-coins on ogl-lin-intel: failed to render
sms-gc on ogl-lin-intel: failed to render
soniccolors-mm on ogl-lin-intel: failed to render
sonicriderszg-gb on ogl-lin-intel: failed to render
spyro-bloom on ogl-lin-intel: failed to render
ss-map on ogl-lin-intel: failed to render

_{^{automated-fifoci-reporter}}

JosJuice force-pushed the async-disc-io branch 4 times, most recently from 4f9c115 to 1c1fc21 Compare March 1, 2015 09:24

JosJuice force-pushed the async-disc-io branch from 1c1fc21 to cd67da1 Compare March 3, 2015 15:39

JosJuice force-pushed the async-disc-io branch 2 times, most recently from b2dfc49 to d5083f5 Compare March 3, 2015 15:41

lioncash reviewed Mar 3, 2015
View reviewed changes

Source/Core/Core/HW/DVDThread.cpp

static std::thread g_DVD_thread;

static std::mutex g_DVD_mutex;

static std::condition_variable g_DVD_condition_working;

static bool g_DVD_working = false;

This comment was marked as off-topic.

Sign in to view

JosJuice force-pushed the async-disc-io branch 2 times, most recently from e4ee5f8 to 75c8968 Compare March 3, 2015 17:06

JosJuice force-pushed the async-disc-io branch from 75c8968 to 7a2b5e7 Compare March 3, 2015 19:01

JosJuice force-pushed the async-disc-io branch from 7a2b5e7 to 587d9d5 Compare March 6, 2015 19:38

JosJuice force-pushed the async-disc-io branch 6 times, most recently from ac301c2 to fe318ce Compare March 13, 2015 10:21

JosJuice force-pushed the async-disc-io branch from fe318ce to 711cdd2 Compare March 20, 2015 20:02

degasus reviewed Nov 9, 2015
View reviewed changes

Source/Core/Core/HW/DVDThread.cpp

CoreTiming::ScheduleEvent_Immediate(s_callback_event_type, DVDInterface::INT_TCINT);

}

void DVDThread()

This comment was marked as off-topic.

Sign in to view

JosJuice force-pushed the async-disc-io branch from 4635f82 to 5805dd7 Compare November 9, 2015 11:34

degasus reviewed Nov 9, 2015
View reviewed changes

JosJuice force-pushed the async-disc-io branch from 5805dd7 to c040bc0 Compare November 9, 2015 11:38

degasus reviewed Nov 9, 2015
View reviewed changes

degasus reviewed Nov 11, 2015
View reviewed changes

Source/Core/Core/HW/DVDThread.cpp

{

WaitUntilIdle();

DEBUG_LOG(DVDINTERFACE, "Disc has been read. Real time: %llu us. Real time including delay: %llu us. Emulated time including delay: %llu us.",

This comment was marked as off-topic.

Sign in to view

degasus reviewed Nov 12, 2015
View reviewed changes

JosJuice force-pushed the async-disc-io branch 2 times, most recently from b649bf8 to ec3ddb8 Compare November 16, 2015 15:23

phire reviewed Nov 16, 2015
View reviewed changes

JosJuice added 6 commits November 16, 2015 23:20

Create DVDThread (no multithreading yet)

c119ad4

Read disc data asynchronously in DVDThread

54ff4bd

This gives the CPU thread more time to do CPU things.

DVDThread: Performance logging

3d7afda

Memmap: Fix a CopyToEmu bug

555eb11

ValidCopyRange incorrectly returned false and stopped a CopyToEmu when pressing B+X+Start in some GameCube games (for instance Metroid Prime) after the DVD thread was implemented

Move DVDRead from DVDInterface to Boot

e3b9e89

It was previously an important part of DVDInterface, but since its usage there was replaced with DVDThread, the only remaining uses of it are in Boot and Boot_BS2Emu.

Don't use GetPointer in DVDRead

1202c2e

JosJuice force-pushed the async-disc-io branch from ec3ddb8 to 1202c2e Compare November 17, 2015 08:55

degasus added a commit that referenced this pull request Nov 17, 2015

Merge pull request #2149 from JosJuice/async-disc-io

24c7d23

Read disc data asynchronously in a new thread

degasus merged commit 24c7d23 into dolphin-emu:master Nov 17, 2015

JosJuice deleted the async-disc-io branch November 17, 2015 09:11

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Read disc data asynchronously in a new thread #2149

Read disc data asynchronously in a new thread #2149

JosJuice commented Feb 28, 2015

magumagu commented Mar 3, 2015

JosJuice commented Mar 3, 2015

JosJuice commented Mar 3, 2015

nrnilsen commented Mar 3, 2015

This comment was marked as off-topic.

JosJuice commented Mar 3, 2015

magumagu commented Mar 3, 2015

JosJuice commented Mar 3, 2015

JMC47 commented Mar 4, 2015

JosJuice commented Mar 6, 2015

magumagu commented Mar 6, 2015

JosJuice commented Mar 6, 2015

This comment was marked as off-topic.

This comment was marked as off-topic.

This comment was marked as off-topic.

This comment was marked as off-topic.

degasus commented Nov 9, 2015

This comment was marked as off-topic.

degasus commented Nov 12, 2015

This comment was marked as off-topic.

This comment was marked as off-topic.

This comment was marked as off-topic.

This comment was marked as off-topic.

This comment was marked as off-topic.

This comment was marked as off-topic.

This comment was marked as off-topic.

degasus commented Nov 16, 2015

This comment was marked as off-topic.

This comment was marked as off-topic.

This comment was marked as off-topic.

This comment was marked as off-topic.

This comment was marked as off-topic.

dolphin-emu-bot commented Nov 17, 2015

Read disc data asynchronously in a new thread #2149

Read disc data asynchronously in a new thread #2149

Conversation

JosJuice commented Feb 28, 2015

magumagu commented Mar 3, 2015

JosJuice commented Mar 3, 2015

JosJuice commented Mar 3, 2015

nrnilsen commented Mar 3, 2015

This comment was marked as off-topic.

JosJuice commented Mar 3, 2015

magumagu commented Mar 3, 2015

JosJuice commented Mar 3, 2015

JMC47 commented Mar 4, 2015

JosJuice commented Mar 6, 2015

magumagu commented Mar 6, 2015

JosJuice commented Mar 6, 2015

This comment was marked as off-topic.

This comment was marked as off-topic.

This comment was marked as off-topic.

This comment was marked as off-topic.

degasus commented Nov 9, 2015

This comment was marked as off-topic.

degasus commented Nov 12, 2015

This comment was marked as off-topic.

This comment was marked as off-topic.

This comment was marked as off-topic.

This comment was marked as off-topic.

This comment was marked as off-topic.

This comment was marked as off-topic.

This comment was marked as off-topic.

degasus commented Nov 16, 2015

This comment was marked as off-topic.

This comment was marked as off-topic.

This comment was marked as off-topic.

This comment was marked as off-topic.

This comment was marked as off-topic.

dolphin-emu-bot commented Nov 17, 2015