Início / dba / Perguntas / 330397
Accepted
Fajela Tajkiya
Asked: 2023-08-18 03:13:40 +0800 CST

O que acontecerá quando a unidade de log do SQL Server estiver cheia?

  • 772

Uma das minhas unidades de arquivo de log do banco de dados de produção foi preenchida e notei as mensagens abaixo no log de erros do SQL Server.

2022-02-13 03:16:24.500 spid72  Error: 9002, Severity: 17, State: 4.
2022-02-13 03:16:24.500 spid72  The transaction log for database 'huge_database' is full due to 'ACTIVE_TRANSACTION'.
2022-02-13 03:16:26.060 spid72  Error: 9002, Severity: 17, State: 4.
2022-02-13 03:16:26.060 spid72  The transaction log for database 'huge_database' is full due to 'ACTIVE_TRANSACTION'.
2022-02-13 03:16:26.070 spid72  Error: 3314, Severity: 21, State: 3.
2022-02-13 03:16:26.070 spid72  During undoing of a logged operation in database 'huge_database', an error occurred at log record ID (2766:550754:254). Typically, the specific failure is logged previously as an error in the Windows Event Log service. Restore the database or file from a backup, or repair the database.
2022-02-13 03:16:26.090 spid72  Database huge_database was shutdown due to error 3314 in routine 'XdesRMReadWrite::RollbackToLsn'. Restart for non-snapshot databases will be attempted after all connections to the database are aborted.
2022-02-13 03:16:26.090 spid72  Error: 3314, Severity: 21, State: 5.
2022-02-13 03:16:26.090 spid72  During undoing of a logged operation in database 'huge_database', an error occurred at log record ID (2678:51796:1). Typically, the specific failure is logged previously as an error in the Windows Event Log service. Restore the database or file from a backup, or repair the database.
2022-02-13 03:16:32.900 spid48s Starting up database 'huge_database'.
2022-02-13 03:16:37.980 spid48s Recovery of database 'huge_database' (20) is 0% complete (approximately 89573 seconds remain). Phase 2 of 3. This is an informational message only. No user action is required.
2022-02-13 03:16:57.980 spid48s Recovery of database 'huge_database' (20) is 0% complete (approximately 60835 seconds remain). Phase 2 of 3. This is an informational message only. No user action is required.
...
2022-02-13 04:26:15.160 spid36s Recovery of database 'huge_database' (20) is 85% complete (approximately 721 seconds remain). Phase 3 of 3. This is an informational message only. No user action is required.
...
2022-02-13 04:36:35.230 spid36s Recovery of database 'huge_database' (20) is 99% complete (approximately 1 seconds remain). Phase 3 of 3. This is an informational message only. No user action is required.
2022-02-13 04:36:35.790 spid36s 1 transactions rolled back in database 'huge_database' (20:0). This is an informational message only. No user action is required.
2022-02-13 04:36:35.790 spid36s Recovery is writing a checkpoint in database 'huge_database' (20). This is an informational message only. No user action is required.
2022-02-13 04:36:36.850 spid36s Recovery completed for database huge_database (database ID 20) in 4804 second(s) (analysis 4881 ms, redo 1196931 ms, undo 3600721 ms.) This is an informational message only. No user action is required.

Parece que a unidade de log do banco de dados está cheia e iniciou um processo de recuperação, que levou mais de uma hora. Por que ele precisa se recuperar neste caso? Eu quero reproduzi-lo, mas não consegui. Abaixo está o meu código:

CREATE DATABASE MyDatabase
ON 
    (NAME = MyDatabase_Data,
    FILENAME = 'f:\mssql\data\MyDatabase_Data.mdf',
    SIZE = 10MB,
    MAXSIZE = 1000MB,
    FILEGROWTH = 5MB)
LOG ON
    (NAME = MyDatabase_Log,
    FILENAME = 'U:\data\MyDatabase_Log.ldf',
    SIZE = 5MB,
    MAXSIZE = 500MB,
    FILEGROWTH = 1MB);
GO

USE MyDatabase;
GO

CREATE TABLE MyTable (
    ID INT IDENTITY(1,1) PRIMARY KEY,
    Data VARCHAR(MAX) NOT NULL
);
GO

BEGIN TRANSACTION;

DECLARE @i INT = 0;
WHILE @i < 1000000
BEGIN
    INSERT INTO MyTable (Data) VALUES (REPLICATE('A', 8000));
    SET @i = @i + 1;
END;

-- Don't commit the transaction
-- COMMIT TRANSACTION;

Quando executo meu código, recebo isso no SSMS:

Msg 9002, Nível 17, Estado 4, Linha 30 O log de transação do banco de dados 'MyDatabase' está cheio devido a 'ACTIVE_TRANSACTION' e o lsn de assalto é (39:24:1).

E isso do log de erros do SQL Server:

2023-08-18 02:59:54.200 spid84  Error: 17053, Severity: 16, State: 1.
2023-08-18 02:59:54.200 spid84  U:\data\MyDatabase_Log.ldf: Operating system error 112(There is not enough space on the disk.) encountered.
2023-08-18 02:59:55.200 spid84  Error: 9002, Severity: 17, State: 4.
2023-08-18 02:59:55.200 spid84  The transaction log for database 'MyDatabase' is full due to 'ACTIVE_TRANSACTION' and the holdup lsn is (39:24:1).

Não há processo de recuperação. Por que? Como imitar meu problema de banco de dados de produção?

Atualizar:

Aliás, durante a recuperação do meu banco de dados de produção, ainda consigo acessá-lo. Ele ainda tem o mesmo status que em outros bancos de dados em sys.databases. Isso é esperado? Embora os bancos de dados em recuperação não estejam acessíveis.

Atualização2:

Ao desfazer uma operação registrada no banco de dados 'huge_database', ocorreu um erro no ID do registro de log (2678:51796:1).

Este log de erro parece que o SQL não reservou espaço suficiente para reverter. Lembrei que Paul Randal disse que o SQL Server sempre reserva algum log para rollback. Se sim, por que isso pode acontecer?

sql-server

1 respostas

  1. Best Answer

    Por que ele precisa se recuperar neste caso?

    Ocorreu um problema ao desfazer uma transação, isso deixa o banco de dados em um estado inconsistente; na verdade, o banco de dados deve ser movido para suspeito. Você pode ver pelo erro que o SQL Server está reiniciando automaticamente.

    2022-02-13 03:16:26.090 spid72  Database huge_database was shutdown due to error 3314 in routine 'XdesRMReadWrite::RollbackToLsn'. Restart for non-snapshot databases will be attempted after all connections to the database are aborted.

    Aliás, durante a recuperação do meu banco de dados de produção, ainda consigo acessá-lo.

    Tanto quanto Dan Guzman afirmou, Enterprise Edition tem "Fast Recovery", que permitirá que o banco de dados seja aberto aos usuários após a conclusão do redo e os bloqueios tenham assumido itens pendentes de desfazer. Você pode ver quando isso ocorreu no log (Fase 1 é Análise, 2 é Refazer, 3 é Desfazer):

    2022-02-13 03:16:57.980 spid48s Recovery of database 'huge_database' (20) is 0% complete (approximately 60835 seconds remain). Phase 2 of 3. This is an informational message only. No user action is required.
...
2022-02-13 04:26:15.160 spid36s Recovery of database 'huge_database' (20) is 85% complete (approximately 721 seconds remain). Phase 3 of 3. This is an informational message only. No user action is required.

    Observe que o "..." em seus dados originais é quando o banco de dados estava disponível, que é algum tempo depois de "2022-02-13 03:16:57.980".

    Não há processo de recuperação. Por que? Como imitar meu problema de banco de dados de produção?

    Você não está atingindo o mesmo problema. No seu exemplo de produção houve uma falha ao desfazer uma alteração, no seu repro não houve falha apenas que o log está cheio.

    Lembrei que Paul Randal disse que o SQL Server sempre reserva algum log para rollback. Se sim, por que isso pode acontecer?

    O gerenciador de log faz uma estimativa de quanto espaço ele precisa reservar por transação, se é muito pouco, muito ou o ideal, não é conhecido no momento. Há, adicionalmente, espaço extra mantido chamado espaço de log "reservado crítico", apenas no caso. Em algumas situações em que não foi mantido log suficiente na reserva e ele transborda, o log pode ficar sem espaço reservado e uma exceção pode ocorrer ao fazer algo, como, por exemplo, reverter uma transação. Não deveria ser uma ocorrência frequente, mas pode acontecer.

    • 3

relate perguntas