Re: Application performance hit when performing archived log backups

  • From: Ryan January <rjanuary@xxxxxxxxx>
  • To: "Mark W. Farnham" <mwf@xxxxxxxx>
  • Date: Tue, 17 May 2016 07:28:37 -0500

1) Are your applications chatty? If you trace an application, do you see an
increase in the sum of the durations of sqlnet waits while the backup is
running?

I wouldn't have anticipated they were, but I'm really starting to wonder.  If 
that is the case, it's possible the increased network traffic, pushing the 
backup to NFS, is causing the delay at the network layer.  IMO that's one of 
the only places the time could be "hiding" given what we've already looked at. 
Trace is the only way we're going to get anything. 

2) Do the data persistence stacks (memory to i/o controller or network to
disk) collide amongst archived log location, archive log destination,
database files, and temp locations? If you trace an application, do you see
an increase in the sum of durations of database reads?

It feels like there has to be a commonality in there, which is something I'm 
still working to address. From what I've seen so far the answer is no.  Oddly, 
backing up data files only has a slight impact, where backing up archived logs 
is rather profound.  If anything, I would have expected the other way around.

I would rule those two out first, but please notice that both start with
tracing an application that runs differently (faster when not doing backup,
slower when doing backup).

So the trace will show what is different. When you have the luxury of ops
staff having reported slowdowns of specific things at specific times please
enjoy benefit that you can measure instead of guessing quite easily.


Suffice it to say you're preaching to the choir ;)
It's not an exaggeration to say that I've been beating them over the head for 
better logging and metric collection for the last few years. The only reason 
they have the perf data is that the infrastructure team got tired of having 
nothing to go on and we did it for them.  The data has been a blessing and a 
curse.  As soon as we began gathering data we've been surfacing odd trends.  

Tracing is one of the next steps.  Unfortunately the app is still very lightly 
instrumented from the DB perspective, JDBC connection pool, the home-grown ORM 
doesn't use binds in many cases. It all adds up to a great deal of my time to 
correlate traces.  My biggest quandary is that we're not talking about a 
slowdown in only a few statements. It truly is across the entire app, with very 
few exceptions.  If you have any tips and tricks for time savers there, I'm all 
ears.  At the last job I had a copy of MR Tools, which spoiled me a bit.  It 
may be a time to make an investment in more tooling here as well.


On May 17, 2016, at 5:12 AM, Mark W. Farnham <mwf@xxxxxxxx> wrote:

1) Are your applications chatty? If you trace an application, do you see an
increase in the sum of the durations of sqlnet waits while the backup is
running?

2) Do the data persistence stacks (memory to i/o controller or network to
disk) collide amongst archived log location, archive log destination,
database files, and temp locations? If you trace an application, do you see
an increase in the sum of durations of database reads?

I would rule those two out first, but please notice that both start with
tracing an application that runs differently (faster when not doing backup,
slower when doing backup).

So the trace will show what is different. When you have the luxury of ops
staff having reported slowdowns of specific things at specific times please
enjoy benefit that you can measure instead of guessing quite easily.

mwf

-----Original Message-----
From: oracle-l-bounce@xxxxxxxxxxxxx [mailto:oracle-l-bounce@xxxxxxxxxxxxx]
On Behalf Of Ryan January
Sent: Monday, May 16, 2016 1:47 PM
To: Listserv Oracle
Subject: Application performance hit when performing archived log backups

I've got a strange one that, as of yet, I've not been able to resolve. 1/8
rack Exadata v4 (x4-2) , 11.2.0.4, OEL 6.  High capacity disks, flash
configured as cache, rather than independent disks.

The DB is backing an in-house java/tomcat OLTP-ish application.  Ops staff
reported slowdowns at specific times. App slow down verified via StatsD
collected performance metrics.  Watching those metrics we identified the
issue to be common across the vast majority of DB calls, and roughly 30
separate application instances.  (separate app/web servers per instance, all
pointing to differing sets of application schemas within the same DB)  

Poking through ASH data the only commonality I found was an increase in
system IO, which ultimately ended up being RMAN. We were performing very
simple archived log backups via rman with a parallelism of 4.  Backup sets
are being pushed uncompressed across a 1Gb link to DataDomain mounted via
NFS. 
App call times went from 1s normally to over 30s at their worst.  Backing
that parallelism off to 1 resulted in a smaller spike with an increased
duration.  Application performance falls off very sharply as the backup
begins, with a slower 2-3 minute exponential increase in performance as the
backup completes.  The same execution plan has been verified for frequent
SQL statements during both good and bad times.
There is nothing specific to individual SQL statements which appears to be
problematic, all application calls during the time suffer.  I've not yet
found any spikes in metrics that explain such a profound performance impact.
AWR reports during the time of slowdown seem similar to those when the
backup is not being performed. We've not been gathering data long enough to
determine if this is entirely new behavior, or if it's been getting
progressively worse over time.

Next steps for me: integrating AWR snapshots before and after the backup
completes to narrow the window AWR is focused on.  I'm also working on
automating 10046 trace for further analysis and comparison.  

Short of that, has anyone seen similar behavior?  I would have never
anticipated archived log backups to have this impact, but the timing matches
up perfectly with 100% repeatability.  If not the root cause, it's at least
a contributor that we've identified as a fact. I would appreciate any
suggestions of where we should consider continuing our troubleshooting, or
guidance on what metrics we should gather. 

Thank you,
Ryan--
//www.freelists.org/webpage/oracle-l



--
//www.freelists.org/webpage/oracle-l


Other related posts: