Generated by /opt/oltp-emul/oltp_isql_run_worker.sh, ISQL session No. 1 of total launched 100. 10.10.2020 06:57
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 16723000 kB
MemAvailable 31589880 kB
Buffers 12 kB
Cached 14897940 kB
SwapCached 6060 kB
Command: fdisk -l
./oltp_isql_run_worker.sh: line 45: fdisk: command not found

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-10 06:56:50
DTS_END                         2020-10-10 06:56:50.7060
FB_GDSCODE                      -1
FB_MNEMONA                      
STACK                           SP_SUPPLIER_INVOICE(39:5) ==> SP_CHECK_TO_STOP_WORK(32:12) ==> SP_HALT_ON_ERROR(67:17)
IP                              ::1/35974
TRN_ID                          236226
ATT_ID                          651
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: 9099.36 28894 1091923
customer order: creation 155.78 397 18693
customer order: refuse 14.06 351 1687
order to supplier: creation 43.34 1425 5201
order to supplier: removal 3.36 133332 403
invoice (draft): creation 43.34 3754 5201
invoice (draft): removal 52.50 1076 6300
invoice accept: apply 39.62 18315 4754
invoice accept: cancel 48.01 896 5761
customer reserve: creation 3719.11 175 446293
customer reserve: removal 4697.51 73 563701
realization accept: apply 76.58 182 9189
realization accept: cancel 86.09 118 10331
payment from customer: creation 55.50 90 6660
payment from customer: removal 5.56 76 667
payment to supplier: creation 45.12 124 5414
payment to supplier: removal 3.64 67 437
service: total inventory turnovers 3.55 3545 426
service: total monetary turnovers 5.82 570 698
service: aggregate perf. data 0.85 16701 102
service: refresh index statistics 0.04 396611 5

Performance in TOTAL, chart


Completed "Performance in TOTAL". Done for 00:00:02, from 10-10-2020 06:57:47 to 10-10-2020 06:57:49.

Performance for every MINUTE

TEST_PHASE_NAME MINUTES_PASSED PERF_SCORE
TEST_TIME 1 2524
TEST_TIME 2 1826
TEST_TIME 3 2405
TEST_TIME 4 2954
TEST_TIME 5 3499
TEST_TIME 6 3775
TEST_TIME 7 4358
TEST_TIME 8 4773
TEST_TIME 9 4739
TEST_TIME 10 5341
TEST_TIME 11 5643
TEST_TIME 12 5861
TEST_TIME 13 5955
TEST_TIME 14 6432
TEST_TIME 15 6473
TEST_TIME 16 6626
TEST_TIME 17 6544
TEST_TIME 18 6621
TEST_TIME 19 7153
TEST_TIME 20 7520
TEST_TIME 21 7836
TEST_TIME 22 8521
TEST_TIME 23 8554
TEST_TIME 24 8416
TEST_TIME 25 8629
TEST_TIME 26 9001
TEST_TIME 27 9802
TEST_TIME 28 11515
TEST_TIME 29 11188
TEST_TIME 30 11327
TEST_TIME 31 11482
TEST_TIME 32 11202
TEST_TIME 33 11133
TEST_TIME 34 10959
TEST_TIME 35 10836
TEST_TIME 36 10790
TEST_TIME 37 10944
TEST_TIME 38 10790
TEST_TIME 39 10747
TEST_TIME 40 10647
TEST_TIME 41 10606
TEST_TIME 42 10753
TEST_TIME 43 10678
TEST_TIME 44 10567
TEST_TIME 45 10497
TEST_TIME 46 10371
TEST_TIME 47 10176
TEST_TIME 48 10156
TEST_TIME 49 10138
TEST_TIME 50 10052
TEST_TIME 51 9955
TEST_TIME 52 9879
TEST_TIME 53 9770
TEST_TIME 54 9749
TEST_TIME 55 9750
TEST_TIME 56 9752
TEST_TIME 57 9778
TEST_TIME 58 9849
TEST_TIME 59 9918
TEST_TIME 60 9866
TEST_TIME 61 9911
TEST_TIME 62 9865
TEST_TIME 63 9847
TEST_TIME 64 9784
TEST_TIME 65 9824
TEST_TIME 66 9773
TEST_TIME 67 9909
TEST_TIME 68 9925
TEST_TIME 69 9853
TEST_TIME 70 9773
TEST_TIME 71 9732
TEST_TIME 72 9652
TEST_TIME 73 9624
TEST_TIME 74 9541
TEST_TIME 75 9436
TEST_TIME 76 9393
TEST_TIME 77 9339
TEST_TIME 78 9480
TEST_TIME 79 9457
TEST_TIME 80 9405
TEST_TIME 81 9468
TEST_TIME 82 9501
TEST_TIME 83 9560
TEST_TIME 84 9551
TEST_TIME 85 9563
TEST_TIME 86 9590
TEST_TIME 87 9575
TEST_TIME 88 9645
TEST_TIME 89 9573
TEST_TIME 90 9484
TEST_TIME 91 9422
TEST_TIME 92 9359
TEST_TIME 93 9319
TEST_TIME 94 9370
TEST_TIME 95 9335
TEST_TIME 96 9352
TEST_TIME 97 9326
TEST_TIME 98 9296
TEST_TIME 99 9292
TEST_TIME 100 9275
TEST_TIME 101 9312
TEST_TIME 102 9281
TEST_TIME 103 9337
TEST_TIME 104 9380
TEST_TIME 105 9424
TEST_TIME 106 9361
TEST_TIME 107 9295
TEST_TIME 108 9273
TEST_TIME 109 9224
TEST_TIME 110 9180
TEST_TIME 111 9181
TEST_TIME 112 9152
TEST_TIME 113 9174
TEST_TIME 114 9166
TEST_TIME 115 9167
TEST_TIME 116 9179
TEST_TIME 117 9178
TEST_TIME 118 9125
TEST_TIME 119 9153
TEST_TIME 120 9104

Performance per minute, chart


Completed "Performance for every MINUTE". Done for 00:00:03, from 10-10-2020 06:57:51 to 10-10-2020 06:57:54.

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 1503693 1503693 0 0.00 0 25287 7 0 0
doc_list_biud 1503690 1503690 0 0.00 0 64049 35 0 0
sp_add_invoice_to_stock 4845 4754 91 1.87 35 212694 18315 0 91
sp_cancel_adding_invoice 5761 5761 0 0.00 5 56182 897 0 0
sp_cancel_client_order 1687 1687 0 0.00 4 24037 351 0 0
sp_cancel_customer_reserve 563701 563701 0 0.00 1 20384 74 0 0
sp_cancel_pay_from_customer 667 667 0 0.00 3 4552 77 0 0
sp_cancel_pay_to_supplier 437 437 0 0.00 3 2881 68 0 0
sp_cancel_supplier_invoice 6309 6300 9 0.14 2 64055 1077 0 9
sp_cancel_supplier_order 403 403 0 0.00 7 1145807 133332 0 0
sp_cancel_write_off 10331 10331 0 0.00 1 20092 118 0 0
sp_client_order 18693 18693 0 0.00 4 26330 397 0 0
sp_customer_reserve 446293 446293 0 0.00 0 165681 175 0 0
sp_fill_shopping_cart 29090 29090 0 0.00 1 22607 50 0 0
sp_fill_shopping_cart_clo_res 446281 446281 0 0.00 0 30460 18 0 0
sp_get_clo_for_invoice 4742 4742 0 0.00 0 37453 485 0 0
sp_kill_cost_storno 17196 17196 0 0.00 0 6444 58 0 0
sp_kill_qstorno_ret_qs2qd 1144436 1144436 0 0.00 0 64048 40 0 0
sp_kill_qty_storno 602114 602114 0 0.00 0 64049 86 0 0
sp_lock_selected_doc 19454 19454 0 0.00 0 13460 6 0 0
sp_make_cost_storno 26005 26005 0 0.00 0 25273 55 0 0
sp_multiply_rows_for_pdistr 26005 26005 0 0.00 0 10659 31 0 0
sp_multiply_rows_for_qdistr 18693 18693 0 0.00 0 26323 220 0 0
sp_pay_from_customer 6660 6660 0 0.00 4 13741 91 0 0
sp_pay_to_supplier 5414 5414 0 0.00 5 16587 125 0 0
sp_payment_common 12074 12074 0 0.00 1 13223 21 0 0
sp_qd_handle_on_cancel_clo 1687 1687 0 0.00 0 24028 323 0 0
sp_qd_handle_on_invoice_upd_sts 10503 10503 0 0.00 0 31239 424 0 0
sp_qd_handle_on_reserve_upd_sts 9189 9189 0 0.00 0 14758 53 0 0
sp_reserve_write_off 9189 9189 0 0.00 7 17502 183 0 0
sp_supplier_invoice 5201 5201 0 0.00 7 106426 3754 0 0
sp_supplier_order 5201 5201 0 0.00 6 94710 1426 0 0
srv_aggregate_perf_data 102 102 0 0.00 2804 190100 16701 0 0
srv_fill_mon_cache_memory 61 61 0 0.00 2117 184561 51679 0 0
srv_find_qd_qs_mism 1046319 1046319 0 0.00 0 20036 6 0 0
srv_make_invnt_saldo 426 426 0 0.00 77 115804 3545 0 0
srv_make_money_saldo 698 698 0 0.00 1 13117 571 0 0
srv_recalc_idx_stat 5 5 0 0.00 199916 562907 396612 0 0
t$perf-abend:sp_add_invoice_to_stock 91 91 0 0.00 0 0 0 0 0
t$perf-abend:sp_cancel_supplier_invoice 9 9 0 0.00 0 0 0 0 0
t$perf-norm:sp_add_invoice_to_stock 4754 4754 0 0.00 0 16033 195 0 0
t$perf-norm:sp_cancel_adding_invoice 379 379 0 0.00 0 20873 157 0 0
t$perf-norm:sp_cancel_client_order 1687 1687 0 0.00 0 1500 12 0 0
t$perf-norm:sp_cancel_customer_reserve 643 643 0 0.00 0 683 9 0 0
t$perf-norm:sp_cancel_pay_from_customer 667 667 0 0.00 0 983 4 0 0
t$perf-norm:sp_cancel_pay_to_supplier 437 437 0 0.00 0 1517 6 0 0
t$perf-norm:sp_cancel_supplier_invoice 392 392 0 0.00 0 7265 39 0 0
t$perf-norm:sp_cancel_supplier_order 403 403 0 0.00 0 19996 1804 0 0
t$perf-norm:sp_cancel_write_off 915 915 0 0.00 0 790 6 0 0
t$perf-norm:sp_client_order 18693 18693 0 0.00 0 9200 18 0 0
t$perf-norm:sp_customer_reserve 979 979 0 0.00 0 1930 8 0 0
t$perf-norm:sp_pay_from_customer 6660 6660 0 0.00 0 9700 15 0 0
t$perf-norm:sp_pay_to_supplier 5414 5414 0 0.00 0 3463 6 0 0
t$perf-norm:sp_reserve_write_off 9189 9189 0 0.00 0 7166 11 0 0
t$perf-norm:sp_supplier_invoice 5201 5201 0 0.00 0 4409 18 0 0
t$perf-norm:sp_supplier_order 5201 5201 0 0.00 0 7152 23 0 0
t$perf-norm:srv_aggregate_perf_data 102 102 0 0.00 0 255 3 0 0
t$perf-norm:srv_fill_mon_cache_memory 61 61 0 0.00 0 863 22 0 0
t$perf-norm:srv_make_invnt_saldo 426 426 0 0.00 0 1101 16 0 0
t$perf-norm:srv_make_money_saldo 698 698 0 0.00 0 692 8 0 0
t$perf-norm:srv_recalc_idx_stat 5 5 0 0.00 1 10 4 0 0
v_add_invoice_to_stock 9666 9484 182 1.88 0 10047 19 0 182
v_all_customers 34498 34498 0 0.00 0 17 1 0 0
v_all_suppliers 28540 28540 0 0.00 0 20 1 0 0
v_all_wares 37386 37386 0 0.00 0 164 1 0 0
v_cancel_adding_invoice 758 758 0 0.00 0 4658 14 0 0
v_cancel_client_order 3374 3374 0 0.00 0 2507 5 0 0
v_cancel_customer_prepayment 1334 1334 0 0.00 0 4152 9 0 0
v_cancel_customer_reserve 1286 1286 0 0.00 0 1099 5 0 0
v_cancel_payment_to_supplier 874 874 0 0.00 0 1204 7 0 0
v_cancel_supplier_invoice 802 784 18 2.24 0 209 10 0 18
v_cancel_supplier_order 806 806 0 0.00 0 3539 8 0 0
v_cancel_write_off 1830 1830 0 0.00 0 926 12 0 0
v_max_id_clo_ord 5198 5198 0 0.00 0 4729 2 0 0
v_max_id_clo_res 979 979 0 0.00 0 4207 10 0 0
v_max_id_ord_sup 5199 5199 0 0.00 0 3358 5 0 0
v_max_non_paid_invoice 1536 1536 0 0.00 0 48 2 0 0
v_max_non_paid_realizn 3431 3431 0 0.00 0 2759 3 0 0
v_min_id_clo_ord 5198 5198 0 0.00 0 2654 5 0 0
v_min_id_clo_res 979 979 0 0.00 0 7209 33 0 0
v_min_id_ord_sup 5199 5199 0 0.00 0 7474 24 0 0
v_min_non_paid_invoice 5414 5414 0 0.00 0 13220 18 0 0
v_min_non_paid_realizn 6660 6660 0 0.00 0 4619 11 0 0
v_our_firm 9346 9346 0 0.00 0 85 1 0 0
v_reserve_write_off 18378 18378 0 0.00 0 4343 5 0 0
x_lock_depdocs_on_canc_invoice 11669 11669 0 0.00 0 14804 124 0 0
x_lock_depdocs_on_canc_sup_ord 403 403 0 0.00 0 5607 399 0 0
x_make_qstorno_1000_1200 5201 5201 0 0.00 2 94589 1349 0 0
x_make_qstorno_1200_2000 5201 5201 0 0.00 3 106416 3559 0 0
x_make_qstorno_2100_3300 446293 446293 0 0.00 0 165680 155 0 0

Completed "Performance in DETAILS". Done for 00:00:04, from 10-10-2020 06:57:55 to 10-10-2020 06:57:59.

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
04:26:54 2 8192000000 8796624000 8807108608 3156752 0.038 1 1 2 0 3254112 61504 35856
04:27:55 20605 8192000000 9718515968 10013593600 792887568 8.824 100 85 168 2 821381152 7719088 20774496
04:29:20 17461 8192000000 9763385920 10071048192 840871488 9.309 100 83 166 0 872072864 11973328 19228048
04:30:44 9417 8192000000 9803596544 10120134656 870922288 9.609 100 79 158 0 912936304 23994896 18019120
04:31:59 10136 8192000000 9868455536 10201137152 916725008 10.064 100 83 166 2 982780544 47965792 18089744
04:33:14 10575 8192000000 9919988304 10267152384 961836784 10.507 100 81 160 1 1035906800 57347872 16722144
04:34:28 5215 8192000000 9964585104 10317455360 991377696 10.795 100 79 158 1 1066385472 59377088 15630688
04:35:36 2721 8192000000 10017572336 10377924608 1024396336 11.114 100 89 176 3 1118981824 76600384 17985104
04:36:39 1908 8192000000 10020175536 10389655552 1047338368 11.335 100 89 180 2 1128781648 62742448 18700832
04:37:42 22698 8192000000 10032622432 10410655744 1063169760 11.487 100 63 126 2 1140583456 65016816 12396880
04:39:06 7738 8192000000 10008842800 10402996224 1078050944 11.629 100 49 98 3 1124021920 35317744 10653232
04:40:17 2611 8192000000 10019979728 10419085312 1080354032 11.651 100 37 74 2 1134317824 46611424 7352368
04:41:19 7424 8192000000 9996487104 10397196288 1088304448 11.727 100 33 65 2 1118658144 23830064 6523632
04:42:27 27297 8192000000 10004394704 10423848960 1092256304 11.764 100 36 69 4 1117004560 17270464 7477792
04:43:55 9237 8192000000 9999191712 10408333312 1093688560 11.778 100 13 26 1 1122649968 26172240 2789168
04:45:06 6249 8192000000 9991430160 10382200832 1080861072 11.656 99 32 60 3 1101921872 14262400 6798400
04:46:13 7379 8192000000 9987977248 10381639680 1071980448 11.571 99 39 77 2 1097273760 16501168 8792144
04:47:20 42967 8192000000 9959426832 10368638976 1035715968 11.223 97 28 56 1 1063547136 21652736 6178432
04:49:07 5908 8192000000 9950410320 10330062848 1009381856 10.969 98 53 106 1 1055677888 33966128 12329904
04:50:13 10530 8192000000 9941981008 10328637440 1004626112 10.923 98 22 43 1 1021611040 12665840 4319088
04:51:27 14095 8192000000 9954097248 10342174720 1033403904 11.201 100 36 71 0 1061331744 19741360 8186480
04:52:41 29040 8192000000 9938570096 10339840000 1043458704 11.298 100 30 60 2 1065311424 14745392 7107328
04:54:12 6260 8192000000 9972783792 10361643008 1060136816 11.458 100 26 50 3 1087308592 21936512 5235264
04:55:22 6540 8192000000 9984482736 10380058624 1065801232 11.512 100 36 70 1 1095778992 22221328 7756432
04:56:29 8745 8192000000 9964750304 10362884096 1060732880 11.463 99 32 63 1 1085221808 17218336 7270592
04:57:45 105630 8192000000 10042846848 10442579968 1089179008 11.735 100 45 90 2 1120675296 22285696 9210592
05:00:35 23875 8192000000 10098043136 10498654208 1108193312 11.915 100 48 94 0 1206727808 89199760 9334736
05:02:03 6231 8192000000 10118186304 10520002560 1126670000 12.090 100 47 92 3 1226242496 89364128 10208368
05:03:20 9466 8192000000 10176992352 10580074496 1134589824 12.165 100 59 117 2 1286266032 138521776 13154432
05:04:32 17671 8192000000 10175040608 10585858048 1134512224 12.164 100 47 93 1 1295600784 151110496 9978064
05:05:56 5993 8192000000 10242695936 10645331968 1150732096 12.316 100 69 137 2 1346738416 179860400 16145920
05:07:09 12187 8192000000 10258114800 10674556928 1163993024 12.441 100 58 116 3 1375519248 198540272 12985952
05:08:27 5250 8192000000 10277792080 10686128128 1154250864 12.349 99 72 141 1 1374131536 203535136 16345536
05:09:38 3918 8192000000 10326546864 10719346688 1150415472 12.313 100 84 168 1 1427499392 258081568 19002352
05:10:47 3668 8192000000 10347372240 10758631424 1160662656 12.409 100 73 143 3 1446284496 269414464 16207376
05:11:59 3513 8192000000 10365699040 10751803392 1144005584 12.253 99 88 175 1 1458995120 294355792 20633744
05:13:07 3354 8192000000 10425455344 10819137536 1155418496 12.360 100 75 150 0 1522631280 349132752 18080032
05:14:16 2117 8192000000 10528449296 10932465664 1169888576 12.496 100 86 169 0 1627868544 437376208 20603760
05:15:22 4040 8192000000 10595728928 11030589440 1180620816 12.596 100 70 137 2 1688160912 490580704 16959392
05:16:36 3564 8192000000 10521969648 10928328704 1140215568 12.218 98 74 147 0 1602603952 444246064 18142320
05:17:49 14138 8192000000 10554815232 11022680064 1178678768 12.578 100 52 104 0 1684059616 492082480 13298368
05:19:27 19065 8192000000 10516127952 10982256640 1175262096 12.546 100 38 76 1 1625349280 440295520 9791664
05:21:11 12060 8192000000 10581297392 11023368192 1152334912 12.331 100 38 76 1 1681855392 519371648 10148832
05:22:35 32303 8192000000 10543235440 11023622144 1133163312 12.151 100 32 64 1 1649976304 507539520 9273472
05:24:17 42505 8192000000 10138937968 10617012224 1135737920 12.175 99 22 44 1 1332341872 190726256 5877696
05:26:01 75684 8192000000 10130850528 10665152512 1130042688 12.122 99 25 51 3 1254966352 118697424 6226240
05:28:19 63169 8192000000 10071867776 10525978624 1109146656 11.924 98 27 52 1 1144976640 29546736 6283248
05:30:24 68620 8192000000 10100176848 10527526912 1066809968 11.522 94 17 34 0 1108450672 38482640 3158064
05:32:33 184560 8192000000 10064594176 10521112576 1093617760 11.777 97 4 8 0 1161055712 66746816 691136
05:36:39 135782 8192000000 10096089008 10603466752 1111858768 11.950 98 10 20 1 1162632336 48997504 1776064
05:39:56 43380 8192000000 10081673856 10500153344 1094113792 11.782 97 20 40 1 1148278672 49934480 4230400
05:41:39 133776 8192000000 10082818272 10511126528 1125152848 12.076 100 21 42 0 1191126112 61807840 4165424
05:44:56 36096 8192000000 10077395376 10506096640 1137466096 12.192 100 62 121 3 1170562992 21276368 11820528
05:46:32 168466 8192000000 10127298208 10585112576 1100222928 11.840 95 17 34 1 1163029056 59517376 3288752
05:50:21 63883 8192000000 10169876960 10623270912 1159160544 12.395 100 20 40 1 1263499152 99489488 4849120
05:52:27 60697 8192000000 10123457456 10570604544 1124546992 12.070 97 21 42 0 1224260944 94361968 5351984
05:54:28 31723 8192000000 10107584656 10539864064 1139058880 12.207 99 33 66 1 1177993696 32351856 6582960
05:56:05 34670 8192000000 10081386656 10518376448 1104302768 11.878 96 19 38 0 1128260000 20147776 3809456
05:57:40 43603 8192000000 10079968528 10506342400 1136952656 12.187 100 18 36 1 1172630624 31647328 4030640
05:59:28 22517 8192000000 10096120320 10531688448 1143898352 12.252 100 28 55 2 1201873520 51837792 6137376
06:00:56 44252 8192000000 10076377808 10525040640 1077252688 11.621 95 20 40 1 1151125136 69679088 4193360
06:02:45 53764 8192000000 10159622784 10663108608 1141583504 12.230 100 20 39 3 1268090624 121860832 4646288
06:04:46 114743 8192000000 10056409712 10482401280 1064486672 11.499 94 28 56 0 1101370768 30451408 6432688
06:07:42 44152 8192000000 10059010112 10522279936 1102656448 11.863 99 7 14 0 1153596576 49570560 1369568
06:09:30 39800 8192000000 10065334272 10538975232 1113067872 11.961 100 11 22 2 1154685392 39834320 1783200
06:11:16 91683 8192000000 10134728672 10587029504 1119993456 12.027 99 14 28 1 1226329520 102993824 3342240
06:14:02 78741 8192000000 10089567328 10576068608 1100782208 11.845 98 15 30 1 1199381328 95040096 3559024
06:16:26 80587 8192000000 10122549184 10620317696 1114482432 11.975 99 15 30 0 1172260160 54705488 3072240
06:19:01 59813 8192000000 10074967152 10564780032 1107274240 11.907 98 20 40 1 1194353728 83280672 3798816
06:21:01 42870 8192000000 10069004752 10489315328 1115504144 11.984 99 32 64 2 1171779408 50111680 6163584
06:22:50 36595 8192000000 10117564960 10541957120 1124872000 12.073 99 37 74 1 1184123088 52006000 7245088
06:24:31 46897 8192000000 10085381600 10565804032 1120223200 12.029 99 27 54 0 1200985584 75469296 5293088
06:26:38 65014 8192000000 10059881008 10509524992 1120064704 12.028 99 18 36 1 1165423600 41476256 3882640
06:29:17 74562 8192000000 10100689344 10582847488 1131426976 12.135 100 4 8 0 1202405904 70110576 868352
06:31:44 60093 8192000000 10074009840 10537365504 1125722288 12.081 99 13 26 0 1178751600 50312384 2716928
06:33:44 50356 8192000000 10101023824 10544906240 1128401040 12.106 99 25 50 3 1164472848 30767344 5304464
06:35:35 72091 8192000000 10127882176 10579476480 1127809680 12.101 98 19 38 0 1220655728 88845456 4000592
06:37:48 63264 8192000000 10134379296 10568138752 1116858288 11.997 97 20 40 1 1192219696 70508160 4853248
06:39:58 82920 8192000000 10107663664 10620964864 1125553648 12.079 99 11 22 0 1221160384 93419856 2186880
06:42:30 112541 8192000000 10051410992 10526978048 1120598816 12.033 100 15 31 0 1175084416 51409024 3076576
06:45:38 47918 8192000000 10072426192 10551214080 1120249936 12.029 99 7 14 0 1159646368 38109712 1286720
06:47:26 46164 8192000000 10047127920 10489839616 1121720304 12.043 99 16 32 1 1161350144 36193040 3436800
06:49:16 74936 8192000000 10069782960 10556145664 1107345696 11.907 97 16 33 1 1184490208 73628448 3516064
06:51:32 52340 8192000000 10090846304 10556899328 1138112736 12.198 100 15 28 1 1193481232 52610208 2758288
06:53:24 56442 8192000000 10080407872 10516058112 1135463536 12.173 100 21 42 2 1187552768 47461904 4627328
06:55:23 62553 8192000000 10086420096 10528608256 1090358544 11.746 96 19 38 0 1150769632 56612704 3798384

Memory consumption, total, chart

Metadata cache size, chart

Statements activity, chart


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

Exceptions occured during test was in run

FB_MNEMONA CNT UNIT FB_GDSCODE
user_exc 91 v_add_invoice_to_stock 335544517
user_exc 9 v_cancel_supplier_invoice 335544517

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

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          234308
MON$OLDEST_ACTIVE               236335
MON$OLDEST_SNAPSHOT             236335
MON$NEXT_TRANSACTION            236335
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                       2125440
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             783
MON$NEXT_STATEMENT              53


ISQL Version: LI-V4.0.0.2223 Firebird 4.0 Release Candidate 1
Server version:
Firebird/Linux/AMD/Intel/x64 (access method), version "LI-V4.0.0.2223 Firebird 4.0 Release Candidate 1"
Firebird/Linux/AMD/Intel/x64 (remote server), version "LI-V4.0.0.2223 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.2223 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 ---
:27: 
:28: mscs-test-161.budzdorov.ru    Sat Oct 10 06:56:51 2020
:29:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:30: 
:31: 
:32: mscs-test-161.budzdorov.ru    Sat Oct 10 06:56:56 2020
:33:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:34: 
--- end of diff output ---

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

10.10.20 06:58:20. 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-10 06:58:22 No severe PSQL-related problems occured
10.10.20 06:58:24. End of report.