SQL Server Parallel Redo – Understanding Messages

availability-groupssql serversql-server-2017sql-server-express

Parallel redo is shutdown for database '' with worker pool size [2].

Parallel redo is started for database '' with worker pool size [2].

Starting up database ''

I see this on a client PC a lot in the Windows Event Viewer (Event Id 49930 or 17137). This is a regular Windows PC, not a server, with a default instance of SQL Server 2017 Express Edition and SSMS.

What is that parallel redo?

Here's the output from the error log:

2019-05-28 12:23:03.360 spid16s A self-generated certificate was successfully loaded for encryption.
2019-05-28 12:23:03.360 spid16s Server is listening on [ 'any' <ipv6> 1433].
2019-05-28 12:23:03.360 spid16s Server is listening on [ 'any' <ipv4> 1433].
2019-05-28 12:23:03.360 spid16s Server is listening on [ 'any' <ipv6> 50374].
2019-05-28 12:23:03.360 spid16s Server is listening on [ 'any' <ipv4> 50374].
2019-05-28 12:23:03.360 spid16s Server local connection provider is ready to accept connection on [ \\.\pipe\SQLLocal\FOLLOWIN ].
2019-05-28 12:23:03.360 spid16s Server named pipe provider is ready to accept connection on [ \\.\pipe\MSSQL$FOLLOWIN\sql\query ].
2019-05-28 12:23:03.360 spid16s Dedicated administrator connection support was not started because it is disabled on this edition of SQL Server. If you want to use a dedicated administrator connection, restart SQL Server using the trace flag 7806. This is an informational message only. No user action is required.
2019-05-28 12:23:03.360 Server  SQL Server is attempting to register a Service Principal Name (SPN) for the SQL Server service. Kerberos authentication will not be possible until a SPN is registered for the SQL Server service. This is an informational message. No user action is required.
2019-05-28 12:23:03.360 spid16s SQL Server is now ready for client connections. This is an informational message; no user action is required.
2019-05-28 12:23:03.370 Server  The SQL Server Network Interface library could not register the Service Principal Name (SPN) [ MSSQLSvc/pcFoo:FOLLOWIN ] for the SQL Server service. Windows return code: 0xffffffff, state: 63. Failure to register a SPN might cause integrated authentication to use NTLM instead of Kerberos. This is an informational message. Further action is only required if Kerberos authentication is required by authentication policies and if the SPN has not been manually registered.
2019-05-28 12:23:03.370 Server  The SQL Server Network Interface library could not register the Service Principal Name (SPN) [ MSSQLSvc/pcFoo:1433 ] for the SQL Server service. Windows return code: 0xffffffff, state: 63. Failure to register a SPN might cause integrated authentication to use NTLM instead of Kerberos. This is an informational message. Further action is only required if Kerberos authentication is required by authentication policies and if the SPN has not been manually registered.
2019-05-28 12:23:03.430 spid17s A new instance of the full-text filter daemon host process has been successfully started.
2019-05-28 12:23:03.520 spid12s Starting up database 'mssqlsystemresource'.
2019-05-28 12:23:03.520 spid21s Starting up database 'Foobar'.
2019-05-28 12:23:03.520 spid20s Starting up database 'msdb'.
2019-05-28 12:23:03.530 spid12s The resource database build version is 14.00.3162. This is an informational message only. No user action is required.
2019-05-28 12:23:03.550 spid12s Synchronize Database 'master' (1) with Resource Database.
2019-05-28 12:23:03.550 spid21s Parallel redo is started for database 'Foobar' with worker pool size [2].
2019-05-28 12:23:03.560 spid12s Starting up database 'model'.
2019-05-28 12:23:03.560 spid21s Parallel redo is shutdown for database 'Foobar' with worker pool size [2].
2019-05-28 12:23:03.580 spid12s Synchronize Database 'model' (3) with Resource Database.
2019-05-28 12:23:03.590 spid12s Polybase feature disabled.
2019-05-28 12:23:03.590 spid12s Clearing tempdb database.
2019-05-28 12:23:03.670 spid12s Starting up database 'tempdb'.
2019-05-28 12:23:03.710 spid20s Synchronize Database 'msdb' (4) with Resource Database.
2019-05-28 12:23:03.710 spid21s Synchronize Database 'Foobar' (5) with Resource Database.
2019-05-28 12:23:03.710 spid22s The Service Broker endpoint is in disabled or stopped state.
2019-05-28 12:23:03.710 spid22s The Database Mirroring endpoint is in disabled or stopped state.
2019-05-28 12:23:03.730 spid22s Service Broker manager has started.
2019-05-28 12:23:03.730 spid6s  Recovery is complete. This is an informational message only. No user action is required.
2019-05-28 12:28:21.180 spid51  Attempting to load library 'xplog70.dll' into memory. This is an informational message only. No user action is required.
2019-05-28 12:28:21.180 spid51  Using 'xplog70.dll' version '2017.140.3162' to execute extended stored procedure 'xp_msver'. This is an informational message only; no user action is required.
2019-05-28 12:28:21.320 spid51  Starting up database 'Foobar'.
2019-05-28 12:28:21.340 spid51  Parallel redo is started for database 'Foobar' with worker pool size [2].
2019-05-28 12:28:21.350 spid51  Parallel redo is shutdown for database 'Foobar' with worker pool size [2].
2019-05-28 12:28:21.360 spid51  Starting up database 'Foo'.
2019-05-28 12:28:21.380 spid51  Parallel redo is started for database 'Foo' with worker pool size [2].
2019-05-28 12:28:21.400 spid51  Parallel redo is shutdown for database 'Foo' with worker pool size [2].
2019-05-28 12:28:21.410 spid51  Synchronize Database 'Foo' (6) with Resource Database.
2019-05-28 14:27:21.430 spid59  Starting up database 'Foo'.
2019-05-28 14:27:21.450 spid59  Parallel redo is started for database 'Foo' with worker pool size [2].
2019-05-28 14:27:21.470 spid59  Parallel redo is shutdown for database 'Foo' with worker pool size [2].
2019-05-28 14:27:21.480 spid59  Starting up database 'Foobar'.
2019-05-28 14:27:21.500 spid59  Parallel redo is started for database 'Foobar' with worker pool size [2].
2019-05-28 14:27:21.510 spid59  Parallel redo is shutdown for database 'Foobar' with worker pool size [2].
2019-05-28 14:27:38.330 spid59  Starting up database 'Foobar'.
2019-05-28 14:27:38.360 spid59  Parallel redo is started for database 'Foobar' with worker pool size [2].
2019-05-28 14:27:38.370 spid59  Parallel redo is shutdown for database 'Foobar' with worker pool size [2].
2019-05-28 14:27:40.010 spid59  Starting up database 'Foo'.
2019-05-28 14:27:40.050 spid59  Parallel redo is started for database 'Foo' with worker pool size [2].
2019-05-28 14:27:40.080 spid59  Parallel redo is shutdown for database 'Foo' with worker pool size [2].
2019-05-28 14:28:04.160 spid59  Starting up database 'Foo'.
2019-05-28 14:28:04.180 spid59  Parallel redo is started for database 'Foo' with worker pool size [2].
2019-05-28 14:28:04.210 spid59  Parallel redo is shutdown for database 'Foo' with worker pool size [2].
2019-05-28 14:28:10.620 spid52  Attempting to load library 'xpstar.dll' into memory. This is an informational message only. No user action is required.
2019-05-28 14:28:10.690 spid52  Using 'xpstar.dll' version '2017.140.3162' to execute extended stored procedure 'xp_instance_regread'. This is an informational message only; no user action is required.
2019-05-28 14:28:14.220 spid52  Starting up database 'Foo'.
2019-05-28 14:28:14.240 spid52  Parallel redo is started for database 'Foo' with worker pool size [2].
2019-05-28 14:28:14.270 spid52  Parallel redo is shutdown for database 'Foo' with worker pool size [2].
2019-05-28 14:28:14.410 Backup  Database backed up. Database: Foo, creation date(time): 2019/05/08(15:06:00), pages dumped: 2555, first LSN: 48:9778:37, last LSN: 48:9795:1, number of dump devices: 1, device information: (FILE=2, TYPE=DISK: {'C:\Users\Joe\Documents\Backup Followin\Foo_FULL_05272019_235209.BAK'}). This is an informational message only. No user action is required.
2019-05-28 14:28:14.420 Backup  BACKUP DATABASE successfully processed 2546 pages in 0.112 seconds (177.529 MB/sec).
2019-05-28 14:28:19.120 spid53  Starting up database 'Foo'.
2019-05-28 14:28:19.140 spid53  Parallel redo is started for database 'Foo' with worker pool size [2].
2019-05-28 14:28:19.160 spid53  Parallel redo is shutdown for database 'Foo' with worker pool size [2].
2019-05-28 14:28:20.610 spid59  Starting up database 'Foo'.
2019-05-28 14:28:20.650 spid59  Parallel redo is started for database 'Foo' with worker pool size [2].
2019-05-28 14:28:20.670 spid59  Parallel redo is shutdown for database 'Foo' with worker pool size [2].
2019-05-28 14:28:31.030 spid54  Using 'dbghelp.dll' version '4.0.5'

0.3162.1 (X64)

May 15 2019 19:14:30

Copyright (C) 2017 Microsoft Corporation

Express Edition (64-bit) on Windows 10 Pro 10.0 <X64> (Build 17763: )

Best Answer

This is an informational log message added in SQL Server 2017 related to parallel redo for Availability Groups:

SQL Server 2016/2017: Availability group secondary replica redo model and performance

The behavior you're seeing (where redo starts and immediately stops) is normal. It's because the databases aren't participating in an Availability Group. When a database starts up, the parallel redo threads for that database start, then realize there is no availability group, then shut down.

You can prove this by turning on documented and supported global trace flag 3459 to disable parallel redo, then offlining and onlining a database. You will no longer see those messages.

See the screenshot of my error log.

I enabled the trace flag, off / onlined the database: no messages

I disabled the trace flag, off / onlined the database: messages returned

enter image description here

Unless you turn on that trace flag, you'll see those messages anytime a database is brought online (either because the server restarted, or the database was specifically brought offline and then back online, and probably other similar situations). However, they are not an indication of a problem.

If your database is participating in an AG, and you see these "redo is shutdown" messages throughout the day, it might be because AUTO_CLOSE is turned on (the default for user databases on Express Edition). Consider changing that setting to off, which is generally considered to be a "best practice:"

ALTER DATABASE YourDatabaseName SET AUTO_CLOSE OFF;

NOTE: these messages are NOT related to the "redo" portion of crash recovery that occurs on database startup.