Generated by /opt/oltp-emul/oltp_isql_run_worker.sh, ISQL session No. 1 of total launched 100. 10.11.2020 07:27
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 e0e7b46250ba4f9795ceb55e0face73f
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 2020-09-25 13:42
Command: dmidecode -t system|grep -i -e 'manufacturer\|product\|hypervisor'
Manufacturer HP
Product Name ProLiant DL380 Gen9
Command: dmesg | grep DMI
[ 0.000000] DMI HP ProLiant DL380 Gen9/ProLiant DL380 Gen9, BIOS P89 05/21/2018
Command: lscpu | grep -i -v flags
Architecture x86_64
CPU op-mode(s) 32-bit, 64-bit
Byte Order Little Endian
CPU(s) 24
On-line CPU(s) list 0-23
Thread(s) per core 2
Core(s) per socket 6
Socket(s) 2
NUMA node(s) 2
Vendor ID GenuineIntel
CPU family 6
Model 63
Model name Intel(R) Xeon(R) CPU E5-2620 v3 @ 2.40GHz
Stepping 2
CPU MHz 1200.000
CPU max MHz 2400.0000
CPU min MHz 1200.0000
BogoMIPS 4794.00
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 17007628 kB
MemAvailable 31407784 kB
Buffers 0 kB
Cached 14630776 kB
SwapCached 2916 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.0
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 2020-11-10 07:26:53
DTS_END                         2020-11-10 07:26:53.2800
FB_GDSCODE                      -1
FB_MNEMONA                      
STACK                           SP_PAY_FROM_CUSTOMER(24:5) ==> SP_CHECK_TO_STOP_WORK(32:12) ==> SP_HALT_ON_ERROR(68:17)
IP                              ::1/41678
TRN_ID                          232684
ATT_ID                          611
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: 8781.21 20698 1053745
customer order: creation 164.22 407 19706
customer order: refuse 14.18 302 1702
order to supplier: creation 43.84 1464 5261
order to supplier: removal 3.21 101522 385
invoice (draft): creation 43.48 3597 5218
invoice (draft): removal 49.30 773 5916
invoice accept: apply 39.91 16368 4789
invoice accept: cancel 44.27 750 5312
customer reserve: creation 3690.23 159 442828
customer reserve: removal 4422.19 59 530663
realization accept: apply 78.88 175 9465
realization accept: cancel 64.68 119 7761
payment from customer: creation 56.21 116 6745
payment from customer: removal 5.38 68 646
payment to supplier: creation 47.37 128 5684
payment to supplier: removal 3.22 53 386
service: total inventory turnovers 3.74 3095 449
service: total monetary turnovers 5.99 410 719
service: aggregate perf. data 0.88 13535 106
service: refresh index statistics 0.03 270868 4

Performance in TOTAL, chart


Completed "Performance in TOTAL". Done for 00:00:03, from 10-11-2020 07:28:05 to 10-11-2020 07:28:08.

Performance for every MINUTE

TEST_PHASE_NAME MINUTES_PASSED PERF_SCORE
TEST_TIME 1 5223
TEST_TIME 2 4927
TEST_TIME 3 4214
TEST_TIME 4 3786
TEST_TIME 5 4372
TEST_TIME 6 4740
TEST_TIME 7 4912
TEST_TIME 8 5029
TEST_TIME 9 5272
TEST_TIME 10 5322
TEST_TIME 11 5393
TEST_TIME 12 5655
TEST_TIME 13 5705
TEST_TIME 14 6070
TEST_TIME 15 6332
TEST_TIME 16 6741
TEST_TIME 17 6799
TEST_TIME 18 7716
TEST_TIME 19 8327
TEST_TIME 20 8339
TEST_TIME 21 8445
TEST_TIME 22 9392
TEST_TIME 23 9590
TEST_TIME 24 9819
TEST_TIME 25 10144
TEST_TIME 26 10281
TEST_TIME 27 10172
TEST_TIME 28 9892
TEST_TIME 29 9685
TEST_TIME 30 9710
TEST_TIME 31 9616
TEST_TIME 32 9440
TEST_TIME 33 9349
TEST_TIME 34 9196
TEST_TIME 35 9146
TEST_TIME 36 9009
TEST_TIME 37 9042
TEST_TIME 38 9199
TEST_TIME 39 9148
TEST_TIME 40 9066
TEST_TIME 41 9058
TEST_TIME 42 9133
TEST_TIME 43 9110
TEST_TIME 44 9195
TEST_TIME 45 9091
TEST_TIME 46 9227
TEST_TIME 47 9297
TEST_TIME 48 9282
TEST_TIME 49 9367
TEST_TIME 50 9275
TEST_TIME 51 9108
TEST_TIME 52 9092
TEST_TIME 53 9008
TEST_TIME 54 8901
TEST_TIME 55 8811
TEST_TIME 56 8774
TEST_TIME 57 8787
TEST_TIME 58 8790
TEST_TIME 59 8921
TEST_TIME 60 8852
TEST_TIME 61 8905
TEST_TIME 62 8917
TEST_TIME 63 8956
TEST_TIME 64 9017
TEST_TIME 65 9066
TEST_TIME 66 9023
TEST_TIME 67 9217
TEST_TIME 68 9283
TEST_TIME 69 9261
TEST_TIME 70 9303
TEST_TIME 71 9175
TEST_TIME 72 9092
TEST_TIME 73 9023
TEST_TIME 74 8957
TEST_TIME 75 8890
TEST_TIME 76 8854
TEST_TIME 77 8866
TEST_TIME 78 8899
TEST_TIME 79 8862
TEST_TIME 80 8898
TEST_TIME 81 8872
TEST_TIME 82 8898
TEST_TIME 83 8925
TEST_TIME 84 8943
TEST_TIME 85 8935
TEST_TIME 86 8929
TEST_TIME 87 8970
TEST_TIME 88 8999
TEST_TIME 89 9018
TEST_TIME 90 8926
TEST_TIME 91 8865
TEST_TIME 92 8826
TEST_TIME 93 8790
TEST_TIME 94 8791
TEST_TIME 95 8792
TEST_TIME 96 8775
TEST_TIME 97 8752
TEST_TIME 98 8769
TEST_TIME 99 8763
TEST_TIME 100 8860
TEST_TIME 101 8893
TEST_TIME 102 8869
TEST_TIME 103 8885
TEST_TIME 104 8880
TEST_TIME 105 8889
TEST_TIME 106 8904
TEST_TIME 107 8996
TEST_TIME 108 8977
TEST_TIME 109 8897
TEST_TIME 110 8839
TEST_TIME 111 8841
TEST_TIME 112 8814
TEST_TIME 113 8792
TEST_TIME 114 8792
TEST_TIME 115 8791
TEST_TIME 116 8782
TEST_TIME 117 8770
TEST_TIME 118 8779
TEST_TIME 119 8775
TEST_TIME 120 8785

Performance per minute, chart


Completed "Performance for every MINUTE". Done for 00:00:03, from 10-11-2020 07:28:09 to 10-11-2020 07:28:12.

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 1463078 1463078 0 0.00 0 18250 6 0 0
doc_list_biud 1463078 1463078 0 0.00 0 27793 27 0 0
sp_add_invoice_to_stock 4846 4789 57 1.17 27 199567 16368 0 57
sp_cancel_adding_invoice 5312 5312 0 0.00 4 66138 750 0 0
sp_cancel_client_order 1702 1702 0 0.00 4 12652 302 0 0
sp_cancel_customer_reserve 530663 530663 0 0.00 1 20231 60 0 0
sp_cancel_pay_from_customer 646 646 0 0.00 3 5330 69 0 0
sp_cancel_pay_to_supplier 386 386 0 0.00 3 1121 53 0 0
sp_cancel_supplier_invoice 5923 5916 7 0.11 2 23233 773 0 7
sp_cancel_supplier_order 385 385 0 0.00 5 1018871 101523 0 0
sp_cancel_write_off 7761 7761 0 0.00 1 8054 120 0 0
sp_client_order 19706 19706 0 0.00 4 18221 408 0 0
sp_customer_reserve 442828 442828 0 0.00 0 80935 159 0 0
sp_fill_shopping_cart 30183 30183 0 0.00 1 16761 48 0 0
sp_fill_shopping_cart_clo_res 442820 442820 0 0.00 0 28131 17 0 0
sp_get_clo_for_invoice 4779 4779 0 0.00 0 39472 521 0 0
sp_kill_cost_storno 14105 14105 0 0.00 0 5819 50 0 0
sp_kill_qstorno_ret_qs2qd 1075388 1075388 0 0.00 0 20652 32 0 0
sp_kill_qty_storno 565983 565983 0 0.00 0 27792 70 0 0
sp_lock_selected_doc 19722 19722 0 0.00 0 7674 4 0 0
sp_make_cost_storno 26673 26673 0 0.00 0 14969 56 0 0
sp_multiply_rows_for_pdistr 26673 26673 0 0.00 0 7771 29 0 0
sp_multiply_rows_for_qdistr 19706 19706 0 0.00 0 12034 230 0 0
sp_pay_from_customer 6745 6745 0 0.00 4 15630 116 0 0
sp_pay_to_supplier 5684 5684 0 0.00 4 13667 128 0 0
sp_payment_common 12429 12429 0 0.00 1 14772 30 0 0
sp_qd_handle_on_cancel_clo 1702 1702 0 0.00 0 12646 283 0 0
sp_qd_handle_on_invoice_upd_sts 10091 10091 0 0.00 0 27791 343 0 0
sp_qd_handle_on_reserve_upd_sts 9465 9465 0 0.00 0 10254 50 0 0
sp_reserve_write_off 9465 9465 0 0.00 6 16433 176 0 0
sp_supplier_invoice 5218 5218 0 0.00 7 91551 3597 0 0
sp_supplier_order 5261 5261 0 0.00 5 78667 1465 0 0
srv_aggregate_perf_data 106 106 0 0.00 2699 234220 13535 0 0
srv_fill_mon_cache_memory 59 59 0 0.00 1058 161744 51675 0 0
srv_find_qd_qs_mism 1007804 1007804 0 0.00 0 18249 5 0 0
srv_make_invnt_saldo 449 449 0 0.00 49 100403 3095 0 0
srv_make_money_saldo 719 719 0 0.00 1 16378 411 0 0
srv_recalc_idx_stat 4 4 0 0.00 54096 467246 270869 0 0
t$perf-abend:sp_add_invoice_to_stock 57 57 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 4789 4789 0 0.00 0 15770 151 0 0
t$perf-norm:sp_cancel_adding_invoice 341 341 0 0.00 0 11890 126 0 0
t$perf-norm:sp_cancel_client_order 1702 1702 0 0.00 0 2316 10 0 0
t$perf-norm:sp_cancel_customer_reserve 667 667 0 0.00 0 3625 14 0 0
t$perf-norm:sp_cancel_pay_from_customer 646 646 0 0.00 0 866 4 0 0
t$perf-norm:sp_cancel_pay_to_supplier 386 386 0 0.00 0 36 1 0 0
t$perf-norm:sp_cancel_supplier_invoice 389 389 0 0.00 0 4004 19 0 0
t$perf-norm:sp_cancel_supplier_order 385 385 0 0.00 0 14598 1249 0 0
t$perf-norm:sp_cancel_write_off 962 962 0 0.00 0 2466 9 0 0
t$perf-norm:sp_client_order 19706 19706 0 0.00 0 6990 15 0 0
t$perf-norm:sp_customer_reserve 957 957 0 0.00 0 7938 21 0 0
t$perf-norm:sp_pay_from_customer 6745 6745 0 0.00 0 11237 9 0 0
t$perf-norm:sp_pay_to_supplier 5684 5684 0 0.00 0 11393 13 0 0
t$perf-norm:sp_reserve_write_off 9465 9465 0 0.00 0 6298 9 0 0
t$perf-norm:sp_supplier_invoice 5218 5218 0 0.00 0 10011 20 0 0
t$perf-norm:sp_supplier_order 5261 5261 0 0.00 0 11204 14 0 0
t$perf-norm:srv_aggregate_perf_data 106 106 0 0.00 0 481 14 0 0
t$perf-norm:srv_fill_mon_cache_memory 59 59 0 0.00 0 4 0 0 0
t$perf-norm:srv_make_invnt_saldo 449 449 0 0.00 0 11206 33 0 0
t$perf-norm:srv_make_money_saldo 719 719 0 0.00 0 392 4 0 0
t$perf-norm:srv_recalc_idx_stat 4 4 0 0.00 1 4 3 0 0
v_add_invoice_to_stock 9672 9558 114 1.17 0 6354 15 0 114
v_all_customers 35648 35648 0 0.00 0 20 1 0 0
v_all_suppliers 29182 29182 0 0.00 0 14 1 0 0
v_all_wares 39412 39412 0 0.00 0 14 1 0 0
v_cancel_adding_invoice 682 682 0 0.00 0 1048 8 0 0
v_cancel_client_order 3404 3404 0 0.00 0 2000 3 0 0
v_cancel_customer_prepayment 1292 1292 0 0.00 0 4739 10 0 0
v_cancel_customer_reserve 1334 1334 0 0.00 0 1226 4 0 0
v_cancel_payment_to_supplier 772 772 0 0.00 0 1101 6 0 0
v_cancel_supplier_invoice 792 778 14 1.76 0 730 14 0 14
v_cancel_supplier_order 770 770 0 0.00 0 788 5 0 0
v_cancel_write_off 1924 1924 0 0.00 0 2230 13 0 0
v_max_id_clo_ord 5261 5261 0 0.00 0 1583 2 0 0
v_max_id_clo_res 957 957 0 0.00 0 3367 21 0 0
v_max_id_ord_sup 5216 5216 0 0.00 0 4762 6 0 0
v_max_non_paid_invoice 1570 1570 0 0.00 0 321 2 0 0
v_max_non_paid_realizn 3734 3734 0 0.00 0 1128 3 0 0
v_min_id_clo_ord 5261 5261 0 0.00 0 3905 6 0 0
v_min_id_clo_res 957 957 0 0.00 0 8134 34 0 0
v_min_id_ord_sup 5216 5216 0 0.00 0 6384 15 0 0
v_min_non_paid_invoice 5684 5684 0 0.00 0 9909 23 0 0
v_min_non_paid_realizn 6745 6745 0 0.00 0 14767 26 0 0
v_our_firm 9786 9786 0 0.00 0 12 1 0 0
v_reserve_write_off 18930 18930 0 0.00 0 6949 8 0 0
x_lock_depdocs_on_canc_invoice 10839 10839 0 0.00 0 16372 93 0 0
x_lock_depdocs_on_canc_sup_ord 385 385 0 0.00 0 11181 279 0 0
x_make_qstorno_1000_1200 5261 5261 0 0.00 2 78656 1391 0 0
x_make_qstorno_1200_2000 5218 5218 0 0.00 3 81534 3402 0 0
x_make_qstorno_2100_3300 442828 442828 0 0.00 0 80934 140 0 0

Completed "Performance in DETAILS". Done for 00:00:04, from 10-11-2020 07:28:13 to 10-11-2020 07:28:17.

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
04:56:56 2 8192000000 8796633152 8807174144 3163616 0.038 1 1 2 0 3261312 61840 35856
04:57:57 31766 8192000000 9730912208 10031169536 803380416 8.931 100 86 171 1 831586592 7540112 20666064
04:59:36 20335 8192000000 9775669056 10084020224 845015168 9.350 100 83 166 2 878146400 13634048 19497184
05:01:04 19306 8192000000 9826051648 10146238464 879170848 9.691 100 86 172 1 926352992 27818496 19363648
05:02:27 10671 8192000000 9891832240 10226913280 921336256 10.109 100 84 168 1 998243264 58721664 18185344
05:03:41 8055 8192000000 9917332864 10260582400 951770528 10.408 100 86 172 0 1031098992 61092976 18235488
05:04:53 3532 8192000000 9956500240 10307760128 999419584 10.873 100 81 159 2 1066031200 50623360 15988256
05:06:00 3736 8192000000 10011931488 10375966720 1026390128 11.134 100 80 160 2 1118413392 76279136 15744128
05:07:05 1940 8192000000 10037525616 10406780928 1058725600 11.444 100 89 180 0 1148251040 71472736 18052704
05:08:09 2772 8192000000 10023365824 10411462656 1071472064 11.566 100 60 120 3 1142931504 59502048 11957392
05:09:14 6248 8192000000 9997304112 10398187520 1077402256 11.623 100 35 69 2 1129277968 44757744 7117968
05:10:21 1592 8192000000 10013314528 10392338432 1083273552 11.679 100 80 159 0 1109444336 8948528 17222256
05:11:22 5970 8192000000 9999502400 10389639168 1086740992 11.712 100 30 58 3 1118815264 25866880 6207392
05:12:29 7445 8192000000 10013533120 10418380800 1097720720 11.816 100 32 64 2 1124927328 19939552 7267056
05:13:39 17946 8192000000 10029621392 10435457024 1102229072 11.859 100 27 51 4 1128153984 19629312 6295600
05:15:35 6773 8192000000 10028105248 10434125824 1105262192 11.888 100 40 78 2 1129889984 15889776 8738016
05:16:46 8231 8192000000 10004422320 10404339712 1088689744 11.730 99 18 32 2 1108727936 16256704 3781488
05:17:55 62537 8192000000 9961623440 10355134464 973027472 10.616 91 26 52 4 1000190576 21770016 5393088
05:20:00 4299 8192000000 9928575472 10306273280 1007910512 10.955 98 42 84 2 1032573184 15468368 9194304
05:21:07 5966 8192000000 9953072416 10334261248 1026776608 11.137 100 54 110 3 1048844336 9194544 12873184
05:22:13 36826 8192000000 9940384592 10334687232 1027813232 11.147 99 29 58 4 1045938800 12157824 5967744
05:23:58 8321 8192000000 9957751504 10359492608 1042047376 11.284 99 29 58 2 1065113072 17090320 5975376
05:25:09 9825 8192000000 9976613296 10381266944 1063637520 11.491 100 20 38 1 1091603104 23483168 4482416
05:26:22 5413 8192000000 9993534000 10395099136 1082735472 11.674 100 32 64 1 1116880816 27043408 7101936
05:27:35 56130 8192000000 10027087968 10444034048 1098439600 11.823 100 52 105 1 1143786736 34140912 11206224
05:29:46 31610 8192000000 10033334800 10435567616 1107321824 11.907 99 43 86 2 1142520880 25627280 9571776
05:31:23 6760 8192000000 10102918000 10509455360 1125614544 12.080 100 43 86 3 1205892448 71391168 8886736
05:32:37 15470 8192000000 10130997600 10551029760 1142157216 12.236 100 42 84 1 1239398448 88054640 9186592
05:33:57 10931 8192000000 10166970480 10570145792 1162353168 12.425 100 57 114 1 1267589840 92195744 13040928
05:35:17 19475 8192000000 10199887808 10616037376 1168249936 12.480 100 40 80 0 1314953136 137322816 9380384
05:36:43 9082 8192000000 10238894224 10659045376 1172843760 12.523 100 56 110 1 1339418960 154461088 12114112
05:37:58 9926 8192000000 10297516752 10706677760 1181905008 12.608 100 72 145 0 1394218848 195675360 16638480
05:39:14 4881 8192000000 10322418128 10722115584 1168202048 12.480 99 71 143 0 1415346480 230986624 16157808
05:40:23 2676 8192000000 10380100656 10781159424 1181742704 12.606 100 82 165 1 1477417904 276735600 18939600
05:41:28 1888 8192000000 10392805920 10795790336 1162344544 12.425 100 76 153 0 1490399920 310589808 17465568
05:42:33 9235 8192000000 10367387616 10782646272 1158071328 12.385 100 69 138 2 1480550032 306836272 15642432
05:43:49 1055 8192000000 10377842880 10779574272 1139285600 12.209 100 73 144 1 1478358832 321808096 17265136
05:44:58 11558 8192000000 10276804624 10695794688 1117172768 12.000 98 33 64 1 1363994608 238549296 8272544
05:46:13 8851 8192000000 10262784352 10678247424 1089354592 11.737 97 36 72 1 1340685760 243305008 8026160
05:47:27 10369 8192000000 10275264624 10687213568 1098037248 11.819 99 38 77 2 1374871392 267370288 9463856
05:48:43 37828 8192000000 10166128368 10633912320 1068646544 11.539 97 25 50 3 1249867232 175297072 5923616
05:50:21 19819 8192000000 10163937728 10606137344 1107928336 11.913 100 18 36 1 1282574400 170087216 4558848
05:51:48 30604 8192000000 10077092112 10538897408 1097260880 11.812 99 22 43 0 1188532832 86220368 5051584
05:53:28 126975 8192000000 10039377424 10482589696 1074603184 11.596 98 22 44 2 1127971264 48418880 4949200
05:56:56 46258 8192000000 10047238128 10477850624 1105946544 11.894 100 26 53 1 1148715568 37630368 5138656
05:58:43 57733 8192000000 10076986208 10523889664 1097967440 11.818 98 19 35 2 1146120960 44755136 3398384
06:00:41 91883 8192000000 10098558768 10555215872 1104055488 11.876 99 13 26 2 1203977424 97143568 2778368
06:03:14 58811 8192000000 10047825520 10559664128 1105987776 11.894 100 14 26 2 1207983264 98863248 3132240
06:06:22 56265 8192000000 10121395696 10562686976 1138996096 12.206 100 29 58 1 1199339408 54280016 6063296
06:08:39 42597 8192000000 10096466624 10513629184 1129334512 12.115 99 31 62 2 1164420720 28841840 6244368
06:10:23 87754 8192000000 10118752400 10551095296 1152628848 12.334 100 14 28 1 1207616656 51988208 2999600
06:13:02 99407 8192000000 10091234192 10521862144 1133761296 12.157 99 15 29 1 1175173600 37500688 3911616
06:16:03 161744 8192000000 10075293872 10555293696 1128500208 12.107 98 13 26 0 1172081024 40863728 2717088
06:20:16 40806 8192000000 10102560448 10548338688 1152984512 12.338 100 10 20 0 1191593072 36276784 2331776
06:22:07 41833 8192000000 10130476976 10593107968 1136504208 12.183 98 13 27 0 1215652720 76212112 2936400
06:23:50 127834 8192000000 10097315664 10585022464 1110757520 11.940 96 20 41 2 1145446016 29979760 4708736
06:26:58 44876 8192000000 10108066608 10562129920 1137097056 12.188 99 28 57 2 1216877200 73544832 6235312
06:28:46 98029 8192000000 10118362736 10609491968 1117120272 12.000 98 12 24 0 1220327472 100764704 2442496
06:31:28 45694 8192000000 10123227392 10551930880 1099860624 11.836 97 23 46 1 1151171888 46892528 4418736
06:33:19 81623 8192000000 10091410784 10623033344 1090610400 11.748 97 8 16 1 1185779024 93438048 1730576
06:36:40 104444 8192000000 10042918368 10499239936 1104272432 11.878 99 17 34 1 1134433264 26888528 3272304
06:39:25 47692 8192000000 10041909680 10486153216 1108581520 11.919 100 8 16 1 1143721968 33764800 1375648
06:41:50 61859 8192000000 10111438112 10578493440 1111423184 11.946 99 13 26 1 1199600544 85250144 2927216
06:43:52 56738 8192000000 10046403008 10481147904 1101699008 11.854 98 10 20 0 1153376800 49501152 2176640
06:45:50 33681 8192000000 10080645680 10509746176 1068285296 11.536 96 27 54 0 1125491056 51648992 5556768
06:47:27 38035 8192000000 10069547472 10502217728 1111699696 11.949 100 32 64 0 1156749088 38253792 6795600
06:49:10 36385 8192000000 10094095472 10543714304 1109140512 11.924 99 28 56 2 1179615792 64892176 5583104
06:50:50 62957 8192000000 10076614320 10522009600 1116286672 11.992 100 32 64 2 1169086528 46445088 6354768
06:52:56 32365 8192000000 10096575136 10528804864 1094378368 11.784 98 43 85 1 1161742448 58694816 8669264
06:54:30 67549 8192000000 10050463248 10546335744 1079335744 11.641 97 12 24 0 1146167584 64423392 2408448
06:56:53 61295 8192000000 10027187296 10451005440 1090599808 11.748 98 21 42 0 1117063136 22560816 3902512
06:58:57 83762 8192000000 10070334352 10529464320 1094795920 11.788 98 9 18 1 1151248368 54657728 1794720
07:01:52 58387 8192000000 10074395760 10524442624 1126909024 12.092 100 17 34 2 1182135888 51900960 3325904
07:03:55 56971 8192000000 10141743120 10593361920 1114992496 11.980 98 27 54 3 1189609008 68632496 5984016
07:06:01 82122 8192000000 10096295440 10625646592 1122466880 12.050 99 19 38 0 1245160944 118500656 4193408
07:08:30 56438 8192000000 10080933568 10512515072 1102066752 11.857 97 33 66 0 1149235680 40669536 6499392
07:10:54 43600 8192000000 10103483680 10548486144 1125998448 12.084 99 27 54 3 1168921648 37675920 5247280
07:12:43 60017 8192000000 10133186928 10639470592 1144205136 12.255 100 10 19 0 1214968896 68936288 1827472
07:14:51 84624 8192000000 10108857760 10595082240 1152341744 12.331 100 17 34 0 1197310704 41278352 3690608
07:17:37 85015 8192000000 10097762432 10590068736 1140616128 12.221 99 4 8 1 1181438128 40223072 598928
07:20:04 81286 8192000000 10087214448 10614870016 1147231648 12.284 99 4 8 0 1221070896 73050976 788272
07:22:38 86570 8192000000 10122191376 10556137472 1109928784 11.932 96 28 56 1 1191095840 75795520 5371536
07:25:07 58691 8192000000 10133711376 10594619392 1112663184 11.958 97 25 48 1 1187893136 70053392 5176560

Memory consumption, total, chart

Metadata cache size, chart

Statements activity, chart


Completed "Memory consumption, metadata cache, attachments activity". Done for 00:00:15, from 10-11-2020 07:28:19 to 10-11-2020 07:28:34.

Exceptions occured during test was in run

FB_MNEMONA CNT UNIT FB_GDSCODE
except 57 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 10-11-2020 07:28:35 to 10-11-2020 07:28:37.

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          229583
MON$OLDEST_ACTIVE               232799
MON$OLDEST_SNAPSHOT             232799
MON$NEXT_TRANSACTION            232799
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                       2077280
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                        {8C105897-B735-40F5-7D8B-A1F76E952B78}
MON$FILE_ID                     02fd0000000000002e02000000000000
MON$NEXT_ATTACHMENT             793
MON$NEXT_STATEMENT              53


ISQL Version: LI-V4.0.0.2249 Firebird 4.0 Release Candidate 1
Server version:
Firebird/Linux/AMD/Intel/x64 (access method), version "LI-V4.0.0.2249 Firebird 4.0 Release Candidate 1"
Firebird/Linux/AMD/Intel/x64 (remote server), version "LI-V4.0.0.2249 Firebird 4.0 Release Candidate 1/tcp (mscs-test-161.budzdorov.ru)/P16:C"
Firebird/Linux/AMD/Intel/x64 (remote interface), version "LI-V4.0.0.2249 Firebird 4.0 Release Candidate 1/tcp (mscs-test-161.budzdorov.ru)/P16: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 ---
:58: 
:59: mscs-test-161.budzdorov.ru    Tue Nov 10 07:27:04 2020
:60:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:61: 
:62: 
:63: mscs-test-161.budzdorov.ru    Tue Nov 10 07:27:14 2020
:64:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:65: 
:66: 
:67: mscs-test-161.budzdorov.ru    Tue Nov 10 07:27:14 2020
:68:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:69: 
:70: 
:71: mscs-test-161.budzdorov.ru    Tue Nov 10 07:27:14 2020
:72:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:73: 
:74: 
:75: mscs-test-161.budzdorov.ru    Tue Nov 10 07:27:15 2020
:76:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:77: 
--- end of diff output ---

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

10.11.20 07:28:38. 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
2020-11-10 07:28:41 No severe PSQL-related problems occured
10.11.20 07:28:42. End of report.