Logging Help

StrykeForce implemented slf4j with logback logging in their Swerve Drive code. This is a much better way of sending diagnostic information to the console for debugging, as log statements can be turned on and off and filtered by level. Figure if we needed it enough to put that System.out.println() in there once, we'll probably need it again. Meanwhile, a logging framework can also provide a little context about which class a message is coming from, something often forgotten with System.out and that can making locating a message filling the logs very quickly hard.

Note that slf4j provides a very efficient logging API for collecting messages. It provides a single API for program code to talk to while allowing the actual logger to be swapped out. In our case, we will use the logback framework underneath it. Both .jar files are required.

Logging Levels

Thanks to https://sematext.com/blog/slf4j-tutorial/ for the following:

TRACE – log events with this level are the most fine-grained and are usually not needed unless you need to have the full visibility of what is happening in your application and inside the third-party libraries that you use. You can expect the TRACE logging level to be very verbose.

DEBUG – less granular compared to the TRACE level, but still more than you will need in everyday use. The DEBUG log level should be used for information that may be needed for deeper diagnostics and troubleshooting.

INFO – the standard log level indicating that something happened, application processed a request, etc. The information logged using the INFO log level should be purely informative and not looking into them on a regular basis shouldn’t result in missing any important information.

WARN – the log level that indicates that something unexpected happened in the application. For example a problem, or a situation that might disturb one of the processes, but the whole application is still working.

ERROR – the log level that should be used when the application hits an issue preventing one or more functionalities from properly functioning. The ERROR log level can be used when one of the payment systems is not available, but there is still the option to check out the basket in the e-commerce application or when your social media logging option is not working for some reason. You can also see the ERROR log level associated with exceptions.

They have a great tutorial here: https://sematext.com/blog/logging-levels/

Adding slf4j and logback to an FRC VS Code project

build.gradle

Per https://docs.wpilib.org/en/stable/docs/software/advanced-gradlerio/external-libraries.html: Above the dependencies section, add the following:

repositories {
    mavenCentral()
}

Then, within dependencies, after wpi.java.vendor.java(), add:

// adding logging support, latest for slf4j and logback (they work together)
implementation "org.slf4j:slf4j-api:2.0.1"
implementation "ch.qos.logback:logback-classic:1.4.14"

logback.xml

Create a folder under src/main called resources if it does not exist. Files in this folder are meant for configuration among other things. Create the logback.xml file here to control logging output.

<configuration>

 <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
   <encoder>
     <pattern>%date{mm:ss.SSS} [%thread] %highlight(%-5level) %logger{20} - %message %n</pattern>
   </encoder>
 </appender>

 <logger name="frc.robot.commands" level="INFO"/>
 <!--logger name="frc.robot.subsystems.GamepieceFinder" level="TRACE"/-->

 <root level="WARN">
   <appender-ref ref="STDOUT"/>
 </root>

</configuration>

The configuration above uses System.out (sometimes called "console", or std. out, as that was what we had Back In The Day), "appending" messages to it given the specified pattern. It adds a little color to the more important logging levels and will tell you which class the message is coming from.

Messages coming from the package, frc.robot.commands, will display only when INFO, WARN, or ERROR. The commented line shows how to turn on TRACE for a specific class (subsystem in this case), which will cause every log message in that class to print. This is good for triage, but is not something you want to do in competition.

Lastly, the "root" appender is set to WARN. This is usually where you want it, as it governs all loggers not otherwise explicitly mentioned. Setting to ALL or TRACE will make for a very full screen.

Using logging in your classes

Adding logging to a class is easy.

First, among the imports near the beginning of the file, import the slf4j Logger and LoggerFactory:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

Define a field for the logger, and initialize it, near the class declaration:

public class MyClass {
    private static final LOG = LoggerFactory.getLogger(MyClass.class);

Note that we pass MyClass.class to getLogger(). This is how slf4j knows where log messages are coming from and can tell us in console output.

Now logging can be used throughout the methods in the class. For example:

// Called when the command is initially scheduled.
@Override
public void initialize() {
    LOG.info("Initializing...");
    counter = 0;
}

One of the best practices is to avoid string concatenation, such as: System.out.println("counter: " + counter);. Java creates the "counter: " string, then creates a string from the variable counter by doing a Integer.toString(counter), and finally, creating a string made up of both. If we didn't want to print that statement, maybe because it was a TRACE and we only want INFO and above, all of that work should have been avoided. The Logger class has a nice way to do this:

LOG.trace("counter: {}", counter);

Note the {} in the first string. That's a substitution variable for the next argument passed to trace(). You avoid a lot of the work, and the message format is easier to read.