ncbo / bioportal-project

Serves to consolidate (in Zenhub) all public issues in BioPortal
BSD 2-Clause "Simplified" License
7 stars 5 forks source link

ZONMV-ADMIN-MD parsing issue #188

Closed graybeal closed 3 years ago

graybeal commented 3 years ago

After relative minor changes (added a bunch of terms, but following an existing template), ZONMV-ADMIN-MD submission 5 failed to complete processing. This was the error log.

# Logfile created on 2020-10-30 00:09:55 -0700 by logger.rb/v1.4.2
I, [2020-10-30T00:09:55.707720 #3699]  INFO -- : ["Starting to process http://data.bioontology.org/ontologies/ZONMW-ADMIN-MD/submissions/5"]
I, [2020-10-30T00:09:55.751120 #3699]  INFO -- : ["Starting to process ZONMW-ADMIN-MD/submissions/5"]
I, [2020-10-30T00:09:55.978693 #3699]  INFO -- : ["Java call [java -DentityExpansionLimit=2500000 -Xmx10240M -jar /srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/bundler/gems/ontologies_linked_data-0a7001683cb0/bin/owlapi-wrapper-1.3.6.jar -m /srv/ncbo/repository/ZONMW-ADMIN-MD/5/FDCCOVIDProjectAdminVocabularies.ttl -o /srv/ncbo/repository/ZONMW-ADMIN-MD/5 -r true]"]
I, [2020-10-30T00:09:57.680495 #3699]  INFO -- : ["2020-10-30T00:09:56 [main] INFO  o.s.n.o.OntologyParserCommand - Parsing invocation with values: ParserInvocation [inputRepositoryFolder=null, outputRepositoryFolder=/srv/ncbo/repository/ZONMW-ADMIN-MD/5, masterFileName=/srv/ncbo/repository/ZONMW-ADMIN-MD/5/FDCCOVIDProjectAdminVocabularies.ttl, invocationId=0, parserLog=, userReasoner= true]\n\n2020-10-30T00:09:56 [main] INFO  o.s.ncbo.oapiwrapper.OntologyParser - executor ...\n\n2020-10-30T00:09:56 [main] INFO  o.s.ncbo.oapiwrapper.OntologyParser - Input repository folder is null. Unique file being parsed.\n\n2020-10-30T00:09:56 [main] DEBUG o.e.rdf4j.rio.RDFParserRegistry - Registered service class org.eclipse.rdf4j.rio.binary.BinaryRDFParserFactory\n\n2020-10-30T00:09:56 [main] DEBUG o.e.rdf4j.rio.RDFParserRegistry - Registered service class org.eclipse.rdf4j.rio.n3.N3ParserFactory\n\n2020-10-30T00:09:56 [main] DEBUG o.e.rdf4j.rio.RDFParserRegistry - Registered service class org.eclipse.rdf4j.rio.nquads.NQuadsParserFactory\n\n2020-10-30T00:09:56 [main] DEBUG o.e.rdf4j.rio.RDFParserRegistry - Registered service class org.eclipse.rdf4j.rio.ntriples.NTriplesParserFactory\n\n2020-10-30T00:09:56 [main] DEBUG o.e.rdf4j.rio.RDFParserRegistry - Registered service class org.eclipse.rdf4j.rio.rdfjson.RDFJSONParserFactory\n\n2020-10-30T00:09:56 [main] DEBUG o.e.rdf4j.rio.RDFParserRegistry - Registered service class org.eclipse.rdf4j.rio.jsonld.JSONLDParserFactory\n\n2020-10-30T00:09:56 [main] DEBUG o.e.rdf4j.rio.RDFParserRegistry - Registered service class org.eclipse.rdf4j.rio.rdfxml.RDFXMLParserFactory\n\n2020-10-30T00:09:56 [main] DEBUG o.e.rdf4j.rio.RDFParserRegistry - Registered service class org.eclipse.rdf4j.rio.trix.TriXParserFactory\n\n2020-10-30T00:09:56 [main] DEBUG o.e.rdf4j.rio.RDFParserRegistry - Registered service class org.eclipse.rdf4j.rio.turtle.TurtleParserFactory\n\n2020-10-30T00:09:56 [main] DEBUG o.e.rdf4j.rio.RDFParserRegistry - Registered service class org.eclipse.rdf4j.rio.trig.TriGParserFactory\n\n2020-10-30T00:09:56 [main] DEBUG o.e.r.rio.DatatypeHandlerRegistry - Registered service class org.eclipse.rdf4j.rio.datatypes.XMLSchemaDatatypeHandler\n\n2020-10-30T00:09:56 [main] DEBUG o.e.r.rio.DatatypeHandlerRegistry - Registered service class org.eclipse.rdf4j.rio.datatypes.RDFDatatypeHandler\n\n2020-10-30T00:09:56 [main] DEBUG o.e.r.rio.DatatypeHandlerRegistry - Registered service class org.eclipse.rdf4j.rio.datatypes.DBPediaDatatypeHandler\n\n2020-10-30T00:09:56 [main] DEBUG o.e.r.rio.DatatypeHandlerRegistry - Registered service class org.eclipse.rdf4j.rio.datatypes.VirtuosoGeometryDatatypeHandler\n\n2020-10-30T00:09:56 [main] DEBUG o.e.r.rio.DatatypeHandlerRegistry - Registered service class org.eclipse.rdf4j.rio.datatypes.GeoSPARQLDatatypeHandler\n\n2020-10-30T00:09:56 [main] DEBUG o.e.r.rio.LanguageHandlerRegistry - Registered service class org.eclipse.rdf4j.rio.languages.RFC3066LanguageHandler\n\n2020-10-30T00:09:56 [main] DEBUG o.e.r.rio.LanguageHandlerRegistry - Registered service class org.eclipse.rdf4j.rio.languages.BCP47LanguageHandler\n\n2020-10-30T00:09:57 [main] INFO  o.s.ncbo.oapiwrapper.OntologyMetrics - Calculating metrics for /srv/ncbo/repository/ZONMW-ADMIN-MD/5/FDCCOVIDProjectAdminVocabularies.ttl\n\n2020-10-30T00:09:57 [main] INFO  o.s.ncbo.oapiwrapper.OntologyMetrics - Finished metrics calculation for /srv/ncbo/repository/ZONMW-ADMIN-MD/5/FDCCOVIDProjectAdminVocabularies.ttl in 1 milliseconds\n\n2020-10-30T00:09:57 [main] INFO  o.s.ncbo.oapiwrapper.OntologyMetrics - Generated metrics CSV file for /srv/ncbo/repository/ZONMW-ADMIN-MD/5/FDCCOVIDProjectAdminVocabularies.ttl\n\n2020-10-30T00:09:57 [main] INFO  o.s.ncbo.oapiwrapper.OntologyParser - Ontology document format: org.semanticweb.owlapi.formats.TurtleDocumentFormat\n\n2020-10-30T00:09:57 [main] INFO  o.s.ncbo.oapiwrapper.OntologyParser - isPrefixOWLOntologyFormat: true\n\n2020-10-30T00:09:57 [main] INFO  o.s.ncbo.oapiwrapper.OntologyParser - isOBO: false\n\n2020-10-30T00:09:57 [main] INFO  o.s.ncbo.oapiwrapper.OntologyParser - Serializing ontology in RDF ...\n\n2020-10-30T00:09:57 [main] INFO  o.s.ncbo.oapiwrapper.OntologyParser - Serialization done!\n\n2020-10-30T00:09:57 [main] INFO  o.s.n.o.OntologyParserCommand - Parse result: true\n\n2020-10-30T00:09:57 [main] INFO  o.s.n.o.OntologyParserCommand - Output triples in: {}/srv/ncbo/repository/ZONMW-ADMIN-MD/5/owlapi.xrdf\n\n2020-10-30T00:09:57 [main] INFO  o.s.n.o.OntologyParserCommand - Finished parsing!\n"]
I, [2020-10-30T00:09:57.680625 #3699]  INFO -- : ["OWLAPI Java command: parsing finished successfully."]
I, [2020-10-30T00:09:57.680793 #3699]  INFO -- : ["Output size 179152 in `/srv/ncbo/repository/ZONMW-ADMIN-MD/5/owlapi.xrdf`"]
E, [2020-10-30T00:09:57.873848 #3699] ERROR -- : ["RestClient::BadRequest: 400 Bad Request\n/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/rest-client-2.1.0/lib/restclient/abstract_response.rb:249:in `exception_with_response'\n\t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/rest-client-2.1.0/lib/restclient/abstract_response.rb:129:in `return!'\n\t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/rest-client-2.1.0/lib/restclient/request.rb:836:in `process_result'\n\t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/rest-client-2.1.0/lib/restclient/request.rb:743:in `block in transmit'\n\t/usr/local/rbenv/versions/2.6.6/lib/ruby/2.6.0/net/http.rb:920:in `start'\n\t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/rest-client-2.1.0/lib/restclient/request.rb:727:in `transmit'\n\t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/rest-client-2.1.0/lib/restclient/request.rb:163:in `execute'\n\t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/rest-client-2.1.0/lib/restclient/request.rb:63:in `execute'\n\t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/bundler/gems/goo-ac4b87e33337/lib/goo/sparql/client.rb:108:in `append_triples_no_bnodes'\n\t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/bundler/gems/goo-ac4b87e33337/lib/goo/sparql/client.rb:133:in `put_triples'\n\t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/bundler/gems/ontologies_linked_data-0a7001683cb0/lib/ontologies_linked_data/models/ontology_submission.rb:1536:in `delete_and_append'\n\t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/bundler/gems/ontologies_linked_data-0a7001683cb0/lib/ontologies_linked_data/models/ontology_submission.rb:475:in `generate_rdf'\n\t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/bundler/gems/ontologies_linked_data-0a7001683cb0/lib/ontologies_linked_data/models/ontology_submission.rb:973:in `process_submission'\n\t/srv/ncbo/ncbo_cron/lib/ncbo_cron/ontology_submission_parser.rb:177:in `process_submission'\n\t/srv/ncbo/ncbo_cron/lib/ncbo_cron/ontology_submission_parser.rb:47:in `block in process_queue_submissions'\n\t/srv/ncbo/ncbo_cron/lib/ncbo_cron/ontology_submission_parser.rb:41:in `each'\n\t/srv/ncbo/ncbo_cron/lib/ncbo_cron/ontology_submission_parser.rb:41:in `process_queue_submissions'\n\t/srv/ncbo/ncbo_cron/bin/ncbo_cron:246:in `block (3 levels) in <main>'\n\t/srv/ncbo/ncbo_cron/lib/ncbo_cron/scheduler.rb:65:in `block (3 levels) in scheduled_locking_job'\n\t/srv/ncbo/ncbo_cron/lib/ncbo_cron/scheduler.rb:51:in `fork'\n\t/srv/ncbo/ncbo_cron/lib/ncbo_cron/scheduler.rb:51:in `block (2 levels) in scheduled_locking_job'\n\t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/mlanett-redis-lock-0.2.7/lib/redis-lock.rb:43:in `lock'\n\t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/mlanett-redis-lock-0.2.7/lib/redis-lock.rb:234:in `lock'\n\t/srv/ncbo/ncbo_cron/lib/ncbo_cron/scheduler.rb:50:in `block in scheduled_locking_job'\n\t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/rufus-scheduler-2.0.24/lib/rufus/sc/jobs.rb:230:in `trigger_block'\n\t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/rufus-scheduler-2.0.24/lib/rufus/sc/jobs.rb:204:in `block in trigger'\n\t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/rufus-scheduler-2.0.24/lib/rufus/sc/scheduler.rb:430:in `block in trigger_job'"]
graybeal commented 3 years ago

Better formatted:

E, [2020-10-30T00:09:57.873848 #3699] ERROR -- : ["RestClient::BadRequest: 400 Bad Request /srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/rest-client-2.1.0/lib/restclient/abstract_response.rb:249:in exception_with_response' \t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/rest-client-2.1.0/lib/restclient/abstract_response.rb:129:inreturn!' \t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/rest-client-2.1.0/lib/restclient/request.rb:836:in process_result' \t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/rest-client-2.1.0/lib/restclient/request.rb:743:inblock in transmit' \t/usr/local/rbenv/versions/2.6.6/lib/ruby/2.6.0/net/http.rb:920:in start' \t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/rest-client-2.1.0/lib/restclient/request.rb:727:intransmit' \t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/rest-client-2.1.0/lib/restclient/request.rb:163:in execute' \t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/rest-client-2.1.0/lib/restclient/request.rb:63:inexecute' \t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/bundler/gems/goo-ac4b87e33337/lib/goo/sparql/client.rb:108:in append_triples_no_bnodes' \t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/bundler/gems/goo-ac4b87e33337/lib/goo/sparql/client.rb:133:input_triples' \t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/bundler/gems/ontologies_linked_data-0a7001683cb0/lib/ontologies_linked_data/models/ontology_submission.rb:1536:in delete_and_append' \t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/bundler/gems/ontologies_linked_data-0a7001683cb0/lib/ontologies_linked_data/models/ontology_submission.rb:475:ingenerate_rdf' \t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/bundler/gems/ontologies_linked_data-0a7001683cb0/lib/ontologies_linked_data/models/ontology_submission.rb:973:in process_submission' \t/srv/ncbo/ncbo_cron/lib/ncbo_cron/ontology_submission_parser.rb:177:inprocess_submission' \t/srv/ncbo/ncbo_cron/lib/ncbo_cron/ontology_submission_parser.rb:47:in block in process_queue_submissions' \t/srv/ncbo/ncbo_cron/lib/ncbo_cron/ontology_submission_parser.rb:41:ineach' \t/srv/ncbo/ncbo_cron/lib/ncbo_cron/ontology_submission_parser.rb:41:in process_queue_submissions' \t/srv/ncbo/ncbo_cron/bin/ncbo_cron:246:inblock (3 levels) in

' \t/srv/ncbo/ncbo_cron/lib/ncbo_cron/scheduler.rb:65:in block (3 levels) in scheduled_locking_job' \t/srv/ncbo/ncbo_cron/lib/ncbo_cron/scheduler.rb:51:infork' \t/srv/ncbo/ncbo_cron/lib/ncbo_cron/scheduler.rb:51:in block (2 levels) in scheduled_locking_job' \t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/mlanett-redis-lock-0.2.7/lib/redis-lock.rb:43:inlock' \t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/mlanett-redis-lock-0.2.7/lib/redis-lock.rb:234:in lock' \t/srv/ncbo/ncbo_cron/lib/ncbo_cron/scheduler.rb:50:inblock in scheduled_locking_job' \t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/rufus-scheduler-2.0.24/lib/rufus/sc/jobs.rb:230:in trigger_block' \t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/rufus-scheduler-2.0.24/lib/rufus/sc/jobs.rb:204:inblock in trigger' \t/srv/ncbo/ncbo_cron/vendor/bundle/ruby/2.6.0/gems/rufus-scheduler-2.0.24/lib/rufus/sc/scheduler.rb:430:in `block in trigger_job'"]

graybeal commented 3 years ago

I re-ran processing and got exactly the same thing.

The ontology opens fine in Protege, with the expected number of concepts.

graybeal commented 3 years ago

oh geez, I found a mistake in a TopConcept. Testing now...

graybeal commented 3 years ago

This was fixed by fixing my input.