microsoft / go-sqlcmd

The new sqlcmd, CLI for SQL Server and Azure SQL (winget install sqlcmd / sqlcmd create mssql / sqlcmd open ads)
https://learn.microsoft.com/sql/tools/sqlcmd/go-sqlcmd-utility
MIT License
393 stars 62 forks source link

"old syntax" fails #247

Closed bweissman closed 1 year ago

bweissman commented 1 year ago

on a windows box, I have set SQLCMDSERVER, SQLCMDUSER and SQLCMDPASSWORD

Old sqlcmd: sqlcmd -Q "SELECT @@version" --> works

go-sqlcmd (using context with same settings): sqlcmd query "select @@version"

Another box (using go-sqlcmd): sqlcmd -Q "SELECT @@version" --> works

This box using go-sqlcmd: sqlcmd -Q "SELECT @@version": unable to open tcp connection with host 'WinServer.bwdemo.io:1433': dial tcp 192.168.100.100:1433: i/o timeout unable to open tcp connection with host 'WinServer.bwdemo.io:1433': dial tcp 192.168.100.100:1433: i/o timeout

That error message seems wrong but I also don't see (on second or first sight) what's missing

shueybubbles commented 1 year ago

@bweissman use --driver-logging-level=65 on the command line to get more diagnostics.

shueybubbles commented 1 year ago

does it fail still if you force tcp by using tcp:WinServer.bwdemo.io as SQLCMDSERVER ?

bweissman commented 1 year ago

DRIVER:unable to get instances from Sql Server Browser on host WinServer.bwdemo.io: read udp 192.168.100.1:56022->192.168.100.100:1434: i/o timeout DRIVER:Skipping protocol np. Error:no named pipe instance matching '' returned from host 'WinServer.bwdemo.io' DRIVER:Dialing with protocol tcp DRIVER:Unable to connect with protocol tcp:unable to open tcp connection with host 'WinServer.bwdemo.io:1433': dial tcp 192.168.100.100:1433: i/o timeout unable to open tcp connection with host 'WinServer.bwdemo.io:1433': dial tcp 192.168.100.100:1433: i/o timeout unable to open tcp connection with host 'WinServer.bwdemo.io:1433': dial tcp 192.168.100.100:1433: i/o timeout

bweissman commented 1 year ago

works when adding the port number to the server

enabling browser service does NOT fix it

bweissman commented 1 year ago

.\sqlcmd\sqlcmd -S "tcp:WinServer.bwdemo.io" -Q "select @@ServerName" --> works .\sqlcmd\sqlcmd -S "WinServer.bwdemo.io,1433" -Q "select @@ServerName" --> works .\sqlcmd\sqlcmd -S "WinServer.bwdemo.io" -Q "select @@ServerName" --> fails

shueybubbles commented 1 year ago

does using -l 60 to increase the login timeout help?

bweissman commented 1 year ago

it does not - however, even with -l 60 or even -l 600, the error fires after 30 seconds. So this must be happening in some place that doesn't take the timeout into account

shueybubbles commented 1 year ago

I think the docs for ODBC sqlcmd may be inaccurate. Supposedly the login timeout default is 8 seconds for it, which empirically is not true in your case.

SQLCMDLOGINTIMEOUT | -l | R/W | "8" (seconds) -- | -- | -- | --

I think go-sqlcmd may need to set a longer value for dial timeout which currently defaults to 15 seconds.

shueybubbles commented 1 year ago

Unfortunately we can't exclude the browser query from the timeout. Both with ODBC and Go, if the browser service is stopped on the remote machine, if you set an infinite timeout on the query the network stack doesn't return an error it just hangs forever.

When browser is stopped and you try to use a named instance, ODBC will use the entire login timeout period. Testing shows 8ish seconds is indeed the default timeout.

17:28:24.52 E:\git>d:\tools\timer.exe sqlcmd -S davidshi-2019\instance
sqlcmd -S davidshi-2019\instance
Sqlcmd: Error: Microsoft ODBC Driver 17 for SQL Server : SQL Server Network Interfaces: Error Locating Server/Instance Specified [xFFFFFFFF]. .
Sqlcmd: Error: Microsoft ODBC Driver 17 for SQL Server : Login timeout expired.
Sqlcmd: Error: Microsoft ODBC Driver 17 for SQL Server : A network-related or instance-specific error has occurred while establishing a connection to SQL Server. Server is not found or not accessible. Check if instance name is correct and if SQL Server is configured to allow remote connections. For more information see SQL Server Books Online..
Results of execution:

    Exit code 1
    Time of execution 9.051

17:28:45.38 E:\git>d:\tools\timer.exe sqlcmd -S davidshi-2019\instance -l 30
sqlcmd -S davidshi-2019\instance -l 30
Sqlcmd: Error: Microsoft ODBC Driver 17 for SQL Server : SQL Server Network Interfaces: Error Locating Server/Instance Specified [xFFFFFFFF]. .
Sqlcmd: Error: Microsoft ODBC Driver 17 for SQL Server : Login timeout expired.
Sqlcmd: Error: Microsoft ODBC Driver 17 for SQL Server : A network-related or instance-specific error has occurred while establishing a connection to SQL Server. Server is not found or not accessible. Check if instance name is correct and if SQL Server is configured to allow remote connections. For more information see SQL Server Books Online..
Results of execution:

    Exit code 1
    Time of execution 30.042

However if you don't provide an instance name, and don't specify a protocol, it still manages to connect quickly using TCP.

17:29:52.64 E:\git>d:\tools\timer.exe sqlcmd -S davidshi-2019 -l 30
sqlcmd -S davidshi-2019 -l 30
1> select net_transport from sys.dm_exec_connections where session_id=@@SPID
2> go
net_transport
----------------------------------------
TCP

I realize now I've been incorrect about the protocol ordering used by ODBC. It seems to use shared memory -> tcp -> named pipe, not TCP last.

I will reorder the protocols in go-sqlcmd to match.

bweissman commented 1 year ago

the interesting part is that sqlcmd query works like a charm - is that using a different order?

shueybubbles commented 1 year ago

I don't know why sqlcmd query would work when the other doesn't.

I found out why I originally chose np over tcp - ODBC used to default to np as well!

Notice the difference from sqlcmd 110 to 170:

c:\>"c:\Program Files\Microsoft SQL Server\110\Tools\Binn\SQLCMD.EXE" -S davidshi-2019\instance -Q "select net_transport from sys.dm_exec_connections where session_id=@@spid"
net_transport
----------------------------------------
Named pipe

(1 rows affected)

c:\>sqlcmd -Q "select net_transport from sys.dm_exec_connections where session_id=@@spid" -S davidshi-2019\instance
net_transport
----------------------------------------
TCP

(1 rows affected)
bweissman commented 1 year ago

I am pretty sure in the end this will be something that will make me look dumb - but I am used to that :D

is there any other flag I can use to get more debug output maybe to see whats happening differently between -Q and query?