пятница, 6 апреля 2018 г.

[prog.c++] Только что довелось самому воспользоваться msg_tracing-фильтрами при поиске проблемы

Делаю примеры для новой статьи про SObjectizer. В примерах имитируется работа с оборудованием и собирается небольшая статистика о задержках в обработке сообщений при разных политиках обработки этих сообщений. По сути, в примерах работает два агента. Первый, a_device_manager, имитирует работу с оборудованием. Второй, a_dashboard, раз в пять секунд выдает на экран текущие показатели.

И вот при первых запусках примеров обнаруживается, что в какой-то момент статистика перестает обновляться. Становится понятно, что это происходит потому, что не обрабатывается одно из сообщений, a_device_manager_t::reinit_device_t. Но почему не обрабатывается? Подписка на него есть:

a_device_manager_t(
      context_t ctx,
      const args_t & args,
      so_5::mbox_t dashboard_mbox)
      :  so_5::agent_t(std::move(ctx))
      ,  args_(args)
      ,  dashboard_mbox_(std::move(dashboard_mbox)) {
   so_subscribe_self()
      .event(&a_device_manager_t::on_init_device, so_5::thread_safe)
      .event(&a_device_manager_t::on_reinit_device, so_5::thread_safe)
      .event(&a_device_manager_t::on_perform_io, so_5::thread_safe);
}

само сообщение так же отсылается:

void on_perform_io(mutable_mhood_t<perform_io_t> cmd) {
   // Обновим статистику по этой операции.
   handle_msg_delay(a_dashboard_t::op_type_t::io_op, *cmd);

   // Количество оставшихся IO-операций должно уменьшиться.
   cmd->device_->remaining_io_ops_ -= 1;
   // Возможно, пришло время переинициализировать устройство.
   if(0 == cmd->device_->remaining_io_ops_)
      // Так и есть, инициируем переинициализацию.
      so_5::send<reinit_device_t>(*this, std::move(cmd->device_));
   else
      // Время переинициализации еще не пришло, продолжаем IO-операции.
      send_perform_io_msg(std::move(cmd->device_));
}

В общем, понятно, что сообщение либо не отсылается вообще, либо не доставляется до получателя. Но непонятно почему. Причем, что особенно плохо, сообщения reinit_device_t должны начать отсылаться не сразу, а лишь спустя какое-то (случайное) время после запуска примера.

Ok. В новой версии SObjectizer-а у нас есть возможность посмотреть, что происходит конкретно с сообщениями этого типа. Просто включаем механизм msg_tracing и добавляем соответствующий фильтр:

so_5::launch([&](so_5::environment_t & env) {
      ...
   },
   [](so_5::environment_params_t & params) {
      params.message_delivery_tracer(
            so_5::msg_tracing::std_cout_tracer());
      params.message_delivery_tracer_filter(
            so_5::msg_tracing::make_filter([](const auto & td) {
               const auto msg_type = td.msg_type();
               return msg_type && *msg_type == typeid(a_device_manager_t::reinit_device_t);
            }));
   });

И когда дело доходит до отсылки сообщений reinit_device_t я получаю следующий трейс (фрагмент):

[tid=8][mbox_id=6] deliver_message.push_to_queue [msg_type=N18a_device_manager_t15reinit_device_tE][payload_ptr=0x2ee6290][overlimit_deep=1][agent_ptr=0x30bb640]
[tid=5][agent_ptr=0x30bb640] create_execution_hint.find_handler [mbox_id=6][msg_type=N18a_device_manager_t15reinit_device_tE][payload_ptr=0x2eecb90][state=<DEFAULT>][evt_handler=NONE]

Тут видно, что сообщение реально отсылается агенту. Даже пытается быть доставленным агенту. Но для этого сообщения нет обработчика, о чем говорит тег [evt_handler=NONE] в трейсе.

Получается странная штука. Подписка на сообщение есть, сообщение отсылается и почти что доходит до агента, но все-таки не доходит. Значит дело в подписке. Еще раз проверяю ее и обнаруживаю, что обработчик-то на самом деле подписывается на мутабельное сообщение типа reinit_device_t (это обязательно, т.к. из экземпляра нужно забрать данные, модифицировать их и затем переслать в другом сообщении):

void on_reinit_device(mutable_mhood_t<reinit_device_t> cmd) {
   ...
}

А отсылается-то сообщение как иммутабельное! Поскольку для системы подписки reinit_device_t и mutable_msg<reinit_device_t> -- это разные типы сообщений, то при отсылке просто reinit_device_t подписка на сообщение не обнаруживается. Вот здесь-то и была зарыта собака.

Меняю код по отсылке сообщения:

so_5::send<so_5::mutable_msg<reinit_device_t>>(*this, std::move(cmd->device_));

И все начинает работать.

В очередной раз механизм msg_tracing помог разобраться с поведением SObjectizer-овского приложения. И, хотя сам этот механизм еще очень далек от совершенства, реальную помощь он оказывает уже сейчас.

Отправить комментарий