D2000 DBManager - logs evaluation
Document version: 1.0, 26.2.2008
This document is used for detail description of log lists and their usage for:
- Errors detecting in the objects configuration of Table type in D2000 (error in structure definition)
- Application errors detecting in ESL
- Power debugging (number of connections setting according to application requests)
- DBManager current status detecting by TELL commands
The most of the following methods suppose that the objects of Database type have been
configured with the allowed option Debug.
It is recommended (for D2000 version 7.01.022 and higher ones) to set the
size of log file (MB) at option Debug
and to configure the actions logging into separate file for each database.
The size of log file must be large enough to obtain the log data for long
period (the maximum size of log file DBManager.log is 10 MB).
DBManager should be run for adequately long period including the period of maximum system load (e.g. 24 hours during working day). Also it is recommended to configure the start-up parameter/E+DBG.DBMANAGER determined for logging of details about performed operations.
1. Errors detecting in objects configuration of Table type
Following errors can be detected from logs:
- table with the given name does not exist,
- column in SQL table is text-based and the column in structure definition in D2000 is not text-based,
- column in SQL table is not numeric and the column in structure definition in D2000 is the numeric (for D2000 version 7.01.022 and higher ones).
Precondition: DBManager runs adequately long period to approach (reading or writing) to all tables which are to be checked.
Searched string: Cannot get any result from SQL Columns.
13:42:28.960 08.02 *** Error in con 1: 13:42:28.962 08.02 con 1:[GetColumnDescript] 13:42:28.964 08.02 con 1:<HI ws1phum1 browser> 13:42:28.967 08.02 con 1:Cannot get any result from SQLColumns. Possible causes are: table "dba"."MAT_SKUPINAxx" does not exist in SQL database; table is not visible by defined user; table has not any column with name matching its structure definition in D2000
Solution: to check
- the existence of table in SQL database,
- the table is accessible to user which was configured in object of Database type; this object is parent of the object of Table type that the error message concerns,
- the table contains at least the one column with the name identical with name of structure definition which is connected in object configuration of Table type (some of the SQL databases can be case-sensitive),
- the table name in SQL database is identical with the parameter Table configured on object of Table type (beware of possible case-sensitivity).
Searched string: text data mapped to non-text columns
14:05:36.496 08.02 Table MAT_SKUPINA (DB.MAT_SKUPINA) text data mapped to non-text columns:NAZOV
Solution: To integrate column type in SQL database and in
structure definition connected in object configuration of Table type. The
column in SQL database is text type and column of structure definition in
D2000 is not text type. In this configuration it depends on if data in specific
column of table in SQL database can be converted to type
different from text type (integer, real, etc.) during reading.
The result of errors at conversion can be for example:
- for OCI version of DBManager: the values absent in column with invalid value and in all following columns in reading of table through browser or in access through pages
- for ODBC version of DBManager and for database Sybase SQL Anywhere: invalid values in all cells of row in which the invalid value occurs.
Searched string: non-number data mapped to number columns
15:47:29.976 08.02 Table Time_Test (DB.Cas) non-number data mapped to number columns:Cas,
Solution: To integrate the column type in SQL database and in structure definition connected in object configuration of Table type. The column in SQL database is not numeric, the column of structure definition in D2000 is numeric (integer, real or relative time). In this configuration it depends on if data in specific column of table in SQL database can be converted to type different from text type (integer, real, etc.) during reading.
2. Application errors detecting in ESL
Following errors, in the form of ODBC or OCI error, can be detected from logs.
Searched string: *** Error in
21:00:11.961 07.02 *** Error in con 2: 21:00:11.962 07.02 con 2:<E.IOPT_Export: 95; 3624><E.IOPT_Scheduler: 32> 21:00:11.962 07.02 con 2:[InsertRecord] Execute: INSERT INTO "ROVE_IOPT"."S_IF_USER" ("IU_ID","IU_PERS_ID","IU_FS_ID","IU_DB_USER","IU_FIRSTNAME","IU_SURNAME","IU_APPL", "IU_PWD_PERMANENT","IU_PWD_KONTO","IU_STATUS","IU_DELETE","IU_TADI_ID") VALUES (:1,:2,:3,:4,:5,:6,:7,:8,:9,:10,:11,:12) ,row 1,Exception name: OCI.THICK.LIB_ERROR Message: ORA-01400: cannot insert NULL do ("IOPT"."IF_USER"."IU_FIRSTNAME") ORA-06512: at line "IOPT.G_IF_USER_TB" Call stack traceback locations: 0x51ae1e 0x51af63 0x5142c3 0x76e54b 0x772065 0x7d0536 0x7e2230 0x8219fa 0x77e64827
16:22:18.474 08.02 *** Error in con 3: 16:22:18.475 08.02 con 3:[PrepareSqlStmt] SQLExecDirect: SELECT ID_MATERIAL FROM materialXX 16:22:18.477 08.02 con 3:<S.sql_Test_Evil: 106> 16:22:18.478 08.02 con 3:(S0002) [Sybase][ODBC Driver][Adaptive Server Anywhere]Table 'materialXX' not found ErrorCode= -141
Solution: Error analysis (e.g. searching of ORA-xxxxx error message, cause detection and removal). If the error occurred e.g. at specific values entering it is recommended to configure start-up parameter /E+DBG.DBMANAGER.DATA for process SELF.DBM (value logging).
Example of usage:
15:20:21.659 08.02 Db SKEI_MES, con 2:PageInsert BEG 15:20:21.660 08.02 PositionedInsert: INSERT INTO "MES"."SOURCE_PLACE" ("ID","IDVECT","KOD","ADDR","NAME","SV_IDX", "WHX","SIMAODB","NTYP","ID_T") VALUES (:1,:2,:3,:4,:5,:6,:7,:8,:9,:10,:11,:12,:13,:14,:15) 15:20:21.661 08.02 PositionedInsert time displayed in pure UTC (configured offset +0) 15:20:21.661 08.02 PositionedInsert data: 88; NULL; 'gsdaf.GPS'; NULL; 'fsgdfd.GPS'; 28; 1.00E+00; NULL; 10; 5; 15:20:21.667 08.02 *** Error in Db SKEI_MES, con 2: 15:20:21.668 08.02 Db SKEI_MES, con 2:<E.Max_ID: 133; 15>< S.SchemeOM: 19; 135; 153> 15:20:21.668 08.02 Db SKEI_MES, con 2:[PositionedInsert] Execute/Commit "ROVE_MES"."ODBERNE_MIESTO":Exception name: OCI.THICK.LIB_ERROR Message: ORA-01438: value larger than specified precision allowed for this column Call stack traceback locations: 0x51b0ce 0x51b213 0x514573 0x767089 0x7ca8db 0x7cab31 0x7e01f8 0x81f71a 0x77e64827 15:20:21.669 08.02 PositionedInsert end 15:20:21.669 08.02 Db SKEI_MES, con 2:PageInsert END
In this example you can open the browser and try to enter manually the written values into table. The saving had run without error till the value in column "NTYP" was less than 10. Oracle Enterprise Manager detected that this column was created by mistake in SQL database as Number(1), i.e. number with range of one figure.
Searched string: timeout expired
10:03:44.597 17.02 WD: con 3: timeout expired 1 times in U_EXECDIRECT1/D_EXECDIRECT2
Connection No. 3 makes some action (detail list U_EXECDIRECT1/D_EXECDIRECT2 are determined for D2000 developers but they indicate that it concerns probably SQL_EXEC_DIRECT). After searching the first existence of string con 3 you can see that the last command, which started to perform, was:
10:02:16.864 17.02 con 3:SQL_EXEC_DIRECT BEG
If debug category DBG.DBMANAGER is switched on, the list contains also the specific command which is executed:
10:02:16.865 17.02 ExecDirect: Delete from EDA_Vektor v WHERE ID_Vektor >= 2000000 AND id_vektor not in (select id_vektor from EDA_VEKTOR_SCENAR) AND not exists (SELECT f.id_vektor FROM EDA_Predpis_Funkcie f WHERE f.funkcia like '%' || v.meno || '%' )
3. Power debugging (number of connection setting according to application requests)
If the option Debug is switched on, DBManager writes also the information about creating, using and ending of the connections into log. The connection is created or assigned as the result of following actions:
- browser opening above the table,
- actions DBS_* called without transaction parameter,
- actions DBS_READ_BLOB and DBS_UPDATE_BLOB called without transaction parameter,
- action DB_TRANS_OPEN.
The other actions use the handle obtained by calling the actions DB_TRANS_OPEN,
DB_CONNECT, PG_CONNECT and
SQL_CONNECT. They must run on the
connection which the handle is bounded up with. Actions SBS_* (DBS_BLOB_*
including) use the connection and release it immediately.
Following messages concerning the creating and assigning of the automatic connection exist in the system:
|(X1) got free NTC||Free automatic connection was used (no handle bounded with this connection exists).|
|(X2) has 3/7 NTC,reusing T con 4||Number of automatic connections did not reached the value defined in Database configuration. Free connection - transactional - is available. This connection will be changed into automatic and will be used.|
|(X3) has 3/7 NTC,creating new||Number of automatic connections did not reached the value defined in Database configuration. Neither free connection nor transactional is available. That is why the new connection on database creates.|
|(X4) has 7/7 NTC,reusing con 5||Number of automatic connections reached the value defined in Database configuration. One of the automatic connections will be used (even though no one is free, i.e. at least one handle is bounded on each connection). The connection with the less requests in queue or with the flag not_busy (currently it processes no request) is used.|
|(X5) has 7/7 NTC, not found any good, hardpanic!||In spite of the number of automatic connections
reached the value defined in Database
configuration, no one available connection was searched.
This status could occur up to version 7.01.023 immediately after restart of DBManager. If the requests came before the predefined connections was linked to database (e.g. connection to Oracle database can take several seconds) or in case of database inaccessible and connection failed repeatedly.
Another occurrence: When DBManager starts-up and some of the databases is switched off and then switch on, the requests for database come before the predefined connections linked to database (if database is switched off during DBManager starts-up, the predefined connections do not link to database but they wait until the database is switch on).
|(X6) has 7 cons, limit is 7, can't create NTC, reusing con 1||Number of automatic connections has not reached the value defined in Database configuration and it is not possible to create a new connection because there is the maximum connections (i.e. other connections are used as transactional). One of the automatic connections will be used according to the same rules as it is in X4.|
|(X7) has 7 cons,limit is 7, can't create NTC, not found any good, hardpanic!||Number of automatic connections has not reached the value defined in Database configuration and it is not possible to create a new connection because there is the maximum connections. At the same time the all connections are used as transactional. This situation should not occur as one connection is always booked as automatic.|
Messages X4 and X6 do not mean that the
requests must wait on each other in DBManager. Even if some of the browsers use
the same automatic connection, this connection is not used most of the time
(until user activates to load the new page or makes the changes). There is only
one possibility - more actions come close one by one and one action will wait
until another one performs.
Wait state is possible to monitor by start-up parameter /DBD<number_of_requests>. Recommended mechanism is following:
- start DBManager with start-up parameter /DBD<number_of_requests>,
- DBManager must run for adequately long period (for one day/week) during common system operation,
- search the string performance warning in log files. If performance warning occurs there, the requests wait. Try to increase the number of automatic connections. If performance warning does not occur there, decrease the number of automatic connections, the user response will not be worsened.
4. DBManager current status detecting by TELL commands
- forgotten transactions/transactions opened longer than it is necessary
->Db DBC_ROVE_EDA con 6:normal, 2 handles, transact 301747, idle 02:53:44.316 ->Db DBC_ROVE_EDA con 6:trans DBC_ROVE_EDA: < S.EDA_Komp_TreeData_Vektor: 531; 567> ->Db DBC_ROVE_EDA con 6:dbase DBC_ROVE_EDA: < S.EDA_Komp_TreeData_Vektor: 532; 567>Above mentioned transactions can be forgotten (DB_TRANS_CLOSE was not called after DB_TRANS_COMMIT or DB_TRANS_ROLLBACK) and they will be ended after closing the picture (if they are placed in picture script) or by event ending/saving (if it concerns about the server event the transactions will be ended after process .EVH finishes).