From 29a2b3ef147447ce333ed5b558cce8acfc42a829 Mon Sep 17 00:00:00 2001 From: abdollahis2 Date: Fri, 28 Jun 2024 10:27:32 -0400 Subject: [PATCH 1/7] modified error handling for node annotator --- tr_sys/tr_ars/utils.py | 61 +++++++++++++++++++++++------------------- 1 file changed, 34 insertions(+), 27 deletions(-) diff --git a/tr_sys/tr_ars/utils.py b/tr_sys/tr_ars/utils.py index 6036c6e3..0a6e981f 100644 --- a/tr_sys/tr_ars/utils.py +++ b/tr_sys/tr_ars/utils.py @@ -44,7 +44,7 @@ } NORMALIZER_URL=os.getenv("TR_NORMALIZER") if os.getenv("TR_NORMALIZER") is not None else "https://nodenormalization-sri.renci.org/1.4/get_normalized_nodes" -ANNOTATOR_URL=os.getenv("TR_ANNOTATOR") if os.getenv("TR_ANNOTATOR") is not None else "https://biothings.ncats.io/annotator/" +ANNOTATOR_URL=os.getenv("TR_ANNOTATOR") if os.getenv("TR_ANNOTATOR") is not None else "https://biothings.test.ncats.io/annotator/" APPRAISER_URL=os.getenv("TR_APPRAISE") if os.getenv("TR_APPRAISE") is not None else "http://localhost:9096/get_appraisal" @@ -551,36 +551,46 @@ def pre_merge_process(data,key, agent_name,inforesid): logging.exception("Error in ARS score normalization") raise e - def post_process(data,key, agent_name): code =200 + status='D' mesg = get_object_or_404(Message.objects.filter(pk=key)) logging.info("Pre node annotation for agent %s pk: %s" % (agent_name, str(key))) try: annotate_nodes(mesg,data,agent_name) logging.info("node annotation successful for agent %s and pk: %s" % (agent_name, str(key))) except Exception as e: + status='E' + code=444 post_processing_error(mesg,data,"Error in annotation of nodes") - logging.error("Error with node annotations for "+str(key)) - logging.exception("problem with node annotation post process function") - raise e + logging.exception(f"problem with node annotation for agent: {agent_name} pk: {str(key)}") + logging.info("pre scrub null for agent %s and pk %s" % (agent_name, str(key))) try: scrub_null_attributes(data) except Exception as e: - logging.info("Problem with the second scrubbing of null attributes") + status='E' + code=444 + logging.exception(f"Problem with the second scrubbing of null attributes for agent: {agent_name} pk: {str(key)}") logging.info("pre blocklist for "+str(key)) try: remove_blocked(mesg, data) except Exception as e: + status='E' + code=444 logging.info(e.__cause__) - logging.info("Problem with block list removal") + logging.exception(f"Problem with block list removal for agent: {agent_name} pk: {str(key)}") + + mesg.status=status + mesg.code=code + mesg.save(update_fields=['status','code']) logging.info("pre appraiser for agent %s and pk %s" % (agent_name, str(key))) try: appraise(mesg,data,agent_name) logging.info("appraiser successful for agent %s and pk %s" % (agent_name, str(key))) except Exception as e: - code = 422 + mesg.status='E' + mesg.code = 422 results = get_safe(data,"message","results") default_ordering_component = { "novelty": 0, @@ -596,10 +606,9 @@ def post_process(data,key, agent_name): else: logging.error('results returned from appraiser is None') - #post_processing_error(mesg,data,"Error in appraiser") - logging.error("Error with appraise for "+str(key)) - logging.exception("Error in appraiser post process function") - #raise e + #logging.exception(f"Problem with appraiser for agent: {agent_name} pk: {str(key)}") + mesg.save(update_fields=['status','code']) + raise e try: results = get_safe(data,"message","results") if results is not None: @@ -611,8 +620,11 @@ def post_process(data,key, agent_name): logging.error('results from appraiser returns None, cant do the scoring') print() except Exception as e: + mesg.status='E' + mesg.code = 422 post_processing_error(mesg,data,"Error in f-score calculation") logging.exception("Error in f-score calculation") + mesg.save(update_fields=['status','code']) raise e try: @@ -625,8 +637,8 @@ def post_process(data,key, agent_name): mesg.code=400 mesg.save(update_fields=['status','code']) try: - mesg.status='D' - mesg.code=200 + mesg.status=status + mesg.code=code mesg.save_compressed_dict(data) logging.info("Time before save") with transaction.atomic(): @@ -693,12 +705,12 @@ def merge_and_post_process(parent_pk,message_to_merge, agent_name, counter=0): logging.info('post processing complete for agent %s with pk %s is returned & ready to be preprocessed' % (agent_name, str(merged.id))) except Exception as e: - logging.info("Problem with post processing for agent %s pk: %s " % (agent_name, (parent_pk))) - logging.info(e, exc_info=True) - logging.info('error message %s' % str(e)) - merged.status='E' - merged.code = 422 - merged.save() + logging.exception("Problem with one/more post processing steps for agent %s pk: %s " % (agent_name, (parent_pk))) + # logging.info(e, exc_info=True) + # logging.info('error message %s' % str(e)) + # merged.status='E' + # merged.code = 422 + # merged.save() def remove_blocked(mesg, data, blocklist=None): try: @@ -947,10 +959,7 @@ def appraise(mesg,data, agent_name,retry_counter=0): logging.error("3 consecutive Errors from appraise for agent %s and pk %s " % (agent_name,str(mesg.id))) raise Exception except Exception as e: - - logging.error("Problem with appraiser for agent %s and pk %s " % (agent_name,str(mesg.id))) - logging.error(type(e).__name__) - logging.error(e.args) + logging.error("Problem with appraiser for agent %s and pk %s of type %s" % (agent_name,str(mesg.id),type(e).__name__)) logging.error("Adding default ordering_components for agent %s and pk %s " % (agent_name,str(mesg.id))) raise e @@ -1002,9 +1011,7 @@ def annotate_nodes(mesg,data,agent_name): else: post_processing_error(mesg,data,"Error in annotation of nodes") except Exception as e: - logging.info('node annotation internal error msg is for agent %s with pk: %s is %s' % (agent_name,str(mesg.pk),str(e))) - logging.exception("error in node annotation internal function") - + logging.exception('node annotation internal error msg is for agent %s with pk: %s is %s' % (agent_name,str(mesg.pk),str(e))) raise e #else: # with open(str(mesg.actor)+".json", "w") as outfile: From 71f363b9f7a97638db606e305fd1532901d5e270 Mon Sep 17 00:00:00 2001 From: abdollahis2 Date: Fri, 28 Jun 2024 10:31:22 -0400 Subject: [PATCH 2/7] fixing the annotator url --- tr_sys/tr_ars/utils.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tr_sys/tr_ars/utils.py b/tr_sys/tr_ars/utils.py index 0a6e981f..df02806a 100644 --- a/tr_sys/tr_ars/utils.py +++ b/tr_sys/tr_ars/utils.py @@ -44,7 +44,7 @@ } NORMALIZER_URL=os.getenv("TR_NORMALIZER") if os.getenv("TR_NORMALIZER") is not None else "https://nodenormalization-sri.renci.org/1.4/get_normalized_nodes" -ANNOTATOR_URL=os.getenv("TR_ANNOTATOR") if os.getenv("TR_ANNOTATOR") is not None else "https://biothings.test.ncats.io/annotator/" +ANNOTATOR_URL=os.getenv("TR_ANNOTATOR") if os.getenv("TR_ANNOTATOR") is not None else "https://biothings.ncats.io/annotator/" APPRAISER_URL=os.getenv("TR_APPRAISE") if os.getenv("TR_APPRAISE") is not None else "http://localhost:9096/get_appraisal" From 45416017d3c18f924109a9010f541d208041ef11 Mon Sep 17 00:00:00 2001 From: abdollahis2 Date: Fri, 28 Jun 2024 11:11:11 -0400 Subject: [PATCH 3/7] added more logging for exceptions --- tr_sys/tr_ars/utils.py | 41 +++++++++++++++++++++++++++++++++-------- 1 file changed, 33 insertions(+), 8 deletions(-) diff --git a/tr_sys/tr_ars/utils.py b/tr_sys/tr_ars/utils.py index df02806a..b6ca0ee8 100644 --- a/tr_sys/tr_ars/utils.py +++ b/tr_sys/tr_ars/utils.py @@ -562,7 +562,6 @@ def post_process(data,key, agent_name): except Exception as e: status='E' code=444 - post_processing_error(mesg,data,"Error in annotation of nodes") logging.exception(f"problem with node annotation for agent: {agent_name} pk: {str(key)}") logging.info("pre scrub null for agent %s and pk %s" % (agent_name, str(key))) @@ -572,6 +571,13 @@ def post_process(data,key, agent_name): status='E' code=444 logging.exception(f"Problem with the second scrubbing of null attributes for agent: {agent_name} pk: {str(key)}") + post_processing_error(mesg,data,"Error in second scrubbing of null attributes") + log_tuple =[ + "Error in second scrubbing of null attributes", + datetime.now().strftime('%H:%M:%S'), + "DEBUG" + ] + add_log_entry(data,log_tuple) logging.info("pre blocklist for "+str(key)) try: remove_blocked(mesg, data) @@ -606,7 +612,6 @@ def post_process(data,key, agent_name): else: logging.error('results returned from appraiser is None') - #logging.exception(f"Problem with appraiser for agent: {agent_name} pk: {str(key)}") mesg.save(update_fields=['status','code']) raise e try: @@ -624,6 +629,12 @@ def post_process(data,key, agent_name): mesg.code = 422 post_processing_error(mesg,data,"Error in f-score calculation") logging.exception("Error in f-score calculation") + log_tuple =[ + "Error in Score computation from result", + datetime.now().strftime('%H:%M:%S'), + "ERROR" + ] + add_log_entry(data,log_tuple) mesg.save(update_fields=['status','code']) raise e @@ -632,7 +643,14 @@ def post_process(data,key, agent_name): mesg.result_stat = ScoreStatCalc(new_res) except Exception as e: logging.exception("Error in ScoreStatCalculation or result count") + post_processing_error(mesg,data,"Error in score stat calculation") raise e + log_tuple =[ + "Error in score stat calculation", + datetime.now().strftime('%H:%M:%S'), + "DEBUG" + ] + add_log_entry(data,log_tuple) mesg.status ='E' mesg.code=400 mesg.save(update_fields=['status','code']) @@ -961,6 +979,12 @@ def appraise(mesg,data, agent_name,retry_counter=0): except Exception as e: logging.error("Problem with appraiser for agent %s and pk %s of type %s" % (agent_name,str(mesg.id),type(e).__name__)) logging.error("Adding default ordering_components for agent %s and pk %s " % (agent_name,str(mesg.id))) + log_tuple =[ + "Error in Appraiser: "+ str(e), + datetime.now().strftime('%H:%M:%S'), + "ERROR" + ] + add_log_entry(data,log_tuple) raise e @@ -1013,11 +1037,12 @@ def annotate_nodes(mesg,data,agent_name): except Exception as e: logging.exception('node annotation internal error msg is for agent %s with pk: %s is %s' % (agent_name,str(mesg.pk),str(e))) raise e - #else: - # with open(str(mesg.actor)+".json", "w") as outfile: - # outfile.write(json_data) - # post_processing_error(mesg,data,"Error in annotation of nodes") - + log_tuple =[ + 'node annotation internal error: '+ str(e), + datetime.now().strftime('%H:%M:%S'), + "DEBUG" + ] + add_log_entry(data,log_tuple) def normalize_scores(data,key, agent_name): res=get_safe(data,"message","results") @@ -1087,7 +1112,7 @@ def post_processing_error(mesg,data,text): mesg.code = 206 log_tuple=[text, (mesg.updated_at).strftime('%H:%M:%S'), - "WARNING"] + "DEBUG"] logging.info(f'the log_tuple is %s'% log_tuple) add_log_entry(data,log_tuple) From 23a2d16b16a3809a7a78e0273b3bd53637385fcc Mon Sep 17 00:00:00 2001 From: abdollahis2 Date: Fri, 28 Jun 2024 11:49:33 -0400 Subject: [PATCH 4/7] added more logging for exceptions --- tr_sys/tr_ars/utils.py | 29 ++++++++++++++--------------- 1 file changed, 14 insertions(+), 15 deletions(-) diff --git a/tr_sys/tr_ars/utils.py b/tr_sys/tr_ars/utils.py index b6ca0ee8..a08ffb05 100644 --- a/tr_sys/tr_ars/utils.py +++ b/tr_sys/tr_ars/utils.py @@ -44,7 +44,7 @@ } NORMALIZER_URL=os.getenv("TR_NORMALIZER") if os.getenv("TR_NORMALIZER") is not None else "https://nodenormalization-sri.renci.org/1.4/get_normalized_nodes" -ANNOTATOR_URL=os.getenv("TR_ANNOTATOR") if os.getenv("TR_ANNOTATOR") is not None else "https://biothings.ncats.io/annotator/" +ANNOTATOR_URL=os.getenv("TR_ANNOTATOR") if os.getenv("TR_ANNOTATOR") is not None else "https://biothings.test.ncats.io/annotator/" APPRAISER_URL=os.getenv("TR_APPRAISE") if os.getenv("TR_APPRAISE") is not None else "http://localhost:9096/get_appraisal" @@ -562,6 +562,12 @@ def post_process(data,key, agent_name): except Exception as e: status='E' code=444 + log_tuple =[ + f'node annotation internal error: {str(e)}', + datetime.now().strftime('%H:%M:%S'), + "DEBUG" + ] + add_log_entry(data,log_tuple) logging.exception(f"problem with node annotation for agent: {agent_name} pk: {str(key)}") logging.info("pre scrub null for agent %s and pk %s" % (agent_name, str(key))) @@ -611,7 +617,12 @@ def post_process(data,key, agent_name): continue else: logging.error('results returned from appraiser is None') - + log_tuple =[ + "Error in Appraiser: "+ str(e), + datetime.now().strftime('%H:%M:%S'), + "ERROR" + ] + add_log_entry(data,log_tuple) mesg.save(update_fields=['status','code']) raise e try: @@ -630,7 +641,7 @@ def post_process(data,key, agent_name): post_processing_error(mesg,data,"Error in f-score calculation") logging.exception("Error in f-score calculation") log_tuple =[ - "Error in Score computation from result", + "Error in f-score calculation", datetime.now().strftime('%H:%M:%S'), "ERROR" ] @@ -979,12 +990,6 @@ def appraise(mesg,data, agent_name,retry_counter=0): except Exception as e: logging.error("Problem with appraiser for agent %s and pk %s of type %s" % (agent_name,str(mesg.id),type(e).__name__)) logging.error("Adding default ordering_components for agent %s and pk %s " % (agent_name,str(mesg.id))) - log_tuple =[ - "Error in Appraiser: "+ str(e), - datetime.now().strftime('%H:%M:%S'), - "ERROR" - ] - add_log_entry(data,log_tuple) raise e @@ -1037,12 +1042,6 @@ def annotate_nodes(mesg,data,agent_name): except Exception as e: logging.exception('node annotation internal error msg is for agent %s with pk: %s is %s' % (agent_name,str(mesg.pk),str(e))) raise e - log_tuple =[ - 'node annotation internal error: '+ str(e), - datetime.now().strftime('%H:%M:%S'), - "DEBUG" - ] - add_log_entry(data,log_tuple) def normalize_scores(data,key, agent_name): res=get_safe(data,"message","results") From af4bf2c3628a4ad1f2f1965f1071f2e160213d14 Mon Sep 17 00:00:00 2001 From: abdollahis2 Date: Fri, 28 Jun 2024 11:50:30 -0400 Subject: [PATCH 5/7] fixed annotator URL --- tr_sys/tr_ars/utils.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tr_sys/tr_ars/utils.py b/tr_sys/tr_ars/utils.py index a08ffb05..a4331788 100644 --- a/tr_sys/tr_ars/utils.py +++ b/tr_sys/tr_ars/utils.py @@ -44,7 +44,7 @@ } NORMALIZER_URL=os.getenv("TR_NORMALIZER") if os.getenv("TR_NORMALIZER") is not None else "https://nodenormalization-sri.renci.org/1.4/get_normalized_nodes" -ANNOTATOR_URL=os.getenv("TR_ANNOTATOR") if os.getenv("TR_ANNOTATOR") is not None else "https://biothings.test.ncats.io/annotator/" +ANNOTATOR_URL=os.getenv("TR_ANNOTATOR") if os.getenv("TR_ANNOTATOR") is not None else "https://biothings.ncats.io/annotator/" APPRAISER_URL=os.getenv("TR_APPRAISE") if os.getenv("TR_APPRAISE") is not None else "http://localhost:9096/get_appraisal" From 3bd5b728a292e0919cae8f197cec3c45f02f4071 Mon Sep 17 00:00:00 2001 From: abdollahis2 Date: Mon, 1 Jul 2024 15:03:48 -0400 Subject: [PATCH 6/7] first draft in seperating the error codes --- tr_sys/tr_ars/utils.py | 187 ++++++++++++++++++++--------------------- 1 file changed, 92 insertions(+), 95 deletions(-) diff --git a/tr_sys/tr_ars/utils.py b/tr_sys/tr_ars/utils.py index a4331788..ec0eb936 100644 --- a/tr_sys/tr_ars/utils.py +++ b/tr_sys/tr_ars/utils.py @@ -44,7 +44,7 @@ } NORMALIZER_URL=os.getenv("TR_NORMALIZER") if os.getenv("TR_NORMALIZER") is not None else "https://nodenormalization-sri.renci.org/1.4/get_normalized_nodes" -ANNOTATOR_URL=os.getenv("TR_ANNOTATOR") if os.getenv("TR_ANNOTATOR") is not None else "https://biothings.ncats.io/annotator/" +ANNOTATOR_URL=os.getenv("TR_ANNOTATOR") if os.getenv("TR_ANNOTATOR") is not None else "https://biothings.test.ncats.io/annotator/" APPRAISER_URL=os.getenv("TR_APPRAISE") if os.getenv("TR_APPRAISE") is not None else "http://localhost:9096/get_appraisal" @@ -551,10 +551,9 @@ def pre_merge_process(data,key, agent_name,inforesid): logging.exception("Error in ARS score normalization") raise e -def post_process(data,key, agent_name): - code =200 - status='D' - mesg = get_object_or_404(Message.objects.filter(pk=key)) +def post_process(mesg,key, agent_name): + + data = mesg.decompress_dict() logging.info("Pre node annotation for agent %s pk: %s" % (agent_name, str(key))) try: annotate_nodes(mesg,data,agent_name) @@ -599,86 +598,68 @@ def post_process(data,key, agent_name): logging.info("pre appraiser for agent %s and pk %s" % (agent_name, str(key))) try: appraise(mesg,data,agent_name) - logging.info("appraiser successful for agent %s and pk %s" % (agent_name, str(key))) + logging.info("appraiser returned with code: %s and status: %s" % (mesg.code, mesg.status)) except Exception as e: - mesg.status='E' - mesg.code = 422 - results = get_safe(data,"message","results") - default_ordering_component = { - "novelty": 0, - "confidence": 0, - "clinical_evidence": 0 - } - if results is not None: - for result in results: - if 'ordering_components' not in result.keys(): - result['ordering_components']=default_ordering_component - else: - continue - else: - logging.error('results returned from appraiser is None') - log_tuple =[ - "Error in Appraiser: "+ str(e), + logging.ERROR("appraiser failed mesg for agent %s is %s: %s"% (agent_name, mesg.code, mesg.status)) + + if mesg.code == 422: + return mesg, mesg.code, mesg.status + else: + try: + results = get_safe(data,"message","results") + if results is not None: + logging.info("+++ pre-scoring for agent: %s & pk: %s" % (agent_name, key)) + new_res=scoring.compute_from_results(results) + data['message']['results']=new_res + logging.info("scoring succeeded for agent %s and pk %s" % (agent_name, key)) + else: + logging.error('results from appraiser returns None, cant do the scoring') + print() + except Exception as e: + status='E' + code = 422 + mesg.save(update_fields=['status','code']) + log_tuple =[ + "Error in f-score calculation: "+ str(e), datetime.now().strftime('%H:%M:%S'), "ERROR" ] - add_log_entry(data,log_tuple) - mesg.save(update_fields=['status','code']) - raise e - try: - results = get_safe(data,"message","results") - if results is not None: - logging.info("+++ pre-scoring for agent: %s & pk: %s" % (agent_name, key)) - new_res=scoring.compute_from_results(results) - data['message']['results']=new_res - logging.info("scoring succeeded for agent %s and pk %s" % (agent_name, key)) - else: - logging.error('results from appraiser returns None, cant do the scoring') - print() - except Exception as e: - mesg.status='E' - mesg.code = 422 - post_processing_error(mesg,data,"Error in f-score calculation") - logging.exception("Error in f-score calculation") - log_tuple =[ - "Error in f-score calculation", - datetime.now().strftime('%H:%M:%S'), - "ERROR" - ] - add_log_entry(data,log_tuple) - mesg.save(update_fields=['status','code']) - raise e + add_log_entry(data,log_tuple) + logging.exception("Error in f-score calculation") + mesg.save_compressed_dict(data) + return mesg, code, status + + try: + mesg.result_count = len(new_res) + mesg.result_stat = ScoreStatCalc(new_res) + logging.info("scoring stat calculation succeeded for agent %s and pk %s" % (agent_name, key)) + except Exception as e: + logging.exception("Error in ScoreStatCalculation or result count") + post_processing_error(mesg,data,"Error in score stat calculation") + log_tuple =[ + "Error in score stat calculation", + datetime.now().strftime('%H:%M:%S'), + "DEBUG" + ] + add_log_entry(data,log_tuple) + status ='E' + code=400 + mesg.save_compressed_dict(data) + return mesg, code, status + + try: + mesg.save_compressed_dict(data) + logging.info("Time before save") + with transaction.atomic(): + mesg.save() + logging.info("Time after save") + + except DatabaseError as e: + status ='E' + code=422 + logging.error("Final save failed") + return mesg, code, status - try: - mesg.result_count = len(new_res) - mesg.result_stat = ScoreStatCalc(new_res) - except Exception as e: - logging.exception("Error in ScoreStatCalculation or result count") - post_processing_error(mesg,data,"Error in score stat calculation") - raise e - log_tuple =[ - "Error in score stat calculation", - datetime.now().strftime('%H:%M:%S'), - "DEBUG" - ] - add_log_entry(data,log_tuple) - mesg.status ='E' - mesg.code=400 - mesg.save(update_fields=['status','code']) - try: - mesg.status=status - mesg.code=code - mesg.save_compressed_dict(data) - logging.info("Time before save") - with transaction.atomic(): - mesg.save() - logging.info("Time after save") - except DatabaseError as e: - mesg.status ='E' - mesg.code=422 - logging.error("Final save failed") - mesg.save(update_fields=['status','code']) - def lock_merge(message): pass if message.merge_semaphore is True: @@ -727,19 +708,12 @@ def merge_and_post_process(parent_pk,message_to_merge, agent_name, counter=0): logging.debug("Merging failed for %s %s" % (agent_name, str(parent_pk))) if merged is not None: - try: - logging.info('merged data for agent %s with pk %s is returned & ready to be preprocessed' % (agent_name, str(merged.id))) - merged_data = merged.decompress_dict() - post_process(merged_data,merged.id, agent_name) - logging.info('post processing complete for agent %s with pk %s is returned & ready to be preprocessed' % (agent_name, str(merged.id))) - - except Exception as e: - logging.exception("Problem with one/more post processing steps for agent %s pk: %s " % (agent_name, (parent_pk))) - # logging.info(e, exc_info=True) - # logging.info('error message %s' % str(e)) - # merged.status='E' - # merged.code = 422 - # merged.save() + logging.info('merged data for agent %s with pk %s is returned & ready to be preprocessed' % (agent_name, str(merged.id))) + merged, code, status = post_process(merged,merged.id, agent_name) + logging.info('post processing complete for agent %s with pk %s is returned & ready to be preprocessed' % (agent_name, str(merged.id))) + merged.status = status + merged.code = code + merged.save() def remove_blocked(mesg, data, blocklist=None): try: @@ -990,8 +964,31 @@ def appraise(mesg,data, agent_name,retry_counter=0): except Exception as e: logging.error("Problem with appraiser for agent %s and pk %s of type %s" % (agent_name,str(mesg.id),type(e).__name__)) logging.error("Adding default ordering_components for agent %s and pk %s " % (agent_name,str(mesg.id))) - raise e - + results = get_safe(data,"message","results") + default_ordering_component = { + "novelty": 0, + "confidence": 0, + "clinical_evidence": 0 + } + if results is not None: + for result in results: + if 'ordering_components' not in result.keys(): + result['ordering_components']=default_ordering_component + else: + continue + else: + logging.error('results returned from appraiser is None') + log_tuple =[ + "Error in Appraiser: "+ str(e), + datetime.now().strftime('%H:%M:%S'), + "ERROR" + ] + add_log_entry(data,log_tuple) + mesg.save_compressed_dict(data) + mesg.status='E' + mesg.code = 422 + mesg.save(update_fields=['status','code']) + def annotate_nodes(mesg,data,agent_name): #TODO pull this URL from SmartAPI From cc830444a795c33d923dc16c9b3c204fc3d4d415 Mon Sep 17 00:00:00 2001 From: abdollahis2 Date: Tue, 2 Jul 2024 09:15:19 -0400 Subject: [PATCH 7/7] added more precise logging for annatator & appraiser failing --- tr_sys/tr_ars/utils.py | 23 +++++++++++++++++------ 1 file changed, 17 insertions(+), 6 deletions(-) diff --git a/tr_sys/tr_ars/utils.py b/tr_sys/tr_ars/utils.py index ec0eb936..0e2a653c 100644 --- a/tr_sys/tr_ars/utils.py +++ b/tr_sys/tr_ars/utils.py @@ -44,7 +44,7 @@ } NORMALIZER_URL=os.getenv("TR_NORMALIZER") if os.getenv("TR_NORMALIZER") is not None else "https://nodenormalization-sri.renci.org/1.4/get_normalized_nodes" -ANNOTATOR_URL=os.getenv("TR_ANNOTATOR") if os.getenv("TR_ANNOTATOR") is not None else "https://biothings.test.ncats.io/annotator/" +ANNOTATOR_URL=os.getenv("TR_ANNOTATOR") if os.getenv("TR_ANNOTATOR") is not None else "https://biothings.ncats.io/annotator/" APPRAISER_URL=os.getenv("TR_APPRAISE") if os.getenv("TR_APPRAISE") is not None else "http://localhost:9096/get_appraisal" @@ -568,6 +568,9 @@ def post_process(mesg,key, agent_name): ] add_log_entry(data,log_tuple) logging.exception(f"problem with node annotation for agent: {agent_name} pk: {str(key)}") + mesg.status=status + mesg.code=code + mesg.save() logging.info("pre scrub null for agent %s and pk %s" % (agent_name, str(key))) try: @@ -583,6 +586,9 @@ def post_process(mesg,key, agent_name): "DEBUG" ] add_log_entry(data,log_tuple) + mesg.status=status + mesg.code=code + mesg.save() logging.info("pre blocklist for "+str(key)) try: remove_blocked(mesg, data) @@ -591,14 +597,13 @@ def post_process(mesg,key, agent_name): code=444 logging.info(e.__cause__) logging.exception(f"Problem with block list removal for agent: {agent_name} pk: {str(key)}") + mesg.status=status + mesg.code=code + mesg.save() - mesg.status=status - mesg.code=code - mesg.save(update_fields=['status','code']) logging.info("pre appraiser for agent %s and pk %s" % (agent_name, str(key))) try: appraise(mesg,data,agent_name) - logging.info("appraiser returned with code: %s and status: %s" % (mesg.code, mesg.status)) except Exception as e: logging.ERROR("appraiser failed mesg for agent %s is %s: %s"% (agent_name, mesg.code, mesg.status)) @@ -650,7 +655,13 @@ def post_process(mesg,key, agent_name): try: mesg.save_compressed_dict(data) logging.info("Time before save") + logging.info('the mesg before save code: %s and status: %s'%(mesg.code, mesg.status)) with transaction.atomic(): + if mesg.code == 202: + code = 200 + status='D' + mesg.code=code + mesg.status=status mesg.save() logging.info("Time after save") @@ -979,7 +990,7 @@ def appraise(mesg,data, agent_name,retry_counter=0): else: logging.error('results returned from appraiser is None') log_tuple =[ - "Error in Appraiser: "+ str(e), + "Error in Appraiser "+ str(e), datetime.now().strftime('%H:%M:%S'), "ERROR" ]