Page MenuHomePhabricator
Create Task
Maniphest T374397

[Z] function calls invoke execute() several times
Open, LowPublic
Actions

Description

What/Why:
While adding metrics instances to gather data on average function call performance from the Orchestrator, the metrics endpoint revealed there can be up to (or perhaps even more for other function calls we haven't tried) a dozen calls made per function call to execute(). Furthermore, the function gets called by several other ZObjects before the initial one is returned (see details in comments). We need to figure out if this is simply an err in the returned data (err with the new metrics logic added or how it is being used) or if this is a revelation of an unknown gnarly bug.

How:

  1. [Spike] figure out why this is occurring

Related Objects
Search...

Event Timeline

ecarg created this task.Sep 9 2024, 8:51 PM

Say I do WL function call from our (local) API SB:

{
	"Z1K1": "Z7",
	"Z7K1": {
		"Z1K1": "Z8",
		"Z8K1": [
			"Z17",
			{
				"Z1K1": "Z17",
				"Z17K1": "Z6",
				"Z17K2": {
					"Z1K1": "Z6",
					"Z6K1": "Z400K1"
				},
				"Z17K3": {
					"Z1K1": "Z12",
					"Z12K1": [
						"Z11"
					]
				}
			},
			{
				"Z1K1": "Z17",
				"Z17K1": "Z6",
				"Z17K2": {
					"Z1K1": "Z6",
					"Z6K1": "Z400K2"
				},
				"Z17K3": {
					"Z1K1": "Z12",
					"Z12K1": [
						"Z11"
					]
				}
			}
		],
		"Z8K2": "Z1",
		"Z8K3": [
			"Z20"
		],
		"Z8K4": [
			"Z14",
			{
				"Z1K1": "Z14",
				"Z14K1": "Z400",
				"Z14K3": {
					"Z1K1": "Z16",
					"Z16K1": "Z600",
					"Z16K2": "function Z400( Z400K1, Z400K2 ) { return (parseInt(Z400K1) + parseInt(Z400K2)).toString(); }"
				}
			}
		],
		"Z8K5": "Z400"
	},
	"Z400K1": "5",
	"Z400K2": "8"
}

This is the resulting metrics summary:

function_orchestrator_function_duration_seconds{quantile="0.1",service="function-orchestrator",Z7_function_identity="Z881",method="POST",requestId="7b63833db886512554bfe14e"} 1
function_orchestrator_function_duration_seconds{quantile="0.25",service="function-orchestrator",Z7_function_identity="Z881",method="POST",requestId="7b63833db886512554bfe14e"} 1
function_orchestrator_function_duration_seconds{quantile="0.5",service="function-orchestrator",Z7_function_identity="Z881",method="POST",requestId="7b63833db886512554bfe14e"} 2.5
function_orchestrator_function_duration_seconds{quantile="0.9",service="function-orchestrator",Z7_function_identity="Z881",method="POST",requestId="7b63833db886512554bfe14e"} 4
function_orchestrator_function_duration_seconds{quantile="0.95",service="function-orchestrator",Z7_function_identity="Z881",method="POST",requestId="7b63833db886512554bfe14e"} 4
function_orchestrator_function_duration_seconds{quantile="0.99",service="function-orchestrator",Z7_function_identity="Z881",method="POST",requestId="7b63833db886512554bfe14e"} 4
function_orchestrator_function_duration_seconds_sum{service="function-orchestrator",Z7_function_identity="Z881",method="POST",requestId="7b63833db886512554bfe14e"} 5
function_orchestrator_function_duration_seconds_count{service="function-orchestrator",Z7_function_identity="Z881",method="POST",requestId="7b63833db886512554bfe14e"} 2
function_orchestrator_function_duration_seconds{quantile="0.1",service="function-orchestrator",Z7_function_identity="Z108",method="POST",requestId="7b63833db886512554bfe14e"} 12
function_orchestrator_function_duration_seconds{quantile="0.25",service="function-orchestrator",Z7_function_identity="Z108",method="POST",requestId="7b63833db886512554bfe14e"} 12
function_orchestrator_function_duration_seconds{quantile="0.5",service="function-orchestrator",Z7_function_identity="Z108",method="POST",requestId="7b63833db886512554bfe14e"} 12
function_orchestrator_function_duration_seconds{quantile="0.9",service="function-orchestrator",Z7_function_identity="Z108",method="POST",requestId="7b63833db886512554bfe14e"} 12
function_orchestrator_function_duration_seconds{quantile="0.95",service="function-orchestrator",Z7_function_identity="Z108",method="POST",requestId="7b63833db886512554bfe14e"} 12
function_orchestrator_function_duration_seconds{quantile="0.99",service="function-orchestrator",Z7_function_identity="Z108",method="POST",requestId="7b63833db886512554bfe14e"} 12
function_orchestrator_function_duration_seconds_sum{service="function-orchestrator",Z7_function_identity="Z108",method="POST",requestId="7b63833db886512554bfe14e"} 12
function_orchestrator_function_duration_seconds_count{service="function-orchestrator",Z7_function_identity="Z108",method="POST",requestId="7b63833db886512554bfe14e"} 1
function_orchestrator_function_duration_seconds{quantile="0.1",service="function-orchestrator",Z7_function_identity="Z400",method="POST",requestId="7b63833db886512554bfe14e"} 167
function_orchestrator_function_duration_seconds{quantile="0.25",service="function-orchestrator",Z7_function_identity="Z400",method="POST",requestId="7b63833db886512554bfe14e"} 167
function_orchestrator_function_duration_seconds{quantile="0.5",service="function-orchestrator",Z7_function_identity="Z400",method="POST",requestId="7b63833db886512554bfe14e"} 167
function_orchestrator_function_duration_seconds{quantile="0.9",service="function-orchestrator",Z7_function_identity="Z400",method="POST",requestId="7b63833db886512554bfe14e"} 167
function_orchestrator_function_duration_seconds{quantile="0.95",service="function-orchestrator",Z7_function_identity="Z400",method="POST",requestId="7b63833db886512554bfe14e"} 167
function_orchestrator_function_duration_seconds{quantile="0.99",service="function-orchestrator",Z7_function_identity="Z400",method="POST",requestId="7b63833db886512554bfe14e"} 167
function_orchestrator_function_duration_seconds_sum{service="function-orchestrator",Z7_function_identity="Z400",method="POST",requestId="7b63833db886512554bfe14e"} 167
function_orchestrator_function_duration_seconds_count{service="function-orchestrator",Z7_function_identity="Z400",method="POST",requestId="7b63833db886512554bfe14e"} 1
ecarg updated the task description. (Show Details)Sep 9 2024, 8:53 PM
• Sharvaniharan triaged this task as Medium priority.Sep 18 2024, 4:39 PM
• Sharvaniharan added a project: Abstract Wikipedia Fix-It tasks.
• Sharvaniharan moved this task from To Triage to Backlog on the Abstract Wikipedia team board.
ecarg added a comment.Oct 3 2024, 7:34 PM

more notes during investigation:

  • many of the repeated calls seem to be validations made per call; maybe these should be paired with additional flag that denotes it is a merely a validation?
CodeReviewBot added a project: Patch-For-Review.Oct 3 2024, 7:48 PM

ecarg opened https://gitlab.wikimedia.org/repos/abstract-wiki/wikifunctions/function-orchestrator/-/merge_requests/239

Draft: function calls trigger execute() several times 🕵🏻‍♀️

ecarg added a comment.Oct 7 2024, 6:59 PM
function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS1 c9ae4b6a7248e5a8707ff2ad
function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS1 c9ae4b6a7248e5a8707ff2ad
function-orchestrator-1          | THOMAS3
function-orchestrator-1          | TOMMY0
function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS1 c9ae4b6a7248e5a8707ff2ad
function-orchestrator-1          | THOMAS3
function-orchestrator-1          | TOMMY0
function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS1 c9ae4b6a7248e5a8707ff2ad
function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS1 c9ae4b6a7248e5a8707ff2ad
function-orchestrator-1          | THOMAS3
function-orchestrator-1          | TOMMY0
function-orchestrator-1          | MAGGIE0 {
function-orchestrator-1          |     "Z1K1": {
function-orchestrator-1          |         "Z1K1": "Z9",
function-orchestrator-1          |         "Z9K1": "Z14"
function-orchestrator-1          |     },
function-orchestrator-1          |     "Z14K1": {
function-orchestrator-1          |         "Z1K1": "Z9",
function-orchestrator-1          |         "Z9K1": "Z108"
function-orchestrator-1          |     },
function-orchestrator-1          |     "Z14K4": {
function-orchestrator-1          |         "Z1K1": "Z6",
function-orchestrator-1          |         "Z6K1": "Z208"
function-orchestrator-1          |     }
function-orchestrator-1          | }
function-orchestrator-1          | MAGS1 Z208
function-orchestrator-1          | THOMAS3
function-orchestrator-1          | TOMMY0
function-orchestrator-1          | MAGGIE0 {
function-orchestrator-1          |     "Z1K1": {
function-orchestrator-1          |         "Z1K1": "Z9",
function-orchestrator-1          |         "Z9K1": "Z14"
function-orchestrator-1          |     },
function-orchestrator-1          |     "Z14K1": {
function-orchestrator-1          |         "Z1K1": "Z9",
function-orchestrator-1          |         "Z9K1": "Z811"
function-orchestrator-1          |     },
function-orchestrator-1          |     "Z14K4": {
function-orchestrator-1          |         "Z1K1": "Z6",
function-orchestrator-1          |         "Z6K1": "Z911"
function-orchestrator-1          |     }
function-orchestrator-1          | }
function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS1 c9ae4b6a7248e5a8707ff2ad
function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS1 c9ae4b6a7248e5a8707ff2ad
function-orchestrator-1          | THOMAS3
function-orchestrator-1          | TOMMY0
function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS1 c9ae4b6a7248e5a8707ff2ad
function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS1 c9ae4b6a7248e5a8707ff2ad
function-orchestrator-1          | THOMAS3
function-orchestrator-1          | TOMMY0
function-orchestrator-1          | MAGGIE0 {
function-orchestrator-1          |     "Z1K1": {
function-orchestrator-1          |         "Z1K1": "Z9",
function-orchestrator-1          |         "Z9K1": "Z14"
function-orchestrator-1          |     },
function-orchestrator-1          |     "Z14K1": {
function-orchestrator-1          |         "Z1K1": "Z9",
function-orchestrator-1          |         "Z9K1": "Z108"
function-orchestrator-1          |     },
function-orchestrator-1          |     "Z14K4": {
function-orchestrator-1          |         "Z1K1": "Z6",
function-orchestrator-1          |         "Z6K1": "Z208"
function-orchestrator-1          |     }
function-orchestrator-1          | }
function-orchestrator-1          | MAGS1 Z208
function-orchestrator-1          | THOMAS3
function-orchestrator-1          | TOMMY0
function-orchestrator-1          | MAGGIE0 {
function-orchestrator-1          |     "Z1K1": {
function-orchestrator-1          |         "Z1K1": "Z9",
function-orchestrator-1          |         "Z9K1": "Z14"
function-orchestrator-1          |     },
function-orchestrator-1          |     "Z14K1": {
function-orchestrator-1          |         "Z1K1": "Z9",
function-orchestrator-1          |         "Z9K1": "Z881"
function-orchestrator-1          |     },
function-orchestrator-1          |     "Z14K4": {
function-orchestrator-1          |         "Z1K1": "Z6",
function-orchestrator-1          |         "Z6K1": "Z981"
function-orchestrator-1          |     }
function-orchestrator-1          | }
function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS1 c9ae4b6a7248e5a8707ff2ad
function-orchestrator-1          | THOMAS3
function-orchestrator-1          | TOMMY0
function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS1 c9ae4b6a7248e5a8707ff2ad
function-orchestrator-1          | THOMAS3
function-orchestrator-1          | TOMMY0
function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS1 c9ae4b6a7248e5a8707ff2ad
function-orchestrator-1          | THOMAS3
function-orchestrator-1          | TOMMY0
function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS1 c9ae4b6a7248e5a8707ff2ad
function-orchestrator-1          | THOMAS3
function-orchestrator-1          | TOMMY0
function-orchestrator-1          | MAGS1 Z981
function-orchestrator-1          | THOMAS3
function-orchestrator-1          | TOMMY0
function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS1 c9ae4b6a7248e5a8707ff2ad
function-orchestrator-1          | THOMAS3
function-orchestrator-1          | TOMMY0
function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS1 c9ae4b6a7248e5a8707ff2ad
function-orchestrator-1          | THOMAS3
function-orchestrator-1          | TOMMY0
function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS1 c9ae4b6a7248e5a8707ff2ad
function-orchestrator-1          | THOMAS3
function-orchestrator-1          | TOMMY0
function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS1 c9ae4b6a7248e5a8707ff2ad
function-orchestrator-1          | THOMAS3
function-orchestrator-1          | TOMMY0
function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS1 c9ae4b6a7248e5a8707ff2ad
function-orchestrator-1          | THOMAS3
function-orchestrator-1          | TOMMY0
function-orchestrator-1          | MAGS1 Z911
function-orchestrator-1          | THOMAS2
function-orchestrator-1          | THOMAS3
function-orchestrator-1          | TOMMY0

THOMAS1 just shows reqId just wanted to check
MAGS1 is where that implamentation calls execute()
TOMMY0 is at the end of rateLimits.decrement() func

ecarg added a comment.Oct 7 2024, 6:59 PM

stacktrace per execute()

function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS0 Error
function-orchestrator-1          |     at execute (/srv/service/src/execute.js:1021:26)
function-orchestrator-1          |     at returnOnFirstError (/srv/service/src/utils.js:330:35)
function-orchestrator-1          |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
function-orchestrator-1          |     at async orchestrate (/srv/service/src/orchestrate.js:82:29)
function-orchestrator-1          |     at async /srv/service/routes/evaluate.js:137:20
function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS0 Error
function-orchestrator-1          |     at execute (/srv/service/src/execute.js:1021:26)
function-orchestrator-1          |     at ZWrapper.resolveInternal_ (/srv/service/src/ZWrapper.js:284:24)
function-orchestrator-1          |     at ZWrapper.resolveInternalHelper_ (/srv/service/src/ZWrapper.js:344:42)
function-orchestrator-1          |     at ZWrapper.resolveEphemeralInternal_ (/srv/service/src/ZWrapper.js:438:21)
function-orchestrator-1          |     at ZWrapper.resolveEphemeral (/srv/service/src/ZWrapper.js:542:24)
function-orchestrator-1          |     at ZWrapper.resolveInternal_ (/srv/service/src/ZWrapper.js:295:46)
function-orchestrator-1          |     at ZWrapper.resolveInternalHelper_ (/srv/service/src/ZWrapper.js:344:42)
function-orchestrator-1          |     at ZWrapper.resolveEphemeralInternal_ (/srv/service/src/ZWrapper.js:438:21)
function-orchestrator-1          |     at ZWrapper.resolveEphemeral (/srv/service/src/ZWrapper.js:542:24)
function-orchestrator-1          |     at resolveFunctionInternals (/srv/service/src/execute.js:478:44)
function-orchestrator-1          |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
function-orchestrator-1          |     at async executeInternal (/srv/service/src/execute.js:787:29)
function-orchestrator-1          |     at async execute (/srv/service/src/execute.js:1044:15)
function-orchestrator-1          |     at async returnOnFirstError (/srv/service/src/utils.js:330:29)
function-orchestrator-1          |     at async orchestrate (/srv/service/src/orchestrate.js:82:29)
function-orchestrator-1          |     at async /srv/service/routes/evaluate.js:137:20
function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS0 Error
function-orchestrator-1          |     at execute (/srv/service/src/execute.js:1021:26)
function-orchestrator-1          |     at ZWrapper.resolveInternal_ (/srv/service/src/ZWrapper.js:284:24)
function-orchestrator-1          |     at ZWrapper.resolveInternalHelper_ (/srv/service/src/ZWrapper.js:344:42)
function-orchestrator-1          |     at ZWrapper.resolveEphemeralInternal_ (/srv/service/src/ZWrapper.js:438:21)
function-orchestrator-1          |     at ZWrapper.resolveEphemeral (/srv/service/src/ZWrapper.js:542:24)
function-orchestrator-1          |     at /srv/service/src/execute.js:496:36
function-orchestrator-1          |     at traverseZList (/srv/service/src/utils.js:289:19)
function-orchestrator-1          |     at resolveFunctionInternals (/srv/service/src/execute.js:489:8)
function-orchestrator-1          |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
function-orchestrator-1          |     at async executeInternal (/srv/service/src/execute.js:787:29)
function-orchestrator-1          |     at async execute (/srv/service/src/execute.js:1044:15)
function-orchestrator-1          |     at async returnOnFirstError (/srv/service/src/utils.js:330:29)
function-orchestrator-1          |     at async orchestrate (/srv/service/src/orchestrate.js:82:29)
function-orchestrator-1          |     at async /srv/service/routes/evaluate.js:137:20
function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS0 Error
function-orchestrator-1          |     at execute (/srv/service/src/execute.js:1021:26)
function-orchestrator-1          |     at runValidationFunction (/srv/service/src/validation.js:44:15)
function-orchestrator-1          |     at runTypeValidatorDynamic (/srv/service/src/validation.js:75:16)
function-orchestrator-1          |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
function-orchestrator-1          |     at async runBuiltinTypeValidator (/srv/service/src/execute.js:528:10)
function-orchestrator-1          |     at async validateFunctionInternals (/srv/service/src/execute.js:531:35)
function-orchestrator-1          |     at async executeInternal (/srv/service/src/execute.js:794:30)
function-orchestrator-1          |     at async execute (/srv/service/src/execute.js:1044:15)
function-orchestrator-1          |     at async returnOnFirstError (/srv/service/src/utils.js:330:29)
function-orchestrator-1          |     at async orchestrate (/srv/service/src/orchestrate.js:82:29)
function-orchestrator-1          |     at async /srv/service/routes/evaluate.js:137:20
function-orchestrator-1          | THOMAS0
function-orchestrator-1          | THOMAS0 Error
function-orchestrator-1          |     at execute (/srv/service/src/execute.js:1021:26)
function-orchestrator-1          |     at ZWrapper.resolveInternal_ (/srv/service/src/ZWrapper.js:284:24)
function-orchestrator-1          |     at ZWrapper.resolveInternalHelper_ (/srv/service/src/ZWrapper.js:344:42)
function-orchestrator-1          |     at ZWrapper.resolveEphemeralInternal_ (/srv/service/src/ZWrapper.js:438:21)
function-orchestrator-1          |     at ZWrapper.resolveEphemeral (/srv/service/src/ZWrapper.js:542:24)
function-orchestrator-1          |     at ZWrapper.resolveInternal_ (/srv/service/src/ZWrapper.js:295:46)
function-orchestrator-1          |     at ZWrapper.resolveInternalHelper_ (/srv/service/src/ZWrapper.js:344:42)
function-orchestrator-1          |     at ZWrapper.resolveEphemeralInternal_ (/srv/service/src/ZWrapper.js:438:21)
function-orchestrator-1          |     at ZWrapper.resolveEphemeral (/srv/service/src/ZWrapper.js:542:24)
function-orchestrator-1          |     at resolveFunctionInternals (/srv/service/src/execute.js:478:44)
function-orchestrator-1          |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
function-orchestrator-1          |     at async executeInternal (/srv/service/src/execute.js:787:29)
function-orchestrator-1          |     at async execute (/srv/service/src/execute.js:1044:15)
function-orchestrator-1          |     at async runValidationFunction (/srv/service/src/validation.js:44:9)
function-orchestrator-1          |     at async runTypeValidatorDynamic (/srv/service/src/validation.js:75:10)
function-orchestrator-1          |     at async runBuiltinTypeValidator (/srv/service/src/execute.js:528:10)
...
ecarg lowered the priority of this task from Medium to Low.Nov 14 2024, 6:55 PM
Jdforrester-WMF moved this task from Backlog to Engineering Backlog on the Abstract Wikipedia team board.Nov 20 2024, 5:57 PM
Content licensed under Creative Commons Attribution-ShareAlike (CC BY-SA) 4.0 unless otherwise noted; code licensed under GNU General Public License (GPL) 2.0 or later and other open source licenses. By using this site, you agree to the Terms of Use, Privacy Policy, and Code of Conduct. · Wikimedia Foundation · Privacy Policy · Code of Conduct · Terms of Use · Disclaimer · CC-BY-SA · GPL · Credits