Skip to Content.
Sympa Menu

freetds - [freetds] SQL Server error not being raised to PHP

freetds AT lists.ibiblio.org

Subject: FreeTDS Development Group

List archive

Chronological Thread  
  • From: Diogo de Araujo Sgrillo <dsgrillo AT gmail.com>
  • To: freetds AT lists.ibiblio.org
  • Subject: [freetds] SQL Server error not being raised to PHP
  • Date: Wed, 25 Oct 2017 16:11:25 +0200

Hi,



I’m not completely sure this is an FreeTDS issue, but I have no more ideas
what it could be.



We developed a system a few months ago using PHP and MySQL.

Recently, it was migrated to SQL Server and some issues started to appear.

We have a middleware which starts a transaction at the beginning of
request, and commit if no exception is caught. Some requests started to
crash PHP – and the errors were hard to track because I think FreeTDS is
swallowing them.



If the request causes some specific kind of SQL error (not every kind), the
transaction is rolled back before the ROLLBACK command is issued by PHP –
and when PHP sends the rollback it prints “The COMMIT TRANSACTION request
has no corresponding BEGIN TRANSACTION” on log and the PHP process crashes.



Notes: tsql –C:

Compile-time settings (established with the "configure" script)

Version: freetds v1.00.55

freetds.conf directory: /usr/local/Cellar/freetds/1.00.55/etc

MS db-lib source compatibility: no

Sybase binary compatibility: no

Thread safety: yes

iconv library: yes

TDS version: 7.3

iODBC: no

unixodbc: no

SSPI "trusted" logins: no

Kerberos: no

OpenSSL: yes

GnuTLS: no

MARS: no



I’m running PHP 5.6 on a MacOS, and it is a SQL Server 2017 running on
Docker (https://hub.docker.com/r/microsoft/mssql-server-linux/)

PDO::ATTR_ERRMODE is set to PDO::ERRMODE_EXCEPTION (some other SQL Server
errors are being raised.)

I'm using pdo_dblib to connect.



How to reproduce:



create table funcionario (FUN_ID int);

insert into table a (1);



select FUN_ID from funcionario where FUN_ID = ‘a’; -- doesn’t raise an
exception to PHP, although the error is printed in freetds.log. If I start
a transaction before, and commit it after – the commit will break and PHP
process will crash.



tdsdump:



16:51:56.475861 79248 (packet.c:742):Sending packet

0000 01 01 00 82 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 73 00 |........ ......s.|

0020 65 00 6c 00 65 00 63 00-74 00 20 00 46 00 55 00 |e.l.e.c. t. .F.U.|

0030 4e 00 5f 00 49 00 44 00-20 00 66 00 72 00 6f 00 |N._.I.D. .f.r.o.|

0040 6d 00 20 00 66 00 75 00-6e 00 63 00 69 00 6f 00 |m. .f.u. n.c.i.o.|

0050 6e 00 61 00 72 00 69 00-6f 00 20 00 77 00 68 00 |n.a.r.i. o. .w.h.|

0060 65 00 72 00 65 00 20 00-46 00 55 00 4e 00 5f 00 |e.r.e. . F.U.N._.|

0070 49 00 44 00 20 00 3d 00-20 00 27 00 61 00 27 00 |I.D. .=. .'.a.'.|

0080 20 00 - | .|



16:51:56.475906 79248 (dblib.c:4657):dbsqlok(0x7ffe57592d10)

16:51:56.475926 79248 (dblib.c:4686):dbsqlok() not done, calling
tds_process_tokens()

16:51:56.475939 79248 (token.c:532):tds_process_tokens(0x7ffe57591f70,
0x7fff59ce595c, 0x7fff59ce596c, 0x6914)

16:51:56.475947 79248 (util.c:165):Changed query state from PENDING to
READING

16:51:56.477510 79248 (packet.c:640):Received packet

0000 04 01 00 e7 00 34 01 00-81 01 00 00 00 00 00 08 |...?.4.. ........|

0010 00 38 06 46 00 55 00 4e-00 5f 00 49 00 44 00 aa |.8.F.U.N ._.I.D.?|

0020 b8 00 f5 00 00 00 01 10-49 00 43 00 6f 00 6e 00 |?.?..... I.C.o.n.|

0030 76 00 65 00 72 00 73 00-69 00 6f 00 6e 00 20 00 |v.e.r.s. i.o.n. .|

0040 66 00 61 00 69 00 6c 00-65 00 64 00 20 00 77 00 |f.a.i.l. e.d. .w.|

0050 68 00 65 00 6e 00 20 00-63 00 6f 00 6e 00 76 00 |h.e.n. . c.o.n.v.|

0060 65 00 72 00 74 00 69 00-6e 00 67 00 20 00 74 00 |e.r.t.i. n.g. .t.|

0070 68 00 65 00 20 00 76 00-61 00 72 00 63 00 68 00 |h.e. .v. a.r.c.h.|

0080 61 00 72 00 20 00 76 00-61 00 6c 00 75 00 65 00 |a.r. .v. a.l.u.e.|

0090 20 00 27 00 61 00 27 00-20 00 74 00 6f 00 20 00 | .'.a.'. .t.o. .|

00a0 64 00 61 00 74 00 61 00-20 00 74 00 79 00 70 00 |d.a.t.a. .t.y.p.|

00b0 65 00 20 00 69 00 6e 00-74 00 2e 00 0c 32 00 32 |e. .i.n. t....2.2|

00c0 00 37 00 63 00 64 00 39-00 38 00 32 00 35 00 39 |.7.c.d.9 .8.2.5.9|

00d0 00 63 00 34 00 00 01 00-00 00 fd 02 00 c1 00 00 |.c.4.... ..?..?..|

00e0 00 00 00 00 00 00 00 - |.......|



16:51:56.477593 79248 (token.c:547):processing result tokens. marker is
81(TDS7_RESULT)

16:51:56.477602 79248 (token.c:1554):processing TDS7 result metadata.

16:51:56.477607 79248 (mem.c:651):tds_free_all_results()

16:51:56.477613 79248 (token.c:1579):set current_results (1 column) to
tds->res_info

16:51:56.477618 79248 (token.c:1586):setting up 1 columns

16:51:56.477635 79248 (token.c:1523):tds7_get_data_info:

colname = FUN_ID

type = 56 (int)

server's type = 56 (int)

column_varint_size = 0

column_size = 4 (4 on server)

16:51:56.477644 79248 (token.c:1597): name size/wsize
type/wtype utype

16:51:56.477651 79248 (token.c:1598): -------------------- ---------------
--------------- -------

16:51:56.477658 79248 (token.c:1603): FUN_ID 4/4
56/56 0

16:51:56.477665 79248 (util.c:165):Changed query state from READING to
PENDING

16:51:56.477673 79248 (dblib.c:4712):dbsqlok() found result token

16:51:56.477680 79248 (dblib.c:1700):dbresults(0x7ffe57592d10)

16:51:56.477687 79248 (dblib.c:1705):dbresults: dbresults_state is 1
(_DB_RES_RESULTSET_EMPTY)

16:51:56.477693 79248 (token.c:532):tds_process_tokens(0x7ffe57591f70,
0x7fff59ce591c, 0x7fff59ce5918, 0x6914)

16:51:56.477700 79248 (util.c:165):Changed query state from PENDING to
READING

16:51:56.477708 79248 (token.c:547):processing result tokens. marker is
aa(ERROR)

16:51:56.477722 79248 (token.c:132):tds_process_default_tokens() marker is
aa(ERROR)

16:51:56.477735 79248 (token.c:2345):tds_process_info() reading message 245
from server

16:51:56.477748 79248 (token.c:2417):tds_process_info() calling client msg
handler

16:51:56.477755 79248
(dbutil.c:74):_dblib_handle_info_message(0x7ffe57700110, 0x7ffe57591f70,
0x7fff59ce5790)

16:51:56.477761 79248 (dbutil.c:75):msgno 245: "Conversion failed when
converting the varchar value 'a' to data type int."

16:51:56.477768 79248 (dblib.c:5797):dbgetuserdata(0x7ffe57592d10)

16:51:56.477776 79248 (dblib.c:5797):dbgetuserdata(0x7ffe57592d10)

16:51:56.477787 79248 (token.c:2434):tds_process_info() returning
TDS_SUCCESS

16:51:56.477794 79248 (token.c:547):processing result tokens. marker is
fd(DONE)

16:51:56.477800 79248 (token.c:2082):tds_process_end: more_results = 0

was_cancelled = 0

error = 1

done_count_valid = 0

16:51:56.477807 79248 (token.c:2099): rows_affected = 0

16:51:56.477814 79248 (token.c:2102):tds_process_end() state set to TDS_IDLE

16:51:56.477820 79248 (util.c:165):Changed query state from READING to IDLE

16:51:56.477826 79248 (util.c:83):logic error: cannot change query state
from IDLE to PENDING

16:51:56.477832 79248 (util.c:165):Changed query state from IDLE to IDLE

16:51:56.477838 79248 (dblib.c:1726):dbresults() tds_process_tokens
returned 0 (TDS_SUCCESS),

result_type TDS_DONE_RESULT

16:51:56.477845 79248 (dblib.c:1753):dbresults(): dbresults_state is 1
(_DB_RES_RESULTSET_EMPTY)

16:51:56.477851 79248 (dblib.c:1689):dbresults returning 1 (SUCCEED)

16:51:56.477858 79248 (dblib.c:2791):dbcount(0x7ffe57592d10)

16:51:56.477864 79248 (dblib.c:1840):dbnumcols(0x7ffe57592d10)

16:51:56.477870 79248 (dblib.c:2791):dbcount(0x7ffe57592d10)

16:51:56.477876 79248 (dblib.c:1840):dbnumcols(0x7ffe57592d10)

16:51:56.477883 79248 (dblib.c:1866):dbcolname(0x7ffe57592d10, 1)

16:51:56.477887 79248 (dblib.c:3063):dbcollen(0x7ffe57592d10, 1)

16:51:56.477911 79248 (dblib.c:2049):dbnextrow(0x7ffe57592d10)

16:51:56.477916 79248 (dblib.c:2055):dbnextrow() dbresults_state = 3
(_DB_RES_NEXT_RESULT)

16:51:56.477920 79248 (dblib.c:2060):leaving dbnextrow() returning -2
(NO_MORE_ROWS)

16:51:56.524837 79248 (dblib.c:1476):dbclose(0x7ffe57592d10)

16:51:56.524865 79248 (dblib.c:241):dblib_del_connection(0x106cdf0e0,
0x7ffe57591f70)

16:51:56.524874 79248 (query.c:3796):tds_disconnect()

16:51:56.524939 79248 (util.c:165):Changed query state from IDLE to DEAD

16:51:56.524950 79248 (mem.c:651):tds_free_all_results()

16:51:56.532415 79248 (dblib.c:288):dblib_release_tds_ctx(1)

16:51:56.532457 79248 (dblib.c:5901):dbfreebuf(0x7ffe57592d10)

16:51:56.532467 79248 (dblib.c:749):dbloginfree(0x7ffe575be6b0)





select FUN_ID from funcionario where FUN_ID = ‘a’ OR FUN_ID = 1; -- same as
before – returns an empty result set

select FUN_ID from unexistingTable; -- **raise** an exception to PHP and
prints the error in freetds.log



Hope you can help.

Sincerely,

Diogo Sgrillo




Archive powered by MHonArc 2.6.24.

Top of Page