Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add trace log messages to indicate how long each loading phase takes #705

Draft
wants to merge 5 commits into
base: master
Choose a base branch
from

Conversation

Shadowrs
Copy link

@Shadowrs Shadowrs commented Aug 4, 2022

This is accompanied by a PR to the Fabric Mixin repo but they are still independent.

Example of log statements added:


[19:29:41] [main/INFO] (FabricLoader) Adding 621 mods
[19:29:41] [main/INFO] (FabricLoader) Adding classpaths of codesources for 621 mods
[19:29:42] [main/INFO] (FabricLoader/Entrypoint) Iterating over entrypoint 'preLaunch' with 10 entrypoints
[19:29:47] [main/TRACE] (FabricLoader/Entrypoint) invoke preLaunch on 'Sodium' at https://github.com/CaffeineMC/sodium-fabric
[19:30:02] [Render thread/INFO] (FabricLoader/Entrypoint) Iterating over entrypoint 'main' with 364 entrypoints
[19:30:34] [INFO] (FabricLoader/Entrypoint) Entrypoint scan main with 364 points 31.606 sec (86.8ms avg)
[19:30:34] [INFO] (FabricLoader/Entrypoint) Iterating over entrypoint 'client' with 331 entrypoints
[19:30:42] [INFO] (FabricLoader/Entrypoint) Entrypoint scan client with 331 points 7.983 sec (24.1ms avg)

Example output of the ported printAuditSummary function which hasn't been usable since the Metronome Agent from Sponge was unmaintained since ~2013:

/***********************************************************************************************************************************/
/*   Section                                         TOTAL  DEFAULT:prepare  DEFAULT:apply  Initial      Count        Avg.         */
/***********************************************************************************************************************************/
/*                                                                                                                                 */
/*   class.load                                       0 ms             0 ms           0 ms        -          0     0.000 ms        */
/*   class.meta                                     298 ms           298 ms              -        -      11684     0.026 ms        */
/*   class.transform                                  0 ms             0 ms           0 ms        -          0     0.000 ms        */
/*   generator.argsclassgenerator                     3 ms             3 ms              -        -        140     0.021 ms        */
/*   generator.innerclassgenerator                    5 ms             5 ms              -        -        123     0.041 ms        */
/*   mixin                                        12841 ms             0 ms       12841 ms        -      34116     0.376 ms        */
/*   mixin.apply                                   6800 ms             0 ms        6800 ms        -        896     7.589 ms        */
/*   mixin.apply.pass.inject                        471 ms             0 ms         471 ms        -        896     0.526 ms        */
/*   mixin.apply.pass.inject.mixin                    0 ms             0 ms           0 ms        -          1     0.000 ms        */
/*   mixin.apply.pass.inject.mixin.coprocessor        0 ms             0 ms           0 ms        -          2     0.000 ms        */
/*   mixin.apply.pass.main                         2130 ms             0 ms        2130 ms        -        896     2.377 ms        */
/*   mixin.apply.pass.preinject                     408 ms             0 ms         408 ms        -        896     0.455 ms        */
/*   mixin.apply.plugin                              11 ms             0 ms          11 ms        -       2114     0.005 ms        */
/*   mixin.apply.plugin.mixin                         1 ms             0 ms           1 ms        -          3     0.333 ms        */
/*   mixin.apply.plugin.mixin.coprocessor             0 ms             0 ms           0 ms        -          6     0.000 ms        */
/*   mixin.apply.pre                               3393 ms             0 ms        3393 ms        -       3973     0.854 ms        */
/*   mixin.apply.pre.attach                        3238 ms             0 ms        3238 ms        -       3973     0.815 ms        */
/*   mixin.apply.pre.attach.fields                   68 ms             0 ms          68 ms        -       3973     0.017 ms        */
/*   mixin.apply.pre.attach.methods                 314 ms             0 ms         314 ms        -       3973     0.079 ms        */
/*   mixin.apply.pre.attach.transform              2850 ms             0 ms        2850 ms        -       3973     0.717 ms        */
/*   mixin.apply.pre.attach.transform.meta         1487 ms             0 ms        1487 ms        -      59500     0.025 ms        */
/*   mixin.apply.pre.attach.transform.meta.meta      16 ms             0 ms          16 ms        -       1965     0.008 ms        */
/*   mixin.apply.pre.conform                         46 ms             0 ms          46 ms        -       3973     0.012 ms        */
/*   mixin.apply.pre.prepare                         32 ms             0 ms          32 ms        -       3973     0.008 ms        */
/*   mixin.coprocessor                               82 ms             0 ms          82 ms        -      67485     0.001 ms        */
/*   mixin.plugin                                     0 ms             0 ms           0 ms        -          0     0.000 ms        */
/*   mixin.postapply                                  4 ms             0 ms           4 ms        -        896     0.004 ms        */
/*   mixin.preapply                                   6 ms             0 ms           6 ms        -        896     0.007 ms        */
/*   mixin.prepare                                 4056 ms          4056 ms           0 ms        -          1     0.000 ms        */
/*   mixin.prepare.conform                          237 ms           237 ms           0 ms        -       5035     0.000 ms        */
/*   mixin.prepare.mixin                             24 ms            24 ms           0 ms        -        416     0.000 ms        */
/*   mixin.prepare.mixin.coprocessor                  2 ms             2 ms           0 ms        -        832     0.000 ms        */
/*   mixin.prepare.plugin                           107 ms           107 ms           0 ms        -       5168     0.000 ms        */
/*   mixin.prepare.plugin.mixin                       9 ms             9 ms           0 ms        -         28     0.000 ms        */
/*   mixin.prepare.plugin.mixin.coprocessor           0 ms             0 ms           0 ms        -         56     0.000 ms        */
/*   mixin.prepare.prepare                           92 ms            92 ms           0 ms        -       9920     0.000 ms        */
/*                                                                                                                                 */
/***********************************************************************************************************************************/
/* Summary for Profiler[mixin,meta,generator]                                                                                      */
/***********************************************************************************************************************************/
/*                                                                                                                                 */
/*                          Total mixin time :     12841 ms      (12.841 seconds)                                                  */
/*                                                                                                                                 */
/*                          Preparing mixins :      4056 ms       (4.056 seconds)                                                  */
/*                             Reading input :         0 ms       (0.000 seconds)                                                  */
/*                           Applying mixins :      6800 ms       (6.800 seconds)                                                  */
/*                            Writing output :         0 ms       (0.000 seconds)                                                  */
/*                                                                                                                                 */
/*                                  of which :                                                                                     */
/*              Time spent loading from disk :         0 ms       (0.000 seconds)                                                  */
/*           Time spent transforming classes :         0 ms       (0.000 seconds)                                                  */
/*                                                                                                                                 */
/*    Time allocation:     Processing mixins :     12841 ms     (100.0% of total)                                                  */
/*                           Loading classes :         0 ms       (0.0% of total)                                                  */
/*                      Running transformers :         0 ms       (0.0% of total)                                                  */
/*                                                                                                                                 */
/***********************************************************************************************************************************/
/* Transformer Times                                                                                                               */
/***********************************************************************************************************************************/
/*                                                                                                                                 */
/* agap.main.mixin.BiomeMixin                                                                                                 1 ms */
/*                                                                                                                                 */
/***********************************************************************************************************************************/

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

1 participant