Olá,
Uma situação que pode acontecer em um ambiente de banco de dados Oracle é o aumento expressivo no número de dados de "redo" gerados pelo aumento do número de transações ao longo do tempo ou até mesmo por alguma operação isolada. A consequência imediata no número de transações que afetam grandes quantidades de dados é o número excessivo de "redo log switches" ou alternâncias de log gerados um curto espaço de tempo. Em ambientes Oracle que operam em modo ARCHIVELOG a geração excessiva de archive logs por conta de várias operações de alternâncias de log em um curto espaço de tempo pode ocasionar problemas como: espaço livre em disco, tempo de backup, entre outros. Portanto, é importante monitorar a quantidade de redo log switches ocorridas na última hora. Vale a pena salientar que o tamanho do arquivo de redo log online influencia na quantidade de alternâncias de log realizadas.
O cenário abaixo ocorreu em um ambiente de banco de dados com redo log de tamanho de 50 MB no qual o padrão era gerar em média 23 alternância de log por dia, ou seja, cerca de uma alternância por hora. No entanto, foi detectado que a partir do dia 09/05 às 11:00 hs, conforme resultado da consulta abaixo, as operações de redo log switches aumentaram drasticamente gerando cerca de 770 alternâncias por dia. O impacto disso foi um aumento significativo de archive logs gerados, consumindo espaço extra na flash recovery area. Uma vez detectado o problema, foi averiguado que a aplicação tinha sido configurada para fazer mais coisas do que deveria e que, a partir do dia 21/05 às 16:00 hs, as operações de alternância de redo log foram reduzidas significativamente.
SQL> select to_char(first_time,'DD/MM/YYYY') day,
2 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'00',1,0)),'999') "00",
3 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'01',1,0)),'999') "01",
4 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'02',1,0)),'999') "02",
5 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'03',1,0)),'999') "03",
6 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'04',1,0)),'999') "04",
7 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'05',1,0)),'999') "05",
8 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'06',1,0)),'999') "06",
9 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'07',1,0)),'999') "07",
10 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'08',1,0)),'999') "08",
11 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'09',1,0)),'999') "09",
12 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'10',1,0)),'999') "10",
13 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'11',1,0)),'999') "11",
14 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'12',1,0)),'999') "12",
15 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'13',1,0)),'999') "13",
16 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'14',1,0)),'999') "14",
17 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'15',1,0)),'999') "15",
18 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'16',1,0)),'999') "16",
19 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'17',1,0)),'999') "17",
20 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'18',1,0)),'999') "18",
21 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'19',1,0)),'999') "19",
22 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'20',1,0)),'999') "20",
23 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'21',1,0)),'999') "21",
24 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'22',1,0)),'999') "22",
25 to_char(sum(decode(substr(to_char(first_time,'HH24'),1,2),'23',1,0)),'999') "23",
26 sum(1) "TOTAL_IN_DAY"
27 from v$log_history
28 group by to_char(first_time,'DD/MM/YYYY')
29 order by to_date(day) desc;
DAY 00 01 02 03 04 05 06 07 08 09 10 11 12 13 14 15 16 17 18 19 20 21 22 23 TOTAL_IN_DAY
---------- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ------------
21/05/2017 32 32 33 32 34 33 34 32 33 32 32 32 33 31 32 33 5 4 2 0 0 0 0 0 531
20/05/2017 32 32 32 33 33 33 34 33 32 32 35 32 32 33 32 33 32 33 32 32 32 32 33 32 781
19/05/2017 33 32 33 32 32 32 34 33 32 32 34 32 32 32 31 33 32 32 32 34 33 32 33 32 779
18/05/2017 33 32 32 32 32 32 34 33 32 32 33 33 32 33 33 31 32 32 32 33 33 32 32 32 777
17/05/2017 33 32 33 32 33 32 34 32 32 33 32 32 33 32 32 33 32 32 33 32 32 32 33 32 778
16/05/2017 32 32 31 32 32 32 33 32 32 31 32 32 31 32 32 32 32 32 32 33 33 32 33 32 769
15/05/2017 31 32 30 32 33 32 34 31 32 31 33 31 31 32 31 33 32 32 31 32 32 31 34 31 764
14/05/2017 31 32 32 31 33 31 33 31 31 31 33 31 32 31 32 31 32 32 32 32 31 31 33 32 761
13/05/2017 31 31 31 32 31 32 33 32 31 32 32 32 32 31 31 32 32 30 32 31 32 32 33 31 759
12/05/2017 31 31 32 32 31 32 33 31 32 32 32 31 31 32 30 31 32 32 31 33 31 32 32 32 759
11/05/2017 32 31 32 31 32 31 35 31 31 31 34 31 30 31 33 31 32 31 32 32 31 32 33 31 761
10/05/2017 31 31 31 31 34 31 33 32 31 31 32 31 32 31 31 31 31 32 32 32 31 32 32 32 758
09/05/2017 0 1 0 1 2 1 2 1 1 0 2 30 32 32 32 32 32 31 32 32 31 32 34 31 424
08/05/2017 0 1 1 0 3 1 3 0 1 1 1 1 1 1 1 1 1 1 1 2 1 1 2 1 27
07/05/2017 0 1 1 0 3 1 3 0 1 1 1 1 1 1 1 1 1 1 1 2 0 1 2 1 26
06/05/2017 0 1 0 1 1 1 3 0 1 1 2 1 1 1 1 1 1 1 1 2 1 1 2 1 26
05/05/2017 0 1 0 1 0 1 3 1 0 1 2 0 1 0 1 0 1 1 0 3 0 1 1 2 21
04/05/2017 1 0 1 0 1 1 4 1 0 1 2 1 0 1 0 1 1 0 1 2 0 1 2 1 23
03/05/2017 0 1 1 0 3 1 3 1 0 1 2 1 1 1 1 1 1 1 0 2 1 1 2 1 27
02/05/2017 1 1 0 1 3 1 2 1 1 1 2 1 1 1 1 1 2 1 1 1 1 1 2 1 29
01/05/2017 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 1 2 1 5
21 linhas selecionadas.
Durante a análise, foi detectado que havia uma sessão no banco de dados que estava gerando mais dados de UNDO/REDO que as demais, conforme resultado da consulta abaixo.
SQL> SELECT s.sid,
2 s.serial#,
3 s.username,
4 s.program,
5 t.used_ublk,
6 t.used_urec
7 FROM v$session s, v$transaction t
8 WHERE s.taddr = t.addr
9 ORDER BY 5 DESC, 6 DESC, 1, 2, 3, 4;
SID SERIAL# USERNAME PROGRAM USED_UBLK USED_UREC
---------- ---------- ------------------- --------------------- ---------- ----------
930 49433 SCOTT JDBC Thin Client 88 6177
633 53173 SCOTT JDBC Thin Client 10 693
250 58501 ADAM JDBC Thin Client 9 692
99 11223 ADAM JDBC Thin Client 5 340
851 51835 SCOTT JDBC Thin Client 0 0
5 linhas selecionadas.
Outra consulta bastante útil é verificar a quantidade de "redo size" gerada para cada sessão no banco de dados.
SQL> SELECT s.sid,
2 sn.SERIAL#,
3 sn.username,
4 n.name,
5 ROUND (VALUE / 1024 / 1024, 2) redo_mb,
6 sn.status,
7 sn.TYPE
8 FROM v$sesstat s
9 JOIN v$statname n ON n.statistic# = s.statistic#
10 JOIN v$session sn ON sn.sid = s.sid
11 WHERE n.name LIKE 'redo size' AND s.VALUE <> 0
12 ORDER BY redo_mb DESC;
SID SERIAL# USERNAME NAME REDO_MB STATUS TYPE
---------- ---------- ------------------- -------------------- ---------- -------- ----------
848 1 redo size 4397,06 ACTIVE BACKGROUND
771 1 redo size 4367,24 ACTIVE BACKGROUND
1079 1 redo size 2689,53 ACTIVE BACKGROUND
930 49433 SCOTT redo size 838,87 INACTIVE USER
8 18777 SCOTT redo size 115,77 INACTIVE USER
166 59825 SCOTT redo size 172,59 INACTIVE USER
707 52285 ADAM redo size 141,95 INACTIVE USER
622 34283 ADAM redo size 139,28 INACTIVE USER
1004 43893 ADAM redo size 112,61 INACTIVE USER
1009 39717 SCOTT redo size 111,41 INACTIVE USER
249 10097 ADAM redo size 106,07 INACTIVE USER
237 44045 SCOTT redo size 181,37 INACTIVE USER
699 40115 ADAM redo size 174,25 INACTIVE USER
391 58243 ADAM redo size 154,91 INACTIVE USER
14 linhas selecionadas.
Por fim, segue abaixo uma consulta que retorna a porcentagem utilizada do arquivo de redo log online corrente antes de realizar uma operação de alternância de log.
SQL> SELECT le.lenum "Group#",
2 le.leseq "Current log sequence No",
3 ROUND (100 * cp.cpodr_bno / (le.lesiz - 28770), 2) "Percent Full",
4 cp.cpodr_bno "Current Block No",
5 le.lesiz * le.lebsz / 1024 / 1024 "Size of Log in MB"
6 FROM x$kcccp cp, x$kccle le
7 WHERE le.leseq = CP.cpodr_seq AND BITAND (le.leflg, 24) = 8;
Group# Current log sequence No Percent Full Current Block No Size of Log in MB
---------- ----------------------- ------------ ---------------- -----------------
13 253996 37,4 372194 50
1 linha selecionada.
No mais, é recomendável que uma operação de alternância de log ocorra no mínimo a cada 20 ou 25 minutos, ou seja de 4 a 5 redo log switches por hora, caso contrário talvez seja necessário rever o tamanho dos arquivos de redo log online.
6 comentários:
Legatti,
muito bacana o post!
Seguindo a finalidade do post, qual a Redo Log Switch Frequency você acha ideal, 1 por hora, conforme mencionou no caso do post ?
Abs,
Paulo
Olá Paulo,
Uma operação de log switch a cada 20 min ou 25 min é aceitável o que equivale a 4 ou 5 switches por hora. Mais do que isso talvez já seja necessário avaliar o tamanho dos redo log files.
Abraços,
Legatti
Olá Legatti,
Vou começar a monitorar as sessões para detectar o porque do aumento excessivo de archivelog. Nestes dias a empresa migou o protheus da versão 11 para 12 e os archives simplemente deram um salto enorme. Antes gerava cerca de 1,2 Gigas por dia de Archives e agora esta gerando quase 800 Gigas de archives por dia, mesmo o banco tento no maximo 100 Gigas dados e 50 gigas de indices.
Olá Alessandro,
Realmente tem algo estranho aí ;-)
Abraços
Legatti
Caro Eduardo,
Aqui Eduardo também!!!
Duas são minhas observações:
1- O usuário Scott está inativo, mas mesmo assim é o responsável pelo crescimento do log?? Fiquei sem entender!!
2- Estou com problema parecido: Uma instalação ora12c com um banco em produção suportando toda uma solução rodando: WebLogic, Portal, SOA, BPM, BAM,etc. De um tempo para cá cresce de forma explosiva. Está derrubando o banco e, o pior, sem que consigamos identificar a causa, pois ocorre em momento diferentes(dias ou horas), primeiro associamos ao uso, mas ontem ocorreu na madrugada(?).
Alguma dica??? Estamos aumentando os espaços, mas sabemos que há algo errado e lutando para resolver!! Assim, qualquer ajuda, é muito bem vinda!!!
Atenciosamente,
Eduardo Lamarca - RJ
Olá Eduardo,
Uma sessão no Oracle armazena as informações de forma cumulativa enquanto ela estiver conectada, independente dela estar ACTIVE ou INACTIVE. O desafio aí é tentar identificar qual sessão de usuário que está gerando essa massa grande de redos. Caso a sessão conecte faça as transações e desconecte logo em seguida, aí realmente é mais difícil de identificar. Talvez vai ter que criar algum monitoramento específico das sessões no banco e dados.
Abraços,
Legatti
Postar um comentário