1Test2::Harness::LogFormUaste(r3)Contributed Perl DocumenTteastti2o:n:Harness::LogFormat(3)
2
3
4
6 Test2::Harness::LogFormat
7
9 This module describes the yath log format in detail.
10
12 The log file is a JSONL file. This means that each line is a complete
13 JSON document. Any given line in the log may be parsed by a JSON parser
14 independently of any other line.
15
16 Each line in the log is exactly 1 event as seen or produced by the
17 harness.
18
19 Events in the log should be in the order they were seen by the harness,
20 no sorting or re-ordering should be done.
21
22 When tests were run concurrently it is perfectly valid for events from
23 multiple test jobs to be muxed together; in other words events are not
24 grouped by test.
25
27 Events may have the following fields at the top level, some fields are
28 optional:
29
30 assert_count
31 The total number of assertions made up to and including this event
32 in the current subtest or top level test if this event is not
33 inside a subtest.
34
35 This may be null, or a whole integer greater than or equal to 0.
36
37 This field is optional and does not appear in harness generated
38 events, only in events passed through from tests.
39
40 event_id
41 This field is required.
42
43 This field should be an ID for the event, and should be a UUID. Be
44 aware some logs may have a string that is not a UUID if a UUID
45 library was unavailable. For safety assume it is a unique string,
46 but do not assume it is a UUID.
47
48 Tools may assume this field is always a UUID and refuse to process
49 logs that do not use UUIDS. Please document such when the tools are
50 written.
51
52 facet_data
53 See the "FACET DATA" section.
54
55 This field is required, and some fields within it are also
56 required.
57
58 job_id
59 This should be the unique ID of the job to which the event belongs.
60 The harness itself will set this field to 0 for any events
61 generated by the harness itself.
62
63 This field is normally 0 for the harness, and a UUID for a real
64 test job. In some cases this may be a unique string that is not a
65 UUID, but tools are free to refuse to process logs that do not use
66 UUIDs here. Note that even when UUIDs are used the harness itself
67 will set the field to 0 for internal harness events.
68
69 pid The process ID from which the event was generated.
70
71 This field is optional. Most test events should include this field,
72 harness internal events will usually omit it.
73
74 run_id
75 The run identification. All events must have the same run_id. This
76 field is a unique string, usually a UUID. Tools are free to reject
77 logs that do not use a UUID for this field.
78
79 stamp
80 The timestamp for when the event was seen by the harness. This
81 field is required.
82
83 Note The stamp is usually the stamp for when the event was
84 generated, but in some cases it may be more accurately described as
85 when the harness first saw the event. This is because the harness
86 sets the field if it is missing, but in most cases the test itself
87 set the field first at event creation.
88
89 stream_id
90 This field is optional. This field is set by the test and is used
91 to synchronize events, stdout and stderr.
92
93 It is safest to never tamper with, or backfill this field. If you
94 are trying to write a tool that outputs the yath log format from
95 another source it is best to omit this field completely.
96
97 tid The thread ID from which the event was generated.
98
99 This field is optional. Most test events should include this field,
100 harness internal events will usually omit it.
101
102 times
103 This field is optional. This field includes timing data from the
104 process at the time the event was generated.
105
106 "times" : [
107 0.04, # user
108 0.01, # system
109 0, # cuser
110 0 # csystem
111 ]
112
113 The data inside the array is the result of the "times()" function
114 as documented at
115 <https://perldoc.perl.org/5.30.0/functions/times.html>.
116
117 This field will only be present when Test2::Formatter::Stream was
118 used. TAP and other formats do not generate this field.
119
121 Facets are what convey useful information about test state from test to
122 harness. In addition some facets are added by the harness itself to
123 convey information for anything that reads the log.
124
125 "facet_data" is a hash, each field is the name of a facet. All facets
126 are hashes, but some facet types allow multiple hashes to be specified
127 in which case the field has a list of them. Each facet type is
128 documented, including the type it wants, hash vs list of hashes.
129
130 There are 3 categories of facet:
131
132 HARNESS FACETS
133 harness
134
135 This facet is always a single hash containing a duplicate of some top-
136 level data:
137
138 "harness" : {
139 "event_id" : "A07FDDFC-9C37-11E9-AE8C-DFDAB0029DDD",
140 "job_id" : "A06685B4-9C37-11E9-88CA-DEDAB0029DDD",
141 "run_id" : "A0649E8E-9C37-11E9-88CA-DEDAB0029DDD"
142 }
143
144 This facet is required. Many tools choose to ignore any data outside of
145 facet_data, so it is important to list these values here.
146
147 harness_run
148
149 This facet contains the details of the test run, which includes
150 environment variables set, where test files were found, library
151 directories that were in use, and flags passed to yath when it was
152 executed.
153
154 Example:
155
156 "harness_run" : {
157 "args" : [],
158 "blib" : 1,
159 "cover" : null,
160 "default_search" : [
161 "./t",
162 "./t2",
163 "test.pl"
164 ],
165 "dummy" : 0,
166 "env_vars" : {
167 "HARNESS_ACTIVE" : 1,
168 "HARNESS_IS_VERBOSE" : 0,
169 "HARNESS_JOBS" : 1,
170 "HARNESS_VERSION" : "Test2-Harness-0.001078",
171 "PERL_USE_UNSAFE_INC" : 1,
172 "T2_HARNESS_ACTIVE" : 1,
173 "T2_HARNESS_IS_VERBOSE" : 0,
174 "T2_HARNESS_JOBS" : 1,
175 "T2_HARNESS_RUN_ID" : "A0649E8E-9C37-11E9-88CA-DEDAB0029DDD",
176 "T2_HARNESS_VERSION" : "0.001078"
177 },
178 "event_uuids" : 1,
179 "exclude_files" : {},
180 "exclude_patterns" : [],
181 "finite" : 1,
182 "input" : null,
183 "job_count" : 1,
184 "lib" : 1,
185 "libs" : [
186 "/lib",
187 "/blib/lib",
188 "/blib/arch"
189 ],
190 "load" : null,
191 "load_import" : null,
192 "mem_usage" : 1,
193 "no_long" : null,
194 "plugins" : [],
195 "preload" : null,
196 "run_id" : "A0649E8E-9C37-11E9-88CA-DEDAB0029DDD",
197 "search" : [
198 "tiny.t"
199 ],
200 "show_times" : null,
201 "switches" : [],
202 "times" : 1,
203 "tlib" : 0,
204 "unsafe_inc" : 1,
205 "use_fork" : 1,
206 "use_stream" : 1,
207 "verbose" : 0
208 }
209
210 harness_job
211
212 This facet is almost always paired with the "harness_job_launch" facet.
213 This facet is always a single hash which describes the test job that is
214 starting. This facet will show up in the log once per test file
215 executed.
216
217 example from the start of "tiny.t":
218
219 "harness_job" : {
220 "args" : [],
221 "category" : "general",
222 "conflicts" : [],
223 "env_vars" : {
224 "HARNESS_ACTIVE" : 1,
225 "HARNESS_IS_VERBOSE" : 0,
226 "HARNESS_JOBS" : 1,
227 "HARNESS_VERSION" : "Test2-Harness-0.001078",
228 "PERL5LIB" : "/lib:/blib/lib:/blib/arch",
229 "PERL_USE_UNSAFE_INC" : null,
230 "T2_HARNESS_ACTIVE" : 1,
231 "T2_HARNESS_IS_VERBOSE" : 0,
232 "T2_HARNESS_JOBS" : 1,
233 "T2_HARNESS_RUN_ID" : "A0649E8E-9C37-11E9-88CA-DEDAB0029DDD",
234 "T2_HARNESS_VERSION" : "0.001078",
235 "TEMPDIR" : "/tmp/yath-test-28710-kFqwxNKE/A06685B4-9C37-11E9-88CA-DEDAB0029DDD/tmp",
236 "TEST2_JOB_DIR" : "/tmp/yath-test-28710-kFqwxNKE/A06685B4-9C37-11E9-88CA-DEDAB0029DDD",
237 "TMPDIR" : "/tmp/yath-test-28710-kFqwxNKE/A06685B4-9C37-11E9-88CA-DEDAB0029DDD/tmp"
238 },
239 "event_timeout" : null,
240 "event_uuids" : 1,
241 "file" : "/tiny.t",
242 "headers" : {},
243 "input" : "",
244 "job_id" : "A06685B4-9C37-11E9-88CA-DEDAB0029DDD",
245 "job_name" : 1,
246 "libs" : [
247 "/lib",
248 "/blib/lib",
249 "/blib/arch"
250 ],
251 "load" : [],
252 "load_import" : [],
253 "mem_usage" : 1,
254 "pid" : 28712,
255 "postexit_timeout" : null,
256 "preload" : [],
257 "shbang" : {},
258 "show_times" : null,
259 "stage" : "default",
260 "stamp" : 1562009833.97186,
261 "switches" : [],
262 "times" : 1,
263 "use_fork" : 1,
264 "use_preload" : 1,
265 "use_stream" : 1,
266 "use_timeout" : 1
267 },
268
269 harness_job_launch
270
271 This facet is present when the harness launches a new job, it is
272 usually paired with the "harness_job" facet. The main point of this
273 facet is to provide a timestamp for job start before the test itself
274 can generate any events.
275
276 "harness_job_launch" : {
277 "retry" : null,
278 "stamp" : 1562009834.09536
279 }
280
281 harness_job_start
282
283 This facet is generated when the test process actually starts (vs when
284 the harness asks it to via launch). This is often generated in a
285 process other than the main harness process, so can be used to see how
286 long it takes for the test process to spawn.
287
288 "harness_job_start" : {
289 "details" : "Job A06685B4-9C37-11E9-88CA-DEDAB0029DDD started at 1562009834.08625",
290 "file" : "/tiny.t",
291 "job_id" : "A06685B4-9C37-11E9-88CA-DEDAB0029DDD",
292 "stamp" : "1562009834.08625"
293 }
294
295 harness_job_exit
296
297 This facet is generated when the test process has exited. This facet
298 will contain the exit code as well as a complete and unfiltered version
299 of the STDOUT and STDERR output. If Test2::Formatter::Stream was used
300 then this will include the T2-HARNESS-ESYNC codes used to make sure
301 STDOUT, STDERR, and all events line up properly.
302
303 "harness_job_exit" : {
304 "details" : "Test script exited 256",
305 "exit" : "256",
306 "file" : "/tiny.t",
307 "job_id" : "A06685B4-9C37-11E9-88CA-DEDAB0029DDD",
308 "stderr" : "...",
309 "stdout" : "...",
310 }
311
312 harness_job_end
313
314 This facet is generated when the harness is closing off the test after
315 the test process has exited.
316
317 "harness_job_end" : {
318 "fail" : 1,
319 "file" : "/tiny.t",
320 "stamp" : 1562009834.15989
321 }
322
323 TEST FACETS
324 Test facets are documented at "THE-FACET-API" in
325 Test2::Manual::Anatomy::Event.
326
327 passing assertion example
328
329 Note In the proper log this would all be on one line.
330
331 "facet_data" : {
332 "about" : {
333 "eid" : "28712~0~1562009834~4",
334 "package" : "Test2::Event::Pass",
335 "uuid" : "A07FE270-9C37-11E9-AE8C-DFDAB0029DDD"
336 },
337 "assert" : {
338 "details" : "A passing test",
339 "pass" : 1
340 },
341 "control" : {},
342 "harness" : {
343 "event_id" : "A07FE270-9C37-11E9-AE8C-DFDAB0029DDD",
344 "job_id" : "A06685B4-9C37-11E9-88CA-DEDAB0029DDD",
345 "run_id" : "A0649E8E-9C37-11E9-88CA-DEDAB0029DDD"
346 },
347 "hubs" : [
348 {
349 "buffered" : 0,
350 "details" : "Test2::Hub",
351 "hid" : "28712~0~1562009834~2",
352 "ipc" : 0,
353 "nested" : 0,
354 "pid" : 28712,
355 "tid" : 0,
356 "uuid" : "A07FD85C-9C37-11E9-AE8C-DFDAB0029DDD"
357 }
358 ],
359 "trace" : {
360 "buffered" : 0,
361 "cid" : "28712~0~1562009834~3",
362 "frame" : [
363 "main",
364 "tiny.t",
365 3,
366 "main::ok"
367 ],
368 "hid" : "28712~0~1562009834~2",
369 "huuid" : "A07FD85C-9C37-11E9-AE8C-DFDAB0029DDD",
370 "nested" : 0,
371 "pid" : 28712,
372 "tid" : 0,
373 "uuid" : "A07FE108-9C37-11E9-AE8C-DFDAB0029DDD"
374 }
375 },
376
377 failing assertion example
378
379 "facet_data" : {
380 "about" : {
381 "details" : "fail",
382 "eid" : "3287~0~1562020001~4",
383 "package" : "Test2::Event::Fail",
384 "uuid" : "4C6EF67C-9C4F-11E9-80B8-8E77B0029DDD"
385 },
386 "assert" : {
387 "details" : "a failing test",
388 "pass" : 0
389 },
390 "control" : {},
391 "harness" : {
392 "event_id" : "4C6EF67C-9C4F-11E9-80B8-8E77B0029DDD",
393 "job_id" : "4C5570F8-9C4F-11E9-B087-8D77B0029DDD",
394 "run_id" : "4C538A2C-9C4F-11E9-B087-8D77B0029DDD"
395 },
396 "hubs" : [
397 {
398 "buffered" : 0,
399 "details" : "Test2::Hub",
400 "hid" : "3287~0~1562020001~2",
401 "ipc" : 0,
402 "nested" : 0,
403 "pid" : 3287,
404 "tid" : 0,
405 "uuid" : "4C6EEB96-9C4F-11E9-80B8-8E77B0029DDD"
406 }
407 ],
408 "info" : [
409 {
410 "debug" : 1,
411 "details" : "This is a diagnostics message for the fail",
412 "tag" : "DIAG"
413 },
414 {
415 "debug" : 1,
416 "details" : "Another diagnostics message",
417 "tag" : "DIAG"
418 }
419 ],
420 "trace" : {
421 "buffered" : 0,
422 "cid" : "3287~0~1562020001~3",
423 "frame" : [
424 "main",
425 "tiny.t",
426 11,
427 "main::ok"
428 ],
429 "hid" : "3287~0~1562020001~2",
430 "huuid" : "4C6EEB96-9C4F-11E9-80B8-8E77B0029DDD",
431 "nested" : 0,
432 "pid" : 3287,
433 "tid" : 0,
434 "uuid" : "4C6EF47E-9C4F-11E9-80B8-8E77B0029DDD"
435 }
436 },
437
438 OTHER FACETS
439 Other facets are any facet not defined above. These facets may come
440 from any number of plugins or tools. The rule is to ignore and pass-
441 through any facet your tool does not know how to handle.
442
444 The source code repository for Test2-Harness can be found at
445 http://github.com/Test-More/Test2-Harness/.
446
448 Chad Granum <exodist@cpan.org>
449
451 Chad Granum <exodist@cpan.org>
452
454 Copyright 2019 Chad Granum <exodist7@gmail.com>.
455
456 This program is free software; you can redistribute it and/or modify it
457 under the same terms as Perl itself.
458
459 See http://dev.perl.org/licenses/
460
461
462
463perl v5.30.0 2019-08-14 Test2::Harness::LogFormat(3)