VOS7: Deadlock: Write wait on column page <number>. Waits should be on the index leaf page, except when col page is held for read by background write

[Aklakan]

I get this messages trying to load the LinkedGeoData data sets (especially the _.ways._ ones, that contain long linestrings) at

http://downloads.linkedgeodata.org/releases/2013-04-29/

Most of time it seems the DB can recover, but at some point it seems to result in a deadlock and only a kill -9 can bring the DB down. Afterwards, I have to remove the transaction log, otherwise upon replay it will again run into the deadlock. Seems like it is somehow related to large objects (e.g. polygons) exceeding page boundaries.

My virtuoso.ini is configured for 4 GB RAM and the virtuoso.db file is about 16GB; but I think the deadlock problem is rather independent of the db file size.

With point geometries this problem also happens, but much less frequent.

Note on loading the datasets: For Virtuoso, you need to do a little conversion (the awk part is there to experiment by filtering lines by length):

bzcat "$file" | ./convert-virtuoso.sh | ./discard-corrupted-geometries.sh | awk 'length<2048' > "$tmp"

The scripts (just sed - 1-liners) are available here:

http://downloads.linkedgeodata.org/releases/scripts/

[openlink]

I believe the root cause of this problem has been addressed in the latest version on develop/7

Can you retest this?

[hanito]

Nope it hasn't I GUESS! I am running the latest version of virtuoso 7.2.0. and I am still have the same problem.

18:04:13 Write wait on column page 225593.  Waits should be on the index leaf page, except when col page is held for read by background write
18:04:13 Write wait on column page 225773.  Waits should be on the index leaf page, except when col page is held for read by background write

[vijayranker]

I am having the same issue:

04:52:58 missed delete of name id cache ns/m.0325l6y 0 (0x1919849 )
04:53:33 Write wait on column page 1963143.  Waits should be on the index leaf page, except when col page is held for read by background write
05:00:46 \* Monitor: Locks are held for a long time
05:01:05 missed delete of name id cache ns/m.0wy0j39 0 (0x2df92e )
05:08:11 Write wait on column page 1091690.  Waits should be on the index leaf page, except when col page is held for read by background write
05:08:27 Write wait on column page 1823750.  Waits should be on the index leaf page, except when col page is held for read by background write

My virtuoso.ini configuration:

;
;  virtuoso.ini
;
;  Configuration file for the OpenLink Virtuoso VDBMS Server
;
;  To learn more about this product, or any other product in our
;  portfolio, please check out our web site at:
;
;      http://virtuoso.openlinksw.com/
;
;  or contact us at:
;
;      general.information@openlinksw.com
;
;  If you have any technical questions, please contact our support
;  staff at:
;
;      technical.support@openlinksw.com
;

;
;  Database setup
;
[Database]
DatabaseFile                    = /var/lib/virtuoso-opensource-7/db/virtuoso.db
ErrorLogFile                    = /var/lib/virtuoso-opensource-7/db/virtuoso.log
LockFile                        = /var/lib/virtuoso-opensource-7/db/virtuoso.lck
TransactionFile                 = /var/lib/virtuoso-opensource-7/db/virtuoso.trx
xa_persistent_file              = /var/lib/virtuoso-opensource-7/db/virtuoso.pxa
ErrorLogLevel                   = 7
FileExtend                      = 200
MaxCheckpointRemap              = 112500
Striping                        = 0
TempStorage                     = TempDatabase

[TempDatabase]
DatabaseFile                    = /var/lib/virtuoso-opensource-7/db/virtuoso-temp.db
TransactionFile                 = /var/lib/virtuoso-opensource-7/db/virtuoso-temp.trx
MaxCheckpointRemap              = 2000
Striping                        = 0

;
;  Server parameters
;
[Parameters]
ServerPort                      = 1111
LiteMode                        = 0
DisableUnixSocket               = 1
DisableTcpSocket                = 0
;SSLServerPort                  = 2111
;SSLCertificate                 = cert.pem
;SSLPrivateKey                  = pk.pem
;X509ClientVerify               = 0
;X509ClientVerifyDepth          = 0
;X509ClientVerifyCAFile         = ca.pem
MaxClientConnections            = 10
CheckpointInterval              = 60
O_DIRECT                        = 0
CaseMode                        = 2
MaxStaticCursorRows             = 5000
CheckpointAuditTrail            = 0
AllowOSCalls                    = 0
SchedulerInterval               = 10
DirsAllowed                     = ., /usr/share/virtuoso-opensource-7/vad, /ranker/apps/triple-store/splits
ThreadCleanupInterval           = 0
ThreadThreshold                 = 0
ResourcesCleanupInterval        = 0
FreeTextBatchSize               = 100000
SingleCPU                       = 0
VADInstallDir                   = /usr/share/virtuoso-opensource-7/vad
PrefixResultNames               = 0
RdfFreeTextRulesSize            = 100
IndexTreeMaps                   = 256
MaxMemPoolSize                  = 300000000
PrefixResultNames               = 0
MacSpotlight                    = 0
IndexTreeMaps                   = 64
MaxQueryMem                     = 2G            ; memory allocated to query processor
VectorSize                      = 1000          ; initial parallel query vector (array of query operations) size
MaxVectorSize                   = 1000000       ; query vector size threshold.
AdjustVectorSize                = 0
ThreadsPerQuery                 = 8
AsyncQueueMaxThreads            = 10
;;
;; When running with large data sets, one should configure the Virtuoso
;; process to use between 2/3 to 3/5 of free system memory and to stripe
;; storage on all available disks.
;;
;; Uncomment next two lines if there is 2 GB system memory free
;NumberOfBuffers          = 170000
;MaxDirtyBuffers          = 130000
;; Uncomment next two lines if there is 4 GB system memory free
;NumberOfBuffers          = 340000
; MaxDirtyBuffers          = 250000
;; Uncomment next two lines if there is 8 GB system memory free
;NumberOfBuffers          = 680000
;MaxDirtyBuffers          = 500000
;; Uncomment next two lines if there is 16 GB system memory free
;NumberOfBuffers          = 1360000
;MaxDirtyBuffers          = 1000000
;; Uncomment next two lines if there is 32 GB system memory free
;NumberOfBuffers          = 2720000
;MaxDirtyBuffers          = 2000000
;; Uncomment next two lines if there is 48 GB system memory free
;NumberOfBuffers          = 4000000
;MaxDirtyBuffers          = 3000000
;; Uncomment next two lines if there is 64 GB system memory free
NumberOfBuffers          = 5450000
MaxDirtyBuffers          = 4000000
;;
;; Note the default settings will take very little memory
;; but will not result in very good performance
;;
#NumberOfBuffers          = 10000
#MaxDirtyBuffers          = 6000

[HTTPServer]
ServerPort                      = 8890
ServerRoot                      = /var/lib/virtuoso-opensource-7/vsp
MaxClientConnections            = 10
DavRoot                         = DAV
EnabledDavVSP                   = 0
HTTPProxyEnabled                = 0
TempASPXDir                     = 0
DefaultMailServer               = localhost:25
ServerThreads                   = 10
MaxKeepAlives                   = 10
KeepAliveTimeout                = 10
MaxCachedProxyConnections       = 10
ProxyConnectionCacheTimeout     = 15
HTTPThreadSize                  = 280000
HttpPrintWarningsInOutput       = 0
Charset                         = UTF-8
;HTTPLogFile                    = logs/http.log
MaintenancePage                 = atomic.html
EnabledGzipContent              = 1

[AutoRepair]
BadParentLinks                  = 0

[Client]
SQL_PREFETCH_ROWS               = 100
SQL_PREFETCH_BYTES              = 16000
SQL_QUERY_TIMEOUT               = 0
SQL_TXN_TIMEOUT                 = 0
;SQL_NO_CHAR_C_ESCAPE           = 1
;SQL_UTF8_EXECS                 = 0
;SQL_NO_SYSTEM_TABLES           = 0
;SQL_BINARY_TIMESTAMP           = 1
;SQL_ENCRYPTION_ON_PASSWORD     = -1

[VDB]
ArrayOptimization               = 0
NumArrayParameters              = 10
VDBDisconnectTimeout            = 1000
KeepConnectionOnFixedThread     = 0

[Replication]
ServerName                      = db-PRD-VIRTUOSO-S01
ServerEnable                    = 1
QueueMax                        = 50000

;
;  Striping setup
;
;  These parameters have only effect when Striping is set to 1 in the
;  [Database] section, in which case the DatabaseFile parameter is ignored.
;
;  With striping, the database is spawned across multiple segments
;  where each segment can have multiple stripes.
;
;  Format of the lines below:
;    Segment<number> = <size>, <stripe file name> [, <stripe file name> .. ]
;
;  <number> must be ordered from 1 up.
;
;  The <size> is the total size of the segment which is equally divided
;  across all stripes forming  the segment. Its specification can be in
;  gigabytes (g), megabytes (m), kilobytes (k) or in database blocks
;  (b, the default)
;
;  Note that the segment size must be a multiple of the database page size
;  which is currently 8k. Also, the segment size must be divisible by the
;  number of stripe files forming  the segment.
;
;  The example below creates a 200 meg database striped on two segments
;  with two stripes of 50 meg and one of 100 meg.
;
;  You can always add more segments to the configuration, but once
;  added, do not change the setup.
;
[Striping]
Segment1                        = 100M, db-seg1-1.db, db-seg1-2.db
Segment2                        = 100M, db-seg2-1.db
;...

;[TempStriping]
;Segment1                       = 100M, db-seg1-1.db, db-seg1-2.db
;Segment2                       = 100M, db-seg2-1.db
;...

;[Ucms]
;UcmPath                        = <path>
;Ucm1                           = <file>
;Ucm2                           = <file>
;...

[Zero Config]
ServerName                      = virtuoso (PRD-VIRTUOSO-S01)
;ServerDSN                      = ZDSN
;SSLServerName                  =
;SSLServerDSN                   =

[Mono]
;MONO_TRACE                     = Off
;MONO_PATH                      = <path_here>
;MONO_ROOT                      = <path_here>
;MONO_CFG_DIR                   = <path_here>
;virtclr.dll                    =

[URIQA]
DynamicLocal                    = 0
DefaultHost                     = localhost:8890

[SPARQL]
;ExternalQuerySource            = 1
;ExternalXsltSource             = 1
;DefaultGraph                   = http://localhost:8890/dataspace
;ImmutableGraphs                = http://localhost:8890/dataspace
ResultSetMaxRows                = 10000
MaxQueryCostEstimationTime      = 400   ; in seconds
MaxQueryExecutionTime           = 60    ; in seconds
DefaultQuery                    = select distinct ?Concept where {[] a ?Concept} LIMIT 100
DeferInferenceRulesInit         = 0  ; controls inference rules loading
;PingService                    = http://rpc.pingthesemanticweb.com/

[Plugins]
LoadPath                        = /usr/lib/virtuoso-opensource-7/hosting
Load1                           = plain, wikiv
Load2                           = plain, mediawiki
Load3                           = plain, creolewiki
;Load4                  = plain, im
;Load5          = plain, wbxml2
;Load6                  = plain, hslookup
;Load7                  = attach, libphp5.so
;Load8                  = Hosting, hosting_php.so
;Load9                  = Hosting,hosting_perl.so
;Load10         = Hosting,hosting_python.so
;Load11         = Hosting,hosting_ruby.so
;Load12                         = msdtc,msdtc_sample

I build the virtuoso today from latest stable/7 source.

Here is server configuration:

• CPU 32 vCPUs
• RAM 60 GB
• System Disk 50 GB
• Network 5 Gb / s

My DATA directory is attached SSD drive.

[whu2015]

Agreed, I also encountered this problem when I was importing the latest version of freebase into virtuoso open source 7, and the run time seems incredibly long. It has already taken more than three days on my server with 8 hard disks in raid 10.

[HughWilliams]

Have you performance tuned your Virtuoso instance as detailed at:

http://vos.openlinksw.com/owiki/wiki/VOS/VirtRDFPerformanceTuning

[whu2015]

yes, I have. Also, I found a very interesting case. If I unzip the freebase dataset and import it into virtuoso, it occupies more disk and much slower, compared with importing the zipped (.gz) version directly. Also, if I increase the buffer to 5450000 (in terms of 64GB), the errors seem appear less frequently.

[KonradHoeffner]

10 years later, I also get these warnings with the newest Docker image virtuoso-opensource-7:7.2.12 when loading LinkedSpending:

virtuoso-1  | 16:55:40 Write wait on column page 421373.  Waits should be on the index leaf page, except when col page is held for read by background write
virtuoso-1  | 16:55:40 Write wait on column page 293200.  Waits should be on the index leaf page, except when col page is held for read by background write
virtuoso-1  | 16:55:40 Write wait on column page 440068.  Waits should be on the index leaf page, except when col page is held for read by background write
virtuoso-1  | 16:55:40 Write wait on column page 452896.  Waits should be on the index leaf page, except when col page is held for read by background write
virtuoso-1  | 16:55:40 Write wait on column page 355190.  Waits should be on the index leaf page, except when col page is held for read by background write
virtuoso-1  | 16:55:41 Write wait on column page 209642.  Waits should be on the index leaf page, except when col page is held for read by background write
virtuoso-1  | 16:55:41 Write wait on column page 279078.  Waits should be on the index leaf page, except when col page is held for read by background write
virtuoso-1  | 16:55:41 Write wait on column page 364376.  Waits should be on the index leaf page, except when col page is held for read by background write
virtuoso-1  | 16:55:41 Write wait on column page 440578.  Waits should be on the index leaf page, except when col page is held for read by background write
virtuoso-1  | 16:55:41 Write wait on column page 421177.  Waits should be on the index leaf page, except when col page is held for read by background write
virtuoso-1  | 16:55:41 Write wait on column page 5849.  Waits should be on the index leaf page, except when col page is held for read by background write
virtuoso-1  | 16:55:44 *** read-ahead of a free or out of range page dp L=180880, database not necessarily corrupted.
virtuoso-1  | 16:55:47 Write wait on column page 227874.  Waits should be on the index leaf page, except when col page is held for read by background write
virtuoso-1  | 16:55:47 Write wait on column page 268597.  Waits should be on the index leaf page, except when col page is held for read by background write
virtuoso-1  | 16:55:47 Write wait on column page 349825.  Waits should be on the index leaf page, except when col page is held for read by background write
virtuoso-1  | 16:55:49 *** read-ahead of a free or out of range page dp L=78630, database not necessarily corrupted.
virtuoso-1  | 16:55:49 *** read-ahead of a free or out of range page dp L=234953, database not necessarily corrupted.
virtuoso-1  | 16:55:50 *** read-ahead of a free or out of range page dp L=18686, database not necessarily corrupted.
virtuoso-1  | 16:55:56 Write wait on column page 407730.  Waits should be on the index leaf page, except when col page is held for read by background write
virtuoso-1  | 16:55:56 Write wait on column page 279079.  Waits should be on the index leaf page, except when col page is held for read by background write
virtuoso-1  | 16:55:56 Write wait on column page 176704.  Waits should be on the index leaf page, except when col page is held for read by background write
virtuoso-1  | 16:55:56 Write wait on column page 407253.  Waits should be on the index leaf page, except when col page is held for read by background write
virtuoso-1  | 16:55:56 Write wait on column page 4230.  Waits should be on the index leaf page, except when col page is held for read by background write

And many more of those. However there hasn't been a deadlock and it did eventually succeed. The file is 28GiB of N-Triples.

docker-compose.yml excerpt

 virtuoso:
    image: openlink/virtuoso-opensource-7:7.2.12
    environment:
      - DBA_PASSWORD=${DBA_PASSWORD}
      - VIRT_DATABASE_ERRORLOGLEVEL=3
      - VIRT_PARAMETERS_NUMBEROFBUFFERS=10000
      - VIRT_PARAMETERS_MAXDIRTYBUFFERS=6000
      - VIRT_HTTPSERVER_SERVERPORT=8890
      - VIRT_SPARQL_DEFAULTGRAPH=http://linkedspending.aksw.org
      - VIRT_SPARQL_RESULTSETMAXROWS=50000
      - VIRT_SPARQL_MAXQUERYCOSTESTIMATIONTIME=400
      - VIRT_SPARQL_MAXQUERYEXECUTIONTIME=120
      - VIRT_SPARQL_DEFAULTQUERY=select distinct * {?s a qb:DataSet.} LIMIT 100
      - VIRT_PLUGINS_-=-
    volumes:
      - ./virtuoso:/opt/virtuoso-opensource/initdb.d:ro
      - ./toload:/database/toload:ro
      - virtuoso-data:/database/data

virtuoso/setup.sql

log_message('Setup: Activate CORS');
update DB.DBA.HTTP_PATH set HP_OPTIONS = serialize(vector('browse_sheet', '', 'noinherit', 'yes', 'cors', '*', 'cors_restricted', 0))  where HP_LPATH = '/sparql';
log_message('Setup: Create graph http://linkedspending.aksw.org');
--log_message('Setup: Create graphs and graph group http://linkedspending.aksw.org/');
--DB.DBA.RDF_GRAPH_GROUP_CREATE('http://linkedspending.aksw.org/',1);
--DB.DBA.RDF_GRAPH_GROUP_INS ('http://linkedspending.aksw.org/', 'http://linkedspending.aksw.org/ontology/');
DB.DBA.XML_SET_NS_DECL ('owl', 'http://www.w3.org/2002/07/owl#', 2);
DB.DBA.XML_SET_NS_DECL ('ls', 'http://linkedspending.aksw.org/instance/', 2);
DB.DBA.XML_SET_NS_DECL ('lso', 'http://linkedspending.aksw.org/ontology/', 2);
DB.DBA.XML_SET_NS_DECL ('qb', 'http://purl.org/linked-data/cube#', 2);
DB.DBA.XML_SET_NS_DECL ('sdmxd', 'http://purl.org/linked-data/sdmx/2009/dimension#', 2);
DB.DBA.XML_SET_NS_DECL ('dbpedia', 'http://dbpedia.org/resource/', 2);
DB.DBA.XML_SET_NS_DECL ('dbr', 'http://dbpedia.org/resource/', 2);
DB.DBA.XML_SET_NS_DECL ('dbp', 'http://dbpedia.org/property/', 2);
DB.DBA.XML_SET_NS_DECL ('lgd', 'http://linkedgeodata.org/triplify/', 2);
log_message('Setup: Load data from .ttl and .nt files');
ld_dir_all ('toload', '*.ttl', 'http://linkedspending.aksw.org');
ld_dir_all ('toload', '*.nt', 'http://linkedspending.aksw.org');
--ld_dir_all ('toload', '*.nt', NULL); -- determine graph name from .graph file
rdf_loader_run();
log_message('Setup: Finished');

[HughWilliams]

In your YML file why are the following set in the INI file:

      - VIRT_PARAMETERS_NUMBEROFBUFFERS=10000
      - VIRT_PARAMETERS_MAXDIRTYBUFFERS=6000

which are the minimal default settings for memory buffers to be used by Virtuoso and should be set as per the Virtuoso RDF Performance Tuning Guide, based on the available memory of the docker container VM, which must be enough for hosting a 28GB dataset file which is a large number of triples.

[KonradHoeffner]

Ah, maybe I copied this over from a smaller knowledge base and forgot to adapt it, thanks!

[TallTed]

@KonradHoeffner -- It appears that the issue described here has been resolved for you, upon correct tuning? Please confirm.

Others (@whu2015, @vijayranker, @hanito, @Aklakan) -- Please advise, whether a current build with appropriate tuning resolves this issue for you as well.

[pkleef]

The `Read/Write wait on column page...' messages are debug messages and can be ignored.

I have pushed dcc37a71e297e99a8b67ef17ab5bd0d105008555 to develop/7

[KonradHoeffner]

With the recommended buffer settings for 2GB RAM, of 170000 buffers and 130000 max dirty buffers, (which uses around 4GB in practice during loading), the "Write wait on column page" messages are gone, thanks for the advice!

I still get the following but I guess that does not relate to this issue:

virtuoso-1  | 19:04:31 *** read-ahead of a free or out of range page dp L=34918, database not necessarily corrupted.
virtuoso-1  | 19:04:31 *** read-ahead of a free or out of range page dp L=34923, database not necessarily corrupted.
virtuoso-1  | 19:04:31 *** read-ahead of a free or out of range page dp L=34949, database not necessarily corrupted.
virtuoso-1  | 19:04:31 *** read-ahead of a free or out of range page dp L=34959, database not necessarily corrupted.

[TallTed]

@KonradHoeffner -- That's good news!

Regarding the remaining read-ahead errors, I recommend you run a database integrity check (backup '/dev/null'), and if that reports errors (and maybe even if not), do a database dump and restore as detailed in the Virtuoso documentation on Database Recovery. If the latter reports errors, or the read-ahead errors persist after dump-and-restore, please start a fresh issue, so we can avoid confusion.