[freetds] Exececute procedure returns errors

David Keith dkeith at logisticshealth.com
Tue Jul 27 12:43:14 EDT 2004


Jim, Joseph -

    Thanks for the assist. I configured SQL 2K to use fibers, but I'm
still getting the same errors. Let me describe how the app works.

    If you understand multhreaded apps that simultaneously generate
multiple database sessions, then pool those sessions, then you
understand how I'm using Asta. In addition to that, each threaded
database module - kylix-speak for non-graphical component container - is
creating an instance of a datamodule that has an additional
database/odbc component on it. So you could say the 'parent' datamodule
creates a 'child' datamodule, each datamodule has it's own
database/connection/session. And the 'parent' datamodule has multiple
instances - 5 to start off with - each having it's own 'child'.

    I attempted to use just the database session component on the
'parent' datamodule, and pass a pointer of it to the 'child'
datamodule's constructor, then point the query components on the 'child'
datamodule to the session component pointer. This caused all server
functions to stop working, each returning the 'Unable to retrieve ODBC
Error' error message. So I went back to each 'parent' and each 'child'
having it's own session (ODBC Express 'hdbc') component.

    Jim - here's 37k of the freetds.log file, let me know if you need more:


Received packet @ 10:48:00.193189
0000 fd 20 00 fd 00 00 00 00-00                      |. ...... .|


10:48:00.193230 tds_process_end: more_results = 0
                was_cancelled = 1
                error = 0
                done_count_valid = 0
10:48:00.193266 tds_process_end() state set to TDS_IDLESQLFreeHandle(3,
0x8402450)
10:48:00.194994 tds_put_string converting 69 bytes of "sp_sproc_columns
@procedure_owner='dbo', at procedure_name='GETSYSUSERS'"
10:48:00.195064 tds_put_string wrote 138 bytes
Sending packet @ 10:48:00.195092
0000 01 01 00 92 00 00 01 00-73 00 70 00 5f 00 73 00 |........ s.p._.s.|
0010 70 00 72 00 6f 00 63 00-5f 00 63 00 6f 00 6c 00 |p.r.o.c. _.c.o.l.|
0020 75 00 6d 00 6e 00 73 00-20 00 40 00 70 00 72 00 |u.m.n.s.  . at .p.r.|
0030 6f 00 63 00 65 00 64 00-75 00 72 00 65 00 5f 00 |o.c.e.d. u.r.e._.|
0040 6f 00 77 00 6e 00 65 00-72 00 3d 00 27 00 64 00 |o.w.n.e. r.=.'.d.|
0050 62 00 6f 00 27 00 2c 00-40 00 70 00 72 00 6f 00 |b.o.'.,. @.p.r.o.|
0060 63 00 65 00 64 00 75 00-72 00 65 00 5f 00 6e 00 |c.e.d.u. r.e._.n.|
0070 61 00 6d 00 65 00 3d 00-27 00 47 00 45 00 54 00 |a.m.e.=. '.G.E.T.|
0080 53 00 59 00 53 00 55 00-53 00 45 00 52 00 53 00 |S.Y.S.U. S.E.R.S.|
0090 27 00                  -                        |'.|


Received header @ 10:48:00.196442
0000 04 01 03 c6 00 36 01 00-                        |.....6..|


Received packet @ 10:48:00.196537
0000 ff 01 00 c0 00 00 00 00-00 ff 11 00 c1 00 01 00 |........ ........|
0010 00 00 ff 01 00 c0 00 00-00 00 00 ff 01 00 c0 00 |........ ........|
0020 00 00 00 00 ff 11 00 c1-00 01 00 00 00 ff 01 00 |........ ........|
0030 c0 00 00 00 00 00 ff 11-00 c1 00 01 00 00 00 ff |........ ........|
0040 11 00 c1 00 01 00 00 00-ff 01 00 c0 00 00 00 00 |........ ........|
0050 00 ff 01 00 c0 00 00 00-00 00 ff 11 00 c1 00 01 |........ ........|
0060 00 00 00 ff 11 00 c1 00-01 00 00 00 ff 01 00 c0 |........ ........|
0070 00 00 00 00 00 81 14 00-00 01 01 00 e7 00 01 09 |........ ........|
0080 04 d0 00 34 13 50 00 52-00 4f 00 43 00 45 00 44 |...4.P.R .O.C.E.D|
0090 00 55 00 52 00 45 00 5f-00 51 00 55 00 41 00 4c |.U.R.E._ .Q.U.A.L|
00a0 00 49 00 46 00 49 00 45-00 52 00 00 01 01 00 e7 |.I.F.I.E .R......|
00b0 00 01 09 04 d0 00 34 0f-50 00 52 00 4f 00 43 00 |......4. P.R.O.C.|
00c0 45 00 44 00 55 00 52 00-45 00 5f 00 4f 00 57 00 |E.D.U.R. E._.O.W.|
00d0 4e 00 45 00 52 00 00 00-01 00 e7 0c 01 09 04 d0 |N.E.R... ........|
00e0 00 34 0e 50 00 52 00 4f-00 43 00 45 00 44 00 55 |.4.P.R.O .C.E.D.U|
00f0 00 52 00 45 00 5f 00 4e-00 41 00 4d 00 45 00 00 |.R.E._.N .A.M.E..|
0100 01 01 00 e7 00 01 09 04-d0 00 34 0b 43 00 4f 00 |........ ..4.C.O.|
0110 4c 00 55 00 4d 00 4e 00-5f 00 4e 00 41 00 4d 00 |L.U.M.N. _.N.A.M.|
0120 45 00 00 00 01 00 26 02-0b 43 00 4f 00 4c 00 55 |E.....&. .C.O.L.U|
0130 00 4d 00 4e 00 5f 00 54-00 59 00 50 00 45 00 00 |.M.N._.T .Y.P.E..|
0140 00 09 00 26 02 09 44 00-41 00 54 00 41 00 5f 00 |...&..D. A.T.A._.|
0150 54 00 59 00 50 00 45 00-00 01 09 00 e7 00 01 09 |T.Y.P.E. ........|
0160 04 d0 00 34 09 54 00 59-00 50 00 45 00 5f 00 4e |...4.T.Y .P.E._.N|
0170 00 41 00 4d 00 45 00 00-00 01 00 26 04 09 50 00 |.A.M.E.. ...&..P.|
0180 52 00 45 00 43 00 49 00-53 00 49 00 4f 00 4e 00 |R.E.C.I. S.I.O.N.|
0190 00 00 01 00 26 04 06 4c-00 45 00 4e 00 47 00 54 |....&..L .E.N.G.T|
01a0 00 48 00 00 00 01 00 26-02 05 53 00 43 00 41 00 |.H.....& ..S.C.A.|
01b0 4c 00 45 00 00 00 09 00-26 02 05 52 00 41 00 44 |L.E..... &..R.A.D|
01c0 00 49 00 58 00 00 00 09-00 26 02 08 4e 00 55 00 |.I.X.... .&..N.U.|
01d0 4c 00 4c 00 41 00 42 00-4c 00 45 00 00 00 01 00 |L.L.A.B. L.E.....|
01e0 a7 fe 00 09 04 d0 00 34-07 52 00 45 00 4d 00 41 |.......4 .R.E.M.A|
01f0 00 52 00 4b 00 53 00 00-00 01 00 e7 40 1f 09 04 |.R.K.S.. .... at ...|
0200 d0 00 34 0a 43 00 4f 00-4c 00 55 00 4d 00 4e 00 |..4.C.O. L.U.M.N.|
0210 5f 00 44 00 45 00 46 00-00 00 09 00 26 02 0d 53 |_.D.E.F. ....&..S|
0220 00 51 00 4c 00 5f 00 44-00 41 00 54 00 41 00 5f |.Q.L._.D .A.T.A._|
0230 00 54 00 59 00 50 00 45-00 00 00 09 00 26 02 10 |.T.Y.P.E .....&..|
0240 53 00 51 00 4c 00 5f 00-44 00 41 00 54 00 45 00 |S.Q.L._. D.A.T.E.|
0250 54 00 49 00 4d 00 45 00-5f 00 53 00 55 00 42 00 |T.I.M.E. _.S.U.B.|
0260 00 00 01 00 26 04 11 43-00 48 00 41 00 52 00 5f |....&..C .H.A.R._|
0270 00 4f 00 43 00 54 00 45-00 54 00 5f 00 4c 00 45 |.O.C.T.E .T._.L.E|
0280 00 4e 00 47 00 54 00 48-00 00 00 01 00 26 04 10 |.N.G.T.H .....&..|
0290 4f 00 52 00 44 00 49 00-4e 00 41 00 4c 00 5f 00 |O.R.D.I. N.A.L._.|
02a0 50 00 4f 00 53 00 49 00-54 00 49 00 4f 00 4e 00 |P.O.S.I. T.I.O.N.|
02b0 00 00 01 00 a7 fe 00 09-04 d0 00 34 0b 49 00 53 |........ ...4.I.S|
02c0 00 5f 00 4e 00 55 00 4c-00 4c 00 41 00 42 00 4c |._.N.U.L .L.A.B.L|
02d0 00 45 00 00 00 21 00 26-01 0c 53 00 53 00 5f 00 |.E...!.& ..S.S._.|
02e0 44 00 41 00 54 00 41 00-5f 00 54 00 59 00 50 00 |D.A.T.A. _.T.Y.P.|
02f0 45 00 a9 08 00 01 00 02-00 03 00 12 00 d1 20 00 |E....... ...... .|
0300 57 00 65 00 62 00 53 00-63 00 68 00 65 00 6d 00 |W.e.b.S. c.h.e.m.|
0310 61 00 4d 00 61 00 6e 00-61 00 67 00 65 00 72 00 |a.M.a.n. a.g.e.r.|
0320 06 00 64 00 62 00 6f 00-1a 00 47 00 45 00 54 00 |..d.b.o. ..G.E.T.|
0330 53 00 59 00 53 00 55 00-53 00 45 00 52 00 53 00 |S.Y.S.U. S.E.R.S.|
0340 3b 00 31 00 1a 00 40 00-52 00 45 00 54 00 55 00 |;.1... at . R.E.T.U.|
0350 52 00 4e 00 5f 00 56 00-41 00 4c 00 55 00 45 00 |R.N._.V. A.L.U.E.|
0360 02 05 00 02 04 00 06 00-69 00 6e 00 74 00 04 0a |........ i.n.t...|
0370 00 00 00 04 04 00 00 00-02 00 00 02 0a 00 02 00 |........ ........|
0380 00 ff ff ff ff 02 04 00-00 00 04 00 00 00 00 02 |........ ........|
0390 00 4e 4f 01 38 ff 11 00-c1 00 01 00 00 00 ff 01 |.NO.8... ........|
03a0 00 ca 00 01 00 00 00 ff-01 00 ca 00 01 00 00 00 |........ ........|
03b0 79 00 00 00 00 fe 00 00-e0 00 01 00 00 00       |y....... ......|


10:48:00.197924 processing result tokens.  marker is  ff(DONEINPROC)
10:48:00.197957 tds_process_end: more_results = 1
                was_cancelled = 0
                error = 0
                done_count_valid = 0
10:48:00.197996 processing result tokens.  marker is  ff(DONEINPROC)
10:48:00.198022 tds_process_end: more_results = 1
                was_cancelled = 0
                error = 0
                done_count_valid = 1
10:48:00.198058                  rows_affected = 1
10:48:00.198082 processing result tokens.  marker is  ff(DONEINPROC)
10:48:00.198108 tds_process_end: more_results = 1
                was_cancelled = 0
                error = 0
                done_count_valid = 0
10:48:00.198144 processing result tokens.  marker is  ff(DONEINPROC)
10:48:00.198170 tds_process_end: more_results = 1
                was_cancelled = 0
                error = 0
                done_count_valid = 0
10:48:00.198206 processing result tokens.  marker is  ff(DONEINPROC)
10:48:00.198232 tds_process_end: more_results = 1
                was_cancelled = 0
                error = 0
                done_count_valid = 1
10:48:00.198268                  rows_affected = 1
10:48:00.198292 processing result tokens.  marker is  ff(DONEINPROC)
10:48:00.198318 tds_process_end: more_results = 1
                was_cancelled = 0
                error = 0
                done_count_valid = 0
10:48:00.198354 processing result tokens.  marker is  ff(DONEINPROC)
10:48:00.198380 tds_process_end: more_results = 1
                was_cancelled = 0
                error = 0
                done_count_valid = 1
10:48:00.198416                  rows_affected = 1
10:48:00.198440 processing result tokens.  marker is  ff(DONEINPROC)
10:48:00.198466 tds_process_end: more_results = 1
                was_cancelled = 0
                error = 0
                done_count_valid = 1
10:48:00.198502                  rows_affected = 1
10:48:00.198558 processing result tokens.  marker is  ff(DONEINPROC)
10:48:00.198585 tds_process_end: more_results = 1
                was_cancelled = 0
                error = 0
                done_count_valid = 0
10:48:00.198622 processing result tokens.  marker is  ff(DONEINPROC)
10:48:00.198648 tds_process_end: more_results = 1
                was_cancelled = 0
                error = 0
                done_count_valid = 0
10:48:00.198684 processing result tokens.  marker is  ff(DONEINPROC)
10:48:00.198710 tds_process_end: more_results = 1
                was_cancelled = 0
                error = 0
                done_count_valid = 1
10:48:00.198746                  rows_affected = 1
10:48:00.198770 processing result tokens.  marker is  ff(DONEINPROC)
10:48:00.198796 tds_process_end: more_results = 1
                was_cancelled = 0
                error = 0
                done_count_valid = 1
10:48:00.198832                  rows_affected = 1
10:48:00.198856 processing result tokens.  marker is  ff(DONEINPROC)
10:48:00.198882 tds_process_end: more_results = 1
                was_cancelled = 0
                error = 0
                done_count_valid = 0
10:48:00.198919 processing result tokens.  marker is  81(TDS7_RESULT)
10:48:00.199020 adjust_character_column_size:
        Server charset: UCS-2LE
        Server column_size: 256
        Client charset: ISO-8859-1
        Client column_size: 128
tds_get_string: reading 38 from wire to give 19 to client.
10:48:00.199102 tds7_get_data_info:1451:
        colname = PROCEDURE_QUALIFIER (19 bytes)
        type = 39 (varchar)
        server's type = 231 (x UCS-2 varchar)
        column_varint_size = 2
        column_size = 128 (256 on server)
10:48:00.199154 adjust_character_column_size:
        Server charset: UCS-2LE
        Server column_size: 256
        Client charset: ISO-8859-1
        Client column_size: 128
tds_get_string: reading 30 from wire to give 15 to client.
10:48:00.199218 tds7_get_data_info:1451:
        colname = PROCEDURE_OWNER (15 bytes)
        type = 39 (varchar)
        server's type = 231 (x UCS-2 varchar)
        column_varint_size = 2
        column_size = 128 (256 on server)
10:48:00.199268 adjust_character_column_size:
        Server charset: UCS-2LE
        Server column_size: 268
        Client charset: ISO-8859-1
        Client column_size: 134
tds_get_string: reading 28 from wire to give 14 to client.
10:48:00.199332 tds7_get_data_info:1451:
        colname = PROCEDURE_NAME (14 bytes)
        type = 39 (varchar)
        server's type = 231 (x UCS-2 varchar)
        column_varint_size = 2
        column_size = 134 (268 on server)
10:48:00.199381 adjust_character_column_size:
        Server charset: UCS-2LE
        Server column_size: 256
        Client charset: ISO-8859-1
        Client column_size: 128
tds_get_string: reading 22 from wire to give 11 to client.
10:48:00.199445 tds7_get_data_info:1451:
        colname = COLUMN_NAME (11 bytes)
        type = 39 (varchar)
        server's type = 231 (x UCS-2 varchar)
        column_varint_size = 2
        column_size = 128 (256 on server)
tds_get_string: reading 22 from wire to give 11 to client.
10:48:00.199517 tds7_get_data_info:1451:
        colname = COLUMN_TYPE (11 bytes)
        type = 38 (integer-null)
        server's type = 38 (integer-null)
        column_varint_size = 1
        column_size = 2 (2 on server)
tds_get_string: reading 18 from wire to give 9 to client.
10:48:00.199589 tds7_get_data_info:1451:
        colname = DATA_TYPE (9 bytes)
        type = 38 (integer-null)
        server's type = 38 (integer-null)
        column_varint_size = 1
        column_size = 2 (2 on server)
10:48:00.199639 adjust_character_column_size:
        Server charset: UCS-2LE
        Server column_size: 256
        Client charset: ISO-8859-1
        Client column_size: 128
tds_get_string: reading 18 from wire to give 9 to client.
10:48:00.199702 tds7_get_data_info:1451:
        colname = TYPE_NAME (9 bytes)
        type = 39 (varchar)
        server's type = 231 (x UCS-2 varchar)
        column_varint_size = 2
        column_size = 128 (256 on server)
tds_get_string: reading 18 from wire to give 9 to client.
10:48:00.199774 tds7_get_data_info:1451:
        colname = PRECISION (9 bytes)
        type = 38 (integer-null)
        server's type = 38 (integer-null)
        column_varint_size = 1
        column_size = 4 (4 on server)
tds_get_string: reading 12 from wire to give 6 to client.
10:48:00.199846 tds7_get_data_info:1451:
        colname = LENGTH (6 bytes)
        type = 38 (integer-null)
        server's type = 38 (integer-null)
        column_varint_size = 1
        column_size = 4 (4 on server)
tds_get_string: reading 10 from wire to give 5 to client.
10:48:00.199955 tds7_get_data_info:1451:
        colname = SCALE (5 bytes)
        type = 38 (integer-null)
        server's type = 38 (integer-null)
        column_varint_size = 1
        column_size = 2 (2 on server)
tds_get_string: reading 10 from wire to give 5 to client.
10:48:00.200028 tds7_get_data_info:1451:
        colname = RADIX (5 bytes)
        type = 38 (integer-null)
        server's type = 38 (integer-null)
        column_varint_size = 1
        column_size = 2 (2 on server)
tds_get_string: reading 16 from wire to give 8 to client.
10:48:00.200100 tds7_get_data_info:1451:
        colname = NULLABLE (8 bytes)
        type = 38 (integer-null)
        server's type = 38 (integer-null)
        column_varint_size = 1
        column_size = 2 (2 on server)
10:48:00.200150 adjust_character_column_size:
        Server charset: CP1252
        Server column_size: 254
        Client charset: ISO-8859-1
        Client column_size: 254
tds_get_string: reading 14 from wire to give 7 to client.
10:48:00.200214 tds7_get_data_info:1451:
        colname = REMARKS (7 bytes)
        type = 39 (varchar)
        server's type = 167 (xvarchar)
        column_varint_size = 2
        column_size = 254 (254 on server)
10:48:00.200264 adjust_character_column_size:
        Server charset: UCS-2LE
        Server column_size: 8000
        Client charset: ISO-8859-1
        Client column_size: 4000
tds_get_string: reading 20 from wire to give 10 to client.
10:48:00.200328 tds7_get_data_info:1451:
        colname = COLUMN_DEF (10 bytes)
        type = 39 (varchar)
        server's type = 231 (x UCS-2 varchar)
        column_varint_size = 2
        column_size = 4000 (8000 on server)
tds_get_string: reading 26 from wire to give 13 to client.
10:48:00.200400 tds7_get_data_info:1451:
        colname = SQL_DATA_TYPE (13 bytes)
        type = 38 (integer-null)
        server's type = 38 (integer-null)
        column_varint_size = 1
        column_size = 2 (2 on server)
tds_get_string: reading 32 from wire to give 16 to client.
10:48:00.200472 tds7_get_data_info:1451:
        colname = SQL_DATETIME_SUB (16 bytes)
        type = 38 (integer-null)
        server's type = 38 (integer-null)
        column_varint_size = 1
        column_size = 2 (2 on server)
tds_get_string: reading 34 from wire to give 17 to client.
10:48:00.200544 tds7_get_data_info:1451:
        colname = CHAR_OCTET_LENGTH (17 bytes)
        type = 38 (integer-null)
        server's type = 38 (integer-null)
        column_varint_size = 1
        column_size = 4 (4 on server)
tds_get_string: reading 32 from wire to give 16 to client.
10:48:00.200617 tds7_get_data_info:1451:
        colname = ORDINAL_POSITION (16 bytes)
        type = 38 (integer-null)
        server's type = 38 (integer-null)
        column_varint_size = 1
        column_size = 4 (4 on server)
10:48:00.200666 adjust_character_column_size:
        Server charset: CP1252
        Server column_size: 254
        Client charset: ISO-8859-1
        Client column_size: 254
tds_get_string: reading 22 from wire to give 11 to client.
10:48:00.200730 tds7_get_data_info:1451:
        colname = IS_NULLABLE (11 bytes)
        type = 39 (varchar)
        server's type = 167 (xvarchar)
        column_varint_size = 2
        column_size = 254 (254 on server)
tds_get_string: reading 24 from wire to give 12 to client.
10:48:00.200802 tds7_get_data_info:1451:
        colname = SS_DATA_TYPE (12 bytes)
        type = 38 (integer-null)
        server's type = 38 (integer-null)
        column_varint_size = 1
        column_size = 1 (1 on server)
10:48:00.200865 processing result tokens.  marker is  a9(ORDERBY)
10:48:00.200896 tds_process_default_tokens() marker is a9(ORDERBY)
10:48:00.200923 token.c:212: Eating ORDERBY token
10:48:00.200945 processing result tokens.  marker is  d1(ROW)
odbc:SQLColAttribute: fDescType is 8
odbc:SQLColAttribute: fDescType is 8
odbc:SQLColAttribute: fDescType is 8
odbc:SQLColAttribute: fDescType is 8
odbc:SQLColAttribute: fDescType is 8
odbc:SQLColAttribute: fDescType is 8
odbc:SQLColAttribute: fDescType is 8
odbc:SQLColAttribute: fDescType is 8
odbc:SQLColAttribute: fDescType is 8
odbc:SQLColAttribute: fDescType is 8
odbc:SQLColAttribute: fDescType is 8
odbc:SQLColAttribute: fDescType is 8
10:48:00.207362 processing row tokens.  marker is  d1(ROW)
10:48:00.207423 processing row.  column is 0 varint size = 2
10:48:00.207452 processing row.  column size is 32
10:48:00.207477 clearing column 0 NULL bit
10:48:00.207516 processing row.  column is 1 varint size = 2
10:48:00.207578 processing row.  column size is 6
10:48:00.207603 clearing column 1 NULL bit
10:48:00.207627 processing row.  column is 2 varint size = 2
10:48:00.207654 processing row.  column size is 26
10:48:00.207678 clearing column 2 NULL bit
10:48:00.207702 processing row.  column is 3 varint size = 2
10:48:00.207728 processing row.  column size is 26
10:48:00.207752 clearing column 3 NULL bit
10:48:00.207776 processing row.  column is 4 varint size = 1
10:48:00.207803 processing row.  column size is 2
10:48:00.207827 clearing column 4 NULL bit
10:48:00.207849 processing row.  column is 5 varint size = 1
10:48:00.207876 processing row.  column size is 2
10:48:00.207899 clearing column 5 NULL bit
10:48:00.207922 processing row.  column is 6 varint size = 2
10:48:00.207948 processing row.  column size is 6
10:48:00.207972 clearing column 6 NULL bit
10:48:00.207995 processing row.  column is 7 varint size = 1
10:48:00.208022 processing row.  column size is 4
10:48:00.208046 clearing column 7 NULL bit
10:48:00.208069 processing row.  column is 8 varint size = 1
10:48:00.208095 processing row.  column size is 4
10:48:00.208119 clearing column 8 NULL bit
10:48:00.208141 processing row.  column is 9 varint size = 1
10:48:00.208168 processing row.  column size is 2
10:48:00.208191 clearing column 9 NULL bit
10:48:00.208214 processing row.  column is 10 varint size = 1
10:48:00.208240 processing row.  column size is 2
10:48:00.208264 clearing column 10 NULL bit
10:48:00.208286 processing row.  column is 11 varint size = 1
10:48:00.208312 processing row.  column size is 2
10:48:00.208336 clearing column 11 NULL bit
10:48:00.208359 processing row.  column is 12 varint size = 2
10:48:00.208385 processing row.  column size is 0
10:48:00.208410 setting column 12 NULL bit
10:48:00.208431 processing row.  column is 13 varint size = 2
10:48:00.208458 processing row.  column size is 0
10:48:00.208481 setting column 13 NULL bit
10:48:00.208503 processing row.  column is 14 varint size = 1
10:48:00.208529 processing row.  column size is 2
10:48:00.208553 clearing column 14 NULL bit
10:48:00.208575 processing row.  column is 15 varint size = 1
10:48:00.208602 processing row.  column size is 0
10:48:00.208625 setting column 15 NULL bit
10:48:00.208647 processing row.  column is 16 varint size = 1
10:48:00.208673 processing row.  column size is 0
10:48:00.208697 setting column 16 NULL bit
10:48:00.208719 processing row.  column is 17 varint size = 1
10:48:00.208745 processing row.  column size is 4
10:48:00.208769 clearing column 17 NULL bit
10:48:00.208791 processing row.  column is 18 varint size = 2
10:48:00.208818 processing row.  column size is 2
10:48:00.208841 clearing column 18 NULL bit
10:48:00.208870 processing row.  column is 19 varint size = 1
10:48:00.208897 processing row.  column size is 1
10:48:00.208921 clearing column 19 NULL bit
convert_tds2sql: src is 39 dest = 1
convert_tds2sql: outputting character data destlen = 129
convert_tds2sql: src is 39 dest = 1
convert_tds2sql: outputting character data destlen = 129
convert_tds2sql: src is 39 dest = 1
convert_tds2sql: outputting character data destlen = 135
convert_tds2sql: src is 39 dest = 1
convert_tds2sql: outputting character data destlen = 129
convert_tds2sql: src is 52 dest = -15
convert_tds2sql: src is 52 dest = -15
convert_tds2sql: src is 39 dest = 1
convert_tds2sql: outputting character data destlen = 129
convert_tds2sql: src is 56 dest = -16
convert_tds2sql: src is 56 dest = -16
convert_tds2sql: src is 52 dest = -15
convert_tds2sql: src is 52 dest = -15
convert_tds2sql: src is 52 dest = -15
convert_tds2sql: src is 52 dest = -15
convert_tds2sql: src is 56 dest = -16
convert_tds2sql: src is 39 dest = 1
convert_tds2sql: outputting character data destlen = 255
convert_tds2sql: src is 48 dest = -26
10:48:00.209501 processing row tokens.  marker is  ff(DONEINPROC)
10:48:00.209536 tds_process_end: more_results = 1
                was_cancelled = 0
                error = 0
                done_count_valid = 1
10:48:00.209574                  rows_affected = 1
SQLFetch: NO_DATA_FOUND
Sending packet @ 10:48:00.209839
0000 06 01 00 08 00 00 01 00-                        |........|


10:48:00.209943 tds_process_default_tokens() marker is ff(DONEINPROC)
10:48:00.209987 tds_process_end: more_results = 1
                was_cancelled = 0
                error = 0
                done_count_valid = 0
10:48:00.210024 tds_process_default_tokens() marker is ff(DONEINPROC)
10:48:00.210050 tds_process_end: more_results = 1
                was_cancelled = 0
                error = 0
                done_count_valid = 0
10:48:00.210127 tds_process_default_tokens() marker is 79(RETURNSTATUS)
10:48:00.210155 tds_process_default_tokens: return status is 0
10:48:00.210181 tds_process_default_tokens() marker is fe(DONEPROC)
10:48:00.210207 tds_process_end: more_results = 0
                was_cancelled = 0
                error = 0
                done_count_valid = 0
10:48:00.210243 tds_process_end() state set to TDS_IDLEReceived header @
10:48:00.210286
0000 04 01 00 11 00 36 01 00-                        |.....6..|


Received packet @ 10:48:00.210338
0000 fd 20 00 fd 00 00 00 00-00                      |. ...... .|


10:48:00.210373 tds_process_end: more_results = 0
                was_cancelled = 1
                error = 0
                done_count_valid = 0
10:48:00.210409 tds_process_end() state set to TDS_IDLESQLFreeHandle(3,
0x83fb420)
odbc:SQLColAttributes: fDescType is 1011
odbc:SQLColAttributes: fDescType is 1012
Sending packet @ 10:48:00.213714
0000 03 01 00 22 00 00 01 00-0b 00 47 00 45 00 54 00 |...".... ..G.E.T.|
0010 53 00 59 00 53 00 55 00-53 00 45 00 52 00 53 00 |S.Y.S.U. S.E.R.S.|
0020 00 00                  -                        |..|


Received header @ 10:48:00.214207
0000 04 01 02 1e 00 36 01 00-                        |.....6..|


Received packet @ 10:48:00.214265
0000 81 0a 00 01 01 10 00 38-09 72 00 65 00 63 00 6f |.......8 .r.e.c.o|
0010 00 72 00 64 00 6b 00 65-00 79 00 05 01 09 00 a7 |.r.d.k.e .y......|
0020 0f 00 09 04 d0 00 34 08-75 00 73 00 65 00 72 00 |......4. u.s.e.r.|
0030 6e 00 61 00 6d 00 65 00-00 00 08 00 a7 0f 00 09 |n.a.m.e. ........|
0040 04 d0 00 34 0a 73 00 79-00 73 00 74 00 65 00 6d |...4.s.y .s.t.e.m|
0050 00 63 00 6f 00 64 00 65-00 00 00 09 00 a7 1e 00 |.c.o.d.e ........|
0060 09 04 d0 00 34 06 70 00-61 00 73 00 73 00 77 00 |....4.p. a.s.s.w.|
0070 64 00 00 00 09 00 a7 32-00 09 04 d0 00 34 08 66 |d......2 .....4.f|
0080 00 75 00 6c 00 6c 00 6e-00 61 00 6d 00 65 00 03 |.u.l.l.n .a.m.e..|
0090 01 09 00 a7 14 00 09 04-d0 00 34 05 70 00 68 00 |........ ..4.p.h.|
00a0 6f 00 6e 00 65 00 02 01-08 00 3d 0a 63 00 72 00 |o.n.e... ..=.c.r.|
00b0 65 00 61 00 74 00 65 00-64 00 61 00 74 00 65 00 |e.a.t.e. d.a.t.e.|
00c0 04 01 08 00 a7 0f 00 09-04 d0 00 34 0a 63 00 72 |........ ...4.c.r|
00d0 00 65 00 61 00 74 00 65-00 75 00 73 00 65 00 72 |.e.a.t.e .u.s.e.r|
00e0 00 02 01 08 00 3d 07 6d-00 6f 00 64 00 64 00 61 |.....=.m .o.d.d.a|
00f0 00 74 00 65 00 04 01 08-00 a7 0f 00 09 04 d0 00 |.t.e.... ........|
0100 34 07 6d 00 6f 00 64 00-75 00 73 00 65 00 72 00 |4.m.o.d. u.s.e.r.|
0110 d1 02 00 00 00 0f 00 64-6b 20 20 20 20 20 20 20 |.......d k       |
0120 20 20 20 20 20 20 0f 00-43 53 58 20 20 20 20 20 |      .. CSX     |
0130 20 20 20 20 20 20 20 1e-00 79 6f 68 6f 20 20 20 |       . .yoho   |
0140 20 20 20 20 20 20 20 20-20 20 20 20 20 20 20 20 |                 |
0150 20 20 20 20 20 20 20 32-00 44 61 76 65 79 20 62 |       2 .Davey b|
0160 6f 79 20 20 20 20 20 20-20 20 20 20 20 20 20 20 |oy               |
0170 20 20 20 20 20 20 20 20-20 20 20 20 20 20 20 20 |                 |
0180 20 20 20 20 20 20 20 20-20 20 20 14 00 39 39 39 |            ..999|
0190 20 20 20 20 20 20 20 20-20 20 20 20 20 20 20 20 |                 |
01a0 20 2c 95 00 00 0e 1e bd-00 03 00 64 62 6f 2c 95 | ,...... ...dbo,.|
01b0 00 00 0e 1e bd 00 03 00-64 62 6f d1 01 00 00 00 |........ dbo.....|
01c0 06 00 64 6b 65 69 74 68-03 00 6c 68 69 04 00 74 |..dkeith ..lhi..t|
01d0 65 73 74 0b 00 44 61 76-69 64 20 4b 65 69 74 68 |est..Dav id Keith|
01e0 03 00 32 30 39 26 95 00-00 76 07 04 01 03 00 64 |..209&.. .v.....d|
01f0 62 6f 26 95 00 00 76 07-04 01 03 00 64 62 6f ff |bo&...v. ....dbo.|
0200 11 00 c1 00 02 00 00 00-79 00 00 00 00 fe 00 00 |........ y.......|
0210 e0 00 02 00 00 00      -                        |......|


10:48:00.215057 processing result tokens.  marker is  81(TDS7_RESULT)
tds_get_string: reading 18 from wire to give 9 to client.
10:48:00.215162 tds7_get_data_info:1451:
        colname = recordkey (9 bytes)
        type = 56 (int)
        server's type = 56 (int)
        column_varint_size = 0
        column_size = 4 (4 on server)
10:48:00.215217 adjust_character_column_size:
        Server charset: CP1252
        Server column_size: 15
        Client charset: ISO-8859-1
        Client column_size: 15
tds_get_string: reading 16 from wire to give 8 to client.
10:48:00.215282 tds7_get_data_info:1451:
        colname = username (8 bytes)
        type = 39 (varchar)
        server's type = 167 (xvarchar)
        column_varint_size = 2
        column_size = 15 (15 on server)
10:48:00.215332 adjust_character_column_size:
        Server charset: CP1252
        Server column_size: 15
        Client charset: ISO-8859-1
        Client column_size: 15
tds_get_string: reading 20 from wire to give 10 to client.
10:48:00.215395 tds7_get_data_info:1451:
        colname = systemcode (10 bytes)
        type = 39 (varchar)
        server's type = 167 (xvarchar)
        column_varint_size = 2
        column_size = 15 (15 on server)
10:48:00.215445 adjust_character_column_size:
        Server charset: CP1252
        Server column_size: 30
        Client charset: ISO-8859-1
        Client column_size: 30
tds_get_string: reading 12 from wire to give 6 to client.
10:48:00.215509 tds7_get_data_info:1451:
        colname = passwd (6 bytes)
        type = 39 (varchar)
        server's type = 167 (xvarchar)
        column_varint_size = 2
        column_size = 30 (30 on server)
10:48:00.215558 adjust_character_column_size:
        Server charset: CP1252
        Server column_size: 50
        Client charset: ISO-8859-1
        Client column_size: 50
tds_get_string: reading 16 from wire to give 8 to client.
10:48:00.215622 tds7_get_data_info:1451:
        colname = fullname (8 bytes)
        type = 39 (varchar)
        server's type = 167 (xvarchar)
        column_varint_size = 2
        column_size = 50 (50 on server)
10:48:00.215671 adjust_character_column_size:
        Server charset: CP1252
        Server column_size: 20
        Client charset: ISO-8859-1
        Client column_size: 20
tds_get_string: reading 10 from wire to give 5 to client.
10:48:00.215735 tds7_get_data_info:1451:
        colname = phone (5 bytes)
        type = 39 (varchar)
        server's type = 167 (xvarchar)
        column_varint_size = 2
        column_size = 20 (20 on server)
tds_get_string: reading 20 from wire to give 10 to client.
10:48:00.215808 tds7_get_data_info:1451:
        colname = createdate (10 bytes)
        type = 61 (datetime)
        server's type = 61 (datetime)
        column_varint_size = 0
        column_size = 8 (8 on server)
10:48:00.215858 adjust_character_column_size:
        Server charset: CP1252
        Server column_size: 15
        Client charset: ISO-8859-1
        Client column_size: 15
tds_get_string: reading 20 from wire to give 10 to client.
10:48:00.215921 tds7_get_data_info:1451:
        colname = createuser (10 bytes)
        type = 39 (varchar)
        server's type = 167 (xvarchar)
        column_varint_size = 2
        column_size = 15 (15 on server)
tds_get_string: reading 14 from wire to give 7 to client.
10:48:00.215993 tds7_get_data_info:1451:
        colname = moddate (7 bytes)
        type = 61 (datetime)
        server's type = 61 (datetime)
        column_varint_size = 0
        column_size = 8 (8 on server)
10:48:00.216043 adjust_character_column_size:
        Server charset: CP1252
        Server column_size: 15
        Client charset: ISO-8859-1
        Client column_size: 15
tds_get_string: reading 14 from wire to give 7 to client.
10:48:00.216127 tds7_get_data_info:1451:
        colname = moduser (7 bytes)
        type = 39 (varchar)
        server's type = 167 (xvarchar)
        column_varint_size = 2
        column_size = 15 (15 on server)
10:48:00.216180 processing result tokens.  marker is  d1(ROW)
odbc:SQLColAttribute: fDescType is 8
10:48:00.223229 processing row tokens.  marker is  d1(ROW)
10:48:00.223289 processing row.  column is 0 varint size = 0
10:48:00.223317 processing row.  column size is 4
10:48:00.223341 clearing column 0 NULL bit
10:48:00.223366 processing row.  column is 1 varint size = 2
10:48:00.223393 processing row.  column size is 15
10:48:00.223416 clearing column 1 NULL bit
10:48:00.223451 processing row.  column is 2 varint size = 2
10:48:00.223478 processing row.  column size is 15
10:48:00.223557 clearing column 2 NULL bit
10:48:00.223585 processing row.  column is 3 varint size = 2
10:48:00.223612 processing row.  column size is 30
10:48:00.223636 clearing column 3 NULL bit
10:48:00.223661 processing row.  column is 4 varint size = 2
10:48:00.223687 processing row.  column size is 50
10:48:00.223711 clearing column 4 NULL bit
10:48:00.223737 processing row.  column is 5 varint size = 2
10:48:00.223763 processing row.  column size is 20
10:48:00.223787 clearing column 5 NULL bit
10:48:00.223811 processing row.  column is 6 varint size = 0
10:48:00.223838 processing row.  column size is 8
10:48:00.223862 clearing column 6 NULL bit
10:48:00.223884 processing row.  column is 7 varint size = 2
10:48:00.223911 processing row.  column size is 3
10:48:00.223934 clearing column 7 NULL bit
10:48:00.223958 processing row.  column is 8 varint size = 0
10:48:00.223985 processing row.  column size is 8
10:48:00.224008 clearing column 8 NULL bit
10:48:00.224031 processing row.  column is 9 varint size = 2
10:48:00.224057 processing row.  column size is 3
10:48:00.224081 clearing column 9 NULL bit
convert_tds2sql: src is 56 dest = -16
convert_tds2sql: src is 39 dest = 1
convert_tds2sql: outputting character data destlen =
16
convert_tds2sql: src is 39 dest = 1
convert_tds2sql: outputting character data destlen =
16
convert_tds2sql: src is 39 dest = 1
convert_tds2sql: outputting character data destlen =
31
convert_tds2sql: src is 39 dest = 1
convert_tds2sql: outputting character data destlen =
51
convert_tds2sql: src is 39 dest = 1
convert_tds2sql: outputting character data destlen =
21
convert_tds2sql: src is 61 dest = 93
convert_tds2sql: src is 39 dest = 1
convert_tds2sql: outputting character data destlen =
16
convert_tds2sql: src is 61 dest = 93
convert_tds2sql: src is 39 dest = 1
convert_tds2sql: outputting character data destlen =
16
10:48:00.225068 processing row tokens.  marker is  d1(ROW)
10:48:00.225107 processing row.  column is 0 varint size = 0
10:48:00.225134 processing row.  column size is 4
10:48:00.225158 clearing column 0 NULL bit
10:48:00.225181 processing row.  column is 1 varint size = 2
10:48:00.225207 processing row.  column size is 6
10:48:00.225231 clearing column 1 NULL bit
10:48:00.225261 processing row.  column is 2 varint size = 2
10:48:00.225288 processing row.  column size is 3
10:48:00.225311 clearing column 2 NULL bit
10:48:00.225335 processing row.  column is 3 varint size = 2
10:48:00.225362 processing row.  column size is 4
10:48:00.225386 clearing column 3 NULL bit
10:48:00.225410 processing row.  column is 4 varint size = 2
10:48:00.225437 processing row.  column size is 11
10:48:00.225460 clearing column 4 NULL bit
10:48:00.225484 processing row.  column is 5 varint size = 2
10:48:00.225511 processing row.  column size is 3
10:48:00.225535 clearing column 5 NULL bit
10:48:00.225559 processing row.  column is 6 varint size = 0
10:48:00.225586 processing row.  column size is 8
10:48:00.225610 clearing column 6 NULL bit
10:48:00.225632 processing row.  column is 7 varint size = 2
10:48:00.225659 processing row.  column size is 3
10:48:00.225682 clearing column 7 NULL bit
10:48:00.225706 processing row.  column is 8 varint size = 0
10:48:00.225733 processing row.  column size is 8
10:48:00.225757 clearing column 8 NULL bit
10:48:00.225779 processing row.  column is 9 varint size = 2
10:48:00.225805 processing row.  column size is 3
10:48:00.225829 clearing column 9 NULL bit
convert_tds2sql: src is 56 dest = -16
convert_tds2sql: src is 39 dest = 1
convert_tds2sql: outputting character data destlen =
16
convert_tds2sql: src is 39 dest = 1
convert_tds2sql: outputting character data destlen =
16
convert_tds2sql: src is 39 dest = 1
convert_tds2sql: outputting character data destlen =
31
convert_tds2sql: src is 39 dest = 1
convert_tds2sql: outputting character data destlen =
51
convert_tds2sql: src is 39 dest = 1
convert_tds2sql: outputting character data destlen =
21
convert_tds2sql: src is 61 dest = 93
convert_tds2sql: src is 39 dest = 1
convert_tds2sql: outputting character data destlen =
16
convert_tds2sql: src is 61 dest = 93
convert_tds2sql: src is 39 dest = 1
convert_tds2sql: outputting character data destlen =
16
10:48:00.226794 processing row tokens.  marker is  ff(DONEINPROC)
10:48:00.226837 tds_process_end: more_results = 1
                was_cancelled = 0
                error = 0
                done_count_valid = 1
10:48:00.226875                  rows_affected = 2
SQLFetch: NO_DATA_FOUND
Sending packet @ 10:48:00.227327
0000 06 01 00 08 00 00 01 00-                        |........|


10:48:00.227417 tds_process_default_tokens() marker is 79(RETURNSTATUS)
10:48:00.227453 tds_process_default_tokens: return status is 0
10:48:00.227480 tds_process_default_tokens() marker is fe(DONEPROC)
10:48:00.227508 tds_process_end: more_results = 0
                was_cancelled = 0
                error = 0
                done_count_valid = 0
10:48:00.227591 tds_process_end() state set to TDS_IDLEReceived header @
10:48:00.227637
0000 04 01 00 11 00 36 01 00-                        |.....6..|


Received packet @ 10:48:00.227690
0000 fd 20 00 fd 00 00 00 00-00                      |. ...... .|


10:48:00.227725 tds_process_end: more_results = 0
                was_cancelled = 1
                error = 0
                done_count_valid = 0
10:48:00.227761 tds_process_end() state set to
TDS_IDLEodbc:SQLColAttributes: fDescType is 1011
odbc:SQLColAttributes: fDescType is 1012
odbc:SQLColAttributes: fDescType is 1011
odbc:SQLColAttributes: fDescType is 1012
odbc:SQLColAttributes: fDescType is 1011
odbc:SQLColAttributes: fDescType is 1012
odbc:SQLColAttributes: fDescType is 1011
odbc:SQLColAttributes: fDescType is 1012
odbc:SQLColAttributes: fDescType is 1011
odbc:SQLColAttributes: fDescType is 1012
sql2tds.c:120 type=1
sql2tds.c:126
sql2tds.c:261
sql2tds.c:120 type=1
sql2tds.c:126
sql2tds.c:261
sql2tds.c:120 type=1
sql2tds.c:126
sql2tds.c:261
sql2tds.c:120 type=1
sql2tds.c:126
10:48:05.807666 setting column 3 NULL bit
tds_submit_query(): state is PENDING
10:48:05.807750 tds_client_msg: #20019: "Attempt to initiate a new SQL
Server operation with results pending.".  Connection state is now 1.


Joseph Geiser wrote:

>and then Jim writes:
>  
>
>>A little more of the above log might help.  I'd suspect two threads
>>sharing a connection.  As far as the server's concerned, there are no
>>threads.  There are only connections, and each connection must finish
>>reading its results before initiating another query.  Two threads not
>>cooperating in their use of a connection could result in the
>>20019 error.
>>    
>>
>
>One thing David may wish to try before throwing his hands up is to configure
>SQL Server to use both Threads and Fibers.  We use fibers here and have not
>had this problem at all -- and the server is hit a lot from both Cold Fusion
>MX 6.1 as well as PHP, both of which are multi-threaded servers.
>
>To prove this out before posting this, I switched a crash-n-burn box back to
>threads only (no fibers) and what Jim writes above takes over... each
>"connection" is unique on its own within a process, and the benefits of
>multi-threading are trashed.  Re-enabling the use of Fibers on the SQL
>Server box produced a substantial performance boost both with executing
>queries and executing SPs with Input/Output parms, as well as returning
>resultsets.
>
>HTH - Cheers,
>Joe
>
>  
>






More information about the FreeTDS mailing list