DEBUG: auth [api.c:218]: check_response: Authorization is OK
DEBUG: <core> [db_res.c:81]: freeing 1 columns
DEBUG: <core> [db_res.c:85]: freeing RES_NAMES[0] at 0x7fc2ea882bb8
DEBUG: <core> [db_res.c:94]: freeing result names at 0x7fc2ea87e258
DEBUG: <core> [db_res.c:99]: freeing result types at 0x7fc2ea8776a0
DEBUG: <core> [db_res.c:54]: freeing 1 rows
DEBUG: <core> [db_row.c:97]: freeing row values at 0x7fc2ea8776b8
DEBUG: <core> [db_res.c:62]: freeing rows at 0x7fc2ea879ad8
DEBUG: <core> [db_res.c:136]: freeing result set at 0x7fc2ea881c20
DEBUG: siputils [checks.c:106]: totag found
DEBUG: <core> [select.c:425]: Calling SELECT 0x7fc2ea864198 
DEBUG: <core> [select.c:425]: Calling SELECT 0x7fc2ea8662f8 
DEBUG: tm [t_lookup.c:1379]: DEBUG: t_newtran: msg id=56 , global msg id=56, T on entrance=0x7fc2dfcad2c0
DEBUG: tm [t_lookup.c:1384]: DEBUG: t_newtran: transaction already in process 0x7fc2dfcad2c0
DEBUG: <script>: new branch [1] to sip:test@10.123.32.41:5060
DEBUG: siputils [checks.c:106]: totag found
DEBUG: siputils [checks.c:106]: totag found
DEBUG: <core> [msg_translator.c:206]: check_via_address(10.123.32.40, 10.123.32.40, 0)
DEBUG: <core> [parser/msg_parser.c:624]: SIP Request:
DEBUG: <core> [parser/msg_parser.c:626]:  method:  <SUBSCRIBE>
DEBUG: <core> [parser/msg_parser.c:628]:  uri:     <sip:test@10.123.32.41:5060>
DEBUG: <core> [parser/msg_parser.c:630]:  version: <SIP/2.0>
DEBUG: <core> [parser/parse_via.c:1286]: Found param type 232, <branch> = <z9hG4bK58c4.4300c8d6.0>; state=16
DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, state=5
DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via found, flags=2
DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: this is the first via
DEBUG: <core> [parser/parse_via.c:1286]: Found param type 235, <rport> = <5060>; state=6
DEBUG: <core> [parser/parse_via.c:1286]: Found param type 253, <TH> = <dcv>; state=6
DEBUG: <core> [parser/parse_via.c:1286]: Found param type 232, <branch> = <z9hG4bK58c4.3300c8d6.0>; state=16
DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, state=5
DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via found, flags=ffffffffffffffff
DEBUG: <core> [parser/msg_parser.c:524]: parse_headers: this is the second via
DEBUG: <core> [parser/parse_via.c:1286]: Found param type 232, <branch> = <pocos-DJALOPrjwNysdoK4w5KjwNSPOUlui5RTw2xFi63WX63J-5rui2wFi63AxusfB7sz-5lWikSFwPDjwPLjwUruiTdr-1dUBUvbh7ojxu4yMUARdPdbkuwFxPhFxUKEx546w5rEQ5L*>; state=16
DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, state=5
DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via found, flags=ffffffffffffffff
DEBUG: <core> [parser/parse_to.c:178]: DEBUG: add_param: tag=as657bce7c
DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=29
DEBUG: <core> [parser/msg_parser.c:188]: DEBUG: get_hdr_field: <To> [47]; uri=[sip:31880100781@sip.pocos.nl] 
DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: to body [<sip:31880100781@sip.pocos.nl>]
DEBUG: <core> [parser/msg_parser.c:168]: get_hdr_field: cseq <CSeq>: <2004> <SUBSCRIBE>
DEBUG: <core> [parser/msg_parser.c:202]: DEBUG: get_hdr_body : content_length=0
DEBUG: <core> [parser/msg_parser.c:104]: found end of header
DEBUG: <core> [parser/parse_to.c:178]: DEBUG: add_param: tag=c37381367f8532f5
DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=29
DEBUG: topoh [topoh_mod.c:345]: the COOKIE is [dch]
DEBUG: topoh [th_msg.c:174]: =======via[1]
DEBUG: topoh [th_msg.c:175]: hdr: [Via]
DEBUG: topoh [th_msg.c:177]: body: 55: [SIP/2.0/UDP 10.123.32.40;branch=z9hG4bK58c4.4300c8d6.0]
DEBUG: topoh [th_msg.c:174]: =======via[2]
DEBUG: topoh [th_msg.c:175]: hdr: [Via]
DEBUG: topoh [th_msg.c:177]: body: 73: [SIP/2.0/UDP 10.123.32.40;rport=5060;TH=dcv;branch=z9hG4bK58c4.3300c8d6.0]
DEBUG: topoh [th_msg.c:188]: +body: 137: [SIP/2.0/UDP 192.168.0.1;branch=pocos-DJALOPrjwNysdoK4w5KaOUrPCkSPwbSJw2vFhYyFB2JTw2xWiTdr-1dUBUvbh7ojxu4yMUARdPdbkPDSxPLjwPwWwYwSQ2xjwK**]
DEBUG: topoh [th_msg.c:174]: =======via[3]
DEBUG: topoh [th_msg.c:175]: hdr: [Via]
DEBUG: topoh [th_msg.c:177]: body: 173: [SIP/2.0/UDP 192.168.0.1;branch=pocos-DJALOPrjwNysdoK4w5KjwNSPOUlui5RTw2xFi63WX63J-5rui2wFi63AxusfB7sz-5lWikSFwPDjwPLjwUruiTdr-1dUBUvbh7ojxu4yMUARdPdbkuwFxPhFxUKEx546w5rEQ5L*]
DEBUG: topoh [th_msg.c:188]: +body: 269: [SIP/2.0/UDP 192.168.0.1;branch=pocos-DJALOPrjwNysdoK4w5zFOUluiNSWOUlgxH3tX7CR-cqIxuyPODdmLDE-De38BJaahudIkPd6CDv8BJa5DlysXesfCs3DBP3Sd7zuwTBxCUCmO5sFB1zFBJQfCUCqMesPQzr6h6RvC1Ec.1v5dHBLdYf6DlE8BTsFB1ADQervw1dsLAsux746XufSB5da5ssqD7dLQY30BcBYMoqRdHtskJsSC5LuBPsFdslT5NR*]
DEBUG: topoh [th_msg.c:319]: no record route header
DEBUG: tm [t_funcs.c:388]: SER: new transaction fwd'ed
DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
DEBUG: <core> [xavp.c:365]: destroying xavp list (nil)
DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
DEBUG: <core> [parser/msg_parser.c:634]: SIP Reply  (status):
DEBUG: <core> [parser/msg_parser.c:636]:  version: <SIP/2.0>
DEBUG: <core> [parser/msg_parser.c:638]:  status:  <404>
DEBUG: <core> [parser/msg_parser.c:640]:  reason:  <Not found>