search

kdgregory / log4j-aws-appenders

Appenders for Log4J 1.2.x, Log4J 2.x, and Logback that write to AWS destinations.
Apache License 2.0
67 stars 18 forks source link

writer initialization timed out #169

Closed RajeshMca1404 closed 1 year ago

RajeshMca1404 commented 1 year ago

Dear Kd,

We are trying to use Kinesis appender. Provided the proper configuration Log4J. But still getting the WrapperListener_start_runner ERROR writer initialization timed out.

Used trouble shooting guide also. but not getting the exact reason for timeout. Should not be firewall or security group because we are using sdk in one of the java program.

    <KinesisAppender name="KinesisAppender">
        <streamName>xxxxxxxxxxxxxxxx</streamName>
         <partitionKey>1234</partitionKey>
         <assumedRole>xxxxxxxxxxxx</assumedRole>
         <batchDelay>500</batchDelay>
         <autoCreate>true</autoCreate>
         <shardCount>1</shardCount>
         <synchronous>true</synchronous>
         <retentionPeriod>25</retentionPeriod>
         <discardAction>newest</discardAction>
          <clientRegion>us-west-2</clientRegion>
         <clientEndpoint>xxxx</clientEndpoint>
         <JsonLayout complete="false" compact="true" eventEol="true" properties="true" locationInfo="true">
            <KeyValuePair key="applicationName" value="test-log4j-aws-appender" />
            <KeyValuePair key="environment" value="dev" />
            <KeyValuePair key="processId" value="${awslogs:pid}" />
            <KeyValuePair key="hostname" value="${awslogs:hostname}" />
            <KeyValuePair key="timestamp" value="$${date:yyyy-MM-dd'T'HH:mm:ss.SSS'Z'}" />
        </JsonLayout>
    </KinesisAppender>

POM file dependency

com.mulesoft.modules mule-secure-configuration-property-module 1.2.3 mule-plugin com.kdgregory.logging logwriters ${kdgregory.version} com.kdgregory.logging log4j2-aws-appenders ${kdgregory.version} com.kdgregory.logging aws-facade-v2 ${kdgregory.version} software.amazon.awssdk iam ${aws-sdk-v2.version} software.amazon.awssdk cloudwatchlogs ${aws-sdk-v2.version} software.amazon.awssdk sns ${aws-sdk-v2.version} Dependency Tree is following +- com.mulesoft.modules:mule-secure-configuration-property-module:jar:mule-plugin:1.2.3:compile [INFO] | \- org.mule:mule-encryption:jar:1.2.1:compile [INFO] +- com.kdgregory.logging:logwriters:jar:3.0.2:compile [INFO] +- org.mule.connectors:mule-http-connector:jar:mule-plugin:1.7.1:compile [INFO] | +- org.mule.modules:mule-module-cors-kernel:jar:1.1.2:compile [INFO] | \- org.apache.commons:commons-text:jar:1.9:compile [INFO] +- org.mule.connectors:mule-sockets-connector:jar:mule-plugin:1.2.2:compile [INFO] | +- org.mule.sdk:mule-sdk-api:jar:0.3.0:compile [INFO] | +- commons-io:commons-io:jar:2.11.0:compile [INFO] | \- org.apache.commons:commons-lang3:jar:3.12.0:compile [INFO] +- com.kdgregory.logging:log4j2-aws-appenders:jar:3.0.2:compile [INFO] +- com.kdgregory.logging:aws-facade-v2:jar:3.0.2:compile [INFO] +- org.apache.logging.log4j:log4j-jcl:jar:2.17.2:compile [INFO] | \- commons-logging:commons-logging:jar:1.2:compile [INFO] +- org.apache.logging.log4j:log4j-slf4j-impl:jar:2.17.2:compile [INFO] | \- org.slf4j:slf4j-api:jar:1.7.25:compile [INFO] +- software.amazon.awssdk:iam:jar:2.17.201:compile [INFO] | +- software.amazon.awssdk:aws-query-protocol:jar:2.17.201:compile [INFO] | +- software.amazon.awssdk:protocol-core:jar:2.17.201:compile [INFO] | +- software.amazon.awssdk:sdk-core:jar:2.17.201:compile [INFO] | | \- org.reactivestreams:reactive-streams:jar:1.0.3:compile [INFO] | +- software.amazon.awssdk:auth:jar:2.17.201:compile [INFO] | | +- software.amazon.awssdk:json-utils:jar:2.17.201:compile [INFO] | | \- software.amazon.eventstream:eventstream:jar:1.0.1:compile [INFO] | +- software.amazon.awssdk:http-client-spi:jar:2.17.201:compile [INFO] | +- software.amazon.awssdk:regions:jar:2.17.201:compile [INFO] | +- software.amazon.awssdk:annotations:jar:2.17.201:compile [INFO] | +- software.amazon.awssdk:utils:jar:2.17.201:compile [INFO] | +- software.amazon.awssdk:aws-core:jar:2.17.201:compile [INFO] | +- software.amazon.awssdk:metrics-spi:jar:2.17.201:compile [INFO] | +- software.amazon.awssdk:apache-client:jar:2.17.201:runtime [INFO] | \- software.amazon.awssdk:netty-nio-client:jar:2.17.201:runtime [INFO] | +- io.netty:netty-codec-http:jar:4.1.77.Final:runtime [INFO] | +- io.netty:netty-codec-http2:jar:4.1.77.Final:runtime [INFO] | +- io.netty:netty-codec:jar:4.1.77.Final:runtime [INFO] | +- io.netty:netty-transport:jar:4.1.77.Final:runtime [INFO] | | \- io.netty:netty-resolver:jar:4.1.77.Final:runtime [INFO] | +- io.netty:netty-common:jar:4.1.77.Final:runtime [INFO] | +- io.netty:netty-buffer:jar:4.1.77.Final:runtime [INFO] | +- io.netty:netty-handler:jar:4.1.77.Final:runtime [INFO] | +- io.netty:netty-transport-classes-epoll:jar:4.1.77.Final:runtime [INFO] | | \- io.netty:netty-transport-native-unix-common:jar:4.1.77.Final:runtime [INFO] | \- com.typesafe.netty:netty-reactive-streams-http:jar:2.0.5:runtime [INFO] | \- com.typesafe.netty:netty-reactive-streams:jar:2.0.5:runtime [INFO] +- software.amazon.awssdk:cloudwatchlogs:jar:2.17.201:compile [INFO] | \- software.amazon.awssdk:aws-json-protocol:jar:2.17.201:compile [INFO] | \- software.amazon.awssdk:third-party-jackson-core:jar:2.17.201:compile [INFO] +- software.amazon.awssdk:sns:jar:2.17.201:compile [INFO] +- com.fasterxml.jackson.dataformat:jackson-dataformat-cbor:jar:2.9.8:compile [INFO] | \- com.fasterxml.jackson.core:jackson-core:jar:2.9.8:compile [INFO] +- org.apache.logging.log4j:log4j-api:jar:2.17.2:compile [INFO] +- org.apache.logging.log4j:log4j-core:jar:2.17.2:compile [INFO] +- javax.servlet:javax.servlet-api:jar:3.0.1:provided [INFO] +- org.apache.httpcomponents:httpclient:jar:4.5.13:compile [INFO] | +- org.apache.httpcomponents:httpcore:jar:4.4.13:compile [INFO] | \- commons-codec:commons-codec:jar:1.11:compile [INFO] +- software.amazon.awssdk:sts:jar:2.17.201:compile [INFO] | \- software.amazon.awssdk:profiles:jar:2.17.201:compile [INFO] +- software.amazon.awssdk:kinesis:jar:2.17.201:compile [INFO] | \- software.amazon.awssdk:aws-cbor-protocol:jar:2.17.201:compile [INFO] | \- software.amazon.awssdk:third-party-jackson-dataformat-cbor:jar:2.17.201:compile [INFO] \- org.mule.modules:mule-apikit-module:jar:mule-plugin:1.6.1:compile [INFO] +- io.projectreactor:reactor-core:jar:3.2.0.M1:compile [INFO] +- org.mule.apikit:parser-service:jar:2.3.1:compile [INFO] | +- org.mule.apikit:raml-parser-interface:jar:2.3.1:compile [INFO] | +- org.mule.apikit:raml-parser-interface-impl-v1:jar:2.3.1:compile [INFO] | | +- org.raml:raml-parser:jar:0.8.43:compile [INFO] | | | +- org.yaml:snakeyaml:jar:1.26:compile [INFO] | | | +- commons-lang:commons-lang:jar:2.6:compile [INFO] | | | +- commons-beanutils:commons-beanutils:jar:1.9.4:compile [INFO] | | | | \- commons-collections:commons-collections:jar:3.2.2:compile [INFO] | | | +- com.github.java-json-tools:json-schema-validator:jar:2.2.8:compile [INFO] | | | | +- com.github.java-json-tools:json-schema-core:jar:1.2.8:compile [INFO] | | | | | +- com.github.fge:jackson-coreutils:jar:1.8:compile [INFO] | | | | | | \- com.github.fge:msg-simple:jar:1.1:compile [INFO] | | | | | | \- com.github.fge:btf:jar:1.2:compile [INFO] | | | | | \- com.github.fge:uri-template:jar:0.9:compile [INFO] | | | | +- joda-time:joda-time:jar:2.9.7:compile [INFO] | | | | +- com.googlecode.libphonenumber:libphonenumber:jar:8.0.0:compile [INFO] | | | | \- net.sf.jopt-simple:jopt-simple:jar:5.0.3:compile [INFO] | | | +- com.sun.mail:jakarta.mail:jar:1.6.3:compile [INFO] | | | \- com.googlecode.juniversalchardet:juniversalchardet:jar:1.0.3:compile [INFO] | | \- org.mozilla:rhino:jar:1.7.14:compile [INFO] | +- org.mule.apikit:raml-parser-interface-impl-v2:jar:2.3.1:compile [INFO] | | \- org.raml:raml-parser-2:jar:1.0.44-2:compile [INFO] | | +- org.raml:yagi:jar:1.0.44-2:compile [INFO] | | | \- com.google.code.findbugs:annotations:jar:3.0.0:compile [INFO] | | +- org.apache.ws.xmlschema:xmlschema-core:jar:2.2.1:compile [INFO] | | +- javax.json:javax.json-api:jar:1.0:compile [INFO] | | \- org.glassfish:javax.json:jar:1.0.4:compile [INFO] | +- org.mule.apikit:raml-parser-interface-impl-amf:jar:2.3.1:compile [INFO] | | +- com.googlecode.json-simple:json-simple:jar:1.1.1:compile [INFO] | | +- com.github.amlorg:amf-client_2.12:jar:4.7.8-4:compile [INFO] | | | +- org.scala-lang:scala-library:jar:2.12.11:compile [INFO] | | | +- com.github.amlorg:amf-webapi_2.12:jar:4.7.8-4:compile [INFO] | | | | +- com.github.everit-org.json-schema:org.everit.json.schema:jar:1.12.2:compile [INFO] | | | | | +- commons-validator:commons-validator:jar:1.6:compile [INFO] | | | | | | \- commons-digester:commons-digester:jar:1.8.1:compile [INFO] | | | | | +- com.damnhandy:handy-uri-templates:jar:2.1.8:compile [INFO] | | | | | \- com.google.re2j:re2j:jar:1.3:compile [INFO] | | | | +- com.github.amlorg:amf-core_2.12:jar:4.2.225-0:compile [INFO] | | | | | \- org.mule.syaml:syaml_2.12:jar:1.1.305:compile [INFO] | | | | | \- org.mule.common:scala-common_2.12:jar:1.0.83:compile [INFO] | | | | \- com.github.amlorg:amf-custom-validation_2.12:jar:5.1.10-1:compile [INFO] | | | | \- com.github.amlorg:amf-aml_2.12:jar:5.1.10-1:compile [INFO] | | | | \- com.github.amlorg:amf-validation_2.12:jar:5.1.10-1:compile [INFO] | | | | +- org.json4s:json4s-native_2.12:jar:3.5.4:compile [INFO] | | | | | \- org.json4s:json4s-core_2.12:jar:3.5.4:compile [INFO] | | | | | +- org.json4s:json4s-ast_2.12:jar:3.5.4:compile [INFO] | | | | | +- org.json4s:json4s-scalap_2.12:jar:3.5.4:compile [INFO] | | | | | +- com.thoughtworks.paranamer:paranamer:jar:2.8:compile [INFO] | | | | | \- org.scala-lang.modules:scala-xml_2.12:jar:1.0.6:compile [INFO] | | | | +- org.apache.jena:jena-shacl:jar:3.14.0:compile [INFO] | | | | | \- org.apache.jena:jena-arq:jar:3.14.0:compile [INFO] | | | | | +- org.apache.jena:jena-core:jar:3.14.0:compile [INFO] | | | | | | +- org.apache.jena:jena-iri:jar:3.14.0:compile [INFO] | | | | | | +- commons-cli:commons-cli:jar:1.4:compile [INFO] | | | | | | \- org.apache.jena:jena-base:jar:3.14.0:compile [INFO] | | | | | | +- org.apache.commons:commons-csv:jar:1.7:compile [INFO] | | | | | | \- com.github.andrewoma.dexx:collection:jar:0.7:compile [INFO] | | | | | +- org.apache.jena:jena-shaded-guava:jar:3.14.0:compile [INFO] | | | | | +- com.github.jsonld-java:jsonld-java:jar:0.12.5:compile [INFO] | | | | | \- org.apache.httpcomponents:httpclient-cache:jar:4.5.10:compile [INFO] | | | | +- org.apache.thrift:libthrift:jar:0.14.1:compile [INFO] | | | | | \- javax.annotation:javax.annotation-api:jar:1.3.2:compile [INFO] | | | | \- org.apache.commons:commons-compress:jar:1.21:compile [INFO] | | | +- com.github.scopt:scopt_2.12:jar:3.7.0:compile [INFO] | | | +- org.reflections:reflections:jar:0.9.12:compile [INFO] | | | | \- org.javassist:javassist:jar:3.26.0-GA:compile [INFO] | | | \- org.scala-lang.modules:scala-java8-compat_2.12:jar:0.8.0:compile [INFO] | | +- org.mule.amf:amf-xml-extension_2.12:jar:1.7.5:compile [INFO] | | | \- com.rackspace.apache:xerces2-xsd11:jar:2.11.2:compile [INFO] | | | +- com.rackspace.eclipse.webtools.sourceediting:org.eclipse.wst.xml.xpath2.processor:jar:2.1.100:compile [INFO] | | | | \- edu.princeton.cup:java-cup:jar:10k:compile [INFO] | | | \- xml-resolver:xml-resolver:jar:1.2:compile [INFO] | | \- com.ibm.icu:icu4j:jar:71.1:compile [INFO] | \- org.json:json:jar:20220320:compile [INFO] +- commons-fileupload:commons-fileupload:jar:1.4:compile [INFO] +- org.apache.httpcomponents:httpmime:jar:4.5.13:compile [INFO] +- com.google.guava:guava:jar:28.1-jre:compile [INFO] | +- com.google.guava:failureaccess:jar:1.0.1:compile [INFO] | +- com.google.guava:listenablefuture:jar:9999.0-empty-to-avoid-conflict-with-guava:compile [INFO] | +- com.google.code.findbugs:jsr305:jar:3.0.2:compile [INFO] | +- org.checkerframework:checker-qual:jar:2.8.1:compile [INFO] | +- com.google.errorprone:error_prone_annotations:jar:2.3.2:compile [INFO] | +- com.google.j2objc:j2objc-annotations:jar:1.3:compile [INFO] | \- org.codehaus.mojo:animal-sniffer-annotations:jar:1.18:compile [INFO] +- com.fasterxml.jackson.core:jackson-annotations:jar:2.13.2:compile [INFO] +- com.fasterxml.jackson.core:jackson-databind:jar:2.13.2.1:compile [INFO] \- com.fasterxml.jackson.module:jackson-module-jsonSchema:jar:2.13.2:compile [INFO] \- javax.validation:validation-api:jar:1.1.0.Final:compile
kdgregory commented 1 year ago

I am currently working on changes that will provide more information about startup timeouts, and also changes the appender so that it doesn't wait for the writer to start (prompted by #167). However, given the time that I am currently able to dedicate to the project, I don't expect it to be released until early December.

You don't show the output from the internal log, so I can't comment on what might be happening. I do see that you have a custom endpoint configured, so would confirm that the other SDK client code is using the same endpoint.

I also see that you've updated the code yourself (com.kdgregory.logging:logwriters:jar:3.0.2:compile), so if you're comfortable doing that you can delete the block that waits for the writer to initialize (search for waitUntilInitialized) in AbstractAppender.

RajeshMca1404 commented 1 year ago

Dear KD,

Here are the logs below. i have changed version to just add few extra logs where it is failing and there is no other intention. Can you please check logs below and suggest

2022-11-16 11:58:38,722 WrapperListener_start_runner DEBUG Starting LoggerContext[name=domain/default/app/demo-kinesis-aws-appender, org.mule.runtime.module.launcher.log4j2.MuleLoggerContext@2b2d3318]... 2022-11-16 11:58:38,722 WrapperListener_start_runner DEBUG Starting LoggerContext[name=domain/default/app/demo-kinesis-aws-appender, org.mule.runtime.module.launcher.log4j2.MuleLoggerContext@2b2d3318]... 2022-11-16 11:58:38,722 WrapperListener_start_runner DEBUG Reconfiguration started for context[name=domain/default/app/demo-kinesis-aws-appender] at URI file:/C:/RajeshK/Anypoint7/AnypointStudio/plugins/org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955/mule/apps/demo-kinesis-aws-appender/log4j2.xml (org.mule.runtime.module.launcher.log4j2.MuleLoggerContext@2b2d3318) with optional ClassLoader: null 2022-11-16 11:58:38,722 WrapperListener_start_runner DEBUG Reconfiguration started for context[name=domain/default/app/demo-kinesis-aws-appender] at URI file:/C:/RajeshK/Anypoint7/AnypointStudio/plugins/org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955/mule/apps/demo-kinesis-aws-appender/log4j2.xml (org.mule.runtime.module.launcher.log4j2.MuleLoggerContext@2b2d3318) with optional ClassLoader: null 2022-11-16 11:58:38,723 WrapperListener_start_runner DEBUG Using configurationFactory org.apache.logging.log4j.core.config.ConfigurationFactory$Factory@7e754258 2022-11-16 11:58:38,723 WrapperListener_start_runner DEBUG Using configurationFactory org.apache.logging.log4j.core.config.ConfigurationFactory$Factory@7e754258 2022-11-16 11:58:38,727 Thread Context Data Task DEBUG Initializing Thread Context Data Service Providers 2022-11-16 11:58:38,727 Thread Context Data Task DEBUG Initializing Thread Context Data Service Providers 2022-11-16 11:58:38,727 Thread Context Data Task DEBUG Thread Context Data Service Provider initialization complete 2022-11-16 11:58:38,727 Thread Context Data Task DEBUG Thread Context Data Service Provider initialization complete 2022-11-16 11:58:38,744 WrapperListener_start_runner DEBUG Not in a ServletContext environment, thus not loading WebLookup plugin. 2022-11-16 11:58:38,744 WrapperListener_start_runner DEBUG Not in a ServletContext environment, thus not loading WebLookup plugin. 2022-11-16 11:58:43,053 WrapperListener_start_runner DEBUG Closing FileInputStream java.io.FileInputStream@3805bd6e 2022-11-16 11:58:43,053 WrapperListener_start_runner DEBUG Closing FileInputStream java.io.FileInputStream@3805bd6e 2022-11-16 11:58:43,063 WrapperListener_start_runner DEBUG Apache Log4j Core 2.17.1 initializing configuration XmlConfiguration[location=C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml] 2022-11-16 11:58:43,063 WrapperListener_start_runner DEBUG Apache Log4j Core 2.17.1 initializing configuration XmlConfiguration[location=C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml] 2022-11-16 11:58:43,065 WrapperListener_start_runner DEBUG Installed 1 script engine 2022-11-16 11:58:43,065 WrapperListener_start_runner DEBUG Installed 1 script engine 2022-11-16 11:58:43,073 WrapperListener_start_runner DEBUG Oracle Nashorn version: 1.8.0_332, language: ECMAScript, threading: Not Thread Safe, compile: true, names: [nashorn, Nashorn], factory class: jdk.nashorn.api.scripting.NashornScriptEngineFactory 2022-11-16 11:58:43,073 WrapperListener_start_runner DEBUG Oracle Nashorn version: 1.8.0_332, language: ECMAScript, threading: Not Thread Safe, compile: true, names: [nashorn, Nashorn], factory class: jdk.nashorn.api.scripting.NashornScriptEngineFactory 2022-11-16 11:58:43,115 WrapperListener_start_runner DEBUG Took 0.036805 seconds to load 4 plugins from package com.kdgregory.log4j2.aws 2022-11-16 11:58:43,115 WrapperListener_start_runner DEBUG Took 0.036805 seconds to load 4 plugins from package com.kdgregory.log4j2.aws 2022-11-16 11:58:43,116 WrapperListener_start_runner DEBUG PluginManager 'Core' found 131 plugins 2022-11-16 11:58:43,116 WrapperListener_start_runner DEBUG PluginManager 'Core' found 131 plugins 2022-11-16 11:58:43,116 WrapperListener_start_runner DEBUG PluginManager 'Level' found 0 plugins 2022-11-16 11:58:43,116 WrapperListener_start_runner DEBUG PluginManager 'Level' found 0 plugins 2022-11-16 11:58:43,120 WrapperListener_start_runner DEBUG PluginManager 'Lookup' found 17 plugins 2022-11-16 11:58:43,120 WrapperListener_start_runner DEBUG PluginManager 'Lookup' found 17 plugins 2022-11-16 11:58:43,139 WrapperListener_start_runner DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.PatternLayout]. 2022-11-16 11:58:43,139 WrapperListener_start_runner DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.PatternLayout]. 2022-11-16 11:58:43,140 WrapperListener_start_runner DEBUG PatternLayout$Builder(pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} %-5p [%t] %c - %m%n", PatternSelector=null, Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml), Replace=null, charset="null", alwaysWriteExceptions="null", disableAnsi="null", noConsoleNoAnsi="null", header="null", footer="null") 2022-11-16 11:58:43,140 WrapperListener_start_runner DEBUG PatternLayout$Builder(pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} %-5p [%t] %c - %m%n", PatternSelector=null, Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml), Replace=null, charset="null", alwaysWriteExceptions="null", disableAnsi="null", noConsoleNoAnsi="null", header="null", footer="null") 2022-11-16 11:58:43,140 WrapperListener_start_runner DEBUG PluginManager 'Converter' found 47 plugins 2022-11-16 11:58:43,140 WrapperListener_start_runner DEBUG PluginManager 'Converter' found 47 plugins 2022-11-16 11:58:43,141 WrapperListener_start_runner DEBUG Building Plugin[name=appender, class=org.apache.logging.log4j.core.appender.ConsoleAppender]. 2022-11-16 11:58:43,141 WrapperListener_start_runner DEBUG Building Plugin[name=appender, class=org.apache.logging.log4j.core.appender.ConsoleAppender]. 2022-11-16 11:58:43,142 WrapperListener_start_runner DEBUG ConsoleAppender$Builder(target="null", follow="null", direct="null", bufferedIo="null", bufferSize="null", immediateFlush="null", ignoreExceptions="null", PatternLayout(%d{yyyy-MM-dd HH:mm:ss.SSS} %-5p [%t] %c - %m%n), name="CONSOLE", Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml), Filter=null, ={}) 2022-11-16 11:58:43,142 WrapperListener_start_runner DEBUG ConsoleAppender$Builder(target="null", follow="null", direct="null", bufferedIo="null", bufferSize="null", immediateFlush="null", ignoreExceptions="null", PatternLayout(%d{yyyy-MM-dd HH:mm:ss.SSS} %-5p [%t] %c - %m%n), name="CONSOLE", Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml), Filter=null, ={}) 2022-11-16 11:58:43,147 WrapperListener_start_runner DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.PatternLayout]. 2022-11-16 11:58:43,147 WrapperListener_start_runner DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.PatternLayout]. 2022-11-16 11:58:43,148 WrapperListener_start_runner DEBUG PatternLayout$Builder(pattern="%-5p %d [%t] [processor: %X{processorPath}; event: %X{correlationId}] %c: %m%n", PatternSelector=null, Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml), Replace=null, charset="null", alwaysWriteExceptions="null", disableAnsi="null", noConsoleNoAnsi="null", header="null", footer="null") 2022-11-16 11:58:43,148 WrapperListener_start_runner DEBUG PatternLayout$Builder(pattern="%-5p %d [%t] [processor: %X{processorPath}; event: %X{correlationId}] %c: %m%n", PatternSelector=null, Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml), Replace=null, charset="null", alwaysWriteExceptions="null", disableAnsi="null", noConsoleNoAnsi="null", header="null", footer="null") 2022-11-16 11:58:43,149 WrapperListener_start_runner DEBUG Building Plugin[name=SizeBasedTriggeringPolicy, class=org.apache.logging.log4j.core.appender.rolling.SizeBasedTriggeringPolicy]. 2022-11-16 11:58:43,149 WrapperListener_start_runner DEBUG Building Plugin[name=SizeBasedTriggeringPolicy, class=org.apache.logging.log4j.core.appender.rolling.SizeBasedTriggeringPolicy]. 2022-11-16 11:58:43,149 WrapperListener_start_runner DEBUG createPolicy(size="10 MB") 2022-11-16 11:58:43,149 WrapperListener_start_runner DEBUG createPolicy(size="10 MB") 2022-11-16 11:58:43,150 WrapperListener_start_runner DEBUG Building Plugin[name=DefaultRolloverStrategy, class=org.apache.logging.log4j.core.appender.rolling.DefaultRolloverStrategy]. 2022-11-16 11:58:43,150 WrapperListener_start_runner DEBUG Building Plugin[name=DefaultRolloverStrategy, class=org.apache.logging.log4j.core.appender.rolling.DefaultRolloverStrategy]. 2022-11-16 11:58:43,151 WrapperListener_start_runner DEBUG DefaultRolloverStrategy$Builder(max="10", min="null", fileIndex="null", compressionLevel="null", ={}, stopCustomActionsOnError="null", tempCompressedFilePattern="null", Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml)) 2022-11-16 11:58:43,151 WrapperListener_start_runner DEBUG DefaultRolloverStrategy$Builder(max="10", min="null", fileIndex="null", compressionLevel="null", ={}, stopCustomActionsOnError="null", tempCompressedFilePattern="null", Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml)) 2022-11-16 11:58:43,152 WrapperListener_start_runner DEBUG Building Plugin[name=appender, class=org.apache.logging.log4j.core.appender.RollingFileAppender]. 2022-11-16 11:58:43,152 WrapperListener_start_runner DEBUG Building Plugin[name=appender, class=org.apache.logging.log4j.core.appender.RollingFileAppender]. 2022-11-16 11:58:43,155 WrapperListener_start_runner DEBUG RollingFileAppender$Builder(fileName="C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\logs\demo-kinesis-aws-appender.log", filePattern="C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\logs\demo-kinesis-aws-appender-%i.log", append="null", locking="null", SizeBasedTriggeringPolicy(SizeBasedTriggeringPolicy(size=10485760)), DefaultRolloverStrategy(DefaultRolloverStrategy(min=1, max=10, useMax=true)), advertise="null", advertiseUri="null", createOnDemand="null", filePermissions="null", fileOwner="null", fileGroup="null", bufferedIo="null", bufferSize="null", immediateFlush="null", ignoreExceptions="null", PatternLayout(%-5p %d [%t] [processor: %X{processorPath}; event: %X{correlationId}] %c: %m%n), name="file", Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml), Filter=null, ={}) 2022-11-16 11:58:43,155 WrapperListener_start_runner DEBUG RollingFileAppender$Builder(fileName="C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\logs\demo-kinesis-aws-appender.log", filePattern="C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\logs\demo-kinesis-aws-appender-%i.log", append="null", locking="null", SizeBasedTriggeringPolicy(SizeBasedTriggeringPolicy(size=10485760)), DefaultRolloverStrategy(DefaultRolloverStrategy(min=1, max=10, useMax=true)), advertise="null", advertiseUri="null", createOnDemand="null", filePermissions="null", fileOwner="null", fileGroup="null", bufferedIo="null", bufferSize="null", immediateFlush="null", ignoreExceptions="null", PatternLayout(%-5p %d [%t] [processor: %X{processorPath}; event: %X{correlationId}] %c: %m%n), name="file", Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml), Filter=null, ={}) 2022-11-16 11:58:43,189 WrapperListener_start_runner DEBUG Returning file creation time for C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\logs\demo-kinesis-aws-appender.log 2022-11-16 11:58:43,189 WrapperListener_start_runner DEBUG Returning file creation time for C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\logs\demo-kinesis-aws-appender.log 2022-11-16 11:58:43,190 WrapperListener_start_runner DEBUG Starting RollingFileManager C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\logs\demo-kinesis-aws-appender.log 2022-11-16 11:58:43,190 WrapperListener_start_runner DEBUG Starting RollingFileManager C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\logs\demo-kinesis-aws-appender.log 2022-11-16 11:58:43,191 WrapperListener_start_runner DEBUG PluginManager 'FileConverter' found 2 plugins 2022-11-16 11:58:43,191 WrapperListener_start_runner DEBUG PluginManager 'FileConverter' found 2 plugins 2022-11-16 11:58:43,191 WrapperListener_start_runner DEBUG Setting prev file time to 2022-10-28T18:00:45.370-0700 2022-11-16 11:58:43,191 WrapperListener_start_runner DEBUG Setting prev file time to 2022-10-28T18:00:45.370-0700 2022-11-16 11:58:43,192 WrapperListener_start_runner DEBUG Initializing triggering policy SizeBasedTriggeringPolicy(size=10485760) 2022-11-16 11:58:43,192 WrapperListener_start_runner DEBUG Initializing triggering policy SizeBasedTriggeringPolicy(size=10485760) 2022-11-16 11:58:43,192 WrapperListener_start_runner DEBUG Building Plugin[name=KeyValuePair, class=org.apache.logging.log4j.core.util.KeyValuePair]. 2022-11-16 11:58:43,192 WrapperListener_start_runner DEBUG Building Plugin[name=KeyValuePair, class=org.apache.logging.log4j.core.util.KeyValuePair]. 2022-11-16 11:58:43,195 WrapperListener_start_runner DEBUG KeyValuePair$Builder(key="applicationName", value="test-log4j-aws-appender") 2022-11-16 11:58:43,195 WrapperListener_start_runner DEBUG KeyValuePair$Builder(key="applicationName", value="test-log4j-aws-appender") 2022-11-16 11:58:43,195 WrapperListener_start_runner DEBUG Building Plugin[name=KeyValuePair, class=org.apache.logging.log4j.core.util.KeyValuePair]. 2022-11-16 11:58:43,195 WrapperListener_start_runner DEBUG Building Plugin[name=KeyValuePair, class=org.apache.logging.log4j.core.util.KeyValuePair]. 2022-11-16 11:58:43,196 WrapperListener_start_runner DEBUG KeyValuePair$Builder(key="environment", value="dev") 2022-11-16 11:58:43,196 WrapperListener_start_runner DEBUG KeyValuePair$Builder(key="environment", value="dev") 2022-11-16 11:58:43,196 WrapperListener_start_runner DEBUG Building Plugin[name=KeyValuePair, class=org.apache.logging.log4j.core.util.KeyValuePair]. 2022-11-16 11:58:43,196 WrapperListener_start_runner DEBUG Building Plugin[name=KeyValuePair, class=org.apache.logging.log4j.core.util.KeyValuePair]. 2022-11-16 11:58:43,198 WrapperListener_start_runner DEBUG KeyValuePair$Builder(key="processId", value="1580") 2022-11-16 11:58:43,198 WrapperListener_start_runner DEBUG KeyValuePair$Builder(key="processId", value="1580") 2022-11-16 11:58:43,199 WrapperListener_start_runner DEBUG Building Plugin[name=KeyValuePair, class=org.apache.logging.log4j.core.util.KeyValuePair]. 2022-11-16 11:58:43,199 WrapperListener_start_runner DEBUG Building Plugin[name=KeyValuePair, class=org.apache.logging.log4j.core.util.KeyValuePair]. 2022-11-16 11:58:43,200 WrapperListener_start_runner DEBUG KeyValuePair$Builder(key="hostname", value="V0188-CON-D056") 2022-11-16 11:58:43,200 WrapperListener_start_runner DEBUG KeyValuePair$Builder(key="hostname", value="V0188-CON-D056") 2022-11-16 11:58:43,200 WrapperListener_start_runner DEBUG Building Plugin[name=KeyValuePair, class=org.apache.logging.log4j.core.util.KeyValuePair]. 2022-11-16 11:58:43,200 WrapperListener_start_runner DEBUG Building Plugin[name=KeyValuePair, class=org.apache.logging.log4j.core.util.KeyValuePair]. 2022-11-16 11:58:43,200 WrapperListener_start_runner DEBUG KeyValuePair$Builder(key="timestamp", value="${date:yyyy-MM-dd'T'HH:mm:ss.SSS'Z'}") 2022-11-16 11:58:43,200 WrapperListener_start_runner DEBUG KeyValuePair$Builder(key="timestamp", value="${date:yyyy-MM-dd'T'HH:mm:ss.SSS'Z'}") 2022-11-16 11:58:43,200 WrapperListener_start_runner DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.JsonLayout]. 2022-11-16 11:58:43,200 WrapperListener_start_runner DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.JsonLayout]. 2022-11-16 11:58:43,209 WrapperListener_start_runner DEBUG JsonLayout$Builder(propertiesAsList="null", objectMessageAsJsonObject="null", ={applicationName=test-log4j-aws-appender, environment=dev, processId=1580, hostname=V0188-CON-D056, timestamp=${date:yyyy-MM-dd'T'HH:mm:ss.SSS'Z'}}, eventEol="true", endOfLine="null", compact="true", complete="false", locationInfo="true", properties="true", includeStacktrace="null", stacktraceAsString="null", includeNullDelimiter="null", includeTimeMillis="null", ={}, charset="null", footerSerializer=null, headerSerializer=null, Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml), footer="null", header="null") 2022-11-16 11:58:43,209 WrapperListener_start_runner DEBUG JsonLayout$Builder(propertiesAsList="null", objectMessageAsJsonObject="null", ={applicationName=test-log4j-aws-appender, environment=dev, processId=1580, hostname=V0188-CON-D056, timestamp=${date:yyyy-MM-dd'T'HH:mm:ss.SSS'Z'}}, eventEol="true", endOfLine="null", compact="true", complete="false", locationInfo="true", properties="true", includeStacktrace="null", stacktraceAsString="null", includeNullDelimiter="null", includeTimeMillis="null", ={}, charset="null", footerSerializer=null, headerSerializer=null, Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml), footer="null", header="null") 2022-11-16 11:58:43,335 WrapperListener_start_runner DEBUG Building Plugin[name=appender, class=com.kdgregory.log4j2.aws.KinesisAppender]. 2022-11-16 11:58:43,335 WrapperListener_start_runner DEBUG Building Plugin[name=appender, class=com.kdgregory.log4j2.aws.KinesisAppender]. 2022-11-16 11:58:43,347 WrapperListener_start_runner DEBUG KinesisAppender$KinesisAppenderBuilder(name="KinesisAppender", streamName="xxxxxxxx", partitionKey="1234", autoCreate="true", shardCount="1", retentionPeriod="25", JsonLayout(org.apache.logging.log4j.core.layout.JsonLayout@6977fcc0), Filter=null, Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml), synchronous="true", batchDelay="500", truncateOversizeMessages="null", discardThreshold="null", discardAction="newest", assumedRole="xxxxxxxxxxxxxxxx", clientFactory="null", clientRegion="xxxxxxxxx", clientEndpoint="xxxxxxxxxxxxxxx", useShutdownHook="null") 2022-11-16 11:58:43,347 WrapperListener_start_runner DEBUG KinesisAppender$KinesisAppenderBuilder(name="KinesisAppender", streamName="xxxxxxxxxxxxxxxxxxx", partitionKey="1234", autoCreate="true", shardCount="1", retentionPeriod="25", JsonLayout(org.apache.logging.log4j.core.layout.JsonLayout@6977fcc0), Filter=null, Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml), synchronous="true", batchDelay="500", truncateOversizeMessages="null", discardThreshold="null", discardAction="newest", assumedRole="xxxxxxxxxxxxxxxx", clientFactory="null", clientRegion="xxxxxxxxx", clientEndpoint="xxxxxxxxxx", useShutdownHook="null") 2022-11-16 11:58:43,354 WrapperListener_start_runner DEBUG Building Plugin[name=appenders, class=org.apache.logging.log4j.core.config.AppendersPlugin]. 2022-11-16 11:58:43,354 WrapperListener_start_runner DEBUG Building Plugin[name=appenders, class=org.apache.logging.log4j.core.config.AppendersPlugin]. 2022-11-16 11:58:43,355 WrapperListener_start_runner DEBUG createAppenders(={CONSOLE, file, com.kdgregory.log4j2.aws.KinesisAppender with name KinesisAppender}) 2022-11-16 11:58:43,355 WrapperListener_start_runner DEBUG createAppenders(={CONSOLE, file, com.kdgregory.log4j2.aws.KinesisAppender with name KinesisAppender}) 2022-11-16 11:58:43,356 WrapperListener_start_runner DEBUG Building Plugin[name=AppenderRef, class=org.apache.logging.log4j.core.config.AppenderRef]. 2022-11-16 11:58:43,356 WrapperListener_start_runner DEBUG Building Plugin[name=AppenderRef, class=org.apache.logging.log4j.core.config.AppenderRef]. 2022-11-16 11:58:43,356 WrapperListener_start_runner DEBUG createAppenderRef(ref="KinesisAppender", level="null", Filter=null) 2022-11-16 11:58:43,356 WrapperListener_start_runner DEBUG createAppenderRef(ref="KinesisAppender", level="null", Filter=null) 2022-11-16 11:58:43,357 WrapperListener_start_runner DEBUG Building Plugin[name=asyncLogger, class=org.apache.logging.log4j.core.async.AsyncLoggerConfig]. 2022-11-16 11:58:43,357 WrapperListener_start_runner DEBUG Building Plugin[name=asyncLogger, class=org.apache.logging.log4j.core.async.AsyncLoggerConfig]. 2022-11-16 11:58:43,358 WrapperListener_start_runner DEBUG createLogger(additivity="true", level="INFO", name="logger.kinesis", includeLocation="null", ={KinesisAppender}, ={}, Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml), Filter=null) 2022-11-16 11:58:43,358 WrapperListener_start_runner DEBUG createLogger(additivity="true", level="INFO", name="logger.kinesis", includeLocation="null", ={KinesisAppender}, ={}, Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml), Filter=null) 2022-11-16 11:58:43,358 WrapperListener_start_runner DEBUG Building Plugin[name=loggers, class=org.apache.logging.log4j.core.config.LoggersPlugin]. 2022-11-16 11:58:43,358 WrapperListener_start_runner DEBUG Building Plugin[name=loggers, class=org.apache.logging.log4j.core.config.LoggersPlugin]. 2022-11-16 11:58:43,359 WrapperListener_start_runner DEBUG createLoggers(={logger.kinesis}) 2022-11-16 11:58:43,359 WrapperListener_start_runner DEBUG createLoggers(={logger.kinesis}) 2022-11-16 11:58:43,359 WrapperListener_start_runner WARN No Root logger was configured, creating default ERROR-level Root logger with Console appender 2022-11-16 11:58:43,359 WrapperListener_start_runner WARN No Root logger was configured, creating default ERROR-level Root logger with Console appender 2022-11-16 11:58:43,365 WrapperListener_start_runner DEBUG Starting OutputStreamManager SYSTEM_OUT.false.false-7 2022-11-16 11:58:43,365 WrapperListener_start_runner DEBUG Starting OutputStreamManager SYSTEM_OUT.false.false-7 2022-11-16 11:58:43,365 WrapperListener_start_runner DEBUG Configuration XmlConfiguration[location=C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml] initialized 2022-11-16 11:58:43,365 WrapperListener_start_runner DEBUG Configuration XmlConfiguration[location=C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml] initialized 2022-11-16 11:58:43,365 WrapperListener_start_runner DEBUG Starting configuration XmlConfiguration[location=C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml] 2022-11-16 11:58:43,365 WrapperListener_start_runner DEBUG Starting configuration XmlConfiguration[location=C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml] 2022-11-16 11:58:43,367 WrapperListener_start_runner DEBUG Starting AsyncLoggerConfig disruptor for this configuration with ringbufferSize=4096, waitStrategy=TimeoutBlockingWaitStrategy, exceptionHandler=org.mule.runtime.module.launcher.api.log4j2.AsyncLoggerExceptionHandler@a9e6d61... 2022-11-16 11:58:43,367 WrapperListener_start_runner DEBUG Starting AsyncLoggerConfig disruptor for this configuration with ringbufferSize=4096, waitStrategy=TimeoutBlockingWaitStrategy, exceptionHandler=org.mule.runtime.module.launcher.api.log4j2.AsyncLoggerExceptionHandler@a9e6d61... 2022-11-16 11:58:43,419 com-kdgregory-aws-logwriter-log4j2-kinesis-1 DEBUG log writer starting (thread: com-kdgregory-aws-logwriter-log4j2-kinesis-1) 2022-11-16 11:58:43,419 com-kdgregory-aws-logwriter-log4j2-kinesis-1 DEBUG log writer starting (thread: com-kdgregory-aws-logwriter-log4j2-kinesis-1) 2022-11-16 12:02:43,491 WrapperListener_start_runner ERROR writer initialization timed out 2022-11-16 12:02:43,491 WrapperListener_start_runner ERROR writer initialization timed out 2022-11-16 12:02:43,496 WrapperListener_start_runner DEBUG Started configuration XmlConfiguration[location=C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml] OK. 2022-11-16 12:02:43,496 WrapperListener_start_runner DEBUG Started configuration XmlConfiguration[location=C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml] OK. 2022-11-16 12:02:43,499 WrapperListener_start_runner DEBUG Shutting down OutputStreamManager SYSTEM_OUT.false.false-7 2022-11-16 12:02:43,499 WrapperListener_start_runner DEBUG Shutting down OutputStreamManager SYSTEM_OUT.false.false-7 2022-11-16 12:02:43,499 WrapperListener_start_runner DEBUG OutputStream closed 2022-11-16 12:02:43,499 WrapperListener_start_runner DEBUG OutputStream closed 2022-11-16 12:02:43,500 WrapperListener_start_runner DEBUG Shut down OutputStreamManager SYSTEM_OUT.false.false-7, all resources released: true 2022-11-16 12:02:43,500 WrapperListener_start_runner DEBUG Shut down OutputStreamManager SYSTEM_OUT.false.false-7, all resources released: true 2022-11-16 12:02:43,500 WrapperListener_start_runner DEBUG Appender DefaultConsole-7 stopped with status true 2022-11-16 12:02:43,500 WrapperListener_start_runner DEBUG Appender DefaultConsole-7 stopped with status true 2022-11-16 12:02:43,514 WrapperListener_start_runner DEBUG Shutting down OutputStreamManager SYSTEM_OUT.false.false-6 2022-11-16 12:02:43,514 WrapperListener_start_runner DEBUG Shutting down OutputStreamManager SYSTEM_OUT.false.false-6 2022-11-16 12:02:43,515 WrapperListener_start_runner DEBUG OutputStream closed 2022-11-16 12:02:43,515 WrapperListener_start_runner DEBUG OutputStream closed 2022-11-16 12:02:43,516 WrapperListener_start_runner DEBUG Shut down OutputStreamManager SYSTEM_OUT.false.false-6, all resources released: true 2022-11-16 12:02:43,516 WrapperListener_start_runner DEBUG Shut down OutputStreamManager SYSTEM_OUT.false.false-6, all resources released: true 2022-11-16 12:02:43,517 WrapperListener_start_runner DEBUG Appender DefaultConsole-6 stopped with status true 2022-11-16 12:02:43,517 WrapperListener_start_runner DEBUG Appender DefaultConsole-6 stopped with status true 2022-11-16 12:02:43,517 WrapperListener_start_runner DEBUG Stopped org.apache.logging.log4j.core.config.DefaultConfiguration@71a3e94d OK 2022-11-16 12:02:43,517 WrapperListener_start_runner DEBUG Stopped org.apache.logging.log4j.core.config.DefaultConfiguration@71a3e94d OK 2022-11-16 12:02:43,518 WrapperListener_start_runner DEBUG JMX disabled for Log4j2. Not registering MBeans. 2022-11-16 12:02:43,518 WrapperListener_start_runner DEBUG JMX disabled for Log4j2. Not registering MBeans. 2022-11-16 12:02:43,518 WrapperListener_start_runner DEBUG Reconfiguration complete for context[name=domain/default/app/demo-kinesis-aws-appender] at URI C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml (org.mule.runtime.module.launcher.log4j2.MuleLoggerContext@2b2d3318) with optional ClassLoader: null 2022-11-16 12:02:43,518 WrapperListener_start_runner DEBUG Reconfiguration complete for context[name=domain/default/app/demo-kinesis-aws-appender] at URI C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml (org.mule.runtime.module.launcher.log4j2.MuleLoggerContext@2b2d3318) with optional ClassLoader: null 2022-11-16 12:02:43,518 WrapperListener_start_runner DEBUG Shutdown hook enabled. Registering a new one. 2022-11-16 12:02:43,518 WrapperListener_start_runner DEBUG Shutdown hook enabled. Registering a new one. 2022-11-16 12:02:43,519 WrapperListener_start_runner DEBUG LoggerContext[name=domain/default/app/demo-kinesis-aws-appender, org.mule.runtime.module.launcher.log4j2.MuleLoggerContext@2b2d3318] started OK. 2022-11-16 12:02:43,519 WrapperListener_start_runner DEBUG LoggerContext[name=domain/default/app/demo-kinesis-aws-appender, org.mule.runtime.module.launcher.log4j2.MuleLoggerContext@2b2d3318] started OK. 2022-11-16 12:02:49,806 com-kdgregory-aws-logwriter-log4j2-kinesis-1 WARN The Logger software.amazon.awssdk.http.apache.internal.conn.SdkTlsSocketFactory was created with the message factory org.apache.logging.log4j.message.ReusableMessageFactory@54ee8120 and is now requested with the message factory org.apache.logging.log4j.message.ReusableMessageFactory@24f8485e, which may create log events with unexpected formatting. 2022-11-16 12:02:49,806 com-kdgregory-aws-logwriter-log4j2-kinesis-1 WARN The Logger software.amazon.awssdk.http.apache.internal.conn.SdkTlsSocketFactory was created with the message factory org.apache.logging.log4j.message.ReusableMessageFactory@54ee8120 and is now requested with the message factory org.apache.logging.log4j.message.ReusableMessageFactory@24f8485e, which may create log events with unexpected formatting. 2022-11-16 12:02:52,204 com-kdgregory-aws-logwriter-log4j2-kinesis-1 DEBUG log writer initialization complete (thread: com-kdgregory-aws-logwriter-log4j2-kinesis-1) 2022-11-16 12:02:52,204 com-kdgregory-aws-logwriter-log4j2-kinesis-1 DEBUG log writer initialization complete (thread: com-kdgregory-aws-logwriter-log4j2-kinesis-1) INFO 2022-11-16 12:04:08,582 [ArtifactDeployer.start.01] org.mule.runtime.core.internal.logging.LogUtil:

RajeshMca1404 commented 1 year ago

Dear KD,

I have shared the logs on git hub in same issue. Can you please check. I have removed that block but still it is not send ing the logs to kinesis.

This is very important for my job. Your help will be appreciated. This is the first problem given to me in new job. Please help.

Regards

On Wed, Nov 16, 2022 at 6:05 AM Keith Gregory @.***> wrote:

I am currently working on changes that will provide more information about startup timeouts, and also changes the appender so that it doesn't wait for the writer to start (prompted by #167 https://github.com/kdgregory/log4j-aws-appenders/issues/167). However, given the time that I am currently able to dedicate to the project, I don't expect it to be released until early December.

You don't show the output from the internal log, so I can't comment on what might be happening. I do see that you have a custom endpoint configured, so would confirm that the other SDK client code is using the same endpoint.

I also see that you've updated the code yourself (com.kdgregory.logging:logwriters:jar:3.0.2:compile), so if you're comfortable doing that you can delete the block that waits for the writer to initialize (search for waitUntilInitialized) in AbstractAppender.

— Reply to this email directly, view it on GitHub https://github.com/kdgregory/log4j-aws-appenders/issues/169#issuecomment-1316817668, or unsubscribe https://github.com/notifications/unsubscribe-auth/A4DJ524DXZ4AWGRO4SVGR7DWIS5W3ANCNFSM6AAAAAASBWDQBE . You are receiving this because you authored the thread.Message ID: @.***>

kdgregory commented 1 year ago

There were some things that I noticed in the log. But first, some things that you need to understand:

  1. This is not my problem. Aside from the general caveats of open-source software, this problem is happening in your environment, with a custom build of the library (as evidenced by the version number in your earlier post). I do not have access to that environment or know what customizations you or your team has made.

  2. I have limited time for this project. Basically, an hour a day, in the morning. Time that could either be used to respond to your messages, or to improve the library as a whole. And even if you discover a clear and easily solvable bug, it will be weeks before I release a new version of the library.

  3. In order to get help, you need to provide clear and accurate information. For example, you said "I have removed that block," without saying which block you removed. It can't be the wait in AbstractAppender, because I still see the message "writer initialization timed out" in the log (at timestamp 12:02:43,491).

With that out of the way, one thing jumps out at me from the log that you sent: you set the synchronous property to true. This is almost certainly a bad idea, because it blocks the appender until the logwriter can send a batch of messages. It also sends the batch on the invoking thread rather the writer thread, which could cause a race condition.

I also saw a message that the writer initialization started at 11:58:43,419 and completed at 12:02:52,204. This is far longer than expected, especially since you're not creating a new stream (even though you've set the autoCreate property to true, I don't see the messages that indicate the logwriter needs to create a stream).

All of which makes me wonder if you're running in a Lambda, in particular, one with a low memory allocation (and therefore a low CPU allocation). There are a lot of issues with running multi-threaded code in a Lambda (you can read my blog post), and I don't believe that my library is appropriate for that environment.

RajeshMca1404 commented 1 year ago

Dear KD,

Thanks for quick reply. To make things clear now. I am now using 3.0.1 original version. And changed to Asynchronous. I am not using Lamda. I am running this on my local standalone box. I have increased the JVM memory also by adding -XX:PermSize=512m -XX:MaxPermSize=1024m. Still it is giving memory time out. Please check the log below.

2022-11-17 08:39:44,125 WrapperListener_start_runner DEBUG PluginManager 'Converter' found 47 plugins 2022-11-17 08:39:44,126 WrapperListener_start_runner DEBUG Starting OutputStreamManager SYSTEM_OUT.false.false-5 2022-11-17 08:39:44,128 WrapperListener_start_runner DEBUG Starting LoggerContext[name=domain/default/app/demo-kinesis-aws-appender, org.mule.runtime.module.launcher.log4j2.MuleLoggerContext@55b51024]... 2022-11-17 08:39:44,131 WrapperListener_start_runner DEBUG Reconfiguration started for context[name=domain/default/app/demo-kinesis-aws-appender] at URI file:/C:/RajeshK/Anypoint7/AnypointStudio/plugins/org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955/mule/apps/demo-kinesis-aws-appender/log4j2.xml (org.mule.runtime.module.launcher.log4j2.MuleLoggerContext@55b51024) with optional ClassLoader: null 2022-11-17 08:39:44,132 WrapperListener_start_runner DEBUG Using configurationFactory org.apache.logging.log4j.core.config.ConfigurationFactory$Factory@1bae0617 2022-11-17 08:39:44,139 Thread Context Data Task DEBUG Initializing Thread Context Data Service Providers 2022-11-17 08:39:44,140 Thread Context Data Task DEBUG Thread Context Data Service Provider initialization complete 2022-11-17 08:39:44,151 WrapperListener_start_runner DEBUG Not in a ServletContext environment, thus not loading WebLookup plugin. 2022-11-17 08:39:47,602 WrapperListener_start_runner DEBUG Closing FileInputStream java.io.FileInputStream@386711f1 2022-11-17 08:39:47,617 WrapperListener_start_runner DEBUG Apache Log4j Core 2.17.1 initializing configuration XmlConfiguration[location=C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml] 2022-11-17 08:39:47,620 WrapperListener_start_runner DEBUG Installed 1 script engine 2022-11-17 08:39:47,630 WrapperListener_start_runner DEBUG Oracle Nashorn version: 1.8.0_332, language: ECMAScript, threading: Not Thread Safe, compile: true, names: [nashorn, Nashorn], factory class: jdk.nashorn.api.scripting.NashornScriptEngineFactory 2022-11-17 08:39:47,729 WrapperListener_start_runner DEBUG Took 0.093834 seconds to load 4 plugins from package com.kdgregory.log4j2.aws 2022-11-17 08:39:47,730 WrapperListener_start_runner DEBUG PluginManager 'Core' found 131 plugins 2022-11-17 08:39:47,730 WrapperListener_start_runner DEBUG PluginManager 'Level' found 0 plugins 2022-11-17 08:39:47,733 WrapperListener_start_runner DEBUG PluginManager 'Lookup' found 17 plugins 2022-11-17 08:39:47,749 WrapperListener_start_runner DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.PatternLayout]. 2022-11-17 08:39:47,750 WrapperListener_start_runner DEBUG PatternLayout$Builder(pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} %-5p [%t] %c - %m%n", PatternSelector=null, Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml), Replace=null, charset="null", alwaysWriteExceptions="null", disableAnsi="null", noConsoleNoAnsi="null", header="null", footer="null") 2022-11-17 08:39:47,751 WrapperListener_start_runner DEBUG PluginManager 'Converter' found 47 plugins 2022-11-17 08:39:47,752 WrapperListener_start_runner DEBUG Building Plugin[name=appender, class=org.apache.logging.log4j.core.appender.ConsoleAppender]. 2022-11-17 08:39:47,752 WrapperListener_start_runner DEBUG ConsoleAppender$Builder(target="null", follow="null", direct="null", bufferedIo="null", bufferSize="null", immediateFlush="null", ignoreExceptions="null", PatternLayout(%d{yyyy-MM-dd HH:mm:ss.SSS} %-5p [%t] %c - %m%n), name="CONSOLE", Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml), Filter=null, ={}) 2022-11-17 08:39:47,765 WrapperListener_start_runner DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.PatternLayout]. 2022-11-17 08:39:47,766 WrapperListener_start_runner DEBUG PatternLayout$Builder(pattern="%-5p %d [%t] [processor: %X{processorPath}; event: %X{correlationId}] %c: %m%n", PatternSelector=null, Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml), Replace=null, charset="null", alwaysWriteExceptions="null", disableAnsi="null", noConsoleNoAnsi="null", header="null", footer="null") 2022-11-17 08:39:47,767 WrapperListener_start_runner DEBUG Building Plugin[name=SizeBasedTriggeringPolicy, class=org.apache.logging.log4j.core.appender.rolling.SizeBasedTriggeringPolicy]. 2022-11-17 08:39:47,768 WrapperListener_start_runner DEBUG createPolicy(size="10 MB") 2022-11-17 08:39:47,769 WrapperListener_start_runner DEBUG Building Plugin[name=DefaultRolloverStrategy, class=org.apache.logging.log4j.core.appender.rolling.DefaultRolloverStrategy]. 2022-11-17 08:39:47,771 WrapperListener_start_runner DEBUG DefaultRolloverStrategy$Builder(max="10", min="null", fileIndex="null", compressionLevel="null", ={}, stopCustomActionsOnError="null", tempCompressedFilePattern="null", Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml)) 2022-11-17 08:39:47,771 WrapperListener_start_runner DEBUG Building Plugin[name=appender, class=org.apache.logging.log4j.core.appender.RollingFileAppender]. 2022-11-17 08:39:47,773 WrapperListener_start_runner DEBUG RollingFileAppender$Builder(fileName="C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\logs\demo-kinesis-aws-appender.log", filePattern="C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\logs\demo-kinesis-aws-appender-%i.log", append="null", locking="null", SizeBasedTriggeringPolicy(SizeBasedTriggeringPolicy(size=10485760)), DefaultRolloverStrategy(DefaultRolloverStrategy(min=1, max=10, useMax=true)), advertise="null", advertiseUri="null", createOnDemand="null", filePermissions="null", fileOwner="null", fileGroup="null", bufferedIo="null", bufferSize="null", immediateFlush="null", ignoreExceptions="null", PatternLayout(%-5p %d [%t] [processor: %X{processorPath}; event: %X{correlationId}] %c: %m%n), name="file", Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml), Filter=null, ={}) 2022-11-17 08:39:47,823 WrapperListener_start_runner DEBUG Returning file creation time for C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\logs\demo-kinesis-aws-appender.log 2022-11-17 08:39:47,824 WrapperListener_start_runner DEBUG Starting RollingFileManager C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\logs\demo-kinesis-aws-appender.log 2022-11-17 08:39:47,825 WrapperListener_start_runner DEBUG PluginManager 'FileConverter' found 2 plugins 2022-11-17 08:39:47,826 WrapperListener_start_runner DEBUG Setting prev file time to 2022-10-28T18:00:45.370-0700 2022-11-17 08:39:47,826 WrapperListener_start_runner DEBUG Initializing triggering policy SizeBasedTriggeringPolicy(size=10485760) 2022-11-17 08:39:47,827 WrapperListener_start_runner DEBUG Building Plugin[name=KeyValuePair, class=org.apache.logging.log4j.core.util.KeyValuePair]. 2022-11-17 08:39:47,830 WrapperListener_start_runner DEBUG KeyValuePair$Builder(key="applicationName", value="test-log4j-aws-appender") 2022-11-17 08:39:47,831 WrapperListener_start_runner DEBUG Building Plugin[name=KeyValuePair, class=org.apache.logging.log4j.core.util.KeyValuePair]. 2022-11-17 08:39:47,831 WrapperListener_start_runner DEBUG KeyValuePair$Builder(key="environment", value="dev") 2022-11-17 08:39:47,831 WrapperListener_start_runner DEBUG Building Plugin[name=KeyValuePair, class=org.apache.logging.log4j.core.util.KeyValuePair]. 2022-11-17 08:39:47,833 WrapperListener_start_runner DEBUG KeyValuePair$Builder(key="processId", value="16536") 2022-11-17 08:39:47,834 WrapperListener_start_runner DEBUG Building Plugin[name=KeyValuePair, class=org.apache.logging.log4j.core.util.KeyValuePair]. 2022-11-17 08:39:47,835 WrapperListener_start_runner DEBUG KeyValuePair$Builder(key="hostname", value="V0188-CON-D056") 2022-11-17 08:39:47,835 WrapperListener_start_runner DEBUG Building Plugin[name=KeyValuePair, class=org.apache.logging.log4j.core.util.KeyValuePair]. 2022-11-17 08:39:47,836 WrapperListener_start_runner DEBUG KeyValuePair$Builder(key="timestamp", value="${date:yyyy-MM-dd'T'HH:mm:ss.SSS'Z'}") 2022-11-17 08:39:47,836 WrapperListener_start_runner DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.JsonLayout]. 2022-11-17 08:39:47,845 WrapperListener_start_runner DEBUG JsonLayout$Builder(propertiesAsList="null", objectMessageAsJsonObject="null", ={applicationName=test-log4j-aws-appender, environment=dev, processId=16536, hostname=V0188-CON-D056, timestamp=${date:yyyy-MM-dd'T'HH:mm:ss.SSS'Z'}}, eventEol="true", endOfLine="null", compact="true", complete="false", locationInfo="true", properties="true", includeStacktrace="null", stacktraceAsString="null", includeNullDelimiter="null", includeTimeMillis="null", ={}, charset="null", footerSerializer=null, headerSerializer=null, Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml), footer="null", header="null") 2022-11-17 08:39:47,955 WrapperListener_start_runner DEBUG Building Plugin[name=appender, class=com.kdgregory.log4j2.aws.KinesisAppender]. 2022-11-17 08:39:47,972 WrapperListener_start_runner DEBUG KinesisAppender$KinesisAppenderBuilder(name="KinesisAppender", streamName="ekk-xxxxxxxxx-dev-uw2-api-KinesisStream-xxxxxx", partitionKey="1234", autoCreate="true", shardCount="1", retentionPeriod="25", JsonLayout(org.apache.logging.log4j.core.layout.JsonLayout@128864d6), Filter=null, Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml), synchronous="false", batchDelay="500", truncateOversizeMessages="null", discardThreshold="null", discardAction="newest", assumedRole="xxxxxxxxxxxxxxxxxxxxxx", clientFactory="null", clientRegion="xxxxxxxxxxx", clientEndpoint="xxxxxxxxxxxxxxxxx", useShutdownHook="null") 2022-11-17 08:39:47,979 WrapperListener_start_runner DEBUG Building Plugin[name=appenders, class=org.apache.logging.log4j.core.config.AppendersPlugin]. 2022-11-17 08:39:47,980 WrapperListener_start_runner DEBUG createAppenders(={CONSOLE, file, com.kdgregory.log4j2.aws.KinesisAppender with name KinesisAppender}) 2022-11-17 08:39:47,981 WrapperListener_start_runner DEBUG Building Plugin[name=AppenderRef, class=org.apache.logging.log4j.core.config.AppenderRef]. 2022-11-17 08:39:47,982 WrapperListener_start_runner DEBUG createAppenderRef(ref="KinesisAppender", level="null", Filter=null) 2022-11-17 08:39:47,983 WrapperListener_start_runner DEBUG Building Plugin[name=asyncLogger, class=org.apache.logging.log4j.core.async.AsyncLoggerConfig]. 2022-11-17 08:39:47,983 WrapperListener_start_runner DEBUG createLogger(additivity="true", level="INFO", name="logger.kinesis", includeLocation="null", ={KinesisAppender}, ={}, Configuration(C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml), Filter=null) 2022-11-17 08:39:47,984 WrapperListener_start_runner DEBUG Building Plugin[name=loggers, class=org.apache.logging.log4j.core.config.LoggersPlugin]. 2022-11-17 08:39:47,984 WrapperListener_start_runner DEBUG createLoggers(={logger.kinesis}) 2022-11-17 08:39:47,985 WrapperListener_start_runner WARN No Root logger was configured, creating default ERROR-level Root logger with Console appender 2022-11-17 08:39:47,985 WrapperListener_start_runner DEBUG Starting OutputStreamManager SYSTEM_OUT.false.false-6 2022-11-17 08:39:47,986 WrapperListener_start_runner DEBUG Configuration XmlConfiguration[location=C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml] initialized 2022-11-17 08:39:47,986 WrapperListener_start_runner DEBUG Starting configuration XmlConfiguration[location=C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml] 2022-11-17 08:39:47,989 WrapperListener_start_runner DEBUG Starting AsyncLoggerConfig disruptor for this configuration with ringbufferSize=4096, waitStrategy=TimeoutBlockingWaitStrategy, exceptionHandler=org.mule.runtime.module.launcher.api.log4j2.AsyncLoggerExceptionHandler@27c1f63f... 2022-11-17 08:39:48,029 com-kdgregory-aws-logwriter-log4j2-kinesis-1 DEBUG log writer starting (thread: com-kdgregory-aws-logwriter-log4j2-kinesis-1) 2022-11-17 08:40:48,134 WrapperListener_start_runner ERROR writer initialization timed out 2022-11-17 08:40:48,137 WrapperListener_start_runner DEBUG Started configuration XmlConfiguration[location=C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml] OK. 2022-11-17 08:40:48,141 WrapperListener_start_runner DEBUG Shutting down OutputStreamManager SYSTEM_OUT.false.false-6 2022-11-17 08:40:48,142 WrapperListener_start_runner DEBUG OutputStream closed 2022-11-17 08:40:48,144 WrapperListener_start_runner DEBUG Shut down OutputStreamManager SYSTEM_OUT.false.false-6, all resources released: true 2022-11-17 08:40:48,144 WrapperListener_start_runner DEBUG Appender DefaultConsole-6 stopped with status true 2022-11-17 08:40:48,154 WrapperListener_start_runner DEBUG Shutting down OutputStreamManager SYSTEM_OUT.false.false-5 2022-11-17 08:40:48,154 WrapperListener_start_runner DEBUG OutputStream closed 2022-11-17 08:40:48,155 WrapperListener_start_runner DEBUG Shut down OutputStreamManager SYSTEM_OUT.false.false-5, all resources released: true 2022-11-17 08:40:48,155 WrapperListener_start_runner DEBUG Appender DefaultConsole-5 stopped with status true 2022-11-17 08:40:48,155 WrapperListener_start_runner DEBUG Stopped org.apache.logging.log4j.core.config.DefaultConfiguration@52289993 OK 2022-11-17 08:40:48,155 WrapperListener_start_runner DEBUG JMX disabled for Log4j2. Not registering MBeans. 2022-11-17 08:40:48,156 WrapperListener_start_runner DEBUG Reconfiguration complete for context[name=domain/default/app/demo-kinesis-aws-appender] at URI C:\RajeshK\Anypoint7\AnypointStudio\plugins\org.mule.tooling.server.4.4.0.ee_7.11.0.202208251955\mule\apps\demo-kinesis-aws-appender\log4j2.xml (org.mule.runtime.module.launcher.log4j2.MuleLoggerContext@55b51024) with optional ClassLoader: null 2022-11-17 08:40:48,156 WrapperListener_start_runner DEBUG Shutdown hook enabled. Registering a new one. 2022-11-17 08:40:48,156 WrapperListener_start_runner DEBUG LoggerContext[name=domain/default/app/demo-kinesis-aws-appender, org.mule.runtime.module.launcher.log4j2.MuleLoggerContext@55b51024] started OK. 2022-11-17 08:40:51,943 com-kdgregory-aws-logwriter-log4j2-kinesis-1 WARN The Logger software.amazon.awssdk.http.apache.internal.conn.SdkTlsSocketFactory was created with the message factory org.apache.logging.log4j.message.ReusableMessageFactory@3ded5886 and is now requested with the message factory org.apache.logging.log4j.message.ReusableMessageFactory@687d3266, which may create log events with unexpected formatting. 2022-11-17 08:40:54,257 com-kdgregory-aws-logwriter-log4j2-kinesis-1 DEBUG log writer initialization complete (thread: com-kdgregory-aws-logwriter-log4j2-kinesis-1) INFO 2022-11-17 08:42:09,386 [ArtifactDeployer.start.01] org.mule.runtime.core.internal.logging.LogUtil:

kdgregory commented 1 year ago

When I look at the log you've attached, I see the following messages from the log writer:

2022-11-17 08:39:48,029 com-kdgregory-aws-logwriter-log4j2-kinesis-1 DEBUG log writer starting (thread: com-kdgregory-aws-logwriter-log4j2-kinesis-1)
2022-11-17 08:40:51,943 com-kdgregory-aws-logwriter-log4j2-kinesis-1 WARN The Logger software.amazon.awssdk.http.apache.internal.conn.SdkTlsSocketFactory was created with the message factory org.apache.logging.log4j.message.ReusableMessageFactory@3ded5886 and is now requested with the message factory org.apache.logging.log4j.message.ReusableMessageFactory@687d3266, which may create log events with unexpected formatting.
2022-11-17 08:40:54,257 com-kdgregory-aws-logwriter-log4j2-kinesis-1 DEBUG log writer initialization complete (thread: com-kdgregory-aws-logwriter-log4j2-kinesis-1)

I don't know what the warning is -- it appears to be something internal to Log4J -- but I think it's irrelevant.

What I don't see is any indication that you're experiencing failures when you're actually logging.

And I'm sorry, but there's absolutely nothing more that I can do to help you.

kdgregory commented 1 year ago

Actually, I do have one more suggestion. Take the Log4J2 example from this project, configure for Kinesis, and verify that you can run it successfully (ie, it writes to the stream). Then start changing the configuration to match what you're using (explicit endpoint, assumed role, whatever), and see where it breaks.

https://github.com/kdgregory/log4j-aws-appenders/tree/trunk/examples/log4j2-example

RajeshMca1404 commented 1 year ago

Dear KD,

I am using your component in Mulesoft. I hope it support Mulesoft also. Do you know what could be reason for Writer Intialization timeout. This might not be working because Writer is not intializing. As you said you have seen Some Log4J warning. Should we use old version which you have tested. Thanks

RajeshMca1404 commented 1 year ago

Dear KD,

Just curious to know if this has been tested with Mulesoft also.

Do you know what could be reason for Writer Intialization timeout. This might not be working because Writer is not intializing.

Can you help us letting know what you think be the reason for initialization error. Do we need to set client factory.

Thanks

kdgregory commented 1 year ago

Just curious to know if this has been tested with Mulesoft also.

No, it has not (at least not by me). Why do you think that would cause the issue?

This might not be working because Writer is not intializing.

As I have said multiple times, the logs show that the writer is initializing. It's just taking a long time to do so.

And as I've also said multiple times, the error that you're seeing is from the appender, but is not meaningful (and will be removed in the next release).

Do we need to set client factory

The real problem is that you don't understand the tools that you're using, and are trying random things to solve what appears to be a nonexistent problem.

I have suggested that you use the example program to verify logging behavior without additional variables. Make sure that you can in fact write to Kinesis. And then use that logging configuration in your actual application.

Please be aware that this is the last time that I will respond to this issue.

RajeshMca1404 commented 1 year ago

Dear KD,

We have tried with existing example also. It is not writing to Kinesis. We can wait for your next release. Thanks