Showing posts with label JBoss. Show all posts
Showing posts with label JBoss. Show all posts

Tuesday, November 13, 2012

JBoss – Spring JDBC SQL logging (log4j)

You might occasionally need to investigate your application on a customer site (or even in your development environment look at parts of the application you’re not familiar with) from the outside first to see what they do in terms of SQL statements, before diving into the code.

Obviously a solution is to trace the statements at database level, but some databases make it easier than others or might require profiling rights and so on. But what you might have access to is your application log4j configuration.

Here’s an example on how to enable SQL logging for Spring JDBC into a separate file appender.

Note that I defined the loggers so they don’t inherit the appenders from parent packages or the root appenders (additivity=”false”) – you can remove that and they will append to predefined appenders as well as this new one. Whenever finished you can raise the level for those two loggers back to WARN to stop the logging, and if you need to leave it on for longer, see the previous post on how to roll logs. It’s probably not recommended though leaving the SQL logging on in production as it might slow the application or will produce large logs in busy environments.
<appender name="FILE_SQL" class="org.jboss.logging.appender.RollingFileAppender">
   <param name="File"      value="${jboss.server.home.dir}/log/sql.log"/>
   <param name="Threshold" value="TRACE"/>
   <param name="Encoding"  value="UTF-8" />

   <layout class="org.apache.log4j.PatternLayout">
     <param name="ConversionPattern" value="%d %-5p (%t) [%c:%L] %m%n"/>
   </layout>        
</appender>

[…]

<!-- SQL logging -->
<logger name="org.springframework.jdbc.core.JdbcTemplate" additivity="false">
  <priority   value="DEBUG"/>
  <appender-ref ref="FILE_SQL"/>
</logger>

<logger name="org.springframework.jdbc.core.StatementCreatorUtils" additivity="false">
  <priority   value="TRACE"/>
  <appender-ref ref="FILE_SQL"/>
</logger>
Sample output:
2012-11-13 16:51:01,969 DEBUG (http-8080-Processor18) [org.springframework.jdbc.core.JdbcTemplate:569] Executing prepared SQL statement [SELECT id, first_name, last_name, address, city, telephone FROM owners WHERE last_name like ?]
2012-11-13 16:51:01,973 TRACE (http-8080-Processor18) [org.springframework.jdbc.core.StatementCreatorUtils:206] Setting SQL statement parameter value: column index 1, parameter value [Doe%], value class [java.lang.String], SQL type unknown

Thursday, November 1, 2012

JBoss – Daily rolling logs (log4j)

Our standard log4j JBoss application configuration uses with size based, index rolling file appenders, and when having to investigate customers issues that happened a few days back requires quite a bit of navigation to find the particular date and time, or worse if a recurrent problem fills up the log parts, it might loose the information that could’ve otherwise helped. So recently I’ve been looking to implement daily rolling file appenders in a customer site.

Looking at Log4j DailyRollingFileAppender they are advising to use the log4j extras companion classes:

http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/DailyRollingFileAppender.html
DailyRollingFileAppender extends FileAppender so that the underlying file is rolled over at a user chosen frequency. DailyRollingFileAppender has been observed to exhibit synchronization issues and data loss. The log4j extras companion includes alternatives which should be considered for new deployments and which are discussed in the documentation for org.apache.log4j.rolling.RollingFileAppender.
You can download the Apache Extras Companion for Apache Log4j from project website, or otherwise from Maven.org - place that in your JBoss / application CLASSPATH and restart the application.

The RollingFileAppender uses a TimeBasedRollingPolicy, controlling when the file is rolled through a SimpleDateFormat pattern (daily, hourly etc). Optionally it can compress the archive log by adding the .gz/.zip extension to the filename. You can also move the archive logs into a separate location.
   <!-- SERVER.LOG -->
   <appender name="FILE" class="org.apache.log4j.rolling.RollingFileAppender">
     <!-- Active log file name -->
     <param name="File"     value="${jboss.server.home.dir}/log/server.log" />
     <param name="Append"   value="true" />
     <param name="Encoding" value="UTF-8" />

     <rollingPolicy class="org.apache.log4j.rolling.TimeBasedRollingPolicy">
       <!-- Archive file to roll to @ midnight (yyyy-MM-dd) with compression -->
       <param name="FileNamePattern" value="${jboss.server.home.dir}/log/archive/server.%d{yyyy-MM-dd}.log.zip" />
     </rollingPolicy>

     <layout class="org.apache.log4j.PatternLayout">
       <param name="ConversionPattern" value="%d %-5p [%t] [%c{1}:%L] %m%n"/>
     </layout>
   </appender>

Thursday, June 7, 2012

JBoss 4.2.3 – Empty work directory on shutdown

A common problem I’ve had with customer installations at testing stage is that as they get updated .ear versions, they won’t see the changes made to .jsp pages until someone will manually remove the contents of the jboss\server\default\work directory.

That is because JBoss compiles the JSP pages into class files and persists them in the work directory, with the gain of not having to recompile them on next start. Problem is that it doesn’t seem to recompile them if there’s a timestamp difference between the source jsp and the .class file… Obviously a solution is to pre-compile JSP pages in your application and ship the .class files with your .ear.

But at the same time, an easy solution is to configure JBoss Web deployer to destroy the contents of the work directory at shutdown through configuration.
[...]
  <!-- Flag to delete the Work Dir on Context Destroy -–>
  <attribute name="DeleteWorkDirOnContextDestroy">true</attribute>
[...]

Thursday, April 12, 2012

JBoss 4.2.3 with VisualVM

I have recently been involved in implementing and testing our application in a high volume / high performance customer case, where I thought I might try using VisualVM to see the JVM in action and find potential bottlenecks, like where would most of the CPU usage would go (the module I’m writing is a big CPU hog) as well as maybe latency issues caused by inadequate garbage collector settings.

The screenshots below are taken from a much smaller test environment where I just ran a quick test, but I have been able to use the tool in the customer environment where we were able to identify occasional high CPU usage with garbage collection (the blue line in the CPU area, left) as well as OutOfMemory problems due to the default garbage collection strategies (notice the erratic/irregular shapes in heap usage on the right side) - both can be addressed by adjusting the garbage collector strategy for low pause, concurrency (using -XX:+UseConcMarkSweepGC and -XX:+UseParNewGC parameters, see "before" and "after" screenshots below).

Also we found high CPU usage on certain application threads that now we can focus to optimize the code in those areas, they are not part of these screenshots, but I might post separately on that. Also from the threads graph is visible we have a high number of threads  with a short life span, probably around the JMS connectivity area that we’re still investigating.

I’m nowhere even close to being an expert on these things, I’m still learning the stuff, but since I struggled a bit to get the JMX enabled with JBoss 4.2.3, though I might share the findings others might find useful and why not even got some more qualified suggestions from you, the readers out there.
We’re using the Java Service Wrapper (just to give you another example of how to use the parameters) and these are the settings I used to allow for remote JMX connectivity (the port is your choice really):
wrapper.java.additional.14=-Djavax.management.builder.initial=org.jboss.system.server.jmx.MBeanServerBuilderImpl
wrapper.java.additional.15=-Djboss.platform.mbeanserver
wrapper.java.additional.16=-Dcom.sun.management.jmxremote
wrapper.java.additional.17=-Dcom.sun.management.jmxremote.port=9999
wrapper.java.additional.18=-Dcom.sun.management.jmxremote.ssl=false
wrapper.java.additional.19=-Dcom.sun.management.jmxremote.authenticate=false
Once setup you can just run VisualVM and point it to localhost:9999 if you’re going to do the monitoring locally, although probably for a high performance environment you might want to run VisualVM from another machine, so it doesn’t affect the environment too much. Just as well, with the JMX enabled you can probably use that from a monitoring application and set warning thresholds for things like free JVM memory, high CPU usage etc.

VisualVM seems to be quite a capable tool (not to mention easy on the eye), giving you real time information through the graphs, being able to take memory dumps to analyze offline (with say the likes of Eclipse Memory Analyzer), perform garbage collection, take thread dumps, look at active / dead threads or run a CPU sampler to see the top consumer threads.


Wednesday, March 14, 2012

JBoss 4.2.3 with Apache Portable Runtime (APR)

http://www.jboss.org/jbossweb/native

By default JBossWeb uses the standard pure-Java implementation and you can observe this in the log:

INFO  [AprLifecycleListener] The Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: [...]
INFO  [Http11Protocol] Initializing Coyote HTTP/1.1 on http-0.0.0.0-8080
INFO  [Http11Protocol] Initializing Coyote HTTP/1.1 on http-8443
INFO  [AjpProtocol] Initializing Coyote AJP/1.3 on ajp-0.0.0.0-8009
INFO  [Catalina] Initialization processed in 1118 ms
INFO  [StandardService] Starting service jboss.web
INFO  [StandardEngine] Starting Servlet Engine: JBossWeb/2.0.1.GA
INFO  [Catalina] Server startup in 93 ms

where with native libraries installed it will look like this:

INFO  [main] [org.jboss.wsf.stack.jbws.NativeServerConfig:51] JBoss Web Services - Native
INFO  [main] [org.jboss.wsf.stack.jbws.NativeServerConfig:52] jbossws-3.0.1-native-2.0.4.GA (build=200803312044)
INFO  [main] [org.apache.catalina.core.AprLifecycleListener:181] Loaded Apache Tomcat Native library 1.1.22.
INFO  [main] [org.apache.catalina.core.AprLifecycleListener:189] APR capabilities: IPv6 [false], sendfile [true], accept filters [false], random [true].
INFO  [main] [org.apache.coyote.http11.Http11AprProtocol:113] Initializing Coyote HTTP/1.1 on http-0.0.0.0-8080
INFO  [main] [org.apache.coyote.ajp.AjpAprProtocol:166] Initializing Coyote AJP/1.3 on ajp-0.0.0.0-8009
INFO  [main] [org.apache.catalina.startup.Catalina:536] Initialization processed in 992 ms
INFO  [main] [org.apache.catalina.core.StandardService:507] Starting service jboss.web
INFO  [main] [org.apache.catalina.core.StandardEngine:431] Starting Servlet Engine: JBossWeb/2.0.1.GA
INFO  [main] [org.apache.catalina.startup.Catalina:584] Server startup in 39 ms

To enable APR, download the appropriate package for the environment from http://www.jboss.org/jbossweb/native and extract into jboss\bin – in my case a Windows server, and that would be tcnative-1.dll and openssl.exe. They need to be in the application path, if it doesn’t find them JBoss will revert to standard Java implementation.

One problem now is that APR uses openssl.exe and the HTTPs configuration has to be changed, but I didn’t look too much into that, since my environment doesn’t require it I just commented it out; otherwise it will throw an exception at start-up complaining about the setup of the secure connector.

jboss\server\default\deploy\jboss-web.deployer\server.xml
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
 <!-- Define a SSL HTTP/1.1 Connector on port 8443
      This connector uses the JSSE configuration, when using APR, the 
      connector should be using the OpenSSL style configuration
      described in the APR documentation
   <Connector port="8443" protocol="HTTP/1.1" SSLEnabled="true"
           maxThreads="150" scheme="https" secure="true"
           clientAuth="false"
           keystoreFile="${jboss.server.home.dir}/conf/ssl-keystore.jks"
           keystorePass="hgf8tx" sslProtocol="TLS" />
-->

Restart JBoss and check the performance.