Re: LGWR, EMC or app cursors?

  • From: Andy Sayer <andysayer@xxxxxxxxx>
  • To: Ls Cheng <exriscer@xxxxxxxxx>
  • Date: Sat, 12 Oct 2019 17:33:09 +0100

 You definitely have a storage problem, your IOs are sometimes going
missing. Your system is resubmitting them when it detects a timeout (30
seconds is a common default). I wouldn't expect other IOs to fail at the
same time, it's unlikely that your storage is just not working for 30
seconds at a time (you would hope that would be super obvious). It's more
likely that there's a one in a billion chance for an IO to go missing and
you hit that one in a billion chance several times a day.

When this missing IO happens to LGWR you immediately see the problem
because every session that does a commit wait (log file sync) will end up
waiting for the same 30 seconds LGWR is waiting for. You will almost
certainly be seeing the same issue with your data files, you can run
queries against dba_hist_event_histogram to identify how often these occur
just to prove this is happening. You can also use ASH to pinpoint exact
times and exact files these occur and your storage team might be able to do
something with this information.

This is certainly a problem with your storage, but there are things you can
do to help manage the pain:

You can reduce your disk time out setting. Let's face it, 30 seconds is an
eternity for an IO in this decade, EMC recommend 10 seconds if you are
using multipathing (you are, right?) - I would say that is a maximum it
should be in any circumstance. This means that when the IO gets lost, you
only wait for 10 seconds before it gets retried, 10 seconds of hanging
might be acceptable enough - it will probably happen exactly as often as
before.
You can reduce the effect on every session when LGWR hits the issue, if you
accept the risk of not writing the commit redo to disk before your
application moves on (i.e. if your system crashes, you might loose your
newer transactions). You can do this by setting commit_wait to nowait (
https://docs.oracle.com/cd/E11882_01/server.112/e40402/initparams033.htm)
but note there's still a few things that will always do a commit wait
rather than use this parameter (non-zero rollbacks, increment a sequence
beyond a value that's cached, probably other examples). This will mean that
when LGWR is hanging on a long IO, your other sessions will be nonplussed
(unless they do a commit wait).

Funnily enough, I'm just trying to get to the EMC website to see if there's
any documentation that would show you how to identify lost IOs, EMC.com
returns ERR_CONNECTION_TIMED_OUT :)

Hope that gives you some ideas,
Andy


On Sat, 12 Oct 2019 at 15:25, Ls Cheng <exriscer@xxxxxxxxx> wrote:

Hi

Have you checked the number of IOPS? Perhaps you could snap v$sysmetric or
v$sysstat every 30 seconds for a day and analyze when the problem happens.

BR



<https://www.avast.com/sig-email?utm_medium=email&utm_source=link&utm_campaign=sig-email&utm_content=webmail>
 Virus-free.
www.avast.com
<https://www.avast.com/sig-email?utm_medium=email&utm_source=link&utm_campaign=sig-email&utm_content=webmail>
<#m_399858249456707877_DAB4FAD8-2DD7-40BB-A1B8-4E2AA1F9FDF2>

On Thu, Oct 10, 2019 at 7:02 PM Herring, David <HerringD@xxxxxxx> wrote:

The code in question is probably going to raise some eyebrows but here
goes since I knew I'd have to explain at some point (and then give the
excuse it's a 3rd party app):



   - The app can run from any number of app servers, in our case 3 are
   needed.  Each app server issues heartbeats and when the heartbeat appears
   to be separated by 30 sec or more, it assumes a lost connection and
   restarts the app server.  The check previously was 15 sec. but I got them
   to adjust to 30 sec.
   - The heartbeat sessions are persistent, running an update that
   uniquely identifies each app server (and hence session) with a timestamp,
   commit, wait 5 sec, the SELECT current time (within DB session) minus
   heartbeat timestamp, then repeat.  I know the 2 SQL_IDs for the heartbeat
   and set tracing on those IDs.  Parsing the tracefiles I see that the
   heartbeats repeat every 5 sec consistently, until the last one I the file
   that hits 25+ sec gap which causes an app restart and hence a restart of
   the DB session.
   - I don't have an extensive OLTP background but to me the heartbeat
   process is asking for trouble.  The table has 1 row per app server, so in
   this case 3.  I dumped the rowid details and confirmed all 3 rows are in
   the same block.  This means every 5 seconds, potentially concurrent, 3
   different sessions will try to update the same block.
   - The DB is running on a 2-node RAC and heartbeat sessions may show
   up wherever (connect via scan) so we get plenty of GC waits.  I would 
think
   they'd want a separate object per app server doing a heartbeat to (nearly)
   completely eliminate contention but again, the app isn't in my control.
   - This env was converted from MySQL and apparently worked fine
   there.  There's a QA env where the heartbeat processing works fine too.



I guess that's a VERY long answer.  Just confirming that COMMITs,
although quite frequent, are no more than 3 every 5 sec per app design.



Regards,



Dave



[image: cid:image001.png@01D05044.5C2AEE60]



*Dave Herring*

DBA

103 JFK Parkway

Short Hills, New Jersey  07078

Mobile 630.441.4404



*dnb.com <http://www.dnb.com/>*



[image: cid:image002.png@01D05044.5C2AEE60]
<http://www.facebook.com/DunBradstreet>[image:
cid:image003.png@01D05044.5C2AEE60] <http://twitter.com/dnbus>[image:
cid:image004.png@01D05044.5C2AEE60]
<http://www.linkedin.com/company/dun-&-bradstreet>[image:
cid:image005.png@01D05044.5C2AEE60]
<http://www.youtube.com/user/DunandBrad>



*From:* oracle-l-bounce@xxxxxxxxxxxxx <oracle-l-bounce@xxxxxxxxxxxxx> *On
Behalf Of *Ls Cheng
*Sent:* Thursday, October 10, 2019 7:24 AM
*To:* dmarc-noreply@xxxxxxxxxxxxx
*Cc:* oracle-l@xxxxxxxxxxxxx
*Subject:* Re: LGWR, EMC or app cursors?



*CAUTION:* This email originated from outside of D&B. Please do not
click links or open attachments unless you recognize the sender and know
the content is safe.



Hi



Can you try to identify the number of commits when that happens plus the
IOPS?



I had a similar problems years ago, it turns our in the code a loop ran
2500 commits per sec




<https://nam03.safelinks.protection.outlook.com/?url=https%3A%2F%2Fwww.avast.com%2Fsig-email%3Futm_medium%3Demail%26utm_source%3Dlink%26utm_campaign%3Dsig-email%26utm_content%3Dwebmail&data=02%7C01%7Cherringd%40dnb.com%7Ce06948109f034f7f372008d74d7cd85b%7C19e2b708bf12437597198dec42771b3e%7C0%7C0%7C637063070921709817&sdata=8Hfty12ixkrOqg9EfpPgu0kP9Kt7wrj6Fx4B2OM%2F8F0%3D&reserved=0>

Virus-free. www.avast.com
<https://nam03.safelinks.protection.outlook.com/?url=https%3A%2F%2Fwww.avast.com%2Fsig-email%3Futm_medium%3Demail%26utm_source%3Dlink%26utm_campaign%3Dsig-email%26utm_content%3Dwebmail&data=02%7C01%7Cherringd%40dnb.com%7Ce06948109f034f7f372008d74d7cd85b%7C19e2b708bf12437597198dec42771b3e%7C0%7C0%7C637063070921709817&sdata=8Hfty12ixkrOqg9EfpPgu0kP9Kt7wrj6Fx4B2OM%2F8F0%3D&reserved=0>



On Mon, Oct 7, 2019 at 5:20 PM Herring, David <
dmarc-noreply@xxxxxxxxxxxxx> wrote:

Folks, I've got a bit of a mystery with a particular db where we're
getting a periodic 25-30 pause between user sessions and LGWR processes and
can't clearly identify what's the cause.



   - The database is 11.2.0.4, RHEL 7.5, running ASM on EMC.
   - Sometimes once a day, sometimes more (never more than 5) times a
   day we see user processes start waiting on "log file sync".  LGWR is
   waiting on "log file parallel write".
   - At the same time one of the emcpower* devices shows 100% busy and
   service time 200+ (from iostat via osw).  mpstat shows 1 CPU at 100% on
   iowait.  It's not always the same disk (emcpowere1, a1, h1, …), not always
   the same CPU.  EMC and sysadmins have confirmed there are no disk errors
   and from their standpoint the disks are waiting on Oracle.
   - During this time LGWR stats in ASH are all 0 - TIME_WAITED, DELTA*
   columns.  Only after the problem goes away (about 25 secs) these columns
   are populated again, obviously the DELTA* columns 1 row later.  LGWR's
   session state is WAITING so I assume the column value observations are due
   to LGWR waiting, as it won't write stats until it can do something.



I am stuck trying to find out, really prove who is the culprit or what
exactly the wait is on.  Is LGWR waiting on user sessions and user sessions
are waiting on LGWR and all that causes the disk to be 100%?  Can I enable
some sort of tracing on LGWR and would that point to exactly what he's
waiting on to prove where the problem is?



Regards,



Dave


PNG image

PNG image

PNG image

PNG image

PNG image

Other related posts: