Re: reads by KTSJ

From: Tanel Poder <tanel_at_tanelpoder.com>
Date: Wed, 13 May 2020 13:57:16 -0400
Message-ID: <CAMHX9JKz+3X+igsMiSFQeSj=-b63=4o-FUMZQ3DSKw6LT5SEgw_at_mail.gmail.com>



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_at_vontobel.com> wrote:

> Thank you, Jonathan.
>
>
>
> I randomly picked the following block:
>
>
>
> SQL> _at_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
>
>
>
>
>

--
http://www.freelists.org/webpage/oracle-l
Received on Wed May 13 2020 - 19:57:16 CEST

Original text of this message