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.

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
• developer.loggingRDFService.stackTrace
  
  • If this is set to true each log message will include an abridged stack trace, showing what code requested the query.
• 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.