[20160119]日志频繁切换.txt
--元旦后的事情，主要问题是节前给主库增加几个数据文件，本来dg的磁盘空间就很紧张，加上节假日没人检查dg。
--导致dg磁盘空间满，出现了日志频繁切换，做1个记录：
1.环境：
SYS@xxxxdg2> @ &r/ver1
PORT_STRING VERSION BANNER
------------------------------ -------------- --------------------------------------------------------------------------------
x86_64/Linux 2.4.xx 11.2.0.4.0 Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production
SELECT TRUNC (first_time) "Date", TO_CHAR (first_time, 'Dy') "Day", COUNT (1) "Total",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '00', 1, 0)) h0,
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '01', 1, 0)) "h1",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '02', 1, 0)) "h2",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '03', 1, 0)) "h3",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '04', 1, 0)) "h4",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '05', 1, 0)) "h5",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '06', 1, 0)) "h6",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '07', 1, 0)) "h7",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '08', 1, 0)) "h8",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '09', 1, 0)) "h9",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '10', 1, 0)) "h10",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '11', 1, 0)) "h11",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '12', 1, 0)) "h12",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '13', 1, 0)) "h13",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '14', 1, 0)) "h14",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '15', 1, 0)) "h15",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '16', 1, 0)) "h16",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '17', 1, 0)) "h17",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '18', 1, 0)) "h18",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '19', 1, 0)) "h19",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '20', 1, 0)) "h20",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '21', 1, 0)) "h21",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '22', 1, 0)) "h22",
SUM (DECODE (TO_CHAR (first_time, 'hh24'), '23', 1, 0)) "h23", ROUND (COUNT (1) / 24, 2) "Avg"
FROM gv$log_history
WHERE first_time >= trunc(SYSDATE) - 20
and thread# = inst_id
GROUP BY TRUNC (first_time), TO_CHAR (first_time, 'Dy')
ORDER BY 1 DESC;
Date Day Total H0 h1 h2 h3 h4 h5 h6 h7 h8 h9 h10 h11 h12 h13 h14 h15 h16 h17 h18 h19 h20 h21 h22 h23 Avg
------------------- ------ ---------- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- -------
...
2016-01-03 00:00:00 Sun 4 0 0 0 0 0 4 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 .17
2016-01-02 00:00:00 Sat 98 0 0 0 0 0 9 12 12 13 12 11 12 8 2 6 1 0 0 0 0 0 0 0 0 4.08
2016-01-01 00:00:00 Fri 4 0 0 0 0 0 4 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 .17
...
SELECT round((next_time - first_time) * 86400,2) xx, sequence#,first_time,next_time,blocks,creator,completion_time
FROM V$ARCHIVED_LOG a
WHERE first_time BETWEEN '2016/01/02' AND '2016/01/03'
AND name LIKE '+RECOC1%'
AND thread# = 1
ORDER BY first_time ;
XX SEQUENCE# FIRST_TIME NEXT_TIME BLOCKS CREATOR COMPLETION_TIME
---------- ---------- ------------------- ------------------- ---------- ------- -------------------
24 1812 2016-01-02 05:27:03 2016-01-02 05:27:27 45 ARCH 2016-01-02 05:27:27
390 1813 2016-01-02 05:27:27 2016-01-02 05:33:57 1696 ARCH 2016-01-02 05:33:57
660 1814 2016-01-02 05:33:57 2016-01-02 05:44:57 5086 ARCH 2016-01-02 05:44:57
360 1815 2016-01-02 05:44:57 2016-01-02 05:50:57 3199 ARCH 2016-01-02 05:50:58
961 1816 2016-01-02 05:50:57 2016-01-02 06:06:58 12949 ARCH 2016-01-02 06:06:58
600 1817 2016-01-02 06:06:58 2016-01-02 06:16:58 6508 ARCH 2016-01-02 06:16:58
660 1818 2016-01-02 06:16:58 2016-01-02 06:27:58 5870 ARCH 2016-01-02 06:27:58
361 1819 2016-01-02 06:27:58 2016-01-02 06:33:59 3229 ARCH 2016-01-02 06:33:59
660 1820 2016-01-02 06:33:59 2016-01-02 06:44:59 3228 ARCH 2016-01-02 06:44:59
600 1821 2016-01-02 06:44:59 2016-01-02 06:54:59 9595 ARCH 2016-01-02 06:54:59
600 1822 2016-01-02 06:54:59 2016-01-02 07:04:59 17983 ARCH 2016-01-02 07:05:00
361 1823 2016-01-02 07:04:59 2016-01-02 07:11:00 7856 ARCH 2016-01-02 07:11:00
360 1824 2016-01-02 07:11:00 2016-01-02 07:17:00 11690 ARCH 2016-01-02 07:17:00
603 1825 2016-01-02 07:17:00 2016-01-02 07:27:03 19300 ARCH 2016-01-02 07:27:03
657 1826 2016-01-02 07:27:03 2016-01-02 07:38:00 21525 ARCH 2016-01-02 07:38:01
601 1827 2016-01-02 07:38:00 2016-01-02 07:48:01 17937 ARCH 2016-01-02 07:48:01
363 1828 2016-01-02 07:48:01 2016-01-02 07:54:04 19807 ARCH 2016-01-02 07:54:04
360 1829 2016-01-02 07:54:04 2016-01-02 08:00:04 19327 ARCH 2016-01-02 08:00:04
600 1830 2016-01-02 08:00:04 2016-01-02 08:10:04 55352 ARCH 2016-01-02 08:10:05
661 1831 2016-01-02 08:10:04 2016-01-02 08:21:05 62631 ARCH 2016-01-02 08:21:05
600 1832 2016-01-02 08:21:05 2016-01-02 08:31:05 65873 ARCH 2016-01-02 08:31:05
360 1833 2016-01-02 08:31:05 2016-01-02 08:37:05 44382 ARCH 2016-01-02 08:37:05
357 1834 2016-01-02 08:37:05 2016-01-02 08:43:02 43982 ARCH 2016-01-02 08:43:03
604 1835 2016-01-02 08:43:02 2016-01-02 08:53:06 89033 ARCH 2016-01-02 08:53:06
660 1836 2016-01-02 08:53:06 2016-01-02 09:04:06 104306 ARCH 2016-01-02 09:04:07
600 1837 2016-01-02 09:04:06 2016-01-02 09:14:06 101150 ARCH 2016-01-02 09:14:07
661 1838 2016-01-02 09:14:06 2016-01-02 09:25:07 113452 ARCH 2016-01-02 09:25:07
600 1839 2016-01-02 09:25:07 2016-01-02 09:35:07 99097 ARCH 2016-01-02 09:35:07
600 1840 2016-01-02 09:35:07 2016-01-02 09:45:07 107339 ARCH 2016-01-02 09:45:08
661 1841 2016-01-02 09:45:07 2016-01-02 09:56:08 118777 ARCH 2016-01-02 09:56:08
600 1842 2016-01-02 09:56:08 2016-01-02 10:06:08 107504 ARCH 2016-01-02 10:06:08
600 1843 2016-01-02 10:06:08 2016-01-02 10:16:08 132672 ARCH 2016-01-02 10:16:09
601 1844 2016-01-02 10:16:08 2016-01-02 10:26:09 115642 ARCH 2016-01-02 10:26:09
600 1845 2016-01-02 10:26:09 2016-01-02 10:36:09 107361 ARCH 2016-01-02 10:36:09
600 1846 2016-01-02 10:36:09 2016-01-02 10:46:09 111693 ARCH 2016-01-02 10:46:09
660 1847 2016-01-02 10:46:09 2016-01-02 10:57:09 92669 ARCH 2016-01-02 10:57:10
601 1848 2016-01-02 10:57:09 2016-01-02 11:07:10 99623 ARCH 2016-01-02 11:07:10
600 1849 2016-01-02 11:07:10 2016-01-02 11:17:10 98332 ARCH 2016-01-02 11:17:10
600 1850 2016-01-02 11:17:10 2016-01-02 11:27:10 98874 ARCH 2016-01-02 11:27:11
601 1851 2016-01-02 11:27:10 2016-01-02 11:37:11 88746 ARCH 2016-01-02 11:37:11
600 1852 2016-01-02 11:37:11 2016-01-02 11:47:11 73500 ARCH 2016-01-02 11:47:11
600 1853 2016-01-02 11:47:11 2016-01-02 11:57:11 76376 ARCH 2016-01-02 11:57:12
661 1854 2016-01-02 11:57:11 2016-01-02 12:08:12 56820 ARCH 2016-01-02 12:08:12
1800 1855 2016-01-02 12:08:12 2016-01-02 12:38:12 87001 ARCH 2016-01-02 12:38:13
601 1856 2016-01-02 12:38:12 2016-01-02 12:48:13 25307 ARCH 2016-01-02 12:48:13
600 1857 2016-01-02 12:48:13 2016-01-02 12:58:13 20046 ARCH 2016-01-02 12:58:13
901 1858 2016-01-02 12:58:13 2016-01-02 13:13:14 45822 ARCH 2016-01-02 13:13:14
3601 1859 2016-01-02 13:13:14 2016-01-02 14:13:15 151869 ARCH 2016-01-02 14:13:16
1201 1860 2016-01-02 14:13:15 2016-01-02 14:33:16 62884 ARCH 2016-01-02 14:33:16
1140 1861 2016-01-02 14:33:16 2016-01-02 14:52:16 168460 ARCH 2016-01-02 14:52:17
361 1862 2016-01-02 14:52:16 2016-01-02 14:58:17 43611 ARCH 2016-01-02 14:58:17
360 1863 2016-01-02 14:58:17 2016-01-02 15:04:17 33833 ARCH 2016-01-02 15:04:17
51769 1864 2016-01-02 15:04:17 2016-01-03 05:27:06 2617582 ARCH 2016-01-03 05:27:19
--sum(blocks)总量与平时的放假的业务基本相当。多数600秒，当然也有部分360秒切换1次。另外奇怪的是到了15:04:17时间后频繁切换日志的情况消失。
--我检查dg的alert*.log文件，发现存在如下信息，到了2016/01/02 15:07:35 2016 ,alert*.log出现：
Sat Jan 02 15:07:35 2016
Non critical error ORA-48181 caught while writing to trace file "/u01/app/oracle/diag/rdbms/dbcndg2/dbcndg2/trace/dbcndg2_m000_26694.trc"
Error message: Linux-x86_64 Error: 28: No space left on device
Additional information: 1
Writing to the above trace file is disabled for now on...
Sat Jan 02 15:08:35 2016
--到了15:07:35 2016，已经没有空间了。节后检查dg发现磁盘满，当时并没有注意日志的切换问题，整理出磁盘空间后一切ok。
总结自己遇到日志频繁切换的主要因素：
1.CP数量U太多，要设置每个redo大一些，最好1G以上。
2.archive_lag_target参数
3.dg磁盘空间满，也会出现这种情况。
4.网络传输速度慢，这个要进一步测试，在log_archive_dest_N包含SYNC的情况下，有时会出现频繁切换的情况，这个好像在网络从坏到
好的情况时，会出现切换情况，我还要需要一些测试。