I get this error on Linux (Ubuntu and CentOS) when executing a stored proc from Perl/DBI/ODBC/FreeTDS to SQL Azure:
[unixODBC][FreeTDS][SQL Server]Read from the server failed (SQL-08S01)
I don't get this error running the same Perl script on Windows (ODBC/Native) connecting to the same SQL Azure database, and although the proc takes a couple minutes to run, it does complete. Obviously a completely different client/driver environment, but they are both going to the same SQL Azure database and there is no difference in the Perl script itself. Both Perl environments should be similar but obviously the client/drivers will be different.
The line which fails is simple – a proc with no parameters which takes data from a staging table and processes it – at the time of failure from Linux call, the environment on SQL Azure is not significantly different than when I test called from Windows (it is completely reproducible when the staging table is loaded with certain data and invoked from Linux):
$dbh->do("EXEC procname;") or die $DBI::errstr ;
Indications from my searches are that this is some kind of connection issue or timeout.
I'm working to improve the proc performance, but the timeout is not set on the Linux machines (so should default to 0).
Is there something I can do to stop this error?
Here is the log from FreeTDS of a bad run:
util.c:156:Changed query state from IDLE to QUERYING
write.c:140:tds_put_string converting 27 bytes of "EXEC DWTOOLS.LoadFromStage;"
write.c:168:tds_put_string wrote 54 bytes
util.c:156:Changed query state from QUERYING to PENDING
net.c:741:Sending packet
0000 01 01 00 3e 00 00 01 00-45 00 58 00 45 00 43 00 |...>.... E.X.E.C.|
0010 20 00 44 00 57 00 54 00-4f 00 4f 00 4c 00 53 00 | .D.W.T. O.O.L.S.|
0020 2e 00 4c 00 6f 00 61 00-64 00 46 00 72 00 6f 00 |..L.o.a. d.F.r.o.|
0030 6d 00 53 00 74 00 61 00-67 00 65 00 3b 00 |m.S.t.a. g.e.;.|
net.c:1257:GNUTLS: level 4:
REC[0x9a833c8]: Sending Packet[5] Application Data(23) with length: 62
net.c:1257:GNUTLS: level 7:
WRITE: enqueued 101 bytes for 0x9a574b8. Total 101 bytes.
net.c:1257:GNUTLS: level 7:
WRITE FLUSH: 101 bytes in buffer.
net.c:1240:in tds_push_func
net.c:1257:GNUTLS: level 7:
WRITE: wrote 101 bytes, 0 bytes left.
net.c:1257:GNUTLS: level 4:
REC[0x9a833c8]: Sent Packet[6] Application Data(23) with length: 101
token.c:540:tds_process_tokens(0x9a574b8, 0xbfcb9ca8, 0xbfcb9cac, 0x6914)
util.c:156:Changed query state from PENDING to READING
net.c:1199:in tds_pull_func
util.c:331:tdserror(0x9a54e80, 0x9a574b8, 20004, 104)
odbc.c:2270:msgno 20004 20003
util.c:361:tdserror: client library returned TDS_INT_CANCEL(2)
util.c:384:tdserror: returning TDS_INT_CANCEL(2)
util.c:156:Changed query state from READING to DEAD
net.c:1257:GNUTLS: level 7:
READ: -1 returned from 0x9a574b8, errno=104 gerrno=0
net.c:1257:GNUTLS: level 2:
ASSERT: gnutls_buffers.c:344
net.c:1257:GNUTLS: level 2:
ASSERT: gnutls_buffers.c:625
net.c:1257:GNUTLS: level 2:
ASSERT: gnutls_record.c:969
token.c:555:processing result tokens. marker is 0()
token.c:122:tds_process_default_tokens() marker is 0()
token.c:125:leaving tds_process_default_tokens() connection dead
util.c:104:logic error: cannot change query state from DEAD to PENDING
odbc.c:3534:odbc_process_tokens: tds_process_tokens returned 0
odbc.c:3535: result_type=4055, TDS_DONE_COUNT=0, TDS_DONE_ERROR=0
odbc.c:3374:_SQLExecute: odbc_process_tokens returned result_type 4048
odbc.c:3450:SQLExecute: bad results
error.c:517:SQLGetDiagRec(3, 0x9a89fe8, 1, 0xbfcb9ce6, 0xbfcb98b8, 0xbfcb9ae6, 512, 0xbfcb98bc)
error.c:566:SQLGetDiagRec: "[FreeTDS][SQL Server]Read from the server failed"
error.c:517:SQLGetDiagRec(3, 0x9a89fe8, 2, 0xbfcb9ce6, 0xbfcb98b8, 0xbfcb9ae6, 512, 0xbfcb98bc)
odbc.c:3980:SQLFreeHandle(3, 0x9a89fe8)
odbc.c:4075:_SQLFreeStmt(0x9a89fe8, 1, 0)
odbc.c:4718:_SQLGetConnectAttr(0x9a55d78, 102, 0xbfcb9e90, -5, (nil))
odbc.c:2240:SQLDisconnect(0x9a55d78)
mem.c:615:tds_free_all_results()
net.c:1257:GNUTLS: level 6:
BUF[HSK]: Cleared Data from buffer
net.c:1257:GNUTLS: level 4:
REC[0x9a833c8]: Epoch #1 freed
odbc.c:3980:SQLFreeHandle(2, 0x9a55d78)
odbc.c:4006:_SQLFreeConnect(0x9a55d78)
odbc.c:3980:SQLFreeHandle(1, 0x9a552f0)
odbc.c:4050:_SQLFreeEnv(0x9a552f0)
Here is the log from a good run – the same proc, just slightly different data – there seems to be no error running the proc from Windows:
util.c:156:Changed query state from IDLE to QUERYING
write.c:140:tds_put_string converting 27 bytes of "EXEC DWTOOLS.LoadFromStage;"
write.c:168:tds_put_string wrote 54 bytes
util.c:156:Changed query state from QUERYING to PENDING
net.c:741:Sending packet
0000 01 01 00 3e 00 00 01 00-45 00 58 00 45 00 43 00 |...>.... E.X.E.C.|
0010 20 00 44 00 57 00 54 00-4f 00 4f 00 4c 00 53 00 | .D.W.T. O.O.L.S.|
0020 2e 00 4c 00 6f 00 61 00-64 00 46 00 72 00 6f 00 |..L.o.a. d.F.r.o.|
0030 6d 00 53 00 74 00 61 00-67 00 65 00 3b 00 |m.S.t.a. g.e.;.|
net.c:1257:GNUTLS: level 4:
REC[0x96ed3c8]: Sending Packet[5] Application Data(23) with length: 62
net.c:1257:GNUTLS: level 7:
WRITE: enqueued 101 bytes for 0x96c14b8. Total 101 bytes.
net.c:1257:GNUTLS: level 7:
WRITE FLUSH: 101 bytes in buffer.
net.c:1240:in tds_push_func
net.c:1257:GNUTLS: level 7:
WRITE: wrote 101 bytes, 0 bytes left.
net.c:1257:GNUTLS: level 4:
REC[0x96ed3c8]: Sent Packet[6] Application Data(23) with length: 101
token.c:540:tds_process_tokens(0x96c14b8, 0xbfd5aeb8, 0xbfd5aebc, 0x6914)
util.c:156:Changed query state from PENDING to READING
net.c:1199:in tds_pull_func
net.c:1257:GNUTLS: level 7:
READ: Got 5 bytes from 0x96c14b8
net.c:1257:GNUTLS: level 7:
READ: read 5 bytes from 0x96c14b8
net.c:1257:GNUTLS: level 7:
RB: Have 0 bytes into buffer. Adding 5 bytes.
net.c:1257:GNUTLS: level 7:
RB: Requested 5 bytes
net.c:1257:GNUTLS: level 4:
REC[0x96ed3c8]: Expected Packet[5] Application Data(23) with length: 8
net.c:1257:GNUTLS: level 4:
REC[0x96ed3c8]: Received Packet[5] Application Data(23) with length: 48
net.c:1199:in tds_pull_func
net.c:1257:GNUTLS: level 7:
READ: Got 48 bytes from 0x96c14b8
net.c:1257:GNUTLS: level 7:
READ: read 48 bytes from 0x96c14b8
net.c:1257:GNUTLS: level 7:
RB: Have 5 bytes into buffer. Adding 48 bytes.
net.c:1257:GNUTLS: level 7:
RB: Requested 53 bytes
net.c:1257:GNUTLS: level 4:
REC[0x96ed3c8]: Decrypted Packet[5] Application Data(23) with length: 22
net.c:1257:GNUTLS: level 6:
BUF[REC]: Inserted 22 bytes of Data(23)
net.c:1257:GNUTLS: level 6:
BUFFER[REC][AD]: Read 8 bytes of Data(23)
net.c:555:Received header
0000 04 01 00 16 03 2f 01 00- |...../..|
net.c:1257:GNUTLS: level 6:
BUFFER[REC][AD]: Read 14 bytes of Data(23)
net.c:609:Received packet
0000 04 01 00 16 03 2f 01 00-79 00 00 00 00 fe 00 00 |...../.. y.......|
0010 e0 00 00 00 00 00 - |......|
token.c:555:processing result tokens. marker is 79(RETURNSTATUS)
token.c:690:tds_process_tokens: return status is 0
util.c:156:Changed query state from READING to PENDING
odbc.c:3534:odbc_process_tokens: tds_process_tokens returned 1
odbc.c:3535: result_type=4043, TDS_DONE_COUNT=0, TDS_DONE_ERROR=0
token.c:540:tds_process_tokens(0x96c14b8, 0xbfd5aeb8, 0xbfd5aebc, 0x6914)
util.c:156:Changed query state from PENDING to READING
token.c:555:processing result tokens. marker is fe(DONEPROC)
token.c:2339:tds_process_end: more_results = 0
was_cancelled = 0
error = 0
done_count_valid = 0
token.c:2355:tds_process_end() state set to TDS_IDLE
util.c:156:Changed query state from READING to IDLE
token.c:2370: rows_affected = 0
util.c:104:logic error: cannot change query state from IDLE to PENDING
odbc.c:3534:odbc_process_tokens: tds_process_tokens returned 1
odbc.c:3535: result_type=4053, TDS_DONE_COUNT=0, TDS_DONE_ERROR=0
odbc.c:3578:odbc_process_tokens: processed TDS_DONEPROC_RESULT
token.c:540:tds_process_tokens(0x96c14b8, 0xbfd5aeb8, 0xbfd5aebc, 0x26914)
token.c:543:tds_process_tokens() state is COMPLETED
odbc.c:3534:odbc_process_tokens: tds_process_tokens returned 2
odbc.c:3535: result_type=4052, TDS_DONE_COUNT=0, TDS_DONE_ERROR=0
odbc.c:3374:_SQLExecute: odbc_process_tokens returned result_type 4046
odbc.c:4506:_SQLRowCount(0x96f3fe8, 0xbfd5b0b8)
odbc.c:4525:SQLRowCount returns 0, row count -1
odbc.c:3980:SQLFreeHandle(3, 0x96f3fe8)
odbc.c:4075:_SQLFreeStmt(0x96f3fe8, 1, 0)
odbc.c:4718:_SQLGetConnectAttr(0x96bfd78, 102, 0xbfd5b240, -5, (nil))
odbc.c:2240:SQLDisconnect(0x96bfd78)
mem.c:615:tds_free_all_results()
net.c:1257:GNUTLS: level 6:
BUF[HSK]: Cleared Data from buffer
net.c:1257:GNUTLS: level 4:
REC[0x96ed3c8]: Epoch #1 freed
util.c:156:Changed query state from IDLE to DEAD
odbc.c:3980:SQLFreeHandle(2, 0x96bfd78)
odbc.c:4006:_SQLFreeConnect(0x96bfd78)
odbc.c:3980:SQLFreeHandle(1, 0x96bf2f0)
odbc.c:4050:_SQLFreeEnv(0x96bf2f0)
Best Answer
I could be that the Linux TDS implementation is outdated compared with the SQL Server version Windows Azure uses. See: http://msdn.microsoft.com/en-us/library/dd340799.aspx. At least the FreeTDS docs at http://www.freetds.org/userguide/tdshistory.htm indicate they are not up to par with the latest versions. Try to connect using JDBC on your Linux machine for instance see if that works better.