Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

bulk insert doesn't handle (N)VARCHAR(MAX) columns #192

Closed
joshuahlang opened this issue Feb 15, 2018 · 4 comments
Closed

bulk insert doesn't handle (N)VARCHAR(MAX) columns #192

joshuahlang opened this issue Feb 15, 2018 · 4 comments

Comments

@joshuahlang
Copy link
Contributor

More detail can be extracted from the log, but the gist is:

  1. Create a table with a single VARCHAR(MAX) column
  2. bcp_init
  3. bcp_bind with a single byte '*', type VARCHAR
  4. bcp_sendrow
  5. bcp_done <-- error raised here

Here's the TDSDUMP (I omitted much of the login stuff since it seems unrelated):

log.c:167:Starting log file for FreeTDS 1.00.80
	on 2018-02-15 06:17:44 with debug flags 0x4fff.
dblib.c:1179:tdsdbopen(0x11e8160, localhost:1433, [microsoft])
dblib.c:1205:tdsdbopen: dbproc->dbopts = 0x12a23b0
dblib.c:1216:tdsdbopen: tds_set_server(0x1050e60, "localhost:1433")
dblib.c:257:dblib_get_tds_ctx(void)
dblib.c:1233:tdsdbopen: About to call tds_read_config_info...
config.c:168:Getting connection information for [localhost:1433].
config.c:172:Attempting to read conf files.
config.c:358:... $FREETDSCONF not set.  Trying $FREETDS/etc.
config.c:371:... $FREETDS not set.  Trying $HOME.
config.c:297:Could not open '/root/.freetds.conf' ((.freetds.conf)).
config.c:301:Found conf file '/usr/etc/freetds.conf' (default).
config.c:509:Looking for section global.
config.c:568:	Found section global.
config.c:571:Got a match.
config.c:594:	tds version = 'auto'
config.c:924:Setting tds version to auto (0x0).
config.c:594:	text size = '64512'
config.c:568:	Found section egserver50.
config.c:568:	Found section egserver70.
config.c:582:	Reached EOF
config.c:509:Looking for section localhost:1433.
config.c:568:	Found section global.
config.c:568:	Found section egserver50.
config.c:568:	Found section egserver70.
config.c:582:	Reached EOF
config.c:307:[localhost:1433] not found.
config.c:358:... $FREETDSCONF not set.  Trying $FREETDS/etc.
config.c:371:... $FREETDS not set.  Trying $HOME.
config.c:297:Could not open '/root/.freetds.conf' ((.freetds.conf)).
config.c:301:Found conf file '/usr/etc/freetds.conf' (default).
config.c:509:Looking for section global.
config.c:568:	Found section global.
config.c:571:Got a match.
config.c:594:	tds version = 'auto'
config.c:924:Setting tds version to auto (0x0).
config.c:594:	text size = '64512'
config.c:568:	Found section egserver50.
config.c:568:	Found section egserver70.
config.c:582:	Reached EOF
config.c:509:Looking for section localhost.
config.c:568:	Found section global.
config.c:568:	Found section egserver50.
config.c:568:	Found section egserver70.
config.c:582:	Reached EOF
config.c:307:[localhost] not found.
config.c:802:Setting 'dump_file' to '/dev/stderr' from $TDSDUMP.
config.c:712:tds_config_login: client_charset is UTF-8.
config.c:719:tds_config_login: database_name is TDSUnittest_12345678901234567890.
config.c:802:Setting 'dump_file' to '/dev/stderr' from $TDSDUMP.
dblib.c:1260:tdsdbopen: Calling tds_connect_and_login(0xfd9d30, 0x11067b0)
iconv.c:325:tds_iconv_open(0xfd9d30, UTF-8)
iconv.c:185:local name for ISO-8859-1 is ISO-8859-1
iconv.c:185:local name for UTF-8 is UTF-8
iconv.c:185:local name for UCS-2LE is UCS-2LE
iconv.c:185:local name for UCS-2BE is UCS-2BE
iconv.c:343:setting up conversions for client charset "UTF-8"
iconv.c:345:preparing iconv for "UTF-8" <-> "UCS-2LE" conversion
iconv.c:384:tds_iconv_open: done
net.c:226:Connecting to 127.0.0.1 port 1433 (TDS version 7.4)
login.c:954:quietly sending TDS 7+ login packet
token.c:305:tds_process_login_tokens()
packet.c:640:Received packet
0000 04 01 01 f9 00 38 01 00-e3 4f 00 01 20 54 00 44 |.....8.. .O.. T.D|
0010 00 53 00 55 00 6e 00 69-00 74 00 74 00 65 00 73 |.S.U.n.i .t.t.e.s|
0020 00 74 00 5f 00 31 00 32-00 33 00 34 00 35 00 36 |.t._.1.2 .3.4.5.6|
0030 00 37 00 38 00 39 00 30-00 31 00 32 00 33 00 34 |.7.8.9.0 .1.2.3.4|
0040 00 35 00 36 00 37 00 38-00 39 00 30 00 06 6d 00 |.5.6.7.8 .9.0..m.|
0050 61 00 73 00 74 00 65 00-72 00 ab a4 00 45 16 00 |a.s.t.e. r....E..|
0060 00 02 00 3f 00 43 00 68-00 61 00 6e 00 67 00 65 |...?.C.h .a.n.g.e|
0070 00 64 00 20 00 64 00 61-00 74 00 61 00 62 00 61 |.d. .d.a .t.a.b.a|
0080 00 73 00 65 00 20 00 63-00 6f 00 6e 00 74 00 65 |.s.e. .c .o.n.t.e|
0090 00 78 00 74 00 20 00 74-00 6f 00 20 00 27 00 54 |.x.t. .t .o. .'.T|
00a0 00 44 00 53 00 55 00 6e-00 69 00 74 00 74 00 65 |.D.S.U.n .i.t.t.e|
00b0 00 73 00 74 00 5f 00 31-00 32 00 33 00 34 00 35 |.s.t._.1 .2.3.4.5|
00c0 00 36 00 37 00 38 00 39-00 30 00 31 00 32 00 33 |.6.7.8.9 .0.1.2.3|
00d0 00 34 00 35 00 36 00 37-00 38 00 39 00 30 00 27 |.4.5.6.7 .8.9.0.'|
00e0 00 2e 00 0c 61 00 63 00-64 00 39 00 32 00 32 00 |....a.c. d.9.2.2.|
00f0 30 00 32 00 64 00 65 00-31 00 32 00 00 01 00 00 |0.2.d.e. 1.2.....|
0100 00 e3 08 00 07 05 09 04-d0 00 34 00 e3 17 00 02 |........ ..4.....|
0110 0a 75 00 73 00 5f 00 65-00 6e 00 67 00 6c 00 69 |.u.s._.e .n.g.l.i|
0120 00 73 00 68 00 00 ab 74-00 47 16 00 00 01 00 27 |.s.h...t .G.....'|
0130 00 43 00 68 00 61 00 6e-00 67 00 65 00 64 00 20 |.C.h.a.n .g.e.d. |
0140 00 6c 00 61 00 6e 00 67-00 75 00 61 00 67 00 65 |.l.a.n.g .u.a.g.e|
0150 00 20 00 73 00 65 00 74-00 74 00 69 00 6e 00 67 |. .s.e.t .t.i.n.g|
0160 00 20 00 74 00 6f 00 20-00 75 00 73 00 5f 00 65 |. .t.o.  .u.s._.e|
0170 00 6e 00 67 00 6c 00 69-00 73 00 68 00 2e 00 0c |.n.g.l.i .s.h....|
0180 61 00 63 00 64 00 39 00-32 00 32 00 30 00 32 00 |a.c.d.9. 2.2.0.2.|
0190 64 00 65 00 31 00 32 00-00 01 00 00 00 ad 36 00 |d.e.1.2. ......6.|
01a0 01 74 00 00 04 16 4d 00-69 00 63 00 72 00 6f 00 |.t....M. i.c.r.o.|
01b0 73 00 6f 00 66 00 74 00-20 00 53 00 51 00 4c 00 |s.o.f.t.  .S.Q.L.|
01c0 20 00 53 00 65 00 72 00-76 00 65 00 72 00 00 00 | .S.e.r. v.e.r...|
01d0 00 00 0e 00 0b c7 e3 13-00 04 04 34 00 30 00 39 |........ ...4.0.9|
01e0 00 36 00 04 34 00 30 00-39 00 36 00 fd 00 00 00 |.6..4.0. 9.6.....|
01f0 00 00 00 00 00 00 00 00-00                      |........ .|

token.c:313:looking for login token, got  e3(ENVCHANGE)
token.c:132:tds_process_default_tokens() marker is e3(ENVCHANGE)
dblib.c:311:db_env_chg(0xfd9d30, 1, master, TDSUnittest_12345678901234567890)
token.c:313:looking for login token, got  ab(INFO)
token.c:132:tds_process_default_tokens() marker is ab(INFO)
mem.c:653:tds_free_all_results()
token.c:2384:tds_process_info() reading message 5701 from server
token.c:2456:tds_process_info() calling client msg handler
dbutil.c:74:_dblib_handle_info_message(0x120f160, 0xfd9d30, 0x7fff4e94df00)
dbutil.c:75:msgno 5701: "Changed database context to 'TDSUnittest_12345678901234567890'."
dblib.c:5807:dbgetuserdata(0x12a1fe0)
token.c:2473:tds_process_info() returning TDS_SUCCESS
token.c:313:looking for login token, got  e3(ENVCHANGE)
token.c:132:tds_process_default_tokens() marker is e3(ENVCHANGE)
token.c:2213:tds_process_env_chg(): 5 bytes of collation data received
token.c:2214:tds->conn->collation was
0000 00 00 00 00 00         -                        |.....|

iconv.c:780:setting server single-byte charset to "CP1252"
token.c:2224:tds->conn->collation now
0000 09 04 d0 00 34         -                        |....4|

token.c:313:looking for login token, got  e3(ENVCHANGE)
token.c:132:tds_process_default_tokens() marker is e3(ENVCHANGE)
dblib.c:311:db_env_chg(0xfd9d30, 2, , us_english)
token.c:313:looking for login token, got  ab(INFO)
token.c:132:tds_process_default_tokens() marker is ab(INFO)
mem.c:653:tds_free_all_results()
token.c:2384:tds_process_info() reading message 5703 from server
token.c:2456:tds_process_info() calling client msg handler
dbutil.c:74:_dblib_handle_info_message(0x120f160, 0xfd9d30, 0x7fff4e94df00)
dbutil.c:75:msgno 5703: "Changed language setting to us_english."
dblib.c:5807:dbgetuserdata(0x12a1fe0)
token.c:2473:tds_process_info() returning TDS_SUCCESS
token.c:313:looking for login token, got  ad(LOGINACK)
token.c:351:server reports TDS version 74.0.0.4
token.c:353:Product name for 0x74000004 is unknown
token.c:385:Product version 8E000BC7
token.c:313:looking for login token, got  e3(ENVCHANGE)
token.c:132:tds_process_default_tokens() marker is e3(ENVCHANGE)
token.c:2273:changing block size from 4096 to 4096
dblib.c:311:db_env_chg(0xfd9d30, 4, 4096, 4096)
token.c:313:looking for login token, got  fd(DONE)
token.c:132:tds_process_default_tokens() marker is fd(DONE)
token.c:2082:tds_process_end: more_results = 0
		was_cancelled = 0
		error = 0
		done_count_valid = 0
token.c:2101:                rows_affected = 0
token.c:2104:tds_process_end() state set to TDS_IDLE
token.c:422:tds_process_login_tokens() returning TDS_SUCCESS
mem.c:653: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:742:Sending packet
0000 01 01 00 44 00 00 00 00-16 00 00 00 12 00 00 00 |...D.... ........|
0010 02 00 00 00 00 00 00 00-00 00 01 00 00 00 73 00 |........ ......s.|
0020 65 00 74 00 20 00 74 00-65 00 78 00 74 00 73 00 |e.t. .t. e.x.t.s.|
0030 69 00 7a 00 65 00 20 00-36 00 34 00 35 00 31 00 |i.z.e. . 6.4.5.1.|
0040 32 00 20 00            -                        |2. .|

token.c:532:tds_process_tokens(0xfd9d30, 0x7fff4e94dfe8, 0x7fff4e94dfec, 0x100)
util.c:165:Changed query state from PENDING to READING
packet.c:640:Received packet
0000 04 01 00 15 00 38 01 00-fd 00 00 be 00 00 00 00 |.....8.. ........|
0010 00 00 00 00 00         -                        |.....|

token.c:547:processing result tokens.  marker is  fd(DONE)
token.c:2082:tds_process_end: more_results = 0
		was_cancelled = 0
		error = 0
		done_count_valid = 0
token.c:2101:                rows_affected = 0
token.c:2104: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:532:tds_process_tokens(0xfd9d30, 0x7fff4e94dfe8, 0x7fff4e94dfec, 0x100)
token.c:535:tds_process_tokens() state is COMPLETED
dblib.c:223:dblib_add_connection(0x7f1db25f55c0, 0xfd9d30)
dblib.c:1303:tdsdbopen: Returning dbproc = 0x12a1fe0
dblib.c:5789:dbsetuserdata(0x12a1fe0, 0x7f1db322d330)
dblib.c:3235:dbcancel(0x12a1fe0)
query.c:2203:tds_send_cancel: not in_cancel and idle
dblib.c:1363:dbcmd(0x12a1fe0, SET ARITHABORT ON;SET ANSI_DEFAULTS ON;SET CONCAT_NULL_YIELDS_NULL ON;SET TEXTSIZE 2147483647;)
dblib.c:1369:dbcmd() bufsz = 0
dblib.c:1363:dbcmd(0x12a1fe0, SET IMPLICIT_TRANSACTIONS )
dblib.c:1369:dbcmd() bufsz = 95
dblib.c:1363:dbcmd(0x12a1fe0, ON)
dblib.c:1369:dbcmd() bufsz = 121
dblib.c:1363:dbcmd(0x12a1fe0, ;)
dblib.c:1369:dbcmd() bufsz = 123
dblib.c:1409:dbsqlexec(0x12a1fe0)
dblib.c:6902:dbsqlsend(0x12a1fe0)
mem.c:653: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:742:Sending packet
0000 01 01 01 14 00 00 01 00-16 00 00 00 12 00 00 00 |........ ........|
0010 02 00 00 00 00 00 00 00-00 00 01 00 00 00 53 00 |........ ......S.|
0020 45 00 54 00 20 00 41 00-52 00 49 00 54 00 48 00 |E.T. .A. R.I.T.H.|
0030 41 00 42 00 4f 00 52 00-54 00 20 00 4f 00 4e 00 |A.B.O.R. T. .O.N.|
0040 3b 00 53 00 45 00 54 00-20 00 41 00 4e 00 53 00 |;.S.E.T.  .A.N.S.|
0050 49 00 5f 00 44 00 45 00-46 00 41 00 55 00 4c 00 |I._.D.E. F.A.U.L.|
0060 54 00 53 00 20 00 4f 00-4e 00 3b 00 53 00 45 00 |T.S. .O. N.;.S.E.|
0070 54 00 20 00 43 00 4f 00-4e 00 43 00 41 00 54 00 |T. .C.O. N.C.A.T.|
0080 5f 00 4e 00 55 00 4c 00-4c 00 5f 00 59 00 49 00 |_.N.U.L. L._.Y.I.|
0090 45 00 4c 00 44 00 53 00-5f 00 4e 00 55 00 4c 00 |E.L.D.S. _.N.U.L.|
00a0 4c 00 20 00 4f 00 4e 00-3b 00 53 00 45 00 54 00 |L. .O.N. ;.S.E.T.|
00b0 20 00 54 00 45 00 58 00-54 00 53 00 49 00 5a 00 | .T.E.X. T.S.I.Z.|
00c0 45 00 20 00 32 00 31 00-34 00 37 00 34 00 38 00 |E. .2.1. 4.7.4.8.|
00d0 33 00 36 00 34 00 37 00-3b 00 53 00 45 00 54 00 |3.6.4.7. ;.S.E.T.|
00e0 20 00 49 00 4d 00 50 00-4c 00 49 00 43 00 49 00 | .I.M.P. L.I.C.I.|
00f0 54 00 5f 00 54 00 52 00-41 00 4e 00 53 00 41 00 |T._.T.R. A.N.S.A.|
0100 43 00 54 00 49 00 4f 00-4e 00 53 00 20 00 4f 00 |C.T.I.O. N.S. .O.|
0110 4e 00 3b 00            -                        |N.;.|

dblib.c:4667:dbsqlok(0x12a1fe0)
dblib.c:4696:dbsqlok() not done, calling tds_process_tokens()
token.c:532:tds_process_tokens(0xfd9d30, 0x7fff4e94e388, 0x7fff4e94e38c, 0x6914)
util.c:165:Changed query state from PENDING to READING
packet.c:640:Received packet
0000 04 01 00 49 00 38 01 00-fd 01 00 b9 00 00 00 00 |...I.8.. ........|
0010 00 00 00 00 00 fd 01 00-b9 00 00 00 00 00 00 00 |........ ........|
0020 00 00 fd 01 00 b9 00 00-00 00 00 00 00 00 00 fd |........ ........|
0030 01 00 be 00 00 00 00 00-00 00 00 00 fd 00 00 b9 |........ ........|
0040 00 00 00 00 00 00 00 00-00                      |........ .|

token.c:547:processing result tokens.  marker is  fd(DONE)
token.c:2082:tds_process_end: more_results = 1
		was_cancelled = 0
		error = 0
		done_count_valid = 0
token.c:2101:                rows_affected = 0
util.c:165:Changed query state from READING to PENDING
dblib.c:4729:dbsqlok() end status is SUCCEED
dblib.c:4740:dbsqlok() end status was success
dblib.c:1704:dbresults(0x12a1fe0)
dblib.c:1709:dbresults: dbresults_state is 5 (_DB_RES_SUCCEED)
dblib.c:1693:dbresults returning 1 (SUCCEED)
dblib.c:2053:dbnextrow(0x12a1fe0)
dblib.c:2059:dbnextrow() dbresults_state = 3 (_DB_RES_NEXT_RESULT)
dblib.c:2064:leaving dbnextrow() returning -2 (NO_MORE_ROWS)
dblib.c:1704:dbresults(0x12a1fe0)
dblib.c:1709:dbresults: dbresults_state is 3 (_DB_RES_NEXT_RESULT)
token.c:532:tds_process_tokens(0xfd9d30, 0x7fff4e94e368, 0x7fff4e94e36c, 0x6914)
util.c:165:Changed query state from PENDING to READING
token.c:547:processing result tokens.  marker is  fd(DONE)
token.c:2082:tds_process_end: more_results = 1
		was_cancelled = 0
		error = 0
		done_count_valid = 0
token.c:2101:                rows_affected = 0
util.c:165:Changed query state from READING to PENDING
dblib.c:1730:dbresults() tds_process_tokens returned 0 (TDS_SUCCESS),
			result_type TDS_DONE_RESULT
dblib.c:1757:dbresults(): dbresults_state is 3 (_DB_RES_NEXT_RESULT)
dblib.c:1693:dbresults returning 1 (SUCCEED)
dblib.c:2053:dbnextrow(0x12a1fe0)
dblib.c:2059:dbnextrow() dbresults_state = 3 (_DB_RES_NEXT_RESULT)
dblib.c:2064:leaving dbnextrow() returning -2 (NO_MORE_ROWS)
dblib.c:1704:dbresults(0x12a1fe0)
dblib.c:1709:dbresults: dbresults_state is 3 (_DB_RES_NEXT_RESULT)
token.c:532:tds_process_tokens(0xfd9d30, 0x7fff4e94e368, 0x7fff4e94e36c, 0x6914)
util.c:165:Changed query state from PENDING to READING
token.c:547:processing result tokens.  marker is  fd(DONE)
token.c:2082:tds_process_end: more_results = 1
		was_cancelled = 0
		error = 0
		done_count_valid = 0
token.c:2101:                rows_affected = 0
util.c:165:Changed query state from READING to PENDING
dblib.c:1730:dbresults() tds_process_tokens returned 0 (TDS_SUCCESS),
			result_type TDS_DONE_RESULT
dblib.c:1757:dbresults(): dbresults_state is 3 (_DB_RES_NEXT_RESULT)
dblib.c:1693:dbresults returning 1 (SUCCEED)
dblib.c:2053:dbnextrow(0x12a1fe0)
dblib.c:2059:dbnextrow() dbresults_state = 3 (_DB_RES_NEXT_RESULT)
dblib.c:2064:leaving dbnextrow() returning -2 (NO_MORE_ROWS)
dblib.c:1704:dbresults(0x12a1fe0)
dblib.c:1709:dbresults: dbresults_state is 3 (_DB_RES_NEXT_RESULT)
token.c:532:tds_process_tokens(0xfd9d30, 0x7fff4e94e368, 0x7fff4e94e36c, 0x6914)
util.c:165:Changed query state from PENDING to READING
token.c:547:processing result tokens.  marker is  fd(DONE)
token.c:2082:tds_process_end: more_results = 1
		was_cancelled = 0
		error = 0
		done_count_valid = 0
token.c:2101:                rows_affected = 0
util.c:165:Changed query state from READING to PENDING
dblib.c:1730:dbresults() tds_process_tokens returned 0 (TDS_SUCCESS),
			result_type TDS_DONE_RESULT
dblib.c:1757:dbresults(): dbresults_state is 3 (_DB_RES_NEXT_RESULT)
dblib.c:1693:dbresults returning 1 (SUCCEED)
dblib.c:2053:dbnextrow(0x12a1fe0)
dblib.c:2059:dbnextrow() dbresults_state = 3 (_DB_RES_NEXT_RESULT)
dblib.c:2064:leaving dbnextrow() returning -2 (NO_MORE_ROWS)
dblib.c:1704:dbresults(0x12a1fe0)
dblib.c:1709:dbresults: dbresults_state is 3 (_DB_RES_NEXT_RESULT)
token.c:532:tds_process_tokens(0xfd9d30, 0x7fff4e94e368, 0x7fff4e94e36c, 0x6914)
util.c:165:Changed query state from PENDING to READING
token.c:547:processing result tokens.  marker is  fd(DONE)
token.c:2082:tds_process_end: more_results = 0
		was_cancelled = 0
		error = 0
		done_count_valid = 0
token.c:2101:                rows_affected = 0
token.c:2104: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
dblib.c:1730:dbresults() tds_process_tokens returned 0 (TDS_SUCCESS),
			result_type TDS_DONE_RESULT
dblib.c:1757:dbresults(): dbresults_state is 3 (_DB_RES_NEXT_RESULT)
dblib.c:1693:dbresults returning 1 (SUCCEED)
dblib.c:2053:dbnextrow(0x12a1fe0)
dblib.c:2059:dbnextrow() dbresults_state = 3 (_DB_RES_NEXT_RESULT)
dblib.c:2064:leaving dbnextrow() returning -2 (NO_MORE_ROWS)
dblib.c:1704:dbresults(0x12a1fe0)
dblib.c:1709:dbresults: dbresults_state is 3 (_DB_RES_NEXT_RESULT)
token.c:532:tds_process_tokens(0xfd9d30, 0x7fff4e94e368, 0x7fff4e94e36c, 0x6914)
token.c:535:tds_process_tokens() state is COMPLETED
dblib.c:1730:dbresults() tds_process_tokens returned 1 (TDS_NO_MORE_RESULTS),
			result_type TDS_DONE_RESULT
dblib.c:1693:dbresults returning 2 (NO_MORE_RESULTS)
dblib.c:5911:dbfreebuf(0x12a1fe0)
dblib.c:1363:dbcmd(0x12a1fe0, 
                        CREATE TABLE test_insert_varchar_max
                        (
                            String VARCHAR(MAX) COLLATE SQL_Latin1_General_CP1_CI_AS
                        )
                        )
dblib.c:1369:dbcmd() bufsz = 0
dblib.c:5911:dbfreebuf(0x12a1fe0)
dblib.c:3235:dbcancel(0x12a1fe0)
query.c:2203:tds_send_cancel: not in_cancel and idle
dblib.c:6902:dbsqlsend(0x12a1fe0)
mem.c:653: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:742:Sending packet
0000 01 01 01 dc 00 00 01 00-16 00 00 00 12 00 00 00 |........ ........|
0010 02 00 00 00 00 00 00 00-00 00 01 00 00 00 0a 00 |........ ........|
0020 20 00 20 00 20 00 20 00-20 00 20 00 20 00 20 00 | . . . .  . . . .|
0030 20 00 20 00 20 00 20 00-20 00 20 00 20 00 20 00 | . . . .  . . . .|
0040 20 00 20 00 20 00 20 00-20 00 20 00 20 00 20 00 | . . . .  . . . .|
0050 43 00 52 00 45 00 41 00-54 00 45 00 20 00 54 00 |C.R.E.A. T.E. .T.|
0060 41 00 42 00 4c 00 45 00-20 00 74 00 65 00 73 00 |A.B.L.E.  .t.e.s.|
0070 74 00 5f 00 69 00 6e 00-73 00 65 00 72 00 74 00 |t._.i.n. s.e.r.t.|
0080 5f 00 76 00 61 00 72 00-63 00 68 00 61 00 72 00 |_.v.a.r. c.h.a.r.|
0090 5f 00 6d 00 61 00 78 00-0a 00 20 00 20 00 20 00 |_.m.a.x. .. . . .|
00a0 20 00 20 00 20 00 20 00-20 00 20 00 20 00 20 00 | . . . .  . . . .|
00b0 20 00 20 00 20 00 20 00-20 00 20 00 20 00 20 00 | . . . .  . . . .|
00c0 20 00 20 00 20 00 20 00-20 00 28 00 0a 00 20 00 | . . . .  .(... .|
00d0 20 00 20 00 20 00 20 00-20 00 20 00 20 00 20 00 | . . . .  . . . .|
00e0 20 00 20 00 20 00 20 00-20 00 20 00 20 00 20 00 | . . . .  . . . .|
00f0 20 00 20 00 20 00 20 00-20 00 20 00 20 00 20 00 | . . . .  . . . .|
0100 20 00 20 00 20 00 53 00-74 00 72 00 69 00 6e 00 | . . .S. t.r.i.n.|
0110 67 00 20 00 56 00 41 00-52 00 43 00 48 00 41 00 |g. .V.A. R.C.H.A.|
0120 52 00 28 00 4d 00 41 00-58 00 29 00 20 00 43 00 |R.(.M.A. X.). .C.|
0130 4f 00 4c 00 4c 00 41 00-54 00 45 00 20 00 53 00 |O.L.L.A. T.E. .S.|
0140 51 00 4c 00 5f 00 4c 00-61 00 74 00 69 00 6e 00 |Q.L._.L. a.t.i.n.|
0150 31 00 5f 00 47 00 65 00-6e 00 65 00 72 00 61 00 |1._.G.e. n.e.r.a.|
0160 6c 00 5f 00 43 00 50 00-31 00 5f 00 43 00 49 00 |l._.C.P. 1._.C.I.|
0170 5f 00 41 00 53 00 0a 00-20 00 20 00 20 00 20 00 |_.A.S...  . . . .|
0180 20 00 20 00 20 00 20 00-20 00 20 00 20 00 20 00 | . . . .  . . . .|
0190 20 00 20 00 20 00 20 00-20 00 20 00 20 00 20 00 | . . . .  . . . .|
01a0 20 00 20 00 20 00 20 00-29 00 0a 00 20 00 20 00 | . . . . )... . .|
01b0 20 00 20 00 20 00 20 00-20 00 20 00 20 00 20 00 | . . . .  . . . .|
01c0 20 00 20 00 20 00 20 00-20 00 20 00 20 00 20 00 | . . . .  . . . .|
01d0 20 00 20 00 20 00 20 00-20 00 20 00             | . . . .  . .|

dblib.c:4667:dbsqlok(0x12a1fe0)
dblib.c:4696:dbsqlok() not done, calling tds_process_tokens()
token.c:532:tds_process_tokens(0xfd9d30, 0x7fff4e94e708, 0x7fff4e94e70c, 0x6914)
util.c:165:Changed query state from PENDING to READING
packet.c:640:Received packet
0000 04 01 00 23 00 38 01 00-e3 0b 00 08 08 01 00 00 |...#.8.. ........|
0010 00 38 00 00 00 00 fd 00-00 c6 00 00 00 00 00 00 |.8...... ........|
0020 00 00 00               -                        |...|

token.c:547:processing result tokens.  marker is  e3(ENVCHANGE)
token.c:132:tds_process_default_tokens() marker is e3(ENVCHANGE)
token.c:547:processing result tokens.  marker is  fd(DONE)
token.c:2082:tds_process_end: more_results = 0
		was_cancelled = 0
		error = 0
		done_count_valid = 0
token.c:2101:                rows_affected = 0
token.c:2104: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
dblib.c:4729:dbsqlok() end status is SUCCEED
dblib.c:4740:dbsqlok() end status was success
dblib.c:2053:dbnextrow(0x12a1fe0)
dblib.c:2059:dbnextrow() dbresults_state = 5 (_DB_RES_SUCCEED)
dblib.c:2064:leaving dbnextrow() returning -2 (NO_MORE_ROWS)
dblib.c:1704:dbresults(0x12a1fe0)
dblib.c:1709:dbresults: dbresults_state is 5 (_DB_RES_SUCCEED)
dblib.c:1693:dbresults returning 1 (SUCCEED)
dblib.c:1844:dbnumcols(0x12a1fe0)
dblib.c:1704:dbresults(0x12a1fe0)
dblib.c:1709:dbresults: dbresults_state is 3 (_DB_RES_NEXT_RESULT)
token.c:532:tds_process_tokens(0xfd9d30, 0x7fff4e94e698, 0x7fff4e94e69c, 0x6914)
token.c:535:tds_process_tokens() state is COMPLETED
dblib.c:1730:dbresults() tds_process_tokens returned 1 (TDS_NO_MORE_RESULTS),
			result_type TDS_DONE_RESULT
dblib.c:1693:dbresults returning 2 (NO_MORE_RESULTS)
bcp.c:701:bcp_getl(0x11e8160)
bcp.c:166:bcp_init(0x12a1fe0, test_insert_varchar_max, NULL, NULL, 1)
bcp.c:2312:_bcp_free_storage(0x12a1fe0)
mem.c:653: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:742:Sending packet
0000 01 01 00 a6 00 00 01 00-16 00 00 00 12 00 00 00 |........ ........|
0010 02 00 01 00 00 00 38 00-00 00 01 00 00 00 53 00 |......8. ......S.|
0020 45 00 54 00 20 00 46 00-4d 00 54 00 4f 00 4e 00 |E.T. .F. M.T.O.N.|
0030 4c 00 59 00 20 00 4f 00-4e 00 20 00 73 00 65 00 |L.Y. .O. N. .s.e.|
0040 6c 00 65 00 63 00 74 00-20 00 2a 00 20 00 66 00 |l.e.c.t.  .*. .f.|
0050 72 00 6f 00 6d 00 20 00-74 00 65 00 73 00 74 00 |r.o.m. . t.e.s.t.|
0060 5f 00 69 00 6e 00 73 00-65 00 72 00 74 00 5f 00 |_.i.n.s. e.r.t._.|
0070 76 00 61 00 72 00 63 00-68 00 61 00 72 00 5f 00 |v.a.r.c. h.a.r._.|
0080 6d 00 61 00 78 00 20 00-53 00 45 00 54 00 20 00 |m.a.x. . S.E.T. .|
0090 46 00 4d 00 54 00 4f 00-4e 00 4c 00 59 00 20 00 |F.M.T.O. N.L.Y. .|
00a0 4f 00 46 00 46 00      -                        |O.F.F.|

token.c:532:tds_process_tokens(0xfd9d30, 0x7fff4e94e65c, (nil), 0x6914)
util.c:165:Changed query state from PENDING to READING
packet.c:640:Received packet
0000 04 01 00 4d 00 38 01 00-fd 01 00 b9 00 00 00 00 |...M.8.. ........|
0010 00 00 00 00 00 81 01 00-00 00 00 00 09 00 a7 ff |........ ........|
0020 ff 09 04 d0 00 34 06 53-00 74 00 72 00 69 00 6e |.....4.S .t.r.i.n|
0030 00 67 00 fd 11 00 c1 00-00 00 00 00 00 00 00 00 |.g...... ........|
0040 fd 00 00 ba 00 00 00 00-00 00 00 00 00          |........ .....|

token.c:547:processing result tokens.  marker is  fd(DONE)
token.c:2082:tds_process_end: more_results = 1
		was_cancelled = 0
		error = 0
		done_count_valid = 0
token.c:2101:                rows_affected = 0
util.c:165:Changed query state from READING to PENDING
token.c:532:tds_process_tokens(0xfd9d30, 0x7fff4e94e65c, (nil), 0x6914)
util.c:165:Changed query state from PENDING to READING
token.c:547:processing result tokens.  marker is  81(TDS7_RESULT)
token.c:1554:processing TDS7 result metadata.
mem.c:653:tds_free_all_results()
token.c:1579:set current_results (1 column) to tds->res_info
token.c:1586:setting up 1 columns
token.c:3227:adjust_character_column_size:
	Server charset: CP1252
	Server column_size: 1073741823
	Client charset: UTF-8
	Client column_size: 2147483647
token.c:1523:tds7_get_data_info: 
	colname = String
	type = 39 (varchar)
	server's type = 167 (xvarchar)
	column_varint_size = 8
	column_size = 2147483647 (1073741823 on server)
token.c:1597: name                 size/wsize      type/wtype      utype  
token.c:1598: -------------------- --------------- --------------- -------
token.c:1603: String               2147483647/1073741823      39/167           0
util.c:165:Changed query state from READING to PENDING
token.c:532:tds_process_tokens(0xfd9d30, 0x7fff4e94e65c, (nil), 0x6914)
util.c:165:Changed query state from PENDING to READING
token.c:547:processing result tokens.  marker is  fd(DONE)
token.c:2082:tds_process_end: more_results = 1
		was_cancelled = 0
		error = 0
		done_count_valid = 1
token.c:2101:                rows_affected = 0
util.c:165:Changed query state from READING to PENDING
token.c:532:tds_process_tokens(0xfd9d30, 0x7fff4e94e65c, (nil), 0x6914)
util.c:165:Changed query state from PENDING to READING
token.c:547:processing result tokens.  marker is  fd(DONE)
token.c:2082:tds_process_end: more_results = 0
		was_cancelled = 0
		error = 0
		done_count_valid = 0
token.c:2101:                rows_affected = 0
token.c:2104: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:532:tds_process_tokens(0xfd9d30, 0x7fff4e94e65c, (nil), 0x6914)
token.c:535:tds_process_tokens() state is COMPLETED
dblib.c:6301:dbprtype(39)
bcp.c:2034:bcp_bind(0x12a1fe0, 0x7f1db3259030, 0, 1 -- (nil), 0, varchar, 1)
bcp.c:1343:bcp_sendrow(0x12a1fe0)
bulk.c:873:tds_bcp_start_copy_in(0xfd9d30, 0x122d210)
bulk.c:220:tds7_build_bulk_insert_stmt(0xfd9d30, 0x7fff4e94d610, 0x11dc2e0, 1)
bulk.c:819:tds_bcp_start(0xfd9d30, 0x122d210)
mem.c:653: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:742:Sending packet
0000 01 01 00 94 00 00 01 00-16 00 00 00 12 00 00 00 |........ ........|
0010 02 00 01 00 00 00 38 00-00 00 01 00 00 00 69 00 |......8. ......i.|
0020 6e 00 73 00 65 00 72 00-74 00 20 00 62 00 75 00 |n.s.e.r. t. .b.u.|
0030 6c 00 6b 00 20 00 74 00-65 00 73 00 74 00 5f 00 |l.k. .t. e.s.t._.|
0040 69 00 6e 00 73 00 65 00-72 00 74 00 5f 00 76 00 |i.n.s.e. r.t._.v.|
0050 61 00 72 00 63 00 68 00-61 00 72 00 5f 00 6d 00 |a.r.c.h. a.r._.m.|
0060 61 00 78 00 20 00 28 00-5b 00 53 00 74 00 72 00 |a.x. .(. [.S.t.r.|
0070 69 00 6e 00 67 00 5d 00-20 00 56 00 41 00 52 00 |i.n.g.].  .V.A.R.|
0080 43 00 48 00 41 00 52 00-28 00 4d 00 41 00 58 00 |C.H.A.R. (.M.A.X.|
0090 29 00 29 00            -                        |).).|

token.c:532:tds_process_tokens(0xfd9d30, 0x7fff4e94e618, 0x7fff4e94e61c, 0x100)
util.c:165:Changed query state from PENDING to READING
packet.c:640:Received packet
0000 04 01 00 15 00 38 01 00-fd 00 00 fd 00 00 00 00 |.....8.. ........|
0010 00 00 00 00 00         -                        |.....|

token.c:547:processing result tokens.  marker is  fd(DONE)
token.c:2082:tds_process_end: more_results = 0
		was_cancelled = 0
		error = 0
		done_count_valid = 0
token.c:2101:                rows_affected = 0
token.c:2104:tds_process_end() state set to TDS_IDLE
mem.c:653:tds_free_all_results()
util.c:165:Changed query state from READING to SENDING
util.c:83:logic error: cannot change query state from SENDING to PENDING
util.c:165:Changed query state from SENDING to SENDING
token.c:532:tds_process_tokens(0xfd9d30, 0x7fff4e94e618, 0x7fff4e94e61c, 0x100)
token.c:535:tds_process_tokens() state is COMPLETED
bulk.c:711:tds7_bcp_send_colmetadata(0xfd9d30, 0x122d210)
util.c:165:Changed query state from SENDING to WRITING
util.c:165:Changed query state from WRITING to SENDING
bulk.c:340:tds_bcp_send_bcp_record(0xfd9d30, 0x122d210, 0x7f1db23a3750, ignored, 0)
util.c:165:Changed query state from SENDING to WRITING
bcp.c:2136:_bcp_get_col_data(0x122d210, 0x11dc2e0)
bulk.c:371:gotten column 1 length 1 null 0
data.c:945:tds_generic_put: colsize = 1
data.c:1017:tds_generic_put: not null param varint_size = 8
util.c:165:Changed query state from WRITING to SENDING
bcp.c:1990:bcp_done(0x12a1fe0)
bulk.c:789:tds_bcp_done(0xfd9d30, 0x7fff4e94e6cc)
util.c:165:Changed query state from SENDING to WRITING
packet.c:742:Sending packet
0000 07 01 00 38 00 00 01 00-81 01 00 00 00 00 00 09 |...8.... ........|
0010 00 a7 ff ff 09 04 d0 00-34 06 53 00 74 00 72 00 |........ 4.S.t.r.|
0020 69 00 6e 00 67 00 d1 01-00 00 00 00 00 00 00 01 |i.n.g... ........|
0030 00 00 00 2a 00 00 00 00-                        |...*....|

util.c:165:Changed query state from WRITING to PENDING
token.c:532:tds_process_tokens(0xfd9d30, 0x7fff4e94e668, 0x7fff4e94e66c, 0x100)
util.c:165:Changed query state from PENDING to READING
packet.c:640:Received packet
0000 04 01 02 8a 00 38 01 00-aa 64 02 c4 12 00 00 01 |.....8.. .d......|
0010 11 1f 01 57 00 68 00 69-00 6c 00 65 00 20 00 72 |...W.h.i .l.e. .r|
0020 00 65 00 61 00 64 00 69-00 6e 00 67 00 20 00 63 |.e.a.d.i .n.g. .c|
0030 00 75 00 72 00 72 00 65-00 6e 00 74 00 20 00 72 |.u.r.r.e .n.t. .r|
0040 00 6f 00 77 00 20 00 66-00 72 00 6f 00 6d 00 20 |.o.w. .f .r.o.m. |
0050 00 68 00 6f 00 73 00 74-00 2c 00 20 00 61 00 20 |.h.o.s.t .,. .a. |
0060 00 70 00 72 00 65 00 6d-00 61 00 74 00 75 00 72 |.p.r.e.m .a.t.u.r|
0070 00 65 00 20 00 65 00 6e-00 64 00 2d 00 6f 00 66 |.e. .e.n .d.-.o.f|
0080 00 2d 00 6d 00 65 00 73-00 73 00 61 00 67 00 65 |.-.m.e.s .s.a.g.e|
0090 00 20 00 77 00 61 00 73-00 20 00 65 00 6e 00 63 |. .w.a.s . .e.n.c|
00a0 00 6f 00 75 00 6e 00 74-00 65 00 72 00 65 00 64 |.o.u.n.t .e.r.e.d|
00b0 00 2d 00 2d 00 61 00 6e-00 20 00 69 00 6e 00 63 |.-.-.a.n . .i.n.c|
00c0 00 6f 00 6d 00 69 00 6e-00 67 00 20 00 64 00 61 |.o.m.i.n .g. .d.a|
00d0 00 74 00 61 00 20 00 73-00 74 00 72 00 65 00 61 |.t.a. .s .t.r.e.a|
00e0 00 6d 00 20 00 77 00 61-00 73 00 20 00 69 00 6e |.m. .w.a .s. .i.n|
00f0 00 74 00 65 00 72 00 72-00 75 00 70 00 74 00 65 |.t.e.r.r .u.p.t.e|
0100 00 64 00 20 00 77 00 68-00 65 00 6e 00 20 00 74 |.d. .w.h .e.n. .t|
0110 00 68 00 65 00 20 00 73-00 65 00 72 00 76 00 65 |.h.e. .s .e.r.v.e|
0120 00 72 00 20 00 65 00 78-00 70 00 65 00 63 00 74 |.r. .e.x .p.e.c.t|
0130 00 65 00 64 00 20 00 74-00 6f 00 20 00 73 00 65 |.e.d. .t .o. .s.e|
0140 00 65 00 20 00 6d 00 6f-00 72 00 65 00 20 00 64 |.e. .m.o .r.e. .d|
0150 00 61 00 74 00 61 00 2e-00 20 00 54 00 68 00 65 |.a.t.a.. . .T.h.e|
0160 00 20 00 68 00 6f 00 73-00 74 00 20 00 70 00 72 |. .h.o.s .t. .p.r|
0170 00 6f 00 67 00 72 00 61-00 6d 00 20 00 6d 00 61 |.o.g.r.a .m. .m.a|
0180 00 79 00 20 00 68 00 61-00 76 00 65 00 20 00 74 |.y. .h.a .v.e. .t|
0190 00 65 00 72 00 6d 00 69-00 6e 00 61 00 74 00 65 |.e.r.m.i .n.a.t.e|
01a0 00 64 00 2e 00 20 00 45-00 6e 00 73 00 75 00 72 |.d... .E .n.s.u.r|
01b0 00 65 00 20 00 74 00 68-00 61 00 74 00 20 00 79 |.e. .t.h .a.t. .y|
01c0 00 6f 00 75 00 20 00 61-00 72 00 65 00 20 00 75 |.o.u. .a .r.e. .u|
01d0 00 73 00 69 00 6e 00 67-00 20 00 61 00 20 00 73 |.s.i.n.g . .a. .s|
01e0 00 75 00 70 00 70 00 6f-00 72 00 74 00 65 00 64 |.u.p.p.o .r.t.e.d|
01f0 00 20 00 63 00 6c 00 69-00 65 00 6e 00 74 00 20 |. .c.l.i .e.n.t. |
0200 00 61 00 70 00 70 00 6c-00 69 00 63 00 61 00 74 |.a.p.p.l .i.c.a.t|
0210 00 69 00 6f 00 6e 00 20-00 70 00 72 00 6f 00 67 |.i.o.n.  .p.r.o.g|
0220 00 72 00 61 00 6d 00 6d-00 69 00 6e 00 67 00 20 |.r.a.m.m .i.n.g. |
0230 00 69 00 6e 00 74 00 65-00 72 00 66 00 61 00 63 |.i.n.t.e .r.f.a.c|
0240 00 65 00 20 00 28 00 41-00 50 00 49 00 29 00 2e |.e. .(.A .P.I.)..|
0250 00 0c 61 00 63 00 64 00-39 00 32 00 32 00 30 00 |..a.c.d. 9.2.2.0.|
0260 32 00 64 00 65 00 31 00-32 00 00 01 00 00 00 e3 |2.d.e.1. 2.......|
0270 0b 00 0a 00 08 01 00 00-00 38 00 00 00 fd 02 00 |........ .8......|
0280 fd 00 00 00 00 00 00 00-00 00                   |........ ..|

token.c:547:processing result tokens.  marker is  aa(ERROR)
token.c:132:tds_process_default_tokens() marker is aa(ERROR)
mem.c:653:tds_free_all_results()
token.c:2384:tds_process_info() reading message 4804 from server
token.c:2456:tds_process_info() calling client msg handler
dbutil.c:74:_dblib_handle_info_message(0x120f160, 0xfd9d30, 0x7fff4e94e510)
dbutil.c:75:msgno 4804: "While reading current row from host, a premature end-of-message was encountered--an incoming data stream was interrupted when the server expected to see more data. The host program may have terminated. Ensure that you are using a supported client application programming interface (API)."
dblib.c:5807:dbgetuserdata(0x12a1fe0)
dblib.c:5807:dbgetuserdata(0x12a1fe0)
token.c:2473:tds_process_info() returning TDS_SUCCESS
token.c:547:processing result tokens.  marker is  e3(ENVCHANGE)
token.c:132:tds_process_default_tokens() marker is e3(ENVCHANGE)
token.c:547:processing result tokens.  marker is  fd(DONE)
token.c:2082:tds_process_end: more_results = 0
		was_cancelled = 0
		error = 1
		done_count_valid = 0
token.c:2101:                rows_affected = 0
token.c:2104: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:532:tds_process_tokens(0xfd9d30, 0x7fff4e94e668, 0x7fff4e94e66c, 0x100)
token.c:535:tds_process_tokens() state is COMPLETED
dblib.c:3235:dbcancel(0x12a1fe0)
query.c:2203:tds_send_cancel: not in_cancel and idle
dblib.c:1363:dbcmd(0x12a1fe0, IF @@TRANCOUNT > 0 ROLLBACK TRANSACTION)
dblib.c:1369:dbcmd() bufsz = 224
dblib.c:5911:dbfreebuf(0x12a1fe0)
dblib.c:1409:dbsqlexec(0x12a1fe0)
dblib.c:6902:dbsqlsend(0x12a1fe0)
mem.c:653: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:742:Sending packet
0000 01 01 00 6c 00 00 01 00-16 00 00 00 12 00 00 00 |...l.... ........|
0010 02 00 00 00 00 00 00 00-00 00 01 00 00 00 49 00 |........ ......I.|
0020 46 00 20 00 40 00 40 00-54 00 52 00 41 00 4e 00 |F. .@.@. T.R.A.N.|
0030 43 00 4f 00 55 00 4e 00-54 00 20 00 3e 00 20 00 |C.O.U.N. T. .>. .|
0040 30 00 20 00 52 00 4f 00-4c 00 4c 00 42 00 41 00 |0. .R.O. L.L.B.A.|
0050 43 00 4b 00 20 00 54 00-52 00 41 00 4e 00 53 00 |C.K. .T. R.A.N.S.|
0060 41 00 43 00 54 00 49 00-4f 00 4e 00             |A.C.T.I. O.N.|

dblib.c:4667:dbsqlok(0x12a1fe0)
dblib.c:4696:dbsqlok() not done, calling tds_process_tokens()
token.c:532:tds_process_tokens(0xfd9d30, 0x7fff4e94e6d8, 0x7fff4e94e6dc, 0x6914)
util.c:165:Changed query state from PENDING to READING
packet.c:640:Received packet
0000 04 01 00 15 00 38 01 00-fd 00 00 c0 00 00 00 00 |.....8.. ........|
0010 00 00 00 00 00         -                        |.....|

token.c:547:processing result tokens.  marker is  fd(DONE)
token.c:2082:tds_process_end: more_results = 0
		was_cancelled = 0
		error = 0
		done_count_valid = 0
token.c:2101:                rows_affected = 0
token.c:2104: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
dblib.c:4729:dbsqlok() end status is SUCCEED
dblib.c:4740:dbsqlok() end status was success
dblib.c:1704:dbresults(0x12a1fe0)
dblib.c:1709:dbresults: dbresults_state is 5 (_DB_RES_SUCCEED)
dblib.c:1693:dbresults returning 1 (SUCCEED)
dblib.c:2053:dbnextrow(0x12a1fe0)
dblib.c:2059:dbnextrow() dbresults_state = 3 (_DB_RES_NEXT_RESULT)
dblib.c:2064:leaving dbnextrow() returning -2 (NO_MORE_ROWS)
dblib.c:1704:dbresults(0x12a1fe0)
dblib.c:1709:dbresults: dbresults_state is 3 (_DB_RES_NEXT_RESULT)
token.c:532:tds_process_tokens(0xfd9d30, 0x7fff4e94e6b8, 0x7fff4e94e6bc, 0x6914)
token.c:535:tds_process_tokens() state is COMPLETED
dblib.c:1730:dbresults() tds_process_tokens returned 1 (TDS_NO_MORE_RESULTS),
			result_type TDS_DONE_RESULT
dblib.c:1693:dbresults returning 2 (NO_MORE_RESULTS)
dblib.c:1480:dbclose(0x12a1fe0)
dblib.c:242:dblib_del_connection(0x7f1db25f55c0, 0xfd9d30)
query.c:3797:tds_disconnect() 
util.c:165:Changed query state from IDLE to DEAD
mem.c:653:tds_free_all_results()
dblib.c:289:dblib_release_tds_ctx(1)
dblib.c:5911:dbfreebuf(0x12a1fe0)
dblib.c:775:dbsetlname(0x11e8160, , 14)
dblib.c:750:dbloginfree(0x11e8160)
@joshuahlang joshuahlang mentioned this issue Feb 15, 2018
Closed
@freddy77
Copy link
Contributor

That's weird, looks like the column is send using varchar(max), but looks like the server does not like the row format (which seems correct to me, is exactly what the server usually expects).
Get a reproduction, a select reply is:
0000 04 01 00 4c 00 33 01 00-81 01 00 00 00 00 00 09 |...L.3.. ........|
0010 00 e7 ff ff 09 04 d0 00-34 06 73 00 74 00 72 00 |........ 4.s.t.r.|
0020 69 00 6e 00 67 00 d1 08-00 00 00 00 00 00 00 08 |i.n.g... ........|
0030 00 00 00 63 00 69 00 61-00 6f 00 00 00 00 00 fd |...c.i.a .o......|
0040 10 00 c1 00 01 00 00 00-00 00 00 00 |........ ....|

The bulk insert (rejected) is:
0000 07 01 00 3f 00 00 01 00-81 01 00 00 00 00 00 09 |...?.... ........|
0010 00 e7 ff ff 09 04 d0 00-34 06 73 00 74 00 72 00 |........ 4.s.t.r.|
0020 69 00 6e 00 67 00 d1 08-00 00 00 00 00 00 00 08 |i.n.g... ........|
0030 00 00 00 63 00 69 00 61-00 6f 00 00 00 00 00 |...c.i.a .o.....|

Beside the DONE token (on select but not on bulk) they are exactly the same (ignoring 8 byte header)

@freddy77
Copy link
Contributor

freddy77 commented Feb 16, 2018 •
edited
Loading

This is weird. I basically try the MS utilities to see the difference. Apparently instead of sending the size at the beginning they send unknown (-2 basically) and works. Both segmentations of data should work from the protocol specification but looks the server don't like a proper length. I replaced the size with -2 in our code and works!

Can you try this patch (which works for me) ?

diff --git a/src/tds/data.c b/src/tds/data.c
index 8ca8349b..726a2b89 100644
--- a/src/tds/data.c
+++ b/src/tds/data.c
@@ -1019,7 +1019,7 @@ tds_generic_put(TDSSOCKET * tds, TDSCOLUMN * curcol, int bcp7)

                switch (curcol->column_varint_size) {
                case 8:
-                       tds_put_int8(tds, colsize);
+                       tds_put_int8(tds, -2);
                        tds_put_int(tds, colsize);
                        break;
                case 4: /* It's a BLOB... */

if this works even for you I would say is a server bug... or at least a documentation one

@joshuahlang
Copy link
Contributor Author

Yes, that also works for me. I would tend to agree that this seems like an issue with the documentation not matching the actual behavior. From the TDS spec (page 32 of v20171201):

In the actual data length case, the ULONGLONGLEN specifies the length of the data and is followed
by any number of PLP_CHUNKs containing the data. The length of the data specified by
ULONGLONGLEN is used as a hint for the receiver. The receiver SHOULD validate that the length
value specified by ULONGLONGLEN matches the actual data length.

This appears to be what the current (non-functioning) code is doing: sending the total length, then a single PLP_CHUNK with the data (and a PLP_TERMINATOR after). However, simply removing the tds_put_int(tds, colsize); line also seems to fix the issue. Perhaps when sending the total length, subsequent data need not be length-prefixed?

@freddy77
Copy link
Contributor

Tried to remove the line you suggested, does not work all the time and imported data are not what they are expected to be. So I can confirm, this is a database server bug. Nothing to worry, operation will fails if the client (FreeTDS in this case) is not implementing some workaround like sending unknown length (the -2). Microsoft client already implements the client in that way.
Applied a patch for FreeTDS with a comment (like b491a5a for Branch-1_00).
Patch is really specific and I don't think will cause any regression or problems.
New snapshots will be generated tomorrow.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@freddy77 @joshuahlang