eclipse-iceoryx / iceoryx

Eclipse iceoryx™ - true zero-copy inter-process-communication
https://iceoryx.io
Apache License 2.0
1.6k stars 373 forks source link

RPC call delayed instability #1984

Open sukeyisme opened 1 year ago

sukeyisme commented 1 year ago

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.

elfenpiff commented 1 year ago

@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.

sukeyisme commented 1 year ago

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 commented 1 year ago

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

elfenpiff commented 1 year ago

@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.

sukeyisme commented 1 year ago

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.

elfenpiff commented 1 year ago

@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.

sukeyisme commented 1 year ago

`// 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_point 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); } `