CODEWITHSUNDEEP
javadatabaseh2filesize
hfs
hfs

Reputation: 2593

H2 database keeps growing: How to analyze the output of the Recover tool?

We use H2 for a long running process which stores many short-lived “events” to an embedded H2 database. There’s a high throughput of rows being inserted and deleted, but the frequency of events varies.

On a semi-productive system the database file had grown to 27 GiB. After compacting it thoroughly, the file only has 1.25 MiB. That’s a factor >20000!

I understand that H2 will not compact during runtime but mark and reuse free space and I think that should be ok. At some point there should be balance between used and free space and the database file should not need to grow further.

H2’s Recover tool is often recommended to analyze such situations (with switch -transactionLog). How to interpret the output of the Recover tool?

First of all, the statistics section at the bottom:

---- Statistics ----
-- page count: 14147341, free: 14106216
-- page data bytes: head 612539, empty 20613944, rows 9040909 (32% full)
-- free 99%, 14108082 page(s)
-- data leaf 0%, 14779 page(s)
-- data node 0%, 241 page(s)
-- btree leaf 0%, 2644 page(s)
-- btree node 0%, 564 page(s)
-- free list 0%, 865 page(s)
-- stream trunk 0%, 39 page(s)
-- stream data 0%, 20124 page(s)

The free page count shows that almost all space is taken by free pages (default page size of 2 KiB).

Stream data 20124 pages means that 40 MiB are used for the transaction log, right?

Next question is about LOBs. In my Recover output there are 13342 INSERT statements for INFORMATION_SCHEMA.LOB_DATA. But when I open the database in the console, this table only has 2 rows. Why the difference?

The usual suspect are uncommitted transactions. Looking at the code autocommit is never switched off, but I want to check anyway. My Recover output has 702431 rows of transaction log. That looks a lot to me? Is that normal? How do I recognize uncommitted transactions? The first few lines look like this:

---- Transaction log ----
-- log 164481:8670836 next: 8673913
-- log 164481:8670836/8672265
-- undo page 34939 data leaf (last)
-- undo page 32723 free list 
-- undo page 8590631 data node 
-- log 164481:8670836/8672266
-- undo page 42949 data node 
-- undo page 6686382 data node 
-- undo page 44 data node 
-- session 1 table 10 - 61593342
DELETE FROM INFORMATION_SCHEMA.LOB_DATA WHERE _ROWID_ = 61593342;
-- commit 1
-- undo page 111 b-tree leaf (last)
-- log 164481:8670836/8672267
-- undo page 62 b-tree node (last)
-- log 164481:8670836/8672268
-- undo page 3566625 b-tree node (last)
-- undo page 48 b-tree node (last)
-- undo page 8590604 data leaf (last)
-- log 164481:8670836/8672269
-- undo page 42802 data node 
-- undo page 8187925 data node 
-- undo page 49 data node 
-- session 1 table 2 - 48272953
DELETE FROM INFORMATION_SCHEMA.LOBS WHERE _ROWID_ = 48272953;
-- commit 1

Aren’t those two committed successfully? Why are they still in the log?

The H2 version is 1.3.163. I have tried 1.3.176 with artificial events, but the file grew fast in the same way.

These questions are related, but didn’t really help me:

Upvotes: 1

Views: 1597

Answers (1)

Thomas Mueller
Thomas Mueller

Reputation: 50107

For the file you have analyzed, 99% of all pages are free: free 99%, 14108082 page(s). So I guess 99% of the data was removed by then (tables truncated, tables dropped, indexes dropped, LOBs removed, transaction log truncated, temporary tables removed, and so on). Therefore, analyzing this file will not help.

What would be interesting is to analyze a file before 99% became free. To do that, you could for example copy the file while the program is running, using the built-in backup feature (SQL statement backup to ...). And then analyze that file (run the Recover tool on that file). You may need to do that multiple times, until you find the place where 99% of the file is not yet free.

Upvotes: 1

Related Questions