FreeTDS Development Group

[Locke Berkebile <locke AT pushby.com>]

The behavior seems to start at around a load of 14 (not .14).  

We are load testing HP blades and the application is primarily CPU 
bound.

Testing with a local PostgreSQL instance, we can continue serving
xml data requests with resonable response times at loads of 30 or 
above.

I will turn allow_persistent off and increase the connect_timeout.

What is the difference between mssql.timeout and 
mssql.connect_timeout?   Is the former the query response time 
and the latter just the handshake/initial response phase?

Locke



On Fri, Feb 02, 2007 at 11:49:31AM -0600, Sokol, Ryan - 244 wrote:
> Try making your mssql.connect_timeout value around 60 seconds.  Also, be
> sure to not use pconnect.
> 
> You saying your server load average is 14 not .14?
> 
> -----Original Message-----
> From: freetds-bounces AT lists.ibiblio.org
> [mailto:freetds-bounces AT lists.ibiblio.org] On Behalf Of Locke Berkebile
> Sent: Friday, February 02, 2007 11:40 AM
> To: FreeTDS Development Group
> Subject: Re: [freetds] Freezes on certain queries under load
> 
> 
> mssql
> 
> MSSQL Support => enabled
> Active Persistent Links => 0
> Active Links => 0
> Library version => FreeTDS
> 
> Directive => Local Value => Master Value
> mssql.allow_persistent => On => On
> mssql.batchsize => 0 => 0
> mssql.charset => no value => no value
> mssql.compatability_mode => Off => Off
> mssql.connect_timeout => 5 => 5
> mssql.datetimeconvert => On => On
> mssql.max_links => Unlimited => Unlimited
> mssql.max_persistent => Unlimited => Unlimited
> mssql.max_procs => Unlimited => Unlimited
> mssql.min_error_severity => 10 => 10
> mssql.min_message_severity => 10 => 10
> mssql.secure_connection => Off => Off
> mssql.textlimit => Server default => Server default
> mssql.textsize => Server default => Server default
> mssql.timeout => 60 => 60
> 
> 
> Locke
> 
> 
> 
> On Fri, Feb 02, 2007 at 11:34:12AM -0600, Sokol, Ryan - 244 wrote:
> > Which PHP functions are you using (mssql, odbc, Sybase)?
> > 
> > -----Original Message-----
> > From: freetds-bounces AT lists.ibiblio.org
> > [mailto:freetds-bounces AT lists.ibiblio.org] On Behalf Of Locke
> Berkebile
> > Sent: Friday, February 02, 2007 11:30 AM
> > To: FreeTDS Development Group
> > Subject: [freetds] Freezes on certain queries under load
> > 
> > 
> > We recently migrated our application servers from Windows Server 2003
> > to FreeBSD to boost performance of our PHP application.  We are using
> > FreeTDS to connect to our existing SQL Server 2000 database server.
> > 
> > FreeTDS was easy to setup and it works very well up to a point.  Under
> > moderate load (where "moderate" is a load average of about 14 and
> above)
> > we begin to see failures.  On investigation, we the following patten
> > emerges:
> > 
> > Occasionally (not always or even usually), selecting with XLOCK causes
> 
> > a freeze in the TDS connection to SQL Server.   The log with
> timestamps
> > included below shows an example of this behavior.
> > 
> > We tested with FreeTDS .63 (bundled in the current FreeBSD ports 
> > collection), FreeTDS .64 and current (.65).  We also tested with
> > protocol version 7.0 and 8.0.  Both produced the same behavior.
> > .63 and .64 produced the same behavior.  .65 current produced
> > many more connection errors, which we didn't pursue further.
> > 
> > Can anyone provide clues to resolving this behavior?
> > 
> > Locke Berkebile
> > San Francisco
> > 
> > 
> > Details follow:
> > 
> > 1) freetds.conf for our server:
> > 
> > [taz]
> >     host = 192.168.10.7
> >     port = 1433
> >     tds version = 8.0
> > 
> > 
> > 2) The head of the tds log file (showing the FreeTDS version
> >    and the TDS protocol version):
> > 
> > 11:22:31.629409 Starting log file for FreeTDS 0.63
> >     on 2007-01-24 11:22:31 with debug level 99.
> > 11:22:31.629633 names for ISO-8859-1: ISO-8859-1
> > 11:22:31.629645 names for UTF-8: UTF-8
> > 11:22:31.629654 names for UCS-2LE: UCS-2LE
> > 11:22:31.629661 names for UCS-2BE: UCS-2BE
> > 11:22:31.629669 iconv to convert client-side data to the "ISO-8859-1"
> > character set
> > 11:22:31.629691 tds_iconv_info_init: converting
> "ISO-8859-1"->"UCS-2LE"
> > 11:22:31.629708 tds_iconv_info_init: converting
> "ISO-8859-1"->"UCS-2LE"
> > 11:22:31.629759 Connecting to 192.168.10.7 port 1433, TDS 7.0.
> > 11:22:31.630629 tds_put_string converting 16 bytes of
> "bsdbanks1.ja.org"
> > 11:22:31.630745 tds_put_string wrote 32 bytes
> > 11:22:31.630756 tds_put_string converting 11 bytes of "Banks_User2"
> > 11:22:31.630766 tds_put_string wrote 22 bytes
> > 11:22:31.630798 tds_put_string converting 5 bytes of "PHP 5"
> > 11:22:31.630809 tds_put_string wrote 10 bytes
> > 11:22:31.630817 tds_put_string converting 3 bytes of "taz"
> > 11:22:31.630826 tds_put_string wrote 6 bytes
> > 11:22:31.630834 tds_put_string converting 10 bytes of "DB-Library"
> > 11:22:31.630843 tds_put_string wrote 20 bytes
> > 11:22:31.630852 tds_put_string converting 10 bytes of "us_english"
> > 11:22:31.630861 tds_put_string wrote 20 bytes
> > 11:22:31.630869 tds_put_string wrote 0 bytes
> > 11:22:31.631023 tds_process_login_tokens()
> > 
> > 
> > 3) The portion of the tds log exhibiting the freezing behavior.  Note
> > that 
> >    the timestamps jump from 11:23:44.041544 to 11:24:35.541649.
> During
> > this
> >    window, we receive connection failure errors in our php
> application:
> > 
> > 11:23:44.041234 tds_process_end() state set to TDS_IDLE
> > 11:23:44.041244 dbsqlok() end status was success
> > 11:23:44.041255 dbresults()
> > 11:23:44.041267 tds_process_row_tokens() state is COMPLETED
> > 11:23:44.041321 dbcmd() bufsz = 20
> > 11:23:44.041332 in dbfreebuf()
> > 11:23:44.041345 in dbsqlexec()
> > 11:23:44.041355 in dbsqlsend()
> > 11:23:44.041366 tds_free_all_results()
> > 11:23:44.041378 tds_put_string converting 117 bytes of "
> >       SELECT lock_state, set_stamp
> >       FROM gamelock_table
> >       WITH (XLOCK)
> >       WHERE game_id = '25318'
> >       "
> > 11:23:44.041393 tds_put_string wrote 234 bytes
> > 11:23:44.041404 Sending packet
> > 0000 01 01 00 f2 00 00 01 00-0a 00 20 00 20 00 20 00 |........ .. . .
> .|
> > 0010 20 00 20 00 20 00 53 00-45 00 4c 00 45 00 43 00 | . . .S.
> E.L.E.C.|
> > 0020 54 00 20 00 6c 00 6f 00-63 00 6b 00 5f 00 73 00 |T. .l.o.
> c.k._.s.|
> > 0030 74 00 61 00 74 00 65 00-2c 00 20 00 73 00 65 00 |t.a.t.e. ,.
> .s.e.|
> > 0040 74 00 5f 00 73 00 74 00-61 00 6d 00 70 00 0a 00 |t._.s.t.
> a.m.p...|
> > 0050 20 00 20 00 20 00 20 00-20 00 20 00 46 00 52 00 | . . . .  .
> .F.R.|
> > 0060 4f 00 4d 00 20 00 67 00-61 00 6d 00 65 00 6c 00 |O.M. .g.
> a.m.e.l.|
> > 0070 6f 00 63 00 6b 00 5f 00-74 00 61 00 62 00 6c 00 |o.c.k._.
> t.a.b.l.|
> > 0080 65 00 0a 00 20 00 20 00-20 00 20 00 20 00 20 00 |e... . .  . . .
> .|
> > 0090 57 00 49 00 54 00 48 00-20 00 28 00 58 00 4c 00 |W.I.T.H.
> .(.X.L.|
> > 00a0 4f 00 43 00 4b 00 29 00-0a 00 20 00 20 00 20 00 |O.C.K.). .. . .
> .|
> > 00b0 20 00 20 00 20 00 57 00-48 00 45 00 52 00 45 00 | . . .W.
> H.E.R.E.|
> > 00c0 20 00 67 00 61 00 6d 00-65 00 5f 00 69 00 64 00 | .g.a.m.
> e._.i.d.|
> > 00d0 20 00 3d 00 20 00 27 00-32 00 35 00 33 00 31 00 | .=. .'.
> 2.5.3.1.|
> > 00e0 38 00 27 00 0a 00 20 00-20 00 20 00 20 00 20 00 |8.'... .  . . .
> .|
> > 00f0 20 00                  -                        | .|
> > 
> > 11:23:44.041544 in dbsqlok() 
> > 11:24:35.541649 Received header
> > 0000 04 01 00 53 00 3d 01 00-                        |...S.=..|
> > 
> > 11:24:35.541679 Received packet
> > 0000 81 02 00 00 00 08 00 38-0a 6c 00 6f 00 63 00 6b |.......8
> .l.o.c.k|
> > 0010 00 5f 00 73 00 74 00 61-00 74 00 65 00 00 00 08 |._.s.t.a
> .t.e....|
> > 0020 00 3d 09 73 00 65 00 74-00 5f 00 73 00 74 00 61 |.=.s.e.t
> ._.s.t.a|
> > 0030 00 6d 00 70 00 d1 00 00-00 00 c0 98 00 00 2c 7f |.m.p....
> ......,.|
> > 0040 cc 00 fd 10 00 c1 00 01-00 00 00                |........ ...|
> > 
> > 11:24:35.541709 dbsqlok() marker is 81
> > 11:24:35.541745 dbsqlok() found result token
> > 11:24:35.541757 dbresults()
> > 11:24:35.541767 tds_free_all_results()
> > 11:24:35.541778 processing result tokens.  marker is  81(TDS7_RESULT)
> > 11:24:35.542015 tds_free_all_results()
> > 11:24:35.542032 processing TDS7 result. set current_results to
> > tds->res_info
> > 11:24:35.542044 tds_get_string: reading 20 from wire to give 10 to
> > client.
> > 11:24:35.542057 tds7_get_data_info:1558: 
> >     colname = lock_state (10 bytes)
> >     type = 56 (int)
> >     server's type = 56 (int)
> >     column_varint_size = 0
> >     column_size = 4 (4 on server)
> > 11:24:35.542071 tds_get_string: reading 18 from wire to give 9 to
> > client.
> > 11:24:35.542082 tds7_get_data_info:1558: 
> >     colname = set_stamp (9 bytes)
> >     type = 61 (datetime)
> >     server's type = 61 (datetime)
> >     column_varint_size = 0
> >     column_size = 8 (8 on server)
> > 11:24:35.542096 dbresults() process_result_tokens returned result_type
> =
> > 4049 retcode = 1
> > 11:24:35.542107 processing result tokens.  marker is  d1(ROW)
> > 11:24:35.542118 dbresults() process_result_tokens returned result_type
> =
> > 4040 retcode = 1
> > 11:24:35.542129 dbnextrow()
> > 11:24:35.542138 dbnextrow() dbresults_state = 2
> > 11:24:35.542149 processing row tokens.  marker is  d1(ROW)
> > 11:24:35.542168 processing row.  column is 0 varint size = 0
> > 11:24:35.542179 processing row.  column size is 4 
> > 11:24:35.542188 clearing column 0 NULL bit
> > 11:24:35.542198 processing row.  column is 1 varint size = 0
> > 11:24:35.542208 processing row.  column size is 8 
> > 11:24:35.542218 clearing column 1 NULL bit
> > 11:24:35.542229 leaving dbnextrow() returning -1
> > 11:24:35.542245 dbdatlen() type = 56
> > 11:24:35.542255 leaving dbdatlen() returning 4
> > 11:24:35.542266 dbdatlen() type = 61
> > 11:24:35.542276 leaving dbdatlen() returning 8
> > 11:24:35.542285 tds_willconvert()
> > 11:24:35.542297 tds_willconvert() 61 47 1
> > 11:24:35.542335 dbdatlen() type = 61
> > 11:24:35.542347 leaving dbdatlen() returning 8
> > 11:24:35.542361 dbnextrow()
> > 11:24:35.542370 dbnextrow() dbresults_state = 2
> > 11:24:35.542380 processing row tokens.  marker is  fd(DONE)
> > 11:24:35.542390 tds_process_end: more_results = 0
> >             was_cancelled = 0
> >             error = 0
> >             done_count_valid = 1
> > 11:24:35.542401 tds_process_end() state set to TDS_IDLE
> > 
> > _______________________________________________
> > 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
> _______________________________________________
> 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