When any code in VIVO accesses the knowledge base (the content models), the request goes through the RDFService interface. The logging RDF Service wrapper allows a developer to see
- what queries are executed,
- how long each query takes,
- what code created the query.
When the logging RDF Service is enabled, it can slow VIVO significantly.
The RDFService interface is used only for content data. This will not log queries against configuration data, like user accounts or display configuration.
Controls
The logging RDF Service is controlled by these runtime properties
developer.loggingRDFService.enable
- The logging RDF Service will do nothing unless this is set to
true
- The logging RDF Service will do nothing unless this is set to
developer.loggingRDFService.stackTrace
- If this is set to
true
each log message will include an abridged stack trace, showing what code requested the query.
- If this is set to
developer.loggingRDFService.restriction
- This can be set to a regular expression that will limit the log messages. Queries are not logged unless one (or more) of the class names in the stack trace match this restriction.
The logging RDF Service is also controlled by the Log4J settings. The messages are logged at a level of INFO
, so if the logging level of edu.cornell.mannlib.vitro.webapp.rdfservice.impl.logging.RDFServiceLogger
is set to WARN
or higher, no messages will be produced. This is equivalent to setting developer.loggingRDFService.enable
to false
, except that you can modify the logging level while VIVO is running.
Examples
Here are some option settings, with explanations.
developer.loggingRDFService.enable=true
The logging RDF Service is enabled. All queries will be logged. This produces a lot of output.
developer.loggingRDFService.enable = true developer.loggingRDFService.stackTrace = true
The logging RDF Service is enabled. All queries will be logged, with a stack trace for each query. This produces a vast amount of output. During the course of a single startup, VIVO will produce multiple log files, as the size limit is exceeded more than once.
developer.loggingRDFService.enable = true developer.loggingRDFService.restriction = SparqlQueryDataGetter
The logging RDF Service is enabled. Queries will be logged only if one of the classes in the stack trace contains the pattern SparqlQueryDataGetter.
developer.loggingRDFService.enable = true developer.loggingRDFService.stackTrace = true developer.loggingRDFService.restriction = SparqlQueryDataGetter|freemarker.template
The logging RDF Service is enabled. Queries will be logged, with stack traces, only if one of the classes in the stack trace contains either SparqlQueryDataGetter
or freemarker.template
.
Output
2013-10-31 12:56:43,283 INFO [RDFServiceLogger] 0.160 sparqlSelectQuery [JSON, SELECT * WHERE { ?s <http://www.w3.org/1999/02/22-rdf-syntax-ns#type> <http://xmlns.com/foaf/0.1/Person> }]
This message does not include a stack trace. The query took 0.160 seconds to execute. It used the RDFService.sparqlSelectQuery()
method, asking for the output in JSON
format. The SPARQL query is as shown.
2013-11-01 11:53:01,553 INFO [RDFServiceLogger] 0.004 sparqlSelectQuery [JSON, SELECT * WHERE { <http://vivo.mydomain.edu/individual/n5124> <http://www.w3.org/2006/vcard/ns#hasTitle> ?o }] line 614, edu.cornell.mannlib.vitro.webapp.rdfservice.impl.logging.LoggingRDFService line 1634, edu.cornell.mannlib.vitro.webapp.rdfservice.filter.LanguageFilteringRDFService line 3954, edu.cornell.mannlib.vitro.webapp.dao.jena.RDFServiceGraph line 2544, edu.cornell.mannlib.vitro.webapp.dao.jena.RDFServiceGraph line 1864, edu.cornell.mannlib.vitro.webapp.dao.jena.RDFServiceGraph line 3544, edu.cornell.mannlib.vitro.webapp.rdfservice.impl.jena.RDFServiceJena line 1634, edu.cornell.mannlib.vitro.webapp.rdfservice.filter.LanguageFilteringRDFService line 3954, edu.cornell.mannlib.vitro.webapp.dao.jena.RDFServiceGraph line 2544, edu.cornell.mannlib.vitro.webapp.dao.jena.RDFServiceGraph line 1864, edu.cornell.mannlib.vitro.webapp.dao.jena.RDFServiceGraph line 1634, edu.cornell.mannlib.vitro.webapp.utils.dataGetter.SparqlQueryDataGetter line 1414, edu.cornell.mannlib.vitro.webapp.utils.dataGetter.SparqlQueryDataGetter line 4854, edu.cornell.mannlib.vitro.webapp.services.shortview.FakeApplicationOntologyService$FakeVivoPeopleDataGetter line 1344, edu.cornell.mannlib.vitro.webapp.services.shortview.ShortViewServiceImpl line 964, edu.cornell.mannlib.vitro.webapp.services.shortview.ShortViewServiceImpl line 504, edu.cornell.mannlib.vitro.webapp.services.shortview.ShortViewServiceImpl line 814, edu.cornell.mannlib.vitro.webapp.controller.json.GetRandomSolrIndividualsByVClass line 664, edu.cornell.mannlib.vitro.webapp.controller.json.GetRandomSolrIndividualsByVClass line 534, edu.cornell.mannlib.vitro.webapp.controller.json.GetRandomSolrIndividualsByVClass line 524, edu.cornell.mannlib.vitro.webapp.controller.json.JsonObjectProducer line 794, edu.cornell.mannlib.vitro.webapp.controller.json.JsonServlet line 6214, javax.servlet.http.HttpServlet line 7224, javax.servlet.http.HttpServlet line 704, edu.cornell.mannlib.vitro.webapp.controller.VitroHttpServlet line 3044, org.apache.catalina.core.ApplicationFilterChain ...
This query includes a stack trace. The trace is abridged:
- It shows class names and line numbers, but not file names or method names.
- References to JENA classes have been removed (anything in
com.hp.hpl.jena
or sub-packages). - The trace is truncated when it reaches when it reaches the
Filter
chain.
Generated SPARQL queries
All access to the content data is in the form of SPARQL queries through the RDF Service interface.
Other forms of access are translated to queries against the RDF Service:
- When code calls the
listStatements()
method on an OntModel, the infrastructure behind that OntModel uses SPARQL queries to obtain the information. - When code executes a SPARQL query against an OntModel, this may be executed directly against the underlying RDFService, or it may be broken down into simpler queries.
Sometimes, some detective work is required to determine what code generated which queries.