Hi

I am setting up one clearwater environment using docker.


I have successfully deployed the ims containers and two AS with IFCs.


The REGISTER requests work with success and reach the AS.


The OPTIONS requests don't work ( i have copied the IFCs from an older 
installation of clearwater, so I believe that the format of the IFCs is OK).


I took a pcap in sprout, and what I observe is that sprout receives the OPTIONS 
and executes a NAPTR dns query to the user domain. The resulting dns query 
points the request to sprout again.


I believe that instead of sprout attempting to execute the above dns query, 
should check the IFCs and send the OPTIONS towards the AS.


Can anyone help me with this?


I send here a part of the logs.


29-03-2018 13:45:19.173 UTC [7f21b8819700] Debug pjsip: sip_endpoint.c 
Processing incoming message: Request msg OPTIONS/cseq=1 (rdata0x7f21b4068500)
29-03-2018 13:45:19.173 UTC [7f21b8819700] Verbose 
common_sip_processing.cpp:87: RX 1686 bytes Request msg OPTIONS/cseq=1 
(rdata0x7f21b4068500) from TCP 172.50.0.9:38087:
--start msg--

OPTIONS sip:[email protected] SIP/2.0
Record-Route: <sip:172.50.0.9:5058;transport=TCP;lr>
...
Route: 
<sip:sprout:5054;transport=tcp;lr;orig;username=+917722000103%40ims.mnc874.mcc405.3gppnetwork.org;nonce=7061e85c400e635f>
Content-Length:  0
...

--end msg--
29-03-2018 13:45:19.173 UTC [7f21b8819700] 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

29-03-2018 13:45:19.173 UTC [7f21b8819700] Debug uri_classifier.cpp:172: 
Classified URI as 5
29-03-2018 13:45:19.173 UTC [7f21b8819700] Debug pjutils.cpp:1771: Logging SAS 
Call-ID marker, Call-ID mHkJ0rybfT
29-03-2018 13:45:19.173 UTC [7f21b8819700] Debug thread_dispatcher.cpp:554: 
Recieved message 0x7f21b4068500 on worker thread
29-03-2018 13:45:19.173 UTC [7f21b8819700] Debug thread_dispatcher.cpp:571: 
Admitted request 0x7f21b4068500 on worker thread
29-03-2018 13:45:19.173 UTC [7f21b8819700] Debug thread_dispatcher.cpp:606: 
Incoming message 0x7f21b4068500 cloned to 0x7f21b406ba18
29-03-2018 13:45:19.173 UTC [7f21b8819700] Debug thread_dispatcher.cpp:625: 
Queuing cloned received message 0x7f21b406ba18 for worker threads with priority 
15
29-03-2018 13:45:19.173 UTC [7f21b8819700] Debug 
event_statistic_accumulator.cpp:32: Accumulate 0 for 0x21b2ad8
29-03-2018 13:45:19.173 UTC [7f21b8819700] Debug 
event_statistic_accumulator.cpp:32: Accumulate 0 for 0x21b2b20
29-03-2018 13:45:19.173 UTC [7f25927cc700] Debug utils.cpp:872: Added IOHook 
0x7f25927cbe30 to stack. There are now 1 hooks
29-03-2018 13:45:19.173 UTC [7f25927cc700] Debug thread_dispatcher.cpp:178: 
Worker thread dequeue message 0x7f21b406ba18
29-03-2018 13:45:19.173 UTC [7f25927cc700] Debug thread_dispatcher.cpp:183: 
Request latency so far = 278us
29-03-2018 13:45:19.173 UTC [7f25927cc700] Debug pjsip: sip_endpoint.c 
Distributing rdata to modules: Request msg OPTIONS/cseq=1 (rdata0x7f21b406ba18)
29-03-2018 13:45:19.173 UTC [7f25927cc700] 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
29-03-2018 13:45:19.173 UTC [7f25927cc700] Debug uri_classifier.cpp:172: 
Classified URI as 5
29-03-2018 13:45:19.173 UTC [7f25927cc700] Debug basicproxy.cpp:62: Process 
OPTIONS request
29-03-2018 13:45:19.173 UTC [7f25927cc700] Debug sproutletproxy.cpp:631: 
Sproutlet Proxy transaction (0x7f219c021810) created. There are now 1 instances
29-03-2018 13:45:19.173 UTC [7f25927cc700] Debug basicproxy.cpp:1318: Report 
SAS start marker - trail (f)
29-03-2018 13:45:19.173 UTC [7f25927cc700] Debug pjutils.cpp:719: Cloned 
Request msg OPTIONS/cseq=1 (rdata0x7f21b406ba18) to tdta0x7f219c021c60
29-03-2018 13:45:19.173 UTC [7f25927cc700] Debug pjsip: tsx0x7f219c025 
Transaction created for Request msg OPTIONS/cseq=1 (rdata0x7f21b406ba18)
29-03-2018 13:45:19.173 UTC [7f25927cc700] Debug pjsip: tsx0x7f219c025 Incoming 
Request msg OPTIONS/cseq=1 (rdata0x7f21b406ba18) in state Null
29-03-2018 13:45:19.173 UTC [7f25927cc700] Debug pjsip: tsx0x7f219c025 State 
changed from Null to Trying, event=RX_MSG
29-03-2018 13:45:19.173 UTC [7f25927cc700] Debug basicproxy.cpp:183: 
tsx0x7f219c025098 - tu_on_tsx_state UAS, TSX_STATE RX_MSG state=Trying
29-03-2018 13:45:19.173 UTC [7f25927cc700] Debug pjsip:       endpoint Response 
msg 408/OPTIONS/cseq=1 (tdta0x7f219c025800) created
29-03-2018 13:45:19.173 UTC [7f25927cc700] Debug sproutletproxy.cpp:165: Find 
target Sproutlet for request
29-03-2018 13:45:19.173 UTC [7f25927cc700] Debug sproutletproxy.cpp:199: Found 
next routable URI: 
sip:sprout:5054;transport=tcp;lr;orig;username=+917722000103%40ims.mnc874.mcc405.3gppnetwork.org;nonce=7061e85c400e635f
29-03-2018 13:45:19.173 UTC [7f25927cc700] Debug sproutletproxy.cpp:237: No 
Sproutlet found using service name or host
29-03-2018 13:45:19.173 UTC [7f25927cc700] Debug sproutletproxy.cpp:243: Find 
default service for port 5054
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:429: 
Creating URI for service registrar
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:455: 
Constructed URI 
sip:sprout;transport=tcp;lr;orig;username=+917722000103%40ims.mnc874.mcc405.3gppnetwork.org;nonce=7061e85c400e635f;service=registrar
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:1276: 
Remove top Route header Route: 
<sip:sprout:5054;transport=tcp;lr;orig;username=+917722000103%40ims.mnc874.mcc405.3gppnetwork.org;nonce=7061e85c400e635f>
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:165: Find 
target Sproutlet for request
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:199: Found 
next routable URI: 
sip:sprout;transport=tcp;lr;orig;username=+917722000103%40ims.mnc874.mcc405.3gppnetwork.org;nonce=7061e85c400e635f;service=registrar
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:302: Found 
services param - registrar
29-03-2018 13:45:19.174 UTC [7f25927cc700] 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
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug uri_classifier.cpp:172: 
Classified URI as 5
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:429: 
Creating URI for service subscription
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:302: Found 
services param - registrar
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:455: 
Constructed URI 
sip:sprout;transport=tcp;lr;orig;username=+917722000103%40ims.mnc874.mcc405.3gppnetwork.org;nonce=7061e85c400e635f;service=subscription
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:1276: 
Remove top Route header Route: 
<sip:sprout;transport=tcp;lr;orig;username=+917722000103%40ims.mnc874.mcc405.3gppnetwork.org;nonce=7061e85c400e635f;service=registrar>
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:165: Find 
target Sproutlet for request
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:199: Found 
next routable URI: 
sip:sprout;transport=tcp;lr;orig;username=+917722000103%40ims.mnc874.mcc405.3gppnetwork.org;nonce=7061e85c400e635f;service=subscription
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:302: Found 
services param - subscription
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:429: 
Creating URI for service scscf-proxy
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:302: Found 
services param - subscription
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:455: 
Constructed URI 
sip:sprout;transport=tcp;lr;orig;username=+917722000103%40ims.mnc874.mcc405.3gppnetwork.org;nonce=7061e85c400e635f;service=scscf-proxy
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:1276: 
Remove top Route header Route: 
<sip:sprout;transport=tcp;lr;orig;username=+917722000103%40ims.mnc874.mcc405.3gppnetwork.org;nonce=7061e85c400e635f;service=subscription>
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:165: Find 
target Sproutlet for request
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:199: Found 
next routable URI: 
sip:sprout;transport=tcp;lr;orig;username=+917722000103%40ims.mnc874.mcc405.3gppnetwork.org;nonce=7061e85c400e635f;service=scscf-proxy
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:302: Found 
services param - scscf-proxy
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug scscfsproutlet.cpp:424: S-CSCF 
Transaction (0x7f219c0278f0) created

29-03-2018 13:45:19.174 UTC [7f25927cc700] Verbose sproutletproxy.cpp:1384: 
Created Sproutlet scscf-proxy-0x7f219c0278f0 for Request msg OPTIONS/cseq=1 
(tdta0x7f219c021c60)
29-03-2018 13:45:19.174 UTC [7f25927cc700] Verbose sproutletproxy.cpp:2487: 
Routing Request msg OPTIONS/cseq=1 (tdta0x7f219c021c60) (1727 bytes) to 
downstream sproutlet scscf-proxy:
--start msg--
OPTIONS sip:[email protected] SIP/2.0
Route: 
<sip:sprout;transport=tcp;lr;orig;username=+917722000103%40ims.mnc874.mcc405.3gppnetwork.org;nonce=7061e85c400e635f;service=scscf-proxy>
Record-Route: <sip:172.50.0.9:5058;transport=TCP;lr>

...
--end msg--
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:2504: 
Network function boundary: yes ('EXTERNAL'->'scscf'/'scscf-proxy')
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:2504: 
Network function boundary: yes ('EXTERNAL'->'scscf'/'scscf-proxy')
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:2517: 
Internal network function boundary: no
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug pjutils.cpp:736: Cloned 
tdta0x7f219c021c60 to tdta0x7f219c028430
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:1450: 
Remove top Route header Route: 
<sip:sprout;transport=tcp;lr;orig;username=+917722000103%40ims.mnc874.mcc405.3gppnetwork.org;nonce=7061e85c400e635f;service=scscf-proxy>
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:2115: 
Adding message 0x7f219c028a40 => txdata 0x7f219c0284d8 mapping
29-03-2018 13:45:19.174 UTC [7f25927cc700] Verbose sproutletproxy.cpp:1946: 
scscf-proxy-0x7f219c0278f0 pass initial request Request msg OPTIONS/cseq=1 
(tdta0x7f219c028430) to Sproutlet
29-03-2018 13:45:19.174 UTC [7f25927cc700] Info scscfsproutlet.cpp:471: S-CSCF 
received initial request
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug uri_classifier.cpp:139: home 
domain: false, local_to_node: true, is_gruu: false, enforce_user_phone: false, 
prefer_sip: true, treat_number_as_phone: false
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug uri_classifier.cpp:172: 
Classified URI as 3
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug scscfsproutlet.cpp:945: Route 
header references this system
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug scscfsproutlet.cpp:998: No ODI 
token, or invalid ODI token, on request, and no P-Charging-Vector header (so 
can't log ICID for correlation)
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug scscfsproutlet.cpp:1004: Got 
our Route header, session case orig, OD=None
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug pjutils.cpp:294: Served user 
from P-Asserted-Identity header
29-03-2018 13:45:19.174 UTC [7f25927cc700] 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
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug uri_classifier.cpp:172: 
Classified URI as 5
29-03-2018 13:45:19.174 UTC [7f25927cc700] 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
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug uri_classifier.cpp:172: 
Classified URI as 5
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug scscfsproutlet.cpp:1348: URI 
is not locally hosted
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug acr.cpp:1797: Create RalfACR 
for node type S-CSCF with role Originating
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug acr.cpp:24: Created ACR 
(0x7f219c02b3a0)
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug acr.cpp:170: Created S-CSCF 
Ralf ACR
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug acr.cpp:29: Destroyed ACR 
(0x7f219c02b3a0)
29-03-2018 13:45:19.174 UTC [7f25927cc700] 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
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug uri_classifier.cpp:172: 
Classified URI as 5
29-03-2018 13:45:19.174 UTC [7f25927cc700] Info scscfsproutlet.cpp:656: Route 
request without applying services
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:1621: 
Sproutlet send_request 0x7f219c028a40
29-03-2018 13:45:19.174 UTC [7f25927cc700] Verbose sproutletproxy.cpp:1662: 
scscf-proxy-0x7f219c0278f0 sending Request msg OPTIONS/cseq=1 
(tdta0x7f219c028430) on fork 0
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:2130: 
Processing actions from sproutlet - 0 responses, 1 requests, 0 timers
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:2170: 
Processing request 0x7f219c0284d8, fork = 0
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:2334: 
scscf-proxy-0x7f219c0278f0 transmitting request on fork 0
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:2349: 
scscf-proxy-0x7f219c0278f0 store reference to non-ACK request Request msg 
OPTIONS/cseq=1 (tdta0x7f219c028430) on fork 0
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:2122: 
Removing message 0x7f219c028a40 => txdata 0x7f219c0284d8 mapping
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:165: Find 
target Sproutlet for request
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:199: Found 
next routable URI: sip:[email protected]
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:342: 
Possible service name ims will be used if mnc874.mcc405.3gppnetwork.org is a 
local hostname
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:365: Found 
user part - +917722000104
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sproutletproxy.cpp:1007: No 
local sproutlet matches request
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug pjsip: tsx0x7f219c02b 
Transaction created for Request msg OPTIONS/cseq=1 (tdta0x7f219c028430)
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug basicproxy.cpp:1669: Added 
trail identifier 15 to UAC transaction
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug pjutils.cpp:510: Next hop node 
is encoded in Request-URI
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug sipresolver.cpp:84: 
SIPResolver::resolve for name ims.mnc874.mcc405.3gppnetwork.org, port 0, 
transport -1, family 2
29-03-2018 13:45:19.174 UTC [7f25927cc700] Debug utils.cpp:446: Attempt to 
parse ims.mnc874.mcc405.3gppnetwork.org as IP address
29-03-2018 13:45:19.175 UTC [7f25927cc700] Debug sipresolver.cpp:147: Do NAPTR 
look-up for ims.mnc874.mcc405.3gppnetwork.org
29-03-2018 13:45:19.175 UTC [7f25927cc700] Debug ttlcache.h:200: Time now is 
1522331119, expiry time of entry at head of expiry list is 1522330274
29-03-2018 13:45:19.175 UTC [7f25927cc700] Debug ttlcache.h:93: Entry not in 
cache, so create new entry
29-03-2018 13:45:19.175 UTC [7f25927cc700] Debug baseresolver.cpp:252: NAPTR 
cache factory called for ims.mnc874.mcc405.3gppnetwork.org
29-03-2018 13:45:19.175 UTC [7f25927cc700] Debug baseresolver.cpp:264: Sending 
DNS NAPTR query for ims.mnc874.mcc405.3gppnetwork.org
29-03-2018 13:45:19.175 UTC [7f25927cc700] Verbose dnscachedresolver.cpp:468: 
Check cache for ims.mnc874.mcc405.3gppnetwork.org type 35
29-03-2018 13:45:19.175 UTC [7f25927cc700] Debug dnscachedresolver.cpp:474: No 
entry found in cache
29-03-2018 13:45:19.175 UTC [7f25927cc700] Debug dnscachedresolver.cpp:477: 
Create cache entry pending query
29-03-2018 13:45:19.175 UTC [7f25927cc700] Debug dnscachedresolver.cpp:525: 
Create and execute DNS query transaction
29-03-2018 13:45:19.175 UTC [7f25927cc700] Debug dnscachedresolver.cpp:538: 
Wait for query responses
29-03-2018 13:45:19.175 UTC [7f25927cc700] Debug thread_dispatcher.cpp:117: 
Pausing stopwatch due to DNS query




Thanks


Daniel


_______________________________________________
Clearwater mailing list
[email protected]
http://lists.projectclearwater.org/mailman/listinfo/clearwater_lists.projectclearwater.org

Reply via email to