Avamar: Avamar SQL Restore timeout, Microsoft SQL Server File Initialization feature zeroing file

Restoring a large SQL database, Avamar SQL restore log, still has a time-out error after extending the waiting time.

In the log, observe the problem is with subprocess timed out:

2019-06-12 15:18:48 avsql Info <6686>: Process 1388 (C:\Program Files\avs\bin\avtar) for workorder MOD-1560316722449#2 started
2019-06-12 15:18:48 avsql Info <42989>: VDC_Complete is supported by VDI.
2019-06-12 15:18:48 avsql Info <6686>: Process 8860 (C:\Program Files\avs\bin\avtar) for workorder MOD-1560316722449#1 started
2019-06-12 15:18:48 avsql Info <42989>: VDC_Complete is supported by VDI.
2019-06-12 15:18:48 avsql Info <6686>: Process 5364 (C:\Program Files\avs\bin\avtar) for workorder MOD-1560316722449#3 started
2019-06-12 15:18:48 avsql Info <42989>: VDC_Complete is supported by VDI.
2019-06-12 15:18:48 avsql Info <6686>: Process 11708 (C:\Program Files\avs\bin\avtar) for workorder MOD-1560316722449#4 started
2019-06-12 15:18:48 avsql Info <42989>: VDC_Complete is supported by VDI.
2019-06-12 15:18:49 avsql Info <10684>: Setting ctl message version to 3 (from 1)
2019-06-12 15:18:49 avsql Info <16136>: Setting ctl max message size to 268435456
2019-06-12 15:18:49 avsql Info <10684>: Setting ctl message version to 3 (from 1)
2019-06-12 15:18:49 avsql Info <16136>: Setting ctl max message size to 268435456
2019-06-12 15:18:49 avsql Info <10684>: Setting ctl message version to 3 (from 1)
2019-06-12 15:18:49 avsql Info <16136>: Setting ctl max message size to 268435456
2019-06-12 15:18:49 avsql Info <10684>: Setting ctl message version to 3 (from 1)
2019-06-12 15:18:49 avsql Info <16136>: Setting ctl max message size to 268435456
2019-06-12 15:39:03 avsql Info <7732>: Waiting for avtar to finish
2019-06-12 15:39:03 avsql Info <7732>: Waiting for avtar to finish
2019-06-12 15:39:03 avsql Info <7732>: Waiting for avtar to finish
2019-06-12 15:39:03 avsql Info <7732>: Waiting for avtar to finish
2019-06-12 15:59:03 avsql Error <12323>: Timeout on wait for sub-process
2019-06-12 15:59:03 avsql Error <12323>: Timeout on wait for sub-process
2019-06-12 15:59:03 avsql Error <12323>: Timeout on wait for sub-process
2019-06-12 15:59:03 avsql Error <12323>: Timeout on wait for sub-process
2019-06-12 15:59:03 avsql Error <18491>: SQL plug-in will now terminate due to the following avtar error: 'code 0xffffffff: No error description string'
2019-06-12 15:59:03 avsql Error <18491>: SQL plug-in will now terminate due to the following avtar error: 'code 0xffffffff: No error description string'
2019-06-12 15:59:03 avsql Error <18491>: SQL plug-in will now terminate due to the following avtar error: 'code 0xffffffff: No error description string'
2019-06-12 15:59:03 avsql Error <18491>: SQL plug-in will now terminate due to the following avtar error: 'code 0xffffffff: No error description string'
2019-06-13 07:40:39 avsql Info <16153>: Cancel request received

The restore fails with a time-out error despite using Avamar SQL plugin flags to set timeout limits, for example.

--subprocesstimeoutsecs=3600
--vditransfertimeoutsecs=10800
 

This is a feature called "File initialization" in the SQL server which means:

Data and log files are initialized to overwrite any existing data left on the disk from previously deleted files. Data and log files are first initialized by zeroing the files (filling with zeros) when you perform one of the following operations:

• Create a database.
• Add data or log files to an existing database.
• Increase the size of an existing file (including autogrow operations).
• Restore a database or filegroup.

File initialization causes these operations to take longer.

Avamar uses SQL VDI API for restore operation, and Avamar does not modify this SQL server's feature.  This can lead to longer waiting time but still not restoring data back to the SQL server as the restore process is stuck on the SQL server side and avtar is not allowed to write data to the SQL server.

Enable "Instant File Initialization" on the SQL server which dramatically saves time (especially for large databases) on create and restore databases.

For detailed information, refer to the Microsoft doc article:  https://docs.microsoft.com/en-us/sql/relational-databases/databases/database-instant-file-initialization?view=sql-server-2017