Generated by /opt/oltp-emul/oltp_isql_run_worker.sh, ISQL session No. 1 of total launched 100. 23.03.2022 19:38
Common Performance Final Results
  1. Hardware and OS info
  2. 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 was not gathered. Change config parameter 'run_db_statistics' to 1.
  3. Database validation was not performed. Change config parameter 'run_db_validation' to 1.
  4. New in firebird.log while test was run
  5. 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 2a7b53d1c5ed44b9bb2712fffac5d8c6
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 2021-11-11 18:28
Command: dmidecode -t system|grep -i -e 'manufacturer\|product\|hypervisor'
Manufacturer HP
Product Name ProLiant DL380 Gen9
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.33
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 16624164 kB
MemAvailable 31629656 kB
Buffers 0 kB
Cached 15061884 kB
SwapCached 2508 kB
Command: fdisk -l
WARNING: fdisk GPT support is currently new, and therefore in an experimental phase. Use at your own discretion.
Disk /dev/sda: 599.9 GB, 599932581888 bytes, 1171743324 sectors
Units = sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 262144 bytes / 524288 bytes
Disk label type: gpt
Disk identifier: 919DACA4-2F35-4CBB-BAA7-2A8CD8F7168C
# Start End Size Type Name
1 2048 411647 200M EFI System EFI System Partition
2 411648 2508799 1G Microsoft basic
3 2508800 1171742719 557.5G Linux LVM
Disk /dev/mapper/centos_mscs--test--161-root: 53.7 GB, 53687091200 bytes, 104857600 sectors
Units = sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 262144 bytes / 524288 bytes
Disk /dev/mapper/centos_mscs--test--161-swap: 16.8 GB, 16844324864 bytes, 32899072 sectors
Units = sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 262144 bytes / 524288 bytes
Disk /dev/sdb: 536 MB, 536870912 bytes, 1048576 sectors
Units = sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disk label type: dos
Disk identifier: 0x00000046
Device Boot Start End Blocks Id System
/dev/sdb1 63 514079 257008+ c W95 FAT32 (LBA)
Disk /dev/mapper/centos_mscs--test--161-home: 528.1 GB, 528109010944 bytes, 1031462912 sectors
Units = sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 262144 bytes / 524288 bytes

Server and database settinfs

SERVER_MODE                     SuperServer 3.0.10
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 2022-03-23 19:38:02
DTS_END                         2022-03-23 19:38:02.3950
FB_GDSCODE                      -1
FB_MNEMONA                      
STACK                           SP_CANCEL_SUPPLIER_ORDER(116:18) ==> SP_CANCEL_CUSTOMER_RESERVE(36:5) ==> SP_CHECK_TO_STOP_WORK(32:12) ==> SP_HALT_ON_ERROR(57:17)
IP                              ::1/52564
TRN_ID                          234799
ATT_ID                          626
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: 9619.90 19324 1154388
customer order: creation 174.08 366 20889
customer order: refuse 14.69 373 1763
order to supplier: creation 44.90 1262 5388
order to supplier: removal 3.52 90560 422
invoice (draft): creation 46.10 3390 5532
invoice (draft): removal 56.93 685 6832
invoice accept: apply 42.23 16985 5067
invoice accept: cancel 51.44 731 6173
customer reserve: creation 3954.04 166 474485
customer reserve: removal 4928.44 51 591413
realization accept: apply 83.76 181 10051
realization accept: cancel 92.73 93 11128
payment from customer: creation 57.18 111 6862
payment from customer: removal 5.95 72 714
payment to supplier: creation 48.46 127 5815
payment to supplier: removal 3.33 115 400
service: total inventory turnovers 4.86 1152 583
service: total monetary turnovers 6.44 36 773
service: aggregate perf. data 0.78 22976 94
service: refresh index statistics 0.03 247042 4

Performance in TOTAL, chart


Completed "Performance in TOTAL". Done for 00:00:02, from 23-03-2022 19:39:17 to 23-03-2022 19:39:19.

Performance for every MINUTE

TEST_PHASE_NAME MINUTES_PASSED PERF_SCORE
TEST_TIME 1 4647
TEST_TIME 2 4798
TEST_TIME 3 4632
TEST_TIME 4 4072
TEST_TIME 5 4626
TEST_TIME 6 4659
TEST_TIME 7 5121
TEST_TIME 8 5427
TEST_TIME 9 5876
TEST_TIME 10 6409
TEST_TIME 11 6910
TEST_TIME 12 7185
TEST_TIME 13 7300
TEST_TIME 14 7437
TEST_TIME 15 7772
TEST_TIME 16 8071
TEST_TIME 17 7929
TEST_TIME 18 8288
TEST_TIME 19 8802
TEST_TIME 20 9178
TEST_TIME 21 9447
TEST_TIME 22 9946
TEST_TIME 23 10229
TEST_TIME 24 9949
TEST_TIME 25 10673
TEST_TIME 26 10702
TEST_TIME 27 11157
TEST_TIME 28 11225
TEST_TIME 29 11141
TEST_TIME 30 10986
TEST_TIME 31 10997
TEST_TIME 32 11028
TEST_TIME 33 11095
TEST_TIME 34 10956
TEST_TIME 35 11043
TEST_TIME 36 10898
TEST_TIME 37 10749
TEST_TIME 38 10897
TEST_TIME 39 10878
TEST_TIME 40 10654
TEST_TIME 41 10504
TEST_TIME 42 10618
TEST_TIME 43 10416
TEST_TIME 44 10332
TEST_TIME 45 10235
TEST_TIME 46 10337
TEST_TIME 47 10430
TEST_TIME 48 10362
TEST_TIME 49 10346
TEST_TIME 50 10270
TEST_TIME 51 10216
TEST_TIME 52 10141
TEST_TIME 53 10098
TEST_TIME 54 10046
TEST_TIME 55 10028
TEST_TIME 56 9938
TEST_TIME 57 10007
TEST_TIME 58 9996
TEST_TIME 59 9926
TEST_TIME 60 9958
TEST_TIME 61 9990
TEST_TIME 62 10005
TEST_TIME 63 10005
TEST_TIME 64 10063
TEST_TIME 65 10093
TEST_TIME 66 10070
TEST_TIME 67 10086
TEST_TIME 68 10069
TEST_TIME 69 10261
TEST_TIME 70 10243
TEST_TIME 71 10249
TEST_TIME 72 10274
TEST_TIME 73 10161
TEST_TIME 74 10102
TEST_TIME 75 10107
TEST_TIME 76 10043
TEST_TIME 77 10080
TEST_TIME 78 10040
TEST_TIME 79 9976
TEST_TIME 80 10001
TEST_TIME 81 9926
TEST_TIME 82 9923
TEST_TIME 83 9839
TEST_TIME 84 9911
TEST_TIME 85 9843
TEST_TIME 86 9965
TEST_TIME 87 9947
TEST_TIME 88 9935
TEST_TIME 89 9930
TEST_TIME 90 9922
TEST_TIME 91 9940
TEST_TIME 92 9950
TEST_TIME 93 9960
TEST_TIME 94 9972
TEST_TIME 95 9991
TEST_TIME 96 9982
TEST_TIME 97 10031
TEST_TIME 98 10024
TEST_TIME 99 10057
TEST_TIME 100 10026
TEST_TIME 101 9943
TEST_TIME 102 9959
TEST_TIME 103 9912
TEST_TIME 104 9897
TEST_TIME 105 9885
TEST_TIME 106 9855
TEST_TIME 107 9802
TEST_TIME 108 9839
TEST_TIME 109 9791
TEST_TIME 110 9834
TEST_TIME 111 9764
TEST_TIME 112 9758
TEST_TIME 113 9699
TEST_TIME 114 9684
TEST_TIME 115 9668
TEST_TIME 116 9731
TEST_TIME 117 9708
TEST_TIME 118 9709
TEST_TIME 119 9698
TEST_TIME 120 9622

Performance per minute, chart


Completed "Performance for every MINUTE". Done for 00:00:04, from 23-03-2022 19:39:20 to 23-03-2022 19:39:24.

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 1592533 1592533 0 0.00 0 15103 6 0 0
doc_list_biud 1592532 1592532 0 0.00 0 90167 24 0 0
sp_add_invoice_to_stock 5167 5067 100 1.93 14 189694 16985 0 100
sp_cancel_adding_invoice 6173 6173 0 0.00 3 51252 731 0 0
sp_cancel_client_order 1763 1763 0 0.00 4 16073 373 0 0
sp_cancel_customer_reserve 591413 591413 0 0.00 1 21596 51 0 0
sp_cancel_pay_from_customer 714 714 0 0.00 2 5642 73 0 0
sp_cancel_pay_to_supplier 400 400 0 0.00 2 9421 115 0 0
sp_cancel_supplier_invoice 6843 6832 11 0.16 1 90173 685 0 11
sp_cancel_supplier_order 422 422 0 0.00 7 876737 90561 0 0
sp_cancel_write_off 11128 11128 0 0.00 1 9697 94 0 0
sp_client_order 20889 20889 0 0.00 3 19788 366 0 0
sp_customer_reserve 474485 474485 0 0.00 0 33568 166 0 0
sp_fill_shopping_cart 31797 31797 0 0.00 1 15022 37 0 0
sp_fill_shopping_cart_clo_res 474483 474483 0 0.00 0 16289 12 0 0
sp_get_clo_for_invoice 5064 5064 0 0.00 0 31092 298 0 0
sp_kill_cost_storno 18415 18415 0 0.00 0 9336 52 0 0
sp_kill_qstorno_ret_qs2qd 1201208 1201208 0 0.00 0 90164 28 0 0
sp_kill_qty_storno 632845 632845 0 0.00 0 90166 60 0 0
sp_lock_selected_doc 21054 21054 0 0.00 0 9822 6 0 0
sp_make_cost_storno 27792 27792 0 0.00 0 15094 55 0 0
sp_multiply_rows_for_pdistr 27792 27792 0 0.00 0 11256 33 0 0
sp_multiply_rows_for_qdistr 20889 20889 0 0.00 0 11520 162 0 0
sp_pay_from_customer 6862 6862 0 0.00 4 15114 112 0 0
sp_pay_to_supplier 5815 5815 0 0.00 5 16554 128 0 0
sp_payment_common 12677 12677 0 0.00 1 15105 26 0 0
sp_qd_handle_on_cancel_clo 1763 1763 0 0.00 0 16067 341 0 0
sp_qd_handle_on_invoice_upd_sts 11237 11237 0 0.00 0 14177 300 0 0
sp_qd_handle_on_reserve_upd_sts 10050 10050 0 0.00 0 16690 61 0 0
sp_reserve_write_off 10051 10051 0 0.00 6 18462 181 0 0
sp_supplier_invoice 5532 5532 0 0.00 6 90268 3391 0 0
sp_supplier_order 5388 5388 0 0.00 4 38526 1262 0 0
srv_aggregate_perf_data 94 94 0 0.00 3223 167763 22977 0 0
srv_fill_mon_cache_memory 62 62 0 0.00 1980 165283 48653 0 0
srv_find_qd_qs_mism 1105796 1105796 0 0.00 0 14951 5 0 0
srv_make_invnt_saldo 583 583 0 0.00 40 83977 1153 0 0
srv_make_money_saldo 773 773 0 0.00 1 3756 37 0 0
srv_recalc_idx_stat 4 4 0 0.00 137113 326040 247043 0 0
t$perf-abend:sp_add_invoice_to_stock 100 100 0 0.00 0 0 0 0 0
t$perf-abend:sp_cancel_supplier_invoice 11 11 0 0.00 0 0 0 0 0
t$perf-norm:sp_add_invoice_to_stock 5067 5067 0 0.00 0 15391 199 0 0
t$perf-norm:sp_cancel_adding_invoice 463 463 0 0.00 0 2798 91 0 0
t$perf-norm:sp_cancel_client_order 1763 1763 0 0.00 0 4062 17 0 0
t$perf-norm:sp_cancel_customer_reserve 694 694 0 0.00 0 6820 22 0 0
t$perf-norm:sp_cancel_pay_from_customer 714 714 0 0.00 0 6082 18 0 0
t$perf-norm:sp_cancel_pay_to_supplier 400 400 0 0.00 0 6538 29 0 0
t$perf-norm:sp_cancel_supplier_invoice 408 408 0 0.00 0 967 15 0 0
t$perf-norm:sp_cancel_supplier_order 422 422 0 0.00 0 20513 1470 0 0
t$perf-norm:sp_cancel_write_off 1076 1076 0 0.00 0 1501 8 0 0
t$perf-norm:sp_client_order 20889 20889 0 0.00 0 11103 23 0 0
t$perf-norm:sp_customer_reserve 1044 1044 0 0.00 0 2376 9 0 0
t$perf-norm:sp_pay_from_customer 6862 6862 0 0.00 0 9632 13 0 0
t$perf-norm:sp_pay_to_supplier 5815 5815 0 0.00 0 8596 13 0 0
t$perf-norm:sp_reserve_write_off 10051 10051 0 0.00 0 9165 14 0 0
t$perf-norm:sp_supplier_invoice 5532 5532 0 0.00 0 8939 25 0 0
t$perf-norm:sp_supplier_order 5388 5388 0 0.00 0 9399 21 0 0
t$perf-norm:srv_aggregate_perf_data 94 94 0 0.00 0 240 8 0 0
t$perf-norm:srv_fill_mon_cache_memory 62 62 0 0.00 0 8 0 0 0
t$perf-norm:srv_make_invnt_saldo 583 583 0 0.00 0 743 20 0 0
t$perf-norm:srv_make_money_saldo 773 773 0 0.00 0 817 17 0 0
t$perf-norm:srv_recalc_idx_stat 4 4 0 0.00 1 5 2 0 0
v_add_invoice_to_stock 10328 10128 200 1.93 0 9495 18 0 200
v_all_customers 37768 37768 0 0.00 0 30 1 0 0
v_all_suppliers 30392 30392 0 0.00 0 114 1 0 0
v_all_wares 41776 41776 0 0.00 0 99 1 0 0
v_cancel_adding_invoice 926 926 0 0.00 0 1372 7 0 0
v_cancel_client_order 3526 3526 0 0.00 0 7662 7 0 0
v_cancel_customer_prepayment 1428 1428 0 0.00 0 5590 8 0 0
v_cancel_customer_reserve 1388 1388 0 0.00 0 6304 8 0 0
v_cancel_payment_to_supplier 800 800 0 0.00 0 9362 20 0 0
v_cancel_supplier_invoice 838 816 22 2.62 0 797 14 0 22
v_cancel_supplier_order 844 844 0 0.00 0 1073 7 0 0
v_cancel_write_off 2152 2152 0 0.00 0 3944 13 0 0
v_max_id_clo_ord 5379 5379 0 0.00 0 855 1 0 0
v_max_id_clo_res 1044 1044 0 0.00 0 7094 28 0 0
v_max_id_ord_sup 5530 5530 0 0.00 0 3167 3 0 0
v_max_non_paid_invoice 1528 1528 0 0.00 0 271 2 0 0
v_max_non_paid_realizn 3630 3630 0 0.00 0 1848 4 0 0
v_min_id_clo_ord 5379 5379 0 0.00 0 4999 7 0 0
v_min_id_clo_res 1044 1044 0 0.00 0 8942 32 0 0
v_min_id_ord_sup 5530 5530 0 0.00 0 8406 10 0 0
v_min_non_paid_invoice 5814 5814 0 0.00 0 10052 15 0 0
v_min_non_paid_realizn 6861 6861 0 0.00 0 8052 21 0 0
v_our_firm 10470 10470 0 0.00 0 16 1 0 0
v_reserve_write_off 20100 20100 0 0.00 0 7973 6 0 0
x_lock_depdocs_on_canc_invoice 12597 12597 0 0.00 0 13904 98 0 0
x_lock_depdocs_on_canc_sup_ord 422 422 0 0.00 0 11344 334 0 0
x_make_qstorno_1000_1200 5388 5388 0 0.00 2 38513 1185 0 0
x_make_qstorno_1200_2000 5532 5532 0 0.00 3 90255 3261 0 0
x_make_qstorno_2100_3300 474485 474485 0 0.00 0 33285 152 0 0

Completed "Performance in DETAILS". Done for 00:00:04, from 23-03-2022 19:39:25 to 23-03-2022 19:39:29.

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
17:08:06 32 8192000000 8807053568 8821121024 11626944 0.141 3 3 4 0 11812288 78240 107104
17:09:07 31818 8192000000 9901935040 10210693120 978176256 10.666 100 89 179 0 1007251952 5867728 23207968
17:10:46 23024 8192000000 9948894592 10271215616 1031257664 11.181 100 92 184 0 1062846160 7989936 23598560
17:12:15 14826 8192000000 9983735040 10316283904 1070628864 11.558 100 85 170 0 1101000048 9714464 20656720
17:13:35 8921 8192000000 10041061520 10389172224 1127618400 12.099 100 81 162 1 1157726112 10960720 19146992
17:14:50 11175 8192000000 10091140432 10452369408 1176903840 12.561 100 83 166 1 1209184800 13405072 18875888
17:16:04 5137 8192000000 10122820464 10494435328 1216495328 12.929 100 82 163 2 1247237664 12415600 18326736
17:17:12 3025 8192000000 10160916928 10535903232 1247805040 13.218 100 80 156 0 1277673120 12451024 17417056
17:18:16 2276 8192000000 10182059008 10559352832 1269325072 13.415 100 87 175 2 1303196736 14454224 19417440
17:19:21 2318 8192000000 10198222160 10580733952 1285802032 13.566 100 91 178 2 1319331808 13353328 20176448
17:20:25 5403 8192000000 10214126448 10603929600 1296091840 13.660 100 71 142 0 1324046752 11596688 16358224
17:21:31 5504 8192000000 10194488704 10602610688 1306529072 13.755 100 23 46 1 1317990592 6088224 5373296
17:22:38 46027 8192000000 10223263600 10625359872 1314429680 13.826 100 63 126 0 1335138224 5394928 15313616
17:24:25 5474 8192000000 10207507408 10626408448 1321239120 13.888 100 21 42 0 1331954608 6116400 4599088
17:25:31 8398 8192000000 10214558528 10631667712 1314147136 13.824 99 28 55 1 1326639248 6077616 6414496
17:26:41 21942 8192000000 10221706576 10642456576 1329328672 13.961 100 24 47 1 1340590320 5637376 5624272
17:28:04 4391 8192000000 10223665248 10646704128 1332329744 13.988 100 30 60 0 1350049408 11103600 6616064
17:29:10 8486 8192000000 10179978592 10581872640 1206032480 12.832 92 31 63 0 1218956592 4605760 8318352
17:30:20 49241 8192000000 10160720096 10539966464 1207153440 12.843 94 51 103 0 1224181392 4792096 12235856
17:32:10 3884 8192000000 10142002144 10533474304 1231839856 13.071 99 40 80 1 1248844464 8230208 8774400
17:33:16 5676 8192000000 10140978160 10536255488 1217964880 12.943 97 22 42 2 1228033248 5117696 4950672
17:34:23 11562 8192000000 10161552944 10573070336 1266037888 13.385 99 25 50 1 1277128928 5640240 5450800
17:35:37 32336 8192000000 10199415664 10594041856 1288422128 13.590 100 67 134 2 1312452976 6368016 17662832
17:37:09 9983 8192000000 10183767360 10600509440 1299286448 13.689 100 21 40 2 1309245328 5291616 4667264
17:38:30 32695 8192000000 10229845904 10631962624 1319908432 13.876 100 51 102 0 1339278160 6810624 12559104
17:40:11 56507 8192000000 10250099072 10669694976 1345874896 14.110 100 52 104 0 1369301424 11915696 11510832
17:42:28 43067 8192000000 10271642464 10699935744 1360982416 14.246 100 32 64 1 1381122704 12570672 7569616
17:44:16 24562 8192000000 10298976800 10714726400 1379542864 14.412 100 50 100 0 1407647872 16207072 11897936
17:45:53 4055 8192000000 10321804336 10738655232 1395918448 14.559 100 76 151 0 1434350224 21047040 17384736
17:47:05 6669 8192000000 10324345264 10745696256 1397149504 14.570 100 60 120 1 1435305120 23621808 14533808
17:48:19 2288 8192000000 10339108816 10762797056 1404965120 14.639 100 73 147 0 1451356480 28436736 17954624
17:49:26 6701 8192000000 10347237072 10767159296 1412364016 14.705 100 72 141 1 1453548480 24302080 16882384
17:50:36 2833 8192000000 10335346656 10760118272 1395286416 14.553 99 62 122 2 1435366000 24984784 15094800
17:51:44 6931 8192000000 10353858800 10774953984 1405163952 14.641 99 68 136 2 1450522672 29176880 16181840
17:52:55 2018 8192000000 10370134352 10785144832 1418924496 14.763 100 88 176 0 1474062784 34123424 21014864
17:54:01 2336 8192000000 10364092992 10783588352 1410293392 14.687 99 79 158 3 1464762688 35083952 19385344
17:55:07 3614 8192000000 10339377680 10750922752 1382938752 14.443 100 72 139 2 1438524816 38047184 17538880
17:56:20 1979 8192000000 10341513952 10743701504 1364392880 14.277 99 91 182 0 1430907696 43091152 23423664
17:57:25 12677 8192000000 10328637504 10756878336 1383324176 14.446 100 42 84 1 1438962736 43311808 12326752
17:58:43 18019 8192000000 10300422736 10734694400 1353748192 14.181 99 29 58 1 1403887504 41914832 8224480
18:00:07 14705 8192000000 10307432032 10747293696 1370823376 14.334 100 28 55 0 1420415328 42428896 7163056
18:01:23 32125 8192000000 10298869008 10737598464 1353662400 14.180 99 19 38 1 1400723456 41519920 5541136
18:02:57 21311 8192000000 10274515408 10706071552 1333555424 13.999 99 27 54 1 1386841728 45688128 7598176
18:04:25 38179 8192000000 10269734592 10718347264 1347329440 14.123 100 13 26 1 1380784736 29315168 4140128
18:06:12 106773 8192000000 10253307296 10696982528 1298594352 13.682 96 13 26 0 1313338112 12144640 2599120
18:09:15 99494 8192000000 10267074208 10718486528 1332898336 13.993 98 19 38 0 1353740000 15998240 4843424
18:12:07 43734 8192000000 10284264640 10719453184 1358366496 14.223 99 16 32 1 1373351984 11600416 3385072
18:14:09 54568 8192000000 10290956880 10713427968 1330618320 13.973 97 20 39 1 1344225296 8616976 4990000
18:16:07 28234 8192000000 10288799488 10736693248 1362691728 14.262 99 11 22 0 1381118112 15837856 2588528
18:18:55 35239 8192000000 10299707472 10737807360 1369123312 14.319 99 53 106 1 1391317456 9155264 13038880
18:20:37 92788 8192000000 10286584784 10746830848 1376415968 14.384 100 9 18 1 1396762608 18428496 1918144
18:23:10 26267 8192000000 10314626640 10756214784 1393257760 14.535 100 22 44 3 1408680976 9852304 5570912
18:25:01 74876 8192000000 10286869616 10765406208 1360003168 14.237 98 8 16 0 1379511936 17792656 1716112
18:27:19 36593 8192000000 10271619072 10733572096 1365859728 14.290 99 10 20 0 1376438352 8130336 2448288
18:29:03 23837 8192000000 10286967312 10736910336 1366696288 14.297 99 15 30 1 1376210224 6348672 3165264
18:30:29 51038 8192000000 10283093312 10744848384 1385370160 14.465 100 7 14 0 1395565648 8438176 1757312
18:32:47 49399 8192000000 10302750832 10760204288 1386108352 14.471 99 20 40 0 1407450240 16939856 4402032
18:34:37 89387 8192000000 10287382192 10762940416 1365198240 14.284 98 19 38 1 1386548592 16742160 4608192
18:37:07 91351 8192000000 10285884880 10751082496 1330085184 13.968 95 14 28 0 1345428368 12187136 3156048
18:39:40 44799 8192000000 10281365552 10733051904 1352792016 14.173 98 16 32 2 1367368160 11537952 3038192
18:41:25 64147 8192000000 10296021888 10751340544 1339077792 14.049 96 14 28 0 1358133600 15709936 3345872
18:43:30 53972 8192000000 10286046992 10734592000 1352793472 14.173 99 14 29 1 1373669008 17560704 3314832
18:45:39 91388 8192000000 10277578656 10733178880 1310227440 13.788 96 14 28 1 1335825232 22386976 3210816
18:48:18 17967 8192000000 10284529872 10721538048 1345744208 14.109 99 42 84 0 1367813280 12992944 9076128
18:49:46 17162 8192000000 10281423232 10713317376 1343133456 14.086 99 41 82 1 1363242368 10315424 9793488
18:51:03 165283 8192000000 10249105984 10702028800 1287948064 13.586 95 14 28 0 1303979392 12562512 3468816
18:55:09 36056 8192000000 10236801552 10679427072 1287408112 13.581 95 23 47 1 1298404448 6499504 4496832
18:56:56 60017 8192000000 10266847392 10715471872 1352553568 14.170 100 25 50 1 1376672640 18561568 5557504
18:59:00 99082 8192000000 10263237344 10719064064 1337896944 14.038 98 10 20 1 1352300320 11949136 2454240
19:01:40 86724 8192000000 10282214704 10746892288 1375141440 14.373 100 21 42 1 1396847568 16957696 4748432
19:04:14 72388 8192000000 10292709536 10766467072 1388040576 14.488 100 11 22 1 1405918416 15289888 2587952
19:06:27 26782 8192000000 10275916160 10734747648 1353982032 14.183 98 11 22 0 1364917456 8717056 2218368
19:07:54 17165 8192000000 10276173216 10715078656 1328472272 13.953 97 41 82 0 1345478928 8067680 8938976
19:09:11 48733 8192000000 10285884112 10742857728 1366747408 14.298 99 34 68 1 1384852832 10942224 7163200
19:11:03 33425 8192000000 10311653280 10756497408 1390447504 14.510 100 38 75 0 1409530720 10434688 8648528
19:12:37 122622 8192000000 10312352368 10777640960 1367841920 14.308 97 15 30 2 1381984304 11023344 3119040
19:15:42 114364 8192000000 10305276800 10763255808 1338383568 14.043 95 12 24 2 1355181600 13578640 3219392
19:18:36 125474 8192000000 10299780704 10761138176 1371743312 14.343 98 17 34 0 1382684160 7534192 3406656
19:21:43 62442 8192000000 10318089104 10775318528 1390176384 14.507 99 29 58 0 1413428096 16456704 6795008
19:23:53 52708 8192000000 10297467952 10760351744 1398736848 14.584 100 22 44 0 1412242192 8369072 5136272
19:26:32 66835 8192000000 10303818832 10770137088 1389864320 14.505 98 12 24 1 1403983280 11119424 2999536
19:29:07 73060 8192000000 10304684864 10764865536 1403576272 14.627 100 26 52 0 1417768480 8026624 6165584
19:31:21 61802 8192000000 10308138848 10762825728 1387693888 14.485 99 21 40 1 1404172128 11993360 4484880
19:33:23 80507 8192000000 10277442208 10755051520 1361513472 14.251 98 6 12 0 1384753568 21807104 1432992
19:35:48 50810 8192000000 10292159504 10743791616 1345505280 14.107 97 16 32 1 1359299424 9191008 4603136
19:37:40 33794 8192000000 9027815920 9243844608 194795440 2.322 15 5 10 1 201775264 5904976 1074848

Memory consumption, total, chart

Metadata cache size, chart

Statements activity, chart


Completed "Memory consumption, metadata cache, attachments activity". Done for 00:00:15, from 23-03-2022 19:39:30 to 23-03-2022 19:39:45.

Exceptions occured during test was in run

FB_MNEMONA CNT UNIT FB_GDSCODE
except 100 v_add_invoice_to_stock 335544517
except 11 v_cancel_supplier_invoice 335544517

Completed "Exceptions occured during test was in run". Done for 00:00:02, from 23-03-2022 19:39:46 to 23-03-2022 19:39:48.

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          236909
MON$OLDEST_ACTIVE               237241
MON$OLDEST_SNAPSHOT             237241
MON$NEXT_TRANSACTION            237241
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                       2042784
MON$STAT_ID                     1
MON$BACKUP_STATE                0
MON$CRYPT_PAGE                  0
MON$OWNER                       SYSDBA                                                                                       
MON$SEC_DATABASE                Default


ISQL Version: LI-V3.0.10.33574 Firebird 3.0
Server version:
Firebird/Linux/AMD/Intel/x64 (access method), version "LI-V3.0.10.33574 Firebird 3.0"
Firebird/Linux/AMD/Intel/x64 (remote server), version "LI-V3.0.10.33574 Firebird 3.0/tcp (mscs-test-161.budzdorov.ru)/P15:C"
Firebird/Linux/AMD/Intel/x64 (remote interface), version "LI-V3.0.10.33574 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 ---
:323: 
:324: mscs-test-161.budzdorov.ru    Wed Mar 23 19:38:22 2022
:325:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3333
:326: 
--- end of diff output ---

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

23.03.22 19:39:49. 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
2022-03-23 19:39:52 No severe PSQL-related problems occured
23.03.22 19:39:53. End of report.