add a bunch of logging to find source of spinning on pedro's computer

backend/app_config.py

@@ -48,19 +48,19 @@ class AppConfig:
 
 ## LOG STUFF
 
-'''
+
 import logging
 from datetime import datetime
 log_dir=os.path.join(DATADIR, "logs")
 if not os.path.exists(log_dir):
     os.makedirs(log_dir)
 now=datetime.now()
 dt_string = now.strftime("%Y-%m-%d_%H-%M-%S")
-log_file=os.path.join(log_dir, dt_string+"t2wml.log")
+log_file=os.path.join(log_dir, dt_string+"_t2wml.log")
 handler = logging.FileHandler(log_file, 'a', 'utf-8')
 logging.basicConfig(level=logging.DEBUG, handlers=[handler])
 web_logger=logging.getLogger('web-t2wml')
-'''
+
 
 
 

backend/application.py

@@ -6,7 +6,7 @@
 from flask import request
 from t2wml.wikification.utility_functions import dict_to_kgtk, kgtk_to_dict
 import web_exceptions
-from app_config import app
+from app_config import app, web_logger
 from werkzeug.utils import secure_filename
 from t2wml.api import add_entities_from_file
 from t2wml.input_processing.annotation_suggesting import annotation_suggester
@@ -51,12 +51,16 @@ def get_project_dict(project):
 def json_response(func):
     def wrapper(*args, **kwargs):
         try:
+            web_logger.info(f"received request {request.url}")
             data, return_code = func(*args, **kwargs)
+            web_logger.info(f"returning from request {request.url}")
             return data, return_code
         except WebException as e:
+            web_logger.error(f"error raised from request {request.url}")
             data = {"error": e.error_dict}
             return data, e.code
         except Exception as e:
+            web_logger.error(f"error raised from request {request.url}")
             print(e)
             if "Permission denied" in str(e):
                 e=web_exceptions.FileOpenElsewhereError("Check whether a file you are trying to edit is open elsewhere on your computer: "+str(e))

backend/t2wml_web.py

@@ -13,31 +13,31 @@
 from t2wml.api import Project
 from app_config import CACHE_FOLDER
 from web_dict_provider import WebDictionaryProvider
-from utils import get_empty_layers
+from utils import get_empty_layers, basic_debug
 from wikidata_utils import get_labels_and_descriptions, get_qnode_url, QNode
 
-
+@basic_debug
 def create_api_project(project_folder, title, description, url):
     api_proj = Project(project_folder, title=title, description=description, url=url)
     api_proj.save()
     return api_proj
-
+@basic_debug
 def get_project_instance(project_folder):
     project = Project.load(project_folder)
     update_t2wml_settings(project)
     return project
-
+@basic_debug
 def wikify(calc_params, region, context):
     ws = WikifierService()
     df, problem_cells = ws.wikify_region(region, calc_params.sheet, context)
     return df, problem_cells
-
+@basic_debug
 def set_web_settings():
     if not os.path.isdir(CACHE_FOLDER):
         os.makedirs(CACHE_FOLDER, exist_ok=True)
     t2wml_settings.cache_data_files_folder = CACHE_FOLDER
     t2wml_settings.wikidata_provider = WebDictionaryProvider()
-
+@basic_debug
 def update_t2wml_settings(project):
     t2wml_settings.update_from_dict(**project.__dict__)
 
@@ -50,7 +50,7 @@ def update_t2wml_settings(project):
 
 
 
-
+@basic_debug
 def get_kg(calc_params):
     wikifier=calc_params.wikifier
     annotation= calc_params.annotation_path
@@ -70,23 +70,23 @@ def get_kg(calc_params):
 
 
 
-
+@basic_debug
 def download(calc_params, filetype):
     response = dict()
     kg = get_kg(calc_params)
     response["data"] = kg.get_output(filetype, calc_params.project)
     response["error"] = None
     response["internalErrors"] = kg.errors if kg.errors else None
     return response
-
+@basic_debug
 def get_kgtk_download_and_variables(calc_params, validate_for_datamart=False):
     kg = get_kg(calc_params)
     download_output = kg.get_output("tsv", calc_params.project)
     variables=get_all_variables(calc_params.project, kg.statements, validate_for_datamart=validate_for_datamart)
     return download_output, variables
 
 
-
+@basic_debug
 def get_qnodes_layer(calc_params):
     sheet = calc_params.sheet
     wikifier = calc_params.wikifier
@@ -118,11 +118,10 @@ def get_qnodes_layer(calc_params):
     return {"qnode": dict(layerType="qNode", entries=list(qnode_entries.values()))}
 
 
-
 def indexer(cell):
     col, row = cell_str_to_tuple(cell)
     return [row, col]
-
+@basic_debug
 def get_cleaned(kg):
     cleanedLayer=dict(layerType="cleaned", entries=[])
     if kg.sheet:
@@ -150,7 +149,7 @@ def get_cell_qnodes(statement, qnodes):
                 if str(outer_value).upper()[0] in ["P", "Q"]:
                     qnodes[str(outer_value)] = None
 
-
+@basic_debug
 def get_yaml_layers(calc_params):
     if calc_params.cache:
         layers=calc_params.cache.get_layers()
@@ -257,7 +256,7 @@ def get_yaml_layers(calc_params):
     return layers
 
 
-
+@basic_debug
 def get_table(calc_params, first_index=0, num_rows=None):
     sheet = calc_params.sheet
     if not sheet:
@@ -277,7 +276,7 @@ def get_table(calc_params, first_index=0, num_rows=None):
 
 
 
-
+@basic_debug
 def get_layers(response, calc_params):
     #convenience function for code that repeats three times
     response["layers"]=get_empty_layers()
@@ -293,7 +292,7 @@ def get_layers(response, calc_params):
                                 cells=[["subject", "property", "value"]])
 
     response["layers"].update(get_qnodes_layer(calc_params)) #needs to be after layers, since layers can update qnodes
-
+@basic_debug
 def get_annotations(calc_params):
     annotations_path=calc_params.annotation_path
     try:
@@ -307,15 +306,15 @@ def get_annotations(calc_params):
     except Exception as e:
         yamlContent="#Error when generating yaml: "+str(e)
     return dga.annotation_block_array, yamlContent
-
+@basic_debug
 def suggest_annotations(calc_params):
     annotations_path=calc_params.annotation_path
     dga=Annotation(block_finder(calc_params.sheet))
     if annotations_path:
         dga.save(annotations_path)
     return dga.annotation_block_array
 
-
+@basic_debug
 def save_annotations(project, annotation, annotations_path, data_path, sheet_name):
     #temporary fix until we fix in frontend:
     for block in annotation:
@@ -330,14 +329,14 @@ def save_annotations(project, annotation, annotations_path, data_path, sheet_nam
     return filename
 
 
-
+@basic_debug
 def get_entities(project: Project):
     entity_dict={}
     for file in project.entity_files:
         full_path=project.get_full_path(file)
         entity_dict[file]=kgtk_to_dict(full_path)
     return entity_dict
-
+@basic_debug
 def update_entities(project, entity_file, updated_entries):
 
     entities=get_entities(project)[entity_file]
@@ -349,7 +348,7 @@ def update_entities(project, entity_file, updated_entries):
     dict_to_kgtk(entities, full_path)
     return get_entities(project)
 
-
+@basic_debug
 def get_partial_csv(calc_params):
     wikifier=calc_params.wikifier
     annotation= calc_params.annotation_path
@@ -376,7 +375,7 @@ def get_partial_csv(calc_params):
     cells.insert(0, list(df.columns))
     return dict(dims=dims, firstRowIndex=0, cells=cells)
 
-
+@basic_debug
 def create_wikification_entry(calc_params, project, selection, value, context, item):
     top_left, bottom_right = selection
     col1, row1 = top_left

backend/utils.py

@@ -3,9 +3,27 @@
 import numpy as np
 from string import punctuation
 from flask import request
-
 import web_exceptions
-
+import logging
+
+
+web_log=logging.getLogger("web-t2wml")
+
+def basic_debug(func=None):
+    def wrapper(*args, **kwargs):
+        try:
+            function_name = func.__func__.__qualname__
+        except:
+            function_name = func.__qualname__
+        web_log.info(f"calling {function_name}")
+        try:
+            result= func(*args, **kwargs)
+            web_log.info(f"returned from {function_name}")
+            return result
+        except Exception as e:
+            web_log.error(f"{function_name} raised {str(e)}")
+            raise e
+    return wrapper
 
 def numpy_converter(o):
     if isinstance(o, np.generic):

backend/web_dict_provider.py

@@ -5,13 +5,14 @@
 from t2wml.wikification.preloaded_properties import preloaded_properties
 from t2wml.wikification.wikidata_provider import FallbackSparql
 from app_config import DEFAULT_SPARQL_ENDPOINT
-
+from utils import basic_debug
 
 def add_entities_from_project(project):
     for f in project.entity_files:
         add_entities_from_file(Path(project.directory) / f)
 
 class WebDictionaryProvider(FallbackSparql):
+    @basic_debug
     def __init__(self, project=None):
         super().__init__()
         self.cache=preloaded_properties
@@ -56,6 +57,7 @@ def save_entry(self, property, data_type, *args, **kwargs):
     def __enter__(self):
         return self
 
+    @basic_debug
     def __exit__(self, exc_type, exc_value, exc_traceback):
         if self.project is not None:
             properties=json.dumps(self.cache)