iceoryx icon indicating copy to clipboard operation
iceoryx copied to clipboard

RPC call delayed instability

Open sukeyisme opened this issue 2 years ago • 7 comments

Required information

Operating system: E.g. Ubuntu 18.04 LTS

Compiler version: E.g. GCC 7.4.0

Eclipse iceoryx version: E.g. v1.2.3 or master branch

Observed result or behaviour: A clear and precise description of the observed result.

Expected result or behaviour: What do you expect to happen?

Conditions where it occurred / Performed steps: Describe how one can reproduce the bug.

sukeyisme avatar May 12 '23 10:05 sukeyisme

@sukeyisme Could you please fill out observed and expected behavior as well as the conditions where it occurred.

Otherwise I have no basis to even start debugging the code.

elfenpiff avatar May 12 '23 16:05 elfenpiff

count 1000000 | min(ms) 0.002362 | max(ms) 7.170497 | avg(ms) 0.031633 | 80%(ms) 0.032039 | 90%(ms) 0.035875 | 95%(ms) 0.041701 | 99%(ms) 0.067779 | 99.9%(ms) 2.088486 | 99.99%(ms) 3.934515

sukeyisme avatar May 15 '23 06:05 sukeyisme

i run the request and response code , 1000000 times, and result here.

sukeyisme avatar May 15 '23 06:05 sukeyisme

@sukeyisme Please provide me a detailed problem description and a set of steps to reproduce the problem.

I have no idea what the context of these numbers are and what kind of request and response code you are referring to.

elfenpiff avatar May 15 '23 08:05 elfenpiff

Measure the total time between sending a request and receiving a reply, code use iceoryx_examples/request_response example, run 1000000 times request-response, and see some latency spikes, expected latency more smooth.

sukeyisme avatar May 15 '23 08:05 sukeyisme

@sukeyisme I request response example does not measure latency so I assume you modified the example to take the measurements.

Could you share your adjusted code here please to provide us some insight what exactly is measured and how.

elfenpiff avatar May 15 '23 09:05 elfenpiff

`// Copyright (c) 2022 by Apex.AI Inc. All rights reserved. // // Licensed under the Apache License, Version 2.0 (the "License"); // you may not use this file except in compliance with the License. // You may obtain a copy of the License at // // http://www.apache.org/licenses/LICENSE-2.0 // // Unless required by applicable law or agreed to in writing, software // distributed under the License is distributed on an "AS IS" BASIS, // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. // See the License for the specific language governing permissions and // limitations under the License. // // SPDX-License-Identifier: Apache-2.0

//! [iceoryx includes] #include "iceoryx_posh/popo/client.hpp"

#include <quantx/math/math.h>

#include "iceoryx_hoofs/posix_wrapper/signal_watcher.hpp" #include "iceoryx_posh/popo/wait_set.hpp" #include "iceoryx_posh/runtime/posh_runtime.hpp" #include "request_and_response_types.hpp" //! [iceoryx includes]

#include

constexpr char APP_NAME[] = "iox-cpp-request-response-client-waitset";

//! [context data to store Fibonacci numbers and sequence ids] struct ContextData { uint64_t fibonacciLast = 0; uint64_t fibonacciCurrent = 1; int64_t requestSequenceId = 0; int64_t expectedResponseSequenceId = requestSequenceId; }; //! [context data to store Fibonacci numbers and sequence ids]

int main() { //! [initialize runtime] iox::runtime::PoshRuntime::initRuntime(APP_NAME); //! [initialize runtime]

ContextData ctx;

//! [create waitset] iox::popo::WaitSet<> waitset;

//! [create client] iox::popo::ClientOptions options; options.responseQueueCapacity = 2U; iox::popo::Client<AddRequest, AddResponse> client( {"Example", "Request-Response", "Add"}, options); //! [create client]

// attach client to waitset waitset.attachState(client, iox::popo::ClientState::HAS_RESPONSE) .or_else( { std::cerr << "failed to attach client" << std::endl; std::exit(EXIT_FAILURE); }); //! [create waitset]

//! [mainloop]

std::chrono::time_pointstd::chrono::steady_clock begin; int64_t i = 0; while (!iox::posix::hasTerminationRequested() && ++i < 1000000) { begin = std::chrono::steady_clock::now(); //! [send request] client.loan() .and_then([&](auto& request) { request.getRequestHeader().setSequenceId(ctx.requestSequenceId); ctx.expectedResponseSequenceId = ctx.requestSequenceId; ctx.requestSequenceId += 1; request->augend = ctx.fibonacciLast; request->addend = ctx.fibonacciCurrent; // std::cout << APP_NAME << " Send Request: " << ctx.fibonacciLast // << " + " << ctx.fibonacciCurrent << std::endl; request.send().or_else([&](auto& error) { std::cout << "Could not send Request! Error: " << error << std::endl; }); }) .or_else([](auto& error) { std::cout << "Could not allocate Request! Error: " << error << std::endl; }); //! [send request]

// We block and wait for samples to arrive, when the time is up we send the
// request again
//! [wait and check if the client triggered]
auto notificationVector =
    waitset.timedWait(iox::units::Duration::fromSeconds(5));

for (auto& notification : notificationVector) {
  if (notification->doesOriginateFrom(&client)) {
    //! [take response]
    while (client.take().and_then([&](const auto& response) {
      auto receivedSequenceId =
          response.getResponseHeader().getSequenceId();
      if (receivedSequenceId == ctx.expectedResponseSequenceId) {
        ctx.fibonacciLast = ctx.fibonacciCurrent;
        ctx.fibonacciCurrent = response->sum;
        // std::cout << APP_NAME << " Got Response : " <<
        // ctx.fibonacciCurrent
        //           << std::endl;
      } else {
        std::cout << "Got Response with outdated sequence ID! Expected = "
                  << ctx.expectedResponseSequenceId
                  << "; Actual = " << receivedSequenceId << "! -> skip"
                  << std::endl;
      }
    })) {
    }
    //! [take response]
  }
}
//! [wait and check if the client triggered]
// constexpr std::chrono::milliseconds SLEEP_TIME{950U};
// std::this_thread::sleep_for(SLEEP_TIME);

std::cout << std::chrono::duration_cast<std::chrono::nanoseconds>(
                 std::chrono::steady_clock::now() - begin)
                 .count()
          << std::endl;

} //! [mainloop]

std::cout << "shutting down" << std::endl;

return (EXIT_SUCCESS); } `

sukeyisme avatar May 15 '23 09:05 sukeyisme