Generated by /opt/oltp-emul/oltp_isql_run_worker.sh, ISQL session No. 1 of total launched 100. 06.10.2021 08:01
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 15928128 kB
MemAvailable 30709372 kB
Buffers 0 kB
Cached 15759004 kB
SwapCached 4784 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-06 08:01:31
DTS_END                         2021-10-06 08:01:31.6960
FB_GDSCODE                      -1
FB_MNEMONA                      
STACK                           SP_CLIENT_ORDER(57:5) ==> SP_CHECK_TO_STOP_WORK(32:12) ==> SP_HALT_ON_ERROR(68:17)
IP                              ::1/56926
TRN_ID                          235086
ATT_ID                          656
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: 9120.53 20937 1094464
customer order: creation 172.74 387 20729
customer order: refuse 14.48 336 1738
order to supplier: creation 46.02 1320 5522
order to supplier: removal 3.18 102546 382
invoice (draft): creation 45.71 3470 5485
invoice (draft): removal 51.11 866 6133
invoice accept: apply 41.83 18004 5019
invoice accept: cancel 46.37 852 5564
customer reserve: creation 3886.03 176 466323
customer reserve: removal 4523.56 56 542827
realization accept: apply 81.87 175 9824
realization accept: cancel 79.83 123 9580
payment from customer: creation 59.55 102 7146
payment from customer: removal 5.62 68 674
payment to supplier: creation 48.85 126 5862
payment to supplier: removal 3.31 86 397
service: total inventory turnovers 3.51 3546 421
service: total monetary turnovers 5.88 481 705
service: aggregate perf. data 1.06 14292 127
service: refresh index statistics 0.05 271723 6

Performance in TOTAL, chart


Completed "Performance in TOTAL". Done for 00:00:03, from 06-10-2021 08:02:19 to 06-10-2021 08:02:22.

Performance for every MINUTE

TEST_PHASE_NAME MINUTES_PASSED PERF_SCORE
TEST_TIME 1 2180
TEST_TIME 2 3414
TEST_TIME 3 2887
TEST_TIME 4 3033
TEST_TIME 5 4957
TEST_TIME 6 5515
TEST_TIME 7 5644
TEST_TIME 8 5638
TEST_TIME 9 5816
TEST_TIME 10 6089
TEST_TIME 11 6253
TEST_TIME 12 6894
TEST_TIME 13 7169
TEST_TIME 14 7390
TEST_TIME 15 7821
TEST_TIME 16 7972
TEST_TIME 17 8744
TEST_TIME 18 8782
TEST_TIME 19 8708
TEST_TIME 20 8963
TEST_TIME 21 9086
TEST_TIME 22 9923
TEST_TIME 23 10162
TEST_TIME 24 10304
TEST_TIME 25 10694
TEST_TIME 26 10373
TEST_TIME 27 10507
TEST_TIME 28 10493
TEST_TIME 29 10538
TEST_TIME 30 10263
TEST_TIME 31 10037
TEST_TIME 32 9982
TEST_TIME 33 10008
TEST_TIME 34 9945
TEST_TIME 35 9770
TEST_TIME 36 9689
TEST_TIME 37 9619
TEST_TIME 38 9482
TEST_TIME 39 9401
TEST_TIME 40 9528
TEST_TIME 41 9347
TEST_TIME 42 9408
TEST_TIME 43 9448
TEST_TIME 44 9391
TEST_TIME 45 9401
TEST_TIME 46 9336
TEST_TIME 47 9489
TEST_TIME 48 9491
TEST_TIME 49 9449
TEST_TIME 50 9457
TEST_TIME 51 9483
TEST_TIME 52 9480
TEST_TIME 53 9492
TEST_TIME 54 9432
TEST_TIME 55 9472
TEST_TIME 56 9525
TEST_TIME 57 9578
TEST_TIME 58 9442
TEST_TIME 59 9377
TEST_TIME 60 9358
TEST_TIME 61 9257
TEST_TIME 62 9229
TEST_TIME 63 9258
TEST_TIME 64 9195
TEST_TIME 65 9145
TEST_TIME 66 9091
TEST_TIME 67 9055
TEST_TIME 68 9116
TEST_TIME 69 9181
TEST_TIME 70 9172
TEST_TIME 71 9191
TEST_TIME 72 9163
TEST_TIME 73 9237
TEST_TIME 74 9199
TEST_TIME 75 9341
TEST_TIME 76 9319
TEST_TIME 77 9344
TEST_TIME 78 9438
TEST_TIME 79 9452
TEST_TIME 80 9449
TEST_TIME 81 9426
TEST_TIME 82 9337
TEST_TIME 83 9267
TEST_TIME 84 9256
TEST_TIME 85 9264
TEST_TIME 86 9215
TEST_TIME 87 9177
TEST_TIME 88 9105
TEST_TIME 89 9100
TEST_TIME 90 9041
TEST_TIME 91 9048
TEST_TIME 92 9066
TEST_TIME 93 9057
TEST_TIME 94 9038
TEST_TIME 95 9006
TEST_TIME 96 9059
TEST_TIME 97 9126
TEST_TIME 98 9144
TEST_TIME 99 9187
TEST_TIME 100 9181
TEST_TIME 101 9232
TEST_TIME 102 9174
TEST_TIME 103 9114
TEST_TIME 104 9099
TEST_TIME 105 9071
TEST_TIME 106 8998
TEST_TIME 107 8968
TEST_TIME 108 8974
TEST_TIME 109 9020
TEST_TIME 110 9042
TEST_TIME 111 9033
TEST_TIME 112 9016
TEST_TIME 113 9026
TEST_TIME 114 9033
TEST_TIME 115 9044
TEST_TIME 116 9061
TEST_TIME 117 9087
TEST_TIME 118 9110
TEST_TIME 119 9096
TEST_TIME 120 9124

Performance per minute, chart


Completed "Performance for every MINUTE". Done for 00:00:03, from 06-10-2021 08:02:23 to 06-10-2021 08:02:26.

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 1524239 1524239 0 0.00 0 23702 6 0 0
doc_list_biud 1524239 1524239 0 0.00 0 49481 26 0 0
sp_add_invoice_to_stock 5166 5019 147 2.84 29 252115 18005 0 147
sp_cancel_adding_invoice 5564 5564 0 0.00 5 87449 853 0 0
sp_cancel_client_order 1738 1738 0 0.00 5 13190 336 0 0
sp_cancel_customer_reserve 542827 542827 0 0.00 1 40216 57 0 0
sp_cancel_pay_from_customer 674 674 0 0.00 3 1815 68 0 0
sp_cancel_pay_to_supplier 397 397 0 0.00 3 8380 87 0 0
sp_cancel_supplier_invoice 6147 6133 14 0.22 1 49496 867 0 14
sp_cancel_supplier_order 382 382 0 0.00 7 1032365 102547 0 0
sp_cancel_write_off 9580 9580 0 0.00 1 11823 123 0 0
sp_client_order 20729 20729 0 0.00 4 24676 387 0 0
sp_customer_reserve 466323 466323 0 0.00 0 110042 177 0 0
sp_fill_shopping_cart 31712 31712 0 0.00 1 27806 45 0 0
sp_fill_shopping_cart_clo_res 466319 466319 0 0.00 0 13349 16 0 0
sp_get_clo_for_invoice 5015 5015 0 0.00 0 30380 402 0 0
sp_kill_cost_storno 16215 16215 0 0.00 0 8374 53 0 0
sp_kill_qstorno_ret_qs2qd 1101749 1101749 0 0.00 0 49478 31 0 0
sp_kill_qty_storno 581063 581063 0 0.00 0 49480 68 0 0
sp_lock_selected_doc 20562 20562 0 0.00 0 7006 4 0 0
sp_make_cost_storno 27847 27847 0 0.00 0 23656 54 0 0
sp_multiply_rows_for_pdistr 27847 27847 0 0.00 0 6424 29 0 0
sp_multiply_rows_for_qdistr 20729 20729 0 0.00 0 24631 201 0 0
sp_pay_from_customer 7146 7146 0 0.00 4 17971 103 0 0
sp_pay_to_supplier 5862 5862 0 0.00 5 14481 126 0 0
sp_payment_common 13008 13008 0 0.00 1 17961 22 0 0
sp_qd_handle_on_cancel_clo 1738 1738 0 0.00 0 13180 305 0 0
sp_qd_handle_on_invoice_upd_sts 10579 10579 0 0.00 0 31869 342 0 0
sp_qd_handle_on_reserve_upd_sts 9824 9824 0 0.00 0 18321 59 0 0
sp_reserve_write_off 9824 9824 0 0.00 6 20802 175 0 0
sp_supplier_invoice 5485 5485 0 0.00 7 114442 3470 0 0
sp_supplier_order 5522 5522 0 0.00 6 26078 1321 0 0
srv_aggregate_perf_data 127 127 0 0.00 2659 212046 14292 0 0
srv_fill_mon_cache_memory 59 59 0 0.00 1538 207576 54731 0 0
srv_find_qd_qs_mism 1045625 1045625 0 0.00 0 15618 5 0 0
srv_make_invnt_saldo 421 421 0 0.00 71 79402 3547 0 0
srv_make_money_saldo 705 705 0 0.00 1 17454 482 0 0
srv_recalc_idx_stat 6 6 0 0.00 145090 446847 271724 0 0
t$perf-abend:sp_add_invoice_to_stock 147 147 0 0.00 0 0 0 0 0
t$perf-abend:sp_cancel_supplier_invoice 14 14 0 0.00 0 0 0 0 0
t$perf-norm:sp_add_invoice_to_stock 5020 5020 0 0.00 0 21333 148 0 0
t$perf-norm:sp_cancel_adding_invoice 418 418 0 0.00 0 2186 92 0 0
t$perf-norm:sp_cancel_client_order 1738 1738 0 0.00 0 3424 12 0 0
t$perf-norm:sp_cancel_customer_reserve 702 702 0 0.00 0 730 6 0 0
t$perf-norm:sp_cancel_pay_from_customer 674 674 0 0.00 0 3366 11 0 0
t$perf-norm:sp_cancel_pay_to_supplier 397 397 0 0.00 0 11674 39 0 0
t$perf-norm:sp_cancel_supplier_invoice 416 416 0 0.00 0 2099 19 0 0
t$perf-norm:sp_cancel_supplier_order 382 382 0 0.00 0 24799 1555 0 0
t$perf-norm:sp_cancel_write_off 998 998 0 0.00 0 4272 10 0 0
t$perf-norm:sp_client_order 20729 20729 0 0.00 0 8002 16 0 0
t$perf-norm:sp_customer_reserve 987 987 0 0.00 0 744 4 0 0
t$perf-norm:sp_pay_from_customer 7146 7146 0 0.00 0 3855 8 0 0
t$perf-norm:sp_pay_to_supplier 5862 5862 0 0.00 0 7202 6 0 0
t$perf-norm:sp_reserve_write_off 9824 9824 0 0.00 0 25475 13 0 0
t$perf-norm:sp_supplier_invoice 5485 5485 0 0.00 0 9616 20 0 0
t$perf-norm:sp_supplier_order 5522 5522 0 0.00 0 13025 19 0 0
t$perf-norm:srv_aggregate_perf_data 127 127 0 0.00 0 103 2 0 0
t$perf-norm:srv_fill_mon_cache_memory 59 59 0 0.00 0 6598 112 0 0
t$perf-norm:srv_make_invnt_saldo 421 421 0 0.00 0 1459 10 0 0
t$perf-norm:srv_make_money_saldo 705 705 0 0.00 0 690 8 0 0
t$perf-norm:srv_recalc_idx_stat 6 6 0 0.00 2 10 4 0 0
v_add_invoice_to_stock 10320 10026 294 2.84 0 5615 15 0 294
v_all_customers 38000 38000 0 0.00 0 20 1 0 0
v_all_suppliers 30320 30320 0 0.00 0 33 1 0 0
v_all_wares 41458 41458 0 0.00 0 25 1 0 0
v_cancel_adding_invoice 836 836 0 0.00 0 2966 11 0 0
v_cancel_client_order 3476 3476 0 0.00 0 2047 5 0 0
v_cancel_customer_prepayment 1348 1348 0 0.00 0 1808 6 0 0
v_cancel_customer_reserve 1404 1404 0 0.00 0 1547 4 0 0
v_cancel_payment_to_supplier 794 794 0 0.00 0 934 6 0 0
v_cancel_supplier_invoice 860 832 28 3.25 0 6606 22 0 28
v_cancel_supplier_order 764 764 0 0.00 0 2709 9 0 0
v_cancel_write_off 1996 1996 0 0.00 0 5792 16 0 0
v_max_id_clo_ord 5522 5522 0 0.00 0 1955 2 0 0
v_max_id_clo_res 987 987 0 0.00 0 5258 27 0 0
v_max_id_ord_sup 5461 5461 0 0.00 0 3604 7 0 0
v_max_non_paid_invoice 1685 1685 0 0.00 0 7225 6 0 0
v_max_non_paid_realizn 3653 3653 0 0.00 0 1102 3 0 0
v_min_id_clo_ord 5522 5522 0 0.00 0 6805 8 0 0
v_min_id_clo_res 987 987 0 0.00 0 4457 25 0 0
v_min_id_ord_sup 5461 5461 0 0.00 0 6547 7 0 0
v_min_non_paid_invoice 5862 5862 0 0.00 0 7786 12 0 0
v_min_non_paid_realizn 7146 7146 0 0.00 0 8147 15 0 0
v_our_firm 10444 10444 0 0.00 0 16 1 0 0
v_reserve_write_off 19648 19648 0 0.00 0 2963 4 0 0
x_lock_depdocs_on_canc_invoice 11281 11281 0 0.00 0 17443 110 0 0
x_lock_depdocs_on_canc_sup_ord 382 382 0 0.00 0 3648 311 0 0
x_make_qstorno_1000_1200 5522 5522 0 0.00 2 26051 1236 0 0
x_make_qstorno_1200_2000 5485 5485 0 0.00 3 95212 3298 0 0
x_make_qstorno_2100_3300 466323 466323 0 0.00 0 110040 159 0 0

Completed "Performance in DETAILS". Done for 00:00:04, from 06-10-2021 08:02:27 to 06-10-2021 08:02:31.

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
05:31:35 2 8192000000 8796669024 8807174144 3189120 0.038 1 1 2 0 3286736 61840 35776
05:32:35 27789 8192000000 9716469472 10008961024 783276096 8.727 100 90 180 1 813682512 7819856 22586560
05:34:10 15723 8192000000 9748358560 10052395008 823280176 9.132 100 82 164 0 855037136 11977152 19779808
05:35:40 17589 8192000000 9798691856 10114813952 861078784 9.511 100 83 166 0 904426768 24535168 18812816
05:37:00 13526 8192000000 9866633680 10199973888 916990384 10.066 100 78 157 1 972280720 38066320 17224016
05:38:18 10487 8192000000 9901126464 10247020544 949849792 10.390 100 73 144 2 1015673648 50671536 15152320
05:39:30 4100 8192000000 9970928848 10327138304 1001754928 10.896 100 79 157 2 1075894592 58625712 15513952
05:40:36 2045 8192000000 9985053312 10355265536 1023526944 11.106 100 79 156 2 1100524320 61429056 15568320
05:41:45 2083 8192000000 10016465248 10387623936 1051467104 11.375 100 89 178 0 1125986544 56823248 17696192
05:42:49 2520 8192000000 10033210688 10415378432 1064675712 11.501 100 68 136 0 1154626352 76507856 13442784
05:43:53 12648 8192000000 10002019376 10392182784 1069059280 11.543 100 51 103 2 1113420160 33185952 11174928
05:45:19 11467 8192000000 9974554336 10378756096 1075908816 11.608 100 38 75 1 1101539152 17007200 8623136
05:46:31 3596 8192000000 9995656240 10390532096 1079717392 11.645 100 51 101 0 1112261872 21579552 10964928
05:47:36 4134 8192000000 9995037136 10389078016 1087506528 11.719 100 35 71 1 1113138624 17499120 8132976
05:48:42 62414 8192000000 10010507104 10411425792 1091517280 11.757 100 38 76 0 1113283904 12917952 8848672
05:50:45 8634 8192000000 10009637376 10408480768 1095380112 11.794 100 34 68 1 1123564096 21268240 6915744
05:51:54 4323 8192000000 10010654928 10413150208 1097025760 11.809 100 48 96 1 1127135808 18954784 11155264
05:53:03 11429 8192000000 9971579056 10358800384 1002618736 10.904 93 34 68 1 1029716640 19591152 7506752
05:54:45 3859 8192000000 9961279184 10344681472 1019536528 11.068 98 49 95 2 1064410864 34261440 10612896
05:55:51 5908 8192000000 9927591440 10299588608 1001612544 10.894 98 56 113 2 1025920976 11856176 12452256
05:56:58 7786 8192000000 9957860496 10344378368 1020620976 11.078 99 50 98 2 1057696768 25441088 11634704
05:58:06 49657 8192000000 9939946528 10339614720 1020183984 11.074 98 28 55 3 1045766048 19595760 5986304
05:59:57 7837 8192000000 9976582032 10376962048 1057510224 11.433 100 47 94 1 1096972976 28999552 10463200
06:01:10 9548 8192000000 10004720544 10403418112 1080249504 11.650 100 51 102 2 1106459712 14168160 12042048
06:02:34 9888 8192000000 10013399744 10407497728 1093754496 11.778 100 43 86 1 1120104960 17530560 8819904
06:03:48 129752 8192000000 10109750768 10532487168 1108624576 11.919 100 38 76 1 1211244720 94337792 8282352
06:07:16 12470 8192000000 10101725904 10511589376 1130604832 12.127 100 44 86 0 1203853824 64307376 8941616
06:08:31 17003 8192000000 10141052224 10554535936 1146708064 12.279 100 52 104 0 1253468784 95294784 11465936
06:10:00 5113 8192000000 10182575664 10593316864 1157867584 12.383 100 61 122 2 1292164528 121146672 13150272
06:11:14 5573 8192000000 10204361696 10619564032 1165786688 12.457 100 71 140 1 1307703936 126236848 15680400
06:12:25 3027 8192000000 10252357584 10660855808 1169904128 12.496 100 77 150 2 1349929232 163884800 16140304
06:13:32 4386 8192000000 10297965328 10707468288 1177671600 12.568 100 83 166 0 1393046368 197465088 17909680
06:14:43 6640 8192000000 10260421120 10679513088 1182675792 12.615 100 71 141 0 1371679088 172966512 16036784
06:15:53 2504 8192000000 10317491520 10723311616 1176817504 12.561 100 85 168 0 1410793632 214309584 19666544
06:16:59 2074 8192000000 10263024032 10659688448 1127163136 12.095 99 84 166 0 1360438320 214484704 18790480
06:18:06 1527 8192000000 10286646784 10694971392 1125003440 12.074 98 84 163 1 1368606480 226260928 17342112
06:19:13 11291 8192000000 10265416896 10693177344 1140821120 12.223 99 30 60 1 1364699168 216544944 7333104
06:20:27 19872 8192000000 10280059792 10701750272 1095905568 11.799 96 31 60 0 1348947808 245903952 7138288
06:21:51 21653 8192000000 10300422848 10724085760 1093595120 11.777 98 28 56 2 1378933808 278025296 7313392
06:23:17 23606 8192000000 10256640784 10691551232 1083790000 11.684 98 18 36 1 1348443920 259849632 4804288
06:24:52 14620 8192000000 10167827232 10583744512 1076342496 11.613 97 22 44 0 1253778320 172157168 5278656
06:26:10 15580 8192000000 10177543920 10646863872 1102705792 11.863 99 22 44 1 1288155488 180083248 5366448
06:27:27 68124 8192000000 10117598768 10573086720 1102147616 11.858 99 41 82 2 1259525840 147019216 10359008
06:29:49 26053 8192000000 10044988416 10514989056 1101242144 11.849 100 35 70 0 1157909328 48674496 7992688
06:31:20 100208 8192000000 10084911296 10528092160 1114864752 11.978 100 25 50 1 1188060256 67362864 5832640
06:34:07 69881 8192000000 10073108160 10522972160 1135401840 12.172 100 22 44 0 1223238864 83347888 4489136
06:36:21 63678 8192000000 10120155872 10558578688 1140643136 12.222 100 21 42 1 1207455232 61646416 5165680
06:38:34 10628 8192000000 10149348912 10577567744 1152070160 12.329 100 39 79 1 1255752352 95813536 7868656
06:39:47 83254 8192000000 10141898208 10645356544 1150192736 12.311 100 34 68 1 1295009632 137540640 7276256
06:42:58 74397 8192000000 10075401792 10601877504 1120980112 12.036 98 15 30 0 1233857440 109482816 3394512
06:45:15 95437 8192000000 10100487728 10582233088 1136000800 12.178 99 11 22 0 1185361936 47017280 2343856
06:47:51 19738 8192000000 10136451168 10595020800 1138119136 12.198 99 34 68 2 1219479920 74604432 6756352
06:49:11 80396 8192000000 10103817776 10566934528 1138997184 12.206 99 17 34 0 1184905232 42731872 3176176
06:51:32 36292 8192000000 10102072144 10533515264 1145612992 12.268 99 44 87 1 1182246912 27817184 8816736
06:53:15 123512 8192000000 10082411344 10551898112 1086350240 11.708 94 11 22 1 1122046848 33897168 1799440
06:56:22 44006 8192000000 10096235680 10588569600 1123676560 12.062 99 18 36 3 1183130096 55694048 3759488
06:58:06 136307 8192000000 10076375200 10510401536 1130703296 12.128 99 27 55 0 1201788176 65989648 5095232
07:01:32 67155 8192000000 10072924672 10533666816 1132564896 12.146 99 16 32 0 1158519184 22496592 3457696
07:03:39 45233 8192000000 10091283056 10546692096 1116078944 11.990 97 23 47 0 1196315456 75602880 4633632
07:05:25 207575 8192000000 10095517760 10583707648 1070428976 11.556 93 24 46 0 1142385632 67297760 4658896
07:09:57 76199 8192000000 10042333888 10513100800 1073711744 11.588 94 14 28 0 1121439632 44881824 2846064
07:12:20 36725 8192000000 10089566160 10520412160 1094134464 11.782 97 28 56 1 1143117296 43158016 5824816
07:14:09 76097 8192000000 10116811920 10591227904 1085074864 11.696 96 21 42 0 1203878672 114215392 4588416
07:16:27 48712 8192000000 10027411216 10476429312 1068144608 11.534 96 16 32 0 1121177600 49921552 3111440
07:18:19 59743 8192000000 10071414304 10589409280 1092858624 11.770 98 17 34 1 1176081216 79721008 3501584
07:20:31 75860 8192000000 10061774064 10539405312 1092447952 11.766 98 21 40 1 1132109648 35572640 4089056
07:22:51 101918 8192000000 10113399328 10546491392 1130546096 12.127 100 32 63 1 1207402224 70194032 6662096
07:25:48 48049 8192000000 10058888736 10546270208 1123028144 12.056 99 10 20 0 1190346208 64993152 2324912
07:27:41 66599 8192000000 10072950352 10537975808 1139261088 12.209 100 11 22 2 1167360336 26418960 1680288
07:29:49 64703 8192000000 10098168624 10561298432 1134146064 12.160 99 17 34 1 1198935616 61074560 3714992
07:31:54 61708 8192000000 10093429840 10556022784 1134975024 12.168 99 14 29 0 1178511680 40506896 3029760
07:33:57 57129 8192000000 10097878608 10539290624 1135220640 12.171 99 21 42 0 1192007520 51787200 4999680
07:36:02 65638 8192000000 10198185104 10641674240 1137520736 12.192 98 22 44 1 1249121392 106682608 4918048
07:38:17 68769 8192000000 10107581552 10564247552 1144724832 12.260 99 12 24 0 1214398016 67601136 2072048
07:40:29 58446 8192000000 10123863536 10576646144 1116306400 11.992 96 17 34 0 1166498080 46809744 3381936
07:42:28 107066 8192000000 10086810736 10559266816 1122999104 12.055 97 23 46 0 1161222864 32898176 5325584
07:45:28 83883 8192000000 10121348832 10617360384 1151679072 12.325 100 15 30 0 1237926464 83171600 3075792
07:48:03 67837 8192000000 10178319152 10650693632 1148779040 12.298 99 13 26 3 1239077856 87500016 2798800
07:50:29 79590 8192000000 10067806432 10556354560 1116187488 11.991 97 19 38 1 1209324352 88911552 4225312
07:53:07 41719 8192000000 10105855072 10559430656 1112418464 11.955 97 35 69 0 1161814432 42304848 7091120
07:55:08 104417 8192000000 10129246720 10611531776 1127723328 12.100 98 17 34 0 1228328944 97123344 3482272
07:57:59 32615 8192000000 10128757040 10578550784 1146739840 12.279 100 27 54 0 1188029008 35660560 5628608
07:59:37 87194 8192000000 10099611424 10569531392 1094808560 11.788 96 19 38 0 1135802368 36964416 4029392

Memory consumption, total, chart

Metadata cache size, chart

Statements activity, chart


Completed "Memory consumption, metadata cache, attachments activity". Done for 00:00:14, from 06-10-2021 08:02:33 to 06-10-2021 08:02:47.

Exceptions occured during test was in run

FB_MNEMONA CNT UNIT FB_GDSCODE
except 147 v_add_invoice_to_stock 335544517
except 14 v_cancel_supplier_invoice 335544517

Completed "Exceptions occured during test was in run". Done for 00:00:02, from 06-10-2021 08:02:48 to 06-10-2021 08:02:50.

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          235203
MON$OLDEST_ACTIVE               235204
MON$OLDEST_SNAPSHOT             235204
MON$NEXT_TRANSACTION            235204
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                       2041568
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             796
MON$NEXT_STATEMENT              53
MON$REPLICA_MODE                0


ISQL Version: LI-V4.0.1.2623 Firebird 4.0
Server version:
Firebird/Linux/AMD/Intel/x64 (access method), version "LI-V4.0.1.2623 Firebird 4.0"
Firebird/Linux/AMD/Intel/x64 (remote server), version "LI-V4.0.1.2623 Firebird 4.0/tcp (mscs-test-161.budzdorov.ru)/P17:C"
Firebird/Linux/AMD/Intel/x64 (remote interface), version "LI-V4.0.1.2623 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 ---
:6: 
:7: mscs-test-161.budzdorov.ru    Wed Oct  6 08:01:49 2021
:8:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:9: 
:10: 
:11: mscs-test-161.budzdorov.ru    Wed Oct  6 08:01:50 2021
:12:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:13: 
:14: 
:15: mscs-test-161.budzdorov.ru    Wed Oct  6 08:01:50 2021
:16:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:17: 
--- end of diff output ---

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

06.10.21 08:02:51. 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-06 08:02:54 No severe PSQL-related problems occured
06.10.21 08:02:55. End of report.