Enabling profile via rest api is not giving phaseTimes while fetching Active Requests via Rest Api

SQL++
1

Hi Everyone,
I have enabled profile in my CB server, profile is set to phases.
Executed this curl command :- curl --location --request POST 'http://localhost:8093/admin/settings' \ --header 'Content-Type: application/json' \ --header 'Authorization: Basic QWRtaW5pc3RyYXRvcjpwYXNzd29yZA==' \ --data-raw '{ "profile": "phases" }'

so the profile got update from off to phases now.

But when querying for active requests ie http://localhost:8093/admin/active_requests
I am getting the below mentioned output :-
[
{
“clientContextID”: “1a1d8828-b06a-46f3-a5fe-13a9841cee18”,
“elapsedTime”: “1.4613172s”,
“executionTime”: “1.4610895s”,
“phaseCounts”: {
“fetch”: 2304,
“primaryScan”: 2727
},
“phaseOperators”: {
“authorize”: 1,
“fetch”: 1,
“primaryScan”: 1
},
“requestId”: “6f44adea-9752-491d-936d-b36c7d450029”,
“requestTime”: “2020-08-27T21:11:28.344Z”,
“scanConsistency”: “unbounded”,
“state”: “running”,
“statement”: "SELECT * FROM beer-sample",
“users”: “Administrator”
}
]

Why the phaseTimes section is not coming in my case.

But if do the same via Couchbase query workbench i can see the phaseTimes section.
please help.

2

If profile is not off PhaseTimes are include in active, completed requests (see below). From 6.50+ these are included by default ever profile off MB-33538 cc @Marco_Greco

curl -u user:pass http://localhost:8093/admin/active_requests

This list all active requests. But will not give PhaseTimes. only single active request gives PhaseTimes via admin endpoint 

Example: curl -u user:pass -XPOST http://localhost:8093/admin/active_requests/<request-uuid>

Alternative for all active_requests is use query endpoint with select query as follows.

curl -u user:pass -v http://localhost:8093/query/service -H "Content-Type: application/json"  -d '{"statement":"SELECT a.* FROM system:active_requests AS a"}'
1 Like
3

The reason is mostly historical, but the active requests endpoint is used internally for the distributed implementation of the system:active_requests keyspace.
While for system:active_requests we always need to send the whole request information, including profiling (whether we produce profiling information is controlled by the setting of the request on the remote node), it was felt that the default information should be compact.
So, you get the phasetimes only on the individual request endpoint, and only if you use a POST request.
To be fair, I think there is scope to revisit this…

4

@vsr Thanks for the explanation, that really helped. But i have 1 query, if i call /query/service with the select statement for active_requests, then i get the select * from active_requests statement as well in the collection of active requests. Though in this case all the active requests contains phaseTimes… So is there any other way?

5

@Marco_Greco So in my application i am trying to monitor the requests on a node by calling /admin/active_requests on per second basis, so as to collect the useful stats on phase counts. But now i need the phasetimes as well.

The solution that @vsr1 suggested might work for me, only downside is in the list of active_requests i also get the “select * from active_requests” statement, which i think might affect in the performance of my logic to monitor, since i need to check on statement now, as i would not want to monitor the phase times for “select * from active_requests”

6

You can always use WHERE clause filter out information you are not required on any fields of active_requests.
SELECT a.* FROM system:active_requests AS a WHERE a.statement NOT LIKE “%system:active_requests%”

1 Like
7

Have logged MB-41206 to have phasetimes included in /admin/active_requests (& completed)
Will be in 7.0.0, but if you make your case to support, it’s an easy backport, and chances are that it could be approved for 6.6.1.

This said, as @vsr1 says, you can use a filter in the where clause to remove anything you don’t need.

8

@vsr1 thanks for your help, this should work.

@Marco_Greco how do i make the case to support? moreover my customer may not upgrade their CB instance so soon, so maybe this workaround for now should be good for me.

Also this SELECT a.* FROM system:active_requests AS a WHERE a.statement NOT LIKE “%system:active_requests%”, with /query/service should work across all the Couchbase version, mainly 5.0+ ?

9

Just open a support ticket and state that you need the fix in 6.6.1.
Re system:active_requests, it will fetch any request that matches your filters across all nodes starting from 5.0.
Note that distributed access is only available in EE. For CE, the monitoring keyspaces only access the local node.

10

@Marco_Greco @vsr1 last question :-
The following is the sample payload of a long running query :-
{
“requestID”: “d61df452-59d8-4748-b5a7-0a43663698b7”,
“signature”: {““:””},
“results”: [
{“elapsedTime”:“1m13.1492758s”,“executionTime”:“1m13.1488998s”,“node”:“127.0.0.1:8091”,“phaseCounts”:{“fetch”:50640,“primaryScan”:51106},“phaseOperators”:{“authorize”:1,“fetch”:1,“primaryScan”:1},“phaseTimes”:{“authorize”:“142.1µs”,“fetch”:“1m3.6066519s”,“instantiate”:“64.3µs”,“parse”:“994.8µs”,“plan”:“25.0633ms”,“primaryScan”:“20.4125409s”},“remoteAddr”:“172.17.0.1:41890”,“requestId”:“9594f2df-7359-462a-9ce0-1d3ca1898e0f”,“requestTime”:“2020-08-29T18:50:55.711Z”,“scanConsistency”:“unbounded”,“state”:“running”,“statement”:“SELECT * FROM travel-sample”,“userAgent”:“couchbase-java-client/2.5.9 (git: 2.5.9, core: 1.5.9) (Mac OS X/10.15.6 x86_64; Java HotSpot™ 64-Bit Server VM 1.8.0_171-b11)”,“users”:“Administrator”}
],
“status”: “success”,
“metrics”: {“elapsedTime”: “549.3386ms”,“executionTime”: “549.155ms”,“resultCount”: 1,“resultSize”: 730}
}

Question 1:- Why there are 2 set of elapsed time and execution time?
Question 2:- The sum of time taken in all the phases(1m32s+) is more than the elapsed time (1m3.14s), isn’t this weird?
Question 3 :- Do u have suggestion to parse the time string for individual phase times as some phases has m and s, some has s and some has microSecond, is there a way in which couchbase can convert internally all time to lets say milliseconds and give the results, I am asking this because i might have to do parse individual string to separtime time in minute and seconds before making use of the data if heterogeneous time format is given as output.

Thanks in advance

11

Q1. Inside results one are corresponding “statement”. Outside one is “SELECT * FROM system:active_requests”
Q2. Sum will not add up because there multiple threads can run in parallel.
Q3 STR_TO_DURATION(“1m13.1488998s”) gives in nano seconds

12

@vsr1 how do i apply this STR_TO_DURATION function while executing
SELECT a.* FROM system:active_requests AS a WHERE a.statement NOT LIKE “%system:active_requests%” ?

So that the phaseTimes are in homogenous format.

13

Elapsed time starts when the service receives the request, execution starts when the request starts executing.
When a service is loaded the request is queued, and there could be a significant difference between the two.
The operators run in parallel, so the phases are concurrent.
Re the times, MB-24001 is the relevant defect

14

Thanks @Marco_Greco for your reply.
Your answer helps for the first 2 questions. Thanks

The ticket MB-24001, related to elapsed time, but i meant if there is a way to get the phase times attributes as in the second or milli seconds format ?

15

MB-24001 is related to all times in the metrics, including phases and profiles, although initially was logged against elapsed time.
While STR_TO_DURATION would help you with the system keyspaces, there’s no other way to implement alternative formats for durations for the monitoring REST endpoints, which is what is of interesting to you.
MB-24001 would have been implemented quite some time ago if it wasn’t for some complicated architectural change that is required to implement it.

16 
SELECT a.*,
       STR_TO_DURATION(a.elapsedTime) AS elapsedTime,
       STR_TO_DURATION(a.executionTime) AS executionTime,
       OBJECT v.name:STR_TO_DURATION(v.val) FOR v IN OBJECT_PAIRS(a.phaseTimes) END AS phaseTimes
FROM system:active_requests AS a
WHERE a.statement NOT LIKE "%system:active_requests%"
17

@vsr1its perfect, thats what i wanted.
Thanks so much.

18

@vsr1 @Marco_Greco Can the following query to fetch execution times be optimised further as it has a significant performance impact, for some cases takes more than 1 second which impacts our application’s core features.
SELECT a.*,
STR_TO_DURATION(a.elapsedTime) AS elapsedTime,
STR_TO_DURATION(a.executionTime) AS executionTime,
OBJECT v.name:STR_TO_DURATION(v.val) FOR v IN OBJECT_PAIRS(a.phaseTimes) END AS phaseTimes
FROM system:active_requests AS a
WHERE a.statement NOT LIKE “%system:active_requests%”