Improved Debuggability for Couchbase's SQL++ User-Defined Functions
Explore two new features introduced in Couchbase 7.6 that provide visibility into the execution of SQL++ user-defined functions.
·
Join the DZone community and get the full member experience.
Join For FreeUser-defined functions (UDFs) are a very useful feature supported in SQL++ (UDF documentation). Couchbase 7.6 introduces improvements that allow for more debuggability and visibility into UDF execution.
This blog will explore two new features in Couchbase 7.6 in the world of UDFs:
- Profiling for SQL++ statements executed in JavaScript UDFs
EXPLAIN FUNCTIONto access query plans of SQL++ statements within UDFs
The examples in this blog require the travel-sample dataset to be installed.
Profiling SQL++ Executed in JavaScript UDFs
Query profiling is a debuggability feature that SQL++ offers.
When profiling is enabled for a statement’s execution, the result of the request includes a detailed execution tree with timing and metrics of each step of the statement’s execution. In addition to the profiling information being returned in the results of the statement, it can also be accessed for the request in the system:active_requests and system:completed_requests system keyspaces.
To dive deeper into request profiling, see request profiling in SQL++.
In Couchbase 7.0, profiling was included for subqueries. This included profiling subqueries that were within Inline UDFs. However, in versions before Couchbase 7.6, profiling was not extended to SQL++ statements within JavaScript UDFs.
In earlier versions, to profile statements within a JavaScript UDF, the user would be required to open up the function’s definition, individually run each statement within the UDF, and collect their profiles. This additional step will no longer be needed in 7.6.0!
Now, when profiling is enabled, if the statement contains JavaScript UDF execution, profiles for all SQL++ statements executed in the UDF will also be collected. This UDF-related profiling information will be available in the request output, system:active_requests and system:completed_requests system keyspaces as well.
Example 1
Create a JavaScript UDF “js1” in a global library “lib1” via the REST endpoint or via the UI.
JavaScriptfunction js1() { var query = SELECT * FROM default:`travel-sample`.inventory.airline LIMIT 1; var res = []; for (const row of query) { res.push(row); } query.close() return res; }Create the corresponding SQL++ function.
SQLCREATE FUNCTION js1() LANGUAGE JAVASCRIPT AS "js1" AT "lib1";Execute the UDF with profiling enabled.
SQLEXECUTE FUNCTION js1();
The response to the statement above will contain the following:
- In the
profilesection of the returned response, theexecutionTimingssubsection contains a field~udfStatements.~udfStatements: An array of profiling information that contains an entry for every SQL++ statement within the JavaScript UDF
Every entry within the ~udfStatements section contains:
executionTimings: This is the execution tree for the statement. It has metrics and timing information for every step of the statement’s execution.statement: The statement stringfunction: This is the name of the function where the statement was executed and is helpful to identify the UDF that executed the statement when there are nested UDF executions.
{
"requestID": "2c5576b5-f01d-445f-a35b-2213c606f394",
"signature": null,
"results": [
[
{
"airline": {
"callsign": "MILE-AIR",
"country": "United States",
"iata": "Q5",
"icao": "MLA",
"id": 10,
"name": "40-Mile Air",
"type": "airline"
}
}
]
],
"status": "success",
"metrics": {
"elapsedTime": "20.757583ms",
"executionTime": "20.636792ms",
"resultCount": 1,
"resultSize": 310,
"serviceLoad": 2
},
"profile": {
"phaseTimes": {
"authorize": "12.835µs",
"fetch": "374.667µs",
"instantiate": "27.75µs",
"parse": "251.708µs",
"plan": "9.125µs",
"primaryScan": "813.249µs",
"primaryScan.GSI": "813.249µs",
"project": "5.541µs",
"run": "27.925833ms",
"stream": "26.375µs"
},
"phaseCounts": {
"fetch": 1,
"primaryScan": 1,
"primaryScan.GSI": 1
},
"phaseOperators": {
"authorize": 2,
"fetch": 1,
"primaryScan": 1,
"primaryScan.GSI": 1,
"project": 1,
"stream": 1
},
"cpuTime": "468.626µs",
"requestTime": "2023-12-04T20:30:00.369+05:30",
"servicingHost": "127.0.0.1:8091",
"executionTimings": {
"#operator": "Authorize",
"#planPreparedTime": "2023-12-04T20:30:00.369+05:30",
"#stats": {
"#phaseSwitches": 4,
"execTime": "1.918µs",
"servTime": "1.125µs"
},
"privileges": {
"List": []
},
"~child": {
"#operator": "Sequence",
"#stats": {
"#phaseSwitches": 2,
"execTime": "2.208µs"
},
"~children": [
{
"#operator": "ExecuteFunction",
"#stats": {
"#itemsOut": 1,
"#phaseSwitches": 4,
"execTime": "22.375µs",
"kernTime": "20.271708ms"
},
"identity": {
"name": "js1",
"namespace": "default",
"type": "global"
}
},
{
"#operator": "Stream",
"#stats": {
"#itemsIn": 1,
"#itemsOut": 1,
"#phaseSwitches": 2,
"execTime": "26.375µs"
},
"serializable": true
}
]
},
"~udfStatements": [
{
"executionTimings": {
"#operator": "Authorize",
"#stats": {
"#phaseSwitches": 4,
"execTime": "2.626µs",
"servTime": "7.166µs"
},
"privileges": {
"List": [
{
"Priv": 7,
"Props": 0,
"Target": "default:travel-sample.inventory.airline"
}
]
},
"~child": {
"#operator": "Sequence",
"#stats": {
"#phaseSwitches": 2,
"execTime": "4.375µs"
},
"~children": [
{
"#operator": "PrimaryScan3",
"#stats": {
"#itemsIn": 1,
"#itemsOut": 1,
"#phaseSwitches": 7,
"execTime": "22.082µs",
"kernTime": "1.584µs",
"servTime": "791.167µs"
},
"bucket": "travel-sample",
"index": "def_inventory_airline_primary",
"index_projection": {
"primary_key": true
},
"keyspace": "airline",
"limit": "1",
"namespace": "default",
"optimizer_estimates": {
"cardinality": 187,
"cost": 45.28617059639748,
"fr_cost": 12.1780009122802,
"size": 12
},
"scope": "inventory",
"using": "gsi"
},
{
"#operator": "Fetch",
"#stats": {
"#itemsIn": 1,
"#itemsOut": 1,
"#phaseSwitches": 10,
"execTime": "18.376µs",
"kernTime": "797.542µs",
"servTime": "356.291µs"
},
"bucket": "travel-sample",
"keyspace": "airline",
"namespace": "default",
"optimizer_estimates": {
"cardinality": 187,
"cost": 192.01699202888378,
"fr_cost": 24.89848658838975,
"size": 204
},
"scope": "inventory"
},
{
"#operator": "InitialProject",
"#stats": {
"#itemsIn": 1,
"#itemsOut": 1,
"#phaseSwitches": 7,
"execTime": "5.541µs",
"kernTime": "1.1795ms"
},
"discard_original": true,
"optimizer_estimates": {
"cardinality": 187,
"cost": 194.6878862611588,
"fr_cost": 24.912769445246838,
"size": 204
},
"preserve_order": true,
"result_terms": [
{
"expr": "self",
"star": true
}
]
},
{
"#operator": "Limit",
"#stats": {
"#itemsIn": 1,
"#itemsOut": 1,
"#phaseSwitches": 4,
"execTime": "6.25µs",
"kernTime": "333ns"
},
"expr": "1",
"optimizer_estimates": {
"cardinality": 1,
"cost": 24.927052302103924,
"fr_cost": 24.927052302103924,
"size": 204
}
},
{
"#operator": "Receive",
"#stats": {
"#phaseSwitches": 3,
"execTime": "10.324833ms",
"kernTime": "792ns",
"state": "running"
}
}
]
}
},
"statement": "SELECT * FROM default:`travel-sample`.inventory.airline LIMIT 1;",
"function": "default:js1"
}
],
"~versions": [
"7.6.0-N1QL",
"7.6.0-1847-enterprise"
]
}
}
}
Query Plans With EXPLAIN FUNCTION
SQL++ offers another wonderful capability to access the plan of a statement with the EXPLAIN statement. However, the EXPLAIN statement does not extend to plans of statements within UDFs, neither inline nor JavaScript UDFs.
In earlier versions, to analyze the query plans for SQL++ within a UDF, it would require the user to open the function’s definition and individually run an EXPLAIN on all the statements within the UDF.
These extra steps will be minimized in Couchbase 7.6 with the introduction of a new statement: EXPLAIN FUNCTION. This statement does exactly what EXPLAIN does, but for SQL++ statements within a UDF.
Let’s explore how to use the EXPLAIN FUNCTION statement!
Syntax
explain_function ::= 'EXPLAIN' 'FUNCTION' function
function refers to the name of the function.
For more detailed information on syntax, please check out the documentation.
Prerequisites
To execute EXPLAIN FUNCTION, the user requires the correct RBAC permissions.
- To run
EXPLAIN FUNCTIONon a UDF, the user must have sufficient RBAC permissions to execute the function. - The user must also have the necessary RBAC permissions to execute the SQL++ statements within the UDF function body as well. For more information, refer to the documentation regarding roles supported in Couchbase.
Inline UDF
EXPLAIN FUNCTION on an inline UDF will return the query plans of all the subqueries within its definition (see inline function documentation).
Example 2: EXPLAIN FUNCTION on an Inline Function
Create an inline UDF and run EXPLAIN FUNCTION on it.
CREATE FUNCTION inline1() {
(
SELECT * FROM default:`travel-sample`.inventory.airport
WHERE city = "Zachar Bay"
)
};EXPLAIN FUNCTION inline1();The results of the above statement will contain:
function: The name of the function on whichEXPLAIN FUNCTIONwas runplans: An array of plan information that contains an entry for every subquery within the inline UDF
{
"function": "default:inline1",
"plans": [
{
"cardinality": 1.1176470588235294,
"cost": 25.117642854609013,
"plan": {
"#operator": "Sequence",
"~children": [
{
"#operator": "IndexScan3",
"bucket": "travel-sample",
"index": "def_inventory_airport_city",
"index_id": "2605c88c115dd3a2",
"index_projection": {
"primary_key": true
},
"keyspace": "airport",
"namespace": "default",
"optimizer_estimates": {
"cardinality": 1.1176470588235294,
"cost": 12.200561852726496,
"fr_cost": 12.179450078755286,
"size": 12
},
"scope": "inventory",
"spans": [
{
"exact": true,
"range": [
{
"high": "\\"Zachar Bay\\"",
"inclusion": 3,
"index_key": "`city`",
"low": "\\"Zachar Bay\\""
}
]
}
],
"using": "gsi"
},
{
"#operator": "Fetch",
"bucket": "travel-sample",
"keyspace": "airport",
"namespace": "default",
"optimizer_estimates": {
"cardinality": 1.1176470588235294,
"cost": 25.082370508382763,
"fr_cost": 24.96843677065826,
"size": 249
},
"scope": "inventory"
},
{
"#operator": "Parallel",
"~child": {
"#operator": "Sequence",
"~children": [
{
"#operator": "Filter",
"condition": "((`airport`.`city`) = \\"Zachar Bay\\")",
"optimizer_estimates": {
"cardinality": 1.1176470588235294,
"cost": 25.100006681495888,
"fr_cost": 24.98421650449632,
"size": 249
}
},
{
"#operator": "InitialProject",
"discard_original": true,
"optimizer_estimates": {
"cardinality": 1.1176470588235294,
"cost": 25.117642854609013,
"fr_cost": 24.99999623833438,
"size": 249
},
"result_terms": [
{
"expr": "self",
"star": true
}
]
}
]
}
}
]
},
"statement": "select self.* from `default`:`travel-sample`.`inventory`.`airport` where ((`airport`.`city`) = \\"Zachar Bay\\")"
}
]
}
JavaScript UDF
SQL++ statements within JavaScript UDFs can be of two types as listed below. EXPLAIN FUNCTION works differently based on the way the SQL++ statement is called.
Refer to the documentation to learn more about calling SQL++ in JavaScript functions.
1. Embedded SQL++
- Embedded SQL++ is “embedded” in the function body and its detection is handled by the JavaScript transpiler.
EXPLAIN FUNCTIONcan return query plans for embedded SQL++ statements.
2. SQL++ Executed by the N1QL() Function Call
- SQL++ can also be executed by passing a statement in the form of a string as an argument to the
N1QL()function. - When parsing the function for potential SQL++ statements to run the
EXPLAINon, it is difficult to get the dynamic string in the function argument. This can only be reliably resolved at runtime. - With this reasoning,
EXPLAIN FUNCTIONdoes not return the query plans for SQL++ statements executed viaN1QL()calls, but instead, returns the line numbers where theN1QL()function calls have been made. This line number is calculated from the beginning of the function definition. - The user can then map the line numbers in the actual function definition and investigate further.
Example 3: EXPLAIN FUNCTION on an External JavaScript Function
Create a JavaScript UDF “js2” in a global library “lib1” via the REST endpoint or via the UI.
JavaScriptfunction js2() { // SQL++ executed by a N1QL() function call var query1 = N1QL("UPDATE default:`travel-sample` SET test = 1 LIMIT 1"); // Embedded SQL++ var query2 = SELECT * FROM default:`travel-sample` LIMIT 1; var res = []; for (const row of query2) { res.push(row); } query2.close() return res; }Create the corresponding SQL++ function.
SQLCREATE FUNCTION js2() LANGUAGE JAVASCRIPT AS "js2" AT "lib1";Run
EXPLAIN FUNCTIONon the SQL++ function.SQLEXPLAIN FUNCTION js2;
The results of the statement above will contain:
function: The name of the function on whichEXPLAIN FUNCTIONwas runline_numbers: An array of line numbers calculated from the beginning of the JavaScript function definition where there areN1QL()function callsplans: An array of plan information that contains an entry for every embedded SQL++ statement within the JavaScript UDF
{
"function": "default:js2",
"line_numbers": [
4
],
"plans": [
{
"cardinality": 1,
"cost": 25.51560885530435,
"plan": {
"#operator": "Authorize",
"privileges": {
"List": [
{
"Target": "default:travel-sample",
"Priv": 7,
"Props": 0
}
]
},
"~child": {
"#operator": "Sequence",
"~children": [
{
"#operator": "Sequence",
"~children": [
{
"#operator": "Sequence",
"~children": [
{
"#operator": "PrimaryScan3",
"index": "def_primary",
"index_projection": {
"primary_key": true
},
"keyspace": "travel-sample",
"limit": "1",
"namespace": "default",
"optimizer_estimates": {
"cardinality": 31591,
"cost": 5402.279801258844,
"fr_cost": 12.170627071041082,
"size": 11
},
"using": "gsi"
},
{
"#operator": "Fetch",
"keyspace": "travel-sample",
"namespace": "default",
"optimizer_estimates": {
"cardinality": 31591,
"cost": 46269.39474997121,
"fr_cost": 25.46387878667884,
"size": 669
}
},
{
"#operator": "Parallel",
"~child": {
"#operator": "Sequence",
"~children": [
{
"#operator": "InitialProject",
"discard_original": true,
"optimizer_estimates": {
"cardinality": 31591,
"cost": 47086.49704894546,
"fr_cost": 25.489743820991595,
"size": 669
},
"preserve_order": true,
"result_terms": [
{
"expr": "self",
"star": true
}
]
}
]
}
}
]
},
{
"#operator": "Limit",
"expr": "1",
"optimizer_estimates": {
"cardinality": 1,
"cost": 25.51560885530435,
"fr_cost": 25.51560885530435,
"size": 669
}
}
]
},
{
"#operator": "Stream",
"optimizer_estimates": {
"cardinality": 1,
"cost": 25.51560885530435,
"fr_cost": 25.51560885530435,
"size": 669
},
"serializable": true
}
]
}
},
"statement": "SELECT * FROM default:`travel-sample` LIMIT 1 ;"
}
]
}
Constraints
If the
N1QL()function has been aliased in a JavaScript function definition,EXPLAIN FUNCTIONwill not be able to return the line numbers where this aliased function was called.Example of such a function definition:
JavaScriptfunction js3() { var alias = N1QL; var q = alias("SELECT 1"); }- If the UDF contains nested UDF executions,
EXPLAIN FUNCTIONdoes not support generating the query plans of SQL++ statements within these nested UDFs.
Summary
Couchbase 7.6 introduces new features to debug UDFs which will help users peek into UDF execution easily.
Helpful References
1. Javascript UDFs:
Opinions expressed by DZone contributors are their own.
Comments