Re: osql: driver line incomplete

On 5-May-11, at 10:31 AM, Dave Dumaresq wrote:

> Greetings, I have freeTDS and unixODBC installed on Ubuntu 10.10, and
> I'm connecting to an SQL Server 2005 host on port 1433 running on a
> vista box.
>
> tsql works fine; however, isql fails with a final error message
> 'Unexpected EOF from the server'
>
> $ sudo isql -v dsn_myvista
> [S1000][unixODBC][FreeTDS][SQL Server]Unable to connect to data source
> [01000][unixODBC][FreeTDS][SQL Server]Adaptive Server connection  
> failed
> [01000][unixODBC][FreeTDS][SQL Server]Unexpected EOF from the server
> [ISQL]ERROR: Could not SQLConnect
>
> I ran this by the folks at unixODBC and they suggested the issue might
> be with freeTDS, since the isql logs show Handle Type = 1, I've
> included the sql dump file below.
>
> I ran osql and found it reports driver line incomplete, but I'm unable
> to figure out what might be the cause. I tried adding Setup=/usr/lib/
> odbc/libtdsS.so to my odbc.ini (even though it's not recommended in
> the freeTDS configuration documentation), but that didn't make any
> difference.
>
> $ osql -S dsn_myvista -U sa -P 1234
> looking for odbc.ini and odbcinst.ini in /usr/local/unixODBC/etc
> 	reading "/home/ddumaresq/.odbc.ini"
> [dsn_myvista] not found in "/home/ddumaresq/.odbc.ini"
> 	reading "/usr/local/unixODBC/etc/odbc.ini"
> [dsn_myvista] found in "/usr/local/unixODBC/etc/odbc.ini"
> found this section:
> 	[dsn_myvista]
> 	##Driver=FreeTDS
> 	Driver=/usr/local/freetds/lib/libtdsodbc.so
> 	Setup=/usr/lib/odbc/libtdsS.so
> 	Description=My local vista box containing ACP
> 	Server=dfd.present.bccampus.ca
> 	Port=1433
> 	User=sa
> 	Password=1234
> 	Database=ldap
> looking for driver for DSN [dsn_myvista]
> driver line incomplete for [dsn_myvista] in odbc.ini
> looking for driver for DSN [default]
> osql: error: no driver found for [dsn_myvista] in odbc.ini
>
> cat /tmp/sql.log
> [ODBC][3011][1304616383.932571][__handles.c][459]
> 		Exit:[SQL_SUCCESS]
> 			Environment = 0x8c59f30
> [ODBC][3011][1304616383.932848][SQLAllocHandle.c][375]
> 		Entry:
> 			Handle Type = 2
> 			Input Handle = 0x8c59f30
> [ODBC][3011][1304616383.932995][SQLAllocHandle.c][493]
> 		Exit:[SQL_SUCCESS]
> 			Output Handle = 0x8c5a6b0
> [ODBC][3011][1304616383.933201][SQLConnect.c][3654]
> 		Entry:
> 			Connection = 0x8c5a6b0
> 			Server Name = [dsn_myvista][length = 11 (SQL_NTS)]
> 			User Name = [sa][length = 2 (SQL_NTS)]
> 			Authentication = [****][length = 4 (SQL_NTS)]
> 		UNICODE Using encoding ASCII 'ISO8859-1' and UNICODE 'UCS-2LE'
>
> 		DIAG [01000] [FreeTDS][SQL Server]Unexpected EOF from the server
>
> 		DIAG [01000] [FreeTDS][SQL Server]Adaptive Server connection failed
>
> 		DIAG [S1000] [FreeTDS][SQL Server]Unable to connect to data source
>
> [ODBC][3011][1304616383.972882][SQLConnect.c][4021]
> 		Exit:[SQL_ERROR]
> [ODBC][3011][1304616383.973055][SQLError.c][434]
> 		Entry:
> 			Connection = 0x8c5a6b0
> 			SQLState = 0xbfb40332
> 			Native = 0xbfb40134
> 			Message Text = 0xbfb4013d
> 			Buffer Length = 500
> 			Text Len Ptr = 0xbfb4013a
> [ODBC][3011][1304616383.973272][SQLError.c][471]
> 		Exit:[SQL_SUCCESS]
> 			SQLState = S1000
> 			Native = 0xbfb40134 -> 0
> 			Message Text = [[unixODBC][FreeTDS][SQL Server]Unable to connect to
> data source]
> [ODBC][3011][1304616383.973441][SQLError.c][434]
> 		Entry:
> 			Connection = 0x8c5a6b0
> 			SQLState = 0xbfb40332
> 			Native = 0xbfb40134
> 			Message Text = 0xbfb4013d
> 			Buffer Length = 500
> 			Text Len Ptr = 0xbfb4013a
> [ODBC][3011][1304616383.973534][SQLError.c][471]
> 		Exit:[SQL_SUCCESS]
> 			SQLState = 01000
> 			Native = 0xbfb40134 -> 20002
> 			Message Text = [[unixODBC][FreeTDS][SQL Server]Adaptive Server
> connection failed]
> [ODBC][3011][1304616383.973623][SQLError.c][434]
> 		Entry:
> 			Connection = 0x8c5a6b0
> 			SQLState = 0xbfb40332
> 			Native = 0xbfb40134
> 			Message Text = 0xbfb4013d
> 			Buffer Length = 500
> 			Text Len Ptr = 0xbfb4013a
> [ODBC][3011][1304616383.973708][SQLError.c][471]
> 		Exit:[SQL_SUCCESS]
> 			SQLState = 01000
> 			Native = 0xbfb40134 -> 20017
> 			Message Text = [[unixODBC][FreeTDS][SQL Server]Unexpected EOF from
> the server]
> [ODBC][3011][1304616383.973795][SQLError.c][434]
> 		Entry:
> 			Connection = 0x8c5a6b0
> 			SQLState = 0xbfb40332
> 			Native = 0xbfb40134
> 			Message Text = 0xbfb4013d
> 			Buffer Length = 500
> 			Text Len Ptr = 0xbfb4013a
> [ODBC][3011][1304616383.973873][SQLError.c][471]
> 		Exit:[SQL_NO_DATA]
> [ODBC][3011][1304616383.973953][SQLError.c][514]
> 		Entry:
> 			Environment = 0x8c59f30
> 			SQLState = 0xbfb40332
> 			Native = 0xbfb40134
> 			Message Text = 0xbfb4013d
> 			Buffer Length = 500
> 			Text Len Ptr = 0xbfb4013a
> [ODBC][3011][1304616383.974032][SQLError.c][551]
> 		Exit:[SQL_NO_DATA]
> [ODBC][3011][1304616383.974203][SQLFreeHandle.c][286]
> 		Entry:
> 			Handle Type = 2
> 			Input Handle = 0x8c5a6b0
> [ODBC][3011][1304616383.974288][SQLFreeHandle.c][337]
> 		Exit:[SQL_SUCCESS]
> [ODBC][3011][1304616383.974378][SQLFreeHandle.c][219]
> 		Entry:
> 			Handle Type = 1
> 			Input Handle = 0x8c59f30
>
>
> --
> Dave Dumaresq
> Technical Analyst - BCcampus
> 200 - 555 Seymour St, Vancouver BC
> Phone: 604-412-7738
>
>
>
>
>
> _______________________________________________
> FreeTDS mailing list
> [email protected]
> http://lists.ibiblio.org/mailman/listinfo/freetds


For what it's worth, here's the dump file from freetds

$ tsql -S dsn_myvista -U sa -P ****

$ cat /tmp/freetds.log
10:46:41.669088 3054 (log.c:190):Starting log file for FreeTDS 0.82
	on 2011-05-05 10:46:41 with debug flags 0xffff.
10:46:41.669986 3054 (iconv.c:197):names for ISO-8859-1: ISO-8859-1
10:46:41.670031 3054 (iconv.c:197):names for UTF-8: UTF-8
10:46:41.670045 3054 (iconv.c:197):names for UCS-2LE: UCS-2LE
10:46:41.670059 3054 (iconv.c:197):names for UCS-2BE: UCS-2BE
10:46:41.670072 3054 (iconv.c:363):iconv to convert client-side data  
to the "UTF-8" character set
10:46:41.670146 3054 (iconv.c:516):tds_iconv_info_init: converting  
"UTF-8"->"UCS-2LE"
10:46:41.670245 3054 (iconv.c:516):tds_iconv_info_init: converting  
"ISO-8859-1"->"UCS-2LE"
10:46:41.670274 3054 (net.c:210):Connecting to 142.232.108.4 port 1433  
(TDS version 8.0)
10:46:41.678029 3054 (net.c:264):tds_open_socket: connect(2) returned  
"Operation now in progress"
10:46:41.678124 3054 (net.c:303):tds_open_socket() succeeded
10:46:41.678166 3054 (util.c:162):Changed query state from DEAD to IDLE
10:46:41.678245 3054 (login.c:735):quietly sending TDS 7+ login packet
10:46:41.678505 3054 (token.c:312):tds_process_login_tokens()
10:46:41.680734 3054 (net.c:592):Received header
0000 04 01 01 a1 00 5c 01 00-                        |.....\..|

10:46:41.680993 3054 (net.c:671):Received packet
0000 e3 1b 00 01 06 6d 00 61-00 73 00 74 00 65 00 72 |.....m.a .s.t.e.r|
0010 00 06 6d 00 61 00 73 00-74 00 65 00 72 00 ab 7a |..m.a.s. t.e.r..z|
0020 00 45 16 00 00 02 00 25-00 43 00 68 00 61 00 6e |.E.....% .C.h.a.n|
0030 00 67 00 65 00 64 00 20-00 64 00 61 00 74 00 61 |.g.e.d.  .d.a.t.a|
0040 00 62 00 61 00 73 00 65-00 20 00 63 00 6f 00 6e |.b.a.s.e . .c.o.n|
0050 00 74 00 65 00 78 00 74-00 20 00 74 00 6f 00 20 |.t.e.x.t . .t.o. |
0060 00 27 00 6d 00 61 00 73-00 74 00 65 00 72 00 27 |.'.m.a.s .t.e.r.'|
0070 00 2e 00 12 55 00 53 00-45 00 52 00 2d 00 50 00 |....U.S. E.R.-.P.|
0080 43 00 5c 00 53 00 51 00-4c 00 45 00 58 00 50 00 |C.\.S.Q. L.E.X.P.|
0090 52 00 45 00 53 00 53 00-00 01 00 e3 08 00 07 05 |R.E.S.S. ........|
00a0 09 04 d0 00 34 00 e3 17-00 02 0a 75 00 73 00 5f |....4... ...u.s._|
00b0 00 65 00 6e 00 67 00 6c-00 69 00 73 00 68 00 00 |.e.n.g.l .i.s.h..|
00c0 ab 7e 00 47 16 00 00 01-00 27 00 43 00 68 00 61 |.~.G.... .'.C.h.a|
00d0 00 6e 00 67 00 65 00 64-00 20 00 6c 00 61 00 6e |.n.g.e.d . .l.a.n|
00e0 00 67 00 75 00 61 00 67-00 65 00 20 00 73 00 65 |.g.u.a.g .e. .s.e|
00f0 00 74 00 74 00 69 00 6e-00 67 00 20 00 74 00 6f |.t.t.i.n .g. .t.o|
0100 00 20 00 75 00 73 00 5f-00 65 00 6e 00 67 00 6c |. .u.s._ .e.n.g.l|
0110 00 69 00 73 00 68 00 2e-00 12 55 00 53 00 45 00 |.i.s.h.. ..U.S.E.|
0120 52 00 2d 00 50 00 43 00-5c 00 53 00 51 00 4c 00 |R.-.P.C. \.S.Q.L.|
0130 45 00 58 00 50 00 52 00-45 00 53 00 53 00 00 01 |E.X.P.R. E.S.S...|
0140 00 ad 36 00 01 71 00 00-01 16 4d 00 69 00 63 00 |..6..q.. ..M.i.c.|
0150 72 00 6f 00 73 00 6f 00-66 00 74 00 20 00 53 00 |r.o.s.o. f.t. .S.|
0160 51 00 4c 00 20 00 53 00-65 00 72 00 76 00 65 00 |Q.L. .S. e.r.v.e.|
0170 72 00 00 00 00 00 09 00-0f c3 e3 13 00 04 04 34 |r....... .......4|
0180 00 30 00 39 00 36 00 04-34 00 30 00 39 00 36 00 |.0.9.6.. 4.0.9.6.|
0190 fd 00 00 00 00 00 00 00-00                      |........ .|

10:46:41.681246 3054 (token.c:316):looking for login token, got   
e3(ENVCHANGE)
10:46:41.681338 3054 (token.c:108):tds_process_default_tokens() marker  
is e3(ENVCHANGE)
10:46:41.681464 3054 (token.c:316):looking for login token, got   
ab(INFO)
10:46:41.681499 3054 (token.c:108):tds_process_default_tokens() marker  
is ab(INFO)
10:46:41.681531 3054 (token.c:2451):tds_process_msg() reading message  
from server
10:46:41.681593 3054 (token.c:2516):tds_process_msg() calling client  
msg handler
10:46:41.681623 3054 (token.c:2529):tds_process_msg() returning  
TDS_SUCCEED
10:46:41.681649 3054 (token.c:316):looking for login token, got   
e3(ENVCHANGE)
10:46:41.681674 3054 (token.c:108):tds_process_default_tokens() marker  
is e3(ENVCHANGE)
10:46:41.681698 3054 (token.c:2281):tds_process_env_chg(): 5 bytes of  
collation data received
10:46:41.681720 3054 (token.c:2282):tds->collation was
0000 00 00 00 00 00         -                        |.....|

10:46:41.681751 3054 (iconv.c:985):setting server single-byte charset  
to "CP1252"
10:46:41.682409 3054 (iconv.c:516):tds_iconv_info_init: converting  
"UTF-8"->"CP1252"
10:46:41.682431 3054 (token.c:2292):tds->collation now
0000 09 04 d0 00 34         -                        |....4|

10:46:41.682452 3054 (token.c:316):looking for login token, got   
e3(ENVCHANGE)
10:46:41.682466 3054 (token.c:108):tds_process_default_tokens() marker  
is e3(ENVCHANGE)
10:46:41.682484 3054 (token.c:316):looking for login token, got   
ab(INFO)
10:46:41.682498 3054 (token.c:108):tds_process_default_tokens() marker  
is ab(INFO)
10:46:41.682512 3054 (token.c:2451):tds_process_msg() reading message  
from server
10:46:41.682529 3054 (token.c:2516):tds_process_msg() calling client  
msg handler
10:46:41.682544 3054 (token.c:2529):tds_process_msg() returning  
TDS_SUCCEED
10:46:41.682557 3054 (token.c:316):looking for login token, got   
ad(LOGINACK)
10:46:41.682573 3054 (token.c:316):looking for login token, got   
e3(ENVCHANGE)
10:46:41.682587 3054 (token.c:108):tds_process_default_tokens() marker  
is e3(ENVCHANGE)
10:46:41.682605 3054 (token.c:316):looking for login token, got   
fd(DONE)
10:46:41.682619 3054 (token.c:108):tds_process_default_tokens() marker  
is fd(DONE)
10:46:41.682633 3054 (token.c:2201):tds_process_end: more_results = 0
		was_cancelled = 0
		error = 0
		done_count_valid = 0
10:46:41.682670 3054 (token.c:2217):tds_process_end() state set to  
TDS_IDLE
10:46:41.682684 3054 (token.c:2232):                rows_affected = 0
10:46:41.682699 3054 (token.c:393):leaving tds_process_login_tokens()  
returning 1
10:46:41.682777 3054 (mem.c:563):tds_free_all_results()
10:46:41.682882 3054 (util.c:162):Changed query state from IDLE to  
QUERYING
10:46:41.686930 3054 (write.c:136):tds_put_string converting 19 bytes  
of "set textsize 64512 "
10:46:41.687024 3054 (write.c:164):tds_put_string wrote 38 bytes
10:46:41.687040 3054 (util.c:162):Changed query state from QUERYING to  
PENDING
10:46:41.687054 3054 (net.c:779):Sending packet
0000 01 01 00 2e 00 00 00 00-73 00 65 00 74 00 20 00 |........ s.e.t. .|
0010 74 00 65 00 78 00 74 00-73 00 69 00 7a 00 65 00 |t.e.x.t. s.i.z.e.|
0020 20 00 36 00 34 00 35 00-31 00 32 00 20 00       | .6.4.5. 1.2. .|

10:46:41.687283 3054 (token.c:495):tds_process_tokens(0x87099d0,  
0xbfb1fedc, 0xbfb1fed8, 0x100)
10:46:41.687301 3054 (util.c:162):Changed query state from PENDING to  
READING
10:46:41.688606 3054 (net.c:592):Received header
0000 04 01 00 11 00 5c 01 00-                        |.....\..|

10:46:41.688672 3054 (net.c:671):Received packet
0000 fd 00 00 be 00 00 00 00-00                      |........ .|

10:46:41.688694 3054 (token.c:510):processing result tokens.  marker  
is  fd(DONE)
10:46:41.688710 3054 (token.c:2201):tds_process_end: more_results = 0
		was_cancelled = 0
		error = 0
		done_count_valid = 0
10:46:41.688725 3054 (token.c:2217):tds_process_end() state set to  
TDS_IDLE
10:46:41.688750 3054 (util.c:162):Changed query state from READING to  
IDLE
10:46:41.688766 3054 (token.c:2232):                rows_affected = 0
10:46:41.688781 3054 (util.c:110):logic error: cannot change query  
state from IDLE to PENDING
10:46:41.688796 3054 (token.c:495):tds_process_tokens(0x87099d0,  
0xbfb1fedc, 0xbfb1fed8, 0x100)
10:46:41.688810 3054 (token.c:498):tds_process_tokens() state is  
COMPLETED
10:46:49.435021 3054 (mem.c:563):tds_free_all_results()
10:46:49.435085 3054 (util.c:162):Changed query state from IDLE to  
QUERYING
10:46:49.435101 3054 (write.c:136):tds_put_string converting 9 bytes  
of "use ldap
"
10:46:49.435124 3054 (write.c:164):tds_put_string wrote 18 bytes
10:46:49.435139 3054 (util.c:162):Changed query state from QUERYING to  
PENDING
10:46:49.435154 3054 (net.c:779):Sending packet
0000 01 01 00 1a 00 00 01 00-75 00 73 00 65 00 20 00 |........ u.s.e. .|
0010 6c 00 64 00 61 00 70 00-0a 00                   |l.d.a.p. ..|

10:46:49.435347 3054 (token.c:495):tds_process_tokens(0x87099d0,  
0xbfb200d4, (nil), 0x6914)
10:46:49.435391 3054 (util.c:162):Changed query state from PENDING to  
READING
10:46:49.436508 3054 (net.c:592):Received header
0000 04 01 00 af 00 5c 01 00-                        |.....\..|

10:46:49.436621 3054 (net.c:671):Received packet
0000 e3 17 00 01 04 6c 00 64-00 61 00 70 00 06 6d 00 |.....l.d .a.p..m.|
0010 61 00 73 00 74 00 65 00-72 00 ab 76 00 45 16 00 |a.s.t.e. r..v.E..|
0020 00 01 00 23 00 43 00 68-00 61 00 6e 00 67 00 65 |...#.C.h .a.n.g.e|
0030 00 64 00 20 00 64 00 61-00 74 00 61 00 62 00 61 |.d. .d.a .t.a.b.a|
0040 00 73 00 65 00 20 00 63-00 6f 00 6e 00 74 00 65 |.s.e. .c .o.n.t.e|
0050 00 78 00 74 00 20 00 74-00 6f 00 20 00 27 00 6c |.x.t. .t .o. .'.l|
0060 00 64 00 61 00 70 00 27-00 2e 00 12 55 00 53 00 |.d.a.p.' ....U.S.|
0070 45 00 52 00 2d 00 50 00-43 00 5c 00 53 00 51 00 |E.R.-.P. C.\.S.Q.|
0080 4c 00 45 00 58 00 50 00-52 00 45 00 53 00 53 00 |L.E.X.P. R.E.S.S.|
0090 00 01 00 e3 08 00 07 05-09 04 d0 00 34 00 fd 00 |........ ....4...|
00a0 00 e2 00 00 00 00 00   -                        |.......|

10:46:49.436714 3054 (token.c:510):processing result tokens.  marker  
is  e3(ENVCHANGE)
10:46:49.436730 3054 (token.c:108):tds_process_default_tokens() marker  
is e3(ENVCHANGE)
10:46:49.436754 3054 (token.c:510):processing result tokens.  marker  
is  ab(INFO)
10:46:49.436769 3054 (token.c:108):tds_process_default_tokens() marker  
is ab(INFO)
10:46:49.436784 3054 (token.c:2451):tds_process_msg() reading message  
from server
10:46:49.436804 3054 (token.c:2516):tds_process_msg() calling client  
msg handler
10:46:49.436818 3054 (token.c:2529):tds_process_msg() returning  
TDS_SUCCEED
10:46:49.436832 3054 (token.c:510):processing result tokens.  marker  
is  e3(ENVCHANGE)
10:46:49.436846 3054 (token.c:108):tds_process_default_tokens() marker  
is e3(ENVCHANGE)
10:46:49.436860 3054 (token.c:2281):tds_process_env_chg(): 5 bytes of  
collation data received
10:46:49.436874 3054 (token.c:2282):tds->collation was
0000 09 04 d0 00 34         -                        |....4|

10:46:49.436895 3054 (iconv.c:985):setting server single-byte charset  
to "CP1252"
10:46:49.436910 3054 (token.c:2292):tds->collation now
0000 09 04 d0 00 34         -                        |....4|

10:46:49.436928 3054 (token.c:510):processing result tokens.  marker  
is  fd(DONE)
10:46:49.436943 3054 (token.c:2201):tds_process_end: more_results = 0
		was_cancelled = 0
		error = 0
		done_count_valid = 0
10:46:49.436957 3054 (token.c:2217):tds_process_end() state set to  
TDS_IDLE
10:46:49.436971 3054 (util.c:162):Changed query state from READING to  
IDLE
10:46:49.436985 3054 (token.c:2232):                rows_affected = 0
10:46:49.436999 3054 (util.c:110):logic error: cannot change query  
state from IDLE to PENDING
10:46:49.437014 3054 (token.c:495):tds_process_tokens(0x87099d0,  
0xbfb200d4, (nil), 0x6914)
10:46:49.437030 3054 (token.c:498):tds_process_tokens() state is  
COMPLETED
10:46:50.876274 3054 (mem.c:563):tds_free_all_results()
10:46:50.876587 3054 (util.c:162):Changed query state from IDLE to DEAD


--
Dave Dumaresq
Technical Analyst - BCcampus
200 - 555 Seymour St, Vancouver BC
Phone: 604-412-7738