Performance and metrics touches on async workers #3502
Conversation
Right now, when using send_after, we're sending a single atom to the process, which means, that we then don't know how to match the flush request when it arrives, and therefore we need to act on all of them, or explore the entire message queue to drop them when we do the selective receive in `cancel_and_flush_timer`. But that selective receive can potentially be expensive, when the batch worker is really loaded and its queues are growing faster than it can process, the code becomes really critical. Even more so when these workers are enabled with message_queue_data=off_heap, which means that a selective receive will go out of its heap, screwing cache locality, and take all those heap fragments into its heap, which is all more expensive. To solve this, we can use start_timer instead of send_after, which will then send a message that contains the TimerRef we get, so we know then exactly which timeout is the active one, where we to receive any. This way, cancel_timer doesn't need to worry about whether the timer actually arrived or not: if it didn't, it's canceled, if it did, we won't attend to it next time, it is simply ignored when the mailbox view arrives to it. One more tiny optimisation: we run cancel_timer asynchronously: https://www.erlang.org/doc/man/erlang.html#cancel_timer-2 > The timer service that manages the timer can be co-located with another scheduler than the scheduler that the calling process is executing on. If so, communication with the timer service takes much longer time than if it is located locally. If the calling process is in critical path, and can do other things while waiting for the result of this operation, or is not interested in the result of the operation, you want to use option {async, true}. If using option {async, false}, the calling process blocks until the operation has been performed.
Watch timed_flushes metric - if it is high, it means that you don't have enough traffic to complete batches within the flush_interval period. In effect, you are writing your data record by record, only a bit later. Apparently you have either too many workers, too big batch_size, or too low flush_interval.
Codecov Report
@@ Coverage Diff @@
## master #3502 +/- ##
==========================================
- Coverage 81.00% 80.99% -0.01%
==========================================
Files 418 418
Lines 32333 32329 -4
==========================================
- Hits 26190 26184 -6
- Misses 6143 6145 +2
Continue to review full report at Codecov.
|
This comment has been minimized.
This comment has been minimized.
…a key Adding this queue length hopefully helps with micro-performance, as this is data already calculated, and the handlers will very likely use this information as well, so just keeping it will save some cycles calculating it when the handler has to calculate it again, which can be important when buffers are actually big.
NelsonVides
changed the title
|
small_tests_24 / small_tests / d6d522f small_tests_23 / small_tests / d6d522f dynamic_domains_mysql_redis_24 / mysql_redis / d6d522f dynamic_domains_pgsql_mnesia_24 / pgsql_mnesia / d6d522f dynamic_domains_pgsql_mnesia_23 / pgsql_mnesia / d6d522f dynamic_domains_mssql_mnesia_24 / odbc_mssql_mnesia / d6d522f ldap_mnesia_23 / ldap_mnesia / d6d522f ldap_mnesia_24 / ldap_mnesia / d6d522f internal_mnesia_24 / internal_mnesia / d6d522f pgsql_mnesia_24 / pgsql_mnesia / d6d522f elasticsearch_and_cassandra_24 / elasticsearch_and_cassandra_mnesia / d6d522f mysql_redis_24 / mysql_redis / d6d522f pgsql_mnesia_23 / pgsql_mnesia / d6d522f riak_mnesia_24 / riak_mnesia / d6d522f small_tests_24 / small_tests / d6d522f small_tests_23 / small_tests / d6d522f dynamic_domains_pgsql_mnesia_23 / pgsql_mnesia / d6d522f dynamic_domains_mysql_redis_24 / mysql_redis / d6d522f dynamic_domains_mssql_mnesia_24 / odbc_mssql_mnesia / d6d522f dynamic_domains_pgsql_mnesia_24 / pgsql_mnesia / d6d522f ldap_mnesia_24 / ldap_mnesia / d6d522f ldap_mnesia_23 / ldap_mnesia / d6d522f internal_mnesia_24 / internal_mnesia / d6d522f pgsql_mnesia_23 / pgsql_mnesia / d6d522f mysql_redis_24 / mysql_redis / d6d522f pgsql_mnesia_24 / pgsql_mnesia / d6d522f elasticsearch_and_cassandra_24 / elasticsearch_and_cassandra_mnesia / d6d522f riak_mnesia_24 / riak_mnesia / d6d522f mssql_mnesia_24 / odbc_mssql_mnesia / d6d522f small_tests_24 / small_tests / d6d522f small_tests_23 / small_tests / d6d522f dynamic_domains_pgsql_mnesia_23 / pgsql_mnesia / d6d522f dynamic_domains_pgsql_mnesia_24 / pgsql_mnesia / d6d522f dynamic_domains_mssql_mnesia_24 / odbc_mssql_mnesia / d6d522f dynamic_domains_mysql_redis_24 / mysql_redis / d6d522f ldap_mnesia_23 / ldap_mnesia / d6d522f ldap_mnesia_24 / ldap_mnesia / d6d522f internal_mnesia_24 / internal_mnesia / d6d522f pgsql_mnesia_23 / pgsql_mnesia / d6d522f pgsql_mnesia_24 / pgsql_mnesia / d6d522f elasticsearch_and_cassandra_24 / elasticsearch_and_cassandra_mnesia / d6d522f mssql_mnesia_24 / odbc_mssql_mnesia / d6d522f riak_mnesia_24 / riak_mnesia / d6d522f mysql_redis_24 / mysql_redis / d6d522f |
|
small_tests_24 / small_tests / 0725fc2 small_tests_23 / small_tests / 0725fc2 dynamic_domains_pgsql_mnesia_23 / pgsql_mnesia / 0725fc2 dynamic_domains_pgsql_mnesia_24 / pgsql_mnesia / 0725fc2 dynamic_domains_mysql_redis_24 / mysql_redis / 0725fc2 dynamic_domains_mssql_mnesia_24 / odbc_mssql_mnesia / 0725fc2 ldap_mnesia_23 / ldap_mnesia / 0725fc2 ldap_mnesia_24 / ldap_mnesia / 0725fc2 internal_mnesia_24 / internal_mnesia / 0725fc2 pgsql_mnesia_24 / pgsql_mnesia / 0725fc2 pgsql_mnesia_23 / pgsql_mnesia / 0725fc2 elasticsearch_and_cassandra_24 / elasticsearch_and_cassandra_mnesia / 0725fc2 mssql_mnesia_24 / odbc_mssql_mnesia / 0725fc2 mysql_redis_24 / mysql_redis / 0725fc2 riak_mnesia_24 / riak_mnesia / 0725fc2 |
big_tests/tests/mam_SUITE.erl
Outdated
|
|
||
| get_mongoose_async_metrics(HostTypePrefix, MetricName) -> | ||
| Metric = [HostTypePrefix, mongoose_async_pools, pm_mam, MetricName], | ||
| {ok, Value} = rpc(mim(), exometer, get_value, [Metric]), |
There was a problem hiding this comment.
use mongoose_metrics:get_metric_value/1. Just in case we move away from exometer :)
Note that escalus_mongooseim doesn't currently support exometer counters, which is an insane fail, but anyway, out of the scope of this PR, so here I do the fetching manually.
NelsonVides
force-pushed
the
batch_worker_timeouts
branch
from
0725fc2 to
4572526
Compare
|
small_tests_24 / small_tests / 4572526 small_tests_23 / small_tests / 4572526 dynamic_domains_pgsql_mnesia_24 / pgsql_mnesia / 4572526 dynamic_domains_pgsql_mnesia_23 / pgsql_mnesia / 4572526 dynamic_domains_mysql_redis_24 / mysql_redis / 4572526 dynamic_domains_mssql_mnesia_24 / odbc_mssql_mnesia / 4572526 ldap_mnesia_24 / ldap_mnesia / 4572526 ldap_mnesia_23 / ldap_mnesia / 4572526 internal_mnesia_24 / internal_mnesia / 4572526 pgsql_mnesia_24 / pgsql_mnesia / 4572526 pgsql_mnesia_23 / pgsql_mnesia / 4572526 elasticsearch_and_cassandra_24 / elasticsearch_and_cassandra_mnesia / 4572526 mssql_mnesia_24 / odbc_mssql_mnesia / 4572526 mysql_redis_24 / mysql_redis / 4572526 riak_mnesia_24 / riak_mnesia / 4572526 |
Right now, when using send_after, we're sending a single atom to the
process, which means, that we then don't know how to match the flush
request when it arrives, and therefore we need to act on all of them, or
explore the entire message queue to drop them when we do the selective
receive in
cancel_and_flush_timer.But that selective receive can potentially be expensive, when the batch
worker is really loaded and its queues are growing faster than it can
process, the code becomes really critical. Even more so when these
workers are enabled with message_queue_data=off_heap, which means that a
selective receive will go out of its heap, screwing cache locality, and
take all those heap fragments into its heap, which is all more
expensive.
To solve this, we can use start_timer instead of send_after, which will
then send a message that contains the TimerRef we get, so we know then
exactly which timeout is the active one, where we to receive any. This
way, cancel_timer doesn't need to worry about whether the timer actually
arrived or not: if it didn't, it's canceled, if it did, we won't attend
to it next time, it is simply ignored when the mailbox view arrives to
it.
One more tiny optimisation: we run cancel_timer asynchronously:
https://www.erlang.org/doc/man/erlang.html#cancel_timer-2
There's other code, see commits for details.