Generated by /opt/oltp-emul/oltp_isql_run_worker.sh, ISQL session No. 1 of total launched 100. 05.10.2021 10: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 58e1ddde69c44dad93d327777e5becec
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-05-09 08:45
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 4793.92
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 16028336 kB
MemAvailable 30769888 kB
Buffers 0 kB
Cached 15713492 kB
SwapCached 4828 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.1
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 2021-10-05 10:37:06
DTS_END                         2021-10-05 10:37:06.1830
FB_GDSCODE                      -1
FB_MNEMONA                      
STACK                           SP_SUPPLIER_ORDER(38:5) ==> SP_CHECK_TO_STOP_WORK(32:12) ==> SP_HALT_ON_ERROR(68:17)
IP                              ::1/42740
TRN_ID                          238388
ATT_ID                          655
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: 8874.85 25893 1064982
customer order: creation 169.23 392 20307
customer order: refuse 14.68 362 1761
order to supplier: creation 46.24 1462 5549
order to supplier: removal 3.03 100910 363
invoice (draft): creation 46.32 3975 5558
invoice (draft): removal 48.54 849 5825
invoice accept: apply 41.92 18741 5030
invoice accept: cancel 44.05 927 5286
customer reserve: creation 3896.64 184 467597
customer reserve: removal 4274.88 56 512986
realization accept: apply 82.77 191 9932
realization accept: cancel 78.62 108 9434
payment from customer: creation 59.16 122 7099
payment from customer: removal 5.92 87 710
payment to supplier: creation 48.80 130 5856
payment to supplier: removal 3.54 100 425
service: total inventory turnovers 3.88 3418 466
service: total monetary turnovers 5.90 484 708
service: aggregate perf. data 0.72 21870 86
service: refresh index statistics 0.03 363488 4

Performance in TOTAL, chart


Completed "Performance in TOTAL". Done for 00:00:02, from 05-10-2021 10:38:52 to 05-10-2021 10:38:54.

Performance for every MINUTE

TEST_PHASE_NAME MINUTES_PASSED PERF_SCORE
TEST_TIME 1 6625
TEST_TIME 2 6061
TEST_TIME 3 6873
TEST_TIME 4 6679
TEST_TIME 5 6734
TEST_TIME 6 6538
TEST_TIME 7 7109
TEST_TIME 8 7133
TEST_TIME 9 7571
TEST_TIME 10 7473
TEST_TIME 11 7613
TEST_TIME 12 7983
TEST_TIME 13 8559
TEST_TIME 14 8501
TEST_TIME 15 8439
TEST_TIME 16 8954
TEST_TIME 17 9492
TEST_TIME 18 9613
TEST_TIME 19 9621
TEST_TIME 20 10023
TEST_TIME 21 10459
TEST_TIME 22 10494
TEST_TIME 23 10788
TEST_TIME 24 10852
TEST_TIME 25 10763
TEST_TIME 26 10808
TEST_TIME 27 10418
TEST_TIME 28 10168
TEST_TIME 29 9959
TEST_TIME 30 9766
TEST_TIME 31 9638
TEST_TIME 32 9603
TEST_TIME 33 9630
TEST_TIME 34 9468
TEST_TIME 35 9311
TEST_TIME 36 9278
TEST_TIME 37 9318
TEST_TIME 38 9439
TEST_TIME 39 9393
TEST_TIME 40 9441
TEST_TIME 41 9363
TEST_TIME 42 9410
TEST_TIME 43 9291
TEST_TIME 44 9411
TEST_TIME 45 9327
TEST_TIME 46 9452
TEST_TIME 47 9480
TEST_TIME 48 9443
TEST_TIME 49 9477
TEST_TIME 50 9477
TEST_TIME 51 9556
TEST_TIME 52 9437
TEST_TIME 53 9285
TEST_TIME 54 9217
TEST_TIME 55 9218
TEST_TIME 56 9115
TEST_TIME 57 9097
TEST_TIME 58 9043
TEST_TIME 59 8983
TEST_TIME 60 8921
TEST_TIME 61 8859
TEST_TIME 62 9000
TEST_TIME 63 9064
TEST_TIME 64 9155
TEST_TIME 65 9159
TEST_TIME 66 9175
TEST_TIME 67 9167
TEST_TIME 68 9098
TEST_TIME 69 9197
TEST_TIME 70 9202
TEST_TIME 71 9208
TEST_TIME 72 9330
TEST_TIME 73 9315
TEST_TIME 74 9220
TEST_TIME 75 9162
TEST_TIME 76 9124
TEST_TIME 77 9157
TEST_TIME 78 9096
TEST_TIME 79 9050
TEST_TIME 80 8988
TEST_TIME 81 8906
TEST_TIME 82 8869
TEST_TIME 83 9009
TEST_TIME 84 8970
TEST_TIME 85 8992
TEST_TIME 86 8978
TEST_TIME 87 8967
TEST_TIME 88 8921
TEST_TIME 89 9008
TEST_TIME 90 9109
TEST_TIME 91 9127
TEST_TIME 92 9161
TEST_TIME 93 9201
TEST_TIME 94 9207
TEST_TIME 95 9129
TEST_TIME 96 9100
TEST_TIME 97 9072
TEST_TIME 98 9076
TEST_TIME 99 9048
TEST_TIME 100 9097
TEST_TIME 101 9090
TEST_TIME 102 9036
TEST_TIME 103 9031
TEST_TIME 104 9055
TEST_TIME 105 9039
TEST_TIME 106 9075
TEST_TIME 107 9150
TEST_TIME 108 9157
TEST_TIME 109 9138
TEST_TIME 110 9089
TEST_TIME 111 9053
TEST_TIME 112 9012
TEST_TIME 113 8988
TEST_TIME 114 8952
TEST_TIME 115 8929
TEST_TIME 116 8907
TEST_TIME 117 8884
TEST_TIME 118 8893
TEST_TIME 119 8945
TEST_TIME 120 8878

Performance per minute, chart


Completed "Performance for every MINUTE". Done for 00:00:03, from 05-10-2021 10:38:56 to 05-10-2021 10:38:59.

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 1496388 1496388 0 0.00 0 29899 7 0 0
doc_list_biud 1496388 1496388 0 0.00 0 45122 25 0 0
sp_add_invoice_to_stock 5137 5030 107 2.08 32 172488 18741 0 107
sp_cancel_adding_invoice 5286 5286 0 0.00 4 88240 927 0 0
sp_cancel_client_order 1761 1761 0 0.00 5 31752 362 0 0
sp_cancel_customer_reserve 512986 512986 0 0.00 1 45126 57 0 0
sp_cancel_pay_from_customer 710 710 0 0.00 3 5908 88 0 0
sp_cancel_pay_to_supplier 425 425 0 0.00 3 3662 101 0 0
sp_cancel_supplier_invoice 5832 5825 7 0.12 2 33852 850 0 7
sp_cancel_supplier_order 363 363 0 0.00 10 780030 100910 0 0
sp_cancel_write_off 9434 9434 0 0.00 1 31548 109 0 0
sp_client_order 20307 20307 0 0.00 4 32874 392 0 0
sp_customer_reserve 467597 467597 0 0.00 0 164769 184 0 0
sp_fill_shopping_cart 31389 31389 0 0.00 1 21945 53 0 0
sp_fill_shopping_cart_clo_res 467591 467591 0 0.00 0 13207 15 0 0
sp_get_clo_for_invoice 5023 5023 0 0.00 0 48377 366 0 0
sp_kill_cost_storno 15855 15855 0 0.00 0 8854 51 0 0
sp_kill_qstorno_ret_qs2qd 1041594 1041594 0 0.00 0 45096 31 0 0
sp_kill_qty_storno 550610 550610 0 0.00 0 45122 68 0 0
sp_lock_selected_doc 20775 20775 0 0.00 0 7760 6 0 0
sp_make_cost_storno 27910 27910 0 0.00 0 14925 60 0 0
sp_multiply_rows_for_pdistr 27910 27910 0 0.00 0 14344 32 0 0
sp_multiply_rows_for_qdistr 20307 20307 0 0.00 0 27397 196 0 0
sp_pay_from_customer 7099 7099 0 0.00 4 20025 123 0 0
sp_pay_to_supplier 5856 5856 0 0.00 5 19960 130 0 0
sp_payment_common 12955 12955 0 0.00 1 11278 24 0 0
sp_qd_handle_on_cancel_clo 1761 1761 0 0.00 0 31742 333 0 0
sp_qd_handle_on_invoice_upd_sts 10309 10309 0 0.00 0 42570 353 0 0
sp_qd_handle_on_reserve_upd_sts 9932 9932 0 0.00 0 16754 61 0 0
sp_reserve_write_off 9932 9932 0 0.00 6 16830 191 0 0
sp_supplier_invoice 5558 5558 0 0.00 7 79256 3975 0 0
sp_supplier_order 5549 5549 0 0.00 6 50310 1463 0 0
srv_aggregate_perf_data 86 86 0 0.00 3417 503341 21871 0 0
srv_fill_mon_cache_memory 63 63 0 0.00 2329 225601 49366 0 0
srv_find_qd_qs_mism 1016468 1016468 0 0.00 0 29829 6 0 0
srv_make_invnt_saldo 466 466 0 0.00 29 99545 3418 0 0
srv_make_money_saldo 708 708 0 0.00 1 14734 484 0 0
srv_recalc_idx_stat 4 4 0 0.00 210942 472481 363488 0 0
t$perf-abend:sp_add_invoice_to_stock 107 107 0 0.00 0 0 0 0 0
t$perf-abend:sp_cancel_supplier_invoice 7 7 0 0.00 0 0 0 0 0
t$perf-norm:sp_add_invoice_to_stock 5030 5030 0 0.00 0 22070 144 0 0
t$perf-norm:sp_cancel_adding_invoice 412 412 0 0.00 0 17026 134 0 0
t$perf-norm:sp_cancel_client_order 1761 1761 0 0.00 0 3516 14 0 0
t$perf-norm:sp_cancel_customer_reserve 681 681 0 0.00 0 503 5 0 0
t$perf-norm:sp_cancel_pay_from_customer 710 710 0 0.00 0 10395 29 0 0
t$perf-norm:sp_cancel_pay_to_supplier 425 425 0 0.00 0 308 3 0 0
t$perf-norm:sp_cancel_supplier_invoice 424 424 0 0.00 0 575 9 0 0
t$perf-norm:sp_cancel_supplier_order 363 363 0 0.00 0 17638 1482 0 0
t$perf-norm:sp_cancel_write_off 1049 1049 0 0.00 0 3840 15 0 0
t$perf-norm:sp_client_order 20307 20307 0 0.00 0 10082 18 0 0
t$perf-norm:sp_customer_reserve 998 998 0 0.00 0 3123 8 0 0
t$perf-norm:sp_pay_from_customer 7099 7099 0 0.00 0 5587 10 0 0
t$perf-norm:sp_pay_to_supplier 5856 5856 0 0.00 0 5237 9 0 0
t$perf-norm:sp_reserve_write_off 9932 9932 0 0.00 0 8997 13 0 0
t$perf-norm:sp_supplier_invoice 5559 5559 0 0.00 0 6384 18 0 0
t$perf-norm:sp_supplier_order 5549 5549 0 0.00 0 8774 17 0 0
t$perf-norm:srv_aggregate_perf_data 86 86 0 0.00 0 54 2 0 0
t$perf-norm:srv_fill_mon_cache_memory 63 63 0 0.00 0 19 1 0 0
t$perf-norm:srv_make_invnt_saldo 466 466 0 0.00 0 2745 15 0 0
t$perf-norm:srv_make_money_saldo 708 708 0 0.00 0 3467 8 0 0
t$perf-norm:srv_recalc_idx_stat 4 4 0 0.00 1 5 3 0 0
v_add_invoice_to_stock 10250 10036 214 2.08 0 6858 20 0 214
v_all_customers 37252 37252 0 0.00 0 25 1 0 0
v_all_suppliers 30408 30408 0 0.00 0 21 1 0 0
v_all_wares 40614 40614 0 0.00 0 143 1 0 0
v_cancel_adding_invoice 824 824 0 0.00 0 2830 15 0 0
v_cancel_client_order 3522 3522 0 0.00 0 4819 6 0 0
v_cancel_customer_prepayment 1420 1420 0 0.00 0 1093 6 0 0
v_cancel_customer_reserve 1362 1362 0 0.00 0 2185 6 0 0
v_cancel_payment_to_supplier 850 850 0 0.00 0 1198 6 0 0
v_cancel_supplier_invoice 862 848 14 1.62 0 6537 28 0 14
v_cancel_supplier_order 726 726 0 0.00 0 1298 8 0 0
v_cancel_write_off 2098 2098 0 0.00 0 7615 23 0 0
v_max_id_clo_ord 5546 5546 0 0.00 0 503 1 0 0
v_max_id_clo_res 998 998 0 0.00 0 2401 24 0 0
v_max_id_ord_sup 5534 5534 0 0.00 0 9238 7 0 0
v_max_non_paid_invoice 1732 1732 0 0.00 0 541 2 0 0
v_max_non_paid_realizn 3825 3825 0 0.00 0 4462 4 0 0
v_min_id_clo_ord 5546 5546 0 0.00 0 2680 6 0 0
v_min_id_clo_res 998 998 0 0.00 0 5211 22 0 0
v_min_id_ord_sup 5534 5534 0 0.00 0 7624 11 0 0
v_min_non_paid_invoice 5856 5856 0 0.00 0 6920 16 0 0
v_min_non_paid_realizn 7099 7099 0 0.00 0 5586 15 0 0
v_our_firm 9910 9910 0 0.00 0 10 1 0 0
v_reserve_write_off 19864 19864 0 0.00 0 5607 7 0 0
x_lock_depdocs_on_canc_invoice 10687 10687 0 0.00 0 35501 130 0 0
x_lock_depdocs_on_canc_sup_ord 363 363 0 0.00 0 8404 332 0 0
x_make_qstorno_1000_1200 5549 5549 0 0.00 2 50300 1386 0 0
x_make_qstorno_1200_2000 5558 5558 0 0.00 3 77891 3754 0 0
x_make_qstorno_2100_3300 467597 467597 0 0.00 0 164767 167 0 0

Completed "Performance in DETAILS". Done for 00:00:04, from 05-10-2021 10:39:00 to 05-10-2021 10:39:04.

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
08:07:10 1021 8192000000 8963213072 9031024640 7194816 0.087 3 2 4 0 7381472 115168 71488
08:08:12 16047 8192000000 9710321936 10004787200 782252368 8.716 100 87 174 0 811472912 8236592 20983952
08:09:33 16033 8192000000 9755171488 10059079680 821936880 9.118 100 90 179 1 854507728 10905280 21665568
08:10:59 11238 8192000000 9792671296 10107678720 858466976 9.485 100 87 174 0 895701904 17029072 20205856
08:12:15 14749 8192000000 9848079968 10175959040 897389024 9.872 100 80 160 1 948895680 34126336 17380320
08:13:32 8037 8192000000 9898297264 10242527232 945840096 10.350 100 71 143 0 996739488 35659936 15239456
08:14:46 4959 8192000000 9967383328 10318462976 984478512 10.728 100 87 173 1 1069069632 67345648 17245472
08:15:53 2710 8192000000 9987513712 10348212224 1015380704 11.027 100 86 169 1 1098128720 66042112 16705904
08:16:58 4249 8192000000 10027967776 10396213248 1038742704 11.253 100 81 161 1 1124654240 70118480 15793056
08:18:04 1160 8192000000 10053505760 10426527744 1066441184 11.518 100 91 182 0 1168498208 83747152 18309872
08:19:06 13361 8192000000 10039359184 10443075584 1066495840 11.519 100 51 102 1 1121983760 45382832 10105088
08:20:20 5418 8192000000 10004794192 10400919552 1076524448 11.614 100 54 108 2 1106955904 18395232 12036224
08:21:28 5666 8192000000 10007694656 10407596032 1084009664 11.686 100 29 58 0 1114479008 24357792 6111552
08:22:36 5327 8192000000 10013081088 10413006848 1085446208 11.699 100 31 62 1 1118893632 26656112 6791312
08:23:42 14325 8192000000 10004849472 10413432832 1086717264 11.711 100 45 87 1 1111800240 15583856 9499120
08:24:57 3740 8192000000 10013803792 10412945408 1088727776 11.731 100 41 80 2 1115828128 18072656 9027696
08:26:01 5123 8192000000 10018651184 10413318144 1090400656 11.746 100 53 106 3 1123027856 19678464 12948736
08:27:09 67300 8192000000 9981493440 10389393408 1083480576 11.681 99 43 87 0 1102609088 9074320 10054192
08:29:16 4314 8192000000 9926896064 10295963648 990504208 10.786 96 46 94 1 1028011968 26979824 10527936
08:30:23 7271 8192000000 9944175328 10325700608 990334704 10.785 97 46 90 1 1017882176 16582464 10965008
08:31:31 11482 8192000000 9943041008 10322485248 1010578416 10.981 98 44 84 0 1032775856 10096144 12101296
08:32:44 7492 8192000000 9940961712 10346115072 1020244288 11.074 98 29 58 0 1047802208 20742112 6815808
08:33:52 8461 8192000000 9979664368 10370727936 1056133232 11.419 100 44 88 0 1077921440 11830128 9958080
08:35:02 8131 8192000000 9993288656 10395377664 1067948768 11.532 100 51 102 1 1104679088 25479872 11250448
08:36:13 61358 8192000000 9999411312 10398351360 1078592032 11.634 100 36 72 2 1103057376 16011056 8454288
08:38:32 12769 8192000000 10076654496 10478080000 1110362304 11.936 100 62 121 2 1186326656 63783376 12180976
08:39:54 15958 8192000000 10081776496 10495733760 1126657536 12.090 100 46 90 0 1200542112 64691344 9193232
08:41:24 31432 8192000000 10125273632 10537234432 1143850384 12.252 100 44 87 1 1205483904 52547936 9085584
08:43:02 18113 8192000000 10155223184 10570088448 1154591104 12.353 100 46 91 0 1262630448 98037840 10001504
08:44:23 9909 8192000000 10209562480 10630103040 1161960896 12.422 100 62 121 1 1325778128 151268320 12548912
08:45:37 7128 8192000000 10224969600 10650505216 1174692848 12.541 100 55 110 1 1326902208 140674672 11534688
08:46:46 3129 8192000000 10235199552 10663272448 1178157024 12.573 100 68 134 2 1339292256 146281168 14854064
08:47:55 6096 8192000000 10260256496 10682093568 1183051632 12.619 100 52 104 0 1365636832 170387888 12197312
08:49:06 8859 8192000000 10307779856 10720608256 1168750272 12.485 99 78 157 0 1408273840 222487792 17035776
08:50:19 12653 8192000000 10300267104 10753044480 1148711648 12.297 99 34 68 0 1392126928 234423424 8991856
08:51:45 5865 8192000000 10269970736 10693873664 1138748048 12.204 99 66 131 0 1362293184 208657856 14887280
08:52:56 4627 8192000000 10283088992 10697641984 1129837840 12.120 99 77 154 0 1370869040 223736768 17294432
08:54:05 2327 8192000000 10266011392 10694610944 1148252976 12.293 100 84 165 0 1368728112 201868432 18606704
08:55:12 9894 8192000000 10255251216 10676719616 1152521152 12.333 100 65 129 1 1355673056 189081408 14070496
08:56:23 17378 8192000000 10226616448 10658742272 1111577104 11.947 98 31 62 1 1328527312 209537280 7412928
08:57:43 16574 8192000000 10173219440 10622963712 1120914144 12.036 99 31 61 3 1279116384 150830224 7372016
08:59:01 26053 8192000000 10136198736 10574151680 1105224448 11.887 99 17 34 1 1225338688 116351472 3762768
09:00:29 15693 8192000000 10101933024 10544623616 1105136288 11.886 99 19 38 1 1188167760 78867504 4163968
09:01:49 22843 8192000000 10067199952 10487148544 1095344368 11.793 99 30 60 0 1167224992 64955120 6925504
09:03:20 19732 8192000000 10081717728 10521636864 1106694368 11.901 100 32 61 2 1188175504 73966384 7514752
09:04:43 56334 8192000000 10023844496 10455740416 1090959040 11.752 99 37 73 2 1116516560 17393152 8164368
09:06:48 31400 8192000000 10093943536 10523353088 1105827200 11.893 99 35 69 0 1185053808 71839008 7387600
09:08:19 73198 8192000000 10138312592 10581614592 1109470912 11.927 99 12 25 1 1218521536 106398528 2652096
09:10:33 30705 8192000000 10104564112 10597527552 1119449104 12.022 100 9 18 0 1216119440 94581840 2088496
09:12:46 13425 8192000000 10106115520 10546200576 1121498160 12.041 100 47 93 1 1205013392 73501968 10013264
09:14:02 24403 8192000000 10148949424 10592043008 1136388576 12.182 100 54 109 1 1237052224 89566784 11096864
09:15:40 56952 8192000000 10057881424 10480881664 1098121488 11.820 97 15 28 0 1143164848 42173808 2869552
09:17:41 40844 8192000000 10061615392 10488623104 1128961312 12.112 100 34 67 1 1159933968 23618656 7354000
09:19:25 67001 8192000000 10092756800 10546233344 1115202080 11.982 98 37 74 0 1182770800 59670624 7898096
09:21:33 42244 8192000000 10100123072 10553831424 1122168064 12.047 99 17 32 0 1168963072 43426240 3368768
09:23:15 125704 8192000000 10104851344 10585567232 1123669536 12.062 98 10 20 1 1180355792 54615536 2070720
09:26:21 78645 8192000000 10135898800 10599604224 1151035632 12.319 100 20 40 0 1216394064 61455744 3902688
09:28:41 110534 8192000000 10068326000 10524712960 1141073264 12.226 100 20 40 0 1171108336 25313840 4721232
09:31:33 44113 8192000000 10087271664 10531954688 1129973552 12.121 99 36 72 0 1185167856 47742288 7452016
09:33:21 225582 8192000000 10043909360 10490400768 999490560 10.874 88 13 26 0 1033952688 31637728 2824400
09:38:07 86008 8192000000 10130232672 10578972672 1119081808 12.018 99 23 46 2 1221542256 97583072 4877376
09:40:38 75098 8192000000 10054316448 10535604224 1100173840 11.839 97 13 25 0 1137446336 35088016 2184480
09:42:53 71087 8192000000 10060524496 10498912256 1064358656 11.498 94 24 48 0 1108545104 39764416 4422032
09:45:15 13853 8192000000 10073012288 10494324736 1107310832 11.907 99 64 128 2 1160658016 39165680 14181504
09:46:32 63781 8192000000 10075893216 10523103232 1088996992 11.733 97 19 38 0 1155607504 62531376 4079136
09:48:40 76642 8192000000 10106130752 10606579712 1101015744 11.847 98 17 34 1 1193281392 88453520 3812128
09:51:19 95327 8192000000 10062946368 10512035840 1085622896 11.701 97 35 71 1 1133146816 40118688 7405232
09:53:55 83048 8192000000 10041664336 10539819008 1114775456 11.978 99 13 26 0 1187207344 69511360 2920528
09:56:23 45223 8192000000 10052788672 10494205952 1100835408 11.846 98 10 20 0 1133998688 30990656 2172624
09:58:21 63731 8192000000 10090253872 10549059584 1103374832 11.870 97 17 34 0 1189619232 81627984 4616416
10:00:32 61940 8192000000 10078809648 10538012672 1118553712 12.013 99 17 34 0 1166516496 44613264 3349520
10:02:56 21449 8192000000 10091067584 10527580160 1115103056 11.981 98 38 76 0 1176127792 53026752 7997984
10:04:28 89166 8192000000 10160472304 10624790528 1139702128 12.213 100 24 48 2 1269801088 124392736 5706224
10:06:58 62520 8192000000 10081773968 10531180544 1092369504 11.765 96 21 42 1 1158508352 61944976 4193872
10:09:09 50291 8192000000 10104908144 10562789376 1126651184 12.090 99 32 64 1 1199985152 67032320 6301648
10:11:02 35227 8192000000 10110949840 10541588480 1119777584 12.025 98 32 66 1 1171312064 45332688 6201792
10:12:41 63503 8192000000 10097215648 10550050816 1128597088 12.108 99 27 54 0 1154360064 20743552 5019424
10:14:57 104334 8192000000 10106887936 10557317120 1125887472 12.083 98 15 28 1 1197716448 68258992 3569984
10:17:51 78401 8192000000 10103301776 10550358016 1101810112 11.855 96 13 26 0 1141039376 36592272 2636992
10:20:11 47747 8192000000 10094785328 10538844160 1117835488 12.007 97 31 62 0 1188450176 64188608 6426080
10:22:14 35849 8192000000 10107640240 10560118784 1144893520 12.262 100 13 27 0 1183703120 35735936 3073664
10:23:52 106342 8192000000 10088004560 10598768640 1114353104 11.974 97 16 32 0 1201300496 83921584 3025808
10:27:05 104273 8192000000 10049092944 10507378688 1111433808 11.946 98 32 64 0 1147186608 29020592 6732208
10:29:59 39276 8192000000 10112545200 10549387264 1127923344 12.102 99 38 76 1 1205028512 69302080 7803088
10:31:38 50442 8192000000 10126078048 10563698688 1098591232 11.824 97 21 41 0 1193552048 90721232 4239584
10:33:29 65954 8192000000 10146197184 10621812736 1117526000 12.004 99 21 42 0 1258982672 136401760 5054912
10:36:00 69893 8192000000 9745505824 10151153664 811110096 9.009 73 13 27 0 872351504 58366768 2874640

Memory consumption, total, chart

Metadata cache size, chart

Statements activity, chart


Completed "Memory consumption, metadata cache, attachments activity". Done for 00:00:15, from 05-10-2021 10:39:06 to 05-10-2021 10:39:21.

Exceptions occured during test was in run

FB_MNEMONA CNT UNIT FB_GDSCODE
except 107 v_add_invoice_to_stock 335544517
except 7 v_cancel_supplier_invoice 335544517

Completed "Exceptions occured during test was in run". Done for 00:00:02, from 05-10-2021 10:39:22 to 05-10-2021 10:39:24.

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          234767
MON$OLDEST_ACTIVE               238592
MON$OLDEST_SNAPSHOT             238592
MON$NEXT_TRANSACTION            238592
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                       2034592
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             811
MON$NEXT_STATEMENT              53
MON$REPLICA_MODE                0


ISQL Version: LI-V4.0.1.2622 Firebird 4.0
Server version:
Firebird/Linux/AMD/Intel/x64 (access method), version "LI-V4.0.1.2622 Firebird 4.0"
Firebird/Linux/AMD/Intel/x64 (remote server), version "LI-V4.0.1.2622 Firebird 4.0/tcp (mscs-test-161.budzdorov.ru)/P17:C"
Firebird/Linux/AMD/Intel/x64 (remote interface), version "LI-V4.0.1.2622 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 ---
:99: 
:100: mscs-test-161.budzdorov.ru    Tue Oct  5 08:29:55 2021
:101:     INET/inet_error: read errno = 104
:102: 
:103: 
:104: mscs-test-161.budzdorov.ru    Tue Oct  5 10:37:23 2021
:105:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:106: 
:107: 
:108: mscs-test-161.budzdorov.ru    Tue Oct  5 10:37:23 2021
:109:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:110: 
:111: 
:112: mscs-test-161.budzdorov.ru    Tue Oct  5 10:37:23 2021
:113:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:114: 
--- end of diff output ---

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

05.10.21 10:39:25. 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
2021-10-05 10:39:27 No severe PSQL-related problems occured
05.10.21 10:39:29. End of report.