So, after much more testing and staring at logs....


The BLFs ARE indeed working for all my Yealinks and MOST of my Grandstreams


The ones that are not working don't like the 'version=1' - these are sending back "481 Subscription Does Not Exist"

---------

NOTIFY sip:305@PRIVATE_IP:55318 SIP/2.0
Via: SIP/2.0/UDP IP_ADDRESS:PORT;branch=z9hG4bKffd9.a74b11b5000000000000000000000000.0
To: <sip:305@domain.net>;tag=2001402711
From: <sip:301@domain.net>;tag=5e1ee053cf7168b9d3ee9c05740f837c-270107a6
CSeq: 2 NOTIFY
Call-ID: 2104033891-55318-6@BA.CEG.HG.GC
Content-Length: 273
User-Agent: kamailio (5.4.4 (x86_64/linux))
Max-Forwards: 70
Event: dialog
Contact: <sip:IP_ADDRESS:PORT>
Subscription-State: active;expires=60
Content-Type: application/dialog-info+xml

<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="1" state="full" entity="sip:301@domain.net">
  <dialog id="615293b33c62dec073e05d9421e9f48b" direction="recipient"> <state>terminated</state> </dialog>
</dialog-info>
--------------


Other wise everything seems OK.


So, any ideas why Kamilio is sending Version=1 repeatedly?


Jerry


On 2021-10-01 1:33 p.m., Jerry Kendall wrote:

Hey Daniel,
here is the (hopefully) sanitized syslog parts around the BLF issue.
I do appreciate your insights here..
------------------
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: <core> [core/udp_server.c:493]: udp_rcv_loop(): received on udp socket: (106/100/726) [[SUBSCRIBE sip:301@domain.net:PORT SIP/2.0 0D  0A Via: SIP/2.0/UDP PRIVATE_IP:44762;br]]
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): SIP Request:
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: <core> [core/parser/msg_parser.c:611]: parse_msg():  method:  <SUBSCRIBE>
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: <core> [core/parser/msg_parser.c:613]: parse_msg():  uri:     <sip:301@domain.net:PORT>
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: <core> [core/parser/msg_parser.c:615]: parse_msg():  version: <SIP/2.0>
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: <core> [core/parser/parse_via.c:1300]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK1251409407>; state=6
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: <core> [core/parser/parse_via.c:1300]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=17
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: <core> [core/parser/msg_parser.c:170]: get_hdr_field(): <To> [46]; uri=[sip:301@domain.net:PORT]
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body (46)[<sip:301@domain.net:PORT>#015#012], to tag (0)[]
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: <core> [core/parser/msg_parser.c:150]: get_hdr_field(): cseq <CSeq>: <21000> <SUBSCRIBE>
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: <core> [core/receive.c:319]: receive_msg(): --- received sip message - request - call-id: [551473572-44762-6@BA.CEG.HG.GC] - cseq: [21000 SUBSCRIBE]
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: <core> [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=0
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header

Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/receive.c:379]: receive_msg(): preparing to run routing scripts...
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio.cfg] l=533 a=5 n=route
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[REQINIT] c=[/etc/kamailio/kamailio.cfg] l=754 a=16 n=if
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[REQINIT] c=[/etc/kamailio/kamailio.cfg] l=759 a=16 n=if
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[REQINIT] c=[/etc/kamailio/kamailio.cfg] l=754 a=25 n=mf_process_maxfwd_header
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 70
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[REQINIT] c=[/etc/kamailio/kamailio.cfg] l=764 a=16 n=if
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[REQINIT] c=[/etc/kamailio/kamailio.cfg] l=759 a=25 n=is_method
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[REQINIT] c=[/etc/kamailio/kamailio.cfg] l=768 a=16 n=if
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[REQINIT] c=[/etc/kamailio/kamailio.cfg] l=764 a=26 n=sanity_check
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:247]: check_ruri_sip_version(): check_ruri_sip_version entered
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:270]: check_ruri_sip_version(): check_ruri_sip_version passed
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:277]: check_ruri_scheme(): check_ruri_scheme entered
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:297]: check_ruri_scheme(): check_ruri_scheme passed
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:318]: check_required_headers(): check_required_headers entered
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:340]: check_required_headers(): check_required_headers passed
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:348]: check_via1_header(): check via1 header
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:506]: check_cseq_method(): check_cseq_method entered
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:539]: check_cseq_method(): check_cseq_method passed
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:548]: check_cseq_value(): check_cseq_value entered
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:576]: check_cseq_value(): check_cseq_value passed
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:585]: check_cl(): check_cl entered
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:610]: check_cl(): check_cl passed
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:622]: check_expires_value(): check_expires_value entered
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:657]: check_expires_value(): check_expires_value passed
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:759]: check_parse_uris(): check_parse_uris entered
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:763]: check_parse_uris(): parsing ruri
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:777]: check_parse_uris(): looking up From header
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:791]: check_parse_uris(): parsing From header
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=138358676
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:817]: check_parse_uris(): parsing From URI
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:835]: check_parse_uris(): looking up To header
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:857]: check_parse_uris(): check_parse_uris(): parsing To URI
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity.c:902]: check_parse_uris(): check_parse_uris passed
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sanity [sanity_mod.c:254]: w_sanity_check(): sanity checks result: 1
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio.cfg] l=536 a=5 n=route
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[NATDETECT] c=[/etc/kamailio/kamailio.cfg] l=952 a=55 n=force_rport
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[NATDETECT] c=[/etc/kamailio/kamailio.cfg] l=965 a=16 n=if
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[NATDETECT] c=[/etc/kamailio/kamailio.cfg] l=953 a=25 n=nat_uac_test
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/msg_translator.c:161]: check_via_address(): (184.148.140.29, PRIVATE_IP, 0)
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[NATDETECT] c=[/etc/kamailio/kamailio.cfg] l=954 a=25 n=xinfo
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[NATDETECT] c=[/etc/kamailio/kamailio.cfg] l=961 a=16 n=if
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[NATDETECT] c=[/etc/kamailio/kamailio.cfg] l=955 a=25 n=is_method
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[NATDETECT] c=[/etc/kamailio/kamailio.cfg] l=961 a=16 n=if
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[NATDETECT] c=[/etc/kamailio/kamailio.cfg] l=958 a=24 n=is_first_hop
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} siputils [sipops.c:159]: is_first_hop(): no 2nd via found - first hop
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[NATDETECT] c=[/etc/kamailio/kamailio.cfg] l=959 a=24 n=set_contact_alias
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/dset.c:919]: uri_add_rcv_alias(): encoded <sip:305@PRIVATE_IP:44762> => [sip:305@PRIVATE_IP:44762;alias=184.148.140.29~44762~1]
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[NATDETECT] c=[/etc/kamailio/kamailio.cfg] l=962 a=39 n=setflag
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[NATDETECT] c=[/etc/kamailio/kamailio.cfg] l=965 a=2 n=return
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio.cfg] l=550 a=16 n=if
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio.cfg] l=542 a=25 n=is_method
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio.cfg] l=559 a=16 n=if
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio.cfg] l=550 a=25 n=is_method
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio.cfg] l=555 a=16 n=if
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio.cfg] l=551 a=24 n=t_precheck_trans
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio.cfg] l=555 a=24 n=t_check_trans
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [t_lookup.c:1034]: t_check_msg(): msg (0x7f1ef9d784e8) id=15/15920 global id=14/15920 T start=0xffffffffffffffff
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [t_lookup.c:497]: t_lookup_request(): start searching: hash=54253, isACK=0
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [t_lookup.c:455]: matching_3261(): RFC3261 transaction matching failed - via branch [z9hG4bK1251409407]
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [t_lookup.c:675]: t_lookup_request(): no transaction found
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [t_lookup.c:1104]: t_check_msg(): msg (0x7f1ef9d784e8) id=15/15920 global id=15/15920 T end=(nil)
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio.cfg] l=559 a=5 n=route
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[WITHINDLG] c=[/etc/kamailio/kamailio.cfg] l=776 a=16 n=if
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[WITHINDLG] c=[/etc/kamailio/kamailio.cfg] l=772 a=24 n=has_totag
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} siputils [checks.c:120]: has_totag(): no totag
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[WITHINDLG] c=[/etc/kamailio/kamailio.cfg] l=772 a=2 n=return
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio.cfg] l=564 a=5 n=route
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[AUTH] c=[/etc/kamailio/kamailio.cfg] l=932 a=16 n=if
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[AUTH] c=[/etc/kamailio/kamailio.cfg] l=920 a=25 n=is_method
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[AUTH] c=[/etc/kamailio/kamailio.cfg] l=946 a=16 n=if
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/socket_info.c:641]: grep_sock_info(): checking if host==us: 29==14 && [domain.net] == [PUBLIC_IP]
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/socket_info.c:648]: grep_sock_info(): checking if port PORT (advertise 0) matches port PORT
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/socket_info.c:641]: grep_sock_info(): checking if host==us: 29==9 && [domain.net] == [127.0.0.1]
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/socket_info.c:648]: grep_sock_info(): checking if port 8080 (advertise 0) matches port PORT
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/name_alias.h:62]: grep_aliases(): matching (0:domain.net:PORT) vs. (2:localhost:8080)
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/name_alias.h:62]: grep_aliases(): matching (0:domain.net:PORT) vs. (1:Kam01:PORT)
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/forward.c:422]: check_self(): host (0:domain.net:PORT) == me
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[AUTH] c=[/etc/kamailio/kamailio.cfg] l=946 a=2 n=return
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio.cfg] l=568 a=25 n=remove_hf
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio.cfg] l=574 a=16 n=if
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio.cfg] l=569 a=25 n=is_method
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio.cfg] l=570 a=24 n=record_route
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} rr [record.c:479]: record_route(): inserted record route (r2: 1 - plen: 0)
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio.cfg] l=579 a=16 n=if
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio.cfg] l=574 a=25 n=is_method
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio.cfg] l=579 a=5 n=route
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[SIPOUT] c=[/etc/kamailio/kamailio.cfg] l=1017 a=16 n=if
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/socket_info.c:641]: grep_sock_info(): checking if host==us: 29==14 && [domain.net] == [PUBLIC_IP]
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/socket_info.c:648]: grep_sock_info(): checking if port PORT (advertise 0) matches port PORT
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/socket_info.c:641]: grep_sock_info(): checking if host==us: 29==9 && [domain.net] == [127.0.0.1]
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/socket_info.c:648]: grep_sock_info(): checking if port 8080 (advertise 0) matches port PORT
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/name_alias.h:62]: grep_aliases(): matching (0:domain.net:PORT) vs. (2:localhost:8080)
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/name_alias.h:62]: grep_aliases(): matching (0:domain.net:PORT) vs. (1:Kam01:PORT)
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/forward.c:422]: check_self(): host (0:domain.net:PORT) == me
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[SIPOUT] c=[/etc/kamailio/kamailio.cfg] l=1015 a=2 n=return
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio.cfg] l=584 a=5 n=route
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[PRESENCE] c=[/etc/kamailio/kamailio.cfg] l=877 a=16 n=if
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[PRESENCE] c=[/etc/kamailio/kamailio.cfg] l=875 a=25 n=is_method
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[PRESENCE] c=[/etc/kamailio/kamailio.cfg] l=885 a=16 n=if
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[PRESENCE] c=[/etc/kamailio/kamailio.cfg] l=877 a=25 n=is_method
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[PRESENCE] c=[/etc/kamailio/kamailio.cfg] l=890 a=16 n=if
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[PRESENCE] c=[/etc/kamailio/kamailio.cfg] l=885 a=24 n=t_newtran
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [t_lookup.c:1328]: t_newtran(): msg (0x7f1ef9d784e8) id=15/15920 global id=15/15920 T start=(nil)
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [t_lookup.c:497]: t_lookup_request(): start searching: hash=54253, isACK=0
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [t_lookup.c:455]: matching_3261(): RFC3261 transaction matching failed - via branch [z9hG4bK1251409407]
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [t_lookup.c:675]: t_lookup_request(): no transaction found
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [t_hooks.c:346]: run_reqin_callbacks_internal(): trans=0x7f1ef323f8c8, callback type 1, id 0 entered
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [t_hooks.c:346]: run_reqin_callbacks_internal(): trans=0x7f1ef323f8c8, callback type 1, id 0 entered
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/crypto/md5utils.c:67]: MD5StringArray(): MD5 calculated: 7e9980da4edb60eee121f954c89f5972
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[PRESENCE] c=[/etc/kamailio/kamailio.cfg] l=897 a=16 n=if
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[PRESENCE] c=[/etc/kamailio/kamailio.cfg] l=890 a=25 n=is_method
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[PRESENCE] c=[/etc/kamailio/kamailio.cfg] l=897 a=16 n=if
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[PRESENCE] c=[/etc/kamailio/kamailio.cfg] l=893 a=25 n=is_method
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[PRESENCE] c=[/etc/kamailio/kamailio.cfg] l=894 a=24 n=handle_subscribe
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [event_list.c:324]: search_event(): start event= [dialog/5]
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [subscribe.c:1312]: extract_sdialog_info_ex(): 'Expires' header found, value= 60
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [subscribe.c:1346]: extract_sdialog_info_ex(): 'To' header ALREADY PARSED: <sip:301@domain.net:PORT>
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [subscribe.c:1403]: extract_sdialog_info_ex(): generating to_tag
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sl [sl.c:354]: get_reply_totag(): totag stateful mode (tm)

Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [subscribe.c:1452]: extract_sdialog_info_ex(): subs->contact= sip:305@PRIVATE_IP:44762;alias=184.148.140.29~44762~1 - len = 55
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [subscribe.c:1207]: handle_subscribe(): subscription status= active - inserted
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [subscribe.c:562]: update_subscription(): update subscription
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:127]: printf_subs(): pres_uri: sip:301@domain.net
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:128]: printf_subs(): watcher_user@watcher_domain: 305@domain.net
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:131]: printf_subs(): to_user@to_domain: 301@domain.net
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:133]: printf_subs(): from_user@from_domain: 305@domain.net
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:135]: printf_subs(): callid/from_tag/to_tag: 551473572-44762-6@BA.CEG.HG.GC/138358676/5e1ee053cf7168b9d3ee9c05740f837c-eb6836a8
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:138]: printf_subs(): local_cseq/remote_cseq: 0/21000
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:140]: printf_subs(): local_contact/contact: sip:PUBLIC_IP:PORT/sip:305@PRIVATE_IP:44762;alias=184.148.140.29~44762~1
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:142]: printf_subs(): record_route:
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:144]: printf_subs(): sockinfo_str: udp:PUBLIC_IP:PORT
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:147]: printf_subs(): event: dialog
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:148]: printf_subs(): status: active
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:149]: printf_subs(): reason:
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:150]: printf_subs(): version: 1
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:151]: printf_subs(): expires: 60
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:153]: printf_subs(): updated/updated_winfo: -1/-1
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [subscribe.c:625]: update_subscription(): subscription not in dialog
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [subscribe.c:628]: update_subscription(): inserting in shtable
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [t_lookup.c:1034]: t_check_msg(): msg (0x7f1ef9d784e8) id=15/15920 global id=15/15920 T start=0x7f1ef323f8c8
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [t_lookup.c:1109]: t_check_msg(): T (0x7f1ef323f8c8) already found for msg (0x7f1ef9d784e8)!
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [t_reply.c:1765]: cleanup_uac_timers(): RETR/FR timers reset
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [t_reply.c:637]: _reply_light(): reply sent out - buf=0x7f1ef9d83a38: SIP/2.0 202 OK#015#012Via:... shmem=0x7f1ef321abc0: SIP/2.0 202 OK#015#012Via:
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [t_reply.c:648]: _reply_light(): finished
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} sl [sl.c:297]: send_reply(): reply in stateful mode (tm)

Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:1622]: send_notify_request(): dialog info:
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:127]: printf_subs(): pres_uri: sip:301@domain.net
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:128]: printf_subs(): watcher_user@watcher_domain: 305@domain.net
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:131]: printf_subs(): to_user@to_domain: 301@domain.net
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:133]: printf_subs(): from_user@from_domain: 305@domain.net
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:135]: printf_subs(): callid/from_tag/to_tag: 551473572-44762-6@BA.CEG.HG.GC/138358676/5e1ee053cf7168b9d3ee9c05740f837c-eb6836a8
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:138]: printf_subs(): local_cseq/remote_cseq: 1/21000
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:140]: printf_subs(): local_contact/contact: sip:PUBLIC_IP:PORT/sip:305@PRIVATE_IP:44762;alias=184.148.140.29~44762~1
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:142]: printf_subs(): record_route:
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:144]: printf_subs(): sockinfo_str: udp:PUBLIC_IP:PORT
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:147]: printf_subs(): event: dialog
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:148]: printf_subs(): status: active
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:149]: printf_subs(): reason:
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:150]: printf_subs(): version: 1
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:151]: printf_subs(): expires: 60
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:153]: printf_subs(): updated/updated_winfo: -1/-1
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [hash.c:522]: search_phtable(): pres_uri= sip:301@domain.net
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:617]: ps_db_get_p_notify_body(): No record exists in hash_table

Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence_dialoginfo [notify_body.c:125]: dlginfo_agg_nbody(): [pres_user]=301 [pres_domain]= domain.net, [n]=0
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence_dialoginfo [notify_body.c:81]: dlginfo_agg_nbody_empty(): creating empty dialog for [pres_user]=301 [pres_domain]= domain.net
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence_dialoginfo [notify_body.c:180]: agregate_xmls(): [pres_user]=301 [pres_domain]= domain.net, [n]=1
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence_dialoginfo [notify_body.c:282]: agregate_xmls(): node type: Element, name: dialog
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence_dialoginfo [notify_body.c:103]: dlginfo_agg_nbody_empty(): [n_body]=0x7f1ef9d83b80
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence_dialoginfo [notify_body.c:105]: dlginfo_agg_nbody_empty(): [*n_body]=<?xml version="1.0"?>#012<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="00000000000" state="full" entity="sip:301@domain.net">#012  <dialog id="615293b33c62dec073e05d9421e9f48b" direction="recipient">#011<state>terminated</state>#011</dialog>#012</dialog-info>#012
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence_dialoginfo [notify_body.c:608]: dlginfo_body_setversion(): replace version with "1"

Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:1707]: send_notify_request(): headers:#012Max-Forwards: 70#015#012Event: dialog#015#012Contact: <sip:PUBLIC_IP:PORT>#015#012Subscription-State: active;expires=60#015#012Content-Type: application/dialog-info+xml#015#012
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:1131]: ps_build_dlg_t(): CONTACT = sip:305@PRIVATE_IP:44762;alias=184.148.140.29~44762~1
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/socket_info.c:641]: grep_sock_info(): checking if host==us: 14==14 && [PUBLIC_IP] == [PUBLIC_IP]
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/socket_info.c:648]: grep_sock_info(): checking if port PORT (advertise 0) matches port PORT
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:1716]: send_notify_request(): expires 60 status 1
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/dset.c:1026]: uri_restore_rcv_alias(): decoded <sip:305@PRIVATE_IP:44762;alias=184.148.140.29~44762~1> => [sip:305@PRIVATE_IP:44762] [sip:184.148.140.29:44762]

Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [uac.c:450]: t_uac_prepare(): next_hop=<sip:184.148.140.29:44762>
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [uac.c:158]: dlg2hash(): hashid 35506
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [uac.c:678]: send_prepared_request_impl(): uac: 0x7f1ef31d9830  branch: 0  to 184.148.140.29:44762

Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/onsend.c:50]: run_onsend(): required parameters are not available - ignoring
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: INFO:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} presence [notify.c:1737]: send_notify_request(): NOTIFY sip:305@domain.net via on behalf of sip:301@domain.net for event dialog : 551473572-44762-6@BA.CEG.HG.GC
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[PRESENCE] c=[/etc/kamailio/kamailio.cfg] l=895 a=24 n=t_release
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [t_lookup.c:1034]: t_check_msg(): msg (0x7f1ef9d784e8) id=15/15920 global id=15/15920 T start=0x7f1ef323f8c8
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [t_lookup.c:1109]: t_check_msg(): T (0x7f1ef323f8c8) already found for msg (0x7f1ef9d784e8)!
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [t_reply.c:1765]: cleanup_uac_timers(): RETR/FR timers reset
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/timer.c:557]: timer_add_safe(): timer_add called on an active timer 0x7f1ef323f950 (0x7f1ef2ec8f10, 0x7f1ef323d4a8), flags 201
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} tm [t_funcs.c:146]: put_on_wait(): transaction 0x7f1ef323f8c8 already on wait
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: exec:  {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} *** cfgtrace:dbg_cfg_trace(): request_route=[PRESENCE] c=[/etc/kamailio/kamailio.cfg] l=897 a=2 n=exit
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/receive.c:436]: receive_msg(): request-route executed in: 39617 usec
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/xavp.c:541]: xavp_destroy_list(): destroying xavp list (nil)
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/xavp.c:541]: xavp_destroy_list(): destroying xavp list (nil)
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/xavp.c:541]: xavp_destroy_list(): destroying xavp list (nil)
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15920]: DEBUG: {1 21000 SUBSCRIBE 551473572-44762-6@BA.CEG.HG.GC} <core> [core/receive.c:528]: receive_msg(): cleaning up

Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15918]: DEBUG: <core> [core/udp_server.c:493]: udp_rcv_loop(): received on udp socket: (106/100/531) [[SIP/2.0 481 Subscription Does Not Exist 0D  0A Via: SIP/2.0/UDP PUBLIC_IP:PORT;branch=z9hG4bK2ba8.5e7]]
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15918]: DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): SIP Reply  (status):
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15918]: DEBUG: <core> [core/parser/msg_parser.c:621]: parse_msg():  version: <SIP/2.0>
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15918]: DEBUG: <core> [core/parser/msg_parser.c:623]: parse_msg():  status:  <481>
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15918]: DEBUG: <core> [core/parser/msg_parser.c:625]: parse_msg():  reason:  <Subscription Does Not Exist>
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15918]: DEBUG: <core> [core/parser/parse_via.c:1300]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK2ba8.5e7ce1f0000000000000000000000000.0>; state=16
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15918]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15918]: DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15918]: DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15918]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=138358676
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15918]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15918]: DEBUG: <core> [core/parser/msg_parser.c:170]: get_hdr_field(): <To> [55]; uri=[sip:305@domain.net]
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15918]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body (39)[<sip:305@domain.net>], to tag (9)[138358676]
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15918]: DEBUG: <core> [core/parser/msg_parser.c:150]: get_hdr_field(): cseq <CSeq>: <2> <NOTIFY>
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15918]: DEBUG: <core> [core/receive.c:319]: receive_msg(): --- received sip message - reply - call-id: [551473572-44762-6@BA.CEG.HG.GC] - cseq: [2 NOTIFY]
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15918]: DEBUG: <core> [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=0
Oct  1 11:31:37 Kam01 /usr/sbin/kamailio[15918]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header

-------------

As I said in my last posting, the 1782s are still having issues "481 Subscription Does Not Exist" is response to a NOTIFY for SUBSCRIBE the the device just sent in...


Jerry

On 2021-10-01 1:11 p.m., Jerry Kendall wrote:
Thanks Daniel,


Now it seems almost done.... I have 6 Grandstream phones connected and they all have 4-6 BLFs watching each other.

(I also have Yealink/Cisco/SNOM/Polycom phones to test later - one thing at a time.....)

The 2x GRP2604P all look great

The GXP2130 seems OK as well

The GXP2170 with side car seems OK

But, the 2x GXP1782 are not quit working yet.


A couple of the BLFs are OK but most are sending back 481 Subscription Does Not Exist... See blow (gotta love sngrep)

--------------------------------

2021/10/01 12:31:13.024698 SITE_IP:44762 -> PUBLIC_IP:8081
SUBSCRIBE sip:301@domain.net:8081 SIP/2.0
Via: SIP/2.0/UDP PRIVATE_IP:44762;branch=z9hG4bK806864449;rport
From: <sip:305@domain.net:8081>;tag=1883014019
To: <sip:301@domain.net:8081>
Call-ID: 551473572-44762-6@BA.CEG.HG.GC
CSeq: 27840 SUBSCRIBE
Contact: <sip:305@PRIVATE_IP:44762>
X-Grandstream-PBX: true
Max-Forwards: 70
User-Agent: Grandstream GXP1782 1.0.1.116
Expires: 60
Supported: replaces, path, timer, eventlist
Event: dialog
Accept: application/dialog-info+xml,multipart/related,application/rlmi+xml
Accept-Encoding: zlib+base64
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0

2021/10/01 12:31:13.026561 PUBLIC_IP:8081 -> SITE_IP:44762
SIP/2.0 202 OK
Via: SIP/2.0/UDP PRIVATE_IP:44762;branch=z9hG4bK806864449;rport=44762;received=SITE_IP
From: <sip:305@domain.net:8081>;tag=1883014019
To: <sip:301@domain.net:8081>;tag=5e1ee053cf7168b9d3ee9c05740f837c-eb6836a8
Call-ID: 551473572-44762-6@BA.CEG.HG.GC
CSeq: 27840 SUBSCRIBE
Expires: 60
Contact: <sip:PUBLIC_IP:8081>
Server: kamailio (5.4.4 (x86_64/linux))
Content-Length: 0

2021/10/01 12:31:13.027436 PUBLIC_IP:8081 -> SITE_IP:44762
NOTIFY sip:305@PRIVATE_IP:44762 SIP/2.0
Via: SIP/2.0/UDP PUBLIC_IP:8081;branch=z9hG4bK2ba8.555213e5000000000000000000000000.0
To: <sip:305@domain.net>;tag=1883014019
From: <sip:301@domain.net>;tag=5e1ee053cf7168b9d3ee9c05740f837c-eb6836a8
CSeq: 2 NOTIFY
Call-ID: 551473572-44762-6@BA.CEG.HG.GC
Content-Length: 273
User-Agent: kamailio (5.4.4 (x86_64/linux))
Max-Forwards: 70
Event: dialog
Contact: <sip:PUBLIC_IP:8081>
Subscription-State: active;expires=60
Content-Type: application/dialog-info+xml

<?xml version="1.0"?>
<dialog-info xmlns="urn:ietf:params:xml:ns:dialog-info" version="1" state="full" entity="sip:301@domain.net">
  <dialog id="615293b33c62dec073e05d9421e9f48b" direction="recipient"> <state>terminated</state> </dialog>
</dialog-info>

2021/10/01 12:31:13.332763 SITE_IP:44762 -> PUBLIC_IP:8081
SIP/2.0 481 Subscription Does Not Exist
Via: SIP/2.0/UDP PUBLIC_IP:8081;branch=z9hG4bK2ba8.555213e5000000000000000000000000.0
From: <sip:301@domain.net>;tag=5e1ee053cf7168b9d3ee9c05740f837c-eb6836a8
To: <sip:305@domain.net>;tag=1883014019
Call-ID: 551473572-44762-6@BA.CEG.HG.GC
CSeq: 2 NOTIFY
Supported: replaces, path, timer
User-Agent: Grandstream GXP1782 1.0.1.116
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE
Content-Length: 0
--------------------------------


Now, I am sure it's not likely the phone setup as I have a FreeSWITCH system that these 6 phones normally talk to.

All i do is change the DNS A Record between the IP of the Kamailio server and the FreeSWITCH server... This way I don't touch the phone configs..

I just change the A Records and take an hour long break...


On the FreeSWITCH server, the phones do exactly as expected...

I am trying to stick the Kamailio server between the phones and FS but, one step at a time.

So, any thoughts as to why the GXP1782 BLFs are not accepting the NOTIFY messages?


Jerry



__________________________________________________________
Kamailio - Users Mailing List - Non Commercial Discussions
 * sr-users@lists.kamailio.org
Important: keep the mailing list in the recipients, do not reply only to the sender!
Edit mailing list options or unsubscribe:
 * https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users

__________________________________________________________
Kamailio - Users Mailing List - Non Commercial Discussions
  * sr-users@lists.kamailio.org
Important: keep the mailing list in the recipients, do not reply only to the sender!
Edit mailing list options or unsubscribe:
  * https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users