Error while executing service

Options
Hello,

I'm facing an error while using service but I don't understand what could it be
steam_api_dotnetwrapper64.dll!memcpy_repmovs() Line 115	Unknown
steam_api_dotnetwrapper64.dll!ExitGames::Photon::Internal::EnetCommand::operator=(const ExitGames::Photon::Internal::EnetCommand & toCopy) Line 371	C++
steam_api_dotnetwrapper64.dll!ExitGames::Photon::Internal::EnetCommand::EnetCommand(const ExitGames::Photon::Internal::EnetCommand & toCopy) Line 381	C++
steam_api_dotnetwrapper64.dll!ExitGames::Common::JVector<ExitGames::Photon::Internal::EnetCommand>::removeElementAt(unsigned int index) Line 560	C++
steam_api_dotnetwrapper64.dll!ExitGames::Photon::Internal::EnetPeer::serializeToBuffer(ExitGames::Common::JVector<ExitGames::Photon::Internal::EnetCommand> & ev) Line 1115	C++
steam_api_dotnetwrapper64.dll!ExitGames::Photon::Internal::EnetPeer::sendOutgoingCommands() Line 224	C++
steam_api_dotnetwrapper64.dll!ExitGames::Photon::Internal::PeerBase::service(bool dispatch) Line 208	C++
steam_api_dotnetwrapper64.dll!ExitGames::Photon::PhotonPeer::service(bool dispatchIncomingCommands) Line 169	C++
steam_api_dotnetwrapper64.dll!ExitGames::LoadBalancing::Client::service(bool dispatchIncomingCommands) Line 701	C++
steam_api_dotnetwrapper64.dll!Photon::PhotonListener::RunCallbacks() Line 216	C++
steam_api_dotnetwrapper64.dll!SteamWrapperAPI_RunCallbacks() Line 202	C++
I also got this warning before the error
2019-10-28 11:48:11,700 WARNING enetpeer.cpp                   ExitGames::Photon::Internal::EnetPeer::queueOutgoingReliableCommand() 937   WARNING! There are 100 outgoing messages waiting in the local sendQueue (PhotonPeer reliable commands)!

Comments

  • benjaml
    benjaml
    edited October 2019
    Options
    I've logged the number of outgoingCommands (with getQueuedOutgoingCommands()) before the call to service that does throw the error, and I have 342 outgoingCommands I don't know if this is very high or normal ? Don't know if this is related to my problem

    here is my logs (Before is before service and after is after)
    Pending outgoing commands Before : 90
    2019-10-28 13:05:59,921 WARNING enetpeer.cpp                   ExitGames::Photon::Internal::EnetPeer::queueOutgoingReliableCommand() 937   WARNING! There are 100 outgoing messages waiting in the local sendQueue (PhotonPeer reliable commands)!
    Received warning: 1027 from client
    Pending outgoing commands after : 107
    Pending outgoing commands Before : 197
    Pending outgoing commands after : 223
    Pending outgoing commands Before : 340
    Pending outgoing commands after : 339
    Pending outgoing commands Before : 342
  • benjaml
    Options
    What I don't understand is why does it not send all the pending commands ?
  • Kaiserludi
    Kaiserludi admin
    edited October 2019
    Options
    Hi @benjaml.

    What is the actual error that you face? I only see a callstack to where it happens, but no information about what happens.

    342 is indeed very high.
    The reason for the warning once the queue goes beyond 100 elements is that even that is already an extraordinary high number.

    With the exception of the caller having passed a huge (100kb or more) message to opRaiseEvent() right before the warning (in which case the warning can be ignored) having so many queued commands is a very strong indicator that there is a problem in your code. opRaiseEvent() adds commands to the outgoing queue and service() grabs the commands in the queue and sends them out. Messages that would results in more than 1200 bytes of UDP datagram size get fragmented into multiple commands. Hence if a message is really big, then a lot of commands will be added to the queue. However normal messages will just result in 1 or at max a handful of commands. Hence if the queue grows to 100 commands nonetheless, this usually means that your code has not called service() for quite a while / did a lot of opRaiseEvent() calls since the last service() call.

    The only ways I see that the queue could be bigger after a service() call than it was before that call, is that you call opRaiseEvent() from within a callback (which is fine) or from a different thread than the one on which you call service() (don't do this without applying locks! - the Photon Client is not thread safe in the sense that you could access the same instance of a class from multiple threads in parallel - it is only thread safe in the sense that static resources which might be accessed by different instances from different threads in parallel, like the memory management, are thread safe, so that you can access different instances from different threads in parallel).


    Pending outgoing commands after : 107
    Pending outgoing commands Before : 197
    Pending outgoing commands after : 223
    Pending outgoing commands Before : 340

    That means you enqueue 340 commands within 2-3 service() calls.
    Either you call service() way too rarely (you should call it regularly, multiple times per second - usually 10-20 times a second is a good choice) (please verify that the thread which calls service() is not blocked by i.E. a loading screen for multiple seconds) or you simply send way too much data. Photon is not a file-server, don't use it as such.
  • benjaml
    Options
    The problem is that I send one large message (~350kb) from time to time (at the end of the game turn) so the problem is that when I send my message, it is split in a lot of outgoing commands if I understand well ?

    I'm currently splitting this message in chunks of 20kb. I call services every frame of my game loop.

    Here is the error : 0xC0000005: Access violation reading location 0xFFFFFFFFFFFFFFFF.
  • Kaiserludi
    Options
    Hi @benjaml.

    What I don't understand is why does it not send all the pending commands ?

    Because by doing so it might cause a buffer overrun in the outgoing buffer of the socket.

    I have just checked the code: Each service() call will only pass one UDP datagram to the socket and any commands that don't fit into it that datagram will have to wait until the next call.
    You can call service() multiple times in one frame, even in a loop until all commands are out, after you have just passed a huge message to opRaiseEvent(). Each call will then check again if the socket has already sent out the data from the previous call so that we can pass it more data. However you need to add a sleep() call after each service() call to give the socket a chance to actually send out the data between service() calls.

    Still 350kb is way beyond what Photon is intended to be used for. Splitting it up into multiple chunks yourself is probably a good idea when you use UDP and try to send more than 100kb. However if you split the data up yourself anyway, it might make sense to split it into something like 1150 byte or so per chunk so that Photon does not have to fragments the chunks. Once you have multiple chunks your code has to deal with the situation that one chunk might get lost and needs to be repeated, anyway.

    All this still does not explain the memory access violation within EnetCommand::operator=(). I don't see why this would happen and I am afraid that I would need you to provide reproduction code + information on which platform this is happening to be able to look into this issue and find out what is causing it.
  • benjaml
    Options
    When I got the error it does stops in memcpy.asm
    ; Code for copying block using enhanced fast strings.
    ; This code needs to be in a separate routine because
    ; it uses non-volatile registers which must be saved
    ; and restored for exception handling.
    
            NESTED_ENTRY memcpy_repmovs, _TEXT
    
            push_reg rdi
            push_reg rsi
            .endprolog
    
            mov     rax, r11                ; return original destination pointer
            mov     rdi, rcx                ; move destination pointer to rdi
            mov     rcx, r8                 ; move length to rcx
            mov     rsi, r10                ; move source pointer to rsi
            rep     movsb                   ; copy source to destination buffer // STOPS HERE
    
            .beginepilog
            pop     rsi
            pop     rdi
            ret                             ; return
    
            NESTED_END memcpy_repmovs, _TEXT
    
  • benjaml
    Options
    So I've logged a bit more and now I know that the error occurs when I send my message (chuncked in 1150 bytes as you suggested), I'm trying to reproduce it with a small tester, I've already tried to send a lot of messages at once to see if the number of message was the issue, but it does not seem to be the case.
  • Kaiserludi
    Options
    Hi @benjaml.

    I am looking forward to your tester then.
  • benjaml
    Options
    I've successfully reproduce the bug with my tester by sending opCustomEvent from another thread, putting a mutex and lock when service() and opCustomEvent seem to correct this. Now I'm struggling with locks to correct my game :)
  • Kaiserludi
    Options
    Hi @benjaml.

    Ah, so it's just threading issue about two threads operating on the same Client instance in parallel.
    Yes, putting locks around those accesses is the way to go in this situation.