Change --times console reporting to be based on Activity

[T-Gro]

With the introduction of general telemetry collecting (System.Diagnostics.Activity) in FCS and
the ability to write out collected statistics to .csv files, console reporting remained hand-coded.

This PR:

• Removes manual code which was used to collect data for console reporting
• Extends the Activity module with mechanism needed to provide equivalent functionality, especially environment-level statistics (memory usage, number of GC collections,..)
• Keeps a generic mechanism via a new System.Diagnostics.ActivityListener for writing to console, therefore the console layout changes from the previous one

(the API and cmd flags remain stable, but the console output does change).

Example output from our CI run:

[vzarytovskii]

Output looks very verbose. Do you think we can introduce multiple verbosity levels?

[baronfel]

Can a before and after example be added to this PR?

[T-Gro]

Output looks very verbose. Do you think we can introduce multiple verbosity levels?

The output has more data, but has changed from repeating attributes to be tabular - a lot more its in. In the end, it takes less space then before thanks to it (the header is there just once on top, instead of the header being repeated with every line).

Can a before and after example be added to this PR?

Example after added as comment here.

[vzarytovskii]

The output has more data, but has changed from repeating attributes to be tabular - a lot more its in. In the end, it takes less space then before thanks to it (the header is there just once on top, instead of the header being repeated with every line).

Yeah, I see now, looks good

Example after added as comment here.

Number of threads looks weird - the same across compilation, stackguard would've produced much more. Unless all of them finish work when measurements happen.

Also, GC generations are not reported here, right? Since it's zeroes.

[T-Gro]

The output has more data, but has changed from repeating attributes to be tabular - a lot more its in. In the end, it takes less space then before thanks to it (the header is there just once on top, instead of the header being repeated with every line).

Yeah, I see now, looks good

Example after added as comment here.

Number of threads looks weird - the same across compilation, stackguard would've produced much more. Unless all of them finish work when measurements happen.

Also, GC generations are not reported here, right? Since it's zeroes.

The threads are taken from processInfo.
I would assume that the threads used are all used from the pool, that is why the number (for entire process) is table, while the computation needs for threading varies.

[T-Gro]

The output has more data, but has changed from repeating attributes to be tabular - a lot more its in. In the end, it takes less space then before thanks to it (the header is there just once on top, instead of the header being repeated with every line).

Yeah, I see now, looks good

Example after added as comment here.

Number of threads looks weird - the same across compilation, stackguard would've produced much more. Unless all of them finish work when measurements happen.

Also, GC generations are not reported here, right? Since it's zeroes.

This was compiling some small project where no garbage collection happened.
Otherwise it does report the GC 0/1/2 collections per each phase.

[T-Gro]

But the number represents number of GC collections that happened, not number of objects.

[vzarytovskii]

The output has more data, but has changed from repeating attributes to be tabular - a lot more its in. In the end, it takes less space then before thanks to it (the header is there just once on top, instead of the header being repeated with every line).

Yeah, I see now, looks good

Example after added as comment here.

Number of threads looks weird - the same across compilation, stackguard would've produced much more. Unless all of them finish work when measurements happen.

Also, GC generations are not reported here, right? Since it's zeroes.

The threads are taken from processInfo.
I would assume that the threads used are all used from the pool, that is why the number (for entire process) is table, while the computation needs for threading varies.

Got it. The awkward part is mostly that the number is the same on the start of the process and somewhere during the optimization.

[vzarytovskii]

Do you think it makes sense to make it more markdown-friendly (basically just have some more vertiacl separators), so it's easier to post to github as is?

---

Phase name	Elapsed	Duration	WS(MB)	GC0	GC1	GC2	Handles	Threads
Import mscorlib+FSharp.Core	0.6806	0.6686	79	0	0	0	333	26
Parse inputs	2.8598	2.1630	264	11	7	4	520	60
Import non-system references	2.9631	0.0949	264	0	0	0	520	60
Typecheck	27.3129	24.3399	508	113	72	2	519	43
Typechecked	27.3286	0.0046	508	0	0	0	519	43
Write Interface File	27.3355	0.0000	508	0	0	0	519	43
Write XML doc signatures	27.3979	0.0555	508	0	0	0	519	43
Write XML docs	27.4472	0.0431	509	0	0	0	519	43
Encode Interface Data	27.9183	0.4637	524	1	1	0	519	43
Optimizations	42.4835	14.5577	689	111	52	2	571	41
Ending Optimizations	42.4903	0.0001	689	0	0	0	571	41
Encoding OptData	42.5338	0.0375	689	0	0	0	571	41
TAST -> IL	47.3280	4.7867	820	29	23	1	436	41
>Write Started	47.3779	0.0227	826	0	0	0	438	41
>Module Generation Preparation	47.3991	0.0150	826	0	0	0	438	41
>Module Generation Pass 1	47.5836	0.1779	831	0	0	0	438	41
>Module Generation Pass 2	49.8990	2.3087	889	12	12	0	438	41
>Module Generation Pass 3	49.9388	0.0334	890	0	0	0	438	41
>Module Generation Pass 4	49.9613	0.0162	895	0	0	0	438	41
>Finalize Module Generation Results	49.9688	0.0013	899	0	0	0	438	41
>Generated Tables and Code	49.9793	0.0047	899	0	0	0	438	41
>Layout Header of Tables	49.9869	0.0019	899	0	0	0	438	41
>Build String/Blob Address Tables	50.1090	0.1164	906	0	0	0	438	41
>Sort Tables	50.1156	0.0003	906	0	0	0	438	41
>Write Header of tablebuf	50.1568	0.0352	924	0	0	0	438	41
>Write Tables to tablebuf	50.1631	0.0000	924	0	0	0	438	41
>Layout Metadata	50.1690	0.0000	924	0	0	0	438	41
>Write Metadata Header	50.1782	0.0034	935	0	0	0	438	41
>Write Metadata Tables	50.1865	0.0020	937	0	0	0	438	41
>Write Metadata Strings	50.1930	0.0007	937	0	0	0	438	41
>Write Metadata User Strings	50.2062	0.0071	939	0	0	0	438	41
>Write Blob Stream	50.2213	0.0094	948	0	0	0	438	41
>Fixup Metadata	50.2273	0.0002	948	0	0	0	438	41
>Generated IL and metadata	50.4905	0.2577	951	2	1	1	438	41
>PDB: Defined 309 documents	50.5035	0.0051	952	0	0	0	438	41
>PDB: Sorted 74217 methods	51.1017	0.5914	880	0	0	0	438	41
>PDB: Created	51.3414	0.2330	881	0	0	0	438	41
>Layout image	51.4560	0.1083	881	0	0	0	438	41
>Writing Image	51.4667	0.0037	883	0	0	0	437	41
>Generate PDB Info	51.4742	0.0009	883	0	0	0	437	41
>Finalize PDB	51.4814	0.0003	883	0	0	0	437	41
Write .NET Binary	51.4890	4.1542	883	14	13	1	437	41

---

[T-Gro]

Example output after markdown-inification, but still keeping it human readable in plain text form:

---

Phase name	Elapsed	Duration	WS(MB)	GC0	GC1	GC2	Handles	Threads
Import mscorlib+FSharp.Core	1.6548	1.6054	174	20	9	5	1302	31
Parse inputs	1.6823	0.0142	175	0	0	0	1302	31
Import non-system references	1.6885	0.0017	175	0	0	0	1302	31
Typecheck	2.4734	0.7805	189	1	1	0	1301	30
Typechecked	2.4899	0.0063	189	0	0	0	1301	30
Write Interface File	2.4958	0.0003	189	0	0	0	1301	30
Write XML doc signatures	2.5016	0.0002	190	0	0	0	1301	30
Write XML docs	2.5099	0.0030	190	0	0	0	1301	30
Encode Interface Data	2.8132	0.2973	195	5	2	1	1302	31
Optimizations	3.0193	0.2008	198	0	0	0	1302	31
Ending Optimizations	3.0248	0.0002	198	0	0	0	1302	31
Encoding OptData	3.0606	0.0309	199	1	1	0	1302	31
TAST -> IL	3.2759	0.2093	205	0	0	0	1302	31
>Write Started	3.3381	0.0305	206	0	0	0	1303	31
>Module Generation Preparation	3.3446	0.0012	206	0	0	0	1303	31
>Module Generation Pass 1	3.3621	0.0125	206	0	0	0	1303	31
>Module Generation Pass 2	3.4123	0.0446	207	0	0	0	1303	31
>Module Generation Pass 3	3.4238	0.0064	207	0	0	0	1303	31
>Module Generation Pass 4	3.4312	0.0027	207	0	0	0	1303	31
>Finalize Module Generation Results	3.4370	0.0007	207	0	0	0	1303	31
>Generated Tables and Code	3.4445	0.0029	207	0	0	0	1303	31
>Layout Header of Tables	3.4494	0.0003	207	0	0	0	1303	31
>Build String/Blob Address Tables	3.4564	0.0025	207	0	0	0	1303	31
>Sort Tables	3.4616	0.0005	208	0	0	0	1303	31
>Write Header of tablebuf	3.4675	0.0014	208	0	0	0	1303	31
>Write Tables to tablebuf	3.4719	0.0000	208	0	0	0	1303	31
>Layout Metadata	3.4764	0.0001	208	0	0	0	1303	31
>Write Metadata Header	3.4808	0.0000	208	0	0	0	1303	31
>Write Metadata Tables	3.4853	0.0000	208	0	0	0	1303	31
>Write Metadata Strings	3.4901	0.0005	208	0	0	0	1303	31
>Write Metadata User Strings	3.4946	0.0002	208	0	0	0	1303	31
>Write Blob Stream	3.4995	0.0006	208	0	0	0	1303	31
>Fixup Metadata	3.5043	0.0005	209	0	0	0	1303	31
>Generated IL and metadata	3.5252	0.0166	209	0	0	0	1303	31
>Layout image	3.5374	0.0073	209	1	0	0	1303	31
>Writing Image	3.5447	0.0023	209	0	0	0	1302	31
>Signing Image	3.5493	0.0000	209	0	0	0	1302	31
Write .NET Binary	3.5541	0.2733	209	1	0	0	1302	31

---

[T-Gro]

Do you think it makes sense to make it more markdown-friendly (basically just have some more vertiacl separators), so it's easier to post to github as is?...

(btw. great idea, pasting output to GH is a common thing to do 👍 )