1
00:00:00,720 --> 00:00:05,440
Hello, in this course I'll show you
how to profile an application in Pharo.

2
00:00:05,600 --> 00:00:08,640
That means measuring
the execution of expressions

3
00:00:08,800 --> 00:00:11,320
to see if we can replace
them with others to gain time,

4
00:00:11,480 --> 00:00:13,520
during the execution of a program.

5
00:00:14,560 --> 00:00:18,360
Basically, what people say is,
if you've never profiled

6
00:00:18,520 --> 00:00:22,920
an application you could
increase speeds by 40-50%.

7
00:00:23,080 --> 00:00:26,240
I'm not convinced.
I don't know, I've no proof.

8
00:00:26,400 --> 00:00:29,160
But I can show you the tools in Pharo

9
00:00:29,320 --> 00:00:32,160
for doing this profiling.

10
00:00:32,320 --> 00:00:35,800
The first expression in Pharo
is "timeToRun".

11
00:00:35,960 --> 00:00:38,320
It's a message we send to a block,

12
00:00:38,480 --> 00:00:40,720
which will give us the run time
of an expression.

13
00:00:40,880 --> 00:00:43,680
So, here in "1000 factorial",

14
00:00:43,840 --> 00:00:48,120
I want to measure the run time
of "1000 factorial", I put it in a block

15
00:00:48,280 --> 00:00:50,600
and I send the message,
"timeToRun".

16
00:00:50,760 --> 00:00:55,120
Now that we have 'timeToRun"
it's easy to compare 2 executions.

17
00:00:55,280 --> 00:00:57,520
Here's a little exercise:

18
00:00:57,680 --> 00:01:00,720
If I do "select" followed by "collect",

19
00:01:00,880 --> 00:01:05,280
is it slower than "select:thenCollect",

20
00:01:05,440 --> 00:01:08,400
knowing that this involves two passes

21
00:01:08,560 --> 00:01:10,600
in the first case
and one in the second.

22
00:01:10,760 --> 00:01:14,120
So I think it will take longer,
but we're going to check.

23
00:01:14,840 --> 00:01:17,560
What do I do?
I create my collection in both cases,

24
00:01:17,720 --> 00:01:21,920
I'm looking, I create my collection
with 10 elements, a small collection,

25
00:01:22,080 --> 00:01:26,200
and what I'll do is create
a certain number of times,

26
00:01:27,360 --> 00:01:31,000
I'll make a loop so I can run
the expressions several times.

27
00:01:31,160 --> 00:01:32,960
You can see, in the first part,

28
00:01:33,120 --> 00:01:38,000
I've my collection,
I select every element larger than 5,

29
00:01:38,160 --> 00:01:41,920
and afterwards, I'll square
the elements I've selected,

30
00:01:42,080 --> 00:01:45,960
and in the 2nd expression, I'll say,
what do I want to select?

31
00:01:46,120 --> 00:01:49,840
Everything larger than 5,
and I'll square them.

32
00:01:50,000 --> 00:01:53,360
We see that the system tells me
that's 500 milliseconds,

33
00:01:53,520 --> 00:01:57,320
and that's 300 milliseconds.
The 2nd expression is better.

34
00:01:57,480 --> 00:01:59,960
You see how it works,
it's up to you to do it.

35
00:02:00,120 --> 00:02:05,800
Note that we're sometimes obliged
to put very large loops inside,

36
00:02:06,560 --> 00:02:11,600
to amplify the measurement,
for both cases, of course.

37
00:02:12,080 --> 00:02:16,800
Otherwise, there's another operation,
another message called "bench".

38
00:02:16,960 --> 00:02:20,520
"Bench" will tell us
how many times the code,

39
00:02:20,680 --> 00:02:26,240
which is being studied,
is executed over 5 seconds.

40
00:02:27,560 --> 00:02:31,560
I take my "1000 factorial bench"
example again, and I can execute it

41
00:02:31,720 --> 00:02:33,840
610,000 times a second.

42
00:02:34,000 --> 00:02:37,000
In this case, if we so desire,
we can also make it

43
00:02:37,160 --> 00:02:39,320
that the figure is as high as possible.

44
00:02:39,480 --> 00:02:42,680
There's also a variant
of bench, "benchFor",

45
00:02:42,840 --> 00:02:46,800
where you can specify the size.
What's interesting to see

46
00:02:46,960 --> 00:02:50,000
is that "2 seconds",
it's really the "second" message,

47
00:02:50,160 --> 00:02:54,920
which is sent to message 2,
which will give us a duration,

48
00:02:55,080 --> 00:02:57,480
an instance of the Duration class,

49
00:02:58,120 --> 00:03:01,080
and which will control
how long the system runs.

50
00:03:01,240 --> 00:03:04,960
This shows you once again
that everything's an object in Pharo.

51
00:03:05,120 --> 00:03:09,240
I set the seconds at 2 seconds.
I send the "second" message to object 2.

52
00:03:10,600 --> 00:03:15,080
What you have next,
there's also what we call a "profiler",

53
00:03:15,240 --> 00:03:16,880
which is sampling-based.

54
00:03:17,040 --> 00:03:20,520
What will happen is,
you'll execute your program,

55
00:03:20,680 --> 00:03:23,880
and it will go at regular intervals

56
00:03:24,040 --> 00:03:26,400
to inspect the execution stack,

57
00:03:26,560 --> 00:03:29,040
see what's in the stack
and collect information.

58
00:03:29,200 --> 00:03:33,760
So how do we bring it up?
We do "timeProfiler, spyOn"

59
00:03:33,920 --> 00:03:37,800
and we'll pass it a block.
I want to repeat 20 times

60
00:03:37,960 --> 00:03:39,680
that I'll show on the Transcript,

61
00:03:39,840 --> 00:03:42,000
"1000 factorial",

62
00:03:42,160 --> 00:03:45,920
which I convert into a string,
which usually costs the most.

63
00:03:46,080 --> 00:03:50,480
After that, the profiler will give us
this kind of result,

64
00:03:50,640 --> 00:03:55,080
with a tree showing us the branches
amongst which we've spent most time.

65
00:03:55,240 --> 00:04:00,000
It shows us we spent 63% of the time
in the method "printOn:base".

66
00:04:01,040 --> 00:04:03,240
It's just to show you it's there.

67
00:04:03,400 --> 00:04:06,960
There's a profiler you can play with
if you're interested.

68
00:04:07,960 --> 00:04:09,240
So to summarize,

69
00:04:09,480 --> 00:04:10,640
to begin with,

70
00:04:10,800 --> 00:04:14,600
you can use "timeToRun",
"bench" and the profiler.

71
00:04:14,760 --> 00:04:19,280
There's a chapter in the book
"Deep into Pharo" showing this kind

72
00:04:19,440 --> 00:04:22,560
of optimization technique.

73
00:04:22,720 --> 00:04:26,240
I just wanted to point out,
as you see in these 3 examples,

74
00:04:26,400 --> 00:04:30,440
we always use blocks.
This is a block...

75
00:04:30,600 --> 00:04:33,400
This is a block too... Why?

76
00:04:33,560 --> 00:04:36,680
You saw in the course
on blocks that they allow you

77
00:04:36,840 --> 00:04:39,520
to freeze the expression,
the definition of the block

78
00:04:39,680 --> 00:04:42,560
doesn't execute and give "bench"
the possibility

79
00:04:42,720 --> 00:04:44,920
of controlling
the number of executions

80
00:04:45,080 --> 00:04:48,080
or deciding when execution
of the program will begin.

81
00:04:48,240 --> 00:04:50,080
The other thing I'd say is,

82
00:04:50,240 --> 00:04:54,680
find out about how "timeToRun"
and "bench" are implemented.

83
00:04:54,840 --> 00:04:57,520
To do that you click on Expression

84
00:04:57,680 --> 00:05:00,840
and do "browse" or "implement"
and you'll see the code.