Unable to connect to Azure SQL instance

Neither a connection, or error event are raised... Here is my test case below (sensitive information removed/adjusted, hostname, database, username, password). I also took out a bit of hex that contained the rest of the details.

test.js:

var clone = require('safe-clone-deep');

var Connection = require('tedious').Connection;

var config = {
  userName: 'my-username@hostname',
  password: 'my-password',
  server: 'hostname.database.secure.windows.net',

  options: {
    encrypt: true
    ,database: 'my-database'
    ,useUTC: true
    ,connectTimeout: 5000
    ,debug:{
      packet:true
      ,data:true
      ,payload:true
      ,token:true
    }
  }
};

function show(event) {
  return function(data){
    console.error(event + ': ' + JSON.stringify(clone(data)));
  }
}

var conn = new Connection(config);
conn.on('debug',function(message){
  if (!message) return;
  console.log("DEBUG: " + message);
});

conn.on('connect',show('connect'));
conn.on('end',show('end'));
conn.on('error', show('error'));
conn.on('infoMessage',show('infoMessage'));
conn.on('errorMessage',show('errorMessage'));
conn.on('databaseChange',show('databaseChange'));
conn.on('secure',show('secure'));

output.txt:

DEBUG: connected to hostname.database.secure.windows.net:1433
DEBUG: Sent
DEBUG:   type:0x12(PRELOGIN), status:0x01(EOM), length:0x002F, spid:0x0000, packetId:0x01, window:0x00
DEBUG:   0000  00001A00 06010020 00010200 21000103 00220004 04002600 01FF0000 00010001  ....... ....!... ."....&. ........
  0020  01000000 000000  .......
DEBUG:   PreLogin - version:0.0.0.1 1, encryption:0x01(ON), instopt:0x00, threadId:0x00000000, mars:0x00(OFF)
DEBUG: State change: Connecting -> SentPrelogin
DEBUG: Received
DEBUG:   type:0x04(TABULAR_RESULT), status:0x01(EOM), length:0x002B, spid:0x0000, packetId:0x01, window:0x00
DEBUG:   0000  00001A00 06010020 00010200 21000103 00220000 04002200 01FF0B00 04DF0002  ....... ....!... ."....". ........
  0020  030000  ...
DEBUG:   PreLogin - version:11.0.4.223 2, encryption:0x03(REQ), instopt:0x00, threadId:0x00000000, mars:0x00(OFF)
DEBUG: Sent
DEBUG:   type:0x10(LOGIN7), status:0x01(EOM), length:0x014E, spid:0x0000, packetId:0x01, window:0x00
DEBUG: ################ OMIT HEX OUTPUT WITH SENSITIVE DATA ##################
DEBUG:   Login7 - TDS:0x74000004, PacketSize:0x00001000, ClientProgVer:0x00000000, ClientPID:0x000001BC, ConnectionID:0x00000000
           Flags1:0xE0, Flags2:0x00, TypeFlags:0x00, Flags3:0x08, ClientTimezone:420, ClientLCID:0x00000409
           Hostname:'michaelr_desk', Username:'my-username@hostname', Password:'my-password', AppName:'Tedious', ServerName:'hostname.database.secure.windows.net', LibraryName:'Tedious'
           Language:'undefined', Database:'my-database', SSPI:'', AttachDbFile:'', ChangePassword:''
DEBUG: State change: SentPrelogin -> SentLogin7WithStandardLogin
DEBUG: socket ended
DEBUG: State change: SentLogin7WithStandardLogin -> Final
end: undefined
DEBUG: connection to hostname.database.secure.windows.net:1433 closed
DEBUG: State is already Final

Can you try specifying 'RC4-MD5' as the ciphersuite?

var config = {
  userName: 'my-username@hostname',
  password: 'my-password',
  server: 'hostname.database.secure.windows.net',

  options: {
    encrypt: true
    ,cryptoCredentialsDetails: { ciphers: 'RC4-MD5' }
    ,database: 'my-database'
    ,useUTC: true
    ,connectTimeout: 5000
    ,debug:{
      packet:true
      ,data:true
      ,payload:true
      ,token:true
    }
  }
};

@t

It looks like you're using the auditing enabled endpoint. If you'd like, I can help you directly debug if you email me at chrande "@t" microsoft.com - then put the results up here if we find the issue.

@arthurschreiber

@arthurschreiber Pretty much the same result...

@christopheranderson thanks for the offer to help, emailing directly

Found the issue. Tedious is not properly handling the "REQ" flag on PreLogin packets. I changed Connection.js:808 to if (preloginPayload.encryptionString === 'ON' || preloginPayload.encryptionString === 'REQ' ) { and everything works like gravy. I'll code up a fix, test, and submit the change tonight.

@christopheranderson

@christopheranderson thank you again... this was very appreciated.

@christopheranderson

@christopheranderson Thank you very much for looking into this. I've had problems with encrypted connections before, based on the cipher that was used, but was not able to find the issue. I'll see if this also fixes the problem I've seen.

Okay.. TLS seems to negotiate, but still not connecting... :-(

DEBUG: TLS negotiated (RC4-MD5, TLSv1/SSLv3)
secure
DEBUG: State change: SentTLSSSLNegotiation -> SentLogin7WithStandardLogin
DEBUG: Failed to connect to fxnmojpfxl.database.secure.windows.net:1433 in 10000ms
connection failed
{ [ConnectionError: Failed to connect to fxnmojpfxl.database.secure.windows.net:1433 in 10000ms]
  name: 'ConnectionError',
  message: 'Failed to connect to fxnmojpfxl.database.secure.windows.net:1433 in 10000ms',
  code: 'ETIMEOUT' }

here's the tail of the script, same config as original...


function show(event) {
  return function(data){
    console.log(event);
    return;

    var txt = data && JSON.stringify(clone(data));
    if (txt.length > 1024) {
      console.error(event + ': ' + txt.substr(0,1024));
    } else {
      console.error(event + ': ' + txt);
    }
  }
}

var conn = new Connection(config);
conn.on('debug',function(message){
  if (!message) return;
  if (message.length > 1024) message = message.substr(0,1024) + '//TRIMMED//';
  console.log("DEBUG: " + message);
});


conn.on('error', show('error'));
conn.on('infoMessage',show('infoMessage'));
conn.on('errorMessage',show('errorMessage'));
conn.on('databaseChange',show('databaseChange'));
conn.on('secure',show('secure'));

conn.on('connect',function(err){
  if (err) {
    console.error('connection failed');
    console.error(err);
    process.exit(2);
  }

  console.error('connect done'); //still never seems to happen

  var r = new sql.Request('SEELCT SYSDATETIMEOFFSET() [Now]', function(err,rowcount){
    console.error('request done');
  });
  r.on('row',console.error.bind(console));

});

conn.on('end',function(){
  console.error('end');
  process.exit(3);
});

//shouldn't take this long
setTimeout(function(){
  console.log('timeout');
},10000);

Without specifying the TLS algorythm...

...
DEBUG: TLS negotiated (ECDHE-RSA-AES256-SHA, TLSv1/SSLv3)
secure
DEBUG: State change: SentTLSSSLNegotiation -> SentLogin7WithStandardLogin
DEBUG: Failed to connect to fxnmojpfxl.database.secure.windows.net:1433 in 10000ms
connection failed
{ [ConnectionError: Failed to connect to fxnmojpfxl.database.secure.windows.net:1433 in 10000ms]
  name: 'ConnectionError',
  message: 'Failed to connect to fxnmojpfxl.database.secure.windows.net:1433 in 10000ms',
  code: 'ETIMEOUT' }

So my understanding of what's still broken (besides the TLS 'REQ' issue)
Prelogin sent ->
Prelogin received <-
TLSNegotiation Sent ->
Login7Packet Sent ->
TLSNegotiationComplete <-
Login7Response (looking for LoginAck) <- [FAILURE for .secure. endpoint]

I'm hoping to get the Azure SQL DB team who owns this endpoint to provide me some telemetry to see if they're receiving everything I'm sending.

@christopheranderson

@christopheranderson I don't think this is specific to Azure, it's a general bug inside the way the TLS upgrade is implemented in tedious. I've seen similar problems when trying to establish an encrypted connection on the AppVeyor CI SQL Server instances, unless I manually specified a RC4-MD5 as the cipher suite.

Yeah, I totally believe this is a Tedious issue (since the other Drivers SQL officially supports are working fine). I'm hoping that I can get them to tell me what we're doing wrong, since they have in depth telemetry on connectivity failures.

@arthurschreiber

@arthurschreiber If you're interested in trying this bug out, I can give you a database to play with on Azure. Just message me at my email I posted above. I was thinking of trying to get a V11, V12, and a secure DB dedicated for our CI testing to try and hit these issues earlier.

@christopheranderson

@christopheranderson Having azure DBs for CI would be great!

Per Yosef Dinerstein <yosefd[at]MICROSOFT.com> ...

It seems with the patch in #240 in place, it works if there's no event binding to the 'secure' event... which seems be broken. (At least I can move forward)

test.js

// node mssql-test.js > log.txt 2>&1

var clone = require('safe-clone-deep');

var Connection = require('tedious').Connection;

var config = {
  userName: 'user@dbserv',
  password: 'password',
  server: 'dbserv.database.secure.windows.net',

  options: {
    database: 'dbname'
    ,encrypt: true
    ,useUTC: true
    ,connectTimeout: 10000
    ,debug:{
      packet:true
      ,data:true
      ,payload:true
      ,token:true
    }
  }
};


function show(event) {
  return function(data){
    console.log(event);
    return;

    var txt = data && JSON.stringify(clone(data));
    if (txt.length > 1024) {
      console.error(event + ': ' + txt.substr(0,1024));
    } else {
      console.error(event + ': ' + txt);
    }
  }
}

var connection = new Connection(config);

function show(event) {
  return function(data){
    console.error(event + ': ' + JSON.stringify(clone(data)));
  }
}

var connection = new Connection(config);

connection.on('debug',function(message){
  if (!message) return;
  console.error("DEBUG: " + message);
});

connection.on('connect', function(err){
  console.error('connected');
  process.exit(0);
});
connection.on('end',show('end'));
connection.on('error', show('error'));
connection.on('infoMessage',show('infoMessage'));
connection.on('errorMessage',show('errorMessage'));
connection.on('databaseChange',show('databaseChange'));

// if this line is uncommented, it will not connect properly
//connection.on('secure',show('secure'));

setTimeout(process.exit.bind(process,666),10000); //timeout, nuclear option

That is super weird. What happens if you bind an empty function as the event handler instead of your show function?

@arthurschreiber

@arthurschreiber wild, it still works...

When I use...

connection.on('secure',function(){
  console.log('secure');
  console.log(arguments);
});

It's probably an issue with my clone command, and the buffer, which is relatively huge... causing a timeout during serialization... non-issue, can close 241 too.

Interesting. I'm still seeing this issue in 1.13.2 (if it is even the same -- I'll create a new issue if necessary), with the secure event unbound. If I change the cipher suite to RC4-MD5, it works. If not, I get stuck at SentLogin7WithStandardLogin. It's not an Azure instance. Unfortunately I don't have admin access to the server.

There doesn't seem to be a workaround which will work for all servers, short of adding a "use legacy encryption" flag to our system, because some servers we connect to have RC4 disabled. What's strange is that the "TLS negotiated (ECDHE-RSA-AES256-SHA, TLSv1/SSLv3)" debug message comes through, but after sending the LOGIN7 packet there is no response.

Unfortunately I don't know much about how the TLS upgrade works, or how it should work, or I'd dig deeper into it. I suspect if I did I'd be wasting my efforts.

(SQLCMD for Linux on the same machine has no problems. The problem SQL server seems to be SQL Server 2008 R2, and seems to have Force Encryption on.)

Navigation Menu

Repository navigation

Unable to connect to Azure SQL instance #238

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Unable to connect to Azure SQL instance #238

Description

Activity

arthurschreiber commented on Feb 6, 2015

christopheranderson commented on Feb 8, 2015

tracker1 commented on Feb 9, 2015

christopheranderson commented on Feb 9, 2015

tracker1 commented on Feb 9, 2015

arthurschreiber commented on Feb 9, 2015

tracker1 commented on Feb 9, 2015

tracker1 commented on Feb 9, 2015

christopheranderson commented on Feb 10, 2015

arthurschreiber commented on Feb 10, 2015

christopheranderson commented on Feb 10, 2015

christopheranderson commented on Feb 10, 2015

arthurschreiber commented on Feb 11, 2015

tracker1 commented on Feb 11, 2015

arthurschreiber commented on Feb 11, 2015

tracker1 commented on Feb 11, 2015

lee-houghton commented on Mar 11, 2016

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions