[SR-Users] MSILO add on deliver event route still no joy

[Roberto Fichera]

On 06/10/2014 12:40 PM, Roberto Fichera wrote:

Hi,

> On 06/10/2014 12:22 PM, Daniel-Constantin Mierla wrote:
>
> Hi,
>
>>
>> On 10/06/14 10:37, Roberto Fichera wrote:
>>> [..]
>>>> the parse from error don't seem to be from parse_msg().
>>>>
>>>> Can you print the uac buffer and send it over here to see if it is something wrong there?
>>>
>>> Jun 10 09:32:29 ip-10-227-0-26.localdomain /usr/sbin/kamailio[29663]: DEBUG: msilo [msilo.c:1403]:
>>> m_tm_callback_on_delivered_event(): t->uac[0].request.buffer: MESSAGE sip:test1 at test.com SIP/2.0
>>>
>>> I've used LM_DBG()  to print it.
>> Can you paste here the full LM_DBG line? It prints only the first line. Maybe you can print also the length of the
>> buffer which is a special field just to see its value.
>
> this is what journalctl -xfa is printing out. Likely it is truncating the output.

This is what the t->uac[0].request.buffer has in the callback:

MESSAGE sip:test1 at test.com SIP/2.0
Via: SIP/2.0/UDP xx.xx.xx.xx:5060;branch=z9hG4bK6c43.66304147000000000000000000000000.0
To: <sip:test1 at test.com>
From: <sip:test2 at test.com>;tag=90a2f67ea18c2dbc1dd6d5c5f690acb0-5ca3
CSeq: 10 MESSAGE
Call-ID: 3f7b9fdc-4789 at 10.227.0.26
Max-Forwards: 70
Content-Length: 18
User-Agent: kamailio (4.1.3 (i386/linux))
Date: Wed, 11 Jun 2014 13:59:48 GMT
Content-Type: text/chat
DICE-Msg-Id: 332a0c12-82c5-4bac-ab3f-80626ebfa108
MSILO: true

test message


while the log shown:

Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: <core> [parser/msg_parser.c:192]:
get_hdr_field(): DEBUG: to body [<sip:test1 at test.com>]
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: <core> [parser/msg_parser.c:170]:
get_hdr_field(): get_hdr_field: cseq <CSeq>: <10> <MESSAGE>
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: tm [t_lookup.c:949]: t_reply_matching():
DEBUG: t_reply_matching: hash 59261 label 0 branch 0
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: tm [t_lookup.c:1004]: t_reply_matching():
DEBUG: t_reply_matching: reply matched (T=0xb2fc5bfc)!
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: tm [t_lookup.c:1141]: t_check_msg(): DEBUG:
t_check_msg: msg id=1 global id=1 T end=0xb2fc5bfc
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: tm [t_reply.c:2206]: reply_received():
DEBUG: reply_received: org. status uas=0, uac[0]=0 local=2 is_invite=0)
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: tm [t_reply.c:1304]:
t_should_relay_response(): ->>>>>>>>> T_code=0, new_code=200
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: tm [t_reply.c:2086]: local_reply(): DEBUG:
local_reply: branch=0, save=0, winner=0
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: tm [t_reply.c:2123]: local_reply(): DEBUG:
local transaction completed
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: tm [t_hooks.c:288]:
run_trans_callbacks_internal(): DBG: trans=0xb2fc5bfc, callback type 1024, id 0 entered
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: msilo [msilo.c:1378]:
m_tm_callback_on_delivered_event(): >>>>>>> msilo_notification_event 0xb30a4e14
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: msilo [msilo.c:1380]:
m_tm_callback_on_delivered_event(): completed with status 200 [mid: 157]
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: msilo [msilo.c:1393]:
m_tm_callback_on_delivered_event(): message <157> was sent successfully
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: msilo [ms_msg_list.c:236]:
msg_list_set_flag(): mid:157 fl:4
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: <core> [parser/msg_parser.c:623]:
parse_msg(): SIP Request:
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: <core> [parser/msg_parser.c:625]:
parse_msg():  method:  <MESSAGE>
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: <core> [parser/msg_parser.c:627]:
parse_msg():  uri:     <sip:test1 at test.com>
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: <core> [parser/msg_parser.c:629]:
parse_msg():  version: <SIP/2.0>
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: msilo [msilo.c:1412]:
m_tm_callback_on_delivered_event(): executing event_route[msilo:on-delivered] (1)
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: msilo [msilo.c:1419]:
m_tm_callback_on_delivered_event(): event_route[msilo:on-delivered] req=0xbfcbbdd0)
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: ERROR: <core> [parser/parse_from.c:58]:
parse_from_header(): ERROR:parse_from_header: bad msg or missing FROM header
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: ERROR: pv [pv_core.c:449]: pv_get_from_attr():
cannot parse From header
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: INFO: <script>: MSILO event on-delivered <<null>>
to <sip:test1 at test.com>
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: INFO: <script>: AVP(MSILO)=<null>
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: INFO: <script>: AVP(DICE-Msg-Id)=<null>
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: tm [t_reply.c:1663]: cleanup_uac_timers():
DEBUG: cleanup_uac_timers: RETR/FR timers reset
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: <core> [usr_avp.c:644]: destroy_avp_list():
DEBUG:destroy_avp_list: destroying list (nil)
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: <core> [xavp.c:448]: xavp_destroy_list():
destroying xavp list (nil)
Jun 11 15:06:24 ip-10-227-0-26.localdomain /usr/sbin/kamailio[4895]: DEBUG: <core> [receive.c:296]: receive_msg():
receive_msg: cleaning up


Cheers,
Roberto Fichera.

>
>>
>> Cheers,
>> Daniel
>>
>>>
>>>> You get a crash as well, very likely due to the shm free at the end.
>>>
>>> The rest of the code hasn't changed, so I kept all the shm_malloc(), actually I do not expect
>>> them to fail.
>>>
>>> Cheers,
>>> Roberto Fichera.
>>
>> -- 
>> Daniel-Constantin Mierla - http://www.asipto.com
>> http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
>>
>>
>> _______________________________________________
>> SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
>> sr-users at lists.sip-router.org
>> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
>
>
>
> _______________________________________________
> SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
> sr-users at lists.sip-router.org
> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20140611/49a3a198/attachment.html>