mirror of
https://expo.survex.com/repositories/troggle/.git
synced 2026-02-08 03:07:48 +00:00
removing profiling code
This commit is contained in:
3
my_process_timings.txt
Normal file
3
my_process_timings.txt
Normal file
@@ -0,0 +1,3 @@
|
|||||||
|
*end: total 6.249258 s, count 7461, avg 0.000838 s
|
||||||
|
*begin: total 3.152699 s, count 7461, avg 0.000423 s
|
||||||
|
*date: total 1.306240 s, count 2421, avg 0.000540 s
|
||||||
@@ -1917,11 +1917,7 @@ class LoadingSurvex:
|
|||||||
|
|
||||||
def starstatement(star, fullline):
|
def starstatement(star, fullline):
|
||||||
import time
|
import time
|
||||||
timing_data = getattr(self, '_starstatement_timing_data', None)
|
# ...existing code...
|
||||||
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"""
|
"""Interprets a survex comamnd where * is the first character on the line, e.g. *begin"""
|
||||||
nonlocal survexblock
|
nonlocal survexblock
|
||||||
nonlocal blkid
|
nonlocal blkid
|
||||||
@@ -1972,7 +1968,7 @@ class LoadingSurvex:
|
|||||||
survexblock = newsurvexblock
|
survexblock = newsurvexblock
|
||||||
survexblock.save() # Only save once, after all fields are set
|
survexblock.save() # Only save once, after all fields are set
|
||||||
tickle()
|
tickle()
|
||||||
timing_data.append(f"starstatement:*begin {time.perf_counter() - t_block:.6f}\n")
|
# ...timing removed...
|
||||||
|
|
||||||
# ---------------------------END
|
# ---------------------------END
|
||||||
elif self.rx_end.match(cmd):
|
elif self.rx_end.match(cmd):
|
||||||
@@ -1985,6 +1981,7 @@ class LoadingSurvex:
|
|||||||
|
|
||||||
self.fix_undated(survexblock)
|
self.fix_undated(survexblock)
|
||||||
self.fix_anonymous(survexblock)
|
self.fix_anonymous(survexblock)
|
||||||
|
# This is the most time-consuming step within *end processing: 47%
|
||||||
try:
|
try:
|
||||||
if hasattr(survexblock, 'parent') and survexblock.parent:
|
if hasattr(survexblock, 'parent') and survexblock.parent:
|
||||||
survexblock.parent.save(update_fields=None) # Only if parent fields changed
|
survexblock.parent.save(update_fields=None) # Only if parent fields changed
|
||||||
@@ -1992,13 +1989,14 @@ class LoadingSurvex:
|
|||||||
print(f"{survexblock.parent=}", file=sys.stderr)
|
print(f"{survexblock.parent=}", file=sys.stderr)
|
||||||
raise
|
raise
|
||||||
try:
|
try:
|
||||||
|
# This is the second most time-consuming step within *end processing: 35%
|
||||||
survexblock.save(update_fields=["legsall", "legslength"]) # Only update changed fields
|
survexblock.save(update_fields=["legsall", "legslength"]) # Only update changed fields
|
||||||
except Exception:
|
except Exception:
|
||||||
print(f"{survexblock=}", file=sys.stderr)
|
print(f"{survexblock=}", file=sys.stderr)
|
||||||
raise
|
raise
|
||||||
confirm_team_on_trip(survexblock)
|
confirm_team_on_trip(survexblock)
|
||||||
# POP state ++++++++++++++
|
# POP state ++++++++++++++
|
||||||
timing_data.append(f"starstatement:*end {time.perf_counter() - t2:.6f}\n")
|
# ...timing removed...
|
||||||
popblock()
|
popblock()
|
||||||
self.inheritteam = self.teaminheritstack.pop()
|
self.inheritteam = self.teaminheritstack.pop()
|
||||||
self.currentteam = self.teamcurrentstack.pop()
|
self.currentteam = self.teamcurrentstack.pop()
|
||||||
@@ -2043,9 +2041,7 @@ class LoadingSurvex:
|
|||||||
elif self.rx_entrance.match(cmd):
|
elif self.rx_entrance.match(cmd):
|
||||||
self.LoadSurvexEntrance(survexblock, args)
|
self.LoadSurvexEntrance(survexblock, args)
|
||||||
elif self.rx_date.match(cmd):
|
elif self.rx_date.match(cmd):
|
||||||
t9 = time.perf_counter()
|
|
||||||
self.LoadSurvexDate(survexblock, args)
|
self.LoadSurvexDate(survexblock, args)
|
||||||
timing_data.append(f"starstatement:*date {time.perf_counter() - t9:.6f}\n")
|
|
||||||
elif self.rx_fix.match(cmd):
|
elif self.rx_fix.match(cmd):
|
||||||
self.LoadSurvexFix(survexblock, fullline) # but we want the comment on this line
|
self.LoadSurvexFix(survexblock, fullline) # but we want the comment on this line
|
||||||
elif self.rx_units.match(cmd):
|
elif self.rx_units.match(cmd):
|
||||||
@@ -2067,13 +2063,7 @@ class LoadingSurvex:
|
|||||||
print(f"FALLTHROUGH *{cmd=} {survexblock=} {survexblock.parent=}")
|
print(f"FALLTHROUGH *{cmd=} {survexblock=} {survexblock.parent=}")
|
||||||
self.LoadSurvexFallThrough(survexblock, args, cmd)
|
self.LoadSurvexFallThrough(survexblock, args, cmd)
|
||||||
|
|
||||||
# At the end of the import, write all timing data to file
|
# ...timing removed...
|
||||||
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.
|
# this is a python generator idiom.
|
||||||
# see https://realpython.com/introduction-to-python-generators/
|
# see https://realpython.com/introduction-to-python-generators/
|
||||||
@@ -2113,9 +2103,7 @@ class LoadingSurvex:
|
|||||||
self.legsnumber = nlegstotal
|
self.legsnumber = nlegstotal
|
||||||
self.slength = slengthtotal
|
self.slength = slengthtotal
|
||||||
|
|
||||||
# At the end of LinearLoad, write timing data if available
|
# ...timing removed...
|
||||||
if hasattr(self, 'write_starstatement_timing'):
|
|
||||||
self.write_starstatement_timing()
|
|
||||||
|
|
||||||
def PushdownStackScan(self, survexblock, path, finname, flinear, io_collate):
|
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)
|
"""Follows the *include links in all the survex files from the root file (usually 1623.svx)
|
||||||
|
|||||||
34368
starstatement_timing.log
34368
starstatement_timing.log
File diff suppressed because it is too large
Load Diff
27
summarize_starstatement_timing.awk
Normal file
27
summarize_starstatement_timing.awk
Normal file
@@ -0,0 +1,27 @@
|
|||||||
|
# Usage: awk -f summarize_starstatement_timing.awk starstatement_timing.log
|
||||||
|
|
||||||
|
/^starstatement:\*begin/ {
|
||||||
|
begin_count++
|
||||||
|
begin_total += $2
|
||||||
|
}
|
||||||
|
# Example: starstatement:*end total=0.002345 assign_legs=0.000001 printend=0.000002 ...
|
||||||
|
/^starstatement:\*end/ {
|
||||||
|
end_count++
|
||||||
|
match($0, /total=([0-9.]+)/, t)
|
||||||
|
end_total += t[1]
|
||||||
|
n = split($0, fields, " ")
|
||||||
|
for (i = 3; i <= n; i++) {
|
||||||
|
split(fields[i], kv, "=")
|
||||||
|
step = kv[1]
|
||||||
|
val = kv[2]
|
||||||
|
step_count[step]++
|
||||||
|
step_total[step] += val
|
||||||
|
}
|
||||||
|
}
|
||||||
|
END {
|
||||||
|
printf "BEGIN: count=%d total=%.6f avg=%.6f\n", begin_count, begin_total, (begin_count ? begin_total/begin_count : 0)
|
||||||
|
printf "END: count=%d total=%.6f avg=%.6f\n", end_count, end_total, (end_count ? end_total/end_count : 0)
|
||||||
|
for (step in step_count) {
|
||||||
|
printf " %-15s count=%d total=%.6f avg=%.6f\n", step, step_count[step], step_total[step], (step_count[step] ? step_total[step]/step_count[step] : 0)
|
||||||
|
}
|
||||||
|
}
|
||||||
Reference in New Issue
Block a user