SQL Server Error 3041 with BACKUP SERVER statement

[kpenza]

Environment

• Python: 3.12
• pyodbc: 5.2.0
• OS: RHEL 9.6
• DB: MS SQL Server 2022
• Driver: Microsoft ODBC Driver 18 for SQL Server (18.5.1.1)

Background

We are currently working with SQL Server on Linux snapshot backups. The highlevel steps entail:

1. Take SQL Server snapshot
   1. Open DB connection.
   2. Execute "ALTER SERVER CONFIGURATION SET SUSPEND_FOR_SNAPSHOT_BACKUP = ON;"
   3. Take Linux LVM snapshot
   4. Execute "BACKUP SERVER TO DISK = '/var/opt/mssql/backup/metadata/backup_1.bkm' WITH METADATA_ONLY, FORMAT;
   5. Close DB connection
2. Mount LVM snapshots
3. Backup them up
4. Unmount LVM snapshots
5. Delete LVM snapshots

Issue

The statement in Step 1, iv fails with multiple "Error: 3041, Severity: 16, State: 1.". We made test with Java, SQL SSMS, Powershell using ODBC connections and all worked fine.
When we used isql with the -v flag we noted that statement in Step 1, iv returns an "SQL_SUCCESS_WITH_INFO" for each datafile in the SQL instance. Looks like only the first "SQL_SUCCESS_WITH_INFO" is handled by pyodbc Note I can provide the isql output if needed.

[gordthompson]

I am unable to reproduce your issue. This works for me on a Windows client hitting a SQL Server 2022 instance in a Docker container:

import pyodbc

cnxn = pyodbc.connect(
    "DSN=msodbcsql18_199;UID=scott;PWD=tiger^5HHH;",
    autocommit=True,
)
crsr = cnxn.cursor()
crsr.execute(
    "ALTER SERVER CONFIGURATION SET SUSPEND_FOR_SNAPSHOT_BACKUP = ON;"
)
crsr.execute(
    "BACKUP SERVER TO DISK = '/var/opt/mssql/backup/metadata/backup_1.bkm' WITH METADATA_ONLY, FORMAT;"
)

[gordthompson]

That same code also works on Ubuntu 24.04 with unixODBC 2.3.12 and Python 3.12.3.

odbctrace.log

[kpenza]

Thanks for looking into the matter. Following the feedback I have gone through the test case again and re-ran it against a SQL Server 2022 running in a container.

Setup:

• SQL Server 2022 instance running in a container on OracleLinux9 via podman, image mcr.microsoft.com/mssql/server:2022-latest
• Python client is running on OracleLinux9.6, unixODBC-2.3.11 and msodbcsql18-18.5.1.1

Findings:

• the python code does not receive any error, however the error is logged in SQL Server errorlog (Missed this detail in the initial report)
• the error Error: 3041, Severity: 16, State: 1 is logged in SQL Server errorlog, if there is more than one user databases.

Code:

import pyodbc

username = 'sa'
password = 'Password!'
server = '127.0.0.1,1433'
connection_string = f'DRIVER={{ODBC Driver 18 for SQL Server}};SERVER={server};UID={username};PWD={password};TrustServerCertificate=yes'

conn = pyodbc.connect(connection_string, autocommit = True)
cursor = conn.cursor()
cursor.execute("ALTER SERVER CONFIGURATION SET SUSPEND_FOR_SNAPSHOT_BACKUP = ON;")
# LVM snapshot code
cursor.execute(f"BACKUP SERVER TO DISK = '/var/opt/mssql/backup/metadata/inst.bkm' WITH METADATA_ONLY, FORMAT;")
cursor.close()
conn.close()

Test case 1 (more than 1 user databases)

Databases in SQL server instance list:

select name from sysdatabases where name not in ('master','tempdb','model','msdb')

DB list:

db1
db2
db3

The python code executes successfully;

$ python3.12 backup.py
$

In errorlog (podman exec -it sql1 tail -f /var/opt/mssql/log/errorlog or podman logs -f -n sql1 ,where sql1 is the container name) :

2025-06-19 05:18:05.06 spid58      Database 'db1' acquired suspend locks in session 58.
2025-06-19 05:18:05.06 spid58      Database 'db2' acquired suspend locks in session 58.
2025-06-19 05:18:05.07 spid58      Database 'db3' acquired suspend locks in session 58.
2025-06-19 05:18:05.10 spid58      I/O is frozen on database db1. No user action is required. However, if I/O is not resumed promptly, you could cancel the backup.
2025-06-19 05:18:05.10 spid58      Database 'db1' successfully suspended for snapshot backup in session 58.
2025-06-19 05:18:05.11 spid58      I/O is frozen on database db2. No user action is required. However, if I/O is not resumed promptly, you could cancel the backup.
2025-06-19 05:18:05.11 spid58      Database 'db2' successfully suspended for snapshot backup in session 58.
2025-06-19 05:18:05.12 spid58      I/O is frozen on database db3. No user action is required. However, if I/O is not resumed promptly, you could cancel the backup.
2025-06-19 05:18:05.13 spid58      Database 'db3' successfully suspended for snapshot backup in session 58.
2025-06-19 05:18:05.13 spid58      Server 'sql1' successfully suspended for snapshot backup in session 58.
2025-06-19 05:18:05.15 spid58      I/O is frozen on database db1. No user action is required. However, if I/O is not resumed promptly, you could cancel the backup.
2025-06-19 05:18:05.15 spid58      I/O is frozen on database db2. No user action is required. However, if I/O is not resumed promptly, you could cancel the backup.
2025-06-19 05:18:05.16 spid58      I/O is frozen on database db3. No user action is required. However, if I/O is not resumed promptly, you could cancel the backup.
2025-06-19 05:18:05.16 spid58      I/O was resumed on database db1. No user action is required.
2025-06-19 05:18:05.16 spid58      Database 'db1' released suspend locks in session 58.
2025-06-19 05:18:05.16 spid58      Database 'db1' originally suspended for snapshot backup in session 58 successfully resumed in session 58.
2025-06-19 05:18:05.16 spid58      I/O was resumed on database db2. No user action is required.
2025-06-19 05:18:05.16 spid58      Database 'db2' released suspend locks in session 58.
2025-06-19 05:18:05.17 spid58      Database 'db2' originally suspended for snapshot backup in session 58 successfully resumed in session 58.
2025-06-19 05:18:05.17 spid58      I/O was resumed on database db3. No user action is required.
2025-06-19 05:18:05.17 spid58      Database 'db3' released suspend locks in session 58.
2025-06-19 05:18:05.17 spid58      Database 'db3' originally suspended for snapshot backup in session 58 successfully resumed in session 58.
2025-06-19 05:18:05.18 Backup      Database backed up. Database: db1, creation date(time): 2025/06/18(16:58:08), pages dumped: 402, first LSN: 42:1232:37, last LSN: 42:1264:1, number of dump devices: 1, device information: (FILE=1, TYPE=DISK: {'/var/opt/mssql/backup/metadata/inst.bkm'}). This is an informational message only. No user action is required.
2025-06-19 05:18:05.19 Backup      BACKUP DATABASE successfully processed 0 pages in 0.022 seconds (0.000 MB/sec).
2025-06-19 05:18:05.20 Backup      Error: 3041, Severity: 16, State: 1.
2025-06-19 05:18:05.20 Backup      BACKUP failed to complete the command BACKUP DATABASE db1. Check the backup application log for detailed messages.
2025-06-19 05:18:05.20 Backup      Error: 3041, Severity: 16, State: 1.
2025-06-19 05:18:05.20 Backup      BACKUP failed to complete the command BACKUP DATABASE db2. Check the backup application log for detailed messages.
2025-06-19 05:18:05.21 Backup      Error: 3041, Severity: 16, State: 1.
2025-06-19 05:18:05.21 Backup      BACKUP failed to complete the command BACKUP DATABASE db3. Check the backup application log for detailed messages.

Test case 2 (with 1 user database)

Database list:

select name from sysdatabases where name not in ('master','tempdb','model','msdb')

DB list:

db1

The python code executes successfully;

$ python3.12 backup.py
$

Errorlog output:

2025-06-19 05:19:45.30 spid69      Database 'db1' acquired suspend locks in session 69.
2025-06-19 05:19:45.37 spid69      I/O is frozen on database db1. No user action is required. However, if I/O is not resumed promptly, you could cancel the backup.
2025-06-19 05:19:45.38 spid69      Database 'db1' successfully suspended for snapshot backup in session 69.
2025-06-19 05:19:45.38 spid69      Server 'sql1' successfully suspended for snapshot backup in session 69.
2025-06-19 05:19:45.39 spid69      I/O is frozen on database db1. No user action is required. However, if I/O is not resumed promptly, you could cancel the backup.
2025-06-19 05:19:45.39 spid69      I/O was resumed on database db1. No user action is required.
2025-06-19 05:19:45.40 spid69      Database 'db1' released suspend locks in session 69.
2025-06-19 05:19:45.40 spid69      Database 'db1' originally suspended for snapshot backup in session 69 successfully resumed in session 69.
2025-06-19 05:19:45.41 Backup      Database backed up. Database: db1, creation date(time): 2025/06/18(16:58:08), pages dumped: 402, first LSN: 42:1360:37, last LSN: 42:1392:1, number of dump devices: 1, device information: (FILE=1, TYPE=DISK: {'/var/opt/mssql/backup/metadata/inst.bkm'}). This is an informational message only. No user action is required.
2025-06-19 05:19:45.42 Backup      BACKUP DATABASE successfully processed 0 pages in 0.011 seconds (0.000 MB/sec).

[gordthompson]

Reproduced. With pyodbc, the script

import pyodbc

cnxn = pyodbc.connect(
    "DSN=msodbcsql18_199;UID=scott;PWD=tiger^5HHH;",
    autocommit=True,
)
crsr = cnxn.cursor()
crsr.execute(
    "ALTER SERVER CONFIGURATION SET SUSPEND_FOR_SNAPSHOT_BACKUP = ON;"
)
crsr.execute(
    "BACKUP SERVER TO DISK = '/var/opt/mssql/backup/metadata/backup_1.bkm' WITH METADATA_ONLY, FORMAT;"
)

results in

root@91b53bb51511:/# tail -n 15 /var/opt/mssql/log/errorlog
2025-06-19 15:17:44.96 spid52      Database 'test' originally suspended for snapshot backup in session 52 successfully resumed in session 52.
2025-06-19 15:17:44.98 spid52      I/O was resumed on database db1. No user action is required.
2025-06-19 15:17:44.99 spid52      Database 'db1' released suspend locks in session 52.
2025-06-19 15:17:45.00 spid52      Database 'db1' originally suspended for snapshot backup in session 52 successfully resumed in session 52.
2025-06-19 15:17:45.01 spid52      I/O was resumed on database db2. No user action is required.
2025-06-19 15:17:45.02 spid52      Database 'db2' released suspend locks in session 52.
2025-06-19 15:17:45.03 spid52      Database 'db2' originally suspended for snapshot backup in session 52 successfully resumed in session 52.
2025-06-19 15:17:45.08 Backup      Database backed up. Database: test, creation date(time): 2025/06/18(12:56:43), pages dumped: 602, first LSN: 40:1136:37, last LSN: 40:1168:1, number of dump devices: 1, device information: (FILE=1, TYPE=DISK: {'/var/opt/mssql/backup/metadata/backup_1.bkm'}). This is an informational message only. No user action is required.
2025-06-19 15:17:45.24 Backup      BACKUP DATABASE successfully processed 0 pages in 0.225 seconds (0.000 MB/sec).
2025-06-19 15:17:45.30 Backup      Error: 3041, Severity: 16, State: 1.
2025-06-19 15:17:45.30 Backup      BACKUP failed to complete the command BACKUP DATABASE test. Check the backup application log for detailed messages.
2025-06-19 15:17:45.36 Backup      Error: 3041, Severity: 16, State: 1.
2025-06-19 15:17:45.36 Backup      BACKUP failed to complete the command BACKUP DATABASE db1. Check the backup application log for detailed messages.
2025-06-19 15:17:45.39 Backup      Error: 3041, Severity: 16, State: 1.
2025-06-19 15:17:45.39 Backup      BACKUP failed to complete the command BACKUP DATABASE db2. Check the backup application log for detailed messages.

With VBScript,

Set con = CreateObject("ADODB.Connection")
con.Open "DSN=msodbcsql18_199;UID=scott;PWD=tiger^5HHH;"
Set cmd = CreateObject("ADODB.Command")
cmd.ActiveConnection = con
cmd.CommandText = "ALTER SERVER CONFIGURATION SET SUSPEND_FOR_SNAPSHOT_BACKUP = ON;"
cmd.Execute
cmd.CommandText = "BACKUP SERVER TO DISK = '/var/opt/mssql/backup/metadata/backup_1.bkm' WITH METADATA_ONLY, FORMAT;"
cmd.Execute

produces

root@91b53bb51511:/# tail -n 15 /var/opt/mssql/log/errorlog
2025-06-19 15:19:05.15 spid52      I/O was resumed on database test. No user action is required.
2025-06-19 15:19:05.17 spid52      Database 'test' released suspend locks in session 52.
2025-06-19 15:19:05.18 spid52      Database 'test' originally suspended for snapshot backup in session 52 successfully resumed in session 52.
2025-06-19 15:19:05.19 spid52      I/O was resumed on database db1. No user action is required.
2025-06-19 15:19:05.20 spid52      Database 'db1' released suspend locks in session 52.
2025-06-19 15:19:05.21 spid52      Database 'db1' originally suspended for snapshot backup in session 52 successfully resumed in session 52.
2025-06-19 15:19:05.23 spid52      I/O was resumed on database db2. No user action is required.
2025-06-19 15:19:05.23 spid52      Database 'db2' released suspend locks in session 52.
2025-06-19 15:19:05.24 spid52      Database 'db2' originally suspended for snapshot backup in session 52 successfully resumed in session 52.
2025-06-19 15:19:05.29 Backup      Database backed up. Database: test, creation date(time): 2025/06/18(12:56:43), pages dumped: 602, first LSN: 40:1200:37, last LSN: 40:1232:1, number of dump devices: 1, device information: (FILE=1, TYPE=DISK: {'/var/opt/mssql/backup/metadata/backup_1.bkm'}). This is an informational message only. No user action is required.
2025-06-19 15:19:05.41 Backup      BACKUP DATABASE successfully processed 0 pages in 0.194 seconds (0.000 MB/sec).
2025-06-19 15:19:05.45 Backup      Database backed up. Database: db1, creation date(time): 2025/06/19(13:49:09), pages dumped: 370, first LSN: 39:904:39, last LSN: 39:936:1, number of dump devices: 1, device information: (FILE=1, TYPE=DISK: {'/var/opt/mssql/backup/metadata/backup_1.bkm'}). This is an informational message only. No user action is required.
2025-06-19 15:19:05.64 Backup      BACKUP DATABASE successfully processed 0 pages in 0.330 seconds (0.000 MB/sec).
2025-06-19 15:19:05.67 Backup      Database backed up. Database: db2, creation date(time): 2025/06/19(13:59:28), pages dumped: 362, first LSN: 39:648:37, last LSN: 39:680:1, number of dump devices: 1, device information: (FILE=1, TYPE=DISK: {'/var/opt/mssql/backup/metadata/backup_1.bkm'}). This is an informational message only. No user action is required.
2025-06-19 15:19:05.81 Backup      BACKUP DATABASE successfully processed 0 pages in 0.452 seconds (0.000 MB/sec).

[kpenza]

@gordthompson, I done further tests with C and unixODBC and found that SQLMoreResults fixes the issue. Below is the C code, for your reference. This solution is highlighted by comment "SOLVES ISSUE" (apologies github does not seems to support line numbers in code blocks).

#include <stdio.h>
#include <sql.h>
#include <sqlext.h>

void printDiag(char *fn, SQLSMALLINT handleType, SQLHANDLE handle)
{
    SQLINTEGER i = 1;
    SQLINTEGER native;
    SQLCHAR state[7];
    SQLCHAR text[256];
    SQLSMALLINT len;
    SQLRETURN ret;

    fprintf(stderr,
            "\n"
            "Driver diagnostics reported whilst running "
            "%s\n",
            fn);

    while ((ret = SQLGetDiagRec(handleType, handle, i, state, &native, text, sizeof(text), &len)) != SQL_NO_DATA)
    {
        printf("RET: %d %s:%d:%d:%s\n", ret, state, i, native, text);
        i++;
    }
}

int main()
{
    SQLHENV env;
    SQLHDBC dbc;
    SQLHSTMT stmt;
    SQLRETURN ret; /* ODBC API return status */
    SQLCHAR outstr[1024];
    SQLSMALLINT outstrlen;

    /* Allocate an environment handle */
    ret = SQLAllocHandle(SQL_HANDLE_ENV, SQL_NULL_HANDLE, &env);
    if (ret != SQL_SUCCESS)
    {
        printDiag("Failed to allocate handle.", SQL_HANDLE_ENV, env);
        if (ret != SQL_SUCCESS_WITH_INFO)
        {
            return 1;
        }
    }
    /* We want ODBC 3 support */
    ret = SQLSetEnvAttr(env, SQL_ATTR_ODBC_VERSION, (void *)SQL_OV_ODBC3, 0);
    if (ret != SQL_SUCCESS)
    {
        printDiag("Failed to set ODBC 3 support", SQL_HANDLE_ENV, env);
        if (ret != SQL_SUCCESS_WITH_INFO)
        {
            SQLFreeHandle(SQL_HANDLE_ENV, env);
            return 1;
        }
    }
    /* Allocate a connection handle */
    ret = SQLAllocHandle(SQL_HANDLE_DBC, env, &dbc);
    if (ret != SQL_SUCCESS && ret != SQL_SUCCESS_WITH_INFO)
    {
        printDiag("Failed to allocate connection handle.\n", SQL_HANDLE_ENV, env);
        if (ret != SQL_SUCCESS_WITH_INFO)
        {
            SQLFreeHandle(SQL_HANDLE_ENV, env);
            return 1;
        }
    }
    /* Connect to the DSN mydsn */
    ret = SQLDriverConnect(dbc,
                           NULL,
                           (SQLCHAR *)"DRIVER={ODBC Driver 18 for SQL Server};SERVER=<sqlserverhostname>;UID=<username>;PWD=<password>;TrustServerCertificate=yes",
                           SQL_NTS,
                           outstr,
                           sizeof(outstr), &outstrlen,
                           SQL_DRIVER_COMPLETE);
    if (ret != SQL_SUCCESS)
    {
        printDiag("Connection diagnostics.", SQL_HANDLE_DBC, dbc);
        if (ret != SQL_SUCCESS_WITH_INFO)
        {
            SQLFreeHandle(SQL_HANDLE_ENV, env);
            return 1;
        }
    }
    printf("Connected using :\n\t%s\n", outstr);

    /* BEGIN BACKUP */
    printf("BEGIN BACKUP\n");
    SQLAllocHandle(SQL_HANDLE_STMT, dbc, &stmt);
    ret = SQLExecDirect(stmt, (SQLCHAR *)"ALTER SERVER CONFIGURATION SET SUSPEND_FOR_SNAPSHOT_BACKUP = ON;", SQL_NTS);
    do
    {
        printf("%d\n", ret);
        if (ret == SQL_SUCCESS)
        {
            printf("Statement ok\n");
        }
        if (ret == SQL_SUCCESS_WITH_INFO)
        {
            printDiag("ALTER SERVER ...: ", SQL_HANDLE_STMT, stmt);
        }
        ret = SQLMoreResults(stmt);
    } while (ret == SQL_SUCCESS_WITH_INFO || ret == SQL_SUCCESS);

    printf("END BACKUP\n");
    /* END BACKUP */
    SQLAllocHandle(SQL_HANDLE_STMT, dbc, &stmt);
    ret = SQLExecDirect(stmt, (SQLCHAR *)"BACKUP SERVER TO DISK = '/var/opt/mssql/backup/metadata/file_c1.bkm' WITH METADATA_ONLY, FORMAT;", SQL_NTS);
    do
    {
        printf("%d\n", ret);
        if (ret == SQL_SUCCESS)
        {
            printf("Statement ok\n");
        }
        if (ret == SQL_SUCCESS_WITH_INFO)
        {
            printDiag("BACKUP SERVER ...: ", SQL_HANDLE_STMT, stmt);
        }
        ret = SQLMoreResults(stmt); /* process next resultset, SOLVES ISSUE */
        // break; /* to restore current pyodbc behaviour, comment previous line and uncomment this one*/
    } while (ret == SQL_SUCCESS_WITH_INFO || ret == SQL_SUCCESS);

    SQLDisconnect(dbc);
    SQLFreeHandle(SQL_HANDLE_STMT, stmt);

    /* free up allocated handles */
    SQLFreeHandle(SQL_HANDLE_DBC, dbc);
    SQLFreeHandle(SQL_HANDLE_ENV, env);
    return 0;
}

[gordthompson]

The ODBC trace logs seem to confirm the findings by @kpenza . Using my repro code above:

pyodbc.LOG

adodb.LOG

With pyodbc (Python):

• SQLExecDirectW runs the BACKUP SERVER TO DISK statement.
• SQLGetDiagRecW is called ten (10) times to retrieve the _WITH_INFO messages.
• SQLGetDiagRecW is called one more time, returning SQL_NO_DATA_FOUND.
• SQLRowCount is called, returning -1.
• SQLNumResultCols is called, returning 0.
• SQLFreeStmt is called with SQL_CLOSE.

With ADODB (VBScript):

• SQLExecDirectW runs the BACKUP SERVER TO DISK statement.
• SQLGetDiagRecW is called fifteen (15) times to retrieve the _WITH_INFO messages.
• SQLGetDiagRecW is called one more time, returning SQL_NO_DATA_FOUND.
• SQLGetDiagFieldW is called.
• SQLRowCount is called, returning -1.
• SQLNumResultCols is called, returning 0.
• SQLGetStmtAttrW is called twice.
• SQLMoreResults is called.     <------
• SQLGetDiagFieldW is called.
• SQLFreeStmt is called with SQL_CLOSE.