Unfortunately, I cannot share the data that causes problems when we upload data
via s-put to a Fuseki 4.3.2 server.
I start the server like this (on windows):
java -Xmx12G -D'log4j.configuration'=file:log4j2.properties -jar
fuseki-server.jar
(I edited the log4j2.properties file to set the levels to DEBUG or TRACE to see
if I could get more info)
We create a dataset with the union graph by expanding this Bash template:
createDataset() {
cat <<EOF
@prefix fu: <http://jena.apache.org/fuseki#> .
@prefix fuseki: <http://jena.apache.org/fuseki#> .
@prefix rdf: <http://www.w3.org/1999/02/22-rdf-syntax-ns#> .
@prefix rdfs: <http://www.w3.org/2000/01/rdf-schema#> .
@prefix tdb: <http://jena.hpl.hp.com/2008/tdb#> .
@prefix ja: <http://jena.hpl.hp.com/2005/11/Assembler#> .
<#${FUSEKI_DATASET}-service> rdf:type fuseki:Service;
fu:name "${FUSEKI_DATASET}";
fu:dataset <#${FUSEKI_DATASET}> ;
fu:serviceQuery "sparql" ;
fu:serviceQuery "query" ;
fu:serviceUpdate "update" ;
fu:serviceUpload "upload" ;
fu:serviceReadWriteGraphStore "data" ;
fu:serviceReadGraphStore "get" ;
.
<#${FUSEKI_DATASET}> rdf:type tdb:DatasetTDB ;
tdb:location "--mem--" ;
tdb:unionDefaultGraph true;
.
EOF
}
We upload a bunch of files in rdf/xml and 3 in ttl format for the entailments
calculated by an owl2-dl/swrl reasoner for classes, properties and individuals.
The error happens systematically at the last file for individual entailments.
This file is fairly big – about 600 KB and has about 1.8 M lines of ttl
statements/spaces.
Once, I got a server error like this:
18:00:40 INFO Fuseki :: [45] PUT
http://localhost:3030/00afdacb677fce276d5463bc8f09aa909a8e9755/data?graph=http%3A%2F%2Feuropa.jpl.nasa.gov%2Fbundle%2F___I%2Fexported-user-models
18:00:40 INFO Fuseki :: [45] => User-Agent: SOH/Fuseki
1.0.0
18:00:40 INFO Fuseki :: [45] => Host: localhost:3030
18:00:40 INFO Fuseki :: [45] => Content-Length: 588975765
18:00:40 INFO Fuseki :: [45] => Content-Type:
text/turtle;charset=utf-8;charset=utf-8
19:10:59 INFO Fuseki :: [44] <= Content-Type:
application/json
19:10:59 INFO Fuseki :: [44] <= Content-Length: 73
19:10:59 INFO Fuseki :: [44] 201 Created (4,595.635 s)
19:11:15 INFO Fuseki :: [45] <= Content-Type: text/plain
19:11:15 INFO Fuseki :: [45] <= Content-Length: 97
19:11:15 INFO Fuseki :: [45] <= Cache-Control:
must-revalidate,no-cache,no-store
19:11:15 INFO Fuseki :: [45] <= Pragma: no-cache
19:11:15 INFO Fuseki :: [45] 500 Server Error (4,234.691 s)
Is there a way to make sure that any such 500 error is logged with additional
information about it cause?
Could there be an unlogged internal exception?
If so, how can we force all internal exceptions to be logged no matter what?
I tried to turn on debugging to see what is happening by changing most INFO to
DEBUG levels and adding the –debug flag.
Below is the partial log of loading the large entailments: C = class, P =
property, I = individuals.
There are lots of JournalControl log messages that I have elided.
12:08:46 INFO Fuseki :: [61] PUT
http://localhost:3030/00afdacb677fce276d5463bc8f09aa909a8e9755/data?graph=http%3A%2F%2Feuropa.jpl.nasa.gov%2Fbundle%2F_C__%2Fexported-user-models
12:08:46 INFO Fuseki :: [61] => User-Agent: SOH/Fuseki
1.0.0
12:08:46 INFO Fuseki :: [61] => Host: localhost:3030
12:08:46 INFO Fuseki :: [61] => Content-Length: 3514749
12:08:46 INFO Fuseki :: [61] => Content-Type:
text/turtle;charset=utf-8;charset=utf-8
12:08:46 DEBUG TDB :: Txn[45]/W: begin$
12:08:46 DEBUG LockMRSW :: Lock : qtp665565246-28
12:08:46 DEBUG TDB :: Txn[45]/W: begin
12:08:46 DEBUG LockMRSW :: qtp665565246-28 >> enterCS: Thread R/W: 0/0
:: Model R/W: 0/0 (thread: qtp665565246-28)
12:08:46 DEBUG LockMRSW :: qtp665565246-28 << enterCS: Thread R/W: 1/0
:: Model R/W: 1/0 (thread: qtp665565246-28)
12:08:46 DEBUG Fuseki ::
PUT->target:<http://europa.jpl.nasa.gov/bundle/_C__/exported-user-models>
12:08:46 INFO Fuseki :: [61] Body: Content-Length=3514749,
Content-Type=text/turtle, Charset=utf-8;charset=utf-8 => Turtle : Count=35378
Triples=35378 Quads=0
12:08:46 DEBUG TDB :: Txn[45]/W: commit
12:08:46 DEBUG LockMRSW :: qtp665565246-28 >> leaveCS: Thread R/W: 1/0
:: Model R/W: 1/0 (thread: qtp665565246-28)
12:08:46 DEBUG LockMRSW :: qtp665565246-28 << leaveCS: Thread R/W: 0/0
:: Model R/W: 0/0 (thread: qtp665565246-28)
12:08:46 DEBUG TDB :: Txn[45]/W: Commit immediately
12:08:46 DEBUG TDB :: Replay Txn[45]/W
12:08:46 DEBUG JournalControl :: Replay: fileref(35):node2id.dat Block: 769
(posn=0, limit=8192, cap=8192)
…
12:08:46 DEBUG JournalControl :: Replay: fileref(28):SPOG.dat Block: 5119
(posn=0, limit=8192, cap=8192)
12:08:46 DEBUG JournalControl :: Replay: fileref(37):prefixIdx.dat Block: 0
(posn=0, limit=8192, cap=8192)
12:08:46 INFO Fuseki :: [61] <= Content-Type:
application/json
12:08:46 INFO Fuseki :: [61] <= Content-Length: 69
12:08:46 INFO Fuseki :: [61] 201 Created (566 ms)
127.0.0.1 - - [05/Jan/2022:20:08:46 +0000] "PUT
/00afdacb677fce276d5463bc8f09aa909a8e9755/data" 201 69 "" "SOH/Fuseki 1.0.0"
12:08:47 INFO Fuseki :: [62] PUT
http://localhost:3030/00afdacb677fce276d5463bc8f09aa909a8e9755/data?graph=http%3A%2F%2Feuropa.jpl.nasa.gov%2Fbundle%2F__P_%2Fexported-user-models
12:08:47 INFO Fuseki :: [62] => User-Agent: SOH/Fuseki
1.0.0
12:08:47 INFO Fuseki :: [62] => Host: localhost:3030
12:08:47 INFO Fuseki :: [62] => Content-Length: 607158
12:08:47 INFO Fuseki :: [62] => Content-Type:
text/turtle;charset=utf-8;charset=utf-8
12:08:47 DEBUG TDB :: Txn[46]/W: begin$
12:08:47 DEBUG LockMRSW :: Lock : qtp665565246-47
12:08:47 DEBUG TDB :: Txn[46]/W: begin
12:08:47 DEBUG LockMRSW :: qtp665565246-47 >> enterCS: Thread R/W: 0/0
:: Model R/W: 0/0 (thread: qtp665565246-47)
12:08:47 DEBUG LockMRSW :: qtp665565246-47 << enterCS: Thread R/W: 1/0
:: Model R/W: 1/0 (thread: qtp665565246-47)
12:08:47 DEBUG Fuseki ::
PUT->target:<http://europa.jpl.nasa.gov/bundle/__P_/exported-user-models>
12:08:47 INFO Fuseki :: [62] Body: Content-Length=607158,
Content-Type=text/turtle, Charset=utf-8;charset=utf-8 => Turtle : Count=5012
Triples=5012 Quads=0
12:08:47 DEBUG TDB :: Txn[46]/W: commit
12:08:47 DEBUG LockMRSW :: qtp665565246-47 >> leaveCS: Thread R/W: 1/0
:: Model R/W: 1/0 (thread: qtp665565246-47)
12:08:47 DEBUG LockMRSW :: qtp665565246-47 << leaveCS: Thread R/W: 0/0
:: Model R/W: 0/0 (thread: qtp665565246-47)
12:08:47 DEBUG TDB :: Txn[46]/W: Commit immediately
12:08:47 DEBUG TDB :: Replay Txn[46]/W
12:08:47 DEBUG JournalControl :: Replay: fileref(35):node2id.dat Block: 80
(posn=0, limit=8192, cap=8192)
…
12:08:47 DEBUG JournalControl :: Replay: fileref(28):SPOG.dat Block: 5119
(posn=0, limit=8192, cap=8192)
12:08:47 DEBUG JournalControl :: Replay: fileref(37):prefixIdx.dat Block: 0
(posn=0, limit=8192, cap=8192)
12:08:47 INFO Fuseki :: [62] <= Content-Type:
application/json
12:08:47 INFO Fuseki :: [62] <= Content-Length: 67
12:08:47 INFO Fuseki :: [62] 201 Created (164 ms)
127.0.0.1 - - [05/Jan/2022:20:08:47 +0000] "PUT
/00afdacb677fce276d5463bc8f09aa909a8e9755/data" 201 67 "" "SOH/Fuseki 1.0.0"
12:08:47 INFO Fuseki :: [63] PUT
http://localhost:3030/00afdacb677fce276d5463bc8f09aa909a8e9755/data?graph=http%3A%2F%2Feuropa.jpl.nasa.gov%2Fbundle%2F___I%2Fexported-user-models
12:08:47 INFO Fuseki :: [63] => User-Agent: SOH/Fuseki
1.0.0
12:08:47 INFO Fuseki :: [63] => Host: localhost:3030
12:08:47 INFO Fuseki :: [63] => Content-Length: 588975765
12:08:47 INFO Fuseki :: [63] => Content-Type:
text/turtle;charset=utf-8;charset=utf-8
12:08:47 DEBUG TDB :: Txn[47]/W: begin$
12:08:47 DEBUG LockMRSW :: Lock : qtp665565246-39
12:08:47 DEBUG TDB :: Txn[47]/W: begin
12:08:47 DEBUG LockMRSW :: qtp665565246-39 >> enterCS: Thread R/W: 0/0
:: Model R/W: 0/0 (thread: qtp665565246-39)
12:08:47 DEBUG LockMRSW :: qtp665565246-39 << enterCS: Thread R/W: 1/0
:: Model R/W: 1/0 (thread: qtp665565246-39)
12:08:47 DEBUG Fuseki ::
PUT->target:<http://europa.jpl.nasa.gov/bundle/___I/exported-user-models>
12:09:22 INFO Fuseki :: [63] Body: Content-Length=588975765,
Content-Type=text/turtle, Charset=utf-8;charset=utf-8 => Turtle : Count=2050519
Triples=2050519 Quads=0
12:14:52 INFO Fuseki :: [64] PUT
http://localhost:3030/00afdacb677fce276d5463bc8f09aa909a8e9755/data?graph=http%3A%2F%2Feuropa.jpl.nasa.gov%2Fbundle%2F___I%2Fexported-user-models
12:14:52 INFO Fuseki :: [64] => User-Agent: SOH/Fuseki
1.0.0
12:14:52 INFO Fuseki :: [64] => Host: localhost:3030
12:14:52 INFO Fuseki :: [64] => Content-Length: 588975765
12:14:52 INFO Fuseki :: [64] => Content-Type:
text/turtle;charset=utf-8;charset=utf-8
On the client side where we use s-put, I got this info:
#----------------------------------
# IRI=http://europa.jpl.nasa.gov/bundle/_C__/exported-user-models
#
/data/outputs/process/auxiliary/owl/europa.jpl.nasa.gov/bundle/_C__/exported-user-models.ttl
#
/data/inputs/auxiliary/owl/europa.jpl.nasa.gov/bundle/_C__/exported-user-models.ttl
# Uploading http://europa.jpl.nasa.gov/bundle/_C__/exported-user-models from
/data/inputs/auxiliary/owl/europa.jpl.nasa.gov/bundle/_C__/exported-user-models.ttl
#----------------------------------
# IRI=http://europa.jpl.nasa.gov/bundle/__P_/exported-user-models
#
/data/outputs/process/auxiliary/owl/europa.jpl.nasa.gov/bundle/__P_/exported-user-models.ttl
#
/data/inputs/auxiliary/owl/europa.jpl.nasa.gov/bundle/__P_/exported-user-models.ttl
# Uploading http://europa.jpl.nasa.gov/bundle/__P_/exported-user-models from
/data/inputs/auxiliary/owl/europa.jpl.nasa.gov/bundle/__P_/exported-user-models.ttl
#----------------------------------
# IRI=http://europa.jpl.nasa.gov/bundle/___I/exported-user-models
#
/data/outputs/process/auxiliary/owl/europa.jpl.nasa.gov/bundle/___I/exported-user-models.ttl
#
/data/inputs/auxiliary/owl/europa.jpl.nasa.gov/bundle/___I/exported-user-models.ttl
# Uploading http://europa.jpl.nasa.gov/bundle/___I/exported-user-models from
/data/inputs/auxiliary/owl/europa.jpl.nasa.gov/bundle/___I/exported-user-models.ttl
Failed to connect: localhost:3030: end of file reached
That is, the server did not crash but it was busy for a few minutes, then
strangely it logged the PUT a second time. Then a few minutes later, the client
stopped with ‘Failed to connect…’
Is there a way to get additional log visibility into what is happening during
these minutes?
Nicolas F. Rouquette
Principal Computer Scientist
Jet Propulsion Laboratory, California Institute of Technology M/S 301-490, 4800
Oak Grove Dr, Pasadena, CA 91189, USA
email: nicolas.f.rouque...@jpl.nasa.gov<mailto:nicolas.f.rouque...@jpl.nasa.gov>
cell: +1 (626) 639-5282
