search

openlink / virtuoso-opensource

Virtuoso is a high-performance and scalable Multi-Model RDBMS, Data Integration Middleware, Linked Data Deployment, and HTTP Application Server Platform
https://vos.openlinksw.com
Other
869 stars 210 forks source link

Non-reproducible results with a certain sparql query using COUNT, ORDER BY and LIMIT - caused by MaxQueryMem=2G #437

Open tlomb opened 9 years ago

tlomb commented 9 years ago

Dear virtuoso team,

I am testing virtuoso-opensource v7.2.1 and I observe non-reproductible results for the following sparql query:

PREFIX up:http://purl.uniprot.org/core/ PREFIX rdfs:http://www.w3.org/2000/01/rdf-schema# SELECT ?protein (COUNT(?xref) AS ?nbxrefs) WHERE { ?protein a up:Protein . ?protein rdfs:seeAlso ?xref . ?xref up:database http://purl.uniprot.org/database/PROSITE } GROUP BY ?protein ORDER BY DESC(?nbxrefs) LIMIT 3;

The dataset is uniprot (2015_07), >14 billions triples (!)

This problem happens when running virutoso-t with MaxQueryMem=2G, but not when using MaxQueryMem=10G. With MaxQueryMem=2G, I can observe the following message: "* Monitor: Low query memory limit, try to increase MaxQueryMem", but not on all executions of this query (~40% of the times)

Versions tested (both show the problem):

I am aware of the discussion about wrong counts results caused by timeouts and the problem to clearly identify such events (see https://github.com/openlink/virtuoso-opensource/issues/112). But the case I report here with a MaxQueryMem issue seems different and more severe, because I don't get any error message at the isql level when MaxQueryMem is too low.

Details (tests on virtuoso-opensource tags/v7.2.1):

Using MaxQueryMem=2G:

[user@testmachine ~]$ [...]/virtuoso-t -f +wait +configfile [...]/virtuoso-config-expasy4j-sparql6237756606046863387_MaxQueryMem_2G_orig.ini [...] [user@testmachine ~]$ ~/bin/isql -H localhost:1112 [...] SQL> sparql PREFIX up:http://purl.uniprot.org/core/ PREFIX rdfs:http://www.w3.org/2000/01/rdf-schema# SELECT ?protein (COUNT(?xref) AS ?nbxrefs) WHERE { ?protein a up:Protein . ?protein rdfs:seeAlso ?xref . ?xref up:database http://purl.uniprot.org/database/PROSITE } GROUP BY ?protein ORDER BY DESC(?nbxrefs) LIMIT 3; protein nbxrefs LONG VARCHAR LONG VARCHAR

http://purl.uniprot.org/uniprot/I4YGH1 7 http://purl.uniprot.org/uniprot/A8DQV8 7 http://purl.uniprot.org/uniprot/K6Q1L9 7

3 Rows. -- 45798 msec. [...] SQL> sparql PREFIX up:http://purl.uniprot.org/core/ PREFIX rdfs:http://www.w3.org/2000/01/rdf-schema# SELECT ?protein (COUNT(?xref) AS ?nbxrefs) WHERE { ?protein a up:Protein . ?protein rdfs:seeAlso ?xref . ?xref up:database http://purl.uniprot.org/database/PROSITE } GROUP BY ?protein ORDER BY DESC(?nbxrefs) LIMIT 3; protein nbxrefs LONG VARCHAR LONG VARCHAR

http://purl.uniprot.org/uniprot/A0A078HGH7 9 http://purl.uniprot.org/uniprot/A0A078H6S6 9 http://purl.uniprot.org/uniprot/T1JBH2 9

3 Rows. -- 39438 msec. [...] SQL>

=> The results are non-reproducible

Here are the corresponding logs for the above query repeated 10 times:

[user@testmachine ~]$ tail -f [...]/virtuoso.log [...] 17:40:09 * Monitor: Low query memory limit, try to increase MaxQueryMem 17:42:23 * Monitor: Low query memory limit, try to increase MaxQueryMem 17:46:31 * Monitor: Low query memory limit, try to increase MaxQueryMem 17:49:23 * Monitor: Low query memory limit, try to increase MaxQueryMem

=> As you see above, I get only 4 "Monitor: Low query memory limit" for 10 queries, but queries give non reproducible results (and wrong in all cases here, see exact result below - we expect 16 as first nbxrefs result).

And using MaxQueryMem=10G:

[user@testmachine ~]$ [...]/virtuoso-t -f +wait +configfile [...]/virtuoso-config-expasy4j-sparql6237756606046863387_MaxQueryMem_10G.ini [user@testmachine ~]$ diff [...]/virtuoso-config-expasy4j-sparql6237756606046863387_MaxQueryMem_2G_orig.ini [...]/virtuoso-config-expasy4j-sparql6237756606046863387_MaxQueryMem_10G.ini 64c64 < MaxQueryMem = 2G

MaxQueryMem = 10G

[user@testmachine ~]$ ~/bin/isql -H localhost:1112 [...] SQL> sparql PREFIX up:http://purl.uniprot.org/core/ PREFIX rdfs:http://www.w3.org/2000/01/rdf-schema# SELECT ?protein (COUNT(?xref) AS ?nbxrefs) WHERE { ?protein a up:Protein . ?protein rdfs:seeAlso ?xref . ?xref up:database http://purl.uniprot.org/database/PROSITE } GROUP BY ?protein ORDER BY DESC(?nbxrefs) LIMIT 3; protein nbxrefs LONG VARCHAR LONG VARCHAR

http://purl.uniprot.org/uniprot/C3ZAW6 16 http://purl.uniprot.org/uniprot/W4Y9H1 15 http://purl.uniprot.org/uniprot/K7ITX8 15

3 Rows. -- 63221 msec. [...] SQL> sparql PREFIX up:http://purl.uniprot.org/core/ PREFIX rdfs:http://www.w3.org/2000/01/rdf-schema# SELECT ?protein (COUNT(?xref) AS ?nbxrefs) WHERE { ?protein a up:Protein . ?protein rdfs:seeAlso ?xref . ?xref up:database http://purl.uniprot.org/database/PROSITE } GROUP BY ?protein ORDER BY DESC(?nbxrefs) LIMIT 3; protein nbxrefs LONG VARCHAR LONG VARCHAR

http://purl.uniprot.org/uniprot/C3ZAW6 16 http://purl.uniprot.org/uniprot/W4Y9H1 15 http://purl.uniprot.org/uniprot/K7ITX8 15

3 Rows. -- 29696 msec. SQL>

=> with MaxQueryMem=10G, the results are reproducible (tested 10x, only 2 shown above)

So my questions are:

Thanks in advance for your help,

Best regards

(int. ref. UPS-131)

HughWilliams commented 9 years ago

@tlomb: I assume you are using the latest uniprot datasets from ftp://ftp.uniprot.org/pub/databases/uniprot/current_release/rdf/ ? As we want to download and attempt recreation locally ...

tlomb commented 9 years ago

@HughWilliams: Thanks for your answer. Yes, I mentioned this test was done on uniprot (2015_07). More precisely, the above tested triple store is containing all *.rdf of ftp://ftp.uniprot.org/pub/databases/uniprot/current_release/rdf/. You can see 2015_07 is the one on the ftp as of today 2015-07-09. See also: ftp://ftp.uniprot.org/pub/databases/uniprot/current_release/relnotes.txt

tlomb commented 9 years ago

@HughWilliams: I re-executed the same test with MaxQueryMem=2G versus MaxQueryMem=10G, both with AdjustVectorSize=0 to exclude a side effect of https://github.com/openlink/virtuoso-opensource/issues/438 .

The outcome is the same, i.e. for the query:

PREFIX up:http://purl.uniprot.org/core/ PREFIX rdfs:http://www.w3.org/2000/01/rdf-schema# SELECT ?protein (COUNT(?xref) AS ?nbxrefs) WHERE { ?protein a up:Protein . ?protein rdfs:seeAlso ?xref . ?xref up:database http://purl.uniprot.org/database/PROSITE } GROUP BY ?protein ORDER BY DESC(?nbxrefs) LIMIT 3;

... I get non reproducible results when using MaxQueryMem=2G, but reproducible results when using MaxQueryMem=10G.

Here are my complete test ini files:

The virtuoso.ini giving non reproducible results: ######################### [user@testserver]$ cat virtuoso-config-expasy4j-sparql6237756606046863387_MaxQueryMem_2G_orig_AdjustVectorSize_0.ini ; ; virtuoso.ini ;

; Database setup ; [Database] DatabaseFile = /scratch/uuw_sparql/2015_07.1/./data/triples/virtuoso.db ErrorLogFile = /scratch/uuw_sparql/2015_07.1/./data/triples/virtuoso.log LockFile = /scratch/uuw_sparql/2015_07.1/./data/triples/virtuoso.lck TransactionFile = /scratch/uuw_sparql/2015_07.1/./data/triples/virtuoso.trx xa_persistent_file = /scratch/uuw_sparql/2015_07.1/./data/triples/virtuoso.pxa ErrorLogLevel = 7 FileExtend = 20000 MaxCheckpointRemap = 20000 Striping = 0 TempStorage = TempDatabase

[TempDatabase] DatabaseFile = /scratch/uuw_sparql/2015_07.1/./data/triples/virtuoso-temp.db TransactionFile = /scratch/uuw_sparql/2015_07.1/./data/triples/virtuoso-temp.trx MaxCheckpointRemap = 2000 Striping = 0

; ; Server parameters ; [Parameters] ServerPort = 1112 LiteMode = 1 DisableUnixSocket = 0 DisableTcpSocket = 0 ServerThreads = 64 AsyncQueueMaxThreads = 10 MaxClientConnections = 64 CheckpointInterval = 600 O_DIRECT = 0 UseAIO = 1 CaseMode = 2 MaxStaticCursorRows = 5000 CheckpointAuditTrail = 0 AllowOSCalls = 0 SchedulerInterval = 10 DirsAllowed = ThreadCleanupInterval = 0 ThreadThreshold = 10 ResourcesCleanupInterval = 0 FreeTextBatchSize = 100000 SingleCPU = 0 VADInstallDir = /dev/null PrefixResultNames = 0 RdfFreeTextRulesSize = 100 IndexTreeMaps = 256 MaxMemPoolSize = 134217728 TransactionAfterImageLimit = 1000000000 ColumnStore = 1 QueryLog = /tmp/virtuoso-query.log NumberOfBuffers = 14695720 MaxDirtyBuffers = 11021790 ThreadsPerQuery = 64 MaxQueryMem = 2G VectorSize = 10000 MaxVectorSize = 1000000 AdjustVectorSize = 0 CheckpointSyncMode = 2

[AutoRepair] BadParentLinks = 0

[HTTPServer] ClientIdString = Mozilla/4.0 (compatible; Virtuoso, running-at: sparql.uniprot.org)

[Client] SQL_PREFETCH_ROWS = 100 SQL_PREFETCH_BYTES = 16000 SQL_QUERY_TIMEOUT = 0 SQL_TXN_TIMEOUT = 0

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

[SPARQL] ;ExternalQuerySource = 1 ;ExternalXsltSource = 1 DefaultGraph = http://beta.sparql.uniprot.org/ ResultSetMaxRows = 20000000000 ; 20 billion for now. MaxQueryCostEstimationTime = 360000 ; in seconds MaxQueryExecutionTime = 360000 ; in seconds DefaultQuery = select distinct ?Concept where {[] a ?Concept} LIMIT 100 DeferInferenceRulesInit = 0 ; controls inference rules loading #########################

And the virtuoso.ini giving reproducible results: ######################### [user@testserver]$ cat virtuoso-config-expasy4j-sparql6237756606046863387_MaxQueryMem_10G_AdjustVectorSize_0.ini ; ; virtuoso.ini ;

; Database setup ; [Database] DatabaseFile = /scratch/uuw_sparql/2015_07.1/./data/triples/virtuoso.db ErrorLogFile = /scratch/uuw_sparql/2015_07.1/./data/triples/virtuoso.log LockFile = /scratch/uuw_sparql/2015_07.1/./data/triples/virtuoso.lck TransactionFile = /scratch/uuw_sparql/2015_07.1/./data/triples/virtuoso.trx xa_persistent_file = /scratch/uuw_sparql/2015_07.1/./data/triples/virtuoso.pxa ErrorLogLevel = 7 FileExtend = 20000 MaxCheckpointRemap = 20000 Striping = 0 TempStorage = TempDatabase

[TempDatabase] DatabaseFile = /scratch/uuw_sparql/2015_07.1/./data/triples/virtuoso-temp.db TransactionFile = /scratch/uuw_sparql/2015_07.1/./data/triples/virtuoso-temp.trx MaxCheckpointRemap = 2000 Striping = 0

; ; Server parameters ; [Parameters] ServerPort = 1112 LiteMode = 1 DisableUnixSocket = 0 DisableTcpSocket = 0 ServerThreads = 64 AsyncQueueMaxThreads = 10 MaxClientConnections = 64 CheckpointInterval = 600 O_DIRECT = 0 UseAIO = 1 CaseMode = 2 MaxStaticCursorRows = 5000 CheckpointAuditTrail = 0 AllowOSCalls = 0 SchedulerInterval = 10 DirsAllowed = ThreadCleanupInterval = 0 ThreadThreshold = 10 ResourcesCleanupInterval = 0 FreeTextBatchSize = 100000 SingleCPU = 0 VADInstallDir = /dev/null PrefixResultNames = 0 RdfFreeTextRulesSize = 100 IndexTreeMaps = 256 MaxMemPoolSize = 134217728 TransactionAfterImageLimit = 1000000000 ColumnStore = 1 QueryLog = /tmp/virtuoso-query.log NumberOfBuffers = 14695720 MaxDirtyBuffers = 11021790 ThreadsPerQuery = 64 MaxQueryMem = 10G VectorSize = 10000 MaxVectorSize = 1000000 AdjustVectorSize = 0 CheckpointSyncMode = 2

[AutoRepair] BadParentLinks = 0

[HTTPServer] ClientIdString = Mozilla/4.0 (compatible; Virtuoso, running-at: sparql.uniprot.org)

[Client] SQL_PREFETCH_ROWS = 100 SQL_PREFETCH_BYTES = 16000 SQL_QUERY_TIMEOUT = 0 SQL_TXN_TIMEOUT = 0

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

[SPARQL] ;ExternalQuerySource = 1 ;ExternalXsltSource = 1 DefaultGraph = http://beta.sparql.uniprot.org/ ResultSetMaxRows = 20000000000 ; 20 billion for now. MaxQueryCostEstimationTime = 360000 ; in seconds MaxQueryExecutionTime = 360000 ; in seconds DefaultQuery = select distinct ?Concept where {[] a ?Concept} LIMIT 100 DeferInferenceRulesInit = 0 ; controls inference rules loading #########################

The only difference is MaxQueryMem: ######################### [user@testserver]$ diff virtuoso-config-expasy4j-sparql6237756606046863387_MaxQueryMem_2G_orig_AdjustVectorSize_0.ini virtuoso-config-expasy4j-sparql6237756606046863387_MaxQueryMem_10G_AdjustVectorSize_0.ini 64c64 < MaxQueryMem = 2G

MaxQueryMem = 10G #########################

Remark about other parameters: You can see that NumberOfBuffers and MaxDirtyBuffers has been adapted for our hardware (250G ram) according to the recommendations you give in the comments of https://github.com/openlink/virtuoso-opensource/blob/v7.2.1/binsrc/samples/demo/default-virtuoso.ini. You can also see that our MaxQueryExecutionTime is very high, so we don't expect to be hit by timeout issues (e.g. https://github.com/openlink/virtuoso-opensource/issues/112).

Best regards

HughWilliams commented 9 years ago

@tlomb: Development have determined the cause of this issue and are working on a fix for it.

In the meantime a workaround can be used which is to set the param "enable_chash_gb = 0" in the "[Flags]" section of the INI file and restart the Virtuoso server.

Let us know if this workaround works for you ?

tlomb commented 9 years ago

@HughWilliams: As mentionned above, the workaround I did was to set MaxQueryMem=10G/AdjustVectorSize=0 (this issue + issue 438). No problems with the queries nor "Monitor: Low query memory limit" in the logs could be seen since with our tests. I had no time to test "enable_chash_gb = 0". Please note that testing all combinations of MaxQueryMem, enable_chash_gb and AdjustVectorSize would be challenging. Honestly, I would prefer to get the code fix ASAP instead of trying another workaround. Are there progresses on the fix? Do you plan a release for that or will I have to go back to develop/7 again? Thanks for your follow-up!

HughWilliams commented 9 years ago

@tlomb: I am checking with development as to the status of a fix for this issue ...

tlomb commented 9 years ago

@HughWilliams: Any progress on this one? And what is the schedule for a virtuoso-opensource v7.2.2? Thanks for your follow-up.

tlomb commented 8 years ago

@HughWilliams: Sorry to bother again, but I've heard that the v7.2.2 is scheduled for this week. Will it include a fix for this issue? From my point of view and for my use case of virtuoso (large store), this is the most serious issue I observed in v7.2.1.

HughWilliams commented 8 years ago

@tlomb: Unfortunately development have not devised a fix for this issue yet, has the workaround of setting "enable_chash_gb = 0" been tested ?