Showing posts with label logback. Show all posts
Showing posts with label logback. Show all posts

Wednesday, January 8, 2014

osb, logback, logstash, grok and elasticsearch, putting it all together

the Java class that I invoke with a custom XPath to trace events :
  • "interface" is like "service/operation"
  • "eventtype" is like "FileConsumed", "JMSMessageConsumed", "WSInvoked"
  • TechnicalMessageID and BusinessID are usinque identifiers for the request/payload
  • ServerName is the WebLogic managed server
  • Priority is P1... P5 in case of error
  • Payload is the actual request... it's traced only if level is "DEBUG"
  • Fault is the error description
package com.acme.osb.logging;

import org.apache.xmlbeans.XmlObject;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

/**
 * Used by OSB to report an Event
 * 
 * @author NNVernetPI
 * 
 */

public class MessageTrackerSLF4J {

 public static String logMessage(String technicalMessageid,
   String businessId, String eventType, String interfaceName,
   XmlObject payload) {

  Logger projectLogger = LoggerFactory.getLogger(interfaceName);

  if (projectLogger.isDebugEnabled()) {
   projectLogger.info(" ::InterfaceName:: {} ::EventType:: {} ::TechnicalMessageID:: {} ::BusinessID:: {} ::ServerName:: {} ::Priority:: {} ::Payload:: {} ::Fault:: {}", 
     interfaceName, eventType, technicalMessageid, businessId, System.getProperty("weblogic.Name"), "NONE", payload != null ? payload.xmlText().replaceAll("\\r\\n|\\r|\\n", " ") : "NONE", "NONE");

  } else {
   projectLogger.info(" ::InterfaceName:: {} ::EventType:: {} ::TechnicalMessageID:: {} ::BusinessID:: {} ::ServerName:: {} ::Priority:: {} ::Payload:: {} ::Fault:: {}", 
     interfaceName, eventType, technicalMessageid, businessId, System.getProperty("weblogic.Name"), "NONE", "NONE", "NONE");
  }

  String logmessage = "Info Message Logged for:: " + interfaceName;
  return logmessage;
 }

 public static String errorLogger(String technicalMessageid,
   String businessId, String interfaceName, XmlObject payload,
   String priority, XmlObject fault) {

  Logger projectLogger = LoggerFactory.getLogger(interfaceName);

  projectLogger.error(" ::InterfaceName:: {} ::EventType:: {} ::TechnicalMessageID:: {} ::BusinessID:: {} ::ServerName:: {} ::Priority:: {} ::Payload:: {} ::Fault:: {}", 
    interfaceName, "ERROR", technicalMessageid, businessId, System.getProperty("weblogic.Name"), priority, payload != null ? payload.xmlText().replaceAll("\\r\\n|\\r|\\n", " ") : "NONE", fault != null ? fault.xmlText().replaceAll("\\r\\n|\\r|\\n", " ") : "NONE");

  String responseMessage = "Error Message Logged for:: " + interfaceName;
  return responseMessage;
 }

}



To make my parsing easier, I have decided to remove all newlines from payload and fault, so as to have a single line per event in the logs.

You can also deal with multiline with this codec.

For a valid message, logback will log:
#### 2014-01-08 18:04:01,980 INFO [[ACTIVE] ExecuteThread: '3' for queue: 'weblogic.kernel.Default (self-tuning)'] - ::InterfaceName:: ProdDeclAven ::EventType:: FileConsumed ::TechnicalMessageID:: ProdDeclAven^BAD_TST_PDA_REV.xml^AVE^1389200641480 ::BusinessID:: 000000000006741320_00376401092900001530 ::ServerName:: osbdev1ms1 ::Priority:: NONE ::Payload:: NONE ::Fault:: NONE ####

logback.xml file:
<?xml version="1.0" ?>
<configuration debug="true" scan="true" scanPeriod="30 seconds">
 <jmxConfigurator/>
 <property name="LOG_DIR" value="/opt/var/log/weblogic/server/"/>
 <appender class="ch.qos.logback.core.ConsoleAppender" name="STDOUT">
  <encoder>
   <pattern>
    #### %date{ISO8601} %level [%thread] - %msg ####%n            
   </pattern>
  </encoder>
 </appender>
 <appender class="ch.qos.logback.core.rolling.RollingFileAppender" name="MyService">
  <file>
   ${LOG_DIR}acmeMyService.log
  </file>
  <rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
   <fileNamePattern>
    acmeMyService.%i.log.zip
   </fileNamePattern>
   <minIndex>
    1
   </minIndex>
   <maxIndex>
    10
   </maxIndex>
  </rollingPolicy>
  <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
   <maxFileSize>
    50MB
   </maxFileSize>
  </triggeringPolicy>
  <encoder>
   <pattern>
    #### %date{ISO8601} %level [%thread] - %msg ####%n                
   </pattern>
  </encoder>
 </appender>

 <logger additivity="false" level="INFO" name="MyService_PSDB_RoutingService">
  <appender-ref ref="MyService"/>
 </logger>

 <root level="DEBUG">
  <appender-ref ref="ALL"/>
 </root>
</configuration>





esgrok.conf will be

input {
  file {
    path => "/opt/var/log/weblogic/server/nesoa2*.log"
  }

}
filter {
  grok {
    match => [ "message", "#### %{TIMESTAMP_ISO8601:timestamp} %{WORD:level} \[\[%{WORD:threadstatus}\] %{GREEDYDATA:threadname}\] -  ::InterfaceName:: %{WORD:interfacename} ::EventType:: %{WORD:eventtype} ::TechnicalMessageID:: %{GREEDYDATA:technicalmessageid} ::BusinessID:: %{GREEDYDATA:businessid} ::ServerName:: %{WORD:servername} ::Priority:: %{WORD:priority} ::Payload:: %{GREEDYDATA:payload} ::Fault:: %{GREEDYDATA:fault} ####" ]
  }
}

output {
  elasticsearch {
    embedded => true
  }
}



Preparing the grok match regexp was very time consuming. Using http://grokdebug.herokuapp.com/ the grok debugger was essential. It worked for me only on Chrome, not on Firefox.

Priceless also the list of grok patterns.

Run with nohup java -jar logstash-1.3.2-flatjar.jar agent -f esgrok.conf -- web > logstash.log 2>&1 &
The result is impressive.
Happy Kibana to you!


Monday, December 30, 2013

OSB, WebLogic and Logback / SLF4j

Being totally fed up with the OSB reporting provider, I am setting up logback.
Maven:
<dependency>
  <groupId>ch.qos.logback</groupId>
  <artifactId>logback-core</artifactId>
  <version>1.0.13</version>
</dependency>
<dependency>
  <groupId>ch.qos.logback</groupId>
  <artifactId>logback-classic</artifactId>
  <version>1.0.13</version>
</dependency>
             
<dependency>
  <groupId>ch.qos.logback</groupId>
  <artifactId>logback-parent</artifactId>
  <version>1.0.13</version>
  <type>pom</type>
</dependency>
 
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-api</artifactId>
    <version>1.7.5</version>
</dependency>



vi /opt/oracle/fmw11_1_1_5/wlserver_10.3/common/bin/commEnv.sh

add this to WEBLOGIC_CLASSPATH:

${CLASSPATHSEP}/opt/oracle/fmw11_1_1_5/wlserver_10.3/server/lib/slf4j-api-1.7.5.jar${CLASSPATHSEP}/opt/oracle/fmw11_1_1_5/wlserver_10.3/server/lib/logback-core-1.0.13.jar${CLASSPATHSEP}/opt/oracle/fmw11_1_1_5/wlserver_10.3/server/lib/logback-classic-1.0.13.jar

and copy the JARs:

cd /opt/oracle/fmw11_1_1_5/wlserver_10.3/server/lib/

this only if you have Nexus, otherwise.... copy them manually:

wget http://nexus.nespresso.com/service/local/repositories/adobe-ext/content/ch/qos/logback/logback-core/1.0.13/logback-core-1.0.13.jar

wget http://nexus.nespresso.com/service/local/repositories/adobe-ext/content/ch/qos/logback/logback-classic/1.0.13/logback-classic-1.0.13.jar

wget http://nexus.nespresso.com/service/local/repositories/adobe-ext/content/org/slf4j/slf4j-api/1.7.5/slf4j-api-1.7.5.jar

vi /opt/oracle/domains/osbpl1do/config/osb/logback.xml

<configuration debug="true" scan="true" scanPeriod="30 seconds">
    <jmxConfigurator />
 
    <property name="LOG_DIR" value="/opt/var/log/weblogic/server/" />
 
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <!-- encoders are assigned the type ch.qos.logback.classic.encoder.PatternLayoutEncoder
            by default -->
        <encoder>
            <pattern>%d %-5level [%thread] %logger{36} - %msg%n
            </pattern>
        </encoder>
    </appender>
 
    <appender name="GM"
        class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOG_DIR}GM.log</file>
            <rollingPolicy class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy">
              <fileNamePattern>GM.%i.log.zip</fileNamePattern>
              <minIndex>1</minIndex>
              <maxIndex>10</maxIndex>
            </rollingPolicy>
            <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
              <maxFileSize>50MB</maxFileSize>
            </triggeringPolicy>
            <encoder>
                <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n
                </pattern>
            </encoder>
    </appender>
 
 
    <logger name="POC_LOG4j" additivity="false" level="INFO">
        <appender-ref ref="GM" />
    </logger>
 
    <root level="DEBUG">
        <appender-ref ref="STDOUT" />
    </root>
 
 
</configuration>


I provide a custom XPath to log :
package com.acme.osb.logging;
import org.apache.xmlbeans.XmlObject;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
/**
 * Used by OSB to report an Event
 *
 * @author NNVernetPI
 *
 */
public class MessageTrackerSLF4J {
    public static String logMessage(String technicalMessageid,
            String businessId, String eventType, String interfaceName,
            XmlObject payload) {
        Logger projectLogger = LoggerFactory.getLogger(interfaceName);
        StringBuilder sb = new StringBuilder();
        if (projectLogger.isDebugEnabled()) {
            sb.append(" ::InterfaceName::  ").append(interfaceName)
                    .append(" ::Payload:: ").append(payload.xmlText())
                    .append(" ::BusinessID::  ").append(businessId);
        } else {
            sb.append(" ::TechnicalMessageID::  ").append(technicalMessageid)
                    .append(" ::BusinessID::  ").append(businessId)
                    .append(" ::InterfaceName::  ").append(interfaceName)
                    .append(" ::EventType::  ").append(eventType)
                    .append(" ::ServerName:: ")
                    .append(System.getProperty("weblogic.Name"));
        }
        projectLogger.info(sb.toString());
        String logmessage = "Info Message Logged for:: " + interfaceName;
        return logmessage;
    }
    public static String errorLogger(String technicalMessageid,
            String businessId, String interfaceName, XmlObject payload,
            String priority, XmlObject fault) {
        Logger projectLogger = LoggerFactory.getLogger(interfaceName);
        StringBuilder sb = new StringBuilder();
        sb.append("::TechnicalMessageID::  ").append(technicalMessageid)
                .append("  ::InterfaceName::  ").append(interfaceName)
                .append("  ::BusinessID::  ").append(businessId)
                .append(" ::Payload:: ").append(payload.xmlText())
                .append(" ::Priority::  ").append(priority)
                .append(" ::FaultDescription:: ").append(fault.xmlText())
                .append(" ::ServerName:: ")
                .append(System.getProperty("weblogic.Name"));
        projectLogger.error(sb.toString());
        String responseMessage = "Error Message Logged for:: " + interfaceName;
        return responseMessage;
    }
}


which I expose as XPath this way:
  <xpf:function>
            <xpf:name>LOG_SLF_errorLogger</xpf:name>
            <xpf:comment>logs an error</xpf:comment>
            <xpf:namespaceURI>http://www.acme.com/acme2/xquery/xquery-functions</xpf:namespaceURI>
            <xpf:className>com.acme.osb.logging.MessageTrackerSLF4J</xpf:className>
            <xpf:method>java.lang.String errorLogger(java.lang.String, java.lang.String, java.lang.String, org.apache.xmlbeans.XmlObject, java.lang.String, org.apache.xmlbeans.XmlObject)</xpf:method>
            <xpf:isDeterministic>false</xpf:isDeterministic>
            <xpf:scope>Pipeline</xpf:scope>
            <xpf:scope>SplitJoin</xpf:scope>
        </xpf:function>     
        
  <xpf:function>
            <xpf:name>LOG_SLF_messageTracker</xpf:name>
            <xpf:comment>logs an event</xpf:comment>
            <xpf:namespaceURI>http://www.acme.com/acme2/xquery/xquery-functions</xpf:namespaceURI>
            <xpf:className>com.acme.osb.logging.MessageTrackerSLF4J</xpf:className>
            <xpf:method>java.lang.String logMessage(java.lang.String, java.lang.String, java.lang.String, java.lang.String, org.apache.xmlbeans.XmlObject)</xpf:method>
            <xpf:isDeterministic>false</xpf:isDeterministic>
            <xpf:scope>Pipeline</xpf:scope>
            <xpf:scope>SplitJoin</xpf:scope>
        </xpf:function>        


Since I have activated the jmxConfigurator, I can reload the logback.xml configuration file by connecting with JMX:

jconsole -J-Djava.class.path=C:\Oracle\MIDDLE~1\JDK160~1\lib\jconsole.jar;C:\Oracle\MIDDLE~1\JDK160~1\lib\tools.jar;C:\Oracle\Middleware\wlserver_10.3\server\lib\wlfullclient.jar -J-Djmx.remote.protocol.provider.pkgs=weblogic.management.remote -debug
and connect as:
service:jmx:iiop://myserver.acme.com:8001/jndi/weblogic.management.mbeanservers.runtime



The advantage is that I can also set programmatically the logger level for each logger, via JMX.



see here the doc, the first argument is the loggerName, the second is the level

A note: reloadByFileName() requires the FULL PATH : /opt/oracle/domains/osbpl1do/config/osb/logback.xml