@@ -164,3 +164,255 @@ pub fn perform_analysis(data: ProfilingData) -> Results {
164
164
total_time,
165
165
}
166
166
}
167
+
168
+ #[ cfg( test) ]
169
+ mod tests {
170
+ use super :: * ;
171
+ use measureme:: ProfilingDataBuilder ;
172
+
173
+ #[ test]
174
+ fn total_time_and_nesting ( ) {
175
+ let mut b = ProfilingDataBuilder :: new ( ) ;
176
+
177
+ b. interval ( QUERY_EVENT_KIND , "q1" , 0 , 100 , 200 , |b| {
178
+ b. interval ( QUERY_EVENT_KIND , "q2" , 0 , 110 , 190 , |b| {
179
+ b. interval ( QUERY_EVENT_KIND , "q3" , 0 , 120 , 180 , |_| { } ) ;
180
+ } ) ;
181
+ } ) ;
182
+
183
+ let results = perform_analysis ( b. into_profiling_data ( ) ) ;
184
+
185
+ assert_eq ! ( results. total_time, Duration :: from_nanos( 100 ) ) ;
186
+
187
+ // 10ns in the beginning and 10ns in the end
188
+ assert_eq ! ( results. query_data_by_label( "q1" ) . self_time, Duration :: from_nanos( 20 ) ) ;
189
+ // 10ns in the beginning and 10ns in the end, again
190
+ assert_eq ! ( results. query_data_by_label( "q2" ) . self_time, Duration :: from_nanos( 20 ) ) ;
191
+ // 60ns of uninterupted self-time
192
+ assert_eq ! ( results. query_data_by_label( "q3" ) . self_time, Duration :: from_nanos( 60 ) ) ;
193
+
194
+ assert_eq ! ( results. query_data_by_label( "q1" ) . invocation_count, 1 ) ;
195
+ assert_eq ! ( results. query_data_by_label( "q2" ) . invocation_count, 1 ) ;
196
+ assert_eq ! ( results. query_data_by_label( "q3" ) . invocation_count, 1 ) ;
197
+ }
198
+
199
+ #[ test]
200
+ fn events_with_same_starting_time ( ) {
201
+ // <--e4-->
202
+ // <---e3--->
203
+ // <--------e1--------><--------e2-------->
204
+ // 100 200 300
205
+
206
+ let mut b = ProfilingDataBuilder :: new ( ) ;
207
+
208
+ b. interval ( QUERY_EVENT_KIND , "e1" , 0 , 100 , 200 , |_| { } ) ;
209
+ b. interval ( QUERY_EVENT_KIND , "e2" , 0 , 200 , 300 , |b| {
210
+ b. interval ( QUERY_EVENT_KIND , "e3" , 0 , 200 , 250 , |b| {
211
+ b. interval ( QUERY_EVENT_KIND , "e4" , 0 , 200 , 220 , |_| { } ) ;
212
+ } ) ;
213
+ } ) ;
214
+
215
+ let results = perform_analysis ( b. into_profiling_data ( ) ) ;
216
+
217
+ assert_eq ! ( results. total_time, Duration :: from_nanos( 200 ) ) ;
218
+
219
+ assert_eq ! ( results. query_data_by_label( "e1" ) . self_time, Duration :: from_nanos( 100 ) ) ;
220
+ assert_eq ! ( results. query_data_by_label( "e2" ) . self_time, Duration :: from_nanos( 50 ) ) ;
221
+ assert_eq ! ( results. query_data_by_label( "e3" ) . self_time, Duration :: from_nanos( 30 ) ) ;
222
+ assert_eq ! ( results. query_data_by_label( "e4" ) . self_time, Duration :: from_nanos( 20 ) ) ;
223
+
224
+ assert_eq ! ( results. query_data_by_label( "e1" ) . invocation_count, 1 ) ;
225
+ assert_eq ! ( results. query_data_by_label( "e2" ) . invocation_count, 1 ) ;
226
+ assert_eq ! ( results. query_data_by_label( "e3" ) . invocation_count, 1 ) ;
227
+ assert_eq ! ( results. query_data_by_label( "e4" ) . invocation_count, 1 ) ;
228
+ }
229
+
230
+ #[ test]
231
+ fn events_with_same_end_time ( ) {
232
+ // <--e4-->
233
+ // <---e3--->
234
+ // <--------e1--------><--------e2-------->
235
+ // 100 200 300
236
+
237
+ let mut b = ProfilingDataBuilder :: new ( ) ;
238
+
239
+ b. interval ( QUERY_EVENT_KIND , "e1" , 0 , 100 , 200 , |_| { } ) ;
240
+ b. interval ( QUERY_EVENT_KIND , "e2" , 0 , 200 , 300 , |b| {
241
+ b. interval ( QUERY_EVENT_KIND , "e3" , 0 , 250 , 300 , |b| {
242
+ b. interval ( QUERY_EVENT_KIND , "e4" , 0 , 280 , 300 , |_| { } ) ;
243
+ } ) ;
244
+ } ) ;
245
+
246
+ let results = perform_analysis ( b. into_profiling_data ( ) ) ;
247
+
248
+ assert_eq ! ( results. total_time, Duration :: from_nanos( 200 ) ) ;
249
+
250
+ assert_eq ! ( results. query_data_by_label( "e1" ) . self_time, Duration :: from_nanos( 100 ) ) ;
251
+ assert_eq ! ( results. query_data_by_label( "e2" ) . self_time, Duration :: from_nanos( 50 ) ) ;
252
+ assert_eq ! ( results. query_data_by_label( "e3" ) . self_time, Duration :: from_nanos( 30 ) ) ;
253
+ assert_eq ! ( results. query_data_by_label( "e4" ) . self_time, Duration :: from_nanos( 20 ) ) ;
254
+
255
+ assert_eq ! ( results. query_data_by_label( "e1" ) . invocation_count, 1 ) ;
256
+ assert_eq ! ( results. query_data_by_label( "e2" ) . invocation_count, 1 ) ;
257
+ assert_eq ! ( results. query_data_by_label( "e3" ) . invocation_count, 1 ) ;
258
+ assert_eq ! ( results. query_data_by_label( "e4" ) . invocation_count, 1 ) ;
259
+ }
260
+
261
+ #[ test]
262
+ fn same_event_multiple_times ( ) {
263
+ // <--e3--> <--e3-->
264
+ // <---e2---> <---e2--->
265
+ // <--------e1--------><--------e1-------->
266
+ // 100 200 300
267
+
268
+ let mut b = ProfilingDataBuilder :: new ( ) ;
269
+
270
+ b. interval ( QUERY_EVENT_KIND , "e1" , 0 , 100 , 200 , |b| {
271
+ b. interval ( QUERY_EVENT_KIND , "e2" , 0 , 120 , 180 , |b| {
272
+ b. interval ( QUERY_EVENT_KIND , "e3" , 0 , 140 , 160 , |_| { } ) ;
273
+ } ) ;
274
+ } ) ;
275
+
276
+ b. interval ( QUERY_EVENT_KIND , "e1" , 0 , 200 , 300 , |b| {
277
+ b. interval ( QUERY_EVENT_KIND , "e2" , 0 , 220 , 280 , |b| {
278
+ b. interval ( QUERY_EVENT_KIND , "e3" , 0 , 240 , 260 , |_| { } ) ;
279
+ } ) ;
280
+ } ) ;
281
+
282
+ let results = perform_analysis ( b. into_profiling_data ( ) ) ;
283
+
284
+ assert_eq ! ( results. total_time, Duration :: from_nanos( 200 ) ) ;
285
+
286
+ assert_eq ! ( results. query_data_by_label( "e1" ) . self_time, Duration :: from_nanos( 80 ) ) ;
287
+ assert_eq ! ( results. query_data_by_label( "e2" ) . self_time, Duration :: from_nanos( 80 ) ) ;
288
+ assert_eq ! ( results. query_data_by_label( "e3" ) . self_time, Duration :: from_nanos( 40 ) ) ;
289
+
290
+ assert_eq ! ( results. query_data_by_label( "e1" ) . invocation_count, 2 ) ;
291
+ assert_eq ! ( results. query_data_by_label( "e2" ) . invocation_count, 2 ) ;
292
+ assert_eq ! ( results. query_data_by_label( "e3" ) . invocation_count, 2 ) ;
293
+ }
294
+
295
+ #[ test]
296
+ fn multiple_threads ( ) {
297
+ // <--e3--> <--e3-->
298
+ // <---e2---> <---e2--->
299
+ // <--------e1--------><--------e1-------->
300
+ // T0 100 200 300
301
+ //
302
+ // <--e3--> <--e3-->
303
+ // <---e2---> <---e2--->
304
+ // <--------e1--------><--------e1-------->
305
+ // T1 100 200 300
306
+
307
+ let mut b = ProfilingDataBuilder :: new ( ) ;
308
+
309
+ // Thread 0
310
+ b. interval ( QUERY_EVENT_KIND , "e1" , 0 , 100 , 200 , |b| {
311
+ b. interval ( QUERY_EVENT_KIND , "e2" , 0 , 120 , 180 , |b| {
312
+ b. interval ( QUERY_EVENT_KIND , "e3" , 0 , 140 , 160 , |_| { } ) ;
313
+ } ) ;
314
+ } ) ;
315
+
316
+ // Thread 1 -- the same as thread 0 with a slight time offset
317
+ b. interval ( QUERY_EVENT_KIND , "e1" , 1 , 110 , 210 , |b| {
318
+ b. interval ( QUERY_EVENT_KIND , "e2" , 1 , 130 , 190 , |b| {
319
+ b. interval ( QUERY_EVENT_KIND , "e3" , 1 , 150 , 170 , |_| { } ) ;
320
+ } ) ;
321
+ } ) ;
322
+
323
+ // Thread 0 -- continued
324
+ b. interval ( QUERY_EVENT_KIND , "e1" , 0 , 200 , 300 , |b| {
325
+ b. interval ( QUERY_EVENT_KIND , "e2" , 0 , 220 , 280 , |b| {
326
+ b. interval ( QUERY_EVENT_KIND , "e3" , 0 , 240 , 260 , |_| { } ) ;
327
+ } ) ;
328
+ } ) ;
329
+
330
+ // Thread 1 -- continued
331
+ b. interval ( QUERY_EVENT_KIND , "e1" , 1 , 210 , 310 , |b| {
332
+ b. interval ( QUERY_EVENT_KIND , "e2" , 1 , 230 , 290 , |b| {
333
+ b. interval ( QUERY_EVENT_KIND , "e3" , 1 , 250 , 270 , |_| { } ) ;
334
+ } ) ;
335
+ } ) ;
336
+
337
+ let results = perform_analysis ( b. into_profiling_data ( ) ) ;
338
+
339
+ assert_eq ! ( results. total_time, Duration :: from_nanos( 400 ) ) ;
340
+
341
+ assert_eq ! ( results. query_data_by_label( "e1" ) . self_time, Duration :: from_nanos( 160 ) ) ;
342
+ assert_eq ! ( results. query_data_by_label( "e2" ) . self_time, Duration :: from_nanos( 160 ) ) ;
343
+ assert_eq ! ( results. query_data_by_label( "e3" ) . self_time, Duration :: from_nanos( 80 ) ) ;
344
+
345
+ assert_eq ! ( results. query_data_by_label( "e1" ) . invocation_count, 4 ) ;
346
+ assert_eq ! ( results. query_data_by_label( "e2" ) . invocation_count, 4 ) ;
347
+ assert_eq ! ( results. query_data_by_label( "e3" ) . invocation_count, 4 ) ;
348
+ }
349
+
350
+ #[ test]
351
+ fn instant_events ( ) {
352
+ // xyxy
353
+ // y <--e3--> x
354
+ // x <-----e2-----> x
355
+ // <--------e1-------->
356
+ // 100 200
357
+
358
+ let mut b = ProfilingDataBuilder :: new ( ) ;
359
+
360
+ b. interval ( QUERY_EVENT_KIND , "e1" , 0 , 200 , 300 , |b| {
361
+ b. instant ( QUERY_CACHE_HIT_EVENT_KIND , "x" , 0 , 210 ) ;
362
+
363
+ b. interval ( QUERY_EVENT_KIND , "e2" , 0 , 220 , 280 , |b| {
364
+
365
+ b. instant ( QUERY_CACHE_HIT_EVENT_KIND , "y" , 0 , 230 ) ;
366
+
367
+ b. interval ( QUERY_EVENT_KIND , "e3" , 0 , 240 , 260 , |b| {
368
+ b. instant ( QUERY_CACHE_HIT_EVENT_KIND , "x" , 0 , 241 ) ;
369
+ b. instant ( QUERY_CACHE_HIT_EVENT_KIND , "y" , 0 , 242 ) ;
370
+ b. instant ( QUERY_CACHE_HIT_EVENT_KIND , "x" , 0 , 243 ) ;
371
+ b. instant ( QUERY_CACHE_HIT_EVENT_KIND , "y" , 0 , 244 ) ;
372
+ } ) ;
373
+
374
+ b. instant ( QUERY_CACHE_HIT_EVENT_KIND , "x" , 0 , 270 ) ;
375
+ } ) ;
376
+
377
+ b. instant ( QUERY_CACHE_HIT_EVENT_KIND , "x" , 0 , 290 ) ;
378
+ } ) ;
379
+
380
+ let results = perform_analysis ( b. into_profiling_data ( ) ) ;
381
+
382
+ assert_eq ! ( results. total_time, Duration :: from_nanos( 100 ) ) ;
383
+
384
+ assert_eq ! ( results. query_data_by_label( "e1" ) . self_time, Duration :: from_nanos( 40 ) ) ;
385
+ assert_eq ! ( results. query_data_by_label( "e2" ) . self_time, Duration :: from_nanos( 40 ) ) ;
386
+ assert_eq ! ( results. query_data_by_label( "e3" ) . self_time, Duration :: from_nanos( 20 ) ) ;
387
+
388
+ assert_eq ! ( results. query_data_by_label( "e1" ) . invocation_count, 1 ) ;
389
+ assert_eq ! ( results. query_data_by_label( "e2" ) . invocation_count, 1 ) ;
390
+ assert_eq ! ( results. query_data_by_label( "e3" ) . invocation_count, 1 ) ;
391
+
392
+ assert_eq ! ( results. query_data_by_label( "x" ) . number_of_cache_hits, 5 ) ;
393
+ assert_eq ! ( results. query_data_by_label( "y" ) . number_of_cache_hits, 3 ) ;
394
+ }
395
+
396
+ #[ test]
397
+ fn stack_of_same_events ( ) {
398
+ // <--e1-->
399
+ // <-----e1----->
400
+ // <--------e1-------->
401
+ // 100 200
402
+
403
+ let mut b = ProfilingDataBuilder :: new ( ) ;
404
+
405
+ b. interval ( QUERY_EVENT_KIND , "e1" , 0 , 200 , 300 , |b| {
406
+ b. interval ( QUERY_EVENT_KIND , "e1" , 0 , 220 , 280 , |b| {
407
+ b. interval ( QUERY_EVENT_KIND , "e1" , 0 , 240 , 260 , |_| { } ) ;
408
+ } ) ;
409
+ } ) ;
410
+
411
+ let results = perform_analysis ( b. into_profiling_data ( ) ) ;
412
+
413
+ assert_eq ! ( results. total_time, Duration :: from_nanos( 100 ) ) ;
414
+
415
+ assert_eq ! ( results. query_data_by_label( "e1" ) . self_time, Duration :: from_nanos( 100 ) ) ;
416
+ assert_eq ! ( results. query_data_by_label( "e1" ) . invocation_count, 3 ) ;
417
+ }
418
+ }
0 commit comments