Generated by /opt/oltp-emul/oltp_isql_run_worker.sh, ISQL session No. 1 of total launched 100. 03.12.2020 10: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 16743176 kB
MemAvailable 31488036 kB
Buffers 0 kB
Cached 14813460 kB
SwapCached 1928 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-12-03 10:26:50
DTS_END                         2020-12-03 10:26:50.8340
FB_GDSCODE                      -1
FB_MNEMONA                      
STACK                           SP_PAY_FROM_CUSTOMER(24:5) ==> SP_CHECK_TO_STOP_WORK(32:12) ==> SP_HALT_ON_ERROR(68:17)
IP                              ::1/45232
TRN_ID                          233973
ATT_ID                          691
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: 9199.39 18098 1103927
customer order: creation 171.01 390 20521
customer order: refuse 14.64 355 1757
order to supplier: creation 44.70 1281 5364
order to supplier: removal 3.35 122515 402
invoice (draft): creation 45.62 3494 5474
invoice (draft): removal 52.17 894 6260
invoice accept: apply 41.99 15680 5039
invoice accept: cancel 47.49 840 5699
customer reserve: creation 3819.60 153 458352
customer reserve: removal 4666.19 70 559943
realization accept: apply 83.58 174 10030
realization accept: cancel 82.43 119 9892
payment from customer: creation 59.20 111 7104
payment from customer: removal 5.83 112 700
payment to supplier: creation 47.14 126 5657
payment to supplier: removal 3.51 68 421
service: total inventory turnovers 3.85 2943 462
service: total monetary turnovers 6.18 497 742
service: aggregate perf. data 0.87 16319 104
service: refresh index statistics 0.03 195816 4

Performance in TOTAL, chart


Completed "Performance in TOTAL". Done for 00:00:02, from 03-12-2020 10:27:38 to 03-12-2020 10:27:40.

Performance for every MINUTE

TEST_PHASE_NAME MINUTES_PASSED PERF_SCORE
TEST_TIME 1 4514
TEST_TIME 2 5226
TEST_TIME 3 5930
TEST_TIME 4 6361
TEST_TIME 5 6177
TEST_TIME 6 6283
TEST_TIME 7 6506
TEST_TIME 8 6555
TEST_TIME 9 6731
TEST_TIME 10 6786
TEST_TIME 11 7127
TEST_TIME 12 7131
TEST_TIME 13 7254
TEST_TIME 14 7428
TEST_TIME 15 7501
TEST_TIME 16 7570
TEST_TIME 17 7566
TEST_TIME 18 7826
TEST_TIME 19 8155
TEST_TIME 20 8520
TEST_TIME 21 8918
TEST_TIME 22 9073
TEST_TIME 23 9223
TEST_TIME 24 10002
TEST_TIME 25 11732
TEST_TIME 26 11732
TEST_TIME 27 11304
TEST_TIME 28 11260
TEST_TIME 29 11227
TEST_TIME 30 11122
TEST_TIME 31 10904
TEST_TIME 32 10777
TEST_TIME 33 10695
TEST_TIME 34 10515
TEST_TIME 35 10474
TEST_TIME 36 10520
TEST_TIME 37 10543
TEST_TIME 38 10528
TEST_TIME 39 10443
TEST_TIME 40 10382
TEST_TIME 41 10375
TEST_TIME 42 10470
TEST_TIME 43 10357
TEST_TIME 44 10540
TEST_TIME 45 10411
TEST_TIME 46 10193
TEST_TIME 47 10076
TEST_TIME 48 10010
TEST_TIME 49 9950
TEST_TIME 50 9908
TEST_TIME 51 9825
TEST_TIME 52 9783
TEST_TIME 53 9761
TEST_TIME 54 9643
TEST_TIME 55 9534
TEST_TIME 56 9625
TEST_TIME 57 9628
TEST_TIME 58 9664
TEST_TIME 59 9717
TEST_TIME 60 9704
TEST_TIME 61 9673
TEST_TIME 62 9684
TEST_TIME 63 9767
TEST_TIME 64 9803
TEST_TIME 65 9798
TEST_TIME 66 9837
TEST_TIME 67 9896
TEST_TIME 68 9847
TEST_TIME 69 9907
TEST_TIME 70 9785
TEST_TIME 71 9760
TEST_TIME 72 9694
TEST_TIME 73 9615
TEST_TIME 74 9542
TEST_TIME 75 9498
TEST_TIME 76 9433
TEST_TIME 77 9421
TEST_TIME 78 9395
TEST_TIME 79 9380
TEST_TIME 80 9342
TEST_TIME 81 9319
TEST_TIME 82 9286
TEST_TIME 83 9361
TEST_TIME 84 9379
TEST_TIME 85 9358
TEST_TIME 86 9348
TEST_TIME 87 9507
TEST_TIME 88 9560
TEST_TIME 89 9509
TEST_TIME 90 9429
TEST_TIME 91 9461
TEST_TIME 92 9404
TEST_TIME 93 9364
TEST_TIME 94 9316
TEST_TIME 95 9367
TEST_TIME 96 9328
TEST_TIME 97 9305
TEST_TIME 98 9320
TEST_TIME 99 9308
TEST_TIME 100 9358
TEST_TIME 101 9365
TEST_TIME 102 9342
TEST_TIME 103 9401
TEST_TIME 104 9454
TEST_TIME 105 9466
TEST_TIME 106 9469
TEST_TIME 107 9384
TEST_TIME 108 9311
TEST_TIME 109 9291
TEST_TIME 110 9222
TEST_TIME 111 9195
TEST_TIME 112 9221
TEST_TIME 113 9231
TEST_TIME 114 9210
TEST_TIME 115 9177
TEST_TIME 116 9223
TEST_TIME 117 9219
TEST_TIME 118 9214
TEST_TIME 119 9257
TEST_TIME 120 9211

Performance per minute, chart


Completed "Performance for every MINUTE". Done for 00:00:03, from 03-12-2020 10:27:42 to 03-12-2020 10:27:45.

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 1528717 1528717 0 0.00 0 17528 6 0 0
doc_list_biud 1528714 1528714 0 0.00 0 25436 32 0 0
sp_add_invoice_to_stock 5212 5039 173 3.31 29 149842 15680 0 173
sp_cancel_adding_invoice 5699 5699 0 0.00 6 76381 840 0 0
sp_cancel_client_order 1757 1757 0 0.00 5 8940 355 0 0
sp_cancel_customer_reserve 559943 559943 0 0.00 1 25441 70 0 0
sp_cancel_pay_from_customer 700 700 0 0.00 3 8659 113 0 0
sp_cancel_pay_to_supplier 421 421 0 0.00 3 4320 68 0 0
sp_cancel_supplier_invoice 6271 6260 11 0.17 2 21388 894 0 11
sp_cancel_supplier_order 402 402 0 0.00 6 1244799 122515 0 0
sp_cancel_write_off 9892 9892 0 0.00 1 9735 120 0 0
sp_client_order 20521 20521 0 0.00 4 34334 391 0 0
sp_customer_reserve 458352 458352 0 0.00 0 62035 154 0 0
sp_fill_shopping_cart 31356 31356 0 0.00 1 40340 49 0 0
sp_fill_shopping_cart_clo_res 458335 458335 0 0.00 0 27449 18 0 0
sp_get_clo_for_invoice 5020 5020 0 0.00 0 33139 439 0 0
sp_kill_cost_storno 16712 16712 0 0.00 0 7208 55 0 0
sp_kill_qstorno_ret_qs2qd 1136440 1136440 0 0.00 0 21379 37 0 0
sp_kill_qty_storno 599003 599003 0 0.00 0 25435 81 0 0
sp_lock_selected_doc 20800 20800 0 0.00 0 18939 6 0 0
sp_make_cost_storno 27811 27811 0 0.00 0 14370 54 0 0
sp_multiply_rows_for_pdistr 27811 27811 0 0.00 0 8653 32 0 0
sp_multiply_rows_for_qdistr 20521 20521 0 0.00 0 19992 223 0 0
sp_pay_from_customer 7104 7104 0 0.00 4 13800 111 0 0
sp_pay_to_supplier 5657 5657 0 0.00 5 11194 127 0 0
sp_payment_common 12761 12761 0 0.00 1 9442 26 0 0
sp_qd_handle_on_cancel_clo 1757 1757 0 0.00 0 8934 334 0 0
sp_qd_handle_on_invoice_upd_sts 10719 10719 0 0.00 0 22626 384 0 0
sp_qd_handle_on_reserve_upd_sts 10030 10030 0 0.00 0 11271 49 0 0
sp_reserve_write_off 10030 10030 0 0.00 7 18997 175 0 0
sp_supplier_invoice 5474 5474 0 0.00 8 108545 3495 0 0
sp_supplier_order 5364 5364 0 0.00 6 49873 1281 0 0
srv_aggregate_perf_data 104 104 0 0.00 2650 185160 16320 0 0
srv_fill_mon_cache_memory 61 61 0 0.00 1377 151296 50286 0 0
srv_find_qd_qs_mism 1056925 1056925 0 0.00 0 17527 5 0 0
srv_make_invnt_saldo 462 462 0 0.00 51 91586 2943 0 0
srv_make_money_saldo 742 742 0 0.00 1 16574 498 0 0
srv_recalc_idx_stat 4 4 0 0.00 169007 227931 195817 0 0
t$perf-abend:sp_add_invoice_to_stock 173 173 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 5039 5039 0 0.00 0 7939 149 0 0
t$perf-norm:sp_cancel_adding_invoice 424 424 0 0.00 0 2908 75 0 0
t$perf-norm:sp_cancel_client_order 1757 1757 0 0.00 0 6205 12 0 0
t$perf-norm:sp_cancel_customer_reserve 686 686 0 0.00 0 661 10 0 0
t$perf-norm:sp_cancel_pay_from_customer 700 700 0 0.00 0 1965 6 0 0
t$perf-norm:sp_cancel_pay_to_supplier 421 421 0 0.00 0 1647 7 0 0
t$perf-norm:sp_cancel_supplier_invoice 399 399 0 0.00 0 1330 16 0 0
t$perf-norm:sp_cancel_supplier_order 402 402 0 0.00 0 24472 1386 0 0
t$perf-norm:sp_cancel_write_off 963 963 0 0.00 0 3363 18 0 0
t$perf-norm:sp_client_order 20521 20521 0 0.00 0 19272 20 0 0
t$perf-norm:sp_customer_reserve 919 919 0 0.00 0 2878 9 0 0
t$perf-norm:sp_pay_from_customer 7104 7104 0 0.00 0 18915 11 0 0
t$perf-norm:sp_pay_to_supplier 5657 5657 0 0.00 0 3499 8 0 0
t$perf-norm:sp_reserve_write_off 10030 10030 0 0.00 0 6848 9 0 0
t$perf-norm:sp_supplier_invoice 5474 5474 0 0.00 0 5846 21 0 0
t$perf-norm:sp_supplier_order 5364 5364 0 0.00 0 9873 18 0 0
t$perf-norm:srv_aggregate_perf_data 104 104 0 0.00 0 541 11 0 0
t$perf-norm:srv_fill_mon_cache_memory 61 61 0 0.00 0 19 1 0 0
t$perf-norm:srv_make_invnt_saldo 462 462 0 0.00 0 998 5 0 0
t$perf-norm:srv_make_money_saldo 742 742 0 0.00 0 319 4 0 0
t$perf-norm:srv_recalc_idx_stat 4 4 0 0.00 1 5 3 0 0
v_add_invoice_to_stock 10384 10038 346 3.33 0 9718 16 0 346
v_all_customers 37200 37200 0 0.00 0 21 1 0 0
v_all_suppliers 29590 29590 0 0.00 0 14 1 0 0
v_all_wares 41042 41042 0 0.00 0 19 1 0 0
v_cancel_adding_invoice 848 848 0 0.00 0 57 5 0 0
v_cancel_client_order 3514 3514 0 0.00 0 3389 5 0 0
v_cancel_customer_prepayment 1400 1400 0 0.00 0 5588 14 0 0
v_cancel_customer_reserve 1372 1372 0 0.00 0 589 4 0 0
v_cancel_payment_to_supplier 842 842 0 0.00 0 1837 7 0 0
v_cancel_supplier_invoice 820 798 22 2.68 0 2739 16 0 22
v_cancel_supplier_order 804 804 0 0.00 0 1703 5 0 0
v_cancel_write_off 1926 1926 0 0.00 0 2577 13 0 0
v_max_id_clo_ord 5364 5364 0 0.00 0 1502 2 0 0
v_max_id_clo_res 919 919 0 0.00 0 4566 22 0 0
v_max_id_ord_sup 5470 5470 0 0.00 0 7030 6 0 0
v_max_non_paid_invoice 1696 1696 0 0.00 0 7792 7 0 0
v_max_non_paid_realizn 3853 3853 0 0.00 0 3459 4 0 0
v_min_id_clo_ord 5364 5364 0 0.00 0 2937 6 0 0
v_min_id_clo_res 919 919 0 0.00 0 5500 18 0 0
v_min_id_ord_sup 5470 5470 0 0.00 0 10257 12 0 0
v_min_non_paid_invoice 5657 5657 0 0.00 0 9433 19 0 0
v_min_non_paid_realizn 7104 7104 0 0.00 0 6111 18 0 0
v_our_firm 10342 10342 0 0.00 0 19 1 0 0
v_reserve_write_off 20058 20058 0 0.00 0 5625 5 0 0
x_lock_depdocs_on_canc_invoice 11560 11560 0 0.00 0 15842 100 0 0
x_lock_depdocs_on_canc_sup_ord 402 402 0 0.00 0 18747 371 0 0
x_make_qstorno_1000_1200 5364 5364 0 0.00 2 49851 1205 0 0
x_make_qstorno_1200_2000 5474 5474 0 0.00 4 108533 3295 0 0
x_make_qstorno_2100_3300 458352 458352 0 0.00 0 62033 134 0 0

Completed "Performance in DETAILS". Done for 00:00:04, from 03-12-2020 10:27:46 to 03-12-2020 10:27:50.

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
07:56:54 7 8192000000 8796641392 8807108608 3168704 0.038 1 1 2 0 3266400 61840 35856
07:57:55 25854 8192000000 9736193968 10032680960 801899872 8.916 100 91 181 1 831788112 7686768 22201472
07:59:22 23054 8192000000 9754285104 10061594624 831434544 9.214 100 87 174 0 865214592 13134432 20645616
08:00:52 13232 8192000000 9806062496 10123878400 870354432 9.604 100 80 160 0 911628544 23113472 18160640
08:02:14 9750 8192000000 9879289920 10212954112 921172016 10.108 100 83 167 0 987634336 47750080 18712240
08:03:27 8804 8192000000 9917026976 10260496384 959060448 10.480 100 84 167 1 1026936848 49948432 17927968
08:04:38 5773 8192000000 9937099232 10289311744 988149520 10.763 100 79 155 0 1049630864 45922144 15559200
08:05:46 3592 8192000000 10007728784 10368315392 1021591728 11.087 100 85 170 3 1123334112 84763600 16978784
08:06:51 1366 8192000000 9988735152 10355232768 1048083152 11.342 100 92 181 1 1108099792 41180704 18835936
08:07:54 1719 8192000000 10045564816 10416529408 1064053120 11.495 100 91 183 1 1157163072 74613584 18496368
08:08:56 5161 8192000000 9997899808 10379251712 1068906368 11.542 100 56 113 0 1110078368 29557376 11614624
08:10:02 5651 8192000000 9998558096 10391527424 1076858304 11.618 100 52 105 1 1118932512 31512016 10562192
08:11:08 5652 8192000000 9991519328 10389147648 1079999504 11.647 100 29 58 1 1101127840 14581808 6546528
08:12:15 52179 8192000000 10002902736 10414411776 1083988560 11.685 100 26 52 2 1113246480 23541872 5716048
08:14:10 4877 8192000000 10015657056 10410049536 1094851392 11.789 100 59 115 5 1123941168 15829408 13260368
08:15:18 9464 8192000000 10014418784 10410622976 1104022896 11.876 100 41 83 4 1132991120 19781104 9187120
08:16:28 65968 8192000000 9996555424 10405605376 1063633920 11.491 97 42 84 0 1095711168 22714000 9363248
08:18:35 4513 8192000000 9939023616 10311364608 969948992 10.586 93 53 106 6 999521184 18211184 11361008
08:19:40 4643 8192000000 9949221600 10330517504 1013699072 11.011 98 45 91 0 1045402464 21318848 10384544
08:20:46 59015 8192000000 9941610592 10334556160 1008089536 10.957 97 30 60 1 1030987568 16551744 6346288
08:22:46 6877 8192000000 9931556624 10318491648 1008497408 10.961 98 47 95 1 1037216640 16571184 12148048
08:23:58 5727 8192000000 9965393072 10360520704 1050356288 11.364 100 49 99 1 1078922096 17478048 11087760
08:25:04 8116 8192000000 9971874704 10372415488 1063200752 11.487 100 37 73 2 1087807328 16393056 8213520
08:26:12 42333 8192000000 10008403904 10417590272 1073072656 11.581 100 25 48 2 1100226464 22419264 4734544
08:28:08 12273 8192000000 10046648656 10443603968 1096216096 11.802 100 53 104 2 1150000192 43493376 10290720
08:29:24 4276 8192000000 10057822864 10455715840 1108506224 11.918 100 41 81 1 1163845184 47099264 8239696
08:30:31 25954 8192000000 10116147408 10522570752 1124479856 12.069 100 57 113 1 1212815744 77280064 11055824
08:32:02 11137 8192000000 10131182016 10545819648 1132019728 12.140 100 41 79 1 1234218112 94030016 8168368
08:33:18 12630 8192000000 10148452288 10565627904 1137998992 12.197 100 47 94 3 1262589584 113863488 10727104
08:34:34 1394 8192000000 10192159168 10588155904 1154307888 12.350 100 81 160 1 1288640848 117267696 17065264
08:35:39 6301 8192000000 10224156576 10638815232 1162215248 12.424 100 55 110 1 1332237328 157605424 12416656
08:36:50 7766 8192000000 10263747328 10679918592 1173278384 12.527 100 58 116 0 1371186256 184734288 13173584
08:38:05 7453 8192000000 10282143872 10695725056 1173519152 12.530 100 62 124 1 1379670384 192389168 13762064
08:39:16 2265 8192000000 10316952656 10725638144 1176203120 12.555 100 75 149 3 1418796096 225477776 17115200
08:40:28 4638 8192000000 10343136080 10743099392 1151045184 12.319 98 74 148 0 1428800432 261103008 16652240
08:41:37 2503 8192000000 10409223504 10807795712 1171737808 12.513 100 91 178 4 1500786656 307964352 21084496
08:42:44 2910 8192000000 10434285824 10834558976 1163301344 12.434 100 74 148 0 1531446736 350846752 17298640
08:43:52 1375 8192000000 10509388304 10905911296 1161317632 12.416 100 94 188 2 1606402432 422370608 22714192
08:44:57 6867 8192000000 10536719872 10953072640 1166796704 12.467 100 64 128 0 1630127264 447032496 16298064
08:46:10 5168 8192000000 10557021792 10977001472 1177393152 12.566 100 74 146 3 1658729680 463268624 18067904
08:47:21 8469 8192000000 10546465664 10985463808 1178498496 12.576 100 46 90 1 1653940480 462715296 12726688
08:48:30 16680 8192000000 10545815008 11004383232 1161962416 12.422 100 32 64 1 1640814432 470168288 8683728
08:49:51 22881 8192000000 10540064608 11013394432 1131544240 12.136 99 27 54 0 1639303968 499625296 8134432
08:51:19 36529 8192000000 10080690256 10579505152 1107542608 11.909 98 17 34 0 1244296304 133193888 3559808
08:52:59 77487 8192000000 10122178800 10551197696 1112844992 11.959 99 39 76 2 1201432592 79925360 8662240
08:55:28 39985 8192000000 10077249056 10569838592 1090483920 11.747 98 8 16 2 1174348208 82252240 1612048
08:57:09 74553 8192000000 10072077184 10496221184 1096563872 11.805 97 24 47 1 1129009296 27735504 4709920
08:59:29 151295 8192000000 10108598176 10569523200 1113168048 11.962 98 20 40 1 1180812064 63034912 4609104
09:03:33 146606 8192000000 10067834400 10507071488 1075753616 11.607 95 14 28 1 1105334416 26545936 3034864
09:07:00 116720 8192000000 10101283472 10586161152 1076883472 11.618 95 14 28 1 1132837408 52970400 2983536
09:09:58 56425 8192000000 10058925664 10528583680 1122507872 12.051 100 17 34 0 1217482144 90833408 4140864
09:12:02 116367 8192000000 10064115200 10513174528 1120272400 12.030 99 30 61 1 1155046160 28461904 6311856
09:14:59 21665 8192000000 10053582832 10495463424 1138638480 12.203 100 23 45 2 1155845344 12190416 5016448
09:16:23 83673 8192000000 10097060656 10570956800 1141257120 12.227 99 13 26 1 1181699056 37824368 2617568
09:19:22 48123 8192000000 10088674224 10573230080 1134819056 12.167 99 13 26 1 1195851584 58514768 2517760
09:21:17 80105 8192000000 10138342784 10615709696 1146353568 12.275 100 11 22 0 1230934624 81594960 2986096
09:23:37 53565 8192000000 10112858272 10590048256 1134513888 12.164 99 22 44 2 1222152224 82795616 4842720
09:25:46 45526 8192000000 10059765872 10512453632 1117453904 12.003 98 16 34 1 1165712464 45212192 3046368
09:27:38 26141 8192000000 10103258464 10533617664 1122785568 12.053 99 37 74 2 1175259760 45265712 7208480
09:29:05 52076 8192000000 10105355696 10585661440 1119679248 12.024 98 16 32 1 1203318336 80283552 3355536
09:30:57 44143 8192000000 10093323376 10553274368 1118356752 12.011 99 16 30 1 1204725104 83115008 3253344
09:32:44 97876 8192000000 10103658080 10572107776 1097702976 11.816 97 9 17 2 1148688080 48893072 2092032
09:35:27 129870 8192000000 10058041936 10568835072 1101641424 11.853 98 22 44 0 1173697104 66983408 5072272
09:38:42 49896 8192000000 10015514848 10466713600 1063000496 11.485 96 9 18 1 1089427136 24638864 1787776
09:40:33 78612 8192000000 10064719072 10508808192 1091762672 11.759 98 15 30 0 1135616656 40265472 3588512
09:42:51 93192 8192000000 10044497568 10512277504 1097126976 11.810 99 12 22 1 1135061808 35965808 1969024
09:45:29 47706 8192000000 10063513840 10502918144 1089665056 11.739 98 16 32 1 1124302224 31457472 3179696
09:47:17 36104 8192000000 10117225696 10549936128 1085237600 11.697 97 26 52 1 1160149792 69497488 5414704
09:48:59 79307 8192000000 10135201440 10596786176 1108313008 11.916 99 23 46 1 1244041632 130431248 5297376
09:51:20 51721 8192000000 10133290208 10570051584 1089513472 11.738 97 26 52 3 1198758976 103491168 5754336
09:53:12 33082 8192000000 10094788976 10556780544 1087992784 11.724 98 17 34 2 1211800336 119783440 4024112
09:54:51 22034 8192000000 10079774224 10493997056 1101085696 11.848 99 41 78 2 1164110976 54993424 8031856
09:56:20 81879 8192000000 10047958944 10536800256 1107623088 11.910 100 16 32 2 1185637200 74676352 3337760
09:58:43 56589 8192000000 10043734608 10522066944 1110746432 11.939 100 5 10 0 1142611072 31208448 656192
10:00:40 77799 8192000000 10077834848 10563309568 1121488848 12.041 99 15 30 1 1168322976 43615296 3218832
10:02:58 67984 8192000000 10128889712 10553737216 1126556208 12.089 99 30 60 2 1205615552 72924608 6134736
10:05:11 44498 8192000000 10129560080 10587250688 1139076336 12.207 100 22 44 4 1218928800 74761856 5090608
10:07:05 48437 8192000000 10090075648 10523721728 1142127648 12.236 100 35 68 3 1211649968 62642704 6879616
10:08:59 80254 8192000000 10120909152 10609623040 1131259216 12.133 99 21 42 0 1227053296 91623312 4170768
10:11:25 123905 8192000000 10077558288 10536853504 1094660736 11.787 95 12 24 0 1149143056 51930848 2551472
10:17:09 72036 8192000000 10124927584 10584317952 1087637552 11.720 95 11 21 0 1143339200 53325408 2376240
10:19:48 55039 8192000000 10054411040 10495651840 1115125664 11.981 98 12 24 3 1136495808 18903008 2467136
10:21:47 112132 8192000000 10076985776 10533535744 1092357344 11.765 96 14 28 1 1158427728 62880720 3189664
10:24:54 51114 8192000000 10093845984 10556903424 1118987840 12.017 98 14 27 1 1170902352 49392288 2522224

Memory consumption, total, chart

Metadata cache size, chart

Statements activity, chart


Completed "Memory consumption, metadata cache, attachments activity". Done for 00:00:14, from 03-12-2020 10:27:52 to 03-12-2020 10:28:06.

Exceptions occured during test was in run

FB_MNEMONA CNT UNIT FB_GDSCODE
except 173 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 03-12-2020 10:28:07 to 03-12-2020 10:28:09.

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          232078
MON$OLDEST_ACTIVE               234114
MON$OLDEST_SNAPSHOT             234114
MON$NEXT_TRANSACTION            234114
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                       2108096
MON$STAT_ID                     1
MON$BACKUP_STATE                0
MON$CRYPT_PAGE                  0
MON$OWNER                       SYSDBA                                                                                                                                                                                                                                                      
MON$SEC_DATABASE                Default
MON$CRYPT_STATE                 0
MON$GUID                        {8C105897-B735-40F5-7D8B-A1F76E952B78}
MON$FILE_ID                     02fd0000000000002e02000000000000
MON$NEXT_ATTACHMENT             793
MON$NEXT_STATEMENT              53


ISQL Version: LI-V4.0.0.2287 Firebird 4.0 Release Candidate 1
Server version:
Firebird/Linux/AMD/Intel/x64 (access method), version "LI-V4.0.0.2287 Firebird 4.0 Release Candidate 1"
Firebird/Linux/AMD/Intel/x64 (remote server), version "LI-V4.0.0.2287 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.2287 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 ---
:67: 
:68: mscs-test-161.budzdorov.ru    Thu Dec  3 10:26:52 2020
:69:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:70: 
:71: 
:72: mscs-test-161.budzdorov.ru    Thu Dec  3 10:26:55 2020
:73:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:74: 
--- end of diff output ---

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

03.12.20 10:28:10. 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-12-03 10:28:12 No severe PSQL-related problems occured
03.12.20 10:28:14. End of report.