Merge branch 'release/1.13.0'

.gitignore

@@ -17,3 +17,9 @@ build/
 run_*/
 nacculator_cfg.ini
 .DS_STORE
+.env
+logs/*
+
+# virtual environment folders .venv is standard, venv is legacy non-standard path
+.venv/ 
+venv/

CHANGELOG

@@ -1,5 +1,17 @@
 Changelog
 =========
+## [1.13.0] - 2024-03-07
+### Summary
+This release adds logging functionality (report_handler) to NACCulator's output (found in the `logs` folder), along with several minor bug fixes. 
+
+### Added
+ * Added report_handler (Kshitij Sinha)
+
+### Fixed
+ * Fix filter name in nacculator_cfg.ini.example (Samantha Emerson)
+ * Add A3NOT field to ivp and fvp builder files (Samantha Emerson)
+ * Add FTLD fields to Z1X in builder.py for ivp and fvp (Samantha Emerson)
+
 ## [1.12.1] - 2023-10-27
 ### Summary
 This release fixes some blanking logic errors in the new Neuropath version 11 module. 

README.md

@@ -382,7 +382,6 @@ first.
 _Note: execute `generator.py` from the same folder as the `corrected`
 folder, which should contain any "corrected" DEDs._
 
-
 ### Resources
 
 * UDS3 forms: https://www.alz.washington.edu/NONMEMBER/UDS/DOCS/VER3/UDS3csvded.html

nacc/local_filters.py

@@ -4,6 +4,7 @@
 import datetime
 import configparser
 from nacc.uds3.filters import *
+import logging
 
 
 # Creating a folder which contains Intermediate files
@@ -26,59 +27,82 @@ def run_all_filters(folder_name, config, input_name):
     # Calling Filters
     try:
         print("--------------Removing subjects already in current--------------------", file=sys.stderr)
+        logging.info('Removing subjects already in current')
         if input_name:
             input_path = input_name
         else:
             input_path = os.path.join(folder_name, "redcap_input.csv")
         output_path = os.path.join(folder_name, "clean.csv")
         print("Processing", file=sys.stderr)
+
         with open(output_path, 'w') as output_ptr, open(input_path, 'r') as input_ptr:
             filter_clean_ptid(input_ptr, config, output_ptr)
 
         print("--------------Replacing drug IDs--------------------", file=sys.stderr)
+        logging.info('Replacing drug IDs')
+
         input_path = os.path.join(folder_name, "clean.csv")
         output_path = os.path.join(folder_name, "drugs.csv")
         with open(output_path, 'w') as output_ptr, open(input_path, 'r') as input_ptr:
             filter_replace_drug_id(input_ptr, config, output_ptr)
 
         print("--------------Fixing Headers--------------------", file=sys.stderr)
+        logging.info('Fixing Headers')
+
         input_path = os.path.join(folder_name, "drugs.csv")
         output_path = os.path.join(folder_name, "clean_headers.csv")
         with open(output_path, 'w') as output_ptr, open(input_path, 'r') as input_ptr:
             filter_fix_headers(input_ptr, config, output_ptr)
 
         print("--------------Filling in Defaults--------------------", file=sys.stderr)
+        logging.info('Filling in Defaults')
+
         input_path = os.path.join(folder_name, "clean_headers.csv")
         output_path = os.path.join(folder_name, "default.csv")
         with open(output_path, 'w') as output_ptr, open(input_path, 'r') as input_ptr:
             filter_fill_default(input_ptr, config, output_ptr)
 
         print("--------------Updating fields--------------------", file=sys.stderr)
+        logging.info('Updating fields')
+
         input_path = os.path.join(folder_name, "default.csv")
         output_path = os.path.join(folder_name, "update_fields.csv")
         with open(output_path, 'w') as output_ptr, open(input_path, 'r') as input_ptr:
-            filter_update_field(input_ptr, config, output_ptr)
+            (input_ptr, config, output_ptr)
 
         print("--------------Fixing Visit Dates--------------------", file=sys.stderr)
+        logging.info('Fixing visit dates')
+
         input_path = os.path.join(folder_name, "update_fields.csv")
         output_path = os.path.join(folder_name, "proper_visitdate.csv")
         with open(output_path, 'w') as output_ptr, open(input_path, 'r') as input_ptr:
             filter_fix_visitdate(input_ptr, config, output_ptr)
 
         print("--------------Removing Unnecessary Records--------------------", file=sys.stderr)
+        logging.info('Removing Unnecessary Records')
         input_path = os.path.join(folder_name, "proper_visitdate.csv")
         output_path = os.path.join(folder_name, "CleanedPtid_Update.csv")
         with open(output_path, 'w') as output_ptr, open(input_path, 'r') as input_ptr:
             filter_remove_ptid(input_ptr, config, output_ptr)
 
         print("--------------Removing Records without VisitDate--------------------", file=sys.stderr)
+        logging.info('Removing Records without VisitDate')
         input_path = os.path.join(folder_name, "CleanedPtid_Update.csv")
         output_path = os.path.join(folder_name, "final_Update.csv")
         with open(output_path, 'w') as output_ptr, open(input_path, 'r') as input_ptr:
             filter_eliminate_empty_date(input_ptr, config, output_ptr)
 
     except Exception as e:
         print("Error in Opening a file")
+        logging.error('Error in Opening a file',
+                      extra={
+                          "report_handler": {
+                              "data": {"ptid": None,
+                                       "error": f'Error in Opening a file: {e}'},
+                              "sheet": 'error'
+                          }
+                      }
+                      )
         print(e)
 
     return

nacc/logger.py

@@ -0,0 +1,23 @@
+import logging
+import sys
+from report_handler.report_handler import ReportHandler
+
+
+def configure_logging(config, handlers: list[logging.Handler] = []):
+    fmt = '%(asctime)s  %(levelname)-9s  %(message)s'
+
+    logging.basicConfig(level=logging.DEBUG, format=fmt,
+                        filename="logs.log")
+
+    console = logging.StreamHandler(sys.stderr)
+    formatter = logging.Formatter(fmt)
+    console.setFormatter(formatter)
+    console.setLevel(logging.DEBUG)
+
+    # Gets the root logger and any config changes here affects logging across the code base
+    logger = logging.getLogger()
+
+    logger.addHandler(console)
+
+    for handler in handlers:
+        logger.addHandler(handler)

nacc/redcap2nacc.py

@@ -37,6 +37,9 @@
 from nacc.uds3 import filters
 from nacc.uds3 import packet as uds3_packet
 from nacc.uds3 import Field
+from nacc.logger import configure_logging
+from report_handler.report_handler import ReportHandler
+import logging
 
 
 def check_blanks(packet: uds3_packet.Packet, options: argparse.Namespace) \
@@ -178,7 +181,8 @@ def check_for_bad_characters(field: Field) -> typing.List:
     return incompatible
 
 
-def check_redcap_event(options, record, out=sys.stdout, err=sys.stderr) -> bool:
+def check_redcap_event(
+        options, record, out=sys.stdout, err=sys.stderr) -> bool:
     """
     Determines if the record's redcap_event_name and filled forms match the
     options flag
@@ -303,8 +307,21 @@ def check_redcap_event(options, record, out=sys.stdout, err=sys.stderr) -> bool:
                     if followup_match in ['', '0']:
                         return False
                 except KeyError:
-                    print("Could not find a REDCap field for TFP Z1X form.",
-                          file=err)
+                    print(
+                        "Could not find a REDCap field for TFP Z1X form.",
+                        file=err)
+                    logging.error(
+                        "Could not find a REDCap field for TFP Z1X form",
+                        extra={
+                            "report_handler": {
+                                "data": {
+                                    "ptid": record['ptid'],
+                                    "error": "Could not find a REDCap field for TFP Z1X form"
+                                },
+                                "sheet": 'ERROR'
+                            }
+                        },
+                    )
                     return False
     elif options.tfp3:
         event_name = 'tele'
@@ -419,9 +436,8 @@ def set_to_zero_if_blank(*field_names):
     # B8 3.
     try:
         if packet['CVDSIGNS'] == 1:
-            set_to_zero_if_blank(
-                'CORTDEF', 'SIVDFIND', 'CVDMOTL', 'CVDMOTR', 'CORTVISL',
-                'CORTVISR', 'SOMATL', 'SOMATR')
+            set_to_zero_if_blank('CORTDEF', 'SIVDFIND', 'CVDMOTL', 'CVDMOTR',
+                                 'CORTVISL', 'CORTVISR', 'SOMATL', 'SOMATR')
     except KeyError:
         pass
 
@@ -440,15 +456,15 @@ def set_to_zero_if_blank(*field_names):
     try:
         if packet['DEMENTED'] == 1:
             set_to_zero_if_blank(
-                    'AMNDEM', 'PCA', 'PPASYN', 'FTDSYN', 'LBDSYN', 'NAMNDEM')
+                'AMNDEM', 'PCA', 'PPASYN', 'FTDSYN', 'LBDSYN', 'NAMNDEM')
     except KeyError:
         pass
 
     # D1 5.
     try:
         if packet['DEMENTED'] == 0:
             set_to_zero_if_blank(
-                    'MCIAMEM', 'MCIAPLUS', 'MCINON1', 'MCINON2', 'IMPNOMCI')
+                'MCIAMEM', 'MCIAPLUS', 'MCINON1', 'MCINON2', 'IMPNOMCI')
     except KeyError:
         pass
 
@@ -470,6 +486,13 @@ def set_to_zero_if_blank(*field_names):
     except KeyError:
         pass
 
+    # NP v11 19(r, s, t)
+    try:
+        set_to_zero_if_blank(
+            'NPPDXR', 'NPPDXS', 'NPPDXT')
+    except KeyError:
+        pass
+
 
 def convert(fp, options, out=sys.stdout, err=sys.stderr):
     """
@@ -512,8 +535,9 @@ def convert(fp, options, out=sys.stdout, err=sys.stderr):
             if not event_match:
                 continue
 
-        print("[START] ptid : " + str(record['ptid']) + " visit " +
-              str(record['visitnum']), file=err)
+        print("[START] ptid : " + str(record['ptid']) +
+              " visit " + str(record['visitnum']), file=err)
+        logging.info('[START] ptid: {}'.format(record['ptid']))
         try:
             if options.lbd and options.ivp:
                 packet = lbd_ivp_builder.build_lbd_ivp_form(record)
@@ -548,14 +572,23 @@ def convert(fp, options, out=sys.stdout, err=sys.stderr):
             elif options.m:
                 packet = m_builder.build_uds3_m_form(record)
 
-        except Exception:
+        except Exception as e:
             if 'ptid' in record:
-                print("[SKIP] Error for ptid : " + str(record['ptid']) +
-                      " visit " + str(record['visitnum']), file=err)
+                print("[SKIP] Error for ptid : " + str(record['ptid']),
+                      file=err)
+                logging.error(
+                    '[SKIP] Error for ptid : {}'.format(record['ptid']),
+                    extra={
+                        "report_handler": {
+                            "data": {"ptid": record['ptid'], "error": str(traceback.format_exc())},
+                            "sheet": "SKIP"
+                        }
+                    }
+                )
             traceback.print_exc()
             continue
 
-        if not (options.np or options.np10 or options.m or options.lbd or
+        if not (options.np10 or options.m or options.lbd or
                 options.lbdsv or options.ftld or options.csf or options.cv):
             set_blanks_to_zero(packet)
 
@@ -565,17 +598,35 @@ def convert(fp, options, out=sys.stdout, err=sys.stderr):
         warnings = []
         try:
             warnings += check_blanks(packet, options)
-        except KeyError:
+        except KeyError as e:
             print("[SKIP] Error for ptid : " + str(record['ptid']) +
                   " visit " + str(record['visitnum']), file=err)
+            logging.error(
+                '[SKIP] Error for ptid : {}'.format(record['ptid']),
+                extra={
+                    "report_handler": {
+                        "data": {"ptid": record['ptid'], "error": str(traceback.format_exc())},
+                        "sheet": "SKIP"
+                    }
+                }
+            )
             traceback.print_exc()
             continue
 
         try:
             warnings += check_characters(packet)
-        except KeyError:
+        except KeyError as e:
             print("[SKIP] Error for ptid : " + str(record['ptid']) +
                   " visit " + str(record['visitnum']), file=err)
+            logging.error(
+                '[SKIP] Error for ptid : {}'.format(record['ptid']),
+                extra={
+                    "report_handler": {
+                        "data": {"ptid": record['ptid'], "error": str(traceback.format_exc())},
+                        "sheet": "SKIP"
+                    }
+                }
+            )
             traceback.print_exc()
             continue
 
@@ -585,6 +636,15 @@ def convert(fp, options, out=sys.stdout, err=sys.stderr):
             warn = "\n".join(map(str, warnings))
             warn = warn.replace("\\", "")
             print(warn, file=err)
+            logging.error(
+                '[SKIP] Error for ptid : {}'.format(record['ptid']),
+                extra={
+                    "report_handler": {
+                        "data": {"ptid": record['ptid'], "error": ",".join(map(str, warnings))},
+                        "sheet": "SKIP"
+                    }
+                }
+            )
             continue
 
         if not options.np and not options.np10 and not options.m and not \
@@ -596,9 +656,19 @@ def convert(fp, options, out=sys.stdout, err=sys.stderr):
 
             try:
                 print(form, file=out)
-            except AssertionError:
-                print("[SKIP] Error for ptid : " + str(record['ptid']) +
-                      " visit " + str(record['visitnum']), file=err)
+            except AssertionError as e:
+                print("[SKIP] Error for ptid assertion: " +
+                      str(record['ptid']),
+                      file=err)
+                logging.error(
+                    '[SKIP] Error for ptid : {}'.format(record['ptid']),
+                    extra={
+                        "report_handler": {
+                            "data": {"ptid": record['ptid'], "error": str(e)},
+                            "sheet": "SKIP"
+                        }
+                    }
+                )
                 traceback.print_exc()
                 continue
 
@@ -700,21 +770,31 @@ def main():
 
     fp = sys.stdin if options.file is None else open(options.file, 'r')
 
+    report_handler = ReportHandler()
+    configure_logging(options, [report_handler])
+
     # Default option is to print out directly to the command terminal.
     # If you want to print the output to a specific file, then redirect
     # stdout to that filename.
     output = sys.stdout
 
-    if options.filter:
-        if options.filter == "getPtid":
-            filters.filter_extract_ptid(
-                fp, options.ptid, options.vnum, options.vtype, output)
+    try:
+        if options.filter:
+            if options.filter == "getPtid":
+                filters.filter_extract_ptid(
+                    fp, options.ptid, options.vnum, options.vtype, output)
+            else:
+                filter_method = 'filter_' + filters_names[options.filter]
+                filter_func = getattr(filters, filter_method)
+                filter_func(fp, options.filter_meta, output)
         else:
-            filter_method = 'filter_' + filters_names[options.filter]
-            filter_func = getattr(filters, filter_method)
-            filter_func(fp, options.filter_meta, output)
-    else:
-        convert(fp, options)
+            convert(fp, options)
+        logging.info('Nacculator Ended')
+    except Exception as e:
+        print(
+            f"An exception occurred in main(): {str(e), str(e.__cause__), str(e.__context__), str(e.__traceback__), str(e.with_traceback())}")
+    finally:
+        report_handler.write_report("logs")
 
 
 if __name__ == '__main__':