0

I might need to change the title to refer to pax logging.

Phenomenon observed:

log entry
... 2 more

Desired outcome:

log entry
log entry
log entry

Notice that the entries in the desired outcome have not been curtailed.

Background

When using Apache Karaf, which uses the log4j 2 interface, there is a properties file etc/org.ops4j.pax.logging.cfg where I can setup what gets logged and how. How do stop it from curtailing log entries as shown above?

org.ops4j.pax.logging.cfg

################################################################################
#
#    Licensed to the Apache Software Foundation (ASF) under one or more
#    contributor license agreements.  See the NOTICE file distributed with
#    this work for additional information regarding copyright ownership.
#    The ASF licenses this file to You under the Apache License, Version 2.0
#    (the "License"); you may not use this file except in compliance with
#    the License.  You may obtain a copy of the License at
#
#       http://www.apache.org/licenses/LICENSE-2.0
#
#    Unless required by applicable law or agreed to in writing, software
#    distributed under the License is distributed on an "AS IS" BASIS,
#    WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
#    See the License for the specific language governing permissions and
#    limitations under the License.
#
################################################################################

# Colors for log level rendering
color.fatal = bright red
color.error = bright red
color.warn = bright yellow
color.info = bright green
color.debug = cyan
color.trace = cyan

# Common pattern layout for appenders
log4j2.pattern = %d{ISO8601} | %-5p | %-16t | %-32c{1} | %X{bundle.id} - %X{bundle.name} - %X{bundle.version} | %m%n
log4j2.out.pattern = \u001b[90m%d{HH:mm:ss\.SSS}\u001b[0m %highlight{%-5level}{FATAL=${color.fatal}, ERROR=${color.error}, WARN=${color.warn}, INFO=${color.info}, DEBUG=${color.debug}, TRACE=${color.trace}} \u001b[90m[%t]\u001b[0m %msg%n%throwable


# Root logger
log4j2.rootLogger.level = INFO
# uncomment to use asynchronous loggers, which require mvn:com.lmax/disruptor/3.3.2 library
#log4j2.rootLogger.type = asyncRoot
#log4j2.rootLogger.includeLocation = false
log4j2.rootLogger.appenderRef.RollingFile.ref = RollingFile
log4j2.rootLogger.appenderRef.PaxOsgi.ref = PaxOsgi
log4j2.rootLogger.appenderRef.Console.ref = Console
log4j2.rootLogger.appenderRef.Console.filter.threshold.type = ThresholdFilter
log4j2.rootLogger.appenderRef.Console.filter.threshold.level = ${karaf.log.console:-FINEST}

# Loggers configuration

# SSHD logger
log4j2.logger.sshd.name = org.apache.sshd
log4j2.logger.sshd.level = INFO

# Spifly logger
log4j2.logger.spifly.name = org.apache.aries.spifly
log4j2.logger.spifly.level = WARN

# Security audit logger
log4j2.logger.audit.name = audit
log4j2.logger.audit.level = TRACE
log4j2.logger.audit.additivity = false
log4j2.logger.audit.appenderRef.AuditRollingFile.ref = AuditRollingFile

# Appenders configuration

# Console appender not used by default (see log4j2.rootLogger.appenderRefs)
log4j2.appender.console.type = Console
log4j2.appender.console.name = Console
log4j2.appender.console.layout.type = PatternLayout
log4j2.appender.console.layout.pattern = ${log4j2.out.pattern}

# Rolling file appender
log4j2.appender.rolling.type = RollingRandomAccessFile
log4j2.appender.rolling.name = RollingFile
log4j2.appender.rolling.fileName = ${karaf.log}/karaf.log
log4j2.appender.rolling.filePattern = ${karaf.log}/karaf.log.%i
# uncomment to not force a disk flush
#log4j2.appender.rolling.immediateFlush = false
log4j2.appender.rolling.append = true
log4j2.appender.rolling.layout.type = PatternLayout
log4j2.appender.rolling.layout.pattern = ${log4j2.pattern}
log4j2.appender.rolling.policies.type = Policies
log4j2.appender.rolling.policies.size.type = SizeBasedTriggeringPolicy
log4j2.appender.rolling.policies.size.size = 16MB

# Audit file appender
log4j2.appender.audit.type = RollingRandomAccessFile
log4j2.appender.audit.name = AuditRollingFile
log4j2.appender.audit.fileName = ${karaf.log}/security.log
log4j2.appender.audit.filePattern = ${karaf.log}/security-%i.log
log4j2.appender.audit.append = true
log4j2.appender.audit.layout.type = PatternLayout
log4j2.appender.audit.layout.pattern = %m%n
log4j2.appender.audit.policies.type = Policies
log4j2.appender.audit.policies.size.type = SizeBasedTriggeringPolicy
log4j2.appender.audit.policies.size.size = 8MB

# OSGi appender
log4j2.appender.osgi.type = PaxOsgi
log4j2.appender.osgi.name = PaxOsgi
log4j2.appender.osgi.filter = *

# help with identification of maven-related problems with pax-url-aether
#log4j2.logger.aether.name = shaded.org.eclipse.aether
#log4j2.logger.aether.level = TRACE
#log4j2.logger.http-headers.name = shaded.org.apache.http.headers
#log4j2.logger.http-headers.level = DEBUG
#log4j2.logger.maven.name = org.ops4j.pax.url.mvn
#log4j2.logger.maven.level = TRACE

Steps to reproduce

Install Karaf 4.2.4

Make new Java project

mvn archetype:generate \
-DinteractiveMode=false \
-DarchetypeGroupId=org.apache.maven.archetypes \
-DgroupId=com.testproject \
-DartifactId=karaftest 

Add a dependency that Karaf is unaware of. Do not add a features.xml. I used a pom.xml to make this easier.

<dependency>
  <groupId>org.apache.camel</groupId>
  <artifactId>camel-blueprint</artifactId>
  <version>2.22.2</version>
  <scope>provided</scope>
</dependency>

Main.class:

import org.apache.camel.blueprint.BlueprintCamelContext;

/**
 * Hello world!
 *
 */
public class App 
{
    public static void main( String[] args )
    {
        BlueprintCamelContext blueprintCamelContext = new BlueprintCamelContext();

        System.out.println( "Hello World!" );
    }
}

Make a bundle. I maven's pom.xml and swapped out the packaging value and added the maven-bundle-plugin to the build command.

<packaging>bundle</packaging>

<build>
    <plugins>
      <plugin>
        <groupId>org.apache.felix</groupId>
        <artifactId>maven-bundle-plugin</artifactId>
        <extensions>true</extensions>
        <version>2.4.0</version>
      </plugin>
    </plugins>
  </build>

Build it

mvn clean install

Place bundle's jar into Karaf's deploy folder.

Karaf will not start the bundle. Start the bundle start 45 (Default bundle id on a fresh install will probably be 45.)

Run log:set debug and log:display. Look for an OSGI osgi.wiring.package error, because I did import the dependency in the MANIFEST.MF (add in the pom.xml)

Exception caught while executing command

Karaf Log Contains

11:24:05.970 ERROR [Karaf local console user karaf] Exception caught while executing command
org.apache.karaf.shell.support.MultiException: Error executing command on bundles:
    Error starting bundle 45: Unable to resolve com.testproject.karaftest [45](R 45.0): missing requirement [com.testproject.karaftest [45](R 45.0)] osgi.wiring.package; (&(osgi.wiring.package=org.apache.camel.blueprint)(version>=2.22.0)(!(version>=3.0.0))) Unresolved requirements: [[com.testproject.karaftest [45](R 45.0)] osgi.wiring.package; (&(osgi.wiring.package=org.apache.camel.blueprint)(version>=2.22.0)(!(version>=3.0.0)))]
    at org.apache.karaf.shell.support.MultiException.throwIf(MultiException.java:61) ~[?:?]
    at org.apache.karaf.bundle.command.BundlesCommand.doExecute(BundlesCommand.java:70) ~[?:?]
    at org.apache.karaf.bundle.command.BundlesCommand.execute(BundlesCommand.java:55) ~[?:?]
    at org.apache.karaf.shell.impl.action.command.ActionCommand.execute(ActionCommand.java:84) ~[?:?]
    at org.apache.karaf.shell.impl.console.osgi.secured.SecuredCommand.execute(SecuredCommand.java:68) ~[?:?]
    at org.apache.karaf.shell.impl.console.osgi.secured.SecuredCommand.execute(SecuredCommand.java:86) ~[?:?]
    at org.apache.felix.gogo.runtime.Closure.executeCmd(Closure.java:599) ~[?:?]
    at org.apache.felix.gogo.runtime.Closure.executeStatement(Closure.java:526) ~[?:?]
    at org.apache.felix.gogo.runtime.Closure.execute(Closure.java:415) ~[?:?]
    at org.apache.felix.gogo.runtime.Pipe.doCall(Pipe.java:416) ~[?:?]
    at org.apache.felix.gogo.runtime.Pipe.call(Pipe.java:229) ~[?:?]
    at org.apache.felix.gogo.runtime.Pipe.call(Pipe.java:59) ~[?:?]
    at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[?:?]
    at java.lang.Thread.run(Thread.java:834) [?:?]
    Suppressed: java.lang.Exception: Error starting bundle 45: Unable to resolve com.testproject.karaftest [45](R 45.0): missing requirement [com.testproject.karaftest [45](R 45.0)] osgi.wiring.package; (&(osgi.wiring.package=org.apache.camel.blueprint)(version>=2.22.0)(!(version>=3.0.0))) Unresolved requirements: [[com.testproject.karaftest [45](R 45.0)] osgi.wiring.package; (&(osgi.wiring.package=org.apache.camel.blueprint)(version>=2.22.0)(!(version>=3.0.0)))]
        at org.apache.karaf.bundle.command.BundlesCommand.doExecute(BundlesCommand.java:67) ~[?:?]
        at org.apache.karaf.bundle.command.BundlesCommand.execute(BundlesCommand.java:55) ~[?:?]
        at org.apache.karaf.shell.impl.action.command.ActionCommand.execute(ActionCommand.java:84) ~[?:?]
        at org.apache.karaf.shell.impl.console.osgi.secured.SecuredCommand.execute(SecuredCommand.java:68) ~[?:?]
        at org.apache.karaf.shell.impl.console.osgi.secured.SecuredCommand.execute(SecuredCommand.java:86) ~[?:?]
        at org.apache.felix.gogo.runtime.Closure.executeCmd(Closure.java:599) ~[?:?]
        at org.apache.felix.gogo.runtime.Closure.executeStatement(Closure.java:526) ~[?:?]
        at org.apache.felix.gogo.runtime.Closure.execute(Closure.java:415) ~[?:?]
        at org.apache.felix.gogo.runtime.Pipe.doCall(Pipe.java:416) ~[?:?]
        at org.apache.felix.gogo.runtime.Pipe.call(Pipe.java:229) ~[?:?]
        at org.apache.felix.gogo.runtime.Pipe.call(Pipe.java:59) ~[?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[?:?]
        at java.lang.Thread.run(Thread.java:834) [?:?]
    Caused by: org.osgi.framework.BundleException: Unable to resolve com.testproject.karaftest [45](R 45.0): missing requirement [com.testproject.karaftest [45](R 45.0)] osgi.wiring.package; (&(osgi.wiring.package=org.apache.camel.blueprint)(version>=2.22.0)(!(version>=3.0.0))) Unresolved requirements: [[com.testproject.karaftest [45](R 45.0)] osgi.wiring.package; (&(osgi.wiring.package=org.apache.camel.blueprint)(version>=2.22.0)(!(version>=3.0.0)))]
        at org.apache.felix.framework.Felix.resolveBundleRevision(Felix.java:4149) ~[?:?]
        at org.apache.felix.framework.Felix.startBundle(Felix.java:2119) ~[?:?]
        at org.apache.felix.framework.BundleImpl.start(BundleImpl.java:998) ~[?:?]
        at org.apache.karaf.bundle.command.Start.executeOnBundle(Start.java:38) ~[?:?]
        at org.apache.karaf.bundle.command.BundlesCommand.doExecute(BundlesCommand.java:65) ~[?:?]
        ... 14 more

Related: How do I stop stacktraces truncating in logs

Jonathan Komar
  • 2,678
  • 4
  • 32
  • 43
  • Can you provide the configuration file contents? – Ancoron Apr 03 '19 at 21:59
  • @Ancoron See appendage. I assume you were referring to `org.ops4j.pax.logging.cfg`. – Jonathan Komar Apr 05 '19 at 06:49
  • OK, the logging configuration is fine. This is certainly not default Karaf behavior. You are not talking about a shortened stacktrace in the log, or? – Ancoron Apr 08 '19 at 04:44
  • @Ancoron Shortened anything, stack traces included. – Jonathan Komar Apr 08 '19 at 04:46
  • I've not seen anything like this behavior. Can you provide a set of real-world example log entries (not modified - complete as in the log file)? – Ancoron Apr 08 '19 at 07:59
  • @Ancoron I added steps to reproduce the problem. Unfortunately it isn‘t a simple copy and paste situation. It is, however, pretty easy to reproduce. Just leave something important out lf the MANIFEST.MF that Karaf is not running. – Jonathan Komar Apr 08 '19 at 09:40
  • Yes, for exceptions, this behavior is actually wanted and for Apache Karaf using the logging service from OPS4J it can not be turned off: https://github.com/ops4j/org.ops4j.pax.logging/blob/master/pax-logging-service/src/main/java/org/apache/log4j/OsgiThrowableRenderer.java#L134 – Ancoron Apr 08 '19 at 11:32
  • Btw. as already explained in the other issue, the hidden lines only contain duplicate information of the same stack (one of the parent exceptions has them printed). So there simply is no point in printing them out again. In your example it is everything starting at `Thread.run` down to `BundlesCommand.execute` that is redundant stack information and therefore removed. – Ancoron Apr 08 '19 at 11:36

0 Answers0