[SR-Users] Errors issued by Kamailio

Daniel-Constantin Mierla miconda at gmail.com
Mon Oct 15 09:16:12 CEST 2012 

This path does not look ok:

/xmlns:resource-lists/xmlns:list%5B at name="rcs"%5D

Where is it coming from?

Cheers,
Daniel

On 10/10/12 4:50 PM, Sangeeta Shah wrote:
> Any clue what the correct path is supposed to be - per the data in the
> xml and the path that's printed out by the module?
>
> Thanks,
> Sangeeta
>
> On Tue, Oct 9, 2012 at 2:38 PM, Sangeeta Shah <sangeeta.shah at gmail.com> wrote:
>> Daniel,
>>     I don't know if this corresponds to the errors I was seeing before.
>> But on a closer look I see the following errors when a subscribe
>> request comes in. This is how I am handling subscribe requests:
>>
>> if( is_method("SUBSCRIBE"))
>>          {
>>                  xdbg("======== Handling subscribe request ==== \n");
>>                   $var(ret_code) = rls_handle_subscribe();
>>                  xdbg("========= RLS Handle subscriber returned with
>> ret code: $var(ret_code) ===\n");
>>                  if ($var(ret_code) == 10)
>>                     xdbg("======== Calling Handle subscribe ===== \n");
>>                     handle_subscribe();
>>                  t_release();
>>          }
>>
>> The resource list XML seems fine to me. But I am not sure if this is correct:
>>   path: /xmlns:resource-lists/xmlns:list%5B at name="rcs"%5D
>>
>> Data from the log file:
>>
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> rls [notify.c:1031]: fetching local <resource-list/>
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24762]: DEBUG:
>> db_mysql [km_res.c:85]: allocate 16 bytes for RES_NAMES[0] at
>> 0x7f75730a3800
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> rls [notify.c:1228]: rl_uri:
>> /xcap-root/resource-lists/users/sip:8475551004 at myip/index/~~/resource-lists/list%5B at name=%22rcs%22%5D
>>
>>
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> rls [notify.c:1242]: doc:
>> /xcap-root/resource-lists/users/sip:8475551004 at myip/index
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24762]: DEBUG:
>> db_mysql [km_res.c:121]: use DB1_BLOB result type
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> rls [notify.c:1276]: path:
>> /xmlns:resource-lists/xmlns:list%5B at name="rcs"%5D
>>
>>
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> rls [notify.c:1350]: rl document:#012<?xml
>> version="1.0"?>#012<resource-lists xmlns="urn:iet
>> f:params:xml:ns:resource-lists">#012  <list name="rcs">#012
>> <display-name>All Contacts</display-name>#012    <external
>> anchor="http://myip:5060/xcap-r
>> oot/resource-lists/users/sip:8475551004 at myip/index/~~/resource-lists/list%5B at name=%22doubango%22%5D"/>#012
>>     #012  </list>#012  <list name="rcs_blockedc
>> ontacts">#012    <display-name>Blocked Contacts</display-name>#012
>> </list>#012  <list name="rcs_revokedcontacts">#012
>> <display-name>Revoked Contacts</display
>> -name>#012  </list>#012  <list name="oma_allcontacts">#012
>> <display-name>OMA All Contacts</display-name>#012  </list>#012  <list
>> name="oma_blockedcontacts">#0
>> 12    <display-name>OMA Blocked Contacts</display-name>#012
>> <external anchor="http://myip:5060/xcap-root/resource-lists/users/sip:8475551004@10.50.251
>> .12/index/~~/resource-lists/list%5B at name=%22rcs_blockedcontacts%22%5D"/>#012
>>     <external anchor="http://myip:5060/xcap-root/resource-lists/users/sip:847
>> 5551004 at myip/index/~~/resource-lists/list%5B at name=%22rcs_revokedcontacts%22%5D"/>#012
>>   </list>#012  <list name="oma_buddylist">#012    <display-name>OMA
>> BuddyList</display-name>#012    <external
>> anchor="http://myip:5060/xcap-root/resource-lists/users/sip:8475551004@myip/index/~~/resource-lists/lis
>> t%5B at name=%22rcs%22%5D"/>#012    <external
>> anchor="http://myip:5060/xcap-root/resource-lists/users/sip:8475551004@myip/index/~~/resource-lists/li
>> st%5B at name=%22oma_pocbuddylist%22%5D"/>#012  </list>#012  <list
>> name="oma_grantedcontacts">#012    <display-name>OMA Granted
>> Contacts</display-name>#012    <exte
>> rnal anchor="http://myip:5060/xcap-root/resource-lists/users/sip:8475551004@myip/index/~~/resource-lists/list%5B@name=%22rcs%22%5D"/>#012
>>     <ext
>> ernal anchor="http://myip:5060/xcap-root/resource-lists/users/sip:8475551004@myip/index/~~/resource-lists/li
>>
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: ERROR:
>> rls [notify.c:1386]: unable to evaluate path
>>
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: ERROR:
>> rls [subscribe.c:732]: failed sending full state notify
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: ERROR:
>> rls [subscribe.c:781]: occured in rls_handle_subscribe
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> <script>: ========= RLS Handle subscriber returned with ret code: -1
>> ===
>>
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> <script>: ========= RLS Handle subscriber returned with ret code: -1
>> ===
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [event_list.c:351]: start event= [presence/1]
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [subscribe.c:1063]: 'Expires' header found, value= 600000
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [subscribe.c:1085]: 'To' header ALREADY PARSED:
>> <sip:8475551004 at myip;pres-l
>> ist=rcs>
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [subscribe.c:1156]: generating to_tag
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> sl [sl.c:327]: totag stateful mode (tm)
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [subscribe.c:1216]: subs->contact=
>> sip:8475551004 at 10.50.0.93:49515;transport=udp -
>> len = 45
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [subscribe.c:961]: subscription status= active - found in
>> watcher table
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [subscribe.c:538]: update subscription
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [notify.c:117]: pres_uri: sip:8475551004 at myip
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [notify.c:118]: watcher_user at watcher_domain: 8475551004 at myip
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [notify.c:119]: to_user at to_domain: 8475551004 at myip
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [notify.c:120]: from_user at from_domain: 8475551004 at myip
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [notify.c:121]: callid/from_tag/to_tag:
>> 0afe5565-8c8d-3012-4096-aff82200caf9/19038676/a6a1c5f60faecf035a1ae5b6e96e979a-a18a
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [notify.c:122]: local_cseq/remote_cseq: 0/24466
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [notify.c:123]: local_contact/contact:
>> sip:myip:5060;transport=udp/sip:8475551004 at 10.50.0.93:49515;transport=udp
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [notify.c:124]: record_route:
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [notify.c:125]: sockinfo_str: udp:myip:5060
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [notify.c:127]: event: presence
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [notify.c:128]: status: active
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [notify.c:129]: reason:
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [notify.c:130]: version: 1
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [notify.c:131]: expires: 3600
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [notify.c:133]: updated/updated_winfo: -1/-1
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [subscribe.c:613]: subscription not in dialog
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> presence [subscribe.c:618]: inserting in shtable
>>
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: ERROR:
>> tm [t_reply.c:589]: ERROR: _reply_light: can't generate 202 reply when
>> a final 200 was sent out
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> tm [t_reply.c:1543]: DEBUG: cleanup_uac_timers: RETR/FR timers reset
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> <core> [timer.c:595]: timer_add called on an active timer
>> 0x7f756cdae230 (0x7f756cad7988, 0x7f756cdb1a98), flags 201
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> tm [t_funcs.c:184]: tm: put_on_wait: transaction 0x7f756cdae1b0
>> already on wait
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: ERROR:
>> sl [sl.c:270]: failed to reply stateful (tm)
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: ERROR:
>> presence [subscribe.c:125]: sending reply
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: ERROR:
>> presence [subscribe.c:655]: sending 202 OK reply
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: ERROR:
>> presence [subscribe.c:707]: occured
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: ERROR:
>> presence [subscribe.c:974]: in update_subscription
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=5 global id=5 T
>> start=0x7f756cdae1b0
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> tm [t_lookup.c:1151]: DEBUG: t_check_msg: T already found!
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> <core> [msg_translator.c:206]: check_via_address(10.50.0.93,
>> 10.50.0.93, 0)
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: ERROR:
>> tm [t_reply.c:589]: ERROR: _reply_light: can't generate 500 reply when
>> a final 200 was sent out
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> tm [t_reply.c:1543]: DEBUG: cleanup_uac_timers: RETR/FR timers reset
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> <core> [timer.c:595]: timer_add called on an active timer
>> 0x7f756cdae230 (0x7f756cad7988, 0x7f756cdb1a98), flags 201
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: DEBUG:
>> tm [t_funcs.c:184]: tm: put_on_wait: transaction 0x7f756cdae1b0
>> already on wait
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: ERROR:
>> sl [sl.c:270]: failed to reply stateful (tm)
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: ERROR:
>> presence [utils_func.c:146]: sending 500 Server Internal Error reply
>> Oct  9 13:55:13 RCS-Presence /usr/local/sbin/kamailio[24739]: ERROR:
>> presence [subscribe.c:1014]: failed to send reply on error case
>>
>>
>>
>>
>> On Mon, Oct 8, 2012 at 5:24 PM, Daniel-Constantin Mierla
>> <miconda at gmail.com> wrote:
>>> Hello,
>>>
>>> the error messages seem to be due to a broken XML document in a NOTIFY --
>>> they are printed because of errors reported by libxml2 parser. Can you get a
>>> sip trace for such requests that throw these error messages in the log?
>>>
>>> Cheers,
>>> Daniel
>>>
>>>
>>> On 10/8/12 11:17 PM, Sangeeta Shah wrote:
>>>> Hi,
>>>>      I am seeing the following errors in syslog:
>>>>
>>>> Oct  8 16:21:54 RCS-Presence /usr/local/sbin/kamailio[6723]: ERROR:
>>>> presence_xml [notify_body.c:635]: while extracting tuple node
>>>> Oct  8 16:21:54 RCS-Presence /usr/local/sbin/kamailio[6723]: ERROR:
>>>> presence_xml [notify_body.c:75]: while constructing offline body
>>>> Oct  8 16:21:54 RCS-Presence /usr/local/sbin/kamailio[6723]: ERROR:
>>>> presence [presentity.c:1220]: preparing body
>>>> Oct  8 16:21:54 RCS-Presence /usr/local/sbin/kamailio[6723]: ERROR:
>>>> presence [publish.c:171]: Marking presentity
>>>> Oct  8 16:21:55 RCS-Presence /usr/local/sbin/kamailio[6734]: INFO:
>>>> presence [notify.c:1581]: NOTIFY sip:8475551004 at 10.50.251.12 via
>>>> sip:8475551004 at 10.50.0.93:60562;transport=udp on behalf of
>>>> sip:8475551004 at 10.50.251.12 for event message-summary
>>>> Oct  8 16:21:55 RCS-Presence /usr/local/sbin/kamailio[6734]: INFO:
>>>> presence [notify.c:1581]: NOTIFY sip:8475551004 at 10.50.251.12 via
>>>> sip:8475551004 at 10.50.0.93:60562;transport=udp on behalf of
>>>> sip:8475551004 at 10.50.251.12 for event presence.winfo
>>>> Oct  8 16:21:57 RCS-Presence /usr/local/sbin/kamailio[6734]: INFO:
>>>> presence [notify.c:1581]: NOTIFY sip:8475551004 at 10.50.251.12 via
>>>> sip:8475551004 at 10.50.0.93:60562;transport=udp on behalf of
>>>> sip:8475551004 at 10.50.251.12 for event presence
>>>>
>>>>
>>>> I am using Kamailio 3.3 with Presence and RLS with integrated XCAP.
>>>>
>>>> The only significant change i made today is update the presence and
>>>> RLS config to DB ONLY mode.
>>>>
>>>> Thanks,
>>>> Sangeeta
>>>>
>>> --
>>> Daniel-Constantin Mierla - http://www.asipto.com
>>> http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
>>> Kamailio Advanced Training, Berlin, Nov 5-8, 2012 - http://asipto.com/u/kat
>>> Kamailio Advanced Training, Miami, USA, Nov 12-14, 2012 -
>>> http://asipto.com/u/katu
>>>
>>
>>
>> --
>> Sangeeta Shah
>
>

-- 
Daniel-Constantin Mierla - http://www.asipto.com
http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
Kamailio Advanced Training, Berlin, Nov 5-8, 2012 - http://asipto.com/u/kat
Kamailio Advanced Training, Miami, USA, Nov 12-14, 2012 - http://asipto.com/u/katu

More information about the sr-users mailing list