Closed chenejac closed 3 years ago
chenejac
commented
3 years ago Matthias Lühr said:
[^mkpubs.rb]
Attached is the script I used to generate lots of triples for generating lots of publication having 4 multilingual labels each asscociating it to a dummy person.
The script itself is pretty straight forward, though.
chenejac
commented
3 years ago Matthias Lühr said:
This is VIVOs behaviour after loading 1000 publications into a person's profile with language filtering disabled:
2020-10-27 16:44:28,879 INFO [RDFServiceLogger] 0.669 sparqlSelectQuery [ PREFIX rdfs: http://www.w3.org/2000/01/rdf-schema# PREFIX core: http://vivoweb.org/ontology/core# PREFIX bibo: http://purl.org/ontology/bibo/ PREFIX vitro: http://vitro.mannlib.cornell.edu/ns/vitro/0.7# PREFIX foaf: http://xmlns.com/foaf/0.1/ SELECT DISTINCT ?subclass ?authorship ?infoResource ?infoResourceName ?dateTime ?journal ?volume ?startPage ?endPage ?doi ?pmid ?isbn10 ?isbn13 ?publisher ?locale ?appearsIn ?partOf ?editor ?hideThis WHERE { https://vivo.hs-mittweida.de/vivo/individual/person_idm79141 http://vivoweb.org/ontology/core#relatedBy ?authorship . ?authorship a core:Authorship ; core:relates ?infoResource . ?infoResource a http://purl.obolibrary.org/obo/IAO_0000030 ; rdfs:label ?infoResourceName . OPTIONAL { ?infoResource vitro:mostSpecificType ?subclass . } OPTIONAL { ?infoResource bibo:volume ?volume . } OPTIONAL { ?infoResource bibo:pageStart ?startPage . } OPTIONAL { ?infoResource bibo:pageEnd ?endPage . } OPTIONAL { ?infoResource bibo:doi ?doi . } OPTIONAL { ?infoResource bibo:pmid ?pmid . } OPTIONAL { ?infoResource bibo:isbn10 ?isbn10 . } OPTIONAL { ?infoResource bibo:isbn13 ?isbn13 . } OPTIONAL { ?infoResource bibo:oclc ?oclc . } OPTIONAL { ?infoResource core:placeOfPublication ?locale . } OPTIONAL { ?infoResource bibo:reproducedIn ?appearsInObj . ?appearsInObj rdfs:label ?appearsIn . } OPTIONAL { ?infoResource core:publisher ?publisherObj . ?publisherObj rdfs:label ?publisher . } OPTIONAL { ?infoResource http://purl.obolibrary.org/obo/BFO_0000050 ?partOfObj . ?partOfObj rdfs:label ?partOf . } OPTIONAL { ?infoResource core:hasPublicationVenue ?publishedIn . ?publishedIn rdfs:label ?journal . } OPTIONAL { ?infoResource core:dateTimeValue ?dateTimeValue . ?dateTimeValue core:dateTime ?dateTime . } OPTIONAL { ?infoResource core:relatedBy ?editorship . ?editorship a core:Editorship . ?editorship core:relates ?editorObj . ?editorObj a foaf:Person . ?editorObj rdfs:label ?editor . } OPTIONAL { ?authorship core:hideFromDisplay ?hideThis . } } ORDER BY ?subclass DESC(?dateTime) ?infoResourceName ] edu.cornell.mannlib.vitro.webapp.rdfservice.impl.logging.LoggingRDFService.sparqlSelectQuery(LoggingRDFService.java:79)
edu.cornell.mannlib.vitro.webapp.dao.jena.ObjectPropertyStatementDaoJena.selectFromRDFService(ObjectPropertyStatementDaoJena.java:352)
edu.cornell.mannlib.vitro.webapp.dao.jena.ObjectPropertyStatementDaoJena.getObjectPropertyStatementsForIndividualByProperty(ObjectPropertyStatementDaoJena.java:316)
edu.cornell.mannlib.vitro.webapp.dao.filtering.ObjectPropertyStatementDaoFiltering.getObjectPropertyStatementsForIndividualByProperty(ObjectPropertyStatementDaoFiltering.java:93)
edu.cornell.mannlib.vitro.webapp.web.templatemodels.individual.ObjectPropertyTemplateModel.getStatementData(ObjectPropertyTemplateModel.java:166)
edu.cornell.mannlib.vitro.webapp.web.templatemodels.individual.CollatedObjectPropertyTemplateModel.
and that's after enabling the language filter:
2020-10-27 16:47:38,612 INFO [RDFServiceLogger] 9.111 sparqlSelectQuery [ PREFIX rdfs: http://www.w3.org/2000/01/rdf-schema# PREFIX core: http://vivoweb.org/ontology/core# PREFIX bibo: http://purl.org/ontology/bibo/ PREFIX vitro: http://vitro.mannlib.cornell.edu/ns/vitro/0.7# PREFIX foaf: http://xmlns.com/foaf/0.1/ SELECT DISTINCT ?subclass ?authorship ?infoResource ?infoResourceName ?dateTime ?journal ?volume ?startPage ?endPage ?doi ?pmid ?isbn10 ?isbn13 ?publisher ?locale ?appearsIn ?partOf ?editor ?hideThis WHERE { https://vivo.hs-mittweida.de/vivo/individual/person_idm79141 http://vivoweb.org/ontology/core#relatedBy ?authorship . ?authorship a core:Authorship ; core:relates ?infoResource . ?infoResource a http://purl.obolibrary.org/obo/IAO_0000030 ; rdfs:label ?infoResourceName . OPTIONAL { ?infoResource vitro:mostSpecificType ?subclass . } OPTIONAL { ?infoResource bibo:volume ?volume . } OPTIONAL { ?infoResource bibo:pageStart ?startPage . } OPTIONAL { ?infoResource bibo:pageEnd ?endPage . } OPTIONAL { ?infoResource bibo:doi ?doi . } OPTIONAL { ?infoResource bibo:pmid ?pmid . } OPTIONAL { ?infoResource bibo:isbn10 ?isbn10 . } OPTIONAL { ?infoResource bibo:isbn13 ?isbn13 . } OPTIONAL { ?infoResource bibo:oclc ?oclc . } OPTIONAL { ?infoResource core:placeOfPublication ?locale . } OPTIONAL { ?infoResource bibo:reproducedIn ?appearsInObj . ?appearsInObj rdfs:label ?appearsIn . } OPTIONAL { ?infoResource core:publisher ?publisherObj . ?publisherObj rdfs:label ?publisher . } OPTIONAL { ?infoResource http://purl.obolibrary.org/obo/BFO_0000050 ?partOfObj . ?partOfObj rdfs:label ?partOf . } OPTIONAL { ?infoResource core:hasPublicationVenue ?publishedIn . ?publishedIn rdfs:label ?journal . } OPTIONAL { ?infoResource core:dateTimeValue ?dateTimeValue . ?dateTimeValue core:dateTime ?dateTime . } OPTIONAL { ?infoResource core:relatedBy ?editorship . ?editorship a core:Editorship . ?editorship core:relates ?editorObj . ?editorObj a foaf:Person . ?editorObj rdfs:label ?editor . } OPTIONAL { ?authorship core:hideFromDisplay ?hideThis . } } ORDER BY ?subclass DESC(?dateTime) ?infoResourceName ] edu.cornell.mannlib.vitro.webapp.rdfservice.impl.logging.LoggingRDFService.sparqlSelectQuery(LoggingRDFService.java:79)
edu.cornell.mannlib.vitro.webapp.rdfservice.filter.LanguageFilteringRDFService.sparqlSelectQuery(LanguageFilteringRDFService.java:177)
edu.cornell.mannlib.vitro.webapp.dao.jena.ObjectPropertyStatementDaoJena.selectFromRDFService(ObjectPropertyStatementDaoJena.java:352)
edu.cornell.mannlib.vitro.webapp.dao.jena.ObjectPropertyStatementDaoJena.getObjectPropertyStatementsForIndividualByProperty(ObjectPropertyStatementDaoJena.java:316)
edu.cornell.mannlib.vitro.webapp.dao.filtering.ObjectPropertyStatementDaoFiltering.getObjectPropertyStatementsForIndividualByProperty(ObjectPropertyStatementDaoFiltering.java:93)
edu.cornell.mannlib.vitro.webapp.web.templatemodels.individual.ObjectPropertyTemplateModel.getStatementData(ObjectPropertyTemplateModel.java:166)
edu.cornell.mannlib.vitro.webapp.web.templatemodels.individual.CollatedObjectPropertyTemplateModel.
chenejac
commented
3 years ago Andrew Woods said:
That is a big difference:
chenejac
commented
3 years ago Matthias Lühr said:
I think I spotted the responsible part
https://github.com/matthiasluehr/Vitro/commit/907031d138bd112ebedfb77929ea27e4c1273ba6
chenejac
commented
3 years ago Matthias Lühr said:
[^vivo-1931-100-publications.txt]
chenejac
commented
3 years ago Matthias Lühr said:
[^vivo-1931-1000-publications.txt]
chenejac
commented
3 years ago Andrew Woods said:
[~accountid:6113d645b704b400686dc9fc]: After analyzing your logging and the code, you are definitely looking at the problem section. Fundamentally, the algorithm used in the LanguageFilteringDRDService.endProcesing() method needs to be restructured. Right now, the algorithm is involves four nested loops:
The math on this explodes with large numbers of publications. Instead of looping over the 'vars' and 'publications' twice each, we should be trying to condense it to a minimal number of loops. The end result is a populated "solnList" with language-filtered results.
As a demonstration of the issue, just commenting out the second "for: solnList.size" loop improves the timing significantly.
chenejac
commented
3 years ago Brian Lowe said:
It seems like one possible approach might be to pre-sort the result set by each non-literal column. Then there would be contiguous sets of rows that could be filtered via one pass through the result set, e.g.:
?infoResource ?journal ?infoResourceTitle ?journalTitle
A J "ceva titlu"@ro "ceva revista"@ro
A J "some title"@en "ceva revista"@ro
A J "ceva titlu"@ro "some journal"@en
A J "some title"@en "some journal"@en
B K "nu știu"@ro "habar n-am"@ro
B K "don't know"@en "habar n-am"@ro
B K "nu știu"@ro "got no idea"@en
B K "don't know"@en "got no idea"@en
Seems like the O( n log ( n ) ) -ish nature of sorting would make this better, at least for large N.
chenejac
commented
3 years ago Brian Lowe said:
Alternatively, I guess you could skip the sorting altogether and just assume that the incoming result set is already sorted – which seems like it should be the case for any real-world list view queries assembling coherent lists of results for page display. If it's some arbitrary unsorted query, then we accept the risk that it may be incompletely filtered. Edit: On further reflection, this is probably too dangerous. There will certainly be incoming queries that only sort on things like ?infoResourceTitle, where the rows to compare in the filter will be separated by arbitrary distances.
chenejac
commented
3 years ago Andrew Woods said:
[~accountid:6113d645b704b400686dc9fc]: can you test this pull-request: https://github.com/vivo-project/Vitro/pull/194
[~accountid:557058:3f53c733-6ac2-4e92-9f12-e34e297283a3]: can you review the code updates?
chenejac
commented
3 years ago Matthias Lühr said:
1000 publications:
2020-10-30 10:53:45,852 INFO [RDFServiceLogger] 0.685 sparqlSelectQuery [ PREFIX rdfs: http://www.w3.org/2000/01/rdf-schema# PREFIX core: http://vivoweb.org/ontology/core# PREFIX bibo: http://purl.org/ontology/bibo/ PREFIX vitro: http://vitro.mannlib.cornell.edu/ns/vitro/0.7# PREFIX foaf: http://xmlns.com/foaf/0.1/ SELECT DISTINCT ?subclass ?authorship ?infoResource ?infoResourceName ?dateTime ?journal ?volume ?startPage ?endPage ?doi ?pmid ?isbn10 ?isbn13 ?publisher ?locale ?appearsIn ?partOf ?editor ?hideThis WHERE { https://vivo.hs-mittweida.de/vivo/individual/person_idm79141 http://vivoweb.org/ontology/core#relatedBy ?authorship . ?authorship a core:Authorship ; core:relates ?infoResource . ?infoResource a http://purl.obolibrary.org/obo/IAO_0000030 ; rdfs:label ?infoResourceName . OPTIONAL { ?infoResource vitro:mostSpecificType ?subclass . } OPTIONAL { ?infoResource bibo:volume ?volume . } OPTIONAL { ?infoResource bibo:pageStart ?startPage . } OPTIONAL { ?infoResource bibo:pageEnd ?endPage . } OPTIONAL { ?infoResource bibo:doi ?doi . } OPTIONAL { ?infoResource bibo:pmid ?pmid . } OPTIONAL { ?infoResource bibo:isbn10 ?isbn10 . } OPTIONAL { ?infoResource bibo:isbn13 ?isbn13 . } OPTIONAL { ?infoResource bibo:oclc ?oclc . } OPTIONAL { ?infoResource core:placeOfPublication ?locale . } OPTIONAL { ?infoResource bibo:reproducedIn ?appearsInObj . ?appearsInObj rdfs:label ?appearsIn . } OPTIONAL { ?infoResource core:publisher ?publisherObj . ?publisherObj rdfs:label ?publisher . } OPTIONAL { ?infoResource http://purl.obolibrary.org/obo/BFO_0000050 ?partOfObj . ?partOfObj rdfs:label ?partOf . } OPTIONAL { ?infoResource core:hasPublicationVenue ?publishedIn . ?publishedIn rdfs:label ?journal . } OPTIONAL { ?infoResource core:dateTimeValue ?dateTimeValue . ?dateTimeValue core:dateTime ?dateTime . } OPTIONAL { ?infoResource core:relatedBy ?editorship . ?editorship a core:Editorship . ?editorship core:relates ?editorObj . ?editorObj a foaf:Person . ?editorObj rdfs:label ?editor . } OPTIONAL { ?authorship core:hideFromDisplay ?hideThis . } } ORDER BY ?subclass DESC(?dateTime) ?infoResourceName ] edu.cornell.mannlib.vitro.webapp.rdfservice.impl.logging.LoggingRDFService.sparqlSelectQuery(LoggingRDFService.java:79)
edu.cornell.mannlib.vitro.webapp.rdfservice.filter.LanguageFilteringRDFService.sparqlSelectQuery(LanguageFilteringRDFService.java:197)
edu.cornell.mannlib.vitro.webapp.dao.jena.ObjectPropertyStatementDaoJena.selectFromRDFService(ObjectPropertyStatementDaoJena.java:352)
edu.cornell.mannlib.vitro.webapp.dao.jena.ObjectPropertyStatementDaoJena.getObjectPropertyStatementsForIndividualByProperty(ObjectPropertyStatementDaoJena.java:316)
edu.cornell.mannlib.vitro.webapp.dao.filtering.ObjectPropertyStatementDaoFiltering.getObjectPropertyStatementsForIndividualByProperty(ObjectPropertyStatementDaoFiltering.java:93)
edu.cornell.mannlib.vitro.webapp.web.templatemodels.individual.ObjectPropertyTemplateModel.getStatementData(ObjectPropertyTemplateModel.java:166)
edu.cornell.mannlib.vitro.webapp.web.templatemodels.individual.CollatedObjectPropertyTemplateModel.
chenejac
commented
3 years ago Matthias Lühr said:
I took the time of the first and the second pass starting from line 223 in LanguageFilteringRDFService.java:
2020-10-30 14:11:04,849 INFO [LanguageFilteringRDFService] VIVO-1931: We are iteraing over 4001 elements. 2020-10-30 14:11:04,851 INFO [LanguageFilteringRDFService] VIVO-1931: It took us 2 millis to do so (firs pass). 2020-10-30 14:11:04,851 INFO [LanguageFilteringRDFService] VIVO-1931: second pass 0 took millis. 2020-10-30 14:11:04,851 INFO [LanguageFilteringRDFService] VIVO-1931: We are iteraing over 4001 elements. 2020-10-30 14:11:04,856 INFO [LanguageFilteringRDFService] VIVO-1931: It took us 5 millis to do so (firs pass). 2020-10-30 14:11:04,856 INFO [LanguageFilteringRDFService] VIVO-1931: second pass 0 took millis. 2020-10-30 14:11:04,856 INFO [LanguageFilteringRDFService] VIVO-1931: We are iteraing over 4001 elements. 2020-10-30 14:11:04,861 INFO [LanguageFilteringRDFService] VIVO-1931: It took us 5 millis to do so (firs pass). 2020-10-30 14:11:04,862 INFO [LanguageFilteringRDFService] VIVO-1931: second pass 1 took millis. 2020-10-30 14:11:04,862 INFO [LanguageFilteringRDFService] VIVO-1931: We are iteraing over 4001 elements. 2020-10-30 14:11:04,902 INFO [LanguageFilteringRDFService] VIVO-1931: It took us 40 millis to do so (firs pass). 2020-10-30 14:11:04,905 INFO [LanguageFilteringRDFService] VIVO-1931: second pass 3 took millis. 2020-10-30 14:11:04,905 INFO [LanguageFilteringRDFService] VIVO-1931: We are iteraing over 4001 elements. 2020-10-30 14:11:04,906 INFO [LanguageFilteringRDFService] VIVO-1931: It took us 1 millis to do so (firs pass). 2020-10-30 14:11:04,906 INFO [LanguageFilteringRDFService] VIVO-1931: second pass 0 took millis.
Where number of elements is solnList.size() and the time is the time passed between the two loops.
chenejac
commented
3 years ago Brian Lowe said:
Resolved in commit https://github.com/vivo-project/Vitro/commit/8801ad434afe5d61964ae5ec49059163016b42de
Andrew Woods (Migrated from VIVO-1931) said:
This task is to investigate the source of decreased response-time performance when rendering pages with i18n enabled, and resolve the issue. As a hint, the performance degradation may relate to the current sorting approach.
To reproduce the issue, set RDFService.languageFilter = false in runtime.properties. Start VIVO and turn on logging of all SPARQL queries on the developer panel (enabled from Site Admin page). Request a page with a large number of related individuals, such as a researcher profile with a long list of publications (preferably if those publications have multiple title rdfs:label statements with different language tags). Observe the time spent in execution the complex SPARQL queries in vivo.all.log.
Then set RDFService.languageFilter = true in runtime.properties, restart VIVO and repeat the exercise. Some, perhaps many, of the queries will show a manifold increase in execution time.
This time will be due to the involvement of edu.cornell.mannlib.vitro.webapp.rdfservice.filter.LanguageFilteringRDFService and/or LanguageFilteringGraph. The next question is how much is due to the filtering logic itself and how much might be overhead like triple serialization/reserialization, and whether either or both of these elements might be optimized without losing the fallback-to-something-if-desired-language-not-found behavior of the current language filters.