Fixes in tracing binlog writer (#859)

- Changed offset for fork id calculation. Before, calculated ids didn't fit 24 bits which caused overflows
- Implement dynamic precision hack to store wait net times > 16 sec to 24 bits

runtime/kphp_tracing.cpp

@@ -169,7 +169,7 @@ static inline float calc_time_offset(double now_timestamp) noexcept {
 }
 
 static inline int calc_coroutine_id(int64_t fork_id) noexcept {
-  return fork_id > 0 ? static_cast<int>(fork_id - FORK_START_ID + 1) : 0;
+  return fork_id > 0 ? static_cast<int>(fork_id - first_forked_resumable_id + 1) : 0;
 }
 
 [[gnu::noinline]] [[gnu::cold]] static void provide_advanced_mem_details() {

runtime/kphp_tracing_binlog.h

@@ -350,7 +350,24 @@ struct BinlogWriter {
   }
 
   static void onWaitNet(int microseconds) {
-    cur_binlog.write_event_type(EventTypeEnum::etScriptWaitNet, microseconds);
+    static constexpr int32_t UPPER_BOUND_MICRO_TIME_MASK = 0x00f00000; // 15'728'640
+    static constexpr int32_t MAX_MILLI_TIME_MASK         = 0x000fffff; //  1'048'575
+    // Here is dynamic precision hack to store wait times > 16 sec in 24 bits:
+    //    - if time < UPPER_BOUND_MICRO_TIME_MASK (~15.73 sec) it's stored as microseconds
+    //    - else it's stored as milliseconds in lowest 20 bits (e.g. max value is ~ 1048.58 sec)
+    // Note: It's compatible with any binlog reader version.
+    //       The only problem is that old binlog reader will see values between ~15.73 sec and ~16.78 sec for large wait times
+    int wait_time_encoded;
+    if (microseconds < UPPER_BOUND_MICRO_TIME_MASK) {
+      wait_time_encoded = microseconds;
+    } else {
+      wait_time_encoded = microseconds / 1000;
+      if (wait_time_encoded > MAX_MILLI_TIME_MASK) {
+        wait_time_encoded = MAX_MILLI_TIME_MASK;
+      }
+      wait_time_encoded |= UPPER_BOUND_MICRO_TIME_MASK;
+    }
+    cur_binlog.write_event_type(EventTypeEnum::etScriptWaitNet, wait_time_encoded);
   }
 
   static void onScriptShuttingDown(float timeOffset, bool isRegularShutdown) {

runtime/resumable.cpp

@@ -54,6 +54,8 @@ void Resumable::update_output() {
   output_ = in_main_thread() ? nullptr : get_storage(runned_resumable_id);
 }
 
+int64_t first_forked_resumable_id;
+
 namespace {
 
 struct resumable_info {
@@ -81,9 +83,8 @@ struct started_resumable_info : resumable_info {
   int64_t fork_id;
 };
 
-int64_t first_forked_resumable_id;
 int64_t first_array_forked_resumable_id;
-int64_t current_forked_resumable_id = FORK_START_ID;
+int64_t current_forked_resumable_id = 1123456789;
 forked_resumable_info *forked_resumables;
 forked_resumable_info gotten_forked_resumable_info;
 uint32_t forked_resumables_size;

runtime/resumable.h

@@ -10,11 +10,10 @@
 #include "runtime/storage.h"
 
 extern bool resumable_finished;
+extern int64_t first_forked_resumable_id;
 
 extern const char *last_wait_error;
 
-constexpr int FORK_START_ID = 1123456789;
-
 #define WAIT return false;
 #define RETURN(x) output_->save <ReturnT> (x); return true;
 #define RETURN_VOID() output_->save_void (); return true;