€•      Œsphinx.addnodes”Œdocument”“”)”}”(Œ	rawsource”Œ ”Œchildren”]”(Œdocutils.nodes”Œcomment”“”)”}”(hŒôParsl wide event observability prototype report documentation master file, created by
sphinx-quickstart on Sun Oct 26 10:13:01 2025.
You can adapt this file completely to your liking, but it should at least
contain the root `toctree` directive.”h]”h	ŒText”“”ŒôParsl wide event observability prototype report documentation master file, created by
sphinx-quickstart on Sun Oct 26 10:13:01 2025.
You can adapt this file completely to your liking, but it should at least
contain the root `toctree` directive.”…””}”Œparent”hsbaŒ
attributes”}”(Œids”]”Œclasses”]”Œnames”]”Œdupnames”]”Œbackrefs”]”Œ	xml:space”Œpreserve”uŒtagname”h
hhŒ	_document”hŒsource”Œ3/home/benc/parsl/src/observability-report/index.rst”Œline”Kubh	Œsection”“”)”}”(hhh]”(h	Œtitle”“”)”}”(hŒ/Parsl wide event observability prototype report”h]”hŒ/Parsl wide event observability prototype report”…””}”(hh1h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hh,h&hh'h(h)Kubh	Œcompound”“”)”}”(hhh]”h Œtoctree”“”)”}”(hhh]”h}”(h]”h]”h]”h]”h!]”hŒindex”Œentries”]”Œincludefiles”]”Œmaxdepth”KŒcaption”Œ	Contents:”Œglob”‰Œhidden”‰Œincludehidden”‰Œnumbered”K Œ
titlesonly”‰Œ
rawentries”]”Œ
rawcaption”hVuh%hDh'h(h)K	hhAubah}”(h]”h]”Œtoctree-wrapper”ah]”h]”h!]”uh%h?hh,h&hh'h(h)Nubh+)”}”(hhh]”(h0)”}”(hŒIntroduction”h]”hŒIntroduction”…””}”(hhih&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hhfh&hh'h(h)Kubh	Œ	paragraph”“”)”}”(hŒ<These are notes about my current iteration of observability.”h]”hŒ<These are notes about my current iteration of observability.”…””}”(hhyh&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Khhfh&hubeh}”(h]”Œintroduction”ah]”h]”Œintroduction”ah]”h!]”uh%h*hh,h&hh'h(h)Kubh+)”}”(hhh]”(h0)”}”(hŒThe Question”h]”hŒThe Question”…””}”(hh’h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hhh&hh'h(h)Kubhx)”}”(hŒWRead this. give your feedback about if you think it should
be the direction Parsl goes.”h]”hŒWRead this. give your feedback about if you think it should
be the direction Parsl goes.”…””}”(hh h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Khhh&hubeh}”(h]”Œthe-question”ah]”h]”Œthe question”ah]”h!]”uh%h*hh,h&hh'h(h)Kubh+)”}”(hhh]”(h0)”}”(hŒ	Structure”h]”hŒ	Structure”…””}”(hh¹h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hh¶h&hh'h(h)Kubhx)”}”(hŒ5Somewhere be clear that this is in two related parts:”h]”hŒ5Somewhere be clear that this is in two related parts:”…””}”(hhÇh&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Khh¶h&hubh	Œbullet_list”“”)”}”(hhh]”(h	Œ	list_item”“”)”}”(hŒ-emitting wide records from Parsl Python code
”h]”hx)”}”(hŒ,emitting wide records from Parsl Python code”h]”hŒ,emitting wide records from Parsl Python code”…””}”(hhàh&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)KhhÜubah}”(h]”h]”h]”h]”h!]”uh%hÚh'h(h)Khh×h&hubhÛ)”}”(hŒHingesting and analysing records, including wide ones,
from many sources
”h]”hx)”}”(hŒGingesting and analysing records, including wide ones,
from many sources”h]”hŒGingesting and analysing records, including wide ones,
from many sources”…””}”(hhøh&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)K hhôubah}”(h]”h]”h]”h]”h!]”uh%hÚh'h(h)K hh×h&hubeh}”(h]”h]”h]”h]”h!]”Œbullet”Œ*”uh%hÕh'h(h)Khh¶h&hubeh}”(h]”Œ	structure”ah]”h]”Œ	structure”ah]”h!]”uh%h*hh,h&hh'h(h)Kubh+)”}”(hhh]”(h0)”}”(hŒ+What is observability, in the Parsl context”h]”hŒ+What is observability, in the Parsl context”…””}”(hj  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hj  h&hh'h(h)K$ubhx)”}”(hŒª"Observability is a measure of how well internal states of a system can be inferred from knowledge of its external outputs."
(https://en.wikipedia.org/wiki/Observability)”h]”(hŒ‚â€œObservability is a measure of how well internal states of a system can be inferred from knowledge of its external outputs.â€
(”…””}”(hj-  h&hh'Nh)Nubh	Œ	reference”“”)”}”(hŒ+https://en.wikipedia.org/wiki/Observability”h]”hŒ+https://en.wikipedia.org/wiki/Observability”…””}”(hj7  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”Œrefuri”j9  uh%j5  hj-  ubhŒ)”…””}”(hj-  h&hh'Nh)Nubeh}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)K&hj  h&hubhx)”}”(hŒphow can we tell whats going on inside a Parsl run by what we can see externally? how can we expose more "stuff"?”h]”hŒthow can we tell whats going on inside a Parsl run by what we can see externally? how can we expose more â€œstuffâ€?”…””}”(hjP  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)K)hj  h&hubhx)”}”(hŒGabstract notion, but in Parsl that is about: logging; Parsl monitoring.”h]”hŒGabstract notion, but in Parsl that is about: logging; Parsl monitoring.”…””}”(hj^  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)K+hj  h&hubhx)”}”(hŒ/and this prototype is about doing that "better"”h]”hŒ3and this prototype is about doing that â€œbetterâ€”…””}”(hjl  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)K-hj  h&hubeh}”(h]”Œ*what-is-observability-in-the-parsl-context”ah]”h]”Œ+what is observability, in the parsl context”ah]”h!]”uh%h*hh,h&hh'h(h)K$ubh+)”}”(hhh]”(h0)”}”(hŒA motivating use case”h]”hŒA motivating use case”…””}”(hj…  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hj‚  h&hh'h(h)K0ubhx)”}”(hŒQHere's a use case that is hard with what exists in master-branch Parsl right now.”h]”hŒSHereâ€™s a use case that is hard with what exists in master-branch Parsl right now.”…””}”(hj“  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)K2hj‚  h&hubhx)”}”(hX  I want to know, for a particular arbitrary task, the timings of the task as it is submitted by the user workflow, flows through the DFK, into the htex interchange, worker pool, executes on an htex worker, and flows back to the user, with the timing of each step.”h]”hX  I want to know, for a particular arbitrary task, the timings of the task as it is submitted by the user workflow, flows through the DFK, into the htex interchange, worker pool, executes on an htex worker, and flows back to the user, with the timing of each step.”…””}”(hj¡  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)K4hj‚  h&hubhx)”}”(hXÀ  What exists in master Parsl right now is some information in monitoring, and some information in log files. The monitoring information is focused on the high level task model, not what is happening inside Parsl to run that high level model. Logs as they exist now are extremely ad-hoc, spread around in at least 4 different places, and poorly integrated: for example, log messages sometimes do not contain context about which task they refer to, do not represent that context uniformly (e.g. in a greppable way) and are ambiguous about context (e.g. some places refer to task 1, the DFK-level task 1, and some places refer to task 1, the HTEX-level task 1, which could be something completely different).”h]”hXÀ  What exists in master Parsl right now is some information in monitoring, and some information in log files. The monitoring information is focused on the high level task model, not what is happening inside Parsl to run that high level model. Logs as they exist now are extremely ad-hoc, spread around in at least 4 different places, and poorly integrated: for example, log messages sometimes do not contain context about which task they refer to, do not represent that context uniformly (e.g. in a greppable way) and are ambiguous about context (e.g. some places refer to task 1, the DFK-level task 1, and some places refer to task 1, the HTEX-level task 1, which could be something completely different).”…””}”(hj¯  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)K6hj‚  h&hubhx)”}”(hŒIAs a contrast, an example output of this prototype (as of 2025-10-26) is:”h]”hŒIAs a contrast, an example output of this prototype (as of 2025-10-26) is:”…””}”(hj½  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)K8hj‚  h&hubh	Œliteral_block”“”)”}”(hXv	  === About task 358 ===
2025-10-26 10:29:46.467298 MainThread@117098 Task 358: will be sent to executor htex_Local (parsl.log)
2025-10-26 10:29:46.467412 MainThread@117098 Task 358: Adding output dependencies (parsl.log)
2025-10-26 10:29:46.467484 MainThread@117098 Task 358: Added output dependencies (parsl.log)
2025-10-26 10:29:46.467550 MainThread@117098 Task 358: Gathering dependencies: start (parsl.log)
2025-10-26 10:29:46.467620 MainThread@117098 Task 358: Gathering dependencies: end (parsl.log)
2025-10-26 10:29:46.467685 MainThread@117098 Task 358: submitted for App random_uuid, not waiting on any dependency (parsl.log)
2025-10-26 10:29:46.467752 MainThread@117098 Task 358: has AppFuture: <AppFuture at 0x7f8bc1aed730 state=pending> (parsl.log)
2025-10-26 10:29:46.467818 MainThread@117098 Task 358: initializing state to pending (parsl.log)
2025-10-26 10:29:46.469992 Task-Launch_0@117098 Task 358: changing state from pending to launched (parsl.log)
2025-10-26 10:29:46.470113 Task-Launch_0@117098 Task 358: try 0 launched on executor htex_Local with executor id 340 (parsl.log)
2025-10-26 10:29:46.470240 Task-Launch_0@117098 Task 358: Standard out will not be redirected. (parsl.log)
2025-10-26 10:29:46.470310 Task-Launch_0@117098 Task 358: Standard error will not be redirected. (parsl.log)
2025-10-26 10:29:46.470336 MainThread@117129 HTEX task 340: putting onto pending_task_queue (interchange log)
2025-10-26 10:29:46.470404 MainThread@117129 HTEX task 340: fetched task (interchange log)
2025-10-26 10:29:46.470815 Interchange-Communicator@117144 Putting HTEX task 340 into scheduler (Pool manager log)
2025-10-26 10:29:46.471166 MainThread@117162 HTEX task 340: received executor task (Pool worker log)
2025-10-26 10:29:46.492449 MainThread@117162 HTEX task 340: Completed task (Pool worker log)
2025-10-26 10:29:46.492742 MainThread@117162 HTEX task 340: All processing finished for task (Pool worker log)
2025-10-26 10:29:46.493508 MainThread@117129 HTEX task 340: Manager b'4f65802901c6': Removing task from manager (interchange log)
2025-10-26 10:29:46.493948 HTEX-Result-Queue-Thread@117098 Task 358: changing state from launched to exec_done (parsl.log)
2025-10-26 10:29:46.494729 HTEX-Result-Queue-Thread@117098 Task 358: Standard out will not be redirected. (parsl.log)
2025-10-26 10:29:46.494905 HTEX-Result-Queue-Thread@117098 Task 358: Standard error will not be redirected. (parsl.log)”h]”hXv	  === About task 358 ===
2025-10-26 10:29:46.467298 MainThread@117098 Task 358: will be sent to executor htex_Local (parsl.log)
2025-10-26 10:29:46.467412 MainThread@117098 Task 358: Adding output dependencies (parsl.log)
2025-10-26 10:29:46.467484 MainThread@117098 Task 358: Added output dependencies (parsl.log)
2025-10-26 10:29:46.467550 MainThread@117098 Task 358: Gathering dependencies: start (parsl.log)
2025-10-26 10:29:46.467620 MainThread@117098 Task 358: Gathering dependencies: end (parsl.log)
2025-10-26 10:29:46.467685 MainThread@117098 Task 358: submitted for App random_uuid, not waiting on any dependency (parsl.log)
2025-10-26 10:29:46.467752 MainThread@117098 Task 358: has AppFuture: <AppFuture at 0x7f8bc1aed730 state=pending> (parsl.log)
2025-10-26 10:29:46.467818 MainThread@117098 Task 358: initializing state to pending (parsl.log)
2025-10-26 10:29:46.469992 Task-Launch_0@117098 Task 358: changing state from pending to launched (parsl.log)
2025-10-26 10:29:46.470113 Task-Launch_0@117098 Task 358: try 0 launched on executor htex_Local with executor id 340 (parsl.log)
2025-10-26 10:29:46.470240 Task-Launch_0@117098 Task 358: Standard out will not be redirected. (parsl.log)
2025-10-26 10:29:46.470310 Task-Launch_0@117098 Task 358: Standard error will not be redirected. (parsl.log)
2025-10-26 10:29:46.470336 MainThread@117129 HTEX task 340: putting onto pending_task_queue (interchange log)
2025-10-26 10:29:46.470404 MainThread@117129 HTEX task 340: fetched task (interchange log)
2025-10-26 10:29:46.470815 Interchange-Communicator@117144 Putting HTEX task 340 into scheduler (Pool manager log)
2025-10-26 10:29:46.471166 MainThread@117162 HTEX task 340: received executor task (Pool worker log)
2025-10-26 10:29:46.492449 MainThread@117162 HTEX task 340: Completed task (Pool worker log)
2025-10-26 10:29:46.492742 MainThread@117162 HTEX task 340: All processing finished for task (Pool worker log)
2025-10-26 10:29:46.493508 MainThread@117129 HTEX task 340: Manager b'4f65802901c6': Removing task from manager (interchange log)
2025-10-26 10:29:46.493948 HTEX-Result-Queue-Thread@117098 Task 358: changing state from launched to exec_done (parsl.log)
2025-10-26 10:29:46.494729 HTEX-Result-Queue-Thread@117098 Task 358: Standard out will not be redirected. (parsl.log)
2025-10-26 10:29:46.494905 HTEX-Result-Queue-Thread@117098 Task 358: Standard error will not be redirected. (parsl.log)”…””}”hjÍ  sbah}”(h]”h]”h]”h]”h!]”Œforce”‰Œhighlight_args”}”h#h$Œlanguage”Œnone”uh%jË  h'h(h)K:hj‚  h&hubhx)”}”(hŒ`This integrates four log files and two task identifier systems into a single sequence of events.”h]”hŒ`This integrates four log files and two task identifier systems into a single sequence of events.”…””}”(hjà  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)KThj‚  h&hubeh}”(h]”Œa-motivating-use-case”ah]”h]”Œa motivating use case”ah]”h!]”uh%h*hh,h&hh'h(h)K0ubh+)”}”(hhh]”(h0)”}”(hŒcase study 2”h]”hŒcase study 2”…””}”(hjù  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hjö  h&hh'h(h)KWubhx)”}”(hŒFDebugging monitoring performance as part of developing this prototype.”h]”hŒFDebugging monitoring performance as part of developing this prototype.”…””}”(hj  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)KYhjö  h&hubhx)”}”(hŒffindcommon tool - finds common task sequence for templated logs and outputs their sequence, like this:”h]”hŒffindcommon tool - finds common task sequence for templated logs and outputs their sequence, like this:”…””}”(hj  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)K[hjö  h&hubhx)”}”(hŒFirst run parsl-perf like this:”h]”hŒFirst run parsl-perf like this:”…””}”(hj#  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)K]hjö  h&hubjÌ  )”}”(hXx  parsl-perf --config parsl/tests/configs/htex_local.py

[...]

==== Iteration 3 ====
Will run 58179 tasks to target 120 seconds runtime
Submitting tasks / invoking apps
All 58179 tasks submitted ... waiting for completion
Submission took 103.880 seconds = 560.059 tasks/second
Runtime: actual 137.225s vs target 120s
Tasks per second: 423.967
Tests complete - leaving DFK block”h]”hXx  parsl-perf --config parsl/tests/configs/htex_local.py

[...]

==== Iteration 3 ====
Will run 58179 tasks to target 120 seconds runtime
Submitting tasks / invoking apps
All 58179 tasks submitted ... waiting for completion
Submission took 103.880 seconds = 560.059 tasks/second
Runtime: actual 137.225s vs target 120s
Tasks per second: 423.967
Tests complete - leaving DFK block”…””}”hj1  sbah}”(h]”h]”h]”h]”h!]”Œforce”‰Œhighlight_args”}”h#h$jÞ  Œnone”uh%jË  h'h(h)K_hjö  h&hubhx)”}”(hŒ*which executes a total around 60000 tasks.”h]”hŒ*which executes a total around 60000 tasks.”…””}”(hjC  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Knhjö  h&hubhx)”}”(hŒyFirst, note that this prototype benchmarks on my laptop significantly slower than the contemperaneous master branch, at .”h]”hŒyFirst, note that this prototype benchmarks on my laptop significantly slower than the contemperaneous master branch, at .”…””}”(hjQ  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Kphjö  h&hubhx)”}”(hXZ  That's perhaps unsurprising: this benchmark is incredibly log sensistive, as my previous posts have noted - TODO: link to blog post and to R-performance report) - around 900 tasks per second on a 120 second benchmark. And this prototype adds a lot of log output. Part of the path to productionisation would be understanding and constraining this.”h]”hX\  Thatâ€™s perhaps unsurprising: this benchmark is incredibly log sensistive, as my previous posts have noted - TODO: link to blog post and to R-performance report) - around 900 tasks per second on a 120 second benchmark. And this prototype adds a lot of log output. Part of the path to productionisation would be understanding and constraining this.”…””}”(hj_  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Krhjö  h&hubhx)”}”(hX  From that output above, it is clear that the submission loop is taking a long time: 100 seconds. With about 35 seconds of execution happening afterwards. The Parsl core should be able to process task submissions much faster than 560 tasks per seconds. So what's taking up time there?”h]”hX  From that output above, it is clear that the submission loop is taking a long time: 100 seconds. With about 35 seconds of execution happening afterwards. The Parsl core should be able to process task submissions much faster than 560 tasks per seconds. So whatâ€™s taking up time there?”…””}”(hjm  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Kthjö  h&hubhx)”}”(hŒeRun findcommon (a could-be-modular-but-isn't helper from this observability prototype) on the result:”h]”hŒgRun findcommon (a could-be-modular-but-isnâ€™t helper from this observability prototype) on the result:”…””}”(hj{  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Kvhjö  h&hubjÌ  )”}”(hXâ  0.0: Task %s: will be sent to executor htex_local
0.00023320618468031343: Task %s: Adding output dependencies
0.0004515730863634116: Task %s: Added output dependencies
0.000672943356177761: Task %s: Gathering dependencies: start
0.0008952160973877195: Task %s: Gathering dependencies: end
0.0011054732824941516: Task %s: submitted for App app, not waiting on any dependency
0.001316777690507145: Task %s: has AppFuture: %s
0.0015680651123983979: Task %s: initializing state to pending
23.684763520758917: HTEX task %s: putting onto pending_task_queue
23.68483662049256: HTEX task %s: fetched task
23.684863335335613: Task %s: changing state from pending to launched
23.6850573607536: Task %s: try %s launched on executor %s with executor id %s
23.685248910492184: Task %s: Standard out will not be redirected.
23.685424046734745: Task %s: Standard error will not be redirected.
23.686276226995773: Putting HTEX task %s into scheduler
23.686777094898495: HTEX task %s: received executor task
23.687025900194147: HTEX task %s: Completed task
23.687268549254735: HTEX task %s: All processing finished for task
23.687837933843614: HTEX task %s: Manager %r: Removing task from manager
23.688483699079185: Task %s: changing state from launched to exec_done”h]”hXâ  0.0: Task %s: will be sent to executor htex_local
0.00023320618468031343: Task %s: Adding output dependencies
0.0004515730863634116: Task %s: Added output dependencies
0.000672943356177761: Task %s: Gathering dependencies: start
0.0008952160973877195: Task %s: Gathering dependencies: end
0.0011054732824941516: Task %s: submitted for App app, not waiting on any dependency
0.001316777690507145: Task %s: has AppFuture: %s
0.0015680651123983979: Task %s: initializing state to pending
23.684763520758917: HTEX task %s: putting onto pending_task_queue
23.68483662049256: HTEX task %s: fetched task
23.684863335335613: Task %s: changing state from pending to launched
23.6850573607536: Task %s: try %s launched on executor %s with executor id %s
23.685248910492184: Task %s: Standard out will not be redirected.
23.685424046734745: Task %s: Standard error will not be redirected.
23.686276226995773: Putting HTEX task %s into scheduler
23.686777094898495: HTEX task %s: received executor task
23.687025900194147: HTEX task %s: Completed task
23.687268549254735: HTEX task %s: All processing finished for task
23.687837933843614: HTEX task %s: Manager %r: Removing task from manager
23.688483699079185: Task %s: changing state from launched to exec_done”…””}”hj‰  sbah}”(h]”h]”h]”h]”h!]”Œforce”‰Œhighlight_args”}”h#h$jÞ  Œnone”uh%jË  h'h(h)Kxhjö  h&hubhx)”}”(hXH  In this stylised synthetic task trace, a task takes an average of 23 seconds to go from the first event (choosing executor) to the final mark as done. That's fairly consistent with the parsl-perf output - I would expect the average here to be around half the time of parsl-perf's submission time to completion time (30 seconds).”h]”hXL  In this stylised synthetic task trace, a task takes an average of 23 seconds to go from the first event (choosing executor) to the final mark as done. Thatâ€™s fairly consistent with the parsl-perf output - I would expect the average here to be around half the time of parsl-perfâ€™s submission time to completion time (30 seconds).”…””}”(hj›  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Khjö  h&hubhx)”}”(hŒæWhat's useful with findcommon's output is that it shows the insides of Parsl's working in more depth: 20 states instead of parsl-perf's start, submitted, end. And the potential exists to calculate other statistics on these events.”h]”hŒîWhatâ€™s useful with findcommonâ€™s output is that it shows the insides of Parslâ€™s working in more depth: 20 states instead of parsl-perfâ€™s start, submitted, end. And the potential exists to calculate other statistics on these events.”…””}”(hj©  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)K’hjö  h&hubhx)”}”(hŒøSo in this average case, there's something slow happening between setting the task to pending, and then the task "simultaneously" being marked as launched on the submit side and the interchange receiving it and placing it in the pending task queue.”h]”hŒþSo in this average case, thereâ€™s something slow happening between setting the task to pending, and then the task â€œsimultaneouslyâ€ being marked as launched on the submit side and the interchange receiving it and placing it in the pending task queue.”…””}”(hj·  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)K”hjö  h&hubhx)”}”(hŒgThat's a bit surprising - tasks are meant to accumulate in the interchange, not before the interchange.”h]”hŒiThatâ€™s a bit surprising - tasks are meant to accumulate in the interchange, not before the interchange.”…””}”(hjÅ  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)K–hjö  h&hubhx)”}”(hX3  So let's perform some deeper investigations -- observability is for Serious Investigators and so it is fine to be hacking on the Parsl source code to understand this more. (by hacking, I mean making temporary changes for the investigation that likely will be thrown away rather than integrated into master).”h]”hX6  So letâ€™s perform some deeper investigations â€“ observability is for Serious Investigators and so it is fine to be hacking on the Parsl source code to understand this more. (by hacking, I mean making temporary changes for the investigation that likely will be thrown away rather than integrated into master).”…””}”(hjÓ  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)K˜hjö  h&hubhx)”}”(hŒòLet's flesh out the whole submission process with some more log lines. On the DFK side, that's pretty straightforward: the observability prototype has a per-task logger which, if you have the task record, will attach log messages to the task.”h]”hŒöLetâ€™s flesh out the whole submission process with some more log lines. On the DFK side, thatâ€™s pretty straightforward: the observability prototype has a per-task logger which, if you have the task record, will attach log messages to the task.”…””}”(hjá  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Kšhjö  h&hubhx)”}”(hŒFor example, here's the changes to add a log around the first call to launch_if_ready, which is probably the call that is launching the task.”h]”hŒFor example, hereâ€™s the changes to add a log around the first call to launch_if_ready, which is probably the call that is launching the task.”…””}”(hjï  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Kœhjö  h&hubjÌ  )”}”(hŒ£+  task_logger.debug("TMP: dependencies added, calling launch_if_ready")
   self.launch_if_ready(task_record)
+  task_logger.debug("TMP: launch_if_ready returned")”h]”hŒ£+  task_logger.debug("TMP: dependencies added, calling launch_if_ready")
   self.launch_if_ready(task_record)
+  task_logger.debug("TMP: launch_if_ready returned")”…””}”hjý  sbah}”(h]”h]”h]”h]”h!]”Œforce”‰Œhighlight_args”}”h#h$jÞ  Œnone”uh%jË  h'h(h)Kžhjö  h&hubhx)”}”(hŒ³My suspicion is that this is around the htex submission queues, with a secondary submission around the launch executor, so to start with I'm going to add more logging around that.”h]”hŒµMy suspicion is that this is around the htex submission queues, with a secondary submission around the launch executor, so to start with Iâ€™m going to add more logging around that.”…””}”(hj  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)K¥hjö  h&hubhx)”}”(hŒ†Then rerun parsl-perf and findcommon, without modifying either, and it turns out to be that secondary submission, the launch executor:”h]”hŒ†Then rerun parsl-perf and findcommon, without modifying either, and it turns out to be that secondary submission, the launch executor:”…””}”(hj  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)K§hjö  h&hubjÌ  )”}”(hX  0.0020453477688227: Task %s: TMP: submitted into launch pool executor
0.002256870306434224: Task %s: TMP: launch_if_ready returned
14.073021359217009: Task %s: TMP: before submitter lock
[...]
14.078550367412324: Task %s: changing state from launched to exec_done”h]”hX  0.0020453477688227: Task %s: TMP: submitted into launch pool executor
0.002256870306434224: Task %s: TMP: launch_if_ready returned
14.073021359217009: Task %s: TMP: before submitter lock
[...]
14.078550367412324: Task %s: changing state from launched to exec_done”…””}”hj+  sbah}”(h]”h]”h]”h]”h!]”Œforce”‰Œhighlight_args”}”h#h$jÞ  Œnone”uh%jË  h'h(h)K©hjö  h&hubhx)”}”(hŒ°Don't worry too much about the final time (14s) changing from 23s in the earlier run -- that's a characteristic of parsl-perf batch sizes that I'm working on in another branch.”h]”hŒ·Donâ€™t worry too much about the final time (14s) changing from 23s in the earlier run â€“ thatâ€™s a characteristic of parsl-perf batch sizes that Iâ€™m working on in another branch.”…””}”(hj=  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)K±hjö  h&hubhx)”}”(hŒ{If that's the case, I'd expect the thread pool executor, previously much faster than htex, to show similar characteristics:”h]”hŒIf thatâ€™s the case, Iâ€™d expect the thread pool executor, previously much faster than htex, to show similar characteristics:”…””}”(hjK  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)K³hjö  h&hubhx)”}”(hX\  surprisingly, though although the throughput is not much much higher... the trace looks very different timewise. the bulk of the time here still happens at the same place, there isn't so much waiting there - less than a second on average. That's possibly because the executor can get through tasks much faster so the queue doesn't build up so much?”h]”hXb  surprisingly, though although the throughput is not much much higherâ€¦ the trace looks very different timewise. the bulk of the time here still happens at the same place, there isnâ€™t so much waiting there - less than a second on average. Thatâ€™s possibly because the executor can get through tasks much faster so the queue doesnâ€™t build up so much?”…””}”(hjY  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Kµhjö  h&hubjÌ  )”}”(hX  ==== Iteration 2 ====
Will run 68976 tasks to target 120 seconds runtime
Submitting tasks / invoking apps
All 68976 tasks submitted ... waiting for completion
Submission took 117.915 seconds = 584.965 tasks/second
Runtime: actual 118.417s vs target 120s
Tasks per second: 582.485”h]”hX  ==== Iteration 2 ====
Will run 68976 tasks to target 120 seconds runtime
Submitting tasks / invoking apps
All 68976 tasks submitted ... waiting for completion
Submission took 117.915 seconds = 584.965 tasks/second
Runtime: actual 118.417s vs target 120s
Tasks per second: 582.485”…””}”hjg  sbah}”(h]”h]”h]”h]”h!]”Œforce”‰Œhighlight_args”}”h#h$jÞ  Œnone”uh%jË  h'h(h)K¸hjö  h&hubjÌ  )”}”(hX‹  0.0: Task %s: will be sent to executor threads
0.00014157412110423425: Task %s: Adding output dependencies
0.0002898652725047201: Task %s: Added output dependencies
0.000425118042214259: Task %s: Gathering dependencies: start
0.0005696294991521399: Task %s: Gathering dependencies: end
0.0006999648174108608: Task %s: submitted for App app, not waiting on any dependency
0.0008433702196425292: Task %s: has AppFuture: %s
0.0010710284919573986: Task %s: initializing state to pending
0.0011652027385929428: Task %s: TMP: dependencies added, calling launch_if_ready
0.0012973675719411494: Task %s: submitting into launch pool executor
0.0014397921284467212: Task %s: submitted into launch pool executor
0.0015767665501452072: Task %s: TMP: launch_if_ready returned
0.3143575128217656: Task %s: before submitter lock
0.31448896150771743: Task %s: after submitter lock, before executor.submit
0.3146383380777917: Task %s: after before executor.submit
0.3147926810507091: Task %s: changing state from pending to launched
0.3149239369413048: Task %s: try 0 launched on executor threads
0.31504996538376506: Task %s: Standard out will not be redirected.
0.31504996538376506: Task %s: Standard out will not be redirected.
0.3151759985402679: Task %s: Standard error will not be redirected.
0.3151759985402679: Task %s: Standard error will not be redirected.
0.315319734920821: Task %s: changing state from launched to exec_done”h]”hX‹  0.0: Task %s: will be sent to executor threads
0.00014157412110423425: Task %s: Adding output dependencies
0.0002898652725047201: Task %s: Added output dependencies
0.000425118042214259: Task %s: Gathering dependencies: start
0.0005696294991521399: Task %s: Gathering dependencies: end
0.0006999648174108608: Task %s: submitted for App app, not waiting on any dependency
0.0008433702196425292: Task %s: has AppFuture: %s
0.0010710284919573986: Task %s: initializing state to pending
0.0011652027385929428: Task %s: TMP: dependencies added, calling launch_if_ready
0.0012973675719411494: Task %s: submitting into launch pool executor
0.0014397921284467212: Task %s: submitted into launch pool executor
0.0015767665501452072: Task %s: TMP: launch_if_ready returned
0.3143575128217656: Task %s: before submitter lock
0.31448896150771743: Task %s: after submitter lock, before executor.submit
0.3146383380777917: Task %s: after before executor.submit
0.3147926810507091: Task %s: changing state from pending to launched
0.3149239369413048: Task %s: try 0 launched on executor threads
0.31504996538376506: Task %s: Standard out will not be redirected.
0.31504996538376506: Task %s: Standard out will not be redirected.
0.3151759985402679: Task %s: Standard error will not be redirected.
0.3151759985402679: Task %s: Standard error will not be redirected.
0.315319734920821: Task %s: changing state from launched to exec_done”…””}”hjy  sbah}”(h]”h]”h]”h]”h!]”Œforce”‰Œhighlight_args”}”h#h$jÞ  Œnone”uh%jË  h'h(h)KÂhjö  h&hubhx)”}”(hXï  So maybe I can do some graphing of events to give more insight than these averages are showing. A favourite of mine from previous monitoring work is how many tasks are in each state at each moment in time. I'll have to implement that for this observability prototype, because it's not done already, but once it's done it should be reusable. and it should share most infrastructure with `findcommon`. Especially relevant is discovering where bottlenecks are: it looks like this is a parsl-affecting performance regression that might be keeping workers idle. For example, we could ask: does the interchange have "enough" tasks at all times to keep dispatching. With 8 cores on my laptop, I'd like it to have at least 8 tasks or so inside htex at any one time, but this looks like it might not be true. Hopefully graphing will reveal more. It's also important to note that this findcommon output shows latency, not throughput -- though high latency at particular points is an indication of throughput problems.”h]”(hXˆ  So maybe I can do some graphing of events to give more insight than these averages are showing. A favourite of mine from previous monitoring work is how many tasks are in each state at each moment in time. Iâ€™ll have to implement that for this observability prototype, because itâ€™s not done already, but once itâ€™s done it should be reusable. and it should share most infrastructure with ”…””}”(hj‹  h&hh'Nh)Nubh	Œtitle_reference”“”)”}”(hŒ`findcommon`”h]”hŒ
findcommon”…””}”(hj•  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%j“  hj‹  ubhXj  . Especially relevant is discovering where bottlenecks are: it looks like this is a parsl-affecting performance regression that might be keeping workers idle. For example, we could ask: does the interchange have â€œenoughâ€ tasks at all times to keep dispatching. With 8 cores on my laptop, Iâ€™d like it to have at least 8 tasks or so inside htex at any one time, but this looks like it might not be true. Hopefully graphing will reveal more. Itâ€™s also important to note that this findcommon output shows latency, not throughput â€“ though high latency at particular points is an indication of throughput problems.”…””}”(hj‹  h&hh'Nh)Nubeh}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)KÝhjö  h&hubhx)”}”(hXg  Or, I can look at how many tasks are in the interchange over time: there either is, or straightforwardly can be, a log line for that. That will fit a different model to the above log lines which are per-task. Instead they're a metric on the state of one thing only: the interchange. of which there is only one, at least for the purposes of this investigation.”h]”hXi  Or, I can look at how many tasks are in the interchange over time: there either is, or straightforwardly can be, a log line for that. That will fit a different model to the above log lines which are per-task. Instead theyâ€™re a metric on the state of one thing only: the interchange. of which there is only one, at least for the purposes of this investigation.”…””}”(hj­  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Kßhjö  h&hubhx)”}”(hŒiAdd a new log line like this into the interchange at a suitable point (after task queueing, for example):”h]”hŒiAdd a new log line like this into the interchange at a suitable point (after task queueing, for example):”…””}”(hj»  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Káhjö  h&hubjÌ  )”}”(hŒ®+  ql = len(self.pending_task_queue)
+  logger.info(f"TMP: there are {ql} tasks in the pending task queue", extra={"metric": "pending_task_queue_length", "queued_tasks": ql})”h]”hŒ®+  ql = len(self.pending_task_queue)
+  logger.info(f"TMP: there are {ql} tasks in the pending task queue", extra={"metric": "pending_task_queue_length", "queued_tasks": ql})”…””}”hjÉ  sbah}”(h]”h]”h]”h]”h!]”Œforce”‰Œhighlight_args”}”h#h$jÞ  Œnone”uh%jË  h'h(h)Kãhjö  h&hubhx)”}”(hŒ˜Now can either look through the logs by hand to manually see the value. Or extract it programmatically and plot it with matplotlib, in an ad-hoc script:”h]”hŒ˜Now can either look through the logs by hand to manually see the value. Or extract it programmatically and plot it with matplotlib, in an ad-hoc script:”…””}”(hjÛ  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Kèhjö  h&hubjÌ  )”}”(hXÌ  import matplotlib.pyplot as plt
from parsl.observability.getlogs import getlogs

logs = getlogs()

# looking for these logs:
# "metric": "pending_task_queue_length", "queued_tasks": ql})

metrics = [(float(l['created']), int(l['queued_tasks']))
           for l in logs
           if  'metric' in l
           and l['metric'] == "pending_task_queue_length"
          ]


plt.scatter(x=[m[0] for m in metrics],
            y=[m[1] for m in metrics])

plt.show()”h]”hXÌ  import matplotlib.pyplot as plt
from parsl.observability.getlogs import getlogs

logs = getlogs()

# looking for these logs:
# "metric": "pending_task_queue_length", "queued_tasks": ql})

metrics = [(float(l['created']), int(l['queued_tasks']))
           for l in logs
           if  'metric' in l
           and l['metric'] == "pending_task_queue_length"
          ]


plt.scatter(x=[m[0] for m in metrics],
            y=[m[1] for m in metrics])

plt.show()”…””}”hjé  sbah}”(h]”h]”h]”h]”h!]”Œforce”‰Œhighlight_args”}”h#h$jÞ  Œpython”uh%jË  h'h(h)Kêhjö  h&hubhx)”}”(hŒtand indeed that shows that the interchange queue length almost never goes above length 1, and never above length 10.”h]”hŒtand indeed that shows that the interchange queue length almost never goes above length 1, and never above length 10.”…””}”(hjû  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M hjö  h&hubhx)”}”(hXC  That's enough for now, but it's a usecase that shows partially understanding throughput: we can see from this observability data that the conceptual 50000 task queue that begins in parsl-perf as a `for`-loop doesn't progress fast enough to the interchange internal queue, and so probably performance effort should probably be focused on understanding and improving the code path around launch and getting into the interchange queue. With an almost empty interchange queue, anything happening on the worker side is probably not too relevant, at least for that parsl-perf use case.”h]”(hŒÉThatâ€™s enough for now, but itâ€™s a usecase that shows partially understanding throughput: we can see from this observability data that the conceptual 50000 task queue that begins in parsl-perf as a ”…””}”(hj	  h&hh'Nh)Nubj”  )”}”(hŒ`for`”h]”hŒfor”…””}”(hj  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%j“  hj	  ubhX{  -loop doesnâ€™t progress fast enough to the interchange internal queue, and so probably performance effort should probably be focused on understanding and improving the code path around launch and getting into the interchange queue. With an almost empty interchange queue, anything happening on the worker side is probably not too relevant, at least for that parsl-perf use case.”…””}”(hj	  h&hh'Nh)Nubeh}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Mhjö  h&hubhx)”}”(hŒ±This "understand the queue lengths (or implicit queue lengths) towards execution" investigation style has been useful in understanding Parsl performance limitations in the past.”h]”hŒµThis â€œunderstand the queue lengths (or implicit queue lengths) towards executionâ€ investigation style has been useful in understanding Parsl performance limitations in the past.”…””}”(hj)  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Mhjö  h&hubeh}”(h]”Œcase-study-2”ah]”h]”Œcase study 2”ah]”h!]”uh%h*hh,h&hh'h(h)KWubh+)”}”(hhh]”(h0)”}”(hŒConfigurability”h]”hŒConfigurability”…””}”(hjB  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hj?  h&hh'h(h)Mubhx)”}”(hŒâA soft start is to let people opt into observability style logs - with most performance hit coming from turning on json output, i think, it doesn't matter performance-wise too much about adding in the extra stuff on log calls.”h]”hŒäA soft start is to let people opt into observability style logs - with most performance hit coming from turning on json output, i think, it doesnâ€™t matter performance-wise too much about adding in the extra stuff on log calls.”…””}”(hjP  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M	hj?  h&hubhx)”}”(hX  The current parsl stuff is not set up for arbitrary log
configuration outside of the submit-side process: for example,
the worker helpers don't do any log config at all and rely
on their enclosing per-executor environments to do it, which
i think some do not.”h]”hX  The current parsl stuff is not set up for arbitrary log
configuration outside of the submit-side process: for example,
the worker helpers donâ€™t do any log config at all and rely
on their enclosing per-executor environments to do it, which
i think some do not.”…””}”(hj^  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Mhj?  h&hubhx)”}”(hŒYhtex interchange and worker logs have a hardcoded log config
with a single debug boolean.”h]”hŒYhtex interchange and worker logs have a hardcoded log config
with a single debug boolean.”…””}”(hjl  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Mhj?  h&hubhx)”}”(hŒÆI'd like to do something a bit more flexible than adding more
parameters, that reflect that in the future people might want
to configure their handlers differently rather than using the
JSONHandler.”h]”hŒÈIâ€™d like to do something a bit more flexible than adding more
parameters, that reflect that in the future people might want
to configure their handlers differently rather than using the
JSONHandler.”…””}”(hjz  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Mhj?  h&hubeh}”(h]”Œconfigurability”ah]”h]”Œconfigurability”ah]”h!]”uh%h*hh,h&hh'h(h)Mubh+)”}”(hhh]”(h0)”}”(hŒ*Relation to monitoring and logging systems”h]”hŒ*Relation to monitoring and logging systems”…””}”(hj“  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hj  h&hh'h(h)Mubhx)”}”(hŒ˜Parsl uses python's logging module. Parsl has its own monitoring system. This work builds on both of those, but changes how thye are used significantly.”h]”hŒšParsl uses pythonâ€™s logging module. Parsl has its own monitoring system. This work builds on both of those, but changes how thye are used significantly.”…””}”(hj¡  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Mhj  h&hubeh}”(h]”Œ*relation-to-monitoring-and-logging-systems”ah]”h]”Œ*relation to monitoring and logging systems”ah]”h!]”uh%h*hh,h&hh'h(h)Mubh+)”}”(hhh]”(h0)”}”(hŒ Why observability? vs monitoring”h]”hŒ Why observability? vs monitoring”…””}”(hjº  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hj·  h&hh'h(h)Mubhx)”}”(hXh  Original monitoring prototype was focused on what is happening
with Parsl user level concepts: tasks, blocks for example
as they move through simple states. Anything deeper is part
of the idea of "Parsl makes it so you don't have to think
about anything happening inside". Which is not how things are
in reality: neither for code reliabilty or for performance.”h]”hXn  Original monitoring prototype was focused on what is happening
with Parsl user level concepts: tasks, blocks for example
as they move through simple states. Anything deeper is part
of the idea of â€œParsl makes it so you donâ€™t have to think
about anything happening insideâ€. Which is not how things are
in reality: neither for code reliabilty or for performance.”…””}”(hjÈ  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M!hj·  h&hubhx)”}”(hŒ3Parsl Monitoring is too strict in a couple of ways:”h]”hŒ3Parsl Monitoring is too strict in a couple of ways:”…””}”(hjÖ  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M(hj·  h&hubhx)”}”(hŒ›The data model is fairly hard-coded into the architecture:
specific SQL schema, specific message formats and specific
places where those messages are sent.”h]”hŒ›The data model is fairly hard-coded into the architecture:
specific SQL schema, specific message formats and specific
places where those messages are sent.”…””}”(hjä  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M*hj·  h&hubhx)”}”(hŒThe transmission model is real-time. Even with recent radio
plugins, the assumption is still that messages will arrive
soon after being sent.”h]”hŒThe transmission model is real-time. Even with recent radio
plugins, the assumption is still that messages will arrive
soon after being sent.”…””}”(hjò  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M.hj·  h&hubhx)”}”(hX  The almost-real-time data transmisison model is especially
awkward when combined with SQL: distributed system events
will arrive at different times or in the original UDP model
perhaps not at all, and the "first" message that
creates a task (for the purposes of the database) might arrive
after some secondary data that requires that primary key to
exist. yes, it's nice for the SQL database to follow foreign
key rules, especially when looking at the data "afterwards"
but that's not realistic for distributed unreliable events.”h]”hX  The almost-real-time data transmisison model is especially
awkward when combined with SQL: distributed system events
will arrive at different times or in the original UDP model
perhaps not at all, and the â€œfirstâ€ message that
creates a task (for the purposes of the database) might arrive
after some secondary data that requires that primary key to
exist. yes, itâ€™s nice for the SQL database to follow foreign
key rules, especially when looking at the data â€œafterwardsâ€
but thatâ€™s not realistic for distributed unreliable events.”…””}”(hj   h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M2hj·  h&hubhx)”}”(hŒContrast this to:”h]”hŒContrast this to:”…””}”(hj  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M<hj·  h&hubhÖ)”}”(hhh]”(hÛ)”}”(hŒxarbitrary logs that may be different for different kinds
of execution - for example, different executor implementations
”h]”hx)”}”(hŒwarbitrary logs that may be different for different kinds
of execution - for example, different executor implementations”h]”hŒwarbitrary logs that may be different for different kinds
of execution - for example, different executor implementations”…””}”(hj#  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M>hj  ubah}”(h]”h]”h]”h]”h!]”uh%hÚh'h(h)M>hj  h&hubhÛ)”}”(hX	  pouring over these logs "later" - there's no need for those
logs to accumulate in real time in one place for post-facto
analysis. And in practice, when doing log analysis rather
than monitoring analysis, "send me a tarball of your runinfo"
is a standard technique.
”h]”hx)”}”(hX  pouring over these logs "later" - there's no need for those
logs to accumulate in real time in one place for post-facto
analysis. And in practice, when doing log analysis rather
than monitoring analysis, "send me a tarball of your runinfo"
is a standard technique.”h]”hX  pouring over these logs â€œlaterâ€ - thereâ€™s no need for those
logs to accumulate in real time in one place for post-facto
analysis. And in practice, when doing log analysis rather
than monitoring analysis, â€œsend me a tarball of your runinfoâ€
is a standard technique.”…””}”(hj;  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MAhj7  ubah}”(h]”h]”h]”h]”h!]”uh%hÚh'h(h)MAhj  h&hubeh}”(h]”h]”h]”h]”h!]”j  j  uh%hÕh'h(h)M>hj·  h&hubhx)”}”(hXx  Parsl Monitoring is not well suited to adding in new ad-hoc
events, perhaps just for one off debugging cases that will be
thrown away: schema modifications in both SQL and in message
tasks, and rearranging code to accomodate that is a serious
business. Contrast logging: there's always a logger in any
part of Parsl, and you can ``logger.debug("hello")`` pretty
much anywhere.”h]”(hXK  Parsl Monitoring is not well suited to adding in new ad-hoc
events, perhaps just for one off debugging cases that will be
thrown away: schema modifications in both SQL and in message
tasks, and rearranging code to accomodate that is a serious
business. Contrast logging: thereâ€™s always a logger in any
part of Parsl, and you can ”…””}”(hjU  h&hh'Nh)Nubh	Œliteral”“”)”}”(hŒ``logger.debug("hello")``”h]”hŒlogger.debug("hello")”…””}”(hj_  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%j]  hjU  ubhŒ pretty
much anywhere.”…””}”(hjU  h&hh'Nh)Nubeh}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MGhj·  h&hubhx)”}”(hŒÈParsl Monitoring was also implemented with a fixed queries
/ dashboard mindset: one set of views that is expected to be
sufficient. As time has shown, people like to make other
outputs from this data.”h]”hŒÈParsl Monitoring was also implemented with a fixed queries
/ dashboard mindset: one set of views that is expected to be
sufficient. As time has shown, people like to make other
outputs from this data.”…””}”(hjw  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MOhj·  h&hubhx)”}”(hŒ\want to debug/profile whats happening *inside parsl* rather
than *inside the user workflow*.”h]”(hŒ&want to debug/profile whats happening ”…””}”(hj…  h&hh'Nh)Nubh	Œemphasis”“”)”}”(hŒ*inside parsl*”h]”hŒinside parsl”…””}”(hj  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%j  hj…  ubhŒ rather
than ”…””}”(hj…  h&hh'Nh)NubjŽ  )”}”(hŒ*inside the user workflow*”h]”hŒinside the user workflow”…””}”(hj¡  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%j  hj…  ubhŒ.”…””}”(hj…  h&hh'Nh)Nubeh}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MThj·  h&hubeh}”(h]”Œwhy-observability-vs-monitoring”ah]”h]”Œ why observability? vs monitoring”ah]”h!]”uh%h*hh,h&hh'h(h)Mubh+)”}”(hhh]”(h0)”}”(hŒOther components”h]”hŒOther components”…””}”(hjÄ  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hjÁ  h&hh'h(h)MXubhx)”}”(hŒÅSome components aren't Parsl-aware: for example work queue
has no notion of a Parsl task ID. and it runs its own
logging system, that is not Python, and so not amenable to
Python monitoring radios.”h]”hŒÇSome components arenâ€™t Parsl-aware: for example work queue
has no notion of a Parsl task ID. and it runs its own
logging system, that is not Python, and so not amenable to
Python monitoring radios.”…””}”(hjÒ  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MZhjÁ  h&hubhx)”}”(hŒÝAnother example: swap out interchange impl for a different
one with a different internal model: a schema of events for
task progress through the original interchange doesn't
necessarily work for some other implementation.”h]”hŒßAnother example: swap out interchange impl for a different
one with a different internal model: a schema of events for
task progress through the original interchange doesnâ€™t
necessarily work for some other implementation.”…””}”(hjà  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M_hjÁ  h&hubhx)”}”(hŒlZMQ generates log messages which have been useful sometimes
and these could be gatewayed into observability.”h]”hŒlZMQ generates log messages which have been useful sometimes
and these could be gatewayed into observability.”…””}”(hjî  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MdhjÁ  h&hubhx)”}”(hX½  Lots of different identifier spaces, loosely structured,
not necessarily hierarchical: for example, an htex task
is not necessarily "inside" a Parsl task, as htex can be
used outside of a Parsl DFK (which is where the notion of
Parsl task lives). An htex task often runs in a unix process
but that process also runs many htex tasks, and an htex task
also has extent outside of that worker process: there's no
containment relationship either way.”h]”hXÃ  Lots of different identifier spaces, loosely structured,
not necessarily hierarchical: for example, an htex task
is not necessarily â€œinsideâ€ a Parsl task, as htex can be
used outside of a Parsl DFK (which is where the notion of
Parsl task lives). An htex task often runs in a unix process
but that process also runs many htex tasks, and an htex task
also has extent outside of that worker process: thereâ€™s no
containment relationship either way.”…””}”(hjü  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MghjÁ  h&hubeh}”(h]”Œother-components”ah]”h]”Œother components”ah]”h!]”uh%h*hh,h&hh'h(h)MXubh+)”}”(hhh]”(h0)”}”(hŒ Optional pieces of observability”h]”hŒ Optional pieces of observability”…””}”(hj  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hj  h&hh'h(h)Mqubhx)”}”(hŒlog levels - INFO vs DEBUG”h]”hŒlog levels - INFO vs DEBUG”…””}”(hj#  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Mshj  h&hubhx)”}”(hŒOmissing log files - eg. start with parsl.log, add in more
files for more detail”h]”hŒOmissing log files - eg. start with parsl.log, add in more
files for more detail”…””}”(hj1  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Muhj  h&hubhx)”}”(hŒ‘security - not so much the Parsl core use case, but eg
GC executor vs GC endpoint logs vs GC central services have
different security properties.”h]”hŒ‘security - not so much the Parsl core use case, but eg
GC executor vs GC endpoint logs vs GC central services have
different security properties.”…””}”(hj?  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Mxhj  h&hubhx)”}”(hŒ³The observability approach needs to accomodate that, for
any/all reasons, some events won't be there. There can't be
a "complete set of events" to complain about being incomplete.”h]”hŒ»The observability approach needs to accomodate that, for
any/all reasons, some events wonâ€™t be there. There canâ€™t be
a â€œcomplete set of eventsâ€ to complain about being incomplete.”…””}”(hjM  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M|hj  h&hubhx)”}”(hŒuless data, well the reports in whatever form are less
informative, to the extent that the lack of data makes them
so.”h]”hŒuless data, well the reports in whatever form are less
informative, to the extent that the lack of data makes them
so.”…””}”(hj[  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M€hj  h&hubeh}”(h]”Œ optional-pieces-of-observability”ah]”h]”Œ optional pieces of observability”ah]”h!]”uh%h*hh,h&hh'h(h)Mqubh+)”}”(hhh]”(h0)”}”(hŒScope for other hacking”h]”hŒScope for other hacking”…””}”(hjt  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hjq  h&hh'h(h)M…ubhx)”}”(hŒ‰should be easy to add other events - the core observability
model shouldn't be prescriptive about what events exist,
what they look like.”h]”hŒ‹should be easy to add other events - the core observability
model shouldnâ€™t be prescriptive about what events exist,
what they look like.”…””}”(hj‚  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M‡hjq  h&hubhx)”}”(hŒ&should be easy to use them in analysis”h]”hŒ&should be easy to use them in analysis”…””}”(hj  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M‹hjq  h&hubhx)”}”(hŒDshould be easy to import some other event stream, in whatever
format”h]”hŒDshould be easy to import some other event stream, in whatever
format”…””}”(hjž  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Mhjq  h&hubhx)”}”(hX  notions of moving logs around to a place of analysis should
not be baked into the architecture. realtime options, file
based options, ... - that is an area for experimentation
(see Chronolog) and this work should facilitate that rather
than being prescriptive”h]”hX  notions of moving logs around to a place of analysis should
not be baked into the architecture. realtime options, file
based options, â€¦ - that is an area for experimentation
(see Chronolog) and this work should facilitate that rather
than being prescriptive”…””}”(hj¬  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Mhjq  h&hubhx)”}”(hŒ‡storage and query of logs is also an area for experimentation.
there are lots of hosted commercial services. lots of small
scale stuff:”h]”hŒ‡storage and query of logs is also an area for experimentation.
there are lots of hosted commercial services. lots of small
scale stuff:”…””}”(hjº  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M–hjq  h&hubhx)”}”(hX2  eg. at small enough scale, parsing logs into a
python session and using e.g. set and list comprehensions is
a legitimate way to analyse things (rather than something
awkwardly shameful that will be replaced by The Real Thing
later) - especially given Parsl users general exposure to
data science in Python.”h]”hX2  eg. at small enough scale, parsing logs into a
python session and using e.g. set and list comprehensions is
a legitimate way to analyse things (rather than something
awkwardly shameful that will be replaced by The Real Thing
later) - especially given Parsl users general exposure to
data science in Python.”…””}”(hjÈ  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Mšhjq  h&hubhx)”}”(hX  Ignore Parsl Monitoring per-task resource monitoring and
do something else that generates similar observability
records. This was always some disappointment with getting
WQ resource monitoring into the Parsl monitoring database:
what exists there that could be imported?”h]”hX  Ignore Parsl Monitoring per-task resource monitoring and
do something else that generates similar observability
records. This was always some disappointment with getting
WQ resource monitoring into the Parsl monitoring database:
what exists there that could be imported?”…””}”(hjÖ  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M¡hjq  h&hubhx)”}”(hŒçInside Python parts of Parsl, this data *is* available
in realtime at the point of logging as it goes to whatever
LogHandler is running in each python process. that isn't
true in general on the "event model" side of things, though.”h]”(hŒ(Inside Python parts of Parsl, this data ”…””}”(hjä  h&hh'Nh)NubjŽ  )”}”(hŒ*is*”h]”hŒis”…””}”(hjì  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%j  hjä  ubhŒÁ available
in realtime at the point of logging as it goes to whatever
LogHandler is running in each python process. that isnâ€™t
true in general on the â€œevent modelâ€ side of things, though.”…””}”(hjä  h&hh'Nh)Nubeh}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M§hjq  h&hubeh}”(h]”Œscope-for-other-hacking”ah]”h]”Œscope for other hacking”ah]”h!]”uh%h*hh,h&hh'h(h)M…ubh+)”}”(hhh]”(h0)”}”(hŒTarget audience”h]”hŒTarget audience”…””}”(hj  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hj  h&hh'h(h)M­ubhx)”}”(hŒ serious debugger/profiler people”h]”hŒ serious debugger/profiler people”…””}”(hj  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M¯hj  h&hubhx)”}”(hŒ|not management-dashboard types - although management
dashboards absolutely should be creatable with this
observability data.”h]”hŒ|not management-dashboard types - although management
dashboards absolutely should be creatable with this
observability data.”…””}”(hj+  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M±hj  h&hubeh}”(h]”Œtarget-audience”ah]”h]”Œtarget audience”ah]”h!]”uh%h*hh,h&hh'h(h)M­ubh+)”}”(hhh]”(h0)”}”(hŒBuild your own stack”h]”hŒBuild your own stack”…””}”(hjD  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hjA  h&hh'h(h)M¶ubhx)”}”(hX|  Lots of observability commentary online talks as if you are
building your entire stack, to the extent that you care about
observability. Parsl is much more a pile of configurable
components stuck together, all with their own different
options for observability/logging/monitoring, and without
easy ability for someone to add a consistent model throughout
the entire stack of code.”h]”hX|  Lots of observability commentary online talks as if you are
building your entire stack, to the extent that you care about
observability. Parsl is much more a pile of configurable
components stuck together, all with their own different
options for observability/logging/monitoring, and without
easy ability for someone to add a consistent model throughout
the entire stack of code.”…””}”(hjR  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M¸hjA  h&hubeh}”(h]”Œbuild-your-own-stack”ah]”h]”Œbuild your own stack”ah]”h!]”uh%h*hh,h&hh'h(h)M¶ubh+)”}”(hhh]”(h0)”}”(hŒAlgebra of merging logs”h]”hŒAlgebra of merging logs”…””}”(hjk  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hjh  h&hh'h(h)MÂubhx)”}”(hŒwidening”h]”hŒwidening”…””}”(hjy  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MÄhjh  h&hubhx)”}”(hŒjoining”h]”hŒjoining”…””}”(hj‡  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MÆhjh  h&hubhx)”}”(hŒ%post-facto relationship establishment”h]”hŒ%post-facto relationship establishment”…””}”(hj•  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MÈhjh  h&hubhx)”}”(hŒrelabelling”h]”hŒrelabelling”…””}”(hj£  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MÊhjh  h&hubhx)”}”(hŒ4look at relational algebra for phrasing and concepts”h]”hŒ4look at relational algebra for phrasing and concepts”…””}”(hj±  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MÌhjh  h&hubhx)”}”(hXÃ  notion of identity and key-sequences:
eg. parsl_dfk/parsl_task_id is a globally
unique identifier for a parsl task across time and space,
and so is parsl_dfk/executor_label/block_number or
parsl_dfk/executor_label/manager_id/worker_number
-- although manager ID is also (in short form) globally
unique.
this is distinct from the hierarchical relations between
entities - although hierarchical identity keys will often
line up with execution hierarchy.”h]”hXÄ  notion of identity and key-sequences:
eg. parsl_dfk/parsl_task_id is a globally
unique identifier for a parsl task across time and space,
and so is parsl_dfk/executor_label/block_number or
parsl_dfk/executor_label/manager_id/worker_number
â€“ although manager ID is also (in short form) globally
unique.
this is distinct from the hierarchical relations between
entities - although hierarchical identity keys will often
line up with execution hierarchy.”…””}”(hj¿  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MÎhjh  h&hubhx)”}”(hŒepeter buneman XML keys stuff did nested sequences of keys
for identifying xml fragments, c. year 2000”h]”hŒepeter buneman XML keys stuff did nested sequences of keys
for identifying xml fragments, c. year 2000”…””}”(hjÍ  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MÙhjh  h&hubeh}”(h]”Œalgebra-of-merging-logs”ah]”h]”Œalgebra of merging logs”ah]”h!]”uh%h*hh,h&hh'h(h)MÂubh+)”}”(hhh]”(h0)”}”(hŒWho wants this?”h]”hŒWho wants this?”…””}”(hjæ  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hjã  h&hh'h(h)MÝubhx)”}”(hŒAt least me.”h]”hŒAt least me.”…””}”(hjô  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Mßhjã  h&hubhx)”}”(hŒ³Many users don't come explicitly asking for monitoring-style
information but do ask how to understand whats going on
inside. And then are excited to use monitoring when it
exists.”h]”hŒµMany users donâ€™t come explicitly asking for monitoring-style
information but do ask how to understand whats going on
inside. And then are excited to use monitoring when it
exists.”…””}”(hj  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Máhjã  h&hubeh}”(h]”Œwho-wants-this”ah]”h]”Œwho wants this?”ah]”h!]”uh%h*hh,h&hh'h(h)MÝubh+)”}”(hhh]”(h0)”}”(hŒ
Browser UI”h]”hŒ
Browser UI”…””}”(hj  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hj  h&hh'h(h)Mèubhx)”}”(hŒ+what might a browser UI look like for this?”h]”hŒ+what might a browser UI look like for this?”…””}”(hj)  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Mêhj  h&hubhx)”}”(hŒ“compare parsl-visualize. compare scrolling through logs,
but with some more interactivity (eg. click / choose
"show me logs from same dfk/task_id")”h]”hŒ—compare parsl-visualize. compare scrolling through logs,
but with some more interactivity (eg. click / choose
â€œshow me logs from same dfk/task_idâ€)”…””}”(hj7  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Mìhj  h&hubeh}”(h]”Œ
browser-ui”ah]”h]”Œ
browser ui”ah]”h!]”uh%h*hh,h&hh'h(h)Mèubh+)”}”(hhh]”(h0)”}”(hŒ4Performance measurement of patch stack on 2025-10-27”h]”hŒ4Performance measurement of patch stack on 2025-10-27”…””}”(hjP  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hjM  h&hh'h(h)MòubjÌ  )”}”(hŒ_pip install -e . && parsl-perf --config parsl/tests/configs/htex_local.py --iterate=1,1,1,10000”h]”hŒ_pip install -e . && parsl-perf --config parsl/tests/configs/htex_local.py --iterate=1,1,1,10000”…””}”hj^  sbah}”(h]”h]”h]”h]”h!]”Œforce”‰Œhighlight_args”}”h#h$jÞ  Œdefault”uh%jË  h'h(h)MôhjM  h&hubhx)”}”(hŒSRunning parsl-perf with constant block sizes (to avoid
queue length speed changes):”h]”hŒSRunning parsl-perf with constant block sizes (to avoid
queue length speed changes):”…””}”(hjp  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MøhjM  h&hubhx)”}”(hŒAmaster branch (165fdc5bf663ab7fd0d3ea7c2d8d177b02d731c5) 1139 tps”h]”hŒAmaster branch (165fdc5bf663ab7fd0d3ea7c2d8d177b02d731c5) 1139 tps”…””}”(hj~  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MûhjM  h&hubhx)”}”(hŒmore-task-tied-logs: 1024”h]”hŒmore-task-tied-logs: 1024”…””}”(hjŒ  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MþhjM  h&hubh	Œdefinition_list”“”)”}”(hhh]”h	Œdefinition_list_item”“”)”}”(hŒLjson-wide-log-records: 537
- but without initializing the JSONHandler: 1122
”h]”(h	Œterm”“”)”}”(hŒjson-wide-log-records: 537”h]”hŒjson-wide-log-records: 537”…””}”(hj§  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%j¥  h'h(h)M hj¡  ubh	Œ
definition”“”)”}”(hhh]”hÖ)”}”(hhh]”hÛ)”}”(hŒ/but without initializing the JSONHandler: 1122
”h]”hx)”}”(hŒ.but without initializing the JSONHandler: 1122”h]”hŒ.but without initializing the JSONHandler: 1122”…””}”(hjÁ  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Mhj½  ubah}”(h]”h]”h]”h]”h!]”uh%hÚh'h(h)Mhjº  ubah}”(h]”h]”h]”h]”h!]”j  Œ-”uh%hÕh'h(h)Mhj·  ubah}”(h]”h]”h]”h]”h!]”uh%jµ  h'h(h)Mhj¡  ubeh}”(h]”h]”h]”h]”h!]”u•N8      h%jŸ  h'h(h)M hjœ  ubah}”(h]”h]”h]”h]”h!]”uh%jš  h'h(h)M hjM  h&hubhx)”}”(hŒ-end of branch with all changes up to now: 385”h]”hŒ-end of branch with all changes up to now: 385”…””}”(hjî  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MhjM  h&hubeh}”(h]”Œ4performance-measurement-of-patch-stack-on-2025-10-27”ah]”h]”Œ4performance measurement of patch stack on 2025-10-27”ah]”h!]”uh%h*hh,h&hh'h(h)Mòubh+)”}”(hhh]”(h0)”}”(hŒ"Applying this approach for academy”h]”hŒ"Applying this approach for academy”…””}”(hj	  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hj	  h&hh'h(h)Mubhx)”}”(hXŒ  As an extreme "data might not be there" -- perhaps Parsl
isn't there at all. What does this code and these techniques
look like applied to a similar but very different codebase,
Academy, which doesn't have any distributed monitoring at
all at the moment. There are ~100 log lines in the
academy codebase right now. How much can this be converted
in a few hours, and then analysed in similar ways?”h]”hX•  As an extreme â€œdata might not be thereâ€ â€“ perhaps Parsl
isnâ€™t there at all. What does this code and these techniques
look like applied to a similar but very different codebase,
Academy, which doesnâ€™t have any distributed monitoring at
all at the moment. There are ~100 log lines in the
academy codebase right now. How much can this be converted
in a few hours, and then analysed in similar ways?”…””}”(hj	  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M	hj	  h&hubhx)”}”(hŒ~The point here being both considering this as a real
logging direction for academy, and as a proof-of-generality
beyond Parsl.”h]”hŒ~The point here being both considering this as a real
logging direction for academy, and as a proof-of-generality
beyond Parsl.”…””}”(hj#	  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Mhj	  h&hubhx)”}”(hŒ	thoughts:”h]”hŒ	thoughts:”…””}”(hj1	  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Mhj	  h&hubhx)”}”(hX®  repr-of-ID-object might not be the correct format for logging:
I want stuff that is nice strings for values, but repr
(although it is a string) is more designed to look like a
python code fragment rather than the core value of an object.
Maybe ``str`` is better, and maybe some other way of
representing the ID is better? The point is to have values
that work well in aggregate, database style analysis, not
easy on the human eye.”h]”(hŒôrepr-of-ID-object might not be the correct format for logging:
I want stuff that is nice strings for values, but repr
(although it is a string) is more designed to look like a
python code fragment rather than the core value of an object.
Maybe ”…””}”(hj?	  h&hh'Nh)Nubj^  )”}”(hŒ``str``”h]”hŒstr”…””}”(hjG	  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%j]  hj?	  ubhŒ³ is better, and maybe some other way of
representing the ID is better? The point is to have values
that work well in aggregate, database style analysis, not
easy on the human eye.”…””}”(hj?	  h&hh'Nh)Nubeh}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Mhj	  h&hubhx)”}”(hŒ±academy logging so far focused on looking pretty on the
console: eg ANSI colour - that's at the opposite end of the
spectrum to what this observability project is trying to log.”h]”hŒ³academy logging so far focused on looking pretty on the
console: eg ANSI colour - thatâ€™s at the opposite end of the
spectrum to what this observability project is trying to log.”…””}”(hj_	  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M hj	  h&hubhx)”}”(hŒxrule of thumb for initial conversion: whatever is substituted
into the human message should be added as an extras field.”h]”hŒxrule of thumb for initial conversion: whatever is substituted
into the human message should be added as an extras field.”…””}”(hjm	  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M$hj	  h&hubhx)”}”(hŒuother components this might be applied to: Globus Compute.
Various related workflow systems that sit on top of Parsl.”h]”hŒuother components this might be applied to: Globus Compute.
Various related workflow systems that sit on top of Parsl.”…””}”(hj{	  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M'hj	  h&hubhx)”}”(hŒÆParsl contains two "mini-workflow-systems" on top of core
Parsl: parsl-perf and pytest tests. It could be interesting
to illustrate how those fit in without being a core part
of Parsl observability.”h]”hŒÊParsl contains two â€œmini-workflow-systemsâ€ on top of core
Parsl: parsl-perf and pytest tests. It could be interesting
to illustrate how those fit in without being a core part
of Parsl observability.”…””}”(hj‰	  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M*hj	  h&hubeh}”(h]”Œ"applying-this-approach-for-academy”ah]”h]”Œ"applying this approach for academy”ah]”h!]”uh%h*hh,h&hh'h(h)Mubh+)”}”(hhh]”(h0)”}”(hŒSee also”h]”hŒSee also”…””}”(hj¢	  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hjŸ	  h&hh'h(h)M0ubhx)”}”(hŒ	netlogger”h]”hŒ	netlogger”…””}”(hj°	  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M2hjŸ	  h&hubhx)”}”(hŒ·my dnpc work, an earlier iteration of this. more focused on human log parsing and so very fragile in the face of improving log messages, and not enough context in the human component.”h]”hŒ·my dnpc work, an earlier iteration of this. more focused on human log parsing and so very fragile in the face of improving log messages, and not enough context in the human component.”…””}”(hj¾	  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M4hjŸ	  h&hubhx)”}”(hŒ:chronolog https://grc.iit.edu/research/projects/chronolog/”h]”(hŒ
chronolog ”…””}”(hjÌ	  h&hh'Nh)Nubj6  )”}”(hŒ0https://grc.iit.edu/research/projects/chronolog/”h]”hŒ0https://grc.iit.edu/research/projects/chronolog/”…””}”(hjÔ	  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”Œrefuri”jÖ	  uh%j5  hjÌ	  ubeh}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M6hjŸ	  h&hubhx)”}”(hŒsyslog”h]”hŒsyslog”…””}”(hjé	  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M8hjŸ	  h&hubeh}”(h]”Œsee-also”ah]”h]”Œsee also”ah]”h!]”uh%h*hh,h&hh'h(h)M0ubh+)”}”(hhh]”(h0)”}”(hŒIn-parsl Python coding”h]”hŒIn-parsl Python coding”…””}”(hj
  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hjÿ	  h&hh'h(h)M;ubhx)”}”(hŒ[Acknowledging observability as a first-order feature means
we can make big changes to code.”h]”hŒ[Acknowledging observability as a first-order feature means
we can make big changes to code.”…””}”(hj
  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M=hjÿ	  h&hubhx)”}”(hX  Every log message needs to be visited to add context. In
many places a bunch of that context can be added by helpers:
for example, in my prototype, some module level loggers are
replaced by object-level loggers: there is a per-task
logger (actually LoggerAdapter) in the TaskRecord, and
logging to that automatically adds on relevant DFK and task
metadata: at most log sites, the change to add that metadata
is to switch from invoking methods on the module-level logger
object, invoking them on the new task-level logger instead.”h]”hX  Every log message needs to be visited to add context. In
many places a bunch of that context can be added by helpers:
for example, in my prototype, some module level loggers are
replaced by object-level loggers: there is a per-task
logger (actually LoggerAdapter) in the TaskRecord, and
logging to that automatically adds on relevant DFK and task
metadata: at most log sites, the change to add that metadata
is to switch from invoking methods on the module-level logger
object, invoking them on the new task-level logger instead.”…””}”(hj
  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M@hjÿ	  h&hubhx)”}”(hŒÏSome log lines bracket an operation, and to help with that,
my prototype introduces a LexicalSpan context manager which
can be used as part of a `with` block to identify the span
of work starting and ending.”h]”(hŒ‘Some log lines bracket an operation, and to help with that,
my prototype introduces a LexicalSpan context manager which
can be used as part of a ”…””}”(hj,
  h&hh'Nh)Nubj”  )”}”(hŒ`with`”h]”hŒwith”…””}”(hj4
  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%j“  hj,
  ubhŒ8 block to identify the span
of work starting and ending.”…””}”(hj,
  h&hh'Nh)Nubeh}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MJhjÿ	  h&hubhx)”}”(hŒõMove away from forming ad-hoc string templates and make
log calls look more machine-readable. This is somewhat
stylistic: with task ID automatically logged, there is no
need to substitute in task ID in some arbitrary subset of
task-related logs.”h]”hŒõMove away from forming ad-hoc string templates and make
log calls look more machine-readable. This is somewhat
stylistic: with task ID automatically logged, there is no
need to substitute in task ID in some arbitrary subset of
task-related logs.”…””}”(hjL
  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MOhjÿ	  h&hubeh}”(h]”Œin-parsl-python-coding”ah]”h]”Œin-parsl python coding”ah]”h!]”uh%h*hh,h&hh'h(h)M;ubh+)”}”(hhh]”(h0)”}”(hŒAcknowledgements”h]”hŒAcknowledgements”…””}”(hje
  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hjb
  h&hh'h(h)MVubhx)”}”(hŒchronolog: nishchay, inna”h]”hŒchronolog: nishchay, inna”…””}”(hjs
  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MXhjb
  h&hubhx)”}”(hŒ/desc: esp david adams, tom glanzman, jim chiang”h]”hŒ/desc: esp david adams, tom glanzman, jim chiang”…””}”(hj
  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MZhjb
  h&hubhx)”}”(hŒ	uiuc: ved”h]”hŒ	uiuc: ved”…””}”(hj
  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M\hjb
  h&hubhx)”}”(hŒ	gc: kevin”h]”hŒ	gc: kevin”…””}”(hj
  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M^hjb
  h&hubhx)”}”(hŒacademy: alok”h]”hŒacademy: alok”…””}”(hj«
  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)M`hjb
  h&hubeh}”(h]”Œacknowledgements”ah]”h]”Œacknowledgements”ah]”h!]”uh%h*hh,h&hh'h(h)MVubeh}”(h]”Œ/parsl-wide-event-observability-prototype-report”ah]”h]”Œ/parsl wide event observability prototype report”ah]”h!]”uh%h*hhh&hh'h(h)Kubh+)”}”(hhh]”(h0)”}”(hŒIndices and tables”h]”hŒIndices and tables”…””}”(hjÌ
  h&hh'Nh)Nubah}”(h]”h]”h]”h]”h!]”uh%h/hjÉ
  h&hh'h(h)McubhÖ)”}”(hhh]”(hÛ)”}”(hŒ:ref:`genindex`”h]”hx)”}”(hjß
  h]”h Œpending_xref”“”)”}”(hjß
  h]”h	Œinline”“”)”}”(hjß
  h]”hŒgenindex”…””}”(hjë
  h&hh'Nh)Nubah}”(h]”h]”(Œxref”Œstd”Œstd-ref”eh]”h]”h!]”uh%jé
  hjæ
  ubah}”(h]”h]”h]”h]”h!]”Œrefdoc”hOŒ	refdomain”jö
  Œreftype”Œref”Œrefexplicit”‰Œrefwarn”ˆŒ	reftarget”Œgenindex”uh%jä
  h'h(h)Mehjá
  ubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MehjÝ
  ubah}”(h]”h]”h]”h]”h!]”uh%hÚh'h(h)MehjÚ
  h&hubhÛ)”}”(hŒ:ref:`modindex`”h]”hx)”}”(hj  h]”jå
  )”}”(hj  h]”jê
  )”}”(hj  h]”hŒmodindex”…””}”(hj  h&hh'Nh)Nubah}”(h]”h]”(jõ
  Œstd”Œstd-ref”eh]”h]”h!]”uh%jé
  hj  ubah}”(h]”h]”h]”h]”h!]”Œrefdoc”hOŒ	refdomain”j)  Œreftype”Œref”Œrefexplicit”‰Œrefwarn”ˆj  Œmodindex”uh%jä
  h'h(h)Mfhj  ubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)Mfhj  ubah}”(h]”h]”h]”h]”h!]”uh%hÚh'h(h)MfhjÚ
  h&hubhÛ)”}”(hŒ:ref:`search`”h]”hx)”}”(hjI  h]”jå
  )”}”(hjI  h]”jê
  )”}”(hjI  h]”hŒsearch”…””}”(hjQ  h&hh'Nh)Nubah}”(h]”h]”(jõ
  Œstd”Œstd-ref”eh]”h]”h!]”uh%jé
  hjN  ubah}”(h]”h]”h]”h]”h!]”Œrefdoc”hOŒ	refdomain”j[  Œreftype”Œref”Œrefexplicit”‰Œrefwarn”ˆj  Œsearch”uh%jä
  h'h(h)MghjK  ubah}”(h]”h]”h]”h]”h!]”uh%hwh'h(h)MghjG  ubah}”(h]”h]”h]”h]”h!]”uh%hÚh'h(h)MghjÚ
  h&hubeh}”(h]”h]”h]”h]”h!]”j  j  uh%hÕh'h(h)MehjÉ
  h&hubeh}”(h]”Œindices-and-tables”ah]”h]”Œindices and tables”ah]”h!]”uh%h*hhh&hh'h(h)Mcubeh}”(h]”h]”h]”h]”h!]”Œsource”h(Œtranslation_progress”}”(Œtotal”K Œ
translated”K uuh%hŒcurrent_source”NŒcurrent_line”NŒsettings”Œdocutils.frontend”ŒValues”“”)”}”(Œoutput”Nh/NŒ	generator”NŒ	datestamp”NŒroot_prefix”Œ/”Œsource_link”NŒ
source_url”NŒtoc_backlinks”Œentry”Œfootnote_backlinks”ˆŒsectnum_xform”ˆŒstrip_comments”NŒstrip_elements_with_classes”NŒstrip_classes”NŒreport_level”KŒ
halt_level”KŒexit_status_level”KŒdebug”NŒwarning_stream”NŒ	traceback”ˆŒinput_encoding”Œ	utf-8-sig”Œinput_encoding_error_handler”Œstrict”Œoutput_encoding”Œutf-8”Œoutput_encoding_error_handler”j±  Œerror_encoding”Œutf-8”Œerror_encoding_error_handler”Œbackslashreplace”Œlanguage_code”Œen”Œrecord_dependencies”NŒconfig”NŒ	id_prefix”hŒauto_id_prefix”Œid”Œdump_settings”NŒdump_internals”NŒdump_transforms”NŒdump_pseudo_xml”NŒexpose_internals”NŒstrict_visitor”NŒ_disable_config”NŒ_source”h(Œ_destination”NŒ_config_files”]”Œfile_insertion_enabled”ˆŒraw_enabled”KŒline_length_limit”M'Œpep_references”NŒpep_base_url”Œhttps://peps.python.org/”Œpep_file_url_template”Œpep-%04d”Œrfc_references”NŒrfc_base_url”Œ&https://datatracker.ietf.org/doc/html/”Œ	tab_width”KŒtrim_footnote_reference_space”‰Œsyntax_highlight”Œlong”Œsmart_quotes”ˆŒsmartquotes_locales”]”Œcharacter_level_inline_markup”‰Œdoctitle_xform”‰Œdocinfo_xform”ˆŒsectsubtitle_xform”‰Œimage_loading”Œlink”Œembed_stylesheet”‰Œcloak_email_addresses”ˆŒsection_self_link”‰Œenv”NubŒreporter”NŒindirect_targets”]”Œsubstitution_defs”}”Œsubstitution_names”}”Œrefnames”}”Œrefids”}”Œnameids”}”(jÆ
  jÃ
  hŒh‰h³h°j  j  j  j|  jó  jð  j<  j9  j  jŠ  j´  j±  j¾  j»  j  j  jn  jk  j	  j  j>  j;  je  jb  jà  jÝ  j  j  jJ  jG  j	  jþ  jœ	  j™	  jü	  jù	  j_
  j\
  j¾
  j»
  j„  j  uŒ	nametypes”}”(jÆ
  ‰hŒ‰h³‰j  ‰j  ‰jó  ‰j<  ‰j  ‰j´  ‰j¾  ‰j  ‰jn  ‰j	  ‰j>  ‰je  ‰jà  ‰j  ‰jJ  ‰j	  ‰jœ	  ‰jü	  ‰j_
  ‰j¾
  ‰j„  ‰uh}”(jÃ
  h,h‰hfh°hj  h¶j|  j  jð  j‚  j9  jö  jŠ  j?  j±  j  j»  j·  j  jÁ  jk  j  j  jq  j;  j  jb  jA  jÝ  jh  j  jã  jG  j  jþ  jM  j™	  j	  jù	  jŸ	  j\
  jÿ	  j»
  jb
  j  jÉ
  uŒfootnote_refs”}”Œcitation_refs”}”Œautofootnotes”]”Œautofootnote_refs”]”Œsymbol_footnotes”]”Œsymbol_footnote_refs”]”Œ	footnotes”]”Œ	citations”]”Œautofootnote_start”KŒsymbol_footnote_start”K Œ
id_counter”Œcollections”ŒCounter”“”}”…”R”Œparse_messages”]”Œtransform_messages”]”Œtransformer”NŒinclude_log”]”Œ
decoration”Nh&hub.