vm: count samples during unoptimized compiler

basis/tools/profiler/sampling/sampling.factor

@@ -1,9 +1,10 @@
 ! (c)2011 Joe Groff bsd license
 USING: accessors assocs calendar combinators
-combinators.short-circuit continuations fry io kernel
+combinators.short-circuit continuations fry generalizations
-kernel.private locals math math.statistics math.vectors memory
+hashtables.identity io kernel kernel.private locals math
-namespaces prettyprint sequences sets sorting
+math.statistics math.vectors memory namespaces prettyprint
-tools.profiler.sampling.private hashtables.identity generalizations ;
+sequences sequences.generalizations sets sorting
+tools.profiler.sampling.private ;
 FROM: sequences => change-nth ;
 FROM: assocs => change-at ;
 IN: tools.profiler.sampling
@@ -26,12 +27,17 @@ CONSTANT: ignore-words
     [ 0 profiling ] [ ] cleanup
     (get-samples) raw-profile-data set-global ; inline
 
-: total-sample-count ( sample -- count ) first ;
+: total-sample-count ( sample -- count ) 0 swap nth ;
-: gc-sample-count ( sample -- count ) second ;
+: gc-sample-count ( sample -- count ) 1 swap nth ;
-: foreign-sample-count ( sample -- count ) third ;
+: jit-sample-count ( sample -- count ) 2 swap nth ;
-: foreign-thread-sample-count ( sample -- count ) fourth ;
+: foreign-sample-count ( sample -- count ) 3 swap nth ;
-: sample-thread ( sample -- alien ) 4 swap nth ;
+: foreign-thread-sample-count ( sample -- count ) 4 swap nth ;
-: sample-callstack ( sample -- array ) 5 swap nth ;
+: sample-counts-slice ( sample -- counts ) 5 head-slice ;
+
+: sample-thread ( sample -- alien ) 5 swap nth ;
+: sample-callstack ( sample -- array ) 6 swap nth ;
+: unclip-callstack ( sample -- sample' callstack-top )
+    clone 6 over [ unclip swap ] change-nth ;
 
 : samples>time ( samples -- time )
     samples-per-second get-global / seconds ;
@@ -63,23 +69,22 @@ CONSTANT: ignore-words
 : time-per-thread ( -- n )
     get-raw-profile-data collect-threads [ (total-time) ] assoc-map ;
 
-: unclip-callstack ( sample -- sample' callstack-top )
-    clone 5 over [ unclip swap ] change-nth ;
-
 : leaf-callstack? ( callstack -- ? )
     [ ignore-word? ] all? ;
 
-: sum-times ( samples -- times )
+CONSTANT: zero-counts { 0 0 0 0 0 }
-    { 0 0 0 0 } [ 4 head-slice v+ ] reduce ;
+
+: sum-counts ( samples -- times )
+    zero-counts [ sample-counts-slice v+ ] reduce ;
 
 TUPLE: profile-node
-    total-time gc-time foreign-time foreign-thread-time children ;
+    total-time gc-time jit-time foreign-time foreign-thread-time children ;
 
 : <profile-node> ( times children -- node )
-    [ first4 [ samples>time ] 4 napply ] dip profile-node boa ;
+    [ 5 firstn [ samples>time ] 5 napply ] dip profile-node boa ;
 
 : <profile-root-node> ( samples collector-quot -- node )
-    [ sum-times ] swap bi <profile-node> ; inline
+    [ sum-counts ] swap bi <profile-node> ; inline
 
 :: (collect-subtrees) ( samples child-quot -- children )
     samples [ sample-callstack leaf-callstack? not ] filter
@@ -87,7 +92,7 @@ TUPLE: profile-node
 
 : collect-tops ( samples -- node )
     [ unclip-callstack ] collect-pairs [
-        [ sum-times ]
+        [ sum-counts ]
         [ [ collect-tops ] (collect-subtrees) ] bi <profile-node>
     ] assoc-map ;
 
@@ -112,7 +117,7 @@ TUPLE: profile-node
     IH{ } clone :> per-word-samples
     samples [| sample |
         sample sample-callstack unique keys [ ignore-word? not ] filter [
-            per-word-samples [ { 0 0 0 0 } or sample 4 head-slice v+ ] change-at
+            per-word-samples [ zero-counts or sample sample-counts-slice v+ ] change-at
         ] each
     ] each
     per-word-samples [ f <profile-node> ] assoc-map ;
@@ -137,16 +142,21 @@ TUPLE: profile-node
     >alist [ second total-time>> ] inv-sort-with ;
 
 : duration. ( duration -- )
-    duration>milliseconds >integer pprint "ms" write ;
+    samples-per-second get-global {
+        { [ dup 1000 <= ] [ drop duration>milliseconds >integer pprint "ms" write ] }
+        { [ dup 1,000,000 <= ] [ drop duration>microseconds >integer pprint "µs" write ] }
+        [ drop duration>nanoseconds >integer pprint "ns" write ]
+    } cond ;
 
 DEFER: (profile.)
 
 : times. ( node -- )
     {
-        [ total-time>> duration. " (" write ]
+        [ total-time>> duration. ]
-        [ gc-time>> duration. " gc, " write ]
+        [ " (GC:" write gc-time>> duration. ]
-        [ foreign-time>> duration. " foreign, " write ]
+        [ ", JIT:" write jit-time>> duration. ]
-        [ foreign-thread-time>> duration. " foreign threads)" write ]
+        [ ", FFI:" write foreign-time>> duration. ]
+        [ ", FT:" write foreign-thread-time>> duration. ")" write ]
     } cleave ;
 
 :: (profile-node.) ( word node depth -- )

vm/jit.cpp

@@ -21,7 +21,16 @@ jit::jit(code_block_type type_, cell owner_, factor_vm *vm)
 	  position(0),
 	  offset(0),
 	  parent(vm)
-{}
+{
+	fixnum count = atomic::add(&parent->current_jit_count, 1);
+	assert(count >= 1);
+}
+
+jit::~jit()
+{
+	fixnum count = atomic::subtract(&parent->current_jit_count, 1);
+	assert(count >= 0);
+}
 
 void jit::emit_relocation(cell relocation_template_)
 {

vm/jit.hpp

@@ -14,6 +14,8 @@ struct jit {
 	factor_vm *parent;
 
 	explicit jit(code_block_type type, cell owner, factor_vm *parent);
+	~jit();
+
 	void compute_position(cell offset);
 
 	void emit_relocation(cell relocation_template);
@@ -67,6 +69,10 @@ struct jit {
 
 	
 	code_block *to_code_block();
+
+private:
+	jit(const jit&);
+	void operator=(const jit&);
 };
 
 }

vm/sampling_profiler.cpp

@@ -9,10 +9,12 @@ profiling_sample_count profiling_sample_count::record_counts() volatile
 	profiling_sample_count returned(
 		sample_count,
 		gc_sample_count,
+		jit_sample_count,
 		foreign_sample_count,
 		foreign_thread_sample_count);
 	atomic::subtract(&sample_count, returned.sample_count);
 	atomic::subtract(&gc_sample_count, returned.gc_sample_count);
+	atomic::subtract(&jit_sample_count, returned.jit_sample_count);
 	atomic::subtract(&foreign_sample_count, returned.foreign_sample_count);
 	atomic::subtract(&foreign_thread_sample_count, returned.foreign_thread_sample_count);
 	return returned;
@@ -22,6 +24,7 @@ void profiling_sample_count::clear() volatile
 {
 	sample_count = 0;
 	gc_sample_count = 0;
+	jit_sample_count = 0;
 	foreign_sample_count = 0;
 	foreign_thread_sample_count = 0;
 	atomic::fence();
@@ -114,14 +117,15 @@ void factor_vm::primitive_get_samples()
 
 		for (; from_iter != samples.end(); ++from_iter, ++to_i)
 		{
-			data_root<array> sample(allot_array(6, false_object),this);
+			data_root<array> sample(allot_array(7, false_object),this);
 
 			set_array_nth(sample.untagged(),0,tag_fixnum(from_iter->counts.sample_count));
 			set_array_nth(sample.untagged(),1,tag_fixnum(from_iter->counts.gc_sample_count));
-			set_array_nth(sample.untagged(),2,tag_fixnum(from_iter->counts.foreign_sample_count));
+			set_array_nth(sample.untagged(),2,tag_fixnum(from_iter->counts.jit_sample_count));
-			set_array_nth(sample.untagged(),3,tag_fixnum(from_iter->counts.foreign_thread_sample_count));
+			set_array_nth(sample.untagged(),3,tag_fixnum(from_iter->counts.foreign_sample_count));
+			set_array_nth(sample.untagged(),4,tag_fixnum(from_iter->counts.foreign_thread_sample_count));
 
-			set_array_nth(sample.untagged(),4,from_iter->thread);
+			set_array_nth(sample.untagged(),5,from_iter->thread);
 
 			cell callstack_size = from_iter->callstack_end - from_iter->callstack_begin;
 			data_root<array> callstack(allot_array(callstack_size,false_object),this);
@@ -135,7 +139,7 @@ void factor_vm::primitive_get_samples()
 			for (; c_from_iter != c_from_iter_end; ++c_from_iter, ++c_to_i)
 				set_array_nth(callstack.untagged(),c_to_i,*c_from_iter);
 
-			set_array_nth(sample.untagged(),5,callstack.value());
+			set_array_nth(sample.untagged(),6,callstack.value());
 
 			set_array_nth(samples_array.untagged(),to_i,sample.value());
 		}
@@ -158,6 +162,8 @@ void factor_vm::enqueue_safepoint_sample(cell samples, cell pc, bool foreign_thr
 		else {
 			if (atomic::load(&current_gc_p))
 				atomic::add(&safepoint_sample_counts.gc_sample_count, samples);
+			if (atomic::load(&current_jit_count) > 0)
+				atomic::add(&safepoint_sample_counts.jit_sample_count, samples);
 			if (pc != 0 && !code->seg->in_segment_p(pc))
 				atomic::add(&safepoint_sample_counts.foreign_sample_count, samples);
 		}

vm/sampling_profiler.hpp

@@ -7,6 +7,8 @@ struct profiling_sample_count
 	fixnum sample_count;
 	// Number of samples taken during GC
 	fixnum gc_sample_count;
+	// Number of samples taken during unoptimized compiler
+	fixnum jit_sample_count;
 	// Number of samples taken during foreign code execution
 	fixnum foreign_sample_count;
 	// Number of samples taken during code execution in non-Factor threads
@@ -15,15 +17,18 @@ struct profiling_sample_count
 	profiling_sample_count() :
 		sample_count(0),
 		gc_sample_count(0),
+		jit_sample_count(0),
 		foreign_sample_count(0),
 		foreign_thread_sample_count(0) {}
 
 	profiling_sample_count(fixnum sample_count,
 		fixnum gc_sample_count,
+		fixnum jit_sample_count,
 		fixnum foreign_sample_count,
 		fixnum foreign_thread_sample_count) :
 		sample_count(sample_count),
 		gc_sample_count(gc_sample_count),
+		jit_sample_count(jit_sample_count),
 		foreign_sample_count(foreign_sample_count),
 		foreign_thread_sample_count(foreign_thread_sample_count) {}
 	
@@ -31,6 +36,7 @@ struct profiling_sample_count
 	{
 		return sample_count
 			+ gc_sample_count
+			+ jit_sample_count
 			+ foreign_sample_count
 			+ foreign_thread_sample_count == 0;
 	}

vm/vm.cpp

@@ -13,7 +13,7 @@ factor_vm::factor_vm() :
 	gc_off(false),
 	current_gc(NULL),
 	current_gc_p(false),
-	current_jit_p(false),
+	current_jit_count(0),
 	gc_events(NULL),
 	fep_p(false),
 	fep_help_was_shown(false),

vm/vm.hpp

@@ -95,7 +95,7 @@ struct factor_vm
 	volatile cell current_gc_p;
 
 	/* Set if we're in the jit */
-	volatile cell current_jit_p;
+	volatile fixnum current_jit_count;
 
 	/* Mark stack */
 	std::vector<cell> mark_stack;