Outgoing Acks Warning

angelskieglazki
edited September 2018 in Native
Hello. I have a question.
I have an application written using a Photon client c++ SDK.
Also I have 10 instances of application implemented using unity PUN SDK. They are in the same room with c++ app and each of them is sending a sync message 10 times per second.
I'm processing the sync messages in the customEventAction event and increase the counter of received sync messages.
Every game I getting a warning #1031 (QueueOutgoingAcksWarning) (and sometimes - #1035) on the c++ client and at this moment my sync counter is not incrementing and I'm not receiving sync messages for a short period of time.

I added the following code to the warningReturn event:
if (1031 == warningCode) {
mLoadBalancingClient.serviceBasic ();
while (mLoadBalancingClient.sendOutgoingCommands ())
}
if (1035 == warningCode) {
mLoadBalancingClient.serviceBasic ();
while (mLoadBalancingClient.dispatchIncomingCommands ())
}
but it does not help. Maybe I should add sendAcksOnly ()?

Best Regards.

Comments

  • Hi @angelskieglazki.

    It looks like you are receiving over 100 incoming reliable messages for which the client needs to send out acks in the time that passes between 2 service() calls. This is usually a symptom of a problem elsewhere in your code. Hence you should figure out why service() is not called more regularly in this situation. Maybe some code is blocking the thread that calls it or there is some performance issue. Measuring the time between service()-calls would be a first step to tracking down the exact source of the problem.
  • angelskieglazki
    edited October 2018
    Hello @Kaiserludi

    I added some debug messages that calculate how much the procedure is performed. I added output of queue sizes.
    void NetworkLogic::run(void) {
    switch(state) {...};
    
    if (mLoadBalancingClient.getQueuedIncomingCommands()) {
      std::cout<<"---> Incoming Q Size: "<< mLoadBalancingClient.getQueuedIncomingCommands()<<std::endl;
    }
    if (mLoadBalancingClient.getQueuedOutgoingCommands()) {
      std::cout<<"---> Outcoming Q Size: "<< mLoadBalancingClient.getQueuedOutgoingCommands() 
      <<std::endl;
    }
    if (mLoadBalancingClient.getIncomingReliableCommandsCount()) {
      std::cout<<"---> Incoming RELIABLE Q Size: "<<mLoadBalancingClient.getIncomingReliableCommandsCount()<<std::endl;
    }
    
    auto t1 = std::chrono::high_resolution_clock::now();
    mLoadBalancingClient.service();
    auto t2 = std::chrono::high_resolution_clock::now();
    if (std::chrono::duration_cast<std::chrono::milliseconds>(t2 - t1).count() > 20)
    std::cout << "process mLoadBalancingClient.service: "
                << std::chrono::duration_cast<std::chrono::milliseconds>(t2 - t1).count()
                << " milliseconds\n";
    while(mLoadBalancingClient.sendOutgoingCommands());
    }

    And that's what I saw.
    ---> Outcoming Q Size: 16
    process onRoomPropertiesChange: 102 milliseconds
    process mLoadBalancingClient.service: 402 milliseconds
    ---> Outcoming Q Size: 19
    process mLoadBalancingClient.service: 351 milliseconds
    ---> Outcoming Q Size: 19
    process mLoadBalancingClient.service: 257 milliseconds
    ---> Outcoming Q Size: 19
    process mLoadBalancingClient.service: 37 milliseconds
    ---> Outcoming Q Size: 21
    ---> Outcoming Q Size: 21
    ---> Outcoming Q Size: 4
    process customEventAction: 53 milliseconds
    process mLoadBalancingClient.service: 255 milliseconds
    ---> Outcoming Q Size: 1
    received warning 1031 from client
    process onRoomPropertiesChange: 82 milliseconds
    process mLoadBalancingClient.service: 1503 milliseconds
    process took: 1530 milliseconds
    Also, after each change in the property of a room or the dispatch of an event, I call this construct: while (mLoadBalancingClient.sendOutgoingCommands ());

    I rewrote the demo loadbalancing. And I call the run-method in a separate thread like this. nl_map - container for exemplars of NetworkLogic(one NetworkLogic exemplar for one game)
    std::thread first;
    std::atomic<bool> running = ATOMIC_VAR_INIT(true);
    
    // Process
    void process(int id)
    {
      showMessage("Process started");
    
    
      std::chrono::duration<double, std::milli> elapsed = 100ms;
    
      for(;running;std::this_thread::sleep_for(elapsed)) {
    
        std::unique_lock<std::mutex> lg(photon_mutex);
    
        for(auto i=nl_map.begin(), e=nl_map.end();i!=e;) {
          if(std::lock_guard<std::mutex>(kill_mutex),kill.erase(i->first)) {
            i=nl_map.erase(i);
            continue;    // test i!=e again
          }
    
          lg.unlock();
    
          auto t1 = std::chrono::high_resolution_clock::now();
          i->second->run();
          auto t2 = std::chrono::high_resolution_clock::now();
          auto t3 = std::chrono::duration_cast<std::chrono::milliseconds>(t2 - t1).count();
    
          if (t3>100) elapsed = 0ms; else elapsed = 100ms - (t2 -t1);
          lg.lock();
          ++i;
        }
      }
    
      showMessage("Process stopped");
    }

    My question: Why service-method can run so long? Am I doing something wrong?
    And another question off topic. There are no implementations in the Foton-cpp directory of latest client lib. So conceived? :smile:

    Best regards.

  • Kaiserludi
    Kaiserludi admin
    edited October 2018
    My question: Why service-method can run so long? Am I doing something wrong?

    service() is from where the Photon client is calling your implementations of the callbacks in the Listener interface.
    So if one of your callbacks takes a really long time, that will result in service() taking a really long time, too.
    Hence you should not do too time intensive work directly inside the callbacks. Instead just set a flag in your callback that certain work in your code should be done and eventually deep-copy the data that you have received in the callback into variables that are still valid after the callback has returned, if you need to access that data later on, and then do the actual work after service() has returned, eventually in another thread or split-up into multiple frames depending on how time-intensive the work that your code does, is.

    More than 50ms or even 100ms is an insanely long execution time for onRoomPropertiesChange() or customEventAction(). These should take way below 1ms.