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
Test configuration Test Finish details Test workload details Indices DDL for heavy-loaded table(s)	Performance, TOTAL score Performance, DYNAMIC, 10 intervals Performance, per MINUTE, since launch Performance, TRACE data for ISQL #1 Performance, DETAILS per units MON$-analysis, per business units Exceptions during test run	mon$database and 'show version' results Database Statistics, full Ratio "Versions / Records" for tables Database Validation Results New in firebird.log while test was run 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