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

Server and database settinfs

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


Test configuration settings

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

Test finish info

FINISH_STATE                    NORMAL: TEST_TIME EXPIRED AT 2020-10-19 07:35:16
DTS_END                         2020-10-19 07:35:16.2530
FB_GDSCODE                      -1
FB_MNEMONA                      
STACK                           SP_ADD_INVOICE_TO_STOCK(190:30) ==> SP_CUSTOMER_RESERVE(47:5) ==> SP_CHECK_TO_STOP_WORK(32:12) ==> SP_HALT_ON_ERROR(67:17)
IP                              ::1/40784
TRN_ID                          238572
ATT_ID                          605
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: 8962.33 23282 1075480
customer order: creation 169.97 413 20396
customer order: refuse 15.08 363 1810
order to supplier: creation 45.62 1366 5474
order to supplier: removal 3.19 128431 383
invoice (draft): creation 44.88 3762 5386
invoice (draft): removal 50.67 1005 6080
invoice accept: apply 40.85 18932 4902
invoice accept: cancel 45.63 913 5476
customer reserve: creation 3814.85 184 457782
customer reserve: removal 4449.36 73 533923
realization accept: apply 82.33 187 9880
realization accept: cancel 74.06 124 8887
payment from customer: creation 58.10 119 6972
payment from customer: removal 5.70 93 684
payment to supplier: creation 47.90 145 5748
payment to supplier: removal 3.51 60 421
service: total inventory turnovers 3.97 3371 476
service: total monetary turnovers 5.96 482 715
service: aggregate perf. data 0.68 23710 81
service: refresh index statistics 0.03 281907 4

Performance in TOTAL, chart


Completed "Performance in TOTAL". Done for 00:00:02, from 19-10-2020 07:36:35 to 19-10-2020 07:36:37.

Performance for every MINUTE

TEST_PHASE_NAME MINUTES_PASSED PERF_SCORE
TEST_TIME 1 5068
TEST_TIME 2 3947
TEST_TIME 3 3435
TEST_TIME 4 4142
TEST_TIME 5 4559
TEST_TIME 6 4784
TEST_TIME 7 4937
TEST_TIME 8 5302
TEST_TIME 9 5568
TEST_TIME 10 5710
TEST_TIME 11 6043
TEST_TIME 12 6211
TEST_TIME 13 6557
TEST_TIME 14 6745
TEST_TIME 15 6774
TEST_TIME 16 6869
TEST_TIME 17 6756
TEST_TIME 18 6696
TEST_TIME 19 7773
TEST_TIME 20 7829
TEST_TIME 21 8094
TEST_TIME 22 8510
TEST_TIME 23 8542
TEST_TIME 24 8946
TEST_TIME 25 9110
TEST_TIME 26 9853
TEST_TIME 27 10347
TEST_TIME 28 11048
TEST_TIME 29 10906
TEST_TIME 30 11061
TEST_TIME 31 10970
TEST_TIME 32 10951
TEST_TIME 33 10747
TEST_TIME 34 10774
TEST_TIME 35 10866
TEST_TIME 36 10629
TEST_TIME 37 10354
TEST_TIME 38 10131
TEST_TIME 39 10155
TEST_TIME 40 10076
TEST_TIME 41 10048
TEST_TIME 42 9922
TEST_TIME 43 10043
TEST_TIME 44 10023
TEST_TIME 45 9956
TEST_TIME 46 9835
TEST_TIME 47 9671
TEST_TIME 48 9611
TEST_TIME 49 9546
TEST_TIME 50 9633
TEST_TIME 51 9606
TEST_TIME 52 9522
TEST_TIME 53 9637
TEST_TIME 54 9657
TEST_TIME 55 9622
TEST_TIME 56 9580
TEST_TIME 57 9571
TEST_TIME 58 9527
TEST_TIME 59 9593
TEST_TIME 60 9630
TEST_TIME 61 9696
TEST_TIME 62 9624
TEST_TIME 63 9498
TEST_TIME 64 9530
TEST_TIME 65 9439
TEST_TIME 66 9455
TEST_TIME 67 9388
TEST_TIME 68 9346
TEST_TIME 69 9319
TEST_TIME 70 9358
TEST_TIME 71 9387
TEST_TIME 72 9441
TEST_TIME 73 9432
TEST_TIME 74 9561
TEST_TIME 75 9628
TEST_TIME 76 9660
TEST_TIME 77 9599
TEST_TIME 78 9510
TEST_TIME 79 9436
TEST_TIME 80 9457
TEST_TIME 81 9371
TEST_TIME 82 9331
TEST_TIME 83 9313
TEST_TIME 84 9275
TEST_TIME 85 9259
TEST_TIME 86 9247
TEST_TIME 87 9243
TEST_TIME 88 9251
TEST_TIME 89 9314
TEST_TIME 90 9337
TEST_TIME 91 9366
TEST_TIME 92 9383
TEST_TIME 93 9373
TEST_TIME 94 9431
TEST_TIME 95 9391
TEST_TIME 96 9306
TEST_TIME 97 9262
TEST_TIME 98 9211
TEST_TIME 99 9198
TEST_TIME 100 9152
TEST_TIME 101 9169
TEST_TIME 102 9165
TEST_TIME 103 9175
TEST_TIME 104 9162
TEST_TIME 105 9138
TEST_TIME 106 9128
TEST_TIME 107 9115
TEST_TIME 108 9121
TEST_TIME 109 9192
TEST_TIME 110 9203
TEST_TIME 111 9248
TEST_TIME 112 9182
TEST_TIME 113 9149
TEST_TIME 114 9109
TEST_TIME 115 9097
TEST_TIME 116 9073
TEST_TIME 117 9060
TEST_TIME 118 9034
TEST_TIME 119 9028
TEST_TIME 120 8964

Performance per minute, chart


Completed "Performance for every MINUTE". Done for 00:00:03, from 19-10-2020 07:36:39 to 19-10-2020 07:36:42.

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 1499517 1499517 0 0.00 0 19122 7 0 0
doc_list_biud 1499517 1499517 0 0.00 0 37481 33 0 0
sp_add_invoice_to_stock 4973 4902 71 1.42 32 181123 18932 0 71
sp_cancel_adding_invoice 5476 5476 0 0.00 4 130514 913 0 0
sp_cancel_client_order 1810 1810 0 0.00 4 11980 363 0 0
sp_cancel_customer_reserve 533923 533923 0 0.00 1 37482 73 0 0
sp_cancel_pay_from_customer 684 684 0 0.00 3 4051 94 0 0
sp_cancel_pay_to_supplier 421 421 0 0.00 2 7219 61 0 0
sp_cancel_supplier_invoice 6086 6080 6 0.09 2 18917 1005 0 6
sp_cancel_supplier_order 383 383 0 0.00 8 1415326 128431 0 0
sp_cancel_write_off 8887 8887 0 0.00 1 9537 125 0 0
sp_client_order 20396 20396 0 0.00 4 22684 413 0 0
sp_customer_reserve 457782 457782 0 0.00 0 62194 184 0 0
sp_fill_shopping_cart 31253 31253 0 0.00 1 28544 45 0 0
sp_fill_shopping_cart_clo_res 457781 457781 0 0.00 0 22115 21 0 0
sp_get_clo_for_invoice 4900 4900 0 0.00 0 48080 419 0 0
sp_kill_cost_storno 15468 15468 0 0.00 0 7184 63 0 0
sp_kill_qstorno_ret_qs2qd 1083196 1083196 0 0.00 0 37476 40 0 0
sp_kill_qty_storno 571339 571339 0 0.00 0 37480 85 0 0
sp_lock_selected_doc 20536 20536 0 0.00 0 20773 6 0 0
sp_make_cost_storno 27500 27500 0 0.00 0 15694 64 0 0
sp_multiply_rows_for_pdistr 27500 27500 0 0.00 0 6485 30 0 0
sp_multiply_rows_for_qdistr 20396 20396 0 0.00 0 16079 221 0 0
sp_pay_from_customer 6972 6972 0 0.00 4 7829 120 0 0
sp_pay_to_supplier 5748 5748 0 0.00 4 14436 145 0 0
sp_payment_common 12720 12720 0 0.00 1 14419 25 0 0
sp_qd_handle_on_cancel_clo 1810 1810 0 0.00 0 11957 326 0 0
sp_qd_handle_on_invoice_upd_sts 10376 10376 0 0.00 0 30045 383 0 0
sp_qd_handle_on_reserve_upd_sts 9880 9880 0 0.00 0 27823 55 0 0
sp_reserve_write_off 9880 9880 0 0.00 6 27871 187 0 0
sp_supplier_invoice 5386 5386 0 0.00 7 142245 3762 0 0
sp_supplier_order 5474 5474 0 0.00 6 46483 1367 0 0
srv_aggregate_perf_data 81 81 0 0.00 2524 538165 23710 0 0
srv_fill_mon_cache_memory 63 63 0 0.00 1783 155375 46168 0 0
srv_find_qd_qs_mism 1028517 1028517 0 0.00 0 19121 6 0 0
srv_make_invnt_saldo 476 476 0 0.00 40 120367 3372 0 0
srv_make_money_saldo 715 715 0 0.00 1 12172 482 0 0
srv_recalc_idx_stat 4 4 0 0.00 186161 448304 281907 0 0
t$perf-abend:sp_add_invoice_to_stock 71 71 0 0.00 0 0 0 0 0
t$perf-abend:sp_cancel_supplier_invoice 6 6 0 0.00 0 0 0 0 0
t$perf-norm:sp_add_invoice_to_stock 4903 4903 0 0.00 0 27533 157 0 0
t$perf-norm:sp_cancel_adding_invoice 392 392 0 0.00 1 8262 131 0 0
t$perf-norm:sp_cancel_client_order 1810 1810 0 0.00 0 2959 12 0 0
t$perf-norm:sp_cancel_customer_reserve 661 661 0 0.00 0 860 10 0 0
t$perf-norm:sp_cancel_pay_from_customer 684 684 0 0.00 0 1476 11 0 0
t$perf-norm:sp_cancel_pay_to_supplier 421 421 0 0.00 0 484 5 0 0
t$perf-norm:sp_cancel_supplier_invoice 402 402 0 0.00 0 1017 13 0 0
t$perf-norm:sp_cancel_supplier_order 383 383 0 0.00 0 16071 1653 0 0
t$perf-norm:sp_cancel_write_off 1003 1003 0 0.00 0 3226 11 0 0
t$perf-norm:sp_client_order 20396 20396 0 0.00 0 3704 16 0 0
t$perf-norm:sp_customer_reserve 1004 1004 0 0.00 0 3098 10 0 0
t$perf-norm:sp_pay_from_customer 6972 6972 0 0.00 0 2581 7 0 0
t$perf-norm:sp_pay_to_supplier 5748 5748 0 0.00 0 11074 14 0 0
t$perf-norm:sp_reserve_write_off 9880 9880 0 0.00 0 7702 12 0 0
t$perf-norm:sp_supplier_invoice 5386 5386 0 0.00 0 3585 15 0 0
t$perf-norm:sp_supplier_order 5474 5474 0 0.00 0 7321 18 0 0
t$perf-norm:srv_aggregate_perf_data 81 81 0 0.00 0 563 8 0 0
t$perf-norm:srv_fill_mon_cache_memory 63 63 0 0.00 0 225 4 0 0
t$perf-norm:srv_make_invnt_saldo 476 476 0 0.00 0 489 5 0 0
t$perf-norm:srv_make_money_saldo 715 715 0 0.00 0 1034 6 0 0
t$perf-norm:srv_recalc_idx_stat 4 4 0 0.00 1 7 4 0 0
v_add_invoice_to_stock 9942 9800 142 1.42 0 8046 16 0 142
v_all_customers 37218 37218 0 0.00 0 17 1 0 0
v_all_suppliers 29938 29938 0 0.00 0 88 1 0 0
v_all_wares 40792 40792 0 0.00 0 116 1 0 0
v_cancel_adding_invoice 784 784 0 0.00 0 2169 11 0 0
v_cancel_client_order 3620 3620 0 0.00 0 3744 8 0 0
v_cancel_customer_prepayment 1368 1368 0 0.00 0 2512 10 0 0
v_cancel_customer_reserve 1322 1322 0 0.00 0 2965 8 0 0
v_cancel_payment_to_supplier 842 842 0 0.00 0 1779 5 0 0
v_cancel_supplier_invoice 816 804 12 1.47 0 3601 20 0 12
v_cancel_supplier_order 766 766 0 0.00 0 1030 5 0 0
v_cancel_write_off 2006 2006 0 0.00 0 946 11 0 0
v_max_id_clo_ord 5474 5474 0 0.00 0 933 1 0 0
v_max_id_clo_res 1004 1004 0 0.00 0 2913 15 0 0
v_max_id_ord_sup 5383 5383 0 0.00 0 2252 4 0 0
v_max_non_paid_invoice 1636 1636 0 0.00 0 3929 5 0 0
v_max_non_paid_realizn 3656 3656 0 0.00 0 3455 4 0 0
v_min_id_clo_ord 5474 5474 0 0.00 0 4542 6 0 0
v_min_id_clo_res 1004 1004 0 0.00 0 1150 4 0 0
v_min_id_ord_sup 5383 5383 0 0.00 0 27132 15 0 0
v_min_non_paid_invoice 5748 5748 0 0.00 0 14415 14 0 0
v_min_non_paid_realizn 6972 6972 0 0.00 0 6101 18 0 0
v_our_firm 10206 10206 0 0.00 0 21 1 0 0
v_reserve_write_off 19760 19760 0 0.00 0 4283 7 0 0
x_lock_depdocs_on_canc_invoice 11154 11154 0 0.00 0 59115 125 0 0
x_lock_depdocs_on_canc_sup_ord 383 383 0 0.00 0 3269 314 0 0
x_make_qstorno_1000_1200 5474 5474 0 0.00 2 46426 1291 0 0
x_make_qstorno_1200_2000 5386 5386 0 0.00 3 135021 3585 0 0
x_make_qstorno_2100_3300 457782 457782 0 0.00 0 54959 161 0 0

Completed "Performance in DETAILS". Done for 00:00:04, from 19-10-2020 07:36:43 to 19-10-2020 07:36:47.

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
05:05:20 7 8192000000 8796624000 8807108608 3156752 0.038 1 1 2 0 3254112 61504 35856
05:06:21 25893 8192000000 9728673504 10026729472 806546512 8.963 100 87 174 1 835018448 7825872 20646064
05:07:52 12761 8192000000 9763156256 10071171072 839599968 9.296 100 86 171 2 873043536 13206176 20237392
05:09:20 15726 8192000000 9811038752 10127847424 869516352 9.595 100 88 176 1 917380512 27874944 19989216
05:10:41 13429 8192000000 9855694016 10183237632 898239984 9.881 100 79 158 3 970171072 54363808 17567280
05:11:58 8299 8192000000 9909552272 10251726848 939563648 10.289 100 77 154 0 1018159120 62227200 16368272
05:13:09 4021 8192000000 9939390496 10290778112 986707376 10.749 100 74 143 1 1048456912 47887728 13861808
05:14:15 2432 8192000000 9995575408 10352615424 1013416032 11.008 100 91 181 1 1105244096 74276224 17551840
05:15:19 1560 8192000000 10008572000 10373902336 1035562528 11.222 100 92 182 0 1123550144 68737888 19249728
05:16:22 1666 8192000000 10035461456 10406780928 1057295440 11.431 100 90 180 1 1153648704 78149728 18203536
05:17:25 16292 8192000000 9968029728 10372128768 1056652448 11.424 100 47 92 2 1096323200 29404496 10266256
05:18:42 6204 8192000000 9980704992 10369744896 1061964752 11.475 100 35 70 0 1098289792 28467008 7858032
05:19:50 7406 8192000000 9978720624 10382192640 1070205328 11.554 100 36 74 0 1098442304 20513152 7723824
05:21:01 77743 8192000000 9988629552 10396860416 1080099552 11.648 100 34 65 6 1100109600 13177824 6832224
05:23:22 6942 8192000000 9991048288 10406928384 1080887808 11.656 100 40 82 1 1111774528 21100576 9786144
05:24:33 4924 8192000000 10001641408 10397831168 1087676224 11.721 100 46 89 3 1113857344 15797152 10383968
05:25:39 43902 8192000000 9949584912 10344628224 976835424 10.653 92 26 52 0 1002314400 19011200 6467776
05:27:40 3415 8192000000 9931307408 10312802304 1015008368 11.024 99 41 83 2 1045744672 21150640 9585664
05:28:47 2737 8192000000 9927157856 10300264448 1015938112 11.033 100 43 86 3 1042110960 17142864 9029984
05:29:52 7850 8192000000 9938272288 10315767808 1009165312 10.967 98 30 60 1 1029711040 13731728 6814000
05:31:02 38833 8192000000 9949614528 10346500096 1029374560 11.162 99 32 64 1 1053263568 16416576 7472432
05:32:46 4030 8192000000 9966155968 10354823168 1053360640 11.393 100 49 99 1 1079732352 14570432 11801280
05:33:51 5773 8192000000 9981785424 10371915776 1061518160 11.471 100 39 78 1 1088548976 17918640 9112176
05:34:58 6806 8192000000 9982585504 10379599872 1067645904 11.530 100 36 73 2 1089963664 14477632 7840128
05:36:10 65671 8192000000 10014067904 10419736576 1094917488 11.789 100 32 64 1 1128322064 26432976 6971600
05:38:24 27466 8192000000 10071979264 10473852928 1111795792 11.949 100 39 78 1 1158813808 38772896 8245120
05:39:59 30573 8192000000 10097365936 10510155776 1119485856 12.022 100 33 66 0 1207016864 80049184 7481824
05:41:38 8522 8192000000 10152939680 10557956096 1139055248 12.207 100 50 100 2 1251715904 101358400 11302256
05:42:52 16164 8192000000 10167530752 10574233600 1141666656 12.231 100 52 101 1 1265549344 112494192 11388496
05:44:11 11432 8192000000 10208610944 10614022144 1164232368 12.443 100 68 132 2 1303647856 124600928 14814560
05:45:32 4129 8192000000 10253833664 10662850560 1165980304 12.459 99 68 136 5 1349039200 167928304 15130592
05:46:40 1779 8192000000 10299041344 10697940992 1171147744 12.508 100 84 166 1 1402173808 212598880 18427184
05:47:45 9139 8192000000 10310622720 10723913728 1156342736 12.369 99 67 132 1 1411306096 240183456 14779904
05:49:09 3414 8192000000 10313303712 10709172224 1153762576 12.345 100 81 161 1 1413668784 240994064 18912144
05:50:18 4252 8192000000 10328680096 10726993920 1158169424 12.386 100 75 150 0 1431315312 256332528 16813360
05:51:26 3368 8192000000 10382431648 10781290496 1170831792 12.505 100 82 164 0 1481154528 290829840 19492896
05:52:39 10511 8192000000 10420153248 10825977856 1165631552 12.456 100 76 148 0 1514536320 331509696 17395072
05:54:00 3292 8192000000 10475893792 10875027456 1156216112 12.368 100 82 161 0 1574767888 399493056 19058720
05:55:10 17463 8192000000 10393349888 10831998976 1157754368 12.382 100 36 72 0 1502541216 335051760 9735088
05:56:44 10005 8192000000 10422061792 10840096768 1135474288 12.173 99 43 86 1 1517754144 371065200 11214656
05:58:08 8405 8192000000 10411066272 10823204864 1135453280 12.173 100 50 98 1 1499179568 352139072 11587216
05:59:19 8292 8192000000 10363004800 10816434176 1119867344 12.026 99 34 68 1 1465257120 336236480 9153296
06:00:29 15888 8192000000 10381735920 10834247680 1125566976 12.080 100 28 56 0 1464054352 331243488 7243888
06:01:53 29901 8192000000 10223984896 10695471104 1097453872 11.813 99 17 34 0 1356684176 254581024 4649280
06:03:24 44653 8192000000 10042840240 10530394112 1076347568 11.613 97 8 16 1 1123724800 45832224 1545008
06:05:12 79490 8192000000 10034846480 10477985792 1079338448 11.641 97 12 24 1 1122923104 41395888 2188768
06:07:33 91555 8192000000 10081193776 10487468032 1088314864 11.727 97 24 48 2 1130157664 36929392 4913408
06:10:05 52312 8192000000 10071456464 10546511872 1122411184 12.050 100 11 21 2 1184251376 59425808 2414384
06:12:05 108052 8192000000 10090062400 10514702336 1121911168 12.045 99 45 89 2 1175856672 44627824 9317680
06:14:54 27419 8192000000 10124957248 10542362624 1143031392 12.244 100 44 88 5 1203527776 50377600 10118784
06:16:24 38657 8192000000 10154400080 10648104960 1151496816 12.324 100 22 44 1 1248831984 92189424 5145744
06:18:05 28765 8192000000 10087178368 10570588160 1137337472 12.190 100 20 41 2 1212294496 70483904 4473120
06:19:46 61068 8192000000 10070745728 10527588352 1121582944 12.042 98 23 45 0 1170538400 43727376 5228080
06:21:52 86967 8192000000 10117228944 10573385728 1124098112 12.066 98 24 48 1 1199228336 69467168 5663056
06:24:20 62037 8192000000 10082771472 10603204608 1136122944 12.179 100 12 24 0 1214697552 75749232 2825376
06:26:34 32372 8192000000 10085490096 10514276352 1129421616 12.116 99 23 46 0 1156499920 22599632 4478672
06:28:09 59512 8192000000 10061691712 10535378944 1133324416 12.153 99 16 33 1 1209034064 72171344 3538304
06:30:09 44171 8192000000 10071866144 10514599936 1094962864 11.790 96 23 44 3 1132916192 33740016 4213312
06:31:58 20580 8192000000 10090437280 10525626368 1110130016 11.934 98 35 69 2 1164134240 47311504 6692720
06:33:23 39279 8192000000 10176688880 10623168512 1105887552 11.893 97 43 86 0 1212989536 98145728 8956256
06:35:22 59158 8192000000 10059264608 10510430208 1092987728 11.771 97 21 41 2 1178392048 81197440 4206880
06:37:24 104999 8192000000 10075355200 10550915072 1099374816 11.832 99 38 76 0 1201643680 94940224 7328640
06:40:14 54484 8192000000 10070663136 10543902720 1109612176 11.929 100 7 14 0 1154478896 43624912 1241808
06:42:09 43420 8192000000 10063668832 10501406720 1108929184 11.922 99 11 22 1 1150869904 39721920 2218800
06:43:53 24583 8192000000 10114758384 10545004544 1108140256 11.915 98 58 116 2 1177479904 57021488 12318160
06:45:32 61141 8192000000 10124462608 10644561920 1118733664 12.015 99 14 28 2 1245268560 123128320 3406576
06:47:35 34626 8192000000 10109378416 10548801536 1100268256 11.840 99 37 74 1 1184705104 76118784 8318064
06:49:11 28292 8192000000 10070828160 10493231104 1088593888 11.729 99 23 46 3 1138792992 45190464 5008640
06:50:46 97043 8192000000 10027449264 10449969152 1034020576 11.207 94 11 22 2 1061881744 25673504 2187664
06:53:37 82222 8192000000 10085662528 10527703040 1098447264 11.823 100 27 54 1 1198696112 94724848 5524000
06:56:15 34454 8192000000 10034697776 10473701376 1099622480 11.834 99 20 41 0 1133947104 29824128 4500496
06:57:58 55648 8192000000 10045419344 10529624064 1101911792 11.856 99 9 18 1 1154650832 50898096 1840944
06:59:54 80323 8192000000 10134780288 10593439744 1120780272 12.034 99 27 54 1 1182629472 56215328 5633872
07:02:15 35400 8192000000 10105904720 10555502592 1095398528 11.794 97 19 38 3 1180144000 80881776 3863696
07:03:51 60809 8192000000 10108209232 10583388160 1120607920 12.033 99 32 64 0 1243110080 115527088 6975072
07:05:58 97469 8192000000 10080123488 10535673856 1123872032 12.064 99 17 34 1 1200602960 73367104 3363824
07:08:44 42520 8192000000 10096670512 10592935936 1128155872 12.104 100 42 83 2 1234926000 97820448 8949680
07:10:35 155375 8192000000 10078579936 10536734720 1133385040 12.153 100 23 46 1 1165036672 26895200 4756432
07:14:15 34849 8192000000 10077734224 10581831680 1126518304 12.089 99 5 10 2 1171774624 44378992 877328
07:16:06 126941 8192000000 10077073600 10571837440 1075900512 11.608 94 18 36 1 1142153120 62349344 3903264
07:20:11 28937 8192000000 10068902832 10498314240 1105260544 11.888 99 24 48 1 1144511792 34445968 4805280
07:21:48 38638 8192000000 10110696800 10543181824 1123631280 12.061 100 39 78 4 1191606608 59762720 8212608
07:23:46 50731 8192000000 10065275184 10566316032 1105395488 11.889 98 11 20 2 1171447760 63998560 2053712
07:25:55 80949 8192000000 10080226656 10529013760 1111829936 11.950 98 12 24 0 1178237680 63969184 2438560
07:28:16 103217 8192000000 10062099536 10530861056 1114670800 11.977 99 19 38 1 1168027856 49374608 3982448
07:31:14 68742 8192000000 10034506576 10506821632 1067430832 11.528 96 4 8 0 1096875584 28785248 659504
07:34:00 56958 8192000000 10068315696 10505064448 1101902432 11.856 99 25 50 1 1172432736 64775696 5754608

Memory consumption, total, chart

Metadata cache size, chart

Statements activity, chart


Completed "Memory consumption, metadata cache, attachments activity". Done for 00:00:15, from 19-10-2020 07:36:49 to 19-10-2020 07:37:04.

Exceptions occured during test was in run

FB_MNEMONA CNT UNIT FB_GDSCODE
user_exc 71 v_add_invoice_to_stock 335544517
user_exc 6 v_cancel_supplier_invoice 335544517

Completed "Exceptions occured during test was in run". Done for 00:00:02, from 19-10-2020 07:37:04 to 19-10-2020 07:37:06.

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          236250
MON$OLDEST_ACTIVE               239211
MON$OLDEST_SNAPSHOT             239211
MON$NEXT_TRANSACTION            239211
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                       2110272
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             789
MON$NEXT_STATEMENT              53


ISQL Version: LI-V4.0.0.2228 Firebird 4.0 Release Candidate 1
Server version:
Firebird/Linux/AMD/Intel/x64 (access method), version "LI-V4.0.0.2228 Firebird 4.0 Release Candidate 1"
Firebird/Linux/AMD/Intel/x64 (remote server), version "LI-V4.0.0.2228 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.2228 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 ---
:6: 
:7: mscs-test-161.budzdorov.ru    Mon Oct 19 07:35:23 2020
:8:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:9: 
:10: 
:11: mscs-test-161.budzdorov.ru    Mon Oct 19 07:35:23 2020
:12:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:13: 
:14: 
:15: mscs-test-161.budzdorov.ru    Mon Oct 19 07:35:25 2020
:16:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:17: 
:18: 
:19: mscs-test-161.budzdorov.ru    Mon Oct 19 07:35:26 2020
:20:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:21: 
--- end of diff output ---

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

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