Strict Mode - Resource leak with logback.xml

[aneebq]

This issue pertains to Logback 1.08.

With strict mode enabled, I'm seeing an error which causes the application to crash. The error only occurs when attempting to pull logback configuration from the logback.xml file in our assets directory.

From what I gather, it's because the stream that reads the XML file is not properly closed.

We did not have this with Logback 1.07.

Here's the stack trace:

05-07 18:51:33.563: E/StrictMode(10832): A resource was acquired at attached stack trace but never released. See java.io.Closeable for information on avoiding resource leaks.
05-07 18:51:33.563: E/StrictMode(10832): java.lang.Throwable: Explicit termination method 'end' not called
05-07 18:51:33.563: E/StrictMode(10832): at dalvik.system.CloseGuard.open(CloseGuard.java:184)
05-07 18:51:33.563: E/StrictMode(10832): at java.util.zip.Inflater.(Inflater.java:82)
05-07 18:51:33.563: E/StrictMode(10832): at java.util.zip.ZipFile.getInputStream(ZipFile.java:270)
05-07 18:51:33.563: E/StrictMode(10832): at java.util.jar.JarFile.getInputStream(JarFile.java:388)
05-07 18:51:33.563: E/StrictMode(10832): at libcore.net.url.JarURLConnectionImpl.getInputStream(JarURLConnectionImpl.java:226)
05-07 18:51:33.563: E/StrictMode(10832): at java.net.URL.openStream(URL.java:462)
05-07 18:51:33.563: E/StrictMode(10832): at java.lang.ClassLoader.getResourceAsStream(ClassLoader.java:436)
05-07 18:51:33.563: E/StrictMode(10832): at ch.qos.logback.classic.util.ContextInitializer.getResource(Unknown Source)
05-07 18:51:33.563: E/StrictMode(10832): at ch.qos.logback.classic.util.ContextInitializer.findConfigFileURLFromAssets(Unknown Source)
05-07 18:51:33.563: E/StrictMode(10832): at ch.qos.logback.classic.util.ContextInitializer.autoConfig(Unknown Source)
05-07 18:51:33.563: E/StrictMode(10832): at org.slf4j.impl.StaticLoggerBinder.init(Unknown Source)
05-07 18:51:33.563: E/StrictMode(10832): at org.slf4j.impl.StaticLoggerBinder.(Unknown Source)
05-07 18:51:33.563: E/StrictMode(10832): at org.slf4j.LoggerFactory.bind(LoggerFactory.java:128)
05-07 18:51:33.563: E/StrictMode(10832): at org.slf4j.LoggerFactory.performInitialization(LoggerFactory.java:107)
05-07 18:51:33.563: E/StrictMode(10832): at org.slf4j.LoggerFactory.getILoggerFactory(LoggerFactory.java:295)
05-07 18:51:33.563: E/StrictMode(10832): at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:269)
05-07 18:51:33.563: E/StrictMode(10832): at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:281)
05-07 18:51:33.563: E/StrictMode(10832): at c.a.v.a.a.AndroidApplication.(AndroidApplication.java:12)
05-07 18:51:33.563: E/StrictMode(10832): at java.lang.Class.newInstanceImpl(Native Method)
05-07 18:51:33.563: E/StrictMode(10832): at java.lang.Class.newInstance(Class.java:1319)
05-07 18:51:33.563: E/StrictMode(10832): at android.app.Instrumentation.newApplication(Instrumentation.java:957)
05-07 18:51:33.563: E/StrictMode(10832): at android.app.Instrumentation.newApplication(Instrumentation.java:942)
05-07 18:51:33.563: E/StrictMode(10832): at android.app.LoadedApk.makeApplication(LoadedApk.java:556)
05-07 18:51:33.563: E/StrictMode(10832): at android.app.ActivityThread.handleBindApplication(ActivityThread.java:4101)
05-07 18:51:33.563: E/StrictMode(10832): at android.app.ActivityThread.access$1300(ActivityThread.java:126)
05-07 18:51:33.563: E/StrictMode(10832): at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1210)
05-07 18:51:33.563: E/StrictMode(10832): at android.os.Handler.dispatchMessage(Handler.java:99)
05-07 18:51:33.563: E/StrictMode(10832): at android.os.Looper.loop(Looper.java:137)
05-07 18:51:33.563: E/StrictMode(10832): at android.app.ActivityThread.main(ActivityThread.java:4586)
05-07 18:51:33.563: E/StrictMode(10832): at java.lang.reflect.Method.invokeNative(Native Method)
05-07 18:51:33.563: E/StrictMode(10832): at java.lang.reflect.Method.invoke(Method.java:511)
05-07 18:51:33.563: E/StrictMode(10832): at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:784)
05-07 18:51:33.563: E/StrictMode(10832): at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:551)
05-07 18:51:33.563: E/StrictMode(10832): at dalvik.system.NativeStart.main(Native Method)
05-07 18:51:33.563: W/System.err(10832): StrictMode VmPolicy violation with POLICY_DEATH; shutting down.

[tony19]

Interesting. I'll take a look later tonight.

[aneebq]

Hopefully it's nothing major. Thanks for the quick reply to the issue.

[tony19]

Can you please test 1.0.10-2-SNAPSHOT.jar for the crash? (I've also deployed the core/classic jars to the Sonatype snapshot repo in case you're using a Maven project)

Even though I found the bug and fixed it, I wasn't able to reproduce the symptom on my Galaxy S4. Perhaps my logback.xml doesn't have the right recipe to cause the crash.

[aneebq]

That works great! Thanks for the quick fix.

[tony19]

Thanks for checking. Can you share a sample logback.xml configuration that caused the problem?

[aneebq]

Here you go:

<configuration>
    <appender
            name="LOGCAT"
            class="ch.qos.logback.classic.android.LogcatAppender">
        <tagEncoder>
            <pattern>%logger{25} [%thread]</pattern>
        </tagEncoder>
        <encoder>
            <pattern>[%method] > %msg%n</pattern>
        </encoder>
    </appender>

    <root level="ERROR">
        <appender-ref ref="LOGCAT" />
    </root>

    <logger name="c.a.v" level="WARN"/>
</configuration>

[tony19]

I formatted it for you...to show xml, use three backticks one one line (at column 0). Append "xml" for XML syntax highlighting.

```xml
<foo>bar</foo>
```

---

I'll have to try that later (but I had a very similar config). Thanks again.

[tony19]

v1.0.10-2 is released with this fix.

[lock]

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.