Generated by /opt/oltp-emul/oltp_isql_run_worker.sh, ISQL session No. 1 of total launched 100. 09.10.2020 16:01
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'
./oltp_isql_run_worker.sh line 45: dmidecode: command not found
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 17523716 kB
MemAvailable 31595148 kB
Buffers 12 kB
Cached 14116920 kB
SwapCached 6252 kB
Command: fdisk -l
./oltp_isql_run_worker.sh: line 45: fdisk: command not found

Server and database settinfs

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


Test configuration settings

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

Test finish info

FINISH_STATE                    NORMAL: TEST_TIME EXPIRED AT 2020-10-09 16:00:43
DTS_END                         2020-10-09 16:00:43.8390
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(56:17)
IP                              ::1/49172
TRN_ID                          248182
ATT_ID                          730
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: 9624.73 21469 1154968
customer order: creation 177.68 333 21322
customer order: refuse 15.01 299 1801
order to supplier: creation 47.13 1098 5656
order to supplier: removal 3.72 81253 446
invoice (draft): creation 46.90 2611 5628
invoice (draft): removal 54.75 653 6570
invoice accept: apply 43.68 18357 5241
invoice accept: cancel 49.93 644 5992
customer reserve: creation 3999.34 185 479921
customer reserve: removal 4889.04 48 586685
realization accept: apply 84.88 158 10185
realization accept: cancel 80.58 99 9669
payment from customer: creation 60.44 99 7253
payment from customer: removal 6.35 68 762
payment to supplier: creation 48.98 125 5878
payment to supplier: removal 3.55 51 426
service: total inventory turnovers 5.25 911 630
service: total monetary turnovers 6.64 39 797
service: aggregate perf. data 0.85 21314 102
service: refresh index statistics 0.03 301031 4

Performance in TOTAL, chart


Completed "Performance in TOTAL". Done for 00:00:03, from 09-10-2020 16:01:40 to 09-10-2020 16:01:43.

Performance for every MINUTE

TEST_PHASE_NAME MINUTES_PASSED PERF_SCORE
TEST_TIME 1 6394
TEST_TIME 2 7839
TEST_TIME 3 7366
TEST_TIME 4 7329
TEST_TIME 5 6758
TEST_TIME 6 6625
TEST_TIME 7 6399
TEST_TIME 8 6662
TEST_TIME 9 6651
TEST_TIME 10 6926
TEST_TIME 11 6951
TEST_TIME 12 7613
TEST_TIME 13 7752
TEST_TIME 14 8299
TEST_TIME 15 8158
TEST_TIME 16 8406
TEST_TIME 17 8774
TEST_TIME 18 8952
TEST_TIME 19 9015
TEST_TIME 20 9142
TEST_TIME 21 9347
TEST_TIME 22 9824
TEST_TIME 23 10109
TEST_TIME 24 10680
TEST_TIME 25 11462
TEST_TIME 26 11220
TEST_TIME 27 11173
TEST_TIME 28 11068
TEST_TIME 29 10815
TEST_TIME 30 10749
TEST_TIME 31 10509
TEST_TIME 32 10291
TEST_TIME 33 10336
TEST_TIME 34 10316
TEST_TIME 35 10203
TEST_TIME 36 10221
TEST_TIME 37 10139
TEST_TIME 38 10129
TEST_TIME 39 10098
TEST_TIME 40 10069
TEST_TIME 41 10000
TEST_TIME 42 10006
TEST_TIME 43 9938
TEST_TIME 44 10197
TEST_TIME 45 10198
TEST_TIME 46 10212
TEST_TIME 47 10221
TEST_TIME 48 10281
TEST_TIME 49 10324
TEST_TIME 50 10301
TEST_TIME 51 10177
TEST_TIME 52 10010
TEST_TIME 53 10034
TEST_TIME 54 10018
TEST_TIME 55 10035
TEST_TIME 56 9957
TEST_TIME 57 9900
TEST_TIME 58 9797
TEST_TIME 59 9826
TEST_TIME 60 9689
TEST_TIME 61 9799
TEST_TIME 62 9750
TEST_TIME 63 9783
TEST_TIME 64 9756
TEST_TIME 65 9821
TEST_TIME 66 9818
TEST_TIME 67 9947
TEST_TIME 68 9972
TEST_TIME 69 9951
TEST_TIME 70 9967
TEST_TIME 71 10061
TEST_TIME 72 10086
TEST_TIME 73 10036
TEST_TIME 74 10121
TEST_TIME 75 9990
TEST_TIME 76 9970
TEST_TIME 77 9909
TEST_TIME 78 9929
TEST_TIME 79 9891
TEST_TIME 80 9844
TEST_TIME 81 9784
TEST_TIME 82 9774
TEST_TIME 83 9696
TEST_TIME 84 9695
TEST_TIME 85 9688
TEST_TIME 86 9694
TEST_TIME 87 9693
TEST_TIME 88 9692
TEST_TIME 89 9673
TEST_TIME 90 9661
TEST_TIME 91 9740
TEST_TIME 92 9772
TEST_TIME 93 9777
TEST_TIME 94 9808
TEST_TIME 95 9837
TEST_TIME 96 9924
TEST_TIME 97 9899
TEST_TIME 98 9859
TEST_TIME 99 9786
TEST_TIME 100 9763
TEST_TIME 101 9709
TEST_TIME 102 9724
TEST_TIME 103 9675
TEST_TIME 104 9636
TEST_TIME 105 9603
TEST_TIME 106 9598
TEST_TIME 107 9576
TEST_TIME 108 9549
TEST_TIME 109 9532
TEST_TIME 110 9562
TEST_TIME 111 9558
TEST_TIME 112 9561
TEST_TIME 113 9610
TEST_TIME 114 9596
TEST_TIME 115 9630
TEST_TIME 116 9602
TEST_TIME 117 9589
TEST_TIME 118 9617
TEST_TIME 119 9606
TEST_TIME 120 9630

Performance per minute, chart


Completed "Performance for every MINUTE". Done for 00:00:03, from 09-10-2020 16:01:44 to 09-10-2020 16:01:47.

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 1600595 1600595 0 0.00 0 27971 6 0 0
doc_list_biud 1600595 1600595 0 0.00 0 40371 23 0 0
sp_add_invoice_to_stock 5366 5241 125 2.32 39 177012 18358 0 125
sp_cancel_adding_invoice 5992 5992 0 0.00 5 47812 644 0 0
sp_cancel_client_order 1801 1801 0 0.00 5 12249 300 0 0
sp_cancel_customer_reserve 586685 586685 0 0.00 1 40372 49 0 0
sp_cancel_pay_from_customer 762 762 0 0.00 2 7199 68 0 0
sp_cancel_pay_to_supplier 426 426 0 0.00 2 3553 51 0 0
sp_cancel_supplier_invoice 6586 6570 16 0.24 2 23103 653 0 16
sp_cancel_supplier_order 446 446 0 0.00 5 721489 81254 0 0
sp_cancel_write_off 9669 9669 0 0.00 1 10741 99 0 0
sp_client_order 21322 21322 0 0.00 3 25647 333 0 0
sp_customer_reserve 479921 479921 0 0.00 0 46115 186 0 0
sp_fill_shopping_cart 32601 32601 0 0.00 1 9549 34 0 0
sp_fill_shopping_cart_clo_res 479908 479908 0 0.00 0 16252 14 0 0
sp_get_clo_for_invoice 5228 5228 0 0.00 0 25255 290 0 0
sp_kill_cost_storno 16849 16849 0 0.00 0 11508 45 0 0
sp_kill_qstorno_ret_qs2qd 1190055 1190055 0 0.00 0 40368 26 0 0
sp_kill_qty_storno 626576 626576 0 0.00 0 40370 57 0 0
sp_lock_selected_doc 21397 21397 0 0.00 0 9073 6 0 0
sp_make_cost_storno 28544 28544 0 0.00 0 21713 49 0 0
sp_multiply_rows_for_pdistr 28544 28544 0 0.00 0 8490 21 0 0
sp_multiply_rows_for_qdistr 21322 21322 0 0.00 0 25637 159 0 0
sp_pay_from_customer 7253 7253 0 0.00 4 18744 99 0 0
sp_pay_to_supplier 5878 5878 0 0.00 5 29737 125 0 0
sp_payment_common 13131 13131 0 0.00 1 18853 37 0 0
sp_qd_handle_on_cancel_clo 1801 1801 0 0.00 0 12238 270 0 0
sp_qd_handle_on_invoice_upd_sts 11220 11220 0 0.00 0 27389 261 0 0
sp_qd_handle_on_reserve_upd_sts 10185 10185 0 0.00 0 11928 53 0 0
sp_reserve_write_off 10185 10185 0 0.00 6 27807 159 0 0
sp_supplier_invoice 5628 5628 0 0.00 6 68232 2611 0 0
sp_supplier_order 5656 5656 0 0.00 5 28714 1098 0 0
srv_aggregate_perf_data 102 102 0 0.00 3168 431182 21315 0 0
srv_fill_mon_cache_memory 62 62 0 0.00 1780 139907 48339 0 0
srv_find_qd_qs_mism 1106430 1106430 0 0.00 0 13124 6 0 0
srv_make_invnt_saldo 630 630 0 0.00 22 60777 911 0 0
srv_make_money_saldo 797 797 0 0.00 0 18402 40 0 0
srv_recalc_idx_stat 4 4 0 0.00 49352 455110 301032 0 0
t$perf-abend:sp_add_invoice_to_stock 125 125 0 0.00 0 0 0 0 0
t$perf-abend:sp_cancel_supplier_invoice 16 16 0 0.00 0 0 0 0 0
t$perf-norm:sp_add_invoice_to_stock 5241 5241 0 0.00 0 14595 145 0 0
t$perf-norm:sp_cancel_adding_invoice 435 435 0 0.00 0 7917 92 0 0
t$perf-norm:sp_cancel_client_order 1801 1801 0 0.00 0 991 8 0 0
t$perf-norm:sp_cancel_customer_reserve 657 657 0 0.00 0 671 7 0 0
t$perf-norm:sp_cancel_pay_from_customer 762 762 0 0.00 0 280 3 0 0
t$perf-norm:sp_cancel_pay_to_supplier 426 426 0 0.00 0 918 9 0 0
t$perf-norm:sp_cancel_supplier_invoice 439 439 0 0.00 0 1299 18 0 0
t$perf-norm:sp_cancel_supplier_order 446 446 0 0.00 0 38094 1511 0 0
t$perf-norm:sp_cancel_write_off 1023 1023 0 0.00 0 10754 21 0 0
t$perf-norm:sp_client_order 21322 21322 0 0.00 0 11423 15 0 0
t$perf-norm:sp_customer_reserve 1024 1024 0 0.00 0 6112 10 0 0
t$perf-norm:sp_pay_from_customer 7253 7253 0 0.00 0 6294 11 0 0
t$perf-norm:sp_pay_to_supplier 5878 5878 0 0.00 0 4550 8 0 0
t$perf-norm:sp_reserve_write_off 10185 10185 0 0.00 0 5272 11 0 0
t$perf-norm:sp_supplier_invoice 5628 5628 0 0.00 0 6187 10 0 0
t$perf-norm:sp_supplier_order 5656 5656 0 0.00 0 11635 16 0 0
t$perf-norm:srv_aggregate_perf_data 102 102 0 0.00 0 99 2 0 0
t$perf-norm:srv_fill_mon_cache_memory 62 62 0 0.00 0 4541 74 0 0
t$perf-norm:srv_make_invnt_saldo 630 630 0 0.00 0 5341 40 0 0
t$perf-norm:srv_make_money_saldo 797 797 0 0.00 0 5917 16 0 0
t$perf-norm:srv_recalc_idx_stat 4 4 0 0.00 1 5 2 0 0
v_add_invoice_to_stock 10696 10446 250 2.33 0 6277 18 0 250
v_all_customers 38308 38308 0 0.00 0 19 0 0 0
v_all_suppliers 30848 30848 0 0.00 0 16 1 0 0
v_all_wares 42644 42644 0 0.00 0 14 1 0 0
v_cancel_adding_invoice 870 870 0 0.00 0 291 5 0 0
v_cancel_client_order 3602 3602 0 0.00 0 6194 6 0 0
v_cancel_customer_prepayment 1524 1524 0 0.00 0 6370 6 0 0
v_cancel_customer_reserve 1314 1314 0 0.00 0 903 4 0 0
v_cancel_payment_to_supplier 852 852 0 0.00 0 3540 7 0 0
v_cancel_supplier_invoice 910 878 32 3.51 0 4111 20 0 32
v_cancel_supplier_order 892 892 0 0.00 0 4194 12 0 0
v_cancel_write_off 2046 2046 0 0.00 0 6367 13 0 0
v_max_id_clo_ord 5654 5654 0 0.00 0 5893 3 0 0
v_max_id_clo_res 1024 1024 0 0.00 0 2139 17 0 0
v_max_id_ord_sup 5625 5625 0 0.00 0 4418 5 0 0
v_max_non_paid_invoice 1733 1733 0 0.00 0 479 2 0 0
v_max_non_paid_realizn 4027 4027 0 0.00 0 9698 8 0 0
v_min_id_clo_ord 5654 5654 0 0.00 0 5072 7 0 0
v_min_id_clo_res 1024 1024 0 0.00 0 1328 5 0 0
v_min_id_ord_sup 5625 5625 0 0.00 0 6992 7 0 0
v_min_non_paid_invoice 5878 5878 0 0.00 0 18849 29 0 0
v_min_non_paid_realizn 7253 7253 0 0.00 0 18728 23 0 0
v_our_firm 10788 10788 0 0.00 0 19 1 0 0
v_reserve_write_off 20370 20370 0 0.00 0 5253 5 0 0
x_lock_depdocs_on_canc_invoice 12123 12123 0 0.00 0 23804 118 0 0
x_lock_depdocs_on_canc_sup_ord 446 446 0 0.00 0 7583 272 0 0
x_make_qstorno_1000_1200 5656 5656 0 0.00 1 28695 1029 0 0
x_make_qstorno_1200_2000 5628 5628 0 0.00 3 67632 2490 0 0
x_make_qstorno_2100_3300 479921 479921 0 0.00 0 42256 170 0 0

Completed "Performance in DETAILS". Done for 00:00:04, from 09-10-2020 16:01:49 to 09-10-2020 16:01:53.

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
13:30:47 4 8192000000 8800800592 8812068864 6918080 0.084 2 1 2 0 7037456 56816 62560
13:31:48 25165 8192000000 10399910112 10728673280 1442306608 14.970 100 86 172 0 1475872768 6126016 27440144
13:33:18 22269 8192000000 10487023392 10824331264 1539581168 15.820 100 90 180 0 1577221120 9009712 28630240
13:34:51 22568 8192000000 10514486640 10869633024 1577469552 16.146 100 82 164 0 1612958336 10081120 25407664
13:36:14 10581 8192000000 10594029328 10956836864 1655308880 16.809 100 78 156 1 1688988672 10536320 23143472
13:37:29 4459 8192000000 10678773952 11046854656 1732035808 17.452 100 88 176 1 1770612784 13890112 24686864
13:38:36 3049 8192000000 10729370112 11109838848 1785105552 17.892 100 84 168 2 1821468672 13022992 23340128
13:39:40 2042 8192000000 10771549952 11158999040 1829604576 18.256 100 89 178 0 1870409696 14979392 25825728
13:40:44 966 8192000000 10815362640 11202097152 1870628240 18.589 100 91 182 0 1910501216 14299504 25573472
13:41:46 6005 8192000000 10786001456 11202949120 1866224736 18.554 100 44 88 0 1887765040 9576864 11963440
13:42:54 10811 8192000000 10784617504 11212623872 1871471088 18.596 100 20 40 1 1882875968 5660896 5743984
13:44:05 11804 8192000000 10783438528 11215314944 1877281664 18.643 100 27 54 3 1891096400 5939184 7875552
13:45:18 29381 8192000000 10800164304 11232919552 1882495376 18.685 100 26 52 2 1895707440 6459456 6752608
13:46:49 7242 8192000000 10811721504 11244126208 1892350832 18.765 100 26 52 2 1905599200 5958416 7289952
13:48:00 8896 8192000000 10814034448 11251208192 1898071776 18.811 100 20 41 1 1912395056 9588128 4735152
13:49:11 62984 8192000000 10778150048 11217289216 1813219328 18.122 96 22 42 3 1829216656 9194464 6802864
13:51:17 6574 8192000000 10721686016 11142209536 1755414336 17.646 96 34 69 0 1771424448 6500944 9509168
13:52:27 11213 8192000000 10688611776 11107381248 1720850816 17.359 96 27 54 1 1734539376 5081136 8607424
13:53:40 23843 8192000000 10695031328 11110658048 1761698528 17.698 98 18 36 2 1772050768 5191824 5160416
13:55:06 5982 8192000000 10730870560 11141009408 1804518960 18.051 100 17 35 4 1815291696 5713232 5059504
13:56:16 6223 8192000000 10743455456 11173175296 1835010656 18.300 100 27 54 1 1849471056 6787936 7672464
13:57:23 9283 8192000000 10759579168 11191787520 1849423728 18.417 100 21 42 4 1860969280 5465808 6079744
13:58:35 9114 8192000000 10766276768 11201937408 1861779056 18.518 100 25 50 0 1874776992 5702720 7295216
13:59:46 23266 8192000000 10796383600 11221590016 1877331264 18.644 100 46 88 0 1895967104 7103408 11532432
14:01:16 3496 8192000000 10856504208 11264225280 1912530368 18.927 100 64 129 4 1940037184 10141808 17365008
14:02:31 7686 8192000000 10871772544 11280867328 1929925328 19.066 100 69 139 0 1961104656 11275392 19903936
14:03:42 28580 8192000000 10847731344 11275272192 1904743184 18.864 98 41 82 1 1927545808 10965536 11837088
14:05:22 21186 8192000000 10873859424 11303256064 1930476704 19.071 99 43 86 1 1952006496 9094016 12435776
14:06:47 17068 8192000000 10911284464 11337060352 1964567456 19.342 100 49 96 1 1991956176 13392576 13996144
14:08:09 7777 8192000000 10905977744 11329933312 1959149472 19.299 100 62 124 0 1994322928 17232864 17940592
14:09:20 6535 8192000000 10898751616 11328049152 1950669520 19.232 99 51 102 1 1981170624 15933568 14567536
14:10:30 6235 8192000000 10948096752 11365744640 1989964640 19.544 100 65 131 0 2030046192 21645520 18436032
14:11:41 6080 8192000000 10897103008 11321323520 1945708640 19.192 100 61 121 2 1989607664 24291648 19607376
14:12:50 1777 8192000000 10920961648 11333660672 1956978656 19.282 100 81 163 0 2010211440 28863328 24369456
14:13:56 1806 8192000000 10935479968 11349999616 1960890832 19.313 100 77 155 1 2018830592 34002752 23937008
14:15:03 4131 8192000000 10919567504 11326590976 1943196560 19.172 100 66 132 2 1995119440 31120144 20802736
14:16:11 5763 8192000000 10879933936 11306557440 1917935824 18.970 100 49 98 2 1969897168 36293936 15667408
14:17:25 1914 8192000000 10916981888 11333734400 1938225312 19.133 100 66 133 4 2001371744 41776560 21369872
14:18:30 10611 8192000000 10888120096 11320639488 1900604752 18.831 98 38 76 1 1948591936 34978912 13008272
14:19:46 15277 8192000000 10916373216 11355467776 1941329424 19.157 99 41 78 5 1995282832 41078592 12874816
14:21:08 25847 8192000000 10886355152 11328315392 1901887504 18.841 97 26 52 2 1949603728 38880528 8835696
14:22:39 20697 8192000000 10894189360 11339304960 1931536304 19.079 100 23 46 2 1980475744 40844928 8094512
14:24:11 22286 8192000000 10885371824 11341086720 1914550128 18.943 99 21 42 1 1966124960 44228240 7346592
14:25:35 84615 8192000000 10864139728 11322736640 1933222192 19.093 100 16 32 1 1953377008 16021600 4133216
14:28:02 34519 8192000000 10863150432 11308560384 1928557440 19.055 100 28 56 2 1943316272 7555360 7203472
14:29:43 51529 8192000000 10868208864 11329986560 1924234528 19.021 99 18 36 0 1939904624 10818480 4851616
14:31:45 50185 8192000000 10905290896 11364708352 1966490544 19.358 100 11 22 1 1991076256 21515168 3070544
14:33:35 67480 8192000000 10883926880 11358015488 1959248912 19.300 99 20 40 0 1980789488 15734880 5805696
14:35:58 46828 8192000000 10883216624 11355213824 1952598352 19.247 99 17 34 0 1965359584 8370720 4390512
14:37:45 64823 8192000000 10898248528 11374333952 1975060336 19.426 100 9 18 1 1989168768 11656096 2452336
14:39:51 71591 8192000000 10929633920 11399798784 1998250576 19.609 100 26 50 2 2016750400 10924016 7575808
14:42:14 63857 8192000000 10950180448 11400896512 2001972432 19.638 100 33 66 0 2028621216 17251984 9396800
14:44:19 83390 8192000000 10930907184 11423522816 1997757664 19.605 100 16 32 1 2024983296 22290048 4935584
14:46:42 89115 8192000000 10929592608 11392139264 1948679168 19.216 97 8 16 0 1969621104 18656576 2285360
14:50:40 99521 8192000000 10910808352 11374338048 1934016768 19.099 97 24 48 0 1954554464 13815152 6722544
14:53:34 53839 8192000000 10905875056 11370401792 1933141152 19.092 97 31 62 1 1960282352 18627728 8513472
14:55:28 71750 8192000000 10879421552 11352825856 1902214832 18.844 96 8 17 0 1910717904 6326240 2176832
14:57:40 59954 8192000000 10893478528 11362283520 1947431744 19.206 98 20 40 1 1962868224 9932928 5503552
14:59:41 76413 8192000000 10877701040 11359416320 1943300608 19.173 99 6 12 0 1958358848 13437168 1621072
15:01:59 29157 8192000000 10875979792 11339673600 1902578160 18.847 97 15 30 1 1917814144 11083232 4152752
15:04:06 37416 8192000000 10889040000 11352801280 1938529552 19.135 99 19 38 1 1955204208 11039536 5635120
15:05:47 64088 8192000000 10909398704 11371462656 1931784608 19.081 98 24 48 1 1956963104 18195568 6982928
15:07:52 40370 8192000000 10907724480 11361308672 1945878880 19.194 99 26 52 0 1964173280 11456080 6838320
15:09:34 34350 8192000000 10902938112 11344879616 1917530368 18.967 98 37 72 0 1938206320 10651248 10024704
15:11:10 113569 8192000000 10839943712 11299692544 1788638272 17.921 93 16 32 1 1805702912 12870480 4194160
15:14:07 118197 8192000000 10835570944 11286999040 1844196384 18.375 96 23 46 1 1865962272 14951712 6814176
15:17:21 55357 8192000000 10847936544 11323805696 1925747984 19.033 100 14 27 1 1945572224 16031312 3792928
15:19:40 43905 8192000000 10858032848 11334778880 1940731360 19.153 100 7 14 0 1950915616 8644656 1539600
15:21:24 90062 8192000000 10882250768 11353640960 1936483008 19.119 99 20 40 1 1954660416 12200640 5976768
15:25:09 53493 8192000000 10884912944 11364773888 1970225664 19.387 100 14 28 1 1982216288 7935504 4055120
15:27:26 35704 8192000000 10895982304 11361083392 1956097504 19.275 99 20 40 1 1970131696 8422960 5611232
15:29:03 72228 8192000000 10931500352 11376947200 1977222272 19.443 100 34 68 2 2001935440 14949056 9764112
15:31:17 138999 8192000000 10925485712 11404500992 1992117408 19.561 100 9 18 0 2006348720 12391072 1840240
15:34:37 139907 8192000000 10932122976 11423449088 1995451808 19.587 100 10 20 0 2017371856 19491280 2428768
15:37:57 34008 8192000000 10931410192 11383197696 1971832736 19.400 99 28 56 2 1988686848 9208368 7645744
15:39:32 102147 8192000000 10914731584 11373539328 1936489568 19.119 97 26 50 0 1951502080 8382544 6629968
15:42:22 47109 8192000000 10881121168 11366178816 1956142896 19.275 99 4 8 0 1966135536 8669456 1323184
15:44:10 59280 8192000000 10898244480 11369201664 1941975488 19.163 98 14 28 0 1956847584 10818256 4053840
15:46:11 89282 8192000000 10864430912 11350835200 1937023968 19.123 98 15 30 0 1952471408 11011360 4436080
15:48:40 39488 8192000000 10869837808 11339104256 1947402944 19.206 99 18 36 1 1960227696 7708720 5116032
15:50:22 28930 8192000000 10872287408 11338682368 1923738640 19.017 98 18 36 0 1936295808 7281152 5276016
15:51:57 24583 8192000000 10877413392 11334037504 1915957792 18.954 98 38 76 0 1937874752 11282784 10634176
15:53:33 99282 8192000000 10877695056 11333746688 1827230624 18.237 93 23 46 0 1845977040 12521376 6225040
15:56:48 14278 8192000000 10834054784 11270385664 1842000240 18.357 97 38 76 0 1861860384 8956288 10903856
15:58:06 52511 8192000000 10814422384 11275276288 1859273120 18.497 98 29 58 0 1878919056 11991312 7654624
15:59:59 55060 8192000000 9393083232 9685417984 538933472 6.172 29 4 8 0 548875584 8880864 1061248

Memory consumption, total, chart

Metadata cache size, chart

Statements activity, chart


Completed "Memory consumption, metadata cache, attachments activity". Done for 00:00:15, from 09-10-2020 16:01:54 to 09-10-2020 16:02:09.

Exceptions occured during test was in run

FB_MNEMONA CNT UNIT FB_GDSCODE
user_exc 125 v_add_invoice_to_stock 335544517
user_exc 16 v_cancel_supplier_invoice 335544517

Completed "Exceptions occured during test was in run". Done for 00:00:02, from 09-10-2020 16:02:10 to 09-10-2020 16:02:12.

Content of mon$database and FB version

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


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

Database statistics

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

Database validation

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

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

--- start of diff output ---
:6: 
:7: mscs-test-161.budzdorov.ru    Fri Oct  9 16:00:57 2020
:8:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3333
:9: 
--- end of diff output ---

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

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