Logs 2.5

Generated by D:\IBSurgeon\OLTP-EMUL\src\oltp_isql_run_worker.bat, ISQL session #1 of total launched 10. 09.03.2016 23:50:31,72.
Common Performance Final Results
  1. Test configuration
  2. Test Finish details
  3. Test workload details
  4. Indices DDL for heavy-loaded table(s)
  1. Performance, TOTAL score
  2. Performance, DYNAMIC, 10 intervals
  3. Performance, per MINUTE, since launch
  4. Performance, TRACE data for ISQL #1
  5. Performance, DETAILS per units
  6. MON$-analysis, per business units
  7. Exceptions during test run
  1. mon$database and 'show version' results
  2. Database Statistics, full
  3. Ratio "Versions / Records" for tables
  4. Database Validation Results
  5. New in firebird.log while test was run
  6. Final processing of ISQL logs

Server and database settings

Server version: WI-V2.5.3.26780 Firebird 2.5
Server implementation: Firebird/x86-64/Windows NT
FB_ARCHITECTURE DB_NAME FORCED_WRITES SWEEP_INT PAGE_BUFFERS PAGE_SIZE
Classic 2.5.3 D:\IBSURGEON\OLTP25.FDB ON 20001 384 8192

Test configuration settings

File: D:\IBSurgeon\OLTP-EMUL\src\oltp25_config.win
PARAM_NAME PARAM_VALUE
fbc D:\IBSurgeon\FB253x64.TMP\bin
dbnm D:\IBSurgeon\oltp25.fdb
host localhost
port 3253
usr SYSDBA
pwd masterke
tmpdir E:\temp\logs.oltp25
working_mode small_03
warm_time 0
test_time 2
idle_time 0
use_mtee 0
is_embed 0
remove_isql_logs if_no_severe_errors
no_auto_undo 1
detailed_info 0
mon_unit_perf 0
trc_unit_perf 1
init_buff 32768
create_with_fw sync
create_with_sweep 20001
wait_if_not_exists 0
wait_after_create 1
init_docs 0
wait_for_copy 0
create_with_debug_objects 1
create_with_split_heavy_tabs 1
create_with_separate_qdistr_idx 0
create_with_compound_columns_order most_selective_first
make_html 1
run_db_statistics 0
run_db_validation 0
file_name_with_test_params regular
file_name_this_host_info profitmed
upload_report 1

Test finish info

FINISH_STATE DTS_END FB_GDSCODE FB_MNEMONA STACK IP TRN_ID ATT_ID EXC_UNIT
NORMAL: TEST_TIME EXPIRED. 2016-03-09 23:50:23.3600 -1 <null> 127.0.0.1 12038 483 2

Current test settings

CATEGORY SETTING VAL
COMMON TRACED_UNITS ,,
COMMON ENABLE_MON_QUERY 0
COMMON HALT_TEST_ON_ERRORS ,CK,
COMMON LOG_PK_VIOLATION 0
COMMON QMISM_VERIFY_BITSET 1
COMMON RECALC_IDX_MIN_INTERVAL 15
COMMON ENABLE_RESERVES_WHEN_ADD_INVOICE 1
COMMON ORDER_FOR_OUR_FIRM_PERCENT 25
COMMON ENABLE_FILL_PHRASES 0
COMMON RANDOM_SEEK_VIA_ROWS_LIMIT 0
COMMON C_INVOICE_MIN_PURCHASE 1000
COMMON C_INVOICE_MAX_PURCHASE 2000
COMMON C_INVOICE_MIN_PROFIT_PRC 35
COMMON C_INVOICE_MAX_PROFIT_PRC 80
COMMON C_MIN_COST_TO_BE_SPLITTED 1000
COMMON C_ROWS_TO_MULTIPLY 10
COMMON C_PAYMENT_FROM_CLIENT_MIN_TOTAL 1000
COMMON C_PAYMENT_FROM_CLIENT_MAX_TOTAL 5000
COMMON C_PAYMENT_TO_SUPPLIER_MIN_TOTAL 2000
COMMON C_PAYMENT_TO_SUPPLIER_MAX_TOTAL 15000
COMMON BUILD_WITH_SPLIT_HEAVY_TABS 1
COMMON BUILD_WITH_SEPAR_QDISTR_IDX 0
COMMON BUILD_WITH_QD_COMPOUND_ORDR MOST_SELECTIVE_FIRST
SMALL_03 C_WARES_MAX_ID 400
SMALL_03 C_CUSTOMER_DOC_MAX_ROWS 10
SMALL_03 C_SUPPLIER_DOC_MAX_ROWS 50
SMALL_03 C_CUSTOMER_DOC_MAX_QTY 15
SMALL_03 C_SUPPLIER_DOC_MAX_QTY 50
SMALL_03 C_NUMBER_OF_AGENTS 50

Index(es) for heavy-loaded table(s)

TAB_NAME IDX_NAME IDX_KEY
XQD_1000_1200 XQD_1000_1200_WARE_SOP_ROP_SND WARE_ID,SND_OPTYPE_ID,RCV_OPTYPE_ID,SND_ID
XQD_1000_3300 XQD_1000_3300_DOC DOC_ID
XQD_1000_3300 XQD_1000_3300_WARE_SOP_ROP_SND WARE_ID,SND_OPTYPE_ID,RCV_OPTYPE_ID,SND_ID
XQD_1200_2000 XQD_1200_2000_WARE_SOP_ROP_SND WARE_ID,SND_OPTYPE_ID,RCV_OPTYPE_ID,SND_ID
XQD_2000_3300 XQD_2000_3300_WARE_SOP_ROP_SND WARE_ID,SND_OPTYPE_ID,RCV_OPTYPE_ID,SND_ID
XQD_2100_3300 XQD_2100_3300_WARE_SOP_ROP_SND WARE_ID,SND_OPTYPE_ID,RCV_OPTYPE_ID,SND_ID
XQD_3300_3400 XQD_3300_3400_WARE_SOP_ROP_SND WARE_ID,SND_OPTYPE_ID,RCV_OPTYPE_ID,SND_ID

Performance reports

Performance in TOTAL:

ACTION AVG_TIMES_PER_MINUTE AVG_ELAPSED_MS SUCCESSFUL_TIMES_DONE JOB_BEG JOB_END
*** OVERALL *** for 2 minutes: 12955.00 202 25910 2016-03-09 23:48 2016-03-09 23:50
customer order: creation 762.50 47 1525 2016-03-09 23:48 2016-03-09 23:50
customer order: refuse 56.00 19 112 2016-03-09 23:48 2016-03-09 23:50
order to supplier: creation 200.50 173 401 2016-03-09 23:48 2016-03-09 23:50
order to supplier: removal 8.00 805 8 2016-03-09 23:48 2016-03-09 23:50
invoice (draft): creation 184.50 186 369 2016-03-09 23:48 2016-03-09 23:50
invoice (draft): removal 24.50 62 49 2016-03-09 23:48 2016-03-09 23:50
invoice accept: apply 121.00 1776 242 2016-03-09 23:48 2016-03-09 23:50
invoice accept: cancel 12.50 347 25 2016-03-09 23:48 2016-03-09 23:50
customer reserve: creation 10037.00 20 20074 2016-03-09 23:48 2016-03-09 23:50
customer reserve: removal 460.00 10 920 2016-03-09 23:48 2016-03-09 23:50
realization accept: apply 354.00 24 708 2016-03-09 23:48 2016-03-09 23:50
realization accept: cancel 81.00 17 162 2016-03-09 23:48 2016-03-09 23:50
payment from customer: creation 265.50 25 531 2016-03-09 23:48 2016-03-09 23:50
payment from customer: removal 24.50 11 49 2016-03-09 23:48 2016-03-09 23:50
payment to supplier: creation 228.00 27 456 2016-03-09 23:48 2016-03-09 23:50
payment to supplier: removal 17.00 13 34 2016-03-09 23:48 2016-03-09 23:50
service: total inventory turnovers 68.00 77 136 2016-03-09 23:48 2016-03-09 23:50
service: total monetary turnovers 54.50 2 109 2016-03-09 23:48 2016-03-09 23:50
service: refresh index statistics <null> <null> <null> 2016-03-09 23:48 2016-03-09 23:50
Done for 6070 ms, from 23:50:50,08 to 23:50:56,15.

Performance in DYNAMIC:

ACTION ITRV_NO CNT_OK_PER_MINUTE CNT_ALL CNT_OK CNT_ERR ERR_PRC ITRV_BEG ITRV_END
interval # 1, overall 1 <null> 1762 1718 44 2.50 23:48:24 23:48:36
interval # 2, overall 2 <null> 2436 1998 438 17.98 23:48:37 23:48:49
interval # 3, overall 3 2317 2334 2317 17 0.73 23:48:50 23:49:02
interval # 4, overall 4 <null> 2269 2253 16 0.71 23:49:03 23:49:15
interval # 5, overall 5 <null> 2373 2356 17 0.72 23:49:16 23:49:28
interval # 6, overall 6 <null> 2847 2816 31 1.09 23:49:29 23:49:41
interval # 7, overall 7 <null> 3944 3579 365 9.25 23:49:42 23:49:54
interval # 8, overall 8 3258 4372 3258 1114 25.48 23:49:55 23:50:07
interval # 9, overall 9 <null> 5610 4499 1111 19.80 23:50:08 23:50:20
interval # 10, overall 10 <null> 1181 1116 65 5.50 23:50:21 23:50:33
Done for 6510 ms, from 23:50:58,58 to 23:51:05,09.

Performance for every MINUTE:

TEST_PHASE MINUTE_SINCE_TEST_START AVG_ESTIMATED MIN_TO_AVG_RATIO MAX_TO_AVG_RATIO ROWS_AGGREGATED DISTINCT_ATTACHMENTS
TEST_TIME 1 11288.02 0.4647 1.5775 2587 10
TEST_TIME 2 10984.00 0.8106 1.1794 1548 10
Done for 2610 ms, from 23:51:05,55 to 23:51:08,16.

Performance from TRACE for ISQL instance #1:

TRACED_DATA ITRV_NO SP_CLIENT_ORDER SP_CANCEL_CLIENT_ORDER SP_SUPPLIER_ORDER SP_CANCEL_SUPPLIER_ORDER SP_SUPPLIER_INVOICE SP_CANCEL_SUPPLIER_INVOICE SP_ADD_INVOICE_TO_STOCK SP_CANCEL_ADDING_INVOICE SP_CUSTOMER_RESERVE SP_CANCEL_CUSTOMER_RESERVE SP_RESERVE_WRITE_OFF SP_CANCEL_WRITE_OFF SP_PAY_FROM_CUSTOMER SP_CANCEL_PAY_FROM_CUSTOMER SP_PAY_TO_SUPPLIER SP_CANCEL_PAY_TO_SUPPLIER SRV_MAKE_INVNT_SALDO SRV_MAKE_MONEY_SALDO SRV_RECALC_IDX_STAT ITRV_BEG ITRV_END
fetches per second 1 23026 71621 29453 <null> 60323 <null> 42327 <null> 2012 27741 22841 24208 42610 <null> 39216 <null> <null> 81413 <null> 23:48:24 23:48:36
fetches per second 2 30840 <null> 38384 <null> 29983 <null> 72174 <null> <null> <null> 25498 <null> 61045 <null> 40325 <null> 315493 <null> <null> 23:48:37 23:48:49
fetches per second 3 29071 <null> 30679 <null> <null> <null> 82537 <null> <null> <null> 26866 <null> 36545 <null> 31867 <null> 518279 192000 <null> 23:48:50 23:49:02
fetches per second 4 35452 54452 31878 <null> 42939 <null> 69422 50080 <null> 36474 44044 <null> 60797 <null> 44251 <null> <null> <null> <null> 23:49:03 23:49:15
fetches per second 5 24466 70238 23709 <null> 34797 <null> 71029 <null> <null> 23739 43625 57755 54824 42793 69956 <null> 144030 118900 <null> 23:49:16 23:49:28
fetches per second 6 45632 62289 49489 <null> 52727 <null> 52167 <null> 2165 <null> 36196 <null> 59741 32689 115921 <null> <null> 486499 <null> 23:49:29 23:49:41
fetches per second 7 37690 <null> 72665 107783 90790 <null> 243865 <null> 1265 <null> 43768 94000 102272 <null> 87212 <null> 326741 614000 <null> 23:49:42 23:49:54
fetches per second 8 53325 85384 77380 <null> 90810 49361 184121 <null> 634 62000 59779 75523 127182 114000 131943 82400 578364 445500 <null> 23:49:55 23:50:07
fetches per second 9 68564 120072 80572 <null> 87166 <null> 283722 149997 <null> <null> 104079 <null> 135230 <null> 189434 123302 1150642 788493 <null> 23:50:08 23:50:20
fetches per second 10 55957 <null> 52820 <null> 108989 <null> 249095 <null> <null> <null> 132254 <null> 185586 <null> <null> 84769 601581 <null> <null> 23:50:21 23:50:33
marks per second 1 4648 7191 6175 <null> 13588 <null> 3628 <null> 147 3145 4051 3706 5730 <null> 5399 <null> <null> 10413 <null> 23:48:24 23:48:36
marks per second 2 5772 <null> 7129 <null> 6188 <null> 3342 <null> <null> <null> 4654 <null> 7799 <null> 4547 <null> 12560 <null> <null> 23:48:37 23:48:49
marks per second 3 5824 <null> 5553 <null> <null> <null> 5154 <null> <null> <null> 4940 <null> 5061 <null> 3960 <null> 21697 4400 <null> 23:48:50 23:49:02
marks per second 4 6632 4666 6076 <null> 8654 <null> 5337 5387 <null> 4628 8201 <null> 7960 <null> 5582 <null> <null> <null> <null> 23:49:03 23:49:15
marks per second 5 5034 6918 4257 <null> 6694 <null> 4620 <null> <null> 2594 8224 8205 7014 5758 7732 <null> 22181 9400 <null> 23:49:16 23:49:28
marks per second 6 8408 6394 9509 <null> 10817 <null> 4446 <null> 236 <null> 7516 <null> 8565 3758 18949 <null> <null> 46166 <null> 23:49:29 23:49:41
marks per second 7 7445 <null> 15269 16522 19726 <null> 8933 <null> 127 <null> 8393 12333 12588 <null> 14908 <null> 36861 100000 <null> 23:49:42 23:49:54
marks per second 8 11045 10076 13996 <null> 19330 8530 7177 <null> 61 6200 11729 7571 16170 14777 12084 10533 23075 61500 <null> 23:49:55 23:50:07
marks per second 9 13074 11900 14363 <null> 13302 <null> 11605 16328 <null> <null> 16582 <null> 15262 <null> 14694 14666 27000 29805 <null> 23:50:08 23:50:20
marks per second 10 10848 <null> 9194 <null> 23045 <null> 12495 <null> <null> <null> 30179 <null> 23503 <null> <null> 9384 38348 <null> <null> 23:50:21 23:50:33
reads/fetches*100 1 8 4 9 <null> 3 <null> 4 <null> 8 7 8 7 4 <null> 5 <null> <null> 1 <null> 23:48:24 23:48:36
reads/fetches*100 2 7 <null> 6 <null> 6 <null> 2 <null> <null> <null> 7 <null> 4 <null> 4 <null> 1 <null> <null> 23:48:37 23:48:49
reads/fetches*100 3 9 <null> 6 <null> <null> <null> 2 <null> <null> <null> 8 <null> 6 <null> 6 <null> 1 2 <null> 23:48:50 23:49:02
reads/fetches*100 4 8 6 7 <null> 5 <null> 3 2 <null> 6 8 <null> 5 <null> 6 <null> <null> <null> <null> 23:49:03 23:49:15
reads/fetches*100 5 9 6 6 <null> 6 <null> 3 <null> <null> 7 8 7 5 7 3 <null> 1 2 <null> 23:49:16 23:49:28
reads/fetches*100 6 9 7 6 <null> 4 <null> 3 <null> 10 <null> 9 <null> 5 5 4 <null> <null> 2 <null> 23:49:29 23:49:41
reads/fetches*100 7 10 <null> 4 2 4 <null> 1 <null> 6 <null> 10 9 4 <null> 5 <null> 1 1 <null> 23:49:42 23:49:54
reads/fetches*100 8 9 7 6 <null> 3 4 2 <null> 9 9 11 9 5 6 4 8 1 1 <null> 23:49:55 23:50:07
reads/fetches*100 9 9 7 4 <null> 5 <null> 2 3 <null> <null> 8 <null> 6 <null> 4 5 1 1 <null> 23:50:08 23:50:20
reads/fetches*100 10 11 <null> 7 <null> 4 <null> 2 <null> <null> <null> 8 <null> 5 <null> <null> 8 1 <null> <null> 23:50:21 23:50:33
writes/marks*100 1 8 13 5 <null> 3 <null> 1 <null> 9 6 8 7 0 <null> 0 <null> <null> 0 <null> 23:48:24 23:48:36
writes/marks*100 2 8 <null> 6 <null> 5 <null> 1 <null> <null> <null> 7 <null> 0 <null> 0 <null> 6 <null> <null> 23:48:37 23:48:49
writes/marks*100 3 9 <null> 5 <null> <null> <null> 1 <null> <null> <null> 7 <null> 0 <null> 1 <null> 7 0 <null> 23:48:50 23:49:02
writes/marks*100 4 6 13 7 <null> 4 <null> 2 1 <null> 6 5 <null> 0 <null> 0 <null> <null> <null> <null> 23:49:03 23:49:15
writes/marks*100 5 7 12 8 <null> 6 <null> 1 <null> <null> 7 6 6 0 0 0 <null> 5 0 <null> 23:49:16 23:49:28
writes/marks*100 6 9 14 7 <null> 7 <null> 2 <null> 7 <null> 6 <null> 0 0 0 <null> <null> 0 <null> 23:49:29 23:49:41
writes/marks*100 7 9 <null> 6 1 4 <null> 1 <null> 18 <null> 7 8 0 <null> 0 <null> 4 0 <null> 23:49:42 23:49:54
writes/marks*100 8 8 10 3 <null> 4 1 1 <null> 11 8 6 10 0 0 0 0 7 0 <null> 23:49:55 23:50:07
writes/marks*100 9 9 12 5 <null> 7 <null> 2 1 <null> <null> 6 <null> 0 <null> 0 0 8 0 <null> 23:50:08 23:50:20
writes/marks*100 10 6 <null> 5 <null> 6 <null> 2 <null> <null> <null> 6 <null> 0 <null> <null> 0 11 <null> <null> 23:50:21 23:50:33
Done for 23340 ms, from 23:51:08,64 to 23:51:31,98.

Performance in DETAILS:

UNIT CNT_ALL CNT_OK CNT_ERR ERR_PRC OK_MIN_MS OK_MAX_MS OK_AVG_MS CNT_LK_CONFL JOB_BEG JOB_END
doc_list_aiud 29783 26796 2987 10.02 0 141 3 2987 2016-03-09 23:48 2016-03-09 23:50
doc_list_biud 29814 26796 3018 10.12 0 187 1 3018 2016-03-09 23:48 2016-03-09 23:50
sp_add_invoice_to_stock 381 242 139 36.48 46 5616 1776 139 2016-03-09 23:48 2016-03-09 23:50
sp_cancel_adding_invoice 60 25 35 58.33 47 1326 347 35 2016-03-09 23:48 2016-03-09 23:50
sp_cancel_client_order 132 112 20 15.15 0 47 19 20 2016-03-09 23:48 2016-03-09 23:50
sp_cancel_customer_reserve 3756 920 2836 75.50 0 62 10 2836 2016-03-09 23:48 2016-03-09 23:50
sp_cancel_pay_from_customer 49 49 0 0.00 0 32 11 0 2016-03-09 23:48 2016-03-09 23:50
sp_cancel_pay_to_supplier 36 34 2 5.55 0 46 13 2 2016-03-09 23:48 2016-03-09 23:50
sp_cancel_supplier_invoice 103 49 54 52.42 16 234 62 54 2016-03-09 23:48 2016-03-09 23:50
sp_cancel_supplier_order 26 8 18 69.23 46 4227 805 18 2016-03-09 23:48 2016-03-09 23:50
sp_cancel_write_off 255 162 93 36.47 0 94 17 93 2016-03-09 23:48 2016-03-09 23:50
sp_client_order 1525 1525 0 0.00 0 312 47 0 2016-03-09 23:48 2016-03-09 23:50
sp_customer_reserve 20074 20074 0 0.00 0 1950 20 0 2016-03-09 23:48 2016-03-09 23:50
sp_fill_shopping_cart 2295 2295 0 0.00 0 640 11 0 2016-03-09 23:48 2016-03-09 23:50
sp_fill_shopping_cart_clo_res 20074 20074 0 0.00 0 47 2 0 2016-03-09 23:48 2016-03-09 23:50
sp_get_clo_for_invoice 242 242 0 0.00 0 359 44 0 2016-03-09 23:48 2016-03-09 23:50
sp_kill_cost_storno 385 270 115 29.87 0 47 3 115 2016-03-09 23:48 2016-03-09 23:50
sp_kill_qstorno_ret_qs2qd 7852 2059 5793 73.77 0 187 4 5793 2016-03-09 23:48 2016-03-09 23:50
sp_kill_qty_storno 5237 2226 3011 57.49 0 187 11 3011 2016-03-09 23:48 2016-03-09 23:50
sp_lock_selected_doc 1556 1330 226 14.52 0 16 0 226 2016-03-09 23:48 2016-03-09 23:50
sp_make_cost_storno 1937 1937 0 0.00 0 94 6 0 2016-03-09 23:48 2016-03-09 23:50
sp_multiply_rows_for_pdistr 1937 1937 0 0.00 0 78 5 0 2016-03-09 23:48 2016-03-09 23:50
sp_multiply_rows_for_qdistr 1525 1525 0 0.00 0 250 20 0 2016-03-09 23:48 2016-03-09 23:50
sp_pay_from_customer 531 531 0 0.00 0 281 25 0 2016-03-09 23:48 2016-03-09 23:50
sp_pay_to_supplier 456 456 0 0.00 0 296 27 0 2016-03-09 23:48 2016-03-09 23:50
sp_payment_common 987 987 0 0.00 0 32 5 0 2016-03-09 23:48 2016-03-09 23:50
sp_qd_handle_on_cancel_clo 132 112 20 15.15 0 32 7 20 2016-03-09 23:48 2016-03-09 23:50
sp_qd_handle_on_invoice_upd_sts 297 267 30 10.10 0 156 40 30 2016-03-09 23:48 2016-03-09 23:50
sp_qd_handle_on_reserve_upd_sts 708 708 0 0.00 0 31 3 0 2016-03-09 23:48 2016-03-09 23:50
sp_reserve_write_off 729 708 21 2.88 0 125 24 21 2016-03-09 23:48 2016-03-09 23:50
sp_supplier_invoice 369 369 0 0.00 15 780 186 0 2016-03-09 23:48 2016-03-09 23:50
sp_supplier_order 401 401 0 0.00 15 561 173 0 2016-03-09 23:48 2016-03-09 23:50
srv_find_qd_qs_mism 16961 13976 2985 17.59 0 94 3 2985 2016-03-09 23:48 2016-03-09 23:50
srv_make_invnt_saldo 136 136 0 0.00 0 562 77 0 2016-03-09 23:48 2016-03-09 23:50
srv_make_money_saldo 109 109 0 0.00 0 16 2 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-abend:sp_add_invoice_to_stock 139 139 0 0.00 0 32 6 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-abend:sp_cancel_adding_invoice 32 32 0 0.00 0 141 43 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-abend:sp_cancel_client_order 20 20 0 0.00 0 16 7 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-abend:sp_cancel_customer_reserve 1 1 0 0.00 0 0 0 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-abend:sp_cancel_pay_to_supplier 2 2 0 0.00 0 16 8 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-abend:sp_cancel_supplier_invoice 13 13 0 0.00 0 31 7 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-abend:sp_cancel_supplier_order 327 327 0 0.00 0 110 22 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-abend:sp_cancel_write_off 2 2 0 0.00 0 15 7 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-abend:sp_reserve_write_off 21 21 0 0.00 0 16 4 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-norm:sp_add_invoice_to_stock 242 242 0 0.00 0 1716 300 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-norm:sp_cancel_adding_invoice 20 20 0 0.00 15 453 143 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-norm:sp_cancel_client_order 112 112 0 0.00 0 32 10 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-norm:sp_cancel_customer_reserve 52 52 0 0.00 0 32 10 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-norm:sp_cancel_pay_from_customer 49 49 0 0.00 0 31 7 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-norm:sp_cancel_pay_to_supplier 34 34 0 0.00 0 46 7 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-norm:sp_cancel_supplier_invoice 17 17 0 0.00 0 31 7 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-norm:sp_cancel_supplier_order 8 8 0 0.00 0 562 93 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-norm:sp_cancel_write_off 88 88 0 0.00 0 62 10 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-norm:sp_client_order 1525 1525 0 0.00 0 94 12 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-norm:sp_customer_reserve 75 75 0 0.00 0 47 6 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-norm:sp_pay_from_customer 531 531 0 0.00 0 62 9 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-norm:sp_pay_to_supplier 456 456 0 0.00 0 63 10 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-norm:sp_reserve_write_off 708 708 0 0.00 0 62 11 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-norm:sp_supplier_invoice 369 369 0 0.00 0 62 12 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-norm:sp_supplier_order 401 401 0 0.00 0 62 13 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-norm:srv_make_invnt_saldo 136 136 0 0.00 0 16 3 0 2016-03-09 23:48 2016-03-09 23:50
t$perf-norm:srv_make_money_saldo 109 109 0 0.00 0 31 3 0 2016-03-09 23:48 2016-03-09 23:50
v_add_invoice_to_stock 762 484 278 36.48 0 16 0 278 2016-03-09 23:48 2016-03-09 23:50
v_all_customers 2330 2330 0 0.00 0 16 0 0 2016-03-09 23:48 2016-03-09 23:50
v_all_suppliers 1652 1652 0 0.00 0 16 0 0 2016-03-09 23:48 2016-03-09 23:50
v_all_wares 3050 3050 0 0.00 0 16 0 0 2016-03-09 23:48 2016-03-09 23:50
v_cancel_adding_invoice 60 40 20 33.33 0 16 1 20 2016-03-09 23:48 2016-03-09 23:50
v_cancel_client_order 264 224 40 15.15 0 16 0 40 2016-03-09 23:48 2016-03-09 23:50
v_cancel_customer_prepayment 98 98 0 0.00 0 16 0 0 2016-03-09 23:48 2016-03-09 23:50
v_cancel_customer_reserve 106 104 2 1.88 0 16 1 2 2016-03-09 23:48 2016-03-09 23:50
v_cancel_payment_to_supplier 72 68 4 5.55 0 16 1 4 2016-03-09 23:48 2016-03-09 23:50
v_cancel_supplier_invoice 60 34 26 43.33 0 16 1 26 2016-03-09 23:48 2016-03-09 23:50
v_cancel_supplier_order 52 16 36 69.23 0 0 0 36 2016-03-09 23:48 2016-03-09 23:50
v_cancel_write_off 180 176 4 2.22 0 16 2 4 2016-03-09 23:48 2016-03-09 23:50
v_max_id_clo_ord 401 401 0 0.00 0 16 0 0 2016-03-09 23:48 2016-03-09 23:50
v_max_id_clo_res 75 75 0 0.00 312 1935 677 0 2016-03-09 23:48 2016-03-09 23:50
v_max_id_ord_sup 369 369 0 0.00 0 16 1 0 2016-03-09 23:48 2016-03-09 23:50
v_max_non_paid_invoice 400 400 0 0.00 0 16 1 0 2016-03-09 23:48 2016-03-09 23:50
v_max_non_paid_realizn 531 531 0 0.00 0 31 1 0 2016-03-09 23:48 2016-03-09 23:50
v_min_id_clo_ord 401 401 0 0.00 0 31 2 0 2016-03-09 23:48 2016-03-09 23:50
v_min_id_clo_res 75 75 0 0.00 0 16 2 0 2016-03-09 23:48 2016-03-09 23:50
v_min_id_ord_sup 369 369 0 0.00 0 31 2 0 2016-03-09 23:48 2016-03-09 23:50
v_min_non_paid_invoice 456 456 0 0.00 0 31 3 0 2016-03-09 23:48 2016-03-09 23:50
v_min_non_paid_realizn 531 531 0 0.00 0 16 1 0 2016-03-09 23:48 2016-03-09 23:50
v_our_firm 720 720 0 0.00 0 16 0 0 2016-03-09 23:48 2016-03-09 23:50
v_reserve_write_off 1458 1416 42 2.88 0 16 1 42 2016-03-09 23:48 2016-03-09 23:50
x_lock_depdocs_on_canc_invoice 215 57 158 73.48 0 16 1 158 2016-03-09 23:48 2016-03-09 23:50
x_lock_depdocs_on_canc_sup_ord 26 8 18 69.23 0 16 4 18 2016-03-09 23:48 2016-03-09 23:50
x_make_qstorno_1000_1200 401 401 0 0.00 0 515 143 0 2016-03-09 23:48 2016-03-09 23:50
x_make_qstorno_1200_2000 369 369 0 0.00 0 733 152 0 2016-03-09 23:48 2016-03-09 23:50
x_make_qstorno_2100_3300 20074 20074 0 0.00 0 218 13 0 2016-03-09 23:48 2016-03-09 23:50
Done for 28590 ms, from 23:51:35,15 to 23:52:03,74.

Config param. mon_unit_perf=0, data from MON$ tables were NOT gathered.

Exceptions occured during test work:

FB_MNEMONA CNT UNIT FB_GDSCODE DTS_BEG DTS_END
deadlock 1 sp_kill_cost_storno 335544336 2016-03-09 23:50 2016-03-09 23:50
deadlock 4 sp_lock_selected_doc 335544336 2016-03-09 23:48 2016-03-09 23:49
deadlock 5 sp_qd_handle_on_invoice_upd_sts 335544336 2016-03-09 23:48 2016-03-09 23:50
deadlock 1 x_lock_depdocs_on_canc_invoice 335544336 2016-03-09 23:49 2016-03-09 23:49
lock_conflict 2 sp_kill_cost_storno 335544345 2016-03-09 23:49 2016-03-09 23:50
lock_conflict 173 sp_lock_selected_doc 335544345 2016-03-09 23:48 2016-03-09 23:50
lock_conflict 20 sp_qd_handle_on_cancel_clo 335544345 2016-03-09 23:48 2016-03-09 23:50
lock_conflict 4 sp_qd_handle_on_invoice_upd_sts 335544345 2016-03-09 23:48 2016-03-09 23:50
lock_conflict 11 x_lock_depdocs_on_canc_invoice 335544345 2016-03-09 23:48 2016-03-09 23:50
lock_conflict 5 x_lock_depdocs_on_canc_sup_ord 335544345 2016-03-09 23:48 2016-03-09 23:50
Done for 3620 ms, from 23:52:04,30 to 23:52:07,92.

MON$DATABASE and FB VERSION info

MON$DATABASE_NAME D:\IBSURGEON\OLTP25.FDB
MON$PAGE_SIZE 8192
MON$ODS_MAJOR 11
MON$ODS_MINOR 2
MON$OLDEST_TRANSACTION 12183
MON$OLDEST_ACTIVE 12184
MON$OLDEST_SNAPSHOT 12184
MON$NEXT_TRANSACTION 12184
MON$PAGE_BUFFERS 384
MON$SQL_DIALECT 3
MON$SHUTDOWN_MODE 0
MON$SWEEP_INTERVAL 20001
MON$READ_ONLY 0
MON$FORCED_WRITES 1
MON$RESERVE_SPACE 1
MON$CREATION_DATE 2016-03-09 21:29:19.7300
MON$PAGES 24980
MON$STAT_ID 1
MON$BACKUP_STATE 0
ISQL Version: WI-V2.5.3.26780 Firebird 2.5
Server version:
Firebird/x86-64/Windows NT (access method), version "WI-V2.5.3.26780 Firebird 2.5"
Firebird/x86-64/Windows NT (remote server), version "WI-V2.5.3.26780 Firebird 2.5/tcp (DB-TEST)/P12"
Firebird/x86-64/Windows NT (remote interface), version "WI-V2.5.3.26780 Firebird 2.5/tcp (DB-TEST)/P12"
on disk structure version 11.2

Database statistics was not gathered, see config parameter 'run_db_statistics'.

Database validation was not performed, see config parameter 'run_db_validation'.

Differences between old and current firebird.log

23:52:09,05. Got:
STDOUT: ---------- E:\TEMP\LOGS.OLTP25\OLTP25_FB_LOG_WHEN_TEST_FINISHED.LOG: 15 (number of rows in extracted log)
Obtained firebird.log info:
Result of DIR command for firebird.log AFTER test finish:
09.03.2016 23:52 454 oltp25_fb_log_when_test_finished.log

End of gathering firebird.log AFTER test finish.

Comparison of old and new firebird.log (get messages that appeared during test):

+++ Start of comparison +++
result: files match. No new messages appeared in firebird.log during test ran.
+++ End of comparison +++

Final processing ISQL logs in E:\temp\logs.oltp25


Remove 32 logs of every ISQL session if there were no serious errors.

Remove logs of every ISQL session if there were no serious errors, pattern: E:\temp\logs.oltp25\oltp25_*.*:

ERRORS_CHECKING_RESULT
NO_SEVERE_ERRORS_FOUND
ISQL logs are removed because no severe errors occured during test.
09.03.2016 23:52:11,39 - end of report, text file: E:\temp\logs.oltp25\oltp25.report.txt, html: E:\temp\logs.oltp25\oltp25.report.html