-
Notifications
You must be signed in to change notification settings - Fork 48
Analyze simulation results
Donghyun Gouk edited this page Oct 10, 2018
·
3 revisions
gem5 support 1. statistic printout and 2. debug log for simulation result analysis.
You can search through gem5 communities for more information (how to measure CPU utilizations and so on).
SimpleSSD prints statistics to gem5 statistic printout.
This contains statistics from each layer of SimpleSSD (HIL, ICL, FTL and PAL).
See previous section for analyze this.
SimpleSSD prints debug log to stdout of gem5 (you can change this from source code).
Following is example of debug log when initializing SimpleSSD.
0: PAL: Channel | Way | Die | Plane | Block | Page
0: PAL: 8 | 4 | 2 | 2 | 512 | 512
0: PAL: Multi-plane mode enabled
0: PAL: Superblock multiplier
0: PAL: x8 (Channel)
0: PAL: x2 (Plane)
0: PAL: Page size 16384 -> 262144
0: PAL: Total block count 65536 -> 4096
0: PAL::PALOLD: NAND timing:
0: PAL::PALOLD: Operation | LSB | CSB | MSB | DMA 0 | DMA 1
0: PAL::PALOLD: READ | 40000000 | 0 | 65000000 | 16689 | 39062500
0: PAL::PALOLD: WRITE | 500000000 | 0 | 1300000000 | 39079188 | 2384
0: PAL::PALOLD: ERASE | 3500000000 | 11920 | 2384
0: FTL: Total physical blocks 4096
0: FTL: Total logical blocks 3072
0: FTL: Logical page size 262144
0: ICL::GenericCache: CREATE | Set size 2048 | Way size 8 | Line size 32768 | Capacity 536870912
0: ICL::GenericCache: CREATE | line count in super page 8 | line count in max I/O 64
0: HIL::NVMe: NS 1 | CREATE | LBA size 512 | Capacity 805306368
This log shows how SSD is configure as provided configuration file.
In initialization process of NVMe controller (by Linux Kernel), you can see following log:
233716400000: HIL::NVMe: INTR | MSI disabled | 1 vectors
233718328000: HIL::NVMe: INTR | MSI-X disabled | 512 vectors
236875131500: HIL::NVMe: BAR0 | READ | Controller Status
236875131500: HIL::NVMe: DMAPORT | READ | DATA 00000000
236876099500: HIL::NVMe: INTR | MSI-X disabled | 512 vectors
236895488000: HIL::NVMe: INTR | MSI-X enabled | 512 vectors
236901656000: HIL::NVMe: INTR | MSI-X enabled | 512 vectors
236901712500: HIL::NVMe: BAR0 | READ | Controller Capabilities
236901712500: HIL::NVMe: DMAPORT | READ | DATA 28010FFF
236901714000: HIL::NVMe: BAR0 | READ | Controller Capabilities
236901714000: HIL::NVMe: DMAPORT | READ | DATA 00200020
236901725500: HIL::NVMe: BAR0 | READ | Version
236901725500: HIL::NVMe: DMAPORT | READ | DATA 00010201
236901730500: HIL::NVMe: BAR0 | READ | Controller Memory Buffer Size
236901730500: HIL::NVMe: DMAPORT | READ | DATA 00000000
236908093500: warn: nvme_interface: Invalid PCI config read offset: 0xa0
236908093500: warn: nvme_interface: Invalid PCI config read offset: 0xa0
236910134000: HIL::NVMe: BAR0 | READ | Controller Capabilities
236910134000: HIL::NVMe: DMAPORT | READ | DATA 28010FFF
236910135500: HIL::NVMe: BAR0 | READ | Controller Capabilities
236910135500: HIL::NVMe: DMAPORT | READ | DATA 00200020
236910138500: HIL::NVMe: BAR0 | READ | Version
236910138500: HIL::NVMe: DMAPORT | READ | DATA 00010201
236910154500: HIL::NVMe: BAR0 | WRITE | Controller Configuration
236910154500: HIL::NVMe: DMAPORT | WRITE | DATA 00000000
236910175000: HIL::NVMe: BAR0 | READ | Controller Status
236910175000: HIL::NVMe: DMAPORT | READ | DATA 00000000
236977165000: HIL::NVMe: BAR0 | WRITE | Admin Queue Attributes
236977165000: HIL::NVMe: DMAPORT | WRITE | DATA 00FF00FF
236977167000: HIL::NVMe: BAR0 | WRITE | Admin Submission Queue Base Address | L
236977167000: HIL::NVMe: DMAPORT | WRITE | DATA FF044000
236977169000: HIL::NVMe: BAR0 | WRITE | Admin Submission Queue Base Address | H
236977169000: HIL::NVMe: DMAPORT | WRITE | DATA 00000000
236977171500: HIL::NVMe: BAR0 | WRITE | Admin Completion Queue Base Address | L
236977171500: HIL::NVMe: DMAPORT | WRITE | DATA FF040000
236977173500: HIL::NVMe: BAR0 | WRITE | Admin Completion Queue Base Address | H
236977173500: HIL::NVMe: DMAPORT | WRITE | DATA 00000000
236977173500: HIL::NVMe: CQ 0 | CREATE | Entry size 256
236977173500: HIL::NVMe: SQ 0 | CREATE | Entry size 256
236977188500: HIL::NVMe: BAR0 | WRITE | Controller Configuration
236977188500: HIL::NVMe: DMAPORT | WRITE | DATA 00460001
236977208000: HIL::NVMe: BAR0 | READ | Controller Status
236977208000: HIL::NVMe: DMAPORT | READ | DATA 00000001
237046383000: HIL::NVMe: BAR0 | READ | Version
237046383000: HIL::NVMe: DMAPORT | READ | DATA 00010201
237046390000: HIL::NVMe: BAR0 | READ | Controller Capabilities
237046390000: HIL::NVMe: DMAPORT | READ | DATA 0020002028010FFF
237049106500: HIL::NVMe: SQ 0 | Submission Queue Tail Doorbell | Item count in queue 0 -> 1 | head 0 | tail 0 -> 1
237049108500: HIL::NVMe: ADMIN | Identify | CNS 1 | CNTID 0 | NSID 0
237051476500: HIL::NVMe: INTR | MSI-X sent | vector 0
237053024000: HIL::NVMe: CQ 0 | Completion Queue Head Doorbell | Item count in queue 1 -> 0 | head 0 -> 1 | tail 1
237056001000: HIL::NVMe: SQ 0 | Submission Queue Tail Doorbell | Item count in queue 0 -> 1 | head 1 | tail 1 -> 2
237056008500: HIL::NVMe: ADMIN | Set Features | Feature 7 | NSID 0
237056008500: HIL::NVMe: INTR | MSI-X sent | vector 0
237056297000: HIL::NVMe: CQ 0 | Completion Queue Head Doorbell | Item count in queue 1 -> 0 | head 1 -> 2 | tail 2
237060309000: HIL::NVMe: INTR | MSI-X disabled | 512 vectors
237089031500: HIL::NVMe: INTR | MSI-X disabled | 512 vectors
237163074000: HIL::NVMe: INTR | MSI-X enabled | 512 vectors
237176106500: HIL::NVMe: INTR | MSI-X enabled | 512 vectors
237359042000: HIL::NVMe: SQ 0 | Submission Queue Tail Doorbell | Item count in queue 0 -> 1 | head 2 | tail 2 -> 3
237359048500: HIL::NVMe: ADMIN | Create I/O Completion Queue
237359048500: HIL::NVMe: CQ 1 | CREATE | Entry size 1024 | IV 0000 | IEN true | PC true
237359048500: HIL::NVMe: INTR | MSI-X sent | vector 0
237359335000: HIL::NVMe: CQ 0 | Completion Queue Head Doorbell | Item count in queue 1 -> 0 | head 2 -> 3 | tail 3
237361749000: HIL::NVMe: SQ 0 | Submission Queue Tail Doorbell | Item count in queue 0 -> 1 | head 3 | tail 3 -> 4
237361758500: HIL::NVMe: ADMIN | Create I/O Submission Queue
237361758500: HIL::NVMe: SQ 1 | CREATE | Entry size 1024 | Priority 2 | PC true
237361758500: HIL::NVMe: INTR | MSI-X sent | vector 0
237362042000: HIL::NVMe: CQ 0 | Completion Queue Head Doorbell | Item count in queue 1 -> 0 | head 3 -> 4 | tail 4
237368196500: HIL::NVMe: SQ 0 | Submission Queue Tail Doorbell | Item count in queue 0 -> 1 | head 4 | tail 4 -> 5
237368198500: HIL::NVMe: ADMIN | Create I/O Completion Queue
237368198500: HIL::NVMe: CQ 2 | CREATE | Entry size 1024 | IV 0001 | IEN true | PC true
237368198500: HIL::NVMe: INTR | MSI-X sent | vector 0
237368489500: HIL::NVMe: CQ 0 | Completion Queue Head Doorbell | Item count in queue 1 -> 0 | head 4 -> 5 | tail 5
237370993000: HIL::NVMe: SQ 0 | Submission Queue Tail Doorbell | Item count in queue 0 -> 1 | head 5 | tail 5 -> 6
237370998500: HIL::NVMe: ADMIN | Create I/O Submission Queue
237370998500: HIL::NVMe: SQ 2 | CREATE | Entry size 1024 | Priority 2 | PC true
237370998500: HIL::NVMe: INTR | MSI-X sent | vector 0
237371286000: HIL::NVMe: CQ 0 | Completion Queue Head Doorbell | Item count in queue 1 -> 0 | head 5 -> 6 | tail 6
237391709000: HIL::NVMe: SQ 0 | Submission Queue Tail Doorbell | Item count in queue 0 -> 1 | head 6 | tail 6 -> 7
237391718500: HIL::NVMe: ADMIN | Create I/O Completion Queue
237391718500: HIL::NVMe: CQ 3 | CREATE | Entry size 1024 | IV 0002 | IEN true | PC true
237391718500: HIL::NVMe: INTR | MSI-X sent | vector 0
237392002000: HIL::NVMe: CQ 0 | Completion Queue Head Doorbell | Item count in queue 1 -> 0 | head 6 -> 7 | tail 7
237394505500: HIL::NVMe: SQ 0 | Submission Queue Tail Doorbell | Item count in queue 0 -> 1 | head 7 | tail 7 -> 8
237394508500: HIL::NVMe: ADMIN | Create I/O Submission Queue
237394508500: HIL::NVMe: SQ 3 | CREATE | Entry size 1024 | Priority 2 | PC true
237394508500: HIL::NVMe: INTR | MSI-X sent | vector 0
237394798500: HIL::NVMe: CQ 0 | Completion Queue Head Doorbell | Item count in queue 1 -> 0 | head 7 -> 8 | tail 8
237412405500: HIL::NVMe: SQ 0 | Submission Queue Tail Doorbell | Item count in queue 0 -> 1 | head 8 | tail 8 -> 9
237412408500: HIL::NVMe: ADMIN | Create I/O Completion Queue
237412408500: HIL::NVMe: CQ 4 | CREATE | Entry size 1024 | IV 0003 | IEN true | PC true
237412408500: HIL::NVMe: INTR | MSI-X sent | vector 0
237412698500: HIL::NVMe: CQ 0 | Completion Queue Head Doorbell | Item count in queue 1 -> 0 | head 8 -> 9 | tail 9
237415202000: HIL::NVMe: SQ 0 | Submission Queue Tail Doorbell | Item count in queue 0 -> 1 | head 9 | tail 9 -> 10
237415208500: HIL::NVMe: ADMIN | Create I/O Submission Queue
237415208500: HIL::NVMe: SQ 4 | CREATE | Entry size 1024 | Priority 2 | PC true
237415208500: HIL::NVMe: INTR | MSI-X sent | vector 0
237415495000: HIL::NVMe: CQ 0 | Completion Queue Head Doorbell | Item count in queue 1 -> 0 | head 9 -> 10 | tail 10
237620805000: HIL::NVMe: SQ 0 | Submission Queue Tail Doorbell | Item count in queue 0 -> 1 | head 10 | tail 10 -> 11
237623134000: HIL::NVMe: SQ 0 | Submission Queue Tail Doorbell | Item count in queue 0 -> 1 | head 11 | tail 11 -> 12
237623138500: HIL::NVMe: ADMIN | Identify | CNS 1 | CNTID 0 | NSID 0
237625504000: HIL::NVMe: INTR | MSI-X sent | vector 0
237626976000: HIL::NVMe: CQ 0 | Completion Queue Head Doorbell | Item count in queue 1 -> 0 | head 10 -> 11 | tail 11
237630250500: HIL::NVMe: SQ 0 | Submission Queue Tail Doorbell | Item count in queue 0 -> 1 | head 12 | tail 12 -> 13
237630258500: HIL::NVMe: ADMIN | Identify | CNS 2 | CNTID 0 | NSID 0
237632620500: HIL::NVMe: INTR | MSI-X sent | vector 0
237634091500: HIL::NVMe: CQ 0 | Completion Queue Head Doorbell | Item count in queue 1 -> 0 | head 11 -> 12 | tail 12
237680176500: HIL::NVMe: SQ 0 | Submission Queue Tail Doorbell | Item count in queue 0 -> 1 | head 13 | tail 13 -> 14
237680178500: HIL::NVMe: ADMIN | Identify | CNS 0 | CNTID 0 | NSID 1
237682546500: HIL::NVMe: INTR | MSI-X sent | vector 0
237684610000: HIL::NVMe: CQ 0 | Completion Queue Head Doorbell | Item count in queue 1 -> 0 | head 12 -> 13 | tail 13
237799462000: HIL::NVMe: SQ 0 | Submission Queue Tail Doorbell | Item count in queue 0 -> 1 | head 14 | tail 14 -> 15
237799468500: HIL::NVMe: ADMIN | Identify | CNS 0 | CNTID 0 | NSID 1
237801832000: HIL::NVMe: INTR | MSI-X sent | vector 0
237803323500: HIL::NVMe: CQ 0 | Completion Queue Head Doorbell | Item count in queue 1 -> 0 | head 13 -> 14 | tail 14
In this log, you can check Linux Kernel initializes NVMe controller of SimpleSSD.
You can see which register are read/written, which commands are sent through which SQ.
After initialization, Linux Kernel tries to detect partition table.
237824921500: HIL::NVMe: SQ 1 | Submission Queue Tail Doorbell | Item count in queue 0 -> 1 | head 0 | tail 0 -> 1
237824928500: HIL::NVMe: NVM | READ | NSID 1
237824928500: HIL: READ | REQ 1 | LCA 0 + 1 | BYTE 0 + 4096
237824928500: ICL::GenericCache: READ | REQ 1-1 | LCA 0 | SIZE 4096
237824928500: ICL::GenericCache: ----- | Begin eviction
237824928500: ICL::GenericCache: ----- | End eviction | 237824931060 - 237824931060 (0)
237824928500: FTL: READ | LPN 0
237824928500: PAL::PALOLD: READ | Block 4088 | Page 0
237824928500: PAL::PALOLD: READ | C 0 | W 0 | D 0 | P 0 | B 511 | P 0
237824928500: FTL::PageMapping: READ | LPN 0 | 237824931060 - 237909026937 (84095877)
237824928500: ICL::GenericCache: READ | Cache miss at (0, 0) | 237824931060 - 237909026937 (84095877)
237824928500: ICL: READ | LCA 0 + 1 | 237824928500 - 237909026937 (84098437)
237824928500: HIL::NVMe: NVM | READ | 0 + 8 | NAND 237824928500 - 237909026937 (84098437)
237824928500: HIL::NVMe: NVM | READ | 0 + 8 | DMA 237909026937 - 237911234937 (2208000)
237911234937: HIL::NVMe: INTR | MSI-X sent | vector 0
237913542000: HIL::NVMe: CQ 1 | Completion Queue Head Doorbell | Item count in queue 1 -> 0 | head 0 -> 1 | tail 1
Through I/O queue 1 (SQ 1), SimpleSSD received READ command. ICL, FTL and PAL handles request and HIL send I/O response.
Format of debug log:
<Simulation Tick>: <Module>: <Message>