Encryption, Trace Flags

Pause and Resume Transparent Data Encryption (TDE) in SQL Server

Transparent Data Encryption (TDE) was originally introduced in SQL Server 2008 (Enterprise Edition) with a goal to protect SQL Server data at rest. In other words, the physical data and log files along with the database backup sitting on file system are protected (encrypted).

Few things to be aware of when implementing TDE:

With TDE, The data transmitted over the network is not encrypted and the data at the object level remains unencrypted. In other words, if a user has select access to a table(s) within the TDE enabled database, he/she will be able to read data with simple select statements, as the name suggests, it’s transparent. TDE does not protect FILESTREAM data and any files related to Buffer Pool Extension (BPE) are not encrypted as well, you should use file system encryption tools like windows Bit-locker or any other third party tools for this purpose. Another caveat is TDE doesn’t support Instant File Initialization for database files. Also, when TDE is enabled on a user database your tempdb database gets encrypted behind the scenes.

Okay, let’s move on to our topic. In this article, we will see how to monitor and manage TDE progress, not essentially how to setup TDE on a user database. Before moving on to our main topic, here is a quick refresher on how Transparent Data Encryption works.

Image Source

Enabling TDE on a given database is a very straightforward process. 20,000-foot view of the process is basically creating a DMK (Master DB) which is protected by Service Master Key, Cert (Master DB), DEK (User DB) and enable TDE(User DB) and you are done. But things get little tricky when you are dealing with VLDBs. What if you have a ginormous database (Let’s say a 30 TeraBytes monster) on which you have to enable TDE? Enabling TDE is not instantaneous, the SQL Server Encryption Scanner has to read all the underlying database pages and encrypt them, For a 30 TB database it might take multiple days for SQL Server to encrypt the entire database and we as DBAs should monitor the encryption progress making sure there are no side effects. In this context I am not talking about server resources, I am talking about the impact on the transaction log file when encryption scanner is in progress. So, why should we worry about LDF file when TDE scanner is in progress? Well, SQL Server doesn’t truncate the transaction log file of your database when TDE Encryption Scanner is doing its job. Things get more complicated if you are not allowed to run TDE during business hours and let’s say you have nightly ETL loads or some other scheduled job(s) which generates a considerable amount of log records. In this article, let’s see how to monitor TDE progress and how to manage transaction log when TDE scanner is in progress.

Further reading : Monitoring/Managing TDE

Advertisements
SQL Server 2008/20008R2, Trace Flags

SQL Server CheckPoints – Trace Flag 3502

Checkpoint – One of the wonderful mechanisms baked within SQL Server to Flush Dirty Pages to Disk and to clear Transaction log(When a Database is Set to SIMPLE Recovery Model) automatically.

Few scenarios where CHECKPOINTS are triggered automatically:

When SQL Instance has been Shutdown, a checkpoint on all the databases.

A Checkpoint on Model Database each time a new database has been created.

T-Log 70% full and Database is in Simple Recovery Model.

A Manual CHECKPOINT by a Sysadmin or Database Owner/Backup Operator.

So…Is there any easy way to monitor the occurrences of Checkpoint??

Yes…We’ve a Documented Trace Flag 3502 which can be enabled Globally.

Demo: Scenario 1 – Shutting Down SQL Instance

I’ve enabled 3502 Traceflag and shut down my SQL Instance. See the Error Log contents below.

2011-09-19 22:12:08.200 spid52 Microsoft SQL Server 2008 R2 (SP1) – 10.50.2425.0 (X64)
Apr 6 2011 21:03:25
Copyright (c) Microsoft Corporation
Developer Edition (64-bit) on Windows NT 6.1 <X64> (Build 7601: Service Pack 1)
2011-09-19 22:12:08.210 spid52 (c) Microsoft Corporation.
2011-09-19 22:12:08.210 spid52 All rights reserved.
2011-09-19 22:12:08.210 spid52 Server process ID is 1968.
2011-09-19 22:12:08.210 spid52 System Manufacturer: ‘Dell Inc.’, System Model: ‘Studio 1555’.
2011-09-19 22:12:08.210 spid52 Authentication mode is MIXED.
2011-09-19 22:12:08.220 spid52 Logging SQL Server messages in file ‘C:\Program Files\Microsoft SQL Server\MSSQL10_50.PROD\MSSQL\Log\ERRORLOG’.
2011-09-19 22:12:08.220 spid52 The error log has been reinitialized. See the previous log for older entries.
2011-09-19 22:12:29.830 spid52 DBCC TRACEON 3502, server process ID (SPID) 52. This is an informational message only; no user action is required.
2011-09-19 22:13:09.050 spid7s Checkpointing and truncating dbid 1 (master).
2011-09-19 22:13:09.060 spid7s Ckpt dbid 1 started (8)
2011-09-19 22:13:09.060 spid7s About to log Checkpoint begin.
2011-09-19 22:13:09.100 spid7s Ckpt dbid 1 phase 1 ended (8)
2011-09-19 22:13:09.130 spid7s About to log Checkpoint end.
2011-09-19 22:13:09.140 spid7s Ckpt dbid 1 complete
2011-09-19 22:13:09.140 spid7s Checkpointing and truncating dbid 2 (tempdb).
2011-09-19 22:13:09.140 spid7s About to log Checkpoint begin.
2011-09-19 22:13:09.160 spid7s About to log Checkpoint end.
2011-09-19 22:13:09.200 spid7s No checkpoint needed on dbid 3 (model).
2011-09-19 22:13:09.200 spid7s Checkpointing and truncating dbid 4 (msdb).
2011-09-19 22:13:09.220 spid7s Ckpt dbid 4 started (8)
2011-09-19 22:13:09.220 spid7s About to log Checkpoint begin.
2011-09-19 22:13:09.220 spid7s Ckpt dbid 4 phase 1 ended (8)
2011-09-19 22:13:09.260 spid7s About to log Checkpoint end.
2011-09-19 22:13:09.310 spid7s Ckpt dbid 4 complete
2011-09-19 22:13:09.350 spid7s No checkpoint needed on dbid 5 (LiteSpeedLocal).
2011-09-19 22:13:09.360 spid7s No checkpoint needed on dbid 6 (LiteSpeedCentral).
2011-09-19 22:13:09.730 spid7s No checkpoint needed on dbid 8 (AdventureWorksDW2008R2).
2011-09-19 22:13:09.780 spid7s No checkpoint needed on dbid 9 (AdventureWorksLT2008R2).
2011-09-19 22:13:09.910 spid7s Checkpointing and truncating dbid 10 (AdventureWorks).
2011-09-19 22:13:09.910 spid7s Ckpt dbid 10 started (8)
2011-09-19 22:13:09.930 spid7s About to log Checkpoint begin.
2011-09-19 22:13:09.930 spid7s Ckpt dbid 10 phase 1 ended (8)
2011-09-19 22:13:09.930 spid7s About to log Checkpoint end.
2011-09-19 22:13:09.980 spid7s Ckpt dbid 10 complete
2011-09-19 22:13:10.000 spid7s No checkpoint needed on dbid 11 (AdventureWorksDW).
2011-09-19 22:13:10.030 spid7s Checkpointing and truncating dbid 12 (AdventureWorksLT).
2011-09-19 22:13:10.030 spid7s Ckpt dbid 12 started (8)
2011-09-19 22:13:10.060 spid7s About to log Checkpoint begin.
2011-09-19 22:13:10.070 spid7s Ckpt dbid 12 phase 1 ended (8)
2011-09-19 22:13:10.070 spid7s About to log Checkpoint end.
2011-09-19 22:13:10.120 spid7s Ckpt dbid 12 complete
2011-09-19 22:13:10.150 spid7s Checkpointing and truncating dbid 13 (AdventureWorks_11).
2011-09-19 22:13:10.150 spid7s Ckpt dbid 13 started (8)
2011-09-19 22:13:10.150 spid7s About to log Checkpoint begin.
2011-09-19 22:13:10.170 spid7s Ckpt dbid 13 phase 1 ended (8)
2011-09-19 22:13:10.170 spid7s About to log Checkpoint end.
2011-09-19 22:13:10.210 spid7s Ckpt dbid 13 complete
2011-09-19 22:13:10.220 spid7s Checkpointing and truncating dbid 14 (AdventureWorks_tstst).
2011-09-19 22:13:10.220 spid7s Ckpt dbid 14 started (8)
2011-09-19 22:13:10.230 spid7s About to log Checkpoint begin.
2011-09-19 22:13:10.230 spid7s Ckpt dbid 14 phase 1 ended (8)
2011-09-19 22:13:10.240 spid7s About to log Checkpoint end.
2011-09-19 22:13:10.280 spid7s Ckpt dbid 14 complete
2011-09-19 22:13:10.300 spid7s No checkpoint needed on dbid 15 (AdventureWorks_testst).
2011-09-19 22:13:10.320 spid7s No checkpoint needed on dbid 16 (tstrestore).
2011-09-19 22:13:10.350 spid7s Checkpointing and truncating dbid 17 (ReportServer).
2011-09-19 22:13:10.350 spid7s Ckpt dbid 17 started (8)
2011-09-19 22:13:10.350 spid7s About to log Checkpoint begin.
2011-09-19 22:13:10.370 spid7s Ckpt dbid 17 phase 1 ended (8)
2011-09-19 22:13:10.370 spid7s About to log Checkpoint end.
2011-09-19 22:13:10.420 spid7s Ckpt dbid 17 complete
2011-09-19 22:13:10.450 spid7s Checkpointing and truncating dbid 18 (ReportServerTempDB).
2011-09-19 22:13:10.450 spid7s Ckpt dbid 18 started (8)
2011-09-19 22:13:10.480 spid7s About to log Checkpoint begin.
2011-09-19 22:13:10.500 spid7s Ckpt dbid 18 phase 1 ended (8)
2011-09-19 22:13:10.500 spid7s About to log Checkpoint end.
2011-09-19 22:13:10.550 spid7s Ckpt dbid 18 complete
2011-09-19 22:13:10.570 spid7s Checkpointing and truncating dbid 19 (3014_demo).
2011-09-19 22:13:10.570 spid7s Ckpt dbid 19 started (8)
2011-09-19 22:13:10.580 spid7s About to log Checkpoint begin.
2011-09-19 22:13:10.590 spid7s Ckpt dbid 19 phase 1 ended (8)
2011-09-19 22:13:10.600 spid7s About to log Checkpoint end.
2011-09-19 22:13:10.630 spid7s Ckpt dbid 19 complete
2011-09-19 22:13:10.630 spid7s Checkpointing and truncating dbid 32767 (mssqlsystemresource).
2011-09-19 22:13:11.160 spid14s Service Broker manager has shut down.
2011-09-19 22:13:11.250 spid7s Skipping CleanShutdownDB() checkpoint on dbid 19 (3014_demo) with 0 freedOutcomes.
2011-09-19 22:13:11.640 spid7s Skipping CleanShutdownDB() checkpoint on dbid 18 (ReportServerTempDB) with 0 freedOutcomes.
2011-09-19 22:13:11.740 spid7s Skipping CleanShutdownDB() checkpoint on dbid 17 (ReportServer) with 0 freedOutcomes.
2011-09-19 22:13:11.850 spid7s Ckpt dbid 16 started (8)
2011-09-19 22:13:11.850 spid7s About to log Checkpoint begin.
2011-09-19 22:13:11.870 spid7s Ckpt dbid 16 phase 1 ended (8)
2011-09-19 22:13:11.890 spid7s About to log Checkpoint end.
2011-09-19 22:13:11.920 spid7s Ckpt dbid 16 complete
2011-09-19 22:13:12.050 spid7s Skipping CleanShutdownDB() checkpoint on dbid 15 (AdventureWorks_testst) with 0 freedOutcomes.
2011-09-19 22:13:12.180 spid7s Skipping CleanShutdownDB() checkpoint on dbid 14 (AdventureWorks_tstst) with 0 freedOutcomes.
2011-09-19 22:13:12.280 spid7s Skipping CleanShutdownDB() checkpoint on dbid 13 (AdventureWorks_11) with 0 freedOutcomes.
2011-09-19 22:13:12.390 spid7s Skipping CleanShutdownDB() checkpoint on dbid 12 (AdventureWorksLT) with 0 freedOutcomes.
2011-09-19 22:13:12.480 spid7s Ckpt dbid 11 started (8)
2011-09-19 22:13:12.480 spid7s About to log Checkpoint begin.
2011-09-19 22:13:12.510 spid7s Ckpt dbid 11 phase 1 ended (8)
2011-09-19 22:13:12.530 spid7s About to log Checkpoint end.
2011-09-19 22:13:12.560 spid7s Ckpt dbid 11 complete
2011-09-19 22:13:12.690 spid7s Skipping CleanShutdownDB() checkpoint on dbid 10 (AdventureWorks) with 0 freedOutcomes.
2011-09-19 22:13:12.860 spid7s Ckpt dbid 9 started (8)
2011-09-19 22:13:12.860 spid7s About to log Checkpoint begin.
2011-09-19 22:13:12.900 spid7s Ckpt dbid 9 phase 1 ended (8)
2011-09-19 22:13:12.920 spid7s About to log Checkpoint end.
2011-09-19 22:13:12.950 spid7s Ckpt dbid 9 complete
2011-09-19 22:13:13.180 spid7s Ckpt dbid 8 started (8)
2011-09-19 22:13:13.180 spid7s About to log Checkpoint begin.
2011-09-19 22:13:13.200 spid7s Ckpt dbid 8 phase 1 ended (8)
2011-09-19 22:13:13.220 spid7s About to log Checkpoint end.
2011-09-19 22:13:13.270 spid7s Ckpt dbid 8 complete
2011-09-19 22:13:13.410 spid7s Ckpt dbid 6 started (8)
2011-09-19 22:13:13.410 spid7s About to log Checkpoint begin.
2011-09-19 22:13:13.460 spid7s Ckpt dbid 6 phase 1 ended (8)
2011-09-19 22:13:13.480 spid7s About to log Checkpoint end.
2011-09-19 22:13:13.510 spid7s Ckpt dbid 6 complete
2011-09-19 22:13:13.640 spid7s Ckpt dbid 5 started (8)
2011-09-19 22:13:13.640 spid7s About to log Checkpoint begin.
2011-09-19 22:13:13.660 spid7s Ckpt dbid 5 phase 1 ended (8)
2011-09-19 22:13:13.670 spid7s About to log Checkpoint end.
2011-09-19 22:13:13.710 spid7s Ckpt dbid 5 complete
2011-09-19 22:13:13.880 spid7s Ckpt dbid 4 started (8)
2011-09-19 22:13:13.880 spid7s About to log Checkpoint begin.
2011-09-19 22:13:13.880 spid7s Ckpt dbid 4 phase 1 ended (8)
2011-09-19 22:13:13.890 spid7s About to log Checkpoint end.
2011-09-19 22:13:13.890 spid7s Ckpt dbid 4 complete
2011-09-19 22:13:14.000 spid7s Skipping CleanShutdownDB() checkpoint on dbid 3 (model) with 0 freedOutcomes.
2011-09-19 22:13:14.140 spid7s Ckpt dbid 1 started (8)
2011-09-19 22:13:14.140 spid7s About to log Checkpoint begin.
2011-09-19 22:13:14.140 spid7s Ckpt dbid 1 phase 1 ended (8)
2011-09-19 22:13:14.140 spid7s About to log Checkpoint end.
2011-09-19 22:13:14.140 spid7s Ckpt dbid 1 complete
2011-09-19 22:13:14.140 spid7s SQL Server is terminating in response to a ‘stop’ request from Service Control Manager. This is an informational message only. No user action is required.
2011-09-19 22:13:14.180 spid7s SQL Trace was stopped due to server shutdown. Trace ID = ‘1’. This is an informational message only; no user action is required.
Sooo….SQL Server is making sure that a CHECKPOINT is issued on all the Databases as mentioned above before Shutting down the SQL Instance.( Which plays a huge and a very critical role in crash recovery when SQL Instance has been started)

Scenario 2- Creating a new User Database:

I’ve created a Database called “Checkpoint_tst”. See the Error Log contents below.

2011-09-19 22:18:58.020 spid53 Microsoft SQL Server 2008 R2 (SP1) – 10.50.2425.0 (X64)
Apr 6 2011 21:03:25
Copyright (c) Microsoft Corporation
Developer Edition (64-bit) on Windows NT 6.1 <X64> (Build 7601: Service Pack 1)
2011-09-19 22:18:58.020 spid53 (c) Microsoft Corporation.
2011-09-19 22:18:58.020 spid53 All rights reserved.
2011-09-19 22:18:58.020 spid53 Server process ID is 9120.
2011-09-19 22:18:58.020 spid53 System Manufacturer: ‘Dell Inc.’, System Model: ‘Studio 1555’.
2011-09-19 22:18:58.020 spid53 Authentication mode is MIXED.
2011-09-19 22:18:58.020 spid53 Logging SQL Server messages in file ‘C:\Program Files\Microsoft SQL Server\MSSQL10_50.PROD\MSSQL\Log\ERRORLOG’.
2011-09-19 22:18:58.020 spid53 The error log has been reinitialized. See the previous log for older entries.
2011-09-19 22:18:58.020 spid53 DBCC TRACEON 3502, server process ID (SPID) 53. This is an informational message only; no user action is required.
2011-09-19 22:20:11.500 spid53 Ckpt dbid 3 started (8)
2011-09-19 22:20:11.500 spid53 About to log Checkpoint begin.
2011-09-19 22:20:11.510 spid53 Ckpt dbid 3 phase 1 ended (8)
2011-09-19 22:20:11.510 spid53 About to log Checkpoint end.
2011-09-19 22:20:11.520 spid53 Ckpt dbid 3 complete
2011-09-19 22:20:11.790 spid53 Starting up database ‘checkpoint_tst’.
2011-09-19 22:20:11.840 spid53 Ckpt dbid 20 started (0)
2011-09-19 22:20:11.840 spid53 About to log Checkpoint begin.
2011-09-19 22:20:11.840 spid53 Ckpt dbid 20 phase 1 ended (0)
2011-09-19 22:20:11.840 spid53 About to log Checkpoint end.
2011-09-19 22:20:11.840 spid53 Ckpt dbid 20 complete
2011-09-19 22:20:55.860 spid11s About to log Checkpoint begin.
2011-09-19 22:20:55.870 spid11s About to log Checkpoint end.

(22 row(s) affected)

dbid= 3 is MODEL Database. You can pull that info by

select name,database_id from sys.databases
where database_id = 3

Hope this is informative!

SQL Server 2008/20008R2, Trace Flags

Backup Internals – Trace Flag 3014

Trace Flag 3014–  This is one of the undocumented Trace flags in SQL Server, which basically gives a detailed information(Well, This might not be useful in most of the cases) regarding File Creation, Padding and much more related Info while you are taking a Backup of your Database.

Do you really need this Info? IMHO, 95% of the cases, i would say NO. I consider this as Just an FYI kind of Information. When i try to troubleshoot Backup/Restore Issues, I rather enable Trace Flags 3004 and 3014 along with 3605(to enable logging of all the entries in our Error Log) instead of Just enabling Single Flag(Make sure you disable these Flags once you are done with diagnostics).

Let’s See what exactly get’s logged when i Enable these Trace Flags and Take a Full Database Backup.

Tadaaaaaaaaaa!
2011-09-15 22:00:40.470 spid54 BackupStream(0): Starting MSDA of size 384 extents
2011-09-15 22:00:40.470 spid54 Started file C:\Program Files\Microsoft SQL Server\MSSQL10_50.PROD\MSSQL\DATA\3014_demo.mdf
2011-09-15 22:00:40.780 spid54 Completed file C:\Program Files\Microsoft SQL Server\MSSQL10_50.PROD\MSSQL\DATA\3014_demo.mdf
2011-09-15 22:00:40.790 spid54 Padding MSDA with 327680 bytes
2011-09-15 22:00:40.790 spid54 BackupStream(0): Total MSDA: 384 extents
2011-09-15 22:00:40.860 Backup Database backed up. Database: 3014_demo, creation date(time): 2011/09/15(21:46:19), pages dumped: 3100, first LSN: 163:1808:37, last LSN: 163:1824:1, number of dump devices: 1, device information: (FILE=2, TYPE=DISK: {‘D:\Backs\3014_full.bak’}).

So..Basically you can see exact times while starting backup stream , how many Extents being affected, what file(s) etc…Again This is Just an FYI information in most of the cases while you are dealing with Backups, where as the Trace Flag 3004(see here) is Extremely Useful while investigating DB Restore Issues. YMMV!

Database, SQL Server 2008/20008R2, Trace Flags

Diagnosing Database Restores – Trace Flag 3004

Recently one of my fellow DBA had an issue with a Database Restore, where he was restoring a database using a full backup(from GUI) and the wizard was progressed upto 100% and it stayed there for more than 30 Minutes and he pinged me to see what’s going on!! Well, The actual issue was the database which he took the backup had 16000+ VLF’s!!(Very Very Bad sign of Log file sizing) and the log file size was close to 78 GB and there was a hugeeee open transaction(which SQL will Undo while restoring the Backup). Note he was creating a brand new database, So SQL will be creating brand new files and remember transaction log file will be Zero Initialized always as apposed to Data files(If Instant File Initialization is enabled on your Instance).

Our focus in this post is not regarding VLF’s and how Log file should be managed, but to identify what’s happening behind the scenes with your Database Restore and kind of identifying current Phase of restore process. For this you can make use of  Undocumented trace flag 3004 along with 3605 to get the events logged in our Error Log. You can enable this trace flag either globally or at session level. (No need of  touching your start up parameters for these trace flags) Please see the below Screenshot.

For demo purpose, Let’s restore a Full Backup of a database(it has an Open Transaction) and let’s see how our Error Log looks like with this trace flag being enabled.

I’ve restored the DB,  see the Error Log in the below Screenshot.

Focus on these steps where you can note the actual time SQL Server took for Zeroing your Log File, Redo,Undo and all other required Information.

1.Zeroing C:\Program Files\Microsoft SQL Server\MSSQL10_50.PROD\MSSQL\DATA\3005_Demo_1.ldf
from page 1 to 20584 (0x2000 to 0xa0d0000)
2.Restore: Waiting for log zero on 3005_Demo
3.Zeroing completed on
C:\Program Files\Microsoft SQL Server\MSSQL10_50.PROD\MSSQL\DATA\3005_Demo_1.ldf
4.Restore: LogZero complete
5.Starting up database ‘3005_Demo’.
6.The database ‘3005_Demo’ is marked RESTORING and is in a state that does not allow recovery to be run.
7.Starting up database ‘3005_Demo’.
8.Recovery is writing a checkpoint in database ‘3005_Demo’ (19).
9.Recovery completed for database 3005_Demo (database ID 19) in 9 second(s)
(analysis 20 ms, redo 1801 ms, undo 7690 ms.)
10.Restore is complete on database ‘3005_Demo’. The database is now available.
Database was restored: Database: 3005_Demo, creation date(time): 2011/08/23(23:16:47), first LSN: 38:19:1 blabla

Hope this is informative!

Trace Flags

Prevent logging all the Backup(Successful) Events in your Error Log

Have you ever been in a situation where you were trying to analyze a particular error details from your error log and you are annoyed by whole bunch of “Database Backed up/Log was Backed up bla bla…” messages?? Let’s say your Instance has 20+ databases and most of them are Log shipped(assume every 10 Mins log backups) to it’s DR Server (This is a very common Scenario). If you see anytime in your error log, you’ll end up with frustration digging into what exactly you are looking for. Because SQL Server has a Bad habit of logging in each and every detail(Success or Failure) of backup Operation(s) by Default. You’ve to define all kinds of crazy filters in your logs to exclude the junk and look what exactly you are looking for. Basically, You’ll be seeing Error logs something very similar to what you are seeing in the below Screenshot.

So…Is there anyway where you can get rid of all these Successful Backup events being logged from your SQL Server Error Log?? The Answer is YES 🙂
Microsoft has introduced a TraceFlag 3226 which you can enable globally, which eliminates all these Junk(In most of the Cases) getting logged into error log. Let’s do a Quick Demo.

Let’s recycle the Error Log, Just to make sure that we’ve a clean log – easy to Demo. It should come up as shown below.

Now, let’s start the actual testing.
I’m taking a Full Database Backup and an immediate Log Backup. Now let’s review our Error Log in the below Screenshot.

It logged Both the Full Backup and the Log Backup Operations.
Let’s turn ON TraceFlag 3226 now and let’s take couple of Backups and turn OFF Trace Flag and again take a backup and see what get’s logged in our Error Log for all the above operations. Just to convince you folks, I’m again Turning OFF Traceflag again and show you the Error Log all at one glance(See Below Screenshot)!!

If you carefully observe the Error Log at the left the tst5 and tst6 backup events are not logged and once we turned off the trace flag tst7 has been succesfully logged.

By this time you should be thinking what about the Failed Backup Events, We need them to be logged all the time in our Error Log. Absolutely “Yes“!!! All the Failed Backup Events are Successfully logged even with this Trace Flag Turned ON. You can see that in the below Screenshot.

I’m really impressed with this and suggest you folks; do Consider testing this trace flag on your Servers!