Re: reads by KTSJ

  • From: Tanel Poder <tanel@xxxxxxxxxxxxxx>
  • To: Noveljic Nenad <nenad.noveljic@xxxxxxxxxxxx>
  • Date: Wed, 13 May 2020 13:57:16 -0400

Print some stack traces of these wait events and it will give you extra
clues.

From 12c onwards you can use something like this to target any wait event
by the W000 background process (and turn itself off after 100 occurrences
of waits, to avoid slowing waits down for too long). I've edited this to
fit on screen, you'll need to put it all on one line.

SQL> ALTER SYSTEM SET EVENTS 'wait_event[all]
          {process:pname = W000} {occurence:end_after 100}
          trace(''event="%" ela=% p1=% p2=% p3=%\nstack=%\n'',
                evargs(5), evargn(1), evargn(2), evargn(3), evargn(4),
shortstack())';

System altered.

The tracefile output is following:

*** 2020-05-13T13:54:12.432934-04:00
event="Space Manager: slave idle wait" ela=2997394 p1=0 p2=0 p3=0
*stack=*
ktsj_slave_main<-ksvrdp_int<-opirip<-opidrv<-sou2o<-opimai_real<-ssthrdmain<-main<-__libc_start_main

*** 2020-05-13T13:54:15.441721-04:00
event="Space Manager: slave idle wait" ela=2997442 p1=0 p2=0 p3=0
*stack=*
ktsj_slave_main<-ksvrdp_int<-opirip<-opidrv<-sou2o<-opimai_real<-ssthrdmain<-main<-__libc_start_main

*** 2020-05-13T13:54:18.449071-04:00
event="Space Manager: slave idle wait" ela=2996692 p1=0 p2=0 p3=0
*stack=k*
tsj_slave_main<-ksvrdp_int<-opirip<-opidrv<-sou2o<-opimai_real<-ssthrdmain<-main<-__libc_start_main

I've explained the syntax here:

https://tanelpoder.com/posts/what-caused-this-wait-event/

By the way, if you've not seen this in social media, I'm running a SQL
Monitoring "understanding the execution timeline column" hacking session
tomorrow May 14th at 12pm ET - over 800 people have signed up already and
my GotoWebinar account's max limit is 1000, so if you act quickly, you can
still sign up ;-)

https://tanelpoder.com/posts/hacking-session-oracle-sql-monitoring-timeline-column-and-cpu-usage/

Thanks,
Tanel.

On Wed, May 13, 2020 at 5:09 AM Noveljic Nenad <nenad.noveljic@xxxxxxxxxxxx>
wrote:

Thank you, Jonathan.



I randomly picked the following block:



SQL> @ashtop
program2,event2,p1,p1text,p2,p2text,p3,p3text,sql_id,top_level_sql_opcode
"program2 like '(W%' and event is not null" "to_date('2020-05-12
13:37:15')"  "to_date('2020-05-12 14:37:15')"




Total
                                                                              
                                                                              
                          Distinct

  Seconds     AAS %This   PROGRAM2
  EVENT2                                             P1
P1TEXT                                 P2
P2TEXT                                 P3 P3TEXT
SQL_ID        TOP_LEVEL_SQL_OPCODE FIRST_S       Execs Seen

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

        1      .0    0% | (WnnA)                                   db file
sequential read                            12
file#                              419748
block#                                  1
blocks                                                          0
2020-05:56:54          1



It belongs to a table segment:



select owner,segment_name,partition_name,segment_type from dba_extents
where file_id=12 and 419748 between block_id and block_id+blocks-1 ;



OWNER                          SEGMENT_NAME
         PARTITION_NAME                 SEGMENT_TYPE

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

XXXXXXXX
      XXXXXXXXXXXXXXXXXXXXXX
  TABLE





Below is the the symbolic dump.



Start dump data blocks tsn: 16 file#:12 minblk 419748 maxblk 419748

Block dump from cache:

Dump of buffer cache at level 3 for pdb=0 tsn=16 rdba=50751396

Block dump from disk:

buffer tsn: 16 rdba: 0x030667a4 (12/419748)

scn: 0x1211b61c3d seq: 0x01 flg: 0x04 tail: 0x1c3d0601

frmt: 0x02 chkval: 0x51a5 type: 0x06=trans data

Hex dump of block: st=0, typ_found=1



The block seems empty.



Best regards,



Nenad





Other related posts: