Custom Level and Properties does not work together

[paulonicolau-rj]

Description

I´m implementing a log file contains trace of request for a funcionality. When i use absolute path in filename attribute of RoliingFileappender, it works fine. When I use property to declare filename, this is ignored and his key is used.

Configuration

Version: [Log4j 2.22.1]

Operating system: [Windows 10/Amazon Linux 2]

JDK: [Oracle 17]

Logs

[Stacktraces, errors, etc. relevant applications logs.]

Reproduction

[An isolated test reproducing the test.
JUnit tests similar to the ones in the code base are extremely appreciated.]

[RapidTransit]

Version: 2.21.1
I had a similar problem, I don't recall what fixed it but here's a snippet of my config, I want to say maybe the property was coming up null?:
AFAIK I haven't tweaked my production config.

 <Properties>
        <Property name="log4j2.disableJmx">true</Property>
        <Property name="log4j2.disable.jmx">true</Property>
        <Property name="log4j2.enableJndiLookup">false</Property>
        <Property name="filename">${env:PROXY_LOG_LOCATION:-/var/log/proxy}</Property>
    </Properties>

    <Select>
    <SystemPropertyArbiter propertyName="log.environment" propertyValue="production">

        <Appenders>

            <RollingFile name="GenericRollingFile" fileName="${filename}/application.log" filePattern="logs/application-%d{MM-dd-yyyy}-%i.log.gz">

[paulonicolau-rj]

I can´t see, but in my case, the problem is when i use a customlevels. If I remove the tag CustomLevels, all works fine.

[ppkarwasz]

@paulonicolau-rj,

Can you add your full configuration as text? Since all other nodes are interpolated using the properties that you provide, the <Properties> element must be the first child of <Configuration>.

[paulonicolau-rj]

@paulonicolau-rj,

Can you add your full configuration as text? Since all other nodes are interpolated using the properties that you provide, the <Properties> element must be the first child of <Configuration>.

Yes, follow:



<Configuration status="warn">
    <CustomLevels>
	    <CustomLevel name="EVENT" intLevel="550" />
    </CustomLevels>

    <Properties>
	    <Property name="basePath">${sys:catalina.home}/logs</Property>
    </Properties>

    <Appenders>
	    <RollingFile name="eventFile" fileName="${basePath}/api-event.log" filePattern="${basePath}/api-event-%d{yyyy-MM-dd}.log">
		    <LevelRangeFilter minLevel="EVENT" maxLevel="EVENT" onMatch="ACCEPT" onMismatch="DENY"/>
		    <PatternLayout>
			    <pattern>[%-5level] %d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %c{1} - %msg%n</pattern>
		    </PatternLayout>
		    <Policies>
			    <TimeBasedTriggeringPolicy interval="1" modulate="true" />
			    <SizeBasedTriggeringPolicy size="10MB" />
		    </Policies>
		    <!-- Max 10 files will be created everyday -->
		    <DefaultRolloverStrategy max="10">
			    <Delete basePath="${basePathr}" maxDepth="10">
				    <!-- Delete all files older than 30 days -->
				    <IfLastModified age="30d" />
			    </Delete>
		    </DefaultRolloverStrategy>
	    </RollingFile>
	    
	    <RollingFile name="infoFile" fileName="${basePath}/api-info.log" filePattern="${basePath}/api-info-%d{yyyy-MM-dd}.log">
		    <LevelRangeFilter minLevel="INFO" maxLevel="INFO" onMatch="ACCEPT" onMismatch="DENY"/>
		    <PatternLayout>
			    <pattern>[%-5level] %d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %c{1} - %msg%n</pattern>
		    </PatternLayout>
		    <Policies>
			    <TimeBasedTriggeringPolicy interval="1" modulate="true" />
			    <SizeBasedTriggeringPolicy size="10MB" />
		    </Policies>
		    <!-- Max 10 files will be created everyday -->
		    <DefaultRolloverStrategy max="10">
			    <Delete basePath="${basePathr}" maxDepth="10">
				    <!-- Delete all files older than 30 days -->
				    <IfLastModified age="30d" />
			    </Delete>
		    </DefaultRolloverStrategy>
	    </RollingFile>

	    <RollingFile name="errorFile" fileName="${basePath}/api-error.log" filePattern="${basePath}/api-error-%d{yyyy-MM-dd}.log">
		    <LevelRangeFilter minLevel="ERROR" maxLevel="ERROR" onMatch="ACCEPT" onMismatch="DENY"/>
		    <PatternLayout>
			    <pattern>[%-5level] %d{yyyy-MM-dd HH:mm:ss.SSS} [%t] %c{1} - %msg%n</pattern>
		    </PatternLayout>
		    <Policies>
			    <TimeBasedTriggeringPolicy interval="1" modulate="true" />
			    <SizeBasedTriggeringPolicy size="10MB" />
		    </Policies>
		    <!-- Max 10 files will be created everyday -->
		    <DefaultRolloverStrategy max="10">
			    <Delete basePath="${basePathr}" maxDepth="10">
				    <!-- Delete all files older than 30 days -->
				    <IfLastModified age="30d" />
			    </Delete>
		    </DefaultRolloverStrategy>
	    </RollingFile>
    </Appenders>

    <Loggers>
	    <Root level="all" additivity="false">
		    <appender-ref ref="eventFile" level="event"/>
		    <appender-ref ref="infoFile" level="info"/>
		    <appender-ref ref="errorFile" level="error" />
	    </Root>
    </Loggers>
</Configuration>

[ppkarwasz]

Switch the order of <Properties> and <CustomLevels>:

<Configuration>
    <Properties>
	    <Property name="basePath">${sys:catalina.home}/logs</Property>
    </Properties>

    <CustomLevels>
	    <CustomLevel name="EVENT" intLevel="550" />
    </CustomLevels>

    ...
</Configuration>

[paulonicolau-rj]

Switch the order of <Properties> and <CustomLevels>:

<Configuration>
    <Properties>
	    <Property name="basePath">${sys:catalina.home}/logs</Property>
    </Properties>

    <CustomLevels>
	    <CustomLevel name="EVENT" intLevel="550" />
    </CustomLevels>

    ...
</Configuration>

Thanks, it worked partially. Now, it´s working when I use absolute path like a value.
<Property name="basePath">/usr/share/tomcat/logs</Property>

But, if I use a system parameter, por example, it doesn´t work.
<Property name="basePath">${sys:catalina.home}/logs</Property>

[ppkarwasz]

Use:

<Property name="basePath" value="${sys:catalina.home}/logs"/>

Unlike XML attributes, the content of the <Property> element is not interpolated. This might actually be a bug:

logging-log4j2/log4j-core/src/main/java/org/apache/logging/log4j/core/config/Property.java

Lines 134 to 137 in 397771c

	public static Property createProperty(
	@PluginAttribute("name") final String name,
	@PluginValue(value = "value", substitute = false) final String rawValue,
	@PluginConfiguration final Configuration configuration) {

[paulonicolau-rj]

So, it worked fully. But, I consider the first report a bug too.
Thanks friend!

[ppkarwasz]

FYI: The restriction on the order of the <Properties> element was lifted in 2.23.0 (cf. #2278).

[ppkarwasz]

@paulonicolau-rj,

When you add other elements before <Properties> you get a ""Properties declaration must be the first element in the configuration" error message on your stdout.

[paulonicolau-rj]

I can´t see this message in stdout, but what I can see is the System property catalina.home is initilize before the container and so, it is store the log files in another folder of eclipse workspace. But this there isn´t a problem.

[ppkarwasz]

Regarding the second problem you reported, I am not able to reproduce it. Both:

<Property name="basePath" value="${sys:catalina.home}/logs"/>

and

<Property name="basePath">${sys:catalina.home}/logs</Property>

work for me.