RE: intermittent long "log file sync" waits

From: Noveljic Nenad <nenad.noveljic_at_vontobel.com>
Date: Wed, 29 Jan 2020 14:44:55 +0000
Message-ID: <33043_1580309117_5E319A7D_33043_4737_1_b0f9c4ec037e439c98af89161330c7ce_at_vontobel.com>



The total log file sync time wait time was <= 5s in 5.5 minutes, so this doesn’t seem to be a problem within the observed time period.

To speed-up the backups you’d need to analyze the I/O performance on the backup and control file devices. This might or might not correlate with the log file sync problem.

Note that you specified sysdate-10/60/24 and sysdate for begin and end time, respectively, which will show you the report for the last 10 minutes, and not for the yesterday’s time interval when you reported the backup issue : “noticed the archivelog backup scheduled to run every hour seems to be stuck and has been for at least 10 mins:“

From: Chris Stephens <cstephens16_at_gmail.com> Sent: Mittwoch, 29. Januar 2020 14:50
To: Noveljic Nenad <nenad.noveljic_at_vontobel.com> Cc: cary.millsap_at_method-r.com; Stefan Koehler <contact_at_soocs.de>; oracle-l <Oracle-L_at_freelists.org> Subject: Re: intermittent long "log file sync" waits

SQL> _at_ashtop event2 1=1 sysdate-10/60/24 sysdate

   TOTALSECONDS    AAS      %This                                    EVENT2             FIRST_SEEN              LAST_SEEN    DIST_SQLEXEC_SEEN
_______________ ______ __________ _________________________________________ ______________________ ______________________ ____________________
           1864    3.1   67% |    Disk file operations I/O                  2020-01-29 07:38:53    2020-01-29 07:48:52                     925
            469    0.8   17% |    ON CPU                                    2020-01-29 07:38:53    2020-01-29 07:48:45                     112
            299    0.5   11% |    control file sequential read              2020-01-29 07:38:53    2020-01-29 07:48:49                     112
             61    0.1    2% |    ASM file metadata operation               2020-01-29 07:39:22    2020-01-29 07:43:02                      12
             13      0    0% |    enq: RS - prevent file delete [mode=2]    2020-01-29 07:39:07    2020-01-29 07:47:09                       8
              9      0    0% |    RMAN backup & recovery I/O                2020-01-29 07:40:06    2020-01-29 07:48:44                       8
              7      0    0% |    ADR block file write                      2020-01-29 07:39:17    2020-01-29 07:46:46                       1
              7      0    0% |    ADR file lock                             2020-01-29 07:39:17    2020-01-29 07:46:46                       1
              7      0    0% |    row cache lock                            2020-01-29 07:41:22    2020-01-29 07:45:46                       7
              5      0    0% |    DLM cross inst call completion            2020-01-29 07:41:15    2020-01-29 07:46:57                       5
              5      0    0% |    log file sync                             2020-01-29 07:42:31    2020-01-29 07:48:03                       1
              4      0    0% |    KSV master wait                           2020-01-29 07:39:22    2020-01-29 07:42:42                       3
              3      0    0% |    reliable message                          2020-01-29 07:47:00    2020-01-29 07:48:07                       3
              2      0    0% |    library cache lock                        2020-01-29 07:42:21    2020-01-29 07:44:42                       2
              1      0    0% |    IMR slave acknowledgement msg             2020-01-29 07:41:04    2020-01-29 07:41:04                       1


15 rows selected.

SQL> _at_ashtop module,event2 1=1 sysdate-10/60/24 sysdate

   TOTALSECONDS    AAS      %This                                     MODULE                          EVENT2             FIRST_SEEN              LAST_SEEN    DIST_SQLEXEC_SEEN
_______________ ______ __________ __________________________________________ _______________________________ ______________________ ______________________ ____________________
            934    1.6   34% |    backup archivelog                          Disk file operations I/O        2020-01-29 07:39:07    2020-01-29 07:49:06                       1
            465    0.8   17% |    rman_at_lsst-oradb04 (TNS V1-V3)              Disk file operations I/O        2020-01-29 07:39:08    2020-01-29 07:49:06                     465
            460    0.8   17% |    rman_at_lsst-oradb01 (TNS V1-V3)              Disk file operations I/O        2020-01-29 07:39:08    2020-01-29 07:49:06                     460
            191    0.3    7% |    backup archivelog                          control file sequential read    2020-01-29 07:39:17    2020-01-29 07:49:00                       1
            135    0.2    5% |    SQL*Plus                                   ON CPU                          2020-01-29 07:39:07    2020-01-29 07:48:06                      18
            130    0.2    5% |    sqlplus_at_lsst-oradb05 (TNS V1-V3)           ON CPU                          2020-01-29 07:39:16    2020-01-29 07:48:57                      50
             80    0.1    3% |                                               ON CPU                          2020-01-29 07:39:23    2020-01-29 07:48:34                       2
             60    0.1    2% |    rman_at_lsst-oradb01 (TNS V1-V3)              control file sequential read    2020-01-29 07:39:19    2020-01-29 07:48:57                      60
             57    0.1    2% |    MMON_SLAVE                                 ASM file metadata operation     2020-01-29 07:40:10    2020-01-29 07:43:02                      11
             52    0.1    2% |    rman_at_lsst-oradb04 (TNS V1-V3)              control file sequential read    2020-01-29 07:39:19    2020-01-29 07:48:57                      52
             41    0.1    1% |    backup archivelog                          ON CPU                          2020-01-29 07:39:17    2020-01-29 07:48:41                       1
             30    0.1    1% |    python_at_lsst-verify-worker28 (TNS V1-V3)    ON CPU                          2020-01-29 07:41:18    2020-01-29 07:48:33                      19
             13      0    0% |    rman_at_lsst-oradb01 (TNS V1-V3)              ON CPU                          2020-01-29 07:39:07    2020-01-29 07:48:54                      12
             13      0    0% |    rman_at_lsst-oradb04 (TNS V1-V3)              ON CPU                          2020-01-29 07:39:15    2020-01-29 07:48:22                      13
              8      0    0% |    backup archivelog                          ADR file lock                   2020-01-29 07:39:17    2020-01-29 07:49:00                       1

On Wed, Jan 29, 2020 at 1:14 AM Noveljic Nenad <nenad.noveljic_at_vontobel.com<mailto:nenad.noveljic_at_vontobel.com>> wrote: Hi Chris,

Could you send the ashtop event2 1=1 _from_ _to_ output for the 10 minutes interval while the backup was hanging?

Let’s see if there was a log file sync problem at the same time.

Best regards,

Nenad

https://nenadnoveljic.com/blog/

From: Chris Stephens <cstephens16_at_gmail.com<mailto:cstephens16_at_gmail.com>> Sent: Dienstag, 28. Januar 2020 23:49
To: Noveljic Nenad <nenad.noveljic_at_vontobel.com<mailto:nenad.noveljic_at_vontobel.com>> Cc: cary.millsap_at_method-r.com<mailto:cary.millsap_at_method-r.com>; Stefan Koehler <contact_at_soocs.de<mailto:contact_at_soocs.de>>; oracle-l <Oracle-L_at_freelists.org<mailto:Oracle-L_at_freelists.org>> Subject: Re: intermittent long "log file sync" waits

was just getting ready to sign off and noticed the archivelog backup scheduled to run every hour seems to be stuck and has been for at least 10 mins:

[oracle_at_lsst-oradb04 ~]$ ps -ef | grep oracle_backup.sh oracle 13369 31167 0 16:43 pts/0 00:00:00 grep --color=auto oracle_backup.sh oracle 14649 14645 0 16:00 ? 00:00:00 /bin/bash /home/oracle/scripts/rman/oracle_backup.sh -d lsst2db -s archivelog.rman -c lsst2db_rman -e cs2018_at_ncsa.illinois.edu<mailto:cs2018_at_ncsa.illinois.edu> -r iddsdba_rman [oracle_at_lsst-oradb04 ~]$ pstack 15649 Process 15649 not found.
[oracle_at_lsst-oradb04 ~]$ pstack 14649
#0 0x00007f9a6537e41c in waitpid () from /lib64/libc.so.6
#1 0x0000000000440b84 in waitchld.isra.10 ()
#2 0x0000000000441e3c in wait_for ()
#3 0x0000000000433b0e in execute_command_internal ()
#4 0x0000000000433d2e in execute_command ()
#5 0x000000000041e365 in reader_loop ()
#6 0x000000000041c9ce in main ()

[oracle_at_lsst-oradb04 ~]$ pstack 14649
#0 0x00007f9a6537e41c in waitpid () from /lib64/libc.so.6
#1 0x0000000000440b84 in waitchld.isra.10 ()
#2 0x0000000000441e3c in wait_for ()
#3 0x0000000000433b0e in execute_command_internal ()
#4 0x0000000000433d2e in execute_command ()
#5 0x000000000041e365 in reader_loop ()
#6 0x000000000041c9ce in main ()

[oracle_at_lsst-oradb04 ~]$ pstack 14649
#0 0x00007f9a6537e41c in waitpid () from /lib64/libc.so.6
#1 0x0000000000440b84 in waitchld.isra.10 ()
#2 0x0000000000441e3c in wait_for ()
#3 0x0000000000433b0e in execute_command_internal ()
#4 0x0000000000433d2e in execute_command ()
#5 0x000000000041e365 in reader_loop ()
#6 0x000000000041c9ce in main ()

[oracle_at_lsst-oradb04 ~]$ pstack 14649
#0 0x00007f9a6537e41c in waitpid () from /lib64/libc.so.6
#1 0x0000000000440b84 in waitchld.isra.10 ()
#2 0x0000000000441e3c in wait_for ()
#3 0x0000000000433b0e in execute_command_internal ()
#4 0x0000000000433d2e in execute_command ()
#5 0x000000000041e365 in reader_loop ()
#6 0x000000000041c9ce in main ()

[oracle_at_lsst-oradb04 ~]$



Please consider the environment before printing this e-mail. Bitte denken Sie an die Umwelt, bevor Sie dieses E-Mail drucken.

Important Notice
This message is intended only for the individual named. It may contain confidential or privileged information. If you are not the named addressee you should in particular not disseminate, distribute, modify or copy this e-mail. Please notify the sender immediately by e-mail, if you have received this message by mistake and delete it from your system. Without prejudice to any contractual agreements between you and us which shall prevail in any case, we take it as your authorization to correspond with you by e-mail if you send us messages by e-mail. However, we reserve the right not to execute orders and instructions transmitted by e-mail at any time and without further explanation. E-mail transmission may not be secure or error-free as information could be intercepted, corrupted, lost, destroyed, arrive late or incomplete. Also processing of incoming e-mails cannot be guaranteed. All liability of Vontobel Holding Ltd. and any of its affiliates (hereinafter collectively referred to as "Vontobel Group") for any damages resulting from e-mail use is excluded. You are advised that urgent and time sensitive messages should not be sent by e-mail and if verification is required please request a printed version. Please note that all e-mail communications to and from the Vontobel Group are subject to electronic storage and review by Vontobel Group. Unless stated to the contrary and without prejudice to any contractual agreements between you and Vontobel Group which shall prevail in any case, e-mail-communication is for informational purposes only and is not intended as an offer or solicitation for the purchase or sale of any financial instrument or as an official confirmation of any transaction. The legal basis for the processing of your personal data is the legitimate interest to develop a commercial relationship with you, as well as your consent to forward you commercial communications. You can exercise, at any time and under the terms established under current regulation, your rights. If you prefer not to receive any further communications, please contact your client relationship manager if you are a client of Vontobel Group or notify the sender. Please note for an exact reference to the affected group entity the corporate e-mail signature. For further information about data privacy at Vontobel Group please consult www.vontobel.com<https://www.vontobel.com>.

<html xmlns="http://www.w3.org/1999/xhtml">
<head>
<meta http-equiv="Content-Type" content="text/html; charset=iso-8859-1">
<style type="text/css">p { font-family: Arial;font-size:9pt }</style>
</head>
<body>
<p>
<br>Important Notice</br>
<br />

This message is intended only for the individual named. It may contain confidential or privileged information. If you are not the named addressee you should in particular not disseminate, distribute, modify or copy this e-mail. Please notify the sender immediately by e-mail, if you have received this message by mistake and delete it from your system.<br /> Without prejudice to any contractual agreements between you and us which shall prevail in any case, we take it as your authorization to correspond with you by e-mail if you send us messages by e-mail. However, we reserve the right not to execute orders and instructions transmitted by e-mail at any time and without further explanation.<br /> E-mail transmission may not be secure or error-free as information could be intercepted, corrupted, lost, destroyed, arrive late or incomplete. Also processing of incoming e-mails cannot be guaranteed. All liability of Vontobel Holding Ltd. and any of its affiliates (hereinafter collectively referred to as "Vontobel Group") for any damages resulting from e-mail use is excluded. You are advised that urgent and time sensitive messages should not be sent by e-mail and if verification is required please request a printed version.</br> Please note that all e-mail communications to and from the Vontobel Group are subject to electronic storage and review by Vontobel Group. Unless stated to the contrary and without prejudice to any contractual agreements between you and Vontobel Group which shall prevail in any case, e-mail-communication is for informational purposes only and is not intended as an offer or solicitation for the purchase or sale of any financial instrument or as an official confirmation of any transaction.<br /> The legal basis for the processing of your personal data is the legitimate interest to develop a commercial relationship with you, as well as your consent to forward you commercial communications. You can exercise, at any time and under the terms established under current regulation, your rights. If you prefer not to receive any further communications, please contact your client relationship manager if you are a client of Vontobel Group or notify the sender. Please note for an exact reference to the affected group entity the corporate e-mail signature. For further information about data privacy at Vontobel Group please consult <a href="https://www.vontobel.com">www.vontobel.com</a>.<br />
</p>
</body>
</html>

--
http://www.freelists.org/webpage/oracle-l
Received on Wed Jan 29 2020 - 15:44:55 CET

Original text of this message