Open evilprince opened 2 years ago
logs of drachtio srf `22-09-02 07:51:25.249645 ClientController::removeApiRequest: clientMsgId f566d3c7-aa53-4f26-8924-e1ca595ed385; size: 0 2022-09-02 07:51:25.249984 Client::write_handler - wrote 528 bytes: system:0 2022-09-02 07:51:25.250117 ClientController::removeNetTransaction: transactionId 332499a4-c760-4941-812e-e695ad1cf9cf; size: 0 2022-09-02 07:51:25.250203 nta.c:5913 incoming_free() nta: incoming_free(0x56127dbf99f0) 2022-09-02 07:51:25.251084 Client::read_handler read: 0cb474ba-8320-4331-91c4-940cb6db402a|sip||2ql0d6l33pi;from-tag=ttH3cQem75UHm BYE sip:placeholder SIP/2.0 Content-Length: 0
2022-09-02 07:51:25.251278 Client::processMessage - got request with 4 tokens 2022-09-02 07:51:25.251367 Client::processMessage - request id 0cb474ba-8320-4331-91c4-940cb6db402a, request type: sip transaction id: , dialog id: 2ql0d6l33pi;from-tag=ttH3cQem75UHm 2022-09-02 07:51:25.251439 Client::processMessage - sending a request inside a dialog (dialogId provided) 2022-09-02 07:51:25.251546 ClientController::addAppTransaction: transactionId 17036590-3936-4c13-86bd-9ad5796f2244; size: 1 2022-09-02 07:51:25.251624 ClientController::addApiRequest: clientMsgId 0cb474ba-8320-4331-91c4-940cb6db402a; size: 1 2022-09-02 07:51:25.251814 SipDialogController::doSendRequestInsideDialog dialog id: 2ql0d6l33pi;from-tag=ttH3cQem75UHm 2022-09-02 07:51:25.252360 SipDialogController::doSendRequestInsideDialog - defaulting request uri to sip:192.168.1.50:30057 2022-09-02 07:51:25.252427 DrachtioController::findTportForSubscription: no transport found for 192.168.1.50 2022-09-02 07:51:25.252528 tport.c:1157 tport_ref() tport_ref(0x56127dc02fd0): refcount is now 3 2022-09-02 07:51:25.252598 nta.c:8688 outgoing_print_tport_error() nta: BYE (56488848): retrying once after Broken pipe (32) with tcp/[(null)]:0 2022-09-02 07:51:25.252651 nta.c:8688 outgoing_print_tport_error() nta: BYE (56488848): Broken pipe (32) with tcp/[(null)]:0 2022-09-02 07:51:25.252718 SipDialogController::doSendRequestInsideDialog - created orq 0x56127dc74720 sending BYE to sip:192.168.1.50:30057 2022-09-02 07:51:25.252791 tport.c:1157 tport_ref() tport_ref(0x56127dc02fd0): refcount is now 4 2022-09-02 07:51:25.252845 tport.c:1170 tport_unref() tport_unref(0x56127dc02fd0): refcount is now 3 2022-09-02 07:51:25.252900 SipDialogController::addRIP adding orq 0x56127dc74720 2022-09-02 07:51:25.252963 No connected clients found to handle incoming cdr:stop request 2022-09-02 07:51:25.253023 ClientController::removeApiRequest: clientMsgId 0cb474ba-8320-4331-91c4-940cb6db402a; size: 0 2022-09-02 07:51:25.253113 SipDialogController::processResponseInsideDialog: 2022-09-02 07:51:25.253167 SipDialogController::findRIPByOrq orq 0x56127dc74720 2022-09-02 07:51:25.253213 SipDialogController::processResponseInsideDialog: found request for BYE sip status 410 2022-09-02 07:51:25.253264 tport.c:1157 tport_ref() tport_ref(0x56127dc02fd0): refcount is now 4 2022-09-02 07:51:25.253313 tport.c:1170 tport_unref() tport_unref(0x56127dc02fd0): refcount is now 3 2022-09-02 07:51:25.253381 ClientController::removeAppTransaction: transactionId 17036590-3936-4c13-86bd-9ad5796f2244; size: 0 2022-09-02 07:51:25.253434 ClientController::removeDialog - after removing dialogs count is now: 4 2022-09-02 07:51:25.253481 SipDialogController::processResponseInsideDialog: clearing dialog after receiving response to BYE or notify w/ subscription-state terminated 2022-09-02 07:51:25.253536 SipDialogController::clearRIP clearing orq 0x56127dc74720 2022-09-02 07:51:25.253589 SipDialog::~SipDialog - destroying sip dialog with call-id 2ql0d6l33pi 2022-09-02 07:51:25.253639 nta.c:4640 nta_leg_destroy() nta_leg_destroy(0x56127dc39110) 2022-09-02 07:51:25.253689 tport.c:1170 tport_unref() tport_unref(0x56127dc02fd0): refcount is now 2 2022-09-02 07:51:25.253740 TimerDHandler::clearTimerD - app never sent ACK for successful uac INVITE 2022-09-02 07:51:25.253785 SipDialog::~SipDialog - destroying orq from original (uac) INVITE 0x56127dc6f370 2022-09-02 07:51:25.255164 Client::read_handler read: e86de0cb-2f85-491b-8c7b-18576904b1c6|sip||gnl16d1joa3itms2ebe5;from-tag=ve2lrsbs97 BYE sip:placeholder SIP/2.0 Content-Length: 0
2022-09-02 07:51:25.255297 Client::processMessage - got request with 4 tokens 2022-09-02 07:51:25.255362 Client::processMessage - request id e86de0cb-2f85-491b-8c7b-18576904b1c6, request type: sip transaction id: , dialog id: gnl16d1joa3itms2ebe5;from-tag=ve2lrsbs97 2022-09-02 07:51:25.255416 Client::processMessage - sending a request inside a dialog (dialogId provided) 2022-09-02 07:51:25.255490 ClientController::addAppTransaction: transactionId b645c5b7-6f9e-48d4-9ada-1e666c729bc1; size: 1 2022-09-02 07:51:25.255549 ClientController::addApiRequest: clientMsgId e86de0cb-2f85-491b-8c7b-18576904b1c6; size: 1 2022-09-02 07:51:25.255640 Client::read_handler processing follow-on message in read buffer, remaining bytes to process: 132 2022-09-02 07:51:25.255707 Client::read_handler follow-on message length of 128 bytes 2022-09-02 07:51:25.255666 SipDialogController::doSendRequestInsideDialog dialog id: gnl16d1joa3itms2ebe5;from-tag=ve2lrsbs97 2022-09-02 07:51:25.255774 Client::read_handler read: c3b85842-5367-4745-a92d-f0264342d0b2|sip||2ql0d6l33pi;from-tag=ttH3cQem75UHm BYE sip:placeholder SIP/2.0 Content-Length: 0
2022-09-02 07:51:25.255810 Can't find dialog for dialog id gnl16d1joa3itms2ebe5;from-tag=ve2lrsbs97 2022-09-02 07:51:25.255854 Client::processMessage - got request with 4 tokens 2022-09-02 07:51:25.255898 SipDialogController::doSendRequestInsideDialog - Error: unable to find dialog for dialog id provided `
Hmm, it would be good to see the drachtio server log that goes along with this. Is this recreatable?
logs of drachtio srf `22-09-02 07:51:25.249645 ClientController::removeApiRequest: clientMsgId f566d3c7-aa53-4f26-8924-e1ca595ed385; size: 0 2022-09-02 07:51:25.249984 Client::write_handler - wrote 528 bytes: system:0 2022-09-02 07:51:25.250117 ClientController::removeNetTransaction: transactionId 332499a4-c760-4941-812e-e695ad1cf9cf; size: 0 2022-09-02 07:51:25.250203 nta.c:5913 incoming_free() nta: incoming_free(0x56127dbf99f0) 2022-09-02 07:51:25.251084 Client::read_handler read: 0cb474ba-8320-4331-91c4-940cb6db402a|sip||2ql0d6l33pi;from-tag=ttH3cQem75UHm BYE sip:placeholder SIP/2.0 Content-Length: 0
2022-09-02 07:51:25.251278 Client::processMessage - got request with 4 tokens 2022-09-02 07:51:25.251367 Client::processMessage - request id 0cb474ba-8320-4331-91c4-940cb6db402a, request type: sip transaction id: , dialog id: 2ql0d6l33pi;from-tag=ttH3cQem75UHm 2022-09-02 07:51:25.251439 Client::processMessage - sending a request inside a dialog (dialogId provided) 2022-09-02 07:51:25.251546 ClientController::addAppTransaction: transactionId 17036590-3936-4c13-86bd-9ad5796f2244; size: 1 2022-09-02 07:51:25.251624 ClientController::addApiRequest: clientMsgId 0cb474ba-8320-4331-91c4-940cb6db402a; size: 1 2022-09-02 07:51:25.251814 SipDialogController::doSendRequestInsideDialog dialog id: 2ql0d6l33pi;from-tag=ttH3cQem75UHm 2022-09-02 07:51:25.252360 SipDialogController::doSendRequestInsideDialog - defaulting request uri to sip:192.168.1.50:30057 2022-09-02 07:51:25.252427 DrachtioController::findTportForSubscription: no transport found for 192.168.1.50 2022-09-02 07:51:25.252528 tport.c:1157 tport_ref() tport_ref(0x56127dc02fd0): refcount is now 3 2022-09-02 07:51:25.252598 nta.c:8688 outgoing_print_tport_error() nta: BYE (56488848): retrying once after Broken pipe (32) with tcp/[(null)]:0 2022-09-02 07:51:25.252651 nta.c:8688 outgoing_print_tport_error() nta: BYE (56488848): Broken pipe (32) with tcp/[(null)]:0 2022-09-02 07:51:25.252718 SipDialogController::doSendRequestInsideDialog - created orq 0x56127dc74720 sending BYE to sip:192.168.1.50:30057 2022-09-02 07:51:25.252791 tport.c:1157 tport_ref() tport_ref(0x56127dc02fd0): refcount is now 4 2022-09-02 07:51:25.252845 tport.c:1170 tport_unref() tport_unref(0x56127dc02fd0): refcount is now 3 2022-09-02 07:51:25.252900 SipDialogController::addRIP adding orq 0x56127dc74720 2022-09-02 07:51:25.252963 No connected clients found to handle incoming cdr:stop request 2022-09-02 07:51:25.253023 ClientController::removeApiRequest: clientMsgId 0cb474ba-8320-4331-91c4-940cb6db402a; size: 0 2022-09-02 07:51:25.253113 SipDialogController::processResponseInsideDialog: 2022-09-02 07:51:25.253167 SipDialogController::findRIPByOrq orq 0x56127dc74720 2022-09-02 07:51:25.253213 SipDialogController::processResponseInsideDialog: found request for BYE sip status 410 2022-09-02 07:51:25.253264 tport.c:1157 tport_ref() tport_ref(0x56127dc02fd0): refcount is now 4 2022-09-02 07:51:25.253313 tport.c:1170 tport_unref() tport_unref(0x56127dc02fd0): refcount is now 3 2022-09-02 07:51:25.253381 ClientController::removeAppTransaction: transactionId 17036590-3936-4c13-86bd-9ad5796f2244; size: 0 2022-09-02 07:51:25.253434 ClientController::removeDialog - after removing dialogs count is now: 4 2022-09-02 07:51:25.253481 SipDialogController::processResponseInsideDialog: clearing dialog after receiving response to BYE or notify w/ subscription-state terminated 2022-09-02 07:51:25.253536 SipDialogController::clearRIP clearing orq 0x56127dc74720 2022-09-02 07:51:25.253589 SipDialog::~SipDialog - destroying sip dialog with call-id 2ql0d6l33pi 2022-09-02 07:51:25.253639 nta.c:4640 nta_leg_destroy() nta_leg_destroy(0x56127dc39110) 2022-09-02 07:51:25.253689 tport.c:1170 tport_unref() tport_unref(0x56127dc02fd0): refcount is now 2 2022-09-02 07:51:25.253740 TimerDHandler::clearTimerD - app never sent ACK for successful uac INVITE 2022-09-02 07:51:25.253785 SipDialog::~SipDialog - destroying orq from original (uac) INVITE 0x56127dc6f370 2022-09-02 07:51:25.255164 Client::read_handler read: e86de0cb-2f85-491b-8c7b-18576904b1c6|sip||gnl16d1joa3itms2ebe5;from-tag=ve2lrsbs97 BYE sip:placeholder SIP/2.0 Content-Length: 0
2022-09-02 07:51:25.255297 Client::processMessage - got request with 4 tokens 2022-09-02 07:51:25.255362 Client::processMessage - request id e86de0cb-2f85-491b-8c7b-18576904b1c6, request type: sip transaction id: , dialog id: gnl16d1joa3itms2ebe5;from-tag=ve2lrsbs97 2022-09-02 07:51:25.255416 Client::processMessage - sending a request inside a dialog (dialogId provided) 2022-09-02 07:51:25.255490 ClientController::addAppTransaction: transactionId b645c5b7-6f9e-48d4-9ada-1e666c729bc1; size: 1 2022-09-02 07:51:25.255549 ClientController::addApiRequest: clientMsgId e86de0cb-2f85-491b-8c7b-18576904b1c6; size: 1 2022-09-02 07:51:25.255640 Client::read_handler processing follow-on message in read buffer, remaining bytes to process: 132 2022-09-02 07:51:25.255707 Client::read_handler follow-on message length of 128 bytes 2022-09-02 07:51:25.255666 SipDialogController::doSendRequestInsideDialog dialog id: gnl16d1joa3itms2ebe5;from-tag=ve2lrsbs97 2022-09-02 07:51:25.255774 Client::read_handler read: c3b85842-5367-4745-a92d-f0264342d0b2|sip||2ql0d6l33pi;from-tag=ttH3cQem75UHm BYE sip:placeholder SIP/2.0 Content-Length: 0
2022-09-02 07:51:25.255810 Can't find dialog for dialog id gnl16d1joa3itms2ebe5;from-tag=ve2lrsbs97 2022-09-02 07:51:25.255854 Client::processMessage - got request with 4 tokens 2022-09-02 07:51:25.255898 SipDialogController::doSendRequestInsideDialog - Error: unable to find dialog for dialog id provided `