Forums | Admin

Discussion Forums: help

Start New Thread Start New Thread

 

By: Simon Macneall
RE: Blobs not being saved [ reply ]  
2010-12-10 04:37
Hi Praveen,

Unfortunately our access to the power7 box has finished. It was in the IBM innovation centre here in Australia, but unfortunately was needed for another purpose.

Thanks for the help, and if we get access to another machine I'll try your last suggestion to get more information.

Simon

By: Praveen Devarao
RE: Blobs not being saved [ reply ]  
2010-12-03 08:06
Hi Simon,

The results are making stuffs "interesting". The integer value passed is 0 (What I was expecting is the primary key value). I cant take this as the problem because if 0 was is then no column would have been update which means we had to atleast see the marker BLOB('?') inserted, but in your case it is an empty string.


Can you provide more details as below, might be these will help

With the patch applied and the puts statement (@ line 80 suggested earlier) in adapter can you let me know what is the output and also provide me the corresponding CLI trace?

Also can you run a irb session and issue a select statement on the table and check what is the value present in the row.

--------------------------------------------------
$irb
>>require 'ibm_db'
>>conn = IBM_DB.connect 'railsdb','user','password'
>>stmt = IBM_DB.exec conn, "select * from testtable where id = 10" #Give the id value that you see when reload issued
>> IBM_DB.fetch_assoc stmt
>> IBM_DB.close conn
>> quit
$
--------------------------------------------------

Thanks

Praveen

By: Simon Macneall
RE: Blobs not being saved [ reply ]  
2010-12-03 06:41
Hi Praveen,

Thanks. Here is the output from running with the instrumented library.

=> #<ModelTest id: nil, name: nil, data: nil>
>> m.data = "foo"
=> "foo"
>> m.save

string value is foo

integer value passed is 0

Value @ putdata is
length is 3=> true

By: Praveen Devarao
RE: Blobs not being saved [ reply ]  
2010-12-03 06:26
Hi Simon,

Once you have made the changes, issue the following commands from the directory where the driver files are available (ibm_db-2.5.5/ext)

$ruby extconf.rb
$make

Make sure you have the env variables IBM_DB_LIB and IBM_DB_INCLUDE set to sqllib/lib and sqllib/include respectively.

This will generate ibm_db.so file. Copy this file over to the lib (ibm_db-2.5.5/lib) directory and you are ready.

Thanks

Praveen

By: Simon Macneall
RE: Blobs not being saved [ reply ]  
2010-12-03 06:07
I'm probably being dense, but once I make the changes, how do I rebuild the native parts only?

Thanks
Simon

By: Praveen Devarao
RE: Blobs not being saved [ reply ]  
2010-12-03 05:09
Hi Simon,

From what you have mentioned looks like the issue might be in the driver. To further diagnose I have instrumented the ibm_db driver with the patch below. Kindly apply the same and let me know what output you see.

This patch is checking if the data is received in the driver and if it is received right.

--------------------
--- trunk/IBM_DB_Driver/ibm_db.c (revision 41)
+++ trunk/IBM_DB_Driver/ibm_db.c (working copy)
@@ -5551,6 +5551,7 @@

case T_FIXNUM:
curr->ivalue = FIX2LONG( *bind_data );
+ printf("\ninteger value passed is %d\n", curr->ivalue);
if(curr->data_type == SQL_BIGINT) {
valueType = SQL_C_DEFAULT;
} else {
@@ -5628,6 +5629,7 @@
tmp_str = (SQLCHAR *) rb_str2cstr( *bind_data, (long*) &curr->ivalue );
origlen = curr->ivalue;
#endif
+ printf("\nstring value is %s\n", tmp_str);
if (curr->param_type == SQL_PARAM_OUTPUT || curr->param_type == SQL_PARAM_INPUT_OUTPUT) {
/*
* An extra parameter is given by the client to pick the size of the string
@@ -6280,6 +6282,7 @@
while ( _ruby_ibm_db_SQLParamData_helper( put_param_data_args ) == SQL_NEED_DATA ) {

/* passing data value for a parameter */
+ printf("\nValue @ putdata is %s\n length is %d", ((param_node*)(put_param_data_args->valuePtr))->svalue, ((param_node*)(put_param_data_args->valuePtr))->ivalue);
rc = _ruby_ibm_db_SQLPutData_helper(put_param_data_args);

if ( rc == SQL_ERROR ) {
--------------------

Thanks

Praveen

By: Simon Macneall
RE: Blobs not being saved [ reply ]  
2010-12-02 08:42
Hi Praveen,

Thanks. Looks like the value is ok.

>> m = ModelTest.new
m=> #<ModelTest id: nil, name: nil, data: nil>
>> m.data = "test"
=> "test"
>> m.save
Value=test
Value=61
=> true
>> m.reload
=> #<ModelTest id: 61, name: nil, data: "">
>>

Simon

By: Praveen Devarao
RE: Blobs not being saved [ reply ]  
2010-12-02 06:17
Hi Simon,

From the trace I see that a empty string is inserted into the table

....
[12/01/2010 19:16:20.980394] SQLPutData( hStmt=1:2, rgbValue=x'', cbValue=0 )
....

To further check on this can you track if the data is correctly received in the handle_lobs call back method (in ibm_db adapter). Here is how you can check.

Add the following 'puts' statement @ line 81 of the file ibm_db_adapter.rb

values.each do |value|
puts value
end

This should print out the blob value and the id value (of the row that was inserted currently).

With this we could narrow down the problem to know if it is in Driver or adapter and then further diagnose.

Thanks

Praveen

By: Simon Macneall
RE: Blobs not being saved [ reply ]  
2010-12-01 08:34
Here's the trace. I'm not sure what I'm looking at, but comparing it to the trace I generated from the working system, the only obvious difference is the cbSqlStr values in the insert/update statements.

[ Process: 12061, Thread: 268381584 ]
[ Date & Time: 12/01/2010 19:16:12.658495 ]
[ Product: QDB2/LINUXPPC DB2 v9.7.0.3 ]
[ Level Identifier: 08040107 ]
[ CLI Driver Version: 09.02.0000 ]
[ Informational Tokens: "DB2 v9.7.0.3","s101006","IP23220","Fixpack 3" ]
[ Install Path: /opt/ibm/db2/V9.7 ]
[ db2cli.ini Location: /home/db2inst1/sqllib/cfg/db2cli.ini ]
[ CLI Driver Type: IBM DB2 Application Runtime Client ]



[12/01/2010 19:16:12.658571] SQLAllocHandle( fHandleType=SQL_HANDLE_ENV, hInput=0:0, phOutput=&10dad660 )
[12/01/2010 19:16:12.658701] ---> Time elapsed - 0 seconds

[12/01/2010 19:16:12.658761] SQLAllocHandle( phOutput=0:1 )
[12/01/2010 19:16:12.658808] <--- SQL_SUCCESS Time elapsed - +2.370000E-004 seconds

[12/01/2010 19:16:12.669005] SQLSetEnvAttr( hEnv=0:1, fAttribute=SQL_ATTR_ODBC_VERSION, vParam=3, cbParam=0 )
[12/01/2010 19:16:12.669123] ---> Time elapsed - +1.019700E-002 seconds

[12/01/2010 19:16:12.669153] SQLSetEnvAttr( )
[12/01/2010 19:16:12.669179] <--- SQL_SUCCESS Time elapsed - +1.740000E-004 seconds

[12/01/2010 19:16:12.669208] SQLAllocHandle( fHandleType=SQL_HANDLE_DBC, hInput=0:1, phOutput=&10dad664 )
[12/01/2010 19:16:12.669297] ---> Time elapsed - +2.900000E-005 seconds

[12/01/2010 19:16:12.669379] SQLAllocHandle( phOutput=0:1 )
[12/01/2010 19:16:12.669434] <--- SQL_SUCCESS Time elapsed - +2.260000E-004 seconds

[12/01/2010 19:16:12.669472] SQLSetConnectAttr( hDbc=0:1, fOption=SQL_ATTR_AUTOCOMMIT, pvParam=&00000001, iStrLen=-3 )
[12/01/2010 19:16:12.669582] ---> Time elapsed - +3.800000E-005 seconds

[12/01/2010 19:16:12.669611] SQLSetConnectAttr( )
[12/01/2010 19:16:12.669638] <--- SQL_SUCCESS Time elapsed - +1.660000E-004 seconds

[12/01/2010 19:16:12.669685] SQLConnect( hDbc=0:1, szDSN="gateway", cbDSN=7, szUID="db2inst1", cbUID=8, szAuthStr="********", cbAuthStr=8 )
[12/01/2010 19:16:12.669857] ---> Time elapsed - +4.700000E-005 seconds
sqlccconnr( timeout - +0.000000E+000, protocol - 0x06 )
sqlccconnr( ) - time elapsed - +0.000000E+000
sqlccsend( Handle - 4097699792 )
sqlccsend( ulBytes - 283 )
sqlccsend( ) rc - 0, time elasped - +4.000000E-006
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 140 ) - rc - 0, time elapsed - +8.800000E-005
sqlccsend( Handle - 4097699792 )
sqlccsend( ulBytes - 256 )
sqlccsend( ) rc - 0, time elasped - +3.000000E-006
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 310 ) - rc - 0, time elapsed - +1.394000E-003
[12/01/2010 19:16:13.457768] ( DBMS NAME="DB2/LINUXPPC64", Version="09.07.0003", Fixpack="0x28040107" )
[12/01/2010 19:16:13.457890]
[12/01/2010 19:16:13.457925] ( Application Codepage=1208, Database Codepage=1208, Database XML Codepage=1208, Char Send/Recv Codepage=1208, Graphic Send/Recv Codepage=1200, XML Send/Recv Codepage=1208 )
[12/01/2010 19:16:13.458082]

[12/01/2010 19:16:13.458121] SQLConnect( )
[12/01/2010 19:16:13.458148] <--- SQL_SUCCESS Time elapsed - +7.884630E-001 seconds
[12/01/2010 19:16:13.458180] ( DSN=""GATEWAY"" )
[12/01/2010 19:16:13.458229]
[12/01/2010 19:16:13.458254] ( UID=""db2inst1"" )
[12/01/2010 19:16:13.458303]
[12/01/2010 19:16:13.458330] ( PWD="" )
[12/01/2010 19:16:13.458376]

[12/01/2010 19:16:13.458422] SQLGetInfo( hDbc=0:1, fInfoType=SQL_DBMS_NAME, rgbInfoValue=&10db8a48, cbInfoValueMax=2048, pcbInfoValue=&ff7fa478 )
[12/01/2010 19:16:13.458559] ---> Time elapsed - +2.740000E-004 seconds

[12/01/2010 19:16:13.458592] SQLGetInfo( rgbInfoValue="DB2/LINUXPPC64", pcbInfoValue=14 )
[12/01/2010 19:16:13.458662] <--- SQL_SUCCESS Time elapsed - +2.400000E-004 seconds

[12/01/2010 19:16:13.458695] SQLSetConnectAttr( hDbc=0:1, fOption=SQL_ATTR_REPLACE_QUOTED_LITERALS, pvParam=&00000001, iStrLen=-6 )
[12/01/2010 19:16:13.458806] ---> Time elapsed - +3.300000E-005 seconds

[12/01/2010 19:16:13.458835] SQLSetConnectAttr( )
[12/01/2010 19:16:13.458862] <--- SQL_SUCCESS Time elapsed - +1.670000E-004 seconds

[12/01/2010 19:16:13.458945] SQLGetInfo( hDbc=0:1, fInfoType=SQL_DBMS_NAME, rgbInfoValue=&ff7f8c13, cbInfoValueMax=255, pcbInfoValue=&ff7f8bf8 )
[12/01/2010 19:16:13.459098] ---> Time elapsed - +8.300000E-005 seconds

[12/01/2010 19:16:13.459129] SQLGetInfo( rgbInfoValue="DB2/LINUXPPC64", pcbInfoValue=14 )
[12/01/2010 19:16:13.459197] <--- SQL_SUCCESS Time elapsed - +2.520000E-004 seconds

[12/01/2010 19:16:13.459232] SQLGetInfo( hDbc=0:1, fInfoType=SQL_DBMS_VER, rgbInfoValue=&ff7f8c08, cbInfoValueMax=11, pcbInfoValue=&ff7f8bf8 )
[12/01/2010 19:16:13.459361] ---> Time elapsed - +3.500000E-005 seconds

[12/01/2010 19:16:13.459391] SQLGetInfo( rgbInfoValue="09.07.0003", pcbInfoValue=10 )
[12/01/2010 19:16:13.459460] <--- SQL_SUCCESS Time elapsed - +2.280000E-004 seconds

[12/01/2010 19:16:13.459490] SQLGetInfo( hDbc=0:1, fInfoType=SQL_DATABASE_CODEPAGE, rgbInfoValue=&ff7f8c00, cbInfoValueMax=4, pcbInfoValue=&ff7f8bf8 )
[12/01/2010 19:16:13.459624] ---> Time elapsed - +3.000000E-005 seconds

[12/01/2010 19:16:13.459652] SQLGetInfo( rgbInfoValue=1208, pcbInfoValue=4 )
[12/01/2010 19:16:13.459723] <--- SQL_SUCCESS Time elapsed - +2.330000E-004 seconds

[12/01/2010 19:16:13.459756] SQLGetInfo( hDbc=0:1, fInfoType=SQL_DATABASE_NAME, rgbInfoValue=&ff7f8c13, cbInfoValueMax=255, pcbInfoValue=&ff7f8bf8 )
[12/01/2010 19:16:13.459887] ---> Time elapsed - +3.300000E-005 seconds

[12/01/2010 19:16:13.459917] SQLGetInfo( rgbInfoValue="GATEWAY", pcbInfoValue=7 )
[12/01/2010 19:16:13.459987] <--- SQL_SUCCESS Time elapsed - +2.310000E-004 seconds

[12/01/2010 19:16:13.460018] SQLGetInfo( hDbc=0:1, fInfoType=SQL_SERVER_NAME, rgbInfoValue=&ff7f8c13, cbInfoValueMax=255, pcbInfoValue=&ff7f8bf8 )
[12/01/2010 19:16:13.460149] ---> Time elapsed - +3.100000E-005 seconds

[12/01/2010 19:16:13.460180] SQLGetInfo( rgbInfoValue="db2inst1", pcbInfoValue=8 )
[12/01/2010 19:16:13.460247] <--- SQL_SUCCESS Time elapsed - +2.290000E-004 seconds

[12/01/2010 19:16:13.460279] SQLGetInfo( hDbc=0:1, fInfoType=SQL_SPECIAL_CHARACTERS, rgbInfoValue=&ff7f8c13, cbInfoValueMax=255, pcbInfoValue=&ff7f8bf8 )
[12/01/2010 19:16:13.460408] ---> Time elapsed - +3.200000E-005 seconds

[12/01/2010 19:16:13.460437] SQLGetInfo( rgbInfoValue="@#", pcbInfoValue=2 )
[12/01/2010 19:16:13.460505] <--- SQL_SUCCESS Time elapsed - +2.260000E-004 seconds

[12/01/2010 19:16:13.460538] SQLGetInfo( hDbc=0:1, fInfoType=SQL_KEYWORDS, rgbInfoValue=&ff7f8d12, cbInfoValueMax=3072, pcbInfoValue=&ff7f8bf8 )
[12/01/2010 19:16:13.460669] ---> Time elapsed - +3.300000E-005 seconds

[12/01/2010 19:16:13.460700] SQLGetInfo( rgbInfoValue="AFTER,ALIAS,ALLOW,APPLICATION,ASSOCIATE,ASUTIME,AUDIT,AUX,AUXILIARY,BEFORE,BINARY,BUFFERPOOL,CACHE,CALL,CALLED,CAPTURE,CARDINALITY,CCSID,CLUSTER,COLLECTION,COLLID,COMMENT,CONCAT,CONDITION,CONTAINS,COUNT_BIG,CURRENT_LC_CTYPE,CURRENT_PATH,CURRENT_SERVER,CURRENT_TIMEZONE,CYCLE,DATA,DATABASE,DAYS,DB2GENERAL,DB2GENRL,DB2SQL,DBINFO,DEFAULTS,DEFINITION,DETERMINISTIC,DISALLOW,DO,DSNHATTR,DSSIZE,DYNAMIC,EACH,EDITPROC,ELSEIF,ENCODING,END-EXEC1,ERASE,EXCLUDING,EXIT,FENCED,FIELDPROC,FILE,FINAL,FREE,FUNCTION,GENERAL,GENERATED,GRAPHIC,HANDLER,HOLD,HOURS,IF,INCLUDING,INCREMENT,INHERIT,INOUT,INTEGRITY,ISOBID,ITERATE,JAR,JAVA,LABEL,LC_CTYPE,LEAVE,LINKTYPE,LOCALE,LOCATOR,LOCATORS,LOCK,LOCKMAX,LOCKSIZE,LONG,LOOP,MAXVALUE,MICROSECOND,MICROSECONDS,MINUTES,MINVALUE,MODE,MODIFIES,MONTHS,NEW,NEW_TABLE,NOCACHE,NOCYCLE,NODENAME,NODENUMBER,NOMAXVALUE,NOMINVALUE,NOORDER,NULLS,NUMPARTS,OBID,OLD,OLD_TABLE,OPTIMIZATION,OPTIMIZE,OUT,OVERRIDING,PACKAGE,PARAMETER,PART,PARTITION,PATH,PIECESIZE,PLAN,PRIQTY,PROGRAM,PSID,QUERYNO,READS,RECOVERY,REFERENCING,RELEASE,RENAME,REPEAT,RESET,RESIGNAL,RESTART,RESULT,RESULT_SET_LOCATOR,RETURN,RETURNS,ROUTINE,ROW,RRN,RUN,SAVEPOINT,SCRATCHPAD,SECONDS,SECQTY,SECURITY,SENSITIVE,SIGNAL,SIMPLE,SOURCE,SPECIFIC,SQLID,STANDARD,START,STATIC,STAY,STOGROUP,STORES,STYLE,SUBPAGES,SYNONYM,SYSFUN,SYSIBM,SYSPROC,SYSTEM,TABLESPACE,TRIGGER,TYPE,UNDO,UNTIL,VALIDPROC,VARIABLE,VARIANT,VCAT,VOLUMES,WHILE,WLM,YEARS", pcbInfoValue=1416 )
[12/01/2010 19:16:13.460769] <--- SQL_SUCCESS Time elapsed - +2.310000E-004 seconds

[12/01/2010 19:16:13.461021] SQLGetInfo( hDbc=0:1, fInfoType=SQL_DEFAULT_TXN_ISOLATION, rgbInfoValue=&ff7f8c04, cbInfoValueMax=4, pcbInfoValue=&ff7f8bf8 )
[12/01/2010 19:16:13.461154] ---> Time elapsed - +2.520000E-004 seconds

[12/01/2010 19:16:13.461185] SQLGetInfo( rgbInfoValue=2, pcbInfoValue=4 )
[12/01/2010 19:16:13.461253] <--- SQL_SUCCESS Time elapsed - +2.320000E-004 seconds

[12/01/2010 19:16:13.461283] SQLGetInfo( hDbc=0:1, fInfoType=SQL_TXN_ISOLATION_OPTION, rgbInfoValue=&ff7f8c04, cbInfoValueMax=4, pcbInfoValue=&ff7f8bf8 )
[12/01/2010 19:16:13.461414] ---> Time elapsed - +3.000000E-005 seconds

[12/01/2010 19:16:13.461442] SQLGetInfo( rgbInfoValue=15, pcbInfoValue=4 )
[12/01/2010 19:16:13.461510] <--- SQL_SUCCESS Time elapsed - +2.270000E-004 seconds

[12/01/2010 19:16:13.461545] SQLGetInfo( hDbc=0:1, fInfoType=SQL_ODBC_SQL_CONFORMANCE, rgbInfoValue=&ff7f8c00, cbInfoValueMax=4, pcbInfoValue=&ff7f8bf8 )
[12/01/2010 19:16:13.461676] ---> Time elapsed - +3.500000E-005 seconds

[12/01/2010 19:16:13.461705] SQLGetInfo( rgbInfoValue=2, pcbInfoValue=2 )
[12/01/2010 19:16:13.461771] <--- SQL_SUCCESS Time elapsed - +2.260000E-004 seconds

[12/01/2010 19:16:13.461803] SQLGetInfo( hDbc=0:1, fInfoType=SQL_PROCEDURES, rgbInfoValue=&ff7f8c08, cbInfoValueMax=11, pcbInfoValue=&ff7f8bf8 )
[12/01/2010 19:16:13.461931] ---> Time elapsed - +3.200000E-005 seconds

[12/01/2010 19:16:13.461963] SQLGetInfo( rgbInfoValue="Y", pcbInfoValue=1 )
[12/01/2010 19:16:13.462032] <--- SQL_SUCCESS Time elapsed - +2.290000E-004 seconds

[12/01/2010 19:16:13.462064] SQLGetInfo( hDbc=0:1, fInfoType=SQL_IDENTIFIER_QUOTE_CHAR, rgbInfoValue=&ff7f8c08, cbInfoValueMax=11, pcbInfoValue=&ff7f8bf8 )
[12/01/2010 19:16:13.462192] ---> Time elapsed - +3.200000E-005 seconds

[12/01/2010 19:16:13.462222] SQLGetInfo( rgbInfoValue=""", pcbInfoValue=1 )
[12/01/2010 19:16:13.462289] <--- SQL_SUCCESS Time elapsed - +2.250000E-004 seconds

[12/01/2010 19:16:13.462320] SQLGetInfo( hDbc=0:1, fInfoType=SQL_LIKE_ESCAPE_CLAUSE, rgbInfoValue=&ff7f8c08, cbInfoValueMax=11, pcbInfoValue=&ff7f8bf8 )
[12/01/2010 19:16:13.462450] ---> Time elapsed - +3.100000E-005 seconds

[12/01/2010 19:16:13.462479] SQLGetInfo( rgbInfoValue="Y", pcbInfoValue=1 )
[12/01/2010 19:16:13.462550] <--- SQL_SUCCESS Time elapsed - +2.300000E-004 seconds

[12/01/2010 19:16:13.462580] SQLGetInfo( hDbc=0:1, fInfoType=SQL_MAX_COLUMN_NAME_LEN, rgbInfoValue=&ff7f8bfa, cbInfoValueMax=2, pcbInfoValue=&ff7f8bf8 )
[12/01/2010 19:16:13.462709] ---> Time elapsed - +3.000000E-005 seconds

[12/01/2010 19:16:13.462740] SQLGetInfo( rgbInfoValue=128, pcbInfoValue=2 )
[12/01/2010 19:16:13.462810] <--- SQL_SUCCESS Time elapsed - +2.300000E-004 seconds

[12/01/2010 19:16:13.462841] SQLGetInfo( hDbc=0:1, fInfoType=SQL_MAX_ROW_SIZE, rgbInfoValue=&ff7f8c00, cbInfoValueMax=4, pcbInfoValue=&ff7f8bf8 )
[12/01/2010 19:16:13.462969] ---> Time elapsed - +3.100000E-005 seconds

[12/01/2010 19:16:13.462998] SQLGetInfo( rgbInfoValue=32677, pcbInfoValue=4 )
[12/01/2010 19:16:13.463068] <--- SQL_SUCCESS Time elapsed - +2.270000E-004 seconds

[12/01/2010 19:16:13.463099] SQLGetInfo( hDbc=0:1, fInfoType=SQL_MAX_IDENTIFIER_LEN, rgbInfoValue=&ff7f8bfa, cbInfoValueMax=2, pcbInfoValue=&ff7f8bf8 )
[12/01/2010 19:16:13.463231] ---> Time elapsed - +3.100000E-005 seconds

[12/01/2010 19:16:13.463260] SQLGetInfo( rgbInfoValue=128, pcbInfoValue=2 )
[12/01/2010 19:16:13.463330] <--- SQL_SUCCESS Time elapsed - +2.310000E-004 seconds

[12/01/2010 19:16:13.463361] SQLGetInfo( hDbc=0:1, fInfoType=SQL_MAX_INDEX_SIZE, rgbInfoValue=&ff7f8c00, cbInfoValueMax=4, pcbInfoValue=&ff7f8bf8 )
[12/01/2010 19:16:13.463490] ---> Time elapsed - +3.100000E-005 seconds

[12/01/2010 19:16:13.463520] SQLGetInfo( rgbInfoValue=1024, pcbInfoValue=4 )
[12/01/2010 19:16:13.463600] <--- SQL_SUCCESS Time elapsed - +2.390000E-004 seconds

[12/01/2010 19:16:13.463630] SQLGetInfo( hDbc=0:1, fInfoType=SQL_MAX_PROCEDURE_NAME_LEN, rgbInfoValue=&ff7f8bfa, cbInfoValueMax=2, pcbInfoValue=&ff7f8bf8 )
[12/01/2010 19:16:13.463768] ---> Time elapsed - +3.000000E-005 seconds

[12/01/2010 19:16:13.463798] SQLGetInfo( rgbInfoValue=128, pcbInfoValue=2 )
[12/01/2010 19:16:13.463866] <--- SQL_SUCCESS Time elapsed - +2.360000E-004 seconds

[12/01/2010 19:16:13.463897] SQLGetInfo( hDbc=0:1, fInfoType=SQL_MAX_SCHEMA_NAME_LEN, rgbInfoValue=&ff7f8bfa, cbInfoValueMax=2, pcbInfoValue=&ff7f8bf8 )
[12/01/2010 19:16:13.464029] ---> Time elapsed - +3.100000E-005 seconds

[12/01/2010 19:16:13.464059] SQLGetInfo( rgbInfoValue=128, pcbInfoValue=2 )
[12/01/2010 19:16:13.464130] <--- SQL_SUCCESS Time elapsed - +2.330000E-004 seconds

[12/01/2010 19:16:13.464160] SQLGetInfo( hDbc=0:1, fInfoType=SQL_MAX_STATEMENT_LEN, rgbInfoValue=&ff7f8c00, cbInfoValueMax=4, pcbInfoValue=&ff7f8bf8 )
[12/01/2010 19:16:13.464290] ---> Time elapsed - +3.000000E-005 seconds

[12/01/2010 19:16:13.464319] SQLGetInfo( rgbInfoValue=2097152, pcbInfoValue=4 )
[12/01/2010 19:16:13.464387] <--- SQL_SUCCESS Time elapsed - +2.270000E-004 seconds

[12/01/2010 19:16:13.464419] SQLGetInfo( hDbc=0:1, fInfoType=SQL_MAX_TABLE_NAME_LEN, rgbInfoValue=&ff7f8bfa, cbInfoValueMax=2, pcbInfoValue=&ff7f8bf8 )
[12/01/2010 19:16:13.464550] ---> Time elapsed - +3.200000E-005 seconds

[12/01/2010 19:16:13.464580] SQLGetInfo( rgbInfoValue=128, pcbInfoValue=2 )
[12/01/2010 19:16:13.464650] <--- SQL_SUCCESS Time elapsed - +2.310000E-004 seconds

[12/01/2010 19:16:13.464681] SQLGetInfo( hDbc=0:1, fInfoType=SQL_NON_NULLABLE_COLUMNS, rgbInfoValue=&ff7f8bfa, cbInfoValueMax=2, pcbInfoValue=&ff7f8bf8 )
[12/01/2010 19:16:13.464811] ---> Time elapsed - +3.100000E-005 seconds

[12/01/2010 19:16:13.464839] SQLGetInfo( rgbInfoValue=1, pcbInfoValue=2 )
[12/01/2010 19:16:13.464908] <--- SQL_SUCCESS Time elapsed - +2.270000E-004 seconds

[12/01/2010 19:16:13.464987] SQLGetConnectAttr( hDbc=0:1, fOption=SQL_ATTR_PING_DB, pvParam=&ff7fa55c, cbParamMax=0, pcbParam=<NULL pointer> )
[12/01/2010 19:16:13.465121] ---> Time elapsed - +7.900000E-005 seconds
sqlccsend( Handle - 4097699792 )
sqlccsend( ulBytes - 1092 )
sqlccsend( ) rc - 0, time elasped - +3.000000E-006
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 28 ) - rc - 0, time elapsed - +2.800000E-005

[12/01/2010 19:16:13.465279] SQLGetConnectAttr( pvParam=119 )
[12/01/2010 19:16:13.465328] <--- SQL_SUCCESS Time elapsed - +3.410000E-004 seconds

[12/01/2010 19:16:13.465707] SQLAllocHandle( fHandleType=SQL_HANDLE_STMT, hInput=0:1, phOutput=&10dbf9cc )
[12/01/2010 19:16:13.465808] ---> Time elapsed - +3.790000E-004 seconds

[12/01/2010 19:16:13.465847] SQLAllocHandle( phOutput=1:1 )
[12/01/2010 19:16:13.465894] <--- SQL_SUCCESS Time elapsed - +1.870000E-004 seconds

[12/01/2010 19:16:13.465935] SQLColumns( hStmt=1:1, pszCatalogName=<NULL pointer>, sCatalogNameByteCount=0, pszSchemaName="DB2INST1", sSchemaNameByteCount=8, pszTableName="MODEL_TESTS", sTableNameByteCount=11, pszColumnName=<NULL pointer>, sColumnNameByteCount=0 )
[12/01/2010 19:16:13.466157] ---> Time elapsed - +4.100000E-005 seconds
[12/01/2010 19:16:13.466223] ( StmtOut="CALL SYSIBM.SQLCOLUMNS(?,?,?,?,?)" )
[12/01/2010 19:16:13.466273]
[12/01/2010 19:16:13.466331] ( Package="SYSSH200 ", Section=4 )
[12/01/2010 19:16:13.466407]
sqlccsend( Handle - 4097699792 )
sqlccsend( ulBytes - 365 )
sqlccsend( ) rc - 0, time elasped - +4.000000E-006
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 305 ) - rc - 0, time elapsed - +1.360000E-004
Elapsed Server Processing Time - +1.900000E-005
Elapsed Server Processing Time - +9.200000E-005
Elapsed Server Processing Time - +2.000000E-005
[12/01/2010 19:16:13.466804] ( Row=1, iPar=1, fCType=SQL_C_CHAR, rgbValue=<NULL pointer>, pcbValue=-1, piIndicatorPtr=-1 )
[12/01/2010 19:16:13.466952]
[12/01/2010 19:16:13.466979] ( Row=1, iPar=2, fCType=SQL_C_CHAR, rgbValue="DB2INST1" - x'444232494E535431', pcbValue=8, piIndicatorPtr=8 )
[12/01/2010 19:16:13.467133]
[12/01/2010 19:16:13.467169] ( Row=1, iPar=3, fCType=SQL_C_CHAR, rgbValue="MODEL_TESTS" - x'4D4F44454C5F5445535453', pcbValue=11, piIndicatorPtr=11 )
[12/01/2010 19:16:13.467321]
[12/01/2010 19:16:13.467347] ( Row=1, iPar=4, fCType=SQL_C_CHAR, rgbValue=<NULL pointer>, pcbValue=-1, piIndicatorPtr=-1 )
[12/01/2010 19:16:13.467493]
[12/01/2010 19:16:13.467519] ( Row=1, iPar=5, fCType=SQL_C_CHAR, rgbValue="DATATYPE='ODBC';GRAPHIC=1;REPORTUDTS=0;TYPEMAPPINGS=UDT:LUWUDT,ROWID:VARBINARY;SUPPORTEDNEWTYPES=XML,DECFLOAT;" - x'44415441545950453D274F444243273B475241504849433D313B5245504F5254554454533D303B545950454D415050494E47533D5544543A4C55575544542C524F5749443A56415242494E4152593B535550504F525445444E455754595045533D584D4C2C444543464C4F41543B', pcbValue=110, piIndicatorPtr=110 )
[12/01/2010 19:16:13.467692]
sqlccsend( Handle - 4097699792 )
sqlccsend( ulBytes - 316 )
sqlccsend( ) rc - 0, time elasped - +3.000000E-006
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 1543 ) - rc - 0, time elapsed - +8.365000E-003
Elapsed Server Processing Time - +8.334000E-003
[12/01/2010 19:16:13.476361] ( return=0 )
[12/01/2010 19:16:13.476435]
[12/01/2010 19:16:13.476464] ( Requested Cursor Attributes=x'00000000' )
[12/01/2010 19:16:13.476512]
[12/01/2010 19:16:13.476542] ( Reply Cursor Attributes=x'00000000' )
[12/01/2010 19:16:13.476590]
[12/01/2010 19:16:13.476617] ( Actual Cursor Attributes=x'00000000' )
[12/01/2010 19:16:13.476665]

[12/01/2010 19:16:13.476696] SQLColumns( )
[12/01/2010 19:16:13.476724] <--- SQL_SUCCESS Time elapsed - +1.078900E-002 seconds

[12/01/2010 19:16:13.476809] SQLNumResultCols( hStmt=1:1, pcCol=&10dbfa34 )
[12/01/2010 19:16:13.476879] ---> Time elapsed - +8.500000E-005 seconds

[12/01/2010 19:16:13.476907] SQLNumResultCols( pcCol=18 )
[12/01/2010 19:16:13.476954] <--- SQL_SUCCESS Time elapsed - +1.450000E-004 seconds

[12/01/2010 19:16:13.476998] SQLDescribeCol( hStmt=1:1, sCol=1, pszColName=&ff7feb58, sColNameMaxByteLen=8192, psColNameCharLen=&10dbf75e, psSQLType=&10dbfa44, puiColDef=&10dbfa48, psScale=&10dbfa4c, psNullable=&10dbfa4e )
[12/01/2010 19:16:13.477210] ---> Time elapsed - +4.400000E-005 seconds

[12/01/2010 19:16:13.477241] SQLDescribeCol( pszColName="TABLE_CAT", psColNameCharLen=9, psSQLType=SQL_VARCHAR, pcbColDef=128, psScale=0, psNullable=SQL_NULLABLE )
[12/01/2010 19:16:13.477389] <--- SQL_SUCCESS Time elapsed - +3.910000E-004 seconds

[12/01/2010 19:16:13.477429] SQLDescribeCol( hStmt=1:1, sCol=2, pszColName=&ff7feb58, sColNameMaxByteLen=8192, psColNameCharLen=&10dbf75e, psSQLType=&10dbfa60, puiColDef=&10dbfa64, psScale=&10dbfa68, psNullable=&10dbfa6a )
[12/01/2010 19:16:13.477641] ---> Time elapsed - +4.000000E-005 seconds

[12/01/2010 19:16:13.477669] SQLDescribeCol( pszColName="TABLE_SCHEM", psColNameCharLen=11, psSQLType=SQL_VARCHAR, pcbColDef=128, psScale=0, psNullable=SQL_NO_NULLS )
[12/01/2010 19:16:13.477818] <--- SQL_SUCCESS Time elapsed - +3.890000E-004 seconds

[12/01/2010 19:16:13.477850] SQLDescribeCol( hStmt=1:1, sCol=3, pszColName=&ff7feb58, sColNameMaxByteLen=8192, psColNameCharLen=&10dbf75e, psSQLType=&10dbfa7c, puiColDef=&10dbfa80, psScale=&10dbfa84, psNullable=&10dbfa86 )
[12/01/2010 19:16:13.478073] ---> Time elapsed - +3.200000E-005 seconds

[12/01/2010 19:16:13.478102] SQLDescribeCol( pszColName="TABLE_NAME", psColNameCharLen=10, psSQLType=SQL_VARCHAR, pcbColDef=128, psScale=0, psNullable=SQL_NO_NULLS )
[12/01/2010 19:16:13.478251] <--- SQL_SUCCESS Time elapsed - +4.010000E-004 seconds

[12/01/2010 19:16:13.478281] SQLDescribeCol( hStmt=1:1, sCol=4, pszColName=&ff7feb58, sColNameMaxByteLen=8192, psColNameCharLen=&10dbf75e, psSQLType=&10dbfa98, puiColDef=&10dbfa9c, psScale=&10dbfaa0, psNullable=&10dbfaa2 )
[12/01/2010 19:16:13.478490] ---> Time elapsed - +3.000000E-005 seconds

[12/01/2010 19:16:13.478518] SQLDescribeCol( pszColName="COLUMN_NAME", psColNameCharLen=11, psSQLType=SQL_VARCHAR, pcbColDef=128, psScale=0, psNullable=SQL_NO_NULLS )
[12/01/2010 19:16:13.478670] <--- SQL_SUCCESS Time elapsed - +3.890000E-004 seconds

[12/01/2010 19:16:13.478720] SQLDescribeCol( hStmt=1:1, sCol=5, pszColName=&ff7feb58, sColNameMaxByteLen=8192, psColNameCharLen=&10dbf75e, psSQLType=&10dbfab4, puiColDef=&10dbfab8, psScale=&10dbfabc, psNullable=&10dbfabe )
[12/01/2010 19:16:13.478930] ---> Time elapsed - +5.000000E-005 seconds

[12/01/2010 19:16:13.478959] SQLDescribeCol( pszColName="DATA_TYPE", psColNameCharLen=9, psSQLType=SQL_SMALLINT, pcbColDef=5, psScale=0, psNullable=SQL_NULLABLE )
[12/01/2010 19:16:13.479109] <--- SQL_SUCCESS Time elapsed - +3.890000E-004 seconds

[12/01/2010 19:16:13.479140] SQLDescribeCol( hStmt=1:1, sCol=6, pszColName=&ff7feb58, sColNameMaxByteLen=8192, psColNameCharLen=&10dbf75e, psSQLType=&10dbfad0, puiColDef=&10dbfad4, psScale=&10dbfad8, psNullable=&10dbfada )
[12/01/2010 19:16:13.479351] ---> Time elapsed - +3.100000E-005 seconds

[12/01/2010 19:16:13.479381] SQLDescribeCol( pszColName="TYPE_NAME", psColNameCharLen=9, psSQLType=SQL_VARCHAR, pcbColDef=261, psScale=0, psNullable=SQL_NO_NULLS )
[12/01/2010 19:16:13.479529] <--- SQL_SUCCESS Time elapsed - +3.890000E-004 seconds

[12/01/2010 19:16:13.479561] SQLDescribeCol( hStmt=1:1, sCol=7, pszColName=&ff7feb58, sColNameMaxByteLen=8192, psColNameCharLen=&10dbf75e, psSQLType=&10dbfaec, puiColDef=&10dbfaf0, psScale=&10dbfaf4, psNullable=&10dbfaf6 )
[12/01/2010 19:16:13.479771] ---> Time elapsed - +3.200000E-005 seconds

[12/01/2010 19:16:13.479800] SQLDescribeCol( pszColName="COLUMN_SIZE", psColNameCharLen=11, psSQLType=SQL_INTEGER, pcbColDef=10, psScale=0, psNullable=SQL_NO_NULLS )
[12/01/2010 19:16:13.479948] <--- SQL_SUCCESS Time elapsed - +3.870000E-004 seconds

[12/01/2010 19:16:13.479980] SQLDescribeCol( hStmt=1:1, sCol=8, pszColName=&ff7feb58, sColNameMaxByteLen=8192, psColNameCharLen=&10dbf75e, psSQLType=&10dbfb08, puiColDef=&10dbfb0c, psScale=&10dbfb10, psNullable=&10dbfb12 )
[12/01/2010 19:16:13.480190] ---> Time elapsed - +3.200000E-005 seconds

[12/01/2010 19:16:13.480218] SQLDescribeCol( pszColName="BUFFER_LENGTH", psColNameCharLen=13, psSQLType=SQL_INTEGER, pcbColDef=10, psScale=0, psNullable=SQL_NULLABLE )
[12/01/2010 19:16:13.480365] <--- SQL_SUCCESS Time elapsed - +3.850000E-004 seconds

[12/01/2010 19:16:13.480397] SQLDescribeCol( hStmt=1:1, sCol=9, pszColName=&ff7feb58, sColNameMaxByteLen=8192, psColNameCharLen=&10dbf75e, psSQLType=&10dbfb24, puiColDef=&10dbfb28, psScale=&10dbfb2c, psNullable=&10dbfb2e )
[12/01/2010 19:16:13.480619] ---> Time elapsed - +3.200000E-005 seconds

[12/01/2010 19:16:13.480648] SQLDescribeCol( pszColName="DECIMAL_DIGITS", psColNameCharLen=14, psSQLType=SQL_SMALLINT, pcbColDef=5, psScale=0, psNullable=SQL_NULLABLE )
[12/01/2010 19:16:13.480794] <--- SQL_SUCCESS Time elapsed - +3.970000E-004 seconds

[12/01/2010 19:16:13.480825] SQLDescribeCol( hStmt=1:1, sCol=10, pszColName=&ff7feb58, sColNameMaxByteLen=8192, psColNameCharLen=&10dbf75e, psSQLType=&10dbfb40, puiColDef=&10dbfb44, psScale=&10dbfb48, psNullable=&10dbfb4a )
[12/01/2010 19:16:13.481040] ---> Time elapsed - +3.100000E-005 seconds

[12/01/2010 19:16:13.481069] SQLDescribeCol( pszColName="NUM_PREC_RADIX", psColNameCharLen=14, psSQLType=SQL_SMALLINT, pcbColDef=5, psScale=0, psNullable=SQL_NULLABLE )
[12/01/2010 19:16:13.481216] <--- SQL_SUCCESS Time elapsed - +3.910000E-004 seconds

[12/01/2010 19:16:13.481245] SQLDescribeCol( hStmt=1:1, sCol=11, pszColName=&ff7feb58, sColNameMaxByteLen=8192, psColNameCharLen=&10dbf75e, psSQLType=&10dbfb5c, puiColDef=&10dbfb60, psScale=&10dbfb64, psNullable=&10dbfb66 )
[12/01/2010 19:16:13.481452] ---> Time elapsed - +2.900000E-005 seconds

[12/01/2010 19:16:13.481482] SQLDescribeCol( pszColName="NULLABLE", psColNameCharLen=8, psSQLType=SQL_SMALLINT, pcbColDef=5, psScale=0, psNullable=SQL_NO_NULLS )
[12/01/2010 19:16:13.481632] <--- SQL_SUCCESS Time elapsed - +3.870000E-004 seconds

[12/01/2010 19:16:13.481663] SQLDescribeCol( hStmt=1:1, sCol=12, pszColName=&ff7feb58, sColNameMaxByteLen=8192, psColNameCharLen=&10dbf75e, psSQLType=&10dbfb78, puiColDef=&10dbfb7c, psScale=&10dbfb80, psNullable=&10dbfb82 )
[12/01/2010 19:16:13.481881] ---> Time elapsed - +3.100000E-005 seconds

[12/01/2010 19:16:13.481909] SQLDescribeCol( pszColName="REMARKS", psColNameCharLen=7, psSQLType=SQL_VARCHAR, pcbColDef=254, psScale=0, psNullable=SQL_NULLABLE )
[12/01/2010 19:16:13.482060] <--- SQL_SUCCESS Time elapsed - +3.970000E-004 seconds

[12/01/2010 19:16:13.482091] SQLDescribeCol( hStmt=1:1, sCol=13, pszColName=&ff7feb58, sColNameMaxByteLen=8192, psColNameCharLen=&10dbf75e, psSQLType=&10dbfb94, puiColDef=&10dbfb98, psScale=&10dbfb9c, psNullable=&10dbfb9e )
[12/01/2010 19:16:13.482298] ---> Time elapsed - +3.100000E-005 seconds

[12/01/2010 19:16:13.482327] SQLDescribeCol( pszColName="COLUMN_DEF", psColNameCharLen=10, psSQLType=SQL_VARCHAR, pcbColDef=254, psScale=0, psNullable=SQL_NULLABLE )
[12/01/2010 19:16:13.482476] <--- SQL_SUCCESS Time elapsed - +3.850000E-004 seconds

[12/01/2010 19:16:13.482507] SQLDescribeCol( hStmt=1:1, sCol=14, pszColName=&ff7feb58, sColNameMaxByteLen=8192, psColNameCharLen=&10dbf75e, psSQLType=&10dbfbb0, puiColDef=&10dbfbb4, psScale=&10dbfbb8, psNullable=&10dbfbba )
[12/01/2010 19:16:13.482722] ---> Time elapsed - +3.100000E-005 seconds

[12/01/2010 19:16:13.482750] SQLDescribeCol( pszColName="SQL_DATA_TYPE", psColNameCharLen=13, psSQLType=SQL_SMALLINT, pcbColDef=5, psScale=0, psNullable=SQL_NULLABLE )
[12/01/2010 19:16:13.482899] <--- SQL_SUCCESS Time elapsed - +3.920000E-004 seconds

[12/01/2010 19:16:13.482930] SQLDescribeCol( hStmt=1:1, sCol=15, pszColName=&ff7feb58, sColNameMaxByteLen=8192, psColNameCharLen=&10dbf75e, psSQLType=&10dbfbcc, puiColDef=&10dbfbd0, psScale=&10dbfbd4, psNullable=&10dbfbd6 )
[12/01/2010 19:16:13.483146] ---> Time elapsed - +3.100000E-005 seconds

[12/01/2010 19:16:13.483176] SQLDescribeCol( pszColName="SQL_DATETIME_SUB", psColNameCharLen=16, psSQLType=SQL_SMALLINT, pcbColDef=5, psScale=0, psNullable=SQL_NULLABLE )
[12/01/2010 19:16:13.483325] <--- SQL_SUCCESS Time elapsed - +3.950000E-004 seconds

[12/01/2010 19:16:13.483357] SQLDescribeCol( hStmt=1:1, sCol=16, pszColName=&ff7feb58, sColNameMaxByteLen=8192, psColNameCharLen=&10dbf75e, psSQLType=&10dbfbe8, puiColDef=&10dbfbec, psScale=&10dbfbf0, psNullable=&10dbfbf2 )
[12/01/2010 19:16:13.483570] ---> Time elapsed - +3.200000E-005 seconds

[12/01/2010 19:16:13.483598] SQLDescribeCol( pszColName="CHAR_OCTET_LENGTH", psColNameCharLen=17, psSQLType=SQL_INTEGER, pcbColDef=10, psScale=0, psNullable=SQL_NULLABLE )
[12/01/2010 19:16:13.483746] <--- SQL_SUCCESS Time elapsed - +3.890000E-004 seconds

[12/01/2010 19:16:13.483777] SQLDescribeCol( hStmt=1:1, sCol=17, pszColName=&ff7feb58, sColNameMaxByteLen=8192, psColNameCharLen=&10dbf75e, psSQLType=&10dbfc04, puiColDef=&10dbfc08, psScale=&10dbfc0c, psNullable=&10dbfc0e )
[12/01/2010 19:16:13.483990] ---> Time elapsed - +3.100000E-005 seconds

[12/01/2010 19:16:13.484019] SQLDescribeCol( pszColName="ORDINAL_POSITION", psColNameCharLen=16, psSQLType=SQL_INTEGER, pcbColDef=10, psScale=0, psNullable=SQL_NO_NULLS )
[12/01/2010 19:16:13.484169] <--- SQL_SUCCESS Time elapsed - +3.920000E-004 seconds

[12/01/2010 19:16:13.484199] SQLDescribeCol( hStmt=1:1, sCol=18, pszColName=&ff7feb58, sColNameMaxByteLen=8192, psColNameCharLen=&10dbf75e, psSQLType=&10dbfc20, puiColDef=&10dbfc24, psScale=&10dbfc28, psNullable=&10dbfc2a )
[12/01/2010 19:16:13.484407] ---> Time elapsed - +3.000000E-005 seconds

[12/01/2010 19:16:13.484435] SQLDescribeCol( pszColName="IS_NULLABLE", psColNameCharLen=11, psSQLType=SQL_VARCHAR, pcbColDef=3, psScale=0, psNullable=SQL_NO_NULLS )
[12/01/2010 19:16:13.484588] <--- SQL_SUCCESS Time elapsed - +3.890000E-004 seconds

[12/01/2010 19:16:13.484628] SQLBindCol( hStmt=1:1, iCol=1, fCType=SQL_C_CHAR, rgbValue=&10dbfe28, cbValueMax=129, pcbValue=&10dbfce8 )
[12/01/2010 19:16:13.484778] ---> Time elapsed - +4.000000E-005 seconds

[12/01/2010 19:16:13.484808] SQLBindCol( )
[12/01/2010 19:16:13.484835] <--- SQL_SUCCESS Time elapsed - +2.070000E-004 seconds

[12/01/2010 19:16:13.484872] SQLBindCol( hStmt=1:1, iCol=2, fCType=SQL_C_CHAR, rgbValue=&10dbfeb0, cbValueMax=129, pcbValue=&10dbfcf8 )
[12/01/2010 19:16:13.485021] ---> Time elapsed - +3.700000E-005 seconds

[12/01/2010 19:16:13.485052] SQLBindCol( )
[12/01/2010 19:16:13.485079] <--- SQL_SUCCESS Time elapsed - +2.070000E-004 seconds

[12/01/2010 19:16:13.485109] SQLBindCol( hStmt=1:1, iCol=3, fCType=SQL_C_CHAR, rgbValue=&10dbff38, cbValueMax=129, pcbValue=&10dbfd08 )
[12/01/2010 19:16:13.485257] ---> Time elapsed - +3.000000E-005 seconds

[12/01/2010 19:16:13.485284] SQLBindCol( )
[12/01/2010 19:16:13.485311] <--- SQL_SUCCESS Time elapsed - +2.020000E-004 seconds

[12/01/2010 19:16:13.485342] SQLBindCol( hStmt=1:1, iCol=4, fCType=SQL_C_CHAR, rgbValue=&10dbffc0, cbValueMax=129, pcbValue=&10dbfd18 )
[12/01/2010 19:16:13.485489] ---> Time elapsed - +3.100000E-005 seconds

[12/01/2010 19:16:13.485523] SQLBindCol( )
[12/01/2010 19:16:13.485551] <--- SQL_SUCCESS Time elapsed - +2.090000E-004 seconds

[12/01/2010 19:16:13.485581] SQLBindCol( hStmt=1:1, iCol=5, fCType=SQL_C_DEFAULT, rgbValue=&10dbfd30, cbValueMax=2, pcbValue=&10dbfd28 )
[12/01/2010 19:16:13.485733] ---> Time elapsed - +3.000000E-005 seconds

[12/01/2010 19:16:13.485762] SQLBindCol( )
[12/01/2010 19:16:13.485789] <--- SQL_SUCCESS Time elapsed - +2.080000E-004 seconds

[12/01/2010 19:16:13.485820] SQLBindCol( hStmt=1:1, iCol=6, fCType=SQL_C_CHAR, rgbValue=&10dc0048, cbValueMax=262, pcbValue=&10dbfd38 )
[12/01/2010 19:16:13.485971] ---> Time elapsed - +3.100000E-005 seconds

[12/01/2010 19:16:13.486002] SQLBindCol( )
[12/01/2010 19:16:13.486029] <--- SQL_SUCCESS Time elapsed - +2.090000E-004 seconds

[12/01/2010 19:16:13.486061] SQLBindCol( hStmt=1:1, iCol=7, fCType=SQL_C_DEFAULT, rgbValue=&10dbfd50, cbValueMax=4, pcbValue=&10dbfd48 )
[12/01/2010 19:16:13.486208] ---> Time elapsed - +3.200000E-005 seconds

[12/01/2010 19:16:13.486237] SQLBindCol( )
[12/01/2010 19:16:13.486264] <--- SQL_SUCCESS Time elapsed - +2.030000E-004 seconds

[12/01/2010 19:16:13.486294] SQLBindCol( hStmt=1:1, iCol=8, fCType=SQL_C_DEFAULT, rgbValue=&10dbfd60, cbValueMax=4, pcbValue=&10dbfd58 )
[12/01/2010 19:16:13.486441] ---> Time elapsed - +3.000000E-005 seconds

[12/01/2010 19:16:13.486474] SQLBindCol( )
[12/01/2010 19:16:13.486501] <--- SQL_SUCCESS Time elapsed - +2.070000E-004 seconds

[12/01/2010 19:16:13.486531] SQLBindCol( hStmt=1:1, iCol=9, fCType=SQL_C_DEFAULT, rgbValue=&10dbfd70, cbValueMax=2, pcbValue=&10dbfd68 )
[12/01/2010 19:16:13.486688] ---> Time elapsed - +3.000000E-005 seconds

[12/01/2010 19:16:13.486717] SQLBindCol( )
[12/01/2010 19:16:13.486743] <--- SQL_SUCCESS Time elapsed - +2.120000E-004 seconds

[12/01/2010 19:16:13.486773] SQLBindCol( hStmt=1:1, iCol=10, fCType=SQL_C_DEFAULT, rgbValue=&10dbfd80, cbValueMax=2, pcbValue=&10dbfd78 )
[12/01/2010 19:16:13.486921] ---> Time elapsed - +3.000000E-005 seconds

[12/01/2010 19:16:13.486951] SQLBindCol( )
[12/01/2010 19:16:13.486978] <--- SQL_SUCCESS Time elapsed - +2.050000E-004 seconds

[12/01/2010 19:16:13.487010] SQLBindCol( hStmt=1:1, iCol=11, fCType=SQL_C_DEFAULT, rgbValue=&10dbfd90, cbValueMax=2, pcbValue=&10dbfd88 )
[12/01/2010 19:16:13.487162] ---> Time elapsed - +3.200000E-005 seconds

[12/01/2010 19:16:13.487191] SQLBindCol( )
[12/01/2010 19:16:13.487217] <--- SQL_SUCCESS Time elapsed - +2.070000E-004 seconds

[12/01/2010 19:16:13.487247] SQLBindCol( hStmt=1:1, iCol=12, fCType=SQL_C_CHAR, rgbValue=&10dc0158, cbValueMax=255, pcbValue=&10dbfd98 )
[12/01/2010 19:16:13.487395] ---> Time elapsed - +3.000000E-005 seconds

[12/01/2010 19:16:13.487425] SQLBindCol( )
[12/01/2010 19:16:13.487453] <--- SQL_SUCCESS Time elapsed - +2.060000E-004 seconds

[12/01/2010 19:16:13.487483] SQLBindCol( hStmt=1:1, iCol=13, fCType=SQL_C_CHAR, rgbValue=&10dc0260, cbValueMax=255, pcbValue=&10dbfda8 )
[12/01/2010 19:16:13.487633] ---> Time elapsed - +3.000000E-005 seconds

[12/01/2010 19:16:13.487662] SQLBindCol( )
[12/01/2010 19:16:13.487697] <--- SQL_SUCCESS Time elapsed - +2.140000E-004 seconds

[12/01/2010 19:16:13.487728] SQLBindCol( hStmt=1:1, iCol=14, fCType=SQL_C_DEFAULT, rgbValue=&10dbfdc0, cbValueMax=2, pcbValue=&10dbfdb8 )
[12/01/2010 19:16:13.487877] ---> Time elapsed - +3.100000E-005 seconds

[12/01/2010 19:16:13.487906] SQLBindCol( )
[12/01/2010 19:16:13.487936] <--- SQL_SUCCESS Time elapsed - +2.080000E-004 seconds

[12/01/2010 19:16:13.487965] SQLBindCol( hStmt=1:1, iCol=15, fCType=SQL_C_DEFAULT, rgbValue=&10dbfdd0, cbValueMax=2, pcbValue=&10dbfdc8 )
[12/01/2010 19:16:13.488117] ---> Time elapsed - +2.900000E-005 seconds

[12/01/2010 19:16:13.488146] SQLBindCol( )
[12/01/2010 19:16:13.488173] <--- SQL_SUCCESS Time elapsed - +2.080000E-004 seconds

[12/01/2010 19:16:13.488203] SQLBindCol( hStmt=1:1, iCol=16, fCType=SQL_C_DEFAULT, rgbValue=&10dbfde0, cbValueMax=4, pcbValue=&10dbfdd8 )
[12/01/2010 19:16:13.488349] ---> Time elapsed - +3.000000E-005 seconds

[12/01/2010 19:16:13.488381] SQLBindCol( )
[12/01/2010 19:16:13.488408] <--- SQL_SUCCESS Time elapsed - +2.050000E-004 seconds

[12/01/2010 19:16:13.488439] SQLBindCol( hStmt=1:1, iCol=17, fCType=SQL_C_DEFAULT, rgbValue=&10dbfdf0, cbValueMax=4, pcbValue=&10dbfde8 )
[12/01/2010 19:16:13.488592] ---> Time elapsed - +3.100000E-005 seconds

[12/01/2010 19:16:13.488619] SQLBindCol( )
[12/01/2010 19:16:13.488646] <--- SQL_SUCCESS Time elapsed - +2.070000E-004 seconds

[12/01/2010 19:16:13.488677] SQLBindCol( hStmt=1:1, iCol=18, fCType=SQL_C_CHAR, rgbValue=&10dbfa30, cbValueMax=4, pcbValue=&10dbfdf8 )
[12/01/2010 19:16:13.488828] ---> Time elapsed - +3.100000E-005 seconds

[12/01/2010 19:16:13.488857] SQLBindCol( )
[12/01/2010 19:16:13.488883] <--- SQL_SUCCESS Time elapsed - +2.060000E-004 seconds

[12/01/2010 19:16:13.488923] SQLFetch( hStmt=1:1 )
[12/01/2010 19:16:13.488970] ---> Time elapsed - +4.000000E-005 seconds
[12/01/2010 19:16:13.489021] ( iRow=1, iCol=1, fCType=SQL_C_CHAR, rgbValue=<NULL data>, pcbValue=-1 )
[12/01/2010 19:16:13.489151]
[12/01/2010 19:16:13.489177] ( iRow=1, iCol=2, fCType=SQL_C_CHAR, rgbValue="DB2INST1" - x'444232494E535431', pcbValue=8 )
[12/01/2010 19:16:13.489307]
[12/01/2010 19:16:13.489334] ( iRow=1, iCol=3, fCType=SQL_C_CHAR, rgbValue="MODEL_TESTS" - x'4D4F44454C5F5445535453', pcbValue=11 )
[12/01/2010 19:16:13.489464]
[12/01/2010 19:16:13.489491] ( iRow=1, iCol=4, fCType=SQL_C_CHAR, rgbValue="ID" - x'4944', pcbValue=2 )
[12/01/2010 19:16:13.489624]
[12/01/2010 19:16:13.489649] ( iRow=1, iCol=5, fCType=SQL_C_DEFAULT, rgbValue=x'0004', pcbValue=2 )
[12/01/2010 19:16:13.489780]
[12/01/2010 19:16:13.489808] ( iRow=1, iCol=6, fCType=SQL_C_CHAR, rgbValue="INTEGER" - x'494E5445474552', pcbValue=7 )
[12/01/2010 19:16:13.489937]
[12/01/2010 19:16:13.489964] ( iRow=1, iCol=7, fCType=SQL_C_DEFAULT, rgbValue=x'0000000A', pcbValue=4 )
[12/01/2010 19:16:13.490096]
[12/01/2010 19:16:13.490122] ( iRow=1, iCol=8, fCType=SQL_C_DEFAULT, rgbValue=x'00000004', pcbValue=4 )
[12/01/2010 19:16:13.490250]
[12/01/2010 19:16:13.490277] ( iRow=1, iCol=9, fCType=SQL_C_DEFAULT, rgbValue=x'0000', pcbValue=2 )
[12/01/2010 19:16:13.490405]
[12/01/2010 19:16:13.490431] ( iRow=1, iCol=10, fCType=SQL_C_DEFAULT, rgbValue=x'000A', pcbValue=2 )
[12/01/2010 19:16:13.490562]
[12/01/2010 19:16:13.490589] ( iRow=1, iCol=11, fCType=SQL_C_DEFAULT, rgbValue=x'0000', pcbValue=2 )
[12/01/2010 19:16:13.490717]
[12/01/2010 19:16:13.490743] ( iRow=1, iCol=12, fCType=SQL_C_CHAR, rgbValue=<NULL data>, pcbValue=-1 )
[12/01/2010 19:16:13.490871]
[12/01/2010 19:16:13.490898] ( iRow=1, iCol=13, fCType=SQL_C_CHAR, rgbValue=<NULL data>, pcbValue=-1 )
[12/01/2010 19:16:13.491027]
[12/01/2010 19:16:13.491056] ( iRow=1, iCol=14, fCType=SQL_C_DEFAULT, rgbValue=x'0004', pcbValue=2 )
[12/01/2010 19:16:13.491187]
[12/01/2010 19:16:13.491214] ( iRow=1, iCol=15, fCType=SQL_C_DEFAULT, rgbValue=<NULL data>, pcbValue=-1 )
[12/01/2010 19:16:13.491342]
[12/01/2010 19:16:13.491369] ( iRow=1, iCol=16, fCType=SQL_C_DEFAULT, rgbValue=<NULL data>, pcbValue=-1 )
[12/01/2010 19:16:13.491504]
[12/01/2010 19:16:13.491530] ( iRow=1, iCol=17, fCType=SQL_C_DEFAULT, rgbValue=x'00000001', pcbValue=4 )
[12/01/2010 19:16:13.491662]
[12/01/2010 19:16:13.491689] ( iRow=1, iCol=18, fCType=SQL_C_CHAR, rgbValue="NO" - x'4E4F', pcbValue=2 )
[12/01/2010 19:16:13.491819]

[12/01/2010 19:16:13.491846] SQLFetch( )
[12/01/2010 19:16:13.491872] <--- SQL_SUCCESS Time elapsed - +2.949000E-003 seconds

[12/01/2010 19:16:13.492010] SQLFetch( hStmt=1:1 )
[12/01/2010 19:16:13.492063] ---> Time elapsed - +1.380000E-004 seconds
[12/01/2010 19:16:13.492094] ( iRow=1, iCol=1, fCType=SQL_C_CHAR, rgbValue=<NULL data>, pcbValue=-1 )
[12/01/2010 19:16:13.492223]
[12/01/2010 19:16:13.492251] ( iRow=1, iCol=2, fCType=SQL_C_CHAR, rgbValue="DB2INST1" - x'444232494E535431', pcbValue=8 )
[12/01/2010 19:16:13.492381]
[12/01/2010 19:16:13.492408] ( iRow=1, iCol=3, fCType=SQL_C_CHAR, rgbValue="MODEL_TESTS" - x'4D4F44454C5F5445535453', pcbValue=11 )
[12/01/2010 19:16:13.492544]
[12/01/2010 19:16:13.492570] ( iRow=1, iCol=4, fCType=SQL_C_CHAR, rgbValue="NAME" - x'4E414D45', pcbValue=4 )
[12/01/2010 19:16:13.492700]
[12/01/2010 19:16:13.492727] ( iRow=1, iCol=5, fCType=SQL_C_DEFAULT, rgbValue=x'000C', pcbValue=2 )
[12/01/2010 19:16:13.492857]
[12/01/2010 19:16:13.492883] ( iRow=1, iCol=6, fCType=SQL_C_CHAR, rgbValue="VARCHAR" - x'56415243484152', pcbValue=7 )
[12/01/2010 19:16:13.493016]
[12/01/2010 19:16:13.493043] ( iRow=1, iCol=7, fCType=SQL_C_DEFAULT, rgbValue=x'000000FF', pcbValue=4 )
[12/01/2010 19:16:13.493173]
[12/01/2010 19:16:13.493201] ( iRow=1, iCol=8, fCType=SQL_C_DEFAULT, rgbValue=x'000000FF', pcbValue=4 )
[12/01/2010 19:16:13.493329]
[12/01/2010 19:16:13.493354] ( iRow=1, iCol=9, fCType=SQL_C_DEFAULT, rgbValue=<NULL data>, pcbValue=-1 )
[12/01/2010 19:16:13.493482]
[12/01/2010 19:16:13.493508] ( iRow=1, iCol=10, fCType=SQL_C_DEFAULT, rgbValue=<NULL data>, pcbValue=-1 )
[12/01/2010 19:16:13.493638]
[12/01/2010 19:16:13.493665] ( iRow=1, iCol=11, fCType=SQL_C_DEFAULT, rgbValue=x'0001', pcbValue=2 )
[12/01/2010 19:16:13.493793]
[12/01/2010 19:16:13.493821] ( iRow=1, iCol=12, fCType=SQL_C_CHAR, rgbValue=<NULL data>, pcbValue=-1 )
[12/01/2010 19:16:13.493947]
[12/01/2010 19:16:13.493973] ( iRow=1, iCol=13, fCType=SQL_C_CHAR, rgbValue=<NULL data>, pcbValue=-1 )
[12/01/2010 19:16:13.494104]
[12/01/2010 19:16:13.494130] ( iRow=1, iCol=14, fCType=SQL_C_DEFAULT, rgbValue=x'000C', pcbValue=2 )
[12/01/2010 19:16:13.494257]
[12/01/2010 19:16:13.494284] ( iRow=1, iCol=15, fCType=SQL_C_DEFAULT, rgbValue=<NULL data>, pcbValue=-1 )
[12/01/2010 19:16:13.494412]
[12/01/2010 19:16:13.494438] ( iRow=1, iCol=16, fCType=SQL_C_DEFAULT, rgbValue=x'000000FF', pcbValue=4 )
[12/01/2010 19:16:13.494568]
[12/01/2010 19:16:13.494595] ( iRow=1, iCol=17, fCType=SQL_C_DEFAULT, rgbValue=x'00000002', pcbValue=4 )
[12/01/2010 19:16:13.494726]
[12/01/2010 19:16:13.494752] ( iRow=1, iCol=18, fCType=SQL_C_CHAR, rgbValue="YES" - x'594553', pcbValue=3 )
[12/01/2010 19:16:13.494883]

[12/01/2010 19:16:13.494910] SQLFetch( )
[12/01/2010 19:16:13.494935] <--- SQL_SUCCESS Time elapsed - +2.925000E-003 seconds

[12/01/2010 19:16:13.495029] SQLFetch( hStmt=1:1 )
[12/01/2010 19:16:13.495080] ---> Time elapsed - +9.400000E-005 seconds
[12/01/2010 19:16:13.495112] ( iRow=1, iCol=1, fCType=SQL_C_CHAR, rgbValue=<NULL data>, pcbValue=-1 )
[12/01/2010 19:16:13.495240]
[12/01/2010 19:16:13.495265] ( iRow=1, iCol=2, fCType=SQL_C_CHAR, rgbValue="DB2INST1" - x'444232494E535431', pcbValue=8 )
[12/01/2010 19:16:13.495397]
[12/01/2010 19:16:13.495423] ( iRow=1, iCol=3, fCType=SQL_C_CHAR, rgbValue="MODEL_TESTS" - x'4D4F44454C5F5445535453', pcbValue=11 )
[12/01/2010 19:16:13.495567]
[12/01/2010 19:16:13.495594] ( iRow=1, iCol=4, fCType=SQL_C_CHAR, rgbValue="DATA" - x'44415441', pcbValue=4 )
[12/01/2010 19:16:13.495720]
[12/01/2010 19:16:13.495747] ( iRow=1, iCol=5, fCType=SQL_C_DEFAULT, rgbValue=x'FF9E', pcbValue=2 )
[12/01/2010 19:16:13.495873]
[12/01/2010 19:16:13.495900] ( iRow=1, iCol=6, fCType=SQL_C_CHAR, rgbValue="BLOB" - x'424C4F42', pcbValue=4 )
[12/01/2010 19:16:13.496034]
[12/01/2010 19:16:13.496064] ( iRow=1, iCol=7, fCType=SQL_C_DEFAULT, rgbValue=x'00100000', pcbValue=4 )
[12/01/2010 19:16:13.496191]
[12/01/2010 19:16:13.496217] ( iRow=1, iCol=8, fCType=SQL_C_DEFAULT, rgbValue=x'00100000', pcbValue=4 )
[12/01/2010 19:16:13.496343]
[12/01/2010 19:16:13.496369] ( iRow=1, iCol=9, fCType=SQL_C_DEFAULT, rgbValue=<NULL data>, pcbValue=-1 )
[12/01/2010 19:16:13.496494]
[12/01/2010 19:16:13.496520] ( iRow=1, iCol=10, fCType=SQL_C_DEFAULT, rgbValue=<NULL data>, pcbValue=-1 )
[12/01/2010 19:16:13.496657]
[12/01/2010 19:16:13.496683] ( iRow=1, iCol=11, fCType=SQL_C_DEFAULT, rgbValue=x'0001', pcbValue=2 )
[12/01/2010 19:16:13.496809]
[12/01/2010 19:16:13.496834] ( iRow=1, iCol=12, fCType=SQL_C_CHAR, rgbValue=<NULL data>, pcbValue=-1 )
[12/01/2010 19:16:13.496959]
[12/01/2010 19:16:13.496985] ( iRow=1, iCol=13, fCType=SQL_C_CHAR, rgbValue=<NULL data>, pcbValue=-1 )
[12/01/2010 19:16:13.497113]
[12/01/2010 19:16:13.497139] ( iRow=1, iCol=14, fCType=SQL_C_DEFAULT, rgbValue=x'FF9E', pcbValue=2 )
[12/01/2010 19:16:13.497265]
[12/01/2010 19:16:13.497291] ( iRow=1, iCol=15, fCType=SQL_C_DEFAULT, rgbValue=<NULL data>, pcbValue=-1 )
[12/01/2010 19:16:13.497417]
[12/01/2010 19:16:13.497443] ( iRow=1, iCol=16, fCType=SQL_C_DEFAULT, rgbValue=x'00100000', pcbValue=4 )
[12/01/2010 19:16:13.497574]
[12/01/2010 19:16:13.497600] ( iRow=1, iCol=17, fCType=SQL_C_DEFAULT, rgbValue=x'00000003', pcbValue=4 )
[12/01/2010 19:16:13.497728]
[12/01/2010 19:16:13.497754] ( iRow=1, iCol=18, fCType=SQL_C_CHAR, rgbValue="YES" - x'594553', pcbValue=3 )
[12/01/2010 19:16:13.497880]

[12/01/2010 19:16:13.497907] SQLFetch( )
[12/01/2010 19:16:13.497936] <--- SQL_SUCCESS Time elapsed - +2.907000E-003 seconds

[12/01/2010 19:16:13.498018] SQLFetch( hStmt=1:1 )
[12/01/2010 19:16:13.498070] ---> Time elapsed - +8.200000E-005 seconds

[12/01/2010 19:16:13.498103] SQLFetch( )
[12/01/2010 19:16:13.498129] <--- SQL_NO_DATA_FOUND Time elapsed - +1.110000E-004 seconds

[12/01/2010 19:16:13.498171] SQLFreeHandle( fHandleType=SQL_HANDLE_STMT, hHandle=1:1 )
[12/01/2010 19:16:13.498241] ---> Time elapsed - +4.200000E-005 seconds
sqlccsend( Handle - 4097699792 )
sqlccsend( ulBytes - 113 )
sqlccsend( ) rc - 0, time elasped - +6.000000E-006
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 92 ) - rc - 0, time elapsed - +1.180000E-004
Elapsed Server Processing Time - +7.400000E-005
[12/01/2010 19:16:13.498515] ( COMMIT REPLY RECEIVED=1 )
[12/01/2010 19:16:13.498578]
[12/01/2010 19:16:13.498615] ( Caching Statement Structure=1 )
[12/01/2010 19:16:13.498662]

[12/01/2010 19:16:13.498688] SQLFreeHandle( )
[12/01/2010 19:16:13.498715] <--- SQL_SUCCESS Time elapsed - +5.440000E-004 seconds

[12/01/2010 19:16:20.971646] SQLSetConnectAttr( hDbc=0:1, fOption=SQL_ATTR_AUTOCOMMIT, pvParam=<NULL pointer>, iStrLen=-6 )
[12/01/2010 19:16:20.971876] ---> Time elapsed - +7.472931E+000 seconds

[12/01/2010 19:16:20.971916] SQLSetConnectAttr( )
[12/01/2010 19:16:20.971942] <--- SQL_SUCCESS Time elapsed - +2.960000E-004 seconds

[12/01/2010 19:16:20.972627] SQLAllocHandle( fHandleType=SQL_HANDLE_STMT, hInput=0:1, phOutput=&10dce88c )
[12/01/2010 19:16:20.972723] ---> Time elapsed - +6.850000E-004 seconds
[12/01/2010 19:16:20.972753] ( Re-using Cached Statement Structure=1 )
[12/01/2010 19:16:20.972801]

[12/01/2010 19:16:20.972835] SQLAllocHandle( phOutput=1:1 )
[12/01/2010 19:16:20.972883] <--- SQL_SUCCESS Time elapsed - +2.560000E-004 seconds

[12/01/2010 19:16:20.972937] SQLExecDirect( hStmt=1:1 )
[12/01/2010 19:16:20.972985] ---> Time elapsed - +5.400000E-005 seconds
[12/01/2010 19:16:20.973015] ( pszSqlStr="INSERT INTO model_tests (name, data) VALUES(NULL, BLOB('?'))", cbSqlStr=60 )
[12/01/2010 19:16:20.973086]
[12/01/2010 19:16:20.973141] ( StmtOut="INSERT INTO model_tests (name, data) VALUES(NULL, BLOB('?'))" )
[12/01/2010 19:16:20.973189]
[12/01/2010 19:16:20.973222] ( Package="SYSSH200 ", Section=65 )
[12/01/2010 19:16:20.973317]
sqlccsend( Handle - 4097699792 )
sqlccsend( ulBytes - 167 )
sqlccsend( ) rc - 0, time elasped - +9.000000E-006
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 149 ) - rc - 0, time elapsed - +2.740000E-004
Elapsed Server Processing Time - +2.520000E-004

[12/01/2010 19:16:20.973750] SQLExecDirect( )
[12/01/2010 19:16:20.973777] <--- SQL_SUCCESS Time elapsed - +8.400000E-004 seconds

[12/01/2010 19:16:20.973903] SQLAllocHandle( fHandleType=SQL_HANDLE_STMT, hInput=0:1, phOutput=&10dced34 )
[12/01/2010 19:16:20.973995] ---> Time elapsed - +1.260000E-004 seconds

[12/01/2010 19:16:20.974028] SQLAllocHandle( phOutput=1:2 )
[12/01/2010 19:16:20.974078] <--- SQL_SUCCESS Time elapsed - +1.750000E-004 seconds

[12/01/2010 19:16:20.974118] SQLPrepare( hStmt=1:2 )
[12/01/2010 19:16:20.974165] ---> Time elapsed - +4.000000E-005 seconds
[12/01/2010 19:16:20.974194] ( pszSqlStr="SELECT IDENTITY_VAL_LOCAL() FROM SYSIBM.SYSDUMMY1", cbSqlStr=49 )
[12/01/2010 19:16:20.974264]
[12/01/2010 19:16:20.974324] ( StmtOut="SELECT IDENTITY_VAL_LOCAL() FROM SYSIBM.SYSDUMMY1" )
[12/01/2010 19:16:20.974371]
[12/01/2010 19:16:20.974403] ( Package="SYSSH200 ", Section=4 )
[12/01/2010 19:16:20.974472]
sqlccsend( Handle - 4097699792 )
sqlccsend( ulBytes - 182 )
sqlccsend( ) rc - 0, time elasped - +3.000000E-006
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 156 ) - rc - 0, time elapsed - +4.800000E-005
Elapsed Server Processing Time - +5.500000E-005

[12/01/2010 19:16:20.974670] SQLPrepare( )
[12/01/2010 19:16:20.974698] <--- SQL_SUCCESS Time elapsed - +5.800000E-004 seconds

[12/01/2010 19:16:20.974742] SQLFreeStmt( hStmt=1:2, fOption=SQL_CLOSE )
[12/01/2010 19:16:20.974814] ---> Time elapsed - +4.400000E-005 seconds

[12/01/2010 19:16:20.974845] SQLFreeStmt( )
[12/01/2010 19:16:20.974872] <--- SQL_SUCCESS Time elapsed - +1.300000E-004 seconds

[12/01/2010 19:16:20.974910] SQLNumParams( hStmt=1:2, pcPar=&10dced84 )
[12/01/2010 19:16:20.974978] ---> Time elapsed - +3.800000E-005 seconds

[12/01/2010 19:16:20.975008] SQLNumParams( pcPar=0 )
[12/01/2010 19:16:20.975058] <--- SQL_SUCCESS Time elapsed - +1.480000E-004 seconds

[12/01/2010 19:16:20.975094] SQLExecute( hStmt=1:2 )
[12/01/2010 19:16:20.975142] ---> Time elapsed - +3.600000E-005 seconds
sqlccsend( Handle - 4097699792 )
sqlccsend( ulBytes - 122 )
sqlccsend( ) rc - 0, time elasped - +2.000000E-006
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 258 ) - rc - 0, time elapsed - +6.000000E-005
Elapsed Server Processing Time - +6.400000E-005
[12/01/2010 19:16:20.975357] ( Requested Cursor Attributes=x'00000000' )
[12/01/2010 19:16:20.975406]
[12/01/2010 19:16:20.975433] ( Reply Cursor Attributes=x'00000000' )
[12/01/2010 19:16:20.975481]
[12/01/2010 19:16:20.975508] ( Actual Cursor Attributes=x'00000000' )
[12/01/2010 19:16:20.975558]

[12/01/2010 19:16:20.975588] SQLExecute( )
[12/01/2010 19:16:20.975615] <--- SQL_SUCCESS Time elapsed - +5.210000E-004 seconds

[12/01/2010 19:16:20.975650] SQLNumResultCols( hStmt=1:2, pcCol=&10dced84 )
[12/01/2010 19:16:20.975719] ---> Time elapsed - +3.500000E-005 seconds

[12/01/2010 19:16:20.975749] SQLNumResultCols( pcCol=1 )
[12/01/2010 19:16:20.975797] <--- SQL_SUCCESS Time elapsed - +1.470000E-004 seconds

[12/01/2010 19:16:20.975830] SQLDescribeCol( hStmt=1:2, sCol=1, pszColName=&ff7f7888, sColNameMaxByteLen=8192, psColNameCharLen=&10dced96, psSQLType=&10dcdaa4, puiColDef=&10dcdaa8, psScale=&10dcdaac, psNullable=&10dcdaae )
[12/01/2010 19:16:20.976045] ---> Time elapsed - +3.300000E-005 seconds

[12/01/2010 19:16:20.976078] SQLDescribeCol( pszColName="1", psColNameCharLen=1, psSQLType=SQL_DECIMAL, pcbColDef=31, psScale=0, psNullable=SQL_NULLABLE )
[12/01/2010 19:16:20.976228] <--- SQL_SUCCESS Time elapsed - +3.980000E-004 seconds

[12/01/2010 19:16:20.976263] SQLFetch( hStmt=1:2 )
[12/01/2010 19:16:20.976309] ---> Time elapsed - +3.500000E-005 seconds

[12/01/2010 19:16:20.976372] SQLFetch( )
[12/01/2010 19:16:20.976400] <--- SQL_SUCCESS Time elapsed - +1.370000E-004 seconds

[12/01/2010 19:16:20.976446] SQLGetData( hStmt=1:2, iCol=1, fCType=SQL_C_CHAR, rgbValue=&10dcedb0, cbValueMax=34, pcbValue=&ff7f98a4 )
[12/01/2010 19:16:20.976606] ---> Time elapsed - +4.600000E-005 seconds

[12/01/2010 19:16:20.976661] SQLGetData( rgbValue="6" - x'36', pcbValue=1 )
[12/01/2010 19:16:20.976737] <--- SQL_SUCCESS Time elapsed - +2.910000E-004 seconds

[12/01/2010 19:16:20.976772] SQLFreeHandle( fHandleType=SQL_HANDLE_STMT, hHandle=1:2 )
[12/01/2010 19:16:20.976840] ---> Time elapsed - +3.500000E-005 seconds
[12/01/2010 19:16:20.976875] ( Caching Statement Structure=1 )
[12/01/2010 19:16:20.976922]

[12/01/2010 19:16:20.976952] SQLFreeHandle( )
[12/01/2010 19:16:20.976978] <--- SQL_SUCCESS Time elapsed - +2.060000E-004 seconds

[12/01/2010 19:16:20.977012] SQLFreeHandle( fHandleType=SQL_HANDLE_STMT, hHandle=1:1 )
[12/01/2010 19:16:20.977084] ---> Time elapsed - +3.400000E-005 seconds

[12/01/2010 19:16:20.977121] SQLFreeHandle( )
[12/01/2010 19:16:20.977148] <--- SQL_SUCCESS Time elapsed - +1.360000E-004 seconds

[12/01/2010 19:16:20.977427] SQLAllocHandle( fHandleType=SQL_HANDLE_STMT, hInput=0:1, phOutput=&10dd011c )
[12/01/2010 19:16:20.977526] ---> Time elapsed - +2.790000E-004 seconds
[12/01/2010 19:16:20.977558] ( Re-using Cached Statement Structure=1 )
[12/01/2010 19:16:20.977604]

[12/01/2010 19:16:20.977632] SQLAllocHandle( phOutput=1:2 )
[12/01/2010 19:16:20.977679] <--- SQL_SUCCESS Time elapsed - +2.520000E-004 seconds

[12/01/2010 19:16:20.977709] SQLPrepare( hStmt=1:2 )
[12/01/2010 19:16:20.977759] ---> Time elapsed - +3.000000E-005 seconds
[12/01/2010 19:16:20.977787] ( pszSqlStr="UPDATE model_tests SET (data) = (?) WHERE id = ?", cbSqlStr=48 )
[12/01/2010 19:16:20.977856]
[12/01/2010 19:16:20.977901] ( StmtOut="UPDATE model_tests SET (data) = (?) WHERE id = ?" )
[12/01/2010 19:16:20.977955]
[12/01/2010 19:16:20.977986] ( Package="SYSSH200 ", Section=4 )
[12/01/2010 19:16:20.978056]
sqlccsend( Handle - 4097699792 )
sqlccsend( ulBytes - 241 )
sqlccsend( ) rc - 0, time elasped - +4.000000E-006
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 197 ) - rc - 0, time elapsed - +4.000000E-005
Elapsed Server Processing Time - +3.300000E-005
Elapsed Server Processing Time - +7.000000E-006

[12/01/2010 19:16:20.978264] SQLPrepare( )
[12/01/2010 19:16:20.978292] <--- SQL_SUCCESS Time elapsed - +5.830000E-004 seconds

[12/01/2010 19:16:20.978411] SQLFreeStmt( hStmt=1:2, fOption=SQL_CLOSE )
[12/01/2010 19:16:20.978482] ---> Time elapsed - +1.190000E-004 seconds

[12/01/2010 19:16:20.978511] SQLFreeStmt( )
[12/01/2010 19:16:20.978549] <--- SQL_SUCCESS Time elapsed - +1.380000E-004 seconds

[12/01/2010 19:16:20.978582] SQLNumParams( hStmt=1:2, pcPar=&10dd190c )
[12/01/2010 19:16:20.978650] ---> Time elapsed - +3.300000E-005 seconds

[12/01/2010 19:16:20.978677] SQLNumParams( pcPar=2 )
[12/01/2010 19:16:20.978725] <--- SQL_SUCCESS Time elapsed - +1.430000E-004 seconds

[12/01/2010 19:16:20.978772] SQLDescribeParam( hStmt=1:2, usPar=1, psSQLType=&10dd1bae, puiParamDef=&10dd1bb0, psScale=&10dd1bb4, psNullable=&10dd1bb6 )
[12/01/2010 19:16:20.978920] ---> Time elapsed - +4.700000E-005 seconds

[12/01/2010 19:16:20.978951] SQLDescribeParam( psSQLType=SQL_BLOB, puiParamDef=1048576, psScale=0, psNullable=SQL_NULLABLE_UNKNOWN )
[12/01/2010 19:16:20.979062] <--- SQL_SUCCESS Time elapsed - +2.900000E-004 seconds

[12/01/2010 19:16:20.979104] SQLBindParameter( hStmt=1:2, iPar=1, fParamType=SQL_PARAM_INPUT, fCType=SQL_C_BINARY, fSQLType=SQL_BLOB, cbColDef=1048576, ibScale=0, rgbValue=&10dd1bc0, cbValueMax=0, pcbValue=&10dd1bd0 )
[12/01/2010 19:16:20.979331] ---> Time elapsed - +4.200000E-005 seconds

[12/01/2010 19:16:20.979366] SQLBindParameter( )
[12/01/2010 19:16:20.979393] <--- SQL_SUCCESS Time elapsed - +2.890000E-004 seconds

[12/01/2010 19:16:20.979433] SQLDescribeParam( hStmt=1:2, usPar=2, psSQLType=&10dd1bae, puiParamDef=&10dd1bb0, psScale=&10dd1bb4, psNullable=&10dd1bb6 )
[12/01/2010 19:16:20.979583] ---> Time elapsed - +4.000000E-005 seconds

[12/01/2010 19:16:20.979612] SQLDescribeParam( psSQLType=SQL_INTEGER, puiParamDef=10, psScale=0, psNullable=SQL_NULLABLE_UNKNOWN )
[12/01/2010 19:16:20.979719] <--- SQL_SUCCESS Time elapsed - +2.860000E-004 seconds

[12/01/2010 19:16:20.979749] SQLBindParameter( hStmt=1:2, iPar=2, fParamType=SQL_PARAM_INPUT, fCType=SQL_C_SBIGINT, fSQLType=SQL_INTEGER, cbColDef=10, ibScale=0, rgbValue=&10dd1c58, cbValueMax=0, pcbValue=<NULL pointer> )
[12/01/2010 19:16:20.979975] ---> Time elapsed - +3.000000E-005 seconds

[12/01/2010 19:16:20.980005] SQLBindParameter( )
[12/01/2010 19:16:20.980032] <--- SQL_SUCCESS Time elapsed - +2.830000E-004 seconds

[12/01/2010 19:16:20.980064] SQLExecute( hStmt=1:2 )
[12/01/2010 19:16:20.980112] ---> Time elapsed - +3.200000E-005 seconds

[12/01/2010 19:16:20.980148] SQLExecute( )
[12/01/2010 19:16:20.980175] <--- SQL_NEED_DATA Time elapsed - +1.110000E-004 seconds

[12/01/2010 19:16:20.980211] SQLParamData( hStmt=1:2, prgbValue=&10dd1c7c )
[12/01/2010 19:16:20.980278] ---> Time elapsed - +3.600000E-005 seconds

[12/01/2010 19:16:20.980308] SQLParamData( prgbValue=&10dd1bc0 )
[12/01/2010 19:16:20.980358] <--- SQL_NEED_DATA Time elapsed - +1.470000E-004 seconds

[12/01/2010 19:16:20.980394] SQLPutData( hStmt=1:2, rgbValue=x'', cbValue=0 )
[12/01/2010 19:16:20.980482] ---> Time elapsed - +3.600000E-005 seconds

[12/01/2010 19:16:20.980521] SQLPutData( )
[12/01/2010 19:16:20.980564] <--- SQL_SUCCESS Time elapsed - +1.700000E-004 seconds

[12/01/2010 19:16:20.980594] SQLParamData( hStmt=1:2, prgbValue=&10dd1c7c )
[12/01/2010 19:16:20.980662] ---> Time elapsed - +3.000000E-005 seconds
[12/01/2010 19:16:20.980703] ( Row=1, iPar=2, fCType=SQL_C_BIGINT, rgbValue=6 )
[12/01/2010 19:16:20.980810]
sqlccsend( Handle - 4097699792 )
sqlccsend( ulBytes - 140 )
sqlccsend( ) rc - 0, time elasped - +3.000000E-006
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 111 ) - rc - 0, time elapsed - +1.230000E-004
Elapsed Server Processing Time - +1.240000E-004

[12/01/2010 19:16:20.981081] SQLParamData( prgbValue=&10dd1bc0 )
[12/01/2010 19:16:20.981129] <--- SQL_SUCCESS Time elapsed - +5.350000E-004 seconds

[12/01/2010 19:16:20.981165] SQLFreeHandle( fHandleType=SQL_HANDLE_STMT, hHandle=1:2 )
[12/01/2010 19:16:20.981232] ---> Time elapsed - +3.600000E-005 seconds
[12/01/2010 19:16:20.981265] ( Caching Statement Structure=1 )
[12/01/2010 19:16:20.981311]

[12/01/2010 19:16:20.981337] SQLFreeHandle( )
[12/01/2010 19:16:20.981364] <--- SQL_SUCCESS Time elapsed - +1.990000E-004 seconds

[12/01/2010 19:16:20.981457] SQLEndTran( fHandleType=SQL_HANDLE_DBC, hHandle=0:1, fType=SQL_COMMIT )
[12/01/2010 19:16:20.981549] ---> Time elapsed - +9.300000E-005 seconds
[12/01/2010 19:16:20.981579] ( COMMIT REQUESTED=1 )
[12/01/2010 19:16:20.981625]
sqlccsend( Handle - 4097699792 )
sqlccsend( ulBytes - 15 )
sqlccsend( ) rc - 0, time elasped - +3.000000E-006
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 59 ) - rc - 0, time elapsed - +2.026000E-003
[12/01/2010 19:16:20.983812] ( COMMIT REPLY RECEIVED=1 )
[12/01/2010 19:16:20.983877]

[12/01/2010 19:16:20.983908] SQLEndTran( )
[12/01/2010 19:16:20.983935] <--- SQL_SUCCESS Time elapsed - +2.478000E-003 seconds

[12/01/2010 19:16:20.983981] SQLSetConnectAttr( hDbc=0:1, fOption=SQL_ATTR_AUTOCOMMIT, pvParam=&00000001, iStrLen=-6 )
[12/01/2010 19:16:20.984091] ---> Time elapsed - +4.600000E-005 seconds

[12/01/2010 19:16:20.984120] SQLSetConnectAttr( )
[12/01/2010 19:16:20.984147] <--- SQL_SUCCESS Time elapsed - +1.660000E-004 seconds

[12/01/2010 19:16:24.027860] SQLAllocHandle( fHandleType=SQL_HANDLE_STMT, hInput=0:1, phOutput=&10dd56ec )
[12/01/2010 19:16:24.028052] ---> Time elapsed - +3.043713E+000 seconds
[12/01/2010 19:16:24.028111] ( Re-using Cached Statement Structure=1 )
[12/01/2010 19:16:24.028160]

[12/01/2010 19:16:24.028190] SQLAllocHandle( phOutput=1:2 )
[12/01/2010 19:16:24.028238] <--- SQL_SUCCESS Time elapsed - +3.780000E-004 seconds

[12/01/2010 19:16:24.028274] SQLExecDirect( hStmt=1:2 )
[12/01/2010 19:16:24.028322] ---> Time elapsed - +3.600000E-005 seconds
[12/01/2010 19:16:24.028352] ( pszSqlStr="SELECT * FROM model_tests WHERE (model_tests.id = 6) ", cbSqlStr=53 )
[12/01/2010 19:16:24.028420]
[12/01/2010 19:16:24.028496] ( StmtOut="SELECT * FROM model_tests WHERE (model_tests.id = 6)" )
[12/01/2010 19:16:24.028548]
[12/01/2010 19:16:24.028582] ( Package="SYSSH200 ", Section=4 )
[12/01/2010 19:16:24.028650]
sqlccsend( Handle - 4097699792 )
sqlccsend( ulBytes - 185 )
sqlccsend( ) rc - 0, time elasped - +8.000000E-006
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 247 ) - rc - 0, time elapsed - +1.622000E-003
Elapsed Server Processing Time - +1.593000E-003
sqlccsend( Handle - 4097699792 )
sqlccsend( ulBytes - 122 )
sqlccsend( ) rc - 0, time elasped - +5.000000E-006
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 108 ) - rc - 0, time elapsed - +5.900000E-005
Elapsed Server Processing Time - +5.800000E-005
[12/01/2010 19:16:24.030704] ( Requested Cursor Attributes=x'00000000' )
[12/01/2010 19:16:24.030771]
[12/01/2010 19:16:24.030798] ( Reply Cursor Attributes=x'00000000' )
[12/01/2010 19:16:24.030847]
[12/01/2010 19:16:24.030875] ( Actual Cursor Attributes=x'00000000' )
[12/01/2010 19:16:24.030922]

[12/01/2010 19:16:24.030951] SQLExecDirect( )
[12/01/2010 19:16:24.030978] <--- SQL_SUCCESS Time elapsed - +2.704000E-003 seconds

[12/01/2010 19:16:24.031130] SQLNumResultCols( hStmt=1:2, pcCol=&10dd5bac )
[12/01/2010 19:16:24.031202] ---> Time elapsed - +1.520000E-004 seconds

[12/01/2010 19:16:24.031230] SQLNumResultCols( pcCol=3 )
[12/01/2010 19:16:24.031278] <--- SQL_SUCCESS Time elapsed - +1.480000E-004 seconds

[12/01/2010 19:16:24.031310] SQLDescribeCol( hStmt=1:2, sCol=1, pszColName=&ff7f7d28, sColNameMaxByteLen=8192, psColNameCharLen=&10dd5c16, psSQLType=&10dd5bbc, puiColDef=&10dd5bc0, psScale=&10dd5bc4, psNullable=&10dd5bc6 )
[12/01/2010 19:16:24.031519] ---> Time elapsed - +3.200000E-005 seconds

[12/01/2010 19:16:24.031554] SQLDescribeCol( pszColName="ID", psColNameCharLen=2, psSQLType=SQL_INTEGER, pcbColDef=10, psScale=0, psNullable=SQL_NO_NULLS )
[12/01/2010 19:16:24.031703] <--- SQL_SUCCESS Time elapsed - +3.930000E-004 seconds

[12/01/2010 19:16:24.031735] SQLDescribeCol( hStmt=1:2, sCol=2, pszColName=&ff7f7d28, sColNameMaxByteLen=8192, psColNameCharLen=&10dd5c16, psSQLType=&10dd5bd8, puiColDef=&10dd5bdc, psScale=&10dd5be0, psNullable=&10dd5be2 )
[12/01/2010 19:16:24.031944] ---> Time elapsed - +3.200000E-005 seconds

[12/01/2010 19:16:24.031974] SQLDescribeCol( pszColName="NAME", psColNameCharLen=4, psSQLType=SQL_VARCHAR, pcbColDef=255, psScale=0, psNullable=SQL_NULLABLE )
[12/01/2010 19:16:24.032128] <--- SQL_SUCCESS Time elapsed - +3.930000E-004 seconds

[12/01/2010 19:16:24.032158] SQLDescribeCol( hStmt=1:2, sCol=3, pszColName=&ff7f7d28, sColNameMaxByteLen=8192, psColNameCharLen=&10dd5c16, psSQLType=&10dd5bf4, puiColDef=&10dd5bf8, psScale=&10dd5bfc, psNullable=&10dd5bfe )
[12/01/2010 19:16:24.032371] ---> Time elapsed - +3.000000E-005 seconds

[12/01/2010 19:16:24.032401] SQLDescribeCol( pszColName="DATA", psColNameCharLen=4, psSQLType=SQL_BLOB, pcbColDef=1048576, psScale=0, psNullable=SQL_NULLABLE )
[12/01/2010 19:16:24.032557] <--- SQL_SUCCESS Time elapsed - +3.990000E-004 seconds

[12/01/2010 19:16:24.032589] SQLBindCol( hStmt=1:2, iCol=1, fCType=SQL_C_DEFAULT, rgbValue=&10dd5878, cbValueMax=4, pcbValue=&10dd5870 )
[12/01/2010 19:16:24.032737] ---> Time elapsed - +3.200000E-005 seconds

[12/01/2010 19:16:24.032770] SQLBindCol( )
[12/01/2010 19:16:24.032799] <--- SQL_SUCCESS Time elapsed - +2.100000E-004 seconds

[12/01/2010 19:16:24.032848] SQLBindCol( hStmt=1:2, iCol=2, fCType=SQL_C_CHAR, rgbValue=&10dd5c68, cbValueMax=256, pcbValue=&10dd5880 )
[12/01/2010 19:16:24.032998] ---> Time elapsed - +4.900000E-005 seconds

[12/01/2010 19:16:24.033027] SQLBindCol( )
[12/01/2010 19:16:24.033056] <--- SQL_SUCCESS Time elapsed - +2.080000E-004 seconds

[12/01/2010 19:16:24.033086] SQLBindCol( hStmt=1:2, iCol=3, fCType=SQL_C_BLOB_LOCATOR, rgbValue=&10dd5c00, cbValueMax=4, pcbValue=&10dd5c04 )
[12/01/2010 19:16:24.033235] ---> Time elapsed - +3.000000E-005 seconds

[12/01/2010 19:16:24.033264] SQLBindCol( )
[12/01/2010 19:16:24.033291] <--- SQL_SUCCESS Time elapsed - +2.050000E-004 seconds

[12/01/2010 19:16:24.033324] SQLFetch( hStmt=1:2 )
[12/01/2010 19:16:24.033371] ---> Time elapsed - +3.300000E-005 seconds
sqlccsend( Handle - 4097699792 )
sqlccsend( ulBytes - 159 )
sqlccsend( ) rc - 0, time elasped - +3.000000E-006
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 171 ) - rc - 0, time elapsed - +1.510000E-004
Elapsed Server Processing Time - +1.560000E-004
[12/01/2010 19:16:24.033694] ( iRow=1, iCol=1, fCType=SQL_C_DEFAULT, rgbValue=x'00000006', pcbValue=4 )
[12/01/2010 19:16:24.033825]
[12/01/2010 19:16:24.033853] ( iRow=1, iCol=2, fCType=SQL_C_CHAR, rgbValue=<NULL data>, pcbValue=-1 )
[12/01/2010 19:16:24.033979]
[12/01/2010 19:16:24.034006] ( iRow=1, iCol=3, fCType=SQL_C_BLOB_LOCATOR, rgbValue=22185CC0, pcbValue=4 )
[12/01/2010 19:16:24.034136]

[12/01/2010 19:16:24.034164] SQLFetch( )
[12/01/2010 19:16:24.034192] <--- SQL_SUCCESS Time elapsed - +8.680000E-004 seconds

[12/01/2010 19:16:24.034248] SQLAllocHandle( fHandleType=SQL_HANDLE_STMT, hInput=0:1, phOutput=&ff7f9d18 )
[12/01/2010 19:16:24.034338] ---> Time elapsed - +5.600000E-005 seconds

[12/01/2010 19:16:24.034371] SQLAllocHandle( phOutput=1:1 )
[12/01/2010 19:16:24.034419] <--- SQL_SUCCESS Time elapsed - +1.710000E-004 seconds

[12/01/2010 19:16:24.034459] SQLGetLength( hStmt=1:1, fCType=SQL_C_BLOB_LOCATOR, iLocator=572021952, pcbLocator=&ff7f9d6c, piIndicatorValue=&10dd5c04 )
[12/01/2010 19:16:24.034599] ---> Time elapsed - +4.000000E-005 seconds
[12/01/2010 19:16:24.034646] ( Row=1, iPar=1, fCType=SQL_C_BLOB_LOCATOR, rgbValue=22185CC0 )
[12/01/2010 19:16:24.034756]
sqlccsend( Handle - 4097699792 )
sqlccsend( ulBytes - 132 )
sqlccsend( ) rc - 0, time elasped - +3.000000E-006
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 67 ) - rc - 0, time elapsed - +8.100000E-005
[12/01/2010 19:16:24.034954] ( Row=1, iPar=2, fCType=SQL_C_LONG, rgbValue=0 )
[12/01/2010 19:16:24.035065]
Elapsed Server Processing Time - +8.500000E-005

[12/01/2010 19:16:24.035118] SQLGetLength( pcbLocator=0, piIndicatorValue=0 )
[12/01/2010 19:16:24.035184] <--- SQL_SUCCESS Time elapsed - +7.250000E-004 seconds

[12/01/2010 19:16:24.035218] SQLFreeHandle( fHandleType=SQL_HANDLE_STMT, hHandle=1:1 )
[12/01/2010 19:16:24.035284] ---> Time elapsed - +3.400000E-005 seconds
[12/01/2010 19:16:24.035321] ( Caching Statement Structure=1 )
[12/01/2010 19:16:24.035368]

[12/01/2010 19:16:24.035396] SQLFreeHandle( )
[12/01/2010 19:16:24.035423] <--- SQL_SUCCESS Time elapsed - +2.050000E-004 seconds

[12/01/2010 19:16:24.035456] SQLAllocHandle( fHandleType=SQL_HANDLE_STMT, hInput=0:1, phOutput=&ff7f9d08 )
[12/01/2010 19:16:24.035548] ---> Time elapsed - +3.300000E-005 seconds
[12/01/2010 19:16:24.035576] ( Re-using Cached Statement Structure=1 )
[12/01/2010 19:16:24.035623]

[12/01/2010 19:16:24.035650] SQLAllocHandle( phOutput=1:1 )
[12/01/2010 19:16:24.035697] <--- SQL_SUCCESS Time elapsed - +2.410000E-004 seconds

[12/01/2010 19:16:24.035738] SQLGetSubString( hStmt=1:1, fCType=SQL_C_BLOB_LOCATOR, iLocator=572021952, iFrom=1, iLength=0, fCTypeTarget=SQL_C_BINARY, rgbValue=&10dd5df8, cbValueMax=0, pcbValue=&ff7f9d68, piIndicatorValue=&10dd5c04 )
[12/01/2010 19:16:24.035967] ---> Time elapsed - +4.100000E-005 seconds
[12/01/2010 19:16:24.036004] ( Row=1, iPar=1, fCType=SQL_C_BLOB_LOCATOR, rgbValue=22185CC0 )
[12/01/2010 19:16:24.036138]
sqlccsend( Handle - 4097699792 )
sqlccsend( ulBytes - 132 )
sqlccsend( ) rc - 0, time elasped - +3.000000E-006
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 67 ) - rc - 0, time elapsed - +2.600000E-005
[12/01/2010 19:16:24.036270] ( Row=1, iPar=2, fCType=SQL_C_LONG, rgbValue=0 )
[12/01/2010 19:16:24.036376]
Elapsed Server Processing Time - +1.600000E-005
[12/01/2010 19:16:24.036437] ( Row=1, iPar=1, fCType=SQL_C_BLOB_LOCATOR, rgbValue=22185CC0 )
[12/01/2010 19:16:24.036560]
[12/01/2010 19:16:24.036587] ( Row=1, iPar=2, fCType=SQL_C_LONG, rgbValue=1 )
[12/01/2010 19:16:24.036694]
[12/01/2010 19:16:24.036721] ( Row=1, iPar=3, fCType=SQL_C_LONG, rgbValue=0 )
[12/01/2010 19:16:24.036828]
sqlccsend( Handle - 4097699792 )
sqlccsend( ulBytes - 148 )
sqlccsend( ) rc - 0, time elasped - +3.000000E-006
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 72 ) - rc - 0, time elapsed - +4.100000E-005
Elapsed Server Processing Time - +3.800000E-005

[12/01/2010 19:16:24.037002] SQLGetSubString( rgbValue=, pcbValue=0, piIndicatorValue=0 )
[12/01/2010 19:16:24.037093] <--- SQL_SUCCESS Time elapsed - +1.355000E-003 seconds

[12/01/2010 19:16:24.037124] SQLFreeHandle( fHandleType=SQL_HANDLE_STMT, hHandle=1:1 )
[12/01/2010 19:16:24.037191] ---> Time elapsed - +3.100000E-005 seconds
[12/01/2010 19:16:24.037221] ( Caching Statement Structure=1 )
[12/01/2010 19:16:24.037268]

[12/01/2010 19:16:24.037295] SQLFreeHandle( )
[12/01/2010 19:16:24.037322] <--- SQL_SUCCESS Time elapsed - +1.980000E-004 seconds

[12/01/2010 19:16:24.037358] SQLFetch( hStmt=1:2 )
[12/01/2010 19:16:24.037405] ---> Time elapsed - +3.600000E-005 seconds

[12/01/2010 19:16:24.037447] SQLFetch( )
[12/01/2010 19:16:24.037475] <--- SQL_NO_DATA_FOUND Time elapsed - +1.170000E-004 seconds

[12/01/2010 19:16:24.037509] SQLFreeHandle( fHandleType=SQL_HANDLE_STMT, hHandle=1:2 )
[12/01/2010 19:16:24.037580] ---> Time elapsed - +3.400000E-005 seconds
[12/01/2010 19:16:24.037612] ( COMMIT REQUESTED=1 )
[12/01/2010 19:16:24.037658]
sqlccsend( Handle - 4097699792 )
sqlccsend( ulBytes - 15 )
sqlccsend( ) rc - 0, time elasped - +2.000000E-006
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 59 ) - rc - 0, time elapsed - +4.100000E-005
[12/01/2010 19:16:24.037811] ( COMMIT REPLY RECEIVED=1 )
[12/01/2010 19:16:24.037858]

[12/01/2010 19:16:24.037898] SQLFreeHandle( )
[12/01/2010 19:16:24.037925] <--- SQL_SUCCESS Time elapsed - +4.160000E-004 seconds

[12/01/2010 19:16:26.221682] SQLDisconnect( hDbc=0:1 )
[12/01/2010 19:16:26.221876] ---> Time elapsed - +2.183757E+000 seconds
sqlccsend( Handle - 4097699792 )
sqlccsend( ulBytes - 25 )
sqlccsend( ) rc - 0, time elasped - +1.500000E-005
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 59 ) - rc - 0, time elapsed - +1.150000E-004
sqlccrecv( timeout - +0.000000E+000 )
sqlccrecv( ulBytes - 0 ) - rc - 71, time elapsed - +4.680000E-004

[12/01/2010 19:16:26.222741] SQLDisconnect( )
[12/01/2010 19:16:26.222778] <--- SQL_SUCCESS Time elapsed - +1.096000E-003 seconds

[12/01/2010 19:16:26.222813] SQLFreeHandle( fHandleType=SQL_HANDLE_DBC, hHandle=0:1 )
[12/01/2010 19:16:26.222881] ---> Time elapsed - +3.500000E-005 seconds
[12/01/2010 19:16:26.222926] ( Number of allocations left before we freed the Pool=1 )
[12/01/2010 19:16:26.222974]

[12/01/2010 19:16:26.223003] SQLFreeHandle( )
[12/01/2010 19:16:26.223030] <--- SQL_SUCCESS Time elapsed - +2.170000E-004 seconds

[12/01/2010 19:16:26.223063] SQLFreeHandle( fHandleType=SQL_HANDLE_ENV, hHandle=0:1 )
[12/01/2010 19:16:26.223130] ---> Time elapsed - +3.300000E-005 seconds

[12/01/2010 19:16:26.223173] SQLFreeHandle( )
[12/01/2010 19:16:26.223199] <--- SQL_SUCCESS Time elapsed - +1.360000E-004 seconds


By: Simon Macneall
RE: Blobs not being saved [ reply ]  
2010-12-01 08:04
Hi Praveen,

I just created a new rails 2.3.8 project, added this migration

class AddTable < ActiveRecord::Migration
def self.up
create_table :model_tests do |t|
t.string :name
t.binary :data
end
end

def self.down
drop_table :model_tests
end
end


and

app/models/model_test.rb

class ModelTest < ActiveRecord::Base

end

Then I run the following:

ruby script/console
Loading development environment (Rails 2.3.8)
>> m = ModelTest.new
m=> #<ModelTest id: nil, name: nil, data: nil>
>> m.data = "test"
=> "test"
>> m.save
=> true
>> m.reload
=> #<ModelTest id: 3, name: nil, data: "">

So, it's gone from nil to "", but has lost the actual value.

I'll play with the CLI trace next.

Cheers
Simon

By: Mario Briggs
RE: Blobs not being saved [ reply ]  
2010-12-01 06:02
2.5.5 rules out my hypothesis, so the CLI trace will help and i will let Praveen proceed in helping you.

BTW i think if i give you hints on how BLOBS is handled, it might rings a few bells...
the default behaviour when LOBS are involved is to dump a indicator like @@@IBM_@@@@ into the column and then immediately after the insert, update it with the actual LOB value. The reason for this strange mumbo-jumbo, is that ROR does not use parameterized queries and with LOB values, you might overrun the max length an SQL string can be. Thus we first dump the indicator and then use another 'update SQL' with parameter markers filtered by pkey.

If the above has not scared you already and you are still willing to work with ROR, well you have lived to see the best part. Since 2.0. of the gem, Praveen worked brilliantly to add support for parameterized queries to ROR when used with DB2. See #3 in this blog and the article it points to - http://programmingzen.com/2010/01/21/db2-support-for-rubyrails-turns-2-0/

the side-effects of this is that when turn on parameterized queries (not the default), all the above strange mumbo-jumbo of LOB handling is gone, becuase we are using parameterized values for the LOBS.

thanks
Mario

By: Simon Macneall
RE: Blobs not being saved [ reply ]  
2010-12-01 05:23
Hi guys,

thanks for the reponses. I should have put the gem version in the original message.

both machines are running 2.5.5

I'll work on getting a cut down app to replicate the issue as well as playing with the CLI trace

Cheers
Simon

By: Mario Briggs
RE: Blobs not being saved [ reply ]  
2010-12-01 05:16
From Simo's description of the problem, it could be the big-endian vs small-endian SQL type 'conversions' of integers bug that existed in the earlier versions of the gem, but fixed since sometime, so knowing the version of the gem is a good way to start here

By: Praveen Devarao
RE: Blobs not being saved [ reply ]  
2010-12-01 03:58
Hi Simon,

Could you get us a small use case. To diagnose your first step would be to turn on the CLI trace and check if data insertion is taking place rightly. The trace should be able to tell you if your data was successfully inserted or not.

Also, let us know which version of ibm_db gem are you using on both the systems.

More about CLI trace: http://publib.boulder.ibm.com/infocenter/db2luw/v9r7/topic/com.ibm.db2.luw.admin.trb.doc/doc/c0008936.html


Thanks

Praveen

By: Simon Macneall
Blobs not being saved [ reply ]  
2010-12-01 02:27
Hi all,

We've been going through db2 validation. I've got our system up and running on one install. Now I am testing on another server and getting strange results.

We have a model that has a blob attribute. When I try to set the attribute everything appears to be fine (save returns true) but if I reload the model, the attribute is empty.

This works fine on our other setup

Working version:
DB2 v9.7.0.2 2

Failing version:
DB2 9.7.0.3 3

The only other difference is that the working version is on a intel chip, while the broken one is on a power7 box.

Anyone have any suggestions on how to debug/fix the issue?

Thanks
Simon