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.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}
Mar 19 10:46:28 [11850] DBG:core:get_hdr_field: <To> [25]; uri=[sip:bob@test.ims.com]
Mar 19 10:46:28 [11850] DBG:core:get_hdr_field: to body [<sip:bob@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
==================
--
S.