freetds AT lists.ibiblio.org

Subject: FreeTDS Development Group

List archive

Re: [freetds] osql: driver line incomplete

From: Dave Dumaresq <ddumaresq AT bccampus.ca>
To: FreeTDS Development Group <freetds AT lists.ibiblio.org>
Subject: Re: [freetds] osql: driver line incomplete
Date: Thu, 5 May 2011 10:51:37 -0700

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
FreeTDS AT lists.ibiblio.org
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

[freetds] osql: driver line incomplete, Dave Dumaresq, 05/05/2011
- Re: [freetds] osql: driver line incomplete, Dave Dumaresq, 05/05/2011
- Re: [freetds] osql: driver line incomplete, Dave Dumaresq, 05/05/2011
  - Re: [freetds] osql: driver line incomplete, jklowden, 05/06/2011
    - Re: [freetds] osql: driver line incomplete, Dave Dumaresq, 05/09/2011
      - Re: [freetds] osql: driver line incomplete, James K. Lowden, 05/10/2011