ARAX responding with 400 errors with TRAPI validation errors when valid Knowledge Graphs are included in the query
Issue: When submitting a query to ARAX that includes a message with a knowledge graph, ARAX responds with a 400 error with the following data:
{
"detail": "{...} is not valid under any of the given schemas - 'message.knowledge_graph'",
"status": 400,
"title": "Bad Request",
"type": "about:blank"
}
where the contents of {...} in the detail is the content of the knowledge graph.
However, when I run these queries through the Reasoner Validator (version 3.8.5) against TRAPI 1.4.2, the query passes validation.
Here's a sample query that will generate the error. The knowledge graph has been stripped down to a single edge and 2 nodes with minimal content. fill_e1_reduced-kg.txt
If we strip out the contents of the knowledge graph nodes and edges completely and also remove "auxiliary_graphs": null (auxiliary_graphs is nullable in the spec but ARAX also issues a warning about it being None), ARAX no longer returns TRAPI validation errors (different errors are returned, but these errors are expected).
fill_e1_no_arax_validation_error.txt
This is not a priority issue for September.
Context: The Translator Clinical Data Committee are working on developing some workflows with the Workflow Runner. In our "Path A" workflow, we want to issue a fill operation on the first edge with a specific allowlist for clinical KPs followed by a second fill operation for the remaining edges using any KP.
Does it possibly work any better if you set auxiliary_graphs to {} in your original query? This was one of the TRAPI 1.40 / 1.4.2 problems I think...
@edeutsch Thanks for the suggestion.
In the first query (fill_e1_reduced-kg.txt), changing it to "auxiliary_graphs": {} made no difference. Similarly, removing it made no difference.
In the second query (fill_e1_no_arax_validation_error.txt), adding "auxiliary_graphs": {} back in does allow it to get past the validation.
@edeutsch : Perhaps we can tag this issue as "post 2023 code freeze", just so it gets some visibility? This issue and #2075 are kind of creating blockers for the TCDC's efforts on the CQS.
Hi @karafecho , I think the issue is just that source_record_urls and auxiliary_graphs can't be none in TRAPI 1.4.0. This is the TRAPI 1.4.0 vs. 1.4.2 problem that we discovered after release and decided it wasn't worth a whole new release. If you just change:
"source_record_urls": null
to:
"source_record_urls": []
and
"auxiliary_graphs": null
to:
"auxiliary_graphs": {}
then it will work fine. Can you do that? Fixing the query will be a lot easier than fixing the code for the moment, and should allow you to proceed? Or is is that not feasible?
This does not generate errors:
{
"message": {
"query_graph": {
"nodes": {
"n0": {
"ids": [
"MONDO:0009061"
],
"categories": null,
"is_set": false,
"constraints": []
},
"n1": {
"ids": null,
"categories": [
"biolink:MolecularEntity",
"biolink:EnvironmentalExposure"
],
"is_set": true,
"constraints": []
},
"n2": {
"ids": null,
"categories": [
"biolink:Gene",
"biolink:Protein"
],
"is_set": true,
"constraints": []
}
},
"edges": {
"e0": {
"subject": "n0",
"object": "n1",
"knowledge_type": null,
"predicates": [
"biolink:correlated_with",
"biolink:associated_with_likelihood_of"
],
"attribute_constraints": [],
"qualifier_constraints": [],
"exclude": false
},
"e1": {
"subject": "n1",
"object": "n2",
"knowledge_type": null,
"predicates": [
"biolink:affects"
],
"attribute_constraints": [],
"qualifier_constraints": [
{
"qualifier_set": [
{
"qualifier_type_id": "biolink:object_direction_qualifier",
"qualifier_value": "increased"
},
{
"qualifier_type_id": "biolink:object_aspect_qualifier",
"qualifier_value": "activity_or_abundance"
},
{
"qualifier_type_id": "biolink:qualified_predicate",
"qualifier_value": "biolink:causes"
}
]
},
{
"qualifier_set": [
{
"qualifier_type_id": "biolink:object_direction_qualifier",
"qualifier_value": "increased"
},
{
"qualifier_type_id": "biolink:object_aspect_qualifier",
"qualifier_value": "expression"
},
{
"qualifier_type_id": "biolink:qualified_predicate",
"qualifier_value": "biolink:causes"
}
]
},
{
"qualifier_set": [
{
"qualifier_type_id": "biolink:object_direction_qualifier",
"qualifier_value": "increased"
},
{
"qualifier_type_id": "biolink:object_aspect_qualifier",
"qualifier_value": "secretion"
},
{
"qualifier_type_id": "biolink:qualified_predicate",
"qualifier_value": "biolink:causes"
}
]
},
{
"qualifier_set": [
{
"qualifier_type_id": "biolink:object_direction_qualifier",
"qualifier_value": "decreased"
},
{
"qualifier_type_id": "biolink:object_aspect_qualifier",
"qualifier_value": "degradation"
},
{
"qualifier_type_id": "biolink:qualified_predicate",
"qualifier_value": "biolink:causes"
}
]
}
],
"exclude": false
}
}
},
"knowledge_graph": {
"nodes": {
"MONDO:0009061": {
"categories": [
"biolink:Disease",
"biolink:DiseaseOrPhenotypicFeature"
]
},
"PUBCHEM.COMPOUND:1068": {
"categories": [
"biolink:SmallMolecule"
]
}
},
"edges": {
"090bb1f96d3c": {
"subject": "PUBCHEM.COMPOUND:1068",
"object": "MONDO:0009061",
"predicate": "biolink:biomarker_for",
"sources": [
{
"resource_id": "infores:ctd",
"resource_role": "primary_knowledge_source",
"upstream_resource_ids": [],
"source_record_urls": [
"http://ctdbase.org/detail.go?type=chem&acc=C004784&view=disease"
]
},
{
"resource_id": "infores:arax",
"resource_role": "aggregator_knowledge_source",
"upstream_resource_ids": [
"infores:molepro"
],
"source_record_urls": []
},
{
"resource_id": "infores:molepro",
"resource_role": "aggregator_knowledge_source",
"upstream_resource_ids": [
"infores:ctd"
],
"source_record_urls": []
}
]
}
}
},
"results": null,
"auxiliary_graphs": {}
},
"workflow": [
{
"id": "fill",
"parameters": {
"allowlist": [],
"qedge_keys": [
"e1"
]
}
}
]
}
I'm not sure fixing the query will work. When I ran your query, it indeed passed the TRAPI validation test, but it did not return any results. [As an aside, when I sent the query to the ARS, I received a 598 timeout error, which shouldn't be the case, but that appears to be an ARS issue that @MarkDWilliams will need to explore.]
@maximusunc explored the issue a bit. From what he reported, I think there are additional issues beyond the TRAPI validation error that are preventing the query from both passing TRAPI validation in ARAX and returning results.
That said, Max and Abrar are re-engineering the Path A CQS query that drove this issue, and so, we may be able to independently resolve it.
Will keep you posted ...
I'll add one other issue that Max identified. Specifically, I think ARAX is considering infores:automat-icees-kg as the primary endpoint for icees-kg; however, infores:automat-icees-kg is the aggregator knowledge source and infores:icees-kg is the primary knowledge source.
Just thought I'd point that out ...
Well, I was just resolving the validation errors. I don't know anything about the query itself or what is expected of it.
I'm not sure I understand about the infores. I think we would go by how it's registered in SmartAPI. So if the SmartAPI name is different than what you specify, then it probably won't work. I think you need to specify the SmartAPI key? I'm not certain.
Here's a stack trace that I get when trying to send a fill allowlist:
- From Workflow Runner: Requesting operation '{'id': <fill.fill: 'fill'>, 'parameters': {'allowlist': ['infores:cohd', 'infores:automat-icees-kg'], 'qedge_keys': ['e0']}}' from ARAX Translator Reasoner - TRAPI 1.4.0...
- From ARAX: Invalid user-specified KP(s): {'infores:automat-icees-kg'}. Valid options are: {'infores:molepro', 'infores:rtx-kg2', 'infores:text-mining-provider-cooccurrence', 'infores:spoke', 'infores:service-provider-trapi', 'infores:openpredict', 'infores:arax-normalized-google-distance', 'infores:cohd', 'infores:genetics-data-provider', 'infores:knowledge-collaboratory', 'infores:connections-hypothesis', 'infores:arax-drug-treats-disease'}
This list of KPs doesn't include any of the automat services, but they are all valid KPs. Could this be looked into please?
@amykglen would you be able to look into item 2 above?
Sorry, we did just discover a bug where the Automats on dev weren't registered on SmartAPI correctly. Could you just try refreshing your KP list please?
ah yes, I forgot about that. we reported in https://github.com/NCATSTranslator/Feedback/issues/557
Refreshing should be automatic within 10 minutes. Is it resolved now?
https://arax.ci.transltr.io/?smartapi=1
@amykglen would you be able to look into item 2 above?
Nevermind, it was likely a SmartAPI registration issue.
I'm seeing green on the ARAX page for the Automats, but I'm still getting the same error when sending a query to ARAX.
okay, thanks for checking and reporting.
@maximusunc can you remind us which endpoint you're testing against?
@amykglen would you look into this?, specifically: From ARAX: Invalid user-specified KP(s): {'infores:automat-icees-kg'}. Valid options are: {'infores:molepro', 'infores:rtx-kg2', 'infores:text-mining-provider-cooccurrence', 'infores:spoke', 'infores:service-provider-trapi', 'infores:openpredict', 'infores:arax-normalized-google-distance', 'infores:cohd', 'infores:genetics-data-provider', 'infores:knowledge-collaboratory', 'infores:connections-hypothesis', 'infores:arax-drug-treats-disease'}
We're hitting your dev instance: https://arax.ncats.io/beta/api/arax/v1.4/query
yep, I'll look into it @edeutsch!
@maximusunc - can you provide an example query that produces the issue you're seeing? that would be super helpful. (I've tried running some of the queries linked earlier in this issue, but none are producing the issue you're reporting)
Sure:
{
"workflow": [
{
"id": "fill",
"parameters": {
"allowlist": [
"infores:cohd",
"infores:automat-icees-kg"
],
"qedge_keys": [
"e0"
]
}
}
],
"message": {
"query_graph": {
"edges": {
"e0": {
"exclude": false,
"predicates": [
"biolink:correlated_with",
"biolink:associated_with_likelihood_of"
],
"subject": "n0",
"object": "n1"
}
},
"nodes": {
"n0": {
"ids": [
"MONDO:0009061"
],
"is_set": false
},
"n1": {
"categories": [
"biolink:MolecularEntity",
"biolink:EnvironmentalExposure"
],
"is_set": true
}
}
}
},
"log_level": "DEBUG"
}
thanks @maximusunc!
well, that query just completed successfully for me (https://arax.ncats.io/beta/?r=172033), but it appears that it might only have worked this time because it happened to trigger a cache refresh on our end:
2023-09-29T23:48:28.321841 INFO: KP info cache(s) have not been updated for 24+ hours. Refreshing stale cache(s).
I thought the ARAX background tasker was supposed to update the KP info cache on something like an hourly basis, so I'm not sure why it was so out of date (this is on /beta)... suggests there's a bug with either the background tasker or the KP info cacher...
Yes, it's possible there is a bug. The Background Tasker and the kp_info_cacher.py were substantially changed in the issue-2114 branch (recently merged to master).
One thing to check is that the Background Tasker process is currently running, for /beta?
yeah, apparently not:
grep Tasker /tmp/RTX_OpenAPI_beta.elog
...
2023-09-27T14:34:51.057912: INFO: ARAXBackgroundTasker status: waiting. Current load is (0.16, 0.4, 0.4), n_clients=0, n_ongoing_queries=0
2023-09-27T14:35:51.239649: INFO: ARAXBackgroundTasker status: waiting. Current load is (0.45, 0.46, 0.43), n_clients=0, n_ongoing_queries=0
2023-09-27T14:36:51.462935: INFO: ARAXBackgroundTasker status: waiting. Current load is (0.16, 0.38, 0.4), n_clients=0, n_ongoing_queries=0
2023-09-27T14:37:51.704246: INFO: ARAXBackgroundTasker status: waiting. Current load is (0.3, 0.39, 0.4), n_clients=0, n_ongoing_queries=0
2023-09-27T14:38:51.942820: INFO: ARAXBackgroundTasker status: waiting. Current load is (0.5, 0.41, 0.41), n_clients=0, n_ongoing_queries=0
Died on the 27th
Is that about when we did the merge to master?
I wonder if we should stop and restart /beta
restarting /beta now
I'm looking through the elog file to look for clues. Will you save that first?
Shoot, just restarted, sorry.
My bad, Eric; I should have thought to save a copy of the elog file.
Eric if you still have it open in less you can probably save it to a new file by hitting the s key
Here's what I see in the elog:
2023-09-27T14:37:51.704246: INFO: ARAXBackgroundTasker status: waiting. Current load is (0.3, 0.39, 0.4), n_clients=0, n_ongoing_queries=0
2023-09-27T14:38:51.942820: INFO: ARAXBackgroundTasker status: waiting. Current load is (0.5, 0.41, 0.41), n_clients=0, n_ongoing_queries=0
INFO:werkzeug:127.0.0.1 - - [27/Sep/2023 14:39:07] "GET /beta/api/arax/v1.4/response/2b3177ad-64ab-4c90-a16e-a0c0082421bc HTTP/1.1" 200 -
INFO:reasoner_validator.biolink:Resolved Biolink Model Version: '3.5.4'
INFO:reasoner_validator.trapi:TRAPISchemaValidator set to TRAPI Version: 'v1.4.2'
INFO: Launching validator via multiprocessing
INFO:reasoner_validator.biolink:Resolved Biolink Model Version: '3.5.4'
INFO:reasoner_validator.trapi:TRAPISchemaValidator set to TRAPI Version: 'v1.4.2'
INFO: Launching validator via multiprocessing
WARNING: tried to convert the response to JSON and it did not work
It was: {'level': 'INFO', 'message': 'ARS info: <!DOCTYPE html><html><head><meta charSet="utf-8"/><meta name="viewport" content="width=device-width"/><title>4
04: This page could not be found</title><meta name="next-head-count" content="3"/><noscript data-n-css=""></noscript><script defer="" nomodule="" s
rc="/_next/static/chunks/polyfills-c67a75d1b6f99dc8.js"></script><script src="/_next/static/chunks/webpack-3864d442a525cf32.js" defer=""></script><script src="/_next
/static/chunks/framework-8883d1e9be70c3da.js" defer=""></script><script src="/_next/static/chunks/main-d1cb916d1fed4c3b.js" defer=""></script><script src="/_nex
t/static/chunks/pages/_app-b555d5e1eab47959.js" defer=""></script><script src="/_next/static/chunks/pages/_error-d79168f986538ac0.js" defer=""></script><script src=&
quot;/_next/static/jUzYuJn7pMobhm-zdAIud/_buildManifest.js" defer=""></script><script src="/_next/static/jUzYuJn7pMobhm-zdAIud/_ssgManifest.js" defer=""></script></h
ead><body><div id="__next"><div style="font-family:system-ui,&quot;Segoe UI&quot;,Roboto,Helvetica,Arial,sans-serif,&quot;Apple Color Emoji&quot;,&quot;Segoe UI Emoji&
quot;;height:100vh;text-align:center;display:flex;flex-direction:column;align-items:center;justify-content:center"><div><style>body{color:#000;background:#fff;margin:0}.next-error-h1{border-right:1px soli
d rgba(0,0,0,.3)}@media (prefers-color-scheme:dark){body{color:#fff;background:#000}.next-error-h1{border-right:1px solid rgba(255,255,255,.3)}}</style><h1 class="next-error-h1" style="display:inline-
block;margin:0 20px 0 0;padding-right:23px;font-size:24px;font-weight:500;vertical-align:top;line-height:49px">404</h1><div style="display:inline-block;text-align:left"><h2 style="font-s
ize:14px;font-weight:400;line-height:49px;margin:0">This page could not be found<!-- -->.</h2></div></div></div></div><script id="__NEXT_DATA__" type="application
/json">{"props":{"pageProps":{"statusCode":404}},"page":"/_error","query":{},"buildId":"jUzYuJn7pMobhm-zdAIud","nextExport":tr
ue,"isFallback":false,"gip":true,"scriptLoader":[]}</script></body></html>'}
INFO:werkzeug:127.0.0.1 - - [27/Sep/2023 14:39:10] "GET /beta/api/arax/v1.4/response/6cf20dc2-2639-4031-ac36-521775e2afb7 HTTP/1.1" 200 -
INFO:root:Importing linkml:types as /mnt/data/python/Python-3.9.16/lib/python3.9/site-packages/linkml_runtime/linkml_model/model/schema/types from source https://raw.githubusercontent.com/biolink/biolink-model/v3.5.4/biolink
-model.yaml; base_dir=None
INFO:reasoner_validator.biolink:Resolved Biolink Model Version: '3.5.4'
INFO:reasoner_validator.trapi:TRAPISchemaValidator set to TRAPI Version: 'v1.4.2'
INFO:werkzeug:127.0.0.1 - - [27/Sep/2023 14:39:10] "GET /beta/api/arax/v1.4/response/b10650e7-91ad-402c-a7c3-ee8fd330edfd HTTP/1.1" 200 -
INFO:reasoner_validator.biolink:Resolved Biolink Model Version: '3.5.4'
INFO:reasoner_validator.trapi:TRAPISchemaValidator set to TRAPI Version: 'v1.4.2'
INFO: Launching validator via multiprocessing
INFO:werkzeug:127.0.0.1 - - [27/Sep/2023 14:39:11] "GET /beta/api/arax/v1.4/response/627fd9eb-732a-4c0f-912b-cfe5e8611f00 HTTP/1.1" 200 -
INFO: Launching validator via multiprocessing
INFO:root:Importing linkml:types as /mnt/data/python/Python-3.9.16/lib/python3.9/site-packages/linkml_runtime/linkml_model/model/schema/types from source https://raw.githubusercontent.com/biolink/biolink-model/v3.5.4/biolink
-model.yaml; base_dir=None
INFO:root:Importing linkml:types as /mnt/data/python/Python-3.9.16/lib/python3.9/site-packages/linkml_runtime/linkml_model/model/schema/types from source https://raw.githubusercontent.com/biolink/biolink-model/v3.5.4/biolink
-model.yaml; base_dir=None
INFO:reasoner_validator.biolink:Resolved Biolink Model Version: '3.5.4'
INFO:reasoner_validator.trapi:TRAPISchemaValidator set to TRAPI Version: 'v1.4.2'
INFO: Launching validator via multiprocessing
INFO:werkzeug:127.0.0.1 - - [27/Sep/2023 14:39:12] "GET /beta/api/arax/v1.4/response/af00ded4-a88e-4813-ac73-ae76276cab64 HTTP/1.1" 200 -
WARNING: tried to convert the response to JSON and it did not work
It was: {'level': 'INFO', 'message': 'ARS info: <html>\n <head>\n <title>Internal Server Error</title>\n </head>\n <body>\n <h1><p>Internal Server Error</p></
h1>\n \n </body>\n</html>\n'}
INFO:werkzeug:127.0.0.1 - - [27/Sep/2023 14:39:12] "GET /beta/api/arax/v1.4/response/bbe08b74-b079-4916-b429-ac9d79768fff HTTP/1.1" 200 -
INFO:werkzeug:127.0.0.1 - - [27/Sep/2023 14:39:13] "GET /beta/api/arax/v1.4/response/f5ee6748-1a97-432a-98b6-ed173940abb4 HTTP/1.1" 200 -
INFO:root:Importing linkml:types as /mnt/data/python/Python-3.9.16/lib/python3.9/site-packages/linkml_runtime/linkml_model/model/schema/types from source https://raw.githubusercontent.com/biolink/biolink-model/v3.5.4/biolink
-model.yaml; base_dir=None
INFO:werkzeug:127.0.0.1 - - [27/Sep/2023 14:39:14] "GET /beta/api/arax/v1.4/response/4b874670-a355-4871-a21a-194f5cd5dde5 HTTP/1.1" 200 -
INFO:werkzeug:127.0.0.1 - - [27/Sep/2023 14:39:14] "GET /beta/api/arax/v1.4/response/2a0685a0-7230-4cfa-b9fb-1f83cd494850 HTTP/1.1" 200 -
INFO:reasoner_validator.biolink:Resolved Biolink Model Version: '3.5.4'
INFO:reasoner_validator.trapi:TRAPISchemaValidator set to TRAPI Version: 'v1.4.2'
INFO: Launching validator via multiprocessing
INFO:werkzeug:127.0.0.1 - - [27/Sep/2023 14:39:16] "GET /beta/api/arax/v1.4/response/738623d0-91fc-49cc-95b3-13fb28697f24 HTTP/1.1" 200 -
INFO:root:Importing linkml:types as /mnt/data/python/Python-3.9.16/lib/python3.9/site-packages/linkml_runtime/linkml_model/model/schema/types from source https://raw.githubusercontent.com/biolink/biolink-model/v3.5.4/biolink
-model.yaml; base_dir=None
INFO:werkzeug:127.0.0.1 - - [27/Sep/2023 14:39:16] "GET /beta/api/arax/v1.4/response/efa2f249-4e25-4794-8f63-ffb32cf12930 HTTP/1.1" 200 -
INFO:werkzeug:127.0.0.1 - - [27/Sep/2023 14:39:16] "GET /beta/api/arax/v1.4/response/b3a2e253-d1eb-46fc-a2a8-2ed22791270e HTTP/1.1" 200 -
INFO:werkzeug:127.0.0.1 - - [27/Sep/2023 14:39:16] "GET /beta/api/arax/v1.4/response/35c870e2-c7b2-4913-a642-5b4b6b0c8e77 HTTP/1.1" 200 -
INFO:werkzeug:127.0.0.1 - - [27/Sep/2023 14:39:18] "GET /beta/api/arax/v1.4/response/593a2193-a513-43fd-92cf-23c0c6b30f66 HTTP/1.1" 200 -
WARNING:bmt.toolkit:no biolink class found for the given curie: metatype:Datetime, try get_element_by_mapping?
WARNING:bmt.toolkit:no biolink class found for the given curie: bts:sentence, try get_element_by_mapping?
INFO:werkzeug:127.0.0.1 - - [27/Sep/2023 14:39:33] "GET /beta/api/arax/v1.4/response/c5a226ff-a5c8-4396-8686-81d92ca062ce HTTP/1.1" 200 -
INFO:werkzeug:127.0.0.1 - - [27/Sep/2023 14:41:20] "HEAD /beta/api/arax/v1.4/entity?q=ibuprofen HTTP/1.1" 200 -
INFO:reasoner_validator.biolink:Resolved Biolink Model Version: '3.5.4'
INFO:reasoner_validator.trapi:TRAPISchemaValidator set to TRAPI Version: 'v1.4.2'
INFO: Launching validator via multiprocessing
INFO:root:Importing linkml:types as /mnt/data/python/Python-3.9.16/lib/python3.9/site-packages/linkml_runtime/linkml_model/model/schema/types from source https://raw.githubusercontent.com/biolink/biolink-model/v3.5.4/biolink
-model.yaml; base_dir=None
WARNING:bmt.toolkit:no biolink class found for the given curie: metatype:Datetime, try get_element_by_mapping?
WARNING:bmt.toolkit:no biolink class found for the given curie: bts:sentence, try get_element_by_mapping?
INFO:werkzeug:127.0.0.1 - - [27/Sep/2023 14:44:23] "GET /beta/api/arax/v1.4/response/c5a226ff-a5c8-4396-8686-81d92ca062ce HTTP/1.1" 200 -
INFO:werkzeug:127.0.0.1 - - [27/Sep/2023 14:46:06] "GET /beta/api/arax/v1.4/response/17cbecc1-4c30-46db-9499-1cc1c1b50df5 HTTP/1.1" 200 -
The next ping from the BackgroundTasker should have been at 14:39:51, but it was not heard from again.
Eric I note that the call to query_tracker.check_ongoing_queries() is not in a try block. Maybe something threw an exception and the child process died?