[Feature] Add timestamp in console

Description:
Checking the console to debug an issue, it is difficult to identify which log output might be related due to the lack of timestamps.

I’d like to recommend, or maybe I already opened a feature request already, to add timestamps.

Steps to reproduce:
1.
2.
3.
4.
5.

Actual results:
Example output

DEBUG WorkflowMigrationManager            Visiting node: 1514, 3:1498:0:1385:0:1536:0:1500
DEBUG NodeContainerEditPart            Table Reader 3:1502 (EXECUTED)
DEBUG ConfigurationAreaChecker            Configuration area is at C:\Program Files\knime_5.3.0\configuration
DEBUG ConfigurationAreaChecker            Locked file in configuration area "C:\Program Files\knime_5.3.0\configuration\org.knime.core\Mike Wiegand.lock"
DEBUG ConfigurationAreaChecker            Configuration area check completed in 0,0s
DEBUG ExtPointUtil                    Found configuration element for org.knime.ui.java.SpaceProviders from com.knime.explorer.server
DEBUG ExtPointUtil                    Found configuration element for org.knime.ui.java.SpaceProviders from com.knime.explorer.server
DEBUG SelectionEventBus               Selection event listener added. Num listeners: 1
DEBUG LifeCycle                       Life cycle state transition: from 'SUSPEND' to 'INIT'
DEBUG LifeCycle                       Life cycle state transition: from 'INIT' to 'WEB_APP_LOADED'
INFO  KnimeBrowserView                %cinfo%c Injecting global logger 
      background: #00BCD4;
      border-radius: 0.5em;
      color: white;
      font-weight: bold;
      padding: 2px 0.5em;
      (source: http://org.knime.ui.java/assets/index-DeXi8oab.js; line: 64)
DEBUG DesktopAPI                      Desktop API function successfully called: setZoomLevel
DEBUG DesktopAPI                      Desktop API function successfully called: getCustomHelpMenuEntries
WARN  JsonRpcErrorResolver            An unexpected json rpc error occurred
ERROR KnimeBrowserView                %cerror%c Error making RPC call 
      background: #c0392b;
      border-radius: 0.5em;
      color: white;
      font-weight: bold;
      padding: 2px 0.5em;
      Error: No item for id '1842676260' (source: http://org.knime.ui.java/assets/index-DeXi8oab.js; line: 64)
INFO  KnimeBrowserView                %cinfo%c Injecting global logger 
      background: #00BCD4;
      border-radius: 0.5em;
      color: white;
      font-weight: bold;
      padding: 2px 0.5em;
      (source: http://org.knime.ui.java/assets/index-DeXi8oab.js; line: 64)
DEBUG DesktopAPI                      Desktop API function successfully called: setZoomLevel
DEBUG DesktopAPI                      Desktop API function successfully called: getCustomHelpMenuEntries
WARN  JsonRpcErrorResolver            An unexpected json rpc error occurred
ERROR KnimeBrowserView                %cerror%c Error making RPC call 
      background: #c0392b;
      border-radius: 0.5em;
      color: white;
      font-weight: bold;
      padding: 2px 0.5em;
      Error: No item for id '1842676260' (source: http://org.knime.ui.java/assets/index-DeXi8oab.js; line: 64)
DEBUG LifeCycle                       Life cycle state transition: from 'WEB_APP_LOADED' to 'SAVE_STATE'
DEBUG LifeCycle                       Life cycle state transition: from 'SAVE_STATE' to 'SUSPEND'
DEBUG DesktopAPI                      Desktop API function successfully called: switchToJavaUI

Expected results:

2024-06-25 14:32:02 DEBUG NodeContainerEditPart            Table Reader 3:1502 (EXECUTED)
2024-06-25 14:32:03 DEBUG ConfigurationAreaChecker            Configuration area is at C:\Program Files\knime_5.3.0\configuration
2024-06-25 14:32:03 DEBUG ConfigurationAreaChecker            Locked file in configuration area "C:\Program Files\knime_5.3.0\configuration\org.knime.core\Mike Wiegand.lock"
2024-06-25 14:32:03 DEBUG ConfigurationAreaChecker            Configuration area check completed in 0,0s
2024-06-25 14:32:04 DEBUG ExtPointUtil                    Found configuration element for org.knime.ui.java.SpaceProviders from com.knime.explorer.server
2024-06-25 14:32:04 DEBUG ExtPointUtil                    Found configuration element for org.knime.ui.java.SpaceProviders from com.knime.explorer.server
2024-06-25 14:32:05 DEBUG SelectionEventBus               Selection event listener added. Num listeners: 1
2024-06-25 14:32:06 DEBUG LifeCycle                       Life cycle state transition: from 'SUSPEND' to 'INIT'
2024-06-25 14:32:07 DEBUG LifeCycle                       Life cycle state transition: from 'INIT' to 'WEB_APP_LOADED'
2024-06-25 14:32:08 INFO  KnimeBrowserView                %cinfo%c Injecting global logger 
      background: #00BCD4;
      border-radius: 0.5em;
      color: white;
      font-weight: bold;
      padding: 2px 0.5em;
      (source: http://org.knime.ui.java/assets/index-DeXi8oab.js; line: 64)
2024-06-25 14:32:09 DEBUG DesktopAPI                      Desktop API function successfully called: setZoomLevel
2024-06-25 14:32:09 DEBUG DesktopAPI                      Desktop API function successfully called: getCustomHelpMenuEntries
2024-06-25 14:32:10 WARN  JsonRpcErrorResolver            An unexpected json rpc error occurred
2024-06-25 14:32:11 ERROR KnimeBrowserView                %cerror%c Error making RPC call 
      background: #c0392b;
      border-radius: 0.5em;
      color: white;
      font-weight: bold;
      padding: 2px 0.5em;
      Error: No item for id '1842676260' (source: http://org.knime.ui.java/assets/index-DeXi8oab.js; line: 64)
2024-06-25 14:32:12 INFO  KnimeBrowserView                %cinfo%c Injecting global logger 
      background: #00BCD4;
      border-radius: 0.5em;
      color: white;
      font-weight: bold;
      padding: 2px 0.5em;
      (source: http://org.knime.ui.java/assets/index-DeXi8oab.js; line: 64)
2024-06-25 14:32:13 DEBUG DesktopAPI                      Desktop API function successfully called: setZoomLevel
2024-06-25 14:32:13 DEBUG DesktopAPI                      Desktop API function successfully called: getCustomHelpMenuEntries
2024-06-25 14:32:14 WARN  JsonRpcErrorResolver            An unexpected json rpc error occurred
2024-06-25 14:32:15 ERROR KnimeBrowserView                %cerror%c Error making RPC call 
      background: #c0392b;
      border-radius: 0.5em;
      color: white;
      font-weight: bold;
      padding: 2px 0.5em;
      Error: No item for id '1842676260' (source: http://org.knime.ui.java/assets/index-DeXi8oab.js; line: 64)
2024-06-25 14:32:16 DEBUG LifeCycle                       Life cycle state transition: from 'WEB_APP_LOADED' to 'SAVE_STATE'
2024-06-25 14:32:17 DEBUG LifeCycle                       Life cycle state transition: from 'SAVE_STATE' to 'SUSPEND'
2024-06-25 14:32:18 DEBUG DesktopAPI                      Desktop API function successfully called: switchToJavaUI

Attachments:

OS:

1 Like

Thank you @mwiegand for sharing your feedback,

I moved this topic to feedback and ideas to possibly have more feedback from the community + upvotes.

Hi @mwiegand,

although it is currently not documented, I think, you can fully customize what is logged and how in KNIME. You have to edit the file log4j3.xml in your workspace, next to where the knime.log is located. It contains several “appenders” that govern which messages are logged and in which format. To customize the Console, go to the “knimeConsole” appender and prepend the timestamp format value %d{ISO8601} to the “ConversionPattern”. It should look something like this (if you never modified it before):

<param name="ConversionPattern" value="%d{ISO8601} %-5p %-20Q{1} %-10I %.10000m\n" />

The “logfile” appender already contains that timestamp format value, which is why you find your messages with a timestamp in the knime.log :slight_smile: Hope that helps.

4 Likes

Log4J was such a huge topic some years ago. Stupid me that I did not recalled it :face_with_peeking_eye:

But thanks for the hint. One thing, though. Being able to modify that in the Knime preference might already be enough as it is a semi- to pro-feature but that little extra on visibility would help for sure.

FYI - As follows my adjustment (full log4j config). @ONR dropping you in as you once asked for the same in:

I also switched from regular white spaces to tabs which, as I noticed, has the added benefit of automatically creating a table in comment like so:

2024-09-19 14:23:11,290 WARN Empty Table Creator 3:9 Node created an empty data table.
2024-09-19 14:23:11,830 WARN Component Input 3:1141:0:1104 Component does not have input data, execute upstream nodes first
2024-09-19 14:23:22,126 WARN HadoopInitializer Unable to find ‘hadoop.dll’ at hadoop home creation.
2024-09-19 14:23:22,127 WARN HadoopInitializer Unable to find ‘msvcr100.dll’ at hadoop home creation.
2024-09-19 14:23:28,315 WARN ColumnarPreferenceInitializer Configured heap memory limit does not leave enough free memory for the columnar backend off-heap memory. Using 768Mb for the off-heap memory limit.
2024-09-19 14:25:18,771 WARN Java Snippet 3:1169

File location (for me): E:\Knime-Workspace.metadata\knime\log4j3.xml

<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">
    <appender name="stdout" class="org.apache.log4j.ConsoleAppender">
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%-5p\t %t %c{1}\t %.10000m\n" />
        </layout>
        <filter class="org.apache.log4j.varia.LevelRangeFilter">
            <param name="levelMin" value="WARN" />
            <param name="levelMax" value="WARN" />
        </filter>
    </appender>

    <appender name="stderr" class="org.apache.log4j.ConsoleAppender">
        <param name="Target" value="System.err" />
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%-5p\t %t %c{1}\t %.10000m\n" />
        </layout>
        <filter class="org.apache.log4j.varia.LevelRangeFilter">
            <param name="levelMin" value="ERROR" />
        </filter>
    </appender>

    <appender name="batchexec" class="org.apache.log4j.ConsoleAppender">
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%-5p\t %t %c{1}\t %.10000m\n" />
        </layout>
        <filter class="org.apache.log4j.varia.LevelRangeFilter">
            <param name="levelMin" value="INFO" />
            <param name="levelMax" value="INFO" />
        </filter>
    </appender>

    <appender name="logfile" class="org.knime.core.util.LogfileAppender">
        <layout class="org.knime.core.node.NodeLoggerPatternLayout">
            <!--  Supported parameter are 
                %W = Workflow directory if available
                    the depth can be specified e.g. %W{2} prints the name of the workflow and the folder it is located in
                    if the depth is omitted the complete workflow directory is printed
                %N = Node name if available
                %Q = Qualifier as a combination of N (Node name) and c (category). Displays the category if the node name is not available.
                    the depth can be specified and is used for the category e.g. %Q{1} prints only last index of the category
                    if the depth is omitted the complete category is printed
                %I = Node id if available
                    the depth can be specified e.g. %I{1} prints only last index of the node id
                    if the depth is omitted the complete node id is printed
                %J = Job id if available
            -->
            <param name="ConversionPattern" value="%d{ISO8601} : %-5p : %t : %J : %c{1} : %N : %I : %m%n" />
        </layout>
    </appender>
    
    <appender name="knimeConsole" class="org.apache.log4j.varia.NullAppender">
        <!-- This appender is only used to retrieve the conversion pattern layout for the KNIME console output
        that is why we use the NullApender that does no log to any file. -->
        <layout class="org.knime.core.node.NodeLoggerPatternLayout">
            <!--  Supported parameter are 
                %W = Workflow directory if available
                    the depth can be specified e.g. %W{2} prints the name of the workflow and the folder it is located in
                    if the depth is omitted the complete workflow directory is printed
                %N = Node name if available
                %Q = Qualifier as a combination of N (Node name) and c (category). Displays the category if the node name is not available.
                    the depth can be specified and is used for the category e.g. %Q{1} prints only last index of the category
                    if the depth is omitted the complete category is printed
                %I = Node id if available
                    the depth can be specified e.g. %I{1} prints only last index of the node id
                    if the depth is omitted the complete node id is printed
                %J = Job id if available
            -->
            <param name="ConversionPattern" value="%d{ISO8601}\t%-5p %-20Q{1} %-10I %.10000m\n" />
            <!-- Strict pattern that maintains the distance by truncating long qualifiers and node ids
            <param name="ConversionPattern" value="%-5p %-35.35Q{1} %-20.20I %.10000m\n" />
            -->
            <!-- Compact log pattern.
            <param name="ConversionPattern" value="%-5p %Q{1} %I %.10000m\n" />
            -->
        </layout>
    </appender>

<!--
if you want to enable debug message for a specific package or class, add something like:

<logger name="org.knime.dev.node.xyz">
    <appender-ref ref="debug"/>
</logger>
-->

    <logger name="org.knime">
        <level value="all" />
    </logger>

    <logger name="com.knime">
        <level value="all" />
    </logger>

    <logger name="org.knime.core.node.workflow.BatchExecutor">
        <appender-ref ref="batchexec" />
    </logger>

    <logger name="com.knime.product.headless.ReportBatchExecutor">
        <appender-ref ref="batchexec" />
    </logger>

    <root>
        <level value="error" />
        <appender-ref ref="stdout" />
        <appender-ref ref="stderr" />
        <appender-ref ref="logfile" />
        <appender-ref ref="knimeConsole" />
    </root>
</log4j:configuration>```

Best
Mike
1 Like