1
00:00:06,540 --> 00:00:09,120
- Asynchronous processing is
quite commonplace these days

2
00:00:09,120 --> 00:00:10,200
in JavaScript.

3
00:00:10,200 --> 00:00:12,960
So for example, if you have
a JavaScript code running

4
00:00:12,960 --> 00:00:14,220
in a web browser,

5
00:00:14,220 --> 00:00:17,400
and you want to make an
Ajax call to a rest service

6
00:00:17,400 --> 00:00:20,190
running on the server, it
might take a second or two

7
00:00:20,190 --> 00:00:21,990
for the result to come back.

8
00:00:21,990 --> 00:00:23,820
So how do you test that?

9
00:00:23,820 --> 00:00:26,430
Well, one approach is to,

10
00:00:26,430 --> 00:00:28,440
when you call a long-running function,

11
00:00:28,440 --> 00:00:31,173
is to pass into that function a callback,

12
00:00:32,010 --> 00:00:32,880
the idea being that

13
00:00:32,880 --> 00:00:36,420
when the long-running
function has completed,

14
00:00:36,420 --> 00:00:38,490
it'll invoke your
callback function to say,

15
00:00:38,490 --> 00:00:40,770
here's the result you've been waiting for.

16
00:00:40,770 --> 00:00:43,680
This has quite a common arrangement.

17
00:00:43,680 --> 00:00:45,270
How can you test for that?

18
00:00:45,270 --> 00:00:48,900
Well, we'll see how to
test callback functions

19
00:00:48,900 --> 00:00:49,860
in this section.

20
00:00:49,860 --> 00:00:51,390
We'll have a long-running function

21
00:00:51,390 --> 00:00:53,700
that takes a few seconds to complete.

22
00:00:53,700 --> 00:00:56,310
Then it'll invoke our callback, hopefully,

23
00:00:56,310 --> 00:00:58,170
and we'll test that our callback has

24
00:00:58,170 --> 00:01:01,260
in fact been invoked successfully.

25
00:01:01,260 --> 00:01:05,026
So the examples for this
section are in that folder,

26
00:01:05,026 --> 00:01:06,717
TestingCallbacks.

27
00:01:06,717 --> 00:01:07,860
And here it is.

28
00:01:07,860 --> 00:01:09,710
We're in Lesson 04, TestingCallbacks.

29
00:01:10,950 --> 00:01:12,690
Okay, if you go into that folder,

30
00:01:12,690 --> 00:01:14,583
the code looks like this.

31
00:01:14,583 --> 00:01:16,920
I have some code that I'm going to test,

32
00:01:16,920 --> 00:01:19,345
and there's some slow code in there.

33
00:01:19,345 --> 00:01:20,730
And then I've got a
couple of tests in here.

34
00:01:20,730 --> 00:01:22,800
What we'll do actually, first of all,

35
00:01:22,800 --> 00:01:25,650
we'll see an inappropriate
way to run tests,

36
00:01:25,650 --> 00:01:27,360
and then we'll see how to do it properly

37
00:01:27,360 --> 00:01:29,430
and explain what the issue is.

38
00:01:29,430 --> 00:01:32,820
So here is my simple code.

39
00:01:32,820 --> 00:01:35,130
It's slowOperation function.

40
00:01:35,130 --> 00:01:36,840
Notice a few points here.

41
00:01:36,840 --> 00:01:40,413
So first of all, the
function receives a callback.

42
00:01:41,310 --> 00:01:44,010
That's a callback function.

43
00:01:44,010 --> 00:01:47,330
In my code here, I call setTimeout.

44
00:01:48,540 --> 00:01:49,830
You know how setTimeout works.

45
00:01:49,830 --> 00:01:52,560
You give it a timeout
parameter like two seconds.

46
00:01:52,560 --> 00:01:54,150
After two seconds have elapsed,

47
00:01:54,150 --> 00:01:58,170
it'll do whatever code you
specify as the first parameter.

48
00:01:58,170 --> 00:02:03,170
Okay? So after two seconds,
it will invoke this code.

49
00:02:03,210 --> 00:02:04,043
It calls me back and it
says, thank you for waiting,

50
00:02:04,043 --> 00:02:08,460
and the result you've
been waiting for is 42.

51
00:02:08,460 --> 00:02:10,500
That was worth waiting for.

52
00:02:10,500 --> 00:02:14,490
That's a call to my callback
function after two seconds.

53
00:02:14,490 --> 00:02:17,370
How can I test that when
I call this function,

54
00:02:17,370 --> 00:02:19,920
it will call me back two seconds later

55
00:02:19,920 --> 00:02:22,110
with the correct result?

56
00:02:22,110 --> 00:02:24,510
Right. Well, let's see how to do that.

57
00:02:24,510 --> 00:02:25,449
Here is the first attempt at how to do it,

58
00:02:25,449 --> 00:02:28,320
and I'm gonna explain in a moment.

59
00:02:28,320 --> 00:02:31,290
This is actually not good.

60
00:02:31,290 --> 00:02:34,800
So first of all, I've imported
the operations from that,

61
00:02:34,800 --> 00:02:35,973
from my code.

62
00:02:36,930 --> 00:02:38,580
Here's my test function.

63
00:02:38,580 --> 00:02:40,200
I'm testing the slow operation.

64
00:02:40,200 --> 00:02:42,360
This is the incorrect technique.

65
00:02:42,360 --> 00:02:44,485
Okay? So bear that in mind.

66
00:02:44,485 --> 00:02:47,460
Okay. Let's have a look
at the code in here, then.

67
00:02:47,460 --> 00:02:51,360
So first of all, I invoke my slowOperation

68
00:02:51,360 --> 00:02:53,490
imported from the ops module.

69
00:02:53,490 --> 00:02:55,320
I call the slowOperation,

70
00:02:55,320 --> 00:02:57,750
and as a parameter, I pass a callback.

71
00:02:57,750 --> 00:03:00,090
TestResult is a callback parameter.

72
00:03:00,090 --> 00:03:02,580
The idea is that it'll
call this function back

73
00:03:02,580 --> 00:03:04,140
two seconds later.

74
00:03:04,140 --> 00:03:06,750
This function is here so this function

75
00:03:06,750 --> 00:03:09,480
will be invoked two seconds later,

76
00:03:09,480 --> 00:03:11,550
and it'll grab the result

77
00:03:11,550 --> 00:03:14,580
that's been passed back to me eventually,

78
00:03:14,580 --> 00:03:17,883
and I check that the result
is what I expected it to be.

79
00:03:18,960 --> 00:03:22,380
Okay. Now, that seems fine.

80
00:03:22,380 --> 00:03:26,133
If you run the test
like this, jest minus T,

81
00:03:27,000 --> 00:03:29,790
this is kind of the
descriptor for the function,

82
00:03:29,790 --> 00:03:33,240
test slow operation,
comma, incorrect technique.

83
00:03:33,240 --> 00:03:36,330
When you run it, this is what happens.

84
00:03:36,330 --> 00:03:37,560
It seems to pass.

85
00:03:37,560 --> 00:03:39,243
You get a pass indicator.

86
00:03:40,590 --> 00:03:44,670
The test slowOperation,
incorrect technique, passed,

87
00:03:44,670 --> 00:03:48,183
but we also get a rather
disturbing warning here.

88
00:03:49,110 --> 00:03:54,110
Jest did not exit one second
after the test run's completed.

89
00:03:54,180 --> 00:03:55,920
So what basically happened is,

90
00:03:55,920 --> 00:03:58,743
jest called my test function,

91
00:03:58,743 --> 00:04:02,520
and my test function basically
terminated immediately,

92
00:04:02,520 --> 00:04:05,400
but the code that it was
calling was still running.

93
00:04:05,400 --> 00:04:08,970
So jest finished while my
code was still executed.

94
00:04:08,970 --> 00:04:12,150
You know, for two more seconds,
my code was still executed.

95
00:04:12,150 --> 00:04:15,270
Jest didn't actually wait
for the callback to happen.

96
00:04:15,270 --> 00:04:16,770
It just terminated immediately.

97
00:04:16,770 --> 00:04:18,780
It didn't know that it had to wait

98
00:04:18,780 --> 00:04:21,240
two seconds to check the result.

99
00:04:21,240 --> 00:04:23,400
So in my test function here,

100
00:04:23,400 --> 00:04:24,780
we've just run the test function,

101
00:04:24,780 --> 00:04:28,110
this first test function here.

102
00:04:28,110 --> 00:04:30,060
Jest came in here.

103
00:04:30,060 --> 00:04:31,680
It kind of noticed that function and said,

104
00:04:31,680 --> 00:04:33,090
well, that's very interesting,

105
00:04:33,090 --> 00:04:34,323
but it invoked that.

106
00:04:35,640 --> 00:04:38,730
That function was taking
two seconds to complete,

107
00:04:38,730 --> 00:04:40,230
but jest terminated,

108
00:04:40,230 --> 00:04:41,460
and that's the end of that.

109
00:04:41,460 --> 00:04:45,000
Jest didn't realize that it had to wait

110
00:04:45,000 --> 00:04:47,013
for this to also be invoked.

111
00:04:48,121 --> 00:04:51,060
So it's suggesting that

112
00:04:51,060 --> 00:04:54,509
jest finished whilst some
asynchronous operations

113
00:04:54,509 --> 00:04:56,553
weren't stopped in time,

114
00:04:58,495 --> 00:05:02,610
and it asks us to consider
running this option in our tests.

115
00:05:02,610 --> 00:05:04,590
Okay, so to run our tests again,

116
00:05:04,590 --> 00:05:07,650
with the detectOpenHandles parameter

117
00:05:07,650 --> 00:05:11,970
that will tell me if my
tests terminated too quickly

118
00:05:11,970 --> 00:05:14,163
whilst the code was still running.

119
00:05:15,390 --> 00:05:16,640
Well, let's do that then.

120
00:05:17,760 --> 00:05:19,770
We're gonna go to the code window,

121
00:05:19,770 --> 00:05:24,770
and we're going to run jest minus T.

122
00:05:25,050 --> 00:05:27,000
And the prompt is going to be,

123
00:05:27,000 --> 00:05:29,910
this is the name of my
function, effectively.

124
00:05:29,910 --> 00:05:33,693
Test slow operation,

125
00:05:34,950 --> 00:05:37,290
operation, comma,

126
00:05:37,290 --> 00:05:41,220
incorrect technique.

127
00:05:41,220 --> 00:05:42,053
Okay.

128
00:05:42,053 --> 00:05:44,673
So that was the name of the
function that I want to run.

129
00:05:46,590 --> 00:05:49,260
So when I run it like
this, we'll see the message

130
00:05:49,260 --> 00:05:52,050
that was displayed on the screen capture.

131
00:05:52,050 --> 00:05:54,420
It passes, but it says,

132
00:05:54,420 --> 00:05:57,510
but are you sure this is actually correct?

133
00:05:57,510 --> 00:06:00,300
Should you use the
detectOpenHandles option

134
00:06:00,300 --> 00:06:02,400
to troubleshoot the issue?

135
00:06:02,400 --> 00:06:03,813
Okay, then let's do that.

136
00:06:04,790 --> 00:06:06,340
So dash dash detect

137
00:06:07,290 --> 00:06:10,290
open handles.

138
00:06:10,290 --> 00:06:14,673
So, is there still some code
running when jest finished?

139
00:06:15,720 --> 00:06:17,580
Ah, now it's failed.

140
00:06:17,580 --> 00:06:20,103
No, this is actually the correct outcome,

141
00:06:21,060 --> 00:06:23,340
because my test completed

142
00:06:23,340 --> 00:06:26,250
before the callback had
a chance to be invoked.

143
00:06:26,250 --> 00:06:29,580
Jest has detected the
following open handle

144
00:06:29,580 --> 00:06:32,520
potentially keeping the test from exiting.

145
00:06:32,520 --> 00:06:36,303
So when my test invoked slowOperation,

146
00:06:36,303 --> 00:06:39,690
slowOperation was gonna
take two seconds to finish.

147
00:06:39,690 --> 00:06:43,350
Jest didn't know that it
had to wait two seconds,

148
00:06:43,350 --> 00:06:46,260
so it never got a chance to, you know,

149
00:06:46,260 --> 00:06:48,603
check that that actually worked properly.

150
00:06:49,530 --> 00:06:51,930
So when you invoke the slowOperations

151
00:06:51,930 --> 00:06:56,930
that will take longer to
execute than your test,

152
00:06:57,270 --> 00:06:58,740
you have to tell jest

153
00:06:58,740 --> 00:07:02,820
wait until I tell you and then complete.

154
00:07:02,820 --> 00:07:04,860
So to do it properly,

155
00:07:04,860 --> 00:07:07,227
when you're invoking a slowOperation

156
00:07:07,227 --> 00:07:11,105
and you have to tell jest
to wait until you are ready,

157
00:07:11,105 --> 00:07:12,450
this is what you have to do.

158
00:07:12,450 --> 00:07:13,920
You have to write your test

159
00:07:13,920 --> 00:07:17,100
in a slightly more careful manner.

160
00:07:17,100 --> 00:07:18,960
So this is the correct technique here.

161
00:07:18,960 --> 00:07:21,183
Notice the following
points in this example.

162
00:07:22,290 --> 00:07:25,500
My test function call, as well as taking

163
00:07:25,500 --> 00:07:26,760
the name of the test,

164
00:07:26,760 --> 00:07:29,040
it now takes a done parameter.

165
00:07:29,040 --> 00:07:33,840
Done is actually a callback
into jest itself, okay?

166
00:07:33,840 --> 00:07:36,960
And the idea is that
when we have finished,

167
00:07:36,960 --> 00:07:39,120
when we have been called back,

168
00:07:39,120 --> 00:07:41,640
and when we've verified
that the result is correct

169
00:07:41,640 --> 00:07:43,920
and we know that we are ready to finish,

170
00:07:43,920 --> 00:07:47,280
what we do is we call the done function.

171
00:07:47,280 --> 00:07:48,870
Okay? So this is what's gonna happen.

172
00:07:48,870 --> 00:07:51,030
Jest will run that test.

173
00:07:51,030 --> 00:07:54,120
It'll call the slowOperation.

174
00:07:54,120 --> 00:07:56,940
This done parameter jest
will know that it has to wait

175
00:07:56,940 --> 00:08:00,120
until we call that
function until it finishes.

176
00:08:00,120 --> 00:08:02,430
So we start the slowOperation.

177
00:08:02,430 --> 00:08:05,460
Two seconds later, it'll call us back.

178
00:08:05,460 --> 00:08:10,140
In our test result callback we
verify the result is correct,

179
00:08:10,140 --> 00:08:12,090
and then we say, we're done.

180
00:08:12,090 --> 00:08:14,310
So at this point, we are telling jest

181
00:08:14,310 --> 00:08:16,380
we have really finished now,

182
00:08:16,380 --> 00:08:18,130
and it's okay for you to terminate.

183
00:08:19,111 --> 00:08:22,620
So every slow operation,
you have to basically take

184
00:08:22,620 --> 00:08:25,290
a parameter here, call it
done, invoke that function

185
00:08:25,290 --> 00:08:28,683
when you know that you're
ready for jest to terminate.

186
00:08:31,200 --> 00:08:33,300
So I can run that test this time,

187
00:08:33,300 --> 00:08:36,900
and it should give me a correct pass.

188
00:08:36,900 --> 00:08:38,640
It'll take two seconds to complete.

189
00:08:38,640 --> 00:08:40,050
I'll run it in a moment,

190
00:08:40,050 --> 00:08:43,740
but when I run it like this,
you can see that it does pass

191
00:08:43,740 --> 00:08:46,620
without any indicators that
something was still running.

192
00:08:46,620 --> 00:08:50,370
It did actually wait two
seconds before completing.

193
00:08:50,370 --> 00:08:53,853
So I want to actually
run that test properly.

194
00:08:55,710 --> 00:08:57,100
So I'm going to just

195
00:08:58,560 --> 00:09:00,153
tweak my handle here,

196
00:09:01,899 --> 00:09:03,690
and I don't need this parameter now,

197
00:09:03,690 --> 00:09:06,480
because there aren't going
to be any open handles.

198
00:09:06,480 --> 00:09:09,030
The function will complete properly.

199
00:09:09,030 --> 00:09:10,440
Let's see.

200
00:09:10,440 --> 00:09:12,600
So it'll call my slowOperation.

201
00:09:12,600 --> 00:09:14,670
That takes two seconds to complete.

202
00:09:14,670 --> 00:09:19,380
Jest waits those two
seconds and then terminates.

203
00:09:19,380 --> 00:09:21,920
Okay. So it called my function.

204
00:09:21,920 --> 00:09:24,750
Correct technique, no problems at all.

205
00:09:24,750 --> 00:09:26,790
It waited for two seconds,

206
00:09:26,790 --> 00:09:29,640
ran my call back.

207
00:09:29,640 --> 00:09:31,710
My callback asserts that
the result was correct.

208
00:09:31,710 --> 00:09:32,880
It was.

209
00:09:32,880 --> 00:09:36,123
And then we can say to jest,
you're done now, move on.