rdf4j
rdf4j copied to clipboard
eclipse-rdf4j
MDB_BAD_VALSIZE: Unsupported size of key/DB name/data, or wrong DUPFIXED size when inserting 10m records into LMDB
Current Behavior
This may be a 5.0 bug b/c 4.3.10 seemed to work. Generated 10m records using SP2B data generator tool (https://dbis.informatik.uni-freiburg.de/index.php%3Fproject=SP2B%252Fdownload.php.html)
tried to insert it via REST interface:
curl -X POST -H "Content-type: text/turtle" --data-binary @10m.ttl http://localhost/rdf4j-server/repositories/reponame/statements
Received:
org.eclipse.rdf4j.http.server.ServerHTTPException: org.eclipse.rdf4j.repository.RepositoryException: org.eclipse.rdf4j.sail.SailException: java.io.IOException: MDB_BAD_VALSIZE: Unsupported size of key/DB name/data, or wrong DUPFIXED size
at org.eclipse.rdf4j.http.server.repository.statements.StatementsController.getAddDataResult(StatementsController.java:420)
at org.eclipse.rdf4j.http.server.repository.statements.StatementsController.handleRequestInternal(StatementsController.java:121)
at org.springframework.web.servlet.mvc.AbstractController.handleRequest(AbstractController.java:177)
at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:51)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1072)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:965)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:909)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:681)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:764)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at com.github.ziplet.filter.compression.CompressingFilter.doFilter(CompressingFilter.java:263)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:197)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:135)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
at org.apache.catalina.valves.HealthCheckValve.invoke(HealthCheckValve.java:102)
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:687)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:360)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:399)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:890)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1787)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.base/java.lang.Thread.run(Thread.java:840)
Caused by: org.eclipse.rdf4j.repository.RepositoryException: org.eclipse.rdf4j.sail.SailException: java.io.IOException: MDB_BAD_VALSIZE: Unsupported size of key/DB name/data, or wrong DUPFIXED size
at org.eclipse.rdf4j.repository.sail.SailRepositoryConnection.commit(SailRepositoryConnection.java:228)
at org.eclipse.rdf4j.http.server.repository.statements.StatementsController.getAddDataResult(StatementsController.java:402)
... 36 common frames omitted
Caused by: org.eclipse.rdf4j.sail.SailException: java.io.IOException: MDB_BAD_VALSIZE: Unsupported size of key/DB name/data, or wrong DUPFIXED size
at org.eclipse.rdf4j.sail.lmdb.LmdbSailStore$LmdbSailSink.approveAll(LmdbSailStore.java:609)
at org.eclipse.rdf4j.sail.base.Changeset.sinkApproved(Changeset.java:857)
at org.eclipse.rdf4j.sail.base.SailSourceBranch.flush(SailSourceBranch.java:519)
at org.eclipse.rdf4j.sail.base.SailSourceBranch.flush(SailSourceBranch.java:484)
at org.eclipse.rdf4j.sail.base.SailSourceBranch.flush(SailSourceBranch.java:299)
at org.eclipse.rdf4j.sail.base.SailSourceBranch.autoFlush(SailSourceBranch.java:392)
at org.eclipse.rdf4j.sail.base.SailSourceBranch$1.close(SailSourceBranch.java:197)
at org.eclipse.rdf4j.sail.base.SailSourceBranch.flush(SailSourceBranch.java:303)
at org.eclipse.rdf4j.sail.base.UnionSailSource.flush(UnionSailSource.java:74)
at org.eclipse.rdf4j.sail.base.SailSourceConnection.commitInternal(SailSourceConnection.java:506)
at org.eclipse.rdf4j.sail.lmdb.LmdbStoreConnection.commitInternal(LmdbStoreConnection.java:91)
at org.eclipse.rdf4j.sail.helpers.AbstractSailConnection.commit(AbstractSailConnection.java:524)
at org.eclipse.rdf4j.repository.sail.SailRepositoryConnection.commit(SailRepositoryConnection.java:226)
... 37 common frames omitted
Caused by: java.io.IOException: MDB_BAD_VALSIZE: Unsupported size of key/DB name/data, or wrong DUPFIXED size
at org.eclipse.rdf4j.sail.lmdb.LmdbUtil.E(LmdbUtil.java:64)
at org.eclipse.rdf4j.sail.lmdb.ValueStore.lambda$findId$10(ValueStore.java:758)
at org.eclipse.rdf4j.sail.lmdb.LmdbUtil.readTransaction(LmdbUtil.java:86)
at org.eclipse.rdf4j.sail.lmdb.ValueStore.readTransaction(ValueStore.java:814)
at org.eclipse.rdf4j.sail.lmdb.ValueStore.findId(ValueStore.java:662)
at org.eclipse.rdf4j.sail.lmdb.ValueStore.getId(ValueStore.java:900)
at org.eclipse.rdf4j.sail.lmdb.ValueStore.storeValue(ValueStore.java:1221)
at org.eclipse.rdf4j.sail.lmdb.LmdbSailStore$LmdbSailSink.approveAll(LmdbSailStore.java:589)
Expected Behavior
for it to work
Steps To Reproduce
- redhat linux
- running 5.0 sdsk wars against tomcat 9.0.64
- created repo with configs:
#!/bin/bash
REPO_NAME="reponame"
REPO_DESC="reponame with lmdb rdf4j 5.0"
REPO_TRIPLE_SIZE_IN_GB=100
REPO_VALUE_SIZE_IN_MB=100
REPO_TRIPLE_INDEX="spoc,posc,ospc"
REPO_CONFIG=$(cat <<-END
@prefix rdfs: <http://www.w3.org/2000/01/rdf-schema#>.
@prefix rep: <http://www.openrdf.org/config/repository#>.
@prefix sr: <http://www.openrdf.org/config/repository/sail#>.
@prefix sail: <http://www.openrdf.org/config/sail#>.
@prefix ns: <http://www.openrdf.org/config/sail/native#>.
@prefix sb: <http://www.openrdf.org/config/sail/base#>.
@prefix lmdb: <http://rdf4j.org/config/sail/lmdb#>.
[] a rep:Repository ;
rep:repositoryID "$REPO_NAME" ;
rdfs:label "$REPO_DESC" ;
rep:repositoryImpl [
rep:repositoryType "openrdf:SailRepository" ;
sr:sailImpl [
sail:sailType "rdf4j:LmdbStore" ;
sb:defaultQueryEvaluationMode "STANDARD";
lmdb:tripleIndexes "$REPO_TRIPLE_INDEX";
lmdb:tripleDBSize $(($REPO_TRIPLE_SIZE_IN_GB*1024*1024*1024));
lmdb:valueDBSize $(($REPO_VALUE_SIZE_IN_MB*1024*1024));
lmdb:autoGrow "true";
]
].
END
)
echo "$REPO_CONFIG" > data.fil
CMD='curl -d "@data.fil" -H "Content-Type: text/turtle" -X PUT '"localhost:19440/rdf4j-server/repositories/$REPO_NAME"
eval "$CMD"
rm data.fil
- generated 10m triples with sp2bench (see above)
- used curl to upload to system
note: received multiple (4) "Resizing map from xxx to 2xxx" before it failed. I bumped up valueDBSize to 100GB and 10m worked but 100m failed with same MBD error as above (but I did not see a Resizing message)
Version
5.0
Are you interested in contributing a solution yourself?
None
Anything else?
No response
Might be related: https://github.com/meilisearch/meilisearch/issues/2743
Or could be caused by a ridiculously long literal, or maybe a long datatype or lang tag.
The key size is checked at this stage. What is new is the error check that was not present before.
Interestingly, the error occurs with mdb_get with a shorter value than was actually retrieved from the store itself. Maybe hashLength is greater than the length of hashIdBb in this case leading to the observed error. However, this should be guarded by compareRegion above?!
The only thing that could happen is that the key size is zero: https://github.com/LMDB/lmdb/blob/ddd0a773e2f44d38e4e31ec9ed81af81f4e4ccbb/libraries/liblmdb/mdb.c#L7129
That supports my reasoning above. A quick fix would be to either remove the additional E(...) check around the get invocation and or to check that hashLength is smaller than hashIdBb size.
@hmottestad I don't have access to a Computer in the next days. Could you support this?
The only thing that could happen is that the key size is zero:
https://github.com/LMDB/lmdb/blob/ddd0a773e2f44d38e4e31ec9ed81af81f4e4ccbb/libraries/liblmdb/mdb.c#L7129
That supports my reasoning above. A quick fix would be to either removed the additional E(...) check around the get invocation and or to check that hashLength is smaller than hashIdBb size.
@hmottestad I don't have access to a Computer in the next days. Could you support this?
I think it's probably best if you do. I don't exactly understand the reason for why the key would be zero length to begin with.
I'm going on holiday tomorrow for about a month. Since you are a committer now you are able to create and publish a release on your own. We have a script and also some documentation (which might be a bit out of date).
Script: https://github.com/eclipse-rdf4j/rdf4j/blob/main/scripts/release.sh
Documentation: https://rdf4j.org/documentation/developer/releases/
The script automates pretty much everything in the documentation. Feel free to email me at the RDF4J developer mailing list if you have any issues.
If you can quickly remove the E(...) check today and make a new release then I'll investigate this further in one or two weeks..If this is not possible then @nguyenm100 has to create his own local fix for now.
Just remove E(...) on this line: https://github.com/eclipse-rdf4j/rdf4j/blob/8e9043b4d5a5f87cf61d4bed0cb70c4e5c0fde6b/core/sail/lmdb/src/main/java/org/eclipse/rdf4j/sail/lmdb/ValueStore.java#L758
@hmottestad The length can be zero for the first found hash entry. This only happens if multiple values map to the same hash (collision).
Just to be absolutely sure, we're removing the E(..) wrapping call and leaving the mdb _get() and its return conditional check?
@kenwenzel I could have sworn that I had removed the E(...) calls where the return value was already being checked.
I pulled down tag 5.0.0 and recompiled locally and deployed just to baseline my setup. Seeing smth different now while trying to load 10m with same config.
No MDB error but logs look funny. It's resizing as expected but looks like it restarts the resize midway through. will share some logs below:
Deployed compiled wars and reran load. What's a little odd was that after this run there was no data in the repo (perhaps it was still flushing??) as count report 0.. I should have waited but I reran the load a second time.
2024-06-28 09:02:35,610 INFO o.e.r.h.s.r.s.StatementsController.handleRequestInternal(120) [repositories/matt] - POST data to repository
2024-06-28 09:04:55,069 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 104857600 to 209715200
2024-06-28 09:04:59,698 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 209715200 to 419430400
2024-06-28 09:05:10,426 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 419430400 to 838860800
2024-06-28 09:05:38,545 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 838860800 to 1677721600
2024-06-28 09:07:46,755 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 104857600 to 209715200
2024-06-28 09:07:49,736 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 209715200 to 419430400
2024-06-28 09:08:16,304 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 419430400 to 838860800
2024-06-28 09:09:02,014 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 838860800 to 1677721600
Second run same repo (note resizing patterns are different from first). This time all 10M made it in and i was able to get a count of 10m.
2024-06-28 09:12:09,959 INFO o.e.r.h.s.r.s.StatementsController.handleRequestInternal(120) [repositories/matt] - POST data to repository
2024-06-28 09:14:32,116 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 104857600 to 209715200
2024-06-28 09:14:36,652 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 209715200 to 419430400
2024-06-28 09:14:49,309 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 419430400 to 838860800
2024-06-28 09:16:59,401 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 104857600 to 209715200
2024-06-28 09:17:01,588 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 209715200 to 419430400
2024-06-28 09:17:16,172 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 419430400 to 838860800
2024-06-28 09:17:36,665 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 838860800 to 1677721600
3rd run I deleted the repo and recreated it and reran load. This time got some strange vocab discrepancy errors which I've not seen before. All 10M went it w/o incident.
2024-06-28 09:20:39,949 INFO o.e.r.h.s.r.h.DefaultRepositoryRequestHandler.handleDeleteRepositoryRequest(49) [repositories/matt] - DELETE request invoked for repository 'matt'
2024-06-28 09:20:40,360 INFO o.e.r.h.s.r.h.DefaultRepositoryRequestHandler.handleDeleteRepositoryRequest(60) [repositories/matt] - DELETE request successfully completed
2024-06-28 09:20:40,406 INFO o.e.r.h.s.r.TupleQueryResultView.logEndOfRequest(109) [http-nio-19440-exec-6] - Request for query 3392903 is finished
2024-06-28 09:21:03,123 INFO o.e.r.h.s.r.h.DefaultRepositoryRequestHandler.handleCreateOrUpdateRepositoryRequest(77) [repositories/matt] - PUT request invoked for repository 'matt'
2024-06-28 09:21:03,125 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 09:21:03,125 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 09:21:03,125 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 09:21:03,125 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 09:21:03,125 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 09:21:03,125 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 09:21:03,126 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 09:21:04,477 INFO o.e.r.h.s.r.TupleQueryResultView.logEndOfRequest(109) [http-nio-19440-exec-4] - Request for query 3392903 is finished
2024-06-28 09:21:10,504 INFO o.e.r.h.s.r.s.StatementsController.handleRequestInternal(120) [repositories/matt] - POST data to repository
2024-06-28 09:21:27,023 INFO o.e.r.h.s.r.TupleQueryResultView.logEndOfRequest(109) [http-nio-19440-exec-6] - Request for query 3392903 is finished
2024-06-28 09:21:52,559 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 104857600 to 209715200
2024-06-28 09:22:50,902 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 209715200 to 419430400
2024-06-28 09:25:17,749 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 419430400 to 838860800
2024-06-28 09:29:43,045 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 104857600 to 209715200
2024-06-28 09:29:44,236 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 209715200 to 419430400
2024-06-28 09:29:55,104 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 419430400 to 838860800
2024-06-28 09:30:13,736 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 838860800 to 1677721600
20
fourth run, i deleted repo and restarted service and got different resize results from run 3.
2024-06-28 09:31:15,008 INFO o.e.r.h.s.r.h.DefaultRepositoryRequestHandler.handleDeleteRepositoryRequest(49) [repositories/matt] - DELETE request invoked for repository 'matt'
2024-06-28 09:31:15,292 INFO o.e.r.h.s.r.h.DefaultRepositoryRequestHandler.handleDeleteRepositoryRequest(60) [repositories/matt] - DELETE request successfully completed
2024-06-28 09:31:15,347 INFO o.e.r.h.s.r.TupleQueryResultView.logEndOfRequest(109) [http-nio-19440-exec-3] - Request for query 3392903 is finished
2024-06-28 09:31:58,335 INFO o.e.r.c.a.l.l.LogbackConfiguration.init(52) [main] - Logback logging API implementation is configured.
2024-06-28 09:31:59,010 INFO o.s.w.s.DispatcherServlet.initServletBean(547) [main] - Completed initialization in 1013 ms
2024-06-28 09:32:00,945 INFO o.e.r.h.s.r.TupleQueryResultView.logEndOfRequest(109) [http-nio-19440-exec-3] - Request for query 3392903 is finished
2024-06-28 09:32:01,166 INFO o.e.r.h.s.r.TupleQueryResultView.logEndOfRequest(109) [http-nio-19440-exec-4] - Request for query 3392903 is finished
2024-06-28 09:32:03,916 INFO o.e.r.h.s.r.TupleQueryResultView.logEndOfRequest(109) [http-nio-19440-exec-7] - Request for query 3392903 is finished
2024-06-28 09:33:56,820 INFO o.e.r.h.s.r.h.DefaultRepositoryRequestHandler.handleCreateOrUpdateRepositoryRequest(77) [repositories/matt] - PUT request invoked for repository 'matt'
2024-06-28 09:33:56,877 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 09:33:56,879 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 09:33:56,880 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 09:33:56,889 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 09:33:56,891 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 09:33:56,904 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 09:33:56,906 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 09:34:00,903 INFO o.e.r.h.s.r.TupleQueryResultView.logEndOfRequest(109) [http-nio-19440-exec-1] - Request for query 3392903 is finished
2024-06-28 09:34:02,611 INFO o.e.r.h.s.r.TupleQueryResultView.logEndOfRequest(109) [http-nio-19440-exec-8] - Request for query 3392903 is finished
2024-06-28 09:34:02,618 INFO o.e.r.h.s.r.TupleQueryResultView.logEndOfRequest(109) [http-nio-19440-exec-9] - Request for query 3392903 is finished
2024-06-28 09:34:02,795 INFO o.e.r.h.s.r.TupleQueryResultView.logEndOfRequest(109) [repositories/matt] - Request for query 3392903 is finished
2024-06-28 09:34:02,857 INFO o.e.r.h.s.r.TupleQueryResultView.logEndOfRequest(109) [http-nio-19440-exec-4] - Request for query 3392903 is finished
2024-06-28 09:34:24,479 INFO o.e.r.h.s.r.s.StatementsController.handleRequestInternal(120) [repositories/matt] - POST data to repository
2024-06-28 09:36:50,215 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 104857600 to 209715200
2024-06-28 09:36:54,246 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 209715200 to 419430400
2024-06-28 09:37:03,712 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 419430400 to 838860800
2024-06-28 09:37:28,338 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 838860800 to 1677721600
2024-06-28 09:40:14,844 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 104857600 to 209715200
2024-06-28 09:40:16,028 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 209715200 to 419430400
2024-06-28 09:40:26,670 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 419430400 to 838860800
2024-06-28 09:40:44,893 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt] - Resizing map from 838860800 to 1677721600
5th run, I created a new repo (matt1) and reran load and got similar results as run 3.
2024-06-28 09:41:46,917 INFO o.e.r.h.s.r.h.DefaultRepositoryRequestHandler.handleCreateOrUpdateRepositoryRequest(77) [repositories/matt1] - PUT request invoked for repository 'matt1'
2024-06-28 09:41:46,919 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt1] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 09:41:46,919 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt1] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 09:41:46,919 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt1] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 09:41:46,919 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt1] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 09:41:46,919 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt1] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 09:41:46,920 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt1] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 09:41:46,920 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt1] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 09:41:57,474 INFO o.e.r.h.s.r.TupleQueryResultView.logEndOfRequest(109) [http-nio-19440-exec-4] - Request for query 3392903 is finished
2024-06-28 09:41:57,525 INFO o.e.r.h.s.r.TupleQueryResultView.logEndOfRequest(109) [http-nio-19440-exec-6] - Request for query 3392903 is finished
2024-06-28 09:42:01,359 INFO o.e.r.h.s.r.s.StatementsController.handleRequestInternal(120) [repositories/matt1] - POST data to repository
2024-06-28 09:44:23,543 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt1] - Resizing map from 104857600 to 209715200
2024-06-28 09:44:28,454 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt1] - Resizing map from 209715200 to 419430400
2024-06-28 09:44:42,081 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt1] - Resizing map from 419430400 to 838860800
2024-06-28 09:47:50,892 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt1] - Resizing map from 104857600 to 209715200
2024-06-28 09:47:52,305 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt1] - Resizing map from 209715200 to 419430400
2024-06-28 09:48:03,275 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt1] - Resizing map from 419430400 to 838860800
2024-06-28 09:48:21,710 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt1] - Resizing map from 838860800 to 1677721600
i will try 100m next to see if i can get the mdb errors with my locally built wars. probably still makes sense to remote the E() check but odd why no mdb errors didn't happen today for me.
Just to be absolutely sure, we're removing the E(..) wrapping call and leaving the mdb _get() and its return conditional check?
Yes. Only the wrapping E(...) call.
deleted and recreated the repo. ran through 100m with no errors, but once load was complete, repo size is 0 (verified by file sizes in the repo). this happened the very first time i tried to load 10m but could not repro with subsequent runs. this is the first time i've tried to load 100m on this machine. could it be an async write thing with lmdb? or maybe transaction was too large (but would have expected an error if so)?
2024-06-28 10:25:13,553 INFO o.e.r.h.s.r.h.DefaultRepositoryRequestHandler.handleCreateOrUpdateRepositoryRequest(77) [repositories/matt1] - PUT request invoked for repository 'matt1'
2024-06-28 10:25:13,554 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt1] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 10:25:13,554 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt1] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 10:25:13,554 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt1] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 10:25:13,554 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt1] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 10:25:13,555 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt1] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 10:25:13,555 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt1] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 10:25:13,555 WARN o.e.r.m.util.Configurations.logDiscrepancyWarning(238) [repositories/matt1] - Discrepancy between use of the old and new config vocabulary.
2024-06-28 10:25:25,223 INFO o.e.r.h.s.r.TupleQueryResultView.logEndOfRequest(109) [http-nio-19440-exec-1] - Request for query 3392903 is finished
2024-06-28 10:26:56,944 INFO o.e.r.h.s.r.s.StatementsController.handleRequestInternal(120) [repositories/matt1] - POST data to repository
2024-06-28 10:29:26,712 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt1] - Resizing map from 104857600 to 209715200
2024-06-28 10:29:31,333 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt1] - Resizing map from 209715200 to 419430400
2024-06-28 10:29:42,136 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt1] - Resizing map from 419430400 to 838860800
2024-06-28 10:30:08,220 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt1] - Resizing map from 838860800 to 1677721600
2024-06-28 10:37:50,402 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt1] - Resizing map from 1677721600 to 3355443200
2024-06-28 10:51:43,772 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt1] - Resizing map from 3355443200 to 6710886400
2024-06-28 11:19:34,307 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt1] - Resizing map from 6710886400 to 13421772800
2024-06-28 11:48:52,264 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt1] - Resizing map from 104857600 to 209715200
2024-06-28 11:49:03,677 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt1] - Resizing map from 209715200 to 419430400
2024-06-28 11:49:35,017 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt1] - Resizing map from 419430400 to 838860800
2024-06-28 11:50:46,206 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt1] - Resizing map from 838860800 to 1677721600
2024-06-28 11:52:09,216 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt1] - Resizing map from 1677721600 to 3355443200
2024-06-28 11:54:11,548 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt1] - Resizing map from 3355443200 to 6710886400
2024-06-28 12:10:08,243 INFO o.e.rdf4j.sail.lmdb.ValueStore.resizeMap(588) [repositories/matt1] - Resizing map from 6710886400 to 13421772800
It seems that it writes the data two times as it resizes the map also a second time. Maybe this is due to the memory overflow. Which isolation level are you using?
Please try with isolation level NONE and transactions of size around 100,000 - 500,000 triples each.
However, it should not happen that the repo is empty after inserting the data.
I'm not specifying in the curl call (above) so whatever is the default for rdf4j 5.0?
It seems that it writes the data two times as it resizes the map also a second time. Maybe this is due to the memory overflow. Which isolation level are you using?
Please try with isolation level NONE and transactions of size around 100,000 - 500,000 triples each.
However, it should not happen that the repo is empty after inserting the data.
it definitely work when we split the file to 100k each.
@nguyenm100 You could try to increase the size of the chunks to 500,000 or more. By passing transaction-setting__org.eclipse.rdf4j.common.transaction.IsolationLevel=NONE as HTTP parameter the insertion performance should also be improved.
BTW, the insertion performance of 30k TPS seems pretty low. What hardware are you using? I was able to load 1 billion statements in about an hour on a VM with network attached storage (but lots of RAM).
We're in an enterprise env so our standard vms are 32g and goes up from there.
Would be interested in understanding optimized configs for lmdb if you have them. 1b load in an hour is impressive. How much mem did you have? What are your setting for your jvm mx as a percentage of your total mem usually?
@nguyenm100 Are you using SSDs directly attached to the server?
@kenwenzel Could it be that since we don't call the MDB sync method that there is some chance that data isn't written to disk?
The vms are all accessed through ceph. We will look into bare metal at a later date.
@nguyenm100 Are you using SSDs directly attached to the server?
@kenwenzel Could it be that since we don't call the MDB sync method that there is some chance that data isn't written to disk?
@hmottestad It might be the case but 30k TPS seem slow. @nguyenm100 Does the data set have larger literals?
I meant about the issue when loading all the data in the first transaction where the DB is still empty afterwards.
I meant about the issue when loading all the data in the first transaction where the DB is still empty afterwards.
@hmottestad Ah OK. But then I wonder that reading from the memory overflow model seems to work?!
There are no large literals. All the records can be generated by the sp2b benchmarking framework as stated above
@nguyenm100 Could you share your particular repository configuration and the used parameters for SP2bench?
repo configuration is provided in the bug (how to reproduce).
download sp2bench from https://dbis.informatik.uni-freiburg.de/index.php%3Fproject=SP2B%252Fdownload.php.html expand and run
./sp2b_gen -t<number of triples>