How to match oracle.dbtools.common.logging.JDKLogSink.record identifier with an actual SQL

R Hachem

Hi

I'm not sure where to find this answer. ORDS 20.4 with APEX 21.1. I'm seeing a number of warnings in the catalina.out such as:

29-Aug-2021 03:40:11.181 WARNING [https-jsse-nio-8443-exec-4] oracle.dbtools.common.logging.JDKLogSink.record <Xt4HuSJqD2nUM61ACIlwzA>

** Request had db ELAPSED time of :8882ms **

29-Aug-2021 07:39:48.725 WARNING [https-jsse-nio-8443-exec-1] oracle.dbtools.common.logging.JDKLogSink.record <YPvd5TmkmpO4omDgNSw8ig>

** Request had db ELAPSED time of :5410ms **

How would I match up these identifiers (eg. Xt4HuSJqD2nUM61ACIlwzA) to an actual SQL statement?

Thanks!

thatJeffSmith-Oracle

'Xt4HuSJqD2nUM61ACIlwzA' is the ECID in v$session - so you can find it like so

select s.ECID , s.SID, s.ACTION, s.MODULE, s.TERMINAL, s.client_info, s.PLSQL_SUBPROGRAM_ID,s.PROGRAM,

( SELECT max( substr( sql_text , 1, 40 )) FROM v$sql sq WHERE sq.sql_id = s.sql_id ) AS sql_text

,   ( SELECT object_name  FROM dba_procedures WHERE object_id = plsql_entry_object_id AND subprogram_id = 0) AS plsql_entry_object

,   ( SELECT procedure_name FROM dba_procedures WHERE object_id = plsql_entry_object_id AND subprogram_id = plsql_entry_subprogram_id) AS plsql_entry_subprogram

,   ( SELECT object_name  FROM dba_procedures WHERE object_id = plsql_object_id    AND subprogram_id = 0) AS plsql_entry_object

,   ( SELECT procedure_name FROM dba_procedures WHERE object_id = plsql_object_id    AND subprogram_id = PLSQL_SUBPROGRAM_ID) AS plsql_entry_subprogram

from v$session s

where s.ecid = ‘Xt4HuSJqD2nUM61ACIlwzA’

R Hachem

Wow you know your stuff! Thank you. Exactly what I needed.

Ray

thatJeffSmith-Oracle

'Xt4HuSJqD2nUM61ACIlwzA' is the ECID in v$session - so you can find it like so

select s.ECID , s.SID, s.ACTION, s.MODULE, s.TERMINAL, s.client_info, s.PLSQL_SUBPROGRAM_ID,s.PROGRAM,

( SELECT max( substr( sql_text , 1, 40 )) FROM v$sql sq WHERE sq.sql_id = s.sql_id ) AS sql_text

,   ( SELECT object_name  FROM dba_procedures WHERE object_id = plsql_entry_object_id AND subprogram_id = 0) AS plsql_entry_object

,   ( SELECT procedure_name FROM dba_procedures WHERE object_id = plsql_entry_object_id AND subprogram_id = plsql_entry_subprogram_id) AS plsql_entry_subprogram

,   ( SELECT object_name  FROM dba_procedures WHERE object_id = plsql_object_id    AND subprogram_id = 0) AS plsql_entry_object

,   ( SELECT procedure_name FROM dba_procedures WHERE object_id = plsql_object_id    AND subprogram_id = PLSQL_SUBPROGRAM_ID) AS plsql_entry_subprogram

from v$session s

where s.ecid = ‘Xt4HuSJqD2nUM61ACIlwzA’

R Hachem

Ah ha. Thank you!

Follow on question. Since the ecid does not seem to persist very long in v$session, is there an easy way to also capture the sql_id from v$session by any chance? That would allow me to match up the slow sessions being reported in catalina.out with a particular sql statement. SQL statements will persist in the database's library cache even after the corresponding database session has moved on to doing something else.

Thanks

thatJeffSmith-Oracle

it would also be in awr/ash...assuming you're licensed for that

R Hachem

Wow you know your stuff! Thank you. Exactly what I needed.

Ray

thatJeffSmith-Oracle

Well, I'll pretend I didn't google ECID - after my dev told me what's what that string represented

R Hachem

😂

thatJeffSmith-Oracle

a bit more detail...

https://www.thatjeffsmith.com/archive/2021/08/how-to-debug-your-rest-apis-in-oracle-rest-data-services/

R Hachem

Yes and in my case, it is now very simple to go from something this like:

01-Sep-2021 11:21:22.502 WARNING [https-jsse-nio-8443-exec-38] oracle.dbtools.common.logging.JDKLogSink.record <WoIqqsD1Lvx-ODV02U46lQ> 

** Request had db ELAPSED time of :15590ms **

to finding out the sql_id:

select unique(sql_id) from v$active_session_history where ecid='WoIqqsD1Lvx-ODV02U46lQ';

SQL_ID

-------------

5ka5fbw5cvkuj

and then finding out the actual sql statement text:

set long 20000

select sql_fulltext from v$sql where sql_id='5ka5fbw5cvkuj';