add timestamps to log messages

corundum/coord.h

@@ -44,18 +44,18 @@ class PCICoordinator {
                 queue.pop_front();
                 if (op->type == PCIOp::OP_MSI) {
 #ifdef COORD_DEBUG
-                    std::cout << "issuing msi " << op->msi_vec << std::endl;
+                    std::cout << main_time << " issuing msi " << op->msi_vec << std::endl;
 #endif
                     pci_msi_issue(op->msi_vec);
                 } else if (op->type == PCIOp::OP_DMA) {
 #ifdef COORD_DEBUG
-                    std::cout << "issuing dma " << op->dma_op << std::endl;
+                    std::cout << main_time << " issuing dma " << op->dma_op << std::endl;
 #endif
                     pci_dma_issue(op->dma_op);
                     dmamap.erase(op->dma_op);
                 } else if (op->type == PCIOp::OP_RWCOMP) {
 #ifdef COORD_DEBUG
-                    std::cout << "issuing mmio " << op->mmio_op << std::endl;
+                    std::cout << main_time << " issuing mmio " << op->mmio_op << std::endl;
 #endif
                     pci_rwcomp_issue(op->mmio_op);
                 } else {
@@ -70,7 +70,7 @@ class PCICoordinator {
         void dma_register(DMAOp *dma_op, bool ready)
         {
 #ifdef COORD_DEBUG
-            std::cout << "registering dma op " << dma_op << "  " << ready << std::endl;
+            std::cout << main_time << " registering dma op " << dma_op << "  " << ready << std::endl;
 #endif
             PCIOp *op = new PCIOp;
             op->dma_op = dma_op;
@@ -86,7 +86,7 @@ class PCICoordinator {
         void dma_mark_ready(DMAOp *op)
         {
 #ifdef COORD_DEBUG
-            std::cout << "readying dma op " << op <<  std::endl;
+            std::cout << main_time << " readying dma op " << op <<  std::endl;
 #endif
             dmamap[op]->ready = true;
 
@@ -96,7 +96,7 @@ class PCICoordinator {
         void msi_enqueue(uint32_t vec)
         {
 #ifdef COORD_DEBUG
-            std::cout << "enqueuing MSI " << vec <<  std::endl;
+            std::cout << main_time << " enqueuing MSI " << vec <<  std::endl;
 #endif
             PCIOp *op = new PCIOp;
             op->msi_vec = vec;
@@ -110,7 +110,7 @@ class PCICoordinator {
         void mmio_comp_enqueue(MMIOOp *mmio_op)
         {
 #ifdef COORD_DEBUG
-            std::cout << "enqueuing MMIO comp " << mmio_op <<  std::endl;
+            std::cout << main_time << " enqueuing MMIO comp " << mmio_op <<  std::endl;
 #endif
             PCIOp *op = new PCIOp;
             op->mmio_op = mmio_op;

corundum/corundum.h

@@ -3,6 +3,8 @@
 
 #include "dma.h"
 
+extern uint64_t main_time;
+
 void pci_dma_issue(DMAOp *op);
 
 #endif /* ndef CORUNDUM_H_ */

corundum/corundum_verilator.cpp

@@ -27,7 +27,7 @@ extern "C" {
 struct DMAOp;
 
 static volatile int exiting = 0;
-static uint64_t main_time = 0;
+uint64_t main_time = 0;
 static struct nicsim_params nsparams;
 #ifdef TRACE_ENABLED
 static VerilatedVcdC* trace;
@@ -226,7 +226,7 @@ class MMIOInterface {
                     rCur->value = top.s_axil_rdata;
                     coord.mmio_comp_enqueue(rCur);
 #ifdef MMIO_DEBUG
-                    std::cout << "MMIO: completed AXI read op=" << rCur << " val=" <<
+                    std::cout << main_time << " MMIO: completed AXI read op=" << rCur << " val=" <<
                         rCur->value << std::endl;
 #endif
                     rCur = 0;
@@ -250,7 +250,7 @@ class MMIOInterface {
                     top.s_axil_bready = 0;
                     // TODO: check top.s_axil_bresp
 #ifdef MMIO_DEBUG
-                    std::cout << "MMIO: completed AXI write op=" << wCur <<
+                    std::cout << main_time << " MMIO: completed AXI write op=" << wCur <<
                         std::endl;
 #endif
                     coord.mmio_comp_enqueue(wCur);
@@ -293,7 +293,7 @@ class MMIOInterface {
         {
             MMIOOp *op = new MMIOOp;
 #ifdef MMIO_DEBUG
-            std::cout << "MMIO: read id=" << id << " addr=" << std::hex << addr
+            std::cout << main_time << " MMIO: read id=" << id << " addr=" << std::hex << addr
                 << " len=" << len << " op=" << op << std::endl;
 #endif
             op->id = id;
@@ -308,7 +308,7 @@ class MMIOInterface {
         {
             MMIOOp *op = new MMIOOp;
 #ifdef MMIO_DEBUG
-            std::cout << "MMIO: write id=" << id << " addr=" << std::hex << addr
+            std::cout << main_time << " MMIO: write id=" << id << " addr=" << std::hex << addr
                 << " len=" << len << " val=" << val << " op=" << op << std::endl;
 #endif
             op->id = id;
@@ -617,7 +617,7 @@ class EthernetTx {
                 COSIM_ETH_PROTO_D2N_OWN_NET;
 
 #ifdef ETH_DEBUG
-            std::cerr << "EthernetTx: packet len=" << std::hex << packet_len << " ";
+            std::cerr << main_time << " EthernetTx: packet len=" << std::hex << packet_len << " ";
             for (size_t i = 0; i < packet_len; i++) {
                 std::cerr << (unsigned) packet_buf[i] << " ";
             }
@@ -678,8 +678,8 @@ class EthernetRx {
             fifo_lens[fifo_pos_wr] = len;
 
 #ifdef ETH_DEBUG
-            std::cout << "rx into " << fifo_pos_wr << std::endl;
-            std::cerr << "EthernetRx: packet len=" << std::hex << len << " ";
+            std::cout << main_time << " rx into " << fifo_pos_wr << std::endl;
+            std::cerr << main_time << " EthernetRx: packet len=" << std::hex << len << " ";
             for (size_t i = 0; i < len; i++) {
                 std::cerr << (unsigned) fifo_bufs[fifo_pos_wr][i] << " ";
             }
@@ -699,7 +699,7 @@ class EthernetRx {
                 } else if (packet_off == fifo_lens[fifo_pos_rd]) {
                     // done with packet
 #ifdef ETH_DEBUG
-                    std::cerr << "EthernetRx: finished packet" << std::endl;
+                    std::cerr << main_time << " EthernetRx: finished packet" << std::endl;
 #endif
                     top.rx_axis_tvalid = 0;
                     top.rx_axis_tlast = 0;
@@ -710,7 +710,7 @@ class EthernetRx {
                 } else {
                     // put out more packet data
 #ifdef ETH_DEBUG
-                    std::cerr << "EthernetRx: push flit " << packet_off << std::endl;
+                    std::cerr << main_time << " EthernetRx: push flit " << packet_off << std::endl;
                     if (packet_off == 0)
                         std::cout << "rx from " << fifo_pos_rd << std::endl;
 #endif
@@ -851,7 +851,7 @@ void pci_msi_issue(uint8_t vec)
     volatile struct cosim_pcie_proto_d2h_interrupt *intr;
 
 #ifdef MSI_DEBUG
-    std::cerr << "MSI interrupt vec=" << (int) vec << std::endl;
+    std::cerr << main_time << " MSI interrupt vec=" << (int) vec << std::endl;
 #endif
 
     intr = &msg->interrupt;
@@ -870,7 +870,7 @@ static void msi_step(Vinterface &top, PCICoordinator &coord)
         return;
 
 #ifdef MSI_DEBUG
-    std::cerr << "msi_step: MSI interrupt raw vec=" << (int) top.msi_irq << std::endl;
+    std::cerr << main_time << " msi_step: MSI interrupt raw vec=" << (int) top.msi_irq << std::endl;
 #endif
     for (size_t i = 0; i < 32; i++) {
         if (!((1ULL << i) & top.msi_irq))

corundum/dma.cpp

@@ -21,7 +21,7 @@ void DMAReader::step()
         pending.insert(op);
 
 #ifdef DMA_DEBUG
-        std::cout << "dma[" << label << "] op " << std::hex << op->dma_addr << " -> " <<
+        std::cout << main_time << " dma[" << label << "] op " << std::hex << op->dma_addr << " -> " <<
             op->ram_sel << ":" << op->ram_addr <<
             "   len=" << op->len << "   tag=" << (int) op->tag << std::endl;
 #endif
@@ -71,7 +71,7 @@ void DMAWriter::step()
         pending.insert(op);
 
 #ifdef DMA_DEBUG
-        std::cout << "dma write [" << label << "] op " << std::hex << op->dma_addr << " -> " <<
+        std::cout << main_time << " dma write [" << label << "] op " << std::hex << op->dma_addr << " -> " <<
             op->ram_sel << ":" << op->ram_addr <<
             "   len=" << op->len << "   tag=" << (int) op->tag << std::endl;
 #endif
@@ -86,7 +86,7 @@ void DMAWriter::step()
         completed.pop_front();
 
 #ifdef DMA_DEBUG
-        std::cout << "dma write [" << label << "] status complete " << op->dma_addr << std::endl;
+        std::cout << main_time << " dma write [" << label << "] status complete " << op->dma_addr << std::endl;
 #endif
 
         p.dma_status_valid = 1;
@@ -100,7 +100,7 @@ void DMAWriter::step()
 void DMAWriter::pci_op_complete(DMAOp *op)
 {
 #ifdef DMA_DEBUG
-    std::cout << "dma write [" << label << "] pci complete " << op->dma_addr << std::endl;
+    std::cout << main_time << " dma write [" << label << "] pci complete " << op->dma_addr << std::endl;
 #endif
     completed.push_back(op);
 }
@@ -108,7 +108,7 @@ void DMAWriter::pci_op_complete(DMAOp *op)
 void DMAWriter::mem_op_complete(DMAOp *op)
 {
 #ifdef DMA_DEBUG
-    std::cout << "dma write [" << label << "] mem complete " << op->dma_addr << ": ";
+    std::cout << main_time << " dma write [" << label << "] mem complete " << op->dma_addr << ": ";
     for (size_t i = 0; i < op->len; i++)
         std::cout << (unsigned) op->data[i] << " ";
     std::cout << std::endl;