Rolling log file doesn't work

Support
#1

Hi all,

I don’t able to understand why log file app.log doesn’t rolling.

This is my logback.xml configuration

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

<configuration debug="true" scan="true" scanPeriod="30 seconds" packagingData="true">

    <property name="logDir" value="${app.home}/logs"/>

    <appender name="File" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${logDir}/app.log</file>

        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>DEBUG</level>
        </filter>

        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!-- daily rollover -->
            <fileNamePattern>${logDir}/app.%d{yyyy-MM}.log</fileNamePattern>
            <!-- keep 30 days' worth of history -->
            <maxHistory>30</maxHistory>
            <cleanHistoryOnStart>true</cleanHistoryOnStart>
        </rollingPolicy>

        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%thread%X{cubaApp}%X{cubaUser}] %logger - %msg%n</pattern>
        </encoder>
    </appender>

    <appender name="Console" class="ch.qos.logback.core.ConsoleAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>INFO</level>
        </filter>

        <encoder>
            <pattern>%d{HH:mm:ss.SSS} %-5level %-40logger{36}- %msg%n</pattern>
        </encoder>
    </appender>

    <root>
        <appender-ref ref="File"/>
    </root>

    <!-- Begin CUBA -->

    <logger name="com.haulmont.cuba" level="DEBUG"/>

    <logger name="com.haulmont.cuba.core.sys" level="INFO"/>

    <logger name="com.haulmont.cuba.core.sys.CubaDefaultListableBeanFactory" level="WARN"/>
    
    <logger name="com.haulmont.cuba.core.app.scheduling" level="INFO"/>

    <logger name="com.haulmont.cuba.web.sys" level="INFO"/>

    <logger name="com.haulmont.cuba.portal" level="INFO"/>

    <logger name="com.haulmont.restapi.sys" level="INFO"/>

    <logger name="com.haulmont.cuba.core.app.LockManager" level="INFO"/>
	
	<logger name="org.flowable" level="INFO"/>
	

    <!-- End CUBA -->

    <logger name="eclipselink" level="WARN"/>

    <logger name="eclipselink.sql" level="INFO"/>

    <logger name="org.springframework" level="WARN"/>

    <logger name="com.vaadin" level="WARN"/>

    <logger name="org.atmosphere" level="WARN"/>

    <logger name="org.activiti" level="INFO"/>

    <logger name="org.jgroups" level="INFO"/>
    
    <logger name="freemarker" level="INFO"/>

    <logger name="org.thymeleaf.TemplateEngine" level="INFO"/>

    <logger name="com.zaxxer.hikari" level="INFO"/>

    <logger name="org.docx4j" level="WARN"/>
    
	<logger name="org.xlsx4j" level="WARN"/>

    <logger name="org.apache.fop.apps.FOUserAgent" level="WARN"/>

    <logger name="org.hibernate" level="WARN"/>

    <logger name="sun" level="INFO"/>

    <logger name="com.sun" level="INFO"/>

    <logger name="javax" level="INFO"/>

    <logger name="org.apache" level="INFO"/>

    <logger name="org.eclipse.jetty" level="INFO"/>

    <logger name="org.docx4j.utils.ResourceUtils" level="ERROR"/>

    <logger name="org.docx4j.Docx4jProperties" level="ERROR"/>

    <logger name="org.xlsx4j.jaxb.Context" level="ERROR"/>

    <logger name="org.docx4j.utils.XSLTUtils" level="ERROR"/>

    <logger name="org.docx4j.jaxb.JaxbValidationEventHandler" level="ERROR"/>

    <logger name="org.docx4j.TraversalUtil" level="ERROR"/>

    <logger name="org.docx4j.fonts" level="ERROR"/>

    <!-- Begin Perf4J  -->

    <appender name="PerfStatFile" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${logDir}/perfstat.log</file>
        <append>true</append>

        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${logDir}/perfstat.%d{yyyy-MM-dd}.log</fileNamePattern>
            <maxHistory>30</maxHistory>
            <cleanHistoryOnStart>true</cleanHistoryOnStart>
        </rollingPolicy>

        <encoder>
            <pattern>%msg%n</pattern>
        </encoder>
    </appender>

    <appender name="CoalescingStatistics" class="org.perf4j.logback.AsyncCoalescingStatisticsAppender">
        <param name="TimeSlice" value="60000"/>
        <appender-ref ref="PerfStatFile"/>
    </appender>

    <appender name="UIPerfStatFile" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${logDir}/perfstat-ui.log</file>
        <append>true</append>

        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${logDir}/perfstat-ui.%d{yyyy-MM-dd}.log</fileNamePattern>
            <maxHistory>30</maxHistory>
            <cleanHistoryOnStart>true</cleanHistoryOnStart>
        </rollingPolicy>

        <encoder>
            <pattern>%msg%n</pattern>
        </encoder>
    </appender>

    <appender name="UICoalescingStatistics" class="org.perf4j.logback.AsyncCoalescingStatisticsAppender">
        <param name="TimeSlice" value="120000"/>
        <appender-ref ref="UIPerfStatFile"/>
    </appender>

    <logger name="org.perf4j.TimingLogger" additivity="false" level="INFO">
        <appender-ref ref="CoalescingStatistics"/>
    </logger>

    <logger name="com.haulmont.cuba.gui.logging.UIPerformanceLogger" additivity="false" level="INFO">
        <appender-ref ref="UICoalescingStatistics"/>
    </logger>

    <!-- End Perf4J  -->

</configuration>

The log record are written always on app.log, despite the logback documentation says that at changing date the log should rotate.

Thanks to all for the help.
Best regards

#2

Hi,

This is a pattern for monthly rollover, not daily…

#3

Hi Alexander,

I did a mistake writing the post, really in production I have yyyy-MM-dd as well as you can see in the other appenders, so the problem persists.

The installation that has this problem is done in windows SO and tomcat 9. I have another installation in docker where log rolling works fine (same logback.xml configuration)

Best regards

#4

I attach complete logback configuration.

<?xml version="1.0" encoding="UTF-8"?> 
<property name="logDir" value="${app.home}/logs"/>

<appender name="File" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>${logDir}/app.log</file>

    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
        <level>DEBUG</level>
    </filter>

    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
        <!-- daily rollover -->
        <fileNamePattern>${logDir}/app.%d{yyyy-MM-dd}.log</fileNamePattern>
        <!-- keep 30 days' worth of history -->
        <maxHistory>30</maxHistory>
        <cleanHistoryOnStart>true</cleanHistoryOnStart>
    </rollingPolicy>

    <encoder>
        <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%thread%X{cubaApp}%X{cubaUser}] %logger - %msg%n</pattern>
    </encoder>
</appender>

<appender name="Console" class="ch.qos.logback.core.ConsoleAppender">
    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
        <level>INFO</level>
    </filter>

    <encoder>
        <pattern>%d{HH:mm:ss.SSS} %-5level %-40logger{36}- %msg%n</pattern>
    </encoder>
</appender>

<appender name="SIFT" class="ch.qos.logback.classic.sift.SiftingAppender">
    <discriminator>
        <key>batchID</key>
        <defaultValue>default</defaultValue>
    </discriminator>
    <sift>
        <appender name="FILE${batchID}" class="ch.qos.logback.core.FileAppender">
            <file>${logDir}/batches/batch_${batchID}.log</file>
            <append>true</append>
            <encoder charset="UTF-8">
                <pattern>[%d{yyyy-MM-dd HH:mm:ss.SSS}] %-5level %logger{35} - %msg%n</pattern>
            </encoder>
        </appender>
    </sift>
</appender>

<logger name="it.hf" level="DEBUG" additivity="true">
    <appender-ref ref="SIFT"/>
</logger>

<root>
    <appender-ref ref="Console"/>
    <appender-ref ref="File"/>
</root>

<!-- Begin CUBA -->

<logger name="com.haulmont.cuba" level="DEBUG"/>

<logger name="com.haulmont.cuba.core.sys" level="INFO"/>

<logger name="com.haulmont.cuba.core.sys.CubaDefaultListableBeanFactory" level="WARN"/>

<logger name="com.haulmont.cuba.core.app.scheduling" level="INFO"/>

<logger name="com.haulmont.cuba.web.sys" level="INFO"/>

<logger name="com.haulmont.cuba.portal" level="INFO"/>

<logger name="com.haulmont.restapi.sys" level="INFO"/>

<logger name="com.haulmont.cuba.core.app.LockManager" level="INFO"/>

<logger name="org.flowable" level="INFO"/>


<!-- End CUBA -->

<logger name="eclipselink" level="WARN"/>

<logger name="eclipselink.sql" level="INFO"/>

<logger name="org.springframework" level="WARN"/>

<logger name="com.vaadin" level="WARN"/>

<logger name="org.atmosphere" level="WARN"/>

<logger name="org.activiti" level="INFO"/>

<logger name="org.jgroups" level="INFO"/>

<logger name="freemarker" level="INFO"/>

<logger name="org.thymeleaf.TemplateEngine" level="INFO"/>

<logger name="com.zaxxer.hikari" level="INFO"/>

<logger name="org.docx4j" level="WARN"/>

<logger name="org.xlsx4j" level="WARN"/>

<logger name="org.apache.fop.apps.FOUserAgent" level="WARN"/>

<logger name="org.hibernate" level="WARN"/>

<logger name="sun" level="INFO"/>

<logger name="com.sun" level="INFO"/>

<logger name="javax" level="INFO"/>

<logger name="org.apache" level="INFO"/>

<logger name="org.eclipse.jetty" level="INFO"/>

<logger name="org.docx4j.utils.ResourceUtils" level="ERROR"/>

<logger name="org.docx4j.Docx4jProperties" level="ERROR"/>

<logger name="org.xlsx4j.jaxb.Context" level="ERROR"/>

<logger name="org.docx4j.utils.XSLTUtils" level="ERROR"/>

<logger name="org.docx4j.jaxb.JaxbValidationEventHandler" level="ERROR"/>

<logger name="org.docx4j.TraversalUtil" level="ERROR"/>

<logger name="org.docx4j.fonts" level="ERROR"/>

<!-- Begin Perf4J  -->

<appender name="PerfStatFile" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>${logDir}/perfstat.log</file>
    <append>true</append>

    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
        <fileNamePattern>${logDir}/perfstat.%d{yyyy-MM-dd}.log</fileNamePattern>
        <maxHistory>30</maxHistory>
        <cleanHistoryOnStart>true</cleanHistoryOnStart>
    </rollingPolicy>

    <encoder>
        <pattern>%msg%n</pattern>
    </encoder>
</appender>

<appender name="CoalescingStatistics" class="org.perf4j.logback.AsyncCoalescingStatisticsAppender">
    <param name="TimeSlice" value="60000"/>
    <appender-ref ref="PerfStatFile"/>
</appender>

<appender name="UIPerfStatFile" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>${logDir}/perfstat-ui.log</file>
    <append>true</append>

    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
        <fileNamePattern>${logDir}/perfstat-ui.%d{yyyy-MM-dd}.log</fileNamePattern>
        <maxHistory>30</maxHistory>
        <cleanHistoryOnStart>true</cleanHistoryOnStart>
    </rollingPolicy>

    <encoder>
        <pattern>%msg%n</pattern>
    </encoder>
</appender>

<appender name="UICoalescingStatistics" class="org.perf4j.logback.AsyncCoalescingStatisticsAppender">
    <param name="TimeSlice" value="120000"/>
    <appender-ref ref="UIPerfStatFile"/>
</appender>

<logger name="org.perf4j.TimingLogger" additivity="false" level="INFO">
    <appender-ref ref="CoalescingStatistics"/>
</logger>

<logger name="com.haulmont.cuba.gui.logging.UIPerformanceLogger" additivity="false" level="INFO">
    <appender-ref ref="UICoalescingStatistics"/>
</logger>

<!-- End Perf4J  -->

Thanks to all for the help.
BR

#5

The appender configuration looks OK.
Maybe the user who runs the Tomcat doesn’t have permissions to create files in the directory?
Maybe there were no messages since the last day in this appender, so it hadn’t chance to rollover the file?

I would also look into the server log file which stores stdout / stderr messages. Logback would write an error to that destination if it would unable to roll a log file for some reason, at midnight or at first appearance of a new message on a new day.

I’m sorry but we here aren’t Logback experts.
Here is the mailing list of the library where one can ask the authors and community: Mailing lists

#6

Hi all,

I found a solution in case of TimeBaseRollingPolicy, after read this documentation: Logback Error Codes

The problem could be the contemporary access to the file and che process cannot rename/create new file.

The solution is omit the tag from the appender.

I hope this could be useful for other.

BR.

1 Like