Add printingAdd print time for wamrc, fix posix mmap bug time for wamrc, fixed a posix mmap bug. (#206)

Change-Id: Ib6517b8a69cf022a1a6a74efa1f98155aec143bc

core/iwasm/compilation/aot_compiler.c

@@ -727,6 +727,8 @@ aot_compile_wasm(AOTCompContext *comp_ctx)
   bool ret;
   uint32 i;
 
+  bh_print_time("Begin to compile WASM bytecode to LLVM IR");
+
   for (i = 0; i < comp_ctx->func_ctx_count; i++)
     if (!aot_compile_func(comp_ctx, i)) {
 #if 0
@@ -744,6 +746,8 @@ aot_compile_wasm(AOTCompContext *comp_ctx)
   errno = 0;
 #endif
 
+  bh_print_time("Begin to verify LLVM module");
+
   ret = LLVMVerifyModule(comp_ctx->module, LLVMPrintMessageAction, &msg);
   if (!ret && msg) {
       if (msg[0] != '\0') {
@@ -754,6 +758,8 @@ aot_compile_wasm(AOTCompContext *comp_ctx)
       LLVMDisposeMessage(msg);
   }
 
+  bh_print_time("Begin to run function optimization passes");
+
   if (comp_ctx->optimize) {
       LLVMInitializeFunctionPassManager(comp_ctx->pass_mgr);
       for (i = 0; i < comp_ctx->func_ctx_count; i++)
@@ -769,6 +775,8 @@ aot_emit_llvm_file(AOTCompContext *comp_ctx, const char *file_name)
 {
     char *err = NULL;
 
+    bh_print_time("Begin to emit LLVM IR file");
+
     if (LLVMPrintModuleToFile(comp_ctx->module, file_name, &err) != 0) {
         if (err) {
             LLVMDisposeMessage(err);
@@ -786,6 +794,8 @@ aot_emit_object_file(AOTCompContext *comp_ctx, char *file_name)
 {
     char *err = NULL;
 
+    bh_print_time("Begin to emit object file");
+
     if (LLVMTargetMachineEmitToFile(comp_ctx->target_machine,
                                     comp_ctx->module,
                                     file_name,

core/iwasm/compilation/aot_emit_aot_file.c

@@ -1837,6 +1837,8 @@ aot_obj_data_create(AOTCompContext *comp_ctx)
     char *err = NULL;
     AOTObjectData *obj_data;
 
+    bh_print_time("Begin to emit object file to buffer");
+
     if (!(obj_data = wasm_runtime_malloc(sizeof(AOTObjectData)))) {
         aot_set_last_error("allocate memory failed.");
         return false;
@@ -1866,6 +1868,8 @@ aot_obj_data_create(AOTCompContext *comp_ctx)
         goto fail;
     }
 
+    bh_print_time("Begin to resolve object file info");
+
     /* resolve target info/text/relocations/functions */
     if (!aot_resolve_target_info(comp_ctx, obj_data)
         || !aot_resolve_text(obj_data)
@@ -1894,6 +1898,8 @@ aot_emit_aot_file(AOTCompContext *comp_ctx, AOTCompData *comp_data,
     if (!obj_data)
         return false;
 
+    bh_print_time("Begin to emit AOT file");
+
     aot_file_size = get_aot_file_size(comp_data, obj_data);
 
     if (!(buf = aot_file_buf = wasm_runtime_malloc(aot_file_size))) {

core/shared/platform/common/posix/posix_memmap.c

@@ -43,7 +43,7 @@ os_mmap(void *hint, uint32 size, int prot, int flags)
 
     /* try 5 times */
     for (i = 0; i < 5; i ++) {
-        addr = mmap(hint, size, map_prot, map_flags, -1, 0);
+        addr = mmap(hint, request_size, map_prot, map_flags, -1, 0);
         if (addr != MAP_FAILED)
             break;
     }

core/shared/utils/bh_log.c

@@ -52,3 +52,28 @@ bh_log(LogLevel log_level, const char *file, int line, const char *fmt, ...)
 
     os_printf("\n");
 }
+
+static uint32 last_time_ms = 0;
+static uint32 total_time_ms = 0;
+
+void
+bh_print_time(const char *prompt)
+{
+    uint32 curr_time_ms;
+
+    if (log_verbose_level < 3)
+        return;
+
+    curr_time_ms = (uint32)bh_get_tick_ms();
+
+    if (last_time_ms == 0)
+        last_time_ms = curr_time_ms;
+
+    total_time_ms += curr_time_ms - last_time_ms;
+
+    printf("%-48s time of last stage: %u ms, total time: %u ms\n",
+           prompt, curr_time_ms - last_time_ms, total_time_ms);
+
+    last_time_ms = curr_time_ms;
+}
+

core/shared/utils/bh_log.h

@@ -47,6 +47,9 @@ bh_log(LogLevel log_level, const char *file, int line, const char *fmt, ...);
 #define LOG_WARNING(...) bh_log(LOG_LEVEL_WARNING, NULL, 0, __VA_ARGS__)
 #define LOG_VERBOSE(...) bh_log(LOG_LEVEL_VERBOSE, NULL, 0, __VA_ARGS__)
 
+void
+bh_print_time(const char *prompt);
+
 #ifdef __cplusplus
 }
 #endif

wamr-compiler/main.c

@@ -35,6 +35,7 @@ print_help()
   printf("                              object         Native object file\n");
   printf("                              llvmir-unopt   Unoptimized LLVM IR\n");
   printf("                              llvmir-opt     Optimized LLVM IR\n");
+  printf("  -v=n                      Set log verbose level (0 to 5, default is 2), larger with more log\n");
   printf("Examples: wamrc -o test.aot test.wasm\n");
   printf("          wamrc --target=i386 -o test.aot test.wasm\n");
   printf("          wamrc --target=i386 --format=object -o test.o test.wasm\n");
@@ -121,6 +122,11 @@ main(int argc, char *argv[])
             return print_help();
         }
     }
+    else if (!strncmp(argv[0], "-v=", 3)) {
+        log_verbose_level = atoi(argv[0] + 3);
+        if (log_verbose_level < 0 || log_verbose_level > 5)
+            return print_help();
+    }
     else
       return print_help();
   }
@@ -148,6 +154,8 @@ main(int argc, char *argv[])
 
   bh_log_set_verbose_level(log_verbose_level);
 
+  bh_print_time("Begin to load wasm file");
+
   /* load WASM byte buffer from WASM bin file */
   if (!(wasm_file = (uint8*)
         bh_read_file_to_buffer(wasm_file_name, &wasm_file_size)))
@@ -165,12 +173,16 @@ main(int argc, char *argv[])
     goto fail3;
   }
 
+  bh_print_time("Begin to create compile context");
+
   if (!(comp_ctx = aot_create_comp_context(comp_data,
                                            &option))) {
     printf("%s\n", aot_get_last_error());
     goto fail4;
   }
 
+  bh_print_time("Begin to compile");
+
   if (!aot_compile_wasm(comp_ctx)) {
     printf("%s\n", aot_get_last_error());
     goto fail5;
@@ -200,6 +212,8 @@ main(int argc, char *argv[])
           break;
   }
 
+  bh_print_time("Compile end");
+
   printf("Compile success, file %s was generated.\n", out_file_name);
 
 fail5:
@@ -221,6 +235,8 @@ fail2:
 fail1:
   /* Destroy runtime environment */
   wasm_runtime_destroy();
+
+  bh_print_time("wamrc return");
   return 0;
 }