From: Jonathan Lewis <jonathan@jlcomp.demon.co.uk>
To: Oracle L <oracle-l@freelists.org>
Subject: Re: intermittent long "log file sync" waits
Thread-Topic: intermittent long "log file sync" waits
Date: Sun, 2 Feb 2020 09:39:52 +0000
Message-ID: 
 <LNXP265MB1562810EC75BB7A638891C97A5010@LNXP265MB1562.GBRP265.PROD.OUTLOOK.COM>
References: 
 <CAEFL0szEBH0P-hqb39Pmjw-pdJ60OZ+RUuFoqCXsC7+=iPEFzQ@mail.gmail.com>
 <38763_1580228753_5E306091_38763_12713_1_cf89e1868e2e40949f6177bf1c604696@vontobel.com>
 <CAEFL0swS2CGeDF2pGWHDBQkO8J1cH7cMbDCxBngx613UW52A+Q@mail.gmail.com>
 <39760_1580232621_5E306FAD_39760_6519_1_238f704e660247f78d5e2f6a5c98b27f@vontobel.com>
 <CAEFL0szP5+-ZUog8Q=P0TiusLw6MpDDM46hZM=7ps0v0o3p_OQ@mail.gmail.com>
 <38763_1580238546_5E3086D2_38763_18592_1_8d9cba2aa89d4aba82f0b60173245848@vontobel.com>
 <CAEFL0szn17WU9kSj7ipRhieXd4w_3hzhU5gSmxDxhx1=WnqDkw@mail.gmail.com>
 <CAMHX9J+FooJWWr896aFx7oqeMk=PKA__GaHjxjU_gsOyE1Tzjg@mail.gmail.com>
 <CAEFL0sx7fAF89Qike6PS2Jy9-N5S-w-r31XQ7kj8AEGP5FonTg@mail.gmail.com>
 <CAEFL0syR4Xy2fPiL4M3jtmmfj_02MmYgC_haCM=LDZ17ikuGgg@mail.gmail.com>
 <CAMHX9JLchyEEvh4mHH8hHXEa53r5FP4Ck-kpCMLUiTgOJzYuEw@mail.gmail.com>,<CAMHX9JLW_i_c+7V0jMwXhWeAKNvUhEdVkf0sKEyHg62XyZP3aA@mail.gmail.com>
In-Reply-To: 
 <CAMHX9JLW_i_c+7V0jMwXhWeAKNvUhEdVkf0sKEyHg62XyZP3aA@mail.gmail.com>
Accept-Language: en-GB, en-US
Content-Language: en-GB
received-spf: None (protection.outlook.com: jlcomp.demon.co.uk does not
 designate permitted sender hosts)
Content-Type: text/plain; charset="iso-8859-1"
Content-Transfer-Encoding: quoted-printable
MIME-Version: 1.0
X-MS-Exchange-CrossTenant-Network-Message-Id: 3956712e-51f6-4dff-0bb5-08d7a7c3dab7
X-MS-Exchange-CrossTenant-originalarrivaltime: 02 Feb 2020 09:39:52.4965
 (UTC)
X-MS-Exchange-CrossTenant-fromentityheader: Hosted
X-MS-Exchange-CrossTenant-id: c5ec3dea-08bd-405e-942c-f61dff9a4831
X-MS-Exchange-CrossTenant-mailboxtype: HOSTED
X-MS-Exchange-CrossTenant-userprincipalname: ip/rfvDmIPQen+nxAF8R+DPTedYPugC9bxVDyUhXWsFTIenC71J2Pt0AK8N5og/nUZXVzqMim2WxChDF0AGaI3+jEiH6dEcwplwLZXBUtY0=
X-MS-Exchange-Transport-CrossTenantHeadersStamped: LNXP265MB0250
X-archive-position: 76130
X-ecartis-version: Ecartis v1.0.0
Sender: oracle-l-bounce@freelists.org
Errors-to: oracle-l-bounce@freelists.org
X-original-sender: jonathan@jlcomp.demon.co.uk
Precedence: normal
Reply-To: jonathan@jlcomp.demon.co.uk
List-Help: <mailto:ecartis@freelists.org?Subject=help>
List-Unsubscribe: <mailto:oracle-l-request@freelists.org?Subject=unsubscribe>
List-software: Ecartis version 1.0.0
List-Id: oracle-l <oracle-l.freelists.org>
X-List-ID: oracle-l <oracle-l.freelists.org>
List-Subscribe: <mailto:oracle-l-request@freelists.org?Subject=subscribe>
List-Owner: <mailto:>
List-post: <mailto:oracle-l@freelists.org>
List-Archive: <http://www.freelists.org/archives/oracle-l>
X-list: oracle-l

=0A=
It be interesting to see the previous 5 or 6 seconds of lgwr WAITS - using =
the "tim=3D" values as indicators to get to a point before that log file sy=
nc started. =0A=
The foreground doesn't have to send a message to the log writer if the log =
writer is already writing because it knows that LGWR will check if there's =
more to write before going to sleep. Possibly there's a race condition wher=
e the foreground decides that it doesn't need to send a message but the log=
 writer has decided there's no more to write - the log writer's activity in=
 the few seconds before it's 2.9 second wait might give us a clue.=0A=
=0A=
I'm also a little puzzled that a foreground could wait 6.9 seconds.  I thou=
ght there was a timeout for LFS (either 1 second or 1/10th second - possibl=
y version dependent, and settable by hidden parameter). So, unless the fore=
ground times out but doesn't start a new wait, it can't wait for 6.9 second=
s.=0A=
=0A=
Purely for the sake of collecting information I think I'd take a look at sm=
on_scn_time to to see what time the foregrounds  "sync scn" corresponded to=
, and to check the SCNs for the start and end time of the LFS wait.  =0A=
=0A=
=0A=
=0A=
Regards=0A=
Jonathan Lewis=0A=
 =0A=
=0A=
=0A=
________________________________________=0A=
From: oracle-l-bounce@freelists.org <oracle-l-bounce@freelists.org> on beha=
lf of Tanel Poder <tanel@tanelpoder.com>=0A=
Sent: 02 February 2020 03:50=0A=
To: Tanel Poder=0A=
Cc: Chris Stephens; Noveljic Nenad; oracle-l=0A=
Subject: Re: intermittent long "log file sync" waits=0A=
=0A=
But your trace file here already indicates that there's some glitch regardi=
ng LGWR wakeups/posting:=0A=
=0A=
Foreground:=0A=
=0A=
*** 2020-01-29T13:04:20.724666-06:00=0A=
WAIT #0: nam=3D'log file sync' ela=3D 6909711 buffer#=3D58996 sync scn=3D97=
6089279 p3=3D0 obj#=3D-1 tim=3D1025228531958=0A=
=0A=
LGWR at the same time:=0A=
=0A=
*** 2020-01-29T13:04:20.725994-06:00=0A=
WAIT #0: nam=3D'rdbms ipc message' ela=3D 2918443 timeout=3D300 p2=3D0 p3=
=3D0 obj#=3D-1 tim=3D1025228533313=0A=
=0A=
The WAIT lines are printed out when the wait ends (and the *** timestamp li=
ne just before the WAIT line is printed out, if enough time has passed sinc=
e the last *** line). So this shows that LGWR had happily been idle, waitin=
g for its idle 3-second timeout to expire, or someone to wake it up (that's=
 what "rdbms ipc message" means) - while someone had issued a commit and wa=
s waiting for LGWR acknowledgment. So this shows that LGWR didn't even get =
the post from your session, nor any other sessions (if you had concurrent t=
ransactional activity). Back in 11g, typically these problems happened when=
 adaptive log file syncing switch between poll and post/wait wakeup method =
happened and you hit a bug. But in 12c there are more moving parts.=0A=
=0A=
--=0A=
Tanel Poder=0A=
https://blog.tanelpoder.com/seminar=0A=
=0A=
--
http://www.freelists.org/webpage/oracle-l