Generated by /opt/oltp-emul/oltp_isql_run_worker.sh, ISQL session No. 1 of total launched 100. 22.10.2020 13: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 16989876 kB
MemAvailable 31524992 kB
Buffers 0 kB
Cached 14655840 kB
SwapCached 3816 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-22 13:26:52
DTS_END                         2020-10-22 13:26:52.5090
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(67:17)
IP                              ::1/36704
TRN_ID                          236538
ATT_ID                          685
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: 9041.99 27464 1085039
customer order: creation 171.42 416 20570
customer order: refuse 14.53 290 1744
order to supplier: creation 45.23 1396 5428
order to supplier: removal 3.30 117127 396
invoice (draft): creation 46.75 3153 5610
invoice (draft): removal 49.31 968 5917
invoice accept: apply 42.41 16420 5089
invoice accept: cancel 44.51 908 5341
customer reserve: creation 3920.60 160 470472
customer reserve: removal 4415.10 71 529812
realization accept: apply 83.21 158 9985
realization accept: cancel 75.99 122 9119
payment from customer: creation 59.90 97 7188
payment from customer: removal 5.84 72 701
payment to supplier: creation 49.46 100 5935
payment to supplier: removal 3.45 50 414
service: total inventory turnovers 4.12 2753 494
service: total monetary turnovers 5.94 468 713
service: aggregate perf. data 0.90 15217 108
service: refresh index statistics 0.03 389329 3

Performance in TOTAL, chart


Completed "Performance in TOTAL". Done for 00:00:02, from 22-10-2020 13:27:51 to 22-10-2020 13:27:53.

Performance for every MINUTE

TEST_PHASE_NAME MINUTES_PASSED PERF_SCORE
TEST_TIME 1 2647
TEST_TIME 2 4962
TEST_TIME 3 4684
TEST_TIME 4 5141
TEST_TIME 5 5000
TEST_TIME 6 4934
TEST_TIME 7 5010
TEST_TIME 8 5242
TEST_TIME 9 5456
TEST_TIME 10 5732
TEST_TIME 11 6164
TEST_TIME 12 6740
TEST_TIME 13 6701
TEST_TIME 14 6621
TEST_TIME 15 6673
TEST_TIME 16 7225
TEST_TIME 17 8372
TEST_TIME 18 8364
TEST_TIME 19 8762
TEST_TIME 20 8724
TEST_TIME 21 8992
TEST_TIME 22 9146
TEST_TIME 23 9428
TEST_TIME 24 10192
TEST_TIME 25 11357
TEST_TIME 26 11276
TEST_TIME 27 11354
TEST_TIME 28 11276
TEST_TIME 29 10897
TEST_TIME 30 10588
TEST_TIME 31 10600
TEST_TIME 32 10484
TEST_TIME 33 10335
TEST_TIME 34 10460
TEST_TIME 35 10426
TEST_TIME 36 10256
TEST_TIME 37 10144
TEST_TIME 38 10028
TEST_TIME 39 10052
TEST_TIME 40 10228
TEST_TIME 41 10103
TEST_TIME 42 10186
TEST_TIME 43 10331
TEST_TIME 44 10224
TEST_TIME 45 10180
TEST_TIME 46 10130
TEST_TIME 47 10078
TEST_TIME 48 10127
TEST_TIME 49 10286
TEST_TIME 50 10218
TEST_TIME 51 10022
TEST_TIME 52 9940
TEST_TIME 53 9863
TEST_TIME 54 9780
TEST_TIME 55 9690
TEST_TIME 56 9605
TEST_TIME 57 9549
TEST_TIME 58 9459
TEST_TIME 59 9404
TEST_TIME 60 9388
TEST_TIME 61 9601
TEST_TIME 62 9581
TEST_TIME 63 9568
TEST_TIME 64 9582
TEST_TIME 65 9579
TEST_TIME 66 9626
TEST_TIME 67 9595
TEST_TIME 68 9600
TEST_TIME 69 9572
TEST_TIME 70 9689
TEST_TIME 71 9594
TEST_TIME 72 9462
TEST_TIME 73 9388
TEST_TIME 74 9346
TEST_TIME 75 9326
TEST_TIME 76 9279
TEST_TIME 77 9239
TEST_TIME 78 9201
TEST_TIME 79 9245
TEST_TIME 80 9308
TEST_TIME 81 9342
TEST_TIME 82 9288
TEST_TIME 83 9359
TEST_TIME 84 9359
TEST_TIME 85 9346
TEST_TIME 86 9405
TEST_TIME 87 9380
TEST_TIME 88 9325
TEST_TIME 89 9244
TEST_TIME 90 9184
TEST_TIME 91 9152
TEST_TIME 92 9129
TEST_TIME 93 9097
TEST_TIME 94 9066
TEST_TIME 95 9096
TEST_TIME 96 9099
TEST_TIME 97 9123
TEST_TIME 98 9088
TEST_TIME 99 9096
TEST_TIME 100 9097
TEST_TIME 101 9152
TEST_TIME 102 9097
TEST_TIME 103 9095
TEST_TIME 104 9066
TEST_TIME 105 9160
TEST_TIME 106 9188
TEST_TIME 107 9113
TEST_TIME 108 9083
TEST_TIME 109 9040
TEST_TIME 110 8997
TEST_TIME 111 9006
TEST_TIME 112 9004
TEST_TIME 113 8988
TEST_TIME 114 9012
TEST_TIME 115 8980
TEST_TIME 116 8959
TEST_TIME 117 8969
TEST_TIME 118 8987
TEST_TIME 119 8988
TEST_TIME 120 9045

Performance per minute, chart


Completed "Performance for every MINUTE". Done for 00:00:04, from 22-10-2020 13:27:54 to 22-10-2020 13:27:58.

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 1519545 1519545 0 0.00 0 34694 6 0 0
doc_list_biud 1519544 1519544 0 0.00 0 71449 31 0 0
sp_add_invoice_to_stock 5247 5089 158 3.01 41 151916 16420 0 158
sp_cancel_adding_invoice 5341 5341 0 0.00 6 65484 909 0 0
sp_cancel_client_order 1744 1744 0 0.00 4 10808 290 0 0
sp_cancel_customer_reserve 529812 529812 0 0.00 1 71450 71 0 0
sp_cancel_pay_from_customer 701 701 0 0.00 3 4736 72 0 0
sp_cancel_pay_to_supplier 414 414 0 0.00 3 1343 51 0 0
sp_cancel_supplier_invoice 5930 5917 13 0.21 3 68254 969 0 13
sp_cancel_supplier_order 396 396 0 0.00 8 946024 117127 0 0
sp_cancel_write_off 9119 9119 0 0.00 1 10968 122 0 0
sp_client_order 20570 20570 0 0.00 4 28862 416 0 0
sp_customer_reserve 470472 470472 0 0.00 0 66612 160 0 0
sp_fill_shopping_cart 31590 31590 0 0.00 1 12883 41 0 0
sp_fill_shopping_cart_clo_res 470467 470467 0 0.00 0 26316 18 0 0
sp_get_clo_for_invoice 5084 5084 0 0.00 0 51565 462 0 0
sp_kill_cost_storno 15575 15575 0 0.00 0 34659 59 0 0
sp_kill_qstorno_ret_qs2qd 1075056 1075056 0 0.00 0 71444 38 0 0
sp_kill_qty_storno 567398 567398 0 0.00 0 71448 81 0 0
sp_lock_selected_doc 20832 20832 0 0.00 0 10006 6 0 0
sp_make_cost_storno 28192 28192 0 0.00 0 19345 47 0 0
sp_multiply_rows_for_pdistr 28192 28192 0 0.00 0 10818 26 0 0
sp_multiply_rows_for_qdistr 20570 20570 0 0.00 0 28851 250 0 0
sp_pay_from_customer 7188 7188 0 0.00 4 12682 97 0 0
sp_pay_to_supplier 5935 5935 0 0.00 5 8858 101 0 0
sp_payment_common 13123 13123 0 0.00 1 12004 16 0 0
sp_qd_handle_on_cancel_clo 1744 1744 0 0.00 0 10799 264 0 0
sp_qd_handle_on_invoice_upd_sts 10425 10425 0 0.00 0 21763 333 0 0
sp_qd_handle_on_reserve_upd_sts 9985 9985 0 0.00 0 14073 49 0 0
sp_reserve_write_off 9985 9985 0 0.00 6 19457 158 0 0
sp_supplier_invoice 5610 5610 0 0.00 8 88986 3154 0 0
sp_supplier_order 5428 5428 0 0.00 5 74274 1396 0 0
srv_aggregate_perf_data 108 108 0 0.00 2312 222417 15217 0 0
srv_fill_mon_cache_memory 62 62 0 0.00 1364 123790 46916 0 0
srv_find_qd_qs_mism 1036362 1036362 0 0.00 0 10117 5 0 0
srv_make_invnt_saldo 494 494 0 0.00 54 96141 2754 0 0
srv_make_money_saldo 713 713 0 0.00 1 14863 469 0 0
srv_recalc_idx_stat 3 3 0 0.00 233552 594933 389330 0 0
t$perf-abend:sp_add_invoice_to_stock 158 158 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 5089 5089 0 0.00 0 12397 136 0 0
t$perf-norm:sp_cancel_adding_invoice 432 432 0 0.00 0 5492 130 0 0
t$perf-norm:sp_cancel_client_order 1744 1744 0 0.00 0 2589 11 0 0
t$perf-norm:sp_cancel_customer_reserve 669 669 0 0.00 0 2591 10 0 0
t$perf-norm:sp_cancel_pay_from_customer 701 701 0 0.00 0 3041 11 0 0
t$perf-norm:sp_cancel_pay_to_supplier 414 414 0 0.00 0 229 1 0 0
t$perf-norm:sp_cancel_supplier_invoice 425 425 0 0.00 0 3076 19 0 0
t$perf-norm:sp_cancel_supplier_order 396 396 0 0.00 0 21140 1537 0 0
t$perf-norm:sp_cancel_write_off 982 982 0 0.00 0 4383 7 0 0
t$perf-norm:sp_client_order 20570 20570 0 0.00 0 12885 15 0 0
t$perf-norm:sp_customer_reserve 1010 1010 0 0.00 0 1967 6 0 0
t$perf-norm:sp_pay_from_customer 7188 7188 0 0.00 0 4324 8 0 0
t$perf-norm:sp_pay_to_supplier 5935 5935 0 0.00 0 6092 10 0 0
t$perf-norm:sp_reserve_write_off 9985 9985 0 0.00 0 8068 9 0 0
t$perf-norm:sp_supplier_invoice 5610 5610 0 0.00 0 11938 14 0 0
t$perf-norm:sp_supplier_order 5428 5428 0 0.00 0 5341 15 0 0
t$perf-norm:srv_aggregate_perf_data 108 108 0 0.00 0 512 11 0 0
t$perf-norm:srv_fill_mon_cache_memory 62 62 0 0.00 0 2486 41 0 0
t$perf-norm:srv_make_invnt_saldo 494 494 0 0.00 0 971 10 0 0
t$perf-norm:srv_make_money_saldo 713 713 0 0.00 0 1766 9 0 0
t$perf-norm:srv_recalc_idx_stat 3 3 0 0.00 2 3 2 0 0
v_add_invoice_to_stock 10484 10168 316 3.01 0 7252 15 0 316
v_all_customers 37384 37384 0 0.00 0 18 1 0 0
v_all_suppliers 30634 30634 0 0.00 0 54 1 0 0
v_all_wares 41140 41140 0 0.00 0 19 1 0 0
v_cancel_adding_invoice 864 864 0 0.00 0 336 5 0 0
v_cancel_client_order 3488 3488 0 0.00 0 1611 5 0 0
v_cancel_customer_prepayment 1402 1402 0 0.00 0 1902 7 0 0
v_cancel_customer_reserve 1338 1338 0 0.00 0 2241 5 0 0
v_cancel_payment_to_supplier 828 828 0 0.00 0 495 4 0 0
v_cancel_supplier_invoice 876 850 26 2.96 0 1763 15 0 26
v_cancel_supplier_order 792 792 0 0.00 0 481 3 0 0
v_cancel_write_off 1964 1964 0 0.00 0 8097 21 0 0
v_max_id_clo_ord 5424 5424 0 0.00 0 1658 2 0 0
v_max_id_clo_res 1010 1010 0 0.00 0 4496 21 0 0
v_max_id_ord_sup 5594 5594 0 0.00 0 2429 4 0 0
v_max_non_paid_invoice 1636 1636 0 0.00 0 347 2 0 0
v_max_non_paid_realizn 3927 3927 0 0.00 0 788 2 0 0
v_min_id_clo_ord 5424 5424 0 0.00 0 3086 5 0 0
v_min_id_clo_res 1010 1010 0 0.00 0 6770 15 0 0
v_min_id_ord_sup 5594 5594 0 0.00 0 5065 7 0 0
v_min_non_paid_invoice 5935 5935 0 0.00 0 4422 8 0 0
v_min_non_paid_realizn 7188 7188 0 0.00 0 7156 9 0 0
v_our_firm 10278 10278 0 0.00 0 14 1 0 0
v_reserve_write_off 19970 19970 0 0.00 0 4858 5 0 0
x_lock_depdocs_on_canc_invoice 10833 10833 0 0.00 0 21795 108 0 0
x_lock_depdocs_on_canc_sup_ord 396 396 0 0.00 0 6895 314 0 0
x_make_qstorno_1000_1200 5428 5428 0 0.00 2 74244 1327 0 0
x_make_qstorno_1200_2000 5610 5610 0 0.00 4 88952 2998 0 0
x_make_qstorno_2100_3300 470472 470472 0 0.00 0 66585 141 0 0

Completed "Performance in DETAILS". Done for 00:00:04, from 22-10-2020 13:27:59 to 22-10-2020 13:28:03.

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
10:56:56 1 8192000000 8796633056 8807174144 3163600 0.038 1 1 2 0 3261296 61840 35856
10:57:57 26092 8192000000 9720148720 10013995008 791069120 8.806 100 87 174 0 820916688 8473152 21374416
10:59:34 23417 8192000000 9773271920 10081058816 843201936 9.332 100 90 180 0 878653216 14036144 21415136
11:01:05 12750 8192000000 9816659888 10139811840 877511136 9.675 100 86 172 1 927653952 30294528 19848288
11:02:25 11710 8192000000 9887873184 10223284224 929547456 10.190 100 78 156 4 996290720 49843584 16899680
11:03:40 5866 8192000000 9942981168 10293972992 978657888 10.671 100 80 159 0 1057592928 62231856 16703184
11:04:48 3840 8192000000 9979331280 10337689600 1007532624 10.951 100 80 158 2 1087478720 63746640 16199456
11:05:54 5052 8192000000 10010260272 10381701120 1035599488 11.222 100 76 148 1 1124176272 73543136 15033648
11:07:01 1721 8192000000 10026689376 10396041216 1053387696 11.393 100 89 178 0 1145014448 73922544 17704208
11:08:04 13677 8192000000 10020378720 10398535680 1065516880 11.509 100 66 132 1 1136317216 57031008 13769328
11:09:18 4392 8192000000 10031164416 10424283136 1073740064 11.588 100 45 91 0 1145555376 62898928 8916384
11:10:23 25809 8192000000 10007361648 10405208064 1073151856 11.582 100 66 132 0 1112784432 24273536 15359040
11:11:50 5748 8192000000 10002563184 10406825984 1078665552 11.635 100 39 79 3 1118792704 30949536 9177616
11:13:01 6175 8192000000 10006211344 10411020288 1084800944 11.693 100 35 71 0 1122090752 30087360 7202448
11:14:09 7561 8192000000 10004951424 10401656832 1078841760 11.636 99 28 56 0 1111393680 26456624 6095296
11:15:17 21120 8192000000 10015675792 10403368960 1094830448 11.789 100 58 118 2 1118196752 10383392 12982912
11:16:39 9408 8192000000 9973382288 10365640704 1039803488 11.263 96 42 83 2 1061686752 12000464 9882800
11:17:52 6496 8192000000 9980382272 10378133504 1044323840 11.306 97 48 97 0 1072109296 17541728 10243728
11:19:05 5888 8192000000 9946593248 10332688384 1020031552 11.072 98 48 99 0 1045637104 14698496 10907056
11:20:11 47137 8192000000 9936007728 10328199168 965842864 10.546 93 22 44 1 981955936 11670896 4442176
11:21:59 8785 8192000000 9948052688 10334199808 1019027472 11.063 98 27 55 0 1037674432 12455056 6191904
11:23:09 7130 8192000000 9969198784 10364006400 1055119632 11.410 100 30 60 1 1088378096 27000912 6257552
11:24:16 6155 8192000000 9976433248 10367242240 1065841376 11.512 100 43 85 0 1088833072 13196224 9795472
11:25:25 32511 8192000000 9969727152 10377465856 1064034256 11.495 100 21 41 3 1092615440 25077408 3503776
11:27:00 35307 8192000000 10011781664 10401628160 1091583328 11.758 100 49 94 2 1116082352 13927616 10571408
11:28:40 15323 8192000000 10073395632 10471960576 1111046080 11.942 100 52 105 0 1185221184 62843824 11331280
11:29:58 63228 8192000000 10122265664 10536624128 1134796672 12.167 100 41 82 3 1251651984 107847936 9007376
11:32:12 8667 8192000000 10168710352 10566615040 1137152016 12.189 99 57 113 1 1269150256 119870496 12127744
11:33:29 6872 8192000000 10196566448 10604228608 1153027792 12.338 100 55 110 1 1310317904 144871536 12418576
11:34:41 15495 8192000000 10248448464 10657157120 1161539264 12.418 100 52 101 1 1357548896 184015648 11993984
11:36:03 9481 8192000000 10267837744 10679197696 1144712656 12.260 99 53 106 0 1368421504 211028160 12680688
11:37:15 3352 8192000000 10309261152 10709508096 1170581536 12.502 100 83 166 0 1408163888 218709920 18872432
11:38:23 2073 8192000000 10324156464 10719903744 1171645536 12.512 100 81 158 0 1428083840 239435712 17002592
11:39:30 3112 8192000000 10379682336 10779652096 1175577520 12.549 100 77 152 1 1483318848 290331984 17409344
11:40:42 5083 8192000000 10412670816 10830462976 1178296432 12.574 100 47 94 0 1515375312 324830400 12248480
11:42:00 1920 8192000000 10468395360 10892083200 1169797488 12.495 100 69 138 0 1569376992 382642576 16936928
11:43:10 1364 8192000000 10460692624 10860732416 1170042976 12.497 100 81 161 1 1558853776 368889504 19921296
11:44:16 2938 8192000000 10382588992 10788372480 1157812640 12.383 100 74 144 2 1484852048 309332240 17707168
11:45:21 16136 8192000000 10376748208 10826096640 1142797856 12.242 99 38 75 1 1473047072 320893648 9355568
11:46:40 16714 8192000000 10401436640 10836549632 1120516320 12.032 98 28 56 2 1472396080 344225936 7653824
11:48:12 20413 8192000000 10386063296 10810077184 1125591360 12.080 100 25 50 0 1509424480 376706256 7126864
11:49:37 13386 8192000000 10395672928 10826063872 1117974704 12.008 100 30 60 1 1489510800 363809008 7727088
11:50:57 14611 8192000000 10265367824 10699214848 1106155408 11.896 99 29 58 0 1353357360 240028224 7173728
11:52:12 73864 8192000000 10060851728 10507255808 1079254320 11.640 96 20 38 2 1146226384 63179728 3792336
11:54:27 97398 8192000000 10090464016 10535518208 1106093056 11.895 99 36 71 2 1185006448 70844320 8069072
11:57:21 19809 8192000000 10062817232 10481258496 1081542352 11.662 97 36 72 1 1142085008 52989344 7553312
11:58:45 42188 8192000000 10109054240 10538356736 1095234496 11.792 97 31 63 1 1177296912 75922320 6140096
12:00:42 56597 8192000000 10106223776 10593939456 1122632512 12.052 100 13 25 1 1206025632 80402752 2990368
12:02:41 63288 8192000000 10126431600 10580631552 1129162048 12.113 99 19 37 2 1206571152 73582912 3826192
12:04:44 67974 8192000000 10127790608 10609049600 1109173648 11.925 98 18 36 0 1242389392 128950032 4265712
12:07:26 43858 8192000000 10117977712 10568200192 1124225808 12.067 100 33 66 0 1200217792 69001184 6990800
12:09:13 61997 8192000000 10059259456 10489286656 1114662896 11.977 99 18 34 0 1163396384 45077600 3655888
12:12:20 45366 8192000000 10112784128 10537050112 1140236608 12.218 100 36 72 3 1214057616 66551008 7270000
12:14:10 123108 8192000000 10092438016 10582904832 1123439792 12.059 98 23 46 1 1219830064 91499888 4890384
12:17:13 95645 8192000000 10072880592 10522062848 1130349600 12.125 99 25 50 0 1163283872 27759648 5174624
12:19:59 49369 8192000000 10065502720 10534809600 1145621792 12.268 100 7 14 1 1183030272 34793712 2614768
12:22:00 72684 8192000000 10104234288 10562039808 1138432512 12.201 99 14 28 1 1189234128 47862128 2939488
12:24:13 50416 8192000000 10125308112 10560851968 1123966288 12.064 98 21 41 2 1206788704 78350512 4471904
12:26:04 90687 8192000000 10175054880 10663780352 1130947664 12.130 98 20 40 1 1266154864 131159056 4048144
12:28:49 65595 8192000000 10099828112 10535378944 1122990816 12.055 98 14 29 0 1165681744 40193696 2497232
12:32:03 41410 8192000000 10079306448 10518700032 1084037632 11.686 97 27 55 0 1140755824 50956192 5762000
12:33:50 26621 8192000000 10074016544 10495655936 1082847648 11.675 97 31 60 2 1126620144 37656944 6115552
12:35:21 8904 8192000000 10068850960 10487599104 1111548208 11.947 100 54 106 1 1161098208 38689600 10860400
12:36:30 123790 8192000000 10057107056 10531942400 1088251072 11.726 98 12 24 1 1154798336 64089008 2458256
12:40:03 46000 8192000000 10036403424 10507608064 1101256688 11.850 99 4 8 1 1128306080 26221936 827456
12:41:50 59177 8192000000 10059851072 10488336384 1101509744 11.852 98 12 24 3 1141929456 37913104 2506608
12:43:49 42616 8192000000 10128172352 10562215936 1134418304 12.163 100 28 56 1 1213874848 73266160 6190384
12:45:39 65151 8192000000 10133049232 10657964032 1118307600 12.011 99 17 34 1 1249911200 127409360 4194240
12:47:45 35857 8192000000 10106656240 10526593024 1113651536 11.967 99 31 61 5 1195858288 75836096 6370656
12:49:25 70302 8192000000 10056016544 10520846336 1071186480 11.563 96 23 46 1 1133782320 57906640 4689200
12:51:38 52019 8192000000 10082273008 10537902080 1093843264 11.779 99 21 42 2 1152712304 54724688 4144352
12:53:34 86577 8192000000 10042374256 10492346368 1111152192 11.943 100 11 23 0 1139551744 25367440 3032112
12:56:53 95324 8192000000 10070068560 10534940672 1133156848 12.151 100 11 22 0 1190478096 55303072 2018176
12:59:28 61456 8192000000 10079030784 10517819392 1118456912 12.012 98 12 24 0 1158312592 37129008 2726672
13:01:33 57588 8192000000 10092688608 10541752320 1121415328 12.040 99 14 27 1 1204658288 80410896 2832064
13:03:31 107983 8192000000 10117453040 10577887232 1120943936 12.036 98 11 22 0 1167708768 44878480 1886352
13:06:53 43666 8192000000 10101579456 10552295424 1152852992 12.336 100 18 36 0 1206728976 50292896 3583088
13:08:41 14417 8192000000 10102896032 10516422656 1133349472 12.153 99 64 125 2 1169714880 23707280 12658128
13:09:56 12995 8192000000 10109869296 10536660992 1134603728 12.165 100 45 88 1 1180877472 37774000 8499744
13:11:09 82758 8192000000 10137861744 10640740352 1127593216 12.099 98 8 16 1 1190197824 61017488 1587120
13:13:40 111055 8192000000 10080220480 10561511424 1129844992 12.120 99 17 34 0 1177219008 43240800 4133216
13:17:44 53735 8192000000 10092293664 10536599552 1130944784 12.130 99 24 49 2 1195497040 59613296 4938960
13:19:50 42752 8192000000 10085213872 10523238400 1113147440 11.962 98 17 35 0 1168682672 52022688 3512544
13:21:42 44644 8192000000 10084023872 10520481792 1076444192 11.614 95 20 40 0 1152202912 71533648 4225072
13:23:31 63267 8192000000 10095035424 10560552960 1093907584 11.780 97 15 30 0 1163941504 66480640 3553280
13:25:38 83301 8192000000 9521153808 9959591936 601916240 6.844 53 7 12 1 658782880 55474480 1392160

Memory consumption, total, chart

Metadata cache size, chart

Statements activity, chart


Completed "Memory consumption, metadata cache, attachments activity". Done for 00:00:15, from 22-10-2020 13:28:05 to 22-10-2020 13:28:20.

Exceptions occured during test was in run

FB_MNEMONA CNT UNIT FB_GDSCODE
user_exc 158 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:01, from 22-10-2020 13:28:21 to 22-10-2020 13:28:22.

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          240485
MON$OLDEST_ACTIVE               240486
MON$OLDEST_SNAPSHOT             240486
MON$NEXT_TRANSACTION            240486
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                       2087136
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             792
MON$NEXT_STATEMENT              53


ISQL Version: LI-V4.0.0.2232 Firebird 4.0 Release Candidate 1
Server version:
Firebird/Linux/AMD/Intel/x64 (access method), version "LI-V4.0.0.2232 Firebird 4.0 Release Candidate 1"
Firebird/Linux/AMD/Intel/x64 (remote server), version "LI-V4.0.0.2232 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.2232 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 ---
:24: 
:25: mscs-test-161.budzdorov.ru    Thu Oct 22 13:27:08 2020
:26:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:27: 
:28: 
:29: mscs-test-161.budzdorov.ru    Thu Oct 22 13:27:22 2020
:30:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:31: 
--- end of diff output ---

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

22.10.20 13:28:24. 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-22 13:28:26 No severe PSQL-related problems occured
22.10.20 13:28:27. End of report.