Janek I think this is a problem we've hit before in OpenIMS HSS. According to the specs, the S-CSCF should set the SIP-Authentication-Scheme to "Unknown" if it doesn't know what authentication mechanism to use for a client, but OpenIMS HSS expects "unknown" (with a lower case 'u'). OpenIMS HSSs error paths are not very well coded in the relevant function and it falls through to report the problem as a missing AVP rather than an AVP with an unexpected value.
We've implemented a workaround for this in Homestead. To enable the workaround, add the following line to /etc/clearwater/user_settings on your Homestead node(s) (creating the file if it doesn't already exist) hss_mar_lowercase_unknown=Y Then run "sudo service homestead stop" to force a restart. This should get you past the problem. Mike -----Original Message----- From: [email protected] [mailto:[email protected]] On Behalf Of Jasio Kololski Sent: 17 April 2014 17:53 To: [email protected] Subject: [Clearwater] OpenIMS HSS integration - Cx Diameter MAR missing mandatory AVP. Problem registering user with Open IMS HSS. HSS retruns 2014-04-16 13:35:56,720 DEBUG de.fhg.fokus.hss.main.Task - execute Processing MAR! de.fhg.fokus.hss.cx.CxExperimentalResultException: Diameter_Missing_AVP at de.fhg.fokus.hss.cx.op.MAR.processRequest(MAR.java:178) at de.fhg.fokus.hss.main.Task.execute(Task.java:127) at de.fhg.fokus.hss.main.Worker.run(Worker.java:66) MAA returned from FoHSS has Experimental-Result-Code: 5005 which is DIAMETER_MISSING_AVP. Unfortunatelly neither MAA nor FoHSS log doesn't indicate failed AVP as per RFC 6733. Homestead log indicates the following: 16-04-2014 13:33:32.478 Verbose httpstack.cpp:231: Handling request for URL /impi/12201234298%40domain.com/registration-status, args impu=sip %3A12201234298%40domain.com&visited-network=domain.com&auth-type=REG 16-04-2014 13:33:32.478 Debug handlers.cpp:476: Parsed HTTP request: private ID [email protected], public ID sip:[email protected], visited network domain.com, authorization type REG 16-04-2014 13:33:32.478 Debug cx.cpp:105: Building User-Authorization request for [email protected]/sip:[email protected] 16-04-2014 13:33:32.478 Debug freeDiameter: No Session-Id AVP found in message 0x7fe43400eef0 16-04-2014 13:33:32.479 Verbose diameterstack.cpp:706: Sending Diameter message of type 300 on transaction 0x7fe43400bb40 with timeout 200 16-04-2014 13:33:32.479 Debug freeDiameter: SENT to 'hss.domain.com': '3GPP/User-Authorization-Request'16777216/300 f:RP-- src:'(nil)' len:43 2 {C:263/l:50,C:260/l:32,C:277/l:12,C:264/l:37,C:296/l:37,C:293/l:38,C:283/l:34,C:1/l:46,V:10415/C:601/l:54,V:10415/C:600/l:38,V:10415/C:623/l:16} 16-04-2014 13:33:32.479 Debug freeDiameter: Sending 432b data on connection {----} TCP,#314->10.193.153.110(3868) 16-04-2014 13:33:32.518 Debug freeDiameter: 'STATE_OPEN' <-- 'FDEVP_CNX_MSG_RECV' (0x7fe42c00c5c0,300) 'hss.domain.com' 16-04-2014 13:33:32.518 Debug freeDiameter: RCV from 'hss.domain.com': (no model)16777216/300 f:-P-- src:'hss.domain.com' len :300 {C:263/l:50,C:264/l:38,C:296/l:34,C:277/l:12,C:260/l:32,V:10415/C:603/l:76,C:297/l:32}16-04-2014 13:33:32.518 Debug freeDiameter: Peer timeout reset to 30 seconds (+/- 2) 16-04-2014 13:33:32.518 Debug freeDiameter: 'hss.domain.com' in state 'STATE_OPEN' waiting for next event. 16-04-2014 13:33:32.518 Debug freeDiameter: DISPATCHING: (no model)16777216/300 f:-P-- src:'hss.domain.com' len:300 {C:263/l:50,C:264/l:38,C:296/l:34,C:277/l:12,C:260/l:32,V:10415/C:603/l:76,C:297/l:32,C:282/l:8} 16-04-2014 13:33:32.518 Debug freeDiameter: Iterating on rules of AVP: 'Vendor-Specific-Application-Id'. 16-04-2014 13:33:32.518 Debug freeDiameter: Iterating on rules of AVP: 'Server-Capabilities'. 16-04-2014 13:33:32.518 Debug freeDiameter: Iterating on rules of AVP: 'Experimental-Result'. 16-04-2014 13:33:32.518 Debug freeDiameter: Iterating on rules of COMMAND: '3GPP/User-Authorization-Answer'. 16-04-2014 13:33:32.518 Debug freeDiameter: Calling callback registered when query was sent (0x43ee60, 0x7fe43400bb40) 16-04-2014 13:33:32.518 Verbose diameterstack.cpp:413: Got Diameter response of type 300 - calling callback on transaction 0x7fe43400bb40 16-04-2014 13:33:32.518 Debug diameterstack.cpp:638: Got Experimental-Result-Code 2001 16-04-2014 13:33:32.519 Debug handlers.cpp:517: Received User-Authorization answer with result 0/2001 16-04-2014 13:33:32.519 Debug handlers.cpp:538: Got Server-Capabilities 16-04-2014 13:33:32.519 Debug cx.cpp:192: Getting server capabilties from User-Authorization answer 16-04-2014 13:33:32.519 Debug cx.cpp:206: Found optional capability 1 16-04-2014 13:33:32.519 Debug cx.cpp:213: Found server name sprout.domain.com 16-04-2014 13:33:32.519 Debug handlers.cpp:543: Got Server-Name sprout.domain.com from Capabilities AVP 16-04-2014 13:33:32.519 Verbose httpstack.cpp:64: Sending response 200 to request for URL /impi/12201234298%40domain.com/registration-status, args impu=sip%3A12201234298%40domain.com&visited-network=domain.com&auth-type=REG 16-04-2014 13:33:32.519 Debug statistic.cpp:103: Send new value for statistic H_hss_latency_us, size 5 16-04-2014 13:33:32.519 Debug statistic.cpp:103: Send new value for statistic H_hss_subscription_latency_us, size 5 16-04-2014 13:33:32.519 Debug zmq_lvc.cpp:167: Update to H_hss_latency_us statistic 16-04-2014 13:33:32.519 Debug zmq_lvc.cpp:250: Clearing message cache for 0x7fe45c005300 16-04-2014 13:33:32.519 Debug zmq_lvc.cpp:167: Update to H_hss_subscription_latency_us statistic 16-04-2014 13:33:32.519 Debug zmq_lvc.cpp:250: Clearing message cache for 0x7fe45c00e730 16-04-2014 13:33:32.538 Verbose httpstack.cpp:231: Handling request for URL /impi/12201234298%40domain.com/av, args impu=sip%3A12201234298%40domain.com 16-04-2014 13:33:32.538 Debug handlers.cpp:116: Parsed HTTP request: private ID [email protected], public ID sip:[email protected], scheme Unknown, authorization 16-04-2014 13:33:32.538 Debug handlers.cpp:123: Authentication vector cache query disabled - query HSS 16-04-2014 13:33:32.538 Debug cx.cpp:356: Building Multimedia-Auth request for [email protected]/sip:[email protected] 16-04-2014 13:33:32.538 Debug freeDiameter: No Session-Id AVP found in message 0x7fe428001b50 16-04-2014 13:33:32.538 Verbose diameterstack.cpp:706: Sending Diameter message of type 303 on transaction 0x7fe428010180 with timeout 200 16-04-2014 13:33:32.539 Debug freeDiameter: SENT to 'hss.domain.com': '3GPP/Multimedia-Auth-Request'16777216/303 f:RP-- src:'(nil)' len:480 {C:263/l:50,C:260/l:32,C:277/l:12,C:283/l:34,C:293/l:38,C:264/l:37,C:296/l:37,C:1/l:46,V:10415/C:601/l:54,V:10415/C:612/l:32,V:10415/C:607/l:16,V:10415/C:602/l:54} 16-04-2014 13:33:32.539 Debug freeDiameter: Sending 480b data on connection {----} TCP,#314->10.193.153.110(3868) 16-04-2014 13:33:32.554 Debug freeDiameter: 'STATE_OPEN' <-- 'FDEVP_CNX_MSG_RECV' (0x7fe42c00c580,224) 'hss.domain.com' 16-04-2014 13:33:32.554 Debug freeDiameter: RCV from 'hss.domain.com': (no model)16777216/303 f:-P-- src:'hss.domain.com' len:224 {C:263/l:50,C:264/l:38,C:296/l:34,C:277/l:12,C:260/l:32,C:297/l:32} 16-04-2014 13:33:32.555 Debug freeDiameter: Peer timeout reset to 30 seconds (+/- 2) 16-04-2014 13:33:32.555 Debug freeDiameter: 'hss.domain.com' in state 'STATE_OPEN' waiting for next event. 16-04-2014 13:33:32.555 Debug freeDiameter: DISPATCHING: (no model)16777216/303 f:-P-- src:'hss.domain.com' len:224 {C:263/l:50,C:264/l:38,C:296/l:34,C:277/l:12,C:260/l:32,C:297/l:32,C:282/l:8} 16-04-2014 13:33:32.555 Debug freeDiameter: Iterating on rules of AVP: 'Vendor-Specific-Application-Id'. 16-04-2014 13:33:32.555 Debug freeDiameter: Iterating on rules of AVP: 'Experimental-Result'. 16-04-2014 13:33:32.555 Debug freeDiameter: Iterating on rules of COMMAND: '3GPP/Multimedia-Auth-Answer'. 16-04-2014 13:33:32.555 Debug freeDiameter: Calling callback registered when query was sent (0x43ee60, 0x7fe428010180) 16-04-2014 13:33:32.555 Verbose diameterstack.cpp:413: Got Diameter response of type 303 - calling callback on transaction 0x7fe428010180 *16-04-2014 13:33:32.555 Debug handlers.cpp:273: Received Multimedia-Auth answer with result code 016-04-2014 13:33:32.555 Info handlers.cpp:318: Multimedia-Auth answer with result code 0 - reject* 16-04-2014 13:33:32.555 Verbose httpstack.cpp:64: Sending response 500 to request for URL /impi/12201234298%40domain.com/av, args impu=sip%3A12201234298%40domain.com 16-04-2014 13:33:32.555 Debug statistic.cpp:103: Send new value for statistic H_hss_digest_latency_us, size 5 16-04-2014 13:33:32.556 Debug zmq_lvc.cpp:167: Update to H_hss_digest_latency_us statistic 16-04-2014 13:33:32.556 Debug zmq_lvc.cpp:250: Clearing message cache for 0x7fe45c009d40 Regards, Janek _______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater _______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater
