Add logging

build/build.py

@@ -10,13 +10,16 @@
 
 def process_pdb_code(code):
     """Builds all the relevant objects for any given PDB code."""
-    
+
     from factories import create_pdb_record, create_metal_record
     from factories import create_chain_record, create_site_record
 
     # Get PDB
+    log(f"Fetching {code}")
     pdb = atomium.fetch(code)
+    log(f"Getting best {code} assembly")
     model, assembly_id = get_best_model(pdb)
+    log(f"Saving {code} to database")
     pdb_record = create_pdb_record(pdb, assembly_id)
 
     # Check model is usable
@@ -34,6 +37,7 @@ def process_pdb_code(code):
         )
 
     # Get metals
+    log(f"Finding {code} liganding atoms")
     metals = remove_duplicate_atoms(model.atoms(is_metal=True))
 
     # Determine liganding atoms of all metals
@@ -47,6 +51,7 @@ def process_pdb_code(code):
              omission="Zinc has too few liganding atoms."
             )
 
+    log(f"Processing {code} sites")
     # Get list of binding site dicts from the metals dict
     sites = [{"metals": {m: v}} for m, v in metals.items()]
 
@@ -67,6 +72,7 @@ def process_pdb_code(code):
         site["chains"] = get_site_chains(site)
 
     # Create chains involved in all binding sites
+    log(f"Processing {code} chains")
     chains, residues = get_all_chains(sites), get_all_residues(sites)
     chains_dict = {}
     for chain in chains:
@@ -75,10 +81,12 @@ def process_pdb_code(code):
 
     # Save sites to database
     for index, site in enumerate(sites, start=1):
+        log(f"Saving {code} site")
         site_record = create_site_record(site, pdb_record, index, chains_dict)
 
 
 def main():
+    log("\n\n\nSTARTING DATABASE BUILD")
     # What PDBs have zinc in them?
     codes = get_zinc_pdb_codes()
     print(f"There are {len(codes)} PDB codes with zinc")

build/utilities.py

@@ -3,6 +3,7 @@
 import math
 import requests
 import subprocess
+from datetime import datetime
 import atomium
 from sites import remove_duplicate_atoms, get_atom_liganding_atoms
 from sites import remove_salt_metals, merge_metal_groups, get_site_residues
@@ -18,6 +19,15 @@ def setup_django():
     django.setup()
 
 
+def log(text):
+    """Writes a line to the log file."""
+
+    with open("data/build.log", "a") as f:
+        f.write("{}: {}\n".format(
+         datetime.now().strftime("%Y-%m-%dT%H:%M:%S"), text
+        ))
+
+
 def get_zinc_pdb_codes():
     """Gets PDB codes for all structures with a zinc atom in them.
     If the response returned has an error code of 500, or if there are fewer
@@ -77,7 +87,7 @@ def zincs_outside_model(model, pdb):
 
 def is_cd_hit_installed():
     """Checks if the CD-hit binary is installed."""
-    
+
     p = subprocess.Popen(
      "which cd-hit", stdout=subprocess.PIPE, stderr=subprocess.PIPE, shell=True
     )

tests/test_build.py

@@ -13,16 +13,19 @@ def setUp(self):
         self.patch1 = patch("build.build.get_zinc_pdb_codes")
         self.patch2 = patch("builtins.print")
         self.patch3 = patch("build.build.tqdm")
+        self.patch4 = patch("build.build.log")
         self.mock_codes = self.patch1.start()
         self.mock_print = self.patch2.start()
         self.mock_tqdm = self.patch3.start()
+        self.mock_log = self.patch4.start()
         self.mock_tqdm.side_effect = lambda l: l
 
 
     def tearDown(self):
         self.patch1.stop()
         self.patch2.stop()
         self.patch3.stop()
+        self.patch4.stop()
 
 
     def check_print_statement(self, fragment):