Generated by /opt/oltp-emul/oltp_isql_run_worker.sh, ISQL session No. 1 of total launched 100. 30.04.2022 13:37
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 16287512 kB
MemAvailable 31512488 kB
Buffers 0 kB
Cached 15390824 kB
SwapCached 3200 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 4.0.2
DB_NAME                         /home/bases/oltp40-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/oltp40-etalone.fdb
param=detailed_info, val=0
param=etalon_dbnm, val=/home/bases/oltp40-etalone.fd0
param=expected_workers, val=100
param=fbc, val=/opt/fb40/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=3400
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/oltp40-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-oltp40
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-04-30 13:37:13
DTS_END                         2022-04-30 13:37:13.8120
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(68:17)
IP                              ::1/55006
TRN_ID                          220439
ATT_ID                          606
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: 9014.08 24187 1081690
customer order: creation 174.62 458 20954
customer order: refuse 14.35 482 1722
order to supplier: creation 46.43 1404 5571
order to supplier: removal 3.13 190033 376
invoice (draft): creation 46.44 3420 5573
invoice (draft): removal 49.76 1097 5971
invoice accept: apply 42.10 27761 5052
invoice accept: cancel 44.97 1406 5396
customer reserve: creation 3927.04 262 471245
customer reserve: removal 4372.18 107 524662
realization accept: apply 83.50 298 10020
realization accept: cancel 80.20 177 9624
payment from customer: creation 57.92 193 6950
payment from customer: removal 5.57 131 668
payment to supplier: creation 49.28 209 5913
payment to supplier: removal 3.53 136 424
service: total inventory turnovers 4.02 4567 482
service: total monetary turnovers 8.03 362 964
service: aggregate perf. data 0.98 15954 118
service: refresh index statistics 0.04 235287 5

Performance in TOTAL, chart


Completed "Performance in TOTAL". Done for 00:00:02, from 30-04-2022 13:38:03 to 30-04-2022 13:38:05.

Performance for every MINUTE

TEST_PHASE_NAME MINUTES_PASSED PERF_SCORE
TEST_TIME 1 9422
TEST_TIME 2 6448
TEST_TIME 3 6534
TEST_TIME 4 5593
TEST_TIME 5 5913
TEST_TIME 6 5693
TEST_TIME 7 5413
TEST_TIME 8 5501
TEST_TIME 9 6038
TEST_TIME 10 5947
TEST_TIME 11 6010
TEST_TIME 12 6023
TEST_TIME 13 6088
TEST_TIME 14 6234
TEST_TIME 15 6425
TEST_TIME 16 6468
TEST_TIME 17 6837
TEST_TIME 18 6952
TEST_TIME 19 7158
TEST_TIME 20 7158
TEST_TIME 21 7577
TEST_TIME 22 7704
TEST_TIME 23 7751
TEST_TIME 24 7747
TEST_TIME 25 7871
TEST_TIME 26 8102
TEST_TIME 27 8125
TEST_TIME 28 8131
TEST_TIME 29 8718
TEST_TIME 30 8834
TEST_TIME 31 8875
TEST_TIME 32 9158
TEST_TIME 33 9229
TEST_TIME 34 9547
TEST_TIME 35 9630
TEST_TIME 36 9886
TEST_TIME 37 10035
TEST_TIME 38 9990
TEST_TIME 39 10415
TEST_TIME 40 10406
TEST_TIME 41 10260
TEST_TIME 42 10223
TEST_TIME 43 10125
TEST_TIME 44 10142
TEST_TIME 45 9961
TEST_TIME 46 9831
TEST_TIME 47 9859
TEST_TIME 48 9765
TEST_TIME 49 9599
TEST_TIME 50 9570
TEST_TIME 51 9618
TEST_TIME 52 9510
TEST_TIME 53 9491
TEST_TIME 54 9491
TEST_TIME 55 9416
TEST_TIME 56 9536
TEST_TIME 57 9499
TEST_TIME 58 9526
TEST_TIME 59 9610
TEST_TIME 60 9543
TEST_TIME 61 9484
TEST_TIME 62 9536
TEST_TIME 63 9587
TEST_TIME 64 9604
TEST_TIME 65 9668
TEST_TIME 66 9705
TEST_TIME 67 9709
TEST_TIME 68 9635
TEST_TIME 69 9703
TEST_TIME 70 9690
TEST_TIME 71 9794
TEST_TIME 72 9714
TEST_TIME 73 9668
TEST_TIME 74 9612
TEST_TIME 75 9548
TEST_TIME 76 9498
TEST_TIME 77 9487
TEST_TIME 78 9475
TEST_TIME 79 9411
TEST_TIME 80 9412
TEST_TIME 81 9348
TEST_TIME 82 9291
TEST_TIME 83 9225
TEST_TIME 84 9176
TEST_TIME 85 9306
TEST_TIME 86 9296
TEST_TIME 87 9277
TEST_TIME 88 9305
TEST_TIME 89 9277
TEST_TIME 90 9290
TEST_TIME 91 9247
TEST_TIME 92 9201
TEST_TIME 93 9272
TEST_TIME 94 9261
TEST_TIME 95 9240
TEST_TIME 96 9364
TEST_TIME 97 9477
TEST_TIME 98 9453
TEST_TIME 99 9402
TEST_TIME 100 9365
TEST_TIME 101 9361
TEST_TIME 102 9320
TEST_TIME 103 9288
TEST_TIME 104 9239
TEST_TIME 105 9256
TEST_TIME 106 9218
TEST_TIME 107 9157
TEST_TIME 108 9113
TEST_TIME 109 9117
TEST_TIME 110 9083
TEST_TIME 111 9060
TEST_TIME 112 9062
TEST_TIME 113 9061
TEST_TIME 114 9048
TEST_TIME 115 9116
TEST_TIME 116 9073
TEST_TIME 117 9069
TEST_TIME 118 9133
TEST_TIME 119 9109
TEST_TIME 120 9042

Performance per minute, chart


Completed "Performance for every MINUTE". Done for 00:00:03, from 30-04-2022 13:38:07 to 30-04-2022 13:38:10.

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 1515089 1515089 0 0.00 0 24033 15 0 0
doc_list_biud 1515071 1515071 0 0.00 0 66117 44 0 0
sp_add_invoice_to_stock 5097 5052 45 0.88 32 226287 27761 0 45
sp_cancel_adding_invoice 5396 5396 0 0.00 7 116377 1406 0 0
sp_cancel_client_order 1722 1722 0 0.00 5 11190 483 0 0
sp_cancel_customer_reserve 524662 524662 0 0.00 1 28127 107 0 0
sp_cancel_pay_from_customer 668 668 0 0.00 4 6697 131 0 0
sp_cancel_pay_to_supplier 424 424 0 0.00 4 1949 136 0 0
sp_cancel_supplier_invoice 5976 5971 5 0.08 4 66146 1097 0 5
sp_cancel_supplier_order 376 376 0 0.00 16 1406344 190034 0 0
sp_cancel_write_off 9624 9624 0 0.00 2 18762 177 0 0
sp_client_order 20954 20954 0 0.00 6 17936 458 0 0
sp_customer_reserve 471245 471245 0 0.00 1 131230 262 0 0
sp_fill_shopping_cart 32089 32089 0 0.00 2 17466 87 0 0
sp_fill_shopping_cart_clo_res 471211 471211 0 0.00 0 16626 20 0 0
sp_get_clo_for_invoice 5009 5009 0 0.00 0 23514 283 0 0
sp_kill_cost_storno 16112 16112 0 0.00 0 20309 81 0 0
sp_kill_qstorno_ret_qs2qd 1065295 1065295 0 0.00 0 66108 47 0 0
sp_kill_qty_storno 562775 562775 0 0.00 0 66113 109 0 0
sp_lock_selected_doc 20662 20662 0 0.00 0 8684 8 0 0
sp_make_cost_storno 27889 27889 0 0.00 0 24018 90 0 0
sp_multiply_rows_for_pdistr 27888 27888 0 0.00 0 6655 41 0 0
sp_multiply_rows_for_qdistr 20953 20953 0 0.00 0 8604 173 0 0
sp_pay_from_customer 6950 6950 0 0.00 6 11868 193 0 0
sp_pay_to_supplier 5913 5913 0 0.00 7 16095 210 0 0
sp_payment_common 12862 12862 0 0.00 2 7795 50 0 0
sp_qd_handle_on_cancel_clo 1722 1722 0 0.00 0 11179 404 0 0
sp_qd_handle_on_invoice_upd_sts 10402 10402 0 0.00 0 25540 570 0 0
sp_qd_handle_on_reserve_upd_sts 10018 10018 0 0.00 0 16390 65 0 0
sp_reserve_write_off 10020 10020 0 0.00 9 24047 299 0 0
sp_supplier_invoice 5573 5573 0 0.00 12 90400 3420 0 0
sp_supplier_order 5571 5571 0 0.00 9 31091 1405 0 0
srv_aggregate_perf_data 118 118 0 0.00 2219 128903 15955 0 0
srv_fill_mon_cache_memory 73 73 0 0.00 860 150856 32765 0 0
srv_find_qd_qs_mism 1031965 1031965 0 0.00 0 19150 11 0 0
srv_make_invnt_saldo 482 482 0 0.00 64 73860 4568 0 0
srv_make_money_saldo 964 964 0 0.00 1 17682 362 0 0
srv_recalc_idx_stat 5 5 0 0.00 53183 312005 235287 0 0
t$perf-abend:sp_add_invoice_to_stock 45 45 0 0.00 0 0 0 0 0
t$perf-abend:sp_cancel_supplier_invoice 5 5 0 0.00 0 0 0 0 0
t$perf-norm:sp_add_invoice_to_stock 5059 5059 0 0.00 1 10994 1014 0 0
t$perf-norm:sp_cancel_adding_invoice 420 420 0 0.00 1 6365 562 0 0
t$perf-norm:sp_cancel_client_order 1722 1722 0 0.00 0 992 29 0 0
t$perf-norm:sp_cancel_customer_reserve 684 684 0 0.00 0 6899 32 0 0
t$perf-norm:sp_cancel_pay_from_customer 668 668 0 0.00 0 1043 16 0 0
t$perf-norm:sp_cancel_pay_to_supplier 424 424 0 0.00 0 1294 19 0 0
t$perf-norm:sp_cancel_supplier_invoice 424 424 0 0.00 0 1490 36 0 0
t$perf-norm:sp_cancel_supplier_order 376 376 0 0.00 1 113170 9002 0 0
t$perf-norm:sp_cancel_write_off 925 925 0 0.00 0 13324 38 0 0
t$perf-norm:sp_client_order 20955 20955 0 0.00 0 14703 41 0 0
t$perf-norm:sp_customer_reserve 1032 1032 0 0.00 0 3369 19 0 0
t$perf-norm:sp_pay_from_customer 6951 6951 0 0.00 0 11328 22 0 0
t$perf-norm:sp_pay_to_supplier 5913 5913 0 0.00 0 4195 21 0 0
t$perf-norm:sp_reserve_write_off 10020 10020 0 0.00 0 10497 27 0 0
t$perf-norm:sp_supplier_invoice 5573 5573 0 0.00 0 5473 36 0 0
t$perf-norm:sp_supplier_order 5571 5571 0 0.00 0 4052 38 0 0
t$perf-norm:srv_aggregate_perf_data 118 118 0 0.00 0 873 31 0 0
t$perf-norm:srv_fill_mon_cache_memory 73 73 0 0.00 0 3353 51 0 0
t$perf-norm:srv_make_invnt_saldo 482 482 0 0.00 0 1020 18 0 0
t$perf-norm:srv_make_money_saldo 964 964 0 0.00 0 922 5 0 0
t$perf-norm:srv_recalc_idx_stat 5 5 0 0.00 5 112 49 0 0
v_add_invoice_to_stock 10094 10004 90 0.89 0 11961 23 0 90
v_all_customers 38296 38296 0 0.00 0 70 4 0 0
v_all_suppliers 30802 30802 0 0.00 0 127 4 0 0
v_all_wares 41902 41902 0 0.00 0 47 4 0 0
v_cancel_adding_invoice 840 840 0 0.00 0 5245 23 0 0
v_cancel_client_order 3444 3444 0 0.00 0 1604 10 0 0
v_cancel_customer_prepayment 1336 1336 0 0.00 0 6598 17 0 0
v_cancel_customer_reserve 1368 1368 0 0.00 1 5479 15 0 0
v_cancel_payment_to_supplier 848 848 0 0.00 0 1866 15 0 0
v_cancel_supplier_invoice 858 848 10 1.16 0 1878 21 0 10
v_cancel_supplier_order 752 752 0 0.00 0 5480 19 0 0
v_cancel_write_off 1850 1850 0 0.00 0 7990 27 0 0
v_max_id_clo_ord 5570 5570 0 0.00 0 570 5 0 0
v_max_id_clo_res 1032 1032 0 0.00 0 2676 14 0 0
v_max_id_ord_sup 5566 5566 0 0.00 0 5113 6 0 0
v_max_non_paid_invoice 1647 1647 0 0.00 0 56 8 0 0
v_max_non_paid_realizn 3542 3542 0 0.00 0 2135 8 0 0
v_min_id_clo_ord 5570 5570 0 0.00 0 2651 11 0 0
v_min_id_clo_res 1032 1032 0 0.00 0 647 7 0 0
v_min_id_ord_sup 5566 5566 0 0.00 0 10015 15 0 0
v_min_non_paid_invoice 5911 5911 0 0.00 0 4912 17 0 0
v_min_non_paid_realizn 6949 6949 0 0.00 0 4690 21 0 0
v_our_firm 10420 10420 0 0.00 0 155 5 0 0
v_reserve_write_off 20034 20034 0 0.00 0 7478 12 0 0
x_lock_depdocs_on_canc_invoice 10943 10943 0 0.00 0 10163 121 0 0
x_lock_depdocs_on_canc_sup_ord 376 376 0 0.00 0 9991 392 0 0
x_make_qstorno_1000_1200 5571 5571 0 0.00 2 31078 1221 0 0
x_make_qstorno_1200_2000 5573 5573 0 0.00 5 90288 3179 0 0
x_make_qstorno_2100_3300 471245 471245 0 0.00 0 131223 229 0 0

Completed "Performance in DETAILS". Done for 00:00:04, from 30-04-2022 13:38:11 to 30-04-2022 13:38:15.

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
11:07:17 3 8192000000 8798799728 8810254336 3901568 0.047 2 1 2 0 4000880 63536 35776
11:08:19 27566 8192000000 9723022672 10023833600 785330720 8.747 100 85 170 0 813092016 7116624 20644672
11:09:50 19072 8192000000 9754529968 10060046336 818179280 9.080 100 87 174 0 852082240 12665600 21237360
11:11:18 2500 8192000000 9782268720 10096652288 845174288 9.352 100 86 173 0 886198144 20768064 20255792
11:12:26 13768 8192000000 9835189792 10169610240 895447504 9.853 100 67 131 0 933983392 24331744 14204144
11:13:46 10078 8192000000 9892278992 10232803328 930699776 10.202 100 83 166 2 994641152 45922096 18019280
11:14:59 4273 8192000000 9949694384 10298253312 966017040 10.548 100 88 174 0 1055443104 71509104 17916960
11:16:07 2593 8192000000 9973426560 10336399360 990901968 10.790 100 80 156 1 1079112608 72026736 16183904
11:17:12 1727 8192000000 10029038096 10394411008 1026552928 11.135 100 94 174 1 1135183488 90537472 18093088
11:18:15 720 8192000000 10039389216 10409938944 1039931184 11.264 100 95 186 2 1143313312 83975008 19407120
11:19:18 1044 8192000000 10045711536 10425180160 1049588288 11.357 100 96 185 2 1158736688 91260144 17888256
11:20:20 1343 8192000000 10051854624 10434113536 1054560064 11.404 100 95 180 0 1160982128 88698784 17723280
11:21:24 825 8192000000 10044657968 10425475072 1060587808 11.462 100 93 180 1 1158426464 79252464 18586192
11:22:26 1001 8192000000 10036110064 10420264960 1069061440 11.543 100 95 182 0 1148123376 59436528 19625408
11:23:29 850 8192000000 10053253488 10446315520 1071966096 11.571 100 82 161 2 1163632480 75696144 15970240
11:24:30 1253 8192000000 10052344992 10442727424 1076179168 11.611 100 83 163 1 1160269392 67523808 16566416
11:25:34 1357 8192000000 10065613408 10454532096 1076200896 11.611 100 93 180 0 1177702448 82459600 19041952
11:26:36 973 8192000000 10066607568 10453352448 1076509680 11.614 100 93 186 0 1175457952 79622928 19325344
11:27:38 1539 8192000000 10038892160 10425708544 1075103888 11.601 100 84 159 2 1151086992 59088128 16894976
11:28:40 1988 8192000000 10048073792 10442813440 1075434864 11.604 100 79 154 1 1159303616 68287456 15581296
11:29:48 1321 8192000000 10034655200 10417790976 1063837680 11.493 100 96 177 1 1143085184 61565296 17682208
11:30:51 1267 8192000000 10031041856 10418417664 1058543024 11.443 100 74 148 0 1138727184 65016736 15167424
11:31:53 2040 8192000000 10021201424 10404687872 1059911424 11.456 100 82 160 3 1132712624 57141776 15659424
11:32:56 1183 8192000000 10002479152 10380312576 1051525408 11.375 100 91 177 0 1123134064 52420784 19187872
11:33:59 2652 8192000000 10013030736 10398982144 1064825968 11.503 100 69 130 2 1153971296 75907968 13237360
11:35:03 1165 8192000000 9995902672 10373971968 1044314816 11.306 100 81 154 2 1120388304 60278160 15795328
11:36:06 1747 8192000000 9981525584 10352283648 1041418576 11.278 100 89 165 1 1105098016 46967344 16712096
11:37:08 1097 8192000000 10004575776 10373668864 1043496848 11.298 100 92 178 0 1129938928 68348304 18093776
11:38:13 1407 8192000000 10006476256 10380849152 1063245392 11.488 100 83 152 0 1121746848 44118464 14382992
11:39:22 18979 8192000000 10039901568 10419003392 1081394240 11.661 100 67 133 1 1157956832 63233712 13328880
11:40:48 894 8192000000 10075535728 10461585408 1106715440 11.901 100 90 172 1 1198049536 72133184 19200912
11:41:54 2159 8192000000 10109812688 10502049792 1105833616 11.893 100 77 148 1 1226436640 103763568 16839456
11:43:05 3797 8192000000 10131663616 10524717056 1123158048 12.057 100 75 147 2 1250130384 112460160 14512176
11:44:14 1256 8192000000 10174518512 10570932224 1128601376 12.108 100 81 157 1 1289313120 144651008 16060736
11:45:39 8779 8192000000 10208109840 10609979392 1140601664 12.221 100 83 159 0 1329836272 171396144 17838464
11:46:57 7261 8192000000 10218718864 10618687488 1158217264 12.387 100 70 137 0 1341853536 168165248 15471024
11:48:10 1126 8192000000 10265838720 10664058880 1169872592 12.496 100 92 179 1 1379312880 188764640 20675648
11:49:16 1985 8192000000 10306916528 10707496960 1183475104 12.623 100 95 184 0 1419443312 215838416 20129792
11:50:22 1617 8192000000 10338333776 10751954944 1184793088 12.635 100 82 162 1 1454123392 250151872 19178432
11:51:27 2570 8192000000 10309224352 10732204032 1177384176 12.566 99 91 174 0 1421369632 224169168 19816288
11:52:34 2288 8192000000 10379851360 10792103936 1186353136 12.649 100 85 168 0 1494575552 289508464 18713952
11:53:39 1905 8192000000 10396494480 10817085440 1191407760 12.696 100 93 186 1 1507433344 295206048 20819536
11:54:45 896 8192000000 10382019120 10806435840 1188639648 12.671 100 98 192 1 1491293312 280288624 22365040
11:55:50 851 8192000000 10432223296 10854273024 1188607296 12.670 100 91 180 2 1538697136 328504000 21585840
11:56:55 914 8192000000 10414267920 10847723520 1189754960 12.681 100 90 173 2 1523387680 313443440 20189280
11:58:00 1073 8192000000 10415445136 10872582144 1190719712 12.690 100 97 187 0 1526690784 314040752 21930320
11:59:04 2555 8192000000 10444909920 10862694400 1190640544 12.689 100 92 183 0 1552165040 340294960 21229536
12:00:09 5722 8192000000 10435893616 10881421312 1189251728 12.676 100 61 118 0 1546070432 341464768 15353936
12:01:18 4798 8192000000 10404637536 10859274240 1170568736 12.502 99 70 135 0 1507352896 319569776 17214384
12:02:29 863 8192000000 10463771840 10922745856 1179568752 12.586 100 98 195 1 1568479872 365599232 23311888
12:03:36 4976 8192000000 10419486736 10874146816 1177334080 12.565 100 61 120 0 1530303504 337730128 15239296
12:04:44 9068 8192000000 10413327440 10873204736 1153897968 12.346 98 60 120 1 1515212144 346795408 14518768
12:05:56 4377 8192000000 10410847424 10930839552 1169110096 12.489 99 71 139 0 1518189632 332308912 16770624
12:07:04 18873 8192000000 10404804096 10840457216 1175374128 12.547 100 41 80 0 1496505392 310949280 10181984
12:08:53 1730 8192000000 10409632928 10847125504 1166849312 12.467 100 54 104 0 1504347392 325328192 12169888
12:10:00 10732 8192000000 10382227024 10809257984 1151990992 12.328 99 57 110 0 1472919744 308170480 12758272
12:11:12 20673 8192000000 10301893456 10806419456 1148636672 12.297 99 38 76 2 1411078272 253094800 9346800
12:12:36 11050 8192000000 10299762000 10770939904 1157793104 12.383 100 33 66 1 1387798064 221569392 8435568
12:13:53 37278 8192000000 10174757616 10667098112 1120251984 12.029 97 18 36 0 1288627744 163640704 4735056
12:15:35 81062 8192000000 10104358896 10683748352 1138169424 12.198 99 13 25 3 1305344560 163846880 3328256
12:18:25 35370 8192000000 10091838736 10522951680 1131107168 12.132 99 36 71 1 1188846048 49864624 7874256
12:20:03 90250 8192000000 10122522560 10562093056 1111533760 11.947 97 47 90 2 1169705328 49109072 9062496
12:22:34 24764 8192000000 10052892160 10479906816 1114964976 11.979 99 54 94 3 1147054512 21891712 10197824
12:24:02 46075 8192000000 10087276496 10548088832 1123558704 12.061 99 38 74 3 1210904512 79019056 8326752
12:25:54 67900 8192000000 10130012560 10591907840 1122267040 12.048 98 23 46 0 1210232128 82563824 5401264
12:28:05 3174 8192000000 10174774544 10612641792 1143709472 12.250 100 53 102 0 1281147040 126410480 11027088
12:29:14 10960 8192000000 10166927024 10583396352 1142266320 12.237 99 82 157 2 1255704864 95348448 18090096
12:30:26 18792 8192000000 10196706160 10658299904 1135985888 12.178 99 39 74 0 1301089296 157140992 7962416
12:31:53 68481 8192000000 10218565552 10686767104 1128884928 12.111 99 18 36 2 1309305392 175288944 5131520
12:34:01 17881 8192000000 10157637520 10665750528 1131828576 12.139 100 8 16 1 1255134448 121297584 2008288
12:35:21 84026 8192000000 10056243136 10520518656 1135638368 12.174 100 7 15 0 1184379728 47053280 1688080
12:37:48 64560 8192000000 10170900016 10612957184 1150511456 12.314 100 18 36 0 1239898464 85663520 3723488
12:39:53 59110 8192000000 10145299920 10601095168 1131628480 12.137 98 25 50 1 1223302624 86287888 5386256
12:41:53 33420 8192000000 10124043824 10607484928 1149289184 12.303 100 34 68 1 1265197808 108935904 6972720
12:43:30 106953 8192000000 10137696224 10610200576 1127036336 12.093 97 28 56 0 1224125904 91094000 5995568
12:46:19 77944 8192000000 10130303824 10605363200 1104244928 11.878 96 13 26 0 1199401824 91697392 3459504
12:48:38 26188 8192000000 10071453296 10498023424 1114860544 11.978 98 29 57 1 1164477200 44199536 5417120
12:50:08 150855 8192000000 10062485808 10500984832 1113995456 11.970 98 31 58 1 1162456096 42477536 5983104
12:53:41 13111 8192000000 10072078256 10494316544 1110859216 11.941 99 44 84 0 1157947248 38452016 8636016
12:54:57 45912 8192000000 10067415264 10524749824 1109324288 11.926 98 16 32 2 1171377744 58638768 3414688
12:56:43 60146 8192000000 10074969312 10530971648 1112681680 11.958 98 32 61 2 1194088112 74508800 6897632
12:58:43 63360 8192000000 10116931104 10566807552 1120290656 12.030 99 15 30 1 1206275552 82245696 3739200
13:00:47 16189 8192000000 10126391488 10566586368 1120812384 12.035 99 53 85 2 1227619008 96706048 10100576
13:02:04 49595 8192000000 10065485472 10504441856 1088435888 11.728 96 13 26 1 1134474448 43626144 2412416
13:04:25 37896 8192000000 10079179328 10512318464 1112656400 11.958 98 40 76 1 1166914144 46780064 7477680
13:06:05 22358 8192000000 10081363744 10512068608 1108345456 11.917 98 33 66 0 1156763280 41996176 6421648
13:07:29 18427 8192000000 10092769968 10540728320 1122617856 12.052 99 44 88 2 1195870096 64077104 9175136
13:09:03 16427 8192000000 10146188256 10572742656 1136363984 12.181 100 49 98 1 1231950048 85754464 9831600
13:10:22 54124 8192000000 10166816720 10611994624 1111193360 11.944 97 29 55 1 1254340672 136872384 6274928
13:12:17 48193 8192000000 10245775840 10686533632 1141031008 12.225 100 25 50 1 1322136464 175770912 5334544
13:14:07 48453 8192000000 10057203952 10539044864 1084549376 11.691 96 15 30 0 1199337168 111697168 3090624
13:15:57 140555 8192000000 10123393008 10586378240 1140148288 12.217 100 39 78 2 1238298688 90049104 8101296
13:19:59 120640 8192000000 10072749136 10542608384 1082972480 11.676 95 21 42 1 1155020992 67472416 4576096
13:23:00 70913 8192000000 10062636608 10509279232 1102599168 11.862 97 15 30 0 1137543232 31198256 3745808
13:25:15 66065 8192000000 10062964048 10539900928 1121710656 12.043 99 15 27 2 1174191616 49266736 3214224
13:27:22 66338 8192000000 10079787520 10527612928 1092407776 11.766 96 24 46 1 1143282240 45532416 5342048
13:29:28 30223 8192000000 10121392192 10564001792 1139211824 12.208 100 44 83 1 1207578336 59175280 9191232
13:31:11 63997 8192000000 10080241408 10575192064 1126164912 12.085 99 25 50 2 1220525312 88285424 6074976
13:33:21 19679 8192000000 10097615840 10524971008 1109152080 11.924 98 46 90 3 1171661264 53323456 9185728
13:34:41 49130 8192000000 10077243952 10551873536 1080527152 11.652 96 34 67 1 1167532464 79936576 7068736
13:36:31 9665 8192000000 10082525792 10510442496 1109942112 11.932 100 49 98 0 1169379600 49619936 9817552

Memory consumption, total, chart

Metadata cache size, chart

Statements activity, chart


Completed "Memory consumption, metadata cache, attachments activity". Done for 00:00:16, from 30-04-2022 13:38:17 to 30-04-2022 13:38:33.

Exceptions occured during test was in run

FB_MNEMONA CNT UNIT FB_GDSCODE
except 45 v_add_invoice_to_stock 335544517
except 5 v_cancel_supplier_invoice 335544517

Completed "Exceptions occured during test was in run". Done for 00:00:02, from 30-04-2022 13:38:34 to 30-04-2022 13:38:36.

Content of mon$database and FB version

MON$DATABASE_NAME               /home/bases/oltp40-etalone.fdb
MON$PAGE_SIZE                   8192
MON$ODS_MAJOR                   13
MON$ODS_MINOR                   0
MON$OLDEST_TRANSACTION          216497
MON$OLDEST_ACTIVE               220700
MON$OLDEST_SNAPSHOT             220700
MON$NEXT_TRANSACTION            220700
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-30 07:30:08.6030 GMT
MON$PAGES                       2073248
MON$STAT_ID                     1
MON$BACKUP_STATE                0
MON$CRYPT_PAGE                  0
MON$OWNER                       SYSDBA                                                                                                                                                                                                                                                      
MON$SEC_DATABASE                Default
MON$CRYPT_STATE                 0
MON$GUID                        {58978C10-B735-40F5-8B7D-F7A1956E782B}
MON$FILE_ID                     02fd0000000000002e02000000000000
MON$NEXT_ATTACHMENT             779
MON$NEXT_STATEMENT              53
MON$REPLICA_MODE                0


ISQL Version: LI-V4.0.2.2761 Firebird 4.0
Server version:
Firebird/Linux/AMD/Intel/x64 (access method), version "LI-V4.0.2.2761 Firebird 4.0"
Firebird/Linux/AMD/Intel/x64 (remote server), version "LI-V4.0.2.2761 Firebird 4.0/tcp (mscs-test-161.budzdorov.ru)/P17:C"
Firebird/Linux/AMD/Intel/x64 (remote interface), version "LI-V4.0.2.2761 Firebird 4.0/tcp (mscs-test-161.budzdorov.ru)/P17:C"
on disk structure version 13.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 ---
:1602: 
:1603: mscs-test-161.budzdorov.ru    Sat Apr 30 13:37:14 2022
:1604:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:1605: 
:1606: 
:1607: mscs-test-161.budzdorov.ru    Sat Apr 30 13:37:19 2022
:1608:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:1609: 
:1610: 
:1611: mscs-test-161.budzdorov.ru    Sat Apr 30 13:37:21 2022
:1612:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:1613: 
--- end of diff output ---

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

30.04.22 13:38:37. There are 3 logs in /var/tmp/logs-oltp40 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-04-30 13:38:40 No severe PSQL-related problems occured
30.04.22 13:38:41. End of report.