Skip to Main Content
Forums

ORDS, SODA & JSON in the Database

Announcement

For appeals, questions and feedback about Oracle Forums, please email oracle-forums-moderators_us@oracle.com. Technical questions should be asked in the appropriate category. Thank you!

ORDS 18.3 on Tomcat 8.5: always chunked response from RESTful services?

RSa-DevMar 7 2019 — edited Mar 8 2019

My setup is APEX 18.2 + ORDS 18.3.0.

I tried to use APEX_WEB_SERVICE.make_rest_request on Oracle-provided sample of RESTful service, HR:

Here is my request:

GET http://127.0.0.1:8080/ords/{workspace}/hr/employees/7369 HTTP/1.1
Content-Length: 2
Connection: Close
Host: 127.0.0.1:8080

Response from ORDS in standalone mode is JSON string good for parsing by APEX_JSON.parse:

HTTP/1.1 200 OK
Connection: close
Date: Thu, 07 Mar 2019 07:10:13 GMT
Content-Type: application/json
ETag: "R4HKU3GUa8tAcm3DixE9lWoauhYpGJRGPMhvQIWDihlVUvRMnumFegkZ18F8m/gaeFxoR4hfmF9UeGfiuTOa7A=="
{"empno":7369,"ename":"SMITH","job":"CLERK","mgr":7902,"hiredate":"1980-12-16T21:00:00Z","sal":800,"comm":null,"deptno":20}

Responce from ORDS deployed on Tomcat 8.5 always have "Transfer-Encoding: chunked", even for tiny size of response bodies:

HTTP/1.1 200
ETag: "R4HKU3GUa8tAcm3DixE9lWoauhYpGJRGPMhvQIWDihlVUvRMnumFegkZ18F8m/gaeFxoR4hfmF9UeGfiuTOa7A=="
Content-Type: application/json
Transfer-Encoding: chunked
Date: Thu, 07 Mar 2019 06:31:44 GMT
7b
{"empno":7369,"ename":"SMITH","job":"CLERK","mgr":7902,"hiredate":"1980-12-16T21:00:00Z","sal":800,"comm":null,"deptno":20}
0

Tomcat works in default config - as installed. According Tomcat docs it should not use Chunked Encoding for small HTTP messages.

Maybe this is an ORDS issue?

Comments

Jonathan Lewis

Unfortunately the numbers look almost self-consistent - provided you assume a programmer made silly mistake:

  • "non-idle" CPU is (100 - 77.7)% = 22.3%  (Note that the sum of the 3 non-idle CPU values is NOT 22.3%)
  • 29.8 / 22.3 = 1.3363

It looks to me as if the 1.3363 is supposed to be the percentage of the total non-idle CPU that has been used by your instance - but the programmer has got the division upside down. For an intuitive understanding the number should have been 22.3 / 29.8 = 74.8%.

(I think the difference between 1.3362 and 1.338 can be explained by the fact that the aritimetic being done to far more decimal places than the 1 d.p. shown for the Host CPU reports.)

Regards

Jonathan Lewis

Franck Pachot

Hi,

Can you show the time model statistics ('DB CPU' and 'background cpu time') and Operating System Statistics (BUSY_TIME, IDLE_TIME and NUM_CPUS) from the same report? And the elapsed time of the report

I think the formulas are something like:

  %Total CPU = (instance CPU from Time Model) / (num cpu * elapsed time)

  %Busy CPU = (instance CPU from Time Model) / (OS non-idle time)

Thanks,

Franck.

Jonathan Lewis
Answer 
Franck Pachot wrote:

I think the formulas are something like:
 %Total CPU = (instance CPU from Time Model) / (num cpu * elapsed time) 
 %Busy CPU = (instance CPU from Time Model) / (OS non-idle time)

What it should be and what it seems to be can be two very different things.

I'm looking at a few AWR reports from a 12.1 system where

%Total CPU seems to be ("Total CPU time" from Time Model Statistics) / ("BUSY_TIME" + "IDLE_TIME" from Operating System Statistics)

and

%Busy CPU = ("Total CPU time" from Time Model Statistics) / "BUSY_TIME" from Operating System Statistics)

However, the Total CPU time is roughly 40%  greater than the BUSY_TIME (22,380 seconds vs. 15,893 seconds)! so the %Busy CPU is (quite correctly, for some value of "correct")  140.8%)

Picking just one report, though, I can see BUSY_TIME  + IDLE_TIME = 106,398, while elapsed time * CPU count = 114,416 so there's more than 8,000 seconds "lost" time.  (Naturally the confusion is compounded by the fact that it's 8 cores and 16 CPUs).

Regards

Jonathan Lewis

Marked as Answer by User_A7RKT · Jun 9 2019
1 person found this helpful
User_A7RKT

Elapsed time:

Snap IdSnap TimeSessionsCursors/Session
Begin Snap:88806-Jun-19 22:30:1156.9
End Snap:88906-Jun-19 23:00:1454.9
Elapsed:30.05 (mins)
DB Time:27.36 (mins)

Time Model Statistics

Statistic NameTime (s)% of DB Time% of Total CPU Time
DB CPU778.0347.3984.42
sql execute elapsed time667.4140.66
PL/SQL execution elapsed time264.2316.10
parse time elapsed10.950.67
repeated bind elapsed time0.460.03
hard parse elapsed time0.140.01
connection management call elapsed time0.070.00
PL/SQL compilation elapsed time0.030.00
sequence load elapsed time0.000.00
DB time1,641.63
background elapsed time950.95
background cpu time143.5915.58
total CPU time921.62

Operating System Statistics

StatisticValueEnd Value
FREE_MEMORY_BYTES39,464,96041,435,136
INACTIVE_MEMORY_BYTES1,314,881,5361,247,432,704
SWAP_FREE_BYTES5,960,953,8565,921,521,664
BUSY_TIME68,905
IDLE_TIME240,014
IOWAIT_TIME16,408
NICE_TIME0
SYS_TIME17,172
USER_TIME32,987

My observations:

DB CPU (778 seconds) is longer than the BUSY_TIME (68905/100= 689.05 seconds) which doesn't make sense

Jonathan proposed formulas applied in my report.

Cds MAX

Hi,
@Jonathan,
I applied your formulas and had:
%Total CPU seems to be ("Total CPU time" from Time Model Statistics 390.40) / ("BUSY_TIME" 87,174 + "IDLE_TIME" from Operating System Statistics 273,039 )=0.108
%Busy CPU = ("Total CPU time" from Time Model Statistics)390.40 / "BUSY_TIME" from Operating System Statistics 87174)=0.448
Here are excerpt of my AWR:
image.pngimage.pngimage.pngI have 100 times less for %Total CPU and %Busy CPU.
In Operating System Statistics table , are values in millseconds or in second?
Regards.

Jonathan Lewis

I have 100 times less for %Total CPU and %Busy CPU.
In Operating System Statistics table , are values in millseconds or in second?
Your observation suggests that for your version of Oracle on your operating system the OSS values are reported in hundredths of second.

1 - 6

Post Details

Added on Mar 7 2019
3 comments
580 views