Logback RollingFileAppender FileNotFoundException

user_4898739 0
Viewed 17259

I am using logback in my spring-boot project. When we deploy the app in PROD environment, deployment is failed with below exceptions. Before PROD, we deployed the app in lower environments, we did not see any issues. Can someone please throw some light?

In logback.xml we have specified the log path as /app/tomcatprofile/micro001/logs/sc-erp-security-permissions-check.log but from logs below, logpath is set as /app/tomcatprofile/micro001/logs.

Also attached our logback.xml.

15:54:22,305 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[FILE] - Active log file name: /app/tomcatprofile/micro001/logs
15:54:22,305 |-INFO in ch.qos.logback.core.rolling.RollingFileAppender[FILE] - File property is set to [/app/tomcatprofile/micro001/logs]
15:54:22,305 |-ERROR in ch.qos.logback.core.rolling.RollingFileAppender[FILE] - openFile(/app/tomcatprofile/micro001/logs,true) call failed. java.io.FileNotFoundException: /app/tomcatprofile/micro001/logs (Is a directory)
    at java.io.FileNotFoundException: /app/tomcatprofile/micro001/logs (Is a directory)
    at  at java.io.FileOutputStream.open0(Native Method)
    at  at java.io.FileOutputStream.open(FileOutputStream.java:270)
    at  at java.io.FileOutputStream.<init>(FileOutputStream.java:213)
    at  at ch.qos.logback.core.recovery.ResilientFileOutputStream.<init>(ResilientFileOutputStream.java:26)
    at  at ch.qos.logback.core.FileAppender.openFile(FileAppender.java:204)
    at  at ch.qos.logback.core.FileAppender.start(FileAppender.java:127)
    at  at ch.qos.logback.core.rolling.RollingFileAppender.start(RollingFileAppender.java:100)
    at  at ch.qos.logback.core.joran.action.AppenderAction.end(AppenderAction.java:90)
    at  at ch.qos.logback.core.joran.spi.Interpreter.callEndAction(Interpreter.java:309)
    at  at ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:193)
    at  at ch.qos.logback.core.joran.spi.Interpreter.endElement(Interpreter.java:179)
    at  at ch.qos.logback.core.joran.spi.EventPlayer.play(EventPlayer.java:62)
    at  at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:165)
    at  at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:152)
    at  at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:110)
    at  at ch.qos.logback.core.joran.GenericConfigurator.doConfigure(GenericConfigurator.java:53)
    at  at ch.qos.logback.classic.util.ContextInitializer.configureByResource(ContextInitializer.java:75)
    at  at ch.qos.logback.classic.util.ContextInitializer.autoConfig(ContextInitializer.java:150)
    at  at org.slf4j.impl.StaticLoggerBinder.init(StaticLoggerBinder.java:84)
    at  at org.slf4j.impl.StaticLoggerBinder.<clinit>(StaticLoggerBinder.java:55)
    at  at org.slf4j.LoggerFactory.bind(LoggerFactory.java:150)
    at  at org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:124)
    at  at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:412)
    at  at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:357)
    at  at org.apache.commons.logging.impl.SLF4JLogFactory.getInstance(SLF4JLogFactory.java:155)
    at  at org.apache.commons.logging.impl.SLF4JLogFactory.getInstance(SLF4JLogFactory.java:132)
    at  at org.apache.commons.logging.LogFactory.getLog(LogFactory.java:273)
    at  at org.springframework.boot.web.support.SpringBootServletInitializer.onStartup(SpringBootServletInitializer.java:86)
    at  at org.springframework.web.SpringServletContainerInitializer.onStartup(SpringServletContainerInitializer.java:169)
    at  at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5151)
    at  at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:150)
    at  at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:725)
    at  at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:701)
    at  at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:717)
    at  at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:917)
    at  at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1701)
    at  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at  at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at  at java.lang.Thread.run(Thread.java:745)

Logback.xml file

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

<configuration>

    <property name="FILE_PATH" value="${catalina.base}/logs/sc-erp-security-permissions-check.log" />

    <appender name="consoleAppender" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <Pattern>%d [%t] %-5p %c - %X{TransactionId} - %m%n</Pattern>
        </encoder>
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>TRACE</level>
        </filter>
    </appender>

    <appender name="mainAppender"
              class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${FILE_PATH}</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${FILE_PATH}.%d{yyyy-MM-dd}.log</fileNamePattern>
            <maxHistory>30</maxHistory>
        </rollingPolicy>
        <append>true</append>
        <encoder>
            <Pattern>%d [%t] %-5p %c - %X{TransactionId} - %m%n</Pattern>
        </encoder>
    </appender>

    <logger name="com.adp.smartconnect" additivity="false">
        <level value="DEBUG" />
        <appender-ref ref="mainAppender" />
        <appender-ref ref="consoleAppender" />
    </logger>

    <include resource="org/springframework/boot/logging/logback/base.xml"/>

    <logger name="org.springframework.web" level="INFO"/>
    <logger name="org.springframework.boot" level="WARN"/>
    <logger name="org.springframework.jmx" level="WARN"/>
    <logger name="com.adp.smartconnect.commons" level="WARN" />
    <logger name="springfox" level="WARN"/>

    <logger name="org.springframework.ws.client.MessageTracing.sent" level="INFO"/>
    <logger name="org.springframework.ws.client.MessageTracing.received" level="INFO"/>
    <logger name="org.springframework.ws.server.MessageTracing" level="INFO"/>

    <root>
        <level value="INFO" />
        <appender-ref ref="mainAppender" />
        <appender-ref ref="consoleAppender" />
    </root>
</configuration>
spring-logback spring-boot logback java
2 Answers

Our logback configuration uses spring-boot logback implementation internally, after I removed below line from logback.xml, issue is resolved.

<include resource="org/springframework/boot/logging/logback/base.xml"/>

Note: Our spring-boot version is 1.5.10

Puzzled questions:

  1. We still don't know why it is stripping "sc-erp-security-permissions-check.log" from complete log file path.
  2. With base.xml, deployment was successful in dev, qa and stage but failing only in 2 of 4 nodes in PROD.

I am still doing my research to find out exact root cause, will update this answer if I find something.

Thanks to @Andreas for his prompt responses.

user_48987390

In my case, the problem is caused by the running user does not have permission to create the folder containing the log file, which I set it to /var/log/webcast

What resolve my issue is to give permission to the running user in my .service file :

[Unit]
Description=myapp
After=syslog.target
  
[Service]
User=webcast
ExecStart=/bin/bash /opt/webcast/run.sh
SuccessExitStatus=143
Restart=always
RestartSec=5
StartLimitInterval=1

[Install]
WantedBy=multi-user.target

sudo usermod -aG adm **webcast**
user_19145570
Related