-
Notifications
You must be signed in to change notification settings - Fork 71
/
producer_plugin.cpp
2899 lines (2481 loc) · 138 KB
/
producer_plugin.cpp
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
427
428
429
430
431
432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
449
450
451
452
453
454
455
456
457
458
459
460
461
462
463
464
465
466
467
468
469
470
471
472
473
474
475
476
477
478
479
480
481
482
483
484
485
486
487
488
489
490
491
492
493
494
495
496
497
498
499
500
501
502
503
504
505
506
507
508
509
510
511
512
513
514
515
516
517
518
519
520
521
522
523
524
525
526
527
528
529
530
531
532
533
534
535
536
537
538
539
540
541
542
543
544
545
546
547
548
549
550
551
552
553
554
555
556
557
558
559
560
561
562
563
564
565
566
567
568
569
570
571
572
573
574
575
576
577
578
579
580
581
582
583
584
585
586
587
588
589
590
591
592
593
594
595
596
597
598
599
600
601
602
603
604
605
606
607
608
609
610
611
612
613
614
615
616
617
618
619
620
621
622
623
624
625
626
627
628
629
630
631
632
633
634
635
636
637
638
639
640
641
642
643
644
645
646
647
648
649
650
651
652
653
654
655
656
657
658
659
660
661
662
663
664
665
666
667
668
669
670
671
672
673
674
675
676
677
678
679
680
681
682
683
684
685
686
687
688
689
690
691
692
693
694
695
696
697
698
699
700
701
702
703
704
705
706
707
708
709
710
711
712
713
714
715
716
717
718
719
720
721
722
723
724
725
726
727
728
729
730
731
732
733
734
735
736
737
738
739
740
741
742
743
744
745
746
747
748
749
750
751
752
753
754
755
756
757
758
759
760
761
762
763
764
765
766
767
768
769
770
771
772
773
774
775
776
777
778
779
780
781
782
783
784
785
786
787
788
789
790
791
792
793
794
795
796
797
798
799
800
801
802
803
804
805
806
807
808
809
810
811
812
813
814
815
816
817
818
819
820
821
822
823
824
825
826
827
828
829
830
831
832
833
834
835
836
837
838
839
840
841
842
843
844
845
846
847
848
849
850
851
852
853
854
855
856
857
858
859
860
861
862
863
864
865
866
867
868
869
870
871
872
873
874
875
876
877
878
879
880
881
882
883
884
885
886
887
888
889
890
891
892
893
894
895
896
897
898
899
900
901
902
903
904
905
906
907
908
909
910
911
912
913
914
915
916
917
918
919
920
921
922
923
924
925
926
927
928
929
930
931
932
933
934
935
936
937
938
939
940
941
942
943
944
945
946
947
948
949
950
951
952
953
954
955
956
957
958
959
960
961
962
963
964
965
966
967
968
969
970
971
972
973
974
975
976
977
978
979
980
981
982
983
984
985
986
987
988
989
990
991
992
993
994
995
996
997
998
999
1000
#include <eosio/producer_plugin/producer_plugin.hpp>
#include <eosio/producer_plugin/block_timing_util.hpp>
#include <eosio/chain/plugin_interface.hpp>
#include <eosio/chain/global_property_object.hpp>
#include <eosio/chain/generated_transaction_object.hpp>
#include <eosio/chain/snapshot.hpp>
#include <eosio/chain/snapshot_scheduler.hpp>
#include <eosio/chain/subjective_billing.hpp>
#include <eosio/chain/thread_utils.hpp>
#include <eosio/chain/unapplied_transaction_queue.hpp>
#include <eosio/resource_monitor_plugin/resource_monitor_plugin.hpp>
#include <fc/io/json.hpp>
#include <fc/log/logger_config.hpp>
#include <fc/scoped_exit.hpp>
#include <fc/time.hpp>
#include <boost/asio.hpp>
#include <boost/date_time/posix_time/posix_time.hpp>
#include <boost/signals2/connection.hpp>
#include <cstdint>
#include <iostream>
#include <algorithm>
#include <mutex>
using boost::signals2::scoped_connection;
using std::string;
using std::vector;
#undef FC_LOG_AND_DROP
#define LOG_AND_DROP() \
catch (const guard_exception& e) { \
chain_plugin::handle_guard_exception(e); \
} \
catch (const std::bad_alloc&) { \
chain_apis::api_base::handle_bad_alloc(); \
} \
catch (boost::interprocess::bad_alloc&) { \
chain_apis::api_base::handle_db_exhaustion(); \
} \
catch (fc::exception & er) { \
wlog("${details}", ("details", er.to_detail_string())); \
} \
catch (const std::exception& e) { \
fc::exception fce(FC_LOG_MESSAGE(warn, "std::exception: ${what}: ", ("what", e.what())), \
fc::std_exception_code, \
BOOST_CORE_TYPEID(e).name(), \
e.what()); \
wlog("${details}", ("details", fce.to_detail_string())); \
} \
catch (...) { \
fc::unhandled_exception e(FC_LOG_MESSAGE(warn, "unknown: ", ), std::current_exception());\
wlog("${details}", ("details", e.to_detail_string())); \
}
const std::string logger_name("producer_plugin");
fc::logger _log;
const std::string trx_successful_trace_logger_name("transaction_success_tracing");
fc::logger _trx_successful_trace_log;
const std::string trx_failed_trace_logger_name("transaction_failure_tracing");
fc::logger _trx_failed_trace_log;
const std::string trx_trace_success_logger_name("transaction_trace_success");
fc::logger _trx_trace_success_log;
const std::string trx_trace_failure_logger_name("transaction_trace_failure");
fc::logger _trx_trace_failure_log;
const std::string trx_logger_name("transaction");
fc::logger _trx_log;
const std::string transient_trx_successful_trace_logger_name("transient_trx_success_tracing");
fc::logger _transient_trx_successful_trace_log;
const std::string transient_trx_failed_trace_logger_name("transient_trx_failure_tracing");
fc::logger _transient_trx_failed_trace_log;
namespace eosio {
static auto _producer_plugin = application::register_plugin<producer_plugin>();
using namespace eosio::chain;
using namespace eosio::chain::plugin_interface;
namespace {
bool exception_is_exhausted(const fc::exception& e) {
auto code = e.code();
return (code == block_cpu_usage_exceeded::code_value) ||
(code == block_net_usage_exceeded::code_value) ||
(code == deadline_exception::code_value) ||
(code == ro_trx_vm_oc_compile_temporary_failure::code_value);
}
} // namespace
namespace {
// track multiple failures on unapplied transactions
class account_failures {
public:
account_failures() = default;
void set_max_failures_per_account(uint32_t max_failures, uint32_t size) {
max_failures_per_account = max_failures;
reset_window_size_in_num_blocks = size;
}
void add(const account_name& n, const fc::exception& e) {
auto& fa = failed_accounts[n];
++fa.num_failures;
fa.add(n, e);
}
// return true if exceeds max_failures_per_account and should be dropped
bool failure_limit(const account_name& n) {
auto fitr = failed_accounts.find(n);
if (fitr != failed_accounts.end() && fitr->second.num_failures >= max_failures_per_account) {
++fitr->second.num_failures;
return true;
}
return false;
}
void report_and_clear(uint32_t block_num, const chain::subjective_billing& sub_bill) {
if (last_reset_block_num != block_num && (block_num % reset_window_size_in_num_blocks == 0)) {
report(block_num, sub_bill);
failed_accounts.clear();
last_reset_block_num = block_num;
}
}
fc::time_point next_reset_timepoint(uint32_t current_block_num, fc::time_point current_block_time) const {
auto num_blocks_to_reset = reset_window_size_in_num_blocks - (current_block_num % reset_window_size_in_num_blocks);
return current_block_time + fc::milliseconds(num_blocks_to_reset * eosio::chain::config::block_interval_ms);
}
private:
void report(uint32_t block_num, const chain::subjective_billing& sub_bill) const {
if (_log.is_enabled(fc::log_level::debug)) {
auto now = fc::time_point::now();
for (const auto& e : failed_accounts) {
std::string reason;
if (e.second.is_deadline())
reason += "deadline";
if (e.second.is_tx_cpu_usage()) {
if (!reason.empty())
reason += ", ";
reason += "tx_cpu_usage";
}
if (e.second.is_eosio_assert()) {
if (!reason.empty())
reason += ", ";
reason += "assert";
}
if (e.second.is_other()) {
if (!reason.empty())
reason += ", ";
reason += "other";
}
fc_dlog(_log, "Failed ${n} trxs, account: ${a}, sub bill: ${b}us, reason: ${r}",
("n", e.second.num_failures)("b", sub_bill.get_subjective_bill(e.first, now))("a", e.first)("r", reason));
}
}
}
struct account_failure {
enum class ex_fields : uint8_t {
ex_deadline_exception = 1,
ex_tx_cpu_usage_exceeded = 2,
ex_eosio_assert_exception = 4,
ex_other_exception = 8
};
void add(const account_name& n, const fc::exception& e) {
auto exception_code = e.code();
if (exception_code == tx_cpu_usage_exceeded::code_value) {
ex_flags = set_field(ex_flags, ex_fields::ex_tx_cpu_usage_exceeded);
} else if (exception_code == deadline_exception::code_value) {
ex_flags = set_field(ex_flags, ex_fields::ex_deadline_exception);
} else if (exception_code == eosio_assert_message_exception::code_value ||
exception_code == eosio_assert_code_exception::code_value) {
ex_flags = set_field(ex_flags, ex_fields::ex_eosio_assert_exception);
} else {
ex_flags = set_field(ex_flags, ex_fields::ex_other_exception);
fc_dlog(_log, "Failed trx, account: ${a}, reason: ${r}, except: ${e}", ("a", n)("r", exception_code)("e", e));
}
}
bool is_deadline() const { return has_field(ex_flags, ex_fields::ex_deadline_exception); }
bool is_tx_cpu_usage() const { return has_field(ex_flags, ex_fields::ex_tx_cpu_usage_exceeded); }
bool is_eosio_assert() const { return has_field(ex_flags, ex_fields::ex_eosio_assert_exception); }
bool is_other() const { return has_field(ex_flags, ex_fields::ex_other_exception); }
uint32_t num_failures = 0;
uint8_t ex_flags = 0;
};
std::map<account_name, account_failure> failed_accounts;
uint32_t max_failures_per_account = 3;
uint32_t last_reset_block_num = 0;
uint32_t reset_window_size_in_num_blocks = 1;
};
struct block_time_tracker {
struct trx_time_tracker {
enum class time_status { success, fail, other };
trx_time_tracker(block_time_tracker& btt, bool transient)
: _block_time_tracker(btt), _is_transient(transient) {}
trx_time_tracker(trx_time_tracker&&) = default;
trx_time_tracker() = delete;
trx_time_tracker(const trx_time_tracker&) = delete;
trx_time_tracker& operator=(const trx_time_tracker&) = delete;
trx_time_tracker& operator=(trx_time_tracker&&) = delete;
void trx_success() { _time_status = time_status::success; }
// Neither success nor fail, will be reported as other
void cancel() { _time_status = time_status::other; }
// updates block_time_tracker
~trx_time_tracker() {
switch (_time_status) {
case time_status::success:
_block_time_tracker.add_success_time(_is_transient);
break;
case time_status::fail:
_block_time_tracker.add_fail_time(_is_transient);
break;
case time_status::other:
_block_time_tracker.add_other_time();
break;
}
}
private:
block_time_tracker& _block_time_tracker;
time_status _time_status = time_status::fail;
bool _is_transient;
};
trx_time_tracker start_trx(bool is_transient, fc::time_point now = fc::time_point::now()) {
assert(!paused);
add_other_time(now);
return {*this, is_transient};
}
void add_other_time(fc::time_point now = fc::time_point::now()) {
assert(!paused);
other_time += now - last_time_point;
last_time_point = now;
}
fc::microseconds add_idle_time(fc::time_point now = fc::time_point::now()) {
assert(!paused);
auto dur = now - last_time_point;
block_idle_time += dur;
last_time_point = now; // guard against calling add_idle_time() twice in a row.
return dur;
}
// assumes idle time before pause
void pause(fc::time_point now = fc::time_point::now()) {
assert(!paused);
add_idle_time(now);
paused = true;
}
// assumes last call was to pause
void unpause(fc::time_point now = fc::time_point::now()) {
assert(paused);
paused = false;
auto pause_time = now - last_time_point;
clear_time_point += pause_time;
last_time_point = now;
}
void report(uint32_t block_num, account_name producer, producer_plugin::speculative_block_metrics& metrics) {
using namespace std::string_literals;
assert(!paused);
auto now = fc::time_point::now();
if( _log.is_enabled( fc::log_level::debug ) ) {
auto diff = now - clear_time_point - block_idle_time - trx_success_time - trx_fail_time - transient_trx_time - other_time;
fc_dlog( _log, "Block #${n} ${p} trx idle: ${i}us out of ${t}us, success: ${sn}, ${s}us, fail: ${fn}, ${f}us, "
"transient: ${ttn}, ${tt}us, other: ${o}us${rest}",
("n", block_num)("p", producer)
("i", block_idle_time)("t", now - clear_time_point)("sn", trx_success_num)("s", trx_success_time)
("fn", trx_fail_num)("f", trx_fail_time)
("ttn", transient_trx_num)("tt", transient_trx_time)
("o", other_time)("rest", diff.count() > 5 ? ", diff: "s + std::to_string(diff.count()) + "us"s : ""s ) );
}
metrics.block_producer = producer;
metrics.block_num = block_num;
metrics.block_total_time_us = (now - clear_time_point).count();
metrics.block_idle_us = block_idle_time.count();
metrics.num_success_trx = trx_success_num;
metrics.success_trx_time_us = trx_success_time.count();
metrics.num_fail_trx = trx_fail_num;
metrics.fail_trx_time_us = trx_fail_time.count();
metrics.num_transient_trx = transient_trx_num;
metrics.transient_trx_time_us = transient_trx_time.count();
metrics.block_other_time_us = other_time.count();
}
void clear() {
assert(!paused);
block_idle_time = trx_fail_time = trx_success_time = transient_trx_time = other_time = fc::microseconds{};
trx_fail_num = trx_success_num = transient_trx_num = 0;
clear_time_point = last_time_point = fc::time_point::now();
}
private:
void add_success_time(bool is_transient) {
assert(!paused);
auto now = fc::time_point::now();
if( is_transient ) {
// transient time includes both success and fail time
transient_trx_time += now - last_time_point;
++transient_trx_num;
} else {
trx_success_time += now - last_time_point;
++trx_success_num;
}
last_time_point = now;
}
void add_fail_time(bool is_transient) {
assert(!paused);
auto now = fc::time_point::now();
if( is_transient ) {
// transient time includes both success and fail time
transient_trx_time += now - last_time_point;
++transient_trx_num;
} else {
trx_fail_time += now - last_time_point;
++trx_fail_num;
}
last_time_point = now;
}
private:
fc::microseconds block_idle_time;
uint32_t trx_success_num = 0;
uint32_t trx_fail_num = 0;
uint32_t transient_trx_num = 0;
fc::microseconds trx_success_time;
fc::microseconds trx_fail_time;
fc::microseconds transient_trx_time;
fc::microseconds other_time;
fc::time_point last_time_point{fc::time_point::now()};
fc::time_point clear_time_point{fc::time_point::now()};
bool paused = false;
};
} // anonymous namespace
class producer_plugin_impl : public std::enable_shared_from_this<producer_plugin_impl> {
public:
producer_plugin_impl(boost::asio::io_service& io)
: _timer(io)
, _transaction_ack_channel(app().get_channel<compat::channels::transaction_ack>())
, _ro_timer(io) {}
void schedule_production_loop();
void schedule_maybe_produce_block(bool exhausted);
void produce_block();
bool maybe_produce_block();
bool block_is_exhausted() const;
bool remove_expired_trxs(const fc::time_point& deadline);
bool process_unapplied_trxs(const fc::time_point& deadline);
bool retire_deferred_trxs(const fc::time_point& deadline);
bool process_incoming_trxs(const fc::time_point& deadline, unapplied_transaction_queue::iterator& itr);
struct push_result {
bool block_exhausted = false;
bool trx_exhausted = false;
bool failed = false;
};
push_result push_transaction(const fc::time_point& block_deadline,
const transaction_metadata_ptr& trx,
bool api_trx,
bool return_failure_trace,
block_time_tracker::trx_time_tracker& trx_tracker,
const next_function<transaction_trace_ptr>& next);
push_result handle_push_result(const transaction_metadata_ptr& trx,
const next_function<transaction_trace_ptr>& next,
const fc::time_point& start,
chain::controller& chain,
const transaction_trace_ptr& trace,
bool return_failure_trace,
bool disable_subjective_enforcement,
account_name first_auth,
int64_t sub_bill,
uint32_t prev_billed_cpu_time_us);
void log_trx_results(const transaction_metadata_ptr& trx, const transaction_trace_ptr& trace, const fc::time_point& start);
void log_trx_results(const transaction_metadata_ptr& trx, const fc::exception_ptr& except_ptr);
void log_trx_results(const packed_transaction_ptr& trx,
const transaction_trace_ptr& trace,
const fc::exception_ptr& except_ptr,
uint32_t billed_cpu_us,
const fc::time_point& start,
bool is_transient);
void add_greylist_accounts(const producer_plugin::greylist_params& params) {
EOS_ASSERT(params.accounts.size() > 0, chain::invalid_http_request, "At least one account is required");
chain::controller& chain = chain_plug->chain();
for (auto& acc : params.accounts) {
chain.add_resource_greylist(acc);
}
}
void remove_greylist_accounts(const producer_plugin::greylist_params& params) {
EOS_ASSERT(params.accounts.size() > 0, chain::invalid_http_request, "At least one account is required");
chain::controller& chain = chain_plug->chain();
for (auto& acc : params.accounts) {
chain.remove_resource_greylist(acc);
}
}
producer_plugin::greylist_params get_greylist() const {
chain::controller& chain = chain_plug->chain();
producer_plugin::greylist_params result;
const auto& list = chain.get_resource_greylist();
result.accounts.reserve(list.size());
for (auto& acc : list) {
result.accounts.push_back(acc);
}
return result;
}
producer_plugin::integrity_hash_information get_integrity_hash() {
chain::controller& chain = chain_plug->chain();
auto reschedule = fc::make_scoped_exit([this]() { schedule_production_loop(); });
if (chain.is_building_block()) {
// abort the pending block
abort_block();
} else {
reschedule.cancel();
}
return {chain.head_block_id(), chain.calculate_integrity_hash()};
}
void create_snapshot(producer_plugin::next_function<chain::snapshot_scheduler::snapshot_information> next) {
chain::controller& chain = chain_plug->chain();
auto reschedule = fc::make_scoped_exit([this]() { schedule_production_loop(); });
auto predicate = [&]() -> void {
if (chain.is_building_block()) {
// abort the pending block
abort_block();
} else {
reschedule.cancel();
}
};
_snapshot_scheduler.create_snapshot(std::move(next), chain, predicate);
}
void update_runtime_options(const producer_plugin::runtime_options& options);
producer_plugin::runtime_options get_runtime_options() const {
return {_max_transaction_time_ms,
_max_irreversible_block_age_us.count() < 0 ? -1 : _max_irreversible_block_age_us.count() / 1'000'000,
get_produce_block_offset().count() / 1'000,
chain_plug->chain().get_subjective_cpu_leeway() ? chain_plug->chain().get_subjective_cpu_leeway()->count()
: std::optional<int32_t>(),
chain_plug->chain().get_greylist_limit()};
}
void schedule_protocol_feature_activations(const producer_plugin::scheduled_protocol_feature_activations& schedule);
void plugin_shutdown();
void plugin_startup();
void plugin_initialize(const boost::program_options::variables_map& options);
boost::program_options::variables_map _options;
bool _production_enabled = false;
bool _pause_production = false;
using signature_provider_type = signature_provider_plugin::signature_provider_type;
std::map<chain::public_key_type, signature_provider_type> _signature_providers;
std::set<chain::account_name> _producers;
boost::asio::deadline_timer _timer;
block_timing_util::producer_watermarks _producer_watermarks;
pending_block_mode _pending_block_mode = pending_block_mode::speculating;
unapplied_transaction_queue _unapplied_transactions;
size_t _thread_pool_size = config::default_controller_thread_pool_size;
named_thread_pool<struct prod> _thread_pool;
std::atomic<int32_t> _max_transaction_time_ms; // modified by app thread, read by net_plugin thread pool
std::atomic<uint32_t> _received_block{0}; // modified by net_plugin thread pool
fc::microseconds _max_irreversible_block_age_us;
// produce-block-offset is in terms of the complete round, internally use calculated value for each block of round
fc::microseconds _produce_block_cpu_effort;
fc::time_point _pending_block_deadline;
uint32_t _max_block_cpu_usage_threshold_us = 0;
uint32_t _max_block_net_usage_threshold_bytes = 0;
bool _disable_subjective_p2p_billing = true;
bool _disable_subjective_api_billing = true;
fc::time_point _irreversible_block_time;
std::vector<chain::digest_type> _protocol_features_to_activate;
bool _protocol_features_signaled = false; // to mark whether it has been signaled in start_block
chain_plugin* chain_plug = nullptr;
compat::channels::transaction_ack::channel_type& _transaction_ack_channel;
incoming::methods::block_sync::method_type::handle _incoming_block_sync_provider;
incoming::methods::transaction_async::method_type::handle _incoming_transaction_async_provider;
account_failures _account_fails;
block_time_tracker _time_tracker;
std::optional<scoped_connection> _accepted_block_connection;
std::optional<scoped_connection> _accepted_block_header_connection;
std::optional<scoped_connection> _irreversible_block_connection;
std::optional<scoped_connection> _block_start_connection;
/*
* HACK ALERT
* Boost timers can be in a state where a handler has not yet executed but is not abortable.
* As this method needs to mutate state handlers depend on for proper functioning to maintain
* invariants for other code (namely accepting incoming transactions in a nearly full block)
* the handlers capture a corelation ID at the time they are set. When they are executed
* they must check that correlation_id against the global ordinal. If it does not match that
* implies that this method has been called with the handler in the state where it should be
* cancelled but wasn't able to be.
*/
uint32_t _timer_corelation_id = 0;
// path to write the snapshots to
std::filesystem::path _snapshots_dir;
// async snapshot scheduler
snapshot_scheduler _snapshot_scheduler;
std::function<void(producer_plugin::produced_block_metrics)> _update_produced_block_metrics;
std::function<void(producer_plugin::speculative_block_metrics)> _update_speculative_block_metrics;
std::function<void(producer_plugin::incoming_block_metrics)> _update_incoming_block_metrics;
// ro for read-only
struct ro_trx_t {
transaction_metadata_ptr trx;
next_func_t next;
};
// The queue storing previously exhausted read-only transactions to be re-executed by read-only threads
// thread-safe
class ro_trx_queue_t {
public:
void push_front(ro_trx_t&& t) {
std::lock_guard g(mtx);
queue.push_front(std::move(t));
}
bool empty() const {
std::lock_guard g(mtx);
return queue.empty();
}
bool pop_front(ro_trx_t& t) {
std::unique_lock g(mtx);
if (queue.empty())
return false;
t = queue.front();
queue.pop_front();
return true;
}
private:
mutable std::mutex mtx;
deque<ro_trx_t> queue; // boost deque which is faster than std::deque
};
uint32_t _ro_thread_pool_size{0};
// In EOS VM OC tierup, 10 pages (11 slices) virtual memory is reserved for
// each read-only thread and 528 pages (529 slices) for the main-thread memory.
// With maximum 128 read-only threads, virtual memory required by OC is
// 15TB (OC's main thread uses 4TB VM (by 529 slices) and the read-only
// threads use 11TB (128 * 11 * 8GB)). It is about 11.7% of total VM space
// in a 64-bit Linux machine (about 128TB).
static constexpr uint32_t _ro_max_threads_allowed{128};
static constexpr uint32_t _ro_default_threads_nonproducer{3};
named_thread_pool<struct read> _ro_thread_pool;
fc::microseconds _ro_write_window_time_us{200000};
fc::microseconds _ro_read_window_time_us{60000};
static constexpr fc::microseconds _ro_read_window_minimum_time_us{10000};
fc::microseconds _ro_read_window_effective_time_us{0}; // calculated during option initialization
std::atomic<int64_t> _ro_all_threads_exec_time_us; // total time spent by all threads executing transactions.
// use atomic for simplicity and performance
fc::time_point _ro_read_window_start_time;
fc::time_point _ro_window_deadline; // only modified on app thread, read-window deadline or write-window deadline
boost::asio::deadline_timer _ro_timer; // only accessible from the main thread
fc::microseconds _ro_max_trx_time_us{0}; // calculated during option initialization
ro_trx_queue_t _ro_exhausted_trx_queue;
std::atomic<uint32_t> _ro_num_active_exec_tasks{0};
std::vector<std::future<bool>> _ro_exec_tasks_fut;
void start_write_window();
void switch_to_write_window();
void switch_to_read_window();
bool read_only_execution_task(uint32_t pending_block_num);
void repost_exhausted_transactions(const fc::time_point& deadline);
bool push_read_only_transaction(transaction_metadata_ptr trx, next_function<transaction_trace_ptr> next);
void set_produce_block_offset(uint32_t produce_block_offset_ms) {
EOS_ASSERT(produce_block_offset_ms < (config::producer_repetitions * config::block_interval_ms), plugin_config_exception,
"produce-block-offset-ms ${p} must be [0 - ${max})", ("p", produce_block_offset_ms)("max", config::producer_repetitions * config::block_interval_ms));
_produce_block_cpu_effort = fc::microseconds(config::block_interval_us - (produce_block_offset_ms*1000 / config::producer_repetitions) );
}
fc::microseconds get_produce_block_offset() const {
return fc::milliseconds( (config::block_interval_ms * config::producer_repetitions) -
((_produce_block_cpu_effort.count() / 1000) * config::producer_repetitions) );
}
void on_block(const block_state_ptr& bsp) {
auto& chain = chain_plug->chain();
auto before = _unapplied_transactions.size();
_unapplied_transactions.clear_applied(bsp);
chain.get_mutable_subjective_billing().on_block(_log, bsp, fc::time_point::now());
if (before > 0) {
fc_dlog(_log, "Removed applied transactions before: ${before}, after: ${after}", ("before", before)("after", _unapplied_transactions.size()));
}
}
void on_block_header(const block_state_ptr& bsp) {
if (_producers.contains(bsp->header.producer))
_producer_watermarks.consider_new_watermark(bsp->header.producer, bsp->block_num, bsp->block->timestamp);
}
void on_irreversible_block(const signed_block_ptr& lib) {
const chain::controller& chain = chain_plug->chain();
EOS_ASSERT(chain.is_write_window(), producer_exception, "write window is expected for on_irreversible_block signal");
_irreversible_block_time = lib->timestamp.to_time_point();
_snapshot_scheduler.on_irreversible_block(lib, chain);
}
void abort_block() {
auto& chain = chain_plug->chain();
std::optional<std::tuple<uint32_t, account_name>> block_info;
if( chain.is_building_block() ) {
block_info = std::make_tuple(chain.pending_block_num(), chain.pending_block_producer());
}
_unapplied_transactions.add_aborted( chain.abort_block() );
_time_tracker.add_other_time();
if (block_info) {
auto[block_num, block_producer] = *block_info;
producer_plugin::speculative_block_metrics metrics;
_time_tracker.report(block_num, block_producer, metrics);
if (_update_speculative_block_metrics)
_update_speculative_block_metrics(metrics);
}
_time_tracker.clear();
}
bool on_incoming_block(const signed_block_ptr& block, const std::optional<block_id_type>& block_id, const block_state_ptr& bsp) {
auto& chain = chain_plug->chain();
if (in_producing_mode()) {
fc_wlog(_log, "dropped incoming block #${num} id: ${id}", ("num", block->block_num())("id", block_id ? (*block_id).str() : "UNKNOWN"));
return false;
}
// start a new speculative block, speculative start_block may have been interrupted
auto ensure = fc::make_scoped_exit([this]() { schedule_production_loop(); });
auto now = fc::time_point::now();
const auto& id = block_id ? *block_id : block->calculate_id();
auto blk_num = block->block_num();
if (now - block->timestamp < fc::minutes(5) || (blk_num % 1000 == 0)) // only log every 1000 during sync
fc_dlog(_log, "received incoming block ${n} ${id}", ("n", blk_num)("id", id));
_time_tracker.add_idle_time(now);
EOS_ASSERT(block->timestamp < (now + fc::seconds(7)), block_from_the_future, "received a block from the future, ignoring it: ${id}", ("id", id));
/* de-dupe here... no point in aborting block if we already know the block */
auto existing = chain.fetch_block_by_id(id);
if (existing) {
return true; // return true because the block is valid
}
// start processing of block
std::future<block_state_ptr> bsf;
if (!bsp) {
bsf = chain.create_block_state_future(id, block);
}
// abort the pending block
abort_block();
// push the new block
auto handle_error = [&](const auto& e) {
elog("Exception on block ${bn}: ${e}", ("bn", blk_num)("e", e.to_detail_string()));
app().get_channel<channels::rejected_block>().publish(priority::medium, block);
throw;
};
controller::block_report br;
try {
const block_state_ptr& bspr = bsp ? bsp : bsf.get();
chain.push_block(
br,
bspr,
[this](const branch_type& forked_branch) { _unapplied_transactions.add_forked(forked_branch); },
[this](const transaction_id_type& id) { return _unapplied_transactions.get_trx(id); });
} catch (const guard_exception& e) {
chain_plugin::handle_guard_exception(e);
return false;
} catch (const std::bad_alloc&) {
chain_apis::api_base::handle_bad_alloc();
} catch (boost::interprocess::bad_alloc&) {
chain_apis::api_base::handle_db_exhaustion();
} catch (const fork_database_exception& e) {
elog("Cannot recover from ${e}. Shutting down.", ("e", e.to_detail_string()));
appbase::app().quit();
return false;
} catch (const fc::exception& e) {
handle_error(e);
} catch (const std::exception& e) {
handle_error(fc::std_exception_wrapper::from_current_exception(e));
}
const auto& hbs = chain.head_block_state();
now = fc::time_point::now();
if (hbs->header.timestamp.next().to_time_point() >= now) {
_production_enabled = true;
}
if (now - block->timestamp < fc::minutes(5) || (blk_num % 1000 == 0)) {
ilog("Received block ${id}... #${n} @ ${t} signed by ${p} "
"[trxs: ${count}, lib: ${lib}, confirmed: ${confs}, net: ${net}, cpu: ${cpu}, elapsed: ${elapsed}, time: ${time}, latency: "
"${latency} ms]",
("p", block->producer)("id", id.str().substr(8, 16))("n", blk_num)("t", block->timestamp)
("count", block->transactions.size())("lib", chain.last_irreversible_block_num())
("confs", block->confirmed)("net", br.total_net_usage)("cpu", br.total_cpu_usage_us)
("elapsed", br.total_elapsed_time)("time", br.total_time)("latency", (now - block->timestamp).count() / 1000));
if (chain.get_read_mode() != db_read_mode::IRREVERSIBLE && hbs->id != id && hbs->block != nullptr) { // not applied to head
ilog("Block not applied to head ${id}... #${n} @ ${t} signed by ${p} "
"[trxs: ${count}, dpos: ${dpos}, confirmed: ${confs}, net: ${net}, cpu: ${cpu}, elapsed: ${elapsed}, time: ${time}, "
"latency: ${latency} ms]",
("p", hbs->block->producer)("id", hbs->id.str().substr(8, 16))("n", hbs->block_num)("t", hbs->block->timestamp)
("count", hbs->block->transactions.size())("dpos", hbs->dpos_irreversible_blocknum)("confs", hbs->block->confirmed)
("net", br.total_net_usage)("cpu", br.total_cpu_usage_us)("elapsed", br.total_elapsed_time)("time", br.total_time)
("latency", (now - hbs->block->timestamp).count() / 1000));
}
}
if (_update_incoming_block_metrics) {
_update_incoming_block_metrics({.trxs_incoming_total = block->transactions.size(),
.cpu_usage_us = br.total_cpu_usage_us,
.total_elapsed_time_us = br.total_elapsed_time.count(),
.total_time_us = br.total_time.count(),
.net_usage_us = br.total_net_usage,
.block_latency_us = (now - block->timestamp).count(),
.last_irreversible = chain.last_irreversible_block_num(),
.head_block_num = blk_num});
}
return true;
}
void restart_speculative_block() {
// log message is used by Node.py verifyStartingBlockMessages in distributed-transactions-test.py test
fc_dlog(_log, "Restarting exhausted speculative block #${n}", ("n", chain_plug->chain().head_block_num() + 1));
// abort the pending block
abort_block();
schedule_production_loop();
}
void on_incoming_transaction_async(const packed_transaction_ptr& trx,
bool api_trx,
transaction_metadata::trx_type trx_type,
bool return_failure_traces,
next_function<transaction_trace_ptr> next) {
const transaction& t = trx->get_transaction();
EOS_ASSERT( t.delay_sec.value == 0, transaction_exception, "transaction cannot be delayed" );
if (trx_type == transaction_metadata::trx_type::read_only) {
assert(_ro_thread_pool_size > 0); // enforced by chain_plugin
assert(app().executor().get_main_thread_id() != std::this_thread::get_id()); // should only be called from read only threads
// Post all read only trxs to read_exclusive queue for execution.
auto trx_metadata = transaction_metadata::create_no_recover_keys(trx, transaction_metadata::trx_type::read_only);
push_read_only_transaction(std::move(trx_metadata), std::move(next));
return;
}
chain::controller& chain = chain_plug->chain();
const auto max_trx_time_ms = (trx_type == transaction_metadata::trx_type::read_only) ? -1 : _max_transaction_time_ms.load();
fc::microseconds max_trx_cpu_usage = max_trx_time_ms < 0 ? fc::microseconds::maximum() : fc::milliseconds(max_trx_time_ms);
auto future = transaction_metadata::start_recover_keys(trx,
chain.get_thread_pool(),
chain.get_chain_id(),
fc::microseconds(max_trx_cpu_usage),
trx_type,
chain.configured_subjective_signature_length_limit());
auto is_transient = (trx_type == transaction_metadata::trx_type::read_only || trx_type == transaction_metadata::trx_type::dry_run);
if (!is_transient) {
next = [this, trx, next{std::move(next)}](const next_function_variant<transaction_trace_ptr>& response) {
next(response);
fc::exception_ptr except_ptr; // rejected
if (std::holds_alternative<fc::exception_ptr>(response)) {
except_ptr = std::get<fc::exception_ptr>(response);
} else if (std::get<transaction_trace_ptr>(response)->except) {
except_ptr = std::get<transaction_trace_ptr>(response)->except->dynamic_copy_exception();
}
_transaction_ack_channel.publish(priority::low, std::pair<fc::exception_ptr, packed_transaction_ptr>(except_ptr, trx));
};
}
boost::asio::post(_thread_pool.get_executor(),
[self = this, future{std::move(future)}, api_trx, is_transient, return_failure_traces,
next{std::move(next)}, trx = trx]() mutable {
if (future.valid()) {
future.wait();
app().executor().post(priority::low, exec_queue::read_write,
[self, future{std::move(future)}, api_trx, is_transient, next{std::move(next)}, trx{std::move(trx)},
return_failure_traces]() mutable {
auto start = fc::time_point::now();
auto idle_time = self->_time_tracker.add_idle_time(start);
auto trx_tracker = self->_time_tracker.start_trx(is_transient, start);
fc_tlog(_log, "Time since last trx: ${t}us", ("t", idle_time));
auto exception_handler =
[self, is_transient, &next, trx{std::move(trx)}, &start](fc::exception_ptr ex) {
self->log_trx_results(trx, nullptr, ex, 0, start, is_transient);
next(std::move(ex));
};
try {
auto result = future.get();
if (!self->process_incoming_transaction_async(result, api_trx, return_failure_traces, trx_tracker, next)) {
if (self->in_producing_mode()) {
self->schedule_maybe_produce_block(true);
} else {
self->restart_speculative_block();
}
}
}
CATCH_AND_CALL(exception_handler);
});
}
});
}
bool process_incoming_transaction_async(const transaction_metadata_ptr& trx,
bool api_trx,
bool return_failure_trace,
block_time_tracker::trx_time_tracker& trx_tracker,
const next_function<transaction_trace_ptr>& next) {
bool exhausted = false;
chain::controller& chain = chain_plug->chain();
try {
const auto& id = trx->id();
fc::time_point bt = chain.is_building_block() ? chain.pending_block_time() : chain.head_block_time();
const fc::time_point expire = trx->packed_trx()->expiration().to_time_point();
if (expire < bt) {
auto except_ptr = std::static_pointer_cast<fc::exception>(std::make_shared<expired_tx_exception>(
FC_LOG_MESSAGE(error, "expired transaction ${id}, expiration ${e}, block time ${bt}", ("id", id)("e", expire)("bt", bt))));
log_trx_results(trx, except_ptr);
next(std::move(except_ptr));
return true;
}
if (chain.is_known_unexpired_transaction(id)) {
auto except_ptr = std::static_pointer_cast<fc::exception>(
std::make_shared<tx_duplicate>(FC_LOG_MESSAGE(error, "duplicate transaction ${id}", ("id", id))));
next(std::move(except_ptr));
return true;
}
if (!chain.is_building_block()) {
_unapplied_transactions.add_incoming(trx, api_trx, return_failure_trace, next);
trx_tracker.cancel();
return true;
}
const auto block_deadline = _pending_block_deadline;
push_result pr = push_transaction(block_deadline, trx, api_trx, return_failure_trace, trx_tracker, next);
if (pr.trx_exhausted) {
_unapplied_transactions.add_incoming(trx, api_trx, return_failure_trace, next);
}
exhausted = pr.block_exhausted;
if ( !in_producing_mode() && pr.trx_exhausted )
exhausted = true; // report transaction exhausted if trx was exhausted in non-producing mode (so we will restart
// a speculative block to retry it immediately, instead of waiting to receive a new block)
} catch (const guard_exception& e) {
chain_plugin::handle_guard_exception(e);
} catch (boost::interprocess::bad_alloc&) {
chain_apis::api_base::handle_db_exhaustion();
} catch (std::bad_alloc&) {
chain_apis::api_base::handle_bad_alloc();
}
CATCH_AND_CALL(next);
return !exhausted;
}
fc::microseconds get_irreversible_block_age() {
auto now = fc::time_point::now();
if (now < _irreversible_block_time) {
return fc::microseconds(0);
} else {
return now - _irreversible_block_time;
}
}
account_name get_pending_block_producer() {
auto& chain = chain_plug->chain();
if (chain.is_building_block()) {
return chain.pending_block_producer();
} else {
return {};
}
}
bool production_disabled_by_policy() {
return !_production_enabled || _pause_production ||
(_max_irreversible_block_age_us.count() >= 0 && get_irreversible_block_age() >= _max_irreversible_block_age_us);
}
bool is_producer_key(const chain::public_key_type& key) const {
return _signature_providers.find(key) != _signature_providers.end();
}
chain::signature_type sign_compact(const chain::public_key_type& key, const fc::sha256& digest) const {
if (key != chain::public_key_type()) {
auto private_key_itr = _signature_providers.find(key);
EOS_ASSERT(private_key_itr != _signature_providers.end(), producer_priv_key_not_found,
"Local producer has no private key in config.ini corresponding to public key ${key}", ("key", key));
return private_key_itr->second(digest);
} else {
return chain::signature_type();
}
}
void resume() {
_pause_production = false;
// it is possible that we are only speculating because of this policy which we have now changed
// re-evaluate that now
//
if (in_speculating_mode()) {
abort_block();
fc_ilog(_log, "Producer resumed. Scheduling production.");
schedule_production_loop();
} else {
fc_ilog(_log, "Producer resumed.");
}
}
enum class start_block_result {
succeeded,
failed,
waiting_for_block,
waiting_for_production,
exhausted
};
inline bool should_interrupt_start_block( const fc::time_point& deadline, uint32_t pending_block_num ) const;
start_block_result start_block();
block_timestamp_type calculate_pending_block_time() const;
void schedule_delayed_production_loop(const std::weak_ptr<producer_plugin_impl>& weak_this, std::optional<fc::time_point> wake_up_time);
bool in_producing_mode() const { return _pending_block_mode == pending_block_mode::producing; }
bool in_speculating_mode() const { return _pending_block_mode == pending_block_mode::speculating; }
};
void new_chain_banner(const eosio::chain::controller& db)
{
std::cerr << "\n"
"*******************************\n"
"* *\n"
"* ------ NEW CHAIN ------ *\n"
"* - Welcome to Antelope - *\n"
"* ----------------------- *\n"