Re: Logging in HV-VES #log


Piotr Jaszczyk
 

Hi,


Thank you Michael for the reply. It clarifies current situation very well. I'm looking forward to getting some more details later.


Using this opportunity I want to ask some questions which relate to logging in reactive (as in Reactive Streams specification [1]) application. Feel free to answer these additional questions later, when you have some more time.


First some background: For now we are using slf4j api directly with logback provider. It binds MDC to a thread context which poses some problems in reactive applications. Traditionally client requests are handled using "one thread per client" strategy. In reactive apps (for instance using Project Reactor or RxJava [2]) this is not the case - clients are handled using pooled threads with some rather small computation thread pool (with the size roughly equal to number of available CPU cores). Each client request might be handled by multiple shared threads. So binding MDC to "client" thread is not an option here. In DCAE HV-VES we've worked around this issue by writing thin adapter for slf4j api which basically sets MDC just before log and clears it right after (see [3]). It's not very clean solution but for now it must suffice. Note that we are using just Reactor- no Spring stuff is used there.


  1. Will we be able to use plain logback without ONAP-specific adapters in Dublin release? Or will these adapters support "reactive" applications?
  2. HV-VES is stream-based (as opposed to request-based). Some of the MDCs defined in the guideline have little or no sense here. I believe the final guideline could address this issue (make some markers optional, define them in other way). For instance RequestID in streaming app can be defined as "unique id for current client connection" which resolves some doubts on whether new ID should be generated for every client or for every message.
  3. I believe we could extract our logging-related code to some common library (+ rewrite it to Java) in some time in the future. This could be a base for logging utility for use in all reactive JVM applications in ONAP. I don't know if there would be a demand for such library - it's just an idea.


@Vijay

I recommend to merge https://gerrit.onap.org/r/#/c/74812/ "as is" because it contains also other (non log format related) changes. We will update the documentation as soon as the final logging specification is ready and implemented in hv-ves. Is it OK with you?


[1] http://www.reactive-streams.org/

[2] https://projectreactor.io/ http://reactivex.io/

[3] https://gerrit.onap.org/r/gitweb?p=dcaegen2/collectors/hv-ves.git;a=tree;f=sources/hv-collector-utils/src/main/kotlin/org/onap/dcae/collectors/veshv/utils/logging;h=05a31729aa808fdf786d2ac6cdc8320b6a3dc285;hb=HEAD


Thanks,

Peter


--
Piotr Jaszczyk
Technical Leader, Software Development
Nokia
Poland, Wrocław, West Gate


From: Michael O'Brien <Frank.Obrien@...>
Sent: Wednesday, January 16, 2019 6:08:04 PM
To: VENKATESH KUMAR, VIJAY; Jaszczyk, Piotr (Nokia - PL/Wroclaw); onap-discuss@...
Cc: Janiak, Kornel (Nokia - PL/Wroclaw); Krzywka, Filip (Nokia - PL/Wroclaw); Dudycz, Jakub (Nokia - PL/Wroclaw); Luke Parker; WELCH, LORRAINE A; WILLIAMSON, DAVID M; Jason Hunt; AGRAHARAM, SANJAY; Prudence Au
Subject: RE: Logging in HV-VES #log
 

Team,

  Sorry for the late reply – there is an RI and a final version of the logback.xml spec in the review below that we would like to help start implementing in Dublin – that I need to rebuild.  The goal for Dublin is implementation of AOP/Injected markers and MDCs (key/value pairs) – while maintaining the older pipe delimited format – so new/older and static/aop libraries can work together.

 

   I will reply back to this thread with more full/accurate details tonight.

   I am a bit busy ending today with deploy issues, testing the Casablanca MR to meet 3.0.1 before 9am tomorrow and CD work today until 6 – I will definitely reply with a more complete email later tonight

 

   For now (review to be resynced)

https://gerrit.onap.org/r/#/c/62405/20/reference/logging-demo/src/main/resources/logback.xml

https://jira.onap.org/browse/LOG-630

POC/RI doc in https://wiki.onap.org/display/DW/Logging+Developer+Guide#LoggingDeveloperGuide-JAVA:AddingLoggingtoaWARProject

developer doc/demo in https://wiki.onap.org/display/DW/Logging+Developer+Guide#LoggingDeveloperGuide-LoggingResults

 

   The pomba project is another reference as well as our proposed RI – portal/sdk – and actually running since casablanca that you could use as well.

https://git.onap.org/oom/tree/kubernetes/pomba/charts/pomba-aaictxbuilder/resources/config/logback.xml

 

   I need to revisit the docs that caused your /t issue – thanks for raising this  - checking https://wiki.onap.org/pages/viewpage.action?pageId=28378955#ONAPApplicationLoggingSpecificationv1.2(Casablanca)-TextOutput in terms of the new spec.

 

   Also part of the scope is both logging spec alignment – and log streaming (all appropriate pods have a 2/2 2nd filebeat container to ship the formatted logs to the ELK stack along with Prometheus based metrics to form a larger picture of transactions with the entire undercloud/k8s framework)

 

https://jira.onap.org/browse/LOG-707

https://wiki.onap.org/display/DW/Logging+Dublin+Scope

filebeat container audit

https://jira.onap.org/browse/LOG-487

 

   thank you

   /michael

 

 

Tentative

<?xml version="1.0" encoding="UTF-8"?>

<!-- based on https://git.onap.org/oom/tree/kubernetes/portal/charts/portal-sdk/resources/config/deliveries/properties/ONAPPORTALSDK/logback.xml -->

<!-- Logging Spec Reference: https://wiki.onap.org/display/DW/Logging+Specifications -->

<configuration

  scan="true"

  scanPeriod="3 seconds"

  debug="false">

  <property file="${APP_CONFIG_DIR}/application.properties" />

  <!-- pod specific -->

  <!--  specify the component name -->

  <property name="componentName"    value="logdemo"></property> <!-- make variable -->

  <property name="subComponentName" value="logdemonode"></property> <!--  make variable -->

 

  <!-- ONAP common -->

  <!--  specify the base path of the log directory - set logDirRoot environment variable in k8s or at the container level - default to "/var" -->

  <property name="logDirPrefix"    value="${LOG_DIR_ROOT_PREFIX}/log/onap"></property>

  <property name="auditLogLevel"   value="${AUDIT_LOG_LEVEL}"></property>

  <property name="debugLogLevel"   value="${DEBUG_LOG_LEVEL}"></property>

  <property name="metricsLogLevel" value="${METRICS_LOG_LEVEL}"></property>

  <property name="errorLogLevel"   value="${ERROR_LOG_LEVEL}"></property>

  <!-- The directories where logs are written -->

  <property name="logDirectory"      value="${logDirPrefix}/${componentName}/${subComponentName}" />

  <!-- Can easily relocate debug logs by modifying this path. -->

  <property name="debugLogDirectory" value="${logDirPrefix}/${componentName}/${subComponentName}" />

  <!-- property name="generalLogName" value="application" /--> <!--  see error.log -->

  <property name="errorLogName"   value="error" />

  <property name="metricsLogName" value="metrics" />

  <property name="auditLogName"   value="audit" />

  <property name="debugLogName"   value="debug" />

  <property name="queueSize"      value="256" />

  <property name="maxFileSize"    value="50MB" />

  <property name="maxHistory"     value="30" />

  <property name="totalSizeCap"   value="10GB" /> 

  

  <!-- MDC and MARKER specific for Cassablanca -->

  <property name="LogTimestamp"   value="%d{&quot;yyyy-MM-dd'T'HH:mm:ss.SSSXXX&quot;, UTC}"/>

  <property name="Level"          value="%.-5level"/>

  <property name="Logger"         value="%logger"/>

  <property name="Mdc"            value="%replace(%replace(%mdc){'\t','\\\\t'}){'\n','\\\\n'}"/>

  <property name="Message"        value="%replace(%replace(%msg){'\t','\\\\t'}){'\n','\\\\n'}"/>

  <!-- 30th field slated for Dublin release only -->

  <property name="RootException"  value="%replace(%replace(%rootException){'\t', '\\\\t'}){'\n','\\\\n'}"/>

  <property name="Marker"         value="%replace(%replace(%marker){'\t','\\\\t'}){'\n','\\\\n'}"/>

  <property name="Thread"         value="%thread"/>

 

  <!-- ONAP uses tabs, ACUMOS uses pipes -->

  <property name="ONAP_Delimiter"   value="\t\t" />

  <property name="ACUMOS_Delimiter" value="|" />

  <property name="delim"            value="${ONAP_Delimiter}" />

  <!-- indexed  -->

  <!--  for Casablanca we support both position dependent pipe delimited - and position independent KVP MDCs -->

  <property name="p_1_LogTimestamp"       value="${LogTimestamp}" />

  <property name="p_2_EntryTimestamp"     value="%X{EntryTimestamp}" />

  <property name="p_3_InvokeTimestamp"    value="%X{InvokeTimestamp}" />

  <property name="p_4_RequestID"          value="%X{RequestId}" />

  <property name="p_5_InvocationID"       value="%X{InvocationId}" />

  <property name="p_6_InstanceID"         value="%X{InstanceUUID}" /> <!--  previously InstanceUUID -->

  <property name="p_7_ServiceInstanceID"  value="%X{ServiceInstanceId}" />

  <property name="p_8_thread"             value="${Thread}" />

  <property name="p_9_ServiceName"        value="%X{ServiceName}" />

  <property name="p_10_PartnerName"       value="%X{PartnerName}" />

  <property name="p_11_StatusCode"        value="%X{StatusCode}" />

  <property name="p_12_ResponseCode"      value="%X{ResponseCode}" />

  <property name="p_13_ResponseDesc"      value="%X{ResponseDesc}" />

  <property name="p_14_level"             value="${Level}" />

  <property name="p_15_Severity"          value="%X{Severity}" />

  <property name="p_16_ServerIPAddress"   value="%X{ServerIPAddress}" />

  <property name="p_17_ElapsedTime"       value="%X{ElapsedTime}" />

  <property name="p_18_ServerFQDN"        value="%X{ServerFQDN}" />

  <property name="p_19_ClientIPAddress"   value="%X{ClientIPAddress}" />

  <property name="p_20_VirtualServerName" value="%X{VirtualServerName}" />

  <property name="p_21_ContextName"       value="%X{ContextName}" />

  <property name="p_22_TargetEntity"      value="%X{TargetEntity}" />

  <property name="p_23_TargetServiceName" value="%X{TargetServiceName}" />

  <property name="p_24_TargetElement"     value="%X{TargetElement}" />

  <property name="p_25_User"              value="%X{User}" />

  <property name="p_26_logger"            value="${Logger}" />

  <property name="p_27_mdc"               value="${Mdc}" />

  <property name="p_28_message"           value="${Message}" />

  <property name="p_29_marker"            value="${Marker}" />

 

  

  <property name="pattern"

    value="%nopexception${p_1_LogTimestamp}${delim}${p_2_EntryTimestamp}${delim}${p_3_InvokeTimestamp}${delim}${p_4_RequestID}${delim}${p_5_InvocationID}${delim}${p_6_InstanceID}${delim}${p_7_ServiceInstanceID}${delim}${p_8_thread}${delim}${p_9_ServiceName}${delim}${p_10_PartnerName}${delim}${p_11_StatusCode}${delim}${p_12_ResponseCode}${delim}${p_13_ResponseDesc}${delim}${p_14_level}${delim}${p_15_Severity}${delim}${p_16_ServerIPAddress}${delim}${p_17_ElapsedTime}${delim}${p_18_ServerFQDN}${delim}${p_19_ClientIPAddress}${delim}${p_20_VirtualServerName}${delim}${p_21_ContextName}${delim}${p_22_TargetEntity}${delim}${p_23_TargetServiceName}${delim}${p_24_TargetElement}${delim}${p_25_User}${delim}${p_26_logger}${delim}${p_27_mdc}${delim}${p_28_message}${delim}${p_29_marker}%n" />

 

  <!-- 4 log files -->

  <property name="auditLoggerPattern"

    value="${pattern}" />

  <property name="metricsLoggerPattern"

    value="${pattern}" />

  <property name="errorLoggerPattern"

    value="${pattern}" /> 

  <property name="debugLoggerPattern"

    value="${pattern}" />

  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">

    <encoder>

      <pattern>${errorLoggerPattern}</pattern>

    </encoder>

  </appender>

 

  <!-- ============================================================================ -->

  <!-- EELF Appenders -->

  <!-- ============================================================================ -->

  <appender name="EELFAudit" class="ch.qos.logback.core.rolling.RollingFileAppender">

    <file>${logDirectory}/${auditLogName}.log</file>

    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">

      <!-- daily rollover -->

      <fileNamePattern>${logDirectory}/${auditLogName}.%d{yyyy-MM-dd}.log.zip</fileNamePattern>

      <!-- keep 30 days' worth of history capped at 3GB total size -->

      <maxHistory>30</maxHistory>

      <totalSizeCap>3GB</totalSizeCap>

    </rollingPolicy>

    <encoder>

      <pattern>${auditLoggerPattern}</pattern>

    </encoder>

  </appender>

 <appender name="asyncEELFAudit" class="ch.qos.logback.classic.AsyncAppender">

    <queueSize>256</queueSize>

    <includeCallerData>true</includeCallerData>

    <appender-ref ref="EELFAudit" />

  </appender>

  <appender name="EELFMetrics" class="ch.qos.logback.core.rolling.RollingFileAppender">

    <file>${logDirectory}/${metricsLogName}.log</file>

    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">

      <!-- daily rollover -->

      <fileNamePattern>${logDirectory}/${metricsLogName}.%d{yyyy-MM-dd}.log.zip</fileNamePattern>

      <!-- keep 30 days' worth of history capped at 3GB total size -->

      <maxHistory>30</maxHistory>

      <totalSizeCap>3GB</totalSizeCap>

    </rollingPolicy>

    <encoder>

      <pattern>${metricsLoggerPattern}</pattern>

    </encoder>

  </appender>

  <appender name="asyncEELFMetrics" class="ch.qos.logback.classic.AsyncAppender">

    <queueSize>256</queueSize>

    <appender-ref ref="EELFMetrics"/>

  </appender>

  <appender name="EELFError" class="ch.qos.logback.core.rolling.RollingFileAppender">

    <file>${logDirectory}/${errorLogName}.log</file>

    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">

      <!-- daily rollover -->

      <fileNamePattern>${logDirectory}/${errorLogName}.%d{yyyy-MM-dd}.log.zip</fileNamePattern>

      <!-- keep 30 days' worth of history capped at 3GB total size -->

      <maxHistory>30</maxHistory>

      <totalSizeCap>3GB</totalSizeCap>

    </rollingPolicy>

    <encoder>

      <pattern>${errorLoggerPattern}</pattern>

    </encoder>

  </appender>

  <appender name="asyncEELFError" class="ch.qos.logback.classic.AsyncAppender">

    <queueSize>256</queueSize>

    <includeCallerData>true</includeCallerData>

    <appender-ref ref="EELFError"/>

  </appender>

  <appender name="EELFDebug" class="ch.qos.logback.core.rolling.RollingFileAppender">

    <file>${debugLogDirectory}/${debugLogName}.log</file>

    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">

      <!-- daily rollover -->

      <fileNamePattern>${logDirectory}/${debugLogName}.%d{yyyy-MM-dd}.log.zip</fileNamePattern>

      <!-- keep 30 days' worth of history capped at 3GB total size -->

      <maxHistory>30</maxHistory>

      <totalSizeCap>3GB</totalSizeCap>

    </rollingPolicy>

    <encoder>

      <pattern>${defaultLoggerPattern}</pattern>

    </encoder>

  </appender>

  <appender name="asyncEELFDebug" class="ch.qos.logback.classic.AsyncAppender">

    <queueSize>256</queueSize>

    <includeCallerData>true</includeCallerData>

    <appender-ref ref="EELFDebug" />

  </appender>

 

  <logger name="org.onap.eelf.audit" level="${auditLogLevel}" additivity="false">

    <appender-ref ref="asyncEELFAudit" />

  </logger>

  <logger name="org.onap.eelf.debug" level="${debugLogLevel}" additivity="false">

    <appender-ref ref="asyncEELFDebug" />

  </logger>

  <logger name="org.onap.eelf.error" level="${errorLogLevel}" additivity="false">

    <appender-ref ref="asyncEELFError" />

  </logger>

  <logger name="org.onap.eelf.metrics" level="${metricsLogLevel}" additivity="false">

    <appender-ref ref="asyncEELFMetrics" />

  </logger>

 

  <root level="INFO">

    <appender-ref ref="asyncEELFAudit" />

  </root>

</configuration>

From: VENKATESH KUMAR, VIJAY <vv770d@...>
Sent: Tuesday, January 15, 2019 9:37 AM
To: Jaszczyk, Piotr (Nokia - PL/Wroclaw) <piotr.jaszczyk@...>; Michael O'Brien <Frank.Obrien@...>
Cc: Janiak, Kornel (Nokia - PL/Wroclaw) <kornel.janiak@...>; Krzywka, Filip (Nokia - PL/Wroclaw) <filip.krzywka@...>; Dudycz, Jakub (Nokia - PL/Wroclaw) <jakub.dudycz@...>
Subject: RE: Logging in HV-VES

 

Hi Piotr,  The changes looks good to me; wiki might need to be corrected.

 

@OBRIEN, FRANK MICHAEL – If there is any concern, please let us know. Otherwise, hope you can help updating the wiki to include the correct pattern.

 

Thanks,

Vijay

 

From: Jaszczyk, Piotr (Nokia - PL/Wroclaw) <piotr.jaszczyk@...>
Sent: Tuesday, January 15, 2019 4:10 AM
To: VENKATESH KUMAR, VIJAY <vv770d@...>; OBRIEN, FRANK MICHAEL <frank.obrien@...>
Cc: Janiak, Kornel (Nokia - PL/Wroclaw) <kornel.janiak@...>; Krzywka, Filip (Nokia - PL/Wroclaw) <filip.krzywka@...>; Dudycz, Jakub (Nokia - PL/Wroclaw) <jakub.dudycz@...>
Subject: Re: Logging in HV-VES

 

Hi Vijay, Frank,

 

Thank you Vijay for prompt answer.

 

When using the logback logging pattern from this wiki page logs looks like this:

 

org.onap.dcae.collectors.veshv.main |2019-01-15T08:19:45.125Z |INFO |\|U\|s\|i\|n\|g\| \|c\|o\|n\|f\|i\|g\|u\|r\|a\|t\|i\|o\|n\|:\| \|S\|e\|r\|v\|e\|r\|C\|o\|n\|f\|i\|g\|u\|r\|a\|t\|i\|o\|n\|(\|s\|e\|r\|v\|e\|r\|L\|i\|s\|t\|e\|n\|A\|d\|d\|r\|e\|s\|s\|=\|0\|.\|0\|.\|0\|.\|0\|/\|0\|.\|0\|.\|0\|.\|0\|:\|6\|0\|6\|1\|,\| \|k\|a\|f\|k\|a\|C\|o\|n\|f\|i\|g\|u\|r\|a\|t\|i\|o\|n\|=\|K\|a\|f\|k\|a\|C\|o\|n\|f\|i\|g\|u\|r\|a\|t\|i\|o\|n\|(\|b\|o\|o\|t\|s\|t\|r\|a\|p\|S\|e\|r\|v\|e\|r\|s\|=\|m\|e\|s\|s\|a\|g\|e\|-\|r\|o\|u\|t\|e\|r\|-\|k\|a\|f\|k\|a\|:\|9\|0\|9\|2\|,\| \|m\|a\|x\|i\|m\|a\|l\|R\|e\|q\|u\|e\|s\|t\|S\|i\|z\|e\|B\|y\|t\|e\|s\|=\|1\|0\|4\|8\|5\|7\|6\|)\|,\| \|c\|o\|n\|f\|i\|g\|u\|r\|a\|t\|i\|o\|n\|P\|r\|o\|v\|i\|d\|e\|r\|P\|a\|r\|a\|m\|s\|=\|C\|o\|n\|f\|i\|g\|u\|r\|a\|t\|i\|o\|n\|P\|r\|o\|v\|i\|d\|e\|r\|P\|a\|r\|a\|m\|s\|(\|c\|o\|n\|f\|i\|g\|u\|r\|a\|t\|i\|o\|n\|U\|r\|l\|=\|h\|t\|t\|p\|:\|/\|/\|c\|o\|n\|s\|u\|l\|-\|s\|e\|r\|v\|e\|r\|:\|8\|5\|0\|0\|/\|v\|1\|/\|k\|v\|/\|v\|e\|s\|h\|v\|-\|c\|o\|n\|f\|i\|g\|?\|r\|a\|w\|=\|t\|r\|u\|e\|,\| \|f\|i\|r\|s\|t\|R\|e\|q\|u\|e\|s\|t\|D\|e\|l\|a\|y\|=\|P\|T\|2\|S\|,\| \|r\|e\|q\|u\|e\|s\|t\|I\|n\|t\|e\|r\|v\|a\|l\|=\|P\|T\|5\|S\|)\|,\| \|s\|e\|c\|u\|r\|i\|t\|y\|C\|o\|n\|f\|i\|g\|u\|r\|a\|t\|i\|o\|n\|=\|S\|e\|c\|u\|r\|i\|t\|y\|C\|o\|n\|f\|i\|g\|u\|r\|a\|t\|i\|o\|n\|(\|s\|s\|l\|D\|i\|s\|a\|b\|l\|e\|=\|f\|a\|l\|s\|e\|,\| \|k\|e\|y\|s\|=\|S\|o\|m\|e\|(\|J\|d\|k\|K\|e\|y\|s\|(\|k\|e\|y\|S\|t\|o\|r\|e\|=\|(\|)\| \|-\|>\| \|j\|a\|v\|a\|.\|i\|o\|.\|F\|i\|l\|e\|I\|n\|p\|u\|t\|S\|t\|r\|e\|a\|m\|,\| \|k\|e\|y\|S\|t\|o\|r\|e\|P\|a\|s\|s\|w\|o\|r\|d\|=\|[\|C\|@\|c\|9\|4\|f\|d\|3\|0\|,\| \|t\|r\|u\|s\|t\|S\|t\|o\|r\|e\|=\|(\|)\| \|-\|>\| \|j\|a\|v\|a\|.\|i\|o\|.\|F\|i\|l\|e\|I\|n\|p\|u\|t\|S\|t\|r\|e\|a\|m\|,\| \|t\|r\|u\|s\|t\|S\|t\|o\|r\|e\|P\|a\|s\|s\|w\|o\|r\|d\|=\|[\|C\|@\|3\|6\|3\|2\|8\|d\|3\|3\|)\|)\|)\|,\| \|i\|d\|l\|e\|T\|i\|m\|e\|o\|u\|t\|=\|P\|T\|1\|M\|,\| \|h\|e\|a\|l\|t\|h\|C\|h\|e\|c\|k\|A\|p\|i\|L\|i\|s\|t\|e\|n\|A\|d\|d\|r\|e\|s\|s\|=\|0\|.\|0\|.\|0\|.\|0\|/\|0\|.\|0\|.\|0\|.\|0\|:\|6\|0\|6\|0\|,\| \|m\|a\|x\|i\|m\|u\|m\|P\|a\|y\|l\|o\|a\|d\|S\|i\|z\|e\|B\|y\|t\|e\|s\|=\|1\|0\|4\|8\|5\|7\|6\|,\| \|l\|o\|g\|L\|e\|v\|e\|l\|=\|D\|E\|B\|U\|G\|,\| \|d\|u\|m\|m\|y\|M\|o\|d\|e\|=\|f\|a\|l\|s\|e\|)\| |\| |\| |\| |main |

 

I believe this is not what is desired :)

 

Should we use the following pattern instead?

 

    <property name="p_log" value="%logger"/>
    <property name="p_tim" value="%date{yyyy-MM-dd'T'HH:mm:ss.SSSXXX,UTC}"/>
    <property name="p_lvl" value="%level"/>
    <property name="p_msg" value="%replace(%replace(%msg){'\t', '\\\\t'}){'\n','\\\\n'}"/>
    <property name="p_mdc" value="%replace(%replace(%mdc){'\t', '\\\\t'}){'\n', '\\\\n'}"/>
    <property name="p_exc" value="%replace(%replace(%rootException){'\t', '\\\\t'}){'\n','\\\\n'}"/>
    <property name="p_mak" value="%replace(%replace(%marker){'\t', '\\\\t'}){'\n','\\\\n'}"/>
    <property name="p_thr" value="%thread"/>

    <property name="ONAP_LOG_PATTERN" value="%nopexception${p_log}|${p_tim}|${p_lvl}|${p_msg}|${p_mdc}|${p_exc}|${p_mak}|${p_thr}%n"/>

 

Which produces messages in a format (new lines added for readability):

org.onap.dcae.collectors.veshv.impl.socket.NettyTcpServer

|2019-01-15T09:01:26.856Z

|DEBUG

|Client connection request received

|RequestID=a55bc8aa-5f40-46c5-a3c2-f15585606956, InstanceID=cda7041f-a60b-484d-afdd-dc799a97b24d, InvocationID=afe456ed-f46a-4149-93ef-86d59722836d, PartnerName=C=PL, ST=DL, L=Wroclaw, O=Nokia, OU=MANO, CN=dcaegen2-hvves-client, StatusCode=INPROGRESS, ClientIPAddress=172.18.0.9, ServerFQDN=f2ff31ee0a0b

|

|ENTRY

|reactor-tcp-nio-2

 

Which looks more like an example log from wiki:

org.onap.example.component1.subcomponent1.LogbackTest
|2017-08-06T16:09:03.594Z
|ERROR
|Here's an error, that's usually bad
|key1=value1, key2=value2 with space, key5=value5"with"quotes, key3=value3\nwith\nnewlines, key4=value4\twith\ttabs
|java.lang.RuntimeException: Here's Johnny
\n\tat org.onap.example.component1.subcomponent1.LogbackTest.main(LogbackTest.java:24)
\nWrapped by: java.lang.RuntimeException: Little pigs, little pigs, let me come in
\n\tat org.onap.example.component1.subcomponent1.LogbackTest.main(LogbackTest.java:27)
|AMarker1
|main

Is it OK with both of you?

 

BR,

Peter

 

 

--

Piotr Jaszczyk
Technical Leader, Software Development
Nokia
Poland, Wrocław, West Gate


From: VENKATESH KUMAR, VIJAY <vv770d@...>
Sent: Monday, January 14, 2019 5:32:29 PM
To: Jaszczyk, Piotr (Nokia - PL/Wroclaw); OBRIEN, FRANK MICHAEL
Cc: Janiak, Kornel (Nokia - PL/Wroclaw); Krzywka, Filip (Nokia - PL/Wroclaw)
Subject: RE: Logging in HV-VES

 

Hi Peter J,   Please find my comments inline.

 

Hi @OBRIEN, FRANK MICHAEL  - Please review/confirm #3 Q&A below.

 

Thanks,

Vijay

 

From: Jaszczyk, Piotr (Nokia - PL/Wroclaw) <piotr.jaszczyk@...>
Sent: Monday, January 14, 2019 2:36 AM
To: VENKATESH KUMAR, VIJAY <vv770d@...>
Cc: Janiak, Kornel (Nokia - PL/Wroclaw) <kornel.janiak@...>; Krzywka, Filip (Nokia - PL/Wroclaw) <filip.krzywka@...>
Subject: Logging in HV-VES

 

Hi Vijay,

 

I'm writing in regard to your comment [1]. I've a few questions.

 

1. Should we use logback configuration as presented after "In logback, this looks like" at linked wiki page [2] ? That is:

 

<property name="defaultPattern" value="%nopexception%logger

|%date{yyyy-MM-dd'T'HH:mm:ss.SSSXXX,UTC}

|%level

|%replace(%replace(%replace(%message){'\t','\\\\t'}){'\n','\\\\n'}){'|','\\\\|'}

|%replace(%replace(%replace(%mdc){'\t','\\\\t'}){'\n','\\\\n'}){'|','\\\\|'}

|%replace(%replace(%replace(%rootException){'\t','\\\\t'}){'\n','\\\\n'}){'|','\\\\|'}

|%replace(%replace(%replace(%marker){'\t','\\\\t'}){'\n','\\\\n'}){'|','\\\\|'}

|%thread

|%n"/>

[Vijay] – Yes; as this seems to be recommendation from Logging team.

 

2. As the ONAP logging format is not very human readable we proposed an optimization. We assume that filebeat-collector is used to collect logs from the file (/var/log/ONAP/<component>[/<subcomponent>]/*.log) and feeds them to the ELK stack. If that is true, it means that console logs can be a bit more human (developer & operator) readable while keeping file logs machine readable. What do you think: can we use standard ONAP logging pattern for FILE appender and more readable version for CONSOLE appender? [3]

[Vijay] – Having separate pattern for FILE and CONSOLE is not desirable, but should be fine for short-term if the information presented is more readable for troubleshooting. Ideally we would want them both in-sync; if there is any recommendation to improve the logging pattern itself – please suggest to the logging team.

 

3. At the time of writing the code we have found many examples of "proper" logback configuration for Dublin, but now it looks like Dublin stays with Casablanca logging specification [4]. Is that true?

[Vijay]-  I believe v1.2 (ONAP Application Logging Specification v1.2) will be used by projects for Dublin; there is no new revision’s I’m aware. Looping @OBRIEN, FRANK MICHAEL -  Logging PTL to confirm.

 

I’m eager to receive your feedback,

Peter J

 

[1] https://gerrit.onap.org/r/#/c/74812/8/docs/sections/services/ves-hv/troubleshooting.rst

[2] https://wiki.onap.org/pages/viewpage.action?pageId=28378955#ONAPApplicationLoggingSpecificationv1.2(Casablanca)-TextOutput

[3] https://wiki.onap.org/pages/viewpage.action?pageId=28378955#ONAPApplicationLoggingSpecificationv1.2(Casablanca)-OutputLocation

[4] https://wiki.onap.org/display/DW/Active+Logging+Specifications

 

--

Piotr Jaszczyk
Technical Leader, Software Development
Nokia
Poland, Wrocław, West Gate

This email and the information contained herein is proprietary and confidential and subject to the Amdocs Email Terms of Service, which you may review at https://www.amdocs.com/about/email-terms-of-service

Join onap-discuss@lists.onap.org to automatically receive all group messages.