Generated by /opt/oltp-emul/oltp_isql_run_worker.sh, ISQL session No. 1 of total launched 100. 29.09.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 15976120 kB
MemAvailable 30772472 kB
Buffers 0 kB
Cached 15739996 kB
SwapCached 2920 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-09-29 19:37:54
DTS_END                         2021-09-29 19:37:54.3830
FB_GDSCODE                      -1
FB_MNEMONA                      
STACK                           SP_CLIENT_ORDER(57:5) ==> SP_CHECK_TO_STOP_WORK(32:12) ==> SP_HALT_ON_ERROR(57:17)
IP                              ::1/34384
TRN_ID                          237597
ATT_ID                          673
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: 9228.92 21299 1107471
customer order: creation 168.30 372 20196
customer order: refuse 14.08 330 1689
order to supplier: creation 45.45 1296 5454
order to supplier: removal 3.47 108876 416
invoice (draft): creation 43.93 3522 5272
invoice (draft): removal 53.98 806 6477
invoice accept: apply 40.60 18540 4872
invoice accept: cancel 49.23 780 5907
customer reserve: creation 3721.57 185 446588
customer reserve: removal 4795.41 62 575449
realization accept: apply 82.18 189 9861
realization accept: cancel 82.66 113 9919
payment from customer: creation 58.83 132 7059
payment from customer: removal 5.57 130 668
payment to supplier: creation 48.50 129 5820
payment to supplier: removal 3.31 91 397
service: total inventory turnovers 4.41 1368 529
service: total monetary turnovers 6.63 26 796
service: aggregate perf. data 0.82 23338 98
service: refresh index statistics 0.03 265693 4

Performance in TOTAL, chart


Completed "Performance in TOTAL". Done for 00:00:03, from 29-09-2021 19:39:44 to 29-09-2021 19:39:47.

Performance for every MINUTE

TEST_PHASE_NAME MINUTES_PASSED PERF_SCORE
TEST_TIME 1 5774
TEST_TIME 2 4414
TEST_TIME 3 5098
TEST_TIME 4 4162
TEST_TIME 5 3980
TEST_TIME 6 4427
TEST_TIME 7 4879
TEST_TIME 8 4756
TEST_TIME 9 5502
TEST_TIME 10 5577
TEST_TIME 11 5669
TEST_TIME 12 5870
TEST_TIME 13 5907
TEST_TIME 14 5855
TEST_TIME 15 6471
TEST_TIME 16 6789
TEST_TIME 17 7455
TEST_TIME 18 7369
TEST_TIME 19 7833
TEST_TIME 20 8201
TEST_TIME 21 8591
TEST_TIME 22 8654
TEST_TIME 23 8521
TEST_TIME 24 8724
TEST_TIME 25 9038
TEST_TIME 26 9473
TEST_TIME 27 9440
TEST_TIME 28 10749
TEST_TIME 29 11027
TEST_TIME 30 10874
TEST_TIME 31 10668
TEST_TIME 32 10499
TEST_TIME 33 10184
TEST_TIME 34 10259
TEST_TIME 35 10456
TEST_TIME 36 10303
TEST_TIME 37 10195
TEST_TIME 38 10108
TEST_TIME 39 9955
TEST_TIME 40 9940
TEST_TIME 41 10153
TEST_TIME 42 10102
TEST_TIME 43 10090
TEST_TIME 44 10072
TEST_TIME 45 10059
TEST_TIME 46 10045
TEST_TIME 47 10129
TEST_TIME 48 10092
TEST_TIME 49 10041
TEST_TIME 50 10050
TEST_TIME 51 10074
TEST_TIME 52 9956
TEST_TIME 53 10087
TEST_TIME 54 10070
TEST_TIME 55 10062
TEST_TIME 56 10157
TEST_TIME 57 10085
TEST_TIME 58 10025
TEST_TIME 59 9932
TEST_TIME 60 9808
TEST_TIME 61 9751
TEST_TIME 62 9778
TEST_TIME 63 9701
TEST_TIME 64 9649
TEST_TIME 65 9600
TEST_TIME 66 9512
TEST_TIME 67 9582
TEST_TIME 68 9563
TEST_TIME 69 9551
TEST_TIME 70 9593
TEST_TIME 71 9496
TEST_TIME 72 9540
TEST_TIME 73 9568
TEST_TIME 74 9564
TEST_TIME 75 9611
TEST_TIME 76 9592
TEST_TIME 77 9613
TEST_TIME 78 9568
TEST_TIME 79 9568
TEST_TIME 80 9645
TEST_TIME 81 9590
TEST_TIME 82 9499
TEST_TIME 83 9507
TEST_TIME 84 9482
TEST_TIME 85 9488
TEST_TIME 86 9471
TEST_TIME 87 9408
TEST_TIME 88 9393
TEST_TIME 89 9343
TEST_TIME 90 9324
TEST_TIME 91 9304
TEST_TIME 92 9278
TEST_TIME 93 9326
TEST_TIME 94 9357
TEST_TIME 95 9353
TEST_TIME 96 9380
TEST_TIME 97 9418
TEST_TIME 98 9403
TEST_TIME 99 9400
TEST_TIME 100 9412
TEST_TIME 101 9388
TEST_TIME 102 9429
TEST_TIME 103 9526
TEST_TIME 104 9553
TEST_TIME 105 9600
TEST_TIME 106 9516
TEST_TIME 107 9524
TEST_TIME 108 9479
TEST_TIME 109 9459
TEST_TIME 110 9403
TEST_TIME 111 9361
TEST_TIME 112 9329
TEST_TIME 113 9324
TEST_TIME 114 9307
TEST_TIME 115 9319
TEST_TIME 116 9307
TEST_TIME 117 9266
TEST_TIME 118 9252
TEST_TIME 119 9255
TEST_TIME 120 9231

Performance per minute, chart


Completed "Performance for every MINUTE". Done for 00:00:03, from 29-09-2021 19:39:48 to 29-09-2021 19:39:51.

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 1523069 1523069 0 0.00 0 18278 6 0 0
doc_list_biud 1523069 1523069 0 0.00 0 38981 29 0 0
sp_add_invoice_to_stock 4991 4872 119 2.38 34 186956 18541 0 119
sp_cancel_adding_invoice 5907 5907 0 0.00 6 67973 780 0 0
sp_cancel_client_order 1689 1689 0 0.00 4 10707 331 0 0
sp_cancel_customer_reserve 575449 575449 0 0.00 1 36791 62 0 0
sp_cancel_pay_from_customer 668 668 0 0.00 3 10087 130 0 0
sp_cancel_pay_to_supplier 397 397 0 0.00 3 4733 91 0 0
sp_cancel_supplier_invoice 6484 6477 7 0.10 1 20077 806 0 7
sp_cancel_supplier_order 416 416 0 0.00 8 971521 108877 0 0
sp_cancel_write_off 9919 9919 0 0.00 1 10746 114 0 0
sp_client_order 20196 20196 0 0.00 3 15711 372 0 0
sp_customer_reserve 446588 446588 0 0.00 0 92701 186 0 0
sp_fill_shopping_cart 30904 30904 0 0.00 1 9975 37 0 0
sp_fill_shopping_cart_clo_res 446579 446579 0 0.00 0 16975 15 0 0
sp_get_clo_for_invoice 4861 4861 0 0.00 0 31289 316 0 0
sp_kill_cost_storno 16891 16891 0 0.00 0 10744 56 0 0
sp_kill_qstorno_ret_qs2qd 1167710 1167710 0 0.00 0 36784 33 0 0
sp_kill_qty_storno 614578 614578 0 0.00 0 38978 72 0 0
sp_lock_selected_doc 20327 20327 0 0.00 0 9796 8 0 0
sp_make_cost_storno 27600 27600 0 0.00 0 18265 57 0 0
sp_multiply_rows_for_pdistr 27600 27600 0 0.00 0 8177 26 0 0
sp_multiply_rows_for_qdistr 20196 20196 0 0.00 0 15678 176 0 0
sp_pay_from_customer 7059 7059 0 0.00 4 16916 132 0 0
sp_pay_to_supplier 5820 5820 0 0.00 5 12055 129 0 0
sp_payment_common 12879 12879 0 0.00 1 16901 38 0 0
sp_qd_handle_on_cancel_clo 1689 1689 0 0.00 0 9831 296 0 0
sp_qd_handle_on_invoice_upd_sts 10767 10767 0 0.00 0 38971 329 0 0
sp_qd_handle_on_reserve_upd_sts 9861 9861 0 0.00 0 15420 62 0 0
sp_reserve_write_off 9861 9861 0 0.00 6 15458 190 0 0
sp_supplier_invoice 5272 5272 0 0.00 7 109804 3522 0 0
sp_supplier_order 5454 5454 0 0.00 5 22797 1297 0 0
srv_aggregate_perf_data 98 98 0 0.00 2751 494701 23339 0 0
srv_fill_mon_cache_memory 63 63 0 0.00 1242 156811 48172 0 0
srv_find_qd_qs_mism 1061863 1061863 0 0.00 0 9712 5 0 0
srv_make_invnt_saldo 529 529 0 0.00 37 47294 1369 0 0
srv_make_money_saldo 796 796 0 0.00 1 3046 27 0 0
srv_recalc_idx_stat 4 4 0 0.00 64657 526908 265693 0 0
t$perf-abend:sp_add_invoice_to_stock 119 119 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 4872 4872 0 0.00 0 7791 155 0 0
t$perf-norm:sp_cancel_adding_invoice 402 402 0 0.00 0 4511 91 0 0
t$perf-norm:sp_cancel_client_order 1689 1689 0 0.00 0 6148 20 0 0
t$perf-norm:sp_cancel_customer_reserve 708 708 0 0.00 0 9546 34 0 0
t$perf-norm:sp_cancel_pay_from_customer 668 668 0 0.00 0 4856 14 0 0
t$perf-norm:sp_cancel_pay_to_supplier 397 397 0 0.00 0 2252 11 0 0
t$perf-norm:sp_cancel_supplier_invoice 380 380 0 0.00 0 437 7 0 0
t$perf-norm:sp_cancel_supplier_order 416 416 0 0.00 0 28950 1712 0 0
t$perf-norm:sp_cancel_write_off 946 946 0 0.00 0 9433 16 0 0
t$perf-norm:sp_client_order 20197 20197 0 0.00 0 8149 19 0 0
t$perf-norm:sp_customer_reserve 1014 1014 0 0.00 0 7525 12 0 0
t$perf-norm:sp_pay_from_customer 7059 7059 0 0.00 0 13216 16 0 0
t$perf-norm:sp_pay_to_supplier 5820 5820 0 0.00 0 5724 15 0 0
t$perf-norm:sp_reserve_write_off 9861 9861 0 0.00 0 8810 13 0 0
t$perf-norm:sp_supplier_invoice 5272 5272 0 0.00 0 13273 27 0 0
t$perf-norm:sp_supplier_order 5454 5454 0 0.00 0 20422 22 0 0
t$perf-norm:srv_aggregate_perf_data 98 98 0 0.00 0 226 7 0 0
t$perf-norm:srv_fill_mon_cache_memory 63 63 0 0.00 0 30 1 0 0
t$perf-norm:srv_make_invnt_saldo 529 529 0 0.00 0 700 21 0 0
t$perf-norm:srv_make_money_saldo 796 796 0 0.00 0 2509 15 0 0
t$perf-norm:srv_recalc_idx_stat 4 4 0 0.00 2 19 8 0 0
v_add_invoice_to_stock 9956 9718 238 2.39 0 6185 22 0 238
v_all_customers 36860 36860 0 0.00 0 21 1 0 0
v_all_suppliers 29986 29986 0 0.00 0 21 1 0 0
v_all_wares 40392 40392 0 0.00 0 142 1 0 0
v_cancel_adding_invoice 804 804 0 0.00 0 550 6 0 0
v_cancel_client_order 3378 3378 0 0.00 0 9543 7 0 0
v_cancel_customer_prepayment 1336 1336 0 0.00 0 6632 11 0 0
v_cancel_customer_reserve 1416 1416 0 0.00 0 2381 10 0 0
v_cancel_payment_to_supplier 794 794 0 0.00 0 4698 12 0 0
v_cancel_supplier_invoice 774 760 14 1.80 0 1350 17 0 14
v_cancel_supplier_order 832 832 0 0.00 0 1127 11 0 0
v_cancel_write_off 1892 1892 0 0.00 0 4082 16 0 0
v_max_id_clo_ord 5450 5450 0 0.00 0 1326 2 0 0
v_max_id_clo_res 1014 1014 0 0.00 0 3759 22 0 0
v_max_id_ord_sup 5257 5257 0 0.00 0 4945 5 0 0
v_max_non_paid_invoice 1534 1534 0 0.00 0 838 3 0 0
v_max_non_paid_realizn 3876 3876 0 0.00 0 4225 6 0 0
v_min_id_clo_ord 5450 5450 0 0.00 0 9705 11 0 0
v_min_id_clo_res 1014 1014 0 0.00 0 4834 11 0 0
v_min_id_ord_sup 5257 5257 0 0.00 0 3125 5 0 0
v_min_non_paid_invoice 5820 5820 0 0.00 0 6479 19 0 0
v_min_non_paid_realizn 7059 7059 0 0.00 0 15145 26 0 0
v_our_firm 9898 9898 0 0.00 0 21 1 0 0
v_reserve_write_off 19722 19722 0 0.00 0 6256 8 0 0
x_lock_depdocs_on_canc_invoice 12004 12004 0 0.00 0 23765 129 0 0
x_lock_depdocs_on_canc_sup_ord 416 416 0 0.00 0 16604 403 0 0
x_make_qstorno_1000_1200 5454 5454 0 0.00 2 22772 1217 0 0
x_make_qstorno_1200_2000 5272 5272 0 0.00 4 109652 3400 0 0
x_make_qstorno_2100_3300 446588 446588 0 0.00 0 92700 168 0 0

Completed "Performance in DETAILS". Done for 00:00:04, from 29-09-2021 19:39:52 to 29-09-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:58 8 8192000000 8801611680 8813117440 7256432 0.088 2 1 2 0 7375808 56816 62560
17:08:59 26896 8192000000 10368557472 10688061440 1423671936 14.805 100 85 170 0 1456556352 5644784 27239632
17:10:32 16101 8192000000 10440107392 10769960960 1492484928 15.411 100 86 172 0 1528751888 8158592 28108368
17:11:54 15389 8192000000 10474171280 10815250432 1533633904 15.768 100 82 164 2 1568759776 9196640 25929232
17:13:24 12024 8192000000 10564669040 10920685568 1621363008 16.521 100 73 146 0 1653831344 10392128 22076208
17:14:44 10718 8192000000 10653073584 11020681216 1714342080 17.305 100 82 163 4 1750411264 12486880 23582304
17:15:57 3663 8192000000 10709215696 11085000704 1764935904 17.725 100 78 156 1 1801528224 14832960 21759360
17:17:03 2622 8192000000 10743151504 11126407168 1809438896 18.091 100 81 158 0 1845340320 13604560 22296864
17:18:07 2658 8192000000 10796334672 11180212224 1851869968 18.437 100 93 186 2 1892877888 13679728 27328192
17:19:11 1986 8192000000 10813875424 11214897152 1877748416 18.647 100 85 170 1 1914176288 12603680 23824192
17:20:14 4018 8192000000 10809481200 11220467712 1884561408 18.702 100 48 95 3 1907210912 8962528 13686976
17:21:20 6299 8192000000 10795244016 11224756224 1889565408 18.742 100 20 40 1 1900989760 5901840 5522512
17:22:27 13004 8192000000 10801097104 11237687296 1898119648 18.811 100 17 33 1 1908187312 5688160 4379504
17:23:40 33610 8192000000 10860071360 11257933824 1911935056 18.922 100 84 168 0 1942799056 5840768 25023232
17:25:14 6733 8192000000 10838301472 11264249856 1912157392 18.924 100 31 62 0 1927362064 6744272 8460400
17:26:22 39266 8192000000 10804978704 11245211648 1857849936 18.486 97 28 56 3 1875508704 9512592 8146176
17:28:03 7473 8192000000 10803178880 11220762624 1834681920 18.297 97 27 54 0 1849006544 7001184 7323440
17:29:16 8395 8192000000 10726190224 11139801088 1776436304 17.820 97 24 49 0 1788912832 5711984 6764544
17:30:33 50898 8192000000 10707917424 11128700928 1686310800 17.070 92 28 56 2 1699728112 5431104 7986208
17:32:28 5360 8192000000 10717035520 11140517888 1795343776 17.976 99 36 69 3 1811209536 4922992 10942768
17:33:33 8267 8192000000 10745136240 11168976896 1828540912 18.247 100 16 30 1 1838107040 5559264 4006864
17:34:42 9672 8192000000 10771904448 11202699264 1860635120 18.508 100 16 30 2 1870470496 5620064 4215312
17:35:56 37423 8192000000 10779863632 11212623872 1871003280 18.592 100 25 50 1 1883703584 5138640 7561664
17:37:36 6443 8192000000 10815229824 11244924928 1901182448 18.836 100 23 46 1 1912958560 5559232 6216880
17:38:45 5837 8192000000 10877579728 11287777280 1937031280 19.123 100 91 181 1 1973875328 10185376 26658672
17:40:04 19477 8192000000 10889639872 11310764032 1952857968 19.249 100 56 112 0 1981358496 12988048 15512480
17:41:43 89596 8192000000 10888765504 11334242304 1954365840 19.261 100 42 83 0 1983783600 17242064 12175696
17:44:21 13189 8192000000 10920742624 11348140032 1957663792 19.287 99 48 96 1 1993241824 20766816 14811216
17:45:40 6680 8192000000 10940044976 11365916672 1987617504 19.525 100 61 122 1 2029227184 22948688 18660992
17:46:50 5548 8192000000 10933533568 11362213888 1980131248 19.466 100 64 126 1 2023490880 25089712 18269920
17:48:01 6501 8192000000 10962186736 11398148096 2010845968 19.708 100 56 114 0 2055637472 26746576 18044928
17:49:13 5602 8192000000 10955808736 11394191360 2005971872 19.670 100 65 130 1 2055339760 29068432 20299456
17:50:23 3628 8192000000 10987626032 11419799552 2021122368 19.789 100 68 131 1 2075590240 35023280 19444592
17:51:33 1242 8192000000 10980569728 11392978944 1997877328 19.606 100 83 166 2 2062008368 39864592 24266448
17:52:39 4035 8192000000 10975767440 11391012864 1986053280 19.513 100 85 169 2 2058193696 45787648 26352768
17:53:45 2081 8192000000 10985988464 11405246464 1989867824 19.543 100 83 166 2 2069823504 54007328 25948352
17:54:51 6445 8192000000 10951476544 11392999424 1975067424 19.426 100 46 92 0 2040285888 49462992 15755472
17:56:09 3314 8192000000 10998252352 11426766848 1988649440 19.533 99 80 159 2 2068518256 55376208 24492608
17:57:20 12448 8192000000 10966285376 11407802368 1988642560 19.533 100 43 85 1 2054736448 52140720 13953168
17:58:35 12266 8192000000 10943214336 11387801600 1970792048 19.392 100 39 76 1 2032728064 49517024 12418992
17:59:54 13905 8192000000 10925269120 11369934848 1915100192 18.948 97 33 66 0 1975546736 49317808 11128736
18:01:14 17852 8192000000 10949180768 11397992448 1964778912 19.344 100 31 62 0 2030472624 55063824 10629888
18:02:40 18868 8192000000 10937499440 11391152128 1941268336 19.157 99 25 50 2 2010050288 59869024 8912928
18:04:03 22538 8192000000 10940439104 11388264448 1948916832 19.218 100 26 52 1 2014788832 56547776 9324224
18:05:28 75244 8192000000 10877620128 11352997888 1888263584 18.732 97 12 24 0 1926959024 35022928 3672512
18:07:43 43033 8192000000 10913410672 11356459008 1966168656 19.355 100 26 52 1 1980025904 6912672 6944576
18:09:28 94962 8192000000 10902728688 11349532672 1931870496 19.082 98 25 51 1 1954609552 15132928 7606128
18:12:26 139330 8192000000 10890923280 11340197888 1851363072 18.433 94 16 32 0 1865679584 9905008 4411504
18:15:47 39287 8192000000 10921442496 11369635840 1978081840 19.450 100 20 40 0 1995893072 11501424 6309808
18:17:28 53490 8192000000 10918930176 11404238848 1994672576 19.581 100 41 83 0 2031964704 24338624 12953504
18:19:38 56346 8192000000 10899629072 11368050688 1947289520 19.205 98 18 37 0 1967286048 14477552 5518976
18:22:08 30673 8192000000 10893346368 11374649344 1972967456 19.409 100 7 14 0 1987563040 12697744 1897840
18:23:56 116914 8192000000 10924988608 11413872640 1988584768 19.533 100 14 28 0 2009684720 17098960 4000992
18:26:53 92812 8192000000 10904493408 11389939712 1969170624 19.379 99 19 36 1 1983769424 8541008 6057792
18:29:28 8557 8192000000 10943811440 11394899968 1998350672 19.610 100 58 116 1 2029364032 13873696 17139664
18:30:42 71234 8192000000 10912159664 11396849664 1945069376 19.187 98 11 22 0 1964084192 15934592 3080224
18:32:53 96797 8192000000 10921543648 11405152256 1949880544 19.226 98 11 22 0 1974712272 22040384 2791344
18:35:47 22904 8192000000 10889885312 11342000128 1915308544 18.949 98 29 58 0 1931261040 7919376 8033120
18:37:10 96611 8192000000 10883554864 11347173376 1896332128 18.797 96 21 42 0 1914687232 12726080 5629024
18:39:59 81059 8192000000 10883003920 11345653760 1873891280 18.616 95 23 46 0 1898531040 18384944 6254816
18:42:27 55124 8192000000 10874102256 11343876096 1925130464 19.028 99 12 22 0 1944782576 17078048 2574064
18:44:24 56187 8192000000 10818372064 11278745600 1855394208 18.466 95 9 18 1 1873076144 15299744 2382192
18:46:31 60573 8192000000 10855203568 11306704896 1830178992 18.261 94 21 42 0 1845241728 8605664 6457072
18:48:37 35687 8192000000 10851857488 11300503552 1882564672 18.686 98 54 109 1 1910400816 12351408 15484736
18:50:12 64897 8192000000 10878131616 11338231808 1936456224 19.118 100 13 26 0 1949908256 9891168 3560864
18:52:17 83740 8192000000 10874232464 11331248128 1898583280 18.815 97 16 32 0 1913059824 10454336 4022208
18:54:46 80519 8192000000 10904715552 11348254720 1936081632 19.115 99 28 56 0 1953144016 9264704 7797680
18:57:08 64920 8192000000 10879711040 11342876672 1931292320 19.077 99 20 41 0 1955111408 18345792 5473296
18:59:15 123437 8192000000 10854404016 11329961984 1918234160 18.973 98 21 41 0 1939400288 15056576 6109552
19:02:20 25110 8192000000 10859815056 11323183104 1908239648 18.893 98 33 68 1 1922611152 5732528 8638976
19:03:48 74895 8192000000 10856872288 11329486848 1930124656 19.068 100 7 14 0 1945553056 13594912 1833488
19:06:04 47713 8192000000 10864885472 11344404480 1939796448 19.145 100 11 22 0 1955145072 11773232 3575392
19:07:52 25117 8192000000 10887843392 11353935872 1960039648 19.306 100 23 42 0 1976079488 9969408 6070432
19:09:17 98233 8192000000 10903274112 11374129152 1942952656 19.170 98 16 32 1 1962403088 14429184 5021248
19:12:26 20785 8192000000 10923992432 11378450432 1970810624 19.392 99 29 59 1 1984959024 6389584 7758816
19:13:47 62036 8192000000 10913167904 11391877120 1969129984 19.379 99 15 31 0 1983015568 9996240 3889344
19:15:49 35761 8192000000 10921850848 11382149120 1971804560 19.400 99 23 46 0 1987955152 9772928 6377664
19:17:26 28404 8192000000 10933839344 11388547072 1956342912 19.277 98 38 76 0 1977865648 11280688 10242048
19:18:58 69959 8192000000 10924161712 11412316160 1979381424 19.460 99 9 18 0 1997610576 15853456 2375696
19:21:12 156810 8192000000 10913802272 11376746496 1885381584 18.709 94 14 28 1 1909173904 19906464 3885856
19:25:07 26696 8192000000 10884711616 11362361344 1929843568 19.066 98 24 49 0 1948558800 12370032 6345200
19:26:40 23028 8192000000 10864099664 11347943424 1946237872 19.197 100 8 16 1 1957850256 9345360 2267024
19:28:04 69334 8192000000 10857821856 11330584576 1853704432 18.452 94 14 28 1 1867930528 10103584 4122512
19:30:25 87261 8192000000 10823863152 11292692480 1848018320 18.406 95 21 42 0 1866881680 12446992 6416368
19:32:53 57610 8192000000 10833542336 11305361408 1900796576 18.833 99 18 36 0 1913187664 6957472 5433616
19:35:03 36113 8192000000 10859379248 11328360448 1928125376 19.052 100 25 49 1 1946331696 11965024 6241296
19:36:40 74516 8192000000 10663468016 11130744832 1726150192 17.403 89 24 49 0 1745172160 12326752 6695216

Memory consumption, total, chart

Metadata cache size, chart

Statements activity, chart


Completed "Memory consumption, metadata cache, attachments activity". Done for 00:00:15, from 29-09-2021 19:39:58 to 29-09-2021 19:40:13.

Exceptions occured during test was in run

FB_MNEMONA CNT UNIT FB_GDSCODE
except 119 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 29-09-2021 19:40:14 to 29-09-2021 19:40:16.

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          237127
MON$OLDEST_ACTIVE               237771
MON$OLDEST_SNAPSHOT             237771
MON$NEXT_TRANSACTION            237771
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                       2038624
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.33504 Firebird 3.0
Server version:
Firebird/Linux/AMD/Intel/x64 (access method), version "LI-V3.0.8.33504 Firebird 3.0"
Firebird/Linux/AMD/Intel/x64 (remote server), version "LI-V3.0.8.33504 Firebird 3.0/tcp (mscs-test-161.budzdorov.ru)/P15:C"
Firebird/Linux/AMD/Intel/x64 (remote interface), version "LI-V3.0.8.33504 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 ---
:19: 
:20: mscs-test-161.budzdorov.ru    Wed Sep 29 19:38:04 2021
:21:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3333
:22: 
:23: 
:24: mscs-test-161.budzdorov.ru    Wed Sep 29 19:38:13 2021
:25:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3333
:26: 
:27: 
:28: mscs-test-161.budzdorov.ru    Wed Sep 29 19:38:13 2021
:29:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3333
:30: 
--- end of diff output ---

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

29.09.21 19:40:17. 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-09-29 19:40:19 No severe PSQL-related problems occured
29.09.21 19:40:20. End of report.