[OpenSIPS-Users] Dedicated Presence Service

Paris Stamatopoulos mobius at realize.gr
Mon Mar 28 15:50:15 CEST 2011 

Hello there,

I am trying to create a seperate Presence server to use with my existing OpenSIPS proxy. My main proxy/registrar listens at 10.1.1.1 port 5080, while the presence server listens to 10.1.1.1 5061.

The registrar/proxy only makes use of pua so as to change the status of non-presence capable phones, and forwards everything else to the dedicated presence server, so I've added to my configuration:

loadmodule "pua.so"
loadmodule "pua_mi.so"
loadmodule "pua_usrloc.so"
loadmodule "pua_dialoginfo.so"
loadmodule "presence"

modparam("pua", "db_url", "mysql://user:pass@host/db")
modparam("pua_usrloc", "default_domain", "domain.com")
modparam("pua_usrloc", "10.1.1.1", "sip:presence at 10.1.1.1:5061")

modparam("pua_dialoginfo", "10.1.1.1", "sip:presence at 10.1.1.1:5061")
modparam("pua_dialoginfo", "include_callid", 1)
modparam("pua_dialoginfo", "include_tags", 1)
modparam("pua_dialoginfo", "caller_confirmed", 0)

modparam("pua_dialoginfo", "caller_spec_param", "$avp(i:10)")

modparam("presence", "mix_dialog_presence", 1)

...

if (has_totag()) {
        if (loose_route()) {
                if (is_method("BYE")) {
                        setflag(1);
                        setflag(3);
                } else if (is_method("INVITE")) {
                        record_route();
                }
                route(1);
        } else {
                if( is_method("SUBSCRIBE") && $rd == "10.1.1.1" ) {
                        t_relay("udp:10.1.1.1:5061");
                        exit;
                }

                                if ( is_method("ACK") ) {
                        if ( t_check_trans() ) {
                                t_relay();
                                exit;
                        } else {
                                exit;
                        }
                }

                                sl_send_reply("404","Not here");
        }

        exit;
}

...

if( is_method("PUBLISH|SUBSCRIBE|NOTIFY") && src_ip != 10.1.1.1 ) {
        t_relay("udp:10.1.1.1:5061");
        exit;
}

...

if( !search("^User-Agent: X-Lite")) {
                pua_set_publish();
}

Presence appears to be partially working, but what seems rather odd (and I believe is the reason why I am facing problems) is the following:

I am seeing on the presence opensips:

Mar 28 16:27:38 [25064] DBG:presence:build_dlg_t: CONTACT = sip:12345 at 10.1.1.1:5080;transport=udp
Mar 28 16:27:38 [25064] DBG:tm:t_uac: next_hop=<sip:10.1.1.1:5080;lr=on;ftag=23294e0b7d1b57e4>
Mar 28 16:27:38 [25064] DBG:core:mk_proxy: doing DNS lookup...
Mar 28 16:27:38 [25064] DBG:tm:dlg2hash: 3372
Mar 28 16:27:38 [25064] DBG:tm:print_request_uri: sip:12345 at 10.1.1.1:5080;transport=udp
Mar 28 16:27:38 [25064] DBG:tm:set_timer: relative timeout is 500000
Mar 28 16:27:38 [25064] DBG:tm:insert_timer_unsafe: [4]: 0x7feff60bba28 (30600000)
Mar 28 16:27:38 [25064] DBG:tm:set_timer: relative timeout is 30
Mar 28 16:27:38 [25064] DBG:tm:insert_timer_unsafe: [0]: 0x7feff60bba58 (60)
Mar 28 16:27:38 [25064] INFO:presence:send_notify_request: NOTIFY sip:12345 at domain.com via sip:10.1.1.1:5080;lr=on;ftag=23294e0b7d1b57e4 on behalf of sip:54321 at domain.com for event presence
Mar 28 16:27:38 [25064] DBG:tm:t_unref: UNREF_UNSAFE: [0x7feff60c0428] after is 0
Mar 28 16:27:38 [25064] DBG:core:destroy_avp_list: destroying list (nil)
Mar 28 16:27:38 [25064] DBG:core:receive_msg: cleaning up
Mar 28 16:27:38 [25064] DBG:core:parse_msg: SIP Reply  (status):
Mar 28 16:27:38 [25064] DBG:core:parse_msg:  version: <SIP/2.0>
Mar 28 16:27:38 [25064] DBG:core:parse_msg:  status:  <404>
Mar 28 16:27:38 [25064] DBG:core:parse_msg:  reason:  <Not here>

As you can see it mentions "NOTIFY sip:12345 at domain.com via sip:10.1.1.1:5080;". The registrar/proxy on the other side:

Mar 28 16:27:38 [24199] DBG:core:parse_msg: SIP Request:
Mar 28 16:27:38 [24199] DBG:core:parse_msg:  method:  <NOTIFY>
Mar 28 16:27:38 [24199] DBG:core:parse_msg:  uri:     <sip:12345 at 10.1.1.1:5080;transport=udp>
Mar 28 16:27:38 [24199] DBG:core:parse_msg:  version: <SIP/2.0>
Mar 28 16:27:38 [24199] DBG:core:parse_headers: flags=2
Mar 28 16:27:38 [24199] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKc2d.7df81c95.0>; state=16
Mar 28 16:27:38 [24199] DBG:core:parse_via: end of header reached, state=5
Mar 28 16:27:38 [24199] DBG:core:parse_headers: via found, flags=2
Mar 28 16:27:38 [24199] DBG:core:parse_headers: this is the first via
Mar 28 16:27:38 [24199] DBG:core:receive_msg: After parse_msg...
Mar 28 16:27:38 [24199] DBG:core:receive_msg: preparing to run routing scripts...
Mar 28 16:27:38 [24199] DBG:core:parse_headers: flags=100
Mar 28 16:27:38 [24199] DBG:core:parse_to_param: tag=23294e0b7d1b57e4
Mar 28 16:27:38 [24199] DBG:core:parse_to: end of header reached, state=29
Mar 28 16:27:38 [24199] DBG:core:parse_to: display={}, ruri={sip:12345 at domain.com}
Mar 28 16:27:38 [24199] DBG:core:get_hdr_field: <To> [54]; uri=[sip:12345 at domain.com]
Mar 28 16:27:38 [24199] DBG:core:get_hdr_field: to body [<sip:12345 at domain.com>]
Mar 28 16:27:38 [24199] DBG:core:get_hdr_field: cseq <CSeq>: <2> <NOTIFY>
Mar 28 16:27:38 [24199] DBG:core:get_hdr_field: content_length=327
Mar 28 16:27:38 [24199] DBG:maxfwd:is_maxfwd_present: value = 70
Mar 28 16:27:38 [24199] DBG:core:parse_to_param: tag=2ccb18146f1d6c25cf2547e9412b7255-79b3
Mar 28 16:27:38 [24199] DBG:core:parse_to: end of header reached, state=29
Mar 28 16:27:38 [24199] DBG:core:parse_to: display={}, ruri={sip:54321 at domain.com}
Mar 28 16:27:38 [24199] DBG:core:db_new_result: allocate 48 bytes for result set at 0x7e6ca0
Mar 28 16:27:38 [24199] DBG:db_mysql:db_mysql_get_columns: 3 columns returned from the query
Mar 28 16:27:38 [24199] DBG:core:db_allocate_columns: allocate 84 bytes for result columns at 0x7e4020
Mar 28 16:27:38 [24199] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7e4038)[0]=[value]
Mar 28 16:27:38 [24199] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Mar 28 16:27:38 [24199] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7e4048)[1]=[attribute]
Mar 28 16:27:38 [24199] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Mar 28 16:27:38 [24199] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7e4058)[2]=[type]
Mar 28 16:27:38 [24199] DBG:db_mysql:db_mysql_get_columns: use DB_INT result type
Mar 28 16:27:38 [24199] DBG:db_mysql:db_mysql_convert_rows: no rows returned from the query
Mar 28 16:27:38 [24199] DBG:avpops:db_close_query: close avp query
Mar 28 16:27:38 [24199] DBG:core:db_free_columns: freeing result columns at 0x7e4020
Mar 28 16:27:38 [24199] DBG:core:db_free_rows: freeing 0 rows
Mar 28 16:27:38 [24199] DBG:core:db_free_result: freeing result set at 0x7e6ca0
Mar 28 16:27:38 [24199] DBG:avpops:ops_dbload_avps: loaded avps = 0
Mar 28 16:27:38 [24199] DBG:core:check_ip_address: params 10.1.1.1, 10.1.1.1, 0
Mar 28 16:27:38 [24199] DBG:core:parse_headers: flags=ffffffffffffffff
Mar 28 16:27:38 [24199] DBG:core:get_hdr_field: found end of header
Mar 28 16:27:38 [24199] DBG:uri:has_totag: totag found
Mar 28 16:27:38 [24199] DBG:core:parse_headers: flags=200
Mar 28 16:27:38 [24199] DBG:rr:is_preloaded: is_preloaded: No
Mar 28 16:27:38 [24199] DBG:core:grep_sock_info: checking if host==us: 12==12 &&  [10.1.1.1] == [10.1.1.1]
Mar 28 16:27:38 [24199] DBG:core:grep_sock_info: checking if port 5080 matches port 5080
Mar 28 16:27:38 [24199] DBG:rr:after_strict: Next hop: 'sip:10.1.1.1:5080;lr=on;ftag=23294e0b7d1b57e4' is loose router
Mar 28 16:27:38 [24199] DBG:core:parse_headers: flags=ffffffffffffffff
Mar 28 16:27:38 [24199] DBG:rr:after_strict: The last route URI: 'sip:10.1.1.1:5080;lr=on;ftag=23294e0b7d1b57e4'
Mar 28 16:27:38 [24199] DBG:rr:run_rr_callbacks: callback id 1 entered with <transport=udp>
Mar 28 16:27:38 [24199] DBG:core:parse_headers: flags=48
Mar 28 16:27:38 [24199] DBG:dialog:get_dlg: input ci=<aa909f8d90deb784 at 192.168.4.51>(29), tt=<2ccb18146f1d6c25cf2547e9412b7255-79b3>(37), ft=<23294e0b7d1b57e4>(16)
Mar 28 16:27:38 [24199] DBG:dialog:get_dlg: no dialog callid='aa909f8d90deb784 at 192.168.4.51' found
Mar 28 16:27:38 [24199] DBG:dialog:dlg_onroute: Callid 'aa909f8d90deb784 at 192.168.4.51' not found
Mar 28 16:27:38 [24199] DBG:rr:run_rr_callbacks: callback id 2 entered with <transport=udp>
Mar 28 16:27:38 [24199] DBG:uac:restore_uri: getting 'vsf' Route param
Mar 28 16:27:38 [24199] DBG:uac:restore_uri: route param 'vsf' not found
Mar 28 16:27:38 [24199] DBG:uac:restore_uri: getting 'vst' Route param
Mar 28 16:27:38 [24199] DBG:uac:restore_uri: route param 'vst' not found
Mar 28 16:27:38 [24199] DBG:tm:t_newtran: transaction on entrance=0xffffffffffffffff
Mar 28 16:27:38 [24199] DBG:core:parse_headers: flags=ffffffffffffffff
Mar 28 16:27:38 [24199] DBG:core:parse_headers: flags=78
Mar 28 16:27:38 [24199] DBG:tm:t_lookup_request: start searching: hash=3372, isACK=0
Mar 28 16:27:38 [24199] DBG:tm:matching_3261: RFC3261 transaction matching failed
Mar 28 16:27:38 [24199] DBG:tm:t_lookup_request: no transaction found
Mar 28 16:27:38 [24199] DBG:tm:run_reqin_callbacks: trans=0x7f5658f8a810, callback type 1, id 2 entered
Mar 28 16:27:38 [24199] DBG:siptrace:trace_onreq_in: trace off...
Mar 28 16:27:38 [24199] DBG:tm:run_reqin_callbacks: trans=0x7f5658f8a810, callback type 1, id 1 entered
Mar 28 16:27:38 [24199] DBG:tm:run_reqin_callbacks: trans=0x7f5658f8a810, callback type 1, id 0 entered
Mar 28 16:27:38 [24199] DBG:core:_shm_resize: resize(0) called
Mar 28 16:27:38 [24199] DBG:core:mk_proxy: doing DNS lookup...
Mar 28 16:27:38 [24199] DBG:tm:set_timer: relative timeout is 500000
Mar 28 16:27:38 [24199] DBG:tm:insert_timer_unsafe: [4]: 0x7f5658f8aa30 (47300000)
Mar 28 16:27:38 [24199] DBG:tm:set_timer: relative timeout is 30
Mar 28 16:27:38 [24199] DBG:tm:insert_timer_unsafe: [0]: 0x7f5658f8aa60 (76)
Mar 28 16:27:38 [24199] DBG:tm:t_relay_to: new transaction fwd'ed
Mar 28 16:27:38 [24199] DBG:tm:t_unref: UNREF_UNSAFE: [0x7f5658f8a810] after is 0
Mar 28 16:27:38 [24199] DBG:core:destroy_avp_list: destroying list (nil)
Mar 28 16:27:38 [24199] DBG:core:receive_msg: cleaning up
Mar 28 16:27:38 [24199] DBG:core:parse_msg: SIP Request:
Mar 28 16:27:38 [24199] DBG:core:parse_msg:  method:  <NOTIFY>
Mar 28 16:27:38 [24199] DBG:core:parse_msg:  uri:     <sip:10.1.1.1:5080;lr=on;ftag=23294e0b7d1b57e4>
Mar 28 16:27:38 [24199] DBG:core:parse_msg:  version: <SIP/2.0>
Mar 28 16:27:38 [24199] DBG:core:parse_headers: flags=2
Mar 28 16:27:38 [24199] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKc2d.d64e9016.0>; state=16
Mar 28 16:27:38 [24199] DBG:core:parse_via: end of header reached, state=5
Mar 28 16:27:38 [24199] DBG:core:parse_headers: via found, flags=2
Mar 28 16:27:38 [24199] DBG:core:parse_headers: this is the first via
Mar 28 16:27:38 [24199] DBG:core:receive_msg: After parse_msg...
Mar 28 16:27:38 [24199] DBG:core:receive_msg: preparing to run routing scripts...
Mar 28 16:27:38 [24199] DBG:core:parse_headers: flags=100
Mar 28 16:27:38 [24199] DBG:core:parse_via_param: found param type 235, <rport> = <5061>; state=6
Mar 28 16:27:38 [24199] DBG:core:parse_via_param: found param type 234, <received> = <10.1.1.1>; state=6
Mar 28 16:27:38 [24199] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKc2d.7df81c95.0>; state=16
Mar 28 16:27:38 [24199] DBG:core:parse_via: end of header reached, state=5
Mar 28 16:27:38 [24199] DBG:core:parse_headers: via found, flags=100
Mar 28 16:27:38 [24199] DBG:core:parse_headers: parse_headers: this is the second via
Mar 28 16:27:38 [24199] DBG:core:parse_to_param: tag=23294e0b7d1b57e4
Mar 28 16:27:38 [24199] DBG:core:parse_to: end of header reached, state=29
Mar 28 16:27:38 [24199] DBG:core:parse_to: display={}, ruri={sip:12345 at domain.com}
Mar 28 16:27:38 [24199] DBG:core:get_hdr_field: <To> [54]; uri=[sip:12345 at domain.com]
Mar 28 16:27:38 [24199] DBG:core:get_hdr_field: to body [<sip:12345 at domain.com>]
Mar 28 16:27:38 [24199] DBG:core:get_hdr_field: cseq <CSeq>: <2> <NOTIFY>
Mar 28 16:27:38 [24199] DBG:core:get_hdr_field: content_length=327
Mar 28 16:27:38 [24199] DBG:maxfwd:is_maxfwd_present: value = 69
Mar 28 16:27:38 [24199] DBG:core:parse_to_param: tag=2ccb18146f1d6c25cf2547e9412b7255-79b3
Mar 28 16:27:38 [24199] DBG:core:parse_to: end of header reached, state=29
Mar 28 16:27:38 [24199] DBG:core:parse_to: display={}, ruri={sip:54321 at domain.com}
Mar 28 16:27:38 [24199] DBG:core:db_new_result: allocate 48 bytes for result set at 0x7e6130
Mar 28 16:27:38 [24199] DBG:db_mysql:db_mysql_get_columns: 3 columns returned from the query
Mar 28 16:27:38 [24199] DBG:core:db_allocate_columns: allocate 84 bytes for result columns at 0x7e4020
Mar 28 16:27:38 [24199] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7e4038)[0]=[value]
Mar 28 16:27:38 [24199] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Mar 28 16:27:38 [24199] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7e4048)[1]=[attribute]
Mar 28 16:27:38 [24199] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Mar 28 16:27:38 [24199] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7e4058)[2]=[type]
Mar 28 16:27:38 [24199] DBG:db_mysql:db_mysql_get_columns: use DB_INT result type
Mar 28 16:27:38 [24199] DBG:db_mysql:db_mysql_convert_rows: no rows returned from the query
Mar 28 16:27:38 [24199] DBG:avpops:db_close_query: close avp query
Mar 28 16:27:38 [24199] DBG:core:db_free_columns: freeing result columns at 0x7e4020
Mar 28 16:27:38 [24199] DBG:core:db_free_rows: freeing 0 rows
Mar 28 16:27:38 [24199] DBG:core:db_free_result: freeing result set at 0x7e6130
Mar 28 16:27:38 [24199] DBG:avpops:ops_dbload_avps: loaded avps = 0
Mar 28 16:27:38 [24199] DBG:core:check_ip_address: params 10.1.1.1, 10.1.1.1, 0
Mar 28 16:27:38 [24199] DBG:core:parse_headers: flags=ffffffffffffffff
Mar 28 16:27:38 [24199] DBG:core:get_hdr_field: found end of header
Mar 28 16:27:38 [24199] DBG:uri:has_totag: totag found
Mar 28 16:27:38 [24199] DBG:core:parse_headers: flags=200
Mar 28 16:27:38 [24199] DBG:rr:find_first_route: No Route headers found
Mar 28 16:27:38 [24199] DBG:rr:loose_route: There is no Route HF
Mar 28 16:27:38 [24199] DBG:core:parse_headers: flags=ffffffffffffffff
Mar 28 16:27:38 [24199] DBG:core:check_ip_address: params 10.1.1.1, 10.1.1.1, 0
Mar 28 16:27:38 [24199] DBG:sl:run_sl_callbacks: callback id 0 entered
Mar 28 16:27:38 [24199] DBG:siptrace:trace_sl_onreply_out: trace off...
Mar 28 16:27:38 [24199] DBG:core:destroy_avp_list: destroying list (nil)
Mar 28 16:27:38 [24199] DBG:core:receive_msg: cleaning up
Mar 28 16:27:38 [24199] DBG:core:parse_msg: SIP Reply  (status):
Mar 28 16:27:38 [24199] DBG:core:parse_msg:  version: <SIP/2.0>
Mar 28 16:27:38 [24199] DBG:core:parse_msg:  status:  <404>
Mar 28 16:27:38 [24199] DBG:core:parse_msg:  reason:  <Not here>

The proxy gets the Via: header from the SIP NOTIFY and forwards the message once more to himself setting the uri to sip:10.1.1.1:5080;lr=on;ftag=23294e0b7d1b57e4. Then the proxy cannot find the destination thus responding with 404 Not Here. The 404 message is being redirected once again to the proxy and then back to the presence service.

I am feeling there is something wrong with the domains configuration on both the Presence/Proxy opensips.

Could anyone share any ideas on the matter?

Regards,
Paris
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/users/attachments/20110328/322dfa44/attachment-0001.htm>

More information about the Users mailing list