Right - I have made a change in sprout that updates the REGISTER Authorisation header so that the nc is incremented and a new hash is written into the response. The authentication is now successful. Unfortunately what happens is that once the registration is complete, the same REGISTER request is sent over and over and over to the scscf-proxy sproutlet until the hops limit is reached.
What exactly is supposed to happen here? According to the flow I have, once the registration on the SCSCF is successful it should send an SAR to the HSS, after which the SCSCF should return 200 OK to the ISCSCF, and so on back to the UE. I cannot see any sign the SAR request is taking place, though I can see the UAR query from the ISCSCF. Here is a section of log from sprout from the moment the REGISTER is first presented to the scscf-proxy sproutlet until the start of the first loop: 21-09-2017 15:53:32.239 UTC Debug scscfsproutlet.cpp:489: S-CSCF Transaction (0x7f474c010e50) created 21-09-2017 15:53:32.239 UTC Verbose sproutletproxy.cpp:1298: Created Sproutlet scscf-proxy-0x7f474c010e50 for Request msg REGISTER/cseq=2 (tdta0x7f474c01ce90) 21-09-2017 15:53:32.239 UTC Verbose sproutletproxy.cpp:2290: Routing Request msg REGISTER/cseq=2 (tdta0x7f474c01ce90) (1399 bytes) to downstream sproutlet scscf-proxy: --start msg— REGISTER sip:scscf.ims.rmcore.net SIP/2.0 Route: <sip:ims.rmcore.net;lr;service=scscf-proxy> Via: SIP/2.0/TCP 10.0.0.222:5058;rport=33214;received=10.0.0.222;branch=z9hG4bKPj1JagMaULIh8xrGTU49BsvwXp7aQVjv9S Path: <sip:[email protected]:5058;transport=TCP;lr;ob> Via: SIP/2.0/UDP 212.159.106.131:59124;rport=59124;received=212.159.106.131;branch=z9hG4bK-524287-1—07005d66d0f9415a Max-Forwards: 68 Contact: <sip:[email protected]:59124;rinstance=39865f51c2a988a3> To: "Jim@IMS" <sip:[email protected]> From: "Jim@IMS" <sip:[email protected]>;tag=e2a4b510 Call-ID: 85656NGM0NGZkNDM3YjVhZTNhZWY3OWNmYzQ1NDc4MjM3ZTQ CSeq: 2 REGISTER Expires: 3600 Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS User-Agent: Bria 4 release 4.8.2 stamp 85656 P-Visited-Network-ID: ims.rmcore.net<http://ims.rmcore.net> P-Charging-Function-Addresses: ccf=cdf.ims.rmcore.net<http://cdf.ims.rmcore.net> P-Charging-Vector: icid-value="85656NGM0NGZkNDM3YjVhZTNhZWY3OWNmYzQ1NDc4MjM3ZTQ";icid-generated-at=ec2-52-56-52-145.eu-west-2.compute.amazonaws.com<http://ec2-52-56-52-145.eu-west-2.compute.amazonaws.com> Authorization: Digest response="5a39ea19aeafcf955924b29a9a375451", username="[email protected]<mailto:[email protected]>", realm="ims.rmcore.net<http://ims.rmcore.net>", nonce="63bff4bb68c27b47", uri="sip:ims.rmcore.net", algorithm=MD5, cnonce="c549e7ca56a2867a6e23caf77a3c629a", opaque="5a5a8de45658f637", qop=auth, nc=00000002,integrity-protected=ip-assoc-pending Content-Length: 0 --end msg— 21-09-2017 15:53:32.239 UTC Debug pjutils.cpp:700: Cloned tdta0x7f474c01ce90 to tdta0x7f474c020150 21-09-2017 15:53:32.239 UTC Debug sproutletproxy.cpp:1364: Remove top Route header Route: <sip:ims.rmcore.net;lr;service=scscf-proxy> 21-09-2017 15:53:32.239 UTC Debug sproutletproxy.cpp:1961: Adding message 0x7f474c020760 => txdata 0x7f474c0201f8 mapping 21-09-2017 15:53:32.239 UTC Verbose sproutletproxy.cpp:1806: scscf-proxy-0x7f474c010e50 pass initial request Request msg REGISTER/cseq=2 (tdta0x7f474c020150) to Sproutlet 21-09-2017 15:53:32.239 UTC Info scscfsproutlet.cpp:536: S-CSCF received initial request 21-09-2017 15:53:32.239 UTC Debug uri_classifier.cpp:139: home domain: true, local_to_node: false, is_gruu: false, enforce_user_phone: false, prefer_sip: true, treat_number_as_phone: false 21-09-2017 15:53:32.239 UTC Debug uri_classifier.cpp:185: Classified URI as 4 21-09-2017 15:53:32.239 UTC Debug scscfsproutlet.cpp:993: Route header references this system 21-09-2017 15:53:32.239 UTC Debug scscfsproutlet.cpp:1039: No ODI token, or invalid ODI token, on request - logging ICID marker 85656NGM0NGZkNDM3YjVhZTNhZWY3OWNmYzQ1NDc4MjM3ZTQ for B2BUA AS correlation 21-09-2017 15:53:32.239 UTC Debug scscfsproutlet.cpp:1052: Got our Route header, session case term, OD=None 21-09-2017 15:53:32.239 UTC 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 21-09-2017 15:53:32.239 UTC Debug uri_classifier.cpp:185: Classified URI as 5 21-09-2017 15:53:32.239 UTC Debug scscfsproutlet.cpp:1396: URI is not locally hosted 21-09-2017 15:53:32.239 UTC Debug acr.cpp:1787: Create RalfACR for node type S-CSCF with role Terminating 21-09-2017 15:53:32.239 UTC Debug acr.cpp:24: Created ACR (0x7f474c022110) 21-09-2017 15:53:32.239 UTC Debug acr.cpp:164: Created S-CSCF Ralf ACR 21-09-2017 15:53:32.239 UTC Debug acr.cpp:29: Destroyed ACR (0x7f474c022110) 21-09-2017 15:53:32.239 UTC Info scscfsproutlet.cpp:714: Route request without applying services 21-09-2017 15:53:32.239 UTC Debug sproutletproxy.cpp:1535: Sproutlet send_request 0x7f474c020760 21-09-2017 15:53:32.239 UTC Verbose sproutletproxy.cpp:1576: scscf-proxy-0x7f474c010e50 sending Request msg REGISTER/cseq=2 (tdta0x7f474c020150) on fork 0 21-09-2017 15:53:32.239 UTC Debug sproutletproxy.cpp:1976: Processing actions from sproutlet - 0 responses, 1 requests, 0 timers 21-09-2017 15:53:32.239 UTC Debug sproutletproxy.cpp:2016: Processing request 0x7f474c0201f8, fork = 0 21-09-2017 15:53:32.239 UTC Debug sproutletproxy.cpp:2141: scscf-proxy-0x7f474c010e50 transmitting request on fork 0 21-09-2017 15:53:32.239 UTC Debug sproutletproxy.cpp:2156: scscf-proxy-0x7f474c010e50 store reference to non-ACK request Request msg REGISTER/cseq=2 (tdta0x7f474c020150) on fork 0 21-09-2017 15:53:32.239 UTC Debug sproutletproxy.cpp:1968: Removing message 0x7f474c020760 => txdata 0x7f474c0201f8 mapping 21-09-2017 15:53:32.239 UTC Debug sproutletproxy.cpp:163: Find target Sproutlet for request 21-09-2017 15:53:32.239 UTC Debug sproutletproxy.cpp:197: Found next routable URI: sip:scscf.ims.rmcore.net 21-09-2017 15:53:32.239 UTC Debug sproutletproxy.cpp:340: Possible service name scscf will be used if ims.rmcore.net<http://ims.rmcore.net> is a local hostname 21-09-2017 15:53:32.239 UTC Debug authenticationsproutlet.cpp:169: Authorization header in request 21-09-2017 15:53:32.239 UTC Debug authenticationsproutlet.cpp:177: Integrity protected with ip-assoc-pending 21-09-2017 15:53:32.239 UTC Verbose sproutletproxy.cpp:1298: Created Sproutlet authentication-0x7f474c022150 for Request msg REGISTER/cseq=2 (tdta0x7f474c020150) 21-09-2017 15:53:32.239 UTC Verbose sproutletproxy.cpp:2290: Routing Request msg REGISTER/cseq=2 (tdta0x7f474c020150) (1347 bytes) to downstream sproutlet authentication: --start msg— REGISTER sip:scscf.ims.rmcore.net SIP/2.0 Via: SIP/2.0/TCP 10.0.0.222:5058;rport=33214;received=10.0.0.222;branch=z9hG4bKPj1JagMaULIh8xrGTU49BsvwXp7aQVjv9S Path: <sip:[email protected]:5058;transport=TCP;lr;ob> Via: SIP/2.0/UDP 212.159.106.131:59124;rport=59124;received=212.159.106.131;branch=z9hG4bK-524287-1—07005d66d0f9415a Max-Forwards: 67 Contact: <sip:[email protected]:59124;rinstance=39865f51c2a988a3> To: "Jim@IMS" <sip:[email protected]> From: "Jim@IMS" <sip:[email protected]>;tag=e2a4b510 Call-ID: 85656NGM0NGZkNDM3YjVhZTNhZWY3OWNmYzQ1NDc4MjM3ZTQ CSeq: 2 REGISTER Expires: 3600 Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS User-Agent: Bria 4 release 4.8.2 stamp 85656 P-Visited-Network-ID: ims.rmcore.net<http://ims.rmcore.net> P-Charging-Function-Addresses: ccf=cdf.ims.rmcore.net<http://cdf.ims.rmcore.net> P-Charging-Vector: icid-value="85656NGM0NGZkNDM3YjVhZTNhZWY3OWNmYzQ1NDc4MjM3ZTQ";icid-generated-at=ec2-52-56-52-145.eu-west-2.compute.amazonaws.com<http://ec2-52-56-52-145.eu-west-2.compute.amazonaws.com> Authorization: Digest response="5a39ea19aeafcf955924b29a9a375451", username="[email protected]<mailto:[email protected]>", realm="ims.rmcore.net<http://ims.rmcore.net>", nonce="63bff4bb68c27b47", uri="sip:ims.rmcore.net", algorithm=MD5, cnonce="c549e7ca56a2867a6e23caf77a3c629a", opaque="5a5a8de45658f637", qop=auth, nc=00000002,integrity-protected=ip-assoc-pending Content-Length: 0 --end msg— 21-09-2017 15:53:32.240 UTC Debug pjutils.cpp:700: Cloned tdta0x7f474c020150 to tdta0x7f474c022360 21-09-2017 15:53:32.240 UTC Debug sproutletproxy.cpp:1961: Adding message 0x7f474c022970 => txdata 0x7f474c022408 mapping 21-09-2017 15:53:32.240 UTC Verbose sproutletproxy.cpp:1806: authentication-0x7f474c022150 pass initial request Request msg REGISTER/cseq=2 (tdta0x7f474c022360) to Sproutlet 21-09-2017 15:53:32.240 UTC Debug authenticationsproutlet.cpp:873: Authentication module invoked 21-09-2017 15:53:32.240 UTC Debug sproutletproxy.cpp:340: Possible service name scscf will be used if sprout.ims.rmcore.net<http://sprout.ims.rmcore.net> is a local hostname 21-09-2017 15:53:32.240 UTC Debug sproutletproxy.cpp:340: Possible service name scscf will be used if ims.rmcore.net<http://ims.rmcore.net> is a local hostname 21-09-2017 15:53:32.240 UTC Debug authenticationsproutlet.cpp:1456: Lookup IMPI object: [email protected]<mailto:[email protected]> 21-09-2017 15:53:32.240 UTC Debug memcachedstore.cpp:295: Start GET from table impi for key [email protected]<mailto:[email protected]> 21-09-2017 15:53:32.240 UTC Debug astaire_resolver.cpp:47: AstaireResolver::resolve for host vellum.ims.rmcore.net<http://vellum.ims.rmcore.net>, family 2 21-09-2017 15:53:32.240 UTC Debug utils.cpp:377: Malformed host/port vellum.ims.rmcore.net<http://vellum.ims.rmcore.net> 21-09-2017 15:53:32.240 UTC Debug utils.cpp:418: Attempt to parse vellum.ims.rmcore.net<http://vellum.ims.rmcore.net> as IP address 21-09-2017 15:53:32.240 UTC Verbose dnscachedresolver.cpp:468: Check cache for vellum.ims.rmcore.net<http://vellum.ims.rmcore.net> type 1 21-09-2017 15:53:32.240 UTC Debug dnscachedresolver.cpp:570: Pulling 1 records from cache for vellum.ims.rmcore.net<http://vellum.ims.rmcore.net> A 21-09-2017 15:53:32.240 UTC Debug baseresolver.cpp:369: Found 1 A/AAAA records, creating iterator 21-09-2017 15:53:32.240 UTC Debug baseresolver.cpp:920: Attempting to get 2 targets for host:vellum.ims.rmcore.net<http://vellum.ims.rmcore.net>. allowed_host_state = 3 21-09-2017 15:53:32.240 UTC Debug baseresolver.cpp:793: 10.0.0.6:11311;transport=TCP has state: WHITE 21-09-2017 15:53:32.240 UTC Debug baseresolver.cpp:793: 10.0.0.6:11311;transport=TCP has state: WHITE 21-09-2017 15:53:32.240 UTC Debug baseresolver.cpp:997: Added a whitelisted server to targets, now have 1 of 2 21-09-2017 15:53:32.240 UTC Debug memcachedstore.cpp:696: Found 1 targets for vellum.ims.rmcore.net<http://vellum.ims.rmcore.net> 21-09-2017 15:53:32.240 UTC Debug memcachedstore.cpp:721: Duplicate target IP=10.0.0.6, port= 11311 as it is the only target 21-09-2017 15:53:32.240 UTC Debug memcachedstore.cpp:249: Try server IP 10.0.0.6, port 11311 21-09-2017 15:53:32.240 UTC Debug connection_pool.h:207: Request for connection to IP: 10.0.0.6, port: 11311 21-09-2017 15:53:32.240 UTC Debug connection_pool.h:220: Found existing connection 0x7f470c06a3e0 in pool 21-09-2017 15:53:32.240 UTC Debug memcachedstore.cpp:74: Fetch result 21-09-2017 15:53:32.240 UTC Debug memcachedstore.cpp:82: Found record on replica 21-09-2017 15:53:32.240 UTC Debug memcachedstore.cpp:260: libmemcached returned 0 21-09-2017 15:53:32.240 UTC Debug connection_pool.h:244: Release connection to IP: 10.0.0.6, port: 11311 to pool 21-09-2017 15:53:32.240 UTC Debug memcachedstore.cpp:339: Read 268 bytes from table impi key [email protected]<mailto:[email protected]>, CAS = 18873 21-09-2017 15:53:32.240 UTC Debug astaire_impistore.cpp:177: Retrieved IMPI for [email protected]<mailto:[email protected]> {"authChallenges":[{"type":"digest","nonce":"63bff4bb68c27b47","nc":2,"expires":1506009512,"correlator":"z9hG4bKPj868.WzubxOAj3T1s2dS1BU0qM0Zj-kpZ","scscf-uri":"sip:scscf.ims.rmcore.net","realm":"ims.rmcore.net<http://ims.rmcore.net>","qop":"auth","ha1":"b144b84f59356acbb86048bf3eb5f48f”}]} 21-09-2017 15:53:32.240 UTC Debug authenticationsproutlet.cpp:994: Verify authentication information in request 21-09-2017 15:53:32.240 UTC Debug authenticationsproutlet.cpp:482: Found Digest HA1 = b144b84f59356acbb86048bf3eb5f48f 21-09-2017 15:53:32.240 UTC Debug authenticationsproutlet.cpp:1006: Request authenticated successfully 21-09-2017 15:53:32.240 UTC Debug authenticationsproutlet.cpp:1033: Storing challenge because nonce counts are supported 21-09-2017 15:53:32.240 UTC Debug astaire_impistore.cpp:134: Storing IMPI for [email protected]<mailto:[email protected]> {"authChallenges":[{"type":"digest","nonce":"63bff4bb68c27b47","nc":3,"expires":1506009512,"correlator":"z9hG4bKPj868.WzubxOAj3T1s2dS1BU0qM0Zj-kpZ","scscf-uri":"sip:scscf.ims.rmcore.net","realm":"ims.rmcore.net<http://ims.rmcore.net>","qop":"auth","ha1":"b144b84f59356acbb86048bf3eb5f48f”}]} 21-09-2017 15:53:32.240 UTC Debug memcachedstore.cpp:413: Writing 268 bytes to table impi key [email protected]<mailto:[email protected]>, CAS = 18873, expiry = 300 21-09-2017 15:53:32.240 UTC Debug astaire_resolver.cpp:47: AstaireResolver::resolve for host vellum.ims.rmcore.net<http://vellum.ims.rmcore.net>, family 2 21-09-2017 15:53:32.240 UTC Debug utils.cpp:377: Malformed host/port vellum.ims.rmcore.net<http://vellum.ims.rmcore.net> 21-09-2017 15:53:32.240 UTC Debug utils.cpp:418: Attempt to parse vellum.ims.rmcore.net<http://vellum.ims.rmcore.net> as IP address 21-09-2017 15:53:32.240 UTC Verbose dnscachedresolver.cpp:468: Check cache for vellum.ims.rmcore.net<http://vellum.ims.rmcore.net> type 1 21-09-2017 15:53:32.240 UTC Debug dnscachedresolver.cpp:570: Pulling 1 records from cache for vellum.ims.rmcore.net<http://vellum.ims.rmcore.net> A 21-09-2017 15:53:32.240 UTC Debug baseresolver.cpp:369: Found 1 A/AAAA records, creating iterator 21-09-2017 15:53:32.240 UTC Debug baseresolver.cpp:920: Attempting to get 2 targets for host:vellum.ims.rmcore.net<http://vellum.ims.rmcore.net>. allowed_host_state = 3 21-09-2017 15:53:32.240 UTC Debug baseresolver.cpp:793: 10.0.0.6:11311;transport=TCP has state: WHITE 21-09-2017 15:53:32.240 UTC Debug baseresolver.cpp:793: 10.0.0.6:11311;transport=TCP has state: WHITE 21-09-2017 15:53:32.240 UTC Debug baseresolver.cpp:997: Added a whitelisted server to targets, now have 1 of 2 21-09-2017 15:53:32.241 UTC Debug memcachedstore.cpp:696: Found 1 targets for vellum.ims.rmcore.net<http://vellum.ims.rmcore.net> 21-09-2017 15:53:32.241 UTC Debug memcachedstore.cpp:721: Duplicate target IP=10.0.0.6, port= 11311 as it is the only target 21-09-2017 15:53:32.241 UTC Debug memcachedstore.cpp:249: Try server IP 10.0.0.6, port 11311 21-09-2017 15:53:32.241 UTC Debug connection_pool.h:207: Request for connection to IP: 10.0.0.6, port: 11311 21-09-2017 15:53:32.241 UTC Debug connection_pool.h:220: Found existing connection 0x7f470c06a3e0 in pool 21-09-2017 15:53:32.241 UTC Debug memcachedstore.cpp:260: libmemcached returned 0 21-09-2017 15:53:32.241 UTC Debug connection_pool.h:244: Release connection to IP: 10.0.0.6, port: 11311 to pool 21-09-2017 15:53:32.241 UTC Debug memcachedstore.cpp:555: Write successful 21-09-2017 15:53:32.241 UTC Debug authenticationsproutlet.cpp:1178: Updated Authorization header with new nc and response 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:427: Creating URI for service registrar 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:340: Possible service name scscf will be used if ims.rmcore.net<http://ims.rmcore.net> is a local hostname 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:453: Constructed URI sip:ims.rmcore.net;lr;service=registrar 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:1535: Sproutlet send_request 0x7f474c022970 21-09-2017 15:53:32.241 UTC Verbose sproutletproxy.cpp:1576: authentication-0x7f474c022150 sending Request msg REGISTER/cseq=2 (tdta0x7f474c022360) on fork 0 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:1976: Processing actions from sproutlet - 0 responses, 1 requests, 0 timers 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:2016: Processing request 0x7f474c022408, fork = 0 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:2141: authentication-0x7f474c022150 transmitting request on fork 0 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:2156: authentication-0x7f474c022150 store reference to non-ACK request Request msg REGISTER/cseq=2 (tdta0x7f474c022360) on fork 0 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:1968: Removing message 0x7f474c022970 => txdata 0x7f474c022408 mapping 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:163: Find target Sproutlet for request 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:197: Found next routable URI: sip:ims.rmcore.net;lr;service=registrar 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:300: Found services param - registrar 21-09-2017 15:53:32.241 UTC 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 21-09-2017 15:53:32.241 UTC Debug uri_classifier.cpp:185: Classified URI as 5 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:427: Creating URI for service subscription 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:300: Found services param - registrar 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:453: Constructed URI sip:ims.rmcore.net;lr;service=subscription 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:1200: Remove top Route header Route: <sip:ims.rmcore.net;lr;service=registrar> 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:163: Find target Sproutlet for request 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:197: Found next routable URI: sip:ims.rmcore.net;lr;service=subscription 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:300: Found services param - subscription 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:427: Creating URI for service scscf-proxy 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:300: Found services param - subscription 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:453: Constructed URI sip:ims.rmcore.net;lr;service=scscf-proxy 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:1200: Remove top Route header Route: <sip:ims.rmcore.net;lr;service=subscription> 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:163: Find target Sproutlet for request 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:197: Found next routable URI: sip:ims.rmcore.net;lr;service=scscf-proxy 21-09-2017 15:53:32.241 UTC Debug sproutletproxy.cpp:300: Found services param - scscf-proxy 21-09-2017 15:53:32.241 UTC Debug scscfsproutlet.cpp:489: S-CSCF Transaction (0x7f474c011150) created 21-09-2017 15:53:32.241 UTC Verbose sproutletproxy.cpp:1298: Created Sproutlet scscf-proxy-0x7f474c011150 for Request msg REGISTER/cseq=2 (tdta0x7f474c022360) 21-09-2017 15:53:32.241 UTC Verbose sproutletproxy.cpp:2290: Routing Request msg REGISTER/cseq=2 (tdta0x7f474c022360) (1399 bytes) to downstream sproutlet scscf-proxy: --start msg— REGISTER sip:scscf.ims.rmcore.net SIP/2.0 Route: <sip:ims.rmcore.net;lr;service=scscf-proxy> Via: SIP/2.0/TCP 10.0.0.222:5058;rport=33214;received=10.0.0.222;branch=z9hG4bKPj1JagMaULIh8xrGTU49BsvwXp7aQVjv9S Path: <sip:[email protected]:5058;transport=TCP;lr;ob> Via: SIP/2.0/UDP 212.159.106.131:59124;rport=59124;received=212.159.106.131;branch=z9hG4bK-524287-1—07005d66d0f9415a Max-Forwards: 66 Contact: <sip:[email protected]:59124;rinstance=39865f51c2a988a3> To: "Jim@IMS" <sip:[email protected]> From: "Jim@IMS" <sip:[email protected]>;tag=e2a4b510 Call-ID: 85656NGM0NGZkNDM3YjVhZTNhZWY3OWNmYzQ1NDc4MjM3ZTQ CSeq: 2 REGISTER Expires: 3600 Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS User-Agent: Bria 4 release 4.8.2 stamp 85656 P-Visited-Network-ID: ims.rmcore.net<http://ims.rmcore.net> P-Charging-Function-Addresses: ccf=cdf.ims.rmcore.net<http://cdf.ims.rmcore.net> P-Charging-Vector: icid-value="85656NGM0NGZkNDM3YjVhZTNhZWY3OWNmYzQ1NDc4MjM3ZTQ";icid-generated-at=ec2-52-56-52-145.eu-west-2.compute.amazonaws.com<http://ec2-52-56-52-145.eu-west-2.compute.amazonaws.com> Authorization: Digest response="54ade38e11b464bf9fcde6f464c7d9e8", username="[email protected]<mailto:[email protected]>", realm="ims.rmcore.net<http://ims.rmcore.net>", nonce="63bff4bb68c27b47", uri="sip:ims.rmcore.net", algorithm=MD5, cnonce="c549e7ca56a2867a6e23caf77a3c629a", opaque="5a5a8de45658f637", qop=auth, nc=00000003,integrity-protected=ip-assoc-pending Content-Length: 0 --end msg— Any idea what’s going wrong here? Thanks Jim RedMatter Ltd Jim Page VP Mobile Services +44 (0)333 150 1666 +44 (0)7870 361412 [email protected]<mailto:[email protected]> On 21 Sep 2017, at 15:38, Jim Page <[email protected]<mailto:[email protected]>> wrote: Hi Clearwater people I could really do with your help with the below. I have a pretty much bog standard setup, standard build with chef in AWS, plus an openimscore HSS instance. I am currently unable to get any sip devices to register due to an apparent issue nonce counting. Can you help? In parallel I am trying to hack the code to work around the issue … but I can’t believe this isn’t a common scenario with a simple solution … ? Thanks in advance … Jim RedMatter Ltd Jim Page VP Mobile Services +44 (0)333 150 1666 +44 (0)7870 361412 [email protected]<mailto:[email protected]> On 17 Sep 2017, at 18:38, Jim Page <[email protected]<mailto:[email protected]>> wrote: Hi There I initially set up my IMS in an AWS VPC, using chef. It worked out of the box without an HSS, I was able to use Ellis to provision accounts and they registered no problem using Bria 4. I decided to add an HSS (using ‘knife box’ to add an openimscore HSS instance) so that I can test our application servers. Now that I have the HSS integrated (there were niggles in the installation), I provisioned a new user on the HSS but the Bria phone will not authenticate, and a feedback loop is generated on the first REGISTER attempt. The problem seems to be related to nonce counting. The process seems to go like this: UE REGISTER -> Bono Bono REGISTER -> icscf No Authorization. Challenge is built, and IMPI is created with nc=1, and stored icscf 401 -> Bono Bono 401 -> UE UE builds an Authorisation header UE REGISTER -> Bono Bono REGISTER -> icscf The Authorisation header contains nc=000001. IMPI is loaded and validation is successful. IMPI is stored with nc=2, log line 'Debug authenticationsproutlet.cpp:1033: Storing challenge because nonce counts are supported’ icscf REGISTER -> scscf-proxy The Authorisation header still contains nc=000001. IMPI is loaded, but log line says: 'Info authenticationsproutlet.cpp:971: Nonce count supplied (1) is lower than expected (2) - ignore it’ The Authorisation header is ignored and another 401 challenge is issued, and the UE responds …. and this causes a loop scscf-proxy 401 -> icscf icscf 401 -> Bono Bono 401 -> UE There seems to be a fundamental flaw here. The IMPI nc is incrementing, but the Authorisation header is not. I can’t see how this can work unless icscf increments nc in the authorisation header before sending it to the scscf Also please note: I disabled nonce_count_supported in shared_config, but the result was a log line ‘nonce count is supplied but not supported’ (or words to that effect) and the Authorisation header is again ignored, and there is a loop. How to move forward from here? I have searched in vain for a way to disable nonce count in Bria 4. I can provide logs if helpful, but they are long and I don’t want to clog everyone’s inbox. Kind regards Jim RedMatter Ltd Jim Page VP Mobile Services +44 (0)333 150 1666 +44 (0)7870 361412 [email protected]<mailto:[email protected]> _______________________________________________ Clearwater mailing list [email protected]<mailto:[email protected]> http://lists.projectclearwater.org/mailman/listinfo/clearwater_lists.projectclearwater.org _______________________________________________ Clearwater mailing list [email protected]<mailto:[email protected]> http://lists.projectclearwater.org/mailman/listinfo/clearwater_lists.projectclearwater.org
_______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/mailman/listinfo/clearwater_lists.projectclearwater.org
