Added operation logging to JSON

license.md

@@ -1,6 +1,6 @@
 # The MIT License (MIT)
 
-Copyright © 2012–2021 MIPT-ILab, Alexander Titov, Pavel Kryukov, Igor Smirnov, Igor Burovenko, Kamil Garifullin, Oleg Ladin, Kirill Korolev, Victor Prutyanov, Ivan Korostelev, Alex Seppar, George Korepanov, Alexey Steksov, Kirill Nedostoev, Alexander Misevich, Denis Los, Alexander Timofeev, Konstantin Soshin, Yan Logovskiy, Andrei Sultan, Vyacheslav Kompan, Yauheni Sharamed, Andrey Agrachev, Vsevolod Pukhov, Arsen Davtyan, Egor Bova, Rustem Yunusov, Maxim Davydov, Eric Konks, Igor Bulatov, Kirill Chemrov, Alexandr Vinogradov, Airat Nazmiev, Daniel Kofanov, Nikolay Zernov, Vladimir Prokhorov, Ilya Burtakov, Nikita Gorbachev, Yaroslav Okatev, Roman Zlobin, Yuly Tarasov, Vladimir Graudt, Alexey Shcherbakov, Anton Okley, Egor Titov, Eugene Naydanov, Mihail Fedorov, Vasilii Zaitsev, Ravil Zakiryanov, Ivan Burtakov, and Johannes Pohl.
+Copyright © 2012–2021 MIPT-ILab, Alexander Titov, Pavel Kryukov, Igor Smirnov, Igor Burovenko, Kamil Garifullin, Oleg Ladin, Kirill Korolev, Victor Prutyanov, Ivan Korostelev, Alex Seppar, George Korepanov, Alexey Steksov, Kirill Nedostoev, Alexander Misevich, Denis Los, Alexander Timofeev, Konstantin Soshin, Yan Logovskiy, Andrei Sultan, Vyacheslav Kompan, Yauheni Sharamed, Andrey Agrachev, Vsevolod Pukhov, Arsen Davtyan, Egor Bova, Rustem Yunusov, Maxim Davydov, Eric Konks, Igor Bulatov, Kirill Chemrov, Alexandr Vinogradov, Airat Nazmiev, Daniel Kofanov, Nikolay Zernov, Vladimir Prokhorov, Ilya Burtakov, Nikita Gorbachev, Yaroslav Okatev, Roman Zlobin, Yuly Tarasov, Vladimir Graudt, Alexey Shcherbakov, Anton Okley, Egor Titov, Eugene Naydanov, Mihail Fedorov, Vasilii Zaitsev, Ravil Zakiryanov, Ivan Burtakov, Andrei Karpyza, and Johannes Pohl.
 
 ----
 

simulator/func_sim/operation.h

@@ -125,6 +125,10 @@ class Operation
     void set_sequence_id( uint64 id) { sequence_id = id; }
     auto get_sequence_id() const { return sequence_id; }
 
+    // instruction_id initialization and return - functions
+    void set_instruction_id(uint64 id) { instruction_id = id; }
+    auto get_instruction_id() const { return instruction_id; }
+
     auto get_delayed_slots() const { return delayed_slots; }
     Addr get_decoded_target() const { return target; }
     auto get_new_PC() const { return new_PC; }
@@ -151,6 +155,8 @@ class Operation
 private:
     OperationType operation = OUT_UNKNOWN;
     uint64 sequence_id = NO_VAL64;
+    // instruction_id initialization
+    uint64 instruction_id = NO_VAL64;
 };
 
 template <typename I>

simulator/infra/log.cpp

@@ -22,3 +22,7 @@ OStreamWrapper::~OStreamWrapper()
 {
     ostream.rdbuf( buffer);
 }
+
+
+std::ofstream* visualizer_logger = new std::ofstream(".\\logs.json", std::ofstream::out);
+std::ofstream& Log::jsonout() { return *visualizer_logger; }

simulator/infra/log.h

@@ -9,6 +9,7 @@
 #define LOG_H
 
 #include <iosfwd>
+#include "fstream"
 
 class LogOstream
 {
@@ -49,6 +50,9 @@ class Log
     mutable LogOstream sout;
     mutable LogOstream serr;
 
+    std::ofstream& jsonout();
+    bool jsonout_enabled = false;
+
     Log();
 
     // Rule of five

simulator/infra/ports/module.cpp

@@ -48,6 +48,13 @@ void Module::enable_logging_impl( const std::unordered_set<std::string>& names)
         c->enable_logging_impl( names);
 }
 
+// enable logging function implementation
+void Module::enable_json_logging(bool key) {
+    jsonout_enabled = key;
+    for (const auto& c : children)
+        c->enable_json_logging(key);
+}
+
 pt::ptree Module::write_ports_dumping() const
 {
     pt::ptree result;

simulator/infra/ports/module.h

@@ -42,6 +42,8 @@ class Module : public Log
     void enable_logging_impl( const std::unordered_set<std::string>& names);
     boost::property_tree::ptree topology_dumping_impl() const;
 
+    // enable-logging function initialization
+    void enable_json_logging(bool key);
 private:
     // NOLINTNEXTLINE(misc-no-recursion) Recursive, but must be finite
     virtual std::shared_ptr<PortMap> get_portmap() const { return parent->get_portmap(); }

simulator/modules/core/perf_sim.cpp

@@ -13,6 +13,8 @@
 namespace config {
     static const AliasedValue<std::string> units_to_log = { "l", "logs", "nothing", "print logs for modules"};
     static const Switch topology_dump = { "tdump", "module topology dump into topology.json" };
+    // command line flag argument for enable/disable json logging
+    static const AliasedSwitch json_dump = { "j", "json-dump", "json logs in .\\logs.json" };
 } // namespace config
 
 template <typename ISA>
@@ -32,6 +34,8 @@ PerfSim<ISA>::PerfSim( std::endian endian, std::string_view isa)
     init_portmap();
     enable_logging( config::units_to_log);
     topology_dumping( config::topology_dump, "topology.json");
+    // json logger configuration
+    enable_json_logging(config::json_dump);
 }
 
 template <typename ISA>
@@ -59,6 +63,9 @@ Addr PerfSim<ISA>::get_pc() const
 template<typename ISA>
 Trap PerfSim<ISA>::run( uint64 instrs_to_run)
 {
+    /* start json dump strings */
+    start_dump_json();
+
     current_trap = Trap( Trap::NO_TRAP);
 
     writeback.set_instrs_to_run( instrs_to_run);
@@ -68,6 +75,9 @@ Trap PerfSim<ISA>::run( uint64 instrs_to_run)
     while (current_trap == Trap::NO_TRAP)
         clock();
 
+    /* end strings */
+    stop_dump_json();
+
     dump_statistics();
 
     return current_trap;
@@ -99,6 +109,24 @@ auto get_rate( int total, float64 piece)
     return total != 0 ? ( piece / total * 100) : 0;
 }
 
+/* standard lines loggers implementation */
+template<typename ISA>
+void PerfSim<ISA>::start_dump_json() {
+    if (jsonout_enabled)
+        (jsonout()) << "[\n" <<
+        "\t{ \"type\": \"Stage\", \"id\": 0, \"description\": \"Fetch\" },\n" <<
+        "\t{ \"type\": \"Stage\", \"id\": 1, \"description\": \"Decode\" },\n" <<
+        "\t{ \"type\": \"Stage\", \"id\": 2, \"description\": \"Execute\" },\n" <<
+        "\t{ \"type\": \"Stage\", \"id\": 3, \"description\": \"Memory\" },\n" <<
+        "\t{ \"type\": \"Stage\", \"id\": 4, \"description\": \"Writeback\" }";
+}
+
+template<typename ISA>
+void PerfSim<ISA>::stop_dump_json() {
+    if (jsonout_enabled)
+        (jsonout()) << "\n]\n";
+}
+
 template<typename ISA>
 void PerfSim<ISA>::dump_statistics() const
 {

simulator/modules/core/perf_sim.h

@@ -83,6 +83,10 @@ class PerfSim : public CycleAccurateSimulator
 
     uint64 read_register( Register index) const { return narrow_cast<uint64>( rf.read( index)); }
     void write_register( Register index, uint64 value) { rf.write( index, narrow_cast<RegisterUInt>( value)); }
+
+    /* default lines initialization */
+    void start_dump_json();
+    void stop_dump_json();
 };
 
 #endif

simulator/modules/decode/decode.cpp

@@ -151,6 +151,10 @@ void Decode<FuncInstr>::clock( Cycle cycle)
     sout << instr << std::endl;
 
     wp_datapath->write( std::move( instr), cycle);
+
+    /* JSON dump of Decode-stage of executing operation */
+    if (jsonout_enabled)
+        (jsonout()) << ",\n\t{ \"type\": \"Event\", \"id\": " << instr.get_instruction_id() << ", \"cycle\": " << cycle << ", \"stage\": 1 }";
 }
 
 

simulator/modules/execute/execute.cpp

@@ -77,6 +77,10 @@ void Execute<FuncInstr>::clock( Cycle cycle)
         {
             wp_long_arithmetic_bypass->write( instr.get_v_dst(), cycle);
             wp_writeback_datapath->write( instr, cycle);
+
+            /* JSON dump of Execute-stage of executing operation */
+            if (jsonout_enabled)
+                (jsonout()) << ",\n\t{ \"type\": \"Event\", \"id\": " << instr.get_instruction_id() << ", \"cycle\": " << cycle << ", \"stage\": 2 }";
         }
     }
 
@@ -133,6 +137,10 @@ void Execute<FuncInstr>::clock( Cycle cycle)
         {
             wp_writeback_datapath->write( std::move( instr), cycle);
         }
+
+        /* JSON dump of Execute-stage of executing operation */
+        if (jsonout_enabled)
+            (jsonout()) << ",\n\t{ \"type\": \"Event\", \"id\": " << instr.get_instruction_id() << ", \"cycle\": " << cycle << ", \"stage\": 2 }";
     }
 }
 

simulator/modules/fetch/fetch.cpp

@@ -180,6 +180,9 @@ void Fetch<FuncInstr>::clock( Cycle cycle)
     Instr instr( memory->fetch_instr( target.address), bp_info);
     instr.set_sequence_id( target.sequence_id);
 
+    /* instruction unique id initialization */
+    instr.set_instruction_id(curr_id++);
+
     /* set next target according to prediction */
     wp_target->write( instr.get_predicted_target(), cycle);
 
@@ -188,6 +191,11 @@ void Fetch<FuncInstr>::clock( Cycle cycle)
 
     /* sending to decode */
     wp_datapath->write( std::move( instr), cycle);
+
+    /* JSON dump of Fetch-stage of executing operation */
+    if (jsonout_enabled)
+        (jsonout()) << ",\n\t{ \"type\": \"Record\", \"id\": " << instr.get_instruction_id() << ", \"disassembly\": \"" << instr.get_disasm() << "\" }" <<
+        ",\n\t{ \"type\": \"Event\", \"id\": " << instr.get_instruction_id() << ", \"cycle\": " << cycle << ", \"stage\": 0 }";
 }
 
 #include <mips/mips.h>

simulator/modules/fetch/fetch.h

@@ -30,6 +30,9 @@ class Fetch : public Module
     std::unique_ptr<InstrMemoryIface<FuncInstr>> memory = nullptr;
     std::unique_ptr<BaseBP> bp = nullptr;
     std::unique_ptr<CacheTagArray> tags = nullptr;
+
+    /* counter for instruction_id implementation */
+    int curr_id = 0;
 
     /* Input signals */
     ReadPort<bool>* rp_stall = nullptr;

simulator/modules/mem/mem.cpp

@@ -50,6 +50,10 @@ void Mem<FuncInstr>::clock( Cycle cycle)
 
     /* data path */
     wp_datapath->write( std::move( instr), cycle);
+
+    /* JSON dump of Memory-stage of executing operation */
+    if (jsonout_enabled)
+        (jsonout()) << ",\n\t{ \"type\": \"Event\", \"id\": " << instr.get_instruction_id() << ", \"cycle\": " << cycle << ", \"stage\": 3 }";
 }
 
 

simulator/modules/writeback/writeback.cpp

@@ -73,8 +73,13 @@ void Writeback<ISA>::clock( Cycle cycle)
 
     if ( instrs.empty())
         writeback_bubble( cycle);
-    else for ( auto& instr : instrs)
-        writeback_instruction_system( &instr, cycle);
+    else for (auto& instr : instrs) {
+        writeback_instruction_system(&instr, cycle);
+
+        /* JSON dump of Writeback-stage of executing operation */
+        if (jsonout_enabled)
+            (jsonout()) << ",\n\t{ \"type\": \"Event\", \"id\": " << instr.get_instruction_id() << ", \"cycle\": " << cycle << ", \"stage\": 4 }";
+    }
 }
 
 template <typename ISA>
@@ -100,8 +105,12 @@ template <typename ISA>
 void Writeback<ISA>::writeback_bubble( Cycle cycle)
 {
     sout << "bubble\n";
-    if ( cycle >= last_writeback_cycle + 100_lt)
-        throw Deadlock( "");
+    if (cycle >= last_writeback_cycle + 100_lt) {
+        /* If will be throwed Deadlock - we need to close brackets in the logs-file */
+        if (jsonout_enabled)
+            (jsonout()) << "\n]\n";
+        throw Deadlock("");
+    }
 }
 
 template <typename ISA>