`sqlcmd' withholding error messages?

[Anton Shepelev]

Greetings to master Erland and all good people prefer-
ring the cleanliness and freedom of Usenet to clut-
tered and centralised web-based media. On a dedicated
machine I host many SQL Server instances and perform
some regular maintenance operations via `sqlcmd' in-
voked in a batch script in a loop over a file with a
list of instances. The relevant fragment is shown be-
low:

for /F %%f in (instances.txt) do (
sqlcmd -A -r 0 -b -l 4 -t 120 -S SBOSQL%f -i %SCR_PAT%%s 2> error.txt
IF ERRORLEVEL 1 (
echo %DATE% %TIME%: >> errors.txt
echo Error invoking %SCR_PAT%%s for %%f: >> errors.txt
type error.txt >> errors.txt
echo -- >> errors.txt
)
del error.txt
)

Most of the time is works as expected, but on rare oc-
casion the log file will contain error entries with an
empty message, e.g.:

Thu 08/11/2022 13:04:12.46:
Error invoking mem_bal _mem_balance.sql for SBO35:
--

Which means that `sqlcmd' returned an error code yet
did not print any message to standard output. Do I in-
voke it incorrectly?

--
() ascii ribbon campaign - against html e-mail
/\ http://preview.tinyurl.com/qcy6mjc [archived]

[Erland Sommarskog]

Anton Shepelev (anton.txt@g{oogle}mail.com) writes:
> Most of the time is works as expected, but on rare oc-
> casion the log file will contain error entries with an
> empty message, e.g.:
>
> Thu 08/11/2022 13:04:12.46:
> Error invoking mem_bal _mem_balance.sql for SBO35:
> --
>
> Which means that `sqlcmd' returned an error code yet
> did not print any message to standard output. Do I in-
> voke it incorrectly?
>

Unfortunately without a reproducible case, this is difficult to comment on.
What I can say is that sometimes I get the feeling that SQLCMD does not
relay all errors when there are many, but I have never investigate it.
But have I run into no errors at all, but still it's apparent that the
operation falied? When I think of it, I think I have, but I don't
recall the details.

What's in your scripts? Loading of stored procedures and other
objects? Or something else? (In my case, it was most likely a stored
procedure.)

[Anton Shepelev]

Erland Sommarskog:

> Unfortunately without a reproducible case, this is
> difficult to comment on.

I should tell you how to reproduce it but if I knew
myself...

> What I can say is that sometimes I get the feeling
> that SQLCMD does not relay all errors when there are
> many, but I have never investigate it.

It has several mutually dependent parameters governing
reaction to errors.

> But have I run into no errors at all, but still it's
> apparent that the operation falied? When I think of
> it, I think I have, but I don't recall the details.
> What's in your scripts? Loading of stored procedures
> and other objects? Or something else? (In my case,
> it was most likely a stored procedure.)

It is my scandalous memory balancer that failed, but
it is much more stable now than it used to be. The
code is not of publishing quality, so you might prefer
to skip it:

-- WARN: May cause the instance to freeze and become unresponsive:
-- Invoke within a DAC to decrease the chance of this failure.
-- TODO: Analyse sys.dm_os_wait_stats from DAC when a server hangs next time.
sp_configure 'show advanced options', 1 RECONFIGURE

/* ----------------------- User-adjustable paramters ------------------------ */
DECLARE @srv_n INT = 6 -- number of MSSQL instances
DECLARE @h_sta INT = 10 -- workday starting hour
DECLARE @h_end INT = 19 -- workday ending hour
DECLARE @m_res INT = 2048 -- memory reserved for the OS
DECLARE @m_db INT = 14 -- additional memory per DB

/* -------------------------------- Constants ------------------------------- */
-- TODO: instead of c_mis, try: round down to next 32, subract 32.
DECLARE @c_mmi INT = 128
DECLARE @c_mma INT = 2147483647
DECLARE @c_ste INT = 32 -- minumum memory decrement (exp.)
DECLARE @c_two FLOAT = 2
DECLARE @c_min VARCHAR(17) = 'min server memory'
DECLARE @c_max VARCHAR(17) = 'max server memory'
DECLARE @c_ofs INT = 32

/* -------------------------------- Variables ------------------------------- */
DECLARE @v_low BIT,
@p_low BIT
-- RAM values, in MB:
DECLARE @m_min INT -- min RAM parameter
DECLARE @m_use INT -- RAM used by this MSSQL instance
DECLARE @m_lim INT -- target RAM limitation
DECLARE @m_lco INT -- corrected limit
DECLARE @N INT
DECLARE @DB_N INT -- number of databases
DECLARE @r_msg NVARCHAR(max) -- result message
DECLARE @r_pre NVARCHAR(max) -- message prefix
DECLARE @m_gra INT -- memory grants pending
DECLARE @m_low BIT
DECLARE @m_mi INT

DECLARE @dec_2 INT = @h_end - @h_sta + 1 -- number of iterations for half-decay

/* ------------------------------ Main script ------------------------------- */
-- Active only in work hours:
IF NOT DATEPART( hour, GETDATE() ) BETWEEN @h_sta AND @h_end GOTO Finish
SET @r_pre = ''

SELECT @DB_N = SUM(1) FROM sys.databases

SET @m_mi = 1 GOTO MemInfo
MI1: IF @m_low = 1 GOTO Finish

SET @m_min = @c_mmi + @m_db * @DB_N
IF @m_use <= @m_min BEGIN
SET @r_msg = FORMATMESSAGE('Current memory usage below lower limit %i Mb.', @m_min)
GOTO Finish END

SET @m_lim = @m_min + (@m_use - @m_min) / POWER(@c_two, 1.0/@dec_2)
IF @m_use - @m_lim < @c_ofs / 4 BEGIN
SET @m_lim = @m_use - @c_ofs / 4
END

SET @m_lco = @m_lim - @c_ofs
IF @m_lco < @m_min BEGIN
--SET @r_msg = FORMATMESSAGE('Current memory usage within correction offset %i Mb of the lower limit %i Mb', @c_ofs, @m_min)
--GOTO Finish END
SET @m_lco = @m_min END

SET @r_pre = FORMATMESSAGE('%i -> %i: ', @m_use, @m_lim)

EXEC sp_configure @c_min, 0
EXEC sp_configure @c_max, @m_lco RECONFIGURE

SET @r_msg = 'Failed to decrease memory usage in time.'
SET @N = 60
WHILE @N > 0
BEGIN
SET @m_mi = 2 GOTO MemInfo
MI2: IF @m_low = 1 BREAK

WAITFOR DELAY '00:00:01'
IF @m_use < @m_lim + @c_ofs/8 BEGIN
-- TODO: Will misfire in case of decrements < 2*@c_ste: fix it somehow!
SET @r_msg = 'Memory usage reached target level.'
BREAK END
SET @N = @N - 1
END
EXEC sp_configure @c_max, @c_mma RECONFIGURE
Finish:
SET @r_msg = @r_pre + FORMATMESSAGE('%i: %s', @m_use, @r_msg)
PRINT @@servername + ': ' + @r_msg
GOTO EndOfScript

MemInfo:
/* --------------------------- Subroutine MemInfo -------------------------- */
-- IN : @m_mi: return point: 1 for label MI1 and 2 for label MI2
-- OUT: @m_use: RAM used by isntance,
-- @m_low: low memory condition
-- @r_msg: low memory message
SET @m_low = 1

SELECT @m_use = physical_memory_in_use_kb/1024,
@p_low = process_physical_memory_low ,
@v_low = process_virtual_memory_low
FROM sys.dm_os_process_memory
IF @p_low = 1 OR @v_low = 1 BEGIN
SET @r_msg = 'Low memory.' GOTO LOWMEM END

SELECT @m_gra = cntr_value
FROM sys.dm_os_performance_counters
WHERE counter_name = N'Memory Grants Pending'
IF @m_gra > 0 BEGIN
SET @r_msg = 'Memory grants pending' GOTO LOWMEM END

SET @m_low = 0
LOWMEM:

IF @m_mi = 1 GOTO MI1
IF @m_mi = 2 GOTO MI2

EndOfScript:

[Luuk]

-r[0 | 1]
Redirects the error message output to the screen (stderr). If you do not
specify a parameter or if you specify 0, only error messages that have a
severity level of 11 or higher are redirected. If you specify 1, all
error message output including PRINT is redirected. Has no effect if you
use -o. By default, messages are sent to stdout.

(source:
https://docs.microsoft.com/en-us/sql/tools/sqlcmd-utility?view=sql-server-ver16)



Conclusion: Do not use `-r 0` because of "if you specify 0, only error
messages that have a severity level of 11 or higher are redirected."

[Anton Shepelev]

Luuk:

> -r[0 | 1]
> Redirects the error message output to the screen (stderr).
> If you do not specify a parameter or if you specify 0,
> only error messages that have a severity level of 11 or
> higher are redirected. If you specify 1, all error message
> output including PRINT is redirected. Has no effect if you
> use -o. By default, messages are sent to stdout.

Yes. I inovke `sqlcmd' not only with -r 0, but also with -b:

-b
Specifies that sqlcmd exits and returns a DOS ERRORLEVEL
value when an error occurs. The value that is returned to
the DOS ERRORLEVEL variable is 1 when the SQL Server error
message has a severity level greater than 10

The invocation sqlcmd -r 0 -b should either succeed or print
an error message in STDERR. In my case, however, it failed
but did not send anything to STDERR.

[Anton Shepelev]

I wrote:

> Luuk:
>
> > -r[0 | 1]
> > Redirects the error message output to the screen
> > (stderr). If you do not specify a parameter or if you
> > specify 0, only error messages that have a severity
> > level of 11 or higher are redirected. If you specify 1,
> > all error message output including PRINT is redirected.
> > Has no effect if you use -o. By default, messages are
> > sent to stdout.
>
> Yes. I inovke `sqlcmd' not only with -r 0, but also with
> -b:
>
> -b
> Specifies that sqlcmd exits and returns a DOS ERRORLEVEL
> value when an error occurs. The value that is returned to
> the DOS ERRORLEVEL variable is 1 when the SQL Server error
> message has a severity level greater than 10
>
> The invocation sqlcmd -r 0 -b should either succeed or

> print an error message in stderr. In my case, however, it
> failed but did not send anything to stderr.

To clarify -- my purpose is to cause `sqlcmd' to terminate
with non-zero error code and to send the output to STDERR in
on errors of severity 11 or highter, and to continue
exeuction and send output to STDOUT otherwise. I believe my
invocation is should achieve that end, does it not?