RTXteam / RTX

Software repo for Team Expander Agent (Oregon State U., Institute for Systems Biology, and Penn State U.)
https://arax.ncats.io/
MIT License
33 stars 21 forks source link

treats patch test failing on arax.ncats.io #2385

Closed edeutsch closed 1 month ago

edeutsch commented 1 month ago

Seeing this test failing:

FAILED test_ARAX_expand.py::test_treats_patch_issue_2328 - AssertionError: assert 'biolink:applied_to_treat' == 'biolink:treats'

Can someone familiar with this test repro/evaluate/fix?

amykglen commented 1 month ago

looking into it - so is this just on /beta or the like? (not prod)

edeutsch commented 1 month ago

yes, sorry, this is failing for master code. It did not test production branch. It's also possible I did something wrong on arax.ncats.io

amykglen commented 1 month ago

very odd - I'm not able to reproduce this in master when running locally...

edeutsch commented 1 month ago

After fixing the cause of the problem in #2384, this continues to be a problem. this is the only (fast) test failing on arax.ncats.io master

amykglen commented 1 month ago

ok thanks, I'll figure it out

amykglen commented 1 month ago

actually, since I can't get into arax.ncats.io at the moment (reported to ITRB), would you be able to paste the ARAX log for that test here?

amykglen commented 1 month ago

(my best guess is that maybe the background tasker died and ARAX is using the wrong KG2 URL? the logs will show which KG2 URL it's using..)

edeutsch commented 1 month ago

here it is:

rt@4342e0c91621:/mnt/data/orangeboard/test/RTX/code/ARAX/test$ pytest -v test_ARAX_expand.py -k test_treats_patch_issue_2328
Running database manager to check for missing databases..
Downloading any missing databases from arax-databases.rtx.ai to /mnt/data/orangeboard/databases
On database cohd_database in _download_to_mnt()
  Database already exists, no need to download
On database curie_to_pmids in _download_to_mnt()
  Database already exists, no need to download
On database curie_ngd in _download_to_mnt()
  Database already exists, no need to download
On database node_synonymizer in _download_to_mnt()
  Database already exists, no need to download
On database kg2c_sqlite in _download_to_mnt()
  Database already exists, no need to download
On database kg2c_meta_kg in _download_to_mnt()
  Database already exists, no need to download
On database fda_approved_drugs in _download_to_mnt()
  Database already exists, no need to download
On database autocomplete in _download_to_mnt()
  Database already exists, no need to download
On database explainable_dtd_db in _download_to_mnt()
  Database already exists, no need to download
On database xcrg_embeddings in _download_to_mnt()
  Database already exists, no need to download
On database xcrg_increase_model in _download_to_mnt()
  Database already exists, no need to download
On database xcrg_decrease_model in _download_to_mnt()
  Database already exists, no need to download
Local version of cohd_database (/mnt/data/orangeboard/test/RTX/code/ARAX/KnowledgeSources/COHD_local/data/COHDdatabase_v1.0_KG2.8.0.db) matches the remote version, skipping...
Local version of curie_to_pmids (/mnt/data/orangeboard/test/RTX/code/ARAX/KnowledgeSources/NormalizedGoogleDistance/curie_to_pmids_v1.0_KG2.10.0.sqlite) matches the remote version, skipping...
Local version of curie_ngd (/mnt/data/orangeboard/test/RTX/code/ARAX/KnowledgeSources/NormalizedGoogleDistance/curie_ngd_v1.0_KG2.10.0.sqlite) matches the remote version, skipping...
Local version of node_synonymizer (/mnt/data/orangeboard/test/RTX/code/ARAX/NodeSynonymizer/node_synonymizer_v1.0_KG2.10.0.sqlite) matches the remote version, skipping...
Local version of kg2c_sqlite (/mnt/data/orangeboard/test/RTX/code/ARAX/KnowledgeSources/KG2c/kg2c_v1.0_KG2.10.0.sqlite) matches the remote version, skipping...
Local version of kg2c_meta_kg (/mnt/data/orangeboard/test/RTX/code/ARAX/KnowledgeSources/meta_kg_v1.0_KG2.10.0c.json) matches the remote version, skipping...
Local version of fda_approved_drugs (/mnt/data/orangeboard/test/RTX/code/ARAX/KnowledgeSources/fda_approved_drugs_v1.0_KG2.10.0c.pickle) matches the remote version, skipping...
Local version of autocomplete (/mnt/data/orangeboard/test/RTX/code/autocomplete/autocomplete_v1.0_KG2.10.0.sqlite) matches the remote version, skipping...
Local version of explainable_dtd_db (/mnt/data/orangeboard/test/RTX/code/ARAX/KnowledgeSources/Prediction/ExplainableDTD_v1.0_KG2.10.0.db) matches the remote version, skipping...
Local version of xcrg_embeddings (/mnt/data/orangeboard/test/RTX/code/ARAX/ARAXQuery/Infer/data/xCRG_data/chemical_gene_embeddings_v1.0.KG2.10.0.npz) matches the remote version, skipping...
Local version of xcrg_increase_model (/mnt/data/orangeboard/test/RTX/code/ARAX/ARAXQuery/Infer/data/xCRG_data/xcrg_increase_model_v1.0.KG2.10.0.pt) matches the remote version, skipping...
Local version of xcrg_decrease_model (/mnt/data/orangeboard/test/RTX/code/ARAX/ARAXQuery/Infer/data/xCRG_data/xcrg_decrease_model_v1.0.KG2.10.0.pt) matches the remote version, skipping...
KP info cache is up to date.
======================================================================================== test session starts ========================================================================================
platform linux -- Python 3.9.18, pytest-7.2.2, pluggy-1.4.0 -- /mnt/data/python/Python-3.9.18/bin/python3.9
cachedir: .pytest_cache
rootdir: /mnt/data/orangeboard/test/RTX/code/ARAX/test
plugins: cov-4.1.0, anyio-4.4.0
collected 72 items / 71 deselected / 1 selected                                                                                                                                                     

test_ARAX_expand.py::test_treats_patch_issue_2328 FAILED                                                                                                                                      [100%]

============================================================================================= FAILURES ==============================================================================================
___________________________________________________________________________________ test_treats_patch_issue_2328 ____________________________________________________________________________________

    def test_treats_patch_issue_2328():
        query = {
            "nodes": {
                "disease": {
                    "ids": ["MONDO:0015564"]
                },
                "chemical": {
                    "categories": ["biolink:ChemicalEntity"]
                }
            },
            "edges": {
                "t_edge": {
                    "object": "disease",
                    "subject": "chemical",
                    "predicates": ["biolink:treats"],
                    "knowledge_type": "inferred",
                    "attribute_constraints": [
                        {
                            "id": "knowledge_source",
                            "name": "knowledge source",
                            "value": ["infores:rtx-kg2"],
                            "operator": "=="
                        }
                    ]
                }
            }
        }
        nodes_by_qg_id, edges_by_qg_id = _run_query_and_do_standard_testing(json_query=query)
        assert edges_by_qg_id["t_edge"]
        kg2_edges_treats = [edge for edge in edges_by_qg_id["t_edge"].values()
                            if any(source.resource_id == "infores:rtx-kg2" for source in edge.sources)]
        print(f"Answer includes {len(kg2_edges_treats)} edges from KG2")
        assert kg2_edges_treats
        print(kg2_edges_treats)
        for edge in kg2_edges_treats:
>           assert edge.predicate == "biolink:treats"
E           AssertionError: assert 'biolink:applied_to_treat' == 'biolink:treats'
E             - biolink:treats
E             + biolink:applied_to_treat

test_ARAX_expand.py:1542: AssertionError
--------------------------------------------------------------------------------------- Captured stdout call ----------------------------------------------------------------------------------------
2024-09-25 20:45:31  [INFO]  Connecting to database
Connecting to database
Disconnecting from database
DEBUG: Datetime now is: 2024-09-25 20:45:43.964563
DEBUG: Cutover date is: 2024-02-16 22:50:00
DEBUG: Since we're after the cutover date, use new us-east-1 S3 bucket arax-response-storage-2
Answer includes 2 edges from KG2
[{'attributes': [{'attribute_source': 'infores:rtx-kg2',
                 'attribute_type_id': 'biolink:agent_type',
                 'attributes': None,
                 'description': None,
                 'original_attribute_name': None,
                 'value': 'manual_agent',
                 'value_type_id': None,
                 'value_url': None},
                {'attribute_source': None,
                 'attribute_type_id': 'biolink:original_predicate',
                 'attributes': None,
                 'description': 'The IDs of the original RTX-KG2pre edge(s) '
                                'corresponding to this edge prior to any '
                                'synonymization or remapping.',
                 'original_attribute_name': None,
                 'value': ['DrugCentral:4933---DrugCentral:indication---None---None---None---DOID:0111157---DrugCentral:'],
                 'value_type_id': 'metatype:String',
                 'value_url': None},
                {'attribute_source': 'infores:rtx-kg2',
                 'attribute_type_id': 'biolink:knowledge_level',
                 'attributes': None,
                 'description': None,
                 'original_attribute_name': None,
                 'value': 'knowledge_assertion',
                 'value_type_id': None,
                 'value_url': None}],
 'object': 'MONDO:0015564',
 'predicate': 'biolink:applied_to_treat',
 'qualifiers': None,
 'sources': [{'resource_id': 'infores:drugcentral',
              'resource_role': 'primary_knowledge_source',
              'source_record_urls': None,
              'upstream_resource_ids': None},
             {'resource_id': 'infores:rtx-kg2',
              'resource_role': 'aggregator_knowledge_source',
              'source_record_urls': None,
              'upstream_resource_ids': ['infores:drugcentral']},
             {'resource_id': 'infores:arax',
              'resource_role': 'aggregator_knowledge_source',
              'source_record_urls': None,
              'upstream_resource_ids': ['infores:rtx-kg2']}],
 'subject': 'PUBCHEM.COMPOUND:10150081'}, {'attributes': [{'attribute_source': 'infores:rtx-kg2',
                 'attribute_type_id': 'biolink:agent_type',
                 'attributes': None,
                 'description': None,
                 'original_attribute_name': None,
                 'value': 'manual_agent',
                 'value_type_id': None,
                 'value_url': None},
                {'attribute_source': None,
                 'attribute_type_id': 'biolink:original_predicate',
                 'attributes': None,
                 'description': 'The IDs of the original RTX-KG2pre edge(s) '
                                'corresponding to this edge prior to any '
                                'synonymization or remapping.',
                 'original_attribute_name': None,
                 'value': ['DrugCentral:4977---DrugCentral:indication---None---None---None---DOID:0111157---DrugCentral:'],
                 'value_type_id': 'metatype:String',
                 'value_url': None},
                {'attribute_source': 'infores:rtx-kg2',
                 'attribute_type_id': 'biolink:knowledge_level',
                 'attributes': None,
                 'description': None,
                 'original_attribute_name': None,
                 'value': 'knowledge_assertion',
                 'value_type_id': None,
                 'value_url': None}],
 'object': 'MONDO:0015564',
 'predicate': 'biolink:applied_to_treat',
 'qualifiers': None,
 'sources': [{'resource_id': 'infores:drugcentral',
              'resource_role': 'primary_knowledge_source',
              'source_record_urls': None,
              'upstream_resource_ids': None},
             {'resource_id': 'infores:rtx-kg2',
              'resource_role': 'aggregator_knowledge_source',
              'source_record_urls': None,
              'upstream_resource_ids': ['infores:drugcentral']},
             {'resource_id': 'infores:arax',
              'resource_role': 'aggregator_knowledge_source',
              'source_record_urls': None,
              'upstream_resource_ids': ['infores:rtx-kg2']}],
 'subject': 'UNII:T4H8FMA7IM'}]
--------------------------------------------------------------------------------------- Captured stderr call ----------------------------------------------------------------------------------------
2024-09-25T20:45:30.959558 INFO: (985310) [] ARAX Query launching on incoming Query
2024-09-25T20:45:30.959636 DEBUG: (985310) [] RTXConfiguration says maturity=development, current_branch=master, is_itrb_instance=False, arax_version=1.5.3, trapi_version=1.5.0
2024-09-25T20:45:30.959674 INFO: (985310) [] Creating an empty template TRAPI Response
2024-09-25T20:45:30.959847: DEBUG: In BiolinkHelper init
2024-09-25T20:45:30.962039: DEBUG: Loading BL lookup map...
2024-09-25T20:45:30.962093: DEBUG: Loading pickle file: /mnt/data/orangeboard/test/RTX/code/ARAX/BiolinkHelper/biolink_lookup_map_4.2.1_v4.pickle
2024-09-25T20:45:30.964141: DEBUG: Done loading BL lookup map
2024-09-25T20:45:30.966816 INFO: (985310) [] Examine input Query for needed information for dispatch
2024-09-25T20:45:30.966868 INFO: (985310) [] Validating the input query graph
2024-09-25T20:45:30.966906 DEBUG: (985310) [] Deserializing message
2024-09-25T20:45:30.967183 INFO: (985310) [] Found input query_graph. Interpreting it and generating ARAXi processing plan to answer it
2024-09-25T20:45:31.031553 DEBUG: (985310) [] Assessing the QueryGraph for basic information
2024-09-25T20:45:31.031605 DEBUG: (985310) [] Found 2 nodes and 1 edges
2024-09-25T20:45:31.032488 DEBUG: (985310) [] canonical_curies={'MONDO:0015564': {'preferred_curie': 'MONDO:0015564', 'preferred_name': 'Castleman disease', 'preferred_category': 'biolink:Disease', 'all_categories': {'biolink:Disease': 13}}}, curie=MONDO:0015564
2024-09-25T20:45:31.032581 DEBUG: (985310) [] The QueryGraph reference template is: n00(ids)-e00()-n01(categories=biolink:ChemicalEntity)
2024-09-25T20:45:31.033221 INFO: (985310) [] Found input processing plan. Sending to the ProcessingPlanExecutor
2024-09-25T20:45:31.033262 DEBUG: (985310) [] Entering execute_processing_plan
2024-09-25T20:45:31.033370 DEBUG: (985310) [] Connecting to ResponseCache
2024-09-25T20:45:31.093802 DEBUG: (985310) [] Creating ARAXMessenger instance
2024-09-25T20:45:31.093887 DEBUG: (985310) [] A single Message is ready and in hand
2024-09-25T20:45:31.094486 DEBUG: (985310) [] Saving original query graph (has qnodes {'chemical', 'disease'} and qedges {'t_edge'})..
2024-09-25T20:45:31.094531 DEBUG: (985310) [] Found actions
2024-09-25T20:45:31.094569 INFO: (985310) [] Parsing input actions list
2024-09-25T20:45:31.094599 DEBUG: (985310) [] Parsing action: expand()
2024-09-25T20:45:31.095430 DEBUG: (985310) [] Parsing action: overlay(action=compute_ngd, virtual_relation_label=N1, subject_qnode_key=disease, object_qnode_key=chemical)
2024-09-25T20:45:31.095507 DEBUG: (985310) [] Parsing action: filter_kg(action=remove_general_concept_nodes,perform_action=True)
2024-09-25T20:45:31.095562 DEBUG: (985310) [] Parsing action: resultify()
2024-09-25T20:45:31.095610 DEBUG: (985310) [] Parsing action: filter_results(action=limit_number_of_results, max_results=500)
2024-09-25T20:45:31.210631: DEBUG: In BiolinkHelper init
2024-09-25T20:45:31.213130: DEBUG: Loading BL lookup map...
2024-09-25T20:45:31.213185: DEBUG: Loading pickle file: /mnt/data/orangeboard/test/RTX/code/ARAX/BiolinkHelper/biolink_lookup_map_4.2.1_v4.pickle
2024-09-25T20:45:31.216260: DEBUG: Done loading BL lookup map
2024-09-25T20:45:31.216719 INFO: (985310) [] Processing action 'expand' with parameters {'': 'true'}
2024-09-25T20:45:31.216933 DEBUG: (985310) [] Loading cached Smart API amd meta map info
2024-09-25T20:45:31.229344: DEBUG: In BiolinkHelper init
2024-09-25T20:45:31.233289: DEBUG: Loading BL lookup map...
2024-09-25T20:45:31.233378: DEBUG: Loading pickle file: /mnt/data/orangeboard/test/RTX/code/ARAX/BiolinkHelper/biolink_lookup_map_4.2.1_v4.pickle
2024-09-25T20:45:31.235482: DEBUG: Done loading BL lookup map
2024-09-25T20:45:31.236123 DEBUG: (985310) [] Applying Expand to Message with parameters {'kp': None, 'edge_key': ['t_edge'], 'node_key': [], 'prune_threshold': None, 'kp_timeout': None, 'return_minimal_metadata': False}
2024-09-25T20:45:31.236440 DEBUG: (985310) [] Sending NodeSynonymizer.get_canonical_curies() a list of 1 curies
2024-09-25T20:45:31.236871 DEBUG: (985310) [] Got response back from NodeSynonymizer
2024-09-25T20:45:31.237070 DEBUG: (985310) [] Inferred category for qnode disease is ['biolink:Disease']
2024-09-25T20:45:31.237120 DEBUG: (985310) [] Making sure QG only uses canonical predicates
2024-09-25T20:45:31.237800 DEBUG: (985310) [] Query graph for this Expand() call is: {'nodes': {'chemical': {'ids': None, 'categories': ['biolink:ChemicalEntity'], 'is_set': False, 'set_interpretation': 'BATCH', 'set_id': None, 'constraints': [], 'option_group_id': None}, 'disease': {'ids': ['MONDO:0015564'], 'categories': ['biolink:Disease', 'biolink:PhenotypicFeature', 'biolink:DiseaseOrPhenotypicFeature'], 'is_set': False, 'set_interpretation': 'BATCH', 'set_id': None, 'constraints': [], 'option_group_id': None}}, 'edges': {'t_edge': {'knowledge_type': 'inferred', 'predicates': ['biolink:treats'], 'subject': 'chemical', 'object': 'disease', 'attribute_constraints': [{'id': 'knowledge_source', 'name': 'knowledge source', 'not': False, 'operator': '==', 'value': ['infores:rtx-kg2'], 'unit_id': None, 'unit_name': None}], 'qualifier_constraints': [], 'exclude': None, 'option_group_id': None}}}
2024-09-25T20:45:31.237941 DEBUG: (985310) [] knowledge_type='inferred' qedges were detected (t_edge); will determine which model to consult based on the category of source qnode and object qnode, as well as predicate.
2024-09-25T20:45:31.237984 INFO: (985310) [] Calling XDTD from Expand for qedge t_edge (has knowledge_type == inferred) and the subject is MONDO:0015564
2024-09-25T20:45:31.238841: DEBUG: In BiolinkHelper init
2024-09-25T20:45:31.241053: DEBUG: Loading BL lookup map...
2024-09-25T20:45:31.241106: DEBUG: Loading pickle file: /mnt/data/orangeboard/test/RTX/code/ARAX/BiolinkHelper/biolink_lookup_map_4.2.1_v4.pickle
2024-09-25T20:45:31.243151: DEBUG: Done loading BL lookup map
2024-09-25T20:45:31.243665 DEBUG: (985310) [] Get equivalent curies ['MONDO:0015564', 'DOID:0111157', 'orphanet:160', 'UMLS:C0017531', 'UMLS:C2931179', 'MESH:C536362', 'MESH:D005871', 'MEDDRA:10050251', 'NCIT:C3056', 'SNOMEDCT:207036003', 'SNOMEDCT:781094002', 'ICD10:D47.Z2', 'CHV:0000001174'] from Node Synonymizer for MONDO:0015564
2024-09-25T20:45:31.781554: DEBUG: In BiolinkHelper init
2024-09-25T20:45:31.783594: DEBUG: Loading BL lookup map...
2024-09-25T20:45:31.783652: DEBUG: Loading pickle file: /mnt/data/orangeboard/test/RTX/code/ARAX/BiolinkHelper/biolink_lookup_map_4.2.1_v4.pickle
2024-09-25T20:45:31.785544: DEBUG: Done loading BL lookup map
2024-09-25T20:45:31.788409 INFO: (985310) [] Adding a QueryNode to Message with input parameters {'key': 'creative_DTD_qnode_0', 'ids': None, 'name': None, 'categories': None, 'is_set': 'true', 'option_group_id': 'creative_DTD_option_group_0'}
2024-09-25T20:45:31.788703 INFO: (985310) [] Adding a QueryNode to Message with input parameters {'key': 'creative_DTD_qnode_1', 'ids': None, 'name': None, 'categories': None, 'is_set': 'true', 'option_group_id': 'creative_DTD_option_group_0'}
2024-09-25T20:45:31.788977 INFO: (985310) [] Adding a QueryEdge to Message with parameters {'key': 'creative_DTD_qedge_0', 'subject': 'chemical', 'object': 'creative_DTD_qnode_0', 'predicates': None, 'option_group_id': 'creative_DTD_option_group_0', 'exclude': None}
2024-09-25T20:45:31.789052 INFO: (985310) [] Adding a QueryEdge to Message with parameters {'key': 'creative_DTD_qedge_1', 'subject': 'creative_DTD_qnode_0', 'object': 'creative_DTD_qnode_1', 'predicates': None, 'option_group_id': 'creative_DTD_option_group_0', 'exclude': None}
2024-09-25T20:45:31.789112 INFO: (985310) [] Adding a QueryEdge to Message with parameters {'key': 'creative_DTD_qedge_2', 'subject': 'creative_DTD_qnode_1', 'object': 'disease', 'predicates': None, 'option_group_id': 'creative_DTD_option_group_0', 'exclude': None}
2024-09-25T20:45:34.941928 DEBUG: (985310) [] Decorating nodes with metadata from KG2c
2024-09-25T20:45:34.942301 DEBUG: (985310) [] Looking up corresponding KG2c nodes in sqlite
2024-09-25T20:45:34.950259 DEBUG: (985310) [] Adding attributes to nodes in the KG
2024-09-25T20:45:35.085027 DEBUG: (985310) [] Decorating edges with EPC info from KG2c
2024-09-25T20:45:35.089560 DEBUG: (985310) [] Identified 1321 edges to decorate
2024-09-25T20:45:35.097443 DEBUG: (985310) [] Looking up EPC edge info in KG2c sqlite
2024-09-25T20:45:35.097488 DEBUG: (985310) [] Looking up corresponding KG2c nodes in sqlite
2024-09-25T20:45:35.114571 DEBUG: (985310) [] Got 1080 rows back from KG2c sqlite
2024-09-25T20:45:35.114651 DEBUG: (985310) [] Adding attributes to edges in the KG
2024-09-25T20:45:35.436486 DEBUG: (985310) [] Applying Resultifier to Message with parameters {'ignore_edge_direction': 'true'}
2024-09-25T20:45:35.436636 DEBUG: (985310) [] Expanded qedges are {'creative_DTD_qedge_1', 'creative_DTD_qedge_0', 'creative_DTD_qedge_2', 't_edge'}, expanded qnodes are {'chemical', 'creative_DTD_qnode_0', 'creative_DTD_qnode_1', 'disease'}; will resultify only this sub-QG
2024-09-25T20:45:35.436695 DEBUG: (985310) [] Non-kryptonite qedges are {'creative_DTD_qedge_1', 'creative_DTD_qedge_0', 'creative_DTD_qedge_2', 't_edge'}, non-kryptonite qnodes are {'disease', 'chemical', 'creative_DTD_qnode_0', 'creative_DTD_qnode_1'}.
2024-09-25T20:45:35.441410 DEBUG: (985310) [] Grabbing only required portion of QG
2024-09-25T20:45:35.441475 DEBUG: (985310) [] Required qnodes are {'chemical', 'disease'}, required qedges are {'t_edge'}
2024-09-25T20:45:35.441545 DEBUG: (985310) [] Subclass self-qedges are set(); qnodes with a subclass self-qedge are: set()
2024-09-25T20:45:35.441583 DEBUG: (985310) [] Building helper indexes for faster lookup of edges
2024-09-25T20:45:35.567904 INFO: (985310) [] Creating result graphs for required portion of QG
2024-09-25T20:45:35.569632 DEBUG: (985310) [] Constructing result graphs qnode by qnode
2024-09-25T20:45:35.569681 DEBUG: (985310) [] Qnode keys already handled are: set()
2024-09-25T20:45:35.569720 DEBUG: (985310) [] Initiating result graphs with nodes for chemical (is_set=False)
2024-09-25T20:45:35.569750 DEBUG: (985310) [] Starting with a result graph for each chemical node
2024-09-25T20:45:35.569884 DEBUG: (985310) [] Current count of result graphs is 47
2024-09-25T20:45:35.569923 DEBUG: (985310) [] Next qnode chosen is: disease
2024-09-25T20:45:35.569954 DEBUG: (985310) [] Adding a layer to each result graph for qnode disease (is_set=False)
2024-09-25T20:45:35.572365 DEBUG: (985310) [] Current count of result graphs is 47
2024-09-25T20:45:35.572410 DEBUG: (985310) [] Done assigning nodes to result graphs.
2024-09-25T20:45:35.572438 DEBUG: (985310) [] Adding edges to result graphs
2024-09-25T20:45:35.572721 DEBUG: (985310) [] After pruning out result graphs missing edges, there are 47 result graphs
2024-09-25T20:45:35.572765 DEBUG: (985310) [] Created 47 required result graphs
2024-09-25T20:45:35.572811 INFO: (985310) [] Distinct option groups detected in the QG are: {'creative_DTD_option_group_0'}
2024-09-25T20:45:35.572871 DEBUG: (985310) [] For option group creative_DTD_option_group_0, qnodes are {'chemical', 'creative_DTD_qnode_0', 'creative_DTD_qnode_1', 'disease'}, qedges are {'creative_DTD_qedge_1', 'creative_DTD_qedge_0', 'creative_DTD_qedge_2', 't_edge'}
2024-09-25T20:45:35.572942 INFO: (985310) [] Creating result graphs for option group creative_DTD_option_group_0
2024-09-25T20:45:35.581125 DEBUG: (985310) [] Constructing result graphs qnode by qnode
2024-09-25T20:45:35.581184 DEBUG: (985310) [] Qnode keys already handled are: {'chemical', 'disease'}
2024-09-25T20:45:35.581225 DEBUG: (985310) [] Next qnode chosen is: creative_DTD_qnode_0
2024-09-25T20:45:35.581255 DEBUG: (985310) [] Adding a layer to each result graph for qnode creative_DTD_qnode_0 (is_set=True)
2024-09-25T20:45:35.585319 DEBUG: (985310) [] Current count of result graphs is 47
2024-09-25T20:45:35.585375 DEBUG: (985310) [] Next qnode chosen is: creative_DTD_qnode_1
2024-09-25T20:45:35.585407 DEBUG: (985310) [] Adding a layer to each result graph for qnode creative_DTD_qnode_1 (is_set=True)
2024-09-25T20:45:35.592686 DEBUG: (985310) [] Current count of result graphs is 47
2024-09-25T20:45:35.592731 DEBUG: (985310) [] Done assigning nodes to result graphs.
2024-09-25T20:45:35.592774 DEBUG: (985310) [] Adding edges to result graphs
2024-09-25T20:45:35.599453 DEBUG: (985310) [] After pruning out result graphs missing edges, there are 47 result graphs
2024-09-25T20:45:35.599642 DEBUG: (985310) [] Created 47 option group creative_DTD_option_group_0 result graphs
2024-09-25T20:45:35.599682 DEBUG: (985310) [] Required non-set qnodes are: ['chemical', 'disease']
2024-09-25T20:45:35.599840 INFO: (985310) [] Merging option group result graphs into required result graphs with matching non-set qnodes
2024-09-25T20:45:35.602972 DEBUG: (985310) [] There are a total of 47 final result graphs
2024-09-25T20:45:35.608913 DEBUG: (985310) [] Loading final result graphs into TRAPI object model
2024-09-25T20:45:35.630208 INFO: (985310) [] Resultify created 47 results
2024-09-25T20:45:35.631494 DEBUG: (985310) [] Cleaning up the KG to remove nodes not used in the results
2024-09-25T20:45:35.633609 INFO: (985310) [] After cleaning, the KG contains 238 nodes and 1368 edges
2024-09-25T20:45:35.640341 WARNING: (985310) [] Could not get predicted drugs for disease DOID:0111157. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-25T20:45:35.644300 WARNING: (985310) [] Could not get predicted drugs for disease orphanet:160. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-25T20:45:35.648208 WARNING: (985310) [] Could not get predicted drugs for disease UMLS:C0017531. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-25T20:45:35.652111 WARNING: (985310) [] Could not get predicted drugs for disease UMLS:C2931179. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-25T20:45:35.655994 WARNING: (985310) [] Could not get predicted drugs for disease MESH:C536362. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-25T20:45:35.659866 WARNING: (985310) [] Could not get predicted drugs for disease MESH:D005871. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-25T20:45:35.663752 WARNING: (985310) [] Could not get predicted drugs for disease MEDDRA:10050251. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-25T20:45:35.667635 WARNING: (985310) [] Could not get predicted drugs for disease NCIT:C3056. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-25T20:45:35.671528 WARNING: (985310) [] Could not get predicted drugs for disease SNOMEDCT:207036003. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-25T20:45:35.675399 WARNING: (985310) [] Could not get predicted drugs for disease SNOMEDCT:781094002. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-25T20:45:35.679273 WARNING: (985310) [] Could not get predicted drugs for disease ICD10:D47.Z2. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-25T20:45:35.683139 WARNING: (985310) [] Could not get predicted drugs for disease CHV:0000001174. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-25T20:45:35.683741 DEBUG: (985310) [] Applying Infer to Message with parameters {'action': 'drug_treatment_graph_expansion', 'node_curie': 'MONDO:0015564', 'qedge_id': 't_edge', 'drug_curie': None, 'n_drugs': 50, 'n_paths': 25}
2024-09-25T20:45:35.686138 DEBUG: (985310) [] Query graph is {'edges': {'creative_DTD_qedge_0': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'creative_DTD_qnode_0',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'chemical'},
           'creative_DTD_qedge_1': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'creative_DTD_qnode_1',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'creative_DTD_qnode_0'},
           'creative_DTD_qedge_2': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'disease',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'creative_DTD_qnode_1'},
           't_edge': {'attribute_constraints': [{'id': 'knowledge_source',
                                                 'name': 'knowledge source',
                                                 'not': False,
                                                 'operator': '==',
                                                 'unit_id': None,
                                                 'unit_name': None,
                                                 'value': ['infores:rtx-kg2']}],
                      'exclude': None,
                      'knowledge_type': 'inferred',
                      'object': 'disease',
                      'option_group_id': None,
                      'predicates': ['biolink:treats'],
                      'qualifier_constraints': [],
                      'subject': 'chemical'}},
 'nodes': {'chemical': {'categories': ['biolink:Drug', 'biolink:SmallMolecule'],
                        'constraints': [],
                        'ids': None,
                        'is_set': False,
                        'option_group_id': None,
                        'set_id': None,
                        'set_interpretation': 'BATCH'},
           'creative_DTD_qnode_0': {'categories': None,
                                    'constraints': [],
                                    'ids': None,
                                    'is_set': True,
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'set_id': None,
                                    'set_interpretation': 'BATCH'},
           'creative_DTD_qnode_1': {'categories': None,
                                    'constraints': [],
                                    'ids': None,
                                    'is_set': True,
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'set_id': None,
                                    'set_interpretation': 'BATCH'},
           'disease': {'categories': None,
                       'constraints': [],
                       'ids': ['MONDO:0015564'],
                       'is_set': False,
                       'option_group_id': None,
                       'set_id': None,
                       'set_interpretation': 'BATCH'}}}
2024-09-25T20:45:35.686208 DEBUG: (985310) [] Number of nodes in KG is 238
2024-09-25T20:45:35.686781 DEBUG: (985310) [] Number of nodes in KG by type is Counter({'biolink:SmallMolecule': 129, 'biolink:Gene': 45, 'biolink:ChemicalEntity': 18, 'biolink:Drug': 9, 'biolink:Cell': 8, 'biolink:GrossAnatomicalStructure': 8, 'biolink:Protein': 6, 'biolink:PhysiologicalProcess': 5, 'biolink:MolecularActivity': 4, 'biolink:Disease': 2, 'biolink:AnatomicalEntity': 2, 'biolink:MolecularMixture': 2})
2024-09-25T20:45:35.686851 DEBUG: (985310) [] Number of edges in KG is 1368
2024-09-25T20:45:35.687855 DEBUG: (985310) [] Number of edges in KG by type is Counter({'biolink:interacts_with': 782, 'biolink:affects': 363, 'biolink:treats': 47, 'biolink:located_in': 36, 'biolink:subclass_of': 32, 'biolink:physically_interacts_with': 23, 'biolink:produces': 18, 'biolink:has_part': 17, 'biolink:gene_associated_with_condition': 14, 'biolink:disrupts': 11, 'biolink:causes': 8, 'biolink:directly_physically_interacts_with': 5, 'biolink:colocalizes_with': 4, 'biolink:has_participant': 4, 'biolink:associated_with': 2, 'biolink:occurs_in': 2})
2024-09-25T20:45:35.688383 DEBUG: (985310) [] Number of edges in KG with attributes is 1368
2024-09-25T20:45:35.698310 DEBUG: (985310) [] Number of edges in KG by attribute Counter({None: 5057, 'defined_datetime': 1368, 'metatype:Datetime': 1368, 'EDAM-DATA:1772': 1368, 'biolink:original_predicate': 1080, 'biolink:knowledge_level': 1080, 'biolink:agent_type': 1080, 'biolink:publications': 270, 'bts:sentence': 179, 'probability_treats': 47, 'EDAM-DATA:0951': 47})
2024-09-25T20:45:35.699470 DEBUG: (985310) [] Done calling ARAX Infer from Expand; returning to regular Expand execution
2024-09-25T20:45:35.699622 DEBUG: (985310) [] Expanding qedge t_edge
2024-09-25T20:45:35.700206 DEBUG: (985310) [] Modified QG for this qedge is (disease:['biolink:Disease', 'biolink:PhenotypicFeature', 'biolink:DiseaseOrPhenotypicFeature'] ['MONDO:0015564'])-['biolink:treats']-(chemical:['biolink:ChemicalEntity'])
2024-09-25T20:45:35.700261 DEBUG: (985310) [] For t_edge, pre-prune threshold is 200
2024-09-25T20:45:35.700305 DEBUG: (985310) [] Selecting KPs to use for qedge t_edge
2024-09-25T20:45:35.700478 DEBUG: (985310) [] selecting from 37 kps
2024-09-25T20:45:35.703302 DEBUG: (985310) [] Skipped infores:text-mining-provider-cooccurrence: KP does not have a TRAPI 1.5 endpoint
2024-09-25T20:45:35.703384 INFO: (985310) [] Expand decided to use 1 KPs to answer t_edge: {'infores:rtx-kg2'}
2024-09-25T20:45:35.703425 DEBUG: (985310) [] Will use asyncio to run KP queries concurrently
2024-09-25T20:45:35.703839 INFO: (985310) [] Expanding qedge t_edge using infores:rtx-kg2
2024-09-25T20:45:35.704320 DEBUG: (985310) [] infores:rtx-kg2: Qnodes with an implied parent query ID are: {'disease': 'MONDO:0015564'}
2024-09-25T20:45:35.704622 DEBUG: (985310) [] Sending NodeSynonymizer.get_canonical_curies() a list of 1 curies
2024-09-25T20:45:35.705038 DEBUG: (985310) [] Got response back from NodeSynonymizer
2024-09-25T20:45:35.705149 INFO: (985310) [] For querying infores:rtx-kg2, edited t_edge to use higher treats-type predicate: ['biolink:treats_or_applied_or_studied_to_treat', 'biolink:treats']
2024-09-25T20:45:35.705375 DEBUG: (985310) [] infores:rtx-kg2: Sending query to infores:rtx-kg2 API (https://kg2cplover.rtx.ai:9990)
2024-09-25T20:45:36.048612 DEBUG: (985310) [] infores:rtx-kg2: Got results from infores:rtx-kg2.
2024-09-25T20:45:36.052229 DEBUG: (985310) [] Sending NodeSynonymizer.get_canonical_curies() a list of 0 curies
2024-09-25T20:45:36.052287 DEBUG: (985310) [] Got response back from NodeSynonymizer
2024-09-25T20:45:36.052544 DEBUG: (985310) [] Sending NodeSynonymizer.get_canonical_curies() a list of 0 curies
2024-09-25T20:45:36.052590 DEBUG: (985310) [] Got response back from NodeSynonymizer
2024-09-25T20:45:36.052691 DEBUG: (985310) [] infores:rtx-kg2: Added 1 subclass_of edges to the KG based on query ID mappings infores:rtx-kg2 returned
2024-09-25T20:45:36.052812 INFO: (985310) [] infores:rtx-kg2: Query for edge t_edge completed (chemical: 6, disease: 2, subclass:disease--disease: 1, t_edge: 10)
2024-09-25T20:45:36.052855 DEBUG: (985310) [] infores:rtx-kg2: Removing any self-edges from the answer KG
2024-09-25T20:45:36.052905 DEBUG: (985310) [] infores:rtx-kg2: After removing self-edges, answer KG counts are: chemical: 6, disease: 2, subclass:disease--disease: 1, t_edge: 10
2024-09-25T20:45:36.053099 DEBUG: (985310) [] Got answers from all KPs; merging them into one KG
2024-09-25T20:45:36.053224 DEBUG: (985310) [] Merging answer into Message.KnowledgeGraph
2024-09-25T20:45:36.053446 DEBUG: (985310) [] Sending NodeSynonymizer.get_canonical_curies() a list of 1 curies
2024-09-25T20:45:36.053856 DEBUG: (985310) [] Got response back from NodeSynonymizer
2024-09-25T20:45:36.054231 DEBUG: (985310) [] Adding subclass_of qedge subclass:disease--disease to the QG since KP(s) returned child nodes for this qnode
2024-09-25T20:45:36.054277 DEBUG: (985310) [] Removed 0 edges fulfilling subclass:disease--disease from the KG because they were orphaned
2024-09-25T20:45:36.054328 DEBUG: (985310) [] Removed 0 edges fulfilling t_edge from the KG because they were orphaned
2024-09-25T20:45:36.054373 DEBUG: (985310) [] After merging KPs' answers, total KG counts are: chemical: 51, creative_DTD_qedge_0: 955, creative_DTD_qedge_1: 348, creative_DTD_qedge_2: 18, creative_DTD_qnode_0: 183, creative_DTD_qnode_1: 16, disease: 2, subclass:disease--disease: 1, t_edge: 57
2024-09-25T20:45:36.054407 DEBUG: (985310) [] Handling any knowledge source constraints
2024-09-25T20:45:36.054447 DEBUG: (985310) [] KP allowlist is {'infores:rtx-kg2'}, denylist is set()
2024-09-25T20:45:36.054693 DEBUG: (985310) [] Removing 8 KG2 semmeddb treats_or_applied-type edges fulfilling t_edge
2024-09-25T20:45:36.054761 DEBUG: (985310) [] Pruning any paths that are now dead ends (with help of Resultify)
2024-09-25T20:45:36.057403 DEBUG: (985310) [] Calling Resultify from Expand..
2024-09-25T20:45:36.057451 DEBUG: (985310) [] Applying Resultifier to Message with parameters {}
2024-09-25T20:45:36.057517 DEBUG: (985310) [] Expanded qedges are {'creative_DTD_qedge_0', 't_edge', 'subclass:disease--disease', 'creative_DTD_qedge_1', 'creative_DTD_qedge_2'}, expanded qnodes are {'chemical', 'creative_DTD_qnode_0', 'creative_DTD_qnode_1', 'disease'}; will resultify only this sub-QG
2024-09-25T20:45:36.057571 DEBUG: (985310) [] Non-kryptonite qedges are {'creative_DTD_qedge_0', 't_edge', 'subclass:disease--disease', 'creative_DTD_qedge_1', 'creative_DTD_qedge_2'}, non-kryptonite qnodes are {'chemical', 'creative_DTD_qnode_0', 'creative_DTD_qnode_1', 'disease'}.
2024-09-25T20:45:36.061803 DEBUG: (985310) [] Grabbing only required portion of QG
2024-09-25T20:45:36.061865 DEBUG: (985310) [] Required qnodes are {'chemical', 'disease'}, required qedges are {'t_edge'}
2024-09-25T20:45:36.061956 DEBUG: (985310) [] Subclass self-qedges are {'subclass:disease--disease'}; qnodes with a subclass self-qedge are: {'disease'}
2024-09-25T20:45:36.061995 DEBUG: (985310) [] Building helper indexes for faster lookup of edges
2024-09-25T20:45:36.074977 INFO: (985310) [] Creating result graphs for required portion of QG
2024-09-25T20:45:36.076651 DEBUG: (985310) [] Constructing result graphs qnode by qnode
2024-09-25T20:45:36.076699 DEBUG: (985310) [] Qnode keys already handled are: set()
2024-09-25T20:45:36.076734 DEBUG: (985310) [] Initiating result graphs with nodes for chemical (is_set=True)
2024-09-25T20:45:36.076763 DEBUG: (985310) [] Starting with one result graph because is_set=True for chemical
2024-09-25T20:45:36.076794 DEBUG: (985310) [] Current count of result graphs is 1
2024-09-25T20:45:36.076830 DEBUG: (985310) [] Next qnode chosen is: disease
2024-09-25T20:45:36.076859 DEBUG: (985310) [] Adding a layer to each result graph for qnode disease (is_set=True)
2024-09-25T20:45:36.077104 DEBUG: (985310) [] Current count of result graphs is 1
2024-09-25T20:45:36.077139 DEBUG: (985310) [] Done assigning nodes to result graphs.
2024-09-25T20:45:36.077166 DEBUG: (985310) [] Adding edges to result graphs
2024-09-25T20:45:36.077256 DEBUG: (985310) [] After pruning out result graphs missing edges, there are 1 result graphs
2024-09-25T20:45:36.077297 DEBUG: (985310) [] Created 1 required result graphs
2024-09-25T20:45:36.077342 INFO: (985310) [] Distinct option groups detected in the QG are: {'creative_DTD_option_group_0'}
2024-09-25T20:45:36.077401 DEBUG: (985310) [] For option group creative_DTD_option_group_0, qnodes are {'chemical', 'creative_DTD_qnode_0', 'creative_DTD_qnode_1', 'disease'}, qedges are {'creative_DTD_qedge_1', 'creative_DTD_qedge_0', 'creative_DTD_qedge_2', 't_edge'}
2024-09-25T20:45:36.077485 INFO: (985310) [] Creating result graphs for option group creative_DTD_option_group_0
2024-09-25T20:45:36.082912 DEBUG: (985310) [] Constructing result graphs qnode by qnode
2024-09-25T20:45:36.082964 DEBUG: (985310) [] Qnode keys already handled are: {'chemical', 'disease'}
2024-09-25T20:45:36.083004 DEBUG: (985310) [] Next qnode chosen is: creative_DTD_qnode_0
2024-09-25T20:45:36.083035 DEBUG: (985310) [] Adding a layer to each result graph for qnode creative_DTD_qnode_0 (is_set=True)
2024-09-25T20:45:36.084017 DEBUG: (985310) [] Current count of result graphs is 1
2024-09-25T20:45:36.084066 DEBUG: (985310) [] Next qnode chosen is: creative_DTD_qnode_1
2024-09-25T20:45:36.084098 DEBUG: (985310) [] Adding a layer to each result graph for qnode creative_DTD_qnode_1 (is_set=True)
2024-09-25T20:45:36.085508 DEBUG: (985310) [] Current count of result graphs is 1
2024-09-25T20:45:36.085544 DEBUG: (985310) [] Done assigning nodes to result graphs.
2024-09-25T20:45:36.085571 DEBUG: (985310) [] Adding edges to result graphs
2024-09-25T20:45:36.086512 DEBUG: (985310) [] After pruning out result graphs missing edges, there are 1 result graphs
2024-09-25T20:45:36.086669 DEBUG: (985310) [] Created 1 option group creative_DTD_option_group_0 result graphs
2024-09-25T20:45:36.086706 DEBUG: (985310) [] Required non-set qnodes are: []
2024-09-25T20:45:36.086737 INFO: (985310) [] Merging option group result graphs into required result graphs with matching non-set qnodes
2024-09-25T20:45:36.086946 DEBUG: (985310) [] There are a total of 1 final result graphs
2024-09-25T20:45:36.089358 INFO: (985310) [] After separating children from parents in our single result, counts are: {'chemical': 48, 'disease': 1, 'creative_DTD_qnode_0': 181, 'creative_DTD_qnode_1': 15}, {'t_edge': 49, 'creative_DTD_qedge_0': 953, 'creative_DTD_qedge_1': 348, 'creative_DTD_qedge_2': 18}
2024-09-25T20:45:36.089392 DEBUG: (985310) [] Loading final result graphs into TRAPI object model
2024-09-25T20:45:36.094005 INFO: (985310) [] Resultify created 1 results
2024-09-25T20:45:36.094949 DEBUG: (985310) [] Cleaning up the KG to remove nodes not used in the results
2024-09-25T20:45:36.096524 INFO: (985310) [] After cleaning, the KG contains 238 nodes and 1371 edges
2024-09-25T20:45:36.097492 DEBUG: (985310) [] After removing dead-end paths, KG counts are: chemical: 49, creative_DTD_qedge_0: 955, creative_DTD_qedge_1: 348, creative_DTD_qedge_2: 18, creative_DTD_qnode_0: 183, creative_DTD_qnode_1: 16, disease: 2, subclass:disease--disease: 1, t_edge: 49
2024-09-25T20:45:36.099523 DEBUG: (985310) [] Decorating nodes with metadata from KG2c
2024-09-25T20:45:36.099894 DEBUG: (985310) [] Looking up corresponding KG2c nodes in sqlite
2024-09-25T20:45:36.105234 DEBUG: (985310) [] Adding attributes to nodes in the KG
2024-09-25T20:45:36.243626 DEBUG: (985310) [] Decorating edges with EPC info from KG2c
2024-09-25T20:45:36.248118 DEBUG: (985310) [] Identified 1323 edges to decorate
2024-09-25T20:45:36.255801 DEBUG: (985310) [] Looking up EPC edge info in KG2c sqlite
2024-09-25T20:45:36.255847 DEBUG: (985310) [] Looking up corresponding KG2c nodes in sqlite
2024-09-25T20:45:36.272284 DEBUG: (985310) [] Got 1082 rows back from KG2c sqlite
2024-09-25T20:45:36.272365 DEBUG: (985310) [] Adding attributes to edges in the KG
2024-09-25T20:45:36.285529 DEBUG: (985310) [] Sending NodeSynonymizer.get_canonical_curies() a list of 1 curies
2024-09-25T20:45:36.285987 DEBUG: (985310) [] Got response back from NodeSynonymizer
2024-09-25T20:45:36.286089 DEBUG: (985310) [] No KG nodes found that use a different curie than was asked for in the QG
2024-09-25T20:45:36.286150 INFO: (985310) [] After Expand, the KG has 238 nodes and 1371 edges (chemical: 49, creative_DTD_qedge_0: 955, creative_DTD_qedge_1: 348, creative_DTD_qedge_2: 18, creative_DTD_qnode_0: 183, creative_DTD_qnode_1: 16, disease: 2, subclass:disease--disease: 1, t_edge: 49)
2024-09-25T20:45:36.288489 INFO: (985310) [] Processing action 'overlay' with parameters {'action': 'compute_ngd', 'virtual_relation_label': 'N1', 'subject_qnode_key': 'disease', 'object_qnode_key': 'chemical'}
2024-09-25T20:45:36.288600 DEBUG: (985310) [] Applying Overlay to Message with parameters {'action': 'compute_ngd', 'virtual_relation_label': 'N1', 'subject_qnode_key': 'disease', 'object_qnode_key': 'chemical'}
2024-09-25T20:45:36.296625 DEBUG: (985310) [] Computing NGD
2024-09-25T20:45:36.296686 INFO: (985310) [] Computing the normalized Google distance: weighting edges based on subject/object node co-occurrence frequency in PubMed abstracts
2024-09-25T20:45:36.296721 DEBUG: (985310) [] Narrowing down disease--chemical node pairs to overlay
2024-09-25T20:45:36.298049 DEBUG: (985310) [] Applying Resultifier to Message with parameters {}
2024-09-25T20:45:36.298129 DEBUG: (985310) [] Expanded qedges are {'creative_DTD_qedge_0', 't_edge', 'subclass:disease--disease', 'creative_DTD_qedge_1', 'creative_DTD_qedge_2'}, expanded qnodes are {'chemical', 'creative_DTD_qnode_0', 'creative_DTD_qnode_1', 'disease'}; will resultify only this sub-QG
2024-09-25T20:45:36.298184 DEBUG: (985310) [] Non-kryptonite qedges are {'creative_DTD_qedge_0', 't_edge', 'subclass:disease--disease', 'creative_DTD_qedge_1', 'creative_DTD_qedge_2'}, non-kryptonite qnodes are {'chemical', 'creative_DTD_qnode_0', 'creative_DTD_qnode_1', 'disease'}.
2024-09-25T20:45:36.302491 DEBUG: (985310) [] Grabbing only required portion of QG
2024-09-25T20:45:36.302560 DEBUG: (985310) [] Required qnodes are {'chemical', 'disease'}, required qedges are {'t_edge'}
2024-09-25T20:45:36.302658 DEBUG: (985310) [] Subclass self-qedges are {'subclass:disease--disease'}; qnodes with a subclass self-qedge are: {'disease'}
2024-09-25T20:45:36.302698 DEBUG: (985310) [] Building helper indexes for faster lookup of edges
2024-09-25T20:45:36.314600 INFO: (985310) [] Creating result graphs for required portion of QG
2024-09-25T20:45:36.316969 DEBUG: (985310) [] Constructing result graphs qnode by qnode
2024-09-25T20:45:36.317030 DEBUG: (985310) [] Qnode keys already handled are: set()
2024-09-25T20:45:36.317066 DEBUG: (985310) [] Initiating result graphs with nodes for chemical (is_set=False)
2024-09-25T20:45:36.317094 DEBUG: (985310) [] Starting with a result graph for each chemical node
2024-09-25T20:45:36.317246 DEBUG: (985310) [] Current count of result graphs is 49
2024-09-25T20:45:36.317285 DEBUG: (985310) [] Next qnode chosen is: disease
2024-09-25T20:45:36.317315 DEBUG: (985310) [] Adding a layer to each result graph for qnode disease (is_set=False)
2024-09-25T20:45:36.319695 DEBUG: (985310) [] Current count of result graphs is 48
2024-09-25T20:45:36.319737 DEBUG: (985310) [] Done assigning nodes to result graphs.
2024-09-25T20:45:36.319765 DEBUG: (985310) [] Adding edges to result graphs
2024-09-25T20:45:36.320040 DEBUG: (985310) [] After pruning out result graphs missing edges, there are 48 result graphs
2024-09-25T20:45:36.320085 DEBUG: (985310) [] Created 48 required result graphs
2024-09-25T20:45:36.320134 INFO: (985310) [] Distinct option groups detected in the QG are: {'creative_DTD_option_group_0'}
2024-09-25T20:45:36.320193 DEBUG: (985310) [] For option group creative_DTD_option_group_0, qnodes are {'chemical', 'creative_DTD_qnode_0', 'creative_DTD_qnode_1', 'disease'}, qedges are {'creative_DTD_qedge_1', 'creative_DTD_qedge_0', 'creative_DTD_qedge_2', 't_edge'}
2024-09-25T20:45:36.320263 INFO: (985310) [] Creating result graphs for option group creative_DTD_option_group_0
2024-09-25T20:45:36.328435 DEBUG: (985310) [] Constructing result graphs qnode by qnode
2024-09-25T20:45:36.328510 DEBUG: (985310) [] Qnode keys already handled are: {'chemical', 'disease'}
2024-09-25T20:45:36.328552 DEBUG: (985310) [] Next qnode chosen is: creative_DTD_qnode_0
2024-09-25T20:45:36.328583 DEBUG: (985310) [] Adding a layer to each result graph for qnode creative_DTD_qnode_0 (is_set=True)
2024-09-25T20:45:36.332683 DEBUG: (985310) [] Current count of result graphs is 47
2024-09-25T20:45:36.332770 DEBUG: (985310) [] Next qnode chosen is: creative_DTD_qnode_1
2024-09-25T20:45:36.332803 DEBUG: (985310) [] Adding a layer to each result graph for qnode creative_DTD_qnode_1 (is_set=True)
2024-09-25T20:45:36.340088 DEBUG: (985310) [] Current count of result graphs is 47
2024-09-25T20:45:36.340137 DEBUG: (985310) [] Done assigning nodes to result graphs.
2024-09-25T20:45:36.340166 DEBUG: (985310) [] Adding edges to result graphs
2024-09-25T20:45:36.346992 DEBUG: (985310) [] After pruning out result graphs missing edges, there are 47 result graphs
2024-09-25T20:45:36.347245 DEBUG: (985310) [] Created 47 option group creative_DTD_option_group_0 result graphs
2024-09-25T20:45:36.347287 DEBUG: (985310) [] Required non-set qnodes are: ['chemical', 'disease']
2024-09-25T20:45:36.347456 INFO: (985310) [] Merging option group result graphs into required result graphs with matching non-set qnodes
2024-09-25T20:45:36.350552 DEBUG: (985310) [] There are a total of 48 final result graphs
2024-09-25T20:45:36.356722 DEBUG: (985310) [] Loading final result graphs into TRAPI object model
2024-09-25T20:45:36.376033 INFO: (985310) [] Resultify created 48 results
2024-09-25T20:45:36.377655 DEBUG: (985310) [] Cleaning up the KG to remove nodes not used in the results
2024-09-25T20:45:36.380006 INFO: (985310) [] After cleaning, the KG contains 238 nodes and 1371 edges
2024-09-25T20:45:36.380482 DEBUG: (985310) [] Identified 48 node pairs to overlay (with help of resultify)
2024-09-25T20:45:36.382494 DEBUG: (985310) [] Canonicalizing curies of relevant nodes using NodeSynonymizer
2024-09-25T20:45:36.384764 DEBUG: (985310) [] Extracting PMID lists from sqlite database for relevant nodes
2024-09-25T20:45:36.448049 DEBUG: (985310) [] Looping through 48 node pairs and calculating NGD values
2024-09-25T20:45:36.675289 INFO: (985310) [] NGD values successfully added to edges
2024-09-25T20:45:36.675394 DEBUG: (985310) [] Decorating edges with EPC info from KG2c
2024-09-25T20:45:36.676181 DEBUG: (985310) [] Identified 48 edges to decorate
2024-09-25T20:45:36.676659 DEBUG: (985310) [] Looking up EPC edge info in KG2c sqlite to decorate NGD edges
2024-09-25T20:45:36.677142 DEBUG: (985310) [] Got 0 rows back from KG2c sqlite
2024-09-25T20:45:36.677184 DEBUG: (985310) [] Adding attributes to NGD edges in the KG
2024-09-25T20:45:36.683858 DEBUG: (985310) [] Query graph is {'edges': {'N1': {'attribute_constraints': [],
                  'exclude': None,
                  'knowledge_type': None,
                  'object': 'chemical',
                  'option_group_id': None,
                  'predicates': ['biolink:occurs_together_in_literature_with'],
                  'qualifier_constraints': [],
                  'subject': 'disease'},
           'creative_DTD_qedge_0': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'creative_DTD_qnode_0',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'chemical'},
           'creative_DTD_qedge_1': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'creative_DTD_qnode_1',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'creative_DTD_qnode_0'},
           'creative_DTD_qedge_2': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'disease',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'creative_DTD_qnode_1'},
           'subclass:disease--disease': {'attribute_constraints': [],
                                         'exclude': None,
                                         'knowledge_type': None,
                                         'object': 'disease',
                                         'option_group_id': 'option_group-subclass:disease--disease',
                                         'predicates': ['biolink:subclass_of'],
                                         'qualifier_constraints': [],
                                         'subject': 'disease'},
           't_edge': {'attribute_constraints': [{'id': 'knowledge_source',
                                                 'name': 'knowledge source',
                                                 'not': False,
                                                 'operator': '==',
                                                 'unit_id': None,
                                                 'unit_name': None,
                                                 'value': ['infores:rtx-kg2']}],
                      'exclude': None,
                      'knowledge_type': 'inferred',
                      'object': 'disease',
                      'option_group_id': None,
                      'predicates': ['biolink:treats'],
                      'qualifier_constraints': [],
                      'subject': 'chemical'}},
 'nodes': {'chemical': {'categories': ['biolink:Drug', 'biolink:SmallMolecule'],
                        'constraints': [],
                        'ids': None,
                        'is_set': False,
                        'option_group_id': None,
                        'set_id': None,
                        'set_interpretation': 'BATCH'},
           'creative_DTD_qnode_0': {'categories': None,
                                    'constraints': [],
                                    'ids': None,
                                    'is_set': True,
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'set_id': None,
                                    'set_interpretation': 'BATCH'},
           'creative_DTD_qnode_1': {'categories': None,
                                    'constraints': [],
                                    'ids': None,
                                    'is_set': True,
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'set_id': None,
                                    'set_interpretation': 'BATCH'},
           'disease': {'categories': None,
                       'constraints': [],
                       'ids': ['MONDO:0015564'],
                       'is_set': False,
                       'option_group_id': None,
                       'set_id': None,
                       'set_interpretation': 'BATCH'}}}
2024-09-25T20:45:36.683966 DEBUG: (985310) [] Number of nodes in KG is 238
2024-09-25T20:45:36.684330 DEBUG: (985310) [] Number of nodes in KG by type is Counter({'biolink:SmallMolecule': 129, 'biolink:Gene': 45, 'biolink:ChemicalEntity': 18, 'biolink:Drug': 9, 'biolink:Cell': 8, 'biolink:GrossAnatomicalStructure': 8, 'biolink:Protein': 6, 'biolink:PhysiologicalProcess': 5, 'biolink:MolecularActivity': 4, 'biolink:Disease': 2, 'biolink:AnatomicalEntity': 2, 'biolink:MolecularMixture': 2})
2024-09-25T20:45:36.684368 DEBUG: (985310) [] Number of edges in KG is 1419
2024-09-25T20:45:36.685350 DEBUG: (985310) [] Number of edges in KG by type is Counter({'biolink:interacts_with': 782, 'biolink:affects': 363, 'biolink:occurs_together_in_literature_with': 48, 'biolink:treats': 47, 'biolink:located_in': 36, 'biolink:subclass_of': 33, 'biolink:physically_interacts_with': 23, 'biolink:produces': 18, 'biolink:has_part': 17, 'biolink:gene_associated_with_condition': 14, 'biolink:disrupts': 11, 'biolink:causes': 8, 'biolink:directly_physically_interacts_with': 5, 'biolink:colocalizes_with': 4, 'biolink:has_participant': 4, 'biolink:associated_with': 2, 'biolink:occurs_in': 2, 'biolink:applied_to_treat': 2})
2024-09-25T20:45:36.685908 DEBUG: (985310) [] Number of edges in KG with attributes is 1419
2024-09-25T20:45:36.690502 DEBUG: (985310) [] Number of edges in KG by attribute Counter({None: 5112, 'defined_datetime': 1416, 'normalized_google_distance': 48, 'virtual_relation_label': 48, 'probability_treats': 47, 'publications': 9})
2024-09-25T20:45:36.690568 INFO: (985310) [] Processing action 'filter_kg' with parameters {'action': 'remove_general_concept_nodes', 'perform_action': 'True'}
2024-09-25T20:45:36.695457 DEBUG: (985310) [] Removing Nodes
2024-09-25T20:45:36.695502 INFO: (985310) [] Removing nodes from the knowledge graph which are general concepts
2024-09-25T20:45:43.561951 INFO: (985310) [] Removed 5 nodes from the knowledge graph which are general concepts
2024-09-25T20:45:43.563612 DEBUG: (985310) [] Removing orphaned nodes
2024-09-25T20:45:43.563657 INFO: (985310) [] Removing orphaned nodes
2024-09-25T20:45:43.564664 DEBUG: (985310) [] Identified 0 orphan nodes to remove
2024-09-25T20:45:43.564698 INFO: (985310) [] Nodes successfully removed
2024-09-25T20:45:43.564729 INFO: (985310) [] Nodes successfully removed
2024-09-25T20:45:43.564805 DEBUG: (985310) [] Applying Overlay to Message with parameters {'action': 'remove_general_concept_nodes', 'perform_action': True}
2024-09-25T20:45:43.567312 DEBUG: (985310) [] Query graph is {'edges': {'N1': {'attribute_constraints': [],
                  'exclude': None,
                  'knowledge_type': None,
                  'object': 'chemical',
                  'option_group_id': None,
                  'predicates': ['biolink:occurs_together_in_literature_with'],
                  'qualifier_constraints': [],
                  'subject': 'disease'},
           'creative_DTD_qedge_0': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'creative_DTD_qnode_0',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'chemical'},
           'creative_DTD_qedge_1': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'creative_DTD_qnode_1',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'creative_DTD_qnode_0'},
           'creative_DTD_qedge_2': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'disease',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'creative_DTD_qnode_1'},
           'subclass:disease--disease': {'attribute_constraints': [],
                                         'exclude': None,
                                         'knowledge_type': None,
                                         'object': 'disease',
                                         'option_group_id': 'option_group-subclass:disease--disease',
                                         'predicates': ['biolink:subclass_of'],
                                         'qualifier_constraints': [],
                                         'subject': 'disease'},
           't_edge': {'attribute_constraints': [{'id': 'knowledge_source',
                                                 'name': 'knowledge source',
                                                 'not': False,
                                                 'operator': '==',
                                                 'unit_id': None,
                                                 'unit_name': None,
                                                 'value': ['infores:rtx-kg2']}],
                      'exclude': None,
                      'knowledge_type': 'inferred',
                      'object': 'disease',
                      'option_group_id': None,
                      'predicates': ['biolink:treats'],
                      'qualifier_constraints': [],
                      'subject': 'chemical'}},
 'nodes': {'chemical': {'categories': ['biolink:Drug', 'biolink:SmallMolecule'],
                        'constraints': [],
                        'ids': None,
                        'is_set': False,
                        'option_group_id': None,
                        'set_id': None,
                        'set_interpretation': 'BATCH'},
           'creative_DTD_qnode_0': {'categories': None,
                                    'constraints': [],
                                    'ids': None,
                                    'is_set': True,
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'set_id': None,
                                    'set_interpretation': 'BATCH'},
           'creative_DTD_qnode_1': {'categories': None,
                                    'constraints': [],
                                    'ids': None,
                                    'is_set': True,
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'set_id': None,
                                    'set_interpretation': 'BATCH'},
           'disease': {'categories': None,
                       'constraints': [],
                       'ids': ['MONDO:0015564'],
                       'is_set': False,
                       'option_group_id': None,
                       'set_id': None,
                       'set_interpretation': 'BATCH'}}}
2024-09-25T20:45:43.567381 DEBUG: (985310) [] Number of nodes in KG is 233
2024-09-25T20:45:43.567636 DEBUG: (985310) [] Number of nodes in KG by type is Counter({'biolink:SmallMolecule': 129, 'biolink:Gene': 45, 'biolink:ChemicalEntity': 15, 'biolink:Drug': 9, 'biolink:Cell': 8, 'biolink:GrossAnatomicalStructure': 8, 'biolink:Protein': 5, 'biolink:PhysiologicalProcess': 5, 'biolink:MolecularActivity': 4, 'biolink:Disease': 2, 'biolink:MolecularMixture': 2, 'biolink:AnatomicalEntity': 1})
2024-09-25T20:45:43.567674 DEBUG: (985310) [] Number of edges in KG is 1396
2024-09-25T20:45:43.568312 DEBUG: (985310) [] Number of edges in KG by type is Counter({'biolink:interacts_with': 776, 'biolink:affects': 358, 'biolink:occurs_together_in_literature_with': 48, 'biolink:treats': 47, 'biolink:located_in': 34, 'biolink:subclass_of': 24, 'biolink:physically_interacts_with': 23, 'biolink:produces': 18, 'biolink:has_part': 16, 'biolink:gene_associated_with_condition': 14, 'biolink:disrupts': 11, 'biolink:causes': 8, 'biolink:directly_physically_interacts_with': 5, 'biolink:colocalizes_with': 4, 'biolink:has_participant': 4, 'biolink:associated_with': 2, 'biolink:occurs_in': 2, 'biolink:applied_to_treat': 2})
2024-09-25T20:45:43.568825 DEBUG: (985310) [] Number of edges in KG with attributes is 1396
2024-09-25T20:45:43.578942 DEBUG: (985310) [] Number of edges in KG by attribute Counter({None: 5013, 'defined_datetime': 1393, 'metatype:Datetime': 1393, 'EDAM-DATA:1772': 1393, 'biolink:original_predicate': 1064, 'biolink:knowledge_level': 1064, 'biolink:agent_type': 1064, 'biolink:publications': 268, 'bts:sentence': 168, 'normalized_google_distance': 48, 'EDAM-DATA:2526': 48, 'virtual_relation_label': 48, 'EDAM-OPERATION:0226': 48, 'probability_treats': 47, 'EDAM-DATA:0951': 47, 'publications': 9, 'biolink:description': 1})
2024-09-25T20:45:43.579018 INFO: (985310) [] Processing action 'resultify' with parameters {'': 'true'}
2024-09-25T20:45:43.579059 DEBUG: (985310) [] Applying Resultifier to Message with parameters {'': 'true'}
2024-09-25T20:45:43.579092 INFO: (985310) [] Clearing previous results and computing a new set of results
2024-09-25T20:45:43.581626 DEBUG: (985310) [] Expanded qedges are {'creative_DTD_qedge_0', 'N1', 't_edge', 'subclass:disease--disease', 'creative_DTD_qedge_1', 'creative_DTD_qedge_2'}, expanded qnodes are {'chemical', 'creative_DTD_qnode_0', 'creative_DTD_qnode_1', 'disease'}; will resultify only this sub-QG
2024-09-25T20:45:43.581697 DEBUG: (985310) [] Non-kryptonite qedges are {'creative_DTD_qedge_0', 'N1', 't_edge', 'subclass:disease--disease', 'creative_DTD_qedge_1', 'creative_DTD_qedge_2'}, non-kryptonite qnodes are {'chemical', 'creative_DTD_qnode_0', 'creative_DTD_qnode_1', 'disease'}.
2024-09-25T20:45:43.586237 DEBUG: (985310) [] Grabbing only required portion of QG
2024-09-25T20:45:43.586302 DEBUG: (985310) [] Required qnodes are {'chemical', 'disease'}, required qedges are {'N1', 't_edge'}
2024-09-25T20:45:43.586402 DEBUG: (985310) [] Subclass self-qedges are {'subclass:disease--disease'}; qnodes with a subclass self-qedge are: {'disease'}
2024-09-25T20:45:43.586443 DEBUG: (985310) [] Building helper indexes for faster lookup of edges
2024-09-25T20:45:43.598142 INFO: (985310) [] Creating result graphs for required portion of QG
2024-09-25T20:45:43.599890 DEBUG: (985310) [] Constructing result graphs qnode by qnode
2024-09-25T20:45:43.599939 DEBUG: (985310) [] Qnode keys already handled are: set()
2024-09-25T20:45:43.599975 DEBUG: (985310) [] Initiating result graphs with nodes for chemical (is_set=False)
2024-09-25T20:45:43.600004 DEBUG: (985310) [] Starting with a result graph for each chemical node
2024-09-25T20:45:43.600156 DEBUG: (985310) [] Current count of result graphs is 49
2024-09-25T20:45:43.600198 DEBUG: (985310) [] Next qnode chosen is: disease
2024-09-25T20:45:43.600229 DEBUG: (985310) [] Adding a layer to each result graph for qnode disease (is_set=False)
2024-09-25T20:45:43.602627 DEBUG: (985310) [] Current count of result graphs is 48
2024-09-25T20:45:43.602670 DEBUG: (985310) [] Done assigning nodes to result graphs.
2024-09-25T20:45:43.602697 DEBUG: (985310) [] Adding edges to result graphs
2024-09-25T20:45:43.603145 DEBUG: (985310) [] After pruning out result graphs missing edges, there are 48 result graphs
2024-09-25T20:45:43.603191 DEBUG: (985310) [] Created 48 required result graphs
2024-09-25T20:45:43.603239 INFO: (985310) [] Distinct option groups detected in the QG are: {'creative_DTD_option_group_0'}
2024-09-25T20:45:43.603299 DEBUG: (985310) [] For option group creative_DTD_option_group_0, qnodes are {'chemical', 'creative_DTD_qnode_0', 'creative_DTD_qnode_1', 'disease'}, qedges are {'creative_DTD_qedge_0', 'N1', 't_edge', 'creative_DTD_qedge_1', 'creative_DTD_qedge_2'}
2024-09-25T20:45:43.603374 INFO: (985310) [] Creating result graphs for option group creative_DTD_option_group_0
2024-09-25T20:45:43.612249 DEBUG: (985310) [] Constructing result graphs qnode by qnode
2024-09-25T20:45:43.612309 DEBUG: (985310) [] Qnode keys already handled are: {'chemical', 'disease'}
2024-09-25T20:45:43.612351 DEBUG: (985310) [] Next qnode chosen is: creative_DTD_qnode_0
2024-09-25T20:45:43.612382 DEBUG: (985310) [] Adding a layer to each result graph for qnode creative_DTD_qnode_0 (is_set=True)
2024-09-25T20:45:43.616891 DEBUG: (985310) [] Current count of result graphs is 47
2024-09-25T20:45:43.616948 DEBUG: (985310) [] Next qnode chosen is: creative_DTD_qnode_1
2024-09-25T20:45:43.616979 DEBUG: (985310) [] Adding a layer to each result graph for qnode creative_DTD_qnode_1 (is_set=True)
2024-09-25T20:45:43.624637 DEBUG: (985310) [] Current count of result graphs is 47
2024-09-25T20:45:43.624682 DEBUG: (985310) [] Done assigning nodes to result graphs.
2024-09-25T20:45:43.624726 DEBUG: (985310) [] Adding edges to result graphs
2024-09-25T20:45:43.631448 DEBUG: (985310) [] After pruning out result graphs missing edges, there are 47 result graphs
2024-09-25T20:45:43.631640 DEBUG: (985310) [] Created 47 option group creative_DTD_option_group_0 result graphs
2024-09-25T20:45:43.631682 DEBUG: (985310) [] Required non-set qnodes are: ['chemical', 'disease']
2024-09-25T20:45:43.631841 INFO: (985310) [] Merging option group result graphs into required result graphs with matching non-set qnodes
2024-09-25T20:45:43.635441 DEBUG: (985310) [] There are a total of 48 final result graphs
2024-09-25T20:45:43.641471 DEBUG: (985310) [] Loading final result graphs into TRAPI object model
2024-09-25T20:45:43.776763 INFO: (985310) [] Resultify created 48 results
2024-09-25T20:45:43.778121 DEBUG: (985310) [] Cleaning up the KG to remove nodes not used in the results
2024-09-25T20:45:43.780339 INFO: (985310) [] After cleaning, the KG contains 233 nodes and 1396 edges
2024-09-25T20:45:43.780399 INFO: (985310) [] Running experimental reranker on results
2024-09-25T20:45:43.780447 DEBUG: (985310) [] Starting to rank results
2024-09-25T20:45:43.780496 DEBUG: (985310) [] Assessing the QueryGraph for basic information
2024-09-25T20:45:43.780530 DEBUG: (985310) [] Found 4 nodes and 6 edges
2024-09-25T20:45:43.781423 DEBUG: (985310) [] canonical_curies={'MONDO:0015564': {'preferred_curie': 'MONDO:0015564', 'preferred_name': 'Castleman disease', 'preferred_category': 'biolink:Disease', 'all_categories': {'biolink:Disease': 13}}}, curie=MONDO:0015564
2024-09-25T20:45:43.781509 DEBUG: (985310) [] QueryGraph has edges with no predicate. This may cause problems with results inference later
2024-09-25T20:45:43.781551 DEBUG: (985310) [] QueryGraph has edges with no predicate. This may cause problems with results inference later
2024-09-25T20:45:43.781590 DEBUG: (985310) [] QueryGraph has edges with no predicate. This may cause problems with results inference later
2024-09-25T20:45:43.781633 WARNING: (985310) [] QueryGraph appears to have a fork in it. This might cause trouble
2024-09-25T20:45:43.781664 WARNING: (985310) [] QueryGraph appears to be circular or has a strange geometry. This might cause trouble
2024-09-25T20:45:43.781700 WARNING: (985310) [] Fell into a loop in the QueryGraph. Picking an end node somewhat arbitrarily.
2024-09-25T20:45:43.781747 INFO: (985310) [] Property is_set is not true for chemical although maybe it should be to keep the query from blowing up. Consider setting is_set to true here.
2024-09-25T20:45:43.781783 INFO: (985310) [] Property is_set is not true for creative_DTD_qnode_0 although maybe it should be to keep the query from blowing up. Consider setting is_set to true here.
2024-09-25T20:45:43.781817 DEBUG: (985310) [] The QueryGraph reference template is: n00(ids)-e00()-n01(categories=biolink:Drug)-e01()-n02()-e02()-n03()
2024-09-25T20:45:43.827042 INFO: (985310) [] Summary of available edge metrics: {'probability_treats': {'minimum': 0.7219532114089924, 'maximum': 0.7643441223573989}, 'normalized_google_distance': {'minimum': 0.29685025999983256, 'maximum': 0.7126693412698298}}
2024-09-25T20:45:43.887299 DEBUG: (985310) [] Results have been ranked and sorted
2024-09-25T20:45:43.887416 INFO: (985310) [] Processing action 'filter_results' with parameters {'action': 'limit_number_of_results', 'max_results': '500'}
2024-09-25T20:45:43.887455 DEBUG: (985310) [] Before filtering, there are 48 results
2024-09-25T20:45:43.922616 DEBUG: (985310) [] Limiting Number of Results
2024-09-25T20:45:43.922671 INFO: (985310) [] Filtering excess results above max result limit
2024-09-25T20:45:43.926145 INFO: (985310) [] KG successfully pruned to match results
2024-09-25T20:45:43.926221 INFO: (985310) [] Successfully limited the number of results
2024-09-25T20:45:43.926260 DEBUG: (985310) [] Applying Overlay to Message with parameters {'action': 'limit_number_of_results', 'max_results': 500, 'prune_kg': True}
2024-09-25T20:45:43.928796 DEBUG: (985310) [] Query graph is {'edges': {'N1': {'attribute_constraints': [],
                  'exclude': None,
                  'knowledge_type': None,
                  'object': 'chemical',
                  'option_group_id': None,
                  'predicates': ['biolink:occurs_together_in_literature_with'],
                  'qualifier_constraints': [],
                  'subject': 'disease'},
           'creative_DTD_qedge_0': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'creative_DTD_qnode_0',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'chemical'},
           'creative_DTD_qedge_1': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'creative_DTD_qnode_1',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'creative_DTD_qnode_0'},
           'creative_DTD_qedge_2': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'disease',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'creative_DTD_qnode_1'},
           'subclass:disease--disease': {'attribute_constraints': [],
                                         'exclude': None,
                                         'knowledge_type': None,
                                         'object': 'disease',
                                         'option_group_id': 'option_group-subclass:disease--disease',
                                         'predicates': ['biolink:subclass_of'],
                                         'qualifier_constraints': [],
                                         'subject': 'disease'},
           't_edge': {'attribute_constraints': [{'id': 'knowledge_source',
                                                 'name': 'knowledge source',
                                                 'not': False,
                                                 'operator': '==',
                                                 'unit_id': None,
                                                 'unit_name': None,
                                                 'value': ['infores:rtx-kg2']}],
                      'exclude': None,
                      'knowledge_type': 'inferred',
                      'object': 'disease',
                      'option_group_id': None,
                      'predicates': ['biolink:treats'],
                      'qualifier_constraints': [],
                      'subject': 'chemical'}},
 'nodes': {'chemical': {'categories': ['biolink:Drug', 'biolink:SmallMolecule'],
                        'constraints': [],
                        'ids': None,
                        'is_set': False,
                        'option_group_id': None,
                        'set_id': None,
                        'set_interpretation': 'BATCH'},
           'creative_DTD_qnode_0': {'categories': None,
                                    'constraints': [],
                                    'ids': None,
                                    'is_set': True,
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'set_id': None,
                                    'set_interpretation': 'BATCH'},
           'creative_DTD_qnode_1': {'categories': None,
                                    'constraints': [],
                                    'ids': None,
                                    'is_set': True,
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'set_id': None,
                                    'set_interpretation': 'BATCH'},
           'disease': {'categories': None,
                       'constraints': [],
                       'ids': ['MONDO:0015564'],
                       'is_set': False,
                       'option_group_id': None,
                       'set_id': None,
                       'set_interpretation': 'BATCH'}}}
2024-09-25T20:45:43.928870 DEBUG: (985310) [] Number of nodes in KG is 233
2024-09-25T20:45:43.929183 DEBUG: (985310) [] Number of nodes in KG by type is Counter({'biolink:SmallMolecule': 129, 'biolink:Gene': 45, 'biolink:ChemicalEntity': 15, 'biolink:Drug': 9, 'biolink:Cell': 8, 'biolink:GrossAnatomicalStructure': 8, 'biolink:Protein': 5, 'biolink:PhysiologicalProcess': 5, 'biolink:MolecularActivity': 4, 'biolink:Disease': 2, 'biolink:MolecularMixture': 2, 'biolink:AnatomicalEntity': 1})
2024-09-25T20:45:43.929220 DEBUG: (985310) [] Number of edges in KG is 1393
2024-09-25T20:45:43.929871 DEBUG: (985310) [] Number of edges in KG by type is Counter({'biolink:interacts_with': 774, 'biolink:affects': 358, 'biolink:occurs_together_in_literature_with': 48, 'biolink:treats': 47, 'biolink:located_in': 34, 'biolink:physically_interacts_with': 23, 'biolink:subclass_of': 23, 'biolink:produces': 18, 'biolink:has_part': 16, 'biolink:gene_associated_with_condition': 14, 'biolink:disrupts': 11, 'biolink:causes': 8, 'biolink:directly_physically_interacts_with': 5, 'biolink:colocalizes_with': 4, 'biolink:has_participant': 4, 'biolink:associated_with': 2, 'biolink:occurs_in': 2, 'biolink:applied_to_treat': 2})
2024-09-25T20:45:43.930384 DEBUG: (985310) [] Number of edges in KG with attributes is 1393
2024-09-25T20:45:43.934822 DEBUG: (985310) [] Number of edges in KG by attribute Counter({None: 5004, 'defined_datetime': 1391, 'normalized_google_distance': 48, 'virtual_relation_label': 48, 'probability_treats': 47, 'publications': 9})
2024-09-25T20:45:43.934893 INFO: (985310) [] Transforming results to TRAPI 1.5 format (moving 'virtual' nodes/edges to support graphs)
2024-09-25T20:45:43.934941 DEBUG: (985310) [] Original input QG contained qnodes {'chemical', 'disease'} and qedges {'t_edge'}
2024-09-25T20:45:43.934973 DEBUG: (985310) [] Non-orphan qnodes in original QG are: {'chemical', 'disease'}
2024-09-25T20:45:43.942220 DEBUG: (985310) [] Replacing ARAX's internal edited QG with the original input QG..
2024-09-25T20:45:43.942281 DEBUG: (985310) [] Virtual qedge keys moved to support_graphs were: {'creative_DTD_qedge_2', 'N1', 'creative_DTD_qedge_0', 'creative_DTD_qedge_1'}
2024-09-25T20:45:43.942313 DEBUG: (985310) [] There are a total of 95 AuxiliaryGraphs.
2024-09-25T20:45:43.942342 INFO: (985310) [] Done transforming results to TRAPI 1.5 format (i.e., using support_graphs)
2024-09-25T20:45:43.942420 DEBUG: (985310) [] Storing resulting Message
2024-09-25T20:45:43.942482 DEBUG: (985310) [] Writing response record to MySQL
INFO: Attempting to write to S3 bucket us-east-1:arax-response-storage-2:/responses/303125.json
2024-09-25T20:45:44.881007 INFO: (985310) [] INFO: Successfully wrote /responses/303125.json to us-east-1 S3 bucket arax-response-storage-2 in 0.35766600724309683 seconds
2024-09-25T20:45:44.883632 INFO: (985310) [] Result was stored with id 303125. It can be viewed at https://arax.ncats.io/?r=303125
2024-09-25T20:45:44.883690 INFO: (985310) [] Processing is complete and resulted in 48 results.
2024-09-25T20:45:44.883722 INFO: (985310) [] Processing is complete. Transmitting resulting Message back to client.
----------------------------------------------------------------------------------------- Captured log call -----------------------------------------------------------------------------------------
INFO     log:ExplianableDTD_db.py:109 Connecting to database
========================================================================================= warnings summary ==========================================================================================
../../../../../../python/Python-3.9.18/lib/python3.9/site-packages/connexion/decorators/validation.py:16
../../../../../../python/Python-3.9.18/lib/python3.9/site-packages/connexion/decorators/validation.py:16
  /mnt/data/python/Python-3.9.18/lib/python3.9/site-packages/connexion/decorators/validation.py:16: DeprecationWarning: Accessing jsonschema.draft4_format_checker is deprecated and will be removed in a future release. Instead, use the FORMAT_CHECKER attribute on the corresponding Validator.
    from jsonschema import Draft4Validator, ValidationError, draft4_format_checker

../ARAXQuery/ARAX_query_tracker.py:29
  /mnt/data/orangeboard/test/RTX/code/ARAX/ARAXQuery/ARAX_query_tracker.py:29: MovedIn20Warning: Deprecated API features detected! These feature(s) are not compatible with SQLAlchemy 2.0. To prevent incompatible upgrades prior to updating applications, ensure requirements files are pinned to "sqlalchemy<2.0". Set environment variable SQLALCHEMY_WARN_20=1 to show all deprecation warnings.  Set environment variable SQLALCHEMY_SILENCE_UBER_WARNING=1 to silence this message. (Background on SQLAlchemy 2.0 at: https://sqlalche.me/e/b8d9)
    Base = declarative_base()

../../../../../../python/Python-3.9.18/lib/python3.9/site-packages/pydantic/_internal/_config.py:284
  /mnt/data/python/Python-3.9.18/lib/python3.9/site-packages/pydantic/_internal/_config.py:284: PydanticDeprecatedSince20: Support for class-based `config` is deprecated, use ConfigDict instead. Deprecated in Pydantic V2.0 to be removed in V3.0. See Pydantic V2 Migration Guide at https://errors.pydantic.dev/2.7/migration/
    warnings.warn(DEPRECATION_MESSAGE, DeprecationWarning)

test_ARAX_expand.py::test_treats_patch_issue_2328
  /mnt/data/orangeboard/test/RTX/code/ARAX/ARAXQuery/Expand/trapi_querier.py:253: DeprecationWarning: verify_ssl is deprecated, use ssl=False instead
    async with aiohttp.ClientSession(connector=aiohttp.TCPConnector(verify_ssl=False)) as session:

test_ARAX_expand.py: 96 warnings
  /mnt/data/python/Python-3.9.18/lib/python3.9/site-packages/networkx/convert_matrix.py:579: DeprecationWarning: to_numpy_matrix is deprecated and will be removed in NetworkX 3.0.
  Use to_numpy_array instead, e.g. np.asmatrix(to_numpy_array(G, **kwargs))
    warnings.warn(

test_ARAX_expand.py: 96 warnings
  /mnt/data/python/Python-3.9.18/lib/python3.9/site-packages/numpy/matrixlib/defmatrix.py:69: PendingDeprecationWarning: the matrix subclass is not the recommended way to represent matrices or deal with linear algebra (see https://docs.scipy.org/doc/numpy/user/numpy-for-matlab-users.html). Please adjust your code to use regular ndarray.
    return matrix(data, dtype=dtype, copy=False)

-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html
====================================================================================== short test summary info ======================================================================================
FAILED test_ARAX_expand.py::test_treats_patch_issue_2328 - AssertionError: assert 'biolink:applied_to_treat' == 'biolink:treats'
========================================================================== 1 failed, 71 deselected, 197 warnings in 16.79s ==========================================================================
amykglen commented 1 month ago

thanks - so it's not a wrong-KG2-url situation, debugging further..

amykglen commented 1 month ago

I'm really perplexed by this - still can't reproduce it locally. so there are no local changes or anything on arax.ncats.io?

I just added more logging to master that might help provide more insight...

edeutsch commented 1 month ago

okay, thanks. there probably is local change that is not desirable on arax.ncats.io, but I don't know what it might be.. I just did a git pull

 code/ARAX/ARAXQuery/ARAX_expander.py | 4 ++++
 code/ARAX/test/test_ARAX_connect.py  | 3 +--

and reran the test

rt@4342e0c91621:/mnt/data/orangeboard/test/RTX/code/ARAX/test$ pytest -v test_ARAX_expand.py -k test_treats_patch_issue_2328
Running database manager to check for missing databases..
Downloading any missing databases from arax-databases.rtx.ai to /mnt/data/orangeboard/databases
On database cohd_database in _download_to_mnt()
  Database already exists, no need to download
On database curie_to_pmids in _download_to_mnt()
  Database already exists, no need to download
On database curie_ngd in _download_to_mnt()
  Database already exists, no need to download
On database node_synonymizer in _download_to_mnt()
  Database already exists, no need to download
On database kg2c_sqlite in _download_to_mnt()
  Database already exists, no need to download
On database kg2c_meta_kg in _download_to_mnt()
  Database already exists, no need to download
On database fda_approved_drugs in _download_to_mnt()
  Database already exists, no need to download
On database autocomplete in _download_to_mnt()
  Database already exists, no need to download
On database explainable_dtd_db in _download_to_mnt()
  Database already exists, no need to download
On database xcrg_embeddings in _download_to_mnt()
  Database already exists, no need to download
On database xcrg_increase_model in _download_to_mnt()
  Database already exists, no need to download
On database xcrg_decrease_model in _download_to_mnt()
  Database already exists, no need to download
Local version of cohd_database (/mnt/data/orangeboard/test/RTX/code/ARAX/KnowledgeSources/COHD_local/data/COHDdatabase_v1.0_KG2.8.0.db) matches the remote version, skipping...
Local version of curie_to_pmids (/mnt/data/orangeboard/test/RTX/code/ARAX/KnowledgeSources/NormalizedGoogleDistance/curie_to_pmids_v1.0_KG2.10.0.sqlite) matches the remote version, skipping...
Local version of curie_ngd (/mnt/data/orangeboard/test/RTX/code/ARAX/KnowledgeSources/NormalizedGoogleDistance/curie_ngd_v1.0_KG2.10.0.sqlite) matches the remote version, skipping...
Local version of node_synonymizer (/mnt/data/orangeboard/test/RTX/code/ARAX/NodeSynonymizer/node_synonymizer_v1.0_KG2.10.0.sqlite) matches the remote version, skipping...
Local version of kg2c_sqlite (/mnt/data/orangeboard/test/RTX/code/ARAX/KnowledgeSources/KG2c/kg2c_v1.0_KG2.10.0.sqlite) matches the remote version, skipping...
Local version of kg2c_meta_kg (/mnt/data/orangeboard/test/RTX/code/ARAX/KnowledgeSources/meta_kg_v1.0_KG2.10.0c.json) matches the remote version, skipping...
Local version of fda_approved_drugs (/mnt/data/orangeboard/test/RTX/code/ARAX/KnowledgeSources/fda_approved_drugs_v1.0_KG2.10.0c.pickle) matches the remote version, skipping...
Local version of autocomplete (/mnt/data/orangeboard/test/RTX/code/autocomplete/autocomplete_v1.0_KG2.10.0.sqlite) matches the remote version, skipping...
Local version of explainable_dtd_db (/mnt/data/orangeboard/test/RTX/code/ARAX/KnowledgeSources/Prediction/ExplainableDTD_v1.0_KG2.10.0.db) matches the remote version, skipping...
Local version of xcrg_embeddings (/mnt/data/orangeboard/test/RTX/code/ARAX/ARAXQuery/Infer/data/xCRG_data/chemical_gene_embeddings_v1.0.KG2.10.0.npz) matches the remote version, skipping...
Local version of xcrg_increase_model (/mnt/data/orangeboard/test/RTX/code/ARAX/ARAXQuery/Infer/data/xCRG_data/xcrg_increase_model_v1.0.KG2.10.0.pt) matches the remote version, skipping...
Local version of xcrg_decrease_model (/mnt/data/orangeboard/test/RTX/code/ARAX/ARAXQuery/Infer/data/xCRG_data/xcrg_decrease_model_v1.0.KG2.10.0.pt) matches the remote version, skipping...
KP info cache is up to date.
======================================================================================== test session starts ========================================================================================
platform linux -- Python 3.9.18, pytest-7.2.2, pluggy-1.4.0 -- /mnt/data/python/Python-3.9.18/bin/python3.9
cachedir: .pytest_cache
rootdir: /mnt/data/orangeboard/test/RTX/code/ARAX/test
plugins: cov-4.1.0, anyio-4.4.0
collected 72 items / 71 deselected / 1 selected                                                                                                                                                     

test_ARAX_expand.py::test_treats_patch_issue_2328 FAILED                                                                                                                                      [100%]

============================================================================================= FAILURES ==============================================================================================
___________________________________________________________________________________ test_treats_patch_issue_2328 ____________________________________________________________________________________

    def test_treats_patch_issue_2328():
        query = {
            "nodes": {
                "disease": {
                    "ids": ["MONDO:0015564"]
                },
                "chemical": {
                    "categories": ["biolink:ChemicalEntity"]
                }
            },
            "edges": {
                "t_edge": {
                    "object": "disease",
                    "subject": "chemical",
                    "predicates": ["biolink:treats"],
                    "knowledge_type": "inferred",
                    "attribute_constraints": [
                        {
                            "id": "knowledge_source",
                            "name": "knowledge source",
                            "value": ["infores:rtx-kg2"],
                            "operator": "=="
                        }
                    ]
                }
            }
        }
        nodes_by_qg_id, edges_by_qg_id = _run_query_and_do_standard_testing(json_query=query)
        assert edges_by_qg_id["t_edge"]
        kg2_edges_treats = [edge for edge in edges_by_qg_id["t_edge"].values()
                            if any(source.resource_id == "infores:rtx-kg2" for source in edge.sources)]
        print(f"Answer includes {len(kg2_edges_treats)} edges from KG2")
        assert kg2_edges_treats
        print(kg2_edges_treats)
        for edge in kg2_edges_treats:
>           assert edge.predicate == "biolink:treats"
E           AssertionError: assert 'biolink:applied_to_treat' == 'biolink:treats'
E             - biolink:treats
E             + biolink:applied_to_treat

test_ARAX_expand.py:1542: AssertionError
--------------------------------------------------------------------------------------- Captured stdout call ----------------------------------------------------------------------------------------
2024-09-26 00:03:43  [INFO]  Connecting to database
Connecting to database
Disconnecting from database
DEBUG: Datetime now is: 2024-09-26 00:03:55.934616
DEBUG: Cutover date is: 2024-02-16 22:50:00
DEBUG: Since we're after the cutover date, use new us-east-1 S3 bucket arax-response-storage-2
Answer includes 2 edges from KG2
[{'attributes': [{'attribute_source': None,
                 'attribute_type_id': 'biolink:original_predicate',
                 'attributes': None,
                 'description': 'The IDs of the original RTX-KG2pre edge(s) '
                                'corresponding to this edge prior to any '
                                'synonymization or remapping.',
                 'original_attribute_name': None,
                 'value': ['DrugCentral:4977---DrugCentral:indication---None---None---None---DOID:0111157---DrugCentral:'],
                 'value_type_id': 'metatype:String',
                 'value_url': None},
                {'attribute_source': 'infores:rtx-kg2',
                 'attribute_type_id': 'biolink:knowledge_level',
                 'attributes': None,
                 'description': None,
                 'original_attribute_name': None,
                 'value': 'knowledge_assertion',
                 'value_type_id': None,
                 'value_url': None},
                {'attribute_source': 'infores:rtx-kg2',
                 'attribute_type_id': 'biolink:agent_type',
                 'attributes': None,
                 'description': None,
                 'original_attribute_name': None,
                 'value': 'manual_agent',
                 'value_type_id': None,
                 'value_url': None}],
 'object': 'MONDO:0015564',
 'predicate': 'biolink:applied_to_treat',
 'qualifiers': None,
 'sources': [{'resource_id': 'infores:drugcentral',
              'resource_role': 'primary_knowledge_source',
              'source_record_urls': None,
              'upstream_resource_ids': None},
             {'resource_id': 'infores:rtx-kg2',
              'resource_role': 'aggregator_knowledge_source',
              'source_record_urls': None,
              'upstream_resource_ids': ['infores:drugcentral']},
             {'resource_id': 'infores:arax',
              'resource_role': 'aggregator_knowledge_source',
              'source_record_urls': None,
              'upstream_resource_ids': ['infores:rtx-kg2']}],
 'subject': 'UNII:T4H8FMA7IM'}, {'attributes': [{'attribute_source': None,
                 'attribute_type_id': 'biolink:original_predicate',
                 'attributes': None,
                 'description': 'The IDs of the original RTX-KG2pre edge(s) '
                                'corresponding to this edge prior to any '
                                'synonymization or remapping.',
                 'original_attribute_name': None,
                 'value': ['DrugCentral:4933---DrugCentral:indication---None---None---None---DOID:0111157---DrugCentral:'],
                 'value_type_id': 'metatype:String',
                 'value_url': None},
                {'attribute_source': 'infores:rtx-kg2',
                 'attribute_type_id': 'biolink:knowledge_level',
                 'attributes': None,
                 'description': None,
                 'original_attribute_name': None,
                 'value': 'knowledge_assertion',
                 'value_type_id': None,
                 'value_url': None},
                {'attribute_source': 'infores:rtx-kg2',
                 'attribute_type_id': 'biolink:agent_type',
                 'attributes': None,
                 'description': None,
                 'original_attribute_name': None,
                 'value': 'manual_agent',
                 'value_type_id': None,
                 'value_url': None}],
 'object': 'MONDO:0015564',
 'predicate': 'biolink:applied_to_treat',
 'qualifiers': None,
 'sources': [{'resource_id': 'infores:drugcentral',
              'resource_role': 'primary_knowledge_source',
              'source_record_urls': None,
              'upstream_resource_ids': None},
             {'resource_id': 'infores:rtx-kg2',
              'resource_role': 'aggregator_knowledge_source',
              'source_record_urls': None,
              'upstream_resource_ids': ['infores:drugcentral']},
             {'resource_id': 'infores:arax',
              'resource_role': 'aggregator_knowledge_source',
              'source_record_urls': None,
              'upstream_resource_ids': ['infores:rtx-kg2']}],
 'subject': 'PUBCHEM.COMPOUND:10150081'}]
--------------------------------------------------------------------------------------- Captured stderr call ----------------------------------------------------------------------------------------
2024-09-26T00:03:43.266748 INFO: (991797) [] ARAX Query launching on incoming Query
2024-09-26T00:03:43.266840 DEBUG: (991797) [] RTXConfiguration says maturity=development, current_branch=master, is_itrb_instance=False, arax_version=1.5.3, trapi_version=1.5.0
2024-09-26T00:03:43.266879 INFO: (991797) [] Creating an empty template TRAPI Response
2024-09-26T00:03:43.267055: DEBUG: In BiolinkHelper init
2024-09-26T00:03:43.269316: DEBUG: Loading BL lookup map...
2024-09-26T00:03:43.269370: DEBUG: Loading pickle file: /mnt/data/orangeboard/test/RTX/code/ARAX/BiolinkHelper/biolink_lookup_map_4.2.1_v4.pickle
2024-09-26T00:03:43.271436: DEBUG: Done loading BL lookup map
2024-09-26T00:03:43.274081 INFO: (991797) [] Examine input Query for needed information for dispatch
2024-09-26T00:03:43.274129 INFO: (991797) [] Validating the input query graph
2024-09-26T00:03:43.274166 DEBUG: (991797) [] Deserializing message
2024-09-26T00:03:43.274439 INFO: (991797) [] Found input query_graph. Interpreting it and generating ARAXi processing plan to answer it
2024-09-26T00:03:43.338028 DEBUG: (991797) [] Assessing the QueryGraph for basic information
2024-09-26T00:03:43.338082 DEBUG: (991797) [] Found 2 nodes and 1 edges
2024-09-26T00:03:43.339053 DEBUG: (991797) [] canonical_curies={'MONDO:0015564': {'preferred_curie': 'MONDO:0015564', 'preferred_name': 'Castleman disease', 'preferred_category': 'biolink:Disease', 'all_categories': {'biolink:Disease': 13}}}, curie=MONDO:0015564
2024-09-26T00:03:43.339150 DEBUG: (991797) [] The QueryGraph reference template is: n00(ids)-e00()-n01(categories=biolink:ChemicalEntity)
2024-09-26T00:03:43.339794 INFO: (991797) [] Found input processing plan. Sending to the ProcessingPlanExecutor
2024-09-26T00:03:43.339836 DEBUG: (991797) [] Entering execute_processing_plan
2024-09-26T00:03:43.339950 DEBUG: (991797) [] Connecting to ResponseCache
2024-09-26T00:03:43.401795 DEBUG: (991797) [] Creating ARAXMessenger instance
2024-09-26T00:03:43.401870 DEBUG: (991797) [] A single Message is ready and in hand
2024-09-26T00:03:43.402400 DEBUG: (991797) [] Saving original query graph (has qnodes {'chemical', 'disease'} and qedges {'t_edge'})..
2024-09-26T00:03:43.402440 DEBUG: (991797) [] Found actions
2024-09-26T00:03:43.402523 INFO: (991797) [] Parsing input actions list
2024-09-26T00:03:43.402554 DEBUG: (991797) [] Parsing action: expand()
2024-09-26T00:03:43.403358 DEBUG: (991797) [] Parsing action: overlay(action=compute_ngd, virtual_relation_label=N1, subject_qnode_key=disease, object_qnode_key=chemical)
2024-09-26T00:03:43.403434 DEBUG: (991797) [] Parsing action: filter_kg(action=remove_general_concept_nodes,perform_action=True)
2024-09-26T00:03:43.403488 DEBUG: (991797) [] Parsing action: resultify()
2024-09-26T00:03:43.403535 DEBUG: (991797) [] Parsing action: filter_results(action=limit_number_of_results, max_results=500)
2024-09-26T00:03:43.539890: DEBUG: In BiolinkHelper init
2024-09-26T00:03:43.542226: DEBUG: Loading BL lookup map...
2024-09-26T00:03:43.542283: DEBUG: Loading pickle file: /mnt/data/orangeboard/test/RTX/code/ARAX/BiolinkHelper/biolink_lookup_map_4.2.1_v4.pickle
2024-09-26T00:03:43.545297: DEBUG: Done loading BL lookup map
2024-09-26T00:03:43.545749 INFO: (991797) [] Processing action 'expand' with parameters {'': 'true'}
2024-09-26T00:03:43.545956 DEBUG: (991797) [] Loading cached Smart API amd meta map info
2024-09-26T00:03:43.557702: DEBUG: In BiolinkHelper init
2024-09-26T00:03:43.561696: DEBUG: Loading BL lookup map...
2024-09-26T00:03:43.561780: DEBUG: Loading pickle file: /mnt/data/orangeboard/test/RTX/code/ARAX/BiolinkHelper/biolink_lookup_map_4.2.1_v4.pickle
2024-09-26T00:03:43.563894: DEBUG: Done loading BL lookup map
2024-09-26T00:03:43.564527 DEBUG: (991797) [] Applying Expand to Message with parameters {'kp': None, 'edge_key': ['t_edge'], 'node_key': [], 'prune_threshold': None, 'kp_timeout': None, 'return_minimal_metadata': False}
2024-09-26T00:03:43.564843 DEBUG: (991797) [] Sending NodeSynonymizer.get_canonical_curies() a list of 1 curies
2024-09-26T00:03:43.565275 DEBUG: (991797) [] Got response back from NodeSynonymizer
2024-09-26T00:03:43.565471 DEBUG: (991797) [] Inferred category for qnode disease is ['biolink:Disease']
2024-09-26T00:03:43.565521 DEBUG: (991797) [] Making sure QG only uses canonical predicates
2024-09-26T00:03:43.566205 DEBUG: (991797) [] Query graph for this Expand() call is: {'nodes': {'chemical': {'ids': None, 'categories': ['biolink:ChemicalEntity'], 'is_set': False, 'set_interpretation': 'BATCH', 'set_id': None, 'constraints': [], 'option_group_id': None}, 'disease': {'ids': ['MONDO:0015564'], 'categories': ['biolink:DiseaseOrPhenotypicFeature', 'biolink:Disease', 'biolink:PhenotypicFeature'], 'is_set': False, 'set_interpretation': 'BATCH', 'set_id': None, 'constraints': [], 'option_group_id': None}}, 'edges': {'t_edge': {'knowledge_type': 'inferred', 'predicates': ['biolink:treats'], 'subject': 'chemical', 'object': 'disease', 'attribute_constraints': [{'id': 'knowledge_source', 'name': 'knowledge source', 'not': False, 'operator': '==', 'value': ['infores:rtx-kg2'], 'unit_id': None, 'unit_name': None}], 'qualifier_constraints': [], 'exclude': None, 'option_group_id': None}}}
2024-09-26T00:03:43.566335 DEBUG: (991797) [] knowledge_type='inferred' qedges were detected (t_edge); will determine which model to consult based on the category of source qnode and object qnode, as well as predicate.
2024-09-26T00:03:43.566381 INFO: (991797) [] Calling XDTD from Expand for qedge t_edge (has knowledge_type == inferred) and the subject is MONDO:0015564
2024-09-26T00:03:43.567282: DEBUG: In BiolinkHelper init
2024-09-26T00:03:43.569530: DEBUG: Loading BL lookup map...
2024-09-26T00:03:43.569583: DEBUG: Loading pickle file: /mnt/data/orangeboard/test/RTX/code/ARAX/BiolinkHelper/biolink_lookup_map_4.2.1_v4.pickle
2024-09-26T00:03:43.571640: DEBUG: Done loading BL lookup map
2024-09-26T00:03:43.572146 DEBUG: (991797) [] Get equivalent curies ['MONDO:0015564', 'DOID:0111157', 'orphanet:160', 'UMLS:C0017531', 'UMLS:C2931179', 'MESH:C536362', 'MESH:D005871', 'MEDDRA:10050251', 'NCIT:C3056', 'SNOMEDCT:207036003', 'SNOMEDCT:781094002', 'ICD10:D47.Z2', 'CHV:0000001174'] from Node Synonymizer for MONDO:0015564
2024-09-26T00:03:44.106091: DEBUG: In BiolinkHelper init
2024-09-26T00:03:44.108158: DEBUG: Loading BL lookup map...
2024-09-26T00:03:44.108217: DEBUG: Loading pickle file: /mnt/data/orangeboard/test/RTX/code/ARAX/BiolinkHelper/biolink_lookup_map_4.2.1_v4.pickle
2024-09-26T00:03:44.110097: DEBUG: Done loading BL lookup map
2024-09-26T00:03:44.112973 INFO: (991797) [] Adding a QueryNode to Message with input parameters {'key': 'creative_DTD_qnode_0', 'ids': None, 'name': None, 'categories': None, 'is_set': 'true', 'option_group_id': 'creative_DTD_option_group_0'}
2024-09-26T00:03:44.113270 INFO: (991797) [] Adding a QueryNode to Message with input parameters {'key': 'creative_DTD_qnode_1', 'ids': None, 'name': None, 'categories': None, 'is_set': 'true', 'option_group_id': 'creative_DTD_option_group_0'}
2024-09-26T00:03:44.113544 INFO: (991797) [] Adding a QueryEdge to Message with parameters {'key': 'creative_DTD_qedge_0', 'subject': 'chemical', 'object': 'creative_DTD_qnode_0', 'predicates': None, 'option_group_id': 'creative_DTD_option_group_0', 'exclude': None}
2024-09-26T00:03:44.113619 INFO: (991797) [] Adding a QueryEdge to Message with parameters {'key': 'creative_DTD_qedge_1', 'subject': 'creative_DTD_qnode_0', 'object': 'creative_DTD_qnode_1', 'predicates': None, 'option_group_id': 'creative_DTD_option_group_0', 'exclude': None}
2024-09-26T00:03:44.113678 INFO: (991797) [] Adding a QueryEdge to Message with parameters {'key': 'creative_DTD_qedge_2', 'subject': 'creative_DTD_qnode_1', 'object': 'disease', 'predicates': None, 'option_group_id': 'creative_DTD_option_group_0', 'exclude': None}
2024-09-26T00:03:47.252016 DEBUG: (991797) [] Decorating nodes with metadata from KG2c
2024-09-26T00:03:47.252392 DEBUG: (991797) [] Looking up corresponding KG2c nodes in sqlite
2024-09-26T00:03:47.260475 DEBUG: (991797) [] Adding attributes to nodes in the KG
2024-09-26T00:03:47.393564 DEBUG: (991797) [] Decorating edges with EPC info from KG2c
2024-09-26T00:03:47.398062 DEBUG: (991797) [] Identified 1321 edges to decorate
2024-09-26T00:03:47.406026 DEBUG: (991797) [] Looking up EPC edge info in KG2c sqlite
2024-09-26T00:03:47.406075 DEBUG: (991797) [] Looking up corresponding KG2c nodes in sqlite
2024-09-26T00:03:47.423256 DEBUG: (991797) [] Got 1080 rows back from KG2c sqlite
2024-09-26T00:03:47.423342 DEBUG: (991797) [] Adding attributes to edges in the KG
2024-09-26T00:03:47.746697 DEBUG: (991797) [] Applying Resultifier to Message with parameters {'ignore_edge_direction': 'true'}
2024-09-26T00:03:47.746852 DEBUG: (991797) [] Expanded qedges are {'creative_DTD_qedge_0', 'creative_DTD_qedge_1', 'creative_DTD_qedge_2', 't_edge'}, expanded qnodes are {'creative_DTD_qnode_1', 'creative_DTD_qnode_0', 'chemical', 'disease'}; will resultify only this sub-QG
2024-09-26T00:03:47.746913 DEBUG: (991797) [] Non-kryptonite qedges are {'creative_DTD_qedge_0', 'creative_DTD_qedge_1', 'creative_DTD_qedge_2', 't_edge'}, non-kryptonite qnodes are {'creative_DTD_qnode_1', 'creative_DTD_qnode_0', 'chemical', 'disease'}.
2024-09-26T00:03:47.751577 DEBUG: (991797) [] Grabbing only required portion of QG
2024-09-26T00:03:47.751642 DEBUG: (991797) [] Required qnodes are {'chemical', 'disease'}, required qedges are {'t_edge'}
2024-09-26T00:03:47.751713 DEBUG: (991797) [] Subclass self-qedges are set(); qnodes with a subclass self-qedge are: set()
2024-09-26T00:03:47.751750 DEBUG: (991797) [] Building helper indexes for faster lookup of edges
2024-09-26T00:03:47.877479 INFO: (991797) [] Creating result graphs for required portion of QG
2024-09-26T00:03:47.879313 DEBUG: (991797) [] Constructing result graphs qnode by qnode
2024-09-26T00:03:47.879365 DEBUG: (991797) [] Qnode keys already handled are: set()
2024-09-26T00:03:47.879403 DEBUG: (991797) [] Initiating result graphs with nodes for chemical (is_set=False)
2024-09-26T00:03:47.879432 DEBUG: (991797) [] Starting with a result graph for each chemical node
2024-09-26T00:03:47.879568 DEBUG: (991797) [] Current count of result graphs is 47
2024-09-26T00:03:47.879608 DEBUG: (991797) [] Next qnode chosen is: disease
2024-09-26T00:03:47.879638 DEBUG: (991797) [] Adding a layer to each result graph for qnode disease (is_set=False)
2024-09-26T00:03:47.882043 DEBUG: (991797) [] Current count of result graphs is 47
2024-09-26T00:03:47.882083 DEBUG: (991797) [] Done assigning nodes to result graphs.
2024-09-26T00:03:47.882110 DEBUG: (991797) [] Adding edges to result graphs
2024-09-26T00:03:47.882396 DEBUG: (991797) [] After pruning out result graphs missing edges, there are 47 result graphs
2024-09-26T00:03:47.882439 DEBUG: (991797) [] Created 47 required result graphs
2024-09-26T00:03:47.882518 INFO: (991797) [] Distinct option groups detected in the QG are: {'creative_DTD_option_group_0'}
2024-09-26T00:03:47.882580 DEBUG: (991797) [] For option group creative_DTD_option_group_0, qnodes are {'creative_DTD_qnode_1', 'creative_DTD_qnode_0', 'chemical', 'disease'}, qedges are {'creative_DTD_qedge_0', 'creative_DTD_qedge_1', 'creative_DTD_qedge_2', 't_edge'}
2024-09-26T00:03:47.882659 INFO: (991797) [] Creating result graphs for option group creative_DTD_option_group_0
2024-09-26T00:03:47.890999 DEBUG: (991797) [] Constructing result graphs qnode by qnode
2024-09-26T00:03:47.891057 DEBUG: (991797) [] Qnode keys already handled are: {'chemical', 'disease'}
2024-09-26T00:03:47.891097 DEBUG: (991797) [] Next qnode chosen is: creative_DTD_qnode_1
2024-09-26T00:03:47.891127 DEBUG: (991797) [] Adding a layer to each result graph for qnode creative_DTD_qnode_1 (is_set=True)
2024-09-26T00:03:47.894917 DEBUG: (991797) [] Current count of result graphs is 47
2024-09-26T00:03:47.894973 DEBUG: (991797) [] Next qnode chosen is: creative_DTD_qnode_0
2024-09-26T00:03:47.895004 DEBUG: (991797) [] Adding a layer to each result graph for qnode creative_DTD_qnode_0 (is_set=True)
2024-09-26T00:03:47.905515 DEBUG: (991797) [] Current count of result graphs is 47
2024-09-26T00:03:47.905561 DEBUG: (991797) [] Done assigning nodes to result graphs.
2024-09-26T00:03:47.905606 DEBUG: (991797) [] Adding edges to result graphs
2024-09-26T00:03:47.912459 DEBUG: (991797) [] After pruning out result graphs missing edges, there are 47 result graphs
2024-09-26T00:03:47.912647 DEBUG: (991797) [] Created 47 option group creative_DTD_option_group_0 result graphs
2024-09-26T00:03:47.912688 DEBUG: (991797) [] Required non-set qnodes are: ['chemical', 'disease']
2024-09-26T00:03:47.912852 INFO: (991797) [] Merging option group result graphs into required result graphs with matching non-set qnodes
2024-09-26T00:03:47.916074 DEBUG: (991797) [] There are a total of 47 final result graphs
2024-09-26T00:03:47.921953 DEBUG: (991797) [] Loading final result graphs into TRAPI object model
2024-09-26T00:03:47.943673 INFO: (991797) [] Resultify created 47 results
2024-09-26T00:03:47.944919 DEBUG: (991797) [] Cleaning up the KG to remove nodes not used in the results
2024-09-26T00:03:47.947119 INFO: (991797) [] After cleaning, the KG contains 238 nodes and 1368 edges
2024-09-26T00:03:47.953761 WARNING: (991797) [] Could not get predicted drugs for disease DOID:0111157. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-26T00:03:47.957729 WARNING: (991797) [] Could not get predicted drugs for disease orphanet:160. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-26T00:03:47.961670 WARNING: (991797) [] Could not get predicted drugs for disease UMLS:C0017531. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-26T00:03:47.965558 WARNING: (991797) [] Could not get predicted drugs for disease UMLS:C2931179. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-26T00:03:47.969469 WARNING: (991797) [] Could not get predicted drugs for disease MESH:C536362. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-26T00:03:47.973379 WARNING: (991797) [] Could not get predicted drugs for disease MESH:D005871. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-26T00:03:47.977286 WARNING: (991797) [] Could not get predicted drugs for disease MEDDRA:10050251. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-26T00:03:47.981191 WARNING: (991797) [] Could not get predicted drugs for disease NCIT:C3056. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-26T00:03:47.985093 WARNING: (991797) [] Could not get predicted drugs for disease SNOMEDCT:207036003. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-26T00:03:47.988994 WARNING: (991797) [] Could not get predicted drugs for disease SNOMEDCT:781094002. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-26T00:03:47.992882 WARNING: (991797) [] Could not get predicted drugs for disease ICD10:D47.Z2. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-26T00:03:47.996781 WARNING: (991797) [] Could not get predicted drugs for disease CHV:0000001174. Likely the model was not trained with this disease. Or No predicted drugs for this disease with score >= 0.5.
2024-09-26T00:03:47.997379 DEBUG: (991797) [] Applying Infer to Message with parameters {'action': 'drug_treatment_graph_expansion', 'node_curie': 'MONDO:0015564', 'qedge_id': 't_edge', 'drug_curie': None, 'n_drugs': 50, 'n_paths': 25}
2024-09-26T00:03:47.999799 DEBUG: (991797) [] Query graph is {'edges': {'creative_DTD_qedge_0': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'creative_DTD_qnode_0',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'chemical'},
           'creative_DTD_qedge_1': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'creative_DTD_qnode_1',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'creative_DTD_qnode_0'},
           'creative_DTD_qedge_2': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'disease',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'creative_DTD_qnode_1'},
           't_edge': {'attribute_constraints': [{'id': 'knowledge_source',
                                                 'name': 'knowledge source',
                                                 'not': False,
                                                 'operator': '==',
                                                 'unit_id': None,
                                                 'unit_name': None,
                                                 'value': ['infores:rtx-kg2']}],
                      'exclude': None,
                      'knowledge_type': 'inferred',
                      'object': 'disease',
                      'option_group_id': None,
                      'predicates': ['biolink:treats'],
                      'qualifier_constraints': [],
                      'subject': 'chemical'}},
 'nodes': {'chemical': {'categories': ['biolink:Drug', 'biolink:SmallMolecule'],
                        'constraints': [],
                        'ids': None,
                        'is_set': False,
                        'option_group_id': None,
                        'set_id': None,
                        'set_interpretation': 'BATCH'},
           'creative_DTD_qnode_0': {'categories': None,
                                    'constraints': [],
                                    'ids': None,
                                    'is_set': True,
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'set_id': None,
                                    'set_interpretation': 'BATCH'},
           'creative_DTD_qnode_1': {'categories': None,
                                    'constraints': [],
                                    'ids': None,
                                    'is_set': True,
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'set_id': None,
                                    'set_interpretation': 'BATCH'},
           'disease': {'categories': None,
                       'constraints': [],
                       'ids': ['MONDO:0015564'],
                       'is_set': False,
                       'option_group_id': None,
                       'set_id': None,
                       'set_interpretation': 'BATCH'}}}
2024-09-26T00:03:47.999871 DEBUG: (991797) [] Number of nodes in KG is 238
2024-09-26T00:03:48.000405 DEBUG: (991797) [] Number of nodes in KG by type is Counter({'biolink:SmallMolecule': 129, 'biolink:Gene': 45, 'biolink:ChemicalEntity': 18, 'biolink:Drug': 9, 'biolink:Cell': 8, 'biolink:GrossAnatomicalStructure': 8, 'biolink:Protein': 6, 'biolink:PhysiologicalProcess': 5, 'biolink:MolecularActivity': 4, 'biolink:Disease': 2, 'biolink:AnatomicalEntity': 2, 'biolink:MolecularMixture': 2})
2024-09-26T00:03:48.000456 DEBUG: (991797) [] Number of edges in KG is 1368
2024-09-26T00:03:48.001440 DEBUG: (991797) [] Number of edges in KG by type is Counter({'biolink:interacts_with': 782, 'biolink:affects': 363, 'biolink:treats': 47, 'biolink:located_in': 36, 'biolink:subclass_of': 32, 'biolink:physically_interacts_with': 23, 'biolink:produces': 18, 'biolink:has_part': 17, 'biolink:gene_associated_with_condition': 14, 'biolink:disrupts': 11, 'biolink:causes': 8, 'biolink:directly_physically_interacts_with': 5, 'biolink:colocalizes_with': 4, 'biolink:has_participant': 4, 'biolink:associated_with': 2, 'biolink:occurs_in': 2})
2024-09-26T00:03:48.001968 DEBUG: (991797) [] Number of edges in KG with attributes is 1368
2024-09-26T00:03:48.012313 DEBUG: (991797) [] Number of edges in KG by attribute Counter({None: 5057, 'defined_datetime': 1368, 'metatype:Datetime': 1368, 'EDAM-DATA:1772': 1368, 'biolink:original_predicate': 1080, 'biolink:knowledge_level': 1080, 'biolink:agent_type': 1080, 'biolink:publications': 270, 'bts:sentence': 179, 'probability_treats': 47, 'EDAM-DATA:0951': 47})
2024-09-26T00:03:48.013408 DEBUG: (991797) [] Done calling ARAX Infer from Expand; returning to regular Expand execution
2024-09-26T00:03:48.013557 DEBUG: (991797) [] Expanding qedge t_edge
2024-09-26T00:03:48.014131 DEBUG: (991797) [] Modified QG for this qedge is (disease:['biolink:DiseaseOrPhenotypicFeature', 'biolink:Disease', 'biolink:PhenotypicFeature'] ['MONDO:0015564'])-['biolink:treats']-(chemical:['biolink:ChemicalEntity'])
2024-09-26T00:03:48.014189 DEBUG: (991797) [] For t_edge, pre-prune threshold is 200
2024-09-26T00:03:48.014232 DEBUG: (991797) [] Selecting KPs to use for qedge t_edge
2024-09-26T00:03:48.014413 DEBUG: (991797) [] selecting from 37 kps
2024-09-26T00:03:48.017221 DEBUG: (991797) [] Skipped infores:text-mining-provider-cooccurrence: KP does not have a TRAPI 1.5 endpoint
2024-09-26T00:03:48.017307 INFO: (991797) [] Expand decided to use 1 KPs to answer t_edge: {'infores:rtx-kg2'}
2024-09-26T00:03:48.017347 DEBUG: (991797) [] Will use asyncio to run KP queries concurrently
2024-09-26T00:03:48.017763 INFO: (991797) [] Expanding qedge t_edge using infores:rtx-kg2
2024-09-26T00:03:48.018240 DEBUG: (991797) [] infores:rtx-kg2: Qnodes with an implied parent query ID are: {'disease': 'MONDO:0015564'}
2024-09-26T00:03:48.018576 DEBUG: (991797) [] Sending NodeSynonymizer.get_canonical_curies() a list of 1 curies
2024-09-26T00:03:48.019010 DEBUG: (991797) [] Got response back from NodeSynonymizer
2024-09-26T00:03:48.019128 INFO: (991797) [] For querying infores:rtx-kg2, edited t_edge to use higher treats-type predicate: ['biolink:treats', 'biolink:treats_or_applied_or_studied_to_treat']
2024-09-26T00:03:48.019354 DEBUG: (991797) [] infores:rtx-kg2: Sending query to infores:rtx-kg2 API (https://kg2cplover.rtx.ai:9990)
2024-09-26T00:03:48.356841 DEBUG: (991797) [] infores:rtx-kg2: Got results from infores:rtx-kg2.
2024-09-26T00:03:48.360515 DEBUG: (991797) [] Sending NodeSynonymizer.get_canonical_curies() a list of 0 curies
2024-09-26T00:03:48.360573 DEBUG: (991797) [] Got response back from NodeSynonymizer
2024-09-26T00:03:48.360829 DEBUG: (991797) [] Sending NodeSynonymizer.get_canonical_curies() a list of 0 curies
2024-09-26T00:03:48.360876 DEBUG: (991797) [] Got response back from NodeSynonymizer
2024-09-26T00:03:48.360977 DEBUG: (991797) [] infores:rtx-kg2: Added 1 subclass_of edges to the KG based on query ID mappings infores:rtx-kg2 returned
2024-09-26T00:03:48.361099 INFO: (991797) [] infores:rtx-kg2: Query for edge t_edge completed (chemical: 6, disease: 2, subclass:disease--disease: 1, t_edge: 10)
2024-09-26T00:03:48.361140 DEBUG: (991797) [] infores:rtx-kg2: Removing any self-edges from the answer KG
2024-09-26T00:03:48.361191 DEBUG: (991797) [] infores:rtx-kg2: After removing self-edges, answer KG counts are: chemical: 6, disease: 2, subclass:disease--disease: 1, t_edge: 10
2024-09-26T00:03:48.361383 DEBUG: (991797) [] Got answers from all KPs; merging them into one KG
2024-09-26T00:03:48.361526 DEBUG: (991797) [] Merging answer into Message.KnowledgeGraph
2024-09-26T00:03:48.361756 DEBUG: (991797) [] Sending NodeSynonymizer.get_canonical_curies() a list of 1 curies
2024-09-26T00:03:48.362165 DEBUG: (991797) [] Got response back from NodeSynonymizer
2024-09-26T00:03:48.362555 DEBUG: (991797) [] Adding subclass_of qedge subclass:disease--disease to the QG since KP(s) returned child nodes for this qnode
2024-09-26T00:03:48.362606 DEBUG: (991797) [] Removed 0 edges fulfilling subclass:disease--disease from the KG because they were orphaned
2024-09-26T00:03:48.362657 DEBUG: (991797) [] Removed 0 edges fulfilling t_edge from the KG because they were orphaned
2024-09-26T00:03:48.362702 DEBUG: (991797) [] After merging KPs' answers, total KG counts are: chemical: 51, creative_DTD_qedge_0: 955, creative_DTD_qedge_1: 348, creative_DTD_qedge_2: 18, creative_DTD_qnode_0: 183, creative_DTD_qnode_1: 16, disease: 2, subclass:disease--disease: 1, t_edge: 57
2024-09-26T00:03:48.362737 DEBUG: (991797) [] Handling any knowledge source constraints
2024-09-26T00:03:48.362777 DEBUG: (991797) [] KP allowlist is {'infores:rtx-kg2'}, denylist is set()
2024-09-26T00:03:48.363005 DEBUG: (991797) [] Removing 8 KG2 semmeddb treats_or_applied-type edges fulfilling t_edge
2024-09-26T00:03:48.363075 DEBUG: (991797) [] Pruning any paths that are now dead ends (with help of Resultify)
2024-09-26T00:03:48.365685 DEBUG: (991797) [] Calling Resultify from Expand..
2024-09-26T00:03:48.365731 DEBUG: (991797) [] Applying Resultifier to Message with parameters {}
2024-09-26T00:03:48.365797 DEBUG: (991797) [] Expanded qedges are {'subclass:disease--disease', 'creative_DTD_qedge_0', 'creative_DTD_qedge_1', 'creative_DTD_qedge_2', 't_edge'}, expanded qnodes are {'creative_DTD_qnode_1', 'creative_DTD_qnode_0', 'chemical', 'disease'}; will resultify only this sub-QG
2024-09-26T00:03:48.365850 DEBUG: (991797) [] Non-kryptonite qedges are {'subclass:disease--disease', 'creative_DTD_qedge_0', 'creative_DTD_qedge_1', 'creative_DTD_qedge_2', 't_edge'}, non-kryptonite qnodes are {'creative_DTD_qnode_1', 'creative_DTD_qnode_0', 'chemical', 'disease'}.
2024-09-26T00:03:48.369998 DEBUG: (991797) [] Grabbing only required portion of QG
2024-09-26T00:03:48.370059 DEBUG: (991797) [] Required qnodes are {'chemical', 'disease'}, required qedges are {'t_edge'}
2024-09-26T00:03:48.370148 DEBUG: (991797) [] Subclass self-qedges are {'subclass:disease--disease'}; qnodes with a subclass self-qedge are: {'disease'}
2024-09-26T00:03:48.370187 DEBUG: (991797) [] Building helper indexes for faster lookup of edges
2024-09-26T00:03:48.383173 INFO: (991797) [] Creating result graphs for required portion of QG
2024-09-26T00:03:48.384859 DEBUG: (991797) [] Constructing result graphs qnode by qnode
2024-09-26T00:03:48.384905 DEBUG: (991797) [] Qnode keys already handled are: set()
2024-09-26T00:03:48.384940 DEBUG: (991797) [] Initiating result graphs with nodes for chemical (is_set=True)
2024-09-26T00:03:48.384969 DEBUG: (991797) [] Starting with one result graph because is_set=True for chemical
2024-09-26T00:03:48.385000 DEBUG: (991797) [] Current count of result graphs is 1
2024-09-26T00:03:48.385038 DEBUG: (991797) [] Next qnode chosen is: disease
2024-09-26T00:03:48.385067 DEBUG: (991797) [] Adding a layer to each result graph for qnode disease (is_set=True)
2024-09-26T00:03:48.385312 DEBUG: (991797) [] Current count of result graphs is 1
2024-09-26T00:03:48.385347 DEBUG: (991797) [] Done assigning nodes to result graphs.
2024-09-26T00:03:48.385373 DEBUG: (991797) [] Adding edges to result graphs
2024-09-26T00:03:48.385467 DEBUG: (991797) [] After pruning out result graphs missing edges, there are 1 result graphs
2024-09-26T00:03:48.385506 DEBUG: (991797) [] Created 1 required result graphs
2024-09-26T00:03:48.385553 INFO: (991797) [] Distinct option groups detected in the QG are: {'creative_DTD_option_group_0'}
2024-09-26T00:03:48.385610 DEBUG: (991797) [] For option group creative_DTD_option_group_0, qnodes are {'creative_DTD_qnode_1', 'creative_DTD_qnode_0', 'chemical', 'disease'}, qedges are {'creative_DTD_qedge_0', 'creative_DTD_qedge_1', 'creative_DTD_qedge_2', 't_edge'}
2024-09-26T00:03:48.385702 INFO: (991797) [] Creating result graphs for option group creative_DTD_option_group_0
2024-09-26T00:03:48.391171 DEBUG: (991797) [] Constructing result graphs qnode by qnode
2024-09-26T00:03:48.391224 DEBUG: (991797) [] Qnode keys already handled are: {'chemical', 'disease'}
2024-09-26T00:03:48.391264 DEBUG: (991797) [] Next qnode chosen is: creative_DTD_qnode_1
2024-09-26T00:03:48.391293 DEBUG: (991797) [] Adding a layer to each result graph for qnode creative_DTD_qnode_1 (is_set=True)
2024-09-26T00:03:48.391541 DEBUG: (991797) [] Current count of result graphs is 1
2024-09-26T00:03:48.391587 DEBUG: (991797) [] Next qnode chosen is: creative_DTD_qnode_0
2024-09-26T00:03:48.391618 DEBUG: (991797) [] Adding a layer to each result graph for qnode creative_DTD_qnode_0 (is_set=True)
2024-09-26T00:03:48.392919 DEBUG: (991797) [] Current count of result graphs is 1
2024-09-26T00:03:48.392956 DEBUG: (991797) [] Done assigning nodes to result graphs.
2024-09-26T00:03:48.392982 DEBUG: (991797) [] Adding edges to result graphs
2024-09-26T00:03:48.393862 DEBUG: (991797) [] After pruning out result graphs missing edges, there are 1 result graphs
2024-09-26T00:03:48.394017 DEBUG: (991797) [] Created 1 option group creative_DTD_option_group_0 result graphs
2024-09-26T00:03:48.394054 DEBUG: (991797) [] Required non-set qnodes are: []
2024-09-26T00:03:48.394086 INFO: (991797) [] Merging option group result graphs into required result graphs with matching non-set qnodes
2024-09-26T00:03:48.394285 DEBUG: (991797) [] There are a total of 1 final result graphs
2024-09-26T00:03:48.396754 INFO: (991797) [] After separating children from parents in our single result, counts are: {'chemical': 48, 'disease': 1, 'creative_DTD_qnode_1': 15, 'creative_DTD_qnode_0': 181}, {'t_edge': 49, 'creative_DTD_qedge_0': 953, 'creative_DTD_qedge_1': 348, 'creative_DTD_qedge_2': 18}
2024-09-26T00:03:48.396794 DEBUG: (991797) [] Loading final result graphs into TRAPI object model
2024-09-26T00:03:48.401348 INFO: (991797) [] Resultify created 1 results
2024-09-26T00:03:48.402234 DEBUG: (991797) [] Cleaning up the KG to remove nodes not used in the results
2024-09-26T00:03:48.403863 INFO: (991797) [] After cleaning, the KG contains 238 nodes and 1371 edges
2024-09-26T00:03:48.404816 DEBUG: (991797) [] After removing dead-end paths, KG counts are: chemical: 49, creative_DTD_qedge_0: 955, creative_DTD_qedge_1: 348, creative_DTD_qedge_2: 18, creative_DTD_qnode_0: 183, creative_DTD_qnode_1: 16, disease: 2, subclass:disease--disease: 1, t_edge: 49
2024-09-26T00:03:48.406877 DEBUG: (991797) [] Decorating nodes with metadata from KG2c
2024-09-26T00:03:48.407246 DEBUG: (991797) [] Looking up corresponding KG2c nodes in sqlite
2024-09-26T00:03:48.412624 DEBUG: (991797) [] Adding attributes to nodes in the KG
2024-09-26T00:03:48.550839 DEBUG: (991797) [] Decorating edges with EPC info from KG2c
2024-09-26T00:03:48.555341 DEBUG: (991797) [] Identified 1323 edges to decorate
2024-09-26T00:03:48.563056 DEBUG: (991797) [] Looking up EPC edge info in KG2c sqlite
2024-09-26T00:03:48.563103 DEBUG: (991797) [] Looking up corresponding KG2c nodes in sqlite
2024-09-26T00:03:48.579428 DEBUG: (991797) [] Got 1082 rows back from KG2c sqlite
2024-09-26T00:03:48.579505 DEBUG: (991797) [] Adding attributes to edges in the KG
2024-09-26T00:03:48.588294 INFO: (991797) [] Treats-like predicates are: {'biolink:treats_or_applied_or_studied_to_treat'}
2024-09-26T00:03:48.588355 INFO: (991797) [] Mode is ARAX, do_issue_2328_patch is True, inferred_qedge_keys is ['t_edge']
2024-09-26T00:03:48.588384 INFO: (991797) [] Made it into block where KG2 treats-like edge alteration happens
2024-09-26T00:03:48.592382 DEBUG: (991797) [] Sending NodeSynonymizer.get_canonical_curies() a list of 1 curies
2024-09-26T00:03:48.592798 DEBUG: (991797) [] Got response back from NodeSynonymizer
2024-09-26T00:03:48.592921 DEBUG: (991797) [] No KG nodes found that use a different curie than was asked for in the QG
2024-09-26T00:03:48.592982 INFO: (991797) [] After Expand, the KG has 238 nodes and 1371 edges (chemical: 49, creative_DTD_qedge_0: 955, creative_DTD_qedge_1: 348, creative_DTD_qedge_2: 18, creative_DTD_qnode_0: 183, creative_DTD_qnode_1: 16, disease: 2, subclass:disease--disease: 1, t_edge: 49)
2024-09-26T00:03:48.595433 INFO: (991797) [] Processing action 'overlay' with parameters {'action': 'compute_ngd', 'virtual_relation_label': 'N1', 'subject_qnode_key': 'disease', 'object_qnode_key': 'chemical'}
2024-09-26T00:03:48.595511 DEBUG: (991797) [] Applying Overlay to Message with parameters {'action': 'compute_ngd', 'virtual_relation_label': 'N1', 'subject_qnode_key': 'disease', 'object_qnode_key': 'chemical'}
2024-09-26T00:03:48.603434 DEBUG: (991797) [] Computing NGD
2024-09-26T00:03:48.603480 INFO: (991797) [] Computing the normalized Google distance: weighting edges based on subject/object node co-occurrence frequency in PubMed abstracts
2024-09-26T00:03:48.603515 DEBUG: (991797) [] Narrowing down disease--chemical node pairs to overlay
2024-09-26T00:03:48.604808 DEBUG: (991797) [] Applying Resultifier to Message with parameters {}
2024-09-26T00:03:48.604885 DEBUG: (991797) [] Expanded qedges are {'subclass:disease--disease', 'creative_DTD_qedge_0', 'creative_DTD_qedge_1', 'creative_DTD_qedge_2', 't_edge'}, expanded qnodes are {'creative_DTD_qnode_1', 'creative_DTD_qnode_0', 'chemical', 'disease'}; will resultify only this sub-QG
2024-09-26T00:03:48.604940 DEBUG: (991797) [] Non-kryptonite qedges are {'subclass:disease--disease', 'creative_DTD_qedge_0', 'creative_DTD_qedge_1', 'creative_DTD_qedge_2', 't_edge'}, non-kryptonite qnodes are {'creative_DTD_qnode_1', 'creative_DTD_qnode_0', 'chemical', 'disease'}.
2024-09-26T00:03:48.609248 DEBUG: (991797) [] Grabbing only required portion of QG
2024-09-26T00:03:48.609311 DEBUG: (991797) [] Required qnodes are {'chemical', 'disease'}, required qedges are {'t_edge'}
2024-09-26T00:03:48.609404 DEBUG: (991797) [] Subclass self-qedges are {'subclass:disease--disease'}; qnodes with a subclass self-qedge are: {'disease'}
2024-09-26T00:03:48.609443 DEBUG: (991797) [] Building helper indexes for faster lookup of edges
2024-09-26T00:03:48.621374 INFO: (991797) [] Creating result graphs for required portion of QG
2024-09-26T00:03:48.623619 DEBUG: (991797) [] Constructing result graphs qnode by qnode
2024-09-26T00:03:48.623671 DEBUG: (991797) [] Qnode keys already handled are: set()
2024-09-26T00:03:48.623706 DEBUG: (991797) [] Initiating result graphs with nodes for chemical (is_set=False)
2024-09-26T00:03:48.623735 DEBUG: (991797) [] Starting with a result graph for each chemical node
2024-09-26T00:03:48.623886 DEBUG: (991797) [] Current count of result graphs is 49
2024-09-26T00:03:48.623926 DEBUG: (991797) [] Next qnode chosen is: disease
2024-09-26T00:03:48.623956 DEBUG: (991797) [] Adding a layer to each result graph for qnode disease (is_set=False)
2024-09-26T00:03:48.626359 DEBUG: (991797) [] Current count of result graphs is 48
2024-09-26T00:03:48.626397 DEBUG: (991797) [] Done assigning nodes to result graphs.
2024-09-26T00:03:48.626424 DEBUG: (991797) [] Adding edges to result graphs
2024-09-26T00:03:48.626726 DEBUG: (991797) [] After pruning out result graphs missing edges, there are 48 result graphs
2024-09-26T00:03:48.626775 DEBUG: (991797) [] Created 48 required result graphs
2024-09-26T00:03:48.626833 INFO: (991797) [] Distinct option groups detected in the QG are: {'creative_DTD_option_group_0'}
2024-09-26T00:03:48.626893 DEBUG: (991797) [] For option group creative_DTD_option_group_0, qnodes are {'creative_DTD_qnode_1', 'creative_DTD_qnode_0', 'chemical', 'disease'}, qedges are {'creative_DTD_qedge_0', 'creative_DTD_qedge_1', 'creative_DTD_qedge_2', 't_edge'}
2024-09-26T00:03:48.626971 INFO: (991797) [] Creating result graphs for option group creative_DTD_option_group_0
2024-09-26T00:03:48.635156 DEBUG: (991797) [] Constructing result graphs qnode by qnode
2024-09-26T00:03:48.635230 DEBUG: (991797) [] Qnode keys already handled are: {'chemical', 'disease'}
2024-09-26T00:03:48.635273 DEBUG: (991797) [] Next qnode chosen is: creative_DTD_qnode_1
2024-09-26T00:03:48.635303 DEBUG: (991797) [] Adding a layer to each result graph for qnode creative_DTD_qnode_1 (is_set=True)
2024-09-26T00:03:48.639171 DEBUG: (991797) [] Current count of result graphs is 48
2024-09-26T00:03:48.639225 DEBUG: (991797) [] Next qnode chosen is: creative_DTD_qnode_0
2024-09-26T00:03:48.639258 DEBUG: (991797) [] Adding a layer to each result graph for qnode creative_DTD_qnode_0 (is_set=True)
2024-09-26T00:03:48.649792 DEBUG: (991797) [] Current count of result graphs is 47
2024-09-26T00:03:48.649838 DEBUG: (991797) [] Done assigning nodes to result graphs.
2024-09-26T00:03:48.649867 DEBUG: (991797) [] Adding edges to result graphs
2024-09-26T00:03:48.656654 DEBUG: (991797) [] After pruning out result graphs missing edges, there are 47 result graphs
2024-09-26T00:03:48.656841 DEBUG: (991797) [] Created 47 option group creative_DTD_option_group_0 result graphs
2024-09-26T00:03:48.656881 DEBUG: (991797) [] Required non-set qnodes are: ['chemical', 'disease']
2024-09-26T00:03:48.657043 INFO: (991797) [] Merging option group result graphs into required result graphs with matching non-set qnodes
2024-09-26T00:03:48.660269 DEBUG: (991797) [] There are a total of 48 final result graphs
2024-09-26T00:03:48.666237 DEBUG: (991797) [] Loading final result graphs into TRAPI object model
2024-09-26T00:03:48.685023 INFO: (991797) [] Resultify created 48 results
2024-09-26T00:03:48.686279 DEBUG: (991797) [] Cleaning up the KG to remove nodes not used in the results
2024-09-26T00:03:48.688466 INFO: (991797) [] After cleaning, the KG contains 238 nodes and 1371 edges
2024-09-26T00:03:48.688919 DEBUG: (991797) [] Identified 48 node pairs to overlay (with help of resultify)
2024-09-26T00:03:48.690675 DEBUG: (991797) [] Canonicalizing curies of relevant nodes using NodeSynonymizer
2024-09-26T00:03:48.692870 DEBUG: (991797) [] Extracting PMID lists from sqlite database for relevant nodes
2024-09-26T00:03:48.752599 DEBUG: (991797) [] Looping through 48 node pairs and calculating NGD values
2024-09-26T00:03:48.974217 INFO: (991797) [] NGD values successfully added to edges
2024-09-26T00:03:48.974320 DEBUG: (991797) [] Decorating edges with EPC info from KG2c
2024-09-26T00:03:48.975117 DEBUG: (991797) [] Identified 48 edges to decorate
2024-09-26T00:03:48.975593 DEBUG: (991797) [] Looking up EPC edge info in KG2c sqlite to decorate NGD edges
2024-09-26T00:03:48.976079 DEBUG: (991797) [] Got 0 rows back from KG2c sqlite
2024-09-26T00:03:48.976120 DEBUG: (991797) [] Adding attributes to NGD edges in the KG
2024-09-26T00:03:48.983009 DEBUG: (991797) [] Query graph is {'edges': {'N1': {'attribute_constraints': [],
                  'exclude': None,
                  'knowledge_type': None,
                  'object': 'chemical',
                  'option_group_id': None,
                  'predicates': ['biolink:occurs_together_in_literature_with'],
                  'qualifier_constraints': [],
                  'subject': 'disease'},
           'creative_DTD_qedge_0': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'creative_DTD_qnode_0',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'chemical'},
           'creative_DTD_qedge_1': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'creative_DTD_qnode_1',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'creative_DTD_qnode_0'},
           'creative_DTD_qedge_2': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'disease',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'creative_DTD_qnode_1'},
           'subclass:disease--disease': {'attribute_constraints': [],
                                         'exclude': None,
                                         'knowledge_type': None,
                                         'object': 'disease',
                                         'option_group_id': 'option_group-subclass:disease--disease',
                                         'predicates': ['biolink:subclass_of'],
                                         'qualifier_constraints': [],
                                         'subject': 'disease'},
           't_edge': {'attribute_constraints': [{'id': 'knowledge_source',
                                                 'name': 'knowledge source',
                                                 'not': False,
                                                 'operator': '==',
                                                 'unit_id': None,
                                                 'unit_name': None,
                                                 'value': ['infores:rtx-kg2']}],
                      'exclude': None,
                      'knowledge_type': 'inferred',
                      'object': 'disease',
                      'option_group_id': None,
                      'predicates': ['biolink:treats'],
                      'qualifier_constraints': [],
                      'subject': 'chemical'}},
 'nodes': {'chemical': {'categories': ['biolink:Drug', 'biolink:SmallMolecule'],
                        'constraints': [],
                        'ids': None,
                        'is_set': False,
                        'option_group_id': None,
                        'set_id': None,
                        'set_interpretation': 'BATCH'},
           'creative_DTD_qnode_0': {'categories': None,
                                    'constraints': [],
                                    'ids': None,
                                    'is_set': True,
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'set_id': None,
                                    'set_interpretation': 'BATCH'},
           'creative_DTD_qnode_1': {'categories': None,
                                    'constraints': [],
                                    'ids': None,
                                    'is_set': True,
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'set_id': None,
                                    'set_interpretation': 'BATCH'},
           'disease': {'categories': None,
                       'constraints': [],
                       'ids': ['MONDO:0015564'],
                       'is_set': False,
                       'option_group_id': None,
                       'set_id': None,
                       'set_interpretation': 'BATCH'}}}
2024-09-26T00:03:48.983118 DEBUG: (991797) [] Number of nodes in KG is 238
2024-09-26T00:03:48.983474 DEBUG: (991797) [] Number of nodes in KG by type is Counter({'biolink:SmallMolecule': 129, 'biolink:Gene': 45, 'biolink:ChemicalEntity': 18, 'biolink:Drug': 9, 'biolink:Cell': 8, 'biolink:GrossAnatomicalStructure': 8, 'biolink:Protein': 6, 'biolink:PhysiologicalProcess': 5, 'biolink:MolecularActivity': 4, 'biolink:Disease': 2, 'biolink:AnatomicalEntity': 2, 'biolink:MolecularMixture': 2})
2024-09-26T00:03:48.983511 DEBUG: (991797) [] Number of edges in KG is 1419
2024-09-26T00:03:48.984487 DEBUG: (991797) [] Number of edges in KG by type is Counter({'biolink:interacts_with': 782, 'biolink:affects': 363, 'biolink:occurs_together_in_literature_with': 48, 'biolink:treats': 47, 'biolink:located_in': 36, 'biolink:subclass_of': 33, 'biolink:physically_interacts_with': 23, 'biolink:produces': 18, 'biolink:has_part': 17, 'biolink:gene_associated_with_condition': 14, 'biolink:disrupts': 11, 'biolink:causes': 8, 'biolink:directly_physically_interacts_with': 5, 'biolink:colocalizes_with': 4, 'biolink:has_participant': 4, 'biolink:associated_with': 2, 'biolink:occurs_in': 2, 'biolink:applied_to_treat': 2})
2024-09-26T00:03:48.985024 DEBUG: (991797) [] Number of edges in KG with attributes is 1419
2024-09-26T00:03:48.989604 DEBUG: (991797) [] Number of edges in KG by attribute Counter({None: 5112, 'defined_datetime': 1416, 'normalized_google_distance': 48, 'virtual_relation_label': 48, 'probability_treats': 47, 'publications': 9})
2024-09-26T00:03:48.989668 INFO: (991797) [] Processing action 'filter_kg' with parameters {'action': 'remove_general_concept_nodes', 'perform_action': 'True'}
2024-09-26T00:03:48.994576 DEBUG: (991797) [] Removing Nodes
2024-09-26T00:03:48.994622 INFO: (991797) [] Removing nodes from the knowledge graph which are general concepts
2024-09-26T00:03:55.526844 INFO: (991797) [] Removed 5 nodes from the knowledge graph which are general concepts
2024-09-26T00:03:55.528475 DEBUG: (991797) [] Removing orphaned nodes
2024-09-26T00:03:55.528515 INFO: (991797) [] Removing orphaned nodes
2024-09-26T00:03:55.529544 DEBUG: (991797) [] Identified 0 orphan nodes to remove
2024-09-26T00:03:55.529578 INFO: (991797) [] Nodes successfully removed
2024-09-26T00:03:55.529609 INFO: (991797) [] Nodes successfully removed
2024-09-26T00:03:55.529688 DEBUG: (991797) [] Applying Overlay to Message with parameters {'action': 'remove_general_concept_nodes', 'perform_action': True}
2024-09-26T00:03:55.532159 DEBUG: (991797) [] Query graph is {'edges': {'N1': {'attribute_constraints': [],
                  'exclude': None,
                  'knowledge_type': None,
                  'object': 'chemical',
                  'option_group_id': None,
                  'predicates': ['biolink:occurs_together_in_literature_with'],
                  'qualifier_constraints': [],
                  'subject': 'disease'},
           'creative_DTD_qedge_0': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'creative_DTD_qnode_0',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'chemical'},
           'creative_DTD_qedge_1': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'creative_DTD_qnode_1',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'creative_DTD_qnode_0'},
           'creative_DTD_qedge_2': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'disease',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'creative_DTD_qnode_1'},
           'subclass:disease--disease': {'attribute_constraints': [],
                                         'exclude': None,
                                         'knowledge_type': None,
                                         'object': 'disease',
                                         'option_group_id': 'option_group-subclass:disease--disease',
                                         'predicates': ['biolink:subclass_of'],
                                         'qualifier_constraints': [],
                                         'subject': 'disease'},
           't_edge': {'attribute_constraints': [{'id': 'knowledge_source',
                                                 'name': 'knowledge source',
                                                 'not': False,
                                                 'operator': '==',
                                                 'unit_id': None,
                                                 'unit_name': None,
                                                 'value': ['infores:rtx-kg2']}],
                      'exclude': None,
                      'knowledge_type': 'inferred',
                      'object': 'disease',
                      'option_group_id': None,
                      'predicates': ['biolink:treats'],
                      'qualifier_constraints': [],
                      'subject': 'chemical'}},
 'nodes': {'chemical': {'categories': ['biolink:Drug', 'biolink:SmallMolecule'],
                        'constraints': [],
                        'ids': None,
                        'is_set': False,
                        'option_group_id': None,
                        'set_id': None,
                        'set_interpretation': 'BATCH'},
           'creative_DTD_qnode_0': {'categories': None,
                                    'constraints': [],
                                    'ids': None,
                                    'is_set': True,
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'set_id': None,
                                    'set_interpretation': 'BATCH'},
           'creative_DTD_qnode_1': {'categories': None,
                                    'constraints': [],
                                    'ids': None,
                                    'is_set': True,
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'set_id': None,
                                    'set_interpretation': 'BATCH'},
           'disease': {'categories': None,
                       'constraints': [],
                       'ids': ['MONDO:0015564'],
                       'is_set': False,
                       'option_group_id': None,
                       'set_id': None,
                       'set_interpretation': 'BATCH'}}}
2024-09-26T00:03:55.532228 DEBUG: (991797) [] Number of nodes in KG is 233
2024-09-26T00:03:55.532475 DEBUG: (991797) [] Number of nodes in KG by type is Counter({'biolink:SmallMolecule': 129, 'biolink:Gene': 45, 'biolink:ChemicalEntity': 15, 'biolink:Drug': 9, 'biolink:Cell': 8, 'biolink:GrossAnatomicalStructure': 8, 'biolink:Protein': 5, 'biolink:PhysiologicalProcess': 5, 'biolink:MolecularActivity': 4, 'biolink:Disease': 2, 'biolink:MolecularMixture': 2, 'biolink:AnatomicalEntity': 1})
2024-09-26T00:03:55.532512 DEBUG: (991797) [] Number of edges in KG is 1396
2024-09-26T00:03:55.533140 DEBUG: (991797) [] Number of edges in KG by type is Counter({'biolink:interacts_with': 776, 'biolink:affects': 358, 'biolink:occurs_together_in_literature_with': 48, 'biolink:treats': 47, 'biolink:located_in': 34, 'biolink:subclass_of': 24, 'biolink:physically_interacts_with': 23, 'biolink:produces': 18, 'biolink:has_part': 16, 'biolink:gene_associated_with_condition': 14, 'biolink:disrupts': 11, 'biolink:causes': 8, 'biolink:directly_physically_interacts_with': 5, 'biolink:colocalizes_with': 4, 'biolink:has_participant': 4, 'biolink:associated_with': 2, 'biolink:occurs_in': 2, 'biolink:applied_to_treat': 2})
2024-09-26T00:03:55.533645 DEBUG: (991797) [] Number of edges in KG with attributes is 1396
2024-09-26T00:03:55.544423 DEBUG: (991797) [] Number of edges in KG by attribute Counter({None: 5013, 'defined_datetime': 1393, 'metatype:Datetime': 1393, 'EDAM-DATA:1772': 1393, 'biolink:original_predicate': 1064, 'biolink:knowledge_level': 1064, 'biolink:agent_type': 1064, 'biolink:publications': 268, 'bts:sentence': 168, 'normalized_google_distance': 48, 'EDAM-DATA:2526': 48, 'virtual_relation_label': 48, 'EDAM-OPERATION:0226': 48, 'probability_treats': 47, 'EDAM-DATA:0951': 47, 'publications': 9, 'biolink:description': 1})
2024-09-26T00:03:55.544490 INFO: (991797) [] Processing action 'resultify' with parameters {'': 'true'}
2024-09-26T00:03:55.544530 DEBUG: (991797) [] Applying Resultifier to Message with parameters {'': 'true'}
2024-09-26T00:03:55.544562 INFO: (991797) [] Clearing previous results and computing a new set of results
2024-09-26T00:03:55.547306 DEBUG: (991797) [] Expanded qedges are {'subclass:disease--disease', 'N1', 'creative_DTD_qedge_0', 'creative_DTD_qedge_1', 'creative_DTD_qedge_2', 't_edge'}, expanded qnodes are {'creative_DTD_qnode_1', 'creative_DTD_qnode_0', 'chemical', 'disease'}; will resultify only this sub-QG
2024-09-26T00:03:55.547382 DEBUG: (991797) [] Non-kryptonite qedges are {'subclass:disease--disease', 'N1', 'creative_DTD_qedge_0', 'creative_DTD_qedge_1', 'creative_DTD_qedge_2', 't_edge'}, non-kryptonite qnodes are {'creative_DTD_qnode_1', 'creative_DTD_qnode_0', 'chemical', 'disease'}.
2024-09-26T00:03:55.551891 DEBUG: (991797) [] Grabbing only required portion of QG
2024-09-26T00:03:55.551956 DEBUG: (991797) [] Required qnodes are {'chemical', 'disease'}, required qedges are {'N1', 't_edge'}
2024-09-26T00:03:55.552057 DEBUG: (991797) [] Subclass self-qedges are {'subclass:disease--disease'}; qnodes with a subclass self-qedge are: {'disease'}
2024-09-26T00:03:55.552096 DEBUG: (991797) [] Building helper indexes for faster lookup of edges
2024-09-26T00:03:55.564148 INFO: (991797) [] Creating result graphs for required portion of QG
2024-09-26T00:03:55.565868 DEBUG: (991797) [] Constructing result graphs qnode by qnode
2024-09-26T00:03:55.565913 DEBUG: (991797) [] Qnode keys already handled are: set()
2024-09-26T00:03:55.565948 DEBUG: (991797) [] Initiating result graphs with nodes for chemical (is_set=False)
2024-09-26T00:03:55.565976 DEBUG: (991797) [] Starting with a result graph for each chemical node
2024-09-26T00:03:55.566118 DEBUG: (991797) [] Current count of result graphs is 49
2024-09-26T00:03:55.566159 DEBUG: (991797) [] Next qnode chosen is: disease
2024-09-26T00:03:55.566189 DEBUG: (991797) [] Adding a layer to each result graph for qnode disease (is_set=False)
2024-09-26T00:03:55.568640 DEBUG: (991797) [] Current count of result graphs is 48
2024-09-26T00:03:55.568683 DEBUG: (991797) [] Done assigning nodes to result graphs.
2024-09-26T00:03:55.568711 DEBUG: (991797) [] Adding edges to result graphs
2024-09-26T00:03:55.569143 DEBUG: (991797) [] After pruning out result graphs missing edges, there are 48 result graphs
2024-09-26T00:03:55.569188 DEBUG: (991797) [] Created 48 required result graphs
2024-09-26T00:03:55.569237 INFO: (991797) [] Distinct option groups detected in the QG are: {'creative_DTD_option_group_0'}
2024-09-26T00:03:55.569295 DEBUG: (991797) [] For option group creative_DTD_option_group_0, qnodes are {'creative_DTD_qnode_1', 'creative_DTD_qnode_0', 'chemical', 'disease'}, qedges are {'N1', 'creative_DTD_qedge_0', 'creative_DTD_qedge_1', 'creative_DTD_qedge_2', 't_edge'}
2024-09-26T00:03:55.569376 INFO: (991797) [] Creating result graphs for option group creative_DTD_option_group_0
2024-09-26T00:03:55.578372 DEBUG: (991797) [] Constructing result graphs qnode by qnode
2024-09-26T00:03:55.578438 DEBUG: (991797) [] Qnode keys already handled are: {'chemical', 'disease'}
2024-09-26T00:03:55.578510 DEBUG: (991797) [] Next qnode chosen is: creative_DTD_qnode_1
2024-09-26T00:03:55.578544 DEBUG: (991797) [] Adding a layer to each result graph for qnode creative_DTD_qnode_1 (is_set=True)
2024-09-26T00:03:55.582805 DEBUG: (991797) [] Current count of result graphs is 48
2024-09-26T00:03:55.582879 DEBUG: (991797) [] Next qnode chosen is: creative_DTD_qnode_0
2024-09-26T00:03:55.582913 DEBUG: (991797) [] Adding a layer to each result graph for qnode creative_DTD_qnode_0 (is_set=True)
2024-09-26T00:03:55.593659 DEBUG: (991797) [] Current count of result graphs is 47
2024-09-26T00:03:55.593704 DEBUG: (991797) [] Done assigning nodes to result graphs.
2024-09-26T00:03:55.593733 DEBUG: (991797) [] Adding edges to result graphs
2024-09-26T00:03:55.600287 DEBUG: (991797) [] After pruning out result graphs missing edges, there are 47 result graphs
2024-09-26T00:03:55.600476 DEBUG: (991797) [] Created 47 option group creative_DTD_option_group_0 result graphs
2024-09-26T00:03:55.600516 DEBUG: (991797) [] Required non-set qnodes are: ['chemical', 'disease']
2024-09-26T00:03:55.600681 INFO: (991797) [] Merging option group result graphs into required result graphs with matching non-set qnodes
2024-09-26T00:03:55.604308 DEBUG: (991797) [] There are a total of 48 final result graphs
2024-09-26T00:03:55.610349 DEBUG: (991797) [] Loading final result graphs into TRAPI object model
2024-09-26T00:03:55.744793 INFO: (991797) [] Resultify created 48 results
2024-09-26T00:03:55.746148 DEBUG: (991797) [] Cleaning up the KG to remove nodes not used in the results
2024-09-26T00:03:55.748370 INFO: (991797) [] After cleaning, the KG contains 233 nodes and 1396 edges
2024-09-26T00:03:55.748431 INFO: (991797) [] Running experimental reranker on results
2024-09-26T00:03:55.748477 DEBUG: (991797) [] Starting to rank results
2024-09-26T00:03:55.748525 DEBUG: (991797) [] Assessing the QueryGraph for basic information
2024-09-26T00:03:55.748559 DEBUG: (991797) [] Found 4 nodes and 6 edges
2024-09-26T00:03:55.749444 DEBUG: (991797) [] canonical_curies={'MONDO:0015564': {'preferred_curie': 'MONDO:0015564', 'preferred_name': 'Castleman disease', 'preferred_category': 'biolink:Disease', 'all_categories': {'biolink:Disease': 13}}}, curie=MONDO:0015564
2024-09-26T00:03:55.749530 DEBUG: (991797) [] QueryGraph has edges with no predicate. This may cause problems with results inference later
2024-09-26T00:03:55.749572 DEBUG: (991797) [] QueryGraph has edges with no predicate. This may cause problems with results inference later
2024-09-26T00:03:55.749610 DEBUG: (991797) [] QueryGraph has edges with no predicate. This may cause problems with results inference later
2024-09-26T00:03:55.749653 WARNING: (991797) [] QueryGraph appears to have a fork in it. This might cause trouble
2024-09-26T00:03:55.749683 WARNING: (991797) [] QueryGraph appears to be circular or has a strange geometry. This might cause trouble
2024-09-26T00:03:55.749719 WARNING: (991797) [] Fell into a loop in the QueryGraph. Picking an end node somewhat arbitrarily.
2024-09-26T00:03:55.749767 INFO: (991797) [] Property is_set is not true for chemical although maybe it should be to keep the query from blowing up. Consider setting is_set to true here.
2024-09-26T00:03:55.749803 INFO: (991797) [] Property is_set is not true for creative_DTD_qnode_0 although maybe it should be to keep the query from blowing up. Consider setting is_set to true here.
2024-09-26T00:03:55.749836 DEBUG: (991797) [] The QueryGraph reference template is: n00(ids)-e00()-n01(categories=biolink:Drug)-e01()-n02()-e02()-n03()
2024-09-26T00:03:55.796742 INFO: (991797) [] Summary of available edge metrics: {'probability_treats': {'minimum': 0.7219532114089924, 'maximum': 0.7643441223573989}, 'normalized_google_distance': {'minimum': 0.29685025999983256, 'maximum': 0.7126693412698298}}
2024-09-26T00:03:55.857138 DEBUG: (991797) [] Results have been ranked and sorted
2024-09-26T00:03:55.857252 INFO: (991797) [] Processing action 'filter_results' with parameters {'action': 'limit_number_of_results', 'max_results': '500'}
2024-09-26T00:03:55.857290 DEBUG: (991797) [] Before filtering, there are 48 results
2024-09-26T00:03:55.892812 DEBUG: (991797) [] Limiting Number of Results
2024-09-26T00:03:55.892869 INFO: (991797) [] Filtering excess results above max result limit
2024-09-26T00:03:55.896405 INFO: (991797) [] KG successfully pruned to match results
2024-09-26T00:03:55.896503 INFO: (991797) [] Successfully limited the number of results
2024-09-26T00:03:55.896543 DEBUG: (991797) [] Applying Overlay to Message with parameters {'action': 'limit_number_of_results', 'max_results': 500, 'prune_kg': True}
2024-09-26T00:03:55.899023 DEBUG: (991797) [] Query graph is {'edges': {'N1': {'attribute_constraints': [],
                  'exclude': None,
                  'knowledge_type': None,
                  'object': 'chemical',
                  'option_group_id': None,
                  'predicates': ['biolink:occurs_together_in_literature_with'],
                  'qualifier_constraints': [],
                  'subject': 'disease'},
           'creative_DTD_qedge_0': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'creative_DTD_qnode_0',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'chemical'},
           'creative_DTD_qedge_1': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'creative_DTD_qnode_1',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'creative_DTD_qnode_0'},
           'creative_DTD_qedge_2': {'attribute_constraints': [],
                                    'exclude': False,
                                    'knowledge_type': None,
                                    'object': 'disease',
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'predicates': None,
                                    'qualifier_constraints': [],
                                    'subject': 'creative_DTD_qnode_1'},
           'subclass:disease--disease': {'attribute_constraints': [],
                                         'exclude': None,
                                         'knowledge_type': None,
                                         'object': 'disease',
                                         'option_group_id': 'option_group-subclass:disease--disease',
                                         'predicates': ['biolink:subclass_of'],
                                         'qualifier_constraints': [],
                                         'subject': 'disease'},
           't_edge': {'attribute_constraints': [{'id': 'knowledge_source',
                                                 'name': 'knowledge source',
                                                 'not': False,
                                                 'operator': '==',
                                                 'unit_id': None,
                                                 'unit_name': None,
                                                 'value': ['infores:rtx-kg2']}],
                      'exclude': None,
                      'knowledge_type': 'inferred',
                      'object': 'disease',
                      'option_group_id': None,
                      'predicates': ['biolink:treats'],
                      'qualifier_constraints': [],
                      'subject': 'chemical'}},
 'nodes': {'chemical': {'categories': ['biolink:Drug', 'biolink:SmallMolecule'],
                        'constraints': [],
                        'ids': None,
                        'is_set': False,
                        'option_group_id': None,
                        'set_id': None,
                        'set_interpretation': 'BATCH'},
           'creative_DTD_qnode_0': {'categories': None,
                                    'constraints': [],
                                    'ids': None,
                                    'is_set': True,
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'set_id': None,
                                    'set_interpretation': 'BATCH'},
           'creative_DTD_qnode_1': {'categories': None,
                                    'constraints': [],
                                    'ids': None,
                                    'is_set': True,
                                    'option_group_id': 'creative_DTD_option_group_0',
                                    'set_id': None,
                                    'set_interpretation': 'BATCH'},
           'disease': {'categories': None,
                       'constraints': [],
                       'ids': ['MONDO:0015564'],
                       'is_set': False,
                       'option_group_id': None,
                       'set_id': None,
                       'set_interpretation': 'BATCH'}}}
2024-09-26T00:03:55.899086 DEBUG: (991797) [] Number of nodes in KG is 233
2024-09-26T00:03:55.899384 DEBUG: (991797) [] Number of nodes in KG by type is Counter({'biolink:SmallMolecule': 129, 'biolink:Gene': 45, 'biolink:ChemicalEntity': 15, 'biolink:Drug': 9, 'biolink:Cell': 8, 'biolink:GrossAnatomicalStructure': 8, 'biolink:Protein': 5, 'biolink:PhysiologicalProcess': 5, 'biolink:MolecularActivity': 4, 'biolink:Disease': 2, 'biolink:MolecularMixture': 2, 'biolink:AnatomicalEntity': 1})
2024-09-26T00:03:55.899420 DEBUG: (991797) [] Number of edges in KG is 1393
2024-09-26T00:03:55.900072 DEBUG: (991797) [] Number of edges in KG by type is Counter({'biolink:interacts_with': 774, 'biolink:affects': 358, 'biolink:occurs_together_in_literature_with': 48, 'biolink:treats': 47, 'biolink:located_in': 34, 'biolink:physically_interacts_with': 23, 'biolink:subclass_of': 23, 'biolink:produces': 18, 'biolink:has_part': 16, 'biolink:gene_associated_with_condition': 14, 'biolink:disrupts': 11, 'biolink:causes': 8, 'biolink:directly_physically_interacts_with': 5, 'biolink:colocalizes_with': 4, 'biolink:has_participant': 4, 'biolink:associated_with': 2, 'biolink:occurs_in': 2, 'biolink:applied_to_treat': 2})
2024-09-26T00:03:55.900574 DEBUG: (991797) [] Number of edges in KG with attributes is 1393
2024-09-26T00:03:55.905009 DEBUG: (991797) [] Number of edges in KG by attribute Counter({None: 5004, 'defined_datetime': 1391, 'normalized_google_distance': 48, 'virtual_relation_label': 48, 'probability_treats': 47, 'publications': 9})
2024-09-26T00:03:55.905078 INFO: (991797) [] Transforming results to TRAPI 1.5 format (moving 'virtual' nodes/edges to support graphs)
2024-09-26T00:03:55.905125 DEBUG: (991797) [] Original input QG contained qnodes {'chemical', 'disease'} and qedges {'t_edge'}
2024-09-26T00:03:55.905157 DEBUG: (991797) [] Non-orphan qnodes in original QG are: {'chemical', 'disease'}
2024-09-26T00:03:55.912459 DEBUG: (991797) [] Replacing ARAX's internal edited QG with the original input QG..
2024-09-26T00:03:55.912522 DEBUG: (991797) [] Virtual qedge keys moved to support_graphs were: {'N1', 'creative_DTD_qedge_0', 'creative_DTD_qedge_1', 'creative_DTD_qedge_2'}
2024-09-26T00:03:55.912553 DEBUG: (991797) [] There are a total of 95 AuxiliaryGraphs.
2024-09-26T00:03:55.912580 INFO: (991797) [] Done transforming results to TRAPI 1.5 format (i.e., using support_graphs)
2024-09-26T00:03:55.912656 DEBUG: (991797) [] Storing resulting Message
2024-09-26T00:03:55.912691 DEBUG: (991797) [] Writing response record to MySQL
INFO: Attempting to write to S3 bucket us-east-1:arax-response-storage-2:/responses/303716.json
2024-09-26T00:03:56.825769 INFO: (991797) [] INFO: Successfully wrote /responses/303716.json to us-east-1 S3 bucket arax-response-storage-2 in 0.3305565556511283 seconds
2024-09-26T00:03:56.828634 INFO: (991797) [] Result was stored with id 303716. It can be viewed at https://arax.ncats.io/?r=303716
2024-09-26T00:03:56.828692 INFO: (991797) [] Processing is complete and resulted in 48 results.
2024-09-26T00:03:56.828740 INFO: (991797) [] Processing is complete. Transmitting resulting Message back to client.
----------------------------------------------------------------------------------------- Captured log call -----------------------------------------------------------------------------------------
INFO     log:ExplianableDTD_db.py:109 Connecting to database
========================================================================================= warnings summary ==========================================================================================
../../../../../../python/Python-3.9.18/lib/python3.9/site-packages/connexion/decorators/validation.py:16
../../../../../../python/Python-3.9.18/lib/python3.9/site-packages/connexion/decorators/validation.py:16
  /mnt/data/python/Python-3.9.18/lib/python3.9/site-packages/connexion/decorators/validation.py:16: DeprecationWarning: Accessing jsonschema.draft4_format_checker is deprecated and will be removed in a future release. Instead, use the FORMAT_CHECKER attribute on the corresponding Validator.
    from jsonschema import Draft4Validator, ValidationError, draft4_format_checker

../ARAXQuery/ARAX_query_tracker.py:29
  /mnt/data/orangeboard/test/RTX/code/ARAX/ARAXQuery/ARAX_query_tracker.py:29: MovedIn20Warning: Deprecated API features detected! These feature(s) are not compatible with SQLAlchemy 2.0. To prevent incompatible upgrades prior to updating applications, ensure requirements files are pinned to "sqlalchemy<2.0". Set environment variable SQLALCHEMY_WARN_20=1 to show all deprecation warnings.  Set environment variable SQLALCHEMY_SILENCE_UBER_WARNING=1 to silence this message. (Background on SQLAlchemy 2.0 at: https://sqlalche.me/e/b8d9)
    Base = declarative_base()

../../../../../../python/Python-3.9.18/lib/python3.9/site-packages/pydantic/_internal/_config.py:284
  /mnt/data/python/Python-3.9.18/lib/python3.9/site-packages/pydantic/_internal/_config.py:284: PydanticDeprecatedSince20: Support for class-based `config` is deprecated, use ConfigDict instead. Deprecated in Pydantic V2.0 to be removed in V3.0. See Pydantic V2 Migration Guide at https://errors.pydantic.dev/2.7/migration/
    warnings.warn(DEPRECATION_MESSAGE, DeprecationWarning)

test_ARAX_expand.py::test_treats_patch_issue_2328
  /mnt/data/orangeboard/test/RTX/code/ARAX/ARAXQuery/Expand/trapi_querier.py:253: DeprecationWarning: verify_ssl is deprecated, use ssl=False instead
    async with aiohttp.ClientSession(connector=aiohttp.TCPConnector(verify_ssl=False)) as session:

test_ARAX_expand.py: 96 warnings
  /mnt/data/python/Python-3.9.18/lib/python3.9/site-packages/networkx/convert_matrix.py:579: DeprecationWarning: to_numpy_matrix is deprecated and will be removed in NetworkX 3.0.
  Use to_numpy_array instead, e.g. np.asmatrix(to_numpy_array(G, **kwargs))
    warnings.warn(

test_ARAX_expand.py: 96 warnings
  /mnt/data/python/Python-3.9.18/lib/python3.9/site-packages/numpy/matrixlib/defmatrix.py:69: PendingDeprecationWarning: the matrix subclass is not the recommended way to represent matrices or deal with linear algebra (see https://docs.scipy.org/doc/numpy/user/numpy-for-matlab-users.html). Please adjust your code to use regular ndarray.
    return matrix(data, dtype=dtype, copy=False)

-- Docs: https://docs.pytest.org/en/stable/how-to/capture-warnings.html
====================================================================================== short test summary info ======================================================================================
FAILED test_ARAX_expand.py::test_treats_patch_issue_2328 - AssertionError: assert 'biolink:applied_to_treat' == 'biolink:treats'
========================================================================== 1 failed, 71 deselected, 197 warnings in 16.42s ==========================================================================
rt@4342e0c91621:/mnt/data/orangeboard/test/RTX/code/ARAX/test$ 
amykglen commented 1 month ago

thanks - ok, starting to narrow down the problem - it looks like, for some reason, arax.ncats.io says these are the only treats-like predicates: 2024-09-26T00:03:48.588294 INFO: (991797) [] Treats-like predicates are: {'biolink:treats_or_applied_or_studied_to_treat'}

whereas locally, this is what that line looks like: 2024-09-25T16:49:54.855537 INFO: (11449) [] Treats-like predicates are: {'biolink:treats_or_applied_or_studied_to_treat', 'biolink:applied_to_treat', 'biolink:beneficial_in_models_for', 'biolink:ameliorates_condition', 'biolink:in_clinical_trials_for', 'biolink:in_preclinical_trials_for', 'biolink:studied_to_treat', 'biolink:preventative_for_condition'}

that is the cause of the failing test - as for why arax.ncats.io has the wrong predicates, I'm not sure yet... that set is retrieved from BiolinkHelper, here: https://github.com/RTXteam/RTX/blob/9a1a97e31d695792a3e9097dea64fcb50427b7fc/code/ARAX/ARAXQuery/ARAX_expander.py#L63 and the current BiolinkHelper (in master) indeed returns the full list of 8 predicates that are descendants of treats_or_applied_or_studied_to_treat:

(rtxspring23) MacBook-Pro:BiolinkHelper amyglen$ python biolink_helper.py 
2024-09-25T17:27:14.514500: DEBUG: In BiolinkHelper init
2024-09-25T17:27:14.515545: DEBUG: Loading BL lookup map...
2024-09-25T17:27:14.515565: DEBUG: in test mode
2024-09-25T17:27:14.515571: INFO: Building local Biolink 4.2.1 ancestor/descendant lookup map because one doesn't yet exist
2024-09-25T17:27:15.839687: DEBUG: Done loading BL lookup map
Descendants of 'biolink:treats_or_applied_or_studied_to_treat are: 
['biolink:treats', 'biolink:in_clinical_trials_for', 'biolink:beneficial_in_models_for', 'biolink:ameliorates_condition', 'biolink:studied_to_treat', 'biolink:preventative_for_condition', 'biolink:applied_to_treat', 'biolink:treats_or_applied_or_studied_to_treat', 'biolink:in_preclinical_trials_for']
All BiolinkHelper tests passed!

I remember a merging of BiolinkHelper code was done recently (and possibly had some conflicts that had to be resolved?) - I wonder if something could've gone wrong there? very strange..

amykglen commented 1 month ago

looked back at commits and there actually doesn't appear to be any merges that happened in biolink_helper.py recently, so scratch that

but I added one more log message to master that reports the Biolink version that BiolinkHelper is using. if that appears normal, I will probably need to wait until I have access to arax.ncats.io and can poke around the code there

edeutsch commented 1 month ago

This is what I see:

rt@4342e0c91621:/mnt/data/orangeboard/test/RTX/code/ARAX$ pwd
/mnt/data/orangeboard/test/RTX/code/ARAX
rt@4342e0c91621:/mnt/data/orangeboard/test/RTX/code/ARAX$ git diff ./BiolinkHelper/biolink_helper.py
rt@4342e0c91621:/mnt/data/orangeboard/test/RTX/code/ARAX$ git status ./BiolinkHelper/biolink_helper.py
On branch master
Your branch is up to date with 'origin/master'.

nothing to commit, working tree clean

rt@4342e0c91621:/mnt/data/orangeboard/test/RTX/code/ARAX$ ll BiolinkHelper/
total 5392
drwxrwxr-x  3 rt rt   4096 Sep 12 03:04 ./
drwxrwxr-x 13 rt rt   4096 Apr 15 18:40 ../
-rw-rw-r--  1 rt rt     15 Aug 17  2021 .gitignore
-rw-rw-r--  1 rt rt   2803 Aug 17  2021 README.md
drwxr-xr-x  2 rt rt   4096 Sep 12 03:04 __pycache__/
-rw-rw-r--  1 rt rt  31956 Sep 12 03:04 biolink_helper.py
-rw-r--r--  1 rt rt 387498 Aug 17  2021 biolink_lookup_map_2.1.0.json
-rw-r--r--  1 rt rt  91162 Aug 17  2021 biolink_lookup_map_2.1.0.pickle
-rw-r--r--  1 rt rt 407553 Aug 24  2021 biolink_lookup_map_2.1.0_v3.json
-rw-r--r--  1 rt rt 102869 Aug 24  2021 biolink_lookup_map_2.1.0_v3.pickle
-rw-r--r--  1 rt rt 495236 May 18  2022 biolink_lookup_map_2.2.11_v3.json
-rw-r--r--  1 rt rt 115414 May 18  2022 biolink_lookup_map_2.2.11_v3.pickle
-rw-r--r--  1 rt rt 478081 Nov 15  2021 biolink_lookup_map_2.2.6_v3.json
-rw-r--r--  1 rt rt 109498 Nov 15  2021 biolink_lookup_map_2.2.6_v3.pickle
-rw-r--r--  1 rt rt 576318 Jan 11  2023 biolink_lookup_map_3.0.3_v3.json
-rw-r--r--  1 rt rt  88022 Jan 11  2023 biolink_lookup_map_3.0.3_v3.pickle
-rw-r--r--  1 rt rt 434625 May 24  2023 biolink_lookup_map_3.1.2_v3.json
-rw-r--r--  1 rt rt  61551 May 24  2023 biolink_lookup_map_3.1.2_v3.pickle
-rw-r--r--  1 rt rt 432593 Jul  5  2023 biolink_lookup_map_3.1.2_v4.json
-rw-r--r--  1 rt rt  61135 Jul  5  2023 biolink_lookup_map_3.1.2_v4.pickle
-rw-r--r--  1 rt rt 452299 Apr 15 18:32 biolink_lookup_map_4.0.0_v4.json
-rw-r--r--  1 rt rt  64357 Apr 15 18:32 biolink_lookup_map_4.0.0_v4.pickle
-rw-r--r--  1 rt rt 461515 Jul  3 18:38 biolink_lookup_map_4.1.0_v4.json
-rw-r--r--  1 rt rt  65998 Jul  3 18:38 biolink_lookup_map_4.1.0_v4.pickle
-rw-r--r--  1 rt rt 473714 Aug 12 16:15 biolink_lookup_map_4.2.1_v4.json
-rw-r--r--  1 rt rt  69275 Aug 12 16:15 biolink_lookup_map_4.2.1_v4.pickle
rt@4342e0c91621:/mnt/data/orangeboard/test/RTX/code/ARAX$ 
amykglen commented 1 month ago

ohh, hmm, one idea - can you try deleting these files:

biolink_lookup_map_4.2.1_v4.json
biolink_lookup_map_4.2.1_v4.pickle

and then try running the test again?

amykglen commented 1 month ago

or alternatively - just pull from master and try rerunning the test?

(I should have bumped BiolinkHelper's subversion from v4 --> v5 when I made some changes to it a month or so ago, just fixed that)

edeutsch commented 1 month ago

yes!

$ git pull
 code/ARAX/ARAXQuery/ARAX_expander.py      | 1 +
 code/ARAX/BiolinkHelper/biolink_helper.py | 2 +-

$ pytest -v test_ARAX_expand.py -k test_treats_patch_issue_2328
test_ARAX_expand.py::test_treats_patch_issue_2328 PASSED                                                                                                                                                                                [100%]

thank you!

edeutsch commented 1 month ago

all tests now passing on arax.ncats.io, closing!