Generated by /opt/oltp-emul/oltp_isql_run_worker.sh, ISQL session No. 1 of total launched 100. 26.10.2020 22: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 17244536 kB
MemAvailable 31496176 kB
Buffers 0 kB
Cached 14413240 kB
SwapCached 3044 kB
Command: fdisk -l
WARNING: fdisk GPT support is currently new, and therefore in an experimental phase. Use at your own discretion.
Disk /dev/sda: 599.9 GB, 599932581888 bytes, 1171743324 sectors
Units = sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 262144 bytes / 524288 bytes
Disk label type: gpt
Disk identifier: 919DACA4-2F35-4CBB-BAA7-2A8CD8F7168C
# Start End Size Type Name
1 2048 411647 200M EFI System EFI System Partition
2 411648 2508799 1G Microsoft basic
3 2508800 1171742719 557.5G Linux LVM
Disk /dev/mapper/centos_mscs--test--161-root: 53.7 GB, 53687091200 bytes, 104857600 sectors
Units = sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 262144 bytes / 524288 bytes
Disk /dev/mapper/centos_mscs--test--161-swap: 16.8 GB, 16844324864 bytes, 32899072 sectors
Units = sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 262144 bytes / 524288 bytes
Disk /dev/sdb: 536 MB, 536870912 bytes, 1048576 sectors
Units = sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disk label type: dos
Disk identifier: 0x00000046
Device Boot Start End Blocks Id System
/dev/sdb1 63 514079 257008+ c W95 FAT32 (LBA)
Disk /dev/mapper/centos_mscs--test--161-home: 528.1 GB, 528109010944 bytes, 1031462912 sectors
Units = sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 262144 bytes / 524288 bytes

Server and database settinfs

SERVER_MODE                     SuperServer 3.0.7
DB_NAME                         /home/bases/oltp30-etalone.fdb
FORCED_WRITES                   ON
SWEEP_INT                       0
PAGE_BUFFERS                    1000000
PAGE_SIZE                       8192


Test configuration settings

param=actions_todo_before_reconnect, val=300
param=create_with_compound_columns_order, val=most_selective_first
param=create_with_debug_objects, val=1
param=create_with_fw, val=sync
param=create_with_separate_qdistr_idx, val=0
param=create_with_split_heavy_tabs, val=1
param=create_with_sweep, val=0
param=dbnm, val=/home/bases/oltp30-etalone.fdb
param=detailed_info, val=0
param=etalon_dbnm, val=/home/bases/oltp30-etalone.fd0
param=expected_workers, val=100
param=fbc, val=/opt/fb30/bin
param=file_name_this_host_info, val=bz_cpu24_ram32
param=file_name_with_test_params, val=regular
param=gather_hardware_info, val=1
param=halt_test_on_errors, val=/CK/
param=host, val=localhost
param=init_buff, val=10000
param=init_docs, val=0
param=is_embed, val=0
param=make_html, val=1
param=max_cps, val=25
param=mon_query_interval, val=60
param=mon_query_role, val=tmp$oemul$worker
param=mon_unit_list, val=//
param=mon_unit_perf, val=2
param=mon_usr_prefix, val=tmp$oemul$user_
param=no_auto_undo, val=1
param=port, val=3333
param=pwd, val=masterkey
param=qmism_verify_bitset, val=1
param=recalc_idx_min_interval, val=30
param=remove_isql_logs, val=if_no_severe_errors
param=replace_instance, val=1
param=report_compress_cmd, val=/usr/bin/7za
param=results_storage_fbk, val=/home/bases/oltp30-results-storage.fbk
param=run_db_statistics, val=0
param=run_db_validation, val=0
param=separate_workers, val=1
param=sleep_ddl, val=./oltp_sleepUDF_nix.sql
param=sleep_max, val=0
param=test_intervals, val=60
param=test_time, val=120
param=tmpdir, val=/var/tmp/logs-oltp30
param=unit_selection_method, val=random
param=update_conflict_percent, val=0
param=used_in_replication, val=0
param=use_mtee, val=0
param=usr, val=SYSDBA
param=wait_after_create, val=0
param=wait_for_copy, val=1
param=wait_if_not_exists, val=0
param=warm_time, val=30
param=working_mode, val=small_03
Custom name of interactive SQL utility: parameter: 'clu', value: |isql|

Test finish info

FINISH_STATE                    NORMAL: TEST_TIME EXPIRED AT 2020-10-26 22:26:59
DTS_END                         2020-10-26 22:26:59.1450
FB_GDSCODE                      -1
FB_MNEMONA                      
STACK                           SP_CANCEL_SUPPLIER_ORDER(134:18) ==> SP_CANCEL_SUPPLIER_INVOICE(36:5) ==> SP_CHECK_TO_STOP_WORK(32:12) ==> SP_HALT_ON_ERROR(56:17)
IP                              ::1/45930
TRN_ID                          263466
ATT_ID                          668
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: 9791.81 15182 1175017
customer order: creation 200.23 301 24028
customer order: refuse 16.44 255 1973
order to supplier: creation 53.08 1069 6370
order to supplier: removal 3.61 70953 433
invoice (draft): creation 53.46 2755 6415
invoice (draft): removal 51.38 690 6165
invoice accept: apply 47.88 14257 5745
invoice accept: cancel 46.20 610 5544
customer reserve: creation 4374.11 144 524893
customer reserve: removal 4614.66 43 553759
realization accept: apply 95.89 139 11507
realization accept: cancel 86.02 86 10322
payment from customer: creation 68.43 89 8212
payment from customer: removal 6.71 46 805
payment to supplier: creation 56.21 82 6745
payment to supplier: removal 3.95 49 474
service: total inventory turnovers 4.95 1035 594
service: total monetary turnovers 7.68 39 921
service: aggregate perf. data 0.90 17516 108
service: refresh index statistics 0.03 193488 4

Performance in TOTAL, chart


Completed "Performance in TOTAL". Done for 00:00:02, from 26-10-2020 22:28:13 to 26-10-2020 22:28:15.

Performance for every MINUTE

TEST_PHASE_NAME MINUTES_PASSED PERF_SCORE
TEST_TIME 1 3870
TEST_TIME 2 4955
TEST_TIME 3 5595
TEST_TIME 4 5543
TEST_TIME 5 5174
TEST_TIME 6 5929
TEST_TIME 7 5711
TEST_TIME 8 7252
TEST_TIME 9 7224
TEST_TIME 10 7381
TEST_TIME 11 7737
TEST_TIME 12 8087
TEST_TIME 13 8487
TEST_TIME 14 8654
TEST_TIME 15 8946
TEST_TIME 16 9680
TEST_TIME 17 9897
TEST_TIME 18 10046
TEST_TIME 19 10314
TEST_TIME 20 11491
TEST_TIME 21 11994
TEST_TIME 22 12075
TEST_TIME 23 11796
TEST_TIME 24 11629
TEST_TIME 25 11457
TEST_TIME 26 11325
TEST_TIME 27 11228
TEST_TIME 28 11199
TEST_TIME 29 11065
TEST_TIME 30 11045
TEST_TIME 31 11270
TEST_TIME 32 11222
TEST_TIME 33 11178
TEST_TIME 34 11329
TEST_TIME 35 11253
TEST_TIME 36 11145
TEST_TIME 37 10867
TEST_TIME 38 10873
TEST_TIME 39 10796
TEST_TIME 40 10679
TEST_TIME 41 10734
TEST_TIME 42 10724
TEST_TIME 43 10644
TEST_TIME 44 10672
TEST_TIME 45 10592
TEST_TIME 46 10486
TEST_TIME 47 10350
TEST_TIME 48 10341
TEST_TIME 49 10288
TEST_TIME 50 10223
TEST_TIME 51 10101
TEST_TIME 52 10079
TEST_TIME 53 10115
TEST_TIME 54 10069
TEST_TIME 55 10145
TEST_TIME 56 10120
TEST_TIME 57 10094
TEST_TIME 58 10177
TEST_TIME 59 10352
TEST_TIME 60 10276
TEST_TIME 61 10249
TEST_TIME 62 10283
TEST_TIME 63 10340
TEST_TIME 64 10351
TEST_TIME 65 10400
TEST_TIME 66 10335
TEST_TIME 67 10247
TEST_TIME 68 10177
TEST_TIME 69 10136
TEST_TIME 70 10045
TEST_TIME 71 10015
TEST_TIME 72 9930
TEST_TIME 73 9937
TEST_TIME 74 9953
TEST_TIME 75 9895
TEST_TIME 76 9934
TEST_TIME 77 9935
TEST_TIME 78 9939
TEST_TIME 79 10102
TEST_TIME 80 10053
TEST_TIME 81 10111
TEST_TIME 82 10140
TEST_TIME 83 10108
TEST_TIME 84 10072
TEST_TIME 85 10060
TEST_TIME 86 10041
TEST_TIME 87 9980
TEST_TIME 88 9924
TEST_TIME 89 9842
TEST_TIME 90 9805
TEST_TIME 91 9866
TEST_TIME 92 9887
TEST_TIME 93 9933
TEST_TIME 94 9936
TEST_TIME 95 9945
TEST_TIME 96 9922
TEST_TIME 97 9952
TEST_TIME 98 10002
TEST_TIME 99 9996
TEST_TIME 100 10034
TEST_TIME 101 9996
TEST_TIME 102 9989
TEST_TIME 103 10005
TEST_TIME 104 10057
TEST_TIME 105 10027
TEST_TIME 106 10004
TEST_TIME 107 9947
TEST_TIME 108 9937
TEST_TIME 109 9957
TEST_TIME 110 9910
TEST_TIME 111 9868
TEST_TIME 112 9826
TEST_TIME 113 9833
TEST_TIME 114 9775
TEST_TIME 115 9754
TEST_TIME 116 9756
TEST_TIME 117 9778
TEST_TIME 118 9751
TEST_TIME 119 9735
TEST_TIME 120 9795

Performance per minute, chart


Completed "Performance for every MINUTE". Done for 00:00:04, from 26-10-2020 22:28:16 to 26-10-2020 22:28:20.

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 1661941 1661941 0 0.00 0 11410 5 0 0
doc_list_biud 1661939 1661939 0 0.00 0 39814 19 0 0
sp_add_invoice_to_stock 5874 5745 129 2.19 37 198395 14258 0 129
sp_cancel_adding_invoice 5544 5544 0 0.00 5 51555 611 0 0
sp_cancel_client_order 1973 1973 0 0.00 4 14249 255 0 0
sp_cancel_customer_reserve 553759 553759 0 0.00 1 24917 44 0 0
sp_cancel_pay_from_customer 805 805 0 0.00 3 2891 46 0 0
sp_cancel_pay_to_supplier 474 474 0 0.00 3 3283 49 0 0
sp_cancel_supplier_invoice 6178 6165 13 0.21 2 26133 691 0 13
sp_cancel_supplier_order 433 433 0 0.00 6 954734 70954 0 0
sp_cancel_write_off 10322 10322 0 0.00 1 9310 86 0 0
sp_client_order 24028 24028 0 0.00 4 22840 301 0 0
sp_customer_reserve 524893 524893 0 0.00 0 112106 144 0 0
sp_fill_shopping_cart 36800 36800 0 0.00 1 16155 35 0 0
sp_fill_shopping_cart_clo_res 524886 524886 0 0.00 0 16984 11 0 0
sp_get_clo_for_invoice 5736 5736 0 0.00 0 17547 236 0 0
sp_kill_cost_storno 17145 17145 0 0.00 0 6086 36 0 0
sp_kill_qstorno_ret_qs2qd 1124438 1124438 0 0.00 0 26109 24 0 0
sp_kill_qty_storno 595439 595439 0 0.00 0 39812 52 0 0
sp_lock_selected_doc 23832 23832 0 0.00 0 9338 6 0 0
sp_make_cost_storno 32200 32200 0 0.00 0 11396 40 0 0
sp_multiply_rows_for_pdistr 32200 32200 0 0.00 0 5909 19 0 0
sp_multiply_rows_for_qdistr 24027 24027 0 0.00 0 16634 135 0 0
sp_pay_from_customer 8212 8212 0 0.00 4 17474 90 0 0
sp_pay_to_supplier 6745 6745 0 0.00 4 6941 83 0 0
sp_payment_common 14957 14957 0 0.00 1 17467 22 0 0
sp_qd_handle_on_cancel_clo 1973 1973 0 0.00 0 14241 236 0 0
sp_qd_handle_on_invoice_upd_sts 11280 11280 0 0.00 0 39810 234 0 0
sp_qd_handle_on_reserve_upd_sts 11507 11507 0 0.00 0 8474 44 0 0
sp_reserve_write_off 11507 11507 0 0.00 6 15963 139 0 0
sp_supplier_invoice 6415 6415 0 0.00 5 88396 2755 0 0
sp_supplier_order 6370 6370 0 0.00 5 29867 1069 0 0
srv_aggregate_perf_data 108 108 0 0.00 2676 403836 17517 0 0
srv_fill_mon_cache_memory 61 61 0 0.00 1284 131263 48783 0 0
srv_find_qd_qs_mism 1120580 1120580 0 0.00 0 8105 5 0 0
srv_make_invnt_saldo 594 594 0 0.00 32 42731 1036 0 0
srv_make_money_saldo 921 921 0 0.00 1 14793 39 0 0
srv_recalc_idx_stat 4 4 0 0.00 131446 303507 193489 0 0
t$perf-abend:sp_add_invoice_to_stock 129 129 0 0.00 0 0 0 0 0
t$perf-abend:sp_cancel_supplier_invoice 13 13 0 0.00 0 0 0 0 0
t$perf-norm:sp_add_invoice_to_stock 5746 5746 0 0.00 0 37177 129 0 0
t$perf-norm:sp_cancel_adding_invoice 474 474 0 0.00 0 3584 69 0 0
t$perf-norm:sp_cancel_client_order 1973 1973 0 0.00 0 8767 19 0 0
t$perf-norm:sp_cancel_customer_reserve 784 784 0 0.00 0 7910 18 0 0
t$perf-norm:sp_cancel_pay_from_customer 805 805 0 0.00 0 3401 10 0 0
t$perf-norm:sp_cancel_pay_to_supplier 474 474 0 0.00 0 3566 16 0 0
t$perf-norm:sp_cancel_supplier_invoice 454 454 0 0.00 0 5174 26 0 0
t$perf-norm:sp_cancel_supplier_order 433 433 0 0.00 0 14042 1124 0 0
t$perf-norm:sp_cancel_write_off 1193 1193 0 0.00 0 3243 10 0 0
t$perf-norm:sp_client_order 24028 24028 0 0.00 0 21663 15 0 0
t$perf-norm:sp_customer_reserve 1174 1174 0 0.00 0 5521 10 0 0
t$perf-norm:sp_pay_from_customer 8212 8212 0 0.00 0 7464 10 0 0
t$perf-norm:sp_pay_to_supplier 6745 6745 0 0.00 0 4971 12 0 0
t$perf-norm:sp_reserve_write_off 11507 11507 0 0.00 0 18970 12 0 0
t$perf-norm:sp_supplier_invoice 6415 6415 0 0.00 0 5959 18 0 0
t$perf-norm:sp_supplier_order 6370 6370 0 0.00 0 6833 15 0 0
t$perf-norm:srv_aggregate_perf_data 108 108 0 0.00 0 165 3 0 0
t$perf-norm:srv_fill_mon_cache_memory 61 61 0 0.00 0 2473 41 0 0
t$perf-norm:srv_make_invnt_saldo 594 594 0 0.00 0 629 12 0 0
t$perf-norm:srv_make_money_saldo 921 921 0 0.00 0 763 6 0 0
t$perf-norm:srv_recalc_idx_stat 4 4 0 0.00 3 76 22 0 0
v_add_invoice_to_stock 11728 11470 258 2.19 0 4494 14 0 258
v_all_customers 43770 43770 0 0.00 0 47 0 0 0
v_all_suppliers 35042 35042 0 0.00 0 94 1 0 0
v_all_wares 48054 48054 0 0.00 0 15 1 0 0
v_cancel_adding_invoice 948 948 0 0.00 0 368 5 0 0
v_cancel_client_order 3946 3946 0 0.00 0 2443 4 0 0
v_cancel_customer_prepayment 1610 1610 0 0.00 0 215 2 0 0
v_cancel_customer_reserve 1568 1568 0 0.00 0 194 2 0 0
v_cancel_payment_to_supplier 948 948 0 0.00 0 699 3 0 0
v_cancel_supplier_invoice 934 908 26 2.78 0 791 12 0 26
v_cancel_supplier_order 866 866 0 0.00 0 783 2 0 0
v_cancel_write_off 2386 2386 0 0.00 0 2432 14 0 0
v_max_id_clo_ord 6368 6368 0 0.00 0 585 1 0 0
v_max_id_clo_res 1174 1174 0 0.00 0 2155 13 0 0
v_max_id_ord_sup 6405 6405 0 0.00 0 5067 4 0 0
v_max_non_paid_invoice 1997 1997 0 0.00 0 2971 4 0 0
v_max_non_paid_realizn 4444 4444 0 0.00 0 2971 3 0 0
v_min_id_clo_ord 6368 6368 0 0.00 0 15395 11 0 0
v_min_id_clo_res 1174 1174 0 0.00 0 463 3 0 0
v_min_id_ord_sup 6405 6405 0 0.00 0 5474 9 0 0
v_min_non_paid_invoice 6745 6745 0 0.00 0 3263 10 0 0
v_min_non_paid_realizn 8212 8212 0 0.00 0 6584 14 0 0
v_our_firm 11820 11820 0 0.00 0 20 1 0 0
v_reserve_write_off 23014 23014 0 0.00 0 4642 5 0 0
x_lock_depdocs_on_canc_invoice 11255 11255 0 0.00 0 9300 92 0 0
x_lock_depdocs_on_canc_sup_ord 433 433 0 0.00 0 8924 285 0 0
x_make_qstorno_1000_1200 6370 6370 0 0.00 1 29852 1000 0 0
x_make_qstorno_1200_2000 6415 6415 0 0.00 2 88379 2634 0 0
x_make_qstorno_2100_3300 524893 524893 0 0.00 0 112104 131 0 0

Completed "Performance in DETAILS". Done for 00:00:04, from 26-10-2020 22:28:21 to 26-10-2020 22:28:25.

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
19:57:02 2 8192000000 8798422528 8808923136 5084624 0.062 1 1 2 0 5202672 55488 62560
19:58:03 30920 8192000000 10376264176 10701123584 1430721056 14.868 100 87 174 0 1465465184 6422048 28322080
19:59:42 21870 8192000000 10450429680 10782588928 1502767616 15.500 100 94 188 0 1541860480 9083776 30009088
20:01:07 21408 8192000000 10504395216 10848223232 1542315328 15.844 100 84 167 1 1579644496 10804608 26524560
20:02:34 13228 8192000000 10593196512 10952888320 1647652272 16.745 100 88 177 2 1686517536 12563632 26301632
20:03:50 5534 8192000000 10679775120 11055878144 1741046256 17.527 100 86 171 1 1778516480 12948656 24521568
20:04:58 3240 8192000000 10720466768 11106922496 1786585760 17.904 100 78 157 0 1821422784 12810720 22026304
20:06:03 2792 8192000000 10773779152 11161190400 1830293120 18.262 100 87 174 2 1869409616 14353472 24763024
20:07:06 1368 8192000000 10810018448 11197669376 1867867344 18.567 100 95 192 1 1908589840 13802848 26919648
20:08:09 17590 8192000000 10785682448 11198259200 1859925584 18.503 100 39 79 0 1878048880 6922224 11201072
20:09:27 7414 8192000000 10776533520 11211333632 1872592960 18.605 100 19 38 3 1883887264 6054704 5239600
20:10:36 15102 8192000000 10794860144 11228545024 1888470288 18.733 100 16 31 2 1898622848 5849184 4303376
20:11:55 60126 8192000000 10810737568 11246596096 1895507712 18.790 100 36 72 1 1911984512 5101904 11374896
20:13:55 5205 8192000000 10821741600 11251699712 1902328176 18.845 100 26 53 1 1914841136 5188848 7324112
20:15:01 7505 8192000000 10806127312 11239751680 1886544112 18.718 100 22 44 2 1903790064 10730800 6515152
20:16:11 67105 8192000000 10762185328 11171807232 1712950848 17.293 91 38 76 0 1729805344 5077168 11777328
20:18:18 5152 8192000000 10720837408 11139002368 1776733952 17.823 98 32 64 2 1792787440 7540416 8513072
20:19:28 8694 8192000000 10699438688 11121950720 1777762080 17.831 99 23 45 1 1790094416 5822112 6510224
20:20:38 18599 8192000000 10636681360 11049394176 1639931120 16.679 91 47 93 1 1659581376 5354512 14295744
20:21:58 6395 8192000000 10729460096 11150987264 1815489760 18.141 100 27 53 2 1829168288 5716768 7961760
20:23:05 9968 8192000000 10758910368 11181043712 1831443632 18.271 99 24 48 0 1843345856 4920240 6981984
20:24:15 12305 8192000000 10796600736 11212423168 1868676752 18.574 100 32 64 1 1885141024 6899568 9564704
20:25:29 11353 8192000000 10780388512 11210182656 1865488912 18.548 100 10 20 2 1873106528 4589920 3027696
20:26:45 4925 8192000000 10798298768 11226877952 1880038496 18.665 100 34 70 2 1895922480 6397344 9486640
20:27:53 1993 8192000000 10863075008 11277795328 1923892176 19.018 100 56 111 0 1948448416 9053312 15502928
20:28:59 38239 8192000000 10884858624 11314745344 1949353040 19.221 100 56 112 0 1977543136 11923536 16266560
20:31:01 36781 8192000000 10898057216 11343269888 1969737568 19.383 100 32 64 2 1997992304 18203856 10050880
20:32:49 16723 8192000000 10920105680 11354468352 1981533408 19.477 100 47 92 1 2011620448 15146784 14940256
20:34:18 3862 8192000000 10956164208 11373178880 1987119664 19.521 100 64 126 0 2031818848 25098624 19600560
20:35:26 5529 8192000000 10940827216 11362037760 1969852608 19.384 99 67 134 0 2015820192 26124992 19842592
20:36:36 2172 8192000000 10981834048 11400355840 2006677472 19.675 100 79 156 1 2061382880 31405424 23299984
20:37:41 2706 8192000000 10926331840 11343691776 1960176896 19.307 100 75 148 1 2016226224 33847568 22201760
20:38:48 1283 8192000000 10929440016 11336613888 1945372496 19.190 99 71 141 1 2004091760 37021520 21697744
20:39:52 9866 8192000000 10892647264 11328057344 1907989712 18.891 98 36 72 6 1954321344 34323520 12008112
20:41:15 10839 8192000000 10888580752 11318603776 1896773472 18.800 98 35 70 0 1947349088 38775264 11800352
20:42:29 11681 8192000000 10902111152 11342381056 1940644000 19.152 100 32 64 1 1986116384 35321088 10151296
20:43:47 15149 8192000000 10913479168 11363512320 1944518592 19.183 100 24 46 1 1996235888 43126096 8591200
20:45:21 13394 8192000000 10907988752 11345547264 1931835248 19.082 100 31 62 1 1985039120 41847872 11356000
20:46:39 21842 8192000000 10872806208 11337355264 1928386560 19.054 100 21 42 1 1973291616 36682720 8222336
20:48:08 64887 8192000000 10821463616 11281534976 1868432144 18.572 98 14 29 1 1884198192 11682576 4083472
20:50:14 52206 8192000000 10841411888 11276423168 1888701520 18.735 99 24 47 3 1902178288 7082976 6393792
20:52:14 48823 8192000000 10844689888 11298009088 1919766784 18.985 100 24 46 1 1935827616 10027728 6033104
20:54:22 71524 8192000000 10882601024 11334291456 1930102656 19.068 99 9 18 0 1944010192 10741088 3166448
20:56:40 77724 8192000000 10903997648 11369385984 1943226672 19.172 99 10 20 0 1965916592 19612432 3077488
20:59:00 41357 8192000000 10938043872 11394260992 1993870304 19.574 100 11 22 0 2006995680 10231136 2894240
21:00:48 122184 8192000000 10925153184 11398373376 1957126512 19.283 98 12 24 1 1974128352 13697488 3304352
21:03:50 35836 8192000000 10948435616 11391533056 1980950512 19.472 99 56 112 2 2010460400 12160768 17349120
21:05:27 118605 8192000000 10925814928 11398688768 1981376704 19.476 99 51 102 2 2005803488 9928480 14498304
21:08:26 42366 8192000000 10908850896 11378495488 1937739968 19.129 97 17 34 1 1953286592 10049872 5496752
21:10:13 28030 8192000000 10870161520 11348750336 1923812944 19.017 98 8 16 1 1938535536 12402000 2320592
21:11:41 33115 8192000000 10879783568 11349139456 1933082368 19.092 98 20 40 0 1947455104 8072096 6300640
21:13:19 35916 8192000000 10885421248 11352903680 1930069600 19.067 98 28 56 5 1950953856 11818448 9065808
21:15:32 42254 8192000000 10892583072 11360493568 1954467184 19.262 99 18 36 1 1965809312 6439760 4902368
21:17:19 43655 8192000000 10866763568 11342508032 1933884304 19.098 99 10 20 0 1944102432 7355744 2862384
21:19:03 62099 8192000000 10869476240 11342397440 1914562496 18.943 98 10 20 0 1926773952 9148416 3063040
21:21:06 44301 8192000000 10823812960 11288731648 1801069056 18.023 93 21 41 2 1815755856 8966528 5720272
21:22:50 38441 8192000000 10839741024 11294924800 1825391792 18.222 95 34 66 2 1847326944 12126672 9808480
21:24:30 71850 8192000000 10841731248 11315412992 1878719376 18.655 98 17 34 2 1903255632 19258144 5278112
21:26:42 24424 8192000000 10870437776 11310010368 1887712592 18.727 98 43 86 0 1909015728 9707360 11595776
21:28:07 60357 8192000000 10845238400 11303378944 1848462944 18.410 95 21 42 1 1870214848 15917520 5834384
21:30:45 78842 8192000000 10876248064 11336986624 1882983664 18.689 98 36 72 3 1915045392 21921408 10140320
21:33:08 86616 8192000000 10867443248 11325190144 1923083280 19.012 99 28 56 3 1940823856 9786208 7954368
21:35:45 45695 8192000000 10859484480 11331784704 1927864272 19.050 99 5 10 0 1935525936 6522656 1139008
21:37:31 63005 8192000000 10842999760 11323498496 1896237632 18.796 98 9 18 2 1904930112 6809408 1883072
21:39:35 66394 8192000000 10871384592 11347226624 1931863616 19.082 99 8 16 1 1942605424 8337408 2404400
21:41:45 16627 8192000000 10890476736 11351891968 1960951744 19.314 100 31 62 1 1979934592 10289216 8693632
21:43:13 35968 8192000000 10885916912 11352657920 1948665536 19.216 100 12 24 2 1964583664 12374880 3543248
21:44:49 131263 8192000000 10901939872 11386085376 1905771312 18.873 97 12 24 0 1927473552 18300912 3401328
21:48:10 73628 8192000000 10894764752 11366957056 1930362656 19.070 98 19 38 0 1944663328 9246368 5054304
21:50:24 8754 8192000000 10924114096 11373543424 1976918656 19.440 100 64 128 0 2004944544 10765744 17260144
21:51:34 115092 8192000000 10910437104 11385360384 1974699360 19.423 100 25 49 0 1994200912 12766944 6734608
21:54:57 76788 8192000000 10911253600 11386998784 1960853040 19.313 99 16 32 1 1977552496 12091600 4607856
21:57:14 102883 8192000000 10891197296 11380277248 1935873520 19.114 98 17 34 2 1955091280 14585104 4632656
21:59:58 62527 8192000000 10887391712 11365699584 1931835120 19.082 98 14 28 0 1942913040 7275056 3802864
22:02:22 60119 8192000000 10890249264 11372244992 1936463840 19.119 98 14 28 0 1952832192 12541408 3826944
22:04:23 53867 8192000000 10862602080 11330994176 1911680944 18.920 99 32 65 0 1934926160 13473984 9771232
22:06:20 68429 8192000000 10852733536 11306528768 1857122320 18.480 96 26 52 1 1877920912 12948224 7850368
22:08:36 76139 8192000000 10840985232 11299553280 1813903568 18.128 94 20 40 0 1833142976 13690944 5548464
22:10:55 90718 8192000000 10825310416 11305312256 1825124320 18.220 95 8 16 0 1839968544 12794608 2049616
22:14:41 48706 8192000000 10868595984 11329368064 1920863760 18.994 99 21 42 1 1937770064 10951488 5954816
22:16:31 48918 8192000000 10854216848 11331940352 1923914944 19.018 99 15 26 2 1934890400 7304976 3670480
22:18:39 64395 8192000000 10874246000 11349360640 1930945552 19.074 99 10 20 2 1945324720 11168112 3211056
22:21:17 69162 8192000000 10864265264 11342524416 1900351136 18.829 97 17 31 2 1913728896 8541184 4836576
22:23:31 50357 8192000000 10891801776 11365801984 1966682768 19.359 100 21 43 0 1980139200 8077440 5378992
22:25:22 28808 8192000000 10890375648 11357229056 1942344816 19.165 99 21 42 0 1959384864 10874032 6166016

Memory consumption, total, chart

Metadata cache size, chart

Statements activity, chart


Completed "Memory consumption, metadata cache, attachments activity". Done for 00:00:14, from 26-10-2020 22:28:27 to 26-10-2020 22:28:41.

Exceptions occured during test was in run

FB_MNEMONA CNT UNIT FB_GDSCODE
user_exc 129 v_add_invoice_to_stock 335544517
user_exc 13 v_cancel_supplier_invoice 335544517

Completed "Exceptions occured during test was in run". Done for 00:00:02, from 26-10-2020 22:28:42 to 26-10-2020 22:28:44.

Content of mon$database and FB version

MON$DATABASE_NAME               /home/bases/oltp30-etalone.fdb
MON$PAGE_SIZE                   8192
MON$ODS_MAJOR                   12
MON$ODS_MINOR                   0
MON$OLDEST_TRANSACTION          262707
MON$OLDEST_ACTIVE               264177
MON$OLDEST_SNAPSHOT             264177
MON$NEXT_TRANSACTION            264177
MON$PAGE_BUFFERS                1000000
MON$SQL_DIALECT                 3
MON$SHUTDOWN_MODE               0
MON$SWEEP_INTERVAL              0
MON$READ_ONLY                   0
MON$FORCED_WRITES               1
MON$RESERVE_SPACE               1
MON$CREATION_DATE               2020-04-03 16:41:55.3470
MON$PAGES                       2050336
MON$STAT_ID                     1
MON$BACKUP_STATE                0
MON$CRYPT_PAGE                  0
MON$OWNER                       SYSDBA                                                                                       
MON$SEC_DATABASE                Default


ISQL Version: LI-V3.0.7.33380 Firebird 3.0
Server version:
Firebird/Linux/AMD/Intel/x64 (access method), version "LI-V3.0.7.33380 Firebird 3.0"
Firebird/Linux/AMD/Intel/x64 (remote server), version "LI-V3.0.7.33380 Firebird 3.0/tcp (mscs-test-161.budzdorov.ru)/P15:C"
Firebird/Linux/AMD/Intel/x64 (remote interface), version "LI-V3.0.7.33380 Firebird 3.0/tcp (mscs-test-161.budzdorov.ru)/P15:C"
on disk structure version 12.0

Database statistics

Database statistics was not gathered, see config parameter 'run_db_statistics'.
===============================================================================

Database validation

Database validation was not performed, see config parameter 'run_db_validation'
===============================================================================

Comparison of old and new firebird.log: get messages that appeared during test

--- start of diff output ---
:136: 
:137: mscs-test-161.budzdorov.ru    Mon Oct 26 22:26:59 2020
:138:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3333
:139: 
:140: 
:141: mscs-test-161.budzdorov.ru    Mon Oct 26 22:27:10 2020
:142:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3333
:143: 
:144: 
:145: mscs-test-161.budzdorov.ru    Mon Oct 26 22:27:15 2020
:146:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3333
:147: 
--- end of diff output ---

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

26.10.20 22:28:45. There are 3 logs in /var/tmp/logs-oltp30 that can be removed if no severe errors occured, see config setting 'remove_isql_logs' Following values of gdscode are considered as SEVERE: 0 Unidentified error in PSQL code: gdscode=0 within WHEN block when exception raised. 335544321 'string truncation'. Attempt to assign too long text into string variable. 335544347 'not_valid'. Validation error for column. 335544349 'no_dup'. Attempt to store duplicate value visible to active transactions. 335544558 'check_constraint'. Operation violates CHECK constraint on view or table. 335544665 'unique_key_violation'. Violation of PRIMARY or UNIQUE KEY constraint. 335544838 'foreign_key_target_doesnt_exist'. Foreign key reference target does not exist. 335544839 'foreign_key_references_present'. Foreign key references are present for the record.
FINISHED_AT ERRORS_RESULT
2020-10-26 22:28:48 No severe PSQL-related problems occured
26.10.20 22:28:49. End of report.