UNDER UPPBYGGNAD!

Applikationsloggar

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

Konfiguration av applikationsloggar i Runtime

För att konfigurera loggning i VP under runtime (applikation i drifts) behöver dess log4j.xml (mule 3.3.1) eller log4j2.xml (mule 3.7.0) uppdateras. Observera att en ändring i log4j.xml slår direkt, dvs inga omstarter av applikationer eller mule. Detta gäller generellt inte i mule 3.7.0 med log4j2.xml. Man kan istället använda jmx för att ändra i runtime.

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.

Mule 3.2.1 och log4j.xml

 <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>

Mule 3.7.0 och log4j2.xml

		<RollingRandomAccessFile name="RollingRandomAccessFile"
				fileName="${log.dir}/mule-app-vp.log"
				filePattern="${log.dir}/mule-app-vp.log.%i">
			<PatternLayout>
				<Pattern>%d %-5p [%t] %-30c - %m%n</Pattern>
			</PatternLayout>
			<Policies>
				<!-- KB, MB -->
				<SizeBasedTriggeringPolicy size="50 MB"/>
			</Policies>
			<DefaultRolloverStrategy fileIndex="min" max="10"/>
		</RollingRandomAccessFile>

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.

Mule 3.3.1 och log4j.xml

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

Mule 3.7.0 och log4j2.xml

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

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 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å kan loggning asynkront till meddelandeköer användas, 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

I de senaste versionerna av VP används Mule 3.7.0 och asynkron loggning som konfigureras direkt i log4j2.xml utan activeMQ.

		<AsyncLogger name="se.skl.tp.vp.vagvalagent.VagvalAgent" level="INFO"/>

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-skltp-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

Element i extra information	Beskrivning
extraInfo.senderid	Indikerar avsändarens logiska adress (konsument)
extrainfo.originalServiceconsumerHsaid	Indikerar ursprunglig avsändarens logiska adress (konsument som ursprungligen gjorde anropet i en komplexare kedja avanrop)
extrainfo.source	Java komponenten (klassen) som genererade loggposten
extrainfo.rivversion	RIV version för anropet i versaler, tex RIVTABP21
extrainfo.senderIpAdress	Konsumentens up adress
extrainfo.wsdl_namespace	Indikerar tjänsteinteraktionens (wsdl) namnrymd
extrainfo.receiverid	Indikerar mottagarens logiska adress (producent)
extrainfo.statusCode	Redovisar html statuskod vid VP009-fel. Typiskt visas 404, 500,501, 502, 503. Finns from v 2.3.0 av VP.

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

Socketloggning (fr.o.m VP 3.2.0)

En logger är konfigurerad för att ta hand om loggning till socket i log4j2.xml . Denna använder en egenutvecklad appender som kan konfigureras i filen "${sys:mule.home}/conf/vp-socketappender.properties" till vilken server/port den skall logga, se SKLTP VP - Konfiguration. Om inget är konfigurerat i filen eller den saknas kommer loggningen vara avslagen.

log4j2.xml

	<SocketLoggerAppender name="SocketLoggerAppender" configFile="${sys:mule.home}/conf/vp-socketappender.properties"></SocketLoggerAppender>

...
	<AsyncLogger name="se.skltp.mule.logging.socketLogger" level="DEBUG" additivity="false">
		<AppenderRef ref="SocketLoggerAppender"></AppenderRef>
	</AsyncLogger>

SKLTP VP - Loggning