Hi Mark, While awaiting moderation of my message with the attached logs, I have pulled out the relevant part of the Sprout log, showing the creation of the INVITE message to Bono (192.168.8.108) on the untrusted 5060 port.
-----8<---- --start msg-- INVITE sip:6505550637@192.168.8.106 SIP/2.0 Record-Route: <sip:scscf.sprout.oam.eeint.co.uk;transport=TCP;lr;billing-role=charge-orig> Record-Route: <sip:192.168.8.106:5058;transport=TCP;lr> Record-Route: <sip:6XitsiyizX@Bono:5060;transport=UDP;lr> Via: SIP/2.0/TCP scscf.sprout.oam.eeint.co.uk;branch=z9hG4bKPjDOqb2VgR3yLNf4Zz9R.RwOgAu6lVkGe1 Via: SIP/2.0/TCP mmtel.sprout.oam.eeint.co.uk;branch=z9hG4bKPjsPEoMDQOUAlOd3eCNRPplYTORl-OGumY Via: SIP/2.0/TCP scscf.sprout.oam.eeint.co.uk;branch=z9hG4bKPjJldrraM6mxRuZf2H7WOjAKKug-6cuY9S Via: SIP/2.0/TCP 192.168.8.106:5058;rport=58455;received=192.168.8.106;branch=z9hG4bKPjE8IDlwRqcANKZfWqmYq-q.XQrTArbCut Via: SIP/2.0/UDP 192.168.9.10;received=192.168.9.10;branch=z9hG4bK011B678b6fac1e From: <sip:6505550...@oam.eeint.co.uk>;tag=3C8463B1 To: <sip:6505550637@192.168.8.106> Call-ID: 2d990fa160b656171@192.168.9.10 CSeq: 3 INVITE Contact: <sip:6505550164@192.168.9.10> User-Agent: IxLoad-IMS-UA-0 P-Access-Network-Info: 3GPP-UTRAN-TDD;utran-cell-id-3gpp=12345ABCDE0 Max-Forwards: 66 Require: 100rel Supported: 100rel, replaces, timer, join Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, SUBSCRIBE, REFER, NOTIFY, PRACK, UPDATE, MESSAGE, INFO Allow-Events: refer P-Asserted-Identity: <sip:6505550...@oam.eeint.co.uk> Session-Expires: 600 P-Served-User: <sip:6505550...@oam.eeint.co.uk>;sescase=orig;regstate=reg Route: <sip:bgcf.sprout.oam.eeint.co.uk;transport=TCP;lr> Content-Type: application/sdp Content-Length: 290 v=0 o=- 0 0 IN IP4 192.168.9.10 s=session c=IN IP4 192.168.9.10 t=0 0 m=audio 10000 RTP/AVP 0 8 18 100 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:100 telephone-event/8000 a=fmtp:100 0-16 a=rtpmap:101 tones/8000 a=ptime:20 --end msg-- 16-01-2019 14:14:38.483 UTC [7f72c9f63700] Debug pjutils.cpp:744: Cloned tdta0x3725fa0 to tdta0x3729ec0 16-01-2019 14:14:38.483 UTC [7f72c9f63700] Debug sproutletproxy.cpp:1783: Remove top Route header Route: <sip:bgcf.sprout.oam.eeint.co.uk;transport=TCP;lr> 16-01-2019 14:14:38.483 UTC [7f72c9f63700] Debug sproutletproxy.cpp:2453: Adding message 0x372a4d0 => txdata 0x3729f68 mapping 16-01-2019 14:14:38.483 UTC [7f72c9f63700] Verbose sproutletproxy.cpp:2284: bgcf-0x36600d0 pass initial request Request msg INVITE/cseq=3 (tdta0x3729ec0) to Sproutlet 16-01-2019 14:14:38.483 UTC [7f72c9f63700] Debug acr.cpp:1797: Create RalfACR for node type BGCF with role Terminating 16-01-2019 14:14:38.483 UTC [7f72c9f63700] Debug acr.cpp:24: Created ACR (0x3652120) 16-01-2019 14:14:38.483 UTC [7f72c9f63700] Debug acr.cpp:170: Created BGCF Ralf ACR 16-01-2019 14:14:38.483 UTC [7f72c9f63700] Debug acr.cpp:250: Set record type for I-CSCF, BGCF, IBCF, AS to EVENT_RECORD 16-01-2019 14:14:38.483 UTC [7f72c9f63700] Debug uri_classifier.cpp:139: home domain: false, local_to_node: false, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 16-01-2019 14:14:38.483 UTC [7f72c9f63700] Debug uri_classifier.cpp:173: Classified URI sip:6505550637@192.168.8.106 as 5 16-01-2019 14:14:38.483 UTC [7f72c9f63700] Debug pjutils.cpp:2657: Not translating URI 16-01-2019 14:14:38.483 UTC [7f72c9f63700] Debug uri_classifier.cpp:139: home domain: false, local_to_node: false, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 16-01-2019 14:14:38.483 UTC [7f72c9f63700] Debug uri_classifier.cpp:173: Classified URI sip:6505550637@192.168.8.106 as 5 16-01-2019 14:14:38.483 UTC [7f72c9f63700] Debug bgcfservice.cpp:163: Getting route for URI domain 192.168.8.106 via BGCF lookup 16-01-2019 14:14:38.483 UTC [7f72c9f63700] Debug bgcfsproutlet.cpp:205: No route configured for 192.168.8.106 16-01-2019 14:14:38.483 UTC [7f72c9f63700] Debug sproutletproxy.cpp:1954: Sproutlet send_request 0x372a4d0 16-01-2019 14:14:38.483 UTC [7f72c9f63700] Verbose sproutletproxy.cpp:1995: bgcf-0x36600d0 sending Request msg INVITE/cseq=3 (tdta0x3729ec0) on fork 0 16-01-2019 14:14:38.483 UTC [7f72c9f63700] Debug sproutletproxy.cpp:2468: Processing actions from sproutlet - 0 responses, 1 requests, 0 timers 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug sproutletproxy.cpp:2508: Processing request 0x3729f68, fork = 0 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug sproutletproxy.cpp:2672: bgcf-0x36600d0 transmitting request on fork 0 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug sproutletproxy.cpp:2687: bgcf-0x36600d0 store reference to non-ACK request Request msg INVITE/cseq=3 (tdta0x3729ec0) on fork 0 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug sproutletproxy.cpp:2460: Removing message 0x372a4d0 => txdata 0x3729f68 mapping 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug sproutletproxy.cpp:185: Find target Sproutlet for request 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug sproutletproxy.cpp:220: Found next routable URI: sip:6505550637@192.168.8.106 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug sproutletproxy.cpp:381: Possible service name 192 will be used if 168.8.106 is a local hostname 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug sproutletproxy.cpp:405: Found user part - 6505550637 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug sproutletproxy.cpp:1189: No local sproutlet matches request 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug pjsip: tsx0x372ced8 Transaction created for Request msg INVITE/cseq=3 (tdta0x3729ec0) 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug basicproxy.cpp:1676: Added trail identifier 52004 to UAC transaction 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug pjutils.cpp:518: Next hop node is encoded in Request-URI 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug sipresolver.cpp:84: SIPResolver::resolve for name 192.168.8.106, port 0, transport -1, family 2 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug utils.cpp:446: Attempt to parse 192.168.8.106 as IP address 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug sipresolver.cpp:101: Target is an IP address - default port/transport if required 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug baseresolver.cpp:587: 192.168.8.106:5060;transport=UDP has state: WHITE 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug baseresolver.cpp:648: Address 192.168.8.106:5060 is in state WHITE and is allowed to be used based on an allowed host state bitfield of 0x3 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Info pjutils.cpp:1001: Resolved destination URI sip:6505550637@192.168.8.106 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug pjutils.cpp:518: Next hop node is encoded in Request-URI 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug basicproxy.cpp:1700: Next hop 192.168.8.106 is not a stateless proxy 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug basicproxy.cpp:1714: Sending request for sip:6505550637@192.168.8.106 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug basicproxy.cpp:2399: Selected host 192.168.8.106:5060;transport=UDP (will be blacklisted by default) 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug pjsip: tsx0x372ced8 Sending Request msg INVITE/cseq=3 (tdta0x3729ec0) in state Null 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug pjsip: endpoint Request msg INVITE/cseq=3 (tdta0x3729ec0): skipping target resolution because address is already set 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug pjsip: endpoint Request msg INVITE/cseq=3 (tdta0x3729ec0) exceeds UDP size threshold (1300), sending with TCP 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Verbose pjsip: tcpc0x372f5b8 tcp->base.local_name: 192.168.8.102 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Verbose pjsip: tcpc0x372f5b8 TCP client transport created 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Verbose pjsip: tcpc0x372f5b8 TCP transport 192.168.8.102:5052 is connecting to 192.168.8.106:5060... 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Verbose common_sip_processing.cpp:103: TX 1815 bytes Request msg INVITE/cseq=3 (tdta0x3729ec0) to TCP 192.168.8.106:5060: --start msg-- INVITE sip:6505550637@192.168.8.106 SIP/2.0 Record-Route: <sip:scscf.sprout.oam.eeint.co.uk;transport=TCP;lr;billing-role=charge-orig> Record-Route: <sip:192.168.8.106:5058;transport=TCP;lr> Record-Route: <sip:6XitsiyizX@Bono:5060;transport=UDP;lr> Via: SIP/2.0/TCP 192.168.8.102:5052;rport;branch=z9hG4bKPjxZg6vBPzxGnvZauLAk4t56Q7jwqup-FJ Via: SIP/2.0/TCP scscf.sprout.oam.eeint.co.uk;branch=z9hG4bKPjDOqb2VgR3yLNf4Zz9R.RwOgAu6lVkGe1 Via: SIP/2.0/TCP mmtel.sprout.oam.eeint.co.uk;branch=z9hG4bKPjsPEoMDQOUAlOd3eCNRPplYTORl-OGumY Via: SIP/2.0/TCP scscf.sprout.oam.eeint.co.uk;branch=z9hG4bKPjJldrraM6mxRuZf2H7WOjAKKug-6cuY9S Via: SIP/2.0/TCP 192.168.8.106:5058;rport=58455;received=192.168.8.106;branch=z9hG4bKPjE8IDlwRqcANKZfWqmYq-q.XQrTArbCut Via: SIP/2.0/UDP 192.168.9.10;received=192.168.9.10;branch=z9hG4bK011B678b6fac1e From: <sip:6505550...@oam.eeint.co.uk>;tag=3C8463B1 To: <sip:6505550637@192.168.8.106> Call-ID: 2d990fa160b656171@192.168.9.10 CSeq: 3 INVITE Contact: <sip:6505550164@192.168.9.10> User-Agent: IxLoad-IMS-UA-0 P-Access-Network-Info: 3GPP-UTRAN-TDD;utran-cell-id-3gpp=12345ABCDE0 Max-Forwards: 66 Require: 100rel Supported: 100rel, replaces, timer, join Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, SUBSCRIBE, REFER, NOTIFY, PRACK, UPDATE, MESSAGE, INFO Allow-Events: refer P-Asserted-Identity: <sip:6505550...@oam.eeint.co.uk> Session-Expires: 600 P-Served-User: <sip:6505550...@oam.eeint.co.uk>;sescase=orig;regstate=reg Content-Type: application/sdp Content-Length: 290 v=0 o=- 0 0 IN IP4 192.168.9.10 s=session c=IN IP4 192.168.9.10 t=0 0 m=audio 10000 RTP/AVP 0 8 18 100 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:100 telephone-event/8000 a=fmtp:100 0-16 a=rtpmap:101 tones/8000 a=ptime:20 --end msg-- 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug pjsip: tsx0x372ced8 State changed from Null to Calling, event=TX_MSG 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug basicproxy.cpp:190: tsx0x372ced8 - tu_on_tsx_state UAC, TSX_STATE TX_MSG state=Calling 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug basicproxy.cpp:1949: tsx0x372ced8 - uac_tsx = 0x365f1b0, uas_tsx = 0x365d350 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug basicproxy.cpp:1957: TX_MSG event on current UAC transaction 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug basicproxy.cpp:2288: Starting timer C 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug thread_dispatcher.cpp:273: Worker thread completed processing message 0x7f729807aba8 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug thread_dispatcher.cpp:287: Request latency = 3783us 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug event_statistic_accumulator.cpp:32: Accumulate 3783 for 0x2613348 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug event_statistic_accumulator.cpp:32: Accumulate 3783 for 0x26133c0 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug load_monitor.cpp:341: Not recalculating rate as we haven't processed 20 requests yet (only 9). 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug utils.cpp:878: Removed IOHook 0x7f72c9f62df0 to stack. There are now 0 hooks 16-01-2019 14:14:38.484 UTC [7f72c9f63700] Debug thread_dispatcher.cpp:161: Attempting to process queue element 16-01-2019 14:14:38.494 UTC [7f729d70a700] Verbose pjsip: tcpc0x372f5b8 TCP transport 192.168.8.102:5052 is connected to 192.168.8.106:5060 16-01-2019 14:14:38.494 UTC [7f729d70a700] Debug pjsip: sip_endpoint.c Processing incoming message: Response msg 403/INVITE/cseq=3 (rdata0x372f8f0) 16-01-2019 14:14:38.494 UTC [7f729d70a700] Verbose common_sip_processing.cpp:87: RX 1057 bytes Response msg 403/INVITE/cseq=3 (rdata0x372f8f0) from TCP 192.168.8.106:5060: --start msg-- SIP/2.0 403 Forbidden Via: SIP/2.0/TCP 192.168.8.102:5052;rport=38340;received=192.168.8.102;branch=z9hG4bKPjxZg6vBPzxGnvZauLAk4t56Q7jwqup-FJ Via: SIP/2.0/TCP scscf.sprout.oam.eeint.co.uk;branch=z9hG4bKPjDOqb2VgR3yLNf4Zz9R.RwOgAu6lVkGe1 Via: SIP/2.0/TCP mmtel.sprout.oam.eeint.co.uk;branch=z9hG4bKPjsPEoMDQOUAlOd3eCNRPplYTORl-OGumY Via: SIP/2.0/TCP scscf.sprout.oam.eeint.co.uk;branch=z9hG4bKPjJldrraM6mxRuZf2H7WOjAKKug-6cuY9S Via: SIP/2.0/TCP 192.168.8.106:5058;rport=58455;received=192.168.8.106;branch=z9hG4bKPjE8IDlwRqcANKZfWqmYq-q.XQrTArbCut Via: SIP/2.0/UDP 192.168.9.10;received=192.168.9.10;branch=z9hG4bK011B678b6fac1e Record-Route: <sip:scscf.sprout.oam.eeint.co.uk;transport=TCP;lr;billing-role=charge-orig> Record-Route: <sip:192.168.8.106:5058;transport=TCP;lr> Record-Route: <sip:6XitsiyizX@Bono:5060;transport=UDP;lr> Call-ID: 2d990fa160b656171@192.168.9.10 From: <sip:6505550...@oam.eeint.co.uk>;tag=3C8463B1 To: <sip:6505550637@192.168.8.106>;tag=z9hG4bKPjxZg6vBPzxGnvZauLAk4t56Q7jwqup-FJ CSeq: 3 INVITE Content-Length: 0 --end msg-- Let me know if you need more. Regards, Brian. From: Brian Grant Sent: 17 January 2019 08:44 To: clearwater@lists.projectclearwater.org Cc: mark.perry...@metaswitch.com Subject: Re: [Project Clearwater] Bono responds to INVITE from SCSCF with 403 Forbidden Hi Mark, Thank you for your swift response and confirmation that Sprout should be communicating back to Bono on the trusted port 5058. Please find attached the corresponding Bono and Sprout logs for further debug. Regards, Brian. No, you shouldn't have to configure Sprout as a trusted peer. However, Sprout should be talking to bono over trusted port 5058, rather than 5060. It is not clear from those logs why this is not the case. Does the call work if you do not invoke the Application Server? Please send sprout logs as well. Mark Perryman -- Brian Grant Creantech Consulting T: +44 781 050 6475
_______________________________________________ Clearwater mailing list Clearwater@lists.projectclearwater.org http://lists.projectclearwater.org/mailman/listinfo/clearwater_lists.projectclearwater.org
