feat: Enhance request struct and add debug logging (#81)

* feat: Enhance request struct and add debug logging

* doc: add doc about print-head-req

Author: xiaguan

.gitignore

@@ -15,3 +15,5 @@ example/cacheSimulatorC/cmake-build-debug
 fig/
 # Chaos
 sftp-config.json
+# Clangd cache
+*.cache/

CMakeLists.txt

@@ -13,6 +13,8 @@ set(CMAKE_CXX_STANDARD 17)
 set(CMAKE_CXX_STANDARD_REQUIRED On)
 set(CMAKE_CXX_EXTENSIONS Off)
 
+# export compile commands, useful for IDEs
+set(EXPORT_COMPILE_COMMANDS ON)
 ########################################
 # define options #
 # options are cached variables https://stackoverflow.com/questions/35744647/disabling-cmake-option-has-no-effect

doc/quickstart_cachesim.md

@@ -185,6 +185,8 @@ You can use `-p` or `--prefetch` to set the prefetching algorithm.
 # Use TTL
 ./cachesim ../data/trace.vscsi vscsi lru 1gb --use-ttl=true
 
+# Disable the print of the first few requests
+./cachesim ../data/trace.vscsi vscsi lru 1gb --print-head-req=false
 ```
 
 

example/cacheSimulator/main.c

@@ -23,7 +23,7 @@ int main(int argc, char **argv) {
 
   /* read one request and print */
   read_one_req(reader, req);
-  print_request(req);
+  print_request(req, INFO_LEVEL);
 
   /* setup a cache */
   common_cache_params_t cc_params = {

libCacheSim/bin/cachesim/cli_parser.c

@@ -47,6 +47,7 @@ enum argp_option_short {
 
   OPTION_PREFETCH_ALGO = 'p',
   OPTION_PREFETCH_PARAMS = 0x109,
+  OPTION_PRINT_HEAD_REQ = 0x10a,
 };
 
 /*
@@ -93,6 +94,8 @@ static struct argp_option options[] = {
     {"consider-obj-metadata", OPTION_CONSIDER_OBJ_METADATA, "false", 0,
      "Whether consider per object metadata size in the simulated cache", 10},
     {"verbose", OPTION_VERBOSE, "1", 0, "Produce verbose output", 10},
+    {"print-head-req", OPTION_PRINT_HEAD_REQ, "false", 0,
+     "Print the first few requests", 10},
 
     {0}};
 
@@ -164,6 +167,9 @@ static error_t parse_opt(int key, char *arg, struct argp_state *state) {
     case OPTION_WARMUP_SEC:
       arguments->warmup_sec = atoi(arg);
       break;
+    case OPTION_PRINT_HEAD_REQ:
+      arguments->print_head_req = is_true(arg) ? true : false;
+      break;
     case ARGP_KEY_ARG:
       if (state->arg_num >= N_ARGS) {
         printf("found too many arguments, current %s\n", arg);
@@ -198,7 +204,8 @@ static char doc[] =
     "trace can be zstd compressed\n"
     "cache_size is in byte, but also support KB/MB/GB\n"
     "supported trace_type: txt/csv/twr/vscsi/oracleGeneralBin\n"
-    "supported eviction_algo: LRU/LFU/FIFO/ARC/LeCaR/Cacheus\n";
+    "supported eviction_algo: LRU/LFU/FIFO/ARC/LeCaR/Cacheus\n"
+    "print-head-req: Print the first few requests when simulating start\n";
 
 /**
  * @brief initialize the arguments
@@ -226,6 +233,7 @@ static void init_arg(struct arguments *args) {
   memset(args->ofilepath, 0, OFILEPATH_LEN);
   args->n_req = -1;
   args->sample_ratio = 1.0;
+  args->print_head_req = true;
 
   for (int i = 0; i < N_MAX_ALGO; i++) {
     args->eviction_algo[i] = NULL;

libCacheSim/bin/cachesim/internal.h

@@ -46,6 +46,7 @@ struct arguments {
   bool ignore_obj_size;
   bool consider_obj_metadata;
   bool use_ttl;
+  bool print_head_req;
 
   /* arguments generated */
   reader_t *reader;
@@ -57,7 +58,8 @@ void parse_cmd(int argc, char *argv[], struct arguments *args);
 void free_arg(struct arguments *args);
 
 void simulate(reader_t *reader, cache_t *cache, int report_interval,
-              int warmup_sec, char *ofilepath, bool ignore_obj_size);
+              int warmup_sec, char *ofilepath, bool ignore_obj_size,
+              bool print_head_req);
 
 void print_parsed_args(struct arguments *args);
 

libCacheSim/bin/cachesim/main.c

@@ -19,10 +19,9 @@ int main(int argc, char **argv) {
   if (args.n_cache_size == 0) {
     ERROR("no cache size found\n");
   }
-
   if (args.n_cache_size * args.n_eviction_algo == 1) {
-    simulate(args.reader, args.caches[0], args.report_interval, args.warmup_sec,
-             args.ofilepath, args.ignore_obj_size);
+    simulate(args.reader, args.caches[0], args.report_interval, args.warmup_sec, args.ofilepath, args.ignore_obj_size,
+             args.print_head_req);
 
     free_arg(&args);
     return 0;

libCacheSim/bin/cachesim/sim.c

@@ -1,5 +1,3 @@
-
-
 #include "../../include/libCacheSim/cache.h"
 #include "../../include/libCacheSim/reader.h"
 #include "../../utils/include/mymath.h"
@@ -10,8 +8,16 @@
 extern "C" {
 #endif
 
-void simulate(reader_t *reader, cache_t *cache, int report_interval,
-              int warmup_sec, char *ofilepath, bool ignore_obj_size) {
+void print_head_requests(request_t *req, uint64_t req_cnt) {
+  if (req_cnt < 2) {
+    print_request(req, INFO_LEVEL);
+  } else if (req_cnt < 10) {
+    print_request(req, DEBUG_LEVEL);
+  }
+}
+
+void simulate(reader_t *reader, cache_t *cache, int report_interval, int warmup_sec, char *ofilepath,
+              bool ignore_obj_size, bool print_head_req) {
   /* random seed */
   srand(time(NULL));
   set_rand_seed(rand());
@@ -27,6 +33,10 @@ void simulate(reader_t *reader, cache_t *cache, int report_interval,
 
   double start_time = -1;
   while (req->valid) {
+    if (print_head_req) {
+      print_head_requests(req, req_cnt);
+    }
+
     req->clock_time -= start_ts;
     if (req->clock_time <= warmup_sec) {
       cache->get(cache, req);
@@ -72,15 +82,15 @@ void simulate(reader_t *reader, cache_t *cache, int report_interval,
 #pragma GCC diagnostic ignored "-Wformat-truncation"
   if (!ignore_obj_size) {
     snprintf(output_str, 1024,
-            "%s %s cache size %8s, %16lu req, miss ratio %.4lf, throughput "
-            "%.2lf MQPS\n",
+             "%s %s cache size %8s, %16lu req, miss ratio %.4lf, throughput "
+             "%.2lf MQPS\n",
             reader->trace_path, cache->cache_name, size_str,
             (unsigned long)req_cnt, (double)miss_cnt / (double)req_cnt,
             (double)req_cnt / 1000000.0 / runtime);
   } else {
     snprintf(output_str, 1024,
-            "%s %s cache size %8ld, %16lu req, miss ratio %.4lf, throughput "
-            "%.2lf MQPS\n",
+             "%s %s cache size %8ld, %16lu req, miss ratio %.4lf, throughput "
+             "%.2lf MQPS\n",
             reader->trace_path, cache->cache_name, cache->cache_size,
             (unsigned long)req_cnt, (double)miss_cnt / (double)req_cnt,
             (double)req_cnt / 1000000.0 / runtime);

libCacheSim/include/libCacheSim/request.h

@@ -108,15 +108,14 @@ static inline request_t *clone_request(const request_t *req) {
  */
 static inline void free_request(request_t *req) { my_free(request_t, req); }
 
-static inline void print_request(request_t *req) {
+static inline void print_request(request_t *req, int log_level) {
 #ifdef SUPPORT_TTL
-  INFO("req clcok_time %lu, id %llu, size %ld, ttl %ld, op %s, valid %d\n",
-       (unsigned long)req->clock_time, (unsigned long long)req->obj_id,
-       (long)req->obj_size, (long)req->ttl, req_op_str[req->op], req->valid);
+  LOGGING(log_level, "req clcok_time %lu, id %llu, size %ld, ttl %ld, op %s, valid %d\n",
+          (unsigned long)req->clock_time, (unsigned long long)req->obj_id, (long)req->obj_size, (long)req->ttl,
+          req_op_str[req->op], req->valid);
 #else
-  printf("req clcok_time %lu, id %llu, size %ld, op %s, valid %d\n",
-         (unsigned long)req->clock_time, (unsigned long long)req->obj_id,
-         (long)req->obj_size, req_op_str[req->op], req->valid);
+  LOGGING(log_level, "req clcok_time %lu, id %llu, size %ld, op %s, valid %d\n", (unsigned long)req->clock_time,
+          (unsigned long long)req->obj_id, (long)req->obj_size, req_op_str[req->op], req->valid);
 #endif
 }
 

libCacheSim/traceReader/customizedReader/oracle/oracleTwrNSBin.h

@@ -101,7 +101,7 @@ static int oracleSysTwrNSBin_read_one_req(reader_t *reader, request_t *req) {
   if (req->val_size == 0 && reader->ignore_size_zero_req && (req->op == OP_GET || req->op == OP_GETS) &&
       reader->read_direction == READ_FORWARD) {
     ERROR("find size 0 request\n");
-    print_request(req);
+    print_request(req, WARN_LEVEL);
     return oracleSysTwrNSBin_read_one_req(reader, req);
   }