High processor usage when no transactions taking place - revisited

[andreas fw]

Hi,

I am having an issue, which may be related to the post by Stephen 3/12/14 titled "High processor usage when no transactions taking place".

I have a Linux box that has been running fine for 3 weeks with a Java app that uses an embedded H2 file database. Suddenly at 3am without any real activity within a minute the average CPU load went from 8% to 25-30%, where a single Java thread "MVStore background writer" takes up 100% when no reads or writes are taking place. Some details about the system:

    1 proc box with 1 SSD
    1 Java app with an embedded H2 file database (1.4.192). The size of the db file is ~500 MB.
    The usage profile:
        Writes 10-100 rows every minute and few random smaller reads (only a few users connected)
    The Java app connection parameter:
        jdbc:h2:file:/mnt/data/x/x-db
        (i.e. no special H2 config)
    Hardware
         1 x Intel Celeron 1900 quad core
    OS
      Ubuntu 16.04 Server edition
      Linux kernel 4.4.64


Running jstack and jvmtop showed that 100% of a thread is spent in the MVStore :

org.h2.store.fs.FileNio.read(FilePathNio.java:74)

(no other threads are taking up time or have to do with H2)

"MVStore background writer nio:/mnt/data/x/x-db.mv.db" #104 daemon prio=5 os_prio=0 tid=0x00007ff09c299000 nid=0x7208 runnable [0x00007ff0832f3000]
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.NativeThread.current(Native Method)
        at sun.nio.ch.NativeThreadSet.add(NativeThreadSet.java:46)
        at sun.nio.ch.FileChannelImpl.readInternal(FileChannelImpl.java:737)
        at sun.nio.ch.FileChannelImpl.read(FileChannelImpl.java:727)
        at org.h2.store.fs.FileNio.read(FilePathNio.java:74)
        at org.h2.mvstore.cache.FilePathCache$FileCache.read(FilePathCache.java:87)
        at org.h2.mvstore.DataUtils.readFully(DataUtils.java:429)
        at org.h2.mvstore.FileStore.readFully(FileStore.java:98)
        at org.h2.mvstore.Page.read(Page.java:190)
        at org.h2.mvstore.MVStore.readPage(MVStore.java:1944)
        at org.h2.mvstore.MVMap.readPage(MVMap.java:736)
        at org.h2.mvstore.Page.getChildPage(Page.java:217)
        at org.h2.mvstore.MVMap.rewrite(MVMap.java:823)
        at org.h2.mvstore.MVMap.rewrite(MVMap.java:823)
        at org.h2.mvstore.MVMap.rewrite(MVMap.java:823)
        at org.h2.mvstore.MVMap.rewrite(MVMap.java:823)
        at org.h2.mvstore.MVMap.rewrite(MVMap.java:782)
        at org.h2.mvstore.MVStore.compactRewrite(MVStore.java:1910)
        at org.h2.mvstore.MVStore.compact(MVStore.java:1802)
        - locked <0x0000000087734c88> (a java.lang.Object)
        at org.h2.mvstore.MVStore.writeInBackground(MVStore.java:2504)

This couldn't be normal, I think..? Does this have to do with the MVStore compaction?
Thanks in advance for your assistance!

Kind Regards

Andreas W

[Thomas Mueller Graf]

Hi,

Yes, this is the background thread trying to compact (garbage collect) the database file. It should only occur if there is no other write activity, and should not affect write performance.

Regards,

Thomas

--
You received this message because you are subscribed to the Google Groups "H2 Database" group.
To unsubscribe from this group and stop receiving emails from it, send an email to h2-database+unsubscribe@googlegroups.com.
To post to this group, send email to h2-da...@googlegroups.com.
Visit this group at https://groups.google.com/group/h2-database.
For more options, visit https://groups.google.com/d/optout.

[andreas fw]

Hi Thomas,
thanks for the answer. But why does it keep running? That thread has been running constantly for 10 days now?
FYI, there is another 3rd party application process that writes data to the same disk, maybe on average 2 MB/sek - that shouldn't make a big impact or...?

Thanks,
-Andreas

[Thomas Mueller Graf]

Hi,

It should not keep running. Does it happen with the latest version of H2? Could you send me the database file (compressed)?

Regards,

Thomas

[andreas fw]

Hi Thomas,
it kept running with a high CPU usage in h2 v. 1.4.192 until we restarted the java app. I'm updating to 1.4.193 now and will keep an eye on it.
Unfortunately I can't send the DB file to you, because it contains confidential information, and if I modify the DB the problem could go away...

Thanks again!
-Andreas

Den fredag den 3. marts 2017 kl. 21.22.48 UTC+1 skrev Thomas Mueller Graf:

Hi,

It should not keep running. Does it happen with the latest version of H2? Could you send me the database file (compressed)?

Regards,

Thomas

On Thu, Mar 2, 2017 at 1:35 PM, andreas fw <and...@wehowsky.dk> wrote:

Hi Thomas,
thanks for the answer. But why does it keep running? That thread has been running constantly for 10 days now?
FYI, there is another 3rd party application process that writes data to the same disk, maybe on average 2 MB/sek - that shouldn't make a big impact or...?

Thanks,
-Andreas

Den onsdag den 1. marts 2017 kl. 17.35.38 UTC+1 skrev Thomas Mueller Graf:

Hi,

Yes, this is the background thread trying to compact (garbage collect) the database file. It should only occur if there is no other write activity, and should not affect write performance.

Regards,

Thomas

--
You received this message because you are subscribed to the Google Groups "H2 Database" group.

To unsubscribe from this group and stop receiving emails from it, send an email to h2-database...@googlegroups.com.