DRAM interface writeQueueSize not being drained.

[olumide-x]

Describe the bug
I'm repeatedly encountering situations where the MemCtrl stops scheduling requests even though mem_intr->writeQueueSize is not zero.
Please refer to the this conversation for a full description of the issue.

I cannot perfectly reproduce the behaviour but I have captured a packet sequence that I play into the MemCtrl. The behaviour is not the same as the non-draining behaviour but the MemCtrl gets into state where it prints

<timestamp> : system.mem_ctrl: QoS Turnarounds selected state

forever.

Affects version
gem5 version 24.0.0.1

gem5 Modifications
I have not modified the gem5 sources but I have added some sim objects as EXTRAS. None of those sim objects are used in the reproduction.

To Reproduce
Fetch the gitlab following gists:

1. packet_replayer.hh
2. packet_replayer.cc
3. PacketReplayer.py.
4. packet_replayer_config.py
5. packets.log

Alternatively browse my gists: https://gist.github.com/olumide-x

Next:

1. Build the PacketReplayer source as an EXTRA or add it to the gem5 source directory.
2. Execute the simulation with the default values and with the PacketReplayer debug flag as follows: ./gem5.debug --debug-flags=PacketReplayer packet_replayer_config.py. You will notice that simulation seems to halt.
3. Edit packet_replayer_config.py and reduce the num_lines parameter (on line 18) to say 10 and rerun. This time the simulation self-terminates.
4. Rerun the simulation with the original num_lines parameter but enable the MemCtrl debug flag, like so ./gem5.debug --debug-flags=MemCtrl packet_replayer_config.py. You should find that the MemCtrl seems to get stuck in a loop as shown in the terminal output below.

Terminal Output

...
12563782: system.mem_ctrl: QoS Turnarounds selected state WRITE
12563782: system.mem_ctrl: Access to 0x3c03c000, ready at 12610141 next burst at 12596504.
12563782: system.mem_ctrl: Command for 0x3c03c000, issued at 12592872.
12567414: system.mem_ctrl: QoS Turnarounds selected state WRITE
12567414: system.mem_ctrl: Removing burstTick for 12560000
12567414: system.mem_ctrl: Access to 0x3c03bec0, ready at 12613773 next burst at 12600136.
12567414: system.mem_ctrl: Command for 0x3c03bec0, issued at 12596504.
12571046: system.mem_ctrl: QoS Turnarounds selected state WRITE [turnaround triggered]
12571046: system.mem_ctrl: Switching to reads after 73 writes with 15 writes waiting
15851365: system.mem_ctrl: QoS Turnarounds selected state READ
19722275: system.mem_ctrl: QoS Turnarounds selected state READ
23607730: system.mem_ctrl: QoS Turnarounds selected state READ
27493185: system.mem_ctrl: QoS Turnarounds selected state READ
31378640: system.mem_ctrl: QoS Turnarounds selected state READ
35264095: system.mem_ctrl: QoS Turnarounds selected state READ
39149550: system.mem_ctrl: QoS Turnarounds selected state READ
43035005: system.mem_ctrl: QoS Turnarounds selected state READ
46920460: system.mem_ctrl: QoS Turnarounds selected state READ
50805915: system.mem_ctrl: QoS Turnarounds selected state READ
54691370: system.mem_ctrl: QoS Turnarounds selected state READ
58576825: system.mem_ctrl: QoS Turnarounds selected state READ
62462280: system.mem_ctrl: QoS Turnarounds selected state READ
66347735: system.mem_ctrl: QoS Turnarounds selected state READ
70233190: system.mem_ctrl: QoS Turnarounds selected state READ
74118645: system.mem_ctrl: QoS Turnarounds selected state READ
78004100: system.mem_ctrl: QoS Turnarounds selected state READ
81889555: system.mem_ctrl: QoS Turnarounds selected state READ
85775010: system.mem_ctrl: QoS Turnarounds selected state READ
89660465: system.mem_ctrl: QoS Turnarounds selected state READ
93545920: system.mem_ctrl: QoS Turnarounds selected state READ
97431375: system.mem_ctrl: QoS Turnarounds selected state READ
101316830: system.mem_ctrl: QoS Turnarounds selected state READ
105202285: system.mem_ctrl: QoS Turnarounds selected state READ
109087740: system.mem_ctrl: QoS Turnarounds selected state READ
112973195: system.mem_ctrl: QoS Turnarounds selected state READ
...

Additionally: rename "WriteReq" to "ReadReq" in packets.log and rerun. You should notice the same behaviour.

Expected behaviour
The MemCtrl ought to be able to handle any pattern of traffic.

Host Operating System
Ubuntu 22.04.5 LTS

Host ISA
AMD x64

Compiler used
g++ 13.1.0

[erin-le]

@olumide-x: Hello, thank you for opening this issue! There have been numerous changes to gem5 since v24.0.0.1, so could you try reproducing this issue on the current develop version of gem5? Thank you!

[olumide-x]

@olumide-x: Hello, thank you for opening this issue! There have been numerous changes to gem5 since v24.0.0.1, so could you try reproducing this issue on the current develop version of gem5? Thank you!

I've done this. The problem still exists in the develop branch, although the MemCtrl now conks off after exactly 1122 repeated read or write requests.

[olumide-x]

Small comment:
qos::MemCtrl::logRequest() and qos::MemCtrl::logResponse() increment and decrement totalWriteQueueSize and totalReadQueueSize respectively. This isn't "logging", and therefore violates the single responsibility principle.
https://github.com/gem5/gem5/blob/stable/src/mem/qos/mem_ctrl.cc#L111

We are also finding that the totalWriteQueueSize is remains at 64 "forever", hinting that WRITEs are not being flushed.

[powerjg]

I think we need more information to help. As you have seen, it's expected that requests in the write queue will not be drained unless it gets to the high water mark (which is a parameter, IIRC). Read requests should alway return. If you're driving the memory controller with a trace player. There is no guarantee that at the end of simulation there won't be requests in the read/write queue unless your trace player waits for the responses for all reads (then writes also have guarantee of propagating). That said, the MemCtrl and DRAMCtrl objects are timing only. It's the underlying AbstractMemory class and its pointer the the PhysicalMemory (owned by System) that holds the functional data.

[olumide-x]

I think we need more information to help. As you have seen, it's expected that requests in the write queue will not be drained unless it gets to the high water mark (which is a parameter, IIRC). Read requests should alway return. If you're driving the memory controller with a trace player. There is no guarantee that at the end of simulation there won't be requests in the read/write queue unless your trace player waits for the responses for all reads (then writes also have guarantee of propagating). That said, the MemCtrl and DRAMCtrl objects are timing only. It's the underlying AbstractMemory class and its pointer the the PhysicalMemory (owned by System) that holds the functional data.

Hi Jason,

I demonstrated the issue with a trace player to isolate it from the code where I first noticed the problem.

The problem happens with different combinations of requests e.g. reads alone or writes alone. The trace file I supplied for example contains 3000 reads yet the controller gets stuck in a loop after 1122 requests. The player never reaches the last memory request.

The player waits for responses to every packet it sent and only then terminates the simulation.

You will also recall that, in my post on the mailing list, I pointed out that the memory controller was reaching line 964 where it stops scheduling events even though mem_intr->writeQueueSize != 0.

Is there something you would like me to check?

[erin-le]

I was able to reproduce the issue on develop with the given information.

[relokin]

A bit of a long shot because I haven't fully understood the problem you've run into. Have you tried setting min_reads_per_switch to 0? We have found the default value of 16 to not be ideal from a performance point a view. Does that help?