2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [receive.c:221]: receive_msg(): preparing to run routing scripts...
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) called from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) returns address 0x7fc44ea651f8 
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 48) called from core: parser/msg_parser.c: get_hdr_field(135)
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 48) returns address 0x7fc44ea64fc8 
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [parser/msg_parser.c:153]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <978108> <INVITE>
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) called from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) returns address 0x7fc44ea44e08 
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) called from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) returns address 0x7fc44ea65040 
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) called from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) returns address 0x7fc44ea44cf8 
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) called from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) returns address 0x7fc44ea44f18 
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) called from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) returns address 0x7fc44ea45028 
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [parser/msg_parser.c:187]: get_hdr_field(): DEBUG: get_hdr_body : content_length=428
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) called from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) returns address 0x7fc44ea37ad0 
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) called from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) returns address 0x7fc44ea67260 
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) called from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) returns address 0x7fc44ea65280 
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) called from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) returns address 0x7fc44ea67020 
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) called from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) returns address 0x7fc44ea44360 
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) called from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) returns address 0x7fc44ea37b58 
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [parser/msg_parser.c:89]: get_hdr_field(): found end of header
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea37b58), called from core: parser/msg_parser.c: parse_headers(343)
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 472) called from sanity: sanity.c: check_parse_uris(789)
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 472) returns address 0x7fc44ea65308 
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 48) called from core: parser/parse_addr_spec.c: parse_to_param(281)
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 48) returns address 0x7fc44ea64e40 
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [parser/parse_addr_spec.c:172]: parse_to_param(): DEBUG: add_param: tag=m6GvVA
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [parser/parse_addr_spec.c:894]: parse_addr_spec(): end of header reached, state=29
2016-12-06 11:13:12.360  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: sanity [mod_sanity.c:248]: w_sanity_check(): sanity checks result: 1
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value = 49 
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 66) called from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 72) returns address 0x7fc3d127a9b8 
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 45) called from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 48) returns address 0x7fc3d118a2f0 
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 58) called from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 64) returns address 0x7fc3d128c9d8 
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 48) called from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 48) returns address 0x7fc3d11a7d58 
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 936) called from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 936) returns address 0x7fc44ea40668 
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea40668), called from core: rvalue.c: rval_destroy(129)
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc3cddf9000, 0x7fc3d11a7d58), called from core: usr_avp.c: destroy_avp(592)
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 48) called from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 48) returns address 0x7fc3d11a7d58 
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <script>:  SOURCE -  172.112.10.231:5060 ID=jzcdBZh5ipLIMXPsy5Bk3Q
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} INFO: <script>: New request - M=INVITE R=sip:8063177900@example.local F=sip:+12143177800@example.local T=sip:8063177900@example.local IP=udp:172.112.10.231:5060 ID=jzcdBZh5ipLIMXPsy5Bk3Q
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 968) called from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 968) returns address 0x7fc44ea33a90 
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea33a90), called from core: rvalue.c: rval_destroy(129)
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [parser/parse_addr_spec.c:894]: parse_addr_spec(): end of header reached, state=10
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 496) called from core: parser/parse_ppi_pai.c: parse_pai_ppi_body(83)
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 496) returns address 0x7fc44ea403e0 
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) called from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) returns address 0x7fc44ea37b58 
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [parser/msg_parser.c:89]: get_hdr_field(): found end of header
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea37b58), called from core: parser/msg_parser.c: parse_headers(343)
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 74) called from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 80) returns address 0x7fc3d0f4c6f8 
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} INFO: <script>: [GET_CLIENT_ID] Apply Manip2 in PAI uri sip:2143177800@example.local (2143177800) to query numbers table in order to get client ID for this call  ID=jzcdBZh5ipLIMXPsy5Bk3Q
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 52) called from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 56) returns address 0x7fc3d124e448 
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 64) called from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 64) returns address 0x7fc3d128c8d8 
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: pv [pv_core.c:800]: pv_get_useragent(): no User-Agent header
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} INFO: <script>: Applying rewrite rules on '2143177800' using dialplan 'Manip2' - R=sip:8063177900@example.local ID=jzcdBZh5ipLIMXPsy5Bk3Q UA='<null>'
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dialplan.c:226]: dp_get_ivalue(): searching 4
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dialplan.c:234]: dp_get_ivalue(): dpid is 2 from pv argument
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dialplan.c:243]: dp_get_svalue(): searching 4 
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dialplan.c:331]: dp_translate_f(): input is 2143177800
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dp_repl.c:592]: translate(): regex operator testing over [2143177800]
2016-12-06 11:13:12.361  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dp_repl.c:592]: translate(): regex operator testing over [2143177800]
2016-12-06 11:13:12.362  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dp_repl.c:592]: translate(): regex operator testing over [2143177800]
2016-12-06 11:13:12.362  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dp_repl.c:657]: translate(): no matching rule
2016-12-06 11:13:12.362  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dialplan.c:336]: dp_translate_f(): could not translate 2143177800 with dpid 2
2016-12-06 11:13:12.362  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: pv [pv_core.c:800]: pv_get_useragent(): no User-Agent header
2016-12-06 11:13:12.362  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} INFO: <script>: No matching rewrite rules for '2143177800' found - R=sip:8063177900@example.local ID=jzcdBZh5ipLIMXPsy5Bk3Q UA='<null>'
2016-12-06 11:13:12.362  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} INFO: <script>: Clean AVPs that contains rewrite rule from method ROUTE_APPLY_REWRITE_RULE ID=jzcdBZh5ipLIMXPsy5Bk3Q
2016-12-06 11:13:12.362  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc3cddf9000, 0x7fc3d0f4c6f8), called from core: usr_avp.c: destroy_avp(592)
2016-12-06 11:13:12.362  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.362  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc3cddf9000, 0x7fc3d124e448), called from core: usr_avp.c: destroy_avp(592)
2016-12-06 11:13:12.362  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.362  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc3cddf9000, 0x7fc3d128c8d8), called from core: usr_avp.c: destroy_avp(592)
2016-12-06 11:13:12.362  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.362  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 121) called from db_postgres: km_dbase.c: db_postgres_submit_query(208)
2016-12-06 11:13:12.362  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 128) returns address 0x7fc44ea44038 
2016-12-06 11:13:12.367  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: db_postgres [km_dbase.c:272]: db_postgres_submit_query(): sending query ok: 0x7fc44ea96eb0 (2) - [select a.client_id, b.operator_context  from numbers a, clients b where '<null>' ~ psi and a.client_id=b.id;]
2016-12-06 11:13:12.367  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea44038), called from db_postgres: km_dbase.c: db_postgres_submit_query(273)
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from db_postgres: km_dbase.c: db_postgres_submit_query(208)
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: db_res.c: db_new_result(110)
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea38008 
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_res.c:116]: db_new_result(): allocate 56 bytes for result set at 0x7fc44ea38008
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: db_postgres [km_dbase.c:552]: db_postgres_store_result(): 0x7fc44ea96eb0 PQresultStatus(PGRES_TUPLES_OK) PQgetResult(0x1c7e860)
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: db_postgres [km_res.c:108]: db_postgres_get_columns(): 2 columns returned from the query
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 16) called from core: db_res.c: db_allocate_columns(146)
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 16) returns address 0x7fc44eab74d8 
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_res.c:154]: db_allocate_columns(): allocate 16 bytes for result names at 0x7fc44eab74d8
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 8) called from core: db_res.c: db_allocate_columns(156)
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 8) returns address 0x7fc44ea307c8 
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_res.c:165]: db_allocate_columns(): allocate 8 bytes for result types at 0x7fc44ea307c8
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 16) called from db_postgres: km_res.c: db_postgres_get_columns(119)
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 16) returns address 0x7fc44eab7f38 
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: db_postgres [km_res.c:126]: db_postgres_get_columns(): allocate 16 bytes for RES_NAMES[0] at 0x7fc44eab7f38
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: db_postgres [km_res.c:133]: db_postgres_get_columns(): RES_NAMES(0x7fc44eab7f38)[0]=[client_id]
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: db_postgres [km_res.c:140]: db_postgres_get_columns(): use DB1_INT result type
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 16) called from db_postgres: km_res.c: db_postgres_get_columns(119)
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 16) returns address 0x7fc44eab7ca0 
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: db_postgres [km_res.c:126]: db_postgres_get_columns(): allocate 16 bytes for RES_NAMES[1] at 0x7fc44eab7ca0
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: db_postgres [km_res.c:133]: db_postgres_get_columns(): RES_NAMES(0x7fc44eab7ca0)[1]=[operator_context]
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: db_postgres [km_res.c:166]: db_postgres_get_columns(): use DB1_STRING result type
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: db_postgres [km_res.c:211]: db_postgres_convert_rows(): no rows returned from the query
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: sqlops [sql_api.c:271]: sql_do_query(): no result after query
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_res.c:79]: db_free_columns(): freeing 2 columns
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[0] at 0x7fc44eab7f38
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44eab7f38), called from core: db_res.c: db_free_columns(84)
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from db_postgres: km_res.c: db_postgres_get_columns(119)
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[1] at 0x7fc44eab7ca0
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44eab7ca0), called from core: db_res.c: db_free_columns(84)
2016-12-06 11:13:12.368  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from db_postgres: km_res.c: db_postgres_get_columns(119)
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_res.c:92]: db_free_columns(): freeing result names at 0x7fc44eab74d8
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44eab74d8), called from core: db_res.c: db_free_columns(93)
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: db_res.c: db_allocate_columns(146)
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_res.c:97]: db_free_columns(): freeing result types at 0x7fc44ea307c8
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea307c8), called from core: db_res.c: db_free_columns(98)
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: db_res.c: db_allocate_columns(156)
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_res.c:134]: db_free_result(): freeing result set at 0x7fc44ea38008
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea38008), called from core: db_res.c: db_free_result(135)
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: db_res.c: db_new_result(110)
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: db_postgres [km_dbase.c:433]: db_postgres_free_query(): PQclear(0x1c7e860) result set
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} INFO: <script>: [GET_CLIENT_ID] Caller Client ID=<null> Operator_context=<null>  ID=jzcdBZh5ipLIMXPsy5Bk3Q
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 74) called from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 80) returns address 0x7fc3d0f4c6f8 
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 52) called from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 56) returns address 0x7fc3d128c8d8 
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 64) called from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 64) returns address 0x7fc3d124e448 
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: pv [pv_core.c:800]: pv_get_useragent(): no User-Agent header
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} INFO: <script>: Applying rewrite rules on '8063177900' using dialplan 'Manip2' - R=sip:8063177900@example.local ID=jzcdBZh5ipLIMXPsy5Bk3Q UA='<null>'
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dialplan.c:226]: dp_get_ivalue(): searching 4
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dialplan.c:234]: dp_get_ivalue(): dpid is 2 from pv argument
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dialplan.c:243]: dp_get_svalue(): searching 4 
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dialplan.c:331]: dp_translate_f(): input is 8063177900
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dp_repl.c:592]: translate(): regex operator testing over [8063177900]
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dp_repl.c:592]: translate(): regex operator testing over [8063177900]
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dp_repl.c:592]: translate(): regex operator testing over [8063177900]
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dp_repl.c:657]: translate(): no matching rule
2016-12-06 11:13:12.369  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dialplan.c:336]: dp_translate_f(): could not translate 8063177900 with dpid 2
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: pv [pv_core.c:800]: pv_get_useragent(): no User-Agent header
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} INFO: <script>: No matching rewrite rules for '8063177900' found - R=sip:8063177900@example.local ID=jzcdBZh5ipLIMXPsy5Bk3Q UA='<null>'
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 70) called from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 72) returns address 0x7fc3d1283900 
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} INFO: <script>: Clean AVPs that contains rewrite rule from method ROUTE_APPLY_REWRITE_RULE ID=jzcdBZh5ipLIMXPsy5Bk3Q
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc3cddf9000, 0x7fc3d0f4c6f8), called from core: usr_avp.c: destroy_avp(592)
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc3cddf9000, 0x7fc3d128c8d8), called from core: usr_avp.c: destroy_avp(592)
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc3cddf9000, 0x7fc3d124e448), called from core: usr_avp.c: destroy_avp(592)
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 54) called from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 56) returns address 0x7fc3d124e448 
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} INFO: <script>: [GET_CLIENT_ID] Callee Client ID=155 ID=jzcdBZh5ipLIMXPsy5Bk3Q
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: siputils [checks.c:97]: has_totag(): no totag
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: del_lump(304)
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea38008 
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: rr [loose.c:1125]: is_direction(): param ftag not found
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: anchor_lump(358)
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea38088 
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: anchor_lump(358)
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea37f88 
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_cond_lump_after(234)
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea40360 
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_cond_lump_before(260)
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea37b58 
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 19) called from rr: record.c: build_rr(227)
2016-12-06 11:13:12.370  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 24) returns address 0x7fc44eab74d8 
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 23) called from rr: record.c: build_rr(228)
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 24) returns address 0x7fc44eab7ca0 
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 3) called from rr: record.c: build_rr(229)
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 8) returns address 0x7fc44ea307c8 
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 6) called from rr: record.c: build_rr(230)
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 8) returns address 0x7fc44ea43e88 
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_new_lump_after(133)
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea37e48 
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_subst_lump_after(183)
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea37ee8 
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_cond_lump_after(234)
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea37d30 
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_new_lump_after(133)
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea44460 
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_new_lump_before(158)
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea43f90 
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_new_lump_before(158)
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea43ed8 
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: anchor_lump(358)
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea44038 
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: anchor_lump(358)
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea45138 
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 19) called from rr: record.c: build_rr(227)
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 24) returns address 0x7fc44eab7f38 
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 23) called from rr: record.c: build_rr(228)
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 24) returns address 0x7fc44eab7240 
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 3) called from rr: record.c: build_rr(229)
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 8) returns address 0x7fc44ea54238 
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 6) called from rr: record.c: build_rr(230)
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 8) returns address 0x7fc44ea5e5f0 
2016-12-06 11:13:12.371  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_new_lump_after(133)
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea451b8 
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_subst_lump_after(183)
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea44100 
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_cond_lump_after(234)
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea44180 
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_new_lump_after(133)
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea650c8 
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_new_lump_before(158)
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea65148 
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_new_lump_before(158)
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea37be8 
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} INFO: <script>: Handle INVITE Request - R=sip:8063177900@example.local F=sip:+12143177800@example.local ID=jzcdBZh5ipLIMXPsy5Bk3Q
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} WARNING: <script>: Search for CPC parameter on PAI/FROM header - F=sip:+12143177800@example.local R=sip:8063177900@example.local ID=jzcdBZh5ipLIMXPsy5Bk3Q 
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 15) called from pv: pv_svar.c: set_var_value(128)
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 16) returns address 0x7fc44eab6018 
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 53) called from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 56) returns address 0x7fc3d128c8d8 
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} INFO: <script>: CPC= ID=jzcdBZh5ipLIMXPsy5Bk3Q 
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} WARNING: <script>: -AS trigger-off, send call to outbound Terminated part ID=jzcdBZh5ipLIMXPsy5Bk3Q
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 79) called from db_postgres: km_dbase.c: db_postgres_submit_query(208)
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 80) returns address 0x7fc44ea37c68 
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: db_postgres [km_dbase.c:272]: db_postgres_submit_query(): sending query ok: 0x7fc44ea96eb0 (2) - [select terminal_sip_uri from terminals where terminal_sip_uri='8063177900';]
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea37c68), called from db_postgres: km_dbase.c: db_postgres_submit_query(273)
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from db_postgres: km_dbase.c: db_postgres_submit_query(208)
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: db_res.c: db_new_result(110)
2016-12-06 11:13:12.372  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea37c68 
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_res.c:116]: db_new_result(): allocate 56 bytes for result set at 0x7fc44ea37c68
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: db_postgres [km_dbase.c:552]: db_postgres_store_result(): 0x7fc44ea96eb0 PQresultStatus(PGRES_TUPLES_OK) PQgetResult(0x29b16d0)
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: db_postgres [km_res.c:108]: db_postgres_get_columns(): 1 columns returned from the query
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 8) called from core: db_res.c: db_allocate_columns(146)
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 8) returns address 0x7fc44ea72948 
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_res.c:154]: db_allocate_columns(): allocate 8 bytes for result names at 0x7fc44ea72948
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 4) called from core: db_res.c: db_allocate_columns(156)
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 8) returns address 0x7fc44ea86278 
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_res.c:165]: db_allocate_columns(): allocate 4 bytes for result types at 0x7fc44ea86278
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 16) called from db_postgres: km_res.c: db_postgres_get_columns(119)
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 16) returns address 0x7fc44eab62b0 
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: db_postgres [km_res.c:126]: db_postgres_get_columns(): allocate 16 bytes for RES_NAMES[0] at 0x7fc44eab62b0
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: db_postgres [km_res.c:133]: db_postgres_get_columns(): RES_NAMES(0x7fc44eab62b0)[0]=[terminal_sip_uri]
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: db_postgres [km_res.c:166]: db_postgres_get_columns(): use DB1_STRING result type
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 8) called from db_postgres: km_res.c: db_postgres_convert_rows(217)
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 8) returns address 0x7fc44ea8b028 
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: db_postgres [km_res.c:222]: db_postgres_convert_rows(): allocate for 1 columns 8 bytes in row buffer at 0x7fc44ea8b028
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 16) called from core: db_res.c: db_allocate_rows(179)
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 16) returns address 0x7fc44eab6548 
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_res.c:184]: db_allocate_rows(): allocate 16 bytes for rows at 0x7fc44eab6548
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: db_postgres [km_res.c:243]: db_postgres_convert_rows(): PQgetvalue(0x7fc44ea96eb0,0,0)=[8063177900]
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: db_postgres [km_res.c:252]: db_postgres_convert_rows(): [0][0] Column[terminal_sip_uri]=[8063177900]
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 32) called from core: db_row.c: db_allocate_row(112)
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 32) returns address 0x7fc44ea44508 
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_row.c:117]: db_allocate_row(): allocate 32 bytes for row values at 0x7fc44ea44508
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_val.c:118]: db_str2val(): converting STRING [8063177900]
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 11) called from core: db_val.c: db_str2val(123)
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 16) returns address 0x7fc44eab6fa8 
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_val.c:128]: db_str2val(): allocate 11 bytes memory for STRING at 0x7fc44eab6fa8
2016-12-06 11:13:12.373  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: db_postgres [km_res.c:267]: db_postgres_convert_rows(): freeing row buffer at 0x7fc44ea8b028
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea8b028), called from db_postgres: km_res.c: db_postgres_convert_rows(268)
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from db_postgres: km_res.c: db_postgres_convert_rows(217)
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: sqlops [sql_api.c:284]: sql_do_query(): rows [1] cols [1]
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 24) called from sqlops: sql_api.c: sql_do_query(286)
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 24) returns address 0x7fc44eab7a08 
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 17) called from sqlops: sql_api.c: sql_do_query(299)
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 24) returns address 0x7fc44eab6a78 
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 8) called from sqlops: sql_api.c: sql_do_query(311)
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 8) returns address 0x7fc44ea8b028 
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 24) called from sqlops: sql_api.c: sql_do_query(320)
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 24) returns address 0x7fc44eab7770 
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 10) called from sqlops: sql_api.c: sql_do_query(398)
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 16) returns address 0x7fc44eab5d80 
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_res.c:79]: db_free_columns(): freeing 1 columns
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_res.c:83]: db_free_columns(): freeing RES_NAMES[0] at 0x7fc44eab62b0
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44eab62b0), called from core: db_res.c: db_free_columns(84)
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from db_postgres: km_res.c: db_postgres_get_columns(119)
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_res.c:92]: db_free_columns(): freeing result names at 0x7fc44ea72948
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea72948), called from core: db_res.c: db_free_columns(93)
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: db_res.c: db_allocate_columns(146)
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_res.c:97]: db_free_columns(): freeing result types at 0x7fc44ea86278
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea86278), called from core: db_res.c: db_free_columns(98)
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: db_res.c: db_allocate_columns(156)
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_res.c:52]: db_free_rows(): freeing 1 rows
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_row.c:66]: db_free_row(): free VAL_STRING[0] '8063177900' at 0x7fc44eab6fa8
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44eab6fa8), called from core: db_row.c: db_free_row(67)
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: db_val.c: db_str2val(123)
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_row.c:95]: db_free_row(): freeing row values at 0x7fc44ea44508
2016-12-06 11:13:12.374  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea44508), called from core: db_row.c: db_free_row(96)
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: db_row.c: db_allocate_row(112)
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_res.c:60]: db_free_rows(): freeing rows at 0x7fc44eab6548
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44eab6548), called from core: db_res.c: db_free_rows(61)
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: db_res.c: db_allocate_rows(179)
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [db_res.c:134]: db_free_result(): freeing result set at 0x7fc44ea37c68
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea37c68), called from core: db_res.c: db_free_result(135)
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: db_res.c: db_new_result(110)
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: db_postgres [km_dbase.c:433]: db_postgres_free_query(): PQclear(0x29b16d0) result set
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 11) called from pv: pv_svar.c: set_var_value(128)
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 16) returns address 0x7fc44eab6548 
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} INFO: <script>: [IS_SIP_TERMINAL] Call destinated to SIP TERMINAL - M=INVITE R=sip:8063177900@example.local F=sip:+12143177800@example.local ID=jzcdBZh5ipLIMXPsy5Bk3Q
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: htable [ht_var.c:90]: pv_set_ht_cell(): set value for $sht(sip_terminal_cache=>sip:8063177900@example.local:terminals)
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 120) called from htable: ht_api.c: ht_cell_new(183)
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 120) returns address 0x7fc3d11d9ea0 
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: registrar [lookup.c:240]: lookup_helper(): contact for [8063177900@example.local] found by address
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 39) called from core: dset.c: rewrite_uri(599)
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 40) returns address 0x7fc44ea37dd8 
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 20) called from core: parser/msg_parser.c: set_ruid(881)
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 24) returns address 0x7fc44eab6fa8 
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 4) called from core: parser/msg_parser.c: set_ua(920)
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 8) returns address 0x7fc44ea86278 
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} INFO: <script>: routing to registered phone ruid=uloc-58469d2a-2156-8 R=sip:172.112.10.227:5060;aor=8063177900 - ID=jzcdBZh5ipLIMXPsy5Bk3Q 
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 61) called from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 64) returns address 0x7fc3d1245500 
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 936) called from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 936) returns address 0x7fc44ea40668 
2016-12-06 11:13:12.375  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 936) called from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 936) returns address 0x7fc44ea33a90 
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea40668), called from core: rvalue.c: rval_destroy(129)
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea33a90), called from core: rvalue.c: rval_destroy(129)
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 5) called from pv: pv_svar.c: set_var_value(128)
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 8) returns address 0x7fc44ea72948 
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc3cddf9000, 0x7fc3d1245500), called from core: usr_avp.c: destroy_avp(592)
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 944) called from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 944) returns address 0x7fc44ea40668 
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 968) called from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 968) returns address 0x7fc44ea33a90 
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea40668), called from core: rvalue.c: rval_destroy(129)
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 936) called from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 936) returns address 0x7fc44ea40668 
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea33a90), called from core: rvalue.c: rval_destroy(129)
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 24) called from pv: pv_svar.c: set_var_value(128)
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 24) returns address 0x7fc44eab62b0 
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea40668), called from core: rvalue.c: rval_destroy(129)
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: tm [t_lookup.c:1312]: t_newtran(): DEBUG: t_newtran: msg id=139 , global msg id=138 , T on entrance=0xffffffffffffffff
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: tm [t_lookup.c:466]: t_lookup_request(): t_lookup_request: start searching: hash=30498, isACK=0
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: tm [t_lookup.c:424]: matching_3261(): DEBUG: RFC3261 transaction matching failed
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: tm [t_lookup.c:648]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found
2016-12-06 11:13:12.376  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 5704) called from tm: h_table.c: build_cell(317)
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 5704) returns address 0x7fc3d11fa418 
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 5392) called from core: sip_msg_clone.c: sip_msg_shm_clone(494)
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 5392) returns address 0x7fc3d11e9cc8 
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [md5utils.c:67]: MD5StringArray(): MD5 calculated: bd89331ceda4ee9ba99b367e8617061c
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: tm [t_funcs.c:321]: t_relay_to(): SER: new INVITE
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 59) called from core: msg_translator.c: received_builder(323)
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) returns address 0x7fc44ea37c68 
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 12) called from core: msg_translator.c: rport_builder(356)
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 16) returns address 0x7fc44eab5ae8 
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 375) called from core: msg_translator.c: build_res_buf_from_sip_req(2418)
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 376) returns address 0x7fc44ea40668 
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea37c68), called from core: msg_translator.c: build_res_buf_from_sip_req(2581)
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: msg_translator.c: received_builder(323)
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44eab5ae8), called from core: msg_translator.c: build_res_buf_from_sip_req(2582)
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: msg_translator.c: rport_builder(356)
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 534) called from tm: t_reply.c: _reply_light(542)
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 536) returns address 0x7fc3d11f0fb0 
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: tm [t_reply.c:648]: _reply_light(): DEBUG: reply sent out. buf=0x7fc44ea40668: SIP/2.0 100 trying -..., shmem=0x7fc3d11f0fb0: SIP/2.0 100 trying -
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea40668), called from tm: t_reply.c: _reply_light(657)
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: msg_translator.c: build_res_buf_from_sip_req(2418)
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: tm [t_reply.c:658]: _reply_light(): DEBUG: _reply_light: finished
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 1192) called from core: sip_msg_clone.c: msg_lump_cloner(978)
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 1192) returns address 0x7fc3d11e77f0 
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea37c68 
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.377  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea45250 
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea452d0 
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea45350 
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea40668 
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea406e8 
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea40768 
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea40828 
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea408a8 
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea40928 
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea409a8 
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea33a90 
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea33b10 
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea33b90 
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea33c10 
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea33c90 
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.378  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea33d10 
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea33d90 
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea33e10 
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 38) called from tm: t_fwd.c: prepare_new_uac(229)
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 40) returns address 0x7fc44ea33e90 
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 20) called from core: parser/msg_parser.c: set_ruid(881)
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 24) returns address 0x7fc44eab5ae8 
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 4) called from core: parser/msg_parser.c: set_ua(920)
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 8) returns address 0x7fc44e791830 
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <script>: new ONNET branch [0] to sip:172.112.10.227:5060;aor=8063177900
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} INFO: <script>: [_CALLS] Last FROM/PAI manipulations using Manip2- M=INVITE R=sip:172.112.10.227:5060;aor=8063177900 F=sip:+12143177800@example.local ID=jzcdBZh5ipLIMXPsy5Bk3Q
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 76) called from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 80) returns address 0x7fc3d0f4c6f8 
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 52) called from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 56) returns address 0x7fc3d1245500 
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 64) called from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 64) returns address 0x7fc3d124dde0 
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: pv [pv_core.c:800]: pv_get_useragent(): no User-Agent header
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} INFO: <script>: Applying rewrite rules on '+12143177800' using dialplan 'Manip2' - R=sip:172.112.10.227:5060;aor=8063177900 ID=jzcdBZh5ipLIMXPsy5Bk3Q UA='<null>'
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dialplan.c:226]: dp_get_ivalue(): searching 4
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dialplan.c:234]: dp_get_ivalue(): dpid is 2 from pv argument
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dialplan.c:243]: dp_get_svalue(): searching 4 
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dialplan.c:331]: dp_translate_f(): input is +12143177800
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dp_repl.c:592]: translate(): regex operator testing over [+12143177800]
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dp_repl.c:592]: translate(): regex operator testing over [+12143177800]
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dp_repl.c:592]: translate(): regex operator testing over [+12143177800]
2016-12-06 11:13:12.379  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dp_repl.c:662]: translate(): found a matching rule 0x7fc3d0ed31e0: pr 1, match_exp ^\+1[1-9][0-9]{9}$
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dp_repl.c:669]: translate(): the rule's attrs are Manip 2
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dp_repl.c:680]: translate(): the copied attributes are: Manip 2
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dp_repl.c:481]: rule_translate(): copying match <2143177800> token size 2
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dialplan.c:340]: dp_translate_f(): input +12143177800 with dpid 2 => output 2143177800
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 76) called from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 80) returns address 0x7fc3d11cb908 
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 71) called from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 72) returns address 0x7fc3d11c2da0 
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: pv [pv_core.c:800]: pv_get_useragent(): no User-Agent header
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} NOTICE: <script>: Rewriting '+12143177800' to '2143177800' - R=sip:172.112.10.227:5060;aor=8063177900 ID=jzcdBZh5ipLIMXPsy5Bk3Q UA='<null>'
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 944) called from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 944) returns address 0x7fc44ea30920 
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 960) called from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 960) returns address 0x7fc44ea2d5f8 
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea30920), called from core: rvalue.c: rval_destroy(129)
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 952) called from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 952) returns address 0x7fc44ea30920 
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea2d5f8), called from core: rvalue.c: rval_destroy(129)
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 35) called from pv: pv_svar.c: set_var_value(128)
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 40) returns address 0x7fc44ea33f00 
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea30920), called from core: rvalue.c: rval_destroy(129)
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: uac [uac.c:441]: w_replace_from(): dsp=0x7ffc38397b30 (len=12) , uri=0x7ffc38397b40 (len=34)
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: uac [replace.c:306]: replace_uri(): removing display ["2143177800"]
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: del_lump(304)
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea33f70 
2016-12-06 11:13:12.380  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 14) called from uac: replace.c: replace_uri(319)
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 16) returns address 0x7fc44eab5850 
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_new_lump_after(133)
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea33ff0 
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: uac [replace.c:346]: replace_uri(): uri to replace [sip:+12143177800@example.local]
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: uac [replace.c:347]: replace_uri(): replacement uri is [sip:2143177800@example.local]
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: del_lump(304)
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea34070 
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 34) called from uac: replace.c: replace_uri(355)
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 40) returns address 0x7fc44ea340f0 
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_new_lump_after(133)
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea30920 
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: uac [replace.c:458]: replace_uri(): encode is=<AAAAABkABgIFBAYPBwhwUSICFxAUXQNbEBsbAEcCQQ8OD2Fs> len=48
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 53) called from uac: replace.c: replace_uri(462)
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea309a0 
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 53) called from rr: record.c: insert_rr_param_lump(171)
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea30a20 
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_new_lump_before(158)
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea30aa0 
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 53) called from rr: record.c: insert_rr_param_lump(171)
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea30b20 
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_new_lump_before(158)
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea30ba0 
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea309a0), called from uac: replace.c: replace_uri(480)
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from uac: replace.c: replace_uri(462)
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 40) called from tm: t_hooks.c: insert_tmcb(137)
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 40) returns address 0x7fc3d11e5478 
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 37) called from pv: pv_trans.c: tr_eval_nameaddr(1525)
2016-12-06 11:13:12.381  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 40) returns address 0x7fc44ea309a0 
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 1) called from pv: pv_svar.c: set_var_value(128)
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 8) returns address 0x7fc44e796e40 
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 11) called from pv: pv_svar.c: set_var_value(128)
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 16) returns address 0x7fc44eab55b8 
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 20) called from pv: pv_svar.c: set_var_value(128)
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 24) returns address 0x7fc44eab5320 
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: del_lump(304)
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea30c20 
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 928) called from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 928) returns address 0x7fc44ea2d5f8 
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 936) called from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 936) returns address 0x7fc44ea22890 
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea2d5f8), called from core: rvalue.c: rval_destroy(129)
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea22890), called from core: rvalue.c: rval_destroy(129)
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 928) called from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 928) returns address 0x7fc44ea22890 
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea22890), called from core: rvalue.c: rval_destroy(129)
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: anchor_lump(358)
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea30ca0 
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 58) called from textops: textops.c: add_hf_helper(2277)
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) returns address 0x7fc44ea30d20 
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_new_lump_before(158)
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea30da8 
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} INFO: <script>: Clean AVPs that contains rewrite rule from method ROUTE_APPLY_REWRITE_RULE ID=jzcdBZh5ipLIMXPsy5Bk3Q
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc3cddf9000, 0x7fc3d0f4c6f8), called from core: usr_avp.c: destroy_avp(592)
2016-12-06 11:13:12.382  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc3cddf9000, 0x7fc3d1245500), called from core: usr_avp.c: destroy_avp(592)
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc3cddf9000, 0x7fc3d11cb908), called from core: usr_avp.c: destroy_avp(592)
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc3cddf9000, 0x7fc3d124dde0), called from core: usr_avp.c: destroy_avp(592)
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} INFO: <script>: [_CALLS] Last RURI/TO manipulations using Manip2- M=INVITE R=sip:172.112.10.227:5060;aor=8063177900 F=sip:+12143177800@example.local ID=jzcdBZh5ipLIMXPsy5Bk3Q
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 52) called from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 56) returns address 0x7fc3d124dde0 
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 64) called from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 64) returns address 0x7fc3d1245500 
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: pv [pv_core.c:800]: pv_get_useragent(): no User-Agent header
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} INFO: <script>: Applying rewrite rules on '<null>' using dialplan 'Manip2' - R=sip:172.112.10.227:5060;aor=8063177900 ID=jzcdBZh5ipLIMXPsy5Bk3Q UA='<null>'
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dialplan.c:226]: dp_get_ivalue(): searching 4
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dialplan.c:234]: dp_get_ivalue(): dpid is 2 from pv argument
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: dialplan [dialplan.c:243]: dp_get_svalue(): searching 4 
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} ERROR: dialplan [dialplan.c:247]: dp_get_svalue(): no AVP, XAVP or SCRIPTVAR found (error in scripts)
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} ERROR: dialplan [dialplan.c:327]: dp_translate_f(): invalid param 2
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: pv [pv_core.c:800]: pv_get_useragent(): no User-Agent header
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} INFO: <script>: No matching rewrite rules for '<null>' found - R=sip:172.112.10.227:5060;aor=8063177900 ID=jzcdBZh5ipLIMXPsy5Bk3Q UA='<null>'
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} INFO: <script>: Clean AVPs that contains rewrite rule from method ROUTE_APPLY_REWRITE_RULE ID=jzcdBZh5ipLIMXPsy5Bk3Q
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc3cddf9000, 0x7fc3d124dde0), called from core: usr_avp.c: destroy_avp(592)
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc3cddf9000, 0x7fc3d1245500), called from core: usr_avp.c: destroy_avp(592)
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: usr_avp.c: create_avp(175)
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 928) called from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 928) returns address 0x7fc44ea22890 
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea22890), called from core: rvalue.c: rval_destroy(129)
2016-12-06 11:13:12.383  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: rvalue.c: rval_new_empty(224)
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: del_lump(304)
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea30e28 
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: del_lump(304)
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea30ea8 
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 23) called from core: parser/msg_parser.c: set_dst_uri(761)
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 24) returns address 0x7fc44eab5088 
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: anchor_lump(358)
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea30f28 
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 95) called from core: msg_translator.c: via_builder(2718)
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 96) returns address 0x7fc44ea22890 
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 59) called from core: msg_translator.c: received_builder(323)
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 64) returns address 0x7fc44ea30fa8 
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 12) called from core: msg_translator.c: rport_builder(356)
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 16) returns address 0x7fc44eab4df0 
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: anchor_lump(358)
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea22938 
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_new_lump_after(133)
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea229b8 
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: del_lump(304)
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea22a38 
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_new_lump_after(133)
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea22ab8 
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_new_lump_before(158)
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea22b38 
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 1249) called from core: msg_translator.c: build_req_buf_from_sip_req(2153)
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 1256) returns address 0x7fc3d11f29d0 
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 21) called from tm: t_fwd.c: prepare_new_uac(509)
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 24) returns address 0x7fc3d128eec0 
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 5) called from tm: t_fwd.c: prepare_new_uac(524)
2016-12-06 11:13:12.384  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc3cddf9000, 8) returns address 0x7fc3d128ee58 
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea33e90), called from tm: t_fwd.c: prepare_new_uac(551)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from tm: t_fwd.c: prepare_new_uac(229)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44eab5ae8), called from core: parser/msg_parser.c: reset_ruid(898)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: set_ruid(881)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44e791830), called from core: parser/msg_parser.c: reset_ua(937)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: set_ua(920)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44eab5088), called from core: parser/msg_parser.c: reset_dst_uri(779)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: set_dst_uri(761)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea45250), called from core: data_lump.c: free_duped_lump_list(619)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea452d0), called from core: data_lump.c: free_duped_lump_list(619)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea45350), called from core: data_lump.c: free_duped_lump_list(619)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea40668), called from core: data_lump.c: free_duped_lump_list(619)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea406e8), called from core: data_lump.c: free_duped_lump_list(619)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea37c68), called from core: data_lump.c: free_duped_lump_list(625)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea40828), called from core: data_lump.c: free_duped_lump_list(612)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea408a8), called from core: data_lump.c: free_duped_lump_list(612)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea30a20), called from core: data_lump.c: free_lump(466)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from rr: record.c: insert_rr_param_lump(171)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea30aa0), called from core: data_lump.c: free_duped_lump_list(612)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_new_lump_before(158)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea40928), called from core: data_lump.c: free_duped_lump_list(612)
2016-12-06 11:13:12.385  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea40768), called from core: data_lump.c: free_duped_lump_list(625)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea33a90), called from core: data_lump.c: free_duped_lump_list(619)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea33b10), called from core: data_lump.c: free_duped_lump_list(619)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea33b90), called from core: data_lump.c: free_duped_lump_list(619)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea33c10), called from core: data_lump.c: free_duped_lump_list(619)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea409a8), called from core: data_lump.c: free_duped_lump_list(625)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea33d10), called from core: data_lump.c: free_duped_lump_list(612)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea30b20), called from core: data_lump.c: free_lump(466)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from rr: record.c: insert_rr_param_lump(171)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea30ba0), called from core: data_lump.c: free_duped_lump_list(612)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_new_lump_before(158)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea33d90), called from core: data_lump.c: free_duped_lump_list(612)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea33c90), called from core: data_lump.c: free_duped_lump_list(625)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea22890), called from core: data_lump.c: free_lump(466)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: msg_translator.c: via_builder(2718)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea22b38), called from core: data_lump.c: free_duped_lump_list(612)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_new_lump_before(158)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea30f28), called from core: data_lump.c: free_duped_lump_list(625)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: anchor_lump(358)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea30fa8), called from core: data_lump.c: free_lump(466)
2016-12-06 11:13:12.386  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: msg_translator.c: received_builder(323)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea229b8), called from core: data_lump.c: free_duped_lump_list(619)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_new_lump_after(133)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea22938), called from core: data_lump.c: free_duped_lump_list(625)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: anchor_lump(358)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44eab4df0), called from core: data_lump.c: free_lump(466)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: msg_translator.c: rport_builder(356)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea22ab8), called from core: data_lump.c: free_duped_lump_list(619)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_new_lump_after(133)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea22a38), called from core: data_lump.c: free_duped_lump_list(625)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: del_lump(304)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44eab5850), called from core: data_lump.c: free_lump(466)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from uac: replace.c: replace_uri(319)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea33ff0), called from core: data_lump.c: free_duped_lump_list(619)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_new_lump_after(133)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea33f70), called from core: data_lump.c: free_duped_lump_list(625)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: del_lump(304)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea340f0), called from core: data_lump.c: free_lump(466)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from uac: replace.c: replace_uri(355)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea30920), called from core: data_lump.c: free_duped_lump_list(619)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_new_lump_after(133)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea34070), called from core: data_lump.c: free_duped_lump_list(625)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: del_lump(304)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea33e10), called from core: data_lump.c: free_duped_lump_list(625)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: dup_lump_list_r(537)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea30ea8), called from core: data_lump.c: free_duped_lump_list(625)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: del_lump(304)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea30e28), called from core: data_lump.c: free_duped_lump_list(625)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: del_lump(304)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea30c20), called from core: data_lump.c: free_duped_lump_list(625)
2016-12-06 11:13:12.387  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: del_lump(304)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea30d20), called from core: data_lump.c: free_lump(466)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from textops: textops.c: add_hf_helper(2277)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea30da8), called from core: data_lump.c: free_duped_lump_list(612)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_new_lump_before(158)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea30ca0), called from core: data_lump.c: free_duped_lump_list(625)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: anchor_lump(358)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: tm [t_funcs.c:368]: t_relay_to(): SER: new transaction fwd'ed
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [receive.c:322]: receive_msg(): cleaning up
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea37dd8), called from core: parser/msg_parser.c: reset_new_uri(735)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: dset.c: rewrite_uri(599)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44eab6fa8), called from core: parser/msg_parser.c: reset_ruid(898)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: set_ruid(881)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea86278), called from core: parser/msg_parser.c: reset_ua(937)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: set_ua(920)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea64f40), called from core: parser/parse_via.c: free_via_param_list(2729)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/parse_via.c: parse_via(2510)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea44d80), called from core: parser/parse_via.c: free_via_param_list(2729)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/parse_via.c: parse_via(2510)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea64eb8), called from core: parser/parse_via.c: free_via_param_list(2729)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/parse_via.c: parse_via(2510)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea670a8), called from core: parser/parse_via.c: free_via_list(2741)
2016-12-06 11:13:12.388  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: get_hdr_field(116)
2016-12-06 11:13:12.389  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea44e90), called from core: parser/hf.c: free_hdr_field_lst(213)
2016-12-06 11:13:12.389  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.389  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea64e40), called from core: parser/parse_addr_spec.c: free_to_params(925)
2016-12-06 11:13:12.389  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/parse_addr_spec.c: parse_to_param(281)
2016-12-06 11:13:12.389  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea65308), called from core: parser/parse_addr_spec.c: free_to(935)
2016-12-06 11:13:12.389  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from sanity: sanity.c: check_parse_uris(789)
2016-12-06 11:13:12.389  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea450b0), called from core: parser/hf.c: free_hdr_field_lst(213)
2016-12-06 11:13:12.389  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.389  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea672e8), called from core: parser/parse_addr_spec.c: free_to(935)
2016-12-06 11:13:12.389  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: get_hdr_field(156)
2016-12-06 11:13:12.389  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea44fa0), called from core: parser/hf.c: free_hdr_field_lst(213)
2016-12-06 11:13:12.389  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.389  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea671d8), called from core: parser/hf.c: free_hdr_field_lst(213)
2016-12-06 11:13:12.389  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.389  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea64fc8), called from core: parser/parse_cseq.c: free_cseq(101)
2016-12-06 11:13:12.389  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: get_hdr_field(135)
2016-12-06 11:13:12.389  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea651f8), called from core: parser/hf.c: free_hdr_field_lst(213)
2016-12-06 11:13:12.389  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.389  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea44e08), called from core: parser/hf.c: free_hdr_field_lst(213)
2016-12-06 11:13:12.389  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.389  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea65040), called from core: parser/hf.c: free_hdr_field_lst(213)
2016-12-06 11:13:12.390  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.390  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea44cf8), called from core: parser/hf.c: free_hdr_field_lst(213)
2016-12-06 11:13:12.390  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.390  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea44f18), called from core: parser/hf.c: free_hdr_field_lst(213)
2016-12-06 11:13:12.390  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.390  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea45028), called from core: parser/hf.c: free_hdr_field_lst(213)
2016-12-06 11:13:12.390  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.390  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea37ad0), called from core: parser/hf.c: free_hdr_field_lst(213)
2016-12-06 11:13:12.390  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.390  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea67260), called from core: parser/hf.c: free_hdr_field_lst(213)
2016-12-06 11:13:12.390  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.390  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea65280), called from core: parser/hf.c: free_hdr_field_lst(213)
2016-12-06 11:13:12.390  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.390  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea403e0), called from core: parser/parse_ppi_pai.c: free_pai_ppi_body(103)
2016-12-06 11:13:12.390  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/parse_ppi_pai.c: parse_pai_ppi_body(83)
2016-12-06 11:13:12.390  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea67020), called from core: parser/hf.c: free_hdr_field_lst(213)
2016-12-06 11:13:12.390  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.390  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea44360), called from core: parser/hf.c: free_hdr_field_lst(213)
2016-12-06 11:13:12.390  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.390  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea40360), called from core: data_lump.c: free_lump_list(499)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_cond_lump_after(234)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44eab74d8), called from core: data_lump.c: free_lump(466)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: tm [t_lookup.c:1011]: t_check_msg(): DEBUG: t_check_msg: msg id=144 global id=143 T start=0xffffffffffffffff
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from rr: record.c: build_rr(227)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: tm [t_lookup.c:888]: t_reply_matching(): DEBUG: t_reply_matching: hash 30498 label 0 branch 0
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea37e48), called from core: data_lump.c: free_lump_list(499)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_new_lump_after(133)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: tm [t_lookup.c:943]: t_reply_matching(): DEBUG: t_reply_matching: reply matched (T=0x7fc3d11fa418)!
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea37ee8), called from core: data_lump.c: free_lump_list(499)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: tm [t_hooks.c:266]: run_trans_callbacks_internal(): DBG: trans=0x7fc3d11fa418, callback type 2, id 0 entered
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_subst_lump_after(183)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea37d30), called from core: data_lump.c: free_lump_list(499)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 472) called from core: parser/parse_from.c: parse_from_header(63)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_cond_lump_after(234)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 472) returns address 0x7fc44ea65108 
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea43e88), called from core: data_lump.c: free_lump(466)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from rr: record.c: build_rr(230)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 48) called from core: parser/parse_addr_spec.c: parse_to_param(281)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea44460), called from core: data_lump.c: free_lump_list(499)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 48) returns address 0x7fc44ea444d0 
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_new_lump_after(133)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea38088), called from core: data_lump.c: free_lump_list(504)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [parser/parse_addr_spec.c:172]: parse_to_param(): DEBUG: add_param: tag=m6GvVA
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [parser/parse_addr_spec.c:894]: parse_addr_spec(): end of header reached, state=29
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: anchor_lump(358)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea37b58), called from core: data_lump.c: free_lump_list(493)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 51) called from uac: replace.c: restore_uri_reply(707)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_cond_lump_before(260)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea37eb8 
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44eab7ca0), called from core: data_lump.c: free_lump(466)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from rr: record.c: build_rr(228)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: uac [replace.c:722]: restore_uri_reply(): removing <"2143177800" <sip:2143177800@example.local>>
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea43f90), called from core: data_lump.c: free_lump_list(493)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: del_lump(304)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea37c10 
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_new_lump_before(158)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: uac [replace.c:731]: restore_uri_reply(): inserting <"2143177800" <sip:+12143177800@example.local>>
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea307c8), called from core: data_lump.c: free_lump(466)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:444]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) called from core: data_lump.c: insert_new_lump_after(133)
2016-12-06 11:13:12.391  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from rr: record.c: build_rr(229)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:527]: fm_malloc(): fm_malloc(0x7fc44e70e010, 56) returns address 0x7fc44ea37d90 
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea43ed8), called from core: data_lump.c: free_lump_list(493)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_new_lump_before(158)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: tm [t_lookup.c:1080]: t_check_msg(): DEBUG: t_check_msg: msg id=144 global id=144 T end=0x7fc3d11fa418
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea37f88), called from core: data_lump.c: free_lump_list(504)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: tm [t_reply.c:2160]: reply_received(): DEBUG: reply_received: org. status uas=100, uac[0]=0 local=0 is_invite=1)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: anchor_lump(358)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44eab7f38), called from core: data_lump.c: free_lump(466)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <script>: incoming reply
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from rr: record.c: build_rr(227)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea451b8), called from core: data_lump.c: free_lump_list(499)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} INFO: <script>: Reply - S=100 - trying -- your call is important to us M=INVITE IP=172.112.10.242 PORT=5070 ID=jzcdBZh5ipLIMXPsy5Bk3Q
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_new_lump_after(133)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: tm [t_reply.c:1233]: t_should_relay_response(): ->>>>>>>>> T_code=100, new_code=100
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea44100), called from core: data_lump.c: free_lump_list(499)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_subst_lump_after(183)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: tm [t_reply.c:1751]: relay_reply(): DEBUG: relay_reply: branch=0, save=0, relay=-1 icode=0
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea44180), called from core: data_lump.c: free_lump_list(499)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_cond_lump_after(234)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea5e5f0), called from core: data_lump.c: free_lump(466)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from rr: record.c: build_rr(230)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea650c8), called from core: data_lump.c: free_lump_list(499)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_new_lump_after(133)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea44038), called from core: data_lump.c: free_lump_list(504)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [usr_avp.c:631]: destroy_avp_list(): destroying list (nil)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: anchor_lump(358)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [receive.c:322]: receive_msg(): cleaning up
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44eab7240), called from core: data_lump.c: free_lump(466)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea44e90), called from core: parser/parse_via.c: free_via_param_list(2729)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from rr: record.c: build_rr(228)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/parse_via.c: parse_via(2510)
2016-12-06 11:13:12.392  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea65148), called from core: data_lump.c: free_lump_list(493)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea64e40), called from core: parser/parse_via.c: free_via_list(2741)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_new_lump_before(158)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: get_hdr_field(116)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea54238), called from core: data_lump.c: free_lump(466)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea44f18), called from core: parser/hf.c: free_hdr_field_lst(213)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from rr: record.c: build_rr(229)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea37be8), called from core: data_lump.c: free_lump_list(493)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea44e08), called from core: parser/parse_via.c: free_via_param_list(2729)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_new_lump_before(158)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/parse_via.c: parse_via(2510)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea45138), called from core: data_lump.c: free_lump_list(504)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea671d8), called from core: parser/parse_via.c: free_via_param_list(2729)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: anchor_lump(358)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/parse_via.c: parse_via(2510)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea38008), called from core: data_lump.c: free_lump_list(504)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea44cf8), called from core: parser/parse_via.c: free_via_param_list(2729)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: del_lump(304)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/parse_via.c: parse_via(2510)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44eaab318), called from core: receive.c: receive_msg(324)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea44d80), called from core: parser/parse_via.c: free_via_param_list(2729)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: receive.c: receive_msg(144)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/parse_via.c: parse_via(2510)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea67260), called from core: parser/parse_via.c: free_via_list(2741)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: get_hdr_field(116)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea65328), called from core: parser/hf.c: free_hdr_field_lst(213)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea444d0), called from core: parser/parse_addr_spec.c: free_to_params(925)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/parse_addr_spec.c: parse_to_param(281)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea65108), called from core: parser/parse_addr_spec.c: free_to(935)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/parse_from.c: parse_from_header(63)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea653b0), called from core: parser/hf.c: free_hdr_field_lst(213)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea44fa0), called from core: parser/parse_addr_spec.c: free_to(935)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: get_hdr_field(156)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea64f70), called from core: parser/hf.c: free_hdr_field_lst(213)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea67150), called from core: parser/hf.c: free_hdr_field_lst(213)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea65438), called from core: parser/parse_cseq.c: free_cseq(101)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: get_hdr_field(135)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea64ff8), called from core: parser/hf.c: free_hdr_field_lst(213)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: parser/msg_parser.c: parse_headers(326)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea37eb8), called from core: data_lump.c: free_lump(466)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from uac: replace.c: restore_uri_reply(707)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea37d90), called from core: data_lump.c: free_lump_list(499)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: insert_new_lump_after(133)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44ea37c10), called from core: data_lump.c: free_lump_list(504)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: data_lump.c: del_lump(304)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:588]: fm_free(): fm_free(0x7fc44e70e010, 0x7fc44eaab318), called from core: receive.c: receive_msg(324)
2016-12-06 11:13:12.393  {INVITE jzcdBZh5ipLIMXPsy5Bk3Q} DEBUG: <core> [mem/f_malloc.c:607]: fm_free(): fm_free: freeing block alloc'ed from core: receive.c: receive_msg(144)
[root@-us-B-ksip-p1 ~]#