mirror of
https://expo.survex.com/repositories/troggle/.git
synced 2026-02-08 03:07:48 +00:00
star statement detailed timing code
This commit is contained in:
59
my_profile.txt
Normal file
59
my_profile.txt
Normal file
@@ -0,0 +1,59 @@
|
||||
1 0.362 0.362 20.271 20.271 /home/philip/expo/troggle/parsers/survex.py:1807(LinearLoad)
|
||||
54488 0.378 0.000 13.937 0.000 /home/philip/expo/troggle/parsers/survex.py:1918(starstatement)
|
||||
46977 0.053 0.000 4.973 0.000 /home/philip/expo/troggle/parsers/survex.py:1767(LoadSurvexComment)
|
||||
2082 0.004 0.000 3.427 0.002 /home/philip/expo/troggle/parsers/survex.py:1592(ProcessIncludeLine)
|
||||
2082 0.016 0.000 3.421 0.002 /home/philip/expo/troggle/parsers/survex.py:1532(LoadSurvexFile)
|
||||
2421 0.012 0.000 1.335 0.001 /home/philip/expo/troggle/parsers/survex.py:882(LoadSurvexDate)
|
||||
5066 0.013 0.000 0.946 0.000 /home/philip/expo/troggle/parsers/survex.py:629(LoadSurvexTeam)
|
||||
4926 0.015 0.000 0.913 0.000 /home/philip/expo/troggle/parsers/survex.py:640(record_team_member)
|
||||
2055 0.014 0.000 0.872 0.000 /home/philip/expo/troggle/parsers/survex.py:1231(LoadSurvexRef)
|
||||
5108 0.029 0.000 0.748 0.000 /home/philip/expo/troggle/parsers/people.py:337(GetPersonExpeditionNameLookup)
|
||||
7461 0.012 0.000 0.717 0.000 /home/philip/expo/troggle/parsers/survex.py:216(confirm_team_on_trip)
|
||||
2082 0.006 0.000 0.701 0.000 /home/philip/expo/troggle/parsers/survex.py:1603(ProcessEdulcniLine)
|
||||
1130 0.001 0.000 0.348 0.000 /home/philip/expo/troggle/parsers/survex.py:1224(LoadSurvexMessteam)
|
||||
7461 0.019 0.000 0.308 0.000 /home/philip/expo/troggle/parsers/survex.py:1892(popblock)
|
||||
161832 0.233 0.000 0.305 0.000 /home/philip/expo/troggle/parsers/survex.py:1020(LoadSurvexLeg)
|
||||
857 0.001 0.000 0.299 0.000 /home/philip/expo/troggle/parsers/survex.py:1740(ProcessQM)
|
||||
643 0.006 0.000 0.297 0.000 /home/philip/expo/troggle/parsers/survex.py:1644(LoadSurvexQM)
|
||||
7461 0.013 0.000 0.270 0.000 /home/philip/expo/troggle/parsers/survex.py:1869(pushblock)
|
||||
5049 0.032 0.000 0.252 0.000 /home/philip/expo/troggle/parsers/survex.py:185(put_person_on_trip)
|
||||
8120 0.020 0.000 0.228 0.000 /home/philip/expo/troggle/parsers/survex.py:1336(LoadSurvexDataNormal)
|
||||
2421 0.007 0.000 0.158 0.000 /home/philip/expo/troggle/parsers/survex.py:900(setdate_on_survexblock)
|
||||
1278 0.002 0.000 0.090 0.000 /home/philip/expo/troggle/parsers/survex.py:112(set_walletdate)
|
||||
8 0.001 0.000 0.073 0.009 /home/philip/expo/troggle/parsers/survex.py:89(datewallet)
|
||||
7461 0.010 0.000 0.070 0.000 /home/philip/expo/troggle/parsers/survex.py:599(fix_anonymous)
|
||||
4842 0.008 0.000 0.039 0.000 /home/philip/expo/troggle/parsers/survex.py:153(get_team_on_trip)
|
||||
7461 0.010 0.000 0.025 0.000 /home/philip/expo/troggle/parsers/survex.py:1831(tickle)
|
||||
2082 0.015 0.000 0.024 0.000 /home/philip/expo/troggle/parsers/survex.py:1464(IdentifyCave)
|
||||
2421 0.003 0.000 0.023 0.000 /home/philip/expo/troggle/parsers/survex.py:170(get_people_on_trip)
|
||||
8104 0.011 0.000 0.020 0.000 /home/philip/expo/troggle/parsers/survex.py:520(fix_undated)
|
||||
7461 0.016 0.000 0.019 0.000 /home/philip/expo/troggle/parsers/survex.py:1844(printbegin)
|
||||
992 0.002 0.000 0.018 0.000 /home/philip/expo/troggle/parsers/survex.py:1410(LoadSurvexFlags)
|
||||
11153 0.009 0.000 0.017 0.000 /home/philip/expo/troggle/core/models/survex.py:284(__str__)
|
||||
1640 0.005 0.000 0.013 0.000 /home/philip/expo/troggle/parsers/survex.py:732(LoadSurvexFix)
|
||||
1278 0.001 0.000 0.009 0.000 /home/philip/expo/troggle/core/models/wallets.py:336(date)
|
||||
1378 0.002 0.000 0.009 0.000 /home/philip/expo/troggle/parsers/people.py:361(apply_variations)
|
||||
8 0.000 0.000 0.008 0.001 /home/philip/expo/troggle/core/models/wallets.py:195(get_json)
|
||||
2421 0.001 0.000 0.006 0.000 /home/philip/expo/troggle/parsers/survex.py:246(get_team_pending)
|
||||
1800 0.004 0.000 0.006 0.000 /home/philip/expo/troggle/parsers/people.py:349(apply_initials)
|
||||
16422 0.004 0.000 0.004 0.000 /home/philip/expo/troggle/core/models/survex.py:245(__str__)
|
||||
2082 0.003 0.000 0.004 0.000 /home/philip/expo/troggle/parsers/survex.py:1449(set_primary)
|
||||
2421 0.002 0.000 0.004 0.000 /home/philip/expo/troggle/parsers/survex.py:855(get_expo_from_year)
|
||||
1 0.000 0.000 0.004 0.004 /home/philip/expo/troggle/parsers/survex.py:2094(write_starstatement_timing)
|
||||
7461 0.003 0.000 0.003 0.000 /home/philip/expo/troggle/parsers/survex.py:1857(printend)
|
||||
15524 0.003 0.000 0.003 0.000 /home/philip/expo/troggle/parsers/survex.py:482(LoadSurvexFallThrough)
|
||||
254 0.001 0.000 0.003 0.000 /home/philip/expo/troggle/parsers/survex.py:236(add_to_pending)
|
||||
299 0.000 0.000 0.002 0.000 /home/philip/expo/troggle/parsers/survex.py:798(LoadSurvexUnits)
|
||||
472 0.001 0.000 0.001 0.000 /home/philip/expo/troggle/parsers/survex.py:505(get_team_inherited)
|
||||
128 0.000 0.000 0.001 0.000 /home/philip/expo/troggle/parsers/survex.py:788(LoadSurvexAlias)
|
||||
643 0.000 0.000 0.001 0.000 /home/philip/expo/troggle/core/models/caves.py:93(slug)
|
||||
643 0.000 0.000 0.001 0.000 /home/philip/expo/troggle/core/models/caves.py:105(newslug)
|
||||
2055 0.001 0.000 0.001 0.000 /home/philip/expo/troggle/parsers/survex.py:146(get_offending_filename)
|
||||
643 0.000 0.000 0.000 0.000 /home/philip/expo/troggle/core/models/caves.py:111(number)
|
||||
1436 0.000 0.000 0.000 0.000 /home/philip/expo/troggle/parsers/survex.py:784(LoadSurvexEntrance)
|
||||
234 0.000 0.000 0.000 0.000 /home/philip/expo/troggle/parsers/people.py:319(known_foreigner)
|
||||
82 0.000 0.000 0.000 0.000 /home/philip/expo/troggle/parsers/survex.py:119(stash_data_issue)
|
||||
4 0.000 0.000 0.000 0.000 /home/philip/expo/troggle/core/utils.py:98(get_process_memory)
|
||||
7 0.000 0.000 0.000 0.000 /home/philip/expo/troggle/parsers/survex.py:714(LoadSurvexSet)
|
||||
8 0.000 0.000 0.000 0.000 /home/philip/expo/troggle/core/models/wallets.py:192(get_url)
|
||||
1 0.000 0.000 0.000 0.000 /home/philip/expo/troggle/parsers/survex.py:1236(check_reused_wallet)
|
||||
@@ -1916,6 +1916,12 @@ class LoadingSurvex:
|
||||
print(f" # POP 'any' flag now:'{self.flagsstar['skiplegs']}' was:{oldflags['skiplegs']} ")
|
||||
|
||||
def starstatement(star, fullline):
|
||||
import time
|
||||
timing_data = getattr(self, '_starstatement_timing_data', None)
|
||||
if timing_data is None:
|
||||
timing_data = []
|
||||
self._starstatement_timing_data = timing_data
|
||||
t0 = time.perf_counter()
|
||||
"""Interprets a survex comamnd where * is the first character on the line, e.g. *begin"""
|
||||
nonlocal survexblock
|
||||
nonlocal blkid
|
||||
@@ -1930,6 +1936,7 @@ class LoadingSurvex:
|
||||
|
||||
# ------------------------BEGIN
|
||||
if self.rx_begin.match(cmd):
|
||||
t_block = time.perf_counter()
|
||||
blkid = args.lower()
|
||||
# PUSH state ++++++++++++++
|
||||
self.depthbegin += 1
|
||||
@@ -1937,19 +1944,19 @@ class LoadingSurvex:
|
||||
self.unitsstack.append((self.units, self.unitsfactor))
|
||||
self.legsnumberstack.append(self.legsnumber)
|
||||
self.slengthstack.append(self.slength)
|
||||
self.teaminheritstack.append(self.inheritteam)
|
||||
self.teamcurrentstack.append(self.currentteam)
|
||||
self.dateinheritstack.append(self.inheritdate)
|
||||
self.datecurrentstack.append(self.currentdate)
|
||||
self.teaminheritstack.append(self.inheritteam)
|
||||
self.teamcurrentstack.append(self.currentteam)
|
||||
self.dateinheritstack.append(self.inheritdate)
|
||||
self.datecurrentstack.append(self.currentdate)
|
||||
pushblock()
|
||||
# PUSH state ++++++++++++++
|
||||
self.legsnumber = 0
|
||||
self.slength = 0.0
|
||||
self.units = "metres"
|
||||
self.inheritteam = self.currentteam
|
||||
self.currentteam = set() # zero the current team when we start a new block
|
||||
self.inheritdate = self.currentdate
|
||||
self.currentdate = None # zero the current date when we start a new block
|
||||
self.inheritteam = self.currentteam
|
||||
self.currentteam = set() # zero the current team when we start a new block
|
||||
self.inheritdate = self.currentdate
|
||||
self.currentdate = None # zero the current date when we start a new block
|
||||
printbegin()
|
||||
newsurvexblock = SurvexBlock(
|
||||
name=blkid,
|
||||
@@ -1958,41 +1965,44 @@ class LoadingSurvex:
|
||||
legsall=0,
|
||||
legslength=0.0,
|
||||
)
|
||||
newsurvexblock.save()
|
||||
# print(f"SB: #{newsurvexblock.id} '{newsurvexblock}' parent:{newsurvexblock.parent} f:{newsurvexblock.survexfile}")
|
||||
# Set title before saving, so all fields are set
|
||||
newsurvexblock.title = (
|
||||
"(" + survexblock.title + ")"
|
||||
) # copy parent inititally, overwrite if it has its own
|
||||
survexblock = newsurvexblock
|
||||
survexblock.save() # django insists on this , but we want to save at the end !
|
||||
survexblock.save() # Only save once, after all fields are set
|
||||
tickle()
|
||||
timing_data.append(f"starstatement:*begin {time.perf_counter() - t_block:.6f}\n")
|
||||
|
||||
# ---------------------------END
|
||||
elif self.rx_end.match(cmd):
|
||||
t2 = time.perf_counter()
|
||||
survexblock.legsall = self.legsnumber
|
||||
survexblock.legslength = self.slength
|
||||
printend()
|
||||
slengthtotal += self.slength
|
||||
nlegstotal += self.legsnumber
|
||||
|
||||
|
||||
self.fix_undated(survexblock)
|
||||
self.fix_anonymous(survexblock)
|
||||
try:
|
||||
survexblock.parent.save() # django insists on this although it is already saved !?
|
||||
except:
|
||||
if hasattr(survexblock, 'parent') and survexblock.parent:
|
||||
survexblock.parent.save(update_fields=None) # Only if parent fields changed
|
||||
except Exception:
|
||||
print(f"{survexblock.parent=}", file=sys.stderr)
|
||||
raise
|
||||
try:
|
||||
survexblock.save() # save to db at end of block
|
||||
except:
|
||||
survexblock.save(update_fields=["legsall", "legslength"]) # Only update changed fields
|
||||
except Exception:
|
||||
print(f"{survexblock=}", file=sys.stderr)
|
||||
raise
|
||||
confirm_team_on_trip(survexblock)
|
||||
# POP state ++++++++++++++
|
||||
timing_data.append(f"starstatement:*end {time.perf_counter() - t2:.6f}\n")
|
||||
popblock()
|
||||
self.inheritteam = self.teaminheritstack.pop()
|
||||
self.inheritteam = self.teaminheritstack.pop()
|
||||
self.currentteam = self.teamcurrentstack.pop()
|
||||
self.inheritdate = self.dateinheritstack.pop()
|
||||
self.inheritdate = self.dateinheritstack.pop()
|
||||
self.currentdate = self.datecurrentstack.pop()
|
||||
self.legsnumber = self.legsnumberstack.pop()
|
||||
self.units, self.unitsfactor = self.unitsstack.pop()
|
||||
@@ -2006,43 +2016,67 @@ class LoadingSurvex:
|
||||
|
||||
# -----------------------------
|
||||
elif self.rx_title.match(cmd):
|
||||
t3 = time.perf_counter()
|
||||
quotedtitle = self.rx_quotedtitle.match(args)
|
||||
timing_data.append(f"starstatement:*title {time.perf_counter() - t3:.6f}\n")
|
||||
if quotedtitle:
|
||||
survexblock.title = quotedtitle.groups()[0]
|
||||
else:
|
||||
survexblock.title = args
|
||||
elif self.rx_ref.match(cmd):
|
||||
t4 = time.perf_counter()
|
||||
self.LoadSurvexRef(survexblock, args)
|
||||
timing_data.append(f"starstatement:*ref {time.perf_counter() - t4:.6f}\n")
|
||||
elif self.rx_flags.match(cmd):
|
||||
t5 = time.perf_counter()
|
||||
oldflags = self.flagsstar
|
||||
self.LoadSurvexFlags(args)
|
||||
if debugprint:
|
||||
timing_data.append(f"starstatement:*flags {time.perf_counter() - t5:.6f}\n")
|
||||
if oldflags["skiplegs"] != self.flagsstar["skiplegs"]:
|
||||
print(f" # CHANGE 'any' flag now:'{self.flagsstar['skiplegs']}' was:{oldflags['skiplegs']} ")
|
||||
|
||||
elif self.rx_data.match(cmd):
|
||||
t6 = time.perf_counter()
|
||||
if self.LoadSurvexDataNormal(survexblock, args):
|
||||
timing_data.append(f"starstatement:*data {time.perf_counter() - t6:.6f}\n")
|
||||
# print(f"just normal data {cmd=} {args=} {survexblock=}", file=sys.stderr)
|
||||
pass
|
||||
else:
|
||||
# returns false i.e. something we do not need to worry about
|
||||
return
|
||||
elif self.rx_alias.match(cmd):
|
||||
t7 = time.perf_counter()
|
||||
self.LoadSurvexAlias(survexblock, args)
|
||||
timing_data.append(f"starstatement:*alias {time.perf_counter() - t7:.6f}\n")
|
||||
elif self.rx_entrance.match(cmd):
|
||||
t8 = time.perf_counter()
|
||||
self.LoadSurvexEntrance(survexblock, args)
|
||||
timing_data.append(f"starstatement:*entrance {time.perf_counter() - t8:.6f}\n")
|
||||
elif self.rx_date.match(cmd):
|
||||
t9 = time.perf_counter()
|
||||
self.LoadSurvexDate(survexblock, args)
|
||||
timing_data.append(f"starstatement:*date {time.perf_counter() - t9:.6f}\n")
|
||||
elif self.rx_fix.match(cmd):
|
||||
self.LoadSurvexFix(survexblock, fullline) # but we want the comment on this line
|
||||
t10 = time.perf_counter()
|
||||
self.LoadSurvexFix(survexblock, fullline) # but we want the comment on this line
|
||||
timing_data.append(f"starstatement:*fix {time.perf_counter() - t10:.6f}\n")
|
||||
elif self.rx_units.match(cmd):
|
||||
t11 = time.perf_counter()
|
||||
self.LoadSurvexUnits(survexblock, args)
|
||||
timing_data.append(f"starstatement:*units {time.perf_counter() - t11:.6f}\n")
|
||||
elif self.rx_team.match(cmd):
|
||||
t12 = time.perf_counter()
|
||||
self.LoadSurvexTeam(survexblock, args)
|
||||
elif self.rx_set.match(cmd): #and self.rx_names.match(cmd):
|
||||
timing_data.append(f"starstatement:*team {time.perf_counter() - t12:.6f}\n")
|
||||
elif self.rx_set.match(cmd): # and self.rx_names.match(cmd):
|
||||
t13 = time.perf_counter()
|
||||
self.LoadSurvexSet(survexblock, args)
|
||||
timing_data.append(f"starstatement:*set {time.perf_counter() - t13:.6f}\n")
|
||||
elif self.rx_include.match(cmd):
|
||||
t14 = time.perf_counter()
|
||||
message = f" ! -ERROR *include command not expected here {path}. Re-run a full Survex import."
|
||||
timing_data.append(f"starstatement:*include {time.perf_counter() - t14:.6f}\n")
|
||||
print(message)
|
||||
print(message, file=sys.stderr)
|
||||
stash_data_issue(
|
||||
@@ -2050,9 +2084,19 @@ class LoadingSurvex:
|
||||
message=message,
|
||||
)
|
||||
else:
|
||||
t15 = time.perf_counter()
|
||||
if cmd not in ["equate", "export", "instrument", "calibrate", "cs", "require", "declination", "infer", "case", "sd"]:
|
||||
print(f"FALLTHROUGH *{cmd=} {survexblock=} {survexblock.parent=}")
|
||||
self.LoadSurvexFallThrough(survexblock, args, cmd)
|
||||
timing_data.append(f"starstatement:*fallthrough {time.perf_counter() - t15:.6f}\n")
|
||||
|
||||
# At the end of the import, write all timing data to file
|
||||
def write_starstatement_timing():
|
||||
timing_data = getattr(self, '_starstatement_timing_data', None)
|
||||
if timing_data:
|
||||
with open('starstatement_timing.log', 'w') as f:
|
||||
f.writelines(timing_data)
|
||||
self.write_starstatement_timing = write_starstatement_timing
|
||||
|
||||
# this is a python generator idiom.
|
||||
# see https://realpython.com/introduction-to-python-generators/
|
||||
@@ -2092,6 +2136,10 @@ class LoadingSurvex:
|
||||
self.legsnumber = nlegstotal
|
||||
self.slength = slengthtotal
|
||||
|
||||
# At the end of LinearLoad, write timing data if available
|
||||
if hasattr(self, 'write_starstatement_timing'):
|
||||
self.write_starstatement_timing()
|
||||
|
||||
def PushdownStackScan(self, survexblock, path, finname, flinear, io_collate):
|
||||
"""Follows the *include links in all the survex files from the root file (usually 1623.svx)
|
||||
and reads only the *include and *begin and *end statements. It produces a linearised
|
||||
@@ -2947,12 +2995,12 @@ def set_survexblocks():
|
||||
if b.scanswallet == wallet:
|
||||
pass
|
||||
elif b.scanswallet:
|
||||
if b.date > date(2024, 1, 1) and b.date < date(2025, 1, 1):
|
||||
if b.date is not None and b.date > date(2024, 1, 1) and b.date < date(2025, 1, 1):
|
||||
print(f"2024-check: not set{wallet} on {b.survexfile} for block {b} as set explicitly to {b.scanswallet}")
|
||||
else:
|
||||
b.scanswallet = wallet
|
||||
b.save()
|
||||
if b.date > date(2024, 1, 1) and b.date < date(2025, 1, 1):
|
||||
if b.date is not None and b.date > date(2024, 1, 1) and b.date < date(2025, 1, 1):
|
||||
print(f"2024-check: setting {wallet} on {b.survexfile} for block {b}")
|
||||
|
||||
def survexifywallets():
|
||||
@@ -3029,14 +3077,14 @@ def survexifywallets():
|
||||
sentinelbad = Wallet.objects.get(walletname="1983#00")
|
||||
cuccblock_count = 0
|
||||
for b in cuccblocks:
|
||||
if b.date > date(2001, 1, 1): # do we care about older ones? 1999 certainly has different wallet system
|
||||
if b.date is not None and b.date > date(2001, 1, 1): # do we care about older ones? 1999 certainly has different wallet system
|
||||
if not b.scanswallet:
|
||||
if b.parent.scanswallet:
|
||||
if b.parent.scanswallet != sentinelbad:
|
||||
b.scanswallet = b.parent.scanswallet
|
||||
continue
|
||||
message = f" ! *REF missing {b.date} {b.survexfile}.svx : '{b}'" # msg appears if a *ref "something in quotes" actually does exist.
|
||||
if b.date > date(2019, 1, 1) and b.date < date(2020, 1, 1):
|
||||
if b.date is not None and b.date > date(2019, 1, 1) and b.date < date(2020, 1, 1):
|
||||
print(message, file=sys.stderr)
|
||||
url = get_offending_filename(b.survexfile.path)
|
||||
DataIssue.objects.update_or_create(parser="ref", message=message, url=url)
|
||||
|
||||
3
process_timings.sh
Executable file
3
process_timings.sh
Executable file
@@ -0,0 +1,3 @@
|
||||
#! /bin/sh
|
||||
|
||||
awk '{split($1,a,":"); sum[a[2]]+=$2; count[a[2]]++} END {for (k in sum) printf "%s: total %.6f s, count %d, avg %.6f s\n", k, sum[k], count[k], sum[k]/count[k]}' starstatement_timing.log | sort -nr --key=3
|
||||
45376
starstatement_timing.log
Normal file
45376
starstatement_timing.log
Normal file
File diff suppressed because it is too large
Load Diff
Reference in New Issue
Block a user