search

rfoltyns / log4j2-elasticsearch

Log4j2 Elasticsearch Appender plugins
Apache License 2.0
174 stars 46 forks source link

Error in Appenders and loggers #35

Closed Parasxidis closed 4 years ago

Parasxidis commented 4 years ago

Hi, I'm getting the next error message when I run my application: 2020-02-05 15:57:11,466 WrapperListener_start_runner ERROR Appenders contains an invalid element or attribute "Elasticsearch" 2020-02-05 15:57:11,487 WrapperListener_start_runner ERROR loggers Loggers has no parameter that matches element AppenderRef

Here is my log4j2.xml:

``<?xml version="1.0" encoding="utf-8"?>

``
rfoltyns commented 4 years ago

@Parasxidis I'm afraid that you'll have to provide much more info here. There must be some more error logs or stacktraces around it.

Otherwise, I can't give you an explanation why "Appenders contains an invalid element or attribute "Elasticsearch". Dependencies missing? Config/init errors? SPI issues? I just can't tell based on the nfo you provided.

rfoltyns commented 4 years ago

Closing due to lack of sufficient information to proceed.

Please visit examples and verify your configuration.

BugraAkdagPXL commented 2 years ago

I have this same exact issue right now, no other error logs or stack traces available. Dependencies should be alright.

rfoltyns commented 2 years ago

@BugraAkdagPXL Can you see more once you enable status logging?

<Configuration status="DEBUG">
... your config ..
</Configuration>

Can you post your Log4j2 config?

Did you try examples already? Try to verify your config there.

BugraAkdagPXL commented 2 years ago

2022-03-18 08:47:49,233 WrapperListener_start_runner DEBUG Building Plugin[name=appenders, class=org.apache.logging.log4j.core.config.AppendersPlugin]. 2022-03-18 08:47:49,234 WrapperListener_start_runner ERROR Appenders contains an invalid element or attribute "Elasticsearch" 2022-03-18 08:47:49,234 WrapperListener_start_runner DEBUG createAppenders(={file}) 2022-03-18 08:47:49,234 WrapperListener_start_runner DEBUG Building Plugin[name=asyncLogger, class=org.apache.logging.log4j.core.async.AsyncLoggerConfig]. 2022-03-18 08:47:49,234 WrapperListener_start_runner DEBUG createLogger(additivity="true", level="WARN", name="org.mule.service.http", includeLocation="null", ={}, ={}, Configuration(cloudhub), Filter=null) 2022-03-18 08:47:49,235 WrapperListener_start_runner DEBUG Building Plugin[name=asyncLogger, class=org.apache.logging.log4j.core.async.AsyncLoggerConfig]. 2022-03-18 08:47:49,235 WrapperListener_start_runner DEBUG createLogger(additivity="true", level="WARN", name="org.mule.extension.http", includeLocation="null", ={}, ={}, Configuration(cloudhub), Filter=null) 2022-03-18 08:47:49,235 WrapperListener_start_runner DEBUG Building Plugin[name=asyncLogger, class=org.apache.logging.log4j.core.async.AsyncLoggerConfig]. 2022-03-18 08:47:49,236 WrapperListener_start_runner DEBUG createLogger(additivity="true", level="INFO", name="org.mule.runtime.core.internal.processor.LoggerMessageProcessor", includeLocation="null", ={}, ={}, Configuration(cloudhub), Filter=null) 2022-03-18 08:47:49,236 WrapperListener_start_runner DEBUG Building Plugin[name=AppenderRef, class=org.apache.logging.log4j.core.config.AppenderRef]. 2022-03-18 08:47:49,236 WrapperListener_start_runner DEBUG createAppenderRef(ref="ELK", level="null", Filter=null)

Little bit more but still no detailed stacktrace.

Here is my log4j

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

local ELK salesforce-sapi HIDDEN
rfoltyns commented 2 years ago

Please remove <JacksonModuleExample/> (unless your own implementation), it's not a part of released binary and may cause this failure.

BugraAkdagPXL commented 2 years ago

Thank you for the fast response but sadly enough this did not resolve the problem. Is the following part necessary in the Pom? Since this is the only thing I do not have in my own pom.

    <dependency>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-log4j2</artifactId>
    </dependency>
    <dependency>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-web</artifactId>
        <exclusions>
            <!-- Because I like Jetty -->
            <exclusion>
                <groupId>org.springframework.boot</groupId>
                <artifactId>spring-boot-starter-tomcat</artifactId>
            </exclusion>
            <!-- Because Log4j2 must take precedence -->
            <exclusion>
                <groupId>org.springframework.boot</groupId>
                <artifactId>spring-boot-starter-logging</artifactId>
            </exclusion>
        </exclusions>
    </dependency>
rfoltyns commented 2 years ago

In log4j2-elasticsearch-examples project, this part of POM forces Spring Boot to use Log4j2. Harmless (and necessary).

You're using PooledItemSourceFactory for item buffers in layout. With this configuration, you need to provide a pool for batch buffers in HCHttp config. Try this:

<HCHttp serverUris="URL">
    <PooledItemSourceFactory poolName="batchPool" itemSizeInBytes="1024000" initialPoolSize="3"/>
    <Security>
        <BasicCredentials username="USERNAME" password="PASSWORD"/>
    </Security>
</HCHttp>

Batch buffer itemSizeInBytes should be itemPool.itemSizeInBytes * asyncBatchDelivery.batchSize. It can be lower, but - depending on your message size - application may need to extend/shrink these buffers back and forth too often causing too much garbage and effectively defeating the purpose of these pools.

BugraAkdagPXL commented 2 years ago

Log4j is already being used in our project. We already used log4j to send messages to Elasticsearch over HTTP. We had memory issues and wanted to try this out. But when reading in the logs its clear that the tag is not recognised in the log4j xml. So any changes made within the Elasticsearch tag is not changing anything.

In my dependencies I have the following

<dependency>
            <groupId>org.appenders.log4j</groupId>
            <artifactId>log4j2-elasticsearch-hc</artifactId>
            <version>${appenders.version}</version>
        </dependency>
        <!-- Because single-threaded serialisation is more memory efficient (optional) -->
        <dependency>
            <groupId>org.appenders.st</groupId>
            <artifactId>appenders-jackson-st</artifactId>
            <version>1.0.1</version>
        </dependency>
        <!-- Because afterburner is cool (optional) -->
        <dependency>
            <groupId>com.fasterxml.jackson.module</groupId>
            <artifactId>jackson-module-afterburner</artifactId>
            <version>${jackson.version}</version>
        </dependency>
        <!-- Because object pooling is configured (optional) -->
        <dependency>
            <groupId>io.netty</groupId>
            <artifactId>netty-buffer</artifactId>
            <version>4.1.32.Final</version>
        </dependency>
        <!-- Because file-backed failover is configured (optional) -->
        <dependency>
            <groupId>net.openhft</groupId>
            <artifactId>chronicle-map</artifactId>
            <version>3.19.40</version>
        </dependency>
        <!-- Because AsyncLogger is recommended (optional) -->
        <dependency>
            <groupId>com.lmax</groupId>
            <artifactId>disruptor</artifactId>
            <version>3.4.2</version>
        </dependency>
rfoltyns commented 2 years ago

Which version are you using? (${appenders.version})

Could you post your current Log4j2 config?

Configuration below starts just fine in with log4j2-elasticsearch-hc-springboot example and unchanged pom(!). Log delivery obviously fails because MalformedUrlException, but Log4j2 initializes successfully.

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="INFO">
    <Appenders>
        <Console name="CONSOLE" />

        <Elasticsearch name="elasticsearch">
            <IndexName indexName="log4j2-elasticsearch-hc"/>
            <JacksonJsonLayout>
                <NonEmptyFilter/>
                <VirtualProperty name="correlationId" value="$${ctx:correlationId:-}"/>
                <VirtualProperty name="apiName" value="${sys:apiName}"/>
                <VirtualProperty name="env" value="${sys:env}"/>
                <PooledItemSourceFactory poolName="itemPool" itemSizeInBytes="1024" initialPoolSize="3000"/>
            </JacksonJsonLayout>
            <AsyncBatchDelivery batchSize="1000" deliveryInterval="10000" >
                <HCHttp serverUris="URL">
                    <PooledItemSourceFactory poolName="batchPool" itemSizeInBytes="1024000" initialPoolSize="3"/>
                    <Security>
                        <BasicCredentials username="USERNAME" password="PASSWORD"/>
                    </Security>
                </HCHttp>
            </AsyncBatchDelivery>
        </Elasticsearch>
    </Appenders>

    <Loggers>
        <AsyncLogger name="elasticsearch">
            <AppenderRef ref="elasticsearch" />
        </AsyncLogger>
        <Root level="info">
            <AppenderRef ref="CONSOLE" />
        </Root>
    </Loggers>
</Configuration>

Also, on other note, $${ctx:correlationId:-} will always be empty if you use AsyncLogger, but let's get to that later.

BugraAkdagPXL commented 2 years ago

I am using appenders version 1.5.2 and jackson version 2.12.0.

Full log4j:

<?xml version="1.0" encoding="utf-8"?>
<Configuration name="cloudhub" packages="com.mulesoft.ch.logging.appender" status="DEBUG">
    <Properties>
        <Property name="env">local</Property>
        <Property name="logs.destination">ELK</Property>
        <Property name="apiName">salesforce-sapi</Property>
        <Property name="elk.password">PASSWORD=</Property>
      </Properties>

    <!--These are some of the loggers you can enable. 
        There are several more you can find in the documentation. 
        Besides this log4j configuration, you can also use Java VM environment variables
        to enable other logs like network (-Djavax.net.debug=ssl or all) and 
        Garbage Collector (-XX:+PrintGC). These will be append to the console, so you will 
        see them in the mule_ee.log file. -->

    <Appenders>
        <RollingFile name="file" fileName="${sys:mule.home}${sys:file.separator}logs${sys:file.separator}${sys:apiName}-implementation.log" 
                 filePattern="${sys:mule.home}${sys:file.separator}logs${sys:file.separator}${sys:apiName}-implementation-%i.log">
            <PatternLayout pattern="%-5p %d [%t] [processor: %X{processorPath}; event: %X{correlationId}] %c: %m%n" />
            <SizeBasedTriggeringPolicy size="10 MB" />
            <DefaultRolloverStrategy max="10"/>
        </RollingFile>
        <Elasticsearch name="ELK">
            <IndexName indexName="log4j2-elasticsearch-hc"/>
            <JacksonJsonLayout>
                <NonEmptyFilter/>
                <VirtualProperty name="correlationId" value="$${ctx:correlationId:-}"/>
                <VirtualProperty name="apiName" value="${sys:apiName}"/>
                <VirtualProperty name="env" value="${sys:env}"/>
                <PooledItemSourceFactory poolName="itemPool" itemSizeInBytes="1024" initialPoolSize="3000"/>
            </JacksonJsonLayout>
            <AsyncBatchDelivery batchSize="1000" deliveryInterval="10000" >
                <HCHttp serverUris="URL">
                <PooledItemSourceFactory poolName="batchPool" itemSizeInBytes="1024000" initialPoolSize="3"/>
                    <Security>
                        <BasicCredentials username="USERNAME" password="URL"/>
                    </Security>
                </HCHttp>
            </AsyncBatchDelivery>
        </Elasticsearch>
    </Appenders>
    <Loggers>

        <!-- Http Logger shows wire traffic on DEBUG. -->
        <!--AsyncLogger name="org.mule.service.http.impl.service.HttpMessageLogger" level="DEBUG" /-->
        <AsyncLogger name="org.mule.service.http" level="WARN"/>
        <AsyncLogger name="org.mule.extension.http" level="WARN"/>

        <!-- Mule logger -->        
        <AsyncLogger name="org.mule.runtime.core.internal.processor.LoggerMessageProcessor" level="INFO"/>

        <AsyncRoot level="INFO">
            <AppenderRef ref="${sys:logs.destination}" />
        </AsyncRoot>
    </Loggers>
</Configuration>
rfoltyns commented 2 years ago

With the configuration above, if you keep the POM file intact, you should get a log similar to this:

[(..)@localhost log4j2-elasticsearch-hc-springboot]$ java -jar -Dhostname=somehostname target/log4j2-elasticsearch-hc-springboot-0.0.1-SNAPSHOT.jar
2022-03-18 13:20:03,888 main DEBUG Apache Log4j Core 2.12.1 initializing configuration XmlConfiguration[location=jar:file:(..)log4j2-elasticsearch-examples/log4j2-elasticsearch-hc-springboot/target/log4j2-elasticsearch-hc-springboot-0.0.1-SNAPSHOT.jar!/BOOT-INF/classes!/log4j2.xml]
2022-03-18 13:20:03,894 main DEBUG Installed 0 script engines
2022-03-18 13:20:03,895 main DEBUG Took 0.000914 seconds to load 0 plugins from package com.mulesoft.ch.logging.appender
2022-03-18 13:20:03,896 main DEBUG PluginManager 'Core' found 146 plugins
2022-03-18 13:20:03,896 main DEBUG PluginManager 'Level' found 0 plugins
2022-03-18 13:20:03,901 main DEBUG Building Plugin[name=property, class=org.apache.logging.log4j.core.config.Property].
2022-03-18 13:20:03,912 main DEBUG PluginManager 'TypeConverter' found 26 plugins
2022-03-18 13:20:03,918 main DEBUG createProperty(name="env", value="local")
2022-03-18 13:20:03,918 main DEBUG Building Plugin[name=property, class=org.apache.logging.log4j.core.config.Property].
2022-03-18 13:20:03,918 main DEBUG createProperty(name="logs.destination", value="ELK")
2022-03-18 13:20:03,919 main DEBUG Building Plugin[name=property, class=org.apache.logging.log4j.core.config.Property].
2022-03-18 13:20:03,919 main DEBUG createProperty(name="apiName", value="salesforce-sapi")
2022-03-18 13:20:03,919 main DEBUG Building Plugin[name=property, class=org.apache.logging.log4j.core.config.Property].
2022-03-18 13:20:03,920 main DEBUG createProperty(name="elk.password", value="PASSWORD=")
2022-03-18 13:20:03,920 main DEBUG Building Plugin[name=properties, class=org.apache.logging.log4j.core.config.PropertiesPlugin].
2022-03-18 13:20:03,923 main DEBUG configureSubstitutor(={env=local, logs.destination=ELK, apiName=salesforce-sapi, elk.password=PASSWORD=}, Configuration(cloudhub))
2022-03-18 13:20:03,923 main DEBUG PluginManager 'Lookup' found 13 plugins
2022-03-18 13:20:03,924 main DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.PatternLayout].
2022-03-18 13:20:03,927 main DEBUG PatternLayout$Builder(pattern="%-5p %d [%t] [processor: %X{processorPath}; event: %X{correlationId}] %c: %m%n", PatternSelector=null, Configuration(cloudhub), Replace=null, charset="null", alwaysWriteExceptions="null", disableAnsi="null", noConsoleNoAnsi="null", header="null", footer="null")
2022-03-18 13:20:03,928 main DEBUG PluginManager 'Converter' found 47 plugins
2022-03-18 13:20:03,939 main DEBUG Building Plugin[name=SizeBasedTriggeringPolicy, class=org.apache.logging.log4j.core.appender.rolling.SizeBasedTriggeringPolicy].
2022-03-18 13:20:03,940 main DEBUG createPolicy(size="10 MB")
2022-03-18 13:20:03,941 main DEBUG Building Plugin[name=DefaultRolloverStrategy, class=org.apache.logging.log4j.core.appender.rolling.DefaultRolloverStrategy].
2022-03-18 13:20:03,943 main DEBUG DefaultRolloverStrategy$Builder(max="10", min="null", fileIndex="null", compressionLevel="null", ={}, stopCustomActionsOnError="null", tempCompressedFilePattern="null", Configuration(cloudhub))
2022-03-18 13:20:03,944 main DEBUG Building Plugin[name=appender, class=org.apache.logging.log4j.core.appender.RollingFileAppender].
2022-03-18 13:20:03,950 main DEBUG RollingFileAppender$Builder(fileName="${sys:mule.home}/logs/salesforce-sapi-implementation.log", filePattern="${sys:mule.home}/logs/salesforce-sapi-implementation-%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(cloudhub), Filter=null, ={})
2022-03-18 13:20:03,953 main DEBUG Returning file creation time for (..)log4j2-elasticsearch-examples/log4j2-elasticsearch-hc-springboot/${sys:mule.home}/logs/salesforce-sapi-implementation.log
2022-03-18 13:20:03,953 main DEBUG Starting RollingFileManager ${sys:mule.home}/logs/salesforce-sapi-implementation.log
2022-03-18 13:20:03,956 main DEBUG PluginManager 'FileConverter' found 2 plugins
2022-03-18 13:20:03,956 main DEBUG Setting prev file time to 2022-03-18T13:20:03.952+0000
2022-03-18 13:20:03,958 main DEBUG Initializing triggering policy SizeBasedTriggeringPolicy(size=10485760)
2022-03-18 13:20:03,958 main DEBUG Building Plugin[name=indexNameFormatter, class=org.appenders.log4j2.elasticsearch.NoopIndexNameFormatter].
2022-03-18 13:20:03,959 main DEBUG NoopIndexNameFormatter$Builder(indexName="log4j2-elasticsearch-hc")
2022-03-18 13:20:03,959 main DEBUG Building Plugin[name=virtualPropertyFilter, class=org.appenders.log4j2.elasticsearch.NonEmptyFilterPlugin].
2022-03-18 13:20:03,959 main DEBUG Builder()
2022-03-18 13:20:03,959 main DEBUG Building Plugin[name=VirtualProperty, class=org.appenders.log4j2.elasticsearch.VirtualProperty].
2022-03-18 13:20:03,960 main DEBUG VirtualProperty$Builder(name="correlationId", value="${ctx:correlationId:-}", dynamic="null")
2022-03-18 13:20:03,960 main DEBUG Building Plugin[name=VirtualProperty, class=org.appenders.log4j2.elasticsearch.VirtualProperty].
2022-03-18 13:20:03,960 main DEBUG VirtualProperty$Builder(name="apiName", value="salesforce-sapi", dynamic="null")
2022-03-18 13:20:03,961 main DEBUG Building Plugin[name=VirtualProperty, class=org.appenders.log4j2.elasticsearch.VirtualProperty].
2022-03-18 13:20:03,961 main DEBUG VirtualProperty$Builder(name="env", value="local", dynamic="null")
2022-03-18 13:20:03,961 main DEBUG Building Plugin[name=itemSourceFactory, class=org.appenders.log4j2.elasticsearch.PooledItemSourceFactory].
2022-03-18 13:20:03,964 main DEBUG PooledItemSourceFactory$Builder(, , poolName="itemPool", resizePolicy=null, itemSizeInBytes="1024", initialPoolSize="3000", monitored="null", monitorTaskInterval="null", resizeTimeout="null", maxItemSizeInBytes="null", )
2022-03-18 13:20:03,965 main INFO No configured resizePolicy found for pool itemPool. Defaulting to UnlimitedResizePolicy
2022-03-18 13:20:04,004 main DEBUG GenericItemSourcePool: org.jctools.queues.MpmcUnboundedXaddArrayQueue not available
2022-03-18 13:20:04,004 main DEBUG GenericItemSourcePool: Falling back to java.util.concurrent.ConcurrentLinkedQueue
2022-03-18 13:20:04,006 main DEBUG Building Plugin[name=layout, class=org.appenders.log4j2.elasticsearch.JacksonJsonLayout].
2022-03-18 13:20:04,011 main DEBUG JacksonJsonLayout$Builder(, , PooledItemSourceFactory(org.appenders.log4j2.elasticsearch.PooledItemSourceFactory@5bb21b69), ={}, ={}, ={correlationId=${ctx:correlationId:-}, apiName=salesforce-sapi, env=local}, ={org.appenders.log4j2.elasticsearch.NonEmptyFilterPlugin@6b9651f3}, afterburner="null", singleThread="null", Configuration(cloudhub), footer="null", header="null")
2022-03-18 13:20:04,089 main DEBUG Building Plugin[name=itemSourceFactory, class=org.appenders.log4j2.elasticsearch.PooledItemSourceFactory].
2022-03-18 13:20:04,090 main DEBUG PooledItemSourceFactory$Builder(, , poolName="batchPool", resizePolicy=null, itemSizeInBytes="1024000", initialPoolSize="3", monitored="null", monitorTaskInterval="null", resizeTimeout="null", maxItemSizeInBytes="null", )
2022-03-18 13:20:04,090 main INFO No configured resizePolicy found for pool batchPool. Defaulting to UnlimitedResizePolicy
2022-03-18 13:20:04,091 main DEBUG GenericItemSourcePool: org.jctools.queues.MpmcUnboundedXaddArrayQueue not available
2022-03-18 13:20:04,091 main DEBUG GenericItemSourcePool: Falling back to java.util.concurrent.ConcurrentLinkedQueue
2022-03-18 13:20:04,091 main DEBUG Building Plugin[name=credentials, class=org.appenders.log4j2.elasticsearch.hc.BasicCredentialsPlugin].
2022-03-18 13:20:04,092 main DEBUG BasicCredentialsPlugin$Builder(username="USERNAME", password="URL")
2022-03-18 13:20:04,093 main DEBUG Building Plugin[name=auth, class=org.appenders.log4j2.elasticsearch.hc.SecurityPlugin].
2022-03-18 13:20:04,093 main DEBUG SecurityPlugin$Builder(BasicCredentials(org.appenders.log4j2.elasticsearch.hc.BasicCredentialsPlugin with name BasicCredentials), certInfo=null)
2022-03-18 13:20:04,094 main DEBUG Building Plugin[name=objectFactory, class=org.appenders.log4j2.elasticsearch.hc.HCHttpPlugin].
2022-03-18 13:20:04,096 main DEBUG HCHttpPlugin$Builder(, Configuration(cloudhub), serverUris="URL", connTimeout="null", readTimeout="null", maxTotalConnections="null", ioThreadCount="null", pooledResponseBuffers="null", pooledResponseBuffersSizeInBytes="null", Security(org.appenders.log4j2.elasticsearch.hc.SecurityPlugin with name Security), PooledItemSourceFactory(org.appenders.log4j2.elasticsearch.PooledItemSourceFactory@4516af24), mappingType="null", BackoffPolicy=null, serviceDiscovery=null, )
2022-03-18 13:20:04,136 main DEBUG GenericItemSourcePool: org.jctools.queues.MpmcUnboundedXaddArrayQueue not available
2022-03-18 13:20:04,136 main DEBUG GenericItemSourcePool: Falling back to java.util.concurrent.ConcurrentLinkedQueue
2022-03-18 13:20:04,138 main DEBUG Building Plugin[name=batchDelivery, class=org.appenders.log4j2.elasticsearch.AsyncBatchDeliveryPlugin].
2022-03-18 13:20:04,138 main DEBUG createAsyncBatchDelivery(HCHttp(org.appenders.log4j2.elasticsearch.hc.HCHttpPlugin@70b0b186), batchSize="1000", deliveryInterval="10000", failoverPolicy=null, shutdownDelayMillis="0", ={})
2022-03-18 13:20:04,141 main INFO BatchEmitterFactory class found org.appenders.log4j2.elasticsearch.hc.BulkEmitterFactory
2022-03-18 13:20:04,141 main INFO BatchEmitterFactory class found org.appenders.log4j2.elasticsearch.hc.BulkEmitterFactory
2022-03-18 13:20:04,142 main DEBUG BulkEmitter: org.jctools.queues.MpmcUnboundedXaddArrayQueue not available
2022-03-18 13:20:04,142 main DEBUG BulkEmitter: Falling back to java.util.concurrent.ConcurrentLinkedQueue
2022-03-18 13:20:04,145 main INFO Using org.appenders.log4j2.elasticsearch.hc.BulkEmitterFactory as BatchEmitterServiceProvider
2022-03-18 13:20:04,145 main DEBUG Building Plugin[name=appender, class=org.appenders.log4j2.elasticsearch.ElasticsearchAppender].
2022-03-18 13:20:04,146 main DEBUG ElasticsearchAppender$Builder(, name="ELK", filter=null, JacksonJsonLayout(org.appenders.log4j2.elasticsearch.JacksonJsonLayout@255b53dc), ignoreExceptions="null", AsyncBatchDelivery(org.appenders.log4j2.elasticsearch.AsyncBatchDeliveryPlugin@1dd92fe2), messageOnly="null", IndexName(org.appenders.log4j2.elasticsearch.NoopIndexNameFormatter@6b53e23f))
2022-03-18 13:20:04,147 main DEBUG Building Plugin[name=appenders, class=org.apache.logging.log4j.core.config.AppendersPlugin].
2022-03-18 13:20:04,148 main DEBUG createAppenders(={file, ELK})
2022-03-18 13:20:04,148 main DEBUG Building Plugin[name=asyncLogger, class=org.apache.logging.log4j.core.async.AsyncLoggerConfig].
2022-03-18 13:20:04,149 main DEBUG createLogger(additivity="true", level="WARN", name="org.mule.service.http", includeLocation="null", ={}, ={}, Configuration(cloudhub), Filter=null)
2022-03-18 13:20:04,152 main DEBUG Building Plugin[name=asyncLogger, class=org.apache.logging.log4j.core.async.AsyncLoggerConfig].
2022-03-18 13:20:04,153 main DEBUG createLogger(additivity="true", level="WARN", name="org.mule.extension.http", includeLocation="null", ={}, ={}, Configuration(cloudhub), Filter=null)
2022-03-18 13:20:04,153 main DEBUG Building Plugin[name=asyncLogger, class=org.apache.logging.log4j.core.async.AsyncLoggerConfig].
2022-03-18 13:20:04,153 main DEBUG createLogger(additivity="true", level="INFO", name="org.mule.runtime.core.internal.processor.LoggerMessageProcessor", includeLocation="null", ={}, ={}, Configuration(cloudhub), Filter=null)
2022-03-18 13:20:04,154 main DEBUG Building Plugin[name=AppenderRef, class=org.apache.logging.log4j.core.config.AppenderRef].
2022-03-18 13:20:04,154 main DEBUG createAppenderRef(ref="ELK", level="null", Filter=null)
2022-03-18 13:20:04,154 main DEBUG Building Plugin[name=asyncRoot, class=org.apache.logging.log4j.core.async.AsyncLoggerConfig$RootLogger].
2022-03-18 13:20:04,155 main DEBUG createLogger(additivity="null", level="INFO", includeLocation="null", ={ELK}, ={}, Configuration(cloudhub), Filter=null)
2022-03-18 13:20:04,155 main DEBUG Building Plugin[name=loggers, class=org.apache.logging.log4j.core.config.LoggersPlugin].
2022-03-18 13:20:04,156 main DEBUG createLoggers(={org.mule.service.http, org.mule.extension.http, org.mule.runtime.core.internal.processor.LoggerMessageProcessor, root})
2022-03-18 13:20:04,156 main DEBUG Configuration XmlConfiguration[location=jar:file:(..)log4j2-elasticsearch-examples/log4j2-elasticsearch-hc-springboot/target/log4j2-elasticsearch-hc-springboot-0.0.1-SNAPSHOT.jar!/BOOT-INF/classes!/log4j2.xml] initialized
2022-03-18 13:20:04,157 main DEBUG Starting configuration XmlConfiguration[location=jar:file:(..)log4j2-elasticsearch-examples/log4j2-elasticsearch-hc-springboot/target/log4j2-elasticsearch-hc-springboot-0.0.1-SNAPSHOT.jar!/BOOT-INF/classes!/log4j2.xml]
2022-03-18 13:20:04,173 main DEBUG Starting AsyncLoggerConfig disruptor for this configuration with ringbufferSize=4096, waitStrategy=TimeoutBlockingWaitStrategy, exceptionHandler=org.apache.logging.log4j.core.async.AsyncLoggerConfigDefaultExceptionHandler@25b485ba...
2022-03-18 13:20:04,184 main INFO Pool [batchPool] 3 pooled elements added. Total pooled elements: 3. Took: 10ms
2022-03-18 13:20:04,186 main INFO Pool [ItemSourcePool] 1 pooled elements added. Total pooled elements: 1. Took: 0ms
2022-03-18 13:20:04,187 main DEBUG ItemSourceAppender started
2022-03-18 13:20:04,206 main INFO Pool [itemPool] 3000 pooled elements added. Total pooled elements: 3000. Took: 19ms
2022-03-18 13:20:04,207 main DEBUG Started configuration XmlConfiguration[location=jar:file:(..)log4j2-elasticsearch-examples/log4j2-elasticsearch-hc-springboot/target/log4j2-elasticsearch-hc-springboot-0.0.1-SNAPSHOT.jar!/BOOT-INF/classes!/log4j2.xml] OK.
2022-03-18 13:20:04,207 main DEBUG Shutting down OutputStreamManager SYSTEM_OUT.false.false-1
2022-03-18 13:20:04,207 main DEBUG Shut down OutputStreamManager SYSTEM_OUT.false.false-1, all resources released: true
2022-03-18 13:20:04,208 main DEBUG Appender DefaultConsole-1 stopped with status true
2022-03-18 13:20:04,208 main DEBUG Stopped org.apache.logging.log4j.core.config.DefaultConfiguration@3ab39c39 OK
2022-03-18 13:20:04,255 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed
2022-03-18 13:20:04,257 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=StatusLogger
2022-03-18 13:20:04,257 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=ContextSelector
2022-03-18 13:20:04,258 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=Loggers,name=
2022-03-18 13:20:04,259 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=Loggers,name=,subtype=RingBuffer
2022-03-18 13:20:04,259 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=Loggers,name=org.mule.extension.http
2022-03-18 13:20:04,259 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=Loggers,name=org.mule.extension.http,subtype=RingBuffer
2022-03-18 13:20:04,260 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=Loggers,name=org.mule.service.http
2022-03-18 13:20:04,260 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=Loggers,name=org.mule.service.http,subtype=RingBuffer
2022-03-18 13:20:04,260 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=Loggers,name=org.mule.runtime.core.internal.processor.LoggerMessageProcessor
2022-03-18 13:20:04,260 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=Loggers,name=org.mule.runtime.core.internal.processor.LoggerMessageProcessor,subtype=RingBuffer
2022-03-18 13:20:04,261 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=Appenders,name=ELK
2022-03-18 13:20:04,262 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=Appenders,name=file
2022-03-18 13:20:04,262 main DEBUG org.apache.logging.log4j.core.util.SystemClock supports precise timestamps.
2022-03-18 13:20:04,263 main DEBUG Reconfiguration complete for context[name=b1bc7ed] at URI jar:file:(..)log4j2-elasticsearch-examples/log4j2-elasticsearch-hc-springboot/target/log4j2-elasticsearch-hc-springboot-0.0.1-SNAPSHOT.jar!/BOOT-INF/classes!/log4j2.xml (org.apache.logging.log4j.core.LoggerContext@4d41cee) with optional ClassLoader: null
2022-03-18 13:20:04,263 main DEBUG Shutdown hook enabled. Registering a new one.
2022-03-18 13:20:04,264 main DEBUG LoggerContext[name=b1bc7ed, org.apache.logging.log4j.core.LoggerContext@4d41cee] started OK.
2022-03-18 13:20:04,448 main DEBUG Reconfiguration started for context[name=b1bc7ed] at URI null (org.apache.logging.log4j.core.LoggerContext@4d41cee) with optional ClassLoader: null
2022-03-18 13:20:04,448 main DEBUG Using configurationFactory org.apache.logging.log4j.core.config.ConfigurationFactory$Factory@55b53d44
2022-03-18 13:20:04,457 main DEBUG Not in a ServletContext environment, thus not loading WebLookup plugin.
2022-03-18 13:20:04,458 main DEBUG Closing  org.springframework.boot.loader.jar.JarURLConnection$2@482bce4f
2022-03-18 13:20:04,462 main DEBUG Apache Log4j Core 2.12.1 initializing configuration XmlConfiguration[location=jar:file:(..)log4j2-elasticsearch-examples/log4j2-elasticsearch-hc-springboot/target/log4j2-elasticsearch-hc-springboot-0.0.1-SNAPSHOT.jar!/BOOT-INF/classes!/log4j2.xml]
2022-03-18 13:20:04,462 main DEBUG Installed 0 script engines
2022-03-18 13:20:04,463 main DEBUG PluginManager 'Core' found 146 plugins
2022-03-18 13:20:04,463 main DEBUG PluginManager 'Level' found 0 plugins
2022-03-18 13:20:04,464 main DEBUG Building Plugin[name=property, class=org.apache.logging.log4j.core.config.Property].
2022-03-18 13:20:04,464 main DEBUG createProperty(name="env", value="local")
2022-03-18 13:20:04,464 main DEBUG Building Plugin[name=property, class=org.apache.logging.log4j.core.config.Property].
2022-03-18 13:20:04,464 main DEBUG createProperty(name="logs.destination", value="ELK")
2022-03-18 13:20:04,465 main DEBUG Building Plugin[name=property, class=org.apache.logging.log4j.core.config.Property].
2022-03-18 13:20:04,465 main DEBUG createProperty(name="apiName", value="salesforce-sapi")
2022-03-18 13:20:04,465 main DEBUG Building Plugin[name=property, class=org.apache.logging.log4j.core.config.Property].
2022-03-18 13:20:04,465 main DEBUG createProperty(name="elk.password", value="PASSWORD=")
2022-03-18 13:20:04,465 main DEBUG Building Plugin[name=properties, class=org.apache.logging.log4j.core.config.PropertiesPlugin].
2022-03-18 13:20:04,466 main DEBUG configureSubstitutor(={env=local, logs.destination=ELK, apiName=salesforce-sapi, elk.password=PASSWORD=}, Configuration(cloudhub))
2022-03-18 13:20:04,466 main DEBUG PluginManager 'Lookup' found 13 plugins
2022-03-18 13:20:04,466 main DEBUG Building Plugin[name=layout, class=org.apache.logging.log4j.core.layout.PatternLayout].
2022-03-18 13:20:04,466 main DEBUG PatternLayout$Builder(pattern="%-5p %d [%t] [processor: %X{processorPath}; event: %X{correlationId}] %c: %m%n", PatternSelector=null, Configuration(cloudhub), Replace=null, charset="null", alwaysWriteExceptions="null", disableAnsi="null", noConsoleNoAnsi="null", header="null", footer="null")
2022-03-18 13:20:04,466 main DEBUG PluginManager 'Converter' found 47 plugins
2022-03-18 13:20:04,467 main DEBUG Building Plugin[name=SizeBasedTriggeringPolicy, class=org.apache.logging.log4j.core.appender.rolling.SizeBasedTriggeringPolicy].
2022-03-18 13:20:04,467 main DEBUG createPolicy(size="10 MB")
2022-03-18 13:20:04,467 main DEBUG Building Plugin[name=DefaultRolloverStrategy, class=org.apache.logging.log4j.core.appender.rolling.DefaultRolloverStrategy].
2022-03-18 13:20:04,468 main DEBUG DefaultRolloverStrategy$Builder(max="10", min="null", fileIndex="null", compressionLevel="null", ={}, stopCustomActionsOnError="null", tempCompressedFilePattern="null", Configuration(cloudhub))
2022-03-18 13:20:04,468 main DEBUG Building Plugin[name=appender, class=org.apache.logging.log4j.core.appender.RollingFileAppender].
2022-03-18 13:20:04,468 main DEBUG RollingFileAppender$Builder(fileName="${sys:mule.home}/logs/salesforce-sapi-implementation.log", filePattern="${sys:mule.home}/logs/salesforce-sapi-implementation-%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(cloudhub), Filter=null, ={})
2022-03-18 13:20:04,469 main DEBUG PluginManager 'FileConverter' found 2 plugins
2022-03-18 13:20:04,469 main DEBUG Building Plugin[name=indexNameFormatter, class=org.appenders.log4j2.elasticsearch.NoopIndexNameFormatter].
2022-03-18 13:20:04,469 main DEBUG NoopIndexNameFormatter$Builder(indexName="log4j2-elasticsearch-hc")
2022-03-18 13:20:04,469 main DEBUG Building Plugin[name=virtualPropertyFilter, class=org.appenders.log4j2.elasticsearch.NonEmptyFilterPlugin].
2022-03-18 13:20:04,469 main DEBUG Builder()
2022-03-18 13:20:04,470 main DEBUG Building Plugin[name=VirtualProperty, class=org.appenders.log4j2.elasticsearch.VirtualProperty].
2022-03-18 13:20:04,470 main DEBUG VirtualProperty$Builder(name="correlationId", value="${ctx:correlationId:-}", dynamic="null")
2022-03-18 13:20:04,470 main DEBUG Building Plugin[name=VirtualProperty, class=org.appenders.log4j2.elasticsearch.VirtualProperty].
2022-03-18 13:20:04,470 main DEBUG VirtualProperty$Builder(name="apiName", value="salesforce-sapi", dynamic="null")
2022-03-18 13:20:04,470 main DEBUG Building Plugin[name=VirtualProperty, class=org.appenders.log4j2.elasticsearch.VirtualProperty].
2022-03-18 13:20:04,471 main DEBUG VirtualProperty$Builder(name="env", value="local", dynamic="null")
2022-03-18 13:20:04,471 main DEBUG Building Plugin[name=itemSourceFactory, class=org.appenders.log4j2.elasticsearch.PooledItemSourceFactory].
2022-03-18 13:20:04,471 main DEBUG PooledItemSourceFactory$Builder(, , poolName="itemPool", resizePolicy=null, itemSizeInBytes="1024", initialPoolSize="3000", monitored="null", monitorTaskInterval="null", resizeTimeout="null", maxItemSizeInBytes="null", )
2022-03-18 13:20:04,471 main INFO No configured resizePolicy found for pool itemPool. Defaulting to UnlimitedResizePolicy
2022-03-18 13:20:04,472 main DEBUG GenericItemSourcePool: org.jctools.queues.MpmcUnboundedXaddArrayQueue not available
2022-03-18 13:20:04,472 main DEBUG GenericItemSourcePool: Falling back to java.util.concurrent.ConcurrentLinkedQueue
2022-03-18 13:20:04,472 main DEBUG Building Plugin[name=layout, class=org.appenders.log4j2.elasticsearch.JacksonJsonLayout].
2022-03-18 13:20:04,472 main DEBUG JacksonJsonLayout$Builder(, , PooledItemSourceFactory(org.appenders.log4j2.elasticsearch.PooledItemSourceFactory@1649b0e6), ={}, ={}, ={correlationId=${ctx:correlationId:-}, apiName=salesforce-sapi, env=local}, ={org.appenders.log4j2.elasticsearch.NonEmptyFilterPlugin@865dd6}, afterburner="null", singleThread="null", Configuration(cloudhub), footer="null", header="null")
2022-03-18 13:20:04,473 main DEBUG Building Plugin[name=itemSourceFactory, class=org.appenders.log4j2.elasticsearch.PooledItemSourceFactory].
2022-03-18 13:20:04,473 main DEBUG PooledItemSourceFactory$Builder(, , poolName="batchPool", resizePolicy=null, itemSizeInBytes="1024000", initialPoolSize="3", monitored="null", monitorTaskInterval="null", resizeTimeout="null", maxItemSizeInBytes="null", )
2022-03-18 13:20:04,473 main INFO No configured resizePolicy found for pool batchPool. Defaulting to UnlimitedResizePolicy
2022-03-18 13:20:04,474 main DEBUG GenericItemSourcePool: org.jctools.queues.MpmcUnboundedXaddArrayQueue not available
2022-03-18 13:20:04,474 main DEBUG GenericItemSourcePool: Falling back to java.util.concurrent.ConcurrentLinkedQueue
2022-03-18 13:20:04,474 main DEBUG Building Plugin[name=credentials, class=org.appenders.log4j2.elasticsearch.hc.BasicCredentialsPlugin].
2022-03-18 13:20:04,474 main DEBUG BasicCredentialsPlugin$Builder(username="USERNAME", password="URL")
2022-03-18 13:20:04,474 main DEBUG Building Plugin[name=auth, class=org.appenders.log4j2.elasticsearch.hc.SecurityPlugin].
2022-03-18 13:20:04,475 main DEBUG SecurityPlugin$Builder(BasicCredentials(org.appenders.log4j2.elasticsearch.hc.BasicCredentialsPlugin with name BasicCredentials), certInfo=null)
2022-03-18 13:20:04,475 main DEBUG Building Plugin[name=objectFactory, class=org.appenders.log4j2.elasticsearch.hc.HCHttpPlugin].
2022-03-18 13:20:04,475 main DEBUG HCHttpPlugin$Builder(, Configuration(cloudhub), serverUris="URL", connTimeout="null", readTimeout="null", maxTotalConnections="null", ioThreadCount="null", pooledResponseBuffers="null", pooledResponseBuffersSizeInBytes="null", Security(org.appenders.log4j2.elasticsearch.hc.SecurityPlugin with name Security), PooledItemSourceFactory(org.appenders.log4j2.elasticsearch.PooledItemSourceFactory@62e7f11d), mappingType="null", BackoffPolicy=null, serviceDiscovery=null, )
2022-03-18 13:20:04,477 main DEBUG GenericItemSourcePool: org.jctools.queues.MpmcUnboundedXaddArrayQueue not available
2022-03-18 13:20:04,477 main DEBUG GenericItemSourcePool: Falling back to java.util.concurrent.ConcurrentLinkedQueue
2022-03-18 13:20:04,477 main DEBUG Building Plugin[name=batchDelivery, class=org.appenders.log4j2.elasticsearch.AsyncBatchDeliveryPlugin].
2022-03-18 13:20:04,478 main DEBUG createAsyncBatchDelivery(HCHttp(org.appenders.log4j2.elasticsearch.hc.HCHttpPlugin@503d687a), batchSize="1000", deliveryInterval="10000", failoverPolicy=null, shutdownDelayMillis="0", ={})
2022-03-18 13:20:04,478 main INFO BatchEmitterFactory class found org.appenders.log4j2.elasticsearch.hc.BulkEmitterFactory
2022-03-18 13:20:04,478 main INFO BatchEmitterFactory class found org.appenders.log4j2.elasticsearch.hc.BulkEmitterFactory
2022-03-18 13:20:04,479 main DEBUG BulkEmitter: org.jctools.queues.MpmcUnboundedXaddArrayQueue not available
2022-03-18 13:20:04,479 main DEBUG BulkEmitter: Falling back to java.util.concurrent.ConcurrentLinkedQueue
2022-03-18 13:20:04,479 main INFO Using org.appenders.log4j2.elasticsearch.hc.BulkEmitterFactory as BatchEmitterServiceProvider
2022-03-18 13:20:04,480 main DEBUG Building Plugin[name=appender, class=org.appenders.log4j2.elasticsearch.ElasticsearchAppender].
2022-03-18 13:20:04,480 main DEBUG ElasticsearchAppender$Builder(, name="ELK", filter=null, JacksonJsonLayout(org.appenders.log4j2.elasticsearch.JacksonJsonLayout@6a370f4), ignoreExceptions="null", AsyncBatchDelivery(org.appenders.log4j2.elasticsearch.AsyncBatchDeliveryPlugin@2abf4075), messageOnly="null", IndexName(org.appenders.log4j2.elasticsearch.NoopIndexNameFormatter@770d3326))
2022-03-18 13:20:04,480 main DEBUG Building Plugin[name=appenders, class=org.apache.logging.log4j.core.config.AppendersPlugin].
2022-03-18 13:20:04,480 main DEBUG createAppenders(={file, ELK})
2022-03-18 13:20:04,480 main DEBUG Building Plugin[name=asyncLogger, class=org.apache.logging.log4j.core.async.AsyncLoggerConfig].
2022-03-18 13:20:04,481 main DEBUG createLogger(additivity="true", level="WARN", name="org.mule.service.http", includeLocation="null", ={}, ={}, Configuration(cloudhub), Filter=null)
2022-03-18 13:20:04,481 main DEBUG Building Plugin[name=asyncLogger, class=org.apache.logging.log4j.core.async.AsyncLoggerConfig].
2022-03-18 13:20:04,481 main DEBUG createLogger(additivity="true", level="WARN", name="org.mule.extension.http", includeLocation="null", ={}, ={}, Configuration(cloudhub), Filter=null)
2022-03-18 13:20:04,481 main DEBUG Building Plugin[name=asyncLogger, class=org.apache.logging.log4j.core.async.AsyncLoggerConfig].
2022-03-18 13:20:04,482 main DEBUG createLogger(additivity="true", level="INFO", name="org.mule.runtime.core.internal.processor.LoggerMessageProcessor", includeLocation="null", ={}, ={}, Configuration(cloudhub), Filter=null)
2022-03-18 13:20:04,482 main DEBUG Building Plugin[name=AppenderRef, class=org.apache.logging.log4j.core.config.AppenderRef].
2022-03-18 13:20:04,482 main DEBUG createAppenderRef(ref="ELK", level="null", Filter=null)
2022-03-18 13:20:04,482 main DEBUG Building Plugin[name=asyncRoot, class=org.apache.logging.log4j.core.async.AsyncLoggerConfig$RootLogger].
2022-03-18 13:20:04,483 main DEBUG createLogger(additivity="null", level="INFO", includeLocation="null", ={ELK}, ={}, Configuration(cloudhub), Filter=null)
2022-03-18 13:20:04,483 main DEBUG Building Plugin[name=loggers, class=org.apache.logging.log4j.core.config.LoggersPlugin].
2022-03-18 13:20:04,483 main DEBUG createLoggers(={org.mule.service.http, org.mule.extension.http, org.mule.runtime.core.internal.processor.LoggerMessageProcessor, root})
2022-03-18 13:20:04,483 main DEBUG Configuration XmlConfiguration[location=jar:file:(..)log4j2-elasticsearch-examples/log4j2-elasticsearch-hc-springboot/target/log4j2-elasticsearch-hc-springboot-0.0.1-SNAPSHOT.jar!/BOOT-INF/classes!/log4j2.xml] initialized
2022-03-18 13:20:04,483 main DEBUG Starting configuration XmlConfiguration[location=jar:file:(..)log4j2-elasticsearch-examples/log4j2-elasticsearch-hc-springboot/target/log4j2-elasticsearch-hc-springboot-0.0.1-SNAPSHOT.jar!/BOOT-INF/classes!/log4j2.xml]
2022-03-18 13:20:04,485 main DEBUG Starting AsyncLoggerConfig disruptor for this configuration with ringbufferSize=4096, waitStrategy=TimeoutBlockingWaitStrategy, exceptionHandler=org.apache.logging.log4j.core.async.AsyncLoggerConfigDefaultExceptionHandler@19d481b...
2022-03-18 13:20:04,486 main INFO Pool [batchPool] 3 pooled elements added. Total pooled elements: 3. Took: 1ms
2022-03-18 13:20:04,486 main INFO Pool [ItemSourcePool] 1 pooled elements added. Total pooled elements: 1. Took: 0ms
2022-03-18 13:20:04,487 main DEBUG ItemSourceAppender started
2022-03-18 13:20:04,490 main INFO Pool [itemPool] 3000 pooled elements added. Total pooled elements: 3000. Took: 3ms
2022-03-18 13:20:04,491 main DEBUG Started configuration XmlConfiguration[location=jar:file:(..)log4j2-elasticsearch-examples/log4j2-elasticsearch-hc-springboot/target/log4j2-elasticsearch-hc-springboot-0.0.1-SNAPSHOT.jar!/BOOT-INF/classes!/log4j2.xml] OK.
2022-03-18 13:20:04,491 main DEBUG Appender file stopped with status true
2022-03-18 13:20:04,492 main DEBUG Stopping ElasticsearchAppender with timeout 0 MILLISECONDS
2022-03-18 13:20:04,492 main DEBUG Stopping ItemSourceAppender
2022-03-18 13:20:04,492 main DEBUG Stopping AsyncBatchDeliveryPlugin
2022-03-18 13:20:04,492 main DEBUG Stopping BulkEmitter. Flushing last batch if possible.
2022-03-18 13:20:04,492 main INFO BulkEmitter: Executor was shutdown gracefully
2022-03-18 13:20:04,492 main DEBUG BulkEmitter stopped
2022-03-18 13:20:04,493 main DEBUG Stopping HCHttpPlugin
2022-03-18 13:20:04,493 main DEBUG batchPool shutting down. Releasing buffers..
2022-03-18 13:20:04,493 main DEBUG batchPool stopping internal threads..
2022-03-18 13:20:04,493 main DEBUG batchPool shutdown complete
2022-03-18 13:20:04,493 main DEBUG ItemSourcePool shutting down. Releasing buffers..
2022-03-18 13:20:04,493 main DEBUG ItemSourcePool stopping internal threads..
2022-03-18 13:20:04,494 main DEBUG ItemSourcePool shutdown complete
2022-03-18 13:20:04,494 main DEBUG HCHttpPlugin stopped
2022-03-18 13:20:04,494 main DEBUG AsyncBatchDeliveryPlugin stopped
2022-03-18 13:20:04,494 main DEBUG ItemSourceAppender stopped
2022-03-18 13:20:04,494 main DEBUG itemPool shutting down. Releasing buffers..
2022-03-18 13:20:04,500 main DEBUG itemPool stopping internal threads..
2022-03-18 13:20:04,500 main DEBUG itemPool shutdown complete
2022-03-18 13:20:04,501 main DEBUG ElasticsearchAppender stopped
2022-03-18 13:20:04,501 main DEBUG Stopped XmlConfiguration[location=jar:file:(..)log4j2-elasticsearch-examples/log4j2-elasticsearch-hc-springboot/target/log4j2-elasticsearch-hc-springboot-0.0.1-SNAPSHOT.jar!/BOOT-INF/classes!/log4j2.xml] OK
2022-03-18 13:20:04,502 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed
2022-03-18 13:20:04,503 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=StatusLogger
2022-03-18 13:20:04,503 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=ContextSelector
2022-03-18 13:20:04,503 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=Loggers,name=
2022-03-18 13:20:04,503 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=Loggers,name=,subtype=RingBuffer
2022-03-18 13:20:04,504 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=Loggers,name=org.mule.extension.http
2022-03-18 13:20:04,504 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=Loggers,name=org.mule.extension.http,subtype=RingBuffer
2022-03-18 13:20:04,504 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=Loggers,name=org.mule.service.http
2022-03-18 13:20:04,505 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=Loggers,name=org.mule.service.http,subtype=RingBuffer
2022-03-18 13:20:04,505 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=Loggers,name=org.mule.runtime.core.internal.processor.LoggerMessageProcessor
2022-03-18 13:20:04,505 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=Loggers,name=org.mule.runtime.core.internal.processor.LoggerMessageProcessor,subtype=RingBuffer
2022-03-18 13:20:04,506 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=Appenders,name=ELK
2022-03-18 13:20:04,506 main DEBUG Registering MBean org.apache.logging.log4j2:type=b1bc7ed,component=Appenders,name=file
2022-03-18 13:20:04,506 main DEBUG Reconfiguration complete for context[name=b1bc7ed] at URI jar:file:(..)log4j2-elasticsearch-examples/log4j2-elasticsearch-hc-springboot/target/log4j2-elasticsearch-hc-springboot-0.0.1-SNAPSHOT.jar!/BOOT-INF/classes!/log4j2.xml (org.apache.logging.log4j.core.LoggerContext@4d41cee) with optional ClassLoader: null

  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::        (v2.2.5.RELEASE)

2022-03-18 13:20:04,655 Log4j2-TF-4-AsyncLoggerConfig-2 DEBUG VirtualProperty with excluded. Value was empty. Name: correlationId
2022-03-18 13:20:04,657 Log4j2-TF-4-AsyncLoggerConfig-2 DEBUG VirtualProperty with excluded. Value was empty. Name: correlationId
2022-03-18 13:20:05,158 Log4j2-TF-4-AsyncLoggerConfig-2 DEBUG VirtualProperty with excluded. Value was empty. Name: correlationId
2022-03-18 13:20:05,159 Log4j2-TF-4-AsyncLoggerConfig-2 DEBUG VirtualProperty with excluded. Value was empty. Name: correlationId
2022-03-18 13:20:10,161 main DEBUG Stopping LoggerContext[name=b1bc7ed, org.apache.logging.log4j.core.LoggerContext@4d41cee]...
2022-03-18 13:20:10,163 main DEBUG Shutting down RollingFileManager ${sys:mule.home}/logs/salesforce-sapi-implementation.log
2022-03-18 13:20:10,163 main DEBUG Shutting down RollingFileManager ${sys:mule.home}/logs/salesforce-sapi-implementation.log
2022-03-18 13:20:10,163 main DEBUG All asynchronous threads have terminated
2022-03-18 13:20:10,163 main DEBUG RollingFileManager shutdown completed with status true
2022-03-18 13:20:10,163 main DEBUG Shut down RollingFileManager ${sys:mule.home}/logs/salesforce-sapi-implementation.log, all resources released: true
2022-03-18 13:20:10,163 main DEBUG Appender file stopped with status true
2022-03-18 13:20:10,163 main DEBUG Stopping ElasticsearchAppender with timeout 0 MILLISECONDS
2022-03-18 13:20:10,163 main DEBUG Stopping ItemSourceAppender
2022-03-18 13:20:10,163 main DEBUG Stopping AsyncBatchDeliveryPlugin
2022-03-18 13:20:10,163 main DEBUG Stopping BulkEmitter. Flushing last batch if possible.
2022-03-18 13:20:10,164 main DEBUG BatchRequest: org.jctools.queues.MpscUnboundedArrayQueue not available
2022-03-18 13:20:10,164 main DEBUG BatchRequest: Falling back to java.util.concurrent.ConcurrentLinkedQueue
2022-03-18 13:20:10,291 main DEBUG GenericItemSourcePool: org.jctools.queues.MpmcUnboundedXaddArrayQueue not available
2022-03-18 13:20:10,292 main DEBUG GenericItemSourcePool: Falling back to java.util.concurrent.ConcurrentLinkedQueue
2022-03-18 13:20:10,292 main ERROR before-batch failed: Can't resolve address: URL java.lang.IllegalArgumentException: Can't resolve address: URL
        at org.appenders.log4j2.elasticsearch.hc.discovery.ServerInfo.<init>(ServerInfo.java:38)
        at org.appenders.log4j2.elasticsearch.hc.ServerPool.<init>(ServerPool.java:54)
        at org.appenders.log4j2.elasticsearch.hc.HttpClientFactory.createInstance(HttpClientFactory.java:96)
        at org.appenders.log4j2.elasticsearch.hc.HttpClientProvider.createClient(HttpClientProvider.java:45)
        at org.appenders.log4j2.elasticsearch.hc.HttpClientProvider.start(HttpClientProvider.java:63)
        at org.appenders.log4j2.elasticsearch.hc.BatchingClientObjectFactory.lambda$start$2(BatchingClientObjectFactory.java:295)
        at org.appenders.log4j2.elasticsearch.hc.BatchingClientObjectFactory$1.apply(BatchingClientObjectFactory.java:109)
        at org.appenders.log4j2.elasticsearch.hc.BatchingClientObjectFactory$1.apply(BatchingClientObjectFactory.java:97)
        at org.appenders.log4j2.elasticsearch.BulkEmitter.notifyListener(BulkEmitter.java:109)
        at org.appenders.log4j2.elasticsearch.BulkEmitter.doStop(BulkEmitter.java:212)
        at org.appenders.log4j2.elasticsearch.DelayedShutdown.run(DelayedShutdown.java:136)
        at org.appenders.log4j2.elasticsearch.DelayedShutdown.start(DelayedShutdown.java:168)
        at org.appenders.log4j2.elasticsearch.BulkEmitter.stop(BulkEmitter.java:204)
        at org.appenders.log4j2.elasticsearch.AsyncBatchDelivery.stop(AsyncBatchDelivery.java:254)
        at org.appenders.log4j2.elasticsearch.ItemSourceAppender.stop(ItemSourceAppender.java:70)
        at org.appenders.log4j2.elasticsearch.ElasticsearchAppender.lifecycleStop(ElasticsearchAppender.java:236)
        at org.appenders.log4j2.elasticsearch.ElasticsearchAppender.stop(ElasticsearchAppender.java:215)
        at org.apache.logging.log4j.core.config.AbstractConfiguration.stop(AbstractConfiguration.java:398)
        at org.apache.logging.log4j.core.LoggerContext.stop(LoggerContext.java:375)
        at org.apache.logging.log4j.core.AbstractLifeCycle.stop(AbstractLifeCycle.java:136)
        at org.springframework.boot.logging.log4j2.Log4J2LoggingSystem$ShutdownHandler.run(Log4J2LoggingSystem.java:278)
        at com.github.rfoltyns.Application.main(Application.java:31)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:78)
        at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:567)
        at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:48)
        at org.springframework.boot.loader.Launcher.launch(Launcher.java:87)
        at org.springframework.boot.loader.Launcher.launch(Launcher.java:51)
        at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:52)
Caused by: java.net.MalformedURLException: no protocol: URL
        at java.base/java.net.URL.<init>(URL.java:672)
        at java.base/java.net.URL.<init>(URL.java:568)
        at java.base/java.net.URL.<init>(URL.java:515)
        at org.appenders.log4j2.elasticsearch.hc.discovery.ServerInfo.<init>(ServerInfo.java:36)
        ... 29 more

2022-03-18 13:20:10,294 main DEBUG GenericItemSourcePool: org.jctools.queues.MpmcUnboundedXaddArrayQueue not available
2022-03-18 13:20:10,294 main DEBUG GenericItemSourcePool: Falling back to java.util.concurrent.ConcurrentLinkedQueue
2022-03-18 13:20:10,294 main WARN Shutdown interrupted: Can't resolve address: URL
2022-03-18 13:20:10,294 main DEBUG Stopping HCHttpPlugin
2022-03-18 13:20:10,295 main DEBUG batchPool shutting down. Releasing buffers..
2022-03-18 13:20:10,295 main DEBUG batchPool stopping internal threads..
2022-03-18 13:20:10,295 main DEBUG batchPool shutdown complete
2022-03-18 13:20:10,295 main DEBUG ItemSourcePool shutting down. Releasing buffers..
2022-03-18 13:20:10,295 main DEBUG ItemSourcePool stopping internal threads..
2022-03-18 13:20:10,295 main DEBUG ItemSourcePool shutdown complete
2022-03-18 13:20:10,295 main DEBUG HCHttpPlugin stopped
2022-03-18 13:20:10,295 main DEBUG AsyncBatchDeliveryPlugin stopped
2022-03-18 13:20:10,295 main DEBUG ItemSourceAppender stopped
2022-03-18 13:20:10,296 main DEBUG itemPool shutting down. Releasing buffers..
2022-03-18 13:20:10,297 main DEBUG itemPool stopping internal threads..
2022-03-18 13:20:10,297 main DEBUG itemPool shutdown complete
2022-03-18 13:20:10,297 main DEBUG ElasticsearchAppender stopped
2022-03-18 13:20:10,297 main DEBUG Stopped XmlConfiguration[location=jar:file:(..)log4j2-elasticsearch-examples/log4j2-elasticsearch-hc-springboot/target/log4j2-elasticsearch-hc-springboot-0.0.1-SNAPSHOT.jar!/BOOT-INF/classes!/log4j2.xml] OK
2022-03-18 13:20:10,297 main DEBUG Stopped LoggerContext[name=b1bc7ed, org.apache.logging.log4j.core.LoggerContext@4d41cee] with status true

Once the URL and credentials (and SSL config if needed) are set, it should be good to go.

Could you run the HC SpringBoot example and post your log, please?

rfoltyns commented 2 years ago

I just noticed that IndexTemplate is also missing. You will not be able to discover your logs in Kibana without it. Date column is timeMillis by default.

<IndexTemplate name="log4j2-elasticsearch-hc-springboot-es-7-test-template" path="classpath:indexTemplate-7.json" />

Template file is not a part of the binary, so you'll have to provide it and maintain it on your own (because only you know how would you like to index your logs).

You can either use the trivial template from examples project, this project's test resources or add it manually if the BasicCredentials.user doesn't have enough privileges.

BugraAkdagPXL commented 2 years ago

I was missing my packages attribute in my log4j. Sorry for the late answer, was sick last week.

rfoltyns commented 2 years ago

@BugraAkdagPXL No worries.

Do you think there's anything that can be done within the scope of this project to avoid these kind of issues. Can be tough if it was simply a misconfigured Mule module.