[asterisk-bugs] [JIRA] (ASTERISK-29844) pjsip logs, probably pcaps, incorrect packet contents
Joshua C. Colp (JIRA)
noreply at issues.asterisk.org
Fri Jan 7 09:46:06 CST 2022
[ https://issues.asterisk.org/jira/browse/ASTERISK-29844?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=257673#comment-257673 ]
Joshua C. Colp commented on ASTERISK-29844:
-------------------------------------------
Things have to be attached after creation, as you need to specify whether something is code or not.
> pjsip logs, probably pcaps, incorrect packet contents
> -----------------------------------------------------
>
> Key: ASTERISK-29844
> URL: https://issues.asterisk.org/jira/browse/ASTERISK-29844
> Project: Asterisk
> Issue Type: Bug
> Security Level: None
> Components: Resources/res_pjsip_logger
> Affects Versions: 18.8.0
> Reporter: Tony Wooster
>
> The pjsip logger logs both textually and can emit pcap-format captures of received SIP messages. On occasion, it appears to output incorrect packet data, showing output of several SIP packets in a single log line.
> As an example, take a look at this (somewhat reformatted, and anonymized), log capture:
> {noformat}
> <--- Received SIP request (611 bytes) from TCP:192.168.125.1:40499 --->
> INVITE sip:xxxxxxxxx at 10.241.240.166;user=phone SIP/2.0
> Record-Route: <sip:192.168.125.1;transport=tcp;r2=on;lr;nat=yes>
> Record-Route: <sip:10.241.240.166;r2=on;lr;nat=yes>
> Via: SIP/2.0/TCP 192.168.125.1;branch=z9hG4bKfc48.81e023d5054cfc91973b6cc82985af44.0
> Via: SIP/2.0/UDP 10.150.16.68:5071;rport=5071;branch=z9hG4bKrbmvcn6vr4212o2v61x2o1524;X-DispMsg=1406
> Call-ID: k4bxn2ov3ov4lvbncb66mkol6oo6xrkl at 10.18.5.64
> From: "xxxxxxxxx"<sip:xxxxxxxxx at 10.150.16.68;transport=udp;user=phone>;tag=b33r3b6v-CC-1052-OFC-215
> To: "xxxxxxxxx"<sip:xxxxxxxxx at 10.241.240.166;transport=udp;user=phone>
> CSeq: 1 INVITE
> P-Access-Network-Info: GEN-ACCESS;"area-number=+xxxxxxxxxxxx"
> Max-Forwards: 69
> Contact: <sip:10.150.16.68:5060;alias=10.150.16.68~5071~1>
> Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,INFO,PRACK,NOTIFY,MESSAGE,UPDATE
> P-Asserted-Identity: <tel:xxxxxxxxx>
> P-Early-Media: supported
> Supported: 100rel,timer,histinfo,precondition
> Min-SE: 90
> Session-Expires: 1800;refresher=uac
> Content-Length: 712
> Content-Type: application/sdp
> v=0
> o=HuaweiSoftx3000 1074236091 1074236092 IN IP4 192.168.125.1
> s=SipCall
> c=IN IP4 192.168.125.1
> t=0 0
> m=audio 43494 RTP/AVP 108 105 3 96 106 101 8 116
> a=rtpmap:108 AMR/8000
> a=fmtp:108 mode-set=0,2,4,7;mode-change-neighbor=1;mode-change-period=2
> a=rtpmap:105 GSM-EFR/8000
> a=rtpmap:3 GSM/8000
> a=rtpmap:96 AMR/8000
> a=fmtp:96 mode-set=0,2,4;mode-change-neighbor=1;mode-change-period=2
> a=rtpmap:106 GSM-HR/8000
> a=rtpmap:101 AMR-WB/8000
> a=fmtp:101 mode-set=0,1,2,8
> a=rtpmap:8 PCMA/8000
> a=rtpmap:116 telephone-event/8000
> a=ptime:20
> a=maxptime:20
> a=curr:qos local sendrecv
> a=curr:qos remote none
> a=des:qos mandatory local sendrecv
> a=des:qos optional remote sendrecv
> a=3gOoBTC
> a=nortpproxy:yes
> BYE sip:192.168.125.10:5060;transport=tcp SIP/2.0
> Via: SIP/2.0/TCP 192.168.125.1;branch=z9hG4bKe5a1.55acf2e6fb99b7f2fe7faf3019ac39b6.0
> Via: SIP/2.0/UDP 10.150.16.68:5071;rport=5071;branch=z9hG4bK1i03bkiiwi82i1bja8k3cphap;X-DispMsg=1406
> Call-ID: 3b2krrccij18l3w83k2ibpkjc0hlhal0 at 10.18.5.64
> From: "xxxxxxxxx"<sip:xxxxxxxxx at 10.150.16.68;transport=udp;user=phone>;tag=iww23a8b-CC-1035-OFC-215
> To: "xxxxxxxxx"<sip:xxxxxxxxx at 10.241.240.166;transport=udp;user=phone>;tag=a82de1b9-196b-416a-98fc-a8b84d97e641
> CSeq: 3 BYE
> Max-Forwards: 69
> Reason: Q.850;cause=16;text="Normal call clearing"
> Content-Length: 0
> INVITE sip:xxxxxxxxx at 10.241.240.166;user=phone SIP/2.0
> Record-Route: <sip:192.168.125.1;transport=tcp;r2=on;lr;nat=yes>
> Record-Route: <sip:10.241.240.166;r2=on;lr;nat=yes>
> ... etc, continues until end of packet buffer ...
> {noformat}
> As you can see, the received length (611 bytes) definitely doesn't correspond to the overall output, nor does it correspond to the typical length of an `INVITE` (~1700 bytes, from what I've seen). It looks more like it's corresponding to the `BYE` that's crushed right up to the end of the first `INVITE` in the output.
> Looking at the code (`res/res_pjsip_logger.c`), I think this is because logging (and pcap both!) have bugs. They reference `pkt_info.packet` -- the start of the packet buffer -- rather than `msg_info.msg_buf` -- the start of the current message -- and textual logging doesn't use the `msg_info.len`.
> I don't have Gerrit access yet, still awaiting legal approval, but hey, I think this is the fix I think will work:
> {noformat}
> diff --git a/res/res_pjsip_logger.c b/res/res_pjsip_logger.c
> index 957020f8a0..7641308761 100644
> --- a/res/res_pjsip_logger.c
> +++ b/res/res_pjsip_logger.c
> @@ -309,16 +309,17 @@ static pj_bool_t logging_on_rx_msg(pjsip_rx_data *rdata)
> ao2_unlock(default_logger);
> if (default_logger->log_to_verbose) {
> - ast_verbose("<--- Received SIP %s (%d bytes) from %s:%s --->\n%s\n",
> + ast_verbose("<--- Received SIP %s (%d bytes) from %s:%s --->\n%.*s\n",
> rdata->msg_info.msg->type == PJSIP_REQUEST_MSG ? "request" : "response",
> rdata->msg_info.len,
> rdata->tp_info.transport->type_name,
> pj_sockaddr_print(&rdata->pkt_info.src_addr, buffer, sizeof(buffer), 3),
> - rdata->pkt_info.packet);
> + rdata->msg_info.len,
> + rdata->msg_info.msg_buf);
> }
> if (default_logger->log_to_pcap) {
> - pjsip_logger_write_to_pcap(default_logger, rdata->pkt_info.packet, rdata->msg_info.len,
> + pjsip_logger_write_to_pcap(default_logger, rdata->msg_info.msg_buf, rdata->msg_info.len,
> &rdata->pkt_info.src_addr, NULL);
> }
> {noformat}
> This is the first time I've dug into Asterisk and PJSIP code, and the patch is untested, however, so I could be wrong. Either way, something is wrong with the log output.
> P.s.: I'd follow the guidelines and attach log output rather than pasting it in the description, but there's no place to do that while creating an issue.
--
This message was sent by Atlassian JIRA
(v6.2#6252)
More information about the asterisk-bugs
mailing list