Why am I getting memory quota exceeded errors on Heroku even while unused? (play2/scala)

Question

Just sitting with no requests, I get memory keeps on increasing, eventually to memory quota exceeded. There are multiple things I don't understand.

1. Why memory use keeps increasing when no requests?
2. Where does the value of "Process running mem" come from (does not seem to be a sum of any combination of numbers from the Heap and Non-Heap usage that I can tell).
3. Why does it exceed even though I have the recommended JAVA_OPTS: -Xmx384m -Xss512k -XX:+UseCompressedOops -javaagent:heroku-javaagent-1.2.jar=stdout=true?

Here is a sample of the log file

app/web.1:  heroku-javaagent: JVM Memory Usage     (Heap): used: 275M committed: 349M max:349M 
app/web.1:  heroku-javaagent: JVM Memory Usage (Non-Heap): used: 37M committed: 37M max:219M 
app/web.1:  heroku-javaagent: JVM Threads                : total: 37 daemon: 7 non-daemon: 21 internal: 9 
app/web.1:  heroku-javaagent: JVM Memory Usage     (Heap): used: 276M committed: 349M max:349M 
app/web.1:  heroku-javaagent: JVM Memory Usage (Non-Heap): used: 37M committed: 37M max:219M 
app/web.1:  heroku-javaagent: JVM Threads                : total: 37 daemon: 7 non-daemon: 21 internal: 9 
app/web.1:  heroku-javaagent: JVM Memory Usage     (Heap): used: 277M committed: 349M max:349M 
app/web.1:  heroku-javaagent: JVM Memory Usage (Non-Heap): used: 37M committed: 37M max:219M 
app/web.1:  heroku-javaagent: JVM Threads                : total: 37 daemon: 7 non-daemon: 21 internal: 9 
app/web.1:  heroku-javaagent: JVM Memory Usage     (Heap): used: 277M committed: 349M max:349M 
app/web.1:  heroku-javaagent: JVM Memory Usage (Non-Heap): used: 37M committed: 37M max:219M 
app/web.1:  heroku-javaagent: JVM Threads                : total: 37 daemon: 7 non-daemon: 21 internal: 9 
app/web.1:  heroku-javaagent: JVM Memory Usage     (Heap): used: 278M committed: 349M max:349M 
app/web.1:  heroku-javaagent: JVM Memory Usage (Non-Heap): used: 37M committed: 37M max:219M 
app/web.1:  heroku-javaagent: JVM Threads                : total: 37 daemon: 7 non-daemon: 21 internal: 9 
heroku/web.1:  Process running mem=517M(101.1%) 
heroku/web.1:  Error R14 (Memory quota exceeded) 
heroku/web.1:  Process running mem=517M(101.1%) 
heroku/web.1:  Error R14 (Memory quota exceeded) 
heroku/web.1:  Process running mem=517M(101.1%) 
heroku/web.1:  Error R14 (Memory quota exceeded) 
app/web.1:  heroku-javaagent: JVM Memory Usage     (Heap): used: 212M committed: 349M max:349M 
app/web.1:  heroku-javaagent: JVM Memory Usage (Non-Heap): used: 37M committed: 37M max:219M 
app/web.1:  heroku-javaagent: JVM Threads                : total: 37 daemon: 7 non-daemon: 21 internal: 9 
heroku/web.1:  Process running mem=517M(101.1%) 
heroku/web.1:  Error R14 (Memory quota exceeded) 
heroku/web.1:  Process running mem=517M(101.1%) 
heroku/web.1:  Error R14 (Memory quota exceeded) 
heroku/web.1:  Process running mem=517M(101.1%) 
heroku/web.1:  Error R14 (Memory quota exceeded) 
app/web.1:  heroku-javaagent: JVM Memory Usage     (Heap): used: 213M committed: 349M max:349M 
app/web.1:  heroku-javaagent: JVM Memory Usage (Non-Heap): used: 37M committed: 37M max:219M 
app/web.1:  heroku-javaagent: JVM Threads                : total: 37 daemon: 7 non-daemon: 21 internal: 9 
heroku/web.1:  Process running mem=517M(101.1%) 
heroku/web.1:  Error R14 (Memory quota exceeded) 
heroku/web.1:  Process running mem=517M(101.1%) 
heroku/web.1:  Error R14 (Memory quota exceeded) 
heroku/web.1:  Process running mem=517M(101.1%) 
heroku/web.1:  Error R14 (Memory quota exceeded) 
app/web.1:  heroku-javaagent: JVM Memory Usage     (Heap): used: 213M committed: 349M max:349M 
app/web.1:  heroku-javaagent: JVM Memory Usage (Non-Heap): used: 37M committed: 37M max:219M 
app/web.1:  heroku-javaagent: JVM Threads                : total: 37 daemon: 7 non-daemon: 21 internal: 9 
heroku/web.1:  Process running mem=517M(101.1%) 
heroku/web.1:  Error R14 (Memory quota exceeded) 
heroku/web.1:  Process running mem=517M(101.1%) 
heroku/web.1:  Error R14 (Memory quota exceeded) 
heroku/web.1:  Process running mem=517M(101.1%) 
heroku/web.1:  Error R14 (Memory quota exceeded) 
app/web.1:  heroku-javaagent: JVM Memory Usage     (Heap): used: 214M committed: 349M max:349M 
app/web.1:  heroku-javaagent: JVM Memory Usage (Non-Heap): used: 37M committed: 37M max:219M 
app/web.1:  heroku-javaagent: JVM Threads                : total: 37 daemon: 7 non-daemon: 21 internal: 9 
heroku/web.1:  Process running mem=517M(101.1%) 
heroku/web.1:  Error R14 (Memory quota exceeded) 
heroku/web.1:  Process running mem=517M(101.1%) 
heroku/web.1:  Error R14 (Memory quota exceeded) 
heroku/web.1:  Process running mem=517M(101.1%) 
heroku/web.1:  Error R14 (Memory quota exceeded) 

Answer 1

This issue should not be specific to Heroku and should (ideally) be able to be reproduced locally. First, I would recommend running your app locally the same way Heroku runs it:

• Run sbt clean compile stage to create the target/start launcher
• Launch your app with target/start -Dhttp.port=$PORT $JAVA_OPTS (set PORT to whatever you want)

Then I would use a memory profiler, such as VisualVM, to attach to your app running locally to see what's going on.

If this does not work or you'd like to get a better breakdown of the memory usage on Heroku, I'd recommend enabling log-runtime-metrics. This can also be used with Log2Viz to get a realtime memory visualizations.

Answer 2

Just had a similar problem. I wasn't able to reproduce the problem locally. It turned out that we had a file appender in our logging configuration. Writing to the logs made the memory grow. You can verify that, by writing a small app that logs a lot. If you enable log-runtime-metrics, you'll see memory_cache and memory_total grow.