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 more trace prints to indicate when each Phase starts + re-word some info logs #93

Draft
wants to merge 2 commits into
base: main
Choose a base branch
from

Conversation

Shadowrs
Copy link

@Shadowrs Shadowrs commented Aug 4, 2022

  • The re-wording of some statements is to maintain some consistency at the start of each sentence- making similar info more human readable
  • Send some logs to MixinEnv.logger as well as system.out - this ensures info is captures in the latest.log (or a file specified by the end user by using a custom log4j.xml)

Suggested log4j.xml which splits mixin related logs to mixin.log instead of spamming latest.log and debug.log:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="warn" packages="com.mojang.util,net.minecrell.terminalconsole.util,com.larxstar.log">
	<Appenders>
(SYSTEM OUT, SYSTEM ERR, DEBUG, LATEST REMOVED FOR DEMO)
		
		<RollingRandomAccessFile name="MixinFile" fileName="logs/mixins.log" filePattern="logs/mixin-%i.log.gz">
			<PatternLayout pattern="[%d{HH:mm:ss}] [%t/%level] (%logger) %msg{nolookups}%n" />
			<Policies>
				<TimeBasedTriggeringPolicy />
				<OnStartupTriggeringPolicy />
			</Policies>
		</RollingRandomAccessFile>
		
		<RollingRandomAccessFile name="MiscFile" fileName="logs/misc.log" filePattern="logs/misc-%i.log.gz">
			<PatternLayout pattern="[%d{HH:mm:ss}] [%t/%level] (%logger) %msg{nolookups}%n" />
			<Policies>
				<TimeBasedTriggeringPolicy />
				<OnStartupTriggeringPolicy />
			</Policies>
		</RollingRandomAccessFile>
	</Appenders>
	<Loggers>
		<Logger level="${sys:fabric.log.level:-info}" name="net.minecraft"/>
		<Logger level="TRACE" name="mixin" additivity="false" >
			<appender-ref ref="MiscFile"/>
		</Logger>
        <Logger level="TRACE" name="mixin.audit" additivity="false" >
			<appender-ref ref="MiscFile"/>
		</Logger>
        <Logger level="TRACE" name="mixin.agent" additivity="false" >
			<appender-ref ref="MiscFile"/>
		</Logger>
        <Logger level="TRACE" name="FabricLoader/Mixin/compat" additivity="false" >
			<appender-ref ref="MixinFile"/>
			<!-- <appender-ref ref="DebugFile"/> -->
		</Logger>
        <Logger level="TRACE" name="FabricLoader/Mixin/meta" additivity="false" >
			<appender-ref ref="MixinFile"/>
		</Logger>
        <Logger level="TRACE" name="FabricLoader/Mixin/all" additivity="false" >
			<appender-ref ref="MixinFile"/>
		</Logger>
        <Logger level="TRACE" name="FabricLoader/Mixin/processor" additivity="false" >
			<appender-ref ref="MixinFile"/>
		</Logger>
        <Logger level="TRACE" name="FabricLoader/Mixin/injector" additivity="false" >
			<appender-ref ref="MixinFile"/>
		</Logger>
        <Logger level="TRACE" name="FabricLoader/Mixin" additivity="false" >
			<appender-ref ref="MixinFile"/>
		</Logger>
		<!-- ctrl+q for comment np++ -->
        <Logger level="TRACE" name="org.spongepowered" additivity="false" >
			<appender-ref ref="MiscFile"/>
		</Logger>
        <Logger level="TRACE" name="org.spongepowered.asm.mixin" additivity="false" >
			<appender-ref ref="MiscFile"/>
		</Logger>
		<Logger level="ERROR" name="net.minecraft.class_3294" additivity="false" >
			<appender-ref ref="MiscFile"/>
		</Logger>
		<Logger level="warn" name="cpw.mods.modlauncher.ClassTransformer" additivity="false" />
		<Logger level="warn" name="com.tterrag.registrate.AbstractRegistrate" additivity="false" />
		<Root level="all" additivity="false" >
			<AppenderRef ref="DebugFile" level="${sys:fabric.log.debug.level:-debug}" />
			<AppenderRef ref="SysOut" level="${sys:fabric.log.level:-info}"/>
			<AppenderRef ref="LatestFile" level="${sys:fabric.log.level:-info}"/>
			<AppenderRef ref="ServerGuiConsole" level="${sys:fabric.log.level:-info}"/>
		</Root>
	</Loggers>
</Configuration>

@@ -659,7 +664,7 @@ private void printLocals(final Callback callback) {
}
printer.add().add("/**").add(" * Expected callback signature").add(" * /");
printer.add("%s {", handlerSig);
printer.add(" // Method body").add("}").add().print(System.err);
printer.add(" // Method body").add("}").add().print(System.err).log(MixinEnvironment.logger);
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Send to the MixinEnv logger as well as sys.err

@Shadowrs
Copy link
Author

Shadowrs commented Aug 4, 2022

The mixin profiler breakdown isn't printing to a log4j file yet and I'm not sure why

@sfPlayer1
Copy link

Mixin in particular is a library where we don't want to diverge too much from upstream unless there's enough of a reason for it. Did you try a sampling based approach yet? It should be able to give a time usage breakdown as well, but without instrumenting the code and with deeper insight.

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.

2 participants