Generated by /opt/oltp-emul/oltp_isql_run_worker.sh, ISQL session No. 1 of total launched 100. 30.10.2020 04:27
Common Performance Final Results
  1. Hardware and OS info
  2. DB and 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, full
  3. Ratio "Versions / Records" for tables
  4. Database Validation Results
  5. New in firebird.log while test was run
  6. 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 16871124 kB
MemAvailable 31448928 kB
Buffers 20 kB
Cached 14724676 kB
SwapCached 3064 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-10-30 04:26:52
DTS_END                         2020-10-30 04:26:52.8980
FB_GDSCODE                      -1
FB_MNEMONA                      
STACK                           SP_ADD_INVOICE_TO_STOCK(190:30) ==> SP_CUSTOMER_RESERVE(47:5) ==> SP_CHECK_TO_STOP_WORK(32:12) ==> SP_HALT_ON_ERROR(67:17)
IP                              ::1/38704
TRN_ID                          229545
ATT_ID                          635
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: 8903.87 20375 1068464
customer order: creation 163.54 452 19625
customer order: refuse 14.98 321 1798
order to supplier: creation 44.57 1384 5348
order to supplier: removal 3.53 124963 423
invoice (draft): creation 43.98 3652 5278
invoice (draft): removal 50.01 1007 6001
invoice accept: apply 40.36 18800 4843
invoice accept: cancel 45.80 919 5496
customer reserve: creation 3745.58 183 449469
customer reserve: removal 4470.22 78 536426
realization accept: apply 80.05 165 9606
realization accept: cancel 81.39 129 9767
payment from customer: creation 55.27 103 6632
payment from customer: removal 5.53 73 663
payment to supplier: creation 44.88 122 5386
payment to supplier: removal 3.48 83 418
service: total inventory turnovers 3.90 3178 468
service: total monetary turnovers 5.89 591 707
service: aggregate perf. data 0.88 15293 106
service: refresh index statistics 0.03 236012 4

Performance in TOTAL, chart


Completed "Performance in TOTAL". Done for 00:00:03, from 30-10-2020 04:28:00 to 30-10-2020 04:28:03.

Performance for every MINUTE

TEST_PHASE_NAME MINUTES_PASSED PERF_SCORE
TEST_TIME 1 3740
TEST_TIME 2 3404
TEST_TIME 3 4586
TEST_TIME 4 5089
TEST_TIME 5 5843
TEST_TIME 6 5533
TEST_TIME 7 5795
TEST_TIME 8 5705
TEST_TIME 9 5622
TEST_TIME 10 5631
TEST_TIME 11 5821
TEST_TIME 12 5950
TEST_TIME 13 6146
TEST_TIME 14 6085
TEST_TIME 15 6088
TEST_TIME 16 6154
TEST_TIME 17 6241
TEST_TIME 18 6269
TEST_TIME 19 6697
TEST_TIME 20 7335
TEST_TIME 21 7721
TEST_TIME 22 8093
TEST_TIME 23 8081
TEST_TIME 24 8283
TEST_TIME 25 8502
TEST_TIME 26 9019
TEST_TIME 27 10931
TEST_TIME 28 11325
TEST_TIME 29 11188
TEST_TIME 30 10958
TEST_TIME 31 10712
TEST_TIME 32 10538
TEST_TIME 33 10409
TEST_TIME 34 10267
TEST_TIME 35 10247
TEST_TIME 36 10158
TEST_TIME 37 10209
TEST_TIME 38 10042
TEST_TIME 39 10011
TEST_TIME 40 10013
TEST_TIME 41 9893
TEST_TIME 42 9932
TEST_TIME 43 9836
TEST_TIME 44 9793
TEST_TIME 45 9756
TEST_TIME 46 9711
TEST_TIME 47 9766
TEST_TIME 48 9728
TEST_TIME 49 9754
TEST_TIME 50 9895
TEST_TIME 51 9821
TEST_TIME 52 9839
TEST_TIME 53 9941
TEST_TIME 54 10003
TEST_TIME 55 10026
TEST_TIME 56 9901
TEST_TIME 57 9759
TEST_TIME 58 9684
TEST_TIME 59 9645
TEST_TIME 60 9571
TEST_TIME 61 9495
TEST_TIME 62 9457
TEST_TIME 63 9459
TEST_TIME 64 9423
TEST_TIME 65 9393
TEST_TIME 66 9382
TEST_TIME 67 9409
TEST_TIME 68 9385
TEST_TIME 69 9441
TEST_TIME 70 9545
TEST_TIME 71 9571
TEST_TIME 72 9516
TEST_TIME 73 9611
TEST_TIME 74 9534
TEST_TIME 75 9427
TEST_TIME 76 9479
TEST_TIME 77 9419
TEST_TIME 78 9329
TEST_TIME 79 9284
TEST_TIME 80 9204
TEST_TIME 81 9222
TEST_TIME 82 9183
TEST_TIME 83 9175
TEST_TIME 84 9155
TEST_TIME 85 9130
TEST_TIME 86 9136
TEST_TIME 87 9141
TEST_TIME 88 9174
TEST_TIME 89 9180
TEST_TIME 90 9208
TEST_TIME 91 9213
TEST_TIME 92 9306
TEST_TIME 93 9265
TEST_TIME 94 9172
TEST_TIME 95 9118
TEST_TIME 96 9112
TEST_TIME 97 9108
TEST_TIME 98 9079
TEST_TIME 99 9101
TEST_TIME 100 9063
TEST_TIME 101 9054
TEST_TIME 102 9049
TEST_TIME 103 9044
TEST_TIME 104 9073
TEST_TIME 105 9074
TEST_TIME 106 9064
TEST_TIME 107 9127
TEST_TIME 108 9191
TEST_TIME 109 9165
TEST_TIME 110 9085
TEST_TIME 111 9062
TEST_TIME 112 9015
TEST_TIME 113 8961
TEST_TIME 114 8956
TEST_TIME 115 8922
TEST_TIME 116 8902
TEST_TIME 117 8915
TEST_TIME 118 8893
TEST_TIME 119 8951
TEST_TIME 120 8911

Performance per minute, chart


Completed "Performance for every MINUTE". Done for 00:00:03, from 30-10-2020 04:28:04 to 30-10-2020 04:28:07.

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 1484600 1484600 0 0.00 0 31802 7 0 0
doc_list_biud 1484600 1484600 0 0.00 0 52277 35 0 0
sp_add_invoice_to_stock 4955 4843 112 2.26 41 206446 18801 0 112
sp_cancel_adding_invoice 5496 5496 0 0.00 4 78441 920 0 0
sp_cancel_client_order 1798 1798 0 0.00 4 10037 322 0 0
sp_cancel_customer_reserve 536426 536426 0 0.00 1 52278 79 0 0
sp_cancel_pay_from_customer 663 663 0 0.00 3 3453 74 0 0
sp_cancel_pay_to_supplier 418 418 0 0.00 3 4281 83 0 0
sp_cancel_supplier_invoice 6008 6001 7 0.11 1 27495 1008 0 7
sp_cancel_supplier_order 423 423 0 0.00 6 1230292 124964 0 0
sp_cancel_write_off 9767 9767 0 0.00 1 10099 130 0 0
sp_client_order 19625 19625 0 0.00 4 31716 453 0 0
sp_customer_reserve 449469 449469 0 0.00 0 153129 183 0 0
sp_fill_shopping_cart 30249 30249 0 0.00 1 18224 43 0 0
sp_fill_shopping_cart_clo_res 449456 449456 0 0.00 0 16190 19 0 0
sp_get_clo_for_invoice 4829 4829 0 0.00 0 21740 398 0 0
sp_kill_cost_storno 16344 16344 0 0.00 0 9957 61 0 0
sp_kill_qstorno_ret_qs2qd 1089043 1089043 0 0.00 0 52274 42 0 0
sp_kill_qty_storno 574346 574346 0 0.00 0 52277 89 0 0
sp_lock_selected_doc 20146 20146 0 0.00 0 8436 6 0 0
sp_make_cost_storno 26453 26453 0 0.00 0 10610 51 0 0
sp_multiply_rows_for_pdistr 26453 26453 0 0.00 0 6070 32 0 0
sp_multiply_rows_for_qdistr 19625 19625 0 0.00 0 19614 271 0 0
sp_pay_from_customer 6632 6632 0 0.00 4 12734 103 0 0
sp_pay_to_supplier 5386 5386 0 0.00 4 12712 123 0 0
sp_payment_common 12018 12018 0 0.00 1 7403 20 0 0
sp_qd_handle_on_cancel_clo 1798 1798 0 0.00 0 10028 291 0 0
sp_qd_handle_on_invoice_upd_sts 10325 10325 0 0.00 0 22950 395 0 0
sp_qd_handle_on_reserve_upd_sts 9606 9606 0 0.00 0 26170 47 0 0
sp_reserve_write_off 9606 9606 0 0.00 7 26190 166 0 0
sp_supplier_invoice 5278 5278 0 0.00 6 153101 3653 0 0
sp_supplier_order 5348 5348 0 0.00 5 37096 1385 0 0
srv_aggregate_perf_data 107 106 1 0.93 2606 141711 15293 0 1
srv_fill_mon_cache_memory 62 62 0 0.00 1054 279964 49906 0 0
srv_find_qd_qs_mism 1022927 1022927 0 0.00 0 26160 6 0 0
srv_make_invnt_saldo 468 468 0 0.00 37 90279 3178 0 0
srv_make_money_saldo 707 707 0 0.00 1 13710 591 0 0
srv_recalc_idx_stat 4 4 0 0.00 112452 313488 236013 0 0
t$perf-abend:sp_add_invoice_to_stock 112 112 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-abend:srv_aggregate_perf_data 1 1 0 0.00 0 0 0 0 0
t$perf-norm:sp_add_invoice_to_stock 4844 4844 0 0.00 0 19052 168 0 0
t$perf-norm:sp_cancel_adding_invoice 388 388 0 0.00 0 6644 110 0 0
t$perf-norm:sp_cancel_client_order 1798 1798 0 0.00 0 2286 14 0 0
t$perf-norm:sp_cancel_customer_reserve 666 666 0 0.00 0 3396 14 0 0
t$perf-norm:sp_cancel_pay_from_customer 663 663 0 0.00 0 6443 16 0 0
t$perf-norm:sp_cancel_pay_to_supplier 418 418 0 0.00 0 943 4 0 0
t$perf-norm:sp_cancel_supplier_invoice 379 379 0 0.00 0 2158 19 0 0
t$perf-norm:sp_cancel_supplier_order 423 423 0 0.00 0 20989 1579 0 0
t$perf-norm:sp_cancel_write_off 979 979 0 0.00 0 7992 13 0 0
t$perf-norm:sp_client_order 19625 19625 0 0.00 0 15252 19 0 0
t$perf-norm:sp_customer_reserve 906 906 0 0.00 0 2790 15 0 0
t$perf-norm:sp_pay_from_customer 6632 6632 0 0.00 0 6961 12 0 0
t$perf-norm:sp_pay_to_supplier 5386 5386 0 0.00 0 12453 13 0 0
t$perf-norm:sp_reserve_write_off 9606 9606 0 0.00 0 5999 11 0 0
t$perf-norm:sp_supplier_invoice 5278 5278 0 0.00 0 6339 17 0 0
t$perf-norm:sp_supplier_order 5348 5348 0 0.00 0 4910 17 0 0
t$perf-norm:srv_aggregate_perf_data 106 106 0 0.00 0 478 16 0 0
t$perf-norm:srv_fill_mon_cache_memory 62 62 0 0.00 0 3469 57 0 0
t$perf-norm:srv_make_invnt_saldo 468 468 0 0.00 0 2493 22 0 0
t$perf-norm:srv_make_money_saldo 707 707 0 0.00 0 658 6 0 0
t$perf-norm:srv_recalc_idx_stat 4 4 0 0.00 2 7 4 0 0
v_add_invoice_to_stock 9876 9652 224 2.26 0 5928 17 0 224
v_all_customers 35722 35722 0 0.00 0 18 1 0 0
v_all_suppliers 28938 28938 0 0.00 0 21 1 0 0
v_all_wares 39250 39250 0 0.00 0 54 1 0 0
v_cancel_adding_invoice 776 776 0 0.00 0 508 6 0 0
v_cancel_client_order 3596 3596 0 0.00 0 4817 5 0 0
v_cancel_customer_prepayment 1326 1326 0 0.00 0 1679 9 0 0
v_cancel_customer_reserve 1332 1332 0 0.00 0 4124 6 0 0
v_cancel_payment_to_supplier 836 836 0 0.00 0 2218 7 0 0
v_cancel_supplier_invoice 772 758 14 1.81 0 755 13 0 14
v_cancel_supplier_order 846 846 0 0.00 0 688 5 0 0
v_cancel_write_off 1958 1958 0 0.00 0 3521 15 0 0
v_max_id_clo_ord 5348 5348 0 0.00 0 878 1 0 0
v_max_id_clo_res 906 906 0 0.00 0 2477 14 0 0
v_max_id_ord_sup 5276 5276 0 0.00 0 4062 4 0 0
v_max_non_paid_invoice 1541 1541 0 0.00 0 198 2 0 0
v_max_non_paid_realizn 3489 3489 0 0.00 0 512 2 0 0
v_min_id_clo_ord 5348 5348 0 0.00 0 2928 7 0 0
v_min_id_clo_res 906 906 0 0.00 0 5209 12 0 0
v_min_id_ord_sup 5276 5276 0 0.00 0 6786 8 0 0
v_min_non_paid_invoice 5386 5386 0 0.00 0 7397 14 0 0
v_min_non_paid_realizn 6632 6632 0 0.00 0 6768 14 0 0
v_our_firm 9814 9814 0 0.00 0 13 1 0 0
v_reserve_write_off 19212 19212 0 0.00 0 5370 6 0 0
x_lock_depdocs_on_canc_invoice 11118 11118 0 0.00 0 34929 123 0 0
x_lock_depdocs_on_canc_sup_ord 423 423 0 0.00 0 4516 319 0 0
x_make_qstorno_1000_1200 5348 5348 0 0.00 2 37092 1310 0 0
x_make_qstorno_1200_2000 5278 5278 0 0.00 2 153074 3487 0 0
x_make_qstorno_2100_3300 449469 449469 0 0.00 0 153128 162 0 0

Completed "Performance in DETAILS". Done for 00:00:04, from 30-10-2020 04:28:08 to 30-10-2020 04:28:12.

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
01:56:56 2 8192000000 8796633136 8807174144 3163600 0.038 1 1 2 0 3261296 61840 35856
01:57:58 20155 8192000000 9724017936 10019954688 801048640 8.907 100 83 166 0 828399584 7544704 19806240
01:59:23 2660 8192000000 9749861792 10054713344 827993648 9.179 100 89 178 0 861514976 12320592 21200736
02:00:30 19653 8192000000 9786851696 10099974144 858554208 9.486 100 84 167 1 895401216 16985696 19861312
02:01:56 12125 8192000000 9845368304 10176745472 906684800 9.965 100 77 154 0 959384048 35026976 17672272
02:03:12 8419 8192000000 9899459120 10243076096 948107920 10.373 100 77 154 1 1017707536 53052528 16547088
02:04:26 5875 8192000000 9959211136 10309140480 991603456 10.797 100 83 166 0 1065393696 57262192 16528048
02:05:35 2341 8192000000 9994038848 10356383744 1018157040 11.054 100 87 173 0 1114339072 78405056 17776976
02:06:38 1561 8192000000 10020926320 10390687744 1051148752 11.372 100 83 167 0 1136124656 68170944 16804960
02:07:41 1617 8192000000 10037667936 10410582016 1065616160 11.510 100 89 179 2 1143672752 59961456 18095136
02:08:44 7414 8192000000 9976204624 10360745984 1067220192 11.526 100 33 69 0 1086548128 11505504 7822432
02:09:52 6911 8192000000 9974676416 10377453568 1073198720 11.583 100 21 41 2 1099346480 21729600 4418160
02:11:01 67145 8192000000 10000979856 10412871680 1080810640 11.655 100 32 64 0 1100738320 13009008 6918672
02:13:09 7004 8192000000 10004876848 10401198080 1090915824 11.751 100 32 63 2 1113349056 15058304 7374928
02:14:17 4707 8192000000 10016912768 10413772800 1091998112 11.762 100 35 70 1 1119510272 20579968 6932192
02:15:23 9040 8192000000 10012347520 10426499072 1085127888 11.696 99 19 37 2 1110886800 21519600 4239312
02:16:35 33920 8192000000 9993431024 10411843584 1050048976 11.361 96 23 46 0 1086526944 31487952 4990016
02:18:09 9230 8192000000 9970132320 10370068480 1020130480 11.073 96 39 78 1 1061009168 32751776 8126912
02:19:21 9835 8192000000 9935859520 10326306816 978422128 10.669 94 21 42 2 1003528480 20678240 4428112
02:20:31 5004 8192000000 9942100480 10317332480 1008171856 10.958 98 39 79 2 1038330080 21430144 8728080
02:21:36 21679 8192000000 9918194768 10308460544 948197344 10.373 92 9 18 1 969658000 19474000 1986656
02:22:58 7477 8192000000 9959177792 10351640576 1035803472 11.224 100 41 82 1 1062613648 17512608 9297568
02:24:06 4738 8192000000 9980518160 10367037440 1060835072 11.464 100 52 106 1 1086744160 13992816 11916272
02:25:13 11810 8192000000 9986423632 10379137024 1067919696 11.532 100 35 71 1 1102274560 25886384 8468480
02:26:25 12610 8192000000 9981504688 10384470016 1079559888 11.643 100 13 24 1 1102219504 20017408 2642208
02:27:43 7695 8192000000 10040273792 10432389120 1096251296 11.802 100 52 104 2 1141459792 34808960 10399536
02:29:03 12256 8192000000 10080215088 10474201088 1108938096 11.922 100 61 121 2 1190509808 69449072 12122640
02:30:17 14588 8192000000 10104522368 10504495104 1114974912 11.979 100 59 118 2 1217823744 90438944 12409888
02:31:46 22136 8192000000 10084651712 10489012224 1130473728 12.126 100 45 90 1 1191897872 50967936 10456208
02:33:10 16443 8192000000 10124074576 10529804288 1143606864 12.249 100 54 108 0 1231636864 76481536 11548464
02:34:35 7086 8192000000 10174120432 10578300928 1152768320 12.335 100 65 130 0 1275334288 109096800 13469168
02:35:49 17426 8192000000 10217115104 10634440704 1168629184 12.484 100 46 92 2 1328323536 149503792 10190560
02:37:11 5451 8192000000 10249039088 10659258368 1176859824 12.561 100 57 112 2 1351926720 162138560 12928336
02:38:19 12781 8192000000 10273899984 10682929152 1182050320 12.609 100 70 138 1 1370657824 173042240 15565264
02:39:36 11159 8192000000 10294279920 10711130112 1183300224 12.621 100 66 131 2 1397163712 198718512 15144976
02:40:55 7022 8192000000 10361212176 10774409216 1191629456 12.699 100 63 124 2 1459119248 253344768 14145024
02:42:09 2946 8192000000 10392571392 10801618944 1208284352 12.853 100 77 156 1 1498204768 271331808 18588608
02:43:16 4345 8192000000 10444300352 10857742336 1180557024 12.595 99 61 122 0 1543296432 347805440 14933968
02:44:23 1053 8192000000 10537585392 10935652352 1190240464 12.686 100 92 184 0 1635951584 423268768 22442352
02:45:31 1974 8192000000 10521906032 10922225664 1153018032 12.338 99 85 168 1 1621202016 448009856 20174128
02:46:38 3819 8192000000 10565415616 10980487168 1168488592 12.483 100 84 168 1 1657413200 467980656 20943952
02:47:43 11720 8192000000 10529104544 10942439424 1182352992 12.612 100 53 106 1 1617118944 420906576 13859376
02:49:05 22138 8192000000 10516416784 10935939072 1175767968 12.551 100 38 77 0 1614901440 429095248 10038224
02:50:28 19669 8192000000 10565247584 11044888576 1176089904 12.554 100 35 70 0 1659311216 473678240 9543072
02:51:52 18911 8192000000 10550465984 11023003648 1145067456 12.263 100 25 50 0 1657531120 504917520 7546144
02:53:13 8105 8192000000 10432616800 10887614464 1118676656 12.014 99 36 73 0 1522005408 394211776 9116976
02:54:25 55953 8192000000 10063990320 10549133312 1102591216 11.862 98 7 13 1 1171020544 66986064 1443264
02:56:22 14179 8192000000 10074533120 10488332288 1115777472 11.987 99 52 103 4 1159714288 33598096 10338720
02:57:37 151684 8192000000 10049310640 10469380096 1064522992 11.500 94 33 66 1 1106567792 35263392 6781408
03:01:28 69473 8192000000 10118836480 10572279808 1094904816 11.789 97 32 64 2 1166676080 65044432 6726832
03:03:46 279964 8192000000 10096119440 10569261056 1109886256 11.931 98 22 44 1 1198818528 84156080 4776192
03:09:30 60293 8192000000 10067236224 10568822784 1132524032 12.145 99 8 16 0 1172254560 38044144 1686384
03:11:32 87417 8192000000 10126576384 10590134272 1137053456 12.188 99 16 32 0 1216807696 76194528 3559712
03:14:10 40774 8192000000 10119943728 10551160832 1131714736 12.138 98 31 62 2 1184949904 47102272 6132896
03:15:56 57223 8192000000 10092543776 10568654848 1132478240 12.145 99 15 30 1 1206332768 70510576 3343952
03:17:54 36160 8192000000 10150569456 10599968768 1147387328 12.285 100 24 48 0 1245093440 92489264 5216848
03:19:31 75345 8192000000 10109551040 10609385472 1124682128 12.071 98 9 18 1 1170210016 43618928 1908960
03:21:47 105885 8192000000 10070074144 10516353024 1136233264 12.180 99 18 35 0 1161541024 21553808 3753952
03:24:53 54937 8192000000 10066904928 10529271808 1140729792 12.222 99 15 30 1 1165946864 21489280 3727792
03:26:49 48056 8192000000 10042194944 10501373952 1101151024 11.849 96 4 8 0 1124988800 23477968 359808
03:28:44 59207 8192000000 10084882176 10539589632 1119678960 12.024 98 12 24 0 1173856032 51898464 2278608
03:30:56 33202 8192000000 10134293024 10570117120 1126419808 12.088 98 25 50 0 1198308736 66883344 5005584
03:32:39 81696 8192000000 10174287024 10637778944 1127945952 12.102 97 25 50 1 1243040736 109411088 5683696
03:35:33 56876 8192000000 10100902640 10563612672 1098118912 11.820 97 17 33 0 1198330896 96801328 3410656
03:37:33 58399 8192000000 10095666912 10518388736 1126885920 12.092 99 45 89 1 1176680768 40097536 9697312
03:39:40 43196 8192000000 10098955200 10542739456 1119819568 12.025 99 32 64 2 1179736352 53827440 6089344
03:41:23 79359 8192000000 10125809584 10598891520 1130801360 12.129 100 41 81 1 1222469152 83353136 8314656
03:43:55 41977 8192000000 10053679056 10534612992 1100940624 11.847 98 5 10 1 1141240832 38968256 1331952
03:45:41 103756 8192000000 10054068496 10540359680 1072508048 11.576 96 8 16 1 1118201920 43788496 1905376
03:48:39 36789 8192000000 10041105728 10470486016 1090540064 11.748 99 19 39 1 1113330352 19000976 3789312
03:50:18 48997 8192000000 10078473440 10514976768 1103632688 11.872 98 30 60 2 1155384656 45373264 6378704
03:52:12 94490 8192000000 10091813488 10547294208 1083257792 11.679 97 25 50 0 1169516336 80957984 5300560
03:55:07 72590 8192000000 10084362816 10517696512 1088294576 11.726 98 24 48 1 1134666864 41385504 4986784
03:57:30 22854 8192000000 10102475168 10526515200 1123606064 12.061 100 43 86 0 1169262992 37259440 8397488
03:58:54 93302 8192000000 10044131488 10554519552 1083872320 11.684 97 6 12 0 1126524928 41672928 979680
04:01:28 50058 8192000000 10045288176 10485260288 1105097328 11.886 99 11 21 2 1135991616 28800672 2093616
04:03:18 64823 8192000000 10065055696 10496135168 1108768688 11.921 99 11 22 0 1139300096 28257648 2273760
04:05:23 49070 8192000000 10065085184 10500079616 1121879920 12.045 99 15 31 2 1156775024 32140976 2754128
04:07:17 44459 8192000000 10088677056 10530377728 1127196432 12.095 99 38 76 3 1173996128 38682880 8116816
04:09:03 59659 8192000000 10091690368 10545713152 1076016832 11.610 94 28 56 2 1135972480 54263232 5692416
04:11:16 103735 8192000000 10175100720 10643136512 1122722992 12.053 99 15 30 1 1197243424 71289856 3230576
04:14:00 142860 8192000000 10080789888 10513104896 1106116800 11.896 97 10 18 1 1167215184 58785952 2312432
04:18:01 60175 8192000000 10057801152 10533638144 1127068528 12.094 99 4 8 0 1164635200 36876304 690368
04:20:01 39944 8192000000 10055019856 10535940096 1114837392 11.978 99 6 12 0 1153310896 37523888 949616
04:21:41 79689 8192000000 10088142832 10549288960 1137738256 12.194 100 19 38 1 1183216624 41727216 3751152
04:24:10 71093 8192000000 10109286896 10580070400 1116757680 11.996 98 20 40 1 1205812304 84989104 4065520
04:26:21 35713 8192000000 9363576304 9683501056 485794240 5.598 43 20 36 3 519600992 29800976 4005776

Memory consumption, total, chart

Metadata cache size, chart

Statements activity, chart


Completed "Memory consumption, metadata cache, attachments activity". Done for 00:00:15, from 30-10-2020 04:28:14 to 30-10-2020 04:28:29.

Exceptions occured during test was in run

FB_MNEMONA CNT UNIT FB_GDSCODE
user_exc 1 srv_aggregate_perf_data 335544517
user_exc 112 v_add_invoice_to_stock 335544517
user_exc 7 v_cancel_supplier_invoice 335544517

Completed "Exceptions occured during test was in run". Done for 00:00:02, from 30-10-2020 04:28:30 to 30-10-2020 04:28:32.

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          229824
MON$OLDEST_ACTIVE               229825
MON$OLDEST_SNAPSHOT             229825
MON$NEXT_TRANSACTION            229825
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                       2087200
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             769
MON$NEXT_STATEMENT              53


ISQL Version: LI-V4.0.0.2241 Firebird 4.0 Release Candidate 1
Server version:
Firebird/Linux/AMD/Intel/x64 (access method), version "LI-V4.0.0.2241 Firebird 4.0 Release Candidate 1"
Firebird/Linux/AMD/Intel/x64 (remote server), version "LI-V4.0.0.2241 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.2241 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 ---
:29: 
:30: mscs-test-161.budzdorov.ru    Fri Oct 30 04:27:05 2020
:31:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:32: 
--- end of diff output ---

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

30.10.20 04:28:33. 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-10-30 04:28:35 No severe PSQL-related problems occured
30.10.20 04:28:37. End of report.