Date: 2013-06-05 15:44:46 +0200
From: Christian Braun <>
To: SQL devs <>
Version: 11.15.19 (Feb2013-SP6)
CC: @mlkersten, @njnes

Last updated: 2014-02-20 15:03:08 +0100

Comment 18779

Date: 2013-06-05 15:44:46 +0200
From: Christian Braun <>

User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:21.0) Gecko/20100101 Firefox/21.0
Build Identifier:

Hello,

i am having these GDKmmap failure / recovery message in the logfile. Is this a bug?
The database takes 30 minutes to startup and become available. It contains 4TB of data. The server has 256GB RAM. Is the startup time related to the database size? Is it normal to take that long?

Thank you for any help,
Christian Braun.

Debian 6.0 with version:
ii monetdb5-server 11.15.7-20130426 MonetDB database server version 5

2013-06-05 14:37:03 MSG merovingian[63122]: Merovingian 1.7 (Feb2013-SP2) starting
2013-06-05 14:37:03 MSG merovingian[63122]: monitoring dbfarm /var/monetdb/dbfarm
2013-06-05 14:37:03 MSG merovingian[63122]: accepting connections on TCP socket 0.0.0.0:50000
2013-06-05 14:37:03 MSG merovingian[63122]: accepting connections on UNIX domain socket /tmp/.s.monetdb.50000
2013-06-05 14:37:03 MSG discovery[63122]: listening for UDP messages on 0.0.0.0:50000
2013-06-05 14:37:03 MSG control[63122]: accepting connections on UNIX domain socket /tmp/.s.merovingian.50000
2013-06-05 14:37:06 MSG control[63122]: (local): served status list
2013-06-05 14:37:06 MSG merovingian[63122]: starting database 'db', up min/avg/max: 4s/1d/6w, crash average: 0.00 0.10 0.07 (321-315=6)
2013-06-05 14:37:07 MSG db[63137]: arguments: /usr/bin/mserver5 --dbpath=/var/monetdb/dbfarm/db --set merovingian_uri=mapi:monetdb://lhotse:50000/db --set mapi_open=false --set mapi_port=0 --set mapi_us
ock=/var/monetdb/dbfarm/db/.mapi.sock --set monet_vault_key=/var/monetdb/dbfarm/db/.vaultkey --set gdk_nr_threads=32 --set max_clients=64 --set sql_optimizer=default_pipe --set monet_daemon=yes
2013-06-05 14:59:15 MSG db[63137]: MonetDB 5 server v11.15.7 "Feb2013-SP2"
2013-06-05 14:59:15 MSG db[63137]: Serving database 'db', using 32 threads
2013-06-05 14:59:15 MSG db[63137]: Compiled for x86_64-pc-linux-gnu/64bit with 64bit OIDs dynamically linked
2013-06-05 14:59:15 MSG db[63137]: Found 252.390 GiB available main-memory.
2013-06-05 14:59:15 MSG db[63137]: Copyright (c) 1993-July 2008 CWI.
2013-06-05 14:59:15 MSG db[63137]: Copyright (c) August 2008-2013 MonetDB B.V., all rights reserved
2013-06-05 14:59:15 MSG db[63137]: Visit http://www.monetdb.org/ for further information
2013-06-05 14:59:15 MSG db[63137]: Listening for UNIX domain connection requests on mapi:monetdb:///var/monetdb/dbfarm/db/.mapi.sock
2013-06-05 14:59:15 MSG db[63137]: GDKmmap(45613056) fails, try to free up space [memory in use=195224400,virtual memory in use=4937100485456]
2013-06-05 14:59:15 MSG db[63137]: GDKmmap(45613056) result [mem=185323792,vm=194498832]
2013-06-05 14:59:15 MSG db[63137]: GDKmmap: recovery ok. Continuing..
2013-06-05 14:59:15 MSG db[63137]: MonetDB/SQL module loaded
2013-06-05 14:59:15 MSG control[63122]: (local): started 'db'

Reproducible: Always

Comment 18793

Date: 2013-06-07 15:22:51 +0200
From: @njnes

During startup the old logs need to be checked. This process may touch a lot of tables/columns which in your case could mean lots of data/IO. The MMAP failures indicate MonetDB is running out of memory. Are there really big tables which could explain this?

Comment 18796

Date: 2013-06-07 16:34:08 +0200
From: Christian Braun <>

There are 4 huge tables. The largest has 6.4 billion rows. The other tables are of modest size. What does this mean for the largest table? Queries seems to work fine on it.

Thank you,
Christian.

Comment 18820

Date: 2013-06-12 10:25:25 +0200
From: @njnes

startup shouldn't be al that expensive. The mmap usage indicates some log rollforward is needed. Are you doing lots of updates?

Comment 18828

Date: 2013-06-12 12:16:48 +0200
From: Christian Braun <>

Yes, many updates. I load new data via copy into and then do a lot of updates to set extra columns. About 150 copy into and 15000 update statements on a daily basis.

Comment 18829

Date: 2013-06-12 12:35:19 +0200
From: @njnes

Could right before the restart check how large the log files (monetdb5/dbfarm/dbname/sql_logs/sql/log*) are.

Comment 18830

Date: 2013-06-12 12:38:10 +0200
From: Christian Braun <>

ls /var/monetdb/dbfarm/db/sql_logs/sql/ -l
total 1036
-rw------- 1 monetdb monetdb 14 Jun 12 04:31 log
-rw------- 1 monetdb monetdb 2 May 22 2012 log.10585
-rw------- 1 monetdb monetdb 2 Jun 5 21:22 log.27162
-rw------- 1 monetdb monetdb 524308 Jun 12 05:04 log.27479

Comment 18831

Date: 2013-06-12 12:43:57 +0200
From: @njnes

did a restart with these small logs take long?

Comment 18833

Date: 2013-06-12 14:20:54 +0200
From: Christian Braun <>

Yes, startup took 20 minutes.

Comment 19065

Date: 2013-08-25 09:45:52 +0200
From: @njnes

I just tested (again) on a 256G machine with tpch sf 1000. And restarting takes
at most 3 sec. Do you have many tables?

Comment 19066

Date: 2013-08-25 09:48:53 +0200
From: Christian Braun <>

~4000 tables

Comment 19068

Date: 2013-08-25 10:04:19 +0200
From: @mlkersten

A test for large cataloges can be found int
the test suite
BugTracker-2012/Tests/huge_table_update.Bug-2803.sql

Perhaps callgrind can give a hint on the performance loss culprit

Comment 19069

Date: 2013-08-25 10:28:44 +0200
From: @mlkersten

running this script with 5000 updates over empty table with 5000 colums takes 10 min.
It could be expanded to work on non-empty tables to approach the case discussed in this bug report.

Comment 19076

Date: 2013-08-25 22:38:43 +0200
From: @mlkersten

Created attachment 224
kcachegrind grab of top use

kcachegrind grab

Attached file: hugetable.tiff (image/tiff, 99458 bytes)
Description: kcachegrind grab of top use

Comment 19077

Date: 2013-08-25 22:42:27 +0200
From: @mlkersten

Created attachment 225
List_find_column

80% of all cycles are spent in this code fragment

Attached file: list_find_column.tiff (image/tiff, 120556 bytes)
Description: List_find_column

Comment 19078

Date: 2013-08-26 08:46:25 +0200
From: MonetDB Mercurial Repository <>

Changeset eac781c321ce made by Martin Kersten mk@cwi.nl in the MonetDB repo, refers to this bug.

For complete details, see http//devmonetdborg/hg/MonetDB?cmd=changeset;node=eac781c321ce

Changeset description:

Added insert into huge table test
This test could potentially be used to debug slow recovery
as reported in bug #3298

Comment 19080

Date: 2013-08-26 20:19:31 +0200
From: @njnes

on restart the logs are indeed replayed. This used to be quick but a small change could lead to changes on files which now need to be flushed (which is
enforced using fsync/fdatasync). This may be very slow.

Comment 19415

Date: 2013-12-11 16:42:42 +0100
From: @njnes

the test now takes 16sec (was 10Min). Seems time to close this bug.

Comment 19624

Date: 2014-02-20 15:03:08 +0100
From: @sjoerdmullender

Jan2014 has been released.