Generated by /opt/oltp-emul/oltp_isql_run_worker.sh, ISQL session No. 1 of total launched 100. 06.10.2020 06:53
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'
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 10388444 kB
MemAvailable 31695768 kB
Buffers 12 kB
Cached 21175872 kB
SwapCached 3756 kB
Command: fdisk -l

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_unit_list, val=//
param=mon_unit_perf, val=2
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-06 06:52:08
DTS_END                         2020-10-06 06:51:44.7370
FB_GDSCODE                      -1
FB_MNEMONA                      
STACK                           SP_ADD_INVOICE_TO_STOCK(190:30) ==> SP_CUSTOMER_RESERVE(47:5) ==> SP_CHECK_TO_STOP_WORK(32:12) ==> SP_HALT_ON_ERROR(67:17)
IP                              ::1/35846
TRN_ID                          233129
ATT_ID                          600
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: 9179.33 22522 1101519
customer order: creation 166.77 400 20012
customer order: refuse 14.01 318 1681
order to supplier: creation 43.86 1358 5263
order to supplier: removal 3.28 116467 394
invoice (draft): creation 43.43 3255 5212
invoice (draft): removal 53.53 811 6424
invoice accept: apply 40.54 17001 4865
invoice accept: cancel 48.65 766 5838
customer reserve: creation 3698.07 168 443768
customer reserve: removal 4781.75 63 573810
realization accept: apply 78.47 157 9417
realization accept: cancel 84.77 118 10172
payment from customer: creation 56.47 105 6776
payment from customer: removal 5.32 93 638
payment to supplier: creation 46.00 107 5520
payment to supplier: removal 3.25 77 390
service: total inventory turnovers 4.18 2894 502
service: total monetary turnovers 6.05 425 726
service: aggregate perf. data 0.88 13435 106
service: refresh index statistics 0.04 292424 5

Performance in TOTAL, chart


Completed "Performance in TOTAL". Done for 00:00:02, from 06-10-2020 06:53:46 to 06-10-2020 06:53:48.

Performance for every MINUTE

TEST_PHASE_NAME MINUTES_PASSED PERF_SCORE
TEST_TIME 1 4034
TEST_TIME 2 6104
TEST_TIME 3 5709
TEST_TIME 4 5647
TEST_TIME 5 5903
TEST_TIME 6 6133
TEST_TIME 7 6010
TEST_TIME 8 5741
TEST_TIME 9 6099
TEST_TIME 10 6479
TEST_TIME 11 6456
TEST_TIME 12 6677
TEST_TIME 13 6785
TEST_TIME 14 6590
TEST_TIME 15 7092
TEST_TIME 16 7823
TEST_TIME 17 8000
TEST_TIME 18 8553
TEST_TIME 19 9126
TEST_TIME 20 9219
TEST_TIME 21 9721
TEST_TIME 22 10175
TEST_TIME 23 10426
TEST_TIME 24 11158
TEST_TIME 25 11486
TEST_TIME 26 11520
TEST_TIME 27 11449
TEST_TIME 28 11330
TEST_TIME 29 11106
TEST_TIME 30 10781
TEST_TIME 31 10549
TEST_TIME 32 10426
TEST_TIME 33 10303
TEST_TIME 34 10375
TEST_TIME 35 10354
TEST_TIME 36 10249
TEST_TIME 37 10160
TEST_TIME 38 10074
TEST_TIME 39 10116
TEST_TIME 40 10198
TEST_TIME 41 10176
TEST_TIME 42 10185
TEST_TIME 43 10068
TEST_TIME 44 10065
TEST_TIME 45 10194
TEST_TIME 46 10116
TEST_TIME 47 10209
TEST_TIME 48 10239
TEST_TIME 49 10148
TEST_TIME 50 9964
TEST_TIME 51 9905
TEST_TIME 52 9753
TEST_TIME 53 9638
TEST_TIME 54 9616
TEST_TIME 55 9609
TEST_TIME 56 9528
TEST_TIME 57 9584
TEST_TIME 58 9617
TEST_TIME 59 9548
TEST_TIME 60 9591
TEST_TIME 61 9610
TEST_TIME 62 9657
TEST_TIME 63 9710
TEST_TIME 64 9657
TEST_TIME 65 9816
TEST_TIME 66 9788
TEST_TIME 67 9768
TEST_TIME 68 9667
TEST_TIME 69 9605
TEST_TIME 70 9506
TEST_TIME 71 9452
TEST_TIME 72 9363
TEST_TIME 73 9308
TEST_TIME 74 9329
TEST_TIME 75 9358
TEST_TIME 76 9353
TEST_TIME 77 9307
TEST_TIME 78 9284
TEST_TIME 79 9376
TEST_TIME 80 9369
TEST_TIME 81 9403
TEST_TIME 82 9394
TEST_TIME 83 9506
TEST_TIME 84 9462
TEST_TIME 85 9363
TEST_TIME 86 9315
TEST_TIME 87 9250
TEST_TIME 88 9194
TEST_TIME 89 9181
TEST_TIME 90 9143
TEST_TIME 91 9102
TEST_TIME 92 9092
TEST_TIME 93 9137
TEST_TIME 94 9108
TEST_TIME 95 9081
TEST_TIME 96 9139
TEST_TIME 97 9109
TEST_TIME 98 9180
TEST_TIME 99 9169
TEST_TIME 100 9217
TEST_TIME 101 9337
TEST_TIME 102 9374
TEST_TIME 103 9377
TEST_TIME 104 9364
TEST_TIME 105 9281
TEST_TIME 106 9228
TEST_TIME 107 9180
TEST_TIME 108 9135
TEST_TIME 109 9111
TEST_TIME 110 9106
TEST_TIME 111 9098
TEST_TIME 112 9134
TEST_TIME 113 9180
TEST_TIME 114 9160
TEST_TIME 115 9144
TEST_TIME 116 9104
TEST_TIME 117 9141
TEST_TIME 118 9205
TEST_TIME 119 9218
TEST_TIME 120 9184

Performance per minute, chart


Completed "Performance for every MINUTE". Done for 00:00:03, from 06-10-2020 06:53:49 to 06-10-2020 06:53:52.

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 1512119 1512119 0 0.00 0 17743 6 0 0
doc_list_biud 1512118 1512118 0 0.00 0 89938 30 0 0
sp_add_invoice_to_stock 4966 4865 101 2.03 31 166800 17002 0 101
sp_cancel_adding_invoice 5838 5838 0 0.00 5 71208 767 0 0
sp_cancel_client_order 1681 1681 0 0.00 4 8184 318 0 0
sp_cancel_customer_reserve 573810 573810 0 0.00 1 89940 64 0 0
sp_cancel_pay_from_customer 638 638 0 0.00 3 9371 93 0 0
sp_cancel_pay_to_supplier 390 390 0 0.00 3 5947 77 0 0
sp_cancel_supplier_invoice 6434 6424 10 0.15 3 19375 812 0 10
sp_cancel_supplier_order 394 394 0 0.00 6 1146437 116467 0 0
sp_cancel_write_off 10172 10172 0 0.00 1 9200 119 0 0
sp_client_order 20012 20012 0 0.00 3 28614 401 0 0
sp_customer_reserve 443768 443768 0 0.00 0 65750 169 0 0
sp_fill_shopping_cart 30473 30473 0 0.00 1 29744 42 0 0
sp_fill_shopping_cart_clo_res 443760 443760 0 0.00 0 18691 19 0 0
sp_get_clo_for_invoice 4857 4857 0 0.00 0 34348 399 0 0
sp_kill_cost_storno 17038 17038 0 0.00 0 9197 56 0 0
sp_kill_qstorno_ret_qs2qd 1164610 1164610 0 0.00 0 89936 34 0 0
sp_kill_qty_storno 612593 612593 0 0.00 0 89938 73 0 0
sp_lock_selected_doc 19733 19733 0 0.00 0 7242 5 0 0
sp_make_cost_storno 26569 26569 0 0.00 0 9071 52 0 0
sp_multiply_rows_for_pdistr 26569 26569 0 0.00 0 7346 29 0 0
sp_multiply_rows_for_qdistr 20012 20012 0 0.00 0 17337 240 0 0
sp_pay_from_customer 6776 6776 0 0.00 4 13398 105 0 0
sp_pay_to_supplier 5520 5520 0 0.00 4 10906 107 0 0
sp_payment_common 12295 12295 0 0.00 1 8598 18 0 0
sp_qd_handle_on_cancel_clo 1681 1681 0 0.00 0 8176 283 0 0
sp_qd_handle_on_invoice_upd_sts 10695 10695 0 0.00 0 31902 339 0 0
sp_qd_handle_on_reserve_upd_sts 9417 9417 0 0.00 0 8623 45 0 0
sp_reserve_write_off 9417 9417 0 0.00 7 13503 157 0 0
sp_supplier_invoice 5212 5212 0 0.00 7 123851 3256 0 0
sp_supplier_order 5263 5263 0 0.00 6 47034 1359 0 0
srv_aggregate_perf_data 106 106 0 0.00 2602 102349 13435 0 0
srv_fill_mon_cache_memory 61 61 0 0.00 1436 172554 50600 0 0
srv_find_qd_qs_mism 1055704 1055704 0 0.00 0 17742 5 0 0
srv_make_invnt_saldo 502 502 0 0.00 52 97718 2894 0 0
srv_make_money_saldo 726 726 0 0.00 1 11825 426 0 0
srv_recalc_idx_stat 5 5 0 0.00 178061 467520 292424 0 0
t$perf-abend:sp_add_invoice_to_stock 102 102 0 0.00 0 0 0 0 0
t$perf-abend:sp_cancel_supplier_invoice 10 10 0 0.00 0 0 0 0 0
t$perf-norm:sp_add_invoice_to_stock 4865 4865 0 0.00 0 21258 170 0 0
t$perf-norm:sp_cancel_adding_invoice 365 365 0 0.00 0 7223 130 0 0
t$perf-norm:sp_cancel_client_order 1681 1681 0 0.00 0 6568 12 0 0
t$perf-norm:sp_cancel_customer_reserve 684 684 0 0.00 0 445 5 0 0
t$perf-norm:sp_cancel_pay_from_customer 638 638 0 0.00 0 198 2 0 0
t$perf-norm:sp_cancel_pay_to_supplier 390 390 0 0.00 0 6345 31 0 0
t$perf-norm:sp_cancel_supplier_invoice 369 369 0 0.00 0 1239 11 0 0
t$perf-norm:sp_cancel_supplier_order 394 394 0 0.00 0 18065 1488 0 0
t$perf-norm:sp_cancel_write_off 939 939 0 0.00 0 2661 5 0 0
t$perf-norm:sp_client_order 20012 20012 0 0.00 0 7972 15 0 0
t$perf-norm:sp_customer_reserve 997 997 0 0.00 0 2648 7 0 0
t$perf-norm:sp_pay_from_customer 6776 6776 0 0.00 0 5377 8 0 0
t$perf-norm:sp_pay_to_supplier 5520 5520 0 0.00 0 5063 8 0 0
t$perf-norm:sp_reserve_write_off 9417 9417 0 0.00 0 6341 10 0 0
t$perf-norm:sp_supplier_invoice 5212 5212 0 0.00 0 5758 17 0 0
t$perf-norm:sp_supplier_order 5263 5263 0 0.00 0 6714 14 0 0
t$perf-norm:srv_aggregate_perf_data 106 106 0 0.00 0 3942 51 0 0
t$perf-norm:srv_fill_mon_cache_memory 61 61 0 0.00 0 2496 74 0 0
t$perf-norm:srv_make_invnt_saldo 502 502 0 0.00 0 3668 20 0 0
t$perf-norm:srv_make_money_saldo 726 726 0 0.00 0 440 4 0 0
t$perf-norm:srv_recalc_idx_stat 5 5 0 0.00 1 7 3 0 0
v_add_invoice_to_stock 9914 9712 202 2.03 0 7472 15 0 202
v_all_customers 36230 36230 0 0.00 0 171 1 0 0
v_all_suppliers 28672 28672 0 0.00 0 172 1 0 0
v_all_wares 40024 40024 0 0.00 0 71 1 0 0
v_cancel_adding_invoice 730 730 0 0.00 0 5844 18 0 0
v_cancel_client_order 3362 3362 0 0.00 0 1671 4 0 0
v_cancel_customer_prepayment 1276 1276 0 0.00 0 1103 5 0 0
v_cancel_customer_reserve 1368 1368 0 0.00 0 686 3 0 0
v_cancel_payment_to_supplier 780 780 0 0.00 0 277 3 0 0
v_cancel_supplier_invoice 758 738 20 2.63 0 6957 21 0 20
v_cancel_supplier_order 788 788 0 0.00 0 560 4 0 0
v_cancel_write_off 1878 1878 0 0.00 0 1135 11 0 0
v_max_id_clo_ord 5263 5263 0 0.00 0 176 1 0 0
v_max_id_clo_res 997 997 0 0.00 0 4300 13 0 0
v_max_id_ord_sup 5198 5198 0 0.00 0 2509 3 0 0
v_max_non_paid_invoice 1645 1645 0 0.00 0 357 2 0 0
v_max_non_paid_realizn 3584 3584 0 0.00 0 719 2 0 0
v_min_id_clo_ord 5263 5263 0 0.00 0 1996 5 0 0
v_min_id_clo_res 997 997 0 0.00 0 1937 8 0 0
v_min_id_ord_sup 5198 5198 0 0.00 0 8072 11 0 0
v_min_non_paid_invoice 5520 5520 0 0.00 0 2470 8 0 0
v_min_non_paid_realizn 6775 6775 0 0.00 0 6041 13 0 0
v_our_firm 10176 10176 0 0.00 0 10 1 0 0
v_reserve_write_off 18834 18834 0 0.00 0 4964 5 0 0
x_lock_depdocs_on_canc_invoice 11893 11893 0 0.00 0 36094 98 0 0
x_lock_depdocs_on_canc_sup_ord 394 394 0 0.00 0 15245 304 0 0
x_make_qstorno_1000_1200 5263 5263 0 0.00 2 47025 1286 0 0
x_make_qstorno_1200_2000 5212 5212 0 0.00 3 114589 3088 0 0
x_make_qstorno_2100_3300 443768 443768 0 0.00 0 65749 148 0 0

Completed "Performance in DETAILS". Done for 00:00:05, from 06-10-2020 06:53:57 to 06-10-2020 06:54:02.

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:21:48 2 8192000000 8796623312 8807108608 3156752 0.038 1 1 2 0 3254112 61504 35856
04:22:49 16191 8192000000 9720545152 10012639232 799577248 8.892 100 88 176 1 828386768 7710912 21098608
04:24:11 27726 8192000000 9765716992 10071834624 845608560 9.356 100 87 174 1 876720592 10600400 20511632
04:25:45 18292 8192000000 9807522816 10126213120 882662576 9.726 100 85 170 0 924043920 22269520 19111824
04:27:10 11651 8192000000 9878590576 10212634624 933664320 10.231 100 80 160 0 992807232 42470160 16672752
04:28:26 6917 8192000000 9939966016 10283966464 968508432 10.572 100 71 142 1 1053132400 70237168 14386800
04:29:35 5003 8192000000 9966311936 10316148736 994499456 10.825 100 82 162 0 1079947952 69072320 16376176
04:30:43 2487 8192000000 10010240512 10371158016 1021813088 11.090 100 83 166 2 1129392672 90746528 16833056
04:31:47 1853 8192000000 10008075776 10370007040 1041893792 11.283 100 90 179 1 1114311952 54412400 18005760
04:32:51 1585 8192000000 10029532032 10404675584 1058195040 11.439 100 83 166 0 1147211792 71873072 17143680
04:33:55 9387 8192000000 10027011408 10424262656 1062629296 11.482 100 49 99 2 1149203616 76158432 10415888
04:35:07 7030 8192000000 9993913456 10377625600 1071164672 11.563 100 42 81 1 1110354688 31019776 8170240
04:36:15 10421 8192000000 10004091360 10405183488 1085391984 11.699 100 38 76 2 1123858272 30535056 7931232
04:37:26 67856 8192000000 10010937904 10402516992 1092912560 11.770 100 42 82 0 1114870112 12815952 9141600
04:39:35 2367 8192000000 10028456320 10419163136 1096892336 11.808 100 41 80 1 1144674960 37736320 10046304
04:40:37 4683 8192000000 9996141872 10381737984 1071726384 11.569 98 49 96 4 1088422672 6233856 10462432
04:41:44 27363 8192000000 9983957216 10388258816 1017762656 11.050 94 25 49 1 1047744576 24809072 5172848
04:43:15 6411 8192000000 9961888160 10355453952 1057618256 11.434 100 23 49 1 1077088736 14178848 5291632
04:44:23 8150 8192000000 9899776464 10287771648 965392784 10.542 95 22 42 4 988789056 18773872 4622400
04:45:32 65863 8192000000 9923528240 10310692864 998373568 10.863 97 40 80 0 1024808432 17685408 8749456
04:47:41 4405 8192000000 9960652208 10341670912 1042158624 11.285 100 43 86 2 1072090672 19015504 10916544
04:48:48 7684 8192000000 9977172224 10374995968 1056292416 11.421 100 34 67 5 1083017328 19177392 7547520
04:49:57 22368 8192000000 9964601232 10368299008 1063245008 11.488 100 46 92 2 1091442432 17968848 10228576
04:51:49 12772 8192000000 10012632832 10402549760 1092417616 11.766 100 50 100 2 1118597392 15179440 11000336
04:53:07 15296 8192000000 10084894688 10493886464 1105345136 11.888 100 49 98 0 1209134912 93936832 9852944
04:54:47 8995 8192000000 10099936928 10493489152 1131405824 12.135 100 67 132 1 1209145808 63669312 14070672
04:56:23 4426 8192000000 10130508272 10534371328 1140168512 12.217 100 46 90 0 1237143232 87509664 9465056
04:57:30 8096 8192000000 10178459024 10584440832 1149569184 12.305 100 56 112 2 1293822080 131746800 12506096
04:58:51 13089 8192000000 10211562576 10616680448 1159859680 12.402 100 63 126 1 1315729872 141745136 14125056
05:00:07 3992 8192000000 10266087952 10668466176 1168444016 12.482 100 67 132 1 1367935968 184650944 14841008
05:01:17 9688 8192000000 10296317120 10709667840 1168178800 12.480 99 59 118 0 1399997392 218725952 13092640
05:02:33 5326 8192000000 10340853088 10753036288 1156452720 12.370 99 58 116 2 1437742336 267803760 13485856
05:03:41 1434 8192000000 10359088864 10746589184 1129148992 12.113 98 86 169 1 1451848288 303610752 19088544
05:04:48 5989 8192000000 10391122128 10794053632 1156019328 12.366 100 63 124 0 1498332944 327913488 14400128
05:06:00 2085 8192000000 10489440960 10897711104 1159841744 12.402 100 77 154 1 1594521200 416356848 18322608
05:07:06 4233 8192000000 10493441008 10901258240 1148815968 12.298 100 74 148 1 1590369776 423599808 17954000
05:08:15 7137 8192000000 10446734256 10876166144 1144279648 12.256 100 46 90 0 1549551072 393772640 11498784
05:09:29 9526 8192000000 10404812336 10815553536 1119041904 12.018 98 36 72 1 1495545744 367155728 9348112
05:10:48 13916 8192000000 10371603648 10814369792 1113562560 11.966 98 33 66 1 1458063376 335698912 8801904
05:12:09 19040 8192000000 10353518624 10795581440 1122374912 12.049 99 29 58 0 1470245856 339844720 8026224
05:13:30 40905 8192000000 10269340656 10750832640 1121994432 12.046 100 19 38 3 1388869984 261615120 5260432
05:15:12 20342 8192000000 10209760464 10704519168 1113451680 11.965 100 17 34 1 1336665824 218788704 4425440
05:16:34 75536 8192000000 10046272208 10463346688 1069656768 11.549 97 24 48 0 1118465280 43611984 5196528
05:18:51 71671 8192000000 10019835456 10431090688 1084146336 11.687 98 40 80 2 1114201728 20662736 9392656
05:21:05 124598 8192000000 10068647296 10507350016 1101029296 11.847 99 32 64 3 1165992048 57571744 7391008
05:24:14 31203 8192000000 10170166144 10631581696 1133361456 12.153 100 18 36 2 1226516384 89608240 3546688
05:25:47 24324 8192000000 10102524720 10539483136 1138657472 12.203 100 21 42 0 1204410464 61418032 4334960
05:27:12 37675 8192000000 10327123760 10775977984 1137220576 12.189 100 21 42 0 1430880960 289580352 4080032
05:29:04 38367 8192000000 10316227648 10791960576 1126032832 12.084 99 12 24 0 1425553296 297028032 2492432
05:30:42 67247 8192000000 10091413840 10570629120 1129545472 12.117 99 14 28 1 1187502944 55279648 2677824
05:32:52 56825 8192000000 10077728224 10517356544 1118729360 12.015 98 20 40 0 1176104880 53128992 4246528
05:35:03 57632 8192000000 10110412688 10560507904 1109990192 11.932 97 34 66 0 1190625520 74124640 6510688
05:37:02 44205 8192000000 10109572144 10530631680 1095363872 11.794 96 19 38 2 1381267104 282456464 3446768
05:38:47 64509 8192000000 10055818720 10514427904 1090757280 11.750 96 14 27 0 1125331792 32292880 2281632
05:40:53 151890 8192000000 10293603936 10765279232 1116494912 11.994 99 21 42 0 1166659504 45777728 4386864
05:44:34 49160 8192000000 10079807680 10553561088 1138846128 12.205 100 6 12 2 1219038752 78948480 1244144
05:46:26 62070 8192000000 10105496400 10540650496 1128652576 12.109 99 21 42 2 1171198496 37910528 4635392
05:48:29 53625 8192000000 10108326720 10579660800 1128584864 12.108 99 21 39 2 1232801200 99631632 4584704
05:50:23 96614 8192000000 10100978016 10556837888 1069316992 11.546 94 15 28 1 1171263952 99207120 2739840
05:53:00 42755 8192000000 10374350128 10800726016 1132686448 12.147 100 29 58 1 1228226240 89597088 5942704
05:54:43 36170 8192000000 10081662528 10514653184 1097648896 11.815 97 28 55 0 1126852624 24240048 4963680
05:56:22 69270 8192000000 10067480032 10493444096 1116081072 11.990 99 13 26 2 1176703168 58506256 2115840
05:58:33 14998 8192000000 10081273552 10496557056 1117668720 12.005 99 51 98 1 1159887344 32534560 9684064
05:59:48 52638 8192000000 10053978592 10498265088 1126646880 12.090 100 19 38 0 1161398432 30696944 4054608
06:01:50 61879 8192000000 10044355520 10501967872 1114728672 11.977 99 14 28 1 1377978272 260112688 3136912
06:03:54 68405 8192000000 10089570608 10553864192 1041301056 11.277 93 13 26 1 1116290608 71900112 3089440
06:06:02 138457 8192000000 10050672448 10476408832 1039172304 11.257 94 16 32 0 1110914320 68566976 3175040
06:09:33 72654 8192000000 10040440128 10508800000 1087516624 11.719 98 16 33 0 1145570496 55007136 3046736
06:11:46 29193 8192000000 10065206032 10467930112 1076716368 11.616 98 37 75 0 1129557152 45706448 7134336
06:13:15 36657 8192000000 10086204944 10504671232 1098975232 11.828 99 30 60 1 1171504608 66616240 5913136
06:14:53 135517 8192000000 10051172912 10478829568 1102245568 11.859 99 26 52 0 1143927728 36590400 5091760
06:18:14 104528 8192000000 10049473360 10493636608 1086761520 11.712 97 12 24 0 1122606704 33411696 2433488
06:20:58 66926 8192000000 10057281216 10539872256 1118998384 12.018 100 13 26 0 1157878560 36508272 2371904
06:23:35 117018 8192000000 10087676096 10539884544 1120251312 12.029 98 17 34 0 1177804912 54252816 3300784
06:26:42 64636 8192000000 10311723680 10778255360 1124033808 12.065 98 24 48 0 1646792080 518165984 4592288
06:28:46 55138 8192000000 10107133280 10603200512 1132365008 12.144 99 32 64 2 1227940624 89508592 6067024
06:30:42 54422 8192000000 10142095040 10584846336 1122283744 12.049 97 37 74 0 1205799760 75652640 7863376
06:32:37 64363 8192000000 10120041840 10605756416 1138323920 12.200 100 10 20 0 1437670912 297352976 1994016
06:35:57 172553 8192000000 10097650112 10551406592 1123733120 12.062 99 17 31 2 1158680912 31780928 3166864
06:41:35 55540 8192000000 10159091504 10654339072 1129175632 12.114 99 17 34 1 1257505040 124474480 3854928
06:43:32 73347 8192000000 10101186880 10549682176 1121043696 12.037 99 16 32 0 1197395888 72905808 3446384
06:45:55 51616 8192000000 10321344192 10764115968 1127124192 12.094 100 26 52 1 1174119296 41737168 5257936
06:47:57 53097 8192000000 10340315520 10785689600 1106608560 11.900 98 30 60 0 1191950592 79120288 6221744
06:49:53 81336 8192000000 10050668048 10500530176 1066434688 11.518 95 16 32 2 1118223856 48267232 3521936

Memory consumption, total, chart

Metadata cache size, chart

Statements activity, chart


Completed "Memory consumption, metadata cache, attachments activity". Done for 00:00:14, from 06-10-2020 06:54:04 to 06-10-2020 06:54:18.

Exceptions occured during test was in run

FB_MNEMONA CNT UNIT FB_GDSCODE
user_exc 101 v_add_invoice_to_stock 335544517
user_exc 10 v_cancel_supplier_invoice 335544517

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

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          248543
MON$OLDEST_ACTIVE               248650
MON$OLDEST_SNAPSHOT             248650
MON$NEXT_TRANSACTION            248650
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                       2099008
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             763
MON$NEXT_STATEMENT              53


ISQL Version: LI-V4.0.0.2214 Firebird 4.0 Release Candidate 1
Server version:
Firebird/Linux/AMD/Intel/x64 (access method), version "LI-V4.0.0.2214 Firebird 4.0 Release Candidate 1"
Firebird/Linux/AMD/Intel/x64 (remote server), version "LI-V4.0.0.2214 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.2214 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 ---
:72: 
:73: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:74:     /opt/fb40/bin/fbguard: /opt/fb40/bin/firebird terminated abnormally (-1)
:75: 
:76: 
:77: 
:78: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:79:     /opt/fb40/bin/fbguard: guardian starting /opt/fb40/bin/firebird
:80: 
:81: 
:82: 
:83: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:84:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:85:     Uncommitted work may have been lost.
:86:     Error reading data from the connection.
:87: 
:88: 
:89: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:90:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:91:     Uncommitted work may have been lost.
:92:     Error reading data from the connection.
:93: 
:94: 
:95: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:96:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:97:     Uncommitted work may have been lost.
:98:     Error reading data from the connection.
:99: 
:100: 
:101: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:102:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:103:     Uncommitted work may have been lost.
:104:     Error reading data from the connection.
:105: 
:106: 
:107: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:108:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:109:     Uncommitted work may have been lost.
:110:     Error reading data from the connection.
:111: 
:112: 
:113: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:114:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:115:     Uncommitted work may have been lost.
:116:     Error reading data from the connection.
:117: 
:118: 
:119: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:120:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:121:     Uncommitted work may have been lost.
:122:     Error reading data from the connection.
:123: 
:124: 
:125: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:126:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:127:     Uncommitted work may have been lost.
:128:     Error reading data from the connection.
:129: 
:130: 
:131: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:132:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:133:     Uncommitted work may have been lost.
:134:     Error reading data from the connection.
:135: 
:136: 
:137: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:138:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:139:     Uncommitted work may have been lost.
:140:     Error reading data from the connection.
:141: 
:142: 
:143: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:144:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:145:     Uncommitted work may have been lost.
:146:     Error reading data from the connection.
:147: 
:148: 
:149: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:150:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:151:     Uncommitted work may have been lost.
:152:     Error reading data from the connection.
:153: 
:154: 
:155: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:156:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:157:     Uncommitted work may have been lost.
:158:     Error reading data from the connection.
:159: 
:160: 
:161: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:162:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:163:     Uncommitted work may have been lost.
:164:     Error reading data from the connection.
:165: 
:166: 
:167: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:168:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:169:     Uncommitted work may have been lost.
:170:     Error reading data from the connection.
:171: 
:172: 
:173: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:174:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:175:     Uncommitted work may have been lost.
:176:     Error reading data from the connection.
:177: 
:178: 
:179: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:180:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:181:     Uncommitted work may have been lost.
:182:     Error reading data from the connection.
:183: 
:184: 
:185: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:186:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:187:     Uncommitted work may have been lost.
:188:     Error reading data from the connection.
:189: 
:190: 
:191: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:192:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:193:     Uncommitted work may have been lost.
:194:     Error reading data from the connection.
:195: 
:196: 
:197: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:198:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:199:     Uncommitted work may have been lost.
:200:     Error reading data from the connection.
:201: 
:202: 
:203: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:204:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:205:     Uncommitted work may have been lost.
:206:     Error reading data from the connection.
:207: 
:208: 
:209: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:210:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:211:     Uncommitted work may have been lost.
:212:     Error reading data from the connection.
:213: 
:214: 
:215: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:216:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:217:     Uncommitted work may have been lost.
:218:     Error reading data from the connection.
:219: 
:220: 
:221: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:222:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:223:     Uncommitted work may have been lost.
:224:     Error reading data from the connection.
:225: 
:226: 
:227: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:228:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:229:     Uncommitted work may have been lost.
:230:     Error reading data from the connection.
:231: 
:232: 
:233: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:234:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:235:     Uncommitted work may have been lost.
:236:     Error reading data from the connection.
:237: 
:238: 
:239: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:240:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:241:     Uncommitted work may have been lost.
:242:     Error reading data from the connection.
:243: 
:244: 
:245: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:246:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:247:     Uncommitted work may have been lost.
:248:     Error reading data from the connection.
:249: 
:250: 
:251: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:252:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:253:     Uncommitted work may have been lost.
:254:     Error reading data from the connection.
:255: 
:256: 
:257: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:258:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:259:     Uncommitted work may have been lost.
:260:     Error reading data from the connection.
:261: 
:262: 
:263: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:264:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:265:     Uncommitted work may have been lost.
:266:     Error reading data from the connection.
:267: 
:268: 
:269: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:270:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:271:     Uncommitted work may have been lost.
:272:     Error reading data from the connection.
:273: 
:274: 
:275: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:276:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:277:     Uncommitted work may have been lost.
:278:     Error reading data from the connection.
:279: 
:280: 
:281: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:282:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:283:     Uncommitted work may have been lost.
:284:     Error reading data from the connection.
:285: 
:286: 
:287: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:288:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:289:     Uncommitted work may have been lost.
:290:     Error reading data from the connection.
:291: 
:292: 
:293: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:294:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:295:     Uncommitted work may have been lost.
:296:     Error reading data from the connection.
:297: 
:298: 
:299: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:300:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:301:     Uncommitted work may have been lost.
:302:     Error reading data from the connection.
:303: 
:304: 
:305: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:306:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:307:     Uncommitted work may have been lost.
:308:     Error reading data from the connection.
:309: 
:310: 
:311: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:312:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:313:     Uncommitted work may have been lost.
:314:     Error reading data from the connection.
:315: 
:316: 
:317: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:318:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:319:     Uncommitted work may have been lost.
:320:     Error reading data from the connection.
:321: 
:322: 
:323: mscs-test-161.budzdorov.ru    Tue Oct  6 06:53:13 2020
:324:     REMOTE INTERFACE/gds__detach: Unsuccesful detach from database.
:325:     Uncommitted work may have been lost.
:326:     Error reading data from the connection.
:327: 
--- end of diff output ---

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

06.10.20 06:54:23. 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: 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-06 06:54:25 NO_SEVERE_ERRORS_FOUND
06.10.20 06:54:27. End of report.