Add support for profiling

[GoogleCodeExporter]

Wasted half an hour of already scarce hacking time to hunt where exactly a car 
gets a non-pair as argument. There is no stack in owl, but if primop errors 
would pass the registers, or at least the most common continuation register, to 
mcp, then the owl side could print something like a stack trace using the 
remaining chain of continuations.

To be useful, this would also need a way to associate a name to continuations 
generated from a named function. This would also useful for other debugging 
messages.

Original issue reported on code.google.com by aohelin on 10 Sep 2010 at 7:30

[GoogleCodeExporter]

Original comment by aohelin on 22 Sep 2010 at 1:41

• Added labels: Milestone-0.3, Type-Enhancement
• Removed labels: Type-Defect

[GoogleCodeExporter]

Rough plan how to do this in practice:
 - allow controlling thread quantums
 - use the suspended thunk to record samples for profiling, and traces for debugging

How this could be used.
 $ ol --profile --run foo.l 11 22 2>&1 | grep "^PROF: " | head -n 3
 PROF: Execution samples:
 PROF:   #<+>: 1124
 PROF:   #<->: 1013
 $

Original comment by aohelin on 4 Jan 2012 at 12:27

• Changed title: Need for debugging and profiling
• Added labels: Priority-High
• Removed labels: Milestone-0.3, Priority-Medium

[GoogleCodeExporter]

Tracking just the profiling part here, since it is currently more important.

Original comment by aohelin on 4 Jan 2012 at 3:04

• Changed title: Add support for profiling

[GoogleCodeExporter]

Added execution tracing.

This is currently done by using a special thread scheduler which stops threads 
at each function call, call or return, which seems to be a good hackable 
approach. Functions names not there yet, which makes the output currently 
rather unhelpful, apart from estimating algorithm complexities... :)

> (profile (lambda () (! 1000) 'exit) 30)
145066:#<function>
144567:#<function>
39769:#<function>
33141:#<function>
33141:#<function>
33141:#<function>
33141:#<function>
33140:#<function>
33140:#<function>
19885:#<function>
13256:#<function>
6628:#<function>
6628:#<function>
6628:#<function>
6628:#<function>
6628:#<function>
6628:#<function>
6628:#<function>
6628:#<function>
999:#<function>
998:#<function>
1:#<function>
1:#<function>
1:#<function>
1:#<function>
1:#<function>
exit
> 

Original comment by aohelin on 5 Jan 2012 at 9:27

• Changed state: Started

[GoogleCodeExporter]

Fixed naming issue. Currently breaking on all function calls and exits and 
counting them seems to cause a 30x overhead. 

$ time bin/vm fasl/bootp.fasl -e ',r "bench/horn.l" (profile (lambda () (test 
null)) 30)'
 + (rule (= (x . 1) (x . 2) 3) (= 1 2 3))
 + (rule (= () () true))
 + (rule (= (x . 0) () false))
 + (rule (= () (x . 0) false))
 + (rule (+ () 1 1))
 + (rule (+ 1 () 1))
 + (rule (+ (x . 1) 2 (x . 3)) (+ 1 2 3))
 + (rule (- 1 2 3) (+ 3 2 1))
 + (rule (* () 0 ()))
 + (rule (* (x . 1) 2 3) (* 1 2 4) (+ 4 2 3))
 + (rule (/ 1 2 3) (* 2 3 1))
 + (rule (fakt () (x)))
 + (rule (fakt 1 2) (- 1 (x) 3) (fakt 3 4) (* 4 1 2))
 + (rule (self 1 2) (fakt 1 3) (- 1 (x) 4) (fakt 4 5) (/ 3 5 2))
solving (fakt (x x x x) 1) {
 - (fakt (x x x x) (x x x x x x x x x x x x x x x x x x x x x x x x))
}
solving (fakt (x x x x) 1) {
 - (fakt (x x x x) (x x x x x x x x x x x x x x x x x x x x x x x x))
}
 => ((self 1 2) (fakt 1 3) (- 1 (x) 4) (fakt 4 5) (/ 3 5 2))
1584816:#<in:seek>
1553103:#<in:seek>
85400:#<in:apply-env>
85400:#<in:apply-env>
85400:#<in:apply-env>
65408:#<in:instantiate-rule>
37351:#<in:apply-env>
37168:#<in:apply-env>
34272:#<in:instantiate-rule>
31136:#<in:instantiate-rule>
31136:#<in:instantiate-rule>
30557:#<function>
30319:#<function>
30319:#<function>
27552:#<in:instantiate-rule>
12410:#<in:unify>
8436:#<in:unify>
7740:#<in:unify>
7524:#<in:unify>
7482:#<function>
6720:#<in:instantiate-rule>
6720:#<function>
4755:#<in:unify>
3360:#<in:prove>
3136:#<in:prove>
3136:#<in:prove>
3136:#<in:prove>
3136:#<in:prove>
3136:#<in:prove>
3136:#<in:instantiate-rule>
(42)

real    0m31.164s
user    0m31.094s
sys     0m0.012s

Original comment by aohelin on 5 Jan 2012 at 11:14

[GoogleCodeExporter]

This needs to wait for dust to settle in library support.

Original comment by aohelin on 19 Jan 2012 at 8:57

• Added labels: Priority-Medium
• Removed labels: Priority-High

[GoogleCodeExporter]

Original comment by aohelin on 13 May 2012 at 5:10

• Changed state: Accepted