Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

SIP Message events lost from drachtio server #339

Open
Vatsalsoni13 opened this issue Feb 12, 2024 · 0 comments
Open

SIP Message events lost from drachtio server #339

Vatsalsoni13 opened this issue Feb 12, 2024 · 0 comments

Comments

@Vatsalsoni13
Copy link

Overview:

User registers with drachtio server successfully, then generates a SIP Message which leads to the issue.

Expected messge:

MESSAGE example.org SIP/2.0
Via: SIP/2.0/WS 9m44aokjkv3e.invalid;branch=z9hG4bK1777670
To: <sip:example.org>
From: "xxxxxxxx" <sip:xxxxxx@xxxxxxxxxxxxxx>;tag=7vd4cmhrc6
CSeq: 1 MESSAGE
Call-ID: f10artt753csvbdh09bd
Max-Forwards: 70
Supported: outbound
User-Agent: SIP.js/0.21.2
Content-Type: application/vnd.3gpp.mcdata-signalling
Content-Length:38

�eɾ��³�´¢�IH©wÙÀ²ÞÉ�� �0�DA��@YÎ�µ¤U

This happens only in case of binary messages.
Function used for binary conversion:

hex2a = (hexx: any) => {
    var hex = hexx.toString();//force conversion
    var str = '';
    for (var i = 0; (i < hex.length); i += 2) {
      str += String.fromCharCode(parseInt(hex.substr(i, 2), 16));
    }
    return str;
  }

Logs on drachtio server. Log-level - 9.
udp-mtu set to 4096

2024-02-12 12:15:34.600846 tport.c:2845 tport_wakeup() tport_wakeup(0x559ab07bd730): events IN
2024-02-12 12:15:34.600969 tport.c:2949 tport_recv_event() tport_recv_event(0x559ab07bd730)
2024-02-12 12:15:34.601071 tport.c:3290 tport_recv_iovec() tport_recv_iovec(0x559ab07bd730) msg 0x559ab07f3b60 from (ws/192.x.x.x:50604) has 808 bytes, veclen = 1
2024-02-12 12:15:34.601339 recv 808 bytes from ws/[192.x.x.x]:50604 at 12:15:34.601128:
MESSAGE sip:example.org SIP/2.0
Via: SIP/2.0/WS 9m44aokjkv3e.invalid;branch=z9hG4bK1777670
To: <sip:example.org>
From: "xxxxxxxx" <sip:xxxxxx@xxxxxxxxxxxxxx>;tag=7vd4cmhrc6
CSeq: 1 MESSAGE
Call-ID: f10artt753csvbdh09bd
Max-Forwards: 70
Supported: outbound
User-Agent: SIP.js/0.21.2
Content-Type: application/vnd.3gpp.mcdata-signalling
Content-Length:38

   <ENCODED DATA>
 
2024-02-12 12:15:34.601413    *** message truncated at 585 ***
2024-02-12 12:15:34.601446 tport.c:3108 tport_deliver() tport_deliver(0x559ab07bd730): msg 0x559ab07f3b60 (808 bytes) from ws/192.x.x.x:50604 next=(nil)
2024-02-12 12:15:34.601477 tport.c:1181 tport_ref() tport_ref(0x559ab07bd730): refcount is now 2
2024-02-12 12:15:34.601512 nta.c:3060 agent_recv_request() nta: received MESSAGE sip:example.org SIP/2.0 (CSeq 1)
2024-02-12 12:15:34.601550 nta.c:3360 agent_check_request_via() nta: Via check: received=192.x.x.x
2024-02-12 12:15:34.601638 nta.c:3277 agent_recv_request() nta: MESSAGE (1) to message callback
2024-02-12 12:15:34.601670 processMessageStatelessly - incoming message with call-id f10artt753csvbdh09bd does not match an existing call leg, processed in thread 140615518198144
2024-02-12 12:15:34.601704 tport.c:1181 tport_ref() tport_ref(0x559ab07bd730): refcount is now 3
2024-02-12 12:15:34.601732 tport.c:1194 tport_unref() tport_unref(0x559ab07bd730): refcount is now 2
2024-02-12 12:15:34.601775 ClientController::selectClientForRequestOutsideDialog - there are 1 possible clients, we are starting with offset 0
2024-02-12 12:15:34.601808 ClientController::route_request_outside_dialog - Selected client at offset 0
2024-02-12 12:15:34.601838 tport.c:1181 tport_ref() tport_ref(0x559ab07bd730): refcount is now 3
2024-02-12 12:15:34.601866 tport.c:1194 tport_unref() tport_unref(0x559ab07bd730): refcount is now 2
2024-02-12 12:15:34.601911 tport.c:1181 tport_ref() tport_ref(0x559ab07bd730): refcount is now 3
2024-02-12 12:15:34.601938 PendingRequestController::add - tport: 0x559ab07bd730, Call-ID: f10artt753csvbdh09bd, transactionId f8043558-c5fb-44fa-a952-d7d70c3d1c6b
2024-02-12 12:15:34.601972 pending-request: Adding entry to go off in 64000ms
2024-02-12 12:15:34.601998 pending-request: Adding entry to the head (queue was empty), length: 1
2024-02-12 12:15:34.602047 tport.c:1181 tport_ref() tport_ref(0x559ab07bd730): refcount is now 4
2024-02-12 12:15:34.602082 tport.c:1194 tport_unref() tport_unref(0x559ab07bd730): refcount is now 3
2024-02-12 12:15:34.610146 tport.c:2845 tport_wakeup() tport_wakeup(0x559ab0751850): events IN
2024-02-12 12:15:34.610241 tport.c:2949 tport_recv_event() tport_recv_event(0x559ab0751850)
2024-02-12 12:15:34.610318 tport.c:3290 tport_recv_iovec() tport_recv_iovec(0x559ab0751850) msg 0x559ab076a490 from (tcp/192.x.x.x:8642) has 504 bytes, veclen = 1
2024-02-12 12:15:34.610580 recv 504 bytes from tcp/[192.x.x.x]:8642 at 12:15:34.610392:
SIP/2.0 403 Forbidden
Via: SIP/2.0/TCP 192.x.x.x:9357;branch=z9hG4bKytD18FeBUHa5B;rport=38855
From: "xxxxxxxx" <sip:xxxxxx@xxxxxxxxxxxxxx>;tag=7vd4cmhrc6
To: <sip:example.org>;tag=e6SNrypZQBFDg
Call-ID: 2a12c9ec-4415-123d-ccb2-80e82c5694de
CSeq: 79306375 MESSAGE
User-Agent: xxxxxxxxxxx
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Content-Length: 0
 
2024-02-12 12:15:34.610719 tport.c:3108 tport_deliver() tport_deliver(0x559ab0751850): msg 0x559ab076a490 (504 bytes) from tcp/192.x.x.x:8642 next=(nil)
2024-02-12 12:15:34.610769 tport.c:1181 tport_ref() tport_ref(0x559ab0751850): refcount is now 10
2024-02-12 12:15:34.610803 nta.c:3484 agent_recv_response() nta: received 403 Forbidden for MESSAGE (79306375)
2024-02-12 12:15:34.610836 nta.c:3551 agent_recv_response() nta: 403 Forbidden is going to a transaction
2024-02-12 12:15:34.610871 nta.c:9813 outgoing_estimate_delay() nta_outgoing: RTT is 2.363 ms
2024-02-12 12:15:34.610909 nta.c:9596 outgoing_recv() outgoing_recv: tport(0x559ab0751850) orq(0x559ab070f670) calling tport_release because we have pending 4
2024-02-12 12:15:34.610958 tport.c:4319 tport_release() tport_release(0x559ab0751850): 0x559ab07850e0 by 0x559ab070f670 with 0x559ab076a490
2024-02-12 12:15:34.610999 SipDialogController::processResponseOutsideDialog
2024-02-12 12:15:34.611043 tport.c:1181 tport_ref() tport_ref(0x559ab0751850): refcount is now 11
2024-02-12 12:15:34.611095 tport.c:1194 tport_unref() tport_unref(0x559ab0751850): refcount is now 10
2024-02-12 12:15:34.611133 SipDialogController::findRIPByOrq orq 0x559ab070f670
2024-02-12 12:15:34.611172 SipDialogController::clearRIP clearing orq 0x559ab070f670
2024-02-12 12:15:34.611211 nta.c:8953 outgoing_free() nta: outgoing_free(0x559ab070f670)
2024-02-12 12:15:34.611250 tport.c:1194 tport_unref() tport_unref(0x559ab0751850): refcount is now 9
2024-02-12 12:15:34.611359 ClientController::removeAppTransaction: transactionId 1d19b4dd-d120-42e4-9fd3-0d748607dc73; size: 0
2024-02-12 12:15:34.611451 tport.c:1194 tport_unref() tport_unref(0x559ab0751850): refcount is now 8
2024-02-12 12:15:34.611520 tport.c:2363 tport_set_secondary_timer() tport(0x559ab0751850): reset timer
2024-02-12 12:15:34.611544 Client::write_handler - wrote 639 bytes: system:0
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant