1Test2::Harness::LogFormUaste(r3)Contributed Perl DocumenTteastti2o:n:Harness::LogFormat(3)
2
3
4

NAME

6       Test2::Harness::LogFormat
7

DESCRIPTION

9       This module describes the yath log format in detail.
10

OVERVIEW

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

EVENT FORMAT

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

FACET DATA

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

SOURCE

444       The source code repository for Test2-Harness can be found at
445       http://github.com/Test-More/Test2-Harness/.
446

MAINTAINERS

448       Chad Granum <exodist@cpan.org>
449

AUTHORS

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)
Impressum