15 Feb
2016
15 Feb
'16
8:50 p.m.
Hi,
I apologise if this is not the correct venue for such a question...
I am running kamailio v4.3.4 (x86_64/linux) on debian Jessie, sourced from;
deb http://deb.kamailio.org/kamailio jessie main
In my routing logic I am handling SUBSCRIBE requests and striping extra Event
package parameters appended to "ua-profile" event types. i.e.;
Event: ua-profile;model=somemodel;vendor=somevendor;profile-type=user
becomes;
Event: ua-profile
This is done with this code;
} else if( is_method("SUBSCRIBE")) {
subst('/ua-profile.*/ua-profile/') ;
handle_subscribe();
t_release();
However, in such conditions "search_event()" doesn't correctly find the
event.
Even though it looks like it is searching for the right event type;
start event= [ua-profile/7]
handle_subscribe(): unsupported presence event ua-profile
--- Begin debug ----
]3(7664) DEBUG: <core> [re.c:457]: subst_run(): matched (332, 79): [Event:
ua-profile;model=somemodel;vendor=somevendor;profile-type=user] with [Event:
ua-profile]extops.c:680]: subst_f(): textops: replacing at offset 376[Event:
ua-profile;model=somemodel;vendor=somevendor;profile-type=user]
13(7664) debug: textops [textops.c:696]: subst_f(): lst was 0x7fb391fd0da8
13(7664) error: *** cfgtrace:request_route=[presence] c=[/etc/kamailio/kamailio.cfg] l=365
a=24 n=handle_subscribe
13(7664) debug: presence [event_list.c:348]: search_event(): start event= [ua-profile/7]
13(7664) notice: presence [subscribe.c:1092]: handle_subscribe(): unsupported presence
event ua-profile
13(7664) debug: tm [t_lookup.c:1011]: t_check_msg(): debug: t_check_msg: msg id=1 global
id=1 t start=0x7fb388763290
13(7664) debug: tm [t_lookup.c:1083]: t_check_msg(): debug: t_check_msg: t already found!
13(7664) debug: <core> [mem/shm_mem.c:101]: _shm_resize(): warning:vqm_resize:
resize(0) called
13(7664) debug: tm [t_reply.c:1591]: cleanup_uac_timers(): debug: cleanup_uac_timers:
retr/fr timers reset
13(7664) debug: <core> [tcp_main.c:2196]: tcpconn_send_put(): send from reader (7664
(13)), reusing fd
13(7664) debug: <core> [tcp_main.c:2430]: tcpconn_do_send(): sending...
13(7664) debug: <core> [tcp_main.c:2464]: tcpconn_do_send(): after real write: c=
0x7fb38875ecf8 n=368 fd=9
13(7664) debug: <core> [tcp_main.c:2465]: tcpconn_do_send(): buf=
sip/2.0 489 bad event
via: sip/2.0/tcp
127.0.1.1:5060;branch=z9hg4bk-2999-1-0;rport=34679;received=192.168.88.88
cseq: 1 subscribe
call-id: 1-2999(a)127.0.1.1
from: <sip:c.vella@albourne.com>;tag=1
to: <sip:provisioning@albourne.com>;tag=a6a1c5f60faecf035a1ae5b6e96e979a-811a
--- End debug ---
As a test, I send another message with clean "Event: ua-profile" and this works
, event= [ua-profile/7] is found.
--- Begin debug ---
]4(7665) DEBUG: <core> [re.c:457]: subst_run(): matched (332, 18): [Event:
ua-profile
] with [Event: ua-profile]extops.c:680]: subst_f(): textops: replacing at offset 376
[Event: ua-profile
14(7665) DEBUG: textops [textops.c:696]: subst_f(): lst was 0x7fb391fd0da8
14(7665) ERROR: *** cfgtrace:request_route=[PRESENCE] c=[/etc/kamailio/kamailio.cfg] l=365
a=24 n=handle_subscribe
14(7665) DEBUG: presence [event_list.c:348]: search_event(): start event= [ua-profile/7]
14(7665) DEBUG: presence [subscribe.c:1161]: extract_sdialog_info_ex(): 'Expires'
header found, value= 3600
14(7665) DEBUG: presence [subscribe.c:1195]: extract_sdialog_info_ex(): 'To'
header ALREADY PARSED: <sip:provisioning@albourne.com>
14(7665) DEBUG: presence [subscribe.c:1266]: extract_sdialog_info_ex(): generating to_tag
14(7665) DEBUG: sl [sl.c:329]: get_reply_totag(): totag stateful mode (tm)
14(7665) DEBUG: presence [subscribe.c:1326]: extract_sdialog_info_ex(): subs->contact=
sip:c.vella@192.168.88.179:59206;transport=tcp - len = 46
14(7665) DEBUG: presence [subscribe.c:1043]: handle_subscribe(): subscription status=
active - inserted
14(7665) DEBUG: presence [subscribe.c:554]: update_subscription(): update subscription
14(7665) DEBUG: presence [notify.c:115]: printf_subs(): pres_uri:
sip:c.vella@albourne.com
14(7665) DEBUG: presence [notify.c:116]: printf_subs(): watcher_user@watcher_domain:
c.vella(a)albourne.com
14(7665) DEBUG: presence [notify.c:117]: printf_subs(): to_user@to_domain:
provisioning(a)albourne.com
14(7665) DEBUG: presence [notify.c:118]: printf_subs(): from_user@from_domain:
c.vella(a)albourne.com
14(7665) DEBUG: presence [notify.c:119]: printf_subs(): callid/from_tag/to_tag:
1-3002(a)127.0.1.1/1/a6a1c5f60faecf035a1ae5b6e96e979a-1030
14(7665) DEBUG: presence [notify.c:120]: printf_subs(): local_cseq/remote_cseq: 0/1
14(7665) DEBUG: presence [notify.c:121]: printf_subs(): local_contact/contact:
sip:192.168.88.85:5060;transport=tcp/sip:c.vella@192.168.88.179:59206;transport=tcp
14(7665) DEBUG: presence [notify.c:122]: printf_subs(): record_route:
14(7665) DEBUG: presence [notify.c:123]: printf_subs(): sockinfo_str:
tcp:192.168.88.85:5060
14(7665) DEBUG: presence [notify.c:125]: printf_subs(): event: ua-profile
14(7665) DEBUG: presence [notify.c:126]: printf_subs(): status: active
14(7665) DEBUG: presence [notify.c:127]: printf_subs(): reason:
14(7665) DEBUG: presence [notify.c:128]: printf_subs(): version: 1
14(7665) DEBUG: presence [notify.c:129]: printf_subs(): expires: 3600
14(7665) DEBUG: presence [notify.c:131]: printf_subs(): updated/updated_winfo: -1/-1
14(7665) DEBUG: presence [subscribe.c:629]: update_subscription(): subscription not in
dialog
14(7665) DEBUG: presence [subscribe.c:634]: update_subscription(): inserting in shtable
14(7665) DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=1 global
id=1 T start=0x7fb388763290
14(7665) DEBUG: tm [t_lookup.c:1083]: t_check_msg(): DEBUG: t_check_msg: T already found!
14(7665) DEBUG: <core> [mem/shm_mem.c:101]: _shm_resize(): WARNING:vqm_resize:
resize(0) called
14(7665) DEBUG: tm [t_reply.c:1591]: cleanup_uac_timers(): DEBUG: cleanup_uac_timers:
RETR/FR timers reset
14(7665) DEBUG: <core> [tcp_main.c:2196]: tcpconn_send_put(): send from reader (7665
(14)), reusing fd
14(7665) DEBUG: <core> [tcp_main.c:2430]: tcpconn_do_send(): sending...
14(7665) DEBUG: <core> [tcp_main.c:2464]: tcpconn_do_send(): after real write: c=
0x7fb38875ecf8 n=399 fd=9
14(7665) DEBUG: <core> [tcp_main.c:2465]: tcpconn_do_send(): buf=
SIP/2.0 202 OK
Via: SIP/2.0/TCP
127.0.1.1:5060;branch=z9hG4bK-3002-1-0;rport=34680;received=192.168.88.88
CSeq: 1 SUBSCRIBE
Call-ID: 1-3002(a)127.0.1.1
From: <sip:c.vella@albourne.com>;tag=1
To: <sip:provisioning@albourne.com>;tag=a6a1c5f60faecf035a1ae5b6e96e979a-1030
Expires: 3600
Contact: <sip:192.168.88.85:5060;transport=tcp>
--- End debug ---
I suspect I am not understanding this correctly. Is there a proper way around
this? I wonder if I am wrong to think that textops Module manipulates the
actual request message?
Thank you!
Regards,
--
Chris Vella
Albourne Partners (Canada) Limited