Hi, I'm having some trouble matching an IFC with an incoming request into Sprout.
I have configured my IFC in HSS to match a RequestURI of sip:[email protected]. The requestURI is that value, but sprout is not matching it. In the attached log, Line 206 is the problem: 31-05-2016 19:49:42.589 UTC Debug ifchandler.cpp:437: SPT class RequestURI: result false I tried lots of values like: INVITE sip:[email protected] SIP/2.0 sip:[email protected] SIP/2.0 sip:[email protected] [email protected] but I couldn't find the actual value. If I try the same test with the To Header instead of RequestURI, then it matches sip:[email protected] fine. I tried some regexp matching for RequestURI and found that .*example.com matches, but sip.* doesn't match. Some more logging would be handy where Sprout prints the two strings it is comparing. What value does sprout think the RequestURI is in this case if it's not sip:[email protected]? thanks Steve
31-05-2016 19:49:42.585 UTC Debug pjsip: tdta0x7f8b244d Destroying txdata Response msg 100/INVITE/cseq=20 (tdta0x7f8b244d3080) 31-05-2016 19:49:42.585 UTC Verbose sproutletproxy.cpp:1967: Routing Request msg INVITE/cseq=20 (tdta0x7f8b244d0110) (1510 bytes) to downstream sproutlet scscf: --start msg-- INVITE sip:[email protected] SIP/2.0 Via: SIP/2.0/TCP 172.31.33.66:5054;received=172.31.33.66;branch=z9hG4bK+e51ca97d9f2c29d2fb8a2ad2b510be021+sip+4+a64dea2b From: <sip:[email protected]>;tag=172.31.33.66+4+b5b842d2+1bc398ca To: <sip:[email protected]> CSeq: 20 INVITE Expires: 180 P-Charging-Function-Addresses: ccf=pri_ccf_address Supported: outbound P-Charging-Vector: icid-value="ccc48f06fe609d26c2553d7887b1627f" Contact: <sip:[email protected]:34501>;+sip.instance="<urn:uuid:5fb1f16f-2479-4c0d-a5e9-91b8befc74ec>" Record-Route: <sip:172.31.33.66:5054;lr> P-Served-User: <sip:[email protected]> P-Asserted-Identity: <sip:[email protected]> Call-ID: [email protected] Max-Forwards: 68 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE User-Agent: Linphone/3.9.1 (belle-sip/1.4.2) P-Visited-Network-ID: example.com Route: <sip:ec2-52-3-140-139.compute-1.amazonaws.com:5054;transport=TCP;lr;orig> Content-Type: application/sdp Content-Length: 430 v=0 o=+6505550337 2658 2249 IN IP4 174.113.205.88 s=Talk c=IN IP4 174.113.205.88 b=AS:512 t=0 0 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 17078 RTP/AVPF 0 8 9 3 101 a=rtpmap:101 telephone-event/8000 a=rtcp-fb:* trr-int 5000 m=video 19078 RTP/AVPF 96 a=rtpmap:96 H264/90000 a=fmtp:96 profile-level-id=42800D a=rtcp-fb:* trr-int 5000 a=rtcp-fb:96 nack pli a=rtcp-fb:96 ccm fir --end msg-- 31-05-2016 19:49:42.585 UTC Debug pjutils.cpp:691: Cloned tdta0x7f8b244d0110 to tdta0x7f8b244d3080 31-05-2016 19:49:42.585 UTC Debug sproutletproxy.cpp:1123: Remove top Route header Route: <sip:ec2-52-3-140-139.compute-1.amazonaws.com:5054;transport=TCP;lr;orig> 31-05-2016 19:49:42.585 UTC Debug sproutletproxy.cpp:1640: Adding message 0x7f8b244d3690 => txdata 0x7f8b244d3128 mapping 31-05-2016 19:49:42.585 UTC Verbose sproutletproxy.cpp:1492: scscf-0x7f8b24443a60 pass initial request Request msg INVITE/cseq=20 (tdta0x7f8b244d3080) to Sproutlet 31-05-2016 19:49:42.585 UTC Info scscfsproutlet.cpp:381: S-CSCF received initial request 31-05-2016 19:49:42.585 UTC Debug session_expires_helper.cpp:124: Set session expires to 600 31-05-2016 19:49:42.585 UTC Debug uri_classifier.cpp:167: home domain: false, local_to_node: true, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 31-05-2016 19:49:42.585 UTC Debug uri_classifier.cpp:197: Classified URI as 3 31-05-2016 19:49:42.585 UTC Debug scscfsproutlet.cpp:677: Route header references this system 31-05-2016 19:49:42.585 UTC Debug scscfsproutlet.cpp:723: No ODI token, or invalid ODI token, on request - logging ICID marker ccc48f06fe609d26c2553d7887b1627f for B2BUA AS correlation 31-05-2016 19:49:42.585 UTC Debug scscfsproutlet.cpp:736: Got our Route header, session case orig, OD=None 31-05-2016 19:49:42.585 UTC Debug pjutils.cpp:291: Served user from P-Served-User header 31-05-2016 19:49:42.585 UTC Debug uri_classifier.cpp:167: home domain: true, local_to_node: false, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 31-05-2016 19:49:42.585 UTC Debug uri_classifier.cpp:197: Classified URI as 4 31-05-2016 19:49:42.585 UTC Debug acr.cpp:49: Created ACR (0x7f8b240b94f0) 31-05-2016 19:49:42.585 UTC Debug scscfsproutlet.cpp:919: Single Record-Route - initiation of originating handling 31-05-2016 19:49:42.585 UTC Debug sproutletproxy.cpp:325: Creating URI for scscf 31-05-2016 19:49:42.586 UTC Debug sproutletproxy.cpp:329: Add services parameter 31-05-2016 19:49:42.586 UTC Debug sproutletproxy.cpp:337: sip:ec2-52-3-140-139.compute-1.amazonaws.com:5054;transport=TCP;lr;service=scscf 31-05-2016 19:49:42.586 UTC Debug scscfsproutlet.cpp:925: Looking up iFCs for sip:[email protected] for new AS chain 31-05-2016 19:49:42.586 UTC Debug hssconnection.cpp:585: Making Homestead request for /impu/sip%3A%2B6505550337%40example.com/reg-data 31-05-2016 19:49:42.586 UTC Debug httpresolver.cpp:71: HttpResolver::resolve for host ec2-52-3-140-139.compute-1.amazonaws.com, port 8888, family 2 31-05-2016 19:49:42.586 UTC Debug baseresolver.cpp:505: Attempt to parse ec2-52-3-140-139.compute-1.amazonaws.com as IP address 31-05-2016 19:49:42.586 UTC Verbose dnscachedresolver.cpp:237: Check cache for ec2-52-3-140-139.compute-1.amazonaws.com type 1 31-05-2016 19:49:42.586 UTC Debug dnscachedresolver.cpp:323: Pulling 1 records from cache for ec2-52-3-140-139.compute-1.amazonaws.com A 31-05-2016 19:49:42.586 UTC Debug baseresolver.cpp:353: Found 1 A/AAAA records, randomizing 31-05-2016 19:49:42.586 UTC Debug baseresolver.cpp:495: 172.31.45.86:8888 transport 6 is not blacklisted 31-05-2016 19:49:42.586 UTC Debug baseresolver.cpp:374: Added a server, now have 1 of 5 31-05-2016 19:49:42.586 UTC Debug baseresolver.cpp:412: Adding 0 servers from blacklist 31-05-2016 19:49:42.586 UTC Debug baseresolver.cpp:505: Attempt to parse 172.31.45.86 as IP address 31-05-2016 19:49:42.586 UTC Debug httpconnection.cpp:623: Sending HTTP request : http://ec2-52-3-140-139.compute-1.amazonaws.com:8888/impu/sip%3A%2B6505550337%40example.com/reg-data (trying 172.31.45.86) ==> homestead/homestead_20160531T190000Z.txt <== 31-05-2016 19:49:42.586 UTC Verbose httpstack.cpp:286: Process request for URL /impu/sip%3A%2B6505550337%40example.com/reg-data, args (null) 31-05-2016 19:49:42.586 UTC Debug handlers.cpp:984: Parsed HTTP request: private ID , public ID sip:[email protected] 31-05-2016 19:49:42.586 UTC Debug handlers.cpp:928: Determining request type from '{"reqtype": "call"}' 31-05-2016 19:49:42.586 UTC Debug handlers.cpp:972: New value of _type is 2 31-05-2016 19:49:42.586 UTC Debug handlers.cpp:1022: Try to find IMS Subscription information in the cache 31-05-2016 19:49:42.586 UTC Debug cassandra_store.cpp:284: Getting thread-local Client 31-05-2016 19:49:42.586 UTC Debug cassandra_store.cpp:129: Generated Cassandra timestamp 1464724182586566 31-05-2016 19:49:42.586 UTC Debug cache.cpp:350: Issuing get for key sip:[email protected] 31-05-2016 19:49:42.587 UTC Debug cassandra_store.cpp:745: Failed TWO read for get_row. Try ONE 31-05-2016 19:49:42.588 UTC Debug cache.cpp:370: Retrieved XML column with TTL 7192 and value <?xml version="1.0" encoding="UTF-8"?><IMSSubscription><PrivateID>[email protected]</PrivateID><ServiceProfile><PublicIdentity><Identity>sip:[email protected]</Identity><Extension><IdentityType>0</IdentityType></Extension></PublicIdentity><InitialFilterCriteria><Priority>1</Priority><TriggerPoint><ConditionTypeCNF>1</ConditionTypeCNF><SPT><ConditionNegated>0</ConditionNegated><Group>0</Group><Method>REGISTER</Method><Extension><RegistrationType>0</RegistrationType></Extension></SPT><SPT><ConditionNegated>0</ConditionNegated><Group>0</Group><Method>REGISTER</Method><Extension><RegistrationType>1</RegistrationType></Extension></SPT><SPT><ConditionNegated>0</ConditionNegated><Group>0</Group><Method>REGISTER</Method><Extension><RegistrationType>2</RegistrationType></Extension></SPT></TriggerPoint><ApplicationServer><ServerName>sip:ip-172-31-37-138.ec2.internal:5060;transport=tcp;oc-charge-mode=offline;oc-mode=mmtel</ServerName><DefaultHandling>0</DefaultHandling><Extension><IncludeRegisterRequest/><IncludeRegisterResponse/></Extension></ApplicationServer></InitialFilterCriteria><InitialFilterCriteria><Priority>2</Priority><TriggerPoint><ConditionTypeCNF>1</ConditionTypeCNF><SPT><ConditionNegated>0</ConditionNegated><Group>0</Group><Method>INVITE</Method><Extension></Extension></SPT><SPT><ConditionNegated>0</ConditionNegated><Group>2</Group><RequestURI>sip:[email protected]</RequestURI><Extension></Extension></SPT></TriggerPoint><ApplicationServer><ServerName>sip:ip-172-31-37-138.ec2.internal:5062;transport=tcp</ServerName><DefaultHandling>0</DefaultHandling><Extension><IncludeRegisterRequest/><IncludeRegisterResponse/></Extension></ApplicationServer></InitialFilterCriteria></ServiceProfile></IMSSubscription> 31-05-2016 19:49:42.588 UTC Debug cache.cpp:382: Retrieved is_registered column with value True and TTL 7192 31-05-2016 19:49:42.588 UTC Debug cache.cpp:411: Retrived primary_ccf column with value pri_ccf_address 31-05-2016 19:49:42.588 UTC Debug handlers.cpp:1051: Got IMS subscription from cache 31-05-2016 19:49:42.588 UTC Debug handlers.cpp:1067: TTL for this database record is 7192, IMS Subscription XML is not empty, registration state is REGISTERED, and the charging addresses are Primary CCF: pri_ccf_address 31-05-2016 19:49:42.588 UTC Debug handlers.cpp:1171: Handling call 31-05-2016 19:49:42.589 UTC Debug handlers.cpp:1352: Sending 200 response (body was {"reqtype": "call"}) 31-05-2016 19:49:42.589 UTC Verbose httpstack.cpp:69: Sending response 200 to request for URL /impu/sip%3A%2B6505550337%40example.com/reg-data, args (null) ==> homestead/access_20160531T190000Z.txt <== 31-05-2016 19:49:42.589 UTC 200 PUT /impu/sip%3A%2B6505550337%40example.com/reg-data 0.002684 seconds ==> sprout/sprout_20160531T190000Z.txt <== 31-05-2016 19:49:42.589 UTC Debug httpconnection.cpp:924: Received header http/1.1200ok with value 31-05-2016 19:49:42.589 UTC Debug httpconnection.cpp:924: Received header content-length with value 2303 31-05-2016 19:49:42.589 UTC Debug httpconnection.cpp:924: Received header content-type with value text/plain 31-05-2016 19:49:42.589 UTC Debug httpconnection.cpp:924: Received header with value 31-05-2016 19:49:42.589 UTC Debug httpconnection.cpp:638: Received HTTP response: status=200, doc=<ClearwaterRegData> <RegistrationState>REGISTERED</RegistrationState> <IMSSubscription> <PrivateID>[email protected]</PrivateID> <ServiceProfile> <PublicIdentity> <Identity>sip:[email protected]</Identity> <Extension> <IdentityType>0</IdentityType> </Extension> </PublicIdentity> <InitialFilterCriteria> <Priority>1</Priority> <TriggerPoint> <ConditionTypeCNF>1</ConditionTypeCNF> <SPT> <ConditionNegated>0</ConditionNegated> <Group>0</Group> <Method>REGISTER</Method> <Extension> <RegistrationType>0</RegistrationType> </Extension> </SPT> <SPT> <ConditionNegated>0</ConditionNegated> <Group>0</Group> <Method>REGISTER</Method> <Extension> <RegistrationType>1</RegistrationType> </Extension> </SPT> <SPT> <ConditionNegated>0</ConditionNegated> <Group>0</Group> <Method>REGISTER</Method> <Extension> <RegistrationType>2</RegistrationType> </Extension> </SPT> </TriggerPoint> <ApplicationServer> <ServerName>sip:ip-172-31-37-138.ec2.internal:5060;transport=tcp;oc-charge-mode=offline;oc-mode=mmtel</ServerName> <DefaultHandling>0</DefaultHandling> <Extension> <IncludeRegisterRequest/> <IncludeRegisterResponse/> </Extension> </ApplicationServer> </InitialFilterCriteria> <InitialFilterCriteria> <Priority>2</Priority> <TriggerPoint> <ConditionTypeCNF>1</ConditionTypeCNF> <SPT> <ConditionNegated>0</ConditionNegated> <Group>0</Group> <Method>INVITE</Method> <Extension/> </SPT> <SPT> <ConditionNegated>0</ConditionNegated> <Group>2</Group> <RequestURI>sip:[email protected]</RequestURI> <Extension/> </SPT> </TriggerPoint> <ApplicationServer> <ServerName>sip:ip-172-31-37-138.ec2.internal:5062;transport=tcp</ServerName> <DefaultHandling>0</DefaultHandling> <Extension> <IncludeRegisterRequest/> <IncludeRegisterResponse/> </Extension> </ApplicationServer> </InitialFilterCriteria> </ServiceProfile> </IMSSubscription> <ChargingAddresses> <CCF priority="1">pri_ccf_address</CCF> </ChargingAddresses> </ClearwaterRegData> 31-05-2016 19:49:42.589 UTC Debug hssconnection.cpp:366: Processing Identity node from HSS XML - sip:[email protected] 31-05-2016 19:49:42.589 UTC Debug hssconnection.cpp:427: Found CCF: pri_ccf_address 31-05-2016 19:49:42.589 UTC Debug scscfsproutlet.cpp:930: Successfully looked up iFCs 31-05-2016 19:49:42.589 UTC Debug aschain.cpp:71: Creating AsChain 0x7f8b24259b20 with 2 IFC and adding to map 31-05-2016 19:49:42.589 UTC Debug aschain.cpp:73: Attached ACR (0x7f8b240b94f0) to chain 31-05-2016 19:49:42.589 UTC Debug scscfsproutlet.cpp:1049: S-CSCF sproutlet transaction 0x7f8b24443a60 linked to AsChain AsChain-orig[0x7f8b24259b20]:1/2 31-05-2016 19:49:42.589 UTC Info scscfsproutlet.cpp:449: Found served user, so apply services 31-05-2016 19:49:42.589 UTC Debug scscfsproutlet.cpp:1057: Performing originating initiating request processing 31-05-2016 19:49:42.589 UTC Debug ifchandler.cpp:437: SPT class Method: result false 31-05-2016 19:49:42.589 UTC Debug ifchandler.cpp:541: Add to group 0 val false 31-05-2016 19:49:42.589 UTC Debug ifchandler.cpp:437: SPT class Method: result false 31-05-2016 19:49:42.589 UTC Debug ifchandler.cpp:541: Add to group 0 val false 31-05-2016 19:49:42.589 UTC Debug ifchandler.cpp:437: SPT class Method: result false 31-05-2016 19:49:42.589 UTC Debug ifchandler.cpp:541: Add to group 0 val false 31-05-2016 19:49:42.589 UTC Debug ifchandler.cpp:559: Result group 0 val false 31-05-2016 19:49:42.589 UTC Debug ifchandler.cpp:572: iFC does not match 31-05-2016 19:49:42.589 UTC Debug ifchandler.cpp:437: SPT class Method: result true 31-05-2016 19:49:42.589 UTC Debug ifchandler.cpp:541: Add to group 0 val true 31-05-2016 19:49:42.589 UTC Debug ifchandler.cpp:437: SPT class RequestURI: result false 31-05-2016 19:49:42.589 UTC Debug ifchandler.cpp:541: Add to group 2 val false 31-05-2016 19:49:42.589 UTC Debug ifchandler.cpp:559: Result group 0 val true 31-05-2016 19:49:42.589 UTC Debug ifchandler.cpp:559: Result group 2 val false 31-05-2016 19:49:42.589 UTC Debug ifchandler.cpp:572: iFC does not match 31-05-2016 19:49:42.589 UTC Info scscfsproutlet.cpp:1082: Completed applying originating services 31-05-2016 19:49:42.589 UTC Debug uri_classifier.cpp:167: home domain: true, local_to_node: false, is_gruu: false, enforce_user_phone: false, prefer_sip: false, treat_number_as_phone: true 31-05-2016 19:49:42.589 UTC Debug uri_classifier.cpp:197: Classified URI as 2 31-05-2016 19:49:42.589 UTC Debug pjutils.cpp:2229: Translating URI 31-05-2016 19:49:42.589 UTC Debug pjutils.cpp:2191: No ENUM server configured, perform default translation 31-05-2016 19:49:42.589 UTC Debug pjutils.cpp:2206: Translate SIP URI sip:[email protected] to itself 31-05-2016 19:49:42.589 UTC Debug uri_classifier.cpp:167: home domain: true, local_to_node: false, is_gruu: false, enforce_user_phone: false, prefer_sip: false, treat_number_as_phone: true 31-05-2016 19:49:42.589 UTC Debug uri_classifier.cpp:197: Classified URI as 2 31-05-2016 19:49:42.589 UTC Debug pjutils.cpp:2278: Translated URI sip:[email protected] is not a SIP URI - replacing Request-URI anyway 31-05-2016 19:49:42.589 UTC Debug uri_classifier.cpp:167: home domain: true, local_to_node: false, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 31-05-2016 19:49:42.589 UTC Debug uri_classifier.cpp:197: Classified URI as 4 31-05-2016 19:49:42.589 UTC Info scscfsproutlet.cpp:1096: New URI string is sip:[email protected] 31-05-2016 19:49:42.589 UTC Info scscfsproutlet.cpp:1293: Routing to I-CSCF sip:ec2-52-3-140-139.compute-1.amazonaws.com:5052;transport=TCP 31-05-2016 19:49:42.589 UTC Debug sproutletproxy.cpp:1258: Sproutlet send_request 0x7f8b244d3690 31-05-2016 19:49:42.589 UTC Verbose sproutletproxy.cpp:1294: scscf-0x7f8b24443a60 sending Request msg INVITE/cseq=20 (tdta0x7f8b244d3080) on fork 0 31-05-2016 19:49:42.589 UTC Debug sproutletproxy.cpp:1655: Processing actions from sproutlet - 0 responses, 1 requests, 0 timers 31-05-2016 19:49:42.589 UTC Debug sproutletproxy.cpp:1695: Processing request 0x7f8b244d3128, fork = 0 31-05-2016 19:49:42.589 UTC Debug sproutletproxy.cpp:1819: scscf-0x7f8b24443a60 transmitting request on fork 0 31-05-2016 19:49:42.589 UTC Debug sproutletproxy.cpp:1833: scscf-0x7f8b24443a60 store reference to non-ACK request Request msg INVITE/cseq=20 (tdta0x7f8b244d3080) on fork 0 31-05-2016 19:49:42.589 UTC Debug sproutletproxy.cpp:1647: Removing message 0x7f8b244d3690 => txdata 0x7f8b244d3128 mapping 31-05-2016 19:49:42.589 UTC Debug sproutletproxy.cpp:102: Find target Sproutlet for request 31-05-2016 19:49:42.589 UTC Debug sproutletproxy.cpp:136: Found next routable URI: sip:ec2-52-3-140-139.compute-1.amazonaws.com:5052;transport=TCP;lr 31-05-2016 19:49:42.589 UTC Debug sproutletproxy.cpp:175: No Sproutlet found using service name or host 31-05-2016 19:49:42.589 UTC Debug sproutletproxy.cpp:180: Find default service for port 5052 31-05-2016 19:49:42.589 UTC Verbose sproutletproxy.cpp:1062: Created Sproutlet icscf-0x7f8b24447330 for Request msg INVITE/cseq=20 (tdta0x7f8b244d3080) 31-05-2016 19:49:42.589 UTC Info pjutils.cpp:1601: Cloning header! 140235586224928 31-05-2016 19:49:42.589 UTC Info pjutils.cpp:1601: Cloning header! 140235586223672
_______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/mailman/listinfo/clearwater_lists.projectclearwater.org
