Good guess. I had the IP address instead of the name for sprout Register is now completing fine
Thanks for the reactive support :-) Olivier DURECU Bell Labs / IP Platform Research Villarceaux Center Tel: +33(0) 130772759 GSM: +33(0) 683776482 -----Message d'origine----- De : Eleanor Merry [mailto:[email protected]] Envoyé : jeudi 3 avril 2014 18:52 À : DURECU, OLIVIER (OLIVIER); James Coleman Cc : [email protected] Objet : RE: [Clearwater] Looping Register at SPROUT Hi Olivier, James, Sprout will remove the top route header on a request if it recognises the hostname as matching the local URI (not including the port). Looking in the logs provided it is failing this check (in basicproxy.cpp, 521, it routes to the next hop in the route set rather than removing the top route header). The local URI is taken from the value of sprout_hostname in /etc/clearwater/config. Does the sprout_hostname value in /etc/clearwater/config equal sprout.bell-labs.net on your Sprout and Bono nodes? Also, if you run 'pgrep -lf sprout', what's the value of the '--sprout-domain' and '--alias' parameters? Ellie -----Original Message----- From: [email protected] [mailto:[email protected]] On Behalf Of DURECU, OLIVIER (OLIVIER) Sent: 03 April 2014 16:33 To: James Coleman Cc: [email protected] Subject: Re: [Clearwater] Looping Register at SPROUT Here are associated logs. I saw an amazing thing. After 20 loops, the message becomes too big (because of 20 via headers added), so sprout can't forward it to itself once again and then triggers the mechanism of SCSCF selection. But the REGISTER can't be forwarded to the selected S-CSCF because of its size... I have a standard install (ICSCF on 5052, SCSCF on 5054) 03-04-2014 14:13:11.529 Debug pjsip: sip_endpoint.c Processing incoming message: Request msg REGISTER/cseq=1 (rdata0x7fe3480177e8) 03-04-2014 14:13:11.529 Verbose stack.cpp:225: RX 817 bytes Request msg REGISTER/cseq=1 (rdata0x7fe3480177e8) from TCP 199.22.0.7:55743: --start msg-- REGISTER sip:bell-labs.net SIP/2.0^M Path: sip:yB1/[email protected]:5058;transport=TCP;lr;ob^M Via: SIP/2.0/TCP 199.22.0.7:55743;rport;branch=z9hG4bKPjEQnMnorFpwHWq37NO7Ue9pudZ7HPPiZY^M Via: SIP/2.0/WS r4918416661.invalid;received=135.244.229.36;branch=z9hG4bKZmE1OWMzNmYzNTc3Yzc1YzM3YTNkNjg1NmY1MmZkNzM.^M From: <sip:[email protected]>;tag=60002256312848305206^M To: <sip:[email protected]>^M Call-ID: [email protected]^M CSeq: 1 REGISTER^M Max-Forwards: 69^M Contact: <sip:[email protected]>;reg-id=1;+sip.instance="<urn:uuid:4ad2b377-27cb-4a36-b406-15adabdb2799>"^M Supported: path, gruu^M Expires: 600^M User-Agent: ALU ORCA Agent 27.11.00:1395696790 spwl Chrome/33.0.1750.154^M Session-Expires: 600^M Route: <sip:sprout.bell-labs.net:5052;transport=TCP;lr;orig>^M Content-Length: 0^M ^M --end msg-- 03-04-2014 14:13:11.529 Debug stack.cpp:410: Queuing cloned received message 0x7fe3480bd898 for worker threads 03-04-2014 14:13:11.529 Debug stack.cpp:188: Worker thread dequeue message 0x7fe3480bd898 03-04-2014 14:13:11.529 Debug pjsip: sip_endpoint.c Distributing rdata to modules: Request msg REGISTER/cseq=1 (rdata0x7fe3480bd898) 03-04-2014 14:13:11.530 Info icscfproxy.cpp:86: I-CSCF processing request 03-04-2014 14:13:11.530 Debug basicproxy.cpp:87: Process REGISTER request 03-04-2014 14:13:11.530 Debug basicproxy.cpp:521: Route to next hop in route set 03-04-2014 14:13:11.530 Debug pjsip: tsx0x7fe2f8002 Transaction created for Request msg REGISTER/cseq=1 (rdata0x7fe3480bd898) 03-04-2014 14:13:11.530 Debug pjsip: tsx0x7fe2f8002 Incoming Request msg REGISTER/cseq=1 (rdata0x7fe3480bd898) in state Null 03-04-2014 14:13:11.530 Debug pjsip: tsx0x7fe2f8002 State changed from Null to Trying, event=RX_MSG 03-04-2014 14:13:11.530 Debug basicproxy.cpp:200: tsx0x7fe2f8002e98 - tu_on_tsx_state UAS, TSX_STATE RX_MSG state=Trying 03-04-2014 14:13:11.530 Debug pjsip: endpoint Response msg 408/REGISTER/cseq=1 (tdta0x7fe2f8003600) created 03-04-2014 14:13:11.530 Debug basicproxy.cpp:1071: Report SAS start marker - trail (10) 03-04-2014 14:13:11.530 Debug icscfproxy.cpp:143: I-CSCF initialize transaction for REGISTER request 03-04-2014 14:13:11.530 Debug basicproxy.cpp:784: Allocating transaction and data for target 0 03-04-2014 14:13:11.530 Debug pjsip: tsx0x7fe2f8006 Transaction created for Request msg REGISTER/cseq=1 (tdta0x7fe2f80046e0) 03-04-2014 14:13:11.530 Debug basicproxy.cpp:1343: Added trail identifier 16 to UAC transaction 03-04-2014 14:13:11.530 Debug basicproxy.cpp:1354: Set target for UAC transaction 03-04-2014 14:13:11.530 Debug basicproxy.cpp:1363: Update Request-URI to sip:bell-labs.net 03-04-2014 14:13:11.530 Debug pjutils.cpp:470: Next hop node is encoded in top route header 03-04-2014 14:13:11.530 Debug sipresolver.cpp:84: SIPResolver::resolve for name sprout.bell-labs.net, port 5052, transport 6, family 2 03-04-2014 14:13:11.530 Debug baseresolver.cpp:474: Attempt to parse sprout.bell-labs.net as IP address 03-04-2014 14:13:11.530 Debug sipresolver.cpp:126: Port is specified 03-04-2014 14:13:11.530 Debug sipresolver.cpp:294: Perform A/AAAA record lookup only, name = sprout.bell-labs.net 03-04-2014 14:13:11.530 Debug dnscachedresolver.cpp:136: Create cache entry pending query 03-04-2014 14:13:11.530 Debug dnscachedresolver.cpp:148: Create and execute DNS query transaction 03-04-2014 14:13:11.530 Debug dnscachedresolver.cpp:154: Wait for query responses 03-04-2014 14:13:11.531 Debug dnscachedresolver.cpp:378: Received DNS response for sprout.bell-labs.net type A 03-04-2014 14:13:11.531 Debug dnsparser.cpp:90: Parsing DNS message 000000: e3bd8580 00010001 00010002 06737072 6f757409 62656c6c 2d6c6162 73036e65 .... .... .... .spr out. bell -lab s.ne 000020: 74000001 0001c00c 00010001 0000012c 0004c716 0007c013 00020001 00000e10 t... .... .... ..., .... .... .... .... 000040: 0005026e 73c013c0 42000100 0100000e 100004c7 160007c0 42001c00 0100000e ...n s... B... .... .... .... B... .... 000060: 10001000 01000000 00000000 00000000 000001 .... .... .... .... ... 03-04-2014 14:13:11.531 Debug dnsparser.cpp:95: Parsing header at offset 0x0 03-04-2014 14:13:11.531 Debug dnsparser.cpp:98: 1 questions, 1 answers, 1 authorities, 2 additional records 03-04-2014 14:13:11.531 Debug dnsparser.cpp:103: Parsing question 1 at offset 0xc 03-04-2014 14:13:11.531 Debug dnsparser.cpp:229: Parsed domain name = sprout.bell-labs.net, encoded length = 22 03-04-2014 14:13:11.531 Debug dnsparser.cpp:112: Parsing answer 1 at offset 0x26 03-04-2014 14:13:11.531 Debug dnsparser.cpp:229: Parsed domain name = sprout.bell-labs.net, encoded length = 2 03-04-2014 14:13:11.531 Debug dnsparser.cpp:282: Resource Record NAME=sprout.bell-labs.net TYPE=A CLASS=IN TTL=300 RDLENGTH=4 03-04-2014 14:13:11.531 Debug dnsparser.cpp:287: Parse A record RDATA 03-04-2014 14:13:11.531 Debug dnsparser.cpp:121: Parsing NS record 1 at offset 0x36 03-04-2014 14:13:11.531 Debug dnsparser.cpp:229: Parsed domain name = bell-labs.net, encoded length = 2 03-04-2014 14:13:11.531 Debug dnsparser.cpp:282: Resource Record NAME=bell-labs.net TYPE=NS CLASS=IN TTL=3600 RDLENGTH=5 03-04-2014 14:13:11.531 Debug dnsparser.cpp:130: Parsing additional record 1 at offset 0x47 03-04-2014 14:13:11.531 Debug dnsparser.cpp:229: Parsed domain name = ns.bell-labs.net, encoded length = 2 03-04-2014 14:13:11.531 Debug dnsparser.cpp:282: Resource Record NAME=ns.bell-labs.net TYPE=A CLASS=IN TTL=3600 RDLENGTH=4 03-04-2014 14:13:11.531 Debug dnsparser.cpp:287: Parse A record RDATA 03-04-2014 14:13:11.531 Debug dnsparser.cpp:130: Parsing additional record 2 at offset 0x57 03-04-2014 14:13:11.531 Debug dnsparser.cpp:229: Parsed domain name = ns.bell-labs.net, encoded length = 2 03-04-2014 14:13:11.531 Debug dnsparser.cpp:282: Resource Record NAME=ns.bell-labs.net TYPE=AAAA CLASS=IN TTL=3600 RDLENGTH=16 03-04-2014 14:13:11.531 Debug dnsparser.cpp:298: Parse AAAA record RDATA 03-04-2014 14:13:11.531 Debug dnsparser.cpp:142: Answer records sprout.bell-labs.net 300 IN A 199.22.0.7 03-04-2014 14:13:11.531 Debug dnsparser.cpp:143: Authority records bell-labs.net 3600 IN NS 03-04-2014 14:13:11.531 Debug dnsparser.cpp:144: Additional records ns.bell-labs.net 3600 IN A 199.22.0.7 ns.bell-labs.net 3600 IN AAAA 1::1 03-04-2014 14:13:11.531 Debug dnscachedresolver.cpp:575: Adding record to cache entry, TTL=300, expiry=1396534691 03-04-2014 14:13:11.531 Debug dnscachedresolver.cpp:579: Update cache entry expiry to 1396534691 03-04-2014 14:13:11.531 Debug dnscachedresolver.cpp:575: Adding record to cache entry, TTL=3600, expiry=1396537991 03-04-2014 14:13:11.531 Debug dnscachedresolver.cpp:579: Update cache entry expiry to 1396537991 03-04-2014 14:13:11.531 Debug dnscachedresolver.cpp:526: Adding ns.bell-labs.net to cache expiry list with expiry time of 1396537991 03-04-2014 14:13:11.531 Debug dnscachedresolver.cpp:575: Adding record to cache entry, TTL=3600, expiry=1396537991 03-04-2014 14:13:11.531 Debug dnscachedresolver.cpp:579: Update cache entry expiry to 1396537991 03-04-2014 14:13:11.531 Debug dnscachedresolver.cpp:526: Adding ns.bell-labs.net to cache expiry list with expiry time of 1396537991 03-04-2014 14:13:11.531 Debug dnscachedresolver.cpp:526: Adding sprout.bell-labs.net to cache expiry list with expiry time of 1396534691 03-04-2014 14:13:11.531 Debug dnscachedresolver.cpp:158: Received all query responses 03-04-2014 14:13:11.531 Debug dnscachedresolver.cpp:178: Pulling 1 records from cache for sprout.bell-labs.net A 03-04-2014 14:13:11.531 Debug baseresolver.cpp:353: Found 1 A/AAAA records, randomizing 03-04-2014 14:13:11.531 Debug baseresolver.cpp:374: Added a server, now have 1 of 5 03-04-2014 14:13:11.531 Debug baseresolver.cpp:412: Adding 0 servers from blacklist 03-04-2014 14:13:11.531 Info pjutils.cpp:753: Resolved destination URI sip:sprout.bell-labs.net:5052;transport=TCP;lr;orig to 1 servers 03-04-2014 14:13:11.531 Debug basicproxy.cpp:1428: Sending request for sip:bell-labs.net 03-04-2014 14:13:11.531 Debug pjsip: tsx0x7fe2f8006 Sending Request msg REGISTER/cseq=1 (tdta0x7fe2f80046e0) in state Null 03-04-2014 14:13:11.531 Debug pjsip: endpoint Request msg REGISTER/cseq=1 (tdta0x7fe2f80046e0): skipping target resolution because address is already set 03-04-2014 14:13:11.531 Verbose pjsip: tcpc0x7fe2f801 TCP client transport created 03-04-2014 14:13:11.532 Verbose pjsip: tcpc0x7fe2f801 TCP transport 199.22.0.7:48841 is connecting to 199.22.0.7:5052... 03-04-2014 14:13:11.532 Verbose pjsip: tcplis:5052 TCP listener 199.22.0.7:5052: got incoming TCP connection from 199.22.0.7:48841, sock=106 Olivier DURECU Bell Labs / IP Platform Research Villarceaux Center Tel: +33(0) 130772759 GSM: +33(0) 683776482 -----Message d'origine----- De : James Coleman [mailto:[email protected]] Envoyé : jeudi 3 avril 2014 17:26 À : DURECU, OLIVIER (OLIVIER) Cc : [email protected] Objet : Re: [Clearwater] Looping Register at SPROUT Hi Olivier, If you could send on more information it might help? What is in your sprout log (/var/log/sprout/sprout_*.txt)? What does your REGISTER message look like as it is passed on? You could increase the log_level of sprout by changing /etc/init.d/sprout start script (set to 4 and you get much more logs). ? James. On 3 April 2014 15:29, DURECU, OLIVIER (OLIVIER) <[email protected]> wrote: > Hello > > I am testing a fresh install of ClearWater and I can’t manager to > Register > > Bono forwards it to Sprout (i-cscf) by adding a route sip:sprout:5052 > Sprout doesn’t remove the route from the message, reads it and > forwards the message to itself on port 5052 indefinitely… > > Any idea of the problem ? > > Olivier DURECU > Bell Labs / IP Platform Research > Villarceaux Center > Tel: +33(0) 130772759 > GSM: +33(0) 683776482 > > > > > _______________________________________________ > Clearwater mailing list > [email protected] > http://lists.projectclearwater.org/listinfo/clearwater > -- <http://www.linkedin.com/company/76647?trk=fc_badge> openmindnetworks.com _______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater _______________________________________________ Clearwater mailing list [email protected] http://lists.projectclearwater.org/listinfo/clearwater
