Hi Bogdan,
I solved the problem with SER startup. The reason was that I download the CVS head onto my notebook and copy it via ftp to the linux server. After downloading CVS head directly onto the linux server, compiling and installing it SER starts up without any error message.
But I have still the problem with call forwarding on busy or no answer. Inserting log information into my CPL script I can reproduce that SER is never processing the <busy> or <noanswer> tag and the following tags. I try out the example script from the current IETF CPL draft for Call Forward Busy/No Answer in the following scenario:
6131 forwards calls to 613 if busy -> 6131 has an active session with 614 -> 612 calls 6131 -> 6131 is busy and SER should invite 613
After uploading the CPL script for 6131 the caller 614 cannot reach 6131 and the syslog represents the attached error message.
Can you identify any mistake I've done in my configuration? Many thanks.
Best Regards,
Oliver
Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: cpl: start script processing now Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl-c:get_dest_user: tring to get user from new_uri Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl-c:get_dest_user: tring to get user from R_uri Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:get_user_script: fetching script for user 6131@10.0.60.2 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:get_user_script: we got the script len=90 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl_run_script: processing CPL node Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl_run_script: processing location node Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl_run_script: processing proxy node Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: parse_headers: flags=16777216 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: parse_headers: flags=4194304 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: parse_headers: flags=33554432 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: parse_headers: flags=2097152 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: parse_headers: flags=8388608 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG: t_newtran: msg id=2 , global msg id=0 , T on entrance=0xffffffff Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: parse_headers: flags=-1 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: parse_headers: flags=60 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: t_lookup_request: start searching: hash=57364, isACK=0 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG: proceeding to pre-RFC3261 transaction matching Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG: t_lookup_request: no transaction found Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG: t_check: msg id=2 global id=2 T start=0x402ef820 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG: t_check: T alredy found! Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl_c:cpl_proxy_to_loc_set: rewriting Request-URI with sip:6131@10.0.60.2 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG: t_newtran: msg id=2 , global msg id=2 , T on entrance=0x402ef820 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: ERROR: t_newtran: transaction already in process 0x402ef820 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: parse_headers: flags=-1 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: check_via_address(10.0.61.4, 10.0.61.4, 0) Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: ERROR: sl_reply_error used: I'm terribly sorry, server error occured (1/SL) Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG: t_check: msg id=2 global id=2 T start=0x402ef820 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG: t_check: T alredy found! Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG: mk_proxy: doing DNS lookup... Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: check_via_address(10.0.61.4, 10.0.61.4, 0) Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2088]: SIP Request: Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2088]: method: <INVITE> Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2088]: uri: sip:6131@10.0.60.2 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2088]: version: <SIP/2.0> Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2088]: parse_headers: flags=1 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2088]: Found param type 232, <branch> = <z9hG4bK410e.de7825a6.0>; state=16 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2088]: end of header reached, state=5 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2088]: parse_headers: Via found, flags=1 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2088]: parse_headers: this is the first via Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2088]: After parse_msg... Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2088]: preparing to run routing scripts... Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2088]: DEBUG : is_maxfwd_present: max_forward header already found! Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2088]: DEBUG: is_maxfwd_present: value = 10 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2088]: parse_headers: flags=8 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2088]: end of header reached, state=5 sipproxy1:/var/log # less messages | grep cpl Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: cpl: start script processing now Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl-c:get_dest_user: tring to get user from new_uri Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl-c:get_dest_user: tring to get user from R_uri Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl_run_script: processing CPL node Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl_run_script: processing location node Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl_run_script: processing proxy node Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl_c:cpl_proxy_to_loc_set: rewriting Request-URI with sip:6131@10.0.60.2 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2088]: cpl: start script processing now Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2088]: DEBUG:cpl-c:get_dest_user: tring to get user from new_uri Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2088]: DEBUG:cpl-c:get_dest_user: tring to get user from R_uri Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2088]: DEBUG:cpl_run_script: processing CPL node Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2088]: DEBUG:cpl_run_script: processing location node Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2088]: DEBUG:cpl_run_script: processing proxy node Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2088]: DEBUG:cpl_c:cpl_proxy_to_loc_set: rewriting Request-URI with sip:6131@10.0.60.2 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2094]: DEBUG:cpl-c:negativ_reply: ------------------------------> ---------------------------------> negativ reply receive Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2094]: DEBUG:cpl-c:failed_reply:final_reply: got a final 500 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2094]: DEBUG:cpl-c:final_reply: code=500 --------------> --------------------------> final reply received Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2100]: cpl: start script processing now Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2100]: DEBUG:cpl-c:get_dest_user: tring to get user from new_uri Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2100]: DEBUG:cpl-c:get_dest_user: tring to get user from R_uri Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2100]: DEBUG:cpl_run_script: processing CPL node Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2100]: DEBUG:cpl_run_script: processing location node Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2100]: DEBUG:cpl_run_script: processing proxy node Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2100]: DEBUG:cpl_c:cpl_proxy_to_loc_set: rewriting Request-URI with sip:6131@10.0.60.2 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2097]: DEBUG:cpl-c:negativ_reply: ------------------------------> ---------------------------------> negativ reply receive Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2097]: DEBUG:cpl-c:failed_reply:final_reply: got a final 500 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2097]: DEBUG:cpl-c:final_reply: code=500 --------------> --------------------------> final reply received Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2091]: cpl: start script processing now Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2091]: DEBUG:cpl-c:get_dest_user: tring to get user from new_uri Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2091]: DEBUG:cpl-c:get_dest_user: tring to get user from R_uri Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2091]: DEBUG:cpl_run_script: processing CPL node Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2091]: DEBUG:cpl_run_script: processing location node Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2091]: DEBUG:cpl_run_script: processing proxy node Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2091]: DEBUG:cpl_c:cpl_proxy_to_loc_set: rewriting Request-URI with sip:6131@10.0.60.2 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl_c:cpl_run_script: done for the moment; waiting after signaling! Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl-c:negativ_reply: ------------------------------> ---------------------------------> negativ reply receive Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl-c:failed_reply:final_reply: got a final 500 Jun 24 11:36:22 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl-c:final_reply: code=500 --------------> --------------------------> final reply received Jun 24 11:36:23 sipproxy1 /usr/local/sbin/ser[2088]: DEBUG:cpl_c:cpl_run_script: done for the moment; waiting after signaling! Jun 24 11:36:23 sipproxy1 /usr/local/sbin/ser[2078]: cpl: start script processing now Jun 24 11:36:23 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl-c:get_dest_user: tring to get user from new_uri Jun 24 11:36:23 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl-c:get_dest_user: tring to get user from R_uri Jun 24 11:36:23 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl_run_script: processing CPL node Jun 24 11:36:23 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl_run_script: processing location node Jun 24 11:36:23 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl_run_script: processing proxy node Jun 24 11:36:23 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl_c:cpl_proxy_to_loc_set: rewriting Request-URI with sip:6131@10.0.60.2 Jun 24 11:36:23 sipproxy1 /usr/local/sbin/ser[2100]: DEBUG:cpl_c:cpl_run_script: done for the moment; waiting after signaling! Jun 24 11:36:23 sipproxy1 /usr/local/sbin/ser[2085]: cpl: start script processing now Jun 24 11:36:23 sipproxy1 /usr/local/sbin/ser[2085]: DEBUG:cpl-c:get_dest_user: tring to get user from new_uri Jun 24 11:36:23 sipproxy1 /usr/local/sbin/ser[2085]: DEBUG:cpl-c:get_dest_user: tring to get user from R_uri Jun 24 11:36:23 sipproxy1 /usr/local/sbin/ser[2085]: DEBUG:cpl_run_script: processing CPL node Jun 24 11:36:23 sipproxy1 /usr/local/sbin/ser[2085]: DEBUG:cpl_run_script: processing location node Jun 24 11:36:23 sipproxy1 /usr/local/sbin/ser[2085]: DEBUG:cpl_run_script: processing proxy node Jun 24 11:36:23 sipproxy1 /usr/local/sbin/ser[2085]: ERROR:cpl-c:run_proxy: processed INVITE is a retransmission! Jun 24 11:36:23 sipproxy1 /usr/local/sbin/ser[2085]: DEBUG:cpl_c:cpl_run_script: script interpretation done! Jun 24 11:36:23 sipproxy1 /usr/local/sbin/ser[2100]: DEBUG:cpl-c:negativ_reply: ------------------------------> ---------------------------------> negativ reply receive Jun 24 11:36:23 sipproxy1 /usr/local/sbin/ser[2100]: DEBUG:cpl-c:failed_reply:final_reply: got a final 500 Jun 24 11:36:23 sipproxy1 /usr/local/sbin/ser[2100]: DEBUG:cpl-c:final_reply: code=500 --------------> --------------------------> final reply received Jun 24 11:36:23 sipproxy1 /usr/local/sbin/ser[2078]: DEBUG:cpl_c:cpl_run_script: done for the moment; waiting after signaling!
Bogdan-Andrei IANCU [mailto:iancu@fokus.fraunhofer.de] wrote
Hi Oliver,
There is nothing wrong with SER and you should use the CVS head version. The problem is in your configuration file - looks like you have some strange string (missing " ?) on the first line.
Bogdan
Brinker, Oliver wrote:
Hi Bogdan,
I've download everything from CVS head, compile it and try to run the SER with the basic config file (no database, authentication and cpl support), but I get the following error message in my syslog
Jun 8 15:46:44 sipproxy1 ser: parse error (1,1-2): parse error Jun 8 15:46:44 sipproxy1 ser: ERROR: cfg. parser: unexpected EOF in unclosed string
... and on the command line together with the whole ser.cfg content
ERROR: bad config file (1 errors)
I leave the ser.cfg unchanged because I want to try out the new installation first. After getting these error message I check other versions from CVS (v_0_8_13-dev-29, v_0_8_13dev-t16 ...) but the problem is the same as before. Compilation ist no problem. Which CVS version is the best for me to download? Many thanks for your help.
Regards, Oliver
Hi Oliver,
please send me your ser.cfg - it will help me to trace the problem. Also be sure you are using the latest cvs head version - there were some updates 1 or 2 weeks ago.
Regards, Bogdan
Brinker, Oliver wrote:
Hi Bogdan,
I solved the problem with SER startup. The reason was that I download the CVS head onto my notebook and copy it via ftp to the linux server. After downloading CVS head directly onto the linux server, compiling and installing it SER starts up without any error message.
But I have still the problem with call forwarding on busy or no answer. Inserting log information into my CPL script I can reproduce that SER is never processing the <busy> or <noanswer> tag and the following tags. I try out the example script from the current IETF CPL draft for Call Forward Busy/No Answer in the following scenario:
6131 forwards calls to 613 if busy -> 6131 has an active session with 614 -> 612 calls 6131 -> 6131 is busy and SER should invite 613
After uploading the CPL script for 6131 the caller 614 cannot reach 6131 and the syslog represents the attached error message.
Can you identify any mistake I've done in my configuration? Many thanks.
Best Regards,
Oliver