Generated by /opt/oltp-emul/oltp_isql_run_worker.sh, ISQL session No. 1 of total launched 100. 09.10.2020 21:57
Common Performance Final Results
  1. Hardware and OS info
  2. DB and test configuration
  3. Test Finish details
  4. Test workload details
  5. Indices DDL for heavy-loaded table(s)
  1. Performance, TOTAL score:    as table     as chart
  2. Performance per MINUTE, during test_time phase:    as table     as chart
  3. Performance, DETAILS per units
  4. Memory consumption, metadata cache, attachments activity    as table    as chart
  5. Monitoring data: STATEMENTS activity, as chart
  6. 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

Hardware and OS info

Command: hostnamectl
Static hostname mscs-test-161.budzdorov.ru
Icon name computer-server
Chassis server
Machine ID aeee285d2cca40bf84c40a748f599e77
Boot ID e0e7b46250ba4f9795ceb55e0face73f
Operating System CentOS Linux 7 (Core)
CPE OS Name cpe:/o:centos:centos:7
Kernel Linux 3.10.0-1127.10.1.el7.x86_64
Architecture x86-64
Command: who -b
bootup_info system boot 2020-09-25 13:42
Command: dmidecode -t system|grep -i -e 'manufacturer\|product\|hypervisor'
./oltp_isql_run_worker.sh line 45: dmidecode: command not found
Command: dmesg | grep DMI
[ 0.000000] DMI HP ProLiant DL380 Gen9/ProLiant DL380 Gen9, BIOS P89 05/21/2018
Command: lscpu | grep -i -v flags
Architecture x86_64
CPU op-mode(s) 32-bit, 64-bit
Byte Order Little Endian
CPU(s) 24
On-line CPU(s) list 0-23
Thread(s) per core 2
Core(s) per socket 6
Socket(s) 2
NUMA node(s) 2
Vendor ID GenuineIntel
CPU family 6
Model 63
Model name Intel(R) Xeon(R) CPU E5-2620 v3 @ 2.40GHz
Stepping 2
CPU MHz 1200.000
CPU max MHz 2400.0000
CPU min MHz 1200.0000
BogoMIPS 4794.00
Virtualization VT-x
L1d cache 32K
L1i cache 32K
L2 cache 256K
L3 cache 15360K
NUMA node0 CPU(s) 0-5,12-17
NUMA node1 CPU(s) 6-11,18-23
Command: cat /proc/meminfo | grep -i -e 'memtotal\|memfree\|memavail\|buffers\|cached\|swapcached'
MemTotal 32643792 kB
MemFree 17382988 kB
MemAvailable 31620356 kB
Buffers 12 kB
Cached 14282404 kB
SwapCached 6236 kB
Command: fdisk -l
./oltp_isql_run_worker.sh: line 45: fdisk: command not found

Server and database settinfs

SERVER_MODE                     SuperServer 3.0.7
DB_NAME                         /home/bases/oltp30-etalone.fdb
FORCED_WRITES                   ON
SWEEP_INT                       0
PAGE_BUFFERS                    1000000
PAGE_SIZE                       8192


Test configuration settings

param=actions_todo_before_reconnect, val=300
param=create_with_compound_columns_order, val=most_selective_first
param=create_with_debug_objects, val=1
param=create_with_fw, val=sync
param=create_with_separate_qdistr_idx, val=0
param=create_with_split_heavy_tabs, val=1
param=create_with_sweep, val=0
param=dbnm, val=/home/bases/oltp30-etalone.fdb
param=detailed_info, val=0
param=etalon_dbnm, val=/home/bases/oltp30-etalone.fd0
param=expected_workers, val=100
param=fbc, val=/opt/fb30/bin
param=file_name_this_host_info, val=bz_cpu24_ram32
param=file_name_with_test_params, val=regular
param=gather_hardware_info, val=1
param=halt_test_on_errors, val=/CK/
param=host, val=localhost
param=init_buff, val=10000
param=init_docs, val=0
param=is_embed, val=0
param=make_html, val=1
param=max_cps, val=25
param=mon_query_interval, val=60
param=mon_query_role, val=tmp$oemul$worker
param=mon_unit_list, val=//
param=mon_unit_perf, val=2
param=mon_usr_prefix, val=tmp$oemul$user_
param=no_auto_undo, val=1
param=port, val=3333
param=pwd, val=masterkey
param=qmism_verify_bitset, val=1
param=recalc_idx_min_interval, val=30
param=remove_isql_logs, val=if_no_severe_errors
param=replace_instance, val=1
param=report_compress_cmd, val=/usr/bin/7za
param=results_storage_fbk, val=/home/bases/oltp30-results-storage.fbk
param=run_db_statistics, val=0
param=run_db_validation, val=0
param=separate_workers, val=1
param=sleep_ddl, val=./oltp_sleepUDF_nix.sql
param=sleep_max, val=0
param=test_intervals, val=60
param=test_time, val=120
param=tmpdir, val=/var/tmp/logs-oltp30
param=unit_selection_method, val=random
param=update_conflict_percent, val=0
param=used_in_replication, val=0
param=use_mtee, val=0
param=usr, val=SYSDBA
param=wait_after_create, val=0
param=wait_for_copy, val=1
param=wait_if_not_exists, val=0
param=warm_time, val=30
param=working_mode, val=small_03
Custom name of interactive SQL utility: parameter: 'clu', value: |isql|

Test finish info

FINISH_STATE                    NORMAL: TEST_TIME EXPIRED AT 2020-10-09 21:56:59
DTS_END                         2020-10-09 21:56:59.8400
FB_GDSCODE                      -1
FB_MNEMONA                      
STACK                           SP_ADD_INVOICE_TO_STOCK(190:30) ==> SP_CUSTOMER_RESERVE(47:5) ==> SP_CHECK_TO_STOP_WORK(32:12) ==> SP_HALT_ON_ERROR(56:17)
IP                              ::1/53218
TRN_ID                          253189
ATT_ID                          694
EXC_UNIT                        2


Test workload details

SETTING_NAME SETTING_VALUE
WORKING_MODE SMALL_03
C_WARES_MAX_ID 400
C_CUSTOMER_DOC_MAX_ROWS 10
C_SUPPLIER_DOC_MAX_ROWS 50
C_CUSTOMER_DOC_MAX_QTY 15
C_SUPPLIER_DOC_MAX_QTY 50
C_NUMBER_OF_AGENTS 50

Indexes for heavy-loaded tables

TAB_NAME IDX_NAME IDX_KEY
XQD_1000_1200 XQD_1000_1200_WA_SO_RO_WKR_SND WARE_ID,SND_OPTYPE_ID,RCV_OPTYPE_ID,WORKER_ID,SND_ID
XQD_1000_3300 XQD_1000_3300_WA_SO_RO_WKR_SND WARE_ID,SND_OPTYPE_ID,RCV_OPTYPE_ID,WORKER_ID,SND_ID
XQD_1000_3300 XQD_1000_3300_WKR_DOC_ASC WORKER_ID,DOC_ID
XQD_1000_3300 XQD_1000_3300_WKR_DOC_DEC WORKER_ID,DOC_ID
XQD_1200_2000 XQD_1200_2000_WA_SO_RO_WKR_SND WARE_ID,SND_OPTYPE_ID,RCV_OPTYPE_ID,WORKER_ID,SND_ID
XQD_2000_3300 XQD_2000_3300_WA_SO_RO_WKR_SND WARE_ID,SND_OPTYPE_ID,RCV_OPTYPE_ID,WORKER_ID,SND_ID
XQD_2100_3300 XQD_2100_3300_WA_SO_RO_WKR_SND WARE_ID,SND_OPTYPE_ID,RCV_OPTYPE_ID,WORKER_ID,SND_ID
XQD_3300_3400 XQD_3300_3400_WA_SO_RO_WKR_SND WARE_ID,SND_OPTYPE_ID,RCV_OPTYPE_ID,WORKER_ID,SND_ID

Performance in TOTAL

ACTION AVG_TIMES_PER_MINUTE AVG_ELAPSED_MS SUCCESSFUL_TIMES_DONE
*** OVERALL *** for 120 minutes: 9663.51 19755 1159621
customer order: creation 179.54 337 21545
customer order: refuse 15.41 283 1849
order to supplier: creation 48.78 1084 5853
order to supplier: removal 3.67 86194 440
invoice (draft): creation 48.08 3157 5770
invoice (draft): removal 55.26 673 6631
invoice accept: apply 42.73 15645 5127
invoice accept: cancel 50.36 625 6043
customer reserve: creation 3954.09 155 474491
customer reserve: removal 4946.70 50 593604
realization accept: apply 86.62 150 10394
realization accept: cancel 98.08 93 11770
payment from customer: creation 61.12 102 7334
payment from customer: removal 5.78 51 694
payment to supplier: creation 51.14 108 6137
payment to supplier: removal 3.55 64 426
service: total inventory turnovers 5.27 950 632
service: total monetary turnovers 6.39 19 767
service: aggregate perf. data 0.92 18323 110
service: refresh index statistics 0.03 267030 4

Performance in TOTAL, chart


Completed "Performance in TOTAL". Done for 00:00:02, from 09-10-2020 21:58:08 to 09-10-2020 21:58:10.

Performance for every MINUTE

TEST_PHASE_NAME MINUTES_PASSED PERF_SCORE
TEST_TIME 1 234
TEST_TIME 2 1635
TEST_TIME 3 2816
TEST_TIME 4 3894
TEST_TIME 5 5214
TEST_TIME 6 5402
TEST_TIME 7 5554
TEST_TIME 8 5498
TEST_TIME 9 6406
TEST_TIME 10 6403
TEST_TIME 11 6686
TEST_TIME 12 6728
TEST_TIME 13 6960
TEST_TIME 14 7207
TEST_TIME 15 7382
TEST_TIME 16 7927
TEST_TIME 17 8287
TEST_TIME 18 8427
TEST_TIME 19 8959
TEST_TIME 20 9462
TEST_TIME 21 9502
TEST_TIME 22 10352
TEST_TIME 23 10632
TEST_TIME 24 11302
TEST_TIME 25 11161
TEST_TIME 26 11495
TEST_TIME 27 11399
TEST_TIME 28 11322
TEST_TIME 29 11234
TEST_TIME 30 11392
TEST_TIME 31 11421
TEST_TIME 32 11417
TEST_TIME 33 11390
TEST_TIME 34 11382
TEST_TIME 35 11199
TEST_TIME 36 11014
TEST_TIME 37 10955
TEST_TIME 38 10784
TEST_TIME 39 10755
TEST_TIME 40 10632
TEST_TIME 41 10628
TEST_TIME 42 10533
TEST_TIME 43 10550
TEST_TIME 44 10462
TEST_TIME 45 10375
TEST_TIME 46 10416
TEST_TIME 47 10486
TEST_TIME 48 10372
TEST_TIME 49 10279
TEST_TIME 50 10167
TEST_TIME 51 10114
TEST_TIME 52 10074
TEST_TIME 53 10017
TEST_TIME 54 9992
TEST_TIME 55 10062
TEST_TIME 56 10183
TEST_TIME 57 10159
TEST_TIME 58 10160
TEST_TIME 59 10156
TEST_TIME 60 10165
TEST_TIME 61 10215
TEST_TIME 62 10324
TEST_TIME 63 10320
TEST_TIME 64 10302
TEST_TIME 65 10381
TEST_TIME 66 10248
TEST_TIME 67 10167
TEST_TIME 68 10135
TEST_TIME 69 10057
TEST_TIME 70 10107
TEST_TIME 71 10021
TEST_TIME 72 9999
TEST_TIME 73 9954
TEST_TIME 74 9922
TEST_TIME 75 9895
TEST_TIME 76 9927
TEST_TIME 77 9880
TEST_TIME 78 9938
TEST_TIME 79 9930
TEST_TIME 80 9963
TEST_TIME 81 10026
TEST_TIME 82 9966
TEST_TIME 83 10002
TEST_TIME 84 10007
TEST_TIME 85 10048
TEST_TIME 86 10056
TEST_TIME 87 10114
TEST_TIME 88 10061
TEST_TIME 89 9990
TEST_TIME 90 9965
TEST_TIME 91 9937
TEST_TIME 92 9883
TEST_TIME 93 9862
TEST_TIME 94 9818
TEST_TIME 95 9839
TEST_TIME 96 9825
TEST_TIME 97 9830
TEST_TIME 98 9823
TEST_TIME 99 9888
TEST_TIME 100 9860
TEST_TIME 101 9942
TEST_TIME 102 9919
TEST_TIME 103 9913
TEST_TIME 104 9912
TEST_TIME 105 9937
TEST_TIME 106 9888
TEST_TIME 107 9937
TEST_TIME 108 9914
TEST_TIME 109 9890
TEST_TIME 110 9846
TEST_TIME 111 9786
TEST_TIME 112 9777
TEST_TIME 113 9774
TEST_TIME 114 9724
TEST_TIME 115 9683
TEST_TIME 116 9660
TEST_TIME 117 9674
TEST_TIME 118 9634
TEST_TIME 119 9658
TEST_TIME 120 9664

Performance per minute, chart


Completed "Performance for every MINUTE". Done for 00:00:03, from 09-10-2020 21:58:12 to 09-10-2020 21:58:15.

Performance in DETAILS

UNIT CNT_ALL CNT_OK CNT_ERR ERR_PRC OK_MIN_MS OK_MAX_MS OK_AVG_MS CNT_LK_CONFL CNT_USER_EXC
doc_list_aiud 1600813 1600813 0 0.00 0 17738 5 0 0
doc_list_biud 1600813 1600813 0 0.00 0 56197 23 0 0
sp_add_invoice_to_stock 5274 5127 147 2.78 49 148608 15646 0 147
sp_cancel_adding_invoice 6043 6043 0 0.00 4 59606 625 0 0
sp_cancel_client_order 1849 1849 0 0.00 3 16928 283 0 0
sp_cancel_customer_reserve 593604 593604 0 0.00 1 56310 50 0 0
sp_cancel_pay_from_customer 694 694 0 0.00 3 3750 52 0 0
sp_cancel_pay_to_supplier 426 426 0 0.00 3 2784 65 0 0
sp_cancel_supplier_invoice 6637 6631 6 0.09 2 14994 673 0 6
sp_cancel_supplier_order 440 440 0 0.00 5 1028874 86194 0 0
sp_cancel_write_off 11770 11770 0 0.00 1 12108 94 0 0
sp_client_order 21545 21545 0 0.00 3 29186 338 0 0
sp_customer_reserve 474491 474491 0 0.00 0 71181 155 0 0
sp_fill_shopping_cart 33155 33155 0 0.00 1 20328 33 0 0
sp_fill_shopping_cart_clo_res 474491 474491 0 0.00 0 27856 13 0 0
sp_get_clo_for_invoice 5127 5127 0 0.00 0 40396 311 0 0
sp_kill_cost_storno 18933 18933 0 0.00 0 7218 46 0 0
sp_kill_qstorno_ret_qs2qd 1206049 1206049 0 0.00 0 56191 27 0 0
sp_kill_qty_storno 635858 635858 0 0.00 0 56197 58 0 0
sp_lock_selected_doc 21523 21523 0 0.00 0 9155 6 0 0
sp_make_cost_storno 28992 28992 0 0.00 0 17726 43 0 0
sp_multiply_rows_for_pdistr 28992 28992 0 0.00 0 6406 23 0 0
sp_multiply_rows_for_qdistr 21545 21545 0 0.00 0 29177 174 0 0
sp_pay_from_customer 7334 7334 0 0.00 4 19971 102 0 0
sp_pay_to_supplier 6137 6137 0 0.00 4 13833 109 0 0
sp_payment_common 13471 13471 0 0.00 1 19957 29 0 0
sp_qd_handle_on_cancel_clo 1849 1849 0 0.00 0 16915 250 0 0
sp_qd_handle_on_invoice_upd_sts 11170 11170 0 0.00 0 26409 254 0 0
sp_qd_handle_on_reserve_upd_sts 10394 10394 0 0.00 0 15239 51 0 0
sp_reserve_write_off 10394 10394 0 0.00 6 15452 151 0 0
sp_supplier_invoice 5770 5770 0 0.00 6 94452 3158 0 0
sp_supplier_order 5853 5853 0 0.00 5 32502 1084 0 0
srv_aggregate_perf_data 110 110 0 0.00 2853 147416 18324 0 0
srv_fill_mon_cache_memory 62 62 0 0.00 2931 186882 48934 0 0
srv_find_qd_qs_mism 1111044 1111044 0 0.00 0 12260 4 0 0
srv_make_invnt_saldo 632 632 0 0.00 34 31478 950 0 0
srv_make_money_saldo 767 767 0 0.00 1 571 20 0 0
srv_recalc_idx_stat 4 4 0 0.00 168926 373880 267030 0 0
t$perf-abend:sp_add_invoice_to_stock 147 147 0 0.00 0 0 0 0 0
t$perf-abend:sp_cancel_supplier_invoice 6 6 0 0.00 0 0 0 0 0
t$perf-norm:sp_add_invoice_to_stock 5127 5127 0 0.00 0 21745 163 0 0
t$perf-norm:sp_cancel_adding_invoice 429 429 0 0.00 0 6496 107 0 0
t$perf-norm:sp_cancel_client_order 1849 1849 0 0.00 0 10563 23 0 0
t$perf-norm:sp_cancel_customer_reserve 693 693 0 0.00 0 5331 17 0 0
t$perf-norm:sp_cancel_pay_from_customer 694 694 0 0.00 0 1555 5 0 0
t$perf-norm:sp_cancel_pay_to_supplier 426 426 0 0.00 0 251 3 0 0
t$perf-norm:sp_cancel_supplier_invoice 425 425 0 0.00 0 2872 14 0 0
t$perf-norm:sp_cancel_supplier_order 440 440 0 0.00 0 22661 1553 0 0
t$perf-norm:sp_cancel_write_off 1046 1046 0 0.00 0 1659 7 0 0
t$perf-norm:sp_client_order 21545 21545 0 0.00 0 13830 19 0 0
t$perf-norm:sp_customer_reserve 1065 1065 0 0.00 0 418 3 0 0
t$perf-norm:sp_pay_from_customer 7334 7334 0 0.00 0 14787 14 0 0
t$perf-norm:sp_pay_to_supplier 6137 6137 0 0.00 0 7065 10 0 0
t$perf-norm:sp_reserve_write_off 10394 10394 0 0.00 0 14502 12 0 0
t$perf-norm:sp_supplier_invoice 5770 5770 0 0.00 0 9022 16 0 0
t$perf-norm:sp_supplier_order 5853 5853 0 0.00 0 13800 14 0 0
t$perf-norm:srv_aggregate_perf_data 110 110 0 0.00 0 274 5 0 0
t$perf-norm:srv_fill_mon_cache_memory 62 62 0 0.00 0 49 1 0 0
t$perf-norm:srv_make_invnt_saldo 632 632 0 0.00 0 3695 23 0 0
t$perf-norm:srv_make_money_saldo 767 767 0 0.00 0 1095 12 0 0
t$perf-norm:srv_recalc_idx_stat 4 4 0 0.00 1 9 3 0 0
v_add_invoice_to_stock 10548 10254 294 2.78 0 4959 18 0 294
v_all_customers 39376 39376 0 0.00 0 181 1 0 0
v_all_suppliers 32274 32274 0 0.00 0 21 1 0 0
v_all_wares 43090 43090 0 0.00 0 165 1 0 0
v_cancel_adding_invoice 858 858 0 0.00 0 1252 7 0 0
v_cancel_client_order 3698 3698 0 0.00 0 4973 6 0 0
v_cancel_customer_prepayment 1388 1388 0 0.00 0 1566 5 0 0
v_cancel_customer_reserve 1386 1386 0 0.00 0 1307 4 0 0
v_cancel_payment_to_supplier 852 852 0 0.00 0 655 4 0 0
v_cancel_supplier_invoice 862 850 12 1.39 0 4952 24 0 12
v_cancel_supplier_order 880 880 0 0.00 0 1379 5 0 0
v_cancel_write_off 2092 2092 0 0.00 0 2706 12 0 0
v_max_id_clo_ord 5851 5851 0 0.00 0 1838 1 0 0
v_max_id_clo_res 1065 1065 0 0.00 0 9800 20 0 0
v_max_id_ord_sup 5757 5757 0 0.00 0 3716 3 0 0
v_max_non_paid_invoice 1608 1608 0 0.00 0 4833 8 0 0
v_max_non_paid_realizn 3764 3764 0 0.00 0 2203 4 0 0
v_min_id_clo_ord 5851 5851 0 0.00 0 1812 4 0 0
v_min_id_clo_res 1065 1065 0 0.00 0 4567 9 0 0
v_min_id_ord_sup 5757 5757 0 0.00 0 6220 7 0 0
v_min_non_paid_invoice 6137 6137 0 0.00 0 13611 17 0 0
v_min_non_paid_realizn 7334 7334 0 0.00 0 15529 19 0 0
v_our_firm 10854 10854 0 0.00 0 31 1 0 0
v_reserve_write_off 20788 20788 0 0.00 0 4979 7 0 0
x_lock_depdocs_on_canc_invoice 12249 12249 0 0.00 0 18874 105 0 0
x_lock_depdocs_on_canc_sup_ord 440 440 0 0.00 0 13495 297 0 0
x_make_qstorno_1000_1200 5853 5853 0 0.00 2 32452 1022 0 0
x_make_qstorno_1200_2000 5770 5770 0 0.00 3 94442 3035 0 0
x_make_qstorno_2100_3300 474491 474491 0 0.00 0 71178 141 0 0

Completed "Performance in DETAILS". Done for 00:00:04, from 09-10-2020 21:58:16 to 09-10-2020 21:58:20.

Memory consumption, metadata cache, attachments activity

Fields:
  page cache memo used            = page cache total size, bytes:
  memo used, total                = total of mon$memory_usage.mon$memory_used for database level (mon$stat_group = 0);
  memo allocated, total           = the same of mon$memory_usage.mon$memory_allocated;
  metadata cache memo used        = metadata cache, bytes;
  metadata cache percent of total = ratio: metadata cache / (metadata cache + page cache);
  total attachments cnt           = total number of attachments, regardless of state;
  active attachments cnt          = number of attachments with mon$state = 1;
  running statements cnt          = number of statements that are operating with data from page cache (mon$state = 1);
  stalled statements cnt          = number of statements that are waiting for client request for fetching ( mon$state = 2);
  memo used by attachments        = total of mon$memory_usage.mon$memory_used for attachment level (mon$stat_group = 1);
  memo used by transactions       = the same of transaction level (mon$stat_group = 2);
  memo used by statements         = the same of statement level (mon$stat_group = 3);


Page cache type: shared, buffers: 1000000 for all connections, with total size: 8192000000                                                                                                                                                                     

measurement_dts measurement duration ms page cache memo used memo used, total memo allocated, total metadata cache metadata cache percent of total total attachments cnt active attachments cnt running statements cnt stalled statements cnt memo used by attachments memo used by transactions memo used by statements
19:27:03 1 8192000000 8798422528 8808923136 5084624 0.062 1 1 2 0 5202672 55488 62560
19:28:04 22461 8192000000 10403261696 10726674432 1449960304 15.038 100 90 180 0 1485230768 6127744 29142720
19:29:29 3375 8192000000 10433851744 10764275712 1488930656 15.380 100 89 178 0 1526342688 8851328 28560704
19:30:44 11320 8192000000 10495889792 10839912448 1548822496 15.900 100 84 169 0 1585509984 10309232 26378256
19:32:05 11521 8192000000 10573115920 10933542912 1630604832 16.600 100 75 150 1 1664958640 11082480 23271328
19:33:27 4934 8192000000 10648027184 11017994240 1712004960 17.285 100 80 160 0 1747734240 12493712 23235568
19:34:35 3990 8192000000 10697725296 11076923392 1757741584 17.666 100 78 156 0 1793242528 13594720 21906224
19:35:40 2495 8192000000 10749109712 11139551232 1813419040 18.124 100 85 171 3 1850859504 13239296 24201168
19:36:45 1202 8192000000 10814165952 11203043328 1870218752 18.586 100 94 189 3 1909653552 13071792 26363008
19:37:47 10326 8192000000 10794689632 11209154560 1868824352 18.575 100 35 71 1 1890269424 10810240 10634832
19:38:58 10941 8192000000 10787036272 11222548480 1886887680 18.721 100 21 42 0 1898623856 6002848 5733328
19:40:09 10220 8192000000 10799311920 11238281216 1897967056 18.810 100 18 37 3 1909749264 6352272 5429936
19:41:22 12729 8192000000 10804736320 11248009216 1906246944 18.877 100 25 50 2 1919989184 6794608 6947632
19:42:35 22569 8192000000 10834844160 11264212992 1910791504 18.913 100 41 82 1 1929161120 7075680 11293936
19:43:58 5931 8192000000 10834811776 11266220032 1913415504 18.934 100 23 46 1 1927311312 6951520 6944288
19:45:04 10408 8192000000 10825365728 11256901632 1892561952 18.766 99 19 39 2 1903787968 5130544 6095472
19:46:16 32274 8192000000 10691523968 11121070080 1624642160 16.549 88 20 40 3 1636025648 4722208 6661280
19:47:49 17916 8192000000 10709164496 11129790464 1732806960 17.459 96 21 42 1 1744110736 5298992 6004784
19:49:08 5797 8192000000 10732593040 11142770688 1808582624 18.084 100 33 65 1 1824919616 6734016 9602976
19:50:18 9045 8192000000 10726298736 11151298560 1817800272 18.160 100 20 38 0 1829038672 5684864 5553536
19:51:27 9729 8192000000 10746151456 11175096320 1835508064 18.304 100 25 50 2 1849089536 5417328 8164144
19:52:38 31540 8192000000 10755017360 11184365568 1830539520 18.264 99 15 30 0 1839951520 5329264 4082736
19:54:10 4643 8192000000 10779533648 11210031104 1867555456 18.564 100 35 70 2 1884441296 6547680 10338160
19:55:17 9915 8192000000 10795959840 11222671360 1875768384 18.631 100 11 22 0 1884743184 5081648 3893152
19:56:29 24195 8192000000 10798357808 11228299264 1882210176 18.683 100 28 54 2 1897174880 6016240 8948464
19:58:14 40363 8192000000 10838347584 11267424256 1917259312 18.965 100 45 90 0 1939675936 8280704 14135920
19:59:58 6952 8192000000 10875276352 11296702464 1939978384 19.147 100 49 97 0 1964381840 10578080 13825376
20:01:10 14748 8192000000 10887300624 11321966592 1952546624 19.247 100 55 110 1 1982313712 13718336 16048752
20:02:30 9030 8192000000 10908110496 11334328320 1967995616 19.370 100 67 134 0 2004917696 16753808 20168272
20:03:45 15733 8192000000 10905052496 11339309056 1966847712 19.360 100 48 94 3 2002283776 21311856 14124208
20:05:10 13326 8192000000 10913388656 11349803008 1971492128 19.397 100 38 76 0 2006231536 21789568 12949840
20:06:31 6901 8192000000 10914274752 11340181504 1961296528 19.316 100 58 114 2 2003514656 25278832 16939296
20:07:48 3514 8192000000 10931524096 11343048704 1948189376 19.212 99 80 159 0 2001980208 29795648 23995184
20:08:55 2931 8192000000 10914861216 11329183744 1943971712 19.178 100 66 131 2 1999002688 34573760 20457216
20:10:01 5378 8192000000 10910796992 11327008768 1939353568 19.142 100 77 153 0 2002048368 38716096 23978704
20:11:10 4800 8192000000 10885286080 11295670272 1910811312 18.913 100 74 147 1 1972406544 38410896 23184336
20:12:18 8406 8192000000 10902848528 11327123456 1931506464 19.079 100 60 119 3 1992382784 42084864 18791456
20:13:31 8375 8192000000 10908163232 11345772544 1941464656 19.158 100 38 76 4 1994236304 40128736 12642912
20:14:47 6255 8192000000 10909906720 11341598720 1934661712 19.104 100 57 113 1 2003246512 49447392 19137408
20:16:24 26942 8192000000 10923731296 11365859328 1934332256 19.102 99 32 63 1 2005115472 59500688 11282528
20:18:27 20345 8192000000 10869566592 11335921664 1906314208 18.877 100 25 49 0 1967551200 52736512 8500480
20:20:02 57484 8192000000 10858379088 11320512512 1902481600 18.846 99 10 20 1 1933052176 27050256 3520320
20:22:00 93780 8192000000 10842838304 11298373632 1867340464 18.563 97 11 22 1 1886981840 16514448 3126928
20:24:36 76111 8192000000 10889671472 11344764928 1932698464 19.088 100 15 30 0 1952324928 14713664 4912800
20:26:57 186882 8192000000 10894325712 11357073408 1855867280 18.470 95 15 30 0 1877028640 17661408 3499952
20:31:05 107059 8192000000 10903249648 11364904960 1965836752 19.352 100 13 26 1 1983187472 13667600 3683120
20:33:52 83666 8192000000 10917231184 11381989376 1985351152 19.507 100 27 54 0 2003942560 11352272 7239136
20:36:17 34495 8192000000 10934743216 11377876992 1966765312 19.360 99 52 106 0 1994864160 12124944 15973904
20:37:53 80542 8192000000 10915675072 11394215936 1970537792 19.390 99 22 44 2 1991017072 14057968 6421312
20:40:15 37053 8192000000 10923792576 11400802304 1992245776 19.562 100 17 34 2 2016518944 19242752 5030416
20:41:53 84875 8192000000 10909968592 11394433024 1962215200 19.324 98 16 32 0 1990243504 22921536 5106768
20:44:18 21891 8192000000 10910505680 11377991680 1986563456 19.517 100 41 85 3 2004856976 6291680 12001840
20:45:51 96461 8192000000 10876016096 11364126720 1919413328 18.982 97 11 22 1 1932531792 10260496 2857968
20:48:40 59814 8192000000 10912546544 11389460480 1963528976 19.334 99 11 22 2 1976842992 9398224 3915792
20:50:42 44609 8192000000 10924301216 11413217280 1979337936 19.459 99 20 41 0 2002921536 16994976 6588624
20:52:27 50135 8192000000 10873542720 11348180992 1902884768 18.849 96 22 44 1 1921017232 11982288 6150176
20:54:25 21710 8192000000 10899945392 11361243136 1951094432 19.235 99 27 54 1 1967591152 8995392 7501328
20:55:48 25072 8192000000 10898338000 11352543232 1910915968 18.914 97 44 89 0 1934741072 11813360 12011744
20:57:15 30566 8192000000 10879204368 11332468736 1900694752 18.832 98 37 74 0 1924873264 14007440 10171072
20:58:48 39704 8192000000 10837004160 11299344384 1831003520 18.268 95 12 24 0 1844867056 10979616 2883920
21:00:29 40114 8192000000 10901095536 11346550784 1938743712 19.137 100 39 77 2 1957224880 7752512 10728656
21:02:10 85256 8192000000 10873317120 11332747264 1862080560 18.520 95 25 50 1 1882500368 13689264 6730544
21:04:42 65254 8192000000 10851763984 11316301824 1918555952 18.975 99 14 28 0 1932517664 10172864 3788848
21:06:48 63306 8192000000 10866512080 11342888960 1929855664 19.066 99 5 10 1 1941746720 10557520 1333536
21:08:51 45712 8192000000 10889002464 11361615872 1961128736 19.315 100 15 30 0 1977085280 11228352 4728192
21:10:38 82969 8192000000 10874641520 11343343616 1902412768 18.846 97 11 22 0 1917002928 11487760 3102400
21:13:08 54364 8192000000 10893543136 11360747520 1941616176 19.160 99 19 38 2 1962206544 14781392 5808976
21:15:56 40133 8192000000 10912970032 11375058944 1974855440 19.424 100 20 40 2 1996303760 15673856 5774464
21:17:39 45854 8192000000 10899332176 11370692608 1952670192 19.248 99 13 26 1 1966774768 10344432 3760144
21:19:35 51685 8192000000 10923103856 11393884160 1948015120 19.211 98 38 76 2 1977771936 19519952 10236864
21:21:27 72292 8192000000 10916402848 11388424192 1946368256 19.198 98 9 18 0 1963976928 15170352 2438320
21:24:14 45340 8192000000 10912034928 11374792704 1958420528 19.293 99 38 75 2 1981849680 12200032 11229120
21:26:27 43905 8192000000 10898967664 11376619520 1975864640 19.432 100 27 54 1 1992704192 8960416 7879136
21:28:19 38817 8192000000 10909183712 11391717376 1975669168 19.430 99 14 29 1 1989665632 10324144 3672320
21:30:01 39874 8192000000 10909030384 11392008192 1983770784 19.495 99 15 30 0 2000873824 12888144 4214896
21:31:54 50450 8192000000 10915126672 11385610240 1955856416 19.273 98 21 40 0 1970550128 9487488 5206224
21:33:50 40891 8192000000 10927533680 11400450048 1964875392 19.345 98 13 26 2 1977173312 8485264 3812656
21:35:35 52830 8192000000 10926557568 11392307200 1920767216 18.993 96 19 38 2 1939193536 13255056 5171264
21:37:30 96052 8192000000 10904369008 11375673344 1906401648 18.878 96 14 29 0 1923804432 13812544 3590240
21:40:07 98728 8192000000 10884809856 11365728256 1867423696 18.563 94 16 32 0 1884257424 12516336 4317392
21:42:49 26672 8192000000 10858557344 11307446272 1873216512 18.610 97 51 101 1 1898706640 11954784 13535344
21:44:16 100695 8192000000 10873886752 11332378624 1891792304 18.760 98 15 30 0 1919109888 22766176 4551408
21:46:57 81237 8192000000 10843178224 11329515520 1894381312 18.781 98 20 40 0 1913605856 13770816 5453728
21:49:33 73265 8192000000 10842800352 11318837248 1860329968 18.506 96 12 20 1 1871506128 7476016 3700144
21:51:47 72019 8192000000 10850696448 11341910016 1923812624 19.017 100 8 16 0 1943665632 17726656 2126352
21:54:20 46306 8192000000 10869453344 11334348800 1886026080 18.714 97 13 26 0 1903195008 13610880 3558048
21:56:12 53991 8192000000 9335642640 9616363520 476882144 5.501 25 10 18 1 482989184 3689968 2417072

Memory consumption, total, chart

Metadata cache size, chart

Statements activity, chart


Completed "Memory consumption, metadata cache, attachments activity". Done for 00:00:15, from 09-10-2020 21:58:22 to 09-10-2020 21:58:37.

Exceptions occured during test was in run

FB_MNEMONA CNT UNIT FB_GDSCODE
user_exc 147 v_add_invoice_to_stock 335544517
user_exc 6 v_cancel_supplier_invoice 335544517

Completed "Exceptions occured during test was in run". Done for 00:00:02, from 09-10-2020 21:58:38 to 09-10-2020 21:58:40.

Content of mon$database and FB version

MON$DATABASE_NAME               /home/bases/oltp30-etalone.fdb
MON$PAGE_SIZE                   8192
MON$ODS_MAJOR                   12
MON$ODS_MINOR                   0
MON$OLDEST_TRANSACTION          252238
MON$OLDEST_ACTIVE               253593
MON$OLDEST_SNAPSHOT             253593
MON$NEXT_TRANSACTION            253593
MON$PAGE_BUFFERS                1000000
MON$SQL_DIALECT                 3
MON$SHUTDOWN_MODE               0
MON$SWEEP_INTERVAL              0
MON$READ_ONLY                   0
MON$FORCED_WRITES               1
MON$RESERVE_SPACE               1
MON$CREATION_DATE               2020-04-03 16:41:55.3470
MON$PAGES                       2046432
MON$STAT_ID                     1
MON$BACKUP_STATE                0
MON$CRYPT_PAGE                  0
MON$OWNER                       SYSDBA                                                                                       
MON$SEC_DATABASE                Default


ISQL Version: LI-V3.0.7.33371 Firebird 3.0
Server version:
Firebird/Linux/AMD/Intel/x64 (access method), version "LI-V3.0.7.33371 Firebird 3.0"
Firebird/Linux/AMD/Intel/x64 (remote server), version "LI-V3.0.7.33371 Firebird 3.0/tcp (mscs-test-161.budzdorov.ru)/P15:C"
Firebird/Linux/AMD/Intel/x64 (remote interface), version "LI-V3.0.7.33371 Firebird 3.0/tcp (mscs-test-161.budzdorov.ru)/P15:C"
on disk structure version 12.0

Database statistics

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

Database validation

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

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

--- start of diff output ---
:28: 
:29: mscs-test-161.budzdorov.ru    Fri Oct  9 21:57:09 2020
:30:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3333
:31: 
--- end of diff output ---

Final processing ISQL logs in /var/tmp/logs-oltp30 according to config parameter 'remove_isql_logs'

09.10.20 21:58:41. There are 3 logs in /var/tmp/logs-oltp30 that can be removed if no severe errors occured, see config setting 'remove_isql_logs' Following values of gdscode are considered as SEVERE: 0 Unidentified error in PSQL code: gdscode=0 within WHEN block when exception raised. 335544321 'string truncation'. Attempt to assign too long text into string variable. 335544347 'not_valid'. Validation error for column. 335544349 'no_dup'. Attempt to store duplicate value visible to active transactions. 335544558 'check_constraint'. Operation violates CHECK constraint on view or table. 335544665 'unique_key_violation'. Violation of PRIMARY or UNIQUE KEY constraint. 335544838 'foreign_key_target_doesnt_exist'. Foreign key reference target does not exist. 335544839 'foreign_key_references_present'. Foreign key references are present for the record.
FINISHED_AT ERRORS_RESULT
2020-10-09 21:58:43 No severe PSQL-related problems occured
09.10.20 21:58:44. End of report.