Re: intermittent long "log file sync" waits
From: Chris Stephens <cstephens16_at_gmail.com>
Date: Thu, 30 Jan 2020 14:43:58 -0600
Message-ID: <CAEFL0syR4Xy2fPiL4M3jtmmfj_02MmYgC_haCM=LDZ17ikuGgg_at_mail.gmail.com>
Date: Thu, 30 Jan 2020 14:43:58 -0600
Message-ID: <CAEFL0syR4Xy2fPiL4M3jtmmfj_02MmYgC_haCM=LDZ17ikuGgg_at_mail.gmail.com>
Here's some additional ash output from the trace data posted in last message including event_hist.sql:
SQL> _at_ashtop username,event2,program2,blocking_session,blocking_inst_id 1=1
"TIMESTAMP'2020-01-29 13:04:20'" "TIMESTAMP'2020-01-29 13:04:27'"
TOTALSECONDS AAS %This USERNAME EVENT2
PROGRAM2 BLOCKING_SESSION BLOCKING_INST_ID FIRST_SEEN
LAST_SEEN DIST_SQLEXEC_SEEN
_______________ ______ __________ ________________ ________________
_____________ ___________________ ___________________
______________________ ______________________ ____________________
2 0.3 50% | SYS ON CPU
(sqlplus) 2020-01-29 13:04:24
2020-01-29 13:04:25 1
1 0.1 25% | GEN3_MGOWER_3 ON CPU
(python) 2020-01-29 13:04:22
2020-01-29 13:04:22 1
1 0.1 25% | GEN3_MGOWER_3 log file sync
(python) 1710 2 2020-01-29 13:04:20
2020-01-29 13:04:20 1
SQL> _at_bg lgwr
NAME DESCRIPTION SID OPID SPID PADDR
SADDR
_______ ______________ _______ _______ ________ ___________________
___________________
LGWR Redo etc. 1710 34 26552 00000001E8718860
00000001D8BFF4A0
SQL> _at_ashtop username,event2,program2,blocking_session,blocking_inst_id
session_id=1710 "TIMESTAMP'2020-01-29 13:04:20'" "TIMESTAMP'2020-01-29
13:04:27'"
no rows selected
SQL> _at_ashtop username,event2,program2,blocking_session,blocking_inst_id session_id=1710 "TIMESTAMP'2020-01-29 13:04:00'" "TIMESTAMP'2020-01-29 13:05:00'"
no rows selected
SQL> _at_ash/event_hist "log file" 1=1 "TIMESTAMP'2020-01-29 13:04:00'"
"TIMESTAMP'2020-01-29 13:05:00'"
EVH_EVENT EVH_MILLISEC EVH_SAMPLE_COUNT
EVH_EST_EVENT_COUNT EVH_EST_TOTAL_SEC PCT_EVT_TIME EVH_GRAPH
FIRST_SEEN LAST_SEEN
________________ __________________ ___________________
______________________ ____________________ _______________ _______________
______________________ ______________________
log file sync < 1024 1
1.8 1.8 12.8 |# | 2020-01-29
13:04:13 2020-01-29 13:04:13
log file sync < 4096 1
1 4.1 29.1 |### | 2020-01-29 13:04:12
2020-01-29 13:04:12
log file sync < 8192 1
1 8.2 58.2 |###### | 2020-01-29 13:04:20
2020-01-29 13:04:20
SQL> _at_ash/event_hist "write" 1=1 "TIMESTAMP'2020-01-29 13:04:00'"
"TIMESTAMP'2020-01-29 13:05:00'"
no rows selected
SQL> _at_ash/event_hist "*" 1=1 "TIMESTAMP'2020-01-29 13:04:00'"
"TIMESTAMP'2020-01-29 13:05:00'"
EVH_EVENT EVH_MILLISEC EVH_SAMPLE_COUNT
EVH_EST_EVENT_COUNT EVH_EST_TOTAL_SEC PCT_EVT_TIME EVH_GRAPH
FIRST_SEEN LAST_SEEN
_________________ __________________ ___________________
______________________ ____________________ _______________ _______________
______________________ ______________________
log file sync < 1024 1
1.8 1.8 12.8 |# | 2020-01-29
13:04:13 2020-01-29 13:04:13
log file sync < 4096 1
1 4.1 29.1 |### | 2020-01-29
13:04:12 2020-01-29 13:04:12
log file sync < 8192 1
1 8.2 58.2 |###### | 2020-01-29
13:04:20 2020-01-29 13:04:20
row cache lock < 1 1
2469.1 2.5 100 |##########| 2020-01-29
13:04:01 2020-01-29 13:04:01
SQL> _at_ashtop username,event2,program2,blocking_session,blocking_inst_id
"lower(program) like '%lg%'" "TIMESTAMP'2020-01-29 13:04:00'"
"TIMESTAMP'2020-01-29 13:05:00'"
no rows selected
i'm going to copy over gv$active_session_history to a single instance database and take a look at ash_wait_chains but i don't expect that to reveal anything either.
i need to confirm whether adding redo resolved issue (will have developer fire up workload) but I think next step is to investigate x$trace and possible process communication issues?
On Thu, Jan 30, 2020 at 10:27 AM Chris Stephens <cstephens16_at_gmail.com> wrote:
> Hey Tanel, > > Thanks for taking time to write this up! Will definitely be attending that > webinar. > > comments inline > > On Wed, Jan 29, 2020 at 10:32 PM Tanel Poder <tanel_at_tanelpoder.com> wrote: > >> Comments: >> >> 1) First, looks like you're using all the right tools for systematic >> troubleshooting ;-) >> > > ***i try! > >> >> 2) As "log file sync" is not directly an I/O wait event (IO happens >> indirectly under the hood), but "wait for LGWR to ACK/increment redo >> persisting position" then there may be multiple reasons for delays. I'm >> repeating some of what others have said here too: >> - LGWR could be waiting for remote ACK (synchronous data guard) - that >> should show up as a LNS* wait or something like that though >> - Process slowness due to CPU overload/scheduling latency or swapping >> (in both cases, LGWR may do its work fast, but it takes a while for the >> foreground process to wake up and end the wait event - you could check if >> there are any reports regarding switching LGWR mode in alert.log around >> that time) >> - Bug/missed post due to switching between LGWR progress polling vs. >> waiting for LGWR post >> - ASM instance communication issues (ASM communication can be on the >> critical path when creating/changing files on ASM and even for reading, >> when the ASM metadata cache in your local instance doesn't have what it >> needs) >> - So, the physical redo log file disk write is not necessarily the >> biggest contributor to the log file sync wait >> >> *** no data guard in the env. > *** we have excess CPU. (20 cores / instance and usually only 1-5 active > foreground processes but i will confirm from TFA collections) > *** yesterday i was ready to blame bug. today, not so sure. i checked log > file switches with a script google found me a few days ago. now thinking > that was inaccurate as a script from metastink shows tones of switching so > that could very well be related. > ***asm communication is something i need to look into. TFA has reported > some ASM issues but there's no details and i never saw anything in asm > alert logs indicating an issue. > > >> 3) You'll need to measure what LGWR itself was doing during the problem >> time >> - Since you're on 19c (12c or later) the LGWR has slaves too and they >> may be doing most of the work >> - You'll need to look into both the LGWR process and any other LG* ones >> too >> - Since you have (Oracle) Snapper running already and writing to trace >> you should have the data already >> - The *lgwr* in the following _at_snapper ash,stats,trace 10 999999 lgwr >> syntax includes LGWR slaves too >> - As LGWR slaves have their own sessions (and SIDs), you should run >> ashtop etc and report if there's any BLOCKING_SESSION value listed for LGWR >> and slaves >> - If LGWR and the slaves were listed *idle* during the problem time >> (while others waited for log file sync event at the same time) *and if *there >> was no huge OS level CPU/memory shortage at the time, this looks like a >> background <-> foreground communication problem. >> - This (and any potential ASM issues) could probably be >> troubleshooted via KST tracing, KSR channels and X$TRACE that could help >> here (some of it is enabled by default ( Like I showed in a previous >> hacking session: https://www.youtube.com/watch?v=mkmvZv58W6w ) >> >> > here is all the output i have corresponding to a 6 sec "log file sync" > wait: > > Experience duration: *R* = *t*1 − *t*0 = 41.336137 seconds > <#m_-5509691095923674063_profile-by-subroutine> > Experience begin time: *t*0 = 2020-01-29T13:04:07.560478 > Experience end time: *t*1 = 2020-01-29T13:04:48.896615 > CALL-NAME DURATION % CALLS MEAN > MIN MAX > ------------------------------ --------- ------ ------ -------- > -------- -------- > SQL*Net message from client 26.017105 66.5% 9,886 0.002632 > 0.000209 7.858051 > log file sync 10.582409 27.1% 150 0.070549 > 0.000295 6.909711 > EXEC 2.088757 5.3% 9,702 0.000215 > 0.000000 0.209199 > DLM cross inst call completion 0.109617 0.3% 212 0.000517 > 0.000005 0.080575 > row cache lock 0.070118 0.2% 125 0.000561 > 0.000208 0.000972 > FETCH 0.047586 0.1% 1,029 0.000046 > 0.000000 0.003056 > PARSE 0.045293 0.1% 4,778 0.000009 > 0.000000 0.002692 > CLOSE 0.033453 0.1% 4,784 0.000007 > 0.000000 0.000237 > library cache lock 0.023614 0.1% 55 0.000429 > 0.000152 0.000901 > library cache pin 0.022311 0.1% 55 0.000406 > 0.000153 0.000689 > 17 others 0.071430 0.2% 10,772 0.000007 > 0.000000 0.001487 > ------------------------------ --------- ------ ------ -------- > -------- -------- > TOTAL (27) 39.111693 100.0% 41,548 0.000941 > 0.000000 7.858051 > > 6 sec wait from raw data: > > *** 2020-01-29T13:04:20.724666-06:00 > WAIT #0: nam='log file sync' ela= 6909711 buffer#=58996 sync scn=976089279 > p3=0 obj#=-1 tim=1025228531958 > WAIT #0: nam='SQL*Net message to client' ela= 2 driver id=1413697536 > #bytes=1 p3=0 obj#=-1 tim=1025228532118 > WAIT #0: nam='SQL*Net message from client' ela= 1711 driver id=1413697536 > #bytes=1 p3=0 obj#=-1 tim=1025228533852 > BINDS #140204587734864: > > i enabled 10046 on lgwr: > > *** 2020-01-29T13:04:20.725994-06:00 > WAIT #0: nam='rdbms ipc message' ela= 2918443 timeout=300 p2=0 p3=0 > obj#=-1 tim=1025228533313 > WAIT #0: nam='log file parallel write' ela= 279 files=1 blocks=17 > requests=2 obj#=-1 tim=1025228533777 > WAIT #0: nam='log file parallel write' ela= 171 files=1 blocks=3 > requests=2 obj#=-1 tim=1025228534104 > WAIT #0: nam='LGWR wait for redo copy' ela= 22 copy latch #=28 p2=0 p3=0 > obj#=-1 tim=1025228534182 > WAIT #0: nam='log file parallel write' ela= 183 files=1 blocks=2 > requests=2 obj#=-1 tim=1025228534437 > WAIT #0: nam='log file parallel write' ela= 174 files=1 blocks=2 > requests=2 obj#=-1 tim=1025228534721 > WAIT #0: nam='rdbms ipc message' ela= 31 timeout=8 p2=0 p3=0 obj#=-1 > tim=1025228534786 > WAIT #0: nam='rdbms ipc message' ela= 3233 timeout=8 p2=0 p3=0 obj#=-1 > tim=1025228538038 > WAIT #0: nam='log file parallel write' ela= 170 files=1 blocks=2 > requests=1 obj#=-1 tim=1025228538297 > WAIT #0: nam='rdbms ipc message' ela= 25 timeout=8 p2=0 p3=0 obj#=-1 > tim=1025228538358 > WAIT #0: nam='rdbms ipc message' ela= 11829 timeout=8 p2=0 p3=0 obj#=-1 > tim=1025228550204 > WAIT #0: nam='LGWR wait for redo copy' ela= 52 copy latch #=8 p2=0 p3=0 > obj#=-1 tim=1025228550294 > WAIT #0: nam='log file parallel write' ela= 239 files=1 blocks=7 > requests=1 obj#=-1 tim=1025228550624 > WAIT #0: nam='rdbms ipc message' ela= 23 timeout=6 p2=0 p3=0 obj#=-1 > tim=1025228550699 > WAIT #0: nam='rdbms ipc message' ela= 16750 timeout=6 p2=0 p3=0 obj#=-1 > tim=1025228567467 > WAIT #0: nam='log file parallel write' ela= 207 files=1 blocks=9 > requests=1 obj#=-1 tim=1025228567762 > WAIT #0: nam='rdbms ipc message' ela= 26 timeout=5 p2=0 p3=0 obj#=-1 > tim=1025228567825 > WAIT #0: nam='rdbms ipc message' ela= 16249 timeout=5 p2=0 p3=0 obj#=-1 > tim=1025228584091 > WAIT #0: nam='log file parallel write' ela= 213 files=1 blocks=9 > requests=1 obj#=-1 tim=1025228584400 > WAIT #0: nam='rdbms ipc message' ela= 48 timeout=3 p2=0 p3=0 obj#=-1 > tim=1025228584502 > WAIT #0: nam='rdbms ipc message' ela= 16466 timeout=3 p2=0 p3=0 obj#=-1 > tim=1025228600993 > WAIT #0: nam='log file parallel write' ela= 228 files=1 blocks=9 > requests=1 obj#=-1 tim=1025228601393 > WAIT #0: nam='rdbms ipc message' ela= 29 timeout=1 p2=0 p3=0 obj#=-1 > tim=1025228601482 > WAIT #0: nam='rdbms ipc message' ela= 9548 timeout=1 p2=0 p3=0 obj#=-1 > tim=1025228611053 > WAIT #0: nam='rdbms ipc message' ela= 7467 timeout=300 p2=0 p3=0 obj#=-1 > tim=1025228618574 > WAIT #0: nam='LGWR wait for redo copy' ela= 13 copy latch #=8 p2=0 p3=0 > obj#=-1 tim=1025228618636 > WAIT #0: nam='log file parallel write' ela= 222 files=1 blocks=9 > requests=1 obj#=-1 tim=1025228618960 > WAIT #0: nam='rdbms ipc message' ela= 31 timeout=300 p2=0 p3=0 obj#=-1 > tim=1025228619066 > WAIT #0: nam='rdbms ipc message' ela= 15946 timeout=300 p2=0 p3=0 obj#=-1 > tim=1025228635045 > WAIT #0: nam='log file parallel write' ela= 240 files=1 blocks=9 > requests=1 obj#=-1 tim=1025228635427 > WAIT #0: nam='rdbms ipc message' ela= 33 timeout=298 p2=0 p3=0 obj#=-1 > tim=1025228635525 > WAIT #0: nam='rdbms ipc message' ela= 15987 timeout=298 p2=0 p3=0 obj#=-1 > tim=1025228651537 > WAIT #0: nam='log file parallel write' ela= 255 files=1 blocks=9 > requests=1 obj#=-1 tim=1025228651912 > WAIT #0: nam='rdbms ipc message' ela= 51 timeout=296 p2=0 p3=0 obj#=-1 > tim=1025228652034 > WAIT #0: nam='rdbms ipc message' ela= 16332 timeout=296 p2=0 p3=0 obj#=-1 > tim=1025228668405 > WAIT #0: nam='log file parallel write' ela= 256 files=1 blocks=9 > requests=1 obj#=-1 tim=1025228668804 > WAIT #0: nam='rdbms ipc message' ela= 37 timeout=295 p2=0 p3=0 obj#=-1 > tim=1025228668911 > WAIT #0: nam='rdbms ipc message' ela= 16969 timeout=295 p2=0 p3=0 obj#=-1 > tim=1025228685907 > WAIT #0: nam='log file parallel write' ela= 273 files=1 blocks=9 > requests=1 obj#=-1 tim=1025228686327 > WAIT #0: nam='rdbms ipc message' ela= 38 timeout=293 p2=0 p3=0 obj#=-1 > tim=1025228686453 > WAIT #0: nam='rdbms ipc message' ela= 6908 timeout=293 p2=0 p3=0 obj#=-1 > tim=1025228693390 > WAIT #0: nam='log file parallel write' ela= 247 files=1 blocks=2 > requests=1 obj#=-1 tim=1025228693768 > WAIT #0: nam='rdbms ipc message' ela= 38 timeout=292 p2=0 p3=0 obj#=-1 > tim=1025228693862j > ...more of the same > 264396 WAIT #0: nam='rdbms ipc message' ela= 32 timeout=52 p2=0 p3=0 > obj#=-1 tim=1025231090742 > 264397 WAIT #0: nam='rdbms ipc message' ela= 19460 timeout=52 p2=0 p3=0 > obj#=-1 tim=1025231110227 > 264398 WAIT #0: nam='log file parallel write' ela= 272 files=1 blocks=9 > requests=1 obj#=-1 tim=1025231110633 > 264399 WAIT #0: nam='rdbms ipc message' ela= 37 timeout=50 p2=0 p3=0 > obj#=-1 tim=1025231110748 > 264400 WAIT #0: nam='rdbms ipc message' ela= 15484 timeout=50 p2=0 p3=0 > obj#=-1 tim=1025231126261 > 264401 WAIT #0: nam='log file parallel write' ela= 247 files=1 blocks=4 > requests=1 obj#=-1 tim=1025231126641 > 264402 WAIT #0: nam='rdbms ipc message' ela= 36 timeout=49 p2=0 p3=0 > obj#=-1 tim=1025231126753 > 264403 WAIT #0: nam='rdbms ipc message' ela= 16732 timeout=49 p2=0 p3=0 > obj#=-1 tim=1025231143514 > 264404 WAIT #0: nam='LGWR wait for redo copy' ela= 31 copy latch #=8 p2=0 > p3=0 obj#=-1 tim=1025231143603 > 264405 WAIT #0: nam='log file parallel write' ela= 279 files=1 blocks=9 > requests=1 obj#=-1 tim=1025231143976 > 264406 WAIT #0: nam='rdbms ipc message' ela= 35 timeout=47 p2=0 p3=0 > obj#=-1 tim=1025231144093 > 264407 WAIT #0: nam='rdbms ipc message' ela= 5384 timeout=47 p2=0 p3=0 > obj#=-1 tim=1025231149515 > 264408 WAIT #0: nam='log file parallel write' ela= 255 files=1 blocks=4 > requests=1 obj#=-1 tim=1025231149889 > 264409 WAIT #0: nam='rdbms ipc message' ela= 32 timeout=47 p2=0 p3=0 > obj#=-1 tim=1025231149989 > 264410 > 264411 *** 2020-01-29T13:04:23.802774-06:00 > 264412 WAIT #0: nam='rdbms ipc message' ela= 460056 timeout=46 p2=0 p3=0 > obj#=-1 tim=1025231610086 > 264413 > 264414 *** 2020-01-29T13:04:26.797925-06:00 > 264415 WAIT #0: nam='rdbms ipc message' ela= 2995027 timeout=300 p2=0 > p3=0 obj#=-1 tim=1025234605238 > 264416 WAIT #0: nam='rdbms ipc message' ela= 10649 timeout=1 p2=0 p3=0 > obj#=-1 tim=1025234616054 > 264417 > > i will get you snapper lgwr output associated w/ this interval as soon as > i can find it (can't remember where i stashed it and lost trace file name > .. fml) > > 4) Paste the full *Snapper* output (of one time snapshot from the problem >> time) here if you can - we'll be able to see what the slaves were doing >> - You'd need to include not only LGWR SID but also any LG* slave SIDs >> too >> - Also we'll see better LGWR delay metrics from V$SESSTAT that go >> beyond just wait events >> - Thinking of metrics like these - snapper already handles them (if you >> look into the rightmost column) >> - *redo synch time overhead (usec)* - "FG wakeup overhead per log >> file sync" >> - *redo write time* - accounting end to end redo write time (not >> just the log file parallel write syscall) "per redo write" >> >> 5) Regarding the *ASH wait chains* error on 19c - I'm aware of this but >> forgot to look into it >> - It has (probably) something to do with GV$ views (or PX slaves used >> for PDB V$ queries) and possibly the connect by I'm using >> - Does it work in the CDB (if multitenant)? >> - Does it work with lower optimizer features enabled? >> - As we are already manually looking into what LGWR and its slaves are >> doing, there's no need for the wait chains script here >> >> ***oracle has filed a bug. altering optimizer_features_enabled doesn't > help. > > >> 6) Linux Process Snapper - pSnapper >> - If you want to see the full "wait" states of Linux >> processes/threads, use the* -a *option. >> - It's somewhat like always showing "idle" threads too >> - But for linux apps it's harder to determine what's idle and what's >> some network RPC wait, so I currently just do what Linux "load" metric does >> - I just shows threads in Runnable and Disk/Uninterruptible sleep >> states by default (-a shows all states, including Sleep and kernel-Idle >> threads etc) >> - So the Linux pSnapper "idle" means a somewhat different thing than >> Oracle "idle" - say LGWR was waiting for a Data Guard ACK, that should not >> be shown as Idle in Oracle, but at the Linux process level it's "just some >> network socket wait" and you'd need to use *-a* option to show all of >> them >> > > *** will add that option to future collections (and watch the video/read > help) > >> >> 7) Were LGWR/LG* processes mostly idle during the problem time? >> - As I kept reading the thread, it looks like ASH reported LGWR being >> mostly idle during the problem time >> - This is not exactly the same pattern, but I've seen cases in the >> past where everyone's waiting for LGWR and LGWR doesn't seem to be busy and >> doesn't show any significant waits >> - It turned out that LGWR was actually waiting for CKPT to make >> progress, but it wasn't synchronously waiting, but just going to sleep and >> "checking again later" in a loop >> - I wrote about this here: >> https://blog.tanelpoder.com/posts/log-file-switch-checkpoint-incomplete-and-lgwr-waiting-for-checkpoint-progress/ >> - So it may still make sense to check what LGWR/LG* processes are >> doing even if they don't seem to be active much (like do you see an >> occasional controlfile read wait by LGWR etc) >> - SQL*Trace would capture all activity of LGWR, but may slow things >> down further, so you could also sample & spool V$SESSION_WAIT_HISTORY (that >> keeps a log of last 10 waits of every session in memory) >> >> *** i think i've addressed most of this. > > >> Incidentally I'm doing another hacking session tomorrow (Thursday 30 Jan >> _at_ 12pm ET) about complex Oracle performance problems that span multiple >> layers and have multiple moving parts. I can add some LGWR troubleshooting >> magic in the end of that (here goes my plan to fit the session in 1.5h >> again!). I'll post the details in my blog in a few minutes. >> >> *** can't wait!! > >> -- >> Tanel Poder >> https://blog.tanelpoder.com/seminar >> >> >> On Tue, Jan 28, 2020 at 2:22 PM Chris Stephens <cstephens16_at_gmail.com> >> wrote: >> >>> doesn't look like any ash data for lgwr: >>> >>> SQL> _at_ashtop session_id,blocking_session,event2 1=1 >>> "TIMESTAMP'2020-01-27 15:50:48'" "TIMESTAMP'2020-01-27 15:52:40'" >>> TOTALSECONDS AAS %This SESSION_ID BLOCKING_SESSION >>> EVENT2 FIRST_SEEN LAST_SEEN >>> DIST_SQLEXEC_SEEN >>> _______________ ______ __________ _____________ ___________________ >>> _____________________ ______________________ ______________________ >>> ____________________ >>> 81 0.7 82% | 1713 1710 log >>> file sync 2020-01-27 15:50:54 2020-01-27 15:52:14 >>> 1 >>> 5 0 5% | 1221 ON >>> CPU 2020-01-27 15:50:59 2020-01-27 15:52:14 >>> 1 >>> 3 0 3% | 246 ON >>> CPU 2020-01-27 15:51:00 2020-01-27 15:52:00 >>> 1 >>> 3 0 3% | 1713 ON >>> CPU 2020-01-27 15:50:51 2020-01-27 15:52:27 >>> 2 >>> 1 0 1% | 123 ON >>> CPU 2020-01-27 15:51:35 2020-01-27 15:51:35 >>> 1 >>> 1 0 1% | 127 ON >>> CPU 2020-01-27 15:51:50 2020-01-27 15:51:50 >>> 1 >>> 1 0 1% | 252 2321 >>> latch free 2020-01-27 15:52:28 2020-01-27 15:52:28 >>> 1 >>> 1 0 1% | 978 ges >>> remote message 2020-01-27 15:50:48 2020-01-27 15:50:48 >>> 1 >>> 1 0 1% | 983 >>> latch free 2020-01-27 15:52:28 2020-01-27 15:52:28 >>> 1 >>> 1 0 1% | 1713 >>> library cache lock 2020-01-27 15:50:48 2020-01-27 15:50:48 >>> 1 >>> 1 0 1% | 1831 ON >>> CPU 2020-01-27 15:50:49 2020-01-27 15:50:49 >>> 1 >>> >>> >>> 11 rows selected. >>> >>> >>> SQL> _at_ashtop session_id,blocking_session,event2 session_id=1710 >>> "TIMESTAMP'2020-01-27 15:50:48'" "TIMESTAMP'2020-01-27 15:52:40'" >>> >>> no rows selected >>> >>> On Tue, Jan 28, 2020 at 1:09 PM Noveljic Nenad < >>> nenad.noveljic_at_vontobel.com> wrote: >>> >>>> You’re using v0.2, but v0.6 should be the latest version. 0.2 wouldn’t >>>> show idle blockers. >>>> >>>> I looked at the ashtop output once again. Strange that lgwr processes >>>> nor any other bg processes show up significantly there. The question is, >>>> what was lgwr doing while the fg processes were waiting on him. >>>> >>>>
-- http://www.freelists.org/webpage/oracle-lReceived on Thu Jan 30 2020 - 21:43:58 CET