fabric8io / ipaas-quickstarts

quickstarts for the fabric8 project
Apache License 2.0
66 stars 86 forks source link

karaf quickstart do not log to docker logs #877

Open davsclaus opened 8 years ago

davsclaus commented 8 years ago

They only log the initial part of booting up karaf, but any log activity that happens since in the karaf log is not shown.

If you run from docker like

davsclaus:~/workspace/quickstarts/quickstart/karaf/camel-log (master)/$ docker run -it fabric8/quickstart-karaf-camellog:2.2.57-SNAPSHOT

Then that is all you see

Checking for *.tar.gz in /opt/jboss/deploy
Executing /opt/jboss/karaf/bin/karaf server ...
I> No access restrictor found, access to all MBean is allowed
Jolokia: Agent started with URL http://172.17.0.10:8778/jolokia/
2015-10-23 13:19:26,793 | INFO  | FelixStartLevel  | fileinstall                      | 6 - org.apache.felix.fileinstall - 3.5.0 | Creating configuration from profile.cfg
2015-10-23 13:19:26,798 | INFO  | FelixStartLevel  | fileinstall                      | 6 - org.apache.felix.fileinstall - 3.5.0 | Creating configuration from org.apache.karaf.management.cfg
2015-10-23 13:19:26,801 | INFO  | FelixStartLevel  | fileinstall                      | 6 - org.apache.felix.fileinstall - 3.5.0 | Creating configuration from org.apache.karaf.features.repos.cfg
2015-10-23 13:19:26,804 | INFO  | FelixStartLevel  | fileinstall                      | 6 - org.apache.felix.fileinstall - 3.5.0 | Creating configuration from org.ops4j.pax.url.mvn.cfg
2015-10-23 13:19:26,807 | INFO  | FelixStartLevel  | fileinstall                      | 6 - org.apache.felix.fileinstall - 3.5.0 | Creating configuration from org.apache.karaf.jaas.cfg
2015-10-23 13:19:26,817 | INFO  | FelixStartLevel  | fileinstall                      | 6 - org.apache.felix.fileinstall - 3.5.0 | Creating configuration from jmx.acl.cfg
2015-10-23 13:19:26,820 | INFO  | FelixStartLevel  | fileinstall                      | 6 - org.apache.felix.fileinstall - 3.5.0 | Creating configuration from org.apache.karaf.shell.cfg
2015-10-23 13:19:26,899 | INFO  | FelixStartLevel  | BlueprintExtender                | 9 - org.apache.aries.blueprint.core - 1.4.3 | No quiesce support is available, so blueprint components will not participate in quiesce operations
2015-10-23 13:19:27,654 | INFO  | FelixStartLevel  | BlueprintContainerImpl           | 9 - org.apache.aries.blueprint.core - 1.4.3 | Bundle org.apache.karaf.jaas.command is waiting for namespace handlers [http://karaf.apache.org/xmlns/shell/v1.1.0]
2015-10-23 13:19:28,155 | INFO  | FelixStartLevel  | BlueprintContainerImpl           | 9 - org.apache.aries.blueprint.core - 1.4.3 | Bundle org.apache.karaf.shell.commands is waiting for namespace handlers [http://karaf.apache.org/xmlns/shell/v1.0.0]

But the application is logging as its the camel-log quickstart that logs every 5th second.

davsclaus commented 8 years ago

Okay it looks like the org.ops4j.pax.logging.cfg should have out in the loggers so it log to standard out

davsclaus commented 8 years ago

It should be

log4j.rootLogger=INFO, stdout, out, osgi:*
jimmidyson commented 8 years ago

Can you make sure it's not logging to file as well? Stdout only otherwise we're wasting disk space & increasing I/O on the node.

davsclaus commented 8 years ago

yeah good idea, this is how the others are done.

davsclaus commented 8 years ago

At first glance it does not look like this plugin can do that https://github.com/jboss-fuse/karaf/blob/4.0.x.redhat-6-2-x-patch/tooling/karaf-maven-plugin/src/main/java/org/apache/karaf/tooling/AssemblyMojo.java#L110

So we may need to add yet another maven plugin that copy over the logging file or something.

davsclaus commented 8 years ago

Add the resource plugin to overwrite the file seems the way forward for now

davsclaus commented 8 years ago

Okay it works for docker run but not on openshift

davsclaus:~/workspace/quickstarts/quickstart/karaf/camel-log (877)/$ docker run -it fabric8/quickstart-karaf-camellog:2.2.57-SNAPSHOT
Checking for *.tar.gz in /opt/jboss/deploy
Executing /opt/jboss/karaf/bin/karaf server ...
I> No access restrictor found, access to all MBean is allowed
Jolokia: Agent started with URL http://172.17.0.13:8778/jolokia/
2015-10-23 13:46:06,269 | INFO  | FelixStartLevel  | fileinstall                      | 6 - org.apache.felix.fileinstall - 3.5.0 | Creating configuration from org.apache.karaf.management.cfg
2015-10-23 13:46:06,276 | INFO  | FelixStartLevel  | fileinstall                      | 6 - org.apache.felix.fileinstall - 3.5.0 | Creating configuration from org.apache.karaf.features.repos.cfg
2015-10-23 13:46:06,281 | INFO  | FelixStartLevel  | fileinstall                      | 6 - org.apache.felix.fileinstall - 3.5.0 | Creating configuration from org.ops4j.pax.url.mvn.cfg
2015-10-23 13:46:06,292 | INFO  | FelixStartLevel  | fileinstall                      | 6 - org.apache.felix.fileinstall - 3.5.0 | Creating configuration from org.apache.karaf.jaas.cfg
2015-10-23 13:46:06,296 | INFO  | FelixStartLevel  | fileinstall                      | 6 - org.apache.felix.fileinstall - 3.5.0 | Creating configuration from jmx.acl.cfg
2015-10-23 13:46:06,328 | INFO  | FelixStartLevel  | fileinstall                      | 6 - org.apache.felix.fileinstall - 3.5.0 | Creating configuration from org.apache.karaf.shell.cfg
2015-10-23 13:46:06,468 | INFO  | FelixStartLevel  | BlueprintExtender                | 9 - org.apache.aries.blueprint.core - 1.4.3 | No quiesce support is available, so blueprint components will not participate in quiesce operations
2015-10-23 13:46:07,172 | INFO  | FelixStartLevel  | BlueprintContainerImpl           | 9 - org.apache.aries.blueprint.core - 1.4.3 | Bundle org.apache.karaf.jaas.command is waiting for namespace handlers [http://karaf.apache.org/xmlns/shell/v1.1.0]
2015-10-23 13:46:07,681 | INFO  | FelixStartLevel  | BlueprintContainerImpl           | 9 - org.apache.aries.blueprint.core - 1.4.3 | Bundle org.apache.karaf.shell.commands is waiting for namespace handlers [http://karaf.apache.org/xmlns/shell/v1.0.0]
2015-10-23 13:46:08,665 | INFO  | FelixStartLevel  | BlueprintContainerImpl           | 9 - org.apache.aries.blueprint.core - 1.4.3 | Bundle io.fabric8.quickstarts.quickstart-karaf-camel-log is waiting for namespace handlers [http://camel.apache.org/schema/blueprint]
2015-10-23 13:46:08,958 | INFO  | FelixStartLevel  | Activator                        | 32 - org.apache.camel.camel-core - 2.16.0 | Camel activator starting
2015-10-23 13:46:08,978 | INFO  | FelixStartLevel  | Activator                        | 32 - org.apache.camel.camel-core - 2.16.0 | Camel activator started
2015-10-23 13:46:10,906 | INFO  | rint Extender: 1 | BlueprintCamelContext            | 32 - org.apache.camel.camel-core - 2.16.0 | Apache Camel 2.16.0 (CamelContext: log-example-context) is starting
2015-10-23 13:46:10,908 | INFO  | rint Extender: 1 | ManagedManagementStrategy        | 32 - org.apache.camel.camel-core - 2.16.0 | JMX is enabled
2015-10-23 13:46:11,077 | INFO  | rint Extender: 1 | DefaultRuntimeEndpointRegistry   | 32 - org.apache.camel.camel-core - 2.16.0 | Runtime endpoint registry is in extended mode gathering usage statistics of all incoming and outgoing endpoints (cache limit: 1000)
2015-10-23 13:46:11,236 | INFO  | rint Extender: 1 | BlueprintCamelContext            | 32 - org.apache.camel.camel-core - 2.16.0 | AllowUseOriginalMessage is enabled. If access to the original message is not needed, then its recommended to turn this option off as it may improve performance.
2015-10-23 13:46:11,236 | INFO  | rint Extender: 1 | BlueprintCamelContext            | 32 - org.apache.camel.camel-core - 2.16.0 | StreamCaching is not in use. If using streams then its recommended to enable stream caching. See more details at http://camel.apache.org/stream-caching.html
2015-10-23 13:46:11,285 | INFO  | rint Extender: 1 | BlueprintCamelContext            | 32 - org.apache.camel.camel-core - 2.16.0 | Route: log-route started and consuming from: Endpoint[timer://foo?period=5s]
2015-10-23 13:46:11,317 | INFO  | rint Extender: 1 | BlueprintCamelContext            | 32 - org.apache.camel.camel-core - 2.16.0 | Total 1 routes, of which 1 is started.
2015-10-23 13:46:11,323 | INFO  | rint Extender: 1 | BlueprintCamelContext            | 32 - org.apache.camel.camel-core - 2.16.0 | Apache Camel 2.16.0 (CamelContext: log-example-context) started in 0.411 seconds
2015-10-23 13:46:12,354 | INFO  | #0 - timer://foo | log-route                        | 32 - org.apache.camel.camel-core - 2.16.0 | >>> Hello from Camel! :
2015-10-23 13:46:17,321 | INFO  | #0 - timer://foo | log-route                        | 32 - org.apache.camel.camel-core - 2.16.0 | >>> Hello from Camel! :

But when I do oc logs -f xxx all I see is the starting piece

^Cdavsclaus:~/workspace/fabric8-installer/vagrant/openshift (master)/$ oc logs -f quickstart-karaf-camel-log-29znn
Checking for *.tar.gz in /opt/jboss/deploy
Executing /opt/jboss/karaf/bin/karaf server ...
I> No access restrictor found, access to all MBean is allowed
Jolokia: Agent started with URL https://172.17.0.12:8778/jolokia/
2015-10-23 13:45:23,518 | INFO  | FelixStartLevel  | fileinstall                      | 6 - org.apache.felix.fileinstall - 3.5.0 | Creating configuration from org.apache.karaf.management.cfg
2015-10-23 13:45:23,524 | INFO  | FelixStartLevel  | fileinstall                      | 6 - org.apache.felix.fileinstall - 3.5.0 | Creating configuration from org.apache.karaf.features.repos.cfg
2015-10-23 13:45:23,528 | INFO  | FelixStartLevel  | fileinstall                      | 6 - org.apache.felix.fileinstall - 3.5.0 | Creating configuration from org.ops4j.pax.url.mvn.cfg
2015-10-23 13:45:23,538 | INFO  | FelixStartLevel  | fileinstall                      | 6 - org.apache.felix.fileinstall - 3.5.0 | Creating configuration from org.apache.karaf.jaas.cfg
2015-10-23 13:45:23,541 | INFO  | FelixStartLevel  | fileinstall                      | 6 - org.apache.felix.fileinstall - 3.5.0 | Creating configuration from jmx.acl.cfg
2015-10-23 13:45:23,547 | INFO  | FelixStartLevel  | fileinstall                      | 6 - org.apache.felix.fileinstall - 3.5.0 | Creating configuration from org.apache.karaf.shell.cfg
2015-10-23 13:45:23,640 | INFO  | FelixStartLevel  | BlueprintExtender                | 9 - org.apache.aries.blueprint.core - 1.4.3 | No quiesce support is available, so blueprint components will not participate in quiesce operations
2015-10-23 13:45:24,430 | INFO  | FelixStartLevel  | BlueprintContainerImpl           | 9 - org.apache.aries.blueprint.core - 1.4.3 | Bundle org.apache.karaf.jaas.command is waiting for namespace handlers [http://karaf.apache.org/xmlns/shell/v1.1.0]
2015-10-23 13:45:25,159 | INFO  | FelixStartLevel  | BlueprintContainerImpl           | 9 - org.apache.aries.blueprint.core - 1.4.3 | Bundle org.apache.karaf.shell.commands is waiting for namespace handlers [http://karaf.apache.org/xmlns/shell/v1.0.0]
jimmidyson commented 8 years ago

That's the same docker container? That's a bug in openshift then.

davsclaus commented 8 years ago

yeah would have though but i did a oc rsh and noticed the log configuration wasn't changed but the old one.

davsclaus commented 8 years ago

Logged this ticket to get it into the karaf-maven-plugin https://issues.jboss.org/browse/OSFUSE-72

rhuss commented 8 years ago

the logging is setup that during startup of karaf (so very late in the process) logging is set to

# Root logger
log4j.rootLogger=INFO, stdout, osgi:*
log4j.throwableRenderer=org.apache.log4j.OsgiThrowableRenderer

# CONSOLE appender not used by default
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%d{ISO8601} | %-5.5p | %-16.16t | %-32.32c{1} | %X{bundle.id} - %X{bundle.name} - %X{bundle.version} | %m%n

This is done here

rhuss commented 8 years ago

I think it's not a configuration issue but sth is blocking the timer or startup of the context. The configuration looks good and can be easily examined by doing a oc exec.