diff --git a/cpu.cpp b/cpu.cpp index dcf4b01..66ad8fe 100644 --- a/cpu.cpp +++ b/cpu.cpp @@ -40,7 +40,7 @@ void cpu::emulation_start() { instruction_count = 0; - running_since = get_ms(); + running_since = get_us(); wait_time = 0; } @@ -64,7 +64,7 @@ std::set cpu::list_breakpoints() return breakpoints; } -uint64_t cpu::get_instructions_executed_count() +uint64_t cpu::get_instructions_executed_count() const { // this may wreck havoc as it is not protected by a mutex // but a mutex would slow things down too much (as would @@ -72,21 +72,21 @@ uint64_t cpu::get_instructions_executed_count() return instruction_count; } -std::tuple cpu::get_mips_rel_speed(const std::optional instruction_count, const bool t_diff_1s) +std::tuple cpu::get_mips_rel_speed(const std::optional & instruction_count, const std::optional & t_diff_in) const { uint64_t instr_count = instruction_count.has_value() ? instruction_count.value() : get_instructions_executed_count(); - uint32_t t_diff = t_diff_1s ? 1000 : (get_ms() - running_since - (wait_time / 1000)); + uint64_t t_diff = t_diff_in.has_value() ? t_diff_in.value() : (get_us() - running_since - wait_time); - double mips = instr_count / (1000.0 * t_diff); + double mips = instr_count / double(t_diff); // see https://retrocomputing.stackexchange.com/questions/6960/what-was-the-clock-speed-and-ips-for-the-original-pdp-11 constexpr double pdp11_clock_cycle = 150; // ns, for the 11/70 - constexpr double pdp11_mhz = 1000.0 / pdp11_clock_cycle; + constexpr double pdp11_MHz = 1000.0 / pdp11_clock_cycle; constexpr double pdp11_avg_cycles_per_instruction = (1 + 5) / 2.0; - constexpr double pdp11_estimated_mips = pdp11_mhz / pdp11_avg_cycles_per_instruction; + constexpr double pdp11_estimated_mips = pdp11_MHz / pdp11_avg_cycles_per_instruction; - return { mips, mips * 100 / pdp11_estimated_mips, instr_count, t_diff, wait_time / 1000. }; + return { mips, mips * 100 / pdp11_estimated_mips, instr_count, t_diff, wait_time }; } void cpu::reset() @@ -1317,8 +1317,7 @@ bool cpu::single_operand_instructions(const uint16_t instr) if (dst_mode == 0) setRegister(dst_reg, v, rm_prev); else { - int prev_run_mode = getPSW_prev_runmode(); - auto a = getGAMAddress(dst_mode, dst_reg, wm_word); + auto a = getGAMAddress(dst_mode, dst_reg, wm_word); b->mmudebug(a.addr.value()); diff --git a/cpu.h b/cpu.h index 1d76521..052cac0 100644 --- a/cpu.h +++ b/cpu.h @@ -101,8 +101,9 @@ public: bus *getBus() { return b; } void emulation_start(); - uint64_t get_instructions_executed_count(); - std::tuple get_mips_rel_speed(const std::optional instruction_count, const bool t_diff_1s); + uint64_t get_instructions_executed_count() const; + uint64_t get_wait_time() const { return wait_time; } + std::tuple get_mips_rel_speed(const std::optional & instruction_count, const std::optional & t_diff_1s) const; void reset(); diff --git a/debugger.cpp b/debugger.cpp index 7af8beb..dd42648 100644 --- a/debugger.cpp +++ b/debugger.cpp @@ -213,7 +213,7 @@ void show_run_statistics(console *const cnsl, cpu *const c) { auto stats = c->get_mips_rel_speed({ }, false); - cnsl->put_string_lf(format("Executed %zu instructions in %u ms of which %.2f ms idle", size_t(std::get<2>(stats)), std::get<3>(stats), std::get<4>(stats))); + cnsl->put_string_lf(format("Executed %zu instructions in %.2f ms of which %.2f ms idle", size_t(std::get<2>(stats)), std::get<3>(stats) / 1000., std::get<4>(stats) / 1000.)); cnsl->put_string_lf(format("MIPS: %.2f, relative speed: %.2f%%", std::get<0>(stats), std::get<1>(stats))); } diff --git a/main.cpp b/main.cpp index 4a8e677..6bb27f1 100644 --- a/main.cpp +++ b/main.cpp @@ -231,25 +231,32 @@ int run_cpu_validation(const std::string & filename) void get_metrics(cpu *const c) { uint64_t previous_instruction_count = c->get_instructions_executed_count(); + uint64_t previous_ts = get_us(); + uint64_t previous_idle_time = c->get_wait_time(); while(event != EVENT_TERMINATE) { sleep(1); - uint64_t ts = get_us(); + uint64_t ts = get_us(); + uint64_t idle_time = c->get_wait_time(); uint64_t current_instruction_count = c->get_instructions_executed_count(); - auto stats = c->get_mips_rel_speed(current_instruction_count - previous_instruction_count, true); + uint64_t current_idle_duration = idle_time - previous_idle_time; + + auto stats = c->get_mips_rel_speed(current_instruction_count - previous_instruction_count, ts - previous_ts - current_idle_duration); FILE *fh = fopen("kek-metrics.csv", "a+"); if (fh) { fseek(fh, 0, SEEK_END); if (ftell(fh) == 0) - fprintf(fh, "timestamp,MIPS,relative speed in %%,instructions executed count\n"); - fprintf(fh, "%.06f, %.2f, %.2f%%, %" PRIu64 "\n", ts / 1000., std::get<0>(stats), std::get<1>(stats), std::get<2>(stats)); + fprintf(fh, "timestamp,MIPS,relative speed in %%,instructions executed count,idle time\n"); + fprintf(fh, "%.06f, %.2f, %.2f%%, %" PRIu64 ", %.3f\n", ts / 1000., std::get<0>(stats), std::get<1>(stats), std::get<2>(stats), current_idle_duration / 1000000.); fclose(fh); } + previous_idle_time = idle_time; previous_instruction_count = current_instruction_count; + previous_ts = ts; } } @@ -545,7 +552,7 @@ int main(int argc, char *argv[]) } auto stats = c->get_mips_rel_speed({ }, false); - cnsl->put_string_lf(format("MIPS: %.2f, relative speed: %.2f%%, instructions executed: %lu", std::get<0>(stats), std::get<1>(stats), std::get<2>(stats))); + cnsl->put_string_lf(format("MIPS: %.2f, relative speed: %.2f%%, instructions executed: %" PRIu64 " in %.2f seconds", std::get<0>(stats), std::get<1>(stats), std::get<2>(stats), std::get<3>(stats) / 1000000.)); } event = EVENT_TERMINATE;