UNDER UPPBYGGNAD!

Applikationsloggar

Virtualiseringsplattformens applikationsloggar återfinns default under <MULE-HOME>/logs/mule-app-vp.log.

Konfiguration av applikationsloggar (log4j.xml) i Runtime

För att konfigurera loggning i VP under runtime (applikation i drifts) behöver dess log4j.xml fil uppdateras. Observera att en ändring i log4j.xml slår direkt, dvs inga omstarter av applikationer eller mule.

vi /home/mule/mule-standalone-3.3.1/apps/vp-services-2.2.1/classes/log4j.xml

Uppdatera storlek på logfiler och inställningar för hur många logfiler som skall sparas.

Storlek på filer hanteras i parametern MaxFileSize.

Antal filer som skall sparas hanteras i parametern MaxBackupIndex.

Nedan exempel definierar en storlek på loggar med 50MB och att 10 filer skall sparas innan den äldsta tas bort.

 <appender name="ROLLINGFILE" class="org.apache.log4j.RollingFileAppender">
        <param  name="file" value="${mule.home}/logs/mule-app-vp.log"/>
        <param name="MaxBackupIndex" value="10" />
        <param name="MaxFileSize" value="50MB" />
        <layout class="org.apache.log4j.PatternLayout">
        	 <param name="ConversionPattern" value="%d %-5p %-30C - %m%n" />
        </layout>
    </appender>

Det finns ockås möjligheter att under runtime (applikation i drift) uppdatera lognivåer på specifika delar av applikationen. Detta görs genom att ändra lognivå (TRACE, DEBUG, INFO, WARN, ERROR, FATAL), där TRACE loggar detaljerat och FATAL loggar enbart fel.

  <!-- Level INFO will give log output for reset cache to selected appender -->
  <logger name="se.skl.tp.vp.vagvalagent.VagvalAgent">
     <level value="INFO"/>
  </logger>

Viktigt är att förändringar i konfiguration för loggning återrapporteras till applikationsförvaltning så att förändringen införs permanent i kommande releaser.

Konfiguration av applikationsloggar (log4j.xml) i källkod

Skulle det finnas behov av att uppdatera inställningar för loggning i källkoden, tex om det finns en inställning som är felaktig eller där det finns inställningar som borde vara default. I detta fallet behöver källkoden för VP uppdateras med de nya inställningarna för att komma med i nästa release. För att få med en sådan permanent ändring skapa ett ärende i Jira och beskriv ändringen.

Asynkron loggning av meddelanden

För att avlasta så mycket som möjligt så sker loggning asynkront till meddelandeköer, och implementationen är baserad på soi-toolkit och Apache ActiveMQ.

Följande köer används:

SOITOOLKIT.LOG.STORE - Normala händelser avseende virtuella tjänster (request och response)
SOITOOLKIT.LOG.ERROR - Felhändelser

Meddelande logpost

Själva nyckeln till en loggpost är en korrelationsidentitet på formatet UUID. Denna identitet exponeras också till konsumenter och producenter via en HTTP header x-vp-correlation-id, vilket möjliggör att snabbt kunna hitta till exakt rätt loggpost för enskilda händelser.

Loggposten transporteras och köas i ActiveMQ som ett XML dokument, och schema (XSD) definitionen återfinns i soi-toolkit, se LogEntry. Där
nyckeln för loggposten mappar mot elementet businessCorrelationId i detta schema.

Följande information kan förväntas i en loggpost, men observera att vilken information som för tillfället finns har med vilken typ (level) av händelse som rapporteras:

Element	Beskrivning
messageInfo.level	Anger vad det är för loggpost och antingen `INFO` eller `ERROR` är aktuella i VP 2.0
messageInfo.message	Om det är `INFO` loggpost indikeras om det är ett request `xreq-in` eller ett response `xreq-out`. Om det är en `ERROR` loggpost indikeras felmeddelandet i detta element.
runtimeInfo.businessCorrelationId	Nyckeln till loggposten
runtimeInfo.timestamp	Tidstämpel för när loggposten skapades
extraInfo.contract	Indikerar tjänstekontraktets namnrymd
extraInfo.sender	Indikerar avsändarens logiska adress (konsument)
extraInfo.receiver	Indikerar mottagarens logiska adress (producent)
extraInfo.in_timestamp	Indikerar tid för anropshändelsen (request)
extraInfo.out_timestamp	Indikerar tid för svarshändelsen (response)
extraInfo.err_timestamp	Indikerar tid för felhändelsen (endast för `ERROR`)
extraInfo.in_payload	Indikerar meddelande-innehåll för anropet
extraInfo.out_payload	Indikerar meddelande-innehåll för svaret
extraInfo.err_payload	Indikerar meddelande-innehåll för felhändelser
extraInfo.in_riv_version	RIV version för anropet i versaler, tex RIVTABP21
extraInfo.out_riv_version	RIV version för svaret i versaler
extraInfo.err_flag	Flagga som ska vara satt till true om det är ett fel
extraInfo.err_message	Felmeddelande på applikationsnivå
extraInfo.err_description	Beskrivning av felet
extraInfo.err_detail	Mer tekniska detaljer om felet
extraInfo.source	Java komponenten (klassen) som genererade loggposten
extraInfo.endpoint_time	Tid i milli-sekunder för att anropa producenten
extraInfo.endpoint_url	Den aktuella URL:en som anropar producenten

Exempel på riktiga log events från mule-app-vp.log

2014-04-03 09:09:24,852 DEBUG org.mule.module.logging.DispatchingLogger - soi-toolkit.log
** logEvent-debug.start ***********************************************************
IntegrationScenarioId=
ContractId=
LogMessage=xreq-in
ServiceImpl=vagval-dynamic-routing-flow
Host=svr-vp-qa (192.168.16.210)
ComponentId=vp-services-2.2.6-RC2
Endpoint=https://192.168.16.210:20000/vp/Ping/1/rivtabp20
MessageId=e34228dd-bafe-11e3-8954-8120699098bb
BusinessCorrelationId=e342ec3a-bafe-11e3-8954-8120699098bb
BusinessContextId=
ExtraInfo=
-senderid=HSASERVICES-100M
-originalServiceconsumerHsaid=null
-source=se.skl.tp.vp.util.LogTransformer
-cxf_service=urn:riv:itinfra:tp:Ping:1:rivtabp20
-rivversion=RIVTABP20
-senderIpAdress=172.16.0.10
-wsdl_namespace=urn:riv:itinfra:tp:Ping:1:rivtabp20
-receiverid=Ping
Payload=<?xml version='1.0' encoding='UTF-8'?><soapenv:Envelope xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/" xmlns:add="http://www.w3.org/2005/08/addressing" xmlns:urn="urn:riv:itinfra:tp:PingResponder:1">
   <soapenv:Header>
      <add:To>Ping</add:To>
   </soapenv:Header>
   <soapenv:Body>
      <urn:ping>
         <urn:pingIn/>
      </urn:ping>
   </soapenv:Body>
</soapenv:Envelope>
** logEvent-debug.end *************************************************************

** logEvent-debug.start ***********************************************************
IntegrationScenarioId=
ContractId=
LogMessage=xresp-out
ServiceImpl=vagval-dynamic-routing-flow
Host=svr-vp-qa (192.168.16.210)
ComponentId=vp-services-2.2.6-RC2
Endpoint=https://192.168.16.210:20000/vp/Ping/1/rivtabp20
MessageId=e3455c43-bafe-11e3-8954-8120699098bb
BusinessCorrelationId=e342ec3a-bafe-11e3-8954-8120699098bb
BusinessContextId=
ExtraInfo=
-senderid=HSASERVICES-100M
-originalServiceconsumerHsaid=HSASERVICES-100M
-source=se.skl.tp.vp.util.LogTransformer
-cxf_service=urn:riv:itinfra:tp:Ping:1:rivtabp20
-rivversion=RIVTABP20
-senderIpAdress=172.16.0.10
-wsdl_namespace=urn:riv:itinfra:tp:Ping:1:rivtabp20
-time.producer=14
-endpoint_url=http://localhost:10000/test/Ping_Service
-receiverid=Ping
Payload=<soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/"><soap:Header><mule:header xmlns:mule="http://www.muleumo.org/providers/soap/1.0"><mule:MULE_CORRELATION_ID>e34228dd-bafe-11e3-8954-8120699098bb</mule:MULE_CORRELATION_ID><mule:MULE_CORRELATION_GROUP_SIZE>1</mule:MULE_CORRELATION_GROUP_SIZE><mule:MULE_CORRELATION_SEQUENCE>-1</mule:MULE_CORRELATION_SEQUENCE></mule:header></soap:Header><soap:Body><pingResponse xmlns="urn:riv:itinfra:tp:PingResponder:1" xmlns:ns2="http://www.w3.org/2005/08/addressing"><pingUt>Ping response from: </pingUt></pingResponse></soap:Body></soap:Envelope>
** logEvent-debug.end *************************************************************

Loggpunkter

Loggposter skapas med hjälp av Mule transformatorer och i flödet för virtuella tjänster och aktiv övervakning ligger dessa som loggpunkter i standardflödena, och i den inbäddade Mule konfigurationen vp-common.xml finns 4 namngivna transformatorer för logg ändamål:

Namn	Beskrivning
logReqIn	Används för inkommande anrop
logReqOut	Används för utgående svar
monitorLogRequest	Används för aktiv övervakning och utgående request
monitorLogResponse	Används för aktiv övervakning och inkommande svar

Konfigurera asynkron loggning med ActiveMQ

Inställningar för ActiveMQ anges i gängse konfigurationsfil vp-config.properties och följande standardinställningar används:

SOITOOLKIT_MULE_AMQ_BROKER_URL=failover:(tcp://localhost:61616)

SOITOOLKIT_MULE_AMQ_MAX_REDELIVERIES=3

SOITOOLKIT_MULE_AMQ_REDELIVERY_DELAY=10000

SOITOOLKIT_MULE_AMQ_NO_OF_CONSUMERS=2

Exempel på logklient (implementation)

I den nationella tjänsteplattformen används en Apache Cassandra databas för att hantera loggposter, och den kontrollerande Webb-applikationen (log-analyzer) ifråga hanterar såväl aktiv övervakning som passiv loggning och aggregering av statistikräknare (sk. aktuellt läge), se vidare skltpservices på Google Code.

Exempel på en implementation som använder Apache Camel för att läsa av en meddelandekö kan se ut enligt (fragment):

...

CamelContext camel = new DefaultCamelContext();

camel.addComponent("activemq", ActiveMQComponent.activeMQComponent("failover:(tcp://localhost:61616)"));

Consumer consumer = camel.getEndpoint("activemq:SOITOOLKIT.LOG.STORE").createConsumer(new Processor() {

@Override

public void process(Exchange exchange) throws Exception {

try {

// Java LogEvent class generated from XSD, unmarshal with JAXB

LogEvent le = unmarshal((String)exchange.getIn().getBody());

// do something

storeLogEvent(le);

} catch (Exception e) {

log.error("Unable to store log event", e);

throw e;

}

});

consumer.start();

...

Konkret logklient - log analyzer

Installation

Applikationen log-analyzer är en web applikation (war)

Källkod, log-analyzer
Ladda ner applikationen, från googlecode
Driftsätt applikationen på Tomcat genom att kopiera war-filen till <TOMCAT>/webapps
Ta bort applikationen genom att ta bort war-filen från <TOMCAT>/webapps och Tomcat avinstallerar applikationen
Ladda om applikationen genom att tex göra en touch på <app>/WEB-INF/web.xml

Konfiguration

Applikationen log-analyzer har defaultinställningar som överlagras genom att definiera en fil med namnet config.properties i katalogen ${user.home}/.log-analyzer/.

Följande parametrar finns definierade och kan överlagras:

# comma separated list
#log.mq.instances=failover:(tcp://localhost:61616)
log.mq.instances=

# log directory, 
# should also have a sub-directory named 'archived' to archive rotating log files
#
log.directory = .
 
# disable log store (Cassandra)
# if set to true then all below is out of scope.
log.storeDisabled=false
 
# 
# Below is only of relevance when "log.storeDisabled=false"
#
# comma separated list
log.store.instances=localhost:9160
log.store.clusterName=SKLTP


#log.store.clusterName=Test Cluster
# time to live in days
log.store.payloadTTL=7


# time to live in days for meta information
log.store.metaTTL=30


# time to live in days for weekly counters
log.store.weeklyCounterTTL=340


# level of logging to stdout/console
console.logLevel = WARN


# timeout in millis
log.store.timeout = 60000


# counter domains
log.store.counterDomains = \
urn:riv:crm:carelisting, urn:riv:ehr:accesscontrol, urn:riv:insuranceprocess:healthreporting:RegisterMedicalCertificate, \
urn:riv:insuranceprocess:healthreporting, urn:riv:eservicesupply, urn:riv:informatics:terminology, \
urn:riv:processdevelopment:infections, urn:riv:crm:scheduling, urn:riv:druglogistics:dosedispensing:, \
urn:riv:inera:se.apotekensservice:axs:, urn:riv:inera:se.apotekensservice:or:, urn:riv:inera:se.apotekensservice:folk:, \
urn:riv:inera:se.apotekensservice:lf:, urn:riv:inera:se.apotekensservice:expo:


# timeout in seconds 
analyze.timeout = 15

SKLTP VP - Loggning