[freetds] Using FreeTDS 0.95 INSERTS fail above 66000 characters...unless 'dump file' is turned on

Jacopille, David DJacopille at MFS.com
Wed Oct 7 13:13:08 EDT 2015


Frediano,

Below is the freetds.log that contains results from these three lines
from the test script.  The INSERT was successful since
logging/debugging was turned on.  It would not have been if logging was
turned off.

DBI->connect
USE
INSERT (string of 100000 ‘x’ characters)

The logs recorded a lot of repetitive lines on INSERT of 100000
‘x’ characters.

To save space I removed the repetitive lines with nothing but x
characters, like this example:

.... 00 78 00 78 00 78 00 78-00 78 00 78 00 78 00 78 |.x.x.x.x .x.x.x.x|

I also removed some of the repetitive packet retries for the long insert.

Everything else, including that beginning of the INSERT should be there.

Thank you for looking into this.

Dave

log.c:167:Starting log file for FreeTDS 0.95.20
        on 2015-10-07 13:06:36 with debug flags 0x4fff.
iconv.c:328:tds_iconv_open(0x7fa6f687a390, UTF-8)
iconv.c:187:local name for ISO-8859-1 is ISO-8859-1
iconv.c:187:local name for UTF-8 is UTF-8
iconv.c:187:local name for UCS-2LE is UCS-2LE
iconv.c:187:local name for UCS-2BE is UCS-2BE
iconv.c:346:setting up conversions for client charset "UTF-8"
iconv.c:348:preparing iconv for "UTF-8" <-> "UCS-2LE" conversion
iconv.c:395:preparing iconv for "ISO-8859-1" <-> "UCS-2LE" conversion
iconv.c:400:tds_iconv_open: done
net.c:202:Connecting to 168.66.122.143 port 1433 (TDS version 7.0)
net.c:274:tds_open_socket: connect(2) returned "Operation now in progress"
net.c:313:tds_open_socket() succeeded
util.c:165:Changed query state from DEAD to IDLE
login.c:788:using NTLM authentication for 'CORP\jacopille_d' account
login.c:852:quietly sending TDS 7+ login packet
token.c:326:tds_process_login_tokens()
packet.c:639:Received packet
0000 04 01 00 e3 00 00 00 00-ed d8 00 4e 54 4c 4d 53 |........ ...NTLMS|
0010 53 50 00 02 00 00 00 08-00 08 00 38 00 00 00 05 |SP...... ...8....|
0020 82 89 02 f5 e6 ef 6b 26-25 0a 98 00 00 00 00 00 |......k& %.......|
0030 00 00 00 98 00 98 00 40-00 00 00 06 01 b1 1d 00 |.......@ ........|
0040 00 00 0f 43 00 4f 00 52-00 50 00 02 00 08 00 43 |...C.O.R .P.....C|
0050 00 4f 00 52 00 50 00 01-00 10 00 42 00 4f 00 53 |.O.R.P.. ...B.O.S|
0060 00 53 00 51 00 4c 00 44-00 34 00 04 00 18 00 63 |.S.Q.L.D .4.....c|
0070 00 6f 00 72 00 70 00 2e-00 6d 00 66 00 73 00 2e |.o.r.p.. .m.f.s..|
0080 00 63 00 6f 00 6d 00 03-00 2a 00 62 00 6f 00 73 |.c.o.m.. .*.b.o.s|
0090 00 73 00 71 00 6c 00 64-00 34 00 2e 00 63 00 6f |.s.q.l.d .4...c.o|
00a0 00 72 00 70 00 2e 00 6d-00 66 00 73 00 2e 00 63 |.r.p...m .f.s...c|
00b0 00 6f 00 6d 00 05 00 1a-00 77 00 69 00 6e 00 72 |.o.m.... .w.i.n.r|
00c0 00 6f 00 6f 00 74 00 2e-00 6c 00 6f 00 63 00 61 |.o.o.t.. .l.o.c.a|
00d0 00 6c 00 07 00 08 00 4e-2f 6c 86 22 01 d1 01 00 |.l.....N /l."....|
00e0 00 00 00               -                        |...|

token.c:335:looking for login token, got  ed(AUTH)
token.c:115:tds_process_default_tokens() marker is ed(AUTH)
token.c:463:TDS_AUTH_TOKEN PDU size 216
challenge.c:648:TDS_AUTH_TOKEN nonce
0000 f5 e6 ef 6b 26 25 0a 98-                        |...k&%..|

challenge.c:702:Draining 0 bytes
packet.c:740:Sending packet
0000 11 01 00 b6 00 00 00 00-4e 54 4c 4d 53 53 50 00 |........ NTLMSSP.|
0010 03 00 00 00 18 00 18 00-7e 00 00 00 18 00 18 00 |........ ~.......|
0020 96 00 00 00 08 00 08 00-40 00 00 00 16 00 16 00 |........ @.......|
0030 48 00 00 00 20 00 20 00-5e 00 00 00 00 00 00 00 |H... . . ^.......|
0040 ae 00 00 00 01 82 00 00-43 00 4f 00 52 00 50 00 |........ C.O.R.P.|
0050 6a 00 61 00 63 00 6f 00-70 00 69 00 6c 00 6c 00 |j.a.c.o. p.i.l.l.|
0060 65 00 5f 00 64 00 30 00-30 00 36 00 2d 00 65 00 |e._.d.0. 0.6.-.e.|
0070 37 00 32 00 37 00 2e 00-6d 00 66 00 73 00 2e 00 |7.2.7... m.f.s...|
0080 63 00 6f 00 6d 00 ad ef-62 84 d4 08 0d 87 00 00 |c.o.m... b.......|
0090 00 00 00 00 00 00 00 00-00 00 00 00 00 00 df c8 |........ ........|
00a0 2e 96 a9 95 b8 b6 2e f2-7e 0b 80 23 14 d2 e6 c8 |........ ~..#....|
00b0 90 e7 6a 64 47 2b      -                        |..jdG+|

packet.c:639:Received packet
0000 04 01 01 94 00 6c 01 00-e3 15 00 01 03 4f 00 74 |.....l.. .....O.t|
0010 00 6f 00 06 6d 00 61 00-73 00 74 00 65 00 72 00 |.o..m.a. s.t.e.r.|
0020 ab 60 00 45 16 00 00 02-00 22 00 43 00 68 00 61 |.`.E.... .".C.h.a|
0030 00 6e 00 67 00 65 00 64-00 20 00 64 00 61 00 74 |.n.g.e.d . .d.a.t|
0040 00 61 00 62 00 61 00 73-00 65 00 20 00 63 00 6f |.a.b.a.s .e. .c.o|
0050 00 6e 00 74 00 65 00 78-00 74 00 20 00 74 00 6f |.n.t.e.x .t. .t.o|
0060 00 20 00 27 00 4f 00 74-00 6f 00 27 00 2e 00 08 |. .'.O.t .o.'....|
0070 42 00 4f 00 53 00 53 00-51 00 4c 00 44 00 34 00 |B.O.S.S. Q.L.D.4.|
0080 00 01 00 e3 17 00 02 0a-75 00 73 00 5f 00 65 00 |........ u.s._.e.|
0090 6e 00 67 00 6c 00 69 00-73 00 68 00 00 ab 6a 00 |n.g.l.i. s.h...j.|
00a0 47 16 00 00 01 00 27 00-43 00 68 00 61 00 6e 00 |G.....'. C.h.a.n.|
00b0 67 00 65 00 64 00 20 00-6c 00 61 00 6e 00 67 00 |g.e.d. . l.a.n.g.|
00c0 75 00 61 00 67 00 65 00-20 00 73 00 65 00 74 00 |u.a.g.e.  .s.e.t.|
00d0 74 00 69 00 6e 00 67 00-20 00 74 00 6f 00 20 00 |t.i.n.g.  .t.o. .|
00e0 75 00 73 00 5f 00 65 00-6e 00 67 00 6c 00 69 00 |u.s._.e. n.g.l.i.|
00f0 73 00 68 00 2e 00 08 42-00 4f 00 53 00 53 00 51 |s.h....B .O.S.S.Q|
0100 00 4c 00 44 00 34 00 00-01 00 e3 0f 00 03 05 69 |.L.D.4.. .......i|
0110 00 73 00 6f 00 5f 00 31-00 01 00 00 e3 0b 00 05 |.s.o._.1 ........|
0120 04 31 00 30 00 33 00 33-00 00 e3 0f 00 06 06 31 |.1.0.3.3 .......1|
0130 00 39 00 36 00 36 00 30-00 39 00 00 ad 36 00 01 |.9.6.6.0 .9...6..|
0140 07 00 00 00 16 4d 00 69-00 63 00 72 00 6f 00 73 |.....M.i .c.r.o.s|
0150 00 6f 00 66 00 74 00 20-00 53 00 51 00 4c 00 20 |.o.f.t.  .S.Q.L. |
0160 00 53 00 65 00 72 00 76-00 65 00 72 00 00 00 00 |.S.e.r.v .e.r....|
0170 00 0b 00 0d 6d e3 13 00-04 04 34 00 30 00 39 00 |....m... ..4.0.9.|
0180 36 00 04 34 00 30 00 39-00 36 00 fd 00 00 00 00 |6..4.0.9 .6......|
0190 00 00 00 00            -                        |....|

token.c:335:looking for login token, got  e3(ENVCHANGE)
token.c:115:tds_process_default_tokens() marker is e3(ENVCHANGE)
token.c:335:looking for login token, got  ab(INFO)
token.c:115:tds_process_default_tokens() marker is ab(INFO)
token.c:2344:tds_process_msg() reading message 5701 from server
token.c:2416:tds_process_msg() calling client msg handler
ctutil.c:142:_ct_handle_server_message(0x7fa6f6874620, 0x7fa6f687a390,
0x7fff5a6c6680)
ct.c:350:ct_con_props(0x7fa6f687a2d0, 33, 9108, 0x7fff5a6c5888, 8, 0x0)
ct.c:352:ct_con_props() action = CS_GET property = 9108
ct.c:512:fetching userdata 0x7fa6f6876d90
token.c:2429:tds_process_msg() returning TDS_SUCCESS
token.c:335:looking for login token, got  e3(ENVCHANGE)
token.c:115:tds_process_default_tokens() marker is e3(ENVCHANGE)
token.c:335:looking for login token, got  ab(INFO)
token.c:115:tds_process_default_tokens() marker is ab(INFO)
token.c:2344:tds_process_msg() reading message 5703 from server
token.c:2416:tds_process_msg() calling client msg handler
ctutil.c:142:_ct_handle_server_message(0x7fa6f6874620, 0x7fa6f687a390,
0x7fff5a6c6680)
ct.c:350:ct_con_props(0x7fa6f687a2d0, 33, 9108, 0x7fff5a6c5888, 8, 0x0)
ct.c:352:ct_con_props() action = CS_GET property = 9108
ct.c:512:fetching userdata 0x7fa6f6876d90
token.c:2429:tds_process_msg() returning TDS_SUCCESS
token.c:335:looking for login token, got  e3(ENVCHANGE)
token.c:115:tds_process_default_tokens() marker is e3(ENVCHANGE)
token.c:2251:server indicated charset change to "iso_1"
iconv.c:796:setting server single-byte charset to "CP1252"
token.c:335:looking for login token, got  e3(ENVCHANGE)
token.c:115:tds_process_default_tokens() marker is e3(ENVCHANGE)
token.c:335:looking for login token, got  e3(ENVCHANGE)
token.c:115:tds_process_default_tokens() marker is e3(ENVCHANGE)
token.c:335:looking for login token, got  ad(LOGINACK)
token.c:373:server reports TDS version 7.0.0.0
token.c:375:Product name for 0x7000000 is 7.0
token.c:407:Product version 8B000D6D
token.c:335:looking for login token, got  e3(ENVCHANGE)
token.c:115:tds_process_default_tokens() marker is e3(ENVCHANGE)
token.c:2235:changing block size from 4096 to 4096
token.c:335:looking for login token, got  fd(DONE)
token.c:115:tds_process_default_tokens() marker is fd(DONE)
token.c:2080:tds_process_end: more_results = 0
                was_cancelled = 0
                error = 0
                done_count_valid = 0
token.c:2097:                rows_affected = 0
token.c:2100:tds_process_end() state set to TDS_IDLE
token.c:439:tds_process_login_tokens() returning TDS_SUCCESS
mem.c:648:tds_free_all_results()
util.c:165:Changed query state from IDLE to WRITING
util.c:165:Changed query state from WRITING to PENDING
packet.c:740:Sending packet
0000 01 01 00 32 00 00 00 00-73 00 65 00 74 00 20 00 |...2.... 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 32 00 30 00 30 00-30 00 30 00 30 00 30 00 | .2.0.0. 0.0.0.0.|
0030 20 00                  -                        | .|

token.c:549:tds_process_tokens(0x7fa6f687a390, 0x7fff5a6c6784,
0x7fff5a6c6780, 0x100)
util.c:165:Changed query state from PENDING to READING
packet.c:639:Received packet
0000 04 01 00 11 00 6c 01 00-fd 00 00 be 00 00 00 00 |.....l.. ........|
0010 00                     -                        |.|

token.c:564:processing result tokens.  marker is  fd(DONE)
token.c:2080:tds_process_end: more_results = 0
                was_cancelled = 0
                error = 0
                done_count_valid = 0
token.c:2097:                rows_affected = 0
token.c:2100:tds_process_end() state set to TDS_IDLE
util.c:165:Changed query state from READING to IDLE
util.c:83:logic error: cannot change query state from IDLE to PENDING
util.c:165:Changed query state from IDLE to IDLE
token.c:549:tds_process_tokens(0x7fa6f687a390, 0x7fff5a6c6784,
0x7fff5a6c6780, 0x100)
token.c:552:tds_process_tokens() state is COMPLETED
ct.c:656:leaving ct_connect() returning 1
ct.c:3383:ct_options(0x7fa6f687a2d0, 34, 5025, 0x7fff5a6c6c44, -99999, 0x0)
ct.c:3415:ct_options: CS_SET, option = 5025
ct.c:3613:      tds_submit_optioncmd will be action(CS_SET) option(25) arg(0)
arglen(1)
query.c:3411:tds_submit_optioncmd()
mem.c:648:tds_free_all_results()
util.c:165:Changed query state from IDLE to WRITING
util.c:165:Changed query state from WRITING to PENDING
packet.c:740:Sending packet
0000 01 01 00 42 00 00 01 00-53 00 45 00 54 00 20 00 |...B.... S.E.T. .|
0010 49 00 4d 00 50 00 4c 00-49 00 43 00 49 00 54 00 |I.M.P.L. I.C.I.T.|
0020 5f 00 54 00 52 00 41 00-4e 00 53 00 41 00 43 00 |_.T.R.A. N.S.A.C.|
0030 54 00 49 00 4f 00 4e 00-53 00 20 00 4f 00 46 00 |T.I.O.N. S. .O.F.|
0040 46 00                  -                        |F.|

token.c:549:tds_process_tokens(0x7fa6f687a390, 0x7fff5a6c6a74,
0x7fff5a6c6a70, 0x100)
util.c:165:Changed query state from PENDING to READING
packet.c:639:Received packet
0000 04 01 00 11 00 6c 01 00-fd 00 00 ba 00 00 00 00 |.....l.. ........|
0010 00                     -                        |.|

token.c:564:processing result tokens.  marker is  fd(DONE)
token.c:2080:tds_process_end: more_results = 0
                was_cancelled = 0
                error = 0
                done_count_valid = 0
token.c:2097:                rows_affected = 0
token.c:2100:tds_process_end() state set to TDS_IDLE
util.c:165:Changed query state from READING to IDLE
util.c:83:logic error: cannot change query state from IDLE to PENDING
util.c:165:Changed query state from IDLE to IDLE
token.c:549:tds_process_tokens(0x7fa6f687a390, 0x7fff5a6c6a74,
0x7fff5a6c6a70, 0x100)
token.c:552:tds_process_tokens() state is COMPLETED
ct.c:673:ct_cmd_alloc(0x7fa6f687a2d0, 0x7fff5a6c6ff8)
ct.c:235:ct_describe_cmd_state(0)
ct.c:235:ct_describe_cmd_state(0)
ct.c:223:setting command state to IDLE (from IDLE)
ct.c:690:ct_cmd_alloc() : allocating command list to head
ct.c:711:ct_command(0x7fa6f5400040, 148, 0x7fff5a6c71c0, -9, -99999)
ct.c:850:_ct_initialise_cmd(0x7fa6f5400040)
ct.c:235:ct_describe_cmd_state(0)
ct.c:235:ct_describe_cmd_state(0)
ct.c:223:setting command state to IDLE (from IDLE)
ct.c:4033:rpc_clear(0x0)
ct.c:235:ct_describe_cmd_state(0)
ct.c:235:ct_describe_cmd_state(0)
ct.c:223:setting command state to IDLE (from IDLE)
ct.c:235:ct_describe_cmd_state(2)
ct.c:235:ct_describe_cmd_state(0)
ct.c:223:setting command state to READY (from IDLE)
ct.c:869:ct_send(0x7fa6f5400040)
ct.c:871:ct_send() command_type = 148
mem.c:648:tds_free_all_results()
util.c:165:Changed query state from IDLE to WRITING
util.c:165:Changed query state from WRITING to PENDING
packet.c:740:Sending packet
0000 01 01 00 28 00 00 01 00-73 00 65 00 6c 00 65 00 |...(.... s.e.l.e.|
0010 63 00 74 00 20 00 40 00-40 00 76 00 65 00 72 00 |c.t. . at . @.v.e.r.|
0020 73 00 69 00 6f 00 6e 00-                        |s.i.o.n.|

ct.c:235:ct_describe_cmd_state(3)
ct.c:235:ct_describe_cmd_state(2)
ct.c:223:setting command state to SENT (from READY)
ct.c:994:ct_send() succeeded
ct.c:1132:ct_results(0x7fa6f5400040, 0x7fff5a6c6ff4)
token.c:549:tds_process_tokens(0x7fa6f687a390, 0x7fff5a6c6f84,
0x7fff5a6c6f80, 0x6914)
util.c:165:Changed query state from PENDING to READING
packet.c:639:Received packet
0000 04 01 01 bd 00 6c 01 00-81 01 00 00 00 21 00 e7 |.....l.. .....!..|
0010 58 02 00 d1 9e 01 4d 00-69 00 63 00 72 00 6f 00 |X.....M. i.c.r.o.|
0020 73 00 6f 00 66 00 74 00-20 00 53 00 51 00 4c 00 |s.o.f.t.  .S.Q.L.|
0030 20 00 53 00 65 00 72 00-76 00 65 00 72 00 20 00 | .S.e.r. v.e.r. .|
0040 32 00 30 00 31 00 32 00-20 00 28 00 53 00 50 00 |2.0.1.2.  .(.S.P.|
0050 31 00 29 00 20 00 2d 00-20 00 31 00 31 00 2e 00 |1.). .-.  .1.1...|
0060 30 00 2e 00 33 00 34 00-33 00 37 00 2e 00 30 00 |0...3.4. 3.7...0.|
0070 20 00 28 00 58 00 36 00-34 00 29 00 20 00 0a 00 | .(.X.6. 4.). ...|
0080 09 00 4d 00 61 00 79 00-20 00 32 00 39 00 20 00 |..M.a.y.  .2.9. .|
0090 32 00 30 00 31 00 34 00-20 00 31 00 36 00 3a 00 |2.0.1.4.  .1.6.:.|
00a0 30 00 33 00 3a 00 34 00-30 00 20 00 0a 00 09 00 |0.3.:.4. 0. .....|
00b0 43 00 6f 00 70 00 79 00-72 00 69 00 67 00 68 00 |C.o.p.y. r.i.g.h.|
00c0 74 00 20 00 28 00 63 00-29 00 20 00 4d 00 69 00 |t. .(.c. ). .M.i.|
00d0 63 00 72 00 6f 00 73 00-6f 00 66 00 74 00 20 00 |c.r.o.s. o.f.t. .|
00e0 43 00 6f 00 72 00 70 00-6f 00 72 00 61 00 74 00 |C.o.r.p. o.r.a.t.|
00f0 69 00 6f 00 6e 00 0a 00-09 00 44 00 65 00 76 00 |i.o.n... ..D.e.v.|
0100 65 00 6c 00 6f 00 70 00-65 00 72 00 20 00 45 00 |e.l.o.p. e.r. .E.|
0110 64 00 69 00 74 00 69 00-6f 00 6e 00 20 00 28 00 |d.i.t.i. o.n. .(.|
0120 36 00 34 00 2d 00 62 00-69 00 74 00 29 00 20 00 |6.4.-.b. i.t.). .|
0130 6f 00 6e 00 20 00 57 00-69 00 6e 00 64 00 6f 00 |o.n. .W. i.n.d.o.|
0140 77 00 73 00 20 00 4e 00-54 00 20 00 36 00 2e 00 |w.s. .N. T. .6...|
0150 31 00 20 00 3c 00 58 00-36 00 34 00 3e 00 20 00 |1. .<.X. 6.4.>. .|
0160 28 00 42 00 75 00 69 00-6c 00 64 00 20 00 37 00 |(.B.u.i. l.d. .7.|
0170 36 00 30 00 31 00 3a 00-20 00 53 00 65 00 72 00 |6.0.1.:.  .S.e.r.|
0180 76 00 69 00 63 00 65 00-20 00 50 00 61 00 63 00 |v.i.c.e.  .P.a.c.|
0190 6b 00 20 00 31 00 29 00-20 00 28 00 48 00 79 00 |k. .1.).  .(.H.y.|
01a0 70 00 65 00 72 00 76 00-69 00 73 00 6f 00 72 00 |p.e.r.v. i.s.o.r.|
01b0 29 00 0a 00 fd 10 00 c1-00 01 00 00 00          |)....... .....|

token.c:564:processing result tokens.  marker is  81(TDS7_RESULT)
token.c:1573:processing TDS7 result metadata.
mem.c:648:tds_free_all_results()
token.c:1598:set current_results (1 column) to tds->res_info
token.c:1605:setting up 1 columns
token.c:3164:adjust_character_column_size:
        Server charset: UCS-2LE
        Server column_size: 600
        Client charset: UTF-8
        Client column_size: 1200
token.c:1542:tds7_get_data_info:
        colname =
        type = 39 (varchar)
        server's type = 231 (x UCS-2 varchar)
        column_varint_size = 2
        column_size = 1200 (600 on server)
token.c:1614: name                 size/wsize      type/wtype      utype
token.c:1615: -------------------- --------------- --------------- -------
token.c:1620:                         1200/600          39/231           0
util.c:165:Changed query state from READING to PENDING
ct.c:1189:ct_results() process_result_tokens returned 0 (type 4049)
token.c:549:tds_process_tokens(0x7fa6f687a390, 0x7fff5a6c6f84,
0x7fff5a6c6f80, 0x6914)
util.c:165:Changed query state from PENDING to READING
token.c:564:processing result tokens.  marker is  d1(ROW)
token.c:680:tds_process_tokens::SET_RETURN stopping on current token
util.c:165:Changed query state from READING to PENDING
ct.c:1189:ct_results() process_result_tokens returned 0 (type 4040)
ct.c:2283:ct_describe(0x7fa6f5400040, 1, 0x7fff5a6c7000)
ct.c:1896:_ct_get_client_type(type 39, user 0, size 1200)
ct.c:2304:ct_describe() datafmt->datatype = 0 server type 39
ct.c:1457:ct_bind(0x7fa6f5400040, 1, 0x7fff5a6c7000, 0x7fff5a6c70c0,
0x7fff5a6c6ff0, 0x7fff5a6c6fee)
ct.c:1459:ct_bind() datafmt count = 1 column_number = 1
ct.c:1518:ct_fetch(0x7fa6f5400040, -99999, -99999, -99999, 0x7fff5a6c6fe8)
token.c:549:tds_process_tokens(0x7fa6f687a390, 0x7fff5a6c6f7c, 0x0, 0x1608)
util.c:165:Changed query state from PENDING to READING
token.c:564:processing result tokens.  marker is  d1(ROW)
token.c:1951:tds_process_row(): reading column 0
data.c:534:tds_get_data: type 39, varint size 2
data.c:587:tds_get_data(): wire column size is 414
util.c:165:Changed query state from READING to PENDING
ct.c:1583:inside ct_fetch() process_row_tokens returned 0
ct.c:1723:_ct_bind_data(0x7fa6f576fd50, 0x7fa6f687adc0, 0x7fa6f687adc0, 0)
ct.c:1730:_ct_bind_data(): column 0 is type 39 and has length 207
ct.c:1896:_ct_get_client_type(type 39, user 0, size 1200)
cs.c:473:cs_convert(0x7fa6f576fd50, 0x7fff5a6c6e50, 0x7fa6f3a11c00,
0x7fff5a6c6da0, 0x7fff5a6c70c0, 0x7fff5a6c6ff0)
ct.c:2007:_ct_get_server_type(0)
ct.c:2007:_ct_get_server_type(0)
cs.c:521:converting type 47 (207 bytes) to type = 47 (255 bytes)
cs.c:535:cs_convert() srctype == desttype
cs.c:571:cs_convert() desttype = character
cs.c:53:cs_prretcode(1)
cs.c:660:cs_convert() returning  CS_SUCCEED
ct.c:1518:ct_fetch(0x7fa6f5400040, -99999, -99999, -99999, 0x7fff5a6c6fe8)
ct.c:1132:ct_results(0x7fa6f5400040, 0x7fff5a6c6ff4)
token.c:549:tds_process_tokens(0x7fa6f687a390, 0x7fff5a6c6f84,
0x7fff5a6c6f80, 0x6914)
util.c:165:Changed query state from PENDING to READING
token.c:564:processing result tokens.  marker is  fd(DONE)
token.c:2080:tds_process_end: more_results = 0
                was_cancelled = 0
                error = 0
                done_count_valid = 1
token.c:2097:                rows_affected = 1
token.c:2100:tds_process_end() state set to TDS_IDLE
util.c:165:Changed query state from READING to IDLE
util.c:83:logic error: cannot change query state from IDLE to PENDING
util.c:165:Changed query state from IDLE to IDLE
ct.c:1189:ct_results() process_result_tokens returned 0 (type 4052)
ct.c:1295:ct_results() results state = 2
ct.c:1296:ct_results() command type  = 148
ct.c:1297:ct_results() dynamic cmd   = 0
ct.c:1132:ct_results(0x7fa6f5400040, 0x7fff5a6c6ff4)
token.c:549:tds_process_tokens(0x7fa6f687a390, 0x7fff5a6c6f84,
0x7fff5a6c6f80, 0x6914)
token.c:552:tds_process_tokens() state is COMPLETED
ct.c:1189:ct_results() process_result_tokens returned 1 (type 4052)
ct.c:235:ct_describe_cmd_state(2)
ct.c:235:ct_describe_cmd_state(3)
ct.c:223:setting command state to READY (from SENT)
ct.c:1796:ct_cmd_drop(0x7fa6f5400040)
ct.c:1827:ct_cmd_drop() : command entry found in list
ct.c:1832:ct_cmd_drop() : relinking list
ct.c:1839:ct_cmd_drop() : relinked list
ct.c:673:ct_cmd_alloc(0x7fa6f687a2d0, 0x7fff5a6c6de0)
ct.c:235:ct_describe_cmd_state(0)
ct.c:235:ct_describe_cmd_state(0)
ct.c:223:setting command state to IDLE (from IDLE)
ct.c:690:ct_cmd_alloc() : allocating command list to head
ct.c:711:ct_command(0x7fa6f5359360, 148, 0x7fa6f2c01f00, -9, -99999)
ct.c:850:_ct_initialise_cmd(0x7fa6f5359360)
ct.c:235:ct_describe_cmd_state(0)
ct.c:235:ct_describe_cmd_state(0)
ct.c:223:setting command state to IDLE (from IDLE)
ct.c:4033:rpc_clear(0x0)
ct.c:235:ct_describe_cmd_state(0)
ct.c:235:ct_describe_cmd_state(0)
ct.c:223:setting command state to IDLE (from IDLE)
ct.c:235:ct_describe_cmd_state(2)
ct.c:235:ct_describe_cmd_state(0)
ct.c:223:setting command state to READY (from IDLE)
ct.c:869:ct_send(0x7fa6f5359360)
ct.c:871:ct_send() command_type = 148
mem.c:648:tds_free_all_results()
util.c:165:Changed query state from IDLE to WRITING
util.c:165:Changed query state from WRITING to PENDING
packet.c:740:Sending packet
0000 01 01 00 18 00 00 01 00-75 00 73 00 65 00 20 00 |........ u.s.e. .|
0010 6f 00 74 00 6f 00 33 00-                        |o.t.o.3.|

ct.c:235:ct_describe_cmd_state(3)
ct.c:235:ct_describe_cmd_state(2)
ct.c:223:setting command state to SENT (from READY)
ct.c:994:ct_send() succeeded
ct.c:1132:ct_results(0x7fa6f5359360, 0x7fff5a6c66d0)
token.c:549:tds_process_tokens(0x7fa6f687a390, 0x7fff5a6c65f4,
0x7fff5a6c65f0, 0x6914)
util.c:165:Changed query state from PENDING to READING
packet.c:639:Received packet
0000 04 01 00 8a 00 6c 01 00-e3 11 00 01 04 4f 00 54 |.....l.. .....O.T|
0010 00 4f 00 33 00 03 4f 00-54 00 4f 00 ab 62 00 45 |.O.3..O. T.O..b.E|
0020 16 00 00 01 00 23 00 43-00 68 00 61 00 6e 00 67 |.....#.C .h.a.n.g|
0030 00 65 00 64 00 20 00 64-00 61 00 74 00 61 00 62 |.e.d. .d .a.t.a.b|
0040 00 61 00 73 00 65 00 20-00 63 00 6f 00 6e 00 74 |.a.s.e.  .c.o.n.t|
0050 00 65 00 78 00 74 00 20-00 74 00 6f 00 20 00 27 |.e.x.t.  .t.o. .'|
0060 00 4f 00 54 00 4f 00 33-00 27 00 2e 00 08 42 00 |.O.T.O.3 .'....B.|
0070 4f 00 53 00 53 00 51 00-4c 00 44 00 34 00 00 01 |O.S.S.Q. L.D.4...|
0080 00 fd 00 00 e2 00 00 00-00 00                   |........ ..|

token.c:564:processing result tokens.  marker is  e3(ENVCHANGE)
token.c:115:tds_process_default_tokens() marker is e3(ENVCHANGE)
token.c:564:processing result tokens.  marker is  ab(INFO)
token.c:115:tds_process_default_tokens() marker is ab(INFO)
token.c:2344:tds_process_msg() reading message 5701 from server
token.c:2416:tds_process_msg() calling client msg handler
ctutil.c:142:_ct_handle_server_message(0x7fa6f6874620, 0x7fa6f687a390,
0x7fff5a6c6420)
ct.c:350:ct_con_props(0x7fa6f687a2d0, 33, 9108, 0x7fff5a6c5628, 8, 0x0)
ct.c:352:ct_con_props() action = CS_GET property = 9108
ct.c:512:fetching userdata 0x7fa6f6876d90
token.c:2429:tds_process_msg() returning TDS_SUCCESS
token.c:564:processing result tokens.  marker is  fd(DONE)
token.c:2080:tds_process_end: more_results = 0
                was_cancelled = 0
                error = 0
                done_count_valid = 0
token.c:2097:                rows_affected = 0
token.c:2100:tds_process_end() state set to TDS_IDLE
util.c:165:Changed query state from READING to IDLE
util.c:83:logic error: cannot change query state from IDLE to PENDING
util.c:165:Changed query state from IDLE to IDLE
ct.c:1189:ct_results() process_result_tokens returned 0 (type 4052)
ct.c:1295:ct_results() results state = 0
ct.c:1296:ct_results() command type  = 148
ct.c:1297:ct_results() dynamic cmd   = 0
ct.c:2347:ct_res_info(0x7fa6f5359360, 800, 0x7fa6f2c67598, -99999, 0x0)
ct.c:2372:ct_res_info(): Number of rows is -1
ct.c:1132:ct_results(0x7fa6f5359360, 0x7fff5a6c66d0)
ct.c:2347:ct_res_info(0x7fa6f5359360, 800, 0x7fa6f2c67598, -99999, 0x0)
ct.c:2372:ct_res_info(): Number of rows is -1
ct.c:1132:ct_results(0x7fa6f5359360, 0x7fff5a6c66d0)
token.c:549:tds_process_tokens(0x7fa6f687a390, 0x7fff5a6c65f4,
0x7fff5a6c65f0, 0x6914)
token.c:552:tds_process_tokens() state is COMPLETED
ct.c:1189:ct_results() process_result_tokens returned 1 (type 4052)
ct.c:235:ct_describe_cmd_state(2)
ct.c:235:ct_describe_cmd_state(3)
ct.c:223:setting command state to READY (from SENT)
ct.c:1796:ct_cmd_drop(0x7fa6f5359360)
ct.c:1827:ct_cmd_drop() : command entry found in list
ct.c:1832:ct_cmd_drop() : relinking list
ct.c:1839:ct_cmd_drop() : relinked list
ct.c:673:ct_cmd_alloc(0x7fa6f687a2d0, 0x7fff5a6c6de0)
ct.c:235:ct_describe_cmd_state(0)
ct.c:235:ct_describe_cmd_state(0)
ct.c:223:setting command state to IDLE (from IDLE)
ct.c:690:ct_cmd_alloc() : allocating command list to head
ct.c:711:ct_command(0x7fa6f5145ea0, 148, 0x1056b8000, -9, -99999)
ct.c:850:_ct_initialise_cmd(0x7fa6f5145ea0)
ct.c:235:ct_describe_cmd_state(0)
ct.c:235:ct_describe_cmd_state(0)
ct.c:223:setting command state to IDLE (from IDLE)
ct.c:4033:rpc_clear(0x0)
ct.c:235:ct_describe_cmd_state(0)
ct.c:235:ct_describe_cmd_state(0)
ct.c:223:setting command state to IDLE (from IDLE)
ct.c:235:ct_describe_cmd_state(2)
ct.c:235:ct_describe_cmd_state(0)
ct.c:223:setting command state to READY (from IDLE)
ct.c:869:ct_send(0x7fa6f5145ea0)
ct.c:871:ct_send() command_type = 148
mem.c:648:tds_free_all_results()
util.c:165:Changed query state from IDLE to WRITING
packet.c:740:Sending packet
0000 01 00 10 00 00 00 01 00-49 00 4e 00 53 00 45 00 |........ I.N.S.E.|
0010 52 00 54 00 20 00 69 00-6e 00 74 00 6f 00 20 00 |R.T. .i. n.t.o. .|
0020 54 00 45 00 53 00 54 00-54 00 41 00 42 00 4c 00 |T.E.S.T. T.A.B.L.|
0030 45 00 20 00 28 00 6d 00-61 00 78 00 74 00 65 00 |E. .(.m. a.x.t.e.|
0040 78 00 74 00 29 00 20 00-76 00 61 00 6c 00 75 00 |x.t.). . v.a.l.u.|
0050 65 00 73 00 20 00 28 00-4e 00 27 00 78 00 78 00 |e.s. .(. N.'.x.x.|

stream.c:125:Error: tds_convert_stream: tds_iconv returned errno 7,
conv_errno 7
packet.c:740:Sending packet
0000 01 00 10 00 00 00 01 00-78 00 78 00 78 00 78 00 |........ x.x.x.x.|

packet.c:740:Sending packet
0000 01 00 10 00 00 00 01 00-78 00 78 00 78 00 78 00 |........ x.x.x.x.|

stream.c:125:Error: tds_convert_stream: tds_iconv returned errno 7,
conv_errno 7
packet.c:740:Sending packet
0000 01 00 10 00 00 00 01 00-78 00 78 00 78 00 78 00 |........ x.x.x.x.|

stream.c:125:Error: tds_convert_stream: tds_iconv returned errno 7,
conv_errno 7
util.c:165:Changed query state from WRITING to PENDING
packet.c:740:Sending packet
0000 01 01 0f 20 00 00 01 00-78 00 78 00 78 00 78 00 |... .... x.x.x.x.|
0f10 78 00 78 00 78 00 78 00-78 00 78 00 27 00 29 00 |x.x.x.x. x.x.'.).|

ct.c:235:ct_describe_cmd_state(3)
ct.c:235:ct_describe_cmd_state(2)
ct.c:223:setting command state to SENT (from READY)
ct.c:994:ct_send() succeeded
ct.c:1132:ct_results(0x7fa6f5145ea0, 0x7fff5a6c66d0)
token.c:549:tds_process_tokens(0x7fa6f687a390, 0x7fff5a6c65f4,
0x7fff5a6c65f0, 0x6914)
util.c:165:Changed query state from PENDING to READING
packet.c:639:Received packet
0000 04 01 00 11 00 6c 01 00-fd 10 00 c3 00 01 00 00 |.....l.. ........|
0010 00                     -                        |.|

token.c:564:processing result tokens.  marker is  fd(DONE)
token.c:2080:tds_process_end: more_results = 0
                was_cancelled = 0
                error = 0
                done_count_valid = 1
token.c:2097:                rows_affected = 1
token.c:2100:tds_process_end() state set to TDS_IDLE
util.c:165:Changed query state from READING to IDLE
util.c:83:logic error: cannot change query state from IDLE to PENDING
util.c:165:Changed query state from IDLE to IDLE
ct.c:1189:ct_results() process_result_tokens returned 0 (type 4052)
ct.c:1295:ct_results() results state = 0
ct.c:1296:ct_results() command type  = 148
ct.c:1297:ct_results() dynamic cmd   = 0
ct.c:2347:ct_res_info(0x7fa6f5145ea0, 800, 0x7fa6f687a908, -99999, 0x0)
ct.c:2372:ct_res_info(): Number of rows is 1
ct.c:1132:ct_results(0x7fa6f5145ea0, 0x7fff5a6c66d0)
ct.c:2347:ct_res_info(0x7fa6f5145ea0, 800, 0x7fa6f687a908, -99999, 0x0)
ct.c:2372:ct_res_info(): Number of rows is 1
ct.c:1132:ct_results(0x7fa6f5145ea0, 0x7fff5a6c66d0)
token.c:549:tds_process_tokens(0x7fa6f687a390, 0x7fff5a6c65f4,
0x7fff5a6c65f0, 0x6914)
token.c:552:tds_process_tokens() state is COMPLETED
ct.c:1189:ct_results() process_result_tokens returned 1 (type 4052)
ct.c:235:ct_describe_cmd_state(2)
ct.c:235:ct_describe_cmd_state(3)
ct.c:223:setting command state to READY (from SENT)
ct.c:1796:ct_cmd_drop(0x7fa6f5145ea0)
ct.c:1827:ct_cmd_drop() : command entry found in list
ct.c:1832:ct_cmd_drop() : relinking list
ct.c:1839:ct_cmd_drop() : relinked list






On 10/7/15, 11:37 AM, "Frediano Ziglio" <freddy77 at gmail.com> wrote:

>I won't be surprised if there are also some limit in sql server.
>
>You are sending the data inside a language query string. It's quite
>surprising changing log settings solve the issue, perhaps there is a
>bug inside Ctlib (DBD::Sybase should use ctlib). You can try using a
>packet sniffer to get traffic with the server. Can you post (or send
>to me if you prefer) the logs anyway?
>Probably you'd better compress them. From the log we can understand
>which calls DBD::Sybase does so I can try reproduce with C directly.
>
>Frediano
>
>
>2015-10-06 1:36 GMT+01:00 Jacopille, David <DJacopille at mfs.com>:
>> DC - Thanks for the quick reply.  Text size is positively set to one
>>million characters.
>>
>> 1.  The data SELECT of 500,000 characters always works.
>> 2.  SELECT @@textsize does confirm the 1,000,000 setting (but the above
>>also proves functionality)
>> 3.  'Text size' setting only applies to SELECT statements, not INSERT
>>where we are having the issue.  This is demonstrably true for MS SQL
>>Server, which we are using.  Don't know about other databases.
>>
>> SQL Server 2012 nvarchar(max) does hold 2 GB theoretical.  This
>>specific table and nvarchar(max) column has proven to handle far more
>>than the 1 MB values I'm testing with.   At least through other software.
>>
>> I suspect that there is a bug in either FreeTDS 0.95 or DBD::Sybase
>>1.15 that is limiting the text.  However I find FreeTDS more suspicious
>>because turning on logging (which changes something in FreeTDS) fixes
>>the problem.
>>
>> Unfortunately the thing that would be useful to find the problem is
>>what fixes the problem.
>>
>> Dave
>>
>> -----Original Message-----
>> From: FreeTDS [mailto:freetds-bounces at lists.ibiblio.org] On Behalf Of
>>David Chang
>> Sent: Monday, October 05, 2015 6:54 PM
>> To: FreeTDS Development Group
>> Subject: Re: [freetds] Using FreeTDS 0.95 INSERTS fail above 66000
>>characters...unless 'dump file' is turned on
>>
>> Dave,
>>
>> I see you set the text size in the freetds.conf file to 1000000.  I
>>would confirm it using 'select @@textsize'.
>>
>> DC
>>
>> On 10/5/2015 2:07 PM, Jacopille, David wrote:
>>> Looking for suggestions or a troubleshooting approach on this 100%
>>> reproducible issue where FreeTDS logging seems to be the only variable.
>>>
>>> Since the issue goes away as soon as I turn on freetds logging I can¹t
>>> look at the logs to find the problem.
>>>
>>> ENVIRONMENT
>>>          SQL Server 2012
>>>          OS X 10.9.5
>>>          FreeTDS 0.95.20
>>>          DBD::Sybase 1.15
>>>          TDSVER 7.0  or 7.1 (same symptoms)
>>>          Perl 5.16.3
>>>          FreeTDS text size = 1000000
>>>
>>> Testing large string INSERTS to a table with a single, nvarchar(max),
>>> column
>>>
>>>
>>> WHAT WORKS
>>> A. With freetds logging on (via 'dump file = /tmp/freetds.log¹) INSERT
>>> values from 0-500,000 characters are successful.  Decreasing
>>> reliability above 500,000 characters.
>>>
>>> B. INSERT statements with values of 0 thru 66,000 characters always
>>> work, regardless of freetds logging on/off
>>>
>>> C. SELECT work correctly for all values 0 thru one million characters,
>>> regardless of freetds logging on/off
>>>
>>>
>>> DOES NOT WORK
>>> If freetds logging is turned off the following fails consistently:
>>>
>>> A. 67,000 character INSERT              stalls at INSERT
>>>
>>> B. 100,000+ character INSERT            doesn¹t stall but doesn¹t
>>>INSERT
>>>
>>> C. Stored Procedures also experiencing failures in same character
>>> ranges
>>>
>>>
>>> FREETDS.CONF
>>>
>>> # In the failure configuration it looks like this.
>>> # The ³DOES NOT WORK² symptoms go away if the last two lines are
>>> uncommented.
>>>
>>> [global]
>>>          client charset = UTF-8
>>>          text size = 1000000
>>>
>>> [bossqld4]
>>>          host = bossqld4.mfs.com
>>>          port = 1433
>>>          tds version = 7.0
>>>          #dump file = /tmp/freetds.log
>>>          #dump file append = no
>>>
>>>
>>> PERL SCRIPT REPRODUCING ISSUE (WITH NO FREETDS LOGGING)
>>>
>>> use DBI qw(:sql_types);
>>> use DBD::Sybase;
>>> my ($sql, $dbh, $ref, $largetext);
>>>
>>> $dbh = DBI->connect( 'DBI:Sybase:server=bossqld4', ŒCORP\user',
>>> Œpassword', { PrintError => 0 } ) or die; $dbh->do('use
>>> testdatabase');
>>>
>>> $largetext = 'x' x 100000; # one hundred thousand characters
>>>
>>> $dbh->do(qq|INSERT into TESTTABLE (maxtext) values
>>> (N\'$largetext\')|);
>>>
>>> # SELECT not affected by FreeTDS logging on/off # SELECT always
>>> successful on all values tested up to one million characters (and
>>> probably much larger, but untested).
>>>
>>> $sql = q|SELECT TOP 1 [maxtext] FROM TESTTABLE|; $ref =
>>> $dbh->selectrow_arrayref($sql); print 'Length of value: '. (length
>>> $$ref[0]) ."\n";
>>>
>>> $dbh->disconnect();
>>>
>>>
>>> Thank you,
>>> Dave Jacopille
>>> Boston
>>>
>>> MFS Email system made the following annotation
>>> ----------------------------------------------------------------------
>>> -----------------------------------------------------------------
>>> This email communication and any attachments may contain proprietary,
>>>confidential, or privileged information. If you are not the intended
>>>recipient, you are hereby notified that you have received this email in
>>>error and that any review, disclosure, dissemination, distribution or
>>>copying of it or its contents is prohibited. The sender does not waive
>>>confidentiality or any privilege by mistransmission. If you have
>>>received this email in error, please notify the sender immediately,
>>>delete this email, and destroy all copies and any attachments.
>>> _______________________________________________
>>> FreeTDS mailing list
>>> FreeTDS at lists.ibiblio.org
>>> http://lists.ibiblio.org/mailman/listinfo/freetds
>>
>> _______________________________________________
>> FreeTDS mailing list
>> FreeTDS at lists.ibiblio.org
>> http://lists.ibiblio.org/mailman/listinfo/freetds
>> MFS Email system made the following annotation
>>
>>-------------------------------------------------------------------------
>>--------------------------------------------------------------
>> This email communication and any attachments may contain proprietary,
>>confidential, or privileged information. If you are not the intended
>>recipient, you are hereby notified that you have received this email in
>>error and that any review, disclosure, dissemination, distribution or
>>copying of it or its contents is prohibited. The sender does not waive
>>confidentiality or any privilege by mistransmission. If you have
>>received this email in error, please notify the sender immediately,
>>delete this email, and destroy all copies and any attachments.
>> _______________________________________________
>> FreeTDS mailing list
>> FreeTDS at lists.ibiblio.org
>> http://lists.ibiblio.org/mailman/listinfo/freetds
>_______________________________________________
>FreeTDS mailing list
>FreeTDS at lists.ibiblio.org
>http://lists.ibiblio.org/mailman/listinfo/freetds

MFS Email system made the following annotation
---------------------------------------------------------------------------------------------------------------------------------------
This email communication and any attachments may contain proprietary, confidential, or privileged information. If you are not the intended recipient, you are hereby notified that you have received this email in error and that any review, disclosure, dissemination, distribution or copying of it or its contents is prohibited. The sender does not waive confidentiality or any privilege by mistransmission. If you have received this email in error, please notify the sender immediately, delete this email, and destroy all copies and any attachments.


More information about the FreeTDS mailing list