Generated by /opt/oltp-emul/oltp_isql_run_worker.sh, ISQL session No. 1 of total launched 100. 10.10.2020 04:07
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 16621692 kB
MemAvailable 31564300 kB
Buffers 20 kB
Cached 14950868 kB
SwapCached 6068 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 04:06:28
DTS_END                         2020-10-10 04:06:28.1040
FB_GDSCODE                      -1
FB_MNEMONA                      
STACK                           SP_CLIENT_ORDER(57:5) ==> SP_CHECK_TO_STOP_WORK(32:12) ==> SP_HALT_ON_ERROR(67:17)
IP                              ::1/34134
TRN_ID                          241032
ATT_ID                          680
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: 9222.09 17920 1106651
customer order: creation 177.00 376 21240
customer order: refuse 15.08 304 1810
order to supplier: creation 46.57 1447 5588
order to supplier: removal 3.50 117853 420
invoice (draft): creation 45.95 3697 5514
invoice (draft): removal 52.35 951 6282
invoice accept: apply 41.95 16225 5034
invoice accept: cancel 47.77 922 5732
customer reserve: creation 3837.42 160 460490
customer reserve: removal 4656.44 70 558773
realization accept: apply 83.83 158 10060
realization accept: cancel 84.09 102 10091
payment from customer: creation 59.08 102 7089
payment from customer: removal 6.05 90 726
payment to supplier: creation 50.26 117 6031
payment to supplier: removal 3.50 71 420
service: total inventory turnovers 4.01 3297 481
service: total monetary turnovers 6.32 561 758
service: aggregate perf. data 0.89 17281 107
service: refresh index statistics 0.04 194621 5

Performance in TOTAL, chart


Completed "Performance in TOTAL". Done for 00:00:02, from 10-10-2020 04:07:24 to 10-10-2020 04:07:26.

Performance for every MINUTE

TEST_PHASE_NAME MINUTES_PASSED PERF_SCORE
TEST_TIME 1 5589
TEST_TIME 2 6627
TEST_TIME 3 6733
TEST_TIME 4 6357
TEST_TIME 5 6364
TEST_TIME 6 6429
TEST_TIME 7 6361
TEST_TIME 8 6220
TEST_TIME 9 6687
TEST_TIME 10 6417
TEST_TIME 11 6745
TEST_TIME 12 7075
TEST_TIME 13 7279
TEST_TIME 14 7671
TEST_TIME 15 7717
TEST_TIME 16 7715
TEST_TIME 17 8040
TEST_TIME 18 7966
TEST_TIME 19 8007
TEST_TIME 20 8779
TEST_TIME 21 9038
TEST_TIME 22 9441
TEST_TIME 23 9603
TEST_TIME 24 10043
TEST_TIME 25 10433
TEST_TIME 26 10653
TEST_TIME 27 11693
TEST_TIME 28 11459
TEST_TIME 29 11412
TEST_TIME 30 11227
TEST_TIME 31 11467
TEST_TIME 32 11444
TEST_TIME 33 11306
TEST_TIME 34 11147
TEST_TIME 35 11223
TEST_TIME 36 11152
TEST_TIME 37 11163
TEST_TIME 38 11087
TEST_TIME 39 11171
TEST_TIME 40 11096
TEST_TIME 41 10885
TEST_TIME 42 10711
TEST_TIME 43 10538
TEST_TIME 44 10422
TEST_TIME 45 10299
TEST_TIME 46 10232
TEST_TIME 47 10243
TEST_TIME 48 10317
TEST_TIME 49 10207
TEST_TIME 50 10169
TEST_TIME 51 10089
TEST_TIME 52 9924
TEST_TIME 53 10098
TEST_TIME 54 10029
TEST_TIME 55 10017
TEST_TIME 56 10092
TEST_TIME 57 10032
TEST_TIME 58 10119
TEST_TIME 59 10047
TEST_TIME 60 10128
TEST_TIME 61 10213
TEST_TIME 62 10188
TEST_TIME 63 10340
TEST_TIME 64 10310
TEST_TIME 65 10275
TEST_TIME 66 10128
TEST_TIME 67 10068
TEST_TIME 68 10034
TEST_TIME 69 9956
TEST_TIME 70 9919
TEST_TIME 71 9879
TEST_TIME 72 9820
TEST_TIME 73 9775
TEST_TIME 74 9725
TEST_TIME 75 9662
TEST_TIME 76 9685
TEST_TIME 77 9736
TEST_TIME 78 9861
TEST_TIME 79 9946
TEST_TIME 80 9943
TEST_TIME 81 9884
TEST_TIME 82 10036
TEST_TIME 83 9935
TEST_TIME 84 9854
TEST_TIME 85 9803
TEST_TIME 86 9738
TEST_TIME 87 9692
TEST_TIME 88 9626
TEST_TIME 89 9549
TEST_TIME 90 9518
TEST_TIME 91 9495
TEST_TIME 92 9530
TEST_TIME 93 9492
TEST_TIME 94 9487
TEST_TIME 95 9466
TEST_TIME 96 9434
TEST_TIME 97 9470
TEST_TIME 98 9434
TEST_TIME 99 9498
TEST_TIME 100 9469
TEST_TIME 101 9504
TEST_TIME 102 9470
TEST_TIME 103 9507
TEST_TIME 104 9491
TEST_TIME 105 9514
TEST_TIME 106 9481
TEST_TIME 107 9397
TEST_TIME 108 9385
TEST_TIME 109 9333
TEST_TIME 110 9327
TEST_TIME 111 9265
TEST_TIME 112 9226
TEST_TIME 113 9226
TEST_TIME 114 9293
TEST_TIME 115 9268
TEST_TIME 116 9264
TEST_TIME 117 9251
TEST_TIME 118 9249
TEST_TIME 119 9276
TEST_TIME 120 9225

Performance per minute, chart


Completed "Performance for every MINUTE". Done for 00:00:04, from 10-10-2020 04:07:27 to 10-10-2020 04:07:31.

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 1534888 1534888 0 0.00 0 17723 6 0 0
doc_list_biud 1534885 1534885 0 0.00 0 23733 32 0 0
sp_add_invoice_to_stock 5157 5034 123 2.38 17 170293 16225 0 123
sp_cancel_adding_invoice 5732 5732 0 0.00 4 84784 922 0 0
sp_cancel_client_order 1810 1810 0 0.00 4 10071 304 0 0
sp_cancel_customer_reserve 558773 558773 0 0.00 1 23735 71 0 0
sp_cancel_pay_from_customer 726 726 0 0.00 3 4772 91 0 0
sp_cancel_pay_to_supplier 420 420 0 0.00 3 4796 71 0 0
sp_cancel_supplier_invoice 6287 6282 5 0.07 2 18115 952 0 5
sp_cancel_supplier_order 420 420 0 0.00 8 1095531 117853 0 0
sp_cancel_write_off 10091 10091 0 0.00 1 6113 103 0 0
sp_client_order 21240 21240 0 0.00 4 22182 377 0 0
sp_customer_reserve 460490 460490 0 0.00 0 127933 160 0 0
sp_fill_shopping_cart 32337 32337 0 0.00 1 16506 45 0 0
sp_fill_shopping_cart_clo_res 460487 460487 0 0.00 0 25187 15 0 0
sp_get_clo_for_invoice 5029 5029 0 0.00 0 48762 401 0 0
sp_kill_cost_storno 16969 16969 0 0.00 0 17711 59 0 0
sp_kill_qstorno_ret_qs2qd 1134339 1134339 0 0.00 0 23730 38 0 0
sp_kill_qty_storno 598196 598196 0 0.00 0 23733 81 0 0
sp_lock_selected_doc 21018 21018 0 0.00 0 5196 3 0 0
sp_make_cost_storno 28209 28209 0 0.00 0 14471 50 0 0
sp_multiply_rows_for_pdistr 28208 28208 0 0.00 0 9029 31 0 0
sp_multiply_rows_for_qdistr 21240 21240 0 0.00 0 22172 203 0 0
sp_pay_from_customer 7089 7089 0 0.00 4 18356 103 0 0
sp_pay_to_supplier 6031 6031 0 0.00 5 15758 118 0 0
sp_payment_common 13119 13119 0 0.00 1 6728 21 0 0
sp_qd_handle_on_cancel_clo 1810 1810 0 0.00 0 10024 283 0 0
sp_qd_handle_on_invoice_upd_sts 10760 10760 0 0.00 0 19060 375 0 0
sp_qd_handle_on_reserve_upd_sts 10060 10060 0 0.00 0 19663 47 0 0
sp_reserve_write_off 10060 10060 0 0.00 7 19675 158 0 0
sp_supplier_invoice 5514 5514 0 0.00 6 101084 3697 0 0
sp_supplier_order 5588 5588 0 0.00 6 22201 1448 0 0
srv_aggregate_perf_data 107 107 0 0.00 2849 104991 17282 0 0
srv_fill_mon_cache_memory 64 64 0 0.00 2224 113450 45266 0 0
srv_find_qd_qs_mism 1059412 1059412 0 0.00 0 8773 5 0 0
srv_make_invnt_saldo 481 481 0 0.00 62 102657 3298 0 0
srv_make_money_saldo 758 758 0 0.00 1 16439 562 0 0
srv_recalc_idx_stat 5 5 0 0.00 72484 270222 194621 0 0
t$perf-abend:sp_add_invoice_to_stock 123 123 0 0.00 0 0 0 0 0
t$perf-abend:sp_cancel_supplier_invoice 5 5 0 0.00 0 0 0 0 0
t$perf-norm:sp_add_invoice_to_stock 5035 5035 0 0.00 0 12610 168 0 0
t$perf-norm:sp_cancel_adding_invoice 426 426 0 0.00 1 5628 81 0 0
t$perf-norm:sp_cancel_client_order 1810 1810 0 0.00 0 3831 16 0 0
t$perf-norm:sp_cancel_customer_reserve 664 664 0 0.00 0 3604 16 0 0
t$perf-norm:sp_cancel_pay_from_customer 726 726 0 0.00 0 3490 9 0 0
t$perf-norm:sp_cancel_pay_to_supplier 420 420 0 0.00 0 483 3 0 0
t$perf-norm:sp_cancel_supplier_invoice 400 400 0 0.00 0 3639 19 0 0
t$perf-norm:sp_cancel_supplier_order 420 420 0 0.00 0 22117 1493 0 0
t$perf-norm:sp_cancel_write_off 1065 1065 0 0.00 0 1244 7 0 0
t$perf-norm:sp_client_order 21240 21240 0 0.00 0 8957 16 0 0
t$perf-norm:sp_customer_reserve 1007 1007 0 0.00 0 828 5 0 0
t$perf-norm:sp_pay_from_customer 7089 7089 0 0.00 0 5375 10 0 0
t$perf-norm:sp_pay_to_supplier 6031 6031 0 0.00 0 4313 7 0 0
t$perf-norm:sp_reserve_write_off 10060 10060 0 0.00 0 9450 11 0 0
t$perf-norm:sp_supplier_invoice 5514 5514 0 0.00 0 6214 16 0 0
t$perf-norm:sp_supplier_order 5588 5588 0 0.00 0 4837 17 0 0
t$perf-norm:srv_aggregate_perf_data 107 107 0 0.00 0 682 13 0 0
t$perf-norm:srv_fill_mon_cache_memory 64 64 0 0.00 0 164 3 0 0
t$perf-norm:srv_make_invnt_saldo 481 481 0 0.00 0 616 6 0 0
t$perf-norm:srv_make_money_saldo 758 758 0 0.00 0 492 4 0 0
t$perf-norm:srv_recalc_idx_stat 5 5 0 0.00 1 12 4 0 0
v_add_invoice_to_stock 10300 10054 246 2.38 0 6787 17 0 246
v_all_customers 38460 38460 0 0.00 0 16 1 0 0
v_all_suppliers 30998 30998 0 0.00 0 14 1 0 0
v_all_wares 42480 42480 0 0.00 0 18 1 0 0
v_cancel_adding_invoice 852 852 0 0.00 0 5368 16 0 0
v_cancel_client_order 3620 3620 0 0.00 0 2417 4 0 0
v_cancel_customer_prepayment 1452 1452 0 0.00 0 936 4 0 0
v_cancel_customer_reserve 1328 1328 0 0.00 0 1975 5 0 0
v_cancel_payment_to_supplier 840 840 0 0.00 0 1283 6 0 0
v_cancel_supplier_invoice 810 800 10 1.23 0 1274 15 0 10
v_cancel_supplier_order 840 840 0 0.00 0 1457 5 0 0
v_cancel_write_off 2130 2130 0 0.00 0 4234 15 0 0
v_max_id_clo_ord 5588 5588 0 0.00 0 1133 1 0 0
v_max_id_clo_res 1007 1007 0 0.00 0 4543 19 0 0
v_max_id_ord_sup 5509 5509 0 0.00 0 5269 4 0 0
v_max_non_paid_invoice 1629 1629 0 0.00 0 227 2 0 0
v_max_non_paid_realizn 3823 3823 0 0.00 0 700 2 0 0
v_min_id_clo_ord 5588 5588 0 0.00 0 4029 6 0 0
v_min_id_clo_res 1007 1007 0 0.00 0 28815 37 0 0
v_min_id_ord_sup 5509 5509 0 0.00 0 6351 12 0 0
v_min_non_paid_invoice 6031 6031 0 0.00 0 5910 14 0 0
v_min_non_paid_realizn 7088 7088 0 0.00 0 6564 16 0 0
v_our_firm 10550 10550 0 0.00 0 15 1 0 0
v_reserve_write_off 20120 20120 0 0.00 0 4263 5 0 0
x_lock_depdocs_on_canc_invoice 11614 11614 0 0.00 0 24475 113 0 0
x_lock_depdocs_on_canc_sup_ord 420 420 0 0.00 0 10502 344 0 0
x_make_qstorno_1000_1200 5588 5588 0 0.00 2 22195 1370 0 0
x_make_qstorno_1200_2000 5514 5514 0 0.00 3 101077 3521 0 0
x_make_qstorno_2100_3300 460490 460490 0 0.00 0 127932 143 0 0

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

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
01:36:31 2 8192000000 8796624000 8807108608 3156752 0.038 1 1 2 0 3254112 61504 35856
01:37:33 29666 8192000000 9720310672 10017357824 795197664 8.848 100 89 178 0 824687120 7390304 22099152
01:39:05 16213 8192000000 9761195584 10067378176 831370448 9.213 100 89 178 3 865044320 12362256 21311616
01:40:25 20969 8192000000 9811885728 10129149952 874499328 9.645 100 88 176 1 915855536 20793264 20562944
01:41:51 13140 8192000000 9871269456 10201305088 915335760 10.050 100 82 164 0 985554032 52425184 17793088
01:43:14 8186 8192000000 9929551360 10274992128 958909936 10.478 100 77 154 0 1049635744 74999008 15726800
01:44:24 3259 8192000000 9967307248 10322300928 996115664 10.841 100 83 167 3 1092002976 78593152 17294160
01:45:29 2474 8192000000 9990106672 10353655808 1023474704 11.106 100 76 151 1 1100015776 61643824 14897248
01:46:33 1580 8192000000 10027979856 10398748672 1060933536 11.465 100 90 177 4 1142179712 61885536 19360640
01:47:35 6043 8192000000 9976505456 10366439424 1064144480 11.496 100 33 64 1 1108918288 37459488 7314320
01:48:43 12626 8192000000 9987058304 10390966272 1077509216 11.624 100 31 61 1 1108863552 25323824 6030512
01:50:00 46043 8192000000 9989903440 10389041152 1084960128 11.695 100 22 39 1 1109115424 18847280 5308016
01:52:10 4835 8192000000 10013178064 10408452096 1090716960 11.749 100 39 78 1 1129056224 30965136 7374128
01:53:17 5162 8192000000 10029079696 10425102336 1095836688 11.798 100 39 78 1 1132425440 29031632 7557120
01:54:23 56181 8192000000 10007665536 10408214528 1085699376 11.702 99 28 55 1 1103424304 11083504 6641424
01:56:19 7807 8192000000 10001101248 10416590848 1076343760 11.613 99 34 68 3 1111425168 27616096 7465312
01:57:28 6722 8192000000 9977742592 10361544704 1041413792 11.278 98 32 64 1 1064611168 15962848 7234528
01:58:35 4870 8192000000 9932949088 10310156288 991387904 10.795 97 38 71 5 1016589520 16836144 8365472
01:59:46 34499 8192000000 9944369472 10343178240 1009628400 10.972 98 14 28 2 1052585280 39904832 3052048
02:01:20 8935 8192000000 9948601440 10325909504 997327616 10.853 97 47 94 4 1020513312 11161680 12024016
02:02:34 9564 8192000000 9971133200 10364203008 1053365632 11.393 100 53 103 2 1084969520 18337120 13266768
02:03:46 5655 8192000000 9981597040 10370297856 1066630016 11.520 100 47 96 1 1087586368 10609648 10346704
02:05:41 7372 8192000000 10000075968 10393882624 1068415904 11.537 100 27 54 3 1099157360 24667616 6073840
02:06:51 10848 8192000000 10016082032 10409537536 1099919152 11.837 100 48 95 3 1123385440 13825504 9640784
02:08:09 6724 8192000000 10088323120 10484178944 1115382384 11.983 100 54 106 1 1188889008 62667856 10838768
02:09:20 28967 8192000000 10091963824 10502696960 1130418048 12.125 100 26 52 1 1193803888 57538208 5847632
02:10:59 5387 8192000000 10142900240 10543435776 1148699632 12.297 100 73 141 0 1246658208 83449248 14509328
02:12:09 3829 8192000000 10185603024 10592157696 1154513600 12.352 100 61 122 2 1293079728 126305952 12260176
02:13:18 6483 8192000000 10207051344 10614747136 1163726512 12.438 100 54 108 0 1310035968 134882912 11426544
02:14:29 2224 8192000000 10255472400 10652798976 1165607584 12.456 100 84 164 1 1357902416 174445168 17849664
02:15:36 8084 8192000000 10274863728 10704715776 1162810160 12.430 99 50 98 1 1378648960 204859232 10979568
02:16:48 3999 8192000000 10325218752 10731593728 1179229296 12.583 100 66 131 0 1423805264 229516976 15058992
02:18:01 9978 8192000000 10326686576 10747351040 1165091840 12.451 99 65 128 0 1424514560 244405840 15016880
02:19:16 10317 8192000000 10348986160 10747330560 1150754592 12.317 99 71 140 0 1437291184 270631872 15904720
02:20:31 5057 8192000000 10336431056 10738470912 1169463440 12.492 100 70 142 1 1440414224 255099488 15851296
02:21:41 7366 8192000000 10350179104 10759843840 1153208288 12.340 99 61 119 1 1443263776 275138272 14917216
02:22:53 4359 8192000000 10439377376 10852237312 1161194480 12.414 100 64 128 0 1529546544 353473040 14879024
02:24:00 3274 8192000000 10422078592 10834608128 1161513088 12.417 100 60 118 2 1524467872 348320144 14634640
02:25:11 4619 8192000000 10481244960 10884444160 1166925296 12.468 100 80 162 2 1574737936 388936016 18876624
02:26:20 4593 8192000000 10510165184 10918645760 1167432368 12.473 100 68 136 1 1604195296 419070288 17692640
02:27:30 12207 8192000000 10446207280 10876243968 1152851232 12.336 100 41 80 0 1553040064 389599760 10589072
02:28:44 22271 8192000000 10417606496 10843426816 1144499808 12.258 100 35 70 1 1505424064 351279744 9644512
02:30:17 21790 8192000000 10354512528 10829447168 1143456192 12.248 100 31 62 1 1490684800 339128656 8099952
02:31:40 24669 8192000000 10322243968 10818166784 1108599104 11.919 99 22 44 2 1433062000 318889840 5573056
02:33:12 72847 8192000000 10089183648 10606501888 1088855872 11.732 97 12 24 2 1184897056 93708240 2332944
02:35:26 89790 8192000000 10105657904 10533171200 1103433408 11.870 98 31 59 2 1187317760 76977696 6906656
02:38:31 96333 8192000000 10075329360 10497015808 1124858672 12.073 98 16 31 2 1173599120 45586080 3154368
02:41:09 79612 8192000000 10070851056 10536693760 1105045728 11.885 97 6 12 1 1147967840 41841280 1080832
02:43:31 68183 8192000000 10090067680 10526380032 1126842224 12.092 99 19 38 2 1171450080 40490416 4117440
02:45:40 80186 8192000000 10067612592 10517889024 1117813408 12.006 98 6 12 0 1155805344 36986656 1005280
02:48:06 76259 8192000000 10076744736 10517712896 1146201888 12.274 100 44 89 0 1179660096 23820640 9637568
02:50:24 9859 8192000000 10086376736 10528698368 1148311936 12.294 99 19 38 2 1177121120 24750736 4058448
02:51:35 61721 8192000000 10170688288 10628448256 1165918624 12.459 100 32 64 0 1277201744 104115392 7167728
02:53:40 40710 8192000000 10090485984 10573144064 1140902896 12.224 99 20 40 3 1232276128 86454464 4918768
02:55:22 52104 8192000000 10103662736 10576986112 1152718656 12.335 100 19 37 1 1192002176 35156528 4126992
02:57:20 94835 8192000000 10165752816 10619654144 1142027872 12.235 98 14 28 0 1220766528 75567744 3170912
03:00:14 36627 8192000000 10093947936 10537492480 1140014752 12.216 99 7 14 0 1187597936 46192224 1390960
03:02:02 66701 8192000000 10103436176 10574069760 1126244224 12.086 98 22 43 1 1209470992 78670800 4555968
03:04:09 46963 8192000000 10115364720 10573856768 1119022064 12.018 97 13 25 3 1180794656 59014368 2758224
03:05:56 42100 8192000000 10117483472 10582188032 1123498240 12.060 98 27 54 0 1221769040 92628736 5642064
03:07:49 42376 8192000000 10129281280 10611466240 1100839696 11.846 96 16 32 2 1172279424 67910720 3529008
03:09:33 108072 8192000000 10078679920 10516398080 1032740224 11.195 91 15 30 1 1076015024 40484752 2790048
03:12:24 99480 8192000000 10082172112 10547859456 1126511888 12.088 100 15 30 0 1192890176 63276800 3101488
03:15:07 63212 8192000000 10065966928 10544406528 1094448512 11.785 97 5 10 0 1145472928 50087696 936720
03:17:12 33359 8192000000 10070642944 10506895360 1114421120 11.974 98 27 56 1 1141585744 21917088 5247536
03:18:48 39829 8192000000 10113906416 10559565824 1147569536 12.287 100 15 30 0 1208897296 57847824 3479936
03:20:28 69876 8192000000 10215480928 10663239680 1148189536 12.293 99 33 65 0 1264137136 108513392 7434208
03:22:42 57886 8192000000 10205624464 10672836608 1117467872 12.003 98 13 26 0 1272415408 151682704 3264832
03:24:51 27191 8192000000 10133306624 10564874240 1117310464 12.002 99 38 75 0 1183803248 58294432 8198352
03:26:23 33211 8192000000 10067373744 10490351616 1103279216 11.869 98 31 63 0 1130694576 21542864 5872496
03:27:59 27992 8192000000 10136925856 10577555456 1122010160 12.046 99 28 56 3 1209956400 82181872 5764368
03:29:28 113450 8192000000 10067692272 10552893440 1127052544 12.094 100 20 40 1 1193519920 62163680 4303696
03:32:34 83795 8192000000 10067821312 10535030784 1138167712 12.198 100 14 28 0 1183355280 42146832 3040736
03:35:01 69261 8192000000 10106760112 10555183104 1128100048 12.103 99 23 46 2 1204728912 71810768 4818096
03:37:18 74506 8192000000 10131161440 10566684672 1122156176 12.047 98 18 36 0 1184371616 58495040 3720400
03:39:45 67441 8192000000 10081763904 10547376128 1119605808 12.023 97 17 34 0 1172679152 50003648 3069696
03:42:11 65684 8192000000 10099436288 10576855040 1138680432 12.203 99 25 50 0 1207338848 63529424 5128992
03:44:23 94056 8192000000 10111581488 10604085248 1131421968 12.135 98 23 46 1 1199228576 63174032 4632576
03:47:39 35518 8192000000 10069275552 10507808768 1108803408 11.921 97 17 34 1 1138380912 25826352 3751152
03:49:20 47780 8192000000 10071729552 10497019904 1108194144 11.915 98 21 41 1 1146132640 33998096 3940400
03:51:08 68933 8192000000 10039038416 10493403136 1078676672 11.635 96 30 60 2 1126456608 42183104 5596832
03:53:19 99439 8192000000 10037653008 10490589184 1078145984 11.630 96 28 56 0 1104630912 20284240 6200688
03:56:05 46299 8192000000 10026531104 10502139904 1083065248 11.677 98 6 12 0 1140507152 55916432 1525472
03:58:58 75582 8192000000 10057833808 10557108224 1088648704 11.730 97 22 44 0 1190688304 96947888 5091712
04:01:32 32761 8192000000 10084897264 10529968128 1120488704 12.032 100 28 56 3 1167875184 41636304 5750176
04:03:05 42936 8192000000 10104009824 10545090560 1100181344 11.839 97 27 54 1 1170840608 64031040 6628224
04:04:52 55080 8192000000 10081224768 10536824832 1103900304 11.875 99 22 44 1 1175288400 66109296 5278800

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 04:07:37 to 10-10-2020 04:07:52.

Exceptions occured during test was in run

FB_MNEMONA CNT UNIT FB_GDSCODE
user_exc 123 v_add_invoice_to_stock 335544517
user_exc 5 v_cancel_supplier_invoice 335544517

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

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          238588
MON$OLDEST_ACTIVE               241154
MON$OLDEST_SNAPSHOT             241154
MON$NEXT_TRANSACTION            241154
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                       2128768
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.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 ---
:6: 
:7: mscs-test-161.budzdorov.ru    Sat Oct 10 04:06:32 2020
:8:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:9: 
:10: 
:11: mscs-test-161.budzdorov.ru    Sat Oct 10 04:06:32 2020
:12:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:13: 
:14: 
:15: mscs-test-161.budzdorov.ru    Sat Oct 10 04:06:33 2020
:16:     INET/inet_error: send errno = 32, server host = localhost, address = ::1/3400
:17: 
:18: 
:19: mscs-test-161.budzdorov.ru    Sat Oct 10 04:06:40 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'

10.10.20 04:07:56. 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 04:07:59 No severe PSQL-related problems occured
10.10.20 04:08:00. End of report.