Generated by /opt/oltp-emul/oltp_isql_run_worker.sh, ISQL session No. 1 of total launched 100. 08.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 16718028 kB
MemAvailable 31409396 kB
Buffers 0 kB
Cached 14904360 kB
SwapCached 2832 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-08 07:26:53
DTS_END                         2020-11-08 07:26:53.1100
FB_GDSCODE                      -1
FB_MNEMONA                      
STACK                           SP_SUPPLIER_ORDER(38:5) ==> SP_CHECK_TO_STOP_WORK(32:12) ==> SP_HALT_ON_ERROR(68:17)
IP                              ::1/38614
TRN_ID                          240951
ATT_ID                          677
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: 9066.78 27804 1088014
customer order: creation 174.22 472 20906
customer order: refuse 14.61 299 1753
order to supplier: creation 45.13 1364 5415
order to supplier: removal 3.23 124794 387
invoice (draft): creation 46.02 3655 5522
invoice (draft): removal 51.00 945 6120
invoice accept: apply 41.58 17366 4990
invoice accept: cancel 45.71 959 5485
customer reserve: creation 3846.80 169 461616
customer reserve: removal 4507.61 72 540913
realization accept: apply 83.18 184 9982
realization accept: cancel 79.64 113 9557
payment from customer: creation 59.63 127 7155
payment from customer: removal 5.43 121 651
payment to supplier: creation 48.66 128 5839
payment to supplier: removal 3.13 50 376
service: total inventory turnovers 4.18 2865 501
service: total monetary turnovers 6.09 456 731
service: aggregate perf. data 0.93 13231 112
service: refresh index statistics 0.03 388710 3

Performance in TOTAL, chart


Completed "Performance in TOTAL". Done for 00:00:02, from 08-11-2020 07:27:45 to 08-11-2020 07:27:47.

Performance for every MINUTE

TEST_PHASE_NAME MINUTES_PASSED PERF_SCORE
TEST_TIME 1 780
TEST_TIME 2 1256
TEST_TIME 3 2156
TEST_TIME 4 2592
TEST_TIME 5 2915
TEST_TIME 6 3309
TEST_TIME 7 3982
TEST_TIME 8 4418
TEST_TIME 9 4680
TEST_TIME 10 5651
TEST_TIME 11 5747
TEST_TIME 12 5802
TEST_TIME 13 6141
TEST_TIME 14 6265
TEST_TIME 15 6399
TEST_TIME 16 6565
TEST_TIME 17 7070
TEST_TIME 18 7431
TEST_TIME 19 7917
TEST_TIME 20 7975
TEST_TIME 21 7911
TEST_TIME 22 8314
TEST_TIME 23 9254
TEST_TIME 24 9795
TEST_TIME 25 9727
TEST_TIME 26 10528
TEST_TIME 27 11040
TEST_TIME 28 10854
TEST_TIME 29 10610
TEST_TIME 30 10717
TEST_TIME 31 10662
TEST_TIME 32 10417
TEST_TIME 33 10210
TEST_TIME 34 10085
TEST_TIME 35 9938
TEST_TIME 36 10073
TEST_TIME 37 10072
TEST_TIME 38 9995
TEST_TIME 39 9960
TEST_TIME 40 9849
TEST_TIME 41 9671
TEST_TIME 42 9732
TEST_TIME 43 9577
TEST_TIME 44 9699
TEST_TIME 45 9617
TEST_TIME 46 9583
TEST_TIME 47 9541
TEST_TIME 48 9635
TEST_TIME 49 9597
TEST_TIME 50 9726
TEST_TIME 51 9714
TEST_TIME 52 9762
TEST_TIME 53 9733
TEST_TIME 54 9739
TEST_TIME 55 9825
TEST_TIME 56 9780
TEST_TIME 57 9631
TEST_TIME 58 9566
TEST_TIME 59 9509
TEST_TIME 60 9397
TEST_TIME 61 9327
TEST_TIME 62 9252
TEST_TIME 63 9325
TEST_TIME 64 9312
TEST_TIME 65 9289
TEST_TIME 66 9289
TEST_TIME 67 9264
TEST_TIME 68 9432
TEST_TIME 69 9364
TEST_TIME 70 9434
TEST_TIME 71 9421
TEST_TIME 72 9425
TEST_TIME 73 9487
TEST_TIME 74 9530
TEST_TIME 75 9407
TEST_TIME 76 9351
TEST_TIME 77 9289
TEST_TIME 78 9254
TEST_TIME 79 9227
TEST_TIME 80 9219
TEST_TIME 81 9187
TEST_TIME 82 9246
TEST_TIME 83 9212
TEST_TIME 84 9235
TEST_TIME 85 9207
TEST_TIME 86 9277
TEST_TIME 87 9329
TEST_TIME 88 9315
TEST_TIME 89 9373
TEST_TIME 90 9404
TEST_TIME 91 9315
TEST_TIME 92 9226
TEST_TIME 93 9241
TEST_TIME 94 9201
TEST_TIME 95 9173
TEST_TIME 96 9179
TEST_TIME 97 9153
TEST_TIME 98 9117
TEST_TIME 99 9131
TEST_TIME 100 9144
TEST_TIME 101 9124
TEST_TIME 102 9168
TEST_TIME 103 9185
TEST_TIME 104 9218
TEST_TIME 105 9332
TEST_TIME 106 9322
TEST_TIME 107 9281
TEST_TIME 108 9232
TEST_TIME 109 9205
TEST_TIME 110 9207
TEST_TIME 111 9164
TEST_TIME 112 9127
TEST_TIME 113 9088
TEST_TIME 114 9092
TEST_TIME 115 9092
TEST_TIME 116 9063
TEST_TIME 117 9051
TEST_TIME 118 9061
TEST_TIME 119 9075
TEST_TIME 120 9067

Performance per minute, chart


Completed "Performance for every MINUTE". Done for 00:00:03, from 08-11-2020 07:27:49 to 08-11-2020 07:27:52.

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 1516507 1516507 0 0.00 0 32002 6 0 0
doc_list_biud 1516507 1516507 0 0.00 0 80776 32 0 0
sp_add_invoice_to_stock 5117 4990 127 2.48 30 178675 17367 0 127
sp_cancel_adding_invoice 5485 5485 0 0.00 5 52896 960 0 0
sp_cancel_client_order 1753 1753 0 0.00 4 13486 300 0 0
sp_cancel_customer_reserve 540913 540913 0 0.00 1 53507 73 0 0
sp_cancel_pay_from_customer 651 651 0 0.00 3 26774 121 0 0
sp_cancel_pay_to_supplier 376 376 0 0.00 3 1380 50 0 0
sp_cancel_supplier_invoice 6131 6120 11 0.17 2 80785 945 0 11
sp_cancel_supplier_order 387 387 0 0.00 9 957983 124794 0 0
sp_cancel_write_off 9557 9557 0 0.00 1 26788 114 0 0
sp_client_order 20906 20906 0 0.00 4 30997 472 0 0
sp_customer_reserve 461616 461616 0 0.00 0 71171 169 0 0
sp_fill_shopping_cart 31839 31839 0 0.00 1 12029 37 0 0
sp_fill_shopping_cart_clo_res 461615 461615 0 0.00 0 25782 21 0 0
sp_get_clo_for_invoice 4989 4989 0 0.00 0 39099 434 0 0
sp_kill_cost_storno 16069 16069 0 0.00 0 27327 62 0 0
sp_kill_qstorno_ret_qs2qd 1097890 1097890 0 0.00 0 80772 39 0 0
sp_kill_qty_storno 579186 579186 0 0.00 0 80775 83 0 0
sp_lock_selected_doc 20689 20689 0 0.00 0 12081 6 0 0
sp_make_cost_storno 27965 27965 0 0.00 0 31997 53 0 0
sp_multiply_rows_for_pdistr 27965 27965 0 0.00 0 28017 39 0 0
sp_multiply_rows_for_qdistr 20906 20906 0 0.00 0 19285 286 0 0
sp_pay_from_customer 7155 7155 0 0.00 4 27905 127 0 0
sp_pay_to_supplier 5839 5839 0 0.00 4 32025 128 0 0
sp_payment_common 12994 12994 0 0.00 1 27901 28 0 0
sp_qd_handle_on_cancel_clo 1753 1753 0 0.00 0 13478 270 0 0
sp_qd_handle_on_invoice_upd_sts 10474 10474 0 0.00 0 51016 385 0 0
sp_qd_handle_on_reserve_upd_sts 9982 9982 0 0.00 0 17349 51 0 0
sp_reserve_write_off 9982 9982 0 0.00 6 31892 185 0 0
sp_supplier_invoice 5522 5522 0 0.00 7 99455 3656 0 0
sp_supplier_order 5415 5415 0 0.00 6 29918 1364 0 0
srv_aggregate_perf_data 112 112 0 0.00 2967 116269 13232 0 0
srv_fill_mon_cache_memory 64 64 0 0.00 1399 137749 44846 0 0
srv_find_qd_qs_mism 1040838 1040838 0 0.00 0 16916 5 0 0
srv_make_invnt_saldo 501 501 0 0.00 48 107703 2866 0 0
srv_make_money_saldo 731 731 0 0.00 1 13180 457 0 0
srv_recalc_idx_stat 3 3 0 0.00 253121 469244 388710 0 0
t$perf-abend:sp_add_invoice_to_stock 127 127 0 0.00 0 0 0 0 0
t$perf-abend:sp_cancel_supplier_invoice 11 11 0 0.00 0 0 0 0 0
t$perf-norm:sp_add_invoice_to_stock 4990 4990 0 0.00 0 8955 141 0 0
t$perf-norm:sp_cancel_adding_invoice 432 432 0 0.00 0 2924 88 0 0
t$perf-norm:sp_cancel_client_order 1753 1753 0 0.00 0 1829 8 0 0
t$perf-norm:sp_cancel_customer_reserve 643 643 0 0.00 0 1483 10 0 0
t$perf-norm:sp_cancel_pay_from_customer 651 651 0 0.00 0 146 2 0 0
t$perf-norm:sp_cancel_pay_to_supplier 376 376 0 0.00 0 1213 9 0 0
t$perf-norm:sp_cancel_supplier_invoice 442 442 0 0.00 0 3950 21 0 0
t$perf-norm:sp_cancel_supplier_order 387 387 0 0.00 0 15759 1424 0 0
t$perf-norm:sp_cancel_write_off 1034 1034 0 0.00 0 2113 6 0 0
t$perf-norm:sp_client_order 20906 20906 0 0.00 0 10791 16 0 0
t$perf-norm:sp_customer_reserve 978 978 0 0.00 0 3518 12 0 0
t$perf-norm:sp_pay_from_customer 7155 7155 0 0.00 0 10733 10 0 0
t$perf-norm:sp_pay_to_supplier 5839 5839 0 0.00 0 10804 12 0 0
t$perf-norm:sp_reserve_write_off 9982 9982 0 0.00 0 6021 10 0 0
t$perf-norm:sp_supplier_invoice 5522 5522 0 0.00 0 4933 14 0 0
t$perf-norm:sp_supplier_order 5415 5415 0 0.00 0 2643 12 0 0
t$perf-norm:srv_aggregate_perf_data 112 112 0 0.00 0 367 10 0 0
t$perf-norm:srv_fill_mon_cache_memory 64 64 0 0.00 0 52 1 0 0
t$perf-norm:srv_make_invnt_saldo 501 501 0 0.00 0 244 5 0 0
t$perf-norm:srv_make_money_saldo 731 731 0 0.00 0 431 5 0 0
t$perf-norm:srv_recalc_idx_stat 3 3 0 0.00 1 2 1 0 0
v_add_invoice_to_stock 10232 9978 254 2.48 0 4411 16 0 254
v_all_customers 37786 37786 0 0.00 0 137 1 0 0
v_all_suppliers 30416 30416 0 0.00 0 18 1 0 0
v_all_wares 41812 41812 0 0.00 0 17 1 0 0
v_cancel_adding_invoice 864 864 0 0.00 0 552 6 0 0
v_cancel_client_order 3506 3506 0 0.00 0 2813 7 0 0
v_cancel_customer_prepayment 1302 1302 0 0.00 0 5996 14 0 0
v_cancel_customer_reserve 1286 1286 0 0.00 0 2647 6 0 0
v_cancel_payment_to_supplier 752 752 0 0.00 0 340 4 0 0
v_cancel_supplier_invoice 906 884 22 2.42 0 2782 15 0 22
v_cancel_supplier_order 774 774 0 0.00 0 430 5 0 0
v_cancel_write_off 2068 2068 0 0.00 0 8550 17 0 0
v_max_id_clo_ord 5415 5415 0 0.00 0 612 1 0 0
v_max_id_clo_res 978 978 0 0.00 0 2191 11 0 0
v_max_id_ord_sup 5515 5515 0 0.00 0 7931 9 0 0
v_max_non_paid_invoice 1561 1561 0 0.00 0 225 2 0 0
v_max_non_paid_realizn 3868 3868 0 0.00 0 1245 3 0 0
v_min_id_clo_ord 5415 5415 0 0.00 0 2920 4 0 0
v_min_id_clo_res 978 978 0 0.00 0 2208 8 0 0
v_min_id_ord_sup 5515 5515 0 0.00 0 5544 8 0 0
v_min_non_paid_invoice 5839 5839 0 0.00 0 27757 13 0 0
v_min_non_paid_realizn 7155 7155 0 0.00 0 27897 27 0 0
v_our_firm 10600 10600 0 0.00 0 18 1 0 0
v_reserve_write_off 19964 19964 0 0.00 0 4298 5 0 0
x_lock_depdocs_on_canc_invoice 11163 11163 0 0.00 0 15445 105 0 0
x_lock_depdocs_on_canc_sup_ord 387 387 0 0.00 0 5786 300 0 0
x_make_qstorno_1000_1200 5415 5415 0 0.00 2 29909 1292 0 0
x_make_qstorno_1200_2000 5522 5522 0 0.00 3 99447 3519 0 0
x_make_qstorno_2100_3300 461616 461616 0 0.00 0 71167 146 0 0

Completed "Performance in DETAILS". Done for 00:00:04, from 08-11-2020 07:27:53 to 08-11-2020 07:27:57.

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 38809 8192000000 9729469040 10028126208 808918512 8.987 100 86 172 0 837405440 7700896 20786032
04:59:38 28039 8192000000 9767062096 10074828800 840825024 9.308 100 89 178 0 876223600 14636624 20761952
05:01:15 6383 8192000000 9805394144 10124468224 867697744 9.577 100 86 172 0 919024288 31516944 19809600
05:02:30 9540 8192000000 9896856512 10229399552 918053328 10.077 100 89 179 1 999016048 61181520 19781200
05:03:41 8511 8192000000 9919641344 10267828224 959089632 10.480 100 70 140 1 1025605776 51766928 14749216
05:04:55 4793 8192000000 9967836464 10321702912 999510560 10.874 100 86 172 0 1075792400 58706720 17575120
05:06:01 4183 8192000000 9999772608 10360610816 1020695616 11.079 100 86 174 0 1113964400 76279840 16988944
05:07:07 2404 8192000000 10032219312 10398560256 1039639712 11.261 100 91 182 4 1138959632 80754448 18565472
05:08:10 1588 8192000000 10020322832 10397167616 1052738256 11.387 100 71 143 0 1134567392 67647712 14181424
05:09:12 15932 8192000000 9977043584 10386812928 1061192080 11.468 100 47 94 0 1085190112 13597408 10400624
05:10:32 5284 8192000000 9994257056 10379243520 1071063312 11.562 100 50 98 3 1097147712 15587232 10497168
05:11:39 3996 8192000000 9979421312 10374131712 1076414128 11.613 100 33 65 1 1100490112 15792592 8283392
05:12:45 70834 8192000000 10002009168 10394869760 1083768032 11.683 100 46 93 2 1108407392 14320000 10319360
05:14:56 3292 8192000000 10008489840 10398855168 1075724928 11.607 99 52 105 1 1104272848 17343712 11204208
05:16:03 7306 8192000000 9985786352 10391904256 1074762688 11.598 100 29 57 4 1094653136 13502064 6388384
05:17:14 64008 8192000000 9937468688 10338492416 986589344 10.748 93 20 40 0 1017540592 27156976 3794272
05:19:18 6562 8192000000 9932999376 10317594624 997365888 10.853 97 39 73 4 1023145680 17034416 8745376
05:20:26 14106 8192000000 9935882816 10336604160 997926752 10.858 97 27 52 2 1029513888 25354832 6232304
05:21:43 14837 8192000000 9958191808 10354098176 1036184384 11.228 100 32 64 1 1079193776 35570656 7438736
05:23:00 46228 8192000000 9961300448 10358419456 1046394320 11.326 100 27 54 1 1074493520 22258320 5840880
05:24:57 4805 8192000000 9981962576 10380976128 1060319968 11.460 100 43 84 3 1095328960 25056160 9952832
05:26:04 10282 8192000000 10005615136 10403667968 1082111120 11.668 100 39 76 1 1119061120 28052720 8897280
05:27:20 11573 8192000000 10021827264 10412335104 1104127408 11.877 100 47 91 1 1124600560 10587632 9885520
05:28:33 71384 8192000000 10059810464 10467545088 1116369472 11.993 100 34 68 2 1169958032 46230928 7357632
05:30:47 34938 8192000000 10119753696 10526298112 1129364528 12.115 100 38 75 1 1208084544 70832944 7887072
05:32:29 6278 8192000000 10158644720 10561298432 1141739072 12.232 100 45 90 4 1262893568 110978368 10176128
05:33:47 2547 8192000000 10217888176 10613829632 1158461840 12.389 100 76 152 3 1315621360 139209984 17949536
05:34:57 19513 8192000000 10207908160 10632544256 1151601792 12.325 99 44 87 2 1318281952 156367760 10312400
05:36:20 11177 8192000000 10226009616 10646020096 1172297648 12.518 100 52 104 2 1331838208 148435920 11104640
05:37:43 3197 8192000000 10252837344 10662309888 1182941424 12.618 100 69 138 0 1364444080 166084752 15417904
05:38:52 4051 8192000000 10307862096 10711072768 1185022416 12.637 100 83 165 2 1417587504 214083760 18481328
05:40:06 4324 8192000000 10344176208 10750566400 1192173696 12.704 100 64 128 2 1450170896 243038560 14958640
05:41:17 1761 8192000000 10377482432 10774573056 1167231440 12.471 100 93 186 0 1478973840 290544416 21197984
05:42:25 2893 8192000000 10416641504 10814775296 1152277120 12.331 99 70 140 0 1510198016 341023072 16897824
05:43:34 1397 8192000000 10423399248 10836205568 1148083792 12.292 100 89 178 0 1519595920 351049904 20462224
05:44:38 9066 8192000000 10417002352 10837123072 1159572976 12.399 100 43 86 1 1523566720 352844416 11149328
05:45:59 8296 8192000000 10402961504 10822086656 1148084208 12.292 99 43 85 2 1494489760 335419632 10985920
05:47:11 14649 8192000000 10429675600 10857394176 1143149360 12.245 99 32 64 3 1519374112 367307936 8916816
05:48:28 11175 8192000000 10460825472 10881433600 1112909616 11.960 97 42 81 1 1536646224 413110096 10626512
05:49:45 18369 8192000000 10326840064 10777387008 1127371488 12.097 100 29 57 1 1417125168 282378272 7375408
05:51:05 22467 8192000000 10239960224 10729926656 1116891632 11.998 100 17 34 3 1350871536 229837440 4142464
05:53:23 88183 8192000000 10036399152 10463264768 1082620656 11.672 97 9 18 0 1133433536 48586080 2226800
05:55:56 64434 8192000000 10078492576 10547208192 1104123008 11.877 99 22 45 1 1195085296 86690128 4272160
05:58:02 78119 8192000000 10083164528 10523017216 1115884896 11.988 99 52 101 2 1151958352 25174272 10899184
06:00:22 46215 8192000000 10097361952 10530304000 1103263312 11.869 98 25 50 1 1166977088 58658176 5055600
06:02:09 66095 8192000000 10070021584 10544648192 1098193792 11.820 97 27 54 4 1183180288 79328848 5657648
06:04:23 25058 8192000000 10049330992 10515529728 1123996704 12.065 100 7 14 1 1172705904 47319152 1390048
06:06:31 91122 8192000000 10105957552 10548228096 1123594752 12.061 99 24 48 0 1178596736 49951968 5050016
06:09:21 57342 8192000000 10116484496 10627133440 1131437136 12.135 99 9 18 0 1214318016 80923072 1957808
06:11:19 37841 8192000000 10068115264 10500268032 1135058336 12.169 99 31 63 2 1172749760 29399552 8291872
06:13:02 24172 8192000000 10109088176 10546040832 1135581952 12.174 99 19 39 1 1199249232 59739264 3928016
06:14:33 40450 8192000000 10110697888 10547159040 1127846192 12.101 98 27 54 0 1200821536 67647072 5328272
06:16:15 60631 8192000000 10117642880 10570506240 1149326960 12.303 100 18 36 2 1260961008 107845632 3788416
06:18:18 28951 8192000000 10104113376 10538246144 1128461584 12.107 98 36 72 0 1184024688 47840080 7723024
06:19:49 44023 8192000000 10148345664 10620227584 1149212592 12.302 99 36 72 2 1242462544 86006288 7243664
06:21:36 42229 8192000000 10082428384 10537672704 1134317232 12.162 98 23 46 1 1177011072 37529424 5164416
06:23:20 79757 8192000000 10057174496 10489692160 1108404480 11.917 97 30 61 0 1131418448 16732016 6281952
06:25:44 44953 8192000000 10054119952 10499121152 1129030176 12.112 99 10 20 0 1161621840 30415728 2175936
06:27:29 40497 8192000000 10066547424 10515787776 1098262464 11.821 97 10 20 0 1127835264 27682512 1890288
06:29:09 49896 8192000000 10067960832 10522329088 1101180304 11.849 97 11 22 1 1150973840 47803888 1989648
06:31:00 23545 8192000000 10085163856 10517286912 1114333408 11.973 98 30 60 1 1164547456 43688512 6525536
06:32:24 45277 8192000000 10111564272 10554347520 1107371008 11.908 98 25 50 1 1199090768 86170384 5549376
06:34:09 65005 8192000000 10074412240 10544017408 1079701376 11.645 97 29 58 1 1185315680 98858560 6755744
06:36:21 57048 8192000000 10077220224 10501378048 1057610448 11.434 95 16 32 1 1125986336 65144464 3231424
06:38:22 19836 8192000000 10079680192 10482900992 1102953056 11.866 100 35 70 1 1156226288 46132640 7140592
06:39:42 89636 8192000000 10060412416 10548953088 1090183360 11.744 98 15 30 1 1160321536 67163328 2974848
06:42:12 81097 8192000000 10034069584 10491559936 1088681296 11.730 98 12 24 0 1121275120 30019488 2574336
06:45:38 41452 8192000000 10066493120 10516058112 1106979632 11.904 99 16 32 1 1169501040 59197216 3324192
06:48:21 53120 8192000000 10086347152 10529394688 1120930752 12.036 100 19 37 3 1212115792 86873408 4311632
06:50:20 74480 8192000000 10142099008 10604240896 1093474496 11.776 97 25 50 1 1202104944 103198240 5432208
06:52:35 54978 8192000000 10113663312 10558525440 1125370832 12.078 100 23 46 1 1208595792 78237248 4987712
06:54:36 109513 8192000000 10085932336 10581807104 1132711072 12.147 100 15 29 2 1192126128 56628352 2786704
06:57:27 135816 8192000000 10105691920 10562826240 1137489152 12.192 99 13 26 0 1202460592 62378320 2593120
07:00:51 34078 8192000000 10059932688 10501808128 1121350624 12.040 98 6 12 0 1139238640 16966032 921984
07:02:25 54037 8192000000 10070485408 10524389376 1134064160 12.160 99 12 24 0 1178907408 42092544 2750704
07:04:20 37721 8192000000 10139854304 10573541376 1139795184 12.214 99 42 85 0 1213694048 64943440 8955424
07:05:58 50825 8192000000 10179635040 10613440512 1155178960 12.358 100 25 50 3 1260368288 99811520 5377808
07:07:55 87295 8192000000 10211385040 10650488832 1166973728 12.469 100 25 50 0 1311776176 138774832 6027616
07:10:35 19512 8192000000 10201537424 10634190848 1161371808 12.416 100 36 71 1 1276745856 107796096 7577952
07:12:00 55037 8192000000 10094207712 10548633600 1120509216 12.032 97 7 14 1 1185649520 63776096 1364208
07:14:02 137748 8192000000 10112097696 10619830272 1139052432 12.207 99 27 54 1 1227780096 82873632 5854032
07:17:33 46973 8192000000 10055130240 10521690112 1094907792 11.789 97 15 29 1 1134513968 36972448 2633728
07:19:20 95518 8192000000 10046971408 10515861504 1115953456 11.989 99 5 10 0 1160401248 43417664 1030128
07:22:18 43062 8192000000 10055821472 10483986432 1072521264 11.576 95 17 34 0 1103003856 27104448 3378144
07:24:01 54262 8192000000 10019461616 10446602240 1040194320 11.267 93 20 40 0 1110679024 65946192 4538512
07:25:56 34233 8192000000 10071846160 10504900608 1095924800 11.799 99 43 87 1 1149909552 45753184 8231568

Memory consumption, total, chart

Metadata cache size, chart

Statements activity, chart


Completed "Memory consumption, metadata cache, attachments activity". Done for 00:00:15, from 08-11-2020 07:27:59 to 08-11-2020 07:28:14.

Exceptions occured during test was in run

FB_MNEMONA CNT UNIT FB_GDSCODE
except 127 v_add_invoice_to_stock 335544517
except 11 v_cancel_supplier_invoice 335544517

Completed "Exceptions occured during test was in run". Done for 00:00:02, from 08-11-2020 07:28:15 to 08-11-2020 07:28:17.

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          237164
MON$OLDEST_ACTIVE               241060
MON$OLDEST_SNAPSHOT             241060
MON$NEXT_TRANSACTION            241060
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                       2106304
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             811
MON$NEXT_STATEMENT              53


ISQL Version: LI-V4.0.0.2248 Firebird 4.0 Release Candidate 1
Server version:
Firebird/Linux/AMD/Intel/x64 (access method), version "LI-V4.0.0.2248 Firebird 4.0 Release Candidate 1"
Firebird/Linux/AMD/Intel/x64 (remote server), version "LI-V4.0.0.2248 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.2248 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 ---
:70: 
:71: mscs-test-161.budzdorov.ru    Sun Nov  8 07:27:00 2020
:72:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:73: 
:74: 
:75: mscs-test-161.budzdorov.ru    Sun Nov  8 07:27:00 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'

08.11.20 07:28:18. 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-08 07:28:21 No severe PSQL-related problems occured
08.11.20 07:28:22. End of report.