Generated by /opt/oltp-emul/oltp_isql_run_worker.sh, ISQL session No. 1 of total launched 100. 05.10.2021 19:39
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 15943496 kB
MemAvailable 30733972 kB
Buffers 0 kB
Cached 15769848 kB
SwapCached 4772 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.8
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 2021-10-05 19:37:49
DTS_END                         2021-10-05 19:37:49.0430
FB_GDSCODE                      -1
FB_MNEMONA                      
STACK                           SRV_RECALC_IDX_STAT(108:9) ==> SP_CHECK_TO_STOP_WORK(32:12) ==> SP_HALT_ON_ERROR(57:17)
IP                              ::1/43206
TRN_ID                          245672
ATT_ID                          697
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: 9118.48 22425 1094218
customer order: creation 175.43 364 21052
customer order: refuse 14.79 334 1775
order to supplier: creation 46.80 1257 5616
order to supplier: removal 3.50 96023 420
invoice (draft): creation 46.99 3431 5639
invoice (draft): removal 49.83 851 5980
invoice accept: apply 42.68 18531 5121
invoice accept: cancel 45.37 878 5444
customer reserve: creation 3932.59 184 471911
customer reserve: removal 4465.44 59 535853
realization accept: apply 84.56 176 10147
realization accept: cancel 79.46 103 9535
payment from customer: creation 59.43 107 7131
payment from customer: removal 5.58 77 670
payment to supplier: creation 49.64 133 5957
payment to supplier: removal 3.76 91 451
service: total inventory turnovers 4.71 1233 565
service: total monetary turnovers 7.02 23 842
service: aggregate perf. data 0.88 21828 105
service: refresh index statistics 0.03 302814 4

Performance in TOTAL, chart


Completed "Performance in TOTAL". Done for 00:00:03, from 05-10-2021 19:39:43 to 05-10-2021 19:39:46.

Performance for every MINUTE

TEST_PHASE_NAME MINUTES_PASSED PERF_SCORE
TEST_TIME 1 870
TEST_TIME 2 1717
TEST_TIME 3 2335
TEST_TIME 4 3371
TEST_TIME 5 3658
TEST_TIME 6 4213
TEST_TIME 7 4243
TEST_TIME 8 4230
TEST_TIME 9 4266
TEST_TIME 10 4637
TEST_TIME 11 5087
TEST_TIME 12 5681
TEST_TIME 13 5846
TEST_TIME 14 6325
TEST_TIME 15 6813
TEST_TIME 16 7039
TEST_TIME 17 7406
TEST_TIME 18 7376
TEST_TIME 19 7568
TEST_TIME 20 8061
TEST_TIME 21 8138
TEST_TIME 22 8348
TEST_TIME 23 8886
TEST_TIME 24 9084
TEST_TIME 25 9306
TEST_TIME 26 9663
TEST_TIME 27 9710
TEST_TIME 28 9968
TEST_TIME 29 10000
TEST_TIME 30 10445
TEST_TIME 31 10354
TEST_TIME 32 10152
TEST_TIME 33 9996
TEST_TIME 34 9864
TEST_TIME 35 10041
TEST_TIME 36 10038
TEST_TIME 37 9962
TEST_TIME 38 9841
TEST_TIME 39 9721
TEST_TIME 40 9911
TEST_TIME 41 9746
TEST_TIME 42 9688
TEST_TIME 43 9677
TEST_TIME 44 9617
TEST_TIME 45 9588
TEST_TIME 46 9419
TEST_TIME 47 9400
TEST_TIME 48 9389
TEST_TIME 49 9243
TEST_TIME 50 9209
TEST_TIME 51 9242
TEST_TIME 52 9260
TEST_TIME 53 9203
TEST_TIME 54 9137
TEST_TIME 55 9068
TEST_TIME 56 9083
TEST_TIME 57 9080
TEST_TIME 58 9041
TEST_TIME 59 9144
TEST_TIME 60 9084
TEST_TIME 61 9112
TEST_TIME 62 9131
TEST_TIME 63 9271
TEST_TIME 64 9348
TEST_TIME 65 9266
TEST_TIME 66 9307
TEST_TIME 67 9306
TEST_TIME 68 9300
TEST_TIME 69 9375
TEST_TIME 70 9325
TEST_TIME 71 9383
TEST_TIME 72 9331
TEST_TIME 73 9244
TEST_TIME 74 9284
TEST_TIME 75 9254
TEST_TIME 76 9198
TEST_TIME 77 9180
TEST_TIME 78 9109
TEST_TIME 79 9071
TEST_TIME 80 9078
TEST_TIME 81 9056
TEST_TIME 82 9021
TEST_TIME 83 8991
TEST_TIME 84 9038
TEST_TIME 85 9021
TEST_TIME 86 9013
TEST_TIME 87 9113
TEST_TIME 88 9069
TEST_TIME 89 9133
TEST_TIME 90 9107
TEST_TIME 91 9143
TEST_TIME 92 9109
TEST_TIME 93 9228
TEST_TIME 94 9232
TEST_TIME 95 9232
TEST_TIME 96 9238
TEST_TIME 97 9196
TEST_TIME 98 9157
TEST_TIME 99 9150
TEST_TIME 100 9145
TEST_TIME 101 9112
TEST_TIME 102 9052
TEST_TIME 103 9035
TEST_TIME 104 9034
TEST_TIME 105 9007
TEST_TIME 106 9034
TEST_TIME 107 9013
TEST_TIME 108 9018
TEST_TIME 109 9011
TEST_TIME 110 9033
TEST_TIME 111 9041
TEST_TIME 112 9020
TEST_TIME 113 9028
TEST_TIME 114 9120
TEST_TIME 115 9078
TEST_TIME 116 9091
TEST_TIME 117 9110
TEST_TIME 118 9129
TEST_TIME 119 9098
TEST_TIME 120 9119

Performance per minute, chart


Completed "Performance for every MINUTE". Done for 00:00:03, from 05-10-2021 19:39:47 to 05-10-2021 19:39:50.

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 1532363 1532363 0 0.00 0 28383 7 0 0
doc_list_biud 1532351 1532351 0 0.00 0 43392 27 0 0
sp_add_invoice_to_stock 5224 5121 103 1.97 35 191608 18532 0 103
sp_cancel_adding_invoice 5444 5444 0 0.00 6 53409 878 0 0
sp_cancel_client_order 1775 1775 0 0.00 4 10598 334 0 0
sp_cancel_customer_reserve 535853 535853 0 0.00 1 43397 60 0 0
sp_cancel_pay_from_customer 670 670 0 0.00 3 4242 78 0 0
sp_cancel_pay_to_supplier 451 451 0 0.00 3 5191 91 0 0
sp_cancel_supplier_invoice 5987 5980 7 0.11 2 38464 852 0 7
sp_cancel_supplier_order 420 420 0 0.00 6 1015298 96024 0 0
sp_cancel_write_off 9535 9535 0 0.00 1 13501 104 0 0
sp_client_order 21052 21052 0 0.00 4 35213 365 0 0
sp_customer_reserve 471911 471911 0 0.00 0 45349 185 0 0
sp_fill_shopping_cart 32305 32305 0 0.00 1 21042 40 0 0
sp_fill_shopping_cart_clo_res 471910 471910 0 0.00 0 22492 14 0 0
sp_get_clo_for_invoice 5120 5120 0 0.00 0 34648 329 0 0
sp_kill_cost_storno 16100 16100 0 0.00 0 6561 54 0 0
sp_kill_qstorno_ret_qs2qd 1087641 1087641 0 0.00 0 43382 33 0 0
sp_kill_qty_storno 574272 574272 0 0.00 0 43391 71 0 0
sp_lock_selected_doc 21165 21165 0 0.00 0 6916 5 0 0
sp_make_cost_storno 28355 28355 0 0.00 0 28373 58 0 0
sp_multiply_rows_for_pdistr 28348 28348 0 0.00 0 6905 28 0 0
sp_multiply_rows_for_qdistr 21052 21052 0 0.00 0 35199 152 0 0
sp_pay_from_customer 7131 7131 0 0.00 4 9949 107 0 0
sp_pay_to_supplier 5957 5957 0 0.00 4 16861 133 0 0
sp_payment_common 13079 13079 0 0.00 1 6400 27 0 0
sp_qd_handle_on_cancel_clo 1775 1775 0 0.00 0 10591 307 0 0
sp_qd_handle_on_invoice_upd_sts 10562 10562 0 0.00 0 13702 332 0 0
sp_qd_handle_on_reserve_upd_sts 10147 10147 0 0.00 0 16705 59 0 0
sp_reserve_write_off 10147 10147 0 0.00 6 17008 176 0 0
sp_supplier_invoice 5639 5639 0 0.00 6 97501 3431 0 0
sp_supplier_order 5616 5616 0 0.00 5 34257 1257 0 0
srv_aggregate_perf_data 105 105 0 0.00 2495 237398 21828 0 0
srv_fill_mon_cache_memory 64 64 0 0.00 1446 154470 45396 0 0
srv_find_qd_qs_mism 1046213 1046213 0 0.00 0 13643 6 0 0
srv_make_invnt_saldo 565 565 0 0.00 36 35017 1233 0 0
srv_make_money_saldo 842 842 0 0.00 1 917 24 0 0
srv_recalc_idx_stat 4 4 0 0.00 132410 418493 302814 0 0
t$perf-abend:sp_add_invoice_to_stock 103 103 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 5121 5121 0 0.00 0 13141 151 0 0
t$perf-norm:sp_cancel_adding_invoice 487 487 0 0.00 0 4875 125 0 0
t$perf-norm:sp_cancel_client_order 1775 1775 0 0.00 0 1154 9 0 0
t$perf-norm:sp_cancel_customer_reserve 685 685 0 0.00 0 8957 24 0 0
t$perf-norm:sp_cancel_pay_from_customer 670 670 0 0.00 0 8304 22 0 0
t$perf-norm:sp_cancel_pay_to_supplier 451 451 0 0.00 0 2342 11 0 0
t$perf-norm:sp_cancel_supplier_invoice 392 392 0 0.00 0 4420 27 0 0
t$perf-norm:sp_cancel_supplier_order 420 420 0 0.00 0 41809 1608 0 0
t$perf-norm:sp_cancel_write_off 1020 1020 0 0.00 0 1303 6 0 0
t$perf-norm:sp_client_order 21052 21052 0 0.00 0 12276 19 0 0
t$perf-norm:sp_customer_reserve 944 944 0 0.00 0 2292 5 0 0
t$perf-norm:sp_pay_from_customer 7131 7131 0 0.00 0 4796 10 0 0
t$perf-norm:sp_pay_to_supplier 5957 5957 0 0.00 0 8666 12 0 0
t$perf-norm:sp_reserve_write_off 10147 10147 0 0.00 0 5837 10 0 0
t$perf-norm:sp_supplier_invoice 5639 5639 0 0.00 0 8457 22 0 0
t$perf-norm:sp_supplier_order 5616 5616 0 0.00 0 7662 18 0 0
t$perf-norm:srv_aggregate_perf_data 105 105 0 0.00 0 612 12 0 0
t$perf-norm:srv_fill_mon_cache_memory 64 64 0 0.00 0 2380 42 0 0
t$perf-norm:srv_make_invnt_saldo 565 565 0 0.00 0 4638 29 0 0
t$perf-norm:srv_make_money_saldo 842 842 0 0.00 0 784 15 0 0
t$perf-norm:srv_recalc_idx_stat 4 4 0 0.00 3 13 7 0 0
v_add_invoice_to_stock 10442 10236 206 1.97 0 6114 18 0 206
v_all_customers 37996 37996 0 0.00 0 29 1 0 0
v_all_suppliers 30818 30818 0 0.00 0 17 1 0 0
v_all_wares 42104 42104 0 0.00 0 46 1 0 0
v_cancel_adding_invoice 974 974 0 0.00 0 2046 8 0 0
v_cancel_client_order 3550 3550 0 0.00 0 5341 7 0 0
v_cancel_customer_prepayment 1340 1340 0 0.00 0 1366 6 0 0
v_cancel_customer_reserve 1370 1370 0 0.00 0 1693 4 0 0
v_cancel_payment_to_supplier 902 902 0 0.00 0 4324 9 0 0
v_cancel_supplier_invoice 798 784 14 1.75 0 240 12 0 14
v_cancel_supplier_order 840 840 0 0.00 0 5992 17 0 0
v_cancel_write_off 2040 2040 0 0.00 0 5052 19 0 0
v_max_id_clo_ord 5616 5616 0 0.00 0 603 1 0 0
v_max_id_clo_res 944 944 0 0.00 0 2743 14 0 0
v_max_id_ord_sup 5637 5637 0 0.00 0 5900 7 0 0
v_max_non_paid_invoice 1796 1796 0 0.00 0 2194 5 0 0
v_max_non_paid_realizn 3918 3918 0 0.00 0 5153 9 0 0
v_min_id_clo_ord 5616 5616 0 0.00 0 2771 6 0 0
v_min_id_clo_res 944 944 0 0.00 0 22816 72 0 0
v_min_id_ord_sup 5637 5637 0 0.00 0 8195 8 0 0
v_min_non_paid_invoice 5952 5952 0 0.00 0 6053 17 0 0
v_min_non_paid_realizn 7127 7127 0 0.00 0 5903 15 0 0
v_our_firm 10526 10526 0 0.00 0 18 1 0 0
v_reserve_write_off 20294 20294 0 0.00 0 5998 6 0 0
x_lock_depdocs_on_canc_invoice 11032 11032 0 0.00 0 15176 128 0 0
x_lock_depdocs_on_canc_sup_ord 420 420 0 0.00 0 2409 300 0 0
x_make_qstorno_1000_1200 5616 5616 0 0.00 1 34249 1177 0 0
x_make_qstorno_1200_2000 5639 5639 0 0.00 3 97237 3282 0 0
x_make_qstorno_2100_3300 471911 471911 0 0.00 0 44907 168 0 0

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

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:07:52 2 8192000000 8798783728 8809381888 5422784 0.066 1 1 2 0 5540832 55488 62560
17:08:53 13146 8192000000 10361984656 10677211136 1417896672 14.754 100 91 182 0 1453527088 5761696 29868720
17:10:10 14314 8192000000 10416743056 10741547008 1472506192 15.236 100 88 176 0 1509122592 8143008 28473392
17:11:30 13404 8192000000 10472713040 10807250944 1532079728 15.755 100 95 190 0 1571927968 10006816 29841424
17:12:46 14659 8192000000 10555585760 10904584192 1605771136 16.389 100 81 162 0 1640922912 11376288 23775488
17:14:02 12125 8192000000 10630704448 10995281920 1679820720 17.016 100 73 146 0 1712499904 11847520 20831664
17:15:19 6574 8192000000 10692129136 11068874752 1755970528 17.651 100 86 172 0 1794263888 14302112 23991248
17:16:30 3069 8192000000 10751361216 11129950208 1806748784 18.069 100 86 171 1 1844689824 13606128 24334912
17:17:35 2189 8192000000 10798326608 11186089984 1852838864 18.445 100 91 181 1 1893182608 14433184 25910560
17:18:38 44628 8192000000 10813501856 11218399232 1882051216 18.682 100 68 136 1 1912132208 10415040 19665952
17:20:23 12177 8192000000 10786079408 11220008960 1887297152 18.724 100 30 60 0 1903410704 7418480 8695072
17:21:39 12645 8192000000 10798150656 11231662080 1894369120 18.781 100 27 54 1 1908525792 5927408 8229264
17:22:56 12821 8192000000 10803354192 11239628800 1896054720 18.795 100 14 28 1 1905781472 6028080 3698672
17:24:10 28469 8192000000 10810458544 11250012160 1905860720 18.873 100 31 63 0 1920695008 5386864 9447424
17:25:39 9116 8192000000 10820907824 11250843648 1908874864 18.898 100 36 72 0 1925317712 5994144 10448704
17:26:49 5007 8192000000 10806974720 11239624704 1876815472 18.639 99 23 46 2 1893439840 10454560 6169808
17:27:55 10574 8192000000 10779823152 11206340608 1840378736 18.344 98 13 26 2 1849118256 5145680 3593840
17:29:06 7889 8192000000 10778120800 11212984320 1870271600 18.586 100 48 92 1 1890028528 6162512 13594416
17:30:15 5107 8192000000 10697072304 11113357312 1754106800 17.636 97 22 42 0 1766202336 5336576 6758960
17:31:22 7062 8192000000 10697326000 11110723584 1761567216 17.697 98 22 44 1 1773365248 5681600 6116432
17:32:29 7305 8192000000 10733717152 11155935232 1795169280 17.974 98 22 43 3 1806797344 5552912 6075152
17:33:38 29686 8192000000 10751976784 11186335744 1849782000 18.420 100 34 68 0 1866450784 6054864 10613920
17:35:11 9229 8192000000 10778772816 11209531392 1866617408 18.557 100 18 36 0 1877318336 5237824 5463104
17:36:22 6838 8192000000 10803788960 11222839296 1875716928 18.631 100 32 62 3 1892331712 5651920 10962864
17:37:30 15696 8192000000 10816668704 11248115712 1903069056 18.851 100 19 36 1 1913031056 4809136 5152864
17:38:49 23006 8192000000 10864217616 11278512128 1925726544 19.033 100 54 106 1 1947907600 7419264 14761792
17:40:30 34619 8192000000 10887964528 11315027968 1946098032 19.195 100 51 102 0 1971840176 11290640 14451504
17:42:13 31071 8192000000 10878564080 11312779264 1941496576 19.159 99 35 70 1 1965921216 13674464 10750176
17:44:06 22487 8192000000 10922453648 11360337920 1983790544 19.495 100 44 87 3 2013665488 17283840 12591104
17:45:32 10438 8192000000 10932332928 11359690752 1979794560 19.463 99 58 116 2 2015997040 18838352 17364128
17:46:46 6041 8192000000 10956292816 11386245120 2001622080 19.636 100 60 120 1 2042032720 22491024 17919616
17:47:58 8466 8192000000 10944939472 11395616768 2005001200 19.662 100 41 82 1 2045213728 27111008 13101520
17:49:28 4615 8192000000 10978022976 11409768448 2013568624 19.730 100 69 136 3 2065242880 30835952 20838304
17:50:41 1443 8192000000 10996340656 11410239488 2014854848 19.740 100 88 172 2 2076425344 35202096 26368400
17:51:45 1806 8192000000 10938702992 11352059904 1965173824 19.347 99 84 166 1 2027125824 37260768 24691232
17:52:50 2818 8192000000 10945614944 11357589504 1954920656 19.266 99 74 144 0 2009097808 30817264 23359888
17:53:59 1686 8192000000 10977711936 11388612608 1997083744 19.600 100 92 183 2 2058038336 34260288 26694304
17:55:05 3093 8192000000 10955711600 11369353216 1961393248 19.317 99 83 165 0 2020166768 33776848 24996672
17:56:14 1773 8192000000 10948409024 11363852288 1967327664 19.364 100 81 163 2 2033707776 41059984 25320128
17:57:21 6291 8192000000 10911999408 11343798272 1928143936 19.052 99 54 108 0 1989242432 43957968 17140528
17:58:34 7618 8192000000 10916767744 11332313088 1917358064 18.966 99 54 108 2 1975909376 39664944 18886368
17:59:43 8846 8192000000 10895415456 11330904064 1923397600 19.014 100 46 92 1 1975563088 37488224 14677264
18:00:55 11124 8192000000 10904610064 11352608768 1946340288 19.197 100 36 72 1 1991453760 33466688 11646784
18:02:21 17658 8192000000 10892513584 11331432448 1919272240 18.981 99 26 53 0 1963018128 34552400 9193488
18:03:44 17372 8192000000 10881218320 11337945088 1918997152 18.979 99 19 38 0 1951837920 26509408 6331360
18:05:18 34386 8192000000 10899007760 11334098944 1932860416 19.090 100 23 46 3 1964487312 24677136 6949760
18:06:58 44011 8192000000 10861425728 11324698624 1874443536 18.620 97 9 18 0 1901654736 24769248 2441952
18:08:51 38695 8192000000 10897229632 11337076736 1946951456 19.202 100 32 63 0 1965700624 9800752 8948416
18:10:34 120643 8192000000 10873746464 11342422016 1924220224 19.021 98 20 40 0 1945032992 14957872 5854896
18:13:51 49492 8192000000 10879154336 11330674688 1947173728 19.204 100 32 64 1 1967253440 10864272 9215440
18:15:45 43116 8192000000 10911919296 11364016128 1972848608 19.408 100 37 74 0 1996726000 12799536 11077856
18:17:33 52434 8192000000 10896916256 11363409920 1951479920 19.238 99 11 22 1 1966420016 11952096 2988000
18:19:26 57228 8192000000 10885817264 11341058048 1936204368 19.116 98 22 44 1 1953940032 9876624 7859040
18:21:24 41180 8192000000 10886477680 11348094976 1953186656 19.252 99 17 34 0 1968476336 10423904 4865776
18:23:15 93655 8192000000 10886112832 11357970432 1966076624 19.354 100 8 16 0 1978364784 9993984 2294176
18:25:50 76031 8192000000 10935020576 11384811520 1988263664 19.530 100 23 46 0 2003782672 8980528 6538480
18:28:08 54079 8192000000 10925328688 11410993152 2008818880 19.692 100 22 43 2 2027172336 12208832 6144624
18:30:05 39306 8192000000 10900486160 11373023232 1921832896 19.002 96 16 31 1 1936652992 10379968 4440128
18:31:44 58109 8192000000 10916997040 11381915648 1988323840 19.531 100 24 50 1 2011654784 15455600 7875344
18:35:00 39938 8192000000 10901908976 11380822016 1978431184 19.452 99 7 14 1 1989993840 9759536 1803120
18:36:44 49784 8192000000 10925237984 11387256832 1975582144 19.430 99 16 32 0 1990695296 11126096 3987056
18:38:34 48989 8192000000 10904735888 11382362112 1930220416 19.069 97 11 22 0 1944654128 11474896 2958816
18:40:24 62818 8192000000 10895729952 11360612352 1904945008 18.866 96 16 32 2 1926454960 17217408 4292544
18:42:27 50983 8192000000 10910726976 11368325120 1981220608 19.474 100 35 70 0 2001796368 10968608 9607152
18:44:23 41314 8192000000 10904829104 11362414592 1923091680 19.012 97 29 58 0 1941829904 10984304 7753920
18:46:17 43632 8192000000 10854861680 11323097088 1899740000 18.824 98 30 61 0 1924152640 16010256 8402384
18:48:07 42426 8192000000 10886717424 11348807680 1934299888 19.101 99 34 68 2 1962249680 18645104 9304688
18:49:57 91370 8192000000 10822147168 11272413184 1872589520 18.605 97 40 80 1 1896521408 12226752 11705136
18:52:38 44645 8192000000 10856784480 11324477440 1912086528 18.923 99 19 38 0 1932400064 14257792 6055744
18:54:47 50170 8192000000 10829762464 11298754560 1885621440 18.710 98 8 16 0 1896259952 8290016 2348496
18:56:57 70791 8192000000 10852203376 11326656512 1920631504 18.992 99 13 26 0 1933913072 9454816 3826752
18:59:08 71483 8192000000 10846025200 11322384384 1883152800 18.691 97 7 14 0 1896710608 11308480 2249328
19:01:20 79339 8192000000 10884731264 11349786624 1942074768 19.163 99 29 58 0 1959963472 9890400 7998304
19:03:40 65299 8192000000 10875639376 11353919488 1922926080 19.010 98 22 42 1 1943110848 14432640 5752128
19:05:45 67578 8192000000 10873727936 11356864512 1937399472 19.126 99 16 32 1 1954037744 12125104 4513168
19:07:54 73812 8192000000 10904404896 11375386624 1937693296 19.128 98 18 36 1 1954200384 12030480 4476608
19:10:08 154470 8192000000 10911870896 11385696256 1932946736 19.090 97 12 24 0 1950006592 14040752 3019104
19:13:43 114121 8192000000 10904283312 11374788608 1938973280 19.139 97 24 48 0 1960887008 14589104 7324624
19:16:56 34759 8192000000 10919402624 11386929152 1992381936 19.563 100 22 44 0 2012243104 13153712 6707456
19:18:34 74802 8192000000 10889540160 11364773888 1950072416 19.227 98 17 34 0 1969709744 14634576 5002752
19:20:51 67489 8192000000 10865989696 11335995392 1934611888 19.104 99 10 20 1 1949648544 11746624 3290032
19:23:27 44023 8192000000 10882135904 11361587200 1951104064 19.235 99 12 24 0 1964909472 10274224 3531184
19:25:12 63479 8192000000 10899694944 11375063040 1935296400 19.109 98 16 32 0 1949119056 9163680 4658976
19:27:15 41110 8192000000 10878746384 11344871424 1901299424 18.837 97 22 44 0 1917095984 9579584 6216976
19:29:01 43264 8192000000 10892632272 11348377600 1923064496 19.011 98 29 58 3 1939290960 8717920 7508544
19:30:49 105357 8192000000 10869352304 11342237696 1881667616 18.679 96 10 20 1 1907906400 23526624 2712160
19:33:36 72506 8192000000 10881404592 11339341824 1881456704 18.677 96 30 60 2 1903902352 14052208 8393440
19:35:49 35300 8192000000 10871600848 11325263872 1854858672 18.462 95 16 32 0 1866118208 6682784 4576752
19:37:25 35344 8192000000 9637940080 9974001664 763789008 8.528 40 3 6 0 773234800 9070896 374896

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 19:39:57 to 05-10-2021 19:40:12.

Exceptions occured during test was in run

FB_MNEMONA CNT UNIT FB_GDSCODE
except 103 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 19:40:13 to 05-10-2021 19:40:15.

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          245671
MON$OLDEST_ACTIVE               246743
MON$OLDEST_SNAPSHOT             246743
MON$NEXT_TRANSACTION            246743
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                       2039968
MON$STAT_ID                     1
MON$BACKUP_STATE                0
MON$CRYPT_PAGE                  0
MON$OWNER                       SYSDBA                                                                                       
MON$SEC_DATABASE                Default


ISQL Version: LI-V3.0.8.33506 Firebird 3.0
Server version:
Firebird/Linux/AMD/Intel/x64 (access method), version "LI-V3.0.8.33506 Firebird 3.0"
Firebird/Linux/AMD/Intel/x64 (remote server), version "LI-V3.0.8.33506 Firebird 3.0/tcp (mscs-test-161.budzdorov.ru)/P15:C"
Firebird/Linux/AMD/Intel/x64 (remote interface), version "LI-V3.0.8.33506 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 ---
:243: 
:244: mscs-test-161.budzdorov.ru    Tue Oct  5 19:38:15 2021
:245:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3333
:246: 
:247: 
:248: mscs-test-161.budzdorov.ru    Tue Oct  5 19:38:15 2021
:249:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3333
:250: 
:251: 
:252: mscs-test-161.budzdorov.ru    Tue Oct  5 19:38:16 2021
:253:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3333
:254: 
:255: 
:256: mscs-test-161.budzdorov.ru    Tue Oct  5 19:38:21 2021
:257:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3333
:258: 
:259: 
:260: mscs-test-161.budzdorov.ru    Tue Oct  5 19:38:21 2021
:261:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3333
:262: 
:263: 
:264: mscs-test-161.budzdorov.ru    Tue Oct  5 19:38:21 2021
:265:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3333
:266: 
--- end of diff output ---

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

05.10.21 19:40:16. 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
2021-10-05 19:40:18 No severe PSQL-related problems occured
05.10.21 19:40:20. End of report.