cgen: implement -profile support.

cmd/tools/preludes/profiled_program.v

@@ -0,0 +1,7 @@
+module main
+
+import time
+
+const (
+	profiled_program_time_used = time.sys_mono_now()
+)

cmd/v/v.v

@@ -146,7 +146,6 @@ fn parse_args(args []string) (&pref.Preferences, string) {
 				res.is_bare = true
 			}
 			'-prof', '-profile' {
-				eprintln('TODO: -prof')
 				res.is_prof = true
 			}
 			'-prod' {

vlib/v/builder/compile.v

@@ -169,6 +169,9 @@ pub fn (v Builder) get_user_files() []string {
 	if v.pref.is_test && v.pref.is_stats {
 		user_files << os.join_path(preludes_path, 'tests_with_stats.v')
 	}
+	if v.pref.is_prof {
+		user_files << os.join_path(preludes_path, 'profiled_program.v')
+	}
 	is_test := dir.ends_with('_test.v')
 	mut is_internal_module_test := false
 	if is_test {

vlib/v/gen/cgen.v

@@ -55,6 +55,8 @@ struct Gen {
 	stringliterals       strings.Builder // all string literals (they depend on tos3() beeing defined
 	auto_str_funcs       strings.Builder // function bodies of all auto generated _str funcs
 	comptime_defines     strings.Builder // custom defines, given by -d/-define flags on the CLI
+	pcs_declarations     strings.Builder // -prof profile counter declarations for each function
+	pcs                  map[string]string // -prof profile counter fn_names => fn counter name
 	table                &table.Table
 	pref                 &pref.Preferences
 mut:
@@ -79,6 +81,7 @@ mut:
 	assign_op            token.Kind // *=, =, etc (for array_set)
 	defer_stmts          []ast.DeferStmt
 	defer_ifdef          string
+	defer_profile_code   string
 	str_types            []string // types that need automatic str() generation
 	threaded_fns         []string // for generating unique wrapper types and fns for `go xxx()`
 	array_fn_definitions []string // array equality functions that have been defined
@@ -113,6 +116,7 @@ pub fn cgen(files []ast.File, table &table.Table, pref &pref.Preferences) string
 		auto_str_funcs: strings.new_builder(100)
 		comptime_defines: strings.new_builder(100)
 		inits: strings.new_builder(100)
+		pcs_declarations: strings.new_builder(100)
 		table: table
 		pref: pref
 		fn_decl: 0
@@ -154,11 +158,34 @@ pub fn cgen(files []ast.File, table &table.Table, pref &pref.Preferences) string
 	}
 	//
 	g.finish()
-	return g.hashes() + g.comptime_defines.str() + '\n// V typedefs:\n' + g.typedefs.str() +
-		'\n// V typedefs2:\n' + g.typedefs2.str() + '\n// V cheaders:\n' + g.cheaders.str() + '\n// V includes:\n' +
-		g.includes.str() + '\n// V definitions:\n' + g.definitions.str() + g.interface_table() + '\n// V gowrappers:\n' +
-		g.gowrappers.str() + '\n// V stringliterals:\n' + g.stringliterals.str() + '\n// V auto str functions:\n' +
-		g.auto_str_funcs.str() + '\n// V out\n' + g.out.str() + '\n// THE END.'
+	//
+	b := strings.new_builder(250000)
+	b.writeln(g.hashes())
+	b.writeln(g.comptime_defines.str())
+	b.writeln('\n// V typedefs:')
+	b.writeln(g.typedefs.str())
+	b.writeln('\n// V typedefs2:')
+	b.writeln(g.typedefs2.str())
+	b.writeln('\n// V cheaders:')
+	b.writeln(g.cheaders.str())
+	b.writeln('\n// V includes:')
+	b.writeln(g.includes.str())
+	b.writeln('\n// V definitions:')
+	b.writeln(g.definitions.str())
+	b.writeln('\n// V profile counters:')
+	b.writeln(g.pcs_declarations.str())
+	b.writeln('\n// V interface table:')
+	b.writeln(g.interface_table())
+	b.writeln('\n// V gowrappers:')
+	b.writeln(g.gowrappers.str())
+	b.writeln('\n// V stringliterals:')
+	b.writeln(g.stringliterals.str())
+	b.writeln('\n// V auto str functions:')
+	b.writeln(g.auto_str_funcs.str())
+	b.writeln('\n// V out')
+	b.writeln(g.out.str())
+	b.writeln('\n// THE END.')
+	return b.str()
 }
 
 pub fn (g Gen) hashes() string {
@@ -483,7 +510,7 @@ fn (mut g Gen) stmt(node ast.Stmt) {
 			fn_start_pos := g.out.len
 			g.fn_decl = it // &it
 			g.gen_fn_decl(it)
-			if g.last_fn_c_name in g.pref.printfn_list {
+			if g.pref.printfn_list.len > 0 && g.last_fn_c_name in g.pref.printfn_list {
 				println(g.out.after(fn_start_pos))
 			}
 			g.writeln('')
@@ -554,9 +581,7 @@ fn (mut g Gen) stmt(node ast.Stmt) {
 		}
 		ast.Module {}
 		ast.Return {
-			if g.defer_stmts.len > 0 {
-				g.write_defer_stmts()
-			}
+			g.write_defer_stmts_when_needed()
 			g.return_statement(it)
 		}
 		ast.StructDecl {

vlib/v/gen/fn.v

@@ -102,6 +102,27 @@ fn (mut g Gen) gen_fn_decl(it ast.FnDecl) {
 			}
 		}
 	}
+
+    // Profiling mode? Start counting at the beginning of the function (save current time).
+    if g.pref.is_prof {
+		if is_main {
+			g.writeln('')
+			g.writeln('\tatexit(vprint_profile_stats);')
+			g.writeln('')
+		}
+		if it.name == 'time.sys_mono_now' {
+			g.defer_profile_code = ''
+		}else{
+			fn_profile_counter_name := 'vpc_${g.last_fn_c_name}'
+			g.writeln('')
+			g.writeln('\tdouble _PROF_FN_START = time__sys_mono_now(); ${fn_profile_counter_name}_calls++; // $it.name')
+			g.writeln('')
+			g.defer_profile_code = '\t${fn_profile_counter_name} += time__sys_mono_now() - _PROF_FN_START;'
+			g.pcs_declarations.writeln('double ${fn_profile_counter_name} = 0.0; u64 ${fn_profile_counter_name}_calls = 0;')
+			g.pcs[ g.last_fn_c_name ] = fn_profile_counter_name
+		}
+	}
+
 	g.stmts(it.stmts)
 	// ////////////
 	if g.autofree {
@@ -116,10 +137,15 @@ fn (mut g Gen) gen_fn_decl(it ast.FnDecl) {
 			verror('test files cannot have function `main`')
 		}
 	}
-	if g.defer_stmts.len > 0 {
-		g.write_defer_stmts()
-	}
+	g.write_defer_stmts_when_needed()
 	if is_main {
+		if g.pref.is_prof {
+			g.pcs_declarations.writeln('void vprint_profile_stats(){')
+			for pfn_name, pcounter_name in g.pcs {
+				g.pcs_declarations.writeln('\tif (${pcounter_name}_calls) printf("%llu %f %f ${pfn_name} \\n", ${pcounter_name}_calls, $pcounter_name, $pcounter_name / ${pcounter_name}_calls );')
+			}
+			g.pcs_declarations.writeln('}')
+		}
 		g.writeln('\treturn 0;')
 	}
 	g.writeln('}')
@@ -127,6 +153,18 @@ fn (mut g Gen) gen_fn_decl(it ast.FnDecl) {
 	g.fn_decl = 0
 }
 
+fn (mut g Gen) write_defer_stmts_when_needed(){
+	if g.defer_profile_code.len > 0 {
+		g.writeln('')
+		g.writeln('\t// defer_profile_code')
+		g.writeln(g.defer_profile_code )
+		g.writeln('')
+	}
+	if g.defer_stmts.len > 0 {
+		g.write_defer_stmts()
+	}
+}
+
 fn (mut g Gen) fn_args(args []table.Arg, is_variadic bool) {
 	no_names := args.len > 0 && args[0].name == 'arg_1'
 	for i, arg in args {
@@ -248,7 +286,7 @@ fn (mut g Gen) method_call(node ast.CallExpr) {
 		g.write('/*rec*/*')
 	}
 	g.expr(node.left)
-	is_variadic := node.expected_arg_types.len > 0 && 
+	is_variadic := node.expected_arg_types.len > 0 &&
 		node.expected_arg_types[node.expected_arg_types.len -1].flag_is(.variadic)
 	if node.args.len > 0 || is_variadic {
 		g.write(', ')