On Thu, Mar 19, 2009 at 12:18 PM, Henning Westerholt < henning.westerholt@1und1.de> wrote:
Hi Sara,
ok, take a look to the plain output from strace, without the grep command. Does it shows any errors from a file open, or a stat? Probably stupid question, but do you've the strace command installed?
Cheers,
Henning
Hello Henning,
I do have strace :-) Yesterday i tried it with and without the grep part, and there was no error. So i did some IMS presence service tests... And Kamailio couldn't process a "SIP PUBLISH" because of an error "*ERROR 600 : Busy everywhere - Forwarding to S-CSCF failed*". For your information, i'm using the Fokus OpenIms Core as an ims server, and Kamailio as a presence server. An IFC (Initial Filter Criteria) is set up in OpenIms to route properly the presence messages to Kamailio. And by the way, i saw some lines in the logs about /tmp/kamailio_fifo opening successfully...
Today, i launch the strace command and gess what... i'm getting the /tmp/kamailio_fifo opening error. Still a new kamailio_fifo is created indeed in my /tmp directory. And well, i am encountering the "busy everywhere" error again...
Have anyone ever noticed the error 600? And what about the mi_fifo error that appears half the time?
PS: Here you are some parts of the logs, and you can have a look at the attached file for the entire trace.
====LOG PARTS====
1/ Error 600 : busy everywhere (in kamailio start)
*Mar 19 10:46:28 [11850] DBG:core:parse_msg: SIP Request: Mar 19 10:46:28 [11850] DBG:core:parse_msg: method: <PUBLISH> Mar 19 10:46:28 [11850] DBG:core:parse_msg: uri: <sip:bob@test.ims.comsip%3Abob@test.ims.com
Mar 19 10:46:28 [11850] DBG:core:parse_msg: version: <SIP/2.0> Mar 19 10:46:28 [11850] DBG:core:parse_headers: flags=2 Mar 19 10:46:28 [11850] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKa813.b002d4e4.0>; state=16 Mar 19 10:46:28 [11850] DBG:core:parse_via: end of header reached, state=5 Mar 19 10:46:28 [11850] DBG:core:parse_headers: via found, flags=2 Mar 19 10:46:28 [11850] DBG:core:parse_headers: this is the first via Mar 19 10:46:28 [11850] DBG:core:receive_msg: After parse_msg... Mar 19 10:46:28 [11850] DBG:core:receive_msg: preparing to run routing scripts... Mar 19 10:46:28 [11850] DBG:core:parse_headers: flags=100 Mar 19 10:46:28 [11850] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKa813.41769183.0>; state=16 Mar 19 10:46:28 [11850] DBG:core:parse_via: end of header reached, state=5 Mar 19 10:46:28 [11850] DBG:core:parse_headers: via found, flags=100 Mar 19 10:46:28 [11850] DBG:core:parse_headers: parse_headers: this is the second via Mar 19 10:46:28 [11850] DBG:core:parse_via_param: found param type 235, <rport> = <5060>; state=6 Mar 19 10:46:28 [11850] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK315224847>; state=16 Mar 19 10:46:28 [11850] DBG:core:parse_via: end of header reached, state=5 Mar 19 10:46:28 [11850] DBG:core:parse_headers: via found, flags=100 Mar 19 10:46:28 [11850] DBG:core:parse_to: end of header reached, state=10 Mar 19 10:46:28 [11850] DBG:core:parse_to: display={}, ruri={ sip:bob@test.ims.com sip%3Abob@test.ims.com} Mar 19 10:46:28 [11850] DBG:core:get_hdr_field: <To> [25]; uri=[** sip:bob@test.ims.com sip%3Abob@test.ims.com**] Mar 19 10:46:28 [11850] DBG:core:get_hdr_field: to body [<** sip:bob@test.ims.com sip%3Abob@test.ims.com**> ] Mar 19 10:46:28 [11850] DBG:core:get_hdr_field: cseq <CSeq>: <20> <PUBLISH> Mar 19 10:46:28 [11850] DBG:maxfwd:is_maxfwd_present: value = 15 Mar 19 10:46:28 [11850] DBG:uri:has_totag: no totag Mar 19 10:46:28 [11850] DBG:core:parse_headers: flags=78 Mar 19 10:46:28 [11850] DBG:tm:t_lookup_request: start searching: hash=12682, isACK=0 Mar 19 10:46:28 [11850] DBG:tm:matching_3261: RFC3261 transaction matched, tid=a813.b002d4e4.0 Mar 19 10:46:28 [11850] DBG:tm:t_lookup_request: REF_UNSAFE: after is 1 Mar 19 10:46:28 [11850] DBG:tm:t_lookup_request: transaction found (T=0xb5a0d430) Mar 19 10:46:28 [11850] DBG:tm:t_retransmit_reply: nothing to retransmit Mar 19 10:46:28 [11850] DBG:tm:t_check_trans: UNREF_UNSAFE: after is 0 Mar 19 10:46:28 [11850] DBG:core:destroy_avp_list: destroying list (nil) Mar 19 10:46:28 [11850] DBG:core:receive_msg: cleaning up Mar 19 10:46:31 [11852] DBG:core:parse_msg: SIP Reply (status): Mar 19 10:46:31 [11852] DBG:core:parse_msg: version: <SIP/2.0> Mar 19 10:46:31 [11852] DBG:core:parse_msg: status: <600> Mar 19 10:46:31 [11852] DBG:core:parse_msg: reason: <Busy everywhere - Forwarding to S-CSCF failed> Mar 19 10:46:31 [11852] DBG:core:parse_headers: flags=2 Mar 19 10:46:31 [11852] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKa813.192cfef5.0>; state=16 Mar 19 10:46:31 [11852] DBG:core:parse_via: end of header reached, state=5*
2/ /tmp/kamailio_fifo opening error (with strace kamctl)
*rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 stat64("/tmp/kamailio_fifo", {st_mode=S_IFIFO|0660, st_size=0, ...}) = 0 geteuid32() = 1000 getegid32() = 1000 getuid32() = 1000 getgid32() = 1000 access("/tmp/kamailio_fifo", W_OK) = -1 EACCES (Permission denied) rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 ioctl(1, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 write(1, "\33[37;31m\33[1mERROR: Error opening"..., 72ERROR: Error opening Kamailio's FIFO /tmp/kamailio_fifo ) = 72 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 ioctl(1, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 brk(0x9302000) = 0x9302000 write(1, "\33[37;31m\33[1mERROR: Make sure you"..., 123ERROR: Make sure you have the line 'modparam("mi_fifo", "fifo_name", "/tmp/kamailio_fifo")' in your config ) = 123 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 ioctl(1, SNDCTL_TMR_TIMEBASE or TCGETS, {B38400 opost isig icanon echo ...}) = 0 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 write(1, "\33[37;31m\33[1mERROR: and also have"..., 64ERROR: and also have loaded the mi_fifo module. ) = 64 rt_sigprocmask(SIG_BLOCK, NULL, [], 8) = 0 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 exit_group(2) = ? Process 12215 detached*
==================