[SR-Users] 200 OK re transmission only on re-SUBSCRIBE

[Lewis Hutchinson]

First of all I should start by saying this is my first post so go easy on me!! : ) and thank for everyone's efforts to share knowledge it has been invaluable for my kamailio learning.

Build Details

Version: kamailio 5.5.3 (x86_64/linux)
Kamailio kemi python

Scenario

Relevant config

def ksr_route_api_query(self, msg):
        KSR.log("info", "SUBSCRIBE API Query Starts")

        # Create new Transaction
        KSR.tm.t_newtran()

        async def main():
            url = 'https://api.hidingtheurl.com/subscribe'
            payload = {
                "ruri": KSR.pv.get("$ru"),
                "from": KSR.pv.get("$fu"),
                "from_tag": KSR.pv.gete("$ft"),
                "to": KSR.pv.get("$tu"),
                "callid": KSR.pv.get("$ci"),
                "cseq": KSR.pv.get("$cs"),
                "contact": KSR.pv.gete("$ct"),
                "supported": KSR.pv.get("$hdr(Supported)"),
                "event": KSR.pv.get("$hdr(Event)"),
                "expires": KSR.pv.get("$hdr(Expires)"),
                "diversion": KSR.pv.get("$di"),
                "body": KSR.pv.get("$rb")
                }
            async with aiohttp.ClientSession() as session:
                async with session.post(url, json=payload) as response:
                    if response.status == 0:
                        KSR.xlog.xinfo(f"SUB Manager Timeout: {response.status}")
                        KSR.tm.t_reply(408, "SUB Manager Timeout")
                    elif response.status >= 500:
                        KSR.xlog.xinfo(f"SUB Manager Down: {response.status}")
                        KSR.tm.t_reply(500, "SUB Manager Down")
                    elif response.status >= 400:
                        KSR.xlog.xinfo(f"SUB Manager Error: {response.status}")
                        KSR.tm.t_reply(400, "SUB Manager Error")
                    else:
                        if response.status == 200:
                            KSR.xlog.xinfo(f"SUB Manager Success: {response.status}")
                            KSR.tm.t_reply(200, "OK")

        KSR.log("info", "SUBSCRIBE API Query Ends")
        asyncio.run(main())
        # API Query Ends

Scenario

Initial SUBSCRIBE >>> hits Kamailio >>> send payload in JSON to API get receive 200OK response from API and send a 200OK on to Device

SUBSCRIBE -------->
<------------ 200 OK

After Subscription Expiry

re-SUBSCRIBE >>> hits Kamailio >>> send payload in JSON to API get 200OK response from API and send a 200OK on to Device but also another 200OK a fraction of a second later...

SUBSCRIBE -------->
<------------ 200 OK
<<<--------- 200 OK


This happens for all following re-SUBSCRIBE's

The 200 OK are identical, and it is a re transmission, but I can't work out why..

Relevant DEBUG is below

Jan 26 12:31:17 ip-172-20-46-39 kamailio[11234]: INFO: <script>: SUB Manager Success: 200
Jan 26 12:31:17 ip-172-20-46-39 kamailio[11234]: DEBUG: app_python3 [apy_kemi.c:232]: sr_apy_kemi_exec_func_ex(): execution of method: t_reply
Jan 26 12:31:17 ip-172-20-46-39 kamailio[11234]: DEBUG: app_python3 [apy_kemi.c:287]: sr_apy_kemi_exec_func_ex(): params[2] for: t_reply are int-str: [200] [OK]
Jan 26 12:31:17 ip-172-20-46-39 kamailio[11234]: DEBUG: tm [t_lookup.c:1034]: t_check_msg(): msg (0x7eff0cd4e828) id=2/11234 global id=2/11234 T start=0x7eff0918d7d8
Jan 26 12:31:17 ip-172-20-46-39 kamailio[11234]: DEBUG: tm [t_lookup.c:1108]: t_check_msg(): T (0x7eff0918d7d8) already found for msg (0x7eff0cd4e828)!
Jan 26 12:31:17 ip-172-20-46-39 kamailio[11234]: DEBUG: <core> [core/msg_translator.c:162]: check_via_address(): (80.111.111.111, 80.111.111.111, 0)
Jan 26 12:31:17 ip-172-20-46-39 kamailio[11234]: DEBUG: tm [t_reply.c:1763]: cleanup_uac_timers(): RETR/FR timers reset
Jan 26 12:31:17 ip-172-20-46-39 kamailio[11234]: DEBUG: tm [t_reply.c:637]: _reply_light(): reply sent out - buf=0x7eff0cd50938: SIP/2.0 200 OK#015#012Via:... shmem=0x7eff09190ca8: SIP/2.0 200 OK#015#012Via:
Jan 26 12:31:17 ip-172-20-46-39 kamailio[11234]: DEBUG: tm [t_reply.c:648]: _reply_light(): finished

Jan 26 12:31:17 ip-172-20-46-39 kamailio[11234]: DEBUG: app_python3 [apy_kemi.c:232]: sr_apy_kemi_exec_func_ex(): execution of method: t_precheck_trans
Jan 26 12:31:17 ip-172-20-46-39 kamailio[11234]: DEBUG: app_python3 [apy_kemi.c:232]: sr_apy_kemi_exec_func_ex(): execution of method: t_check_trans
Jan 26 12:31:17 ip-172-20-46-39 kamailio[11234]: DEBUG: tm [t_lookup.c:1034]: t_check_msg(): msg (0x7eff0cd4e828) id=2/11234 global id=2/11234 T start=0x7eff0918d7d8
Jan 26 12:31:17 ip-172-20-46-39 kamailio[11234]: DEBUG: tm [t_lookup.c:1108]: t_check_msg(): T (0x7eff0918d7d8) already found for msg (0x7eff0cd4e828)!
Jan 26 12:31:17 ip-172-20-46-39 kamailio[11234]: DEBUG: tm [t_reply.c:1703]: t_retransmit_reply(): reply retransmitted. buf=0x7eff0cb18220: SIP/2.0 2..., shmem=0x7eff09190ca8: SIP/2.0 2
Jan 26 12:31:17 ip-172-20-46-39 kamailio[11234]: DEBUG: app_python3 [apy_kemi.c:112]: sr_kemi_config_engine_python(): execution of route type 1 with no name returned 1
Jan 26 12:31:17 ip-172-20-46-39 kamailio[11234]: DEBUG: <core> [core/receive.c:514]: receive_msg(): request-route executed in: 38258 usec


Everything works well as is but I want to clean up this issue or at least understand what is causing it.



Lewis
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-users/attachments/20220126/cb06b873/attachment.htm>