Server websocket disconnects after 10 pings

edited March 2021 in Repetier-Server
Hello,
I am running Server 1.0.4 Flora 54 running under raspbian buster.

I am using the websockets api for python to receive events from the printer. This works well, though as the documentation states, the server kills the connection after about 10s. To remedy this, every two seconds I am sending a ping message.

The behavior that I am seeing is that the server replies to the first 10 pings over 20s and then after that stops returning pings, but still returns events. Soon after it stops returning pings it closes the socket.

It was my impression from the api doc that pings would keep the socket from being closed. IS this not true?

Here is the data returned from the server on a ping:
Sending ping:
{"action":"ping","data":{},"printer":"MyPrinter","callback_id":20000}
{"callback_id":20000,"data":{},"session":"IeZwcrpnMArc$43#zv9TaiXpk#Ljr7!@}
{"callback_id":-1,"data":[{"data":{"login":"global","permissions":65535,"settings":{"gcodeGroup":"{\"RepRap\":\"#\"}","gcodeSortBy":"2","gcodeViewMode":"0","tempDiagActive":"0","tempDiagAll":"0","tempDiagBed":"0","tempDiagChamber":"0","tempDiagMode":"0","theme":"auto"}},"event":"userCredentials"}],"eventList":true}

As you can see, sending a ping (first line is printed from python prior to sending) results in a reply, followed by an event. The next few lines show the the 10th and 11th pings:

Sending ping:
{"action":"ping","data":{},"printer":"MyPrinter","callback_id":20009}
{"callback_id":20009,"data":{},"session":"IeZwcrpnMArc$43#zv9TaiXpk#Ljr7!@}
{"callback_id":-1,"data":[{"data":{"O":0.0,"S":0.0,"T":19.5,"id":0,"t":1616111334379},"event":"temp","printer":"RepRap"},{"data":{"O":0.0,"S":0.0,"T":19.3,"id":1,"t":1616111334380},"event":"temp","printer":"RepRap"},{"data":{"O":0.0,"S":0.0,"T":19.3,"id":1000,"t":1616111334380},"event":"temp","printer":"RepRap"}],"eventList":true}
{"callback_id":-1,"data":[{"data":{"O":0.0,"S":0.0,"T":19.5,"id":0,"t":1616111335383},"event":"temp","printer":"RepRap"},{"data":{"O":0.0,"S":0.0,"T":19.3,"id":1,"t":1616111335383},"event":"temp","printer":"RepRap"},{"data":{"O":0.0,"S":0.0,"T":19.4,"id":1000,"t":1616111335383},"event":"temp","printer":"RepRap"}],"eventList":true}

Sending ping:
{"action":"ping","data":{},"printer":"MyPrinter","callback_id":20010}
{"callback_id":-1,"data":[{"data":{"O":0.0,"S":0.0,"T":19.8,"id":0,"t":1616111336382},"event":"temp","printer":"RepRap"},{"data":{"O":0.0,"S":0.0,"T":19.4,"id":1,"t":1616111336382},"event":"temp","printer":"RepRap"},{"data":{"O":0.0,"S":0.0,"T":19.4,"id":1000,"t":1616111336383},"event":"temp","printer":"RepRap"}],"eventList":true}
{"callback_id":-1,"data":[{"data":{"O":0.0,"S":0.0,"T":19.4,"id":0,"t":1616111337382},"event":"temp","printer":"RepRap"},{"data":{"O":0.0,"S":0.0,"T":19.2,"id":1,"t":1616111337382},"event":"temp","printer":"RepRap"},{"data":{"O":0.0,"S":0.0,"T":19.4,"id":1000,"t":1616111337382},"event":"temp","printer":"RepRap"}],"eventList":true}

As you can see, the server stops replying, but still sends events. This goes on until the server closes the connection.

My python code is relatively simple:
#!/usr/bin/python3

import websockets
import asyncio

async def get_message(websocket):
       while True:
             try:
                 message = await websocket.recv()
                 print(message)

             except websockets.exceptions.ConnectionClosed:
                 print('ConnectionClosed')
                 is_alive = False
                 break
async def ping_server(websocket):
       callback_id = 20000
       while True:
                 ping_str = """{"action":"ping","data":{},"printer":"MyPrinter","callback_id":""" + str(callback_id) + """}"""
                 print("\nSending ping:")
                 print(ping_str)
                 await websocket.send(ping_str)
                 callback_id = callback_id + 1

                 await asyncio.sleep(2)
 
async def main():
        async with websockets.connect('ws://localhost:3344/socket') as ws:
                res = await asyncio.gather(get_message(ws), ping_server(ws))
        return res


if(__name__ == "__main__"):
        r1, r2 = asyncio.run(main())

Any insights on the cause of my problem would be greatly appreciated!

Thank you



Comments

  • Also, trying to change the behavior with extendPing at the beginning returns this:
    Sending extendPing:
    {"action":"extendPing","data":{"timeout":"100"},"printer":"MyPrinter","callback_id":199}

    Sending ping:
    {"action":"ping","data":{},"printer":"MyPrinter","callback_id":200}
    {"callback_id":199,"data":{},"session":"*RJ@sF1u670BGNwa5KwkIm^zzI&EY41D"}

    but ultimately has no effect on the behavior.

  • The problem is when you start sending real websocket ping frames. This confuses the server and it does not understand the commands anymore as they are prefixed with ping frame content. Connect like this instead:

            async with websockets.connect('ws://localhost:3344/socket',ping_interval=None) as ws:

    ping_interval=None disables sending ping frames and server is happy.
  • Thanks to your example I could now add a ping/pong correctly. So starting with 1.0.5 ping messages get correctly answered from the websocket protocol as well. Until then disable native ping.
  • Thank you for your prompt reply!

    You are awesome as usual.

     --D
Sign In or Register to comment.