Como essas duas reversões do SQL Server são diferentes?

13

No SQL Server 2008 R2, como essas duas reversões são diferentes:

  1. Execute uma ALTERinstrução por alguns minutos e pressione 'Cancelar execução'. Demora alguns minutos para reverter completamente.

  2. Execute a mesma ALTERinstrução, mas verifique se o LDFarquivo não é grande o suficiente para ser concluído com êxito. Depois que o LDFlimite é atingido e nenhum 'crescimento automático' é permitido, a execução da consulta para imediatamente (ou ocorre uma reversão) com esta mensagem de erro:

The statement has been terminated.
Msg 9002, Level 17, State 4, Line 1
The transaction log for database 'SampleDB' is full. 
To find out why space in the log cannot be reused, see the 
log_reuse_wait_desc column in sys.databases

Como esses dois são diferentes nos seguintes pontos?

  1. Por que a segunda reversão é instantânea? Não tenho muita certeza se isso poderia ser chamado de reversão. Meu palpite é que o log de transações é gravado à medida que a execução avança e, quando percebe que não há espaço suficiente para concluir completamente a tarefa, ele apenas para com alguma mensagem 'final', sem confirmação.

  2. O que acontece quando a primeira reversão leva tanto tempo (uma reversão é encadeada única)?
    2.1 O SQL Server volta e desfaz as entradas feitas no LDFarquivo?
    2.2 O LDFtamanho do arquivo fica menor no final da reversão (de DBCC SQLPERF(LOGSPACE))

  3. Uma pergunta adicional: durante o segundo cenário, o SQL Server começa a consumir o LDFarquivo rapidamente. No meu caso, aumentou de 18% para 90% nos primeiros minutos (<4 minutos). Mas uma vez que atingiu 99%, permaneceu por mais 8 minutos, variando o uso entre 99,1% e 99,8%. Ele sobe (99,8%) e desce (99,2%) e sobe novamente (99,7%) e desce (99,5%) algumas vezes antes do erro ser lançado. O que está acontecendo nos bastidores?

Quaisquer links do MSDN que possam ajudar a explicar isso mais são bem-vindos.

Por sugestão de Ali Razeghi, estou adicionando perfmon: Disk Bytes/sec

Cenário 1:

Cenário 1

Cenário 2:

Cenário 2

ToC
fonte
Apenas um comentário rápido: tamanho do arquivo! = Espaço usado em um arquivo.
Aaron Bertrand
@ Aaron Sim, eu estou familiarizado com isso. Eu usei DBCC SQLPERF (LOGSPACE) para medir o uso. O arquivo LDF permaneceu o mesmo durante toda a duração, pois limitei o tamanho do arquivo a 10 GB. O uso interno varia.
ToC
1
Eu suspeito que o segundo rollback aparece instantânea, porque o erro é relatado depois da conclusão do rollback. Estes são provavelmente os 8 minutos que você observa em 3., onde o uso do LDF permanece bastante constante.
mustaccio
@mustaccio Eu concordo com você, mas os artefatos estão apontando em uma direção diferente. Se, de fato, ocorreu a reversão, o uso do arquivo de log deve retornar a um número menor; e não fique em 99,3% quando a mensagem de erro é lançada.
ToC
1
Acredito que a reversão ocupa espaço de log. Quando o log fica cheio durante a reversão, o banco de dados se torna suspeito. Não é mais tocado. Isso parece reversão instantânea, mas a reversão foi adiada até que você possa recuperar o banco de dados online (quando houver espaço em disco disponível) .; Além disso, quando o log ficar cheio, o SQL Server poderá tentar liberar espaço, verificando o que pode explicar picos na atividade de E / S.
usr

Respostas:

1

Como indicado acima, depois de executar mais testes, cheguei a conclusões calculadas. Resumi todos eles em um post do blog aqui , mas copiarei algum conteúdo para este post para posteridade.

Conjectura (com base em alguns testes)

A partir de agora, não tenho uma explicação clara sobre o porquê disso. Mas a seguir, minhas estimativas com base nos artefatos coletados durante os testes.

A reversão ocorre nos dois cenários. Uma é a reversão explícita (o usuário pressiona o botão Cancelar), a outra é implícita (o Sql Server toma essa decisão internamente).

Nos dois cenários, o tráfego que vai para o arquivo de log é consistente. Veja as imagens abaixo:

Cenário 1:

Cenário 1:

Cenário 2:

Cenário 2

  • Um artefato que reforçou essa linha de pensamento é capturar o Sql Trace durante os dois cenários.

    • O cenário 1 é óbvio, ou seja, quando clicamos em 'Cancelar', ele retrocede.
    • No cenário 2, a mensagem de erro é exibida após executar 'rollback' implicitamente. No Sql Trace, vemos a mensagem de erro “O log de transações do banco de dados 'SampleDB' está cheio” muito tempo antes de a mensagem ser exibida na tela. Portanto, meu palpite é que as reversões acontecem nos dois cenários, mas a mensagem de erro é Cenário 2 é exibida após executar a reversão com êxito e completamente.
  • O cenário 2 parece levar mais tempo à medida que progride muito mais, portanto, a reversão leva mais tempo.

Comportamento inexplicável:

  • Por que o uso do arquivo de log varia tanto?
    • Aumenta para 90%, depois diminui para 85%, depois até 99% e fica suspenso por um longo tempo. Vejo subir e descer dessa maneira várias vezes: 99,2%, 99,8%, 99,1%, 99,7%. Por que isso acontece?
    • Uma explicação possível é que, pode haver um processo em segundo plano (algo como Log Flush) que limpa o arquivo de log a cada poucos minutos. E sempre que entra, algumas entradas são limpas, resultando em mais espaço livre disponível.

Todas as idéias para ajudar a explicar melhor esse comportamento são bem-vindas.

ToC
fonte
2
Verificado com Paul Randal, ele confirmou que você chegou à conclusão correta - a reversão é a mesma nos dois casos.
Paul White 9
0

Eu tentei o seguinte experimento e obtive resultados semelhantes. Nos dois casos, o fn_dblog () mostra a reversão e parece ocorrer mais rapidamente no Cenário 2 do que no Cenário 1.

A propósito, coloquei o MDF e o LDF no mesmo disco externo (USB 2.0).

Minha conclusão inicial é que não há diferença na operação de reversão neste caso, e provavelmente qualquer diferença aparente de velocidade está relacionada ao subsistema de E / S. Essa é apenas a minha hipótese de trabalho no momento.

Cenário 1:

  • Crie um banco de dados com um arquivo de log que comece em 1 MB, cresça em pedaços de 4 MB e tenha um tamanho máximo de 100 MB.
  • Abra uma transação explícita, execute-a por 10 segundos e cancele-a manualmente no SSMS
  • Veja o tamanho da reserva fn_dblog () count e log e confira DBCC SQLPERF (LOGSPACE)

Cenário 2:

  • Crie um banco de dados com um arquivo de log que comece em 1 MB, cresça em pedaços de 4 MB e tenha um tamanho máximo de 100 MB.
  • Abra uma transação explícita, execute-a até o erro completo do log aparecer
  • Veja o tamanho da reserva fn_dblog () count e log e confira DBCC SQLPERF (LOGSPACE)

Resultados do Monitor de Desempenho:

Cenário 1: ***Cenário 1***

Cenário 2: *** Cenário 2 ***

Código:

USE [mestre];
IR

SE DATABASEPROPERTYEX (N'SampleDB ', N'Version')> 0
INÍCIO
    ALTER DATABASE [SampleDB] SET SINGLE_USER
        COM ROLLBACK IMEDIATO;
    DROP DATABASE [SampleDB];
FIM;
IR

CRIAR BASE DE DADOS [SampleDB] NO PRIMÁRIO 
( 
      NAME = N'SampleDB '
    , FILENAME = N'E: \ data \ SampleDB.mdf ' 
    , SIZE = 3MB 
    , FILEGROWTH = 1MB 
)
ENTRAR 
( 
      NAME = N'SampleDB_log '
    , FILENAME = N'E: \ data \ SampleDB_log.ldf '
    , SIZE = 1MB 
    , MAXSIZE = 100 MB 
    , FILEGROWTH = 4MB 
);
IR

USE [SampleDB];
IR

- Adicione uma tabela
CRIAR TABELA dbo.test
(
    c1 CHAR (8000) NÃO NULL REPLICATE PADRÃO ('a', 8000)
) ON [PRIMÁRIO];
IR

- Garantir que não somos é um modelo de recuperação pseudo-simples
BACKUP DATABASE SampleDB
PARA DISCO = 'NUL';
IR

- Faça backup do arquivo de log
LOG DE BACKUP SampleDB
PARA DISCO = 'NUL';
IR

- Verifique o espaço de log usado
DBCC SQLPERF (LOGSPACE);
IR

- Quantos registros são visíveis com fn_dblog ()?
SELECT * FROM fn_dblog (NULL, NULL); - Cerca de 9 no meu caso

/ **********************************
             CENÁRIO 1
********************************** /
- Abra uma nova transação e reverta-a
COMEÇAR A TRANSAÇÃO

    INSERIR EM dbo.test VALORES PADRÃO;
    GO 10000 - Let é executado por 10 segundos e pressione Cancel na janela de consulta do SSMS

    - Cancelar a transação
    - Demora alguns segundos para terminar


- Não há necessidade de reverter a transação, pois o cancelamento já fez isso por você.
-- Apenas tente. Você receberá este erro
- Msg 3903, Nível 16, Estado 1, Linha 1
- A solicitação ROLLBACK TRANSACTION não tem BEGIN TRANSACTION correspondente.
TRANSAÇÃO ROLLBACK;

- Qual é o espaço de log usado? Acima de 100%.
DBCC SQLPERF (LOGSPACE);
IR

- Quantos registros são visíveis com fn_dblog ()?
SELECT * 
FROM fn_dblog (NULL, NULL); - Cerca de 91.926 no meu caso

- Reserva total de log mostrada por fn_dblog ()?
SELECIONAR SOMA ([Reserva de Log]) AS [Reserva Total de Log]
FROM fn_dblog (NULL, NULL); - Cerca de 88,72MB


/ **********************************
             CENÁRIO 2
********************************** /
- Afaste o banco de dados e comece de novo
USE [mestre];
IR

SE DATABASEPROPERTYEX (N'SampleDB ', N'Version')> 0
INÍCIO
    ALTER DATABASE [SampleDB] SET SINGLE_USER
        COM ROLLBACK IMEDIATO;
    DROP DATABASE [SampleDB];
FIM;
IR

CRIAR BASE DE DADOS [SampleDB] NO PRIMÁRIO 
( 
      NAME = N'SampleDB '
    , FILENAME = N'E: \ data \ SampleDB.mdf ' 
    , SIZE = 3MB 
    , FILEGROWTH = 1MB 
)
ENTRAR 
( 
      NAME = N'SampleDB_log '
    , FILENAME = N'E: \ data \ SampleDB_log.ldf '
    , SIZE = 1MB 
    , MAXSIZE = 100 MB 
    , FILEGROWTH = 4MB 
);
IR

USE [SampleDB];
IR

- Adicione uma tabela
CRIAR TABELA dbo.test
(
    c1 CHAR (8000) NÃO NULL REPLICATE PADRÃO ('a', 8000)
) ON [PRIMÁRIO];
IR

- Garantir que não somos é um modelo de recuperação pseudo-simples
BACKUP DATABASE SampleDB
PARA DISCO = 'NUL';
IR

- Faça backup do arquivo de log
LOG DE BACKUP SampleDB
PARA DISCO = 'NUL';
IR

- Agora, vamos explodir o arquivo de log dentro de nossa transação
COMEÇAR A TRANSAÇÃO
    INSERIR EM dbo.test VALORES PADRÃO;
    GO 10000

- A reversão nunca é acionada. Tente. Você receberá um erro.
- Msg 3903, Nível 16, Estado 1, Linha 1
- A solicitação ROLLBACK TRANSACTION não tem BEGIN TRANSACTION correspondente.
TRANSAÇÃO ROLLBACK;

- O arquivo de log está 100% cheio? 
DBCC SQLPERF (LOGSPACE);

- Quantos registros são visíveis com fn_dblog ()?
SELECT * 
FROM fn_dblog (NULL, NULL); - Cerca de 91.926 no meu caso
IR

- Reserva total de log mostrada por fn_dblog ()?
SELECIONAR SOMA ([Reserva de Log]) AS [Reserva Total de Log]
FROM fn_dblog (NULL, NULL); - 88,72MB
IR
ooutwire
fonte
Obrigado pelos testes detalhados. Depois de executar mais testes, cheguei a uma conclusão semelhante. Então, escrevi uma postagem no blog . Para mim Cenário 2 leva mais tempo para reverter porque a quantidade de trabalho realizado no Cenário 2, antes Sql Server percebe a necessidade de reversão é mais do que o Cenário 1.
TOC