Debugging and Logging

This tutorial provides some high level advice on debugging problems with your plugin and the logging options that are available.

It is inevitable that there will be problems encountered during development of a plugin. When this occurs there are various techniques and tools available to help determine the cause of any problems encountered.

Adding logging throughout your plugin

Logging is a mechanism in which you output messages that let you check your expectations in a running program. The log4j2 logging framework is used by plugins to assist in writing log messages that can be configured in Funnelback. When writing plugin code log messages can be added to write out messages to a file - and you can control the levels of detail by making use of log levels.

Log Levels

When a log message is defined in the code you also define the log level at which the message will print.

Log4j has six log levels, ordered in priority:

fatal
error
warn
info
debug
trace

In your program, you might write something like

private static final Logger log = LogManager.getLogger(TitlePrefixPluginSearchLifeCyclePlugin.class);

@Override public void postProcess(SearchTransaction transaction) {
  log.info("Running title-prefix-plugin")
}

When the plugin runs it will run with the log level set at a particular level (which can be changed via configuration). This log level acts as a base threshold and any log messages of this level or higher will be printed.

This means that if Funnelback is configured to log messages of debug or higher, your message will appear in the logs. However, if its configured to only show messages of warn, the message will not appear as info messages are of a lower priority.

Since a plugin can interact with Funnelback in different ways, the specific log file that they output to depends on the type of interaction it does. The following table tries to outline where different interfaces will output their logs to and where the log level can be configured.

Interface Log output files

gatherer

Data source gatherer logs

filtering

Data source gatherer logs

jsoup-filtering

Data source gatherer logs

indexing

Data source indexer logs

facets

Results page user interface logs

searchLifeCycle

Results page user interface logs

See: Funnelback logs reference for the specific log file names for different data source types.

To configure the log level for all interfaces except the searchLifeCycle interface

  1. create a logj2.xml file in your data source’s conf directory. The easiest way to accomplish this is to copy the default logging file that comes with Funnelback into your data source’s conf folder and modify it for your package.

    cp $SEARCH_HOME/conf/log4j2.xml.default $SEARCH_HOME/conf/<DATA-SOURCE>/log4j2.xml
  2. Then modify it by adding a new entry:

    log4j2.xml
     <Logger name="com.example" level="trace" /> (1)
    1 Set any package that starts with com.example to log messages at the trace level or higher.

    The value for the name property should be the groupId or package name that was used to create our project.

For the searchLifeCycle interface logging is configured globally as part of the public UI.

For this logging needs to be configured by editing $SEARCH_HOME/web/conf/modernui/log4j2.xml.

Changing the public UI log configuration (modernui.*.log files) will affect all results pages on the Funnelback server.
If your plugin is not logging anything while developing and your not sure if you’ve configured the log levels correctly, you can use a higher priority log level e.g. log.fatal. This is likely to be shown, but ideally, you should clean that up again before sending your plugin for review on the marketplace.

Push data sources

Plugins will also be run as part of push data sources. These will appear either in the above locations or in $SEARCH_HOME/web/logs/push.log

Push data source logging is global and the log messages from plugins run on on push data sources will be logged via this global configuration. Push data source logging can be configured using $SEARCH_HOME/web/conf/push/log4j2.xml.

Changing the push data source log configuration will affect all push data sources on the Funnelback server.

Exercise

Follow the examples above to create a logging file for the results page you made earlier. Then change the data source configuration to refer to the wrong key. e.g. lets pretend you forgot the '-plugin' part.

Results page configuration
plugin.title-prefix.pattern=Product Documentation |
plugin.title-prefix.replaceWith=Funnelback Documentation v16 |

Perform a search and then look in modernui.Admin.log. You should see something similar to:

modernui.Admin.log
2020-04-23 15:25:40,141 [admin-3067442] [example:_default_preview] WARN  titleprefixplugin.TitlePrefixPluginSearchLifeCyclePlugin - Could not find a pattern specified at plugin.title-prefix-plugin.pattern. The TitlePrefixPlugin will do nothing.

Debugging using your IDE

While logging is useful for debugging plugins that have issues when running on the Funnelback instance itself, it might be more useful to debug issues that you run into while developing. This is where the IDE (IntelliJ IDEA in our case) can start to help us step through problems much quicker.

Assuming we had a working project, lets inject some flaws and see how a debugger might help us track it down. For now, lets pretend that in TitlePrefixPluginSearchLifeCyclePluginTest, the test methods we created looked instead like this:

    @Test // 6
    public void testPostProcess_with_replacement_pattern() { // 7
        testInput
            .withProfileSetting("plugin.title-prefix-plugin.pattern", "ExampleCorp -") // 8
            .withProfileSetting("plugin.title-prefix.replaceWith", "EC |");
        pluginUnderTest.postProcess(testInput); // 9
        Set<String> expectedResultTitles = Set.of(
            "EC | Fake search data to take home",
            "EC | Another result with the same prefix",
            "This result does not match the pattern"); // 10
        List<Result> mockResults = testInput.getResponse().getResultPacket().getResults(); // 11
        Set<String> actualResultTitles = mockResults.stream().map(finalResult -> finalResult.getTitle()).collect(Collectors.toSet()); // 12
        Assert.assertEquals("the pattern should have been replaced with the new one", expectedResultTitles,actualResultTitles); // 13
    }

Note, we have just changed one of the profile settings to have different keys. Now when we run the test, we’ll notice that testPostProcess_with_replacement_pattern fails, but not really be sure where things went wrong. The trick is to put breakpoints in our code and step through the test.

Open the plugin code: TitlePrefixPluginSearchLifeCyclePlugin, and on line B, (the first line of postProcess), add a breakpoint by clicking next to the line of code number. A little red dot will appear if you’ve done it correctly. A breakpoint lets us pause the execution of the code and inspect each of the values step by step.

adding a breakpoint

Next, run the test in debug mode by Run  Debug TitlePrefixPluginSearchLifeCyclePluginTest (Shift+f9) and you’ll notice that the code stops part way through. From here, you can hover over certain objects to look at their value. For example, if you hover on transaction and explore it, you’ll be able to find the fake results we configured earlier.

explore transaction in debugger

Hover over prefixToMatch. Since the line has not been executed yet, there is nothing there yet.

Now, press the Step Over key (f8) and it will execute the previous line and if you hover over prefixToMatch now, it will show ExampleCorp - `. So we know that process method has read that key correctly. Press the key again, and look at the value for `givenReplaceWith.

givenReplaceWith is null

This time, we might have expected a pattern to be there, but there is nothing. This means either we’re reading it wrong, or we’ve set our test up wrong. By checking both assumptions, you should be able to find the "mistake" we added earlier, and fix it.

One final tip: In IntelliJ, you can also execute arbitrary code from within a paused environment. Right click and select 'evaluate expression' from the menu. You can then run something like prefixToMatch.isBlank() to see if that is what you want it to do.

Other questions you may have

How do I know that my plugin was installed correctly?

Login to the Funnelback server and check the contents of the $SEARCH_HOME/share/plugins directory. This should contain a folder for each installed plugin.

Check that the plugin you are interested in is here and that the folder contains appropriate file permissions (user and group permissions should be set to the search user).

© 2015- Squiz Pty Ltd