troggle-unchained/parsers/logbooks.py

import csv
import os
import re
import pickle
import shelve
import time
from random import randint
from datetime import datetime, date
from pathlib import Path

from django.conf import settings
from django.template.defaultfilters import slugify
from django.utils.timezone import get_current_timezone, make_aware

from troggle.core.models.troggle import DataIssue, Expedition
from troggle.core.utils import TROG, save_carefully
from troggle.core.models.caves import Cave, LogbookEntry, PersonTrip, GetCaveLookup
from parsers.people import GetPersonExpeditionNameLookup

'''
Parses and imports logbooks in all their wonderful confusion

# When we edit logbook entries, allow a "?" after any piece of data to say we've frigged it and
# it can be checked up later from the hard-copy if necessary; or it's not possible to determin (name, trip place, etc)
'''
todo='''
- refactor everything with some urgency, esp. LoadLogbookForExpedition()

- profile the code to find bad repetitive things, of which there are many.

- far too many uses of Django field dereferencing to get values, which is SLOW

- Logbooks 1987, 1988, 1989 all crash on MySql - but not sqlite - with db constraint fail. Edit logbook to fix.

- import/parse/re-export-as-html the 'artisanal-format' old logbooks so that
  we keep only a modern HTML05 format. Then we can retire the old parsers and reduce the
  volume of code here substantially.

- rewrite to use generators rather than storing everything intermediate in lists - to reduce memory impact.
  
- We should ensure logbook.html is utf-8 and stop this crap:             
            file_in = open(logbookfile,'rb')
            txt = file_in.read().decode("latin1")
            
- this is a slow and uncertain function:  cave = getCaveByReference(caveRef)

'''

logentries = [] # the entire logbook for one year is a single object: a list of entries
noncaveplaces = [ "QMplaceholder", "Journey", "Loser Plateau", "UNKNOWN", 'plateau', 
        'base camp', 'basecamp', 'top camp', 'topcamp' ]
logdataissues = TROG['issues']['logdataissues']
trips ={}

entries = { "2022": 64, "2019": 44, "2018": 74, "2017": 60, "2016": 81, "2015": 79, 
    "2014": 65, "2013": 51, "2012": 75, "2011": 68, "2010": 22, "2009": 52, 
    "2008": 49, "2007": 111, "2006": 60, "2005": 55, "2004": 76, "2003": 40, "2002": 31, 
    "2001": 48, "2000": 54, "1999": 79, "1998": 43, "1997": 53, "1996": 94, "1995": 41, 
    "1994": 32, "1993": 41, "1992": 61, "1991": 38, "1990": 87, "1989": 1,"1988": 1,"1987": 1,
    "1985": 24,"1984": 32,"1983": 52,"1982": 42,}
# Logbooks log.htm exist for 1983, 84, 85, 87, 88, 89 but have no full-working parser, or need hand-editing.


#
# the logbook loading section
#
def set_trip_id(year, seq):
    tid= f"{year}_s{seq:02d}"
    return tid

rx_tripperson   = re.compile(r'(?i)<u>(.*?)</u>$')
rx_round_bracket = re.compile(r"[\(\[].*?[\)\]]")

    
def GetTripPersons(trippeople, expedition, logtime_underground, tid=None):
    res = [ ]
    author = None
    #print(f'# {tid}')
       
    for tripperson in re.split(r",|\+|&amp;|&(?!\w+;)| and ", trippeople):
        tripperson = tripperson.strip()
        # mul = re.match(r"(?i)<u>(.*?)</u>$", tripperson)
        mul = rx_tripperson.match(tripperson)
        if mul:
            tripperson = mul.group(1).strip()
        if tripperson and tripperson[0] != '*':
            tripperson = re.sub(rx_round_bracket, "", tripperson).strip()
            
            if tripperson =="Wiggy":
                tripperson = "Phil Wigglesworth"
            if tripperson =="Animal":
                tripperson = "Mike Richardson"
            if tripperson =="MikeTA":
                tripperson = "Mike Richardson"

                            
            personyear = GetPersonExpeditionNameLookup(expedition).get(tripperson.lower())
            if not personyear:
                message = f" ! - {expedition.year} No name match for: '{tripperson}' in entry {tid=} for this expedition year." 
                print(message)
                DataIssue.objects.create(parser='logbooks', message=message)
                logdataissues[tid]=message
            res.append((personyear, logtime_underground))
            if mul:
                author = personyear
    if not author:
        if not res:
            return None, None
        author = res[-1][0]
        
    return res, author

def EnterLogIntoDbase(date, place, title, text, trippeople, expedition, logtime_underground, tid=None):
    """ saves a logbook entry and related persontrips 
    Does NOT save the expeditionday_id  - all NULLs. why? Because we are deprecating expeditionday !
    
    troggle.log shows that we are creating lots of duplicates, which is no no problem with SQL as they just overwrite
    but we are saving the  same thing too many times.. 
    """
    try:
        trippersons, author = GetTripPersons(trippeople, expedition, logtime_underground, tid=tid)
    except:
        message = f" ! - {expedition.year} Skipping logentry: {title} - GetTripPersons FAIL"
        DataIssue.objects.create(parser='logbooks', message=message)
        logdataissues["title"]=message
        print(message)
        raise
        return
        
    if not author:
        message = f" ! - {expedition.year} Warning: logentry: {title} - no author for entry '{tid}'"
        DataIssue.objects.create(parser='logbooks', message=message)
        logdataissues["title"]=message
        print(message)
        #return

    # This needs attention. The slug field is derived from 'title'
    # both GetCaveLookup() and GetTripCave() need to work together better. None of this data is *used* though?
    #tripCave = GetTripCave(place):

    lplace = place.lower()
    cave=None
    if lplace not in noncaveplaces:
        cave = GetCaveLookup().get(lplace)
    
    y = str(date)[:4]
    text = text.replace('src="', f'src="/years/{y}/' )
    text = text.replace("src='", f"src='/years/{y}/" )

    #Check for an existing copy of the current entry, and save
    expeditionday = expedition.get_expedition_day(date)
    lookupAttribs={'date':date, 'title':title}
    # 'cave' is converted to a string doing this, which renders as the cave slug.
    # but it is a db query which we should try to avoid - rewrite this
    
    #NEW slug for a logbook entry here! Unique id + slugified title fragment
    # working for all cache files 2019-2005, failed on 2004; but fine when parsing logbook and not reading cache. Hmm.
    if tid is not None:
        slug = tid + "_" + slugify(title)[:10].replace('-','_')
    else: 
        slug = str(randint(1000,10000)) + "_" + slugify(title)[:10].replace('-','_')
    nonLookupAttribs={'place':place, 'text':text, 'expedition':expedition, 'cave_slug':str(cave), 'slug': slug}
    
    # This creates the lbo instance of LogbookEntry
    lbo, created=save_carefully(LogbookEntry, lookupAttribs, nonLookupAttribs)

    
    for tripperson, time_underground in trippersons:
        lookupAttribs={'personexpedition':tripperson, 'logbook_entry':lbo}
        nonLookupAttribs={'time_underground':time_underground, 'is_logbook_entry_author':(tripperson == author)}
        # this creates the PersonTrip instance. 
        save_carefully(PersonTrip, lookupAttribs, nonLookupAttribs) # PersonTrip also saved in SetDatesFromLogbookEntries

def ParseDate(tripdate, year):
    """ Interprets dates in the expo logbooks and returns a correct datetime.date object  """
    dummydate = date(1970, 1, 1)
    month = 1
    day = 1
    # message = f" ! - Trying to parse date in logbook: {tripdate} - {year}"
    # print(message)
    try:
        mdatestandard = re.match(r"(\d\d\d\d)-(\d\d)-(\d\d)", tripdate)
        mdategoof = re.match(r"(\d\d?)/0?(\d)/(20|19)?(\d\d)", tripdate)
        if mdatestandard:
            if not (mdatestandard.group(1) == year):
                message = f" ! - Bad date (year) in logbook: {tripdate} - {year}"
                DataIssue.objects.create(parser='logbooks', message=message)
                logdataissues["tripdate"]=message
                return dummydate
            else:
                year, month, day = int(mdatestandard.group(1)), int(mdatestandard.group(2)), int(mdatestandard.group(3))
        elif mdategoof:
            if not (not mdategoof.group(3) or mdategoof.group(3) == year[:2]):
                message = " ! - Bad date mdategoof.group(3) in logbook: " + tripdate + " - " + mdategoof.group(3)
                DataIssue.objects.create(parser='logbooks', message=message)
                logdataissues["tripdate"]=message
                return dummydate
            else:
                yadd = int(year[:2]) * 100
                day, month, year = int(mdategoof.group(1)), int(mdategoof.group(2)), int(mdategoof.group(4)) + yadd
        else:
            year = 1970
            message = f" ! - Bad date in logbook: {tripdate} - {year}"
            DataIssue.objects.create(parser='logbooks', message=message)
            logdataissues["tripdate"]=message

        return date(year, month, day)
    except:
        message = f" ! - Failed to parse date in logbook: {tripdate} - {year}"
        DataIssue.objects.create(parser='logbooks', message=message)
        logdataissues["tripdate"]=message
        return datetime.date(1970, 1, 1)

# (2006 - not any more), 2008 - 2009
def Parselogwikitxt(year, expedition, txt):
    global logentries
    global logdataissues

    logbook_entry_count = 0
    trippara = re.findall(r"===(.*?)===([\s\S]*?)(?====)", txt)
    for triphead, triptext in trippara:
        logbook_entry_count += 1
        tid = set_trip_id(year,logbook_entry_count)
        
        tripheadp = triphead.split("|")
        if not (len(tripheadp) == 3):
            message = " ! - Bad no of items in tripdate in logbook: " + tripdate + " - " + tripheadp
            DataIssue.objects.create(parser='logbooks', message=message)
            logdataissues["tripdate"]=message
         
        tripdate, tripplace, trippeople = tripheadp
        tripsplace = tripplace.split(" - ")
        tripcave = tripsplace[0].strip()
        if len(tripsplace) == 1:
            tripsplace = tripsplace[0] 
        else:
            tripsplace = tripsplace[1]
            
        #print(f"! LOGBOOK {year} {logbook_entry_count:2}  {len(triptext):4}  '{tripsplace}'")

        tul = re.findall(r"T/?U:?\s*(\d+(?:\.\d*)?|unknown)\s*(hrs|hours)?", triptext)
        if tul:
            tu = tul[0][0]
        else:
            tu = ""

        ldate = ParseDate(tripdate.strip(), year)
        tripid =""
        
        entrytuple = (ldate, tripcave, tripsplace, triptext, 
                trippeople, expedition, tu, "wiki", tripid)
        logentries.append(entrytuple)
        
        
# 2002, 2004, 2005, 2007, 2010 - now
# 2006 wiki text is incomplete, but the html all there. So using this parser now.
def Parseloghtmltxt(year, expedition, txt):
    global logentries
    global logdataissues

    tripparas = re.findall(r"<hr\s*/>([\s\S]*?)(?=<hr)", txt)
    logbook_entry_count = 0
    for trippara in tripparas:
        logbook_entry_count += 1
        tid = set_trip_id(year,logbook_entry_count)
        # print(f' - new tid:{tid} lbe count: {logbook_entry_count}')
       
        s = re.match(r'''(?x)(?:\s*<div\sclass="tripdate"\sid=".*?">.*?</div>\s*<p>)?  # second date
                            \s*(?:<a\s+id="(.*?)"\s*/>\s*</a>)?
                            \s*<div\s+class="tripdate"\s*(?:id="(.*?)")?>(.*?)</div>(?:<p>)?
                            \s*<div\s+class="trippeople">\s*(.*?)</div>
                            \s*<div\s+class="triptitle">\s*(.*?)</div>
                            ([\s\S]*?)
                            \s*(?:<div\s+class="timeug">\s*(.*?)</div>)?
                            \s*$
                     ''', trippara)
        if s:
            tripid, tripid1, tripdate, trippeople, triptitle, triptext, tu = s.groups()
        else: # allow title and people to be swapped in order
            s2 = re.match(r'''(?x)(?:\s*<div\sclass="tripdate"\sid=".*?">.*?</div>\s*<p>)?  # second date
                                \s*(?:<a\s+id="(.*?)"\s*/>\s*</a>)?
                                \s*<div\s+class="tripdate"\s*(?:id="(.*?)")?>(.*?)</div>(?:<p>)?
                                \s*<div\s+class="triptitle">\s*(.*?)</div>
                                \s*<div\s+class="trippeople">\s*(.*?)</div>
                                ([\s\S]*?)
                                \s*(?:<div\s+class="timeug">\s*(.*?)</div>)?
                                \s*$
                         ''', trippara)
            if s2:
                tripid, tripid1, tripdate, triptitle, trippeople, triptext, tu = s2.groups()
            else:
                if not re.search(r"Rigging Guide", trippara):
                    msg = " !- Logbook. Can't parse: {} entry:{}".format(trippara, logbook_entry_count) 
                    print(msg)
                    DataIssue.objects.create(parser='logbooks', message=msg)
                    logdataissues[tid]=msg
                continue
        
        ldate = ParseDate(tripdate.strip(), year)
        triptitles = triptitle.split(" - ")
        if len(triptitles) >= 2:
            tripcave = triptitles[0]
        else:
            tripcave = "UNKNOWN"
        ltriptext = re.sub(r"</p>", "", triptext)
        ltriptext = re.sub(r"\s*?\n\s*", " ", ltriptext)
        ltriptext = re.sub(r"<p>", "</br></br>", ltriptext).strip()

        entrytuple = (ldate, tripcave, triptitle, ltriptext, 
                trippeople, expedition, tu, "html", tripid1)
        logentries.append(entrytuple)


# main parser for 1991 - 2001.  simpler because the data has been hacked so much to fit it
# trying it out for years 1982 - 1990 too. Some logbook editing required by hand.. place
def Parseloghtml01(year, expedition, txt):
    global logentries
    global logdataissues
    errorcount = 0

    tripparas = re.findall(r"<hr[\s/]*>([\s\S]*?)(?=<hr)", txt)
    logbook_entry_count = 0
    for trippara in tripparas:
        logbook_entry_count += 1
        tid = set_trip_id(year,logbook_entry_count)
        # print(f" #0 - tid: {tid}")
        try:
            #print(f" #1 - tid: {tid}")
            s = re.match(r"(?s)\s*(?:<p>)?(.*?)</?p>(.*)$(?i)", trippara)
            if not s:
                message = " ! - Skipping logentry {year} failure to parse header: " + tid + trippara[:300] + "..."
                DataIssue.objects.create(parser='logbooks', message=message)
                logdataissues[tid]=message
                print(message)
                break
            try:
                tripheader, triptext = s.group(1), s.group(2)
            except:
                message = f" ! - Fail to set tripheader, triptext. trip:<{tid}> s:'{s}'" 
                DataIssue.objects.create(parser='logbooks', message=message)
                logdataissues[tid]=message
                print(message)
                

            # mtripid = re.search(r'<a id="(.*?)"', tripheader)
            # if not mtripid:
                # message = f" ! - A tag id not found. Never mind. Not needed. trip:<{tid}> header:'{tripheader}'" 
                # DataIssue.objects.create(parser='logbooks', message=message)
                # logdataissues[tid]=message
                # print(message)
                
            # tripid = mtripid and mtripid.group(1) or ""
            # print(f" # - mtripid: {mtripid}")
            tripheader = re.sub(r"</?(?:[ab]|span)[^>]*>", "", tripheader)
            #print(f" #2 - tid: {tid}")
            try:
                tripdate, triptitle, trippeople = tripheader.split("|")
            except:
                message = f" ! - Fail 3 to split out date|title|people. trip:<{tid}> '{tripheader.split('|')}'" 
                DataIssue.objects.create(parser='logbooks', message=message)
                logdataissues[tid]=message
                print(message)
                try:
                    tripdate, triptitle = tripheader.split("|")
                    trippeople = "GUESS ANON"
                except:
                    message = f" ! - Skipping logentry {year} Fail 2 to split out date|title (anon). trip:<{tid}> '{tripheader.split('|')}' CRASHES MySQL !" 
                    DataIssue.objects.create(parser='logbooks', message=message)
                    logdataissues[tid]=message
                    print(message)
                    break
            #print(f" #3 - tid: {tid}")
            ldate = ParseDate(tripdate.strip(), year)
            #print(f" # -             tid: {tid} <{tripdate}> <{triptitle}> <{trippeople}>")
            #print(f" #4 - tid: {tid}")

            mtu = re.search(r'<p[^>]*>(T/?U.*)', triptext)
            if mtu:
                tu = mtu.group(1)
                triptext = triptext[:mtu.start(0)] + triptext[mtu.end():]
            else:
                tu = ""

            triptitles = triptitle.split(" - ")
            tripcave = triptitles[0].strip()

            ltriptext = triptext
            
            mtail = re.search(r'(?:<a href="[^"]*">[^<]*</a>|\s|/|-|&amp;|</?p>|\((?:same day|\d+)\))*$', ltriptext)
            if mtail:
                ltriptext = ltriptext[:mtail.start(0)]
            ltriptext = re.sub(r"</p>", "", ltriptext)
            ltriptext = re.sub(r"\s*?\n\s*", " ", ltriptext)
            ltriptext = re.sub(r"<p>|<br>", "\n\n", ltriptext).strip()
            ltriptext = re.sub(r"</?u>", "_", ltriptext)
            ltriptext = re.sub(r"</?i>", "''", ltriptext)
            ltriptext = re.sub(r"</?b>", "'''", ltriptext)
            
            if ltriptext == "":
                message = " ! - Zero content for logbook entry!: " + tid 
                DataIssue.objects.create(parser='logbooks', message=message)
                logdataissues[tid]=message
                print(message)
                

            entrytuple = (ldate, tripcave, triptitle, ltriptext, 
                    trippeople, expedition, tu, "html01", tid)
            logentries.append(entrytuple)
                
        except:
            message = f" ! - Skipping logentry {year} due to exception in: {tid}"
            DataIssue.objects.create(parser='logbooks', message=message)
            logdataissues[tid]=message
            print(message)
            errorcount += 1
            if errorcount >5 :
                message = f" !!- TOO MANY ERRORS - aborting at '{tid}' logbook: {year}"
                DataIssue.objects.create(parser='logbooks', message=message)
                logdataissues[tid]=message
                print(message)
                return

# parser for 2003
def Parseloghtml03(year, expedition, txt):
    global logentries
    global logdataissues

    tripparas = re.findall(r"<hr\s*/>([\s\S]*?)(?=<hr)", txt)
    logbook_entry_count = 0
    for trippara in tripparas:
        logbook_entry_count += 1
        tid = set_trip_id(year,logbook_entry_count)
        
        s = re.match(r"(?s)\s*<p>(.*?)</p>(.*)$", trippara)
        if not ( s ) :
            message = " ! - Skipping logentry {year} on failure to parse Parseloghtml03: {} {} {}...".format(tid,s,trippara[:300])
            DataIssue.objects.create(parser='logbooks', message=message)
            logdataissues[tid]=message
            print(message)
            break
        
        tripheader, triptext = s.group(1), s.group(2)
        tripheader = re.sub(r"&nbsp;", " ", tripheader)
        tripheader = re.sub(r"\s+", " ", tripheader).strip()
        sheader = tripheader.split(" -- ")
        tu = ""
        if re.match("T/U|Time underwater", sheader[-1]):
            tu = sheader.pop()
        if len(sheader) != 3:
            print(" ! Header not three pieces", sheader)
        tripdate, triptitle, trippeople = sheader
        ldate = ParseDate(tripdate.strip(), year)
        triptitles = triptitle.split(" , ")
        if len(triptitles) >= 2:
            tripcave = triptitles[0]
        else:
            tripcave = "UNKNOWN"
        ltriptext = re.sub(r"</p>", "", triptext)
        ltriptext = re.sub(r"\s*?\n\s*", " ", ltriptext)
        ltriptext = re.sub(r"<p>", "\n\n", ltriptext).strip()
        ltriptext = re.sub(r"[^\s0-9a-zA-Z\-.,:;'!&()\[\]<>?=+*%]", "_NONASCII_", ltriptext)


        entrytuple = (ldate, tripcave, triptitle, ltriptext, 
                trippeople, expedition, tu, "html03", tid)
        logentries.append(entrytuple)

def SetDatesFromLogbookEntries(expedition):
    """Sets the next and previous entry for a persontrip by setting 
    persontrip_prev
    persontrip_next
    for each persontrip instance.
        
    This is ONLY needed when a logbook entry is displayed. So could be called lazily
    only when one of these entries is requested.
    
    It does NOT do what the docstring says here:
    Sets the date_from and date_to field for an expedition based on persontrips.
    Then sets the expedition date_from and date_to based on the personexpeditions.
    """
    # Probably a faster way to do this. This uses a lot of db queries, but we have all this
    # in memory..
    for personexpedition in expedition.personexpedition_set.all():
        persontrips = personexpedition.persontrip_set.order_by('logbook_entry__date')
        # sequencing is difficult to do
        lprevpersontrip = None
        for persontrip in persontrips:
            persontrip.persontrip_prev = lprevpersontrip
            if lprevpersontrip:
                lprevpersontrip.persontrip_next = persontrip
                lprevpersontrip.save()
            persontrip.persontrip_next = None
            lprevpersontrip = persontrip
            #persontrip.save() # also saved in EnterLogIntoDbase. MERGE these to speed up import.


def LoadLogbookForExpedition(expedition):
    """ Parses all logbook entries for one expedition 
    If a cache is found it uses it. If not found, or fails sanity checks, parses source file.
    """
    # absolutely horrid. REFACTOR THIS (all my fault..)
    global logentries
    global logdataissues
    global entries

    logbook_parseable = False
    logbook_cached = False
    yearlinks   = settings.LOGBOOK_PARSER_SETTINGS
    expologbase = os.path.join(settings.EXPOWEB, "years")
    logentries=[]
    
    year = expedition.year
    expect = entries[year]
    # print(" - Logbook for: " + year)

    def validcache(year,n, lbsize):
        if year != expedition:
            print("   ! cache loading: year != expedition ",year, expedition )
            return False
        currentsize = logbookpath.stat().st_size
        if lbsize != currentsize:
            print(f"   ! cache loading: Logbook size {lbsize} != {currentsize} ")
            return False
        if len(logentries) != n:
            print("   ! cache loading: len(logentries) != n ",len(logentries), n )
            return False
        if n != expect:
            print("   ! cache loading: n != expect ",n, expect )
            return False
        return True
    
    def cleanerrors(year):
        global logdataissues
        dataissues = DataIssue.objects.filter(parser='logbooks')
        for di in dataissues:
            ph = year
            if re.search(ph, di.message) is not None:
                #print(f'   - CLEANING dataissue {di.message}')
                di.delete()
     
        #print(f'   - CLEAN {year} {len(logdataissues)} {type(logdataissues)} data issues for this year')
        dellist = []
        for key, value in logdataissues.items():
            #print(f'   - CLEANING logdataissues [{key}]: {value}')
            if key.startswith(year):
                #print(f'   - CLEANING logdataissues [{key:12}]: {value} ')
                dellist.append(key)
        for i in dellist:
            del logdataissues[i]

    cleanerrors(year)

    if year in yearlinks:
        logbookpath = Path(expologbase) /  year / yearlinks[year][0]
        expedition.logbookfile = yearlinks[year][0] 
        parsefunc   = yearlinks[year][1]
    else:
        logbookpath = Path(expologbase) /  year / settings.DEFAULT_LOGBOOK_FILE
        expedition.logbookfile = settings.DEFAULT_LOGBOOK_FILE
        parsefunc   = settings.DEFAULT_LOGBOOK_PARSER
    cache_filename = Path(str(logbookpath) + ".cache")
    if not cache_filename.is_file():
        print("   - Cache file does not exist \"" + str(cache_filename) +"\"")

    expedition.save()
    logbook_cached = False
    if False: # enable cache system
        now = time.time()
        bad_cache = False # temporarily disable reading the cache - buggy
        try:
            cache_t = os.path.getmtime(cache_filename)
            if os.path.getmtime(logbookpath) - cache_t > 2: # at least 2 secs later
                print(" - ! Cache is older than the logbook file")
                bad_cache= True
            if now - cache_t > 30*24*60*60:
                print(" - ! Cache is > 30 days old")
                bad_cache= True
            if bad_cache:
                print("   - so cache is either stale or more than 30 days old. Deleting it.")
                os.remove(cache_filename)
                logentries=[]
                print("   - Deleted stale or corrupt cache file")
                raise
            try:
                # print("   - Reading cache: " + str(cache_filename), end='')
                with open(cache_filename, "rb") as f:
                    year, lbsize, n, logentries = pickle.load(f) 
                if validcache(year, n, lbsize):
                    print(f"  -- {year} : Loaded {len(logentries)} log entries")
                    logbook_cached = True
                else:
                    print("  !- {year} : Cache failed validity checks")
                    raise
            except:
                print("   ! Failed to load corrupt cache  (or I was told to ignore it). Deleting it.")
                os.remove(cache_filename)
                logentries=[]
                raise
        except : 
            print("   - Cache old or de-pickle failure \"" + str(cache_filename) +"\"")
            try:
                file_in = open(logbookpath,'rb')
                txt = file_in.read().decode("utf-8")
                file_in.close()
                logbook_parseable = True
            except (IOError):
                logbook_parseable = False
                print("   ! Couldn't open logbook as UTF-8 " + logbookpath)
    else:
        try:
            file_in = open(logbookpath,'rb')
            txt = file_in.read().decode("utf-8")
            file_in.close()
            logbook_parseable = True
        except (IOError):
            logbook_parseable = False
            print("   ! Couldn't open logbook as UTF-8 " + logbookpath)
        except:
            logbook_parseable = False
            print("   ! Very Bad Error opening " + logbookpath)

    if logbook_parseable:
        parser = globals()[parsefunc]
        print(f' - {year} parsing with {parsefunc}')
        parser(year, expedition, txt) # this launches the right parser for this year
        
        # SetDatesFromLogbookEntries(expedition)
        # if len(logentries) >0:
            # print("   - Cacheing " , len(logentries), " log entries")
            # lbsize = logbookpath.stat().st_size
            # with open(cache_filename, "wb") as fc: # we much check that permission are g+w ! or expo can't delete the cache
                # logbk=(expedition,lbsize,len(logentries),logentries)
                # pickle.dump(logbk, fc, protocol=4)
        # else:
            # print("   ! NO TRIP entries found in logbook, check the syntax.")

    i=0
    for entrytuple in logentries:
        # date, tripcave, triptitle, text, trippeople, expedition, logtime_underground, tripid1 = entrytuple
        try:
            date, tripcave, triptitle, text, trippeople, expedition, logtime_underground, tripid1 = entrytuple
        except ValueError: # cope with removal of entry_type but still in cache files. Remove in Dec. 2022.
            date, tripcave, triptitle, text, trippeople, expedition, logtime_underground, entry_type, tripid1 = entrytuple
        EnterLogIntoDbase(date, tripcave, triptitle, text, trippeople, expedition, 0,
                tripid1)
        i +=1
    # SetDatesFromLogbookEntries(expedition)
    
    if len(logentries) == expect:
        # print(f"OK  {year} {len(logentries):5d} is {expect}\n")
        pass
    else:
        print(f"Mismatch {year} {len(logentries):5d} is not {expect}\n")

    return len(logentries)

def LoadLogbooks():
    """ This is the master function for parsing all logbooks into the Troggle database. 
    Parser settings appropriate for each year are set in settings.py LOGBOOK_PARSER_SETTINGS.
    This should be rewritten to use coroutines to load all logbooks from disc in parallel,
    but must be serialised to write to database as sqlite is single-user.
    """
    global logdataissues
    global entries

    logdataissues = {}
    DataIssue.objects.filter(parser='logbooks').delete()
    expos = Expedition.objects.all()
    if len(expos) <= 1:
        message = f" ! - No expeditions found. Load 'people' first" 
        DataIssue.objects.create(parser='logbooks', message=message)
        logdataissues[f"sqlfail 0000"]=message
        print(message)

    noexpo =      ["1986", "2020", "2021",] #no expo
    lostlogbook = ["1976", "1977", "1978", "1979", "1980", "1981"]
    sqlfail =     ["1987", "1988", "1989"] # breaks mysql with db constraint fail - debug locally first]
    nologbook = noexpo + lostlogbook + sqlfail

    nlbe={}
    expd ={}
    actuals = []
    
    for expo in expos: # pointless as we explicitly know the years in this code.
        year = expo.year
        TROG['pagecache']['expedition'][year] = None # clear cache
        if year in sqlfail:
            print(" - Logbook for: " + year + " NO parsing attempted - known sql failures")
            message = f" ! - Not even attempting to parse logbook for {year} until code fixed" 
            DataIssue.objects.create(parser='logbooks', message=message)
            logdataissues[f"sqlfail {year}"]=message
            print(message)

        if year not in nologbook:
            if year in entries:
                actuals.append(expo)
            else:
                print(" - No Logbook yet for: " + year) # catch case when preparing for next expo

    for ex in actuals:
        nlbe[ex] = LoadLogbookForExpedition(ex)  # this actually loads the logbook for one expo
        
    # tried to use map with concurrent threads - but sqlite database is not concurrent, so failed with database lock
    # yt = 0
    # for r in map(LoadLogbookForExpedition, actuals): 
        # yt = r

    yt = 0
    for e in nlbe:
        yt += nlbe[e]
    print(f"total {yt:,} log entries parsed in all expeditions")
    if yt != len(trips):
        print(f"** total trips in ObjStore:{len(trips):,}")

    try:
        shelvfilenm = 'logbktrips.shelve' # ".db" automatically apended after python 3.8
        with shelve.open(shelvfilenm, writeback=True) as odb:
            for lbe in trips:
                odb[lbe]=trips[lbe]
            odb.sync()
            odb.close()
    except:
        message = f" ! - Failed store cached logbooks in '{shelvfilenm}.db' - Delete old file and try again" 
        DataIssue.objects.create(parser='logbooks', message=message)
        logdataissues["Shelve Fail"]=message
        print(message)


# dateRegex = re.compile(r'<span\s+class="date">(\d\d\d\d)-(\d\d)-(\d\d)</span>', re.S)
# expeditionYearRegex = re.compile(r'<span\s+class="expeditionyear">(.*?)</span>', re.S)
# titleRegex = re.compile(r'<H1>(.*?)</H1>', re.S)
# reportRegex = re.compile(r'<div\s+class="report">(.*)</div>\s*</body>', re.S)
# personRegex = re.compile(r'<div\s+class="person">(.*?)</div>', re.S)
# nameAuthorRegex = re.compile(r'<span\s+class="name(,author|)">(.*?)</span>', re.S)
# TURegex = re.compile(r'<span\s+class="TU">([0-9]*\.?[0-9]+)</span>', re.S)
# locationRegex = re.compile(r'<span\s+class="location">(.*?)</span>', re.S)
# caveRegex = re.compile(r'<span\s+class="cave">(.*?)</span>', re.S)