<div dir="ltr"><div><div><div><div>Hi All<br></div>I am trying ti implement a IMS client. For testing I am using Kamailio proxy.<br><br></div>During call setup, I get 404 for Prack message.<br></div>Whats going wrong not able to figure out.<br></div>Here is the Kamailio log below, can somebody help me too find whats wrong her.<br><br><i><b>11(25376) DEBUG: sl [sl.c:296]: send_reply(): reply in stateless mode (sl)<br>11(25376) DEBUG: <core> [msg_translator.c:206]: check_via_address(): check_via_address(192.168.1.195, 192.168.1.195, 0)<br>11(25376) DEBUG: <core> [tcp_main.c:2281]: tcpconn_send_put(): tcp_send: send from reader (25376 (11)), reusing fd<br>11(25376) DEBUG: <core> [tcp_main.c:2516]: tcpconn_do_send(): tcp_send: sending...<br>11(25376) DEBUG: <core> [tcp_main.c:2550]: tcpconn_do_send(): tcp_send: after real write: c= 0x7fe2ebd05390 n=386 fd=5<br>11(25376) DEBUG: <core> [tcp_main.c:2551]: tcpconn_do_send(): tcp_send: buf=<br>SIP/2.0 200 OK<br>Via: SIP/2.0/TCP 192.168.1.195:40611;branch=z9hG4bK1186661565<br>From: <<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>>;tag=1307796831<br>To: <<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>>;tag=25fbdd2b0c9b93b0791296269f5ae411.38a0<br>Call-ID: <a href="mailto:835380265@192.168.1.195">835380265@192.168.1.195</a><br>CSeq: 2 REGISTER<br>Contact: <sip:linux_ua_1@192.168.1.195:40611;transport=tcp>;expires=3600<br>Server: kamailio (4.2.3 (x86_64/linux))<br>Content-Length: 0<br><br><br>11(25376) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>11(25376) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>11(25376) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>11(25376) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>11(25376) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>11(25376) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>11(25376) DEBUG: <core> [xavp.c:448]: xavp_destroy_list(): destroying xavp list (nil)<br>11(25376) DEBUG: <core> [receive.c:298]: receive_msg(): receive_msg: cleaning up<br>11(25376) DEBUG: <core> [io_wait.h:388]: io_watch_add(): DBG: io_watch_add(0xa33180, 5, 2, 0x7fe2ebd05390), fd_no=1<br>11(25376) DEBUG: <core> [tcp_read.c:1362]: tcp_read_req(): tcp_read_req: content-length= 0<br>11(25376) DEBUG: <core> [parser/msg_parser.c:623]: parse_msg(): SIP Request:<br>11(25376) DEBUG: <core> [parser/msg_parser.c:625]: parse_msg():  method:  <SUBSCRIBE><br>11(25376) DEBUG: <core> [parser/msg_parser.c:627]: parse_msg():  uri:     <<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>><br>11(25376) DEBUG: <core> [parser/msg_parser.c:629]: parse_msg():  version: <SIP/2.0><br>11(25376) DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK1577674881>; state=16<br>11(25376) DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of header reached, state=5<br>11(25376) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers(): parse_headers: Via found, flags=2<br>11(25376) DEBUG: <core> [parser/msg_parser.c:515]: parse_headers(): parse_headers: this is the first via<br>11(25376) DEBUG: <core> [receive.c:154]: receive_msg(): After parse_msg...<br>11(25376) DEBUG: <core> [receive.c:197]: receive_msg(): preparing to run routing scripts...<br>11(25376) DEBUG: <core> [parser/parse_addr_spec.c:898]: parse_addr_spec(): end of header reached, state=10<br>11(25376) DEBUG: <core> [parser/msg_parser.c:190]: get_hdr_field(): DEBUG: get_hdr_field: <To> [28]; uri=[<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>] <br>11(25376) DEBUG: <core> [parser/msg_parser.c:192]: get_hdr_field(): DEBUG: to body [<<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>><br>]<br>11(25376) DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <2> <SUBSCRIBE><br>11(25376) DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value = 70 <br>11(25376) DEBUG: <core> [parser/msg_parser.c:204]: get_hdr_field(): DEBUG: get_hdr_body : content_length=0<br>11(25376) DEBUG: <core> [parser/msg_parser.c:106]: get_hdr_field(): found end of header<br>11(25376) DEBUG: <core> [parser/parse_addr_spec.c:176]: parse_to_param(): DEBUG: add_param: tag=1335679035<br>11(25376) DEBUG: <core> [parser/parse_addr_spec.c:898]: parse_addr_spec(): end of header reached, state=29<br>11(25376) DEBUG: sanity [mod_sanity.c:255]: w_sanity_check(): sanity checks result: 1<br>11(25376) DEBUG: siputils [checks.c:103]: has_totag(): no totag<br>11(25376) DEBUG: tm [t_lookup.c:1072]: t_check_msg(): DEBUG: t_check_msg: msg id=2 global id=1 T start=(nil)<br>11(25376) DEBUG: tm [t_lookup.c:527]: t_lookup_request(): t_lookup_request: start searching: hash=34123, isACK=0<br>11(25376) DEBUG: tm [t_lookup.c:485]: matching_3261(): DEBUG: RFC3261 transaction matching failed<br>11(25376) DEBUG: tm [t_lookup.c:709]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found<br>11(25376) DEBUG: tm [t_lookup.c:1141]: t_check_msg(): DEBUG: t_check_msg: msg id=2 global id=2 T end=(nil)<br>11(25376) DEBUG: <core> [socket_info.c:583]: grep_sock_info(): grep_sock_info - checking if host==us: 13==13 && [192.168.1.195] == [192.168.1.195]<br>11(25376) DEBUG: <core> [socket_info.c:587]: grep_sock_info(): grep_sock_info - checking if port 4060 (advertise 0) matches port 5060<br>11(25376) DEBUG: <core> [socket_info.c:583]: grep_sock_info(): grep_sock_info - checking if host==us: 13==13 && [192.168.1.195] == [192.168.1.195]<br>11(25376) DEBUG: <core> [socket_info.c:587]: grep_sock_info(): grep_sock_info - checking if port 4060 (advertise 0) matches port 5060<br>11(25376) DEBUG: <core> [socket_info.c:583]: grep_sock_info(): grep_sock_info - checking if host==us: 13==13 && [192.168.1.195] == [192.168.1.195]<br>11(25376) DEBUG: <core> [socket_info.c:587]: grep_sock_info(): grep_sock_info - checking if port 4090 (advertise 0) matches port 5060<br>11(25376) DEBUG: registrar [lookup.c:203]: lookup_helper(): contact for [linux_ua_1] cannot handle the SIP method<br>11(25376) DEBUG: registrar [lookup.c:211]: lookup_helper(): 'linux_ua_1' has no valid contact in usrloc<br>11(25376) DEBUG: tm [t_lookup.c:1373]: t_newtran(): DEBUG: t_newtran: msg id=2 , global msg id=2 , T on entrance=(nil)<br>11(25376) DEBUG: tm [t_lookup.c:527]: t_lookup_request(): t_lookup_request: start searching: hash=34123, isACK=0<br>11(25376) DEBUG: tm [t_lookup.c:485]: matching_3261(): DEBUG: RFC3261 transaction matching failed<br>11(25376) DEBUG: tm [t_lookup.c:709]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found<br>11(25376) DEBUG: tm [t_hooks.c:380]: run_reqin_callbacks_internal(): DBG: trans=0x7fe2ebd10e68, callback type 1, id 0 entered<br>11(25376) DEBUG: <core> [md5utils.c:67]: MD5StringArray(): DEBUG: MD5 calculated: c17c6f2bd5d60787072aef8ffcf5bfe6<br>11(25376) DEBUG: tm [t_lookup.c:1072]: t_check_msg(): DEBUG: t_check_msg: msg id=2 global id=2 T start=0x7fe2ebd10e68<br>11(25376) DEBUG: tm [t_lookup.c:1144]: t_check_msg(): DEBUG: t_check_msg: T already found!<br>11(25376) DEBUG: <core> [msg_translator.c:206]: check_via_address(): check_via_address(192.168.1.195, 192.168.1.195, 0)<br>11(25376) DEBUG: <core> [mem/shm_mem.c:111]: _shm_resize(): WARNING:vqm_resize: resize(0) called<br>11(25376) DEBUG: tm [t_reply.c:1653]: cleanup_uac_timers(): DEBUG: cleanup_uac_timers: RETR/FR timers reset<br>11(25376) DEBUG: <core> [tcp_main.c:2281]: tcpconn_send_put(): tcp_send: send from reader (25376 (11)), reusing fd<br>11(25376) DEBUG: <core> [tcp_main.c:2516]: tcpconn_do_send(): tcp_send: sending...<br>11(25376) DEBUG: <core> [tcp_main.c:2550]: tcpconn_do_send(): tcp_send: after real write: c= 0x7fe2ebd05390 n=334 fd=5<br>11(25376) DEBUG: <core> [tcp_main.c:2551]: tcpconn_do_send(): tcp_send: buf=<br>SIP/2.0 405 Method Not Allowed<br>Via: SIP/2.0/TCP 192.168.1.195:40611;branch=z9hG4bK1577674881<br>From: <<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>>;tag=1335679035<br>To: <<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>>;tag=ff272440259f71af2c767e7942717037-95d5<br>Call-ID: <a href="mailto:1397060040@192.168.1.195">1397060040@192.168.1.195</a><br>CSeq: 2 SUBSCRIBE<br>Server: kamailio (4.2.3 (x86_64/linux))<br>Content-Length: 0<br><br><br>11(25376) DEBUG: tm [t_reply.c:728]: _reply_light(): DEBUG: reply sent out. buf=0x7fe30fea65c0: SIP/2.0 405 Method N..., shmem=0x7fe2ebd135a8: SIP/2.0 405 Method N<br>11(25376) DEBUG: tm [t_reply.c:738]: _reply_light(): DEBUG: _reply_light: finished<br>11(25376) DEBUG: sl [sl.c:288]: send_reply(): reply in stateful mode (tm)<br>11(25376) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>11(25376) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>11(25376) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>11(25376) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>11(25376) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>11(25376) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>11(25376) DEBUG: <core> [xavp.c:448]: xavp_destroy_list(): destroying xavp list (nil)<br>11(25376) DEBUG: <core> [receive.c:298]: receive_msg(): receive_msg: cleaning up<br> 9(25374) DEBUG: websocket [ws_conn.c:459]: wsconn_get_list(): wsconn_get_list<br> 9(25374) DEBUG: websocket [ws_conn.c:503]: wsconn_get_list(): wsconn_get_list returns list [(nil)] with [0] members<br>10(25375) DEBUG: <core> [tcp_read.c:1362]: tcp_read_req(): tcp_read_req: content-length= 359<br>10(25375) DEBUG: <core> [parser/msg_parser.c:623]: parse_msg(): SIP Request:<br>10(25375) DEBUG: <core> [parser/msg_parser.c:625]: parse_msg():  method:  <INVITE><br>10(25375) DEBUG: <core> [parser/msg_parser.c:627]: parse_msg():  uri:     <<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>><br>10(25375) DEBUG: <core> [parser/msg_parser.c:629]: parse_msg():  version: <SIP/2.0><br>10(25375) DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK1970975121>; state=16<br>10(25375) DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of header reached, state=5<br>10(25375) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers(): parse_headers: Via found, flags=2<br>10(25375) DEBUG: <core> [parser/msg_parser.c:515]: parse_headers(): parse_headers: this is the first via<br>10(25375) DEBUG: <core> [receive.c:154]: receive_msg(): After parse_msg...<br>10(25375) DEBUG: <core> [receive.c:197]: receive_msg(): preparing to run routing scripts...<br>10(25375) DEBUG: <core> [parser/parse_addr_spec.c:898]: parse_addr_spec(): end of header reached, state=10<br>10(25375) DEBUG: <core> [parser/msg_parser.c:190]: get_hdr_field(): DEBUG: get_hdr_field: <To> [28]; uri=[<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>] <br>10(25375) DEBUG: <core> [parser/msg_parser.c:192]: get_hdr_field(): DEBUG: to body [<<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>><br>]<br>10(25375) DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <2> <INVITE><br>10(25375) DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value = 70 <br>10(25375) DEBUG: <core> [parser/msg_parser.c:204]: get_hdr_field(): DEBUG: get_hdr_body : content_length=359<br>10(25375) DEBUG: <core> [parser/msg_parser.c:106]: get_hdr_field(): found end of header<br>10(25375) DEBUG: <core> [parser/parse_addr_spec.c:176]: parse_to_param(): DEBUG: add_param: tag=604263664<br>10(25375) DEBUG: <core> [parser/parse_addr_spec.c:898]: parse_addr_spec(): end of header reached, state=29<br>10(25375) DEBUG: sanity [mod_sanity.c:255]: w_sanity_check(): sanity checks result: 1<br>10(25375) DEBUG: siputils [checks.c:103]: has_totag(): no totag<br>10(25375) DEBUG: tm [t_lookup.c:1072]: t_check_msg(): DEBUG: t_check_msg: msg id=3 global id=2 T start=0xffffffffffffffff<br>10(25375) DEBUG: tm [t_lookup.c:527]: t_lookup_request(): t_lookup_request: start searching: hash=12870, isACK=0<br>10(25375) DEBUG: tm [t_lookup.c:485]: matching_3261(): DEBUG: RFC3261 transaction matching failed<br>10(25375) DEBUG: tm [t_lookup.c:709]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found<br>10(25375) DEBUG: tm [t_lookup.c:1141]: t_check_msg(): DEBUG: t_check_msg: msg id=3 global id=3 T end=(nil)<br>10(25375) DEBUG: <core> [socket_info.c:583]: grep_sock_info(): grep_sock_info - checking if host==us: 13==13 && [192.168.1.195] == [192.168.1.195]<br>10(25375) DEBUG: <core> [socket_info.c:587]: grep_sock_info(): grep_sock_info - checking if port 4060 (advertise 0) matches port 5060<br>10(25375) DEBUG: <core> [socket_info.c:583]: grep_sock_info(): grep_sock_info - checking if host==us: 13==13 && [192.168.1.195] == [192.168.1.195]<br>10(25375) DEBUG: <core> [socket_info.c:587]: grep_sock_info(): grep_sock_info - checking if port 4060 (advertise 0) matches port 5060<br>10(25375) DEBUG: <core> [socket_info.c:583]: grep_sock_info(): grep_sock_info - checking if host==us: 13==13 && [192.168.1.195] == [192.168.1.195]<br>10(25375) DEBUG: <core> [socket_info.c:587]: grep_sock_info(): grep_sock_info - checking if port 4090 (advertise 0) matches port 5060<br>10(25375) DEBUG: registrar [lookup.c:198]: lookup_helper(): contact for [linux_ua_1] found by address<br>10(25375) DEBUG: tm [t_lookup.c:1373]: t_newtran(): DEBUG: t_newtran: msg id=3 , global msg id=3 , T on entrance=(nil)<br>10(25375) DEBUG: tm [t_lookup.c:527]: t_lookup_request(): t_lookup_request: start searching: hash=12870, isACK=0<br>10(25375) DEBUG: tm [t_lookup.c:485]: matching_3261(): DEBUG: RFC3261 transaction matching failed<br>10(25375) DEBUG: tm [t_lookup.c:709]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found<br>10(25375) DEBUG: tm [t_hooks.c:380]: run_reqin_callbacks_internal(): DBG: trans=0x7fe2ebd13848, callback type 1, id 0 entered<br>10(25375) DEBUG: <core> [md5utils.c:67]: MD5StringArray(): DEBUG: MD5 calculated: c4c3d26baa62dea619271f186d6344fc<br>10(25375) DEBUG: tm [t_funcs.c:347]: t_relay_to(): SER: new INVITE<br>10(25375) DEBUG: <core> [msg_translator.c:206]: check_via_address(): check_via_address(192.168.1.195, 192.168.1.195, 0)<br>10(25375) DEBUG: <core> [mem/shm_mem.c:111]: _shm_resize(): WARNING:vqm_resize: resize(0) called<br>10(25375) DEBUG: <core> [tcp_main.c:2281]: tcpconn_send_put(): tcp_send: send from reader (25375 (10)), reusing fd<br>10(25375) DEBUG: <core> [tcp_main.c:2516]: tcpconn_do_send(): tcp_send: sending...<br>10(25375) DEBUG: <core> [tcp_main.c:2550]: tcpconn_do_send(): tcp_send: after real write: c= 0x7fe2ebd096b0 n=307 fd=5<br>10(25375) DEBUG: <core> [tcp_main.c:2551]: tcpconn_do_send(): tcp_send: buf=<br>SIP/2.0 100 trying -- your call is important to us<br>Via: SIP/2.0/TCP 192.168.1.195:19009;branch=z9hG4bK1970975121<br>From: <<a href="mailto:sip%3Alinux_ua_0@192.168.1.195">sip:linux_ua_0@192.168.1.195</a>>;tag=604263664<br>To: <<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>><br>Call-ID: <a href="mailto:734015646@192.168.1.195">734015646@192.168.1.195</a><br>CSeq: 2 INVITE<br>Server: kamailio (4.2.3 (x86_64/linux))<br>Content-Length: 0<br><br><br>10(25375) DEBUG: tm [t_reply.c:728]: _reply_light(): DEBUG: reply sent out. buf=0x7fe30fea6968: SIP/2.0 100 trying -..., shmem=0x7fe2ebd163f0: SIP/2.0 100 trying -<br>10(25375) DEBUG: tm [t_reply.c:738]: _reply_light(): DEBUG: _reply_light: finished<br>10(25375) DEBUG: <script>: new branch [0] to sip:linux_ua_1@192.168.1.195:40611;transport=tcp<br>10(25375) DEBUG: <core> [msg_translator.c:2893]: create_via_hf(): create_via_hf: id added: <;i=2>, rcv proto=2<br>10(25375) DEBUG: <core> [msg_translator.c:206]: check_via_address(): check_via_address(192.168.1.195, 192.168.1.195, 0)<br>10(25375) DEBUG: <core> [tcp_main.c:1818]: tcp_send(): tcp_send: no open tcp connection found, opening new one<br>10(25375) DEBUG: <core> [ip_addr.c:243]: print_ip(): tcpconn_new: new tcp connection: 192.168.1.195<br>10(25375) DEBUG: <core> [tcp_main.c:1073]: tcpconn_new(): tcpconn_new: on port 40611, type 2<br>10(25375) DEBUG: <core> [tcp_main.c:1382]: tcpconn_add(): tcpconn_add: hashes: 3453:3998:0, 3<br>10(25375) INFO: <core> [tcp_main.c:2753]: tcpconn_1st_send(): quick connect for 0x7fe2ebd17030<br>10(25375) DEBUG: tm [t_funcs.c:394]: t_relay_to(): SER: new transaction fwd'ed<br>10(25375) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>10(25375) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>14(25379) DEBUG: <core> [tcp_main.c:3565]: handle_ser_child(): handle_ser_child: read response= 7fe2ebd17030, 6, fd 28 from 10 (25375)<br>10(25375) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>10(25375) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>10(25375) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>10(25375) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>10(25375) DEBUG: <core> [xavp.c:448]: xavp_destroy_list(): destroying xavp list (nil)<br>14(25379) DEBUG: <core> [io_wait.h:388]: io_watch_add(): DBG: io_watch_add(0x9eeee0, 28, 2, 0x7fe2ebd17030), fd_no=19<br>10(25375) DEBUG: <core> [receive.c:298]: receive_msg(): receive_msg: cleaning up<br>14(25379) DEBUG: <core> [io_wait.h:610]: io_watch_del(): DBG: io_watch_del (0x9eeee0, 28, -1, 0x0) fd_no=20 called<br>14(25379) DEBUG: <core> [tcp_main.c:4219]: handle_tcpconn_ev(): tcp: DBG: sending to child, events 1<br>14(25379) DEBUG: <core> [tcp_main.c:3902]: send2child(): selected tcp worker 2 12(25377) for activity on [tcp:<a href="http://192.168.1.195:4060">192.168.1.195:4060</a>], 0x7fe2ebd17030<br>12(25377) DEBUG: <core> [tcp_read.c:1554]: handle_io(): received n=8 con=0x7fe2ebd17030, fd=5<br>12(25377) DEBUG: <core> [tcp_read.c:1362]: tcp_read_req(): tcp_read_req: content-length= 388<br>12(25377) DEBUG: <core> [parser/msg_parser.c:633]: parse_msg(): SIP Reply  (status):<br>12(25377) DEBUG: <core> [parser/msg_parser.c:635]: parse_msg():  version: <SIP/2.0><br>12(25377) DEBUG: <core> [parser/msg_parser.c:637]: parse_msg():  status:  <183><br>12(25377) DEBUG: <core> [parser/msg_parser.c:639]: parse_msg():  reason:  <Session Progress><br>12(25377) DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK6423.c4c3d26baa62dea619271f186d6344fc.0>; state=6<br>12(25377) DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 236, <i> = <2>; state=16<br>12(25377) DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of header reached, state=5<br>12(25377) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers(): parse_headers: Via found, flags=2<br>12(25377) DEBUG: <core> [parser/msg_parser.c:515]: parse_headers(): parse_headers: this is the first via<br>12(25377) DEBUG: <core> [receive.c:154]: receive_msg(): After parse_msg...<br>12(25377) DEBUG: tm [t_lookup.c:1072]: t_check_msg(): DEBUG: t_check_msg: msg id=1 global id=0 T start=0xffffffffffffffff<br>12(25377) DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK1970975121>; state=16<br>12(25377) DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of header reached, state=5<br>12(25377) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers(): parse_headers: Via found, flags=62<br>12(25377) DEBUG: <core> [parser/msg_parser.c:526]: parse_headers(): parse_headers: this is the second via<br>12(25377) DEBUG: <core> [parser/parse_addr_spec.c:176]: parse_to_param(): DEBUG: add_param: tag=1656432204<br>12(25377) DEBUG: <core> [parser/parse_addr_spec.c:898]: parse_addr_spec(): end of header reached, state=29<br>12(25377) DEBUG: <core> [parser/msg_parser.c:190]: get_hdr_field(): DEBUG: get_hdr_field: <To> [43]; uri=[<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>] <br>12(25377) DEBUG: <core> [parser/msg_parser.c:192]: get_hdr_field(): DEBUG: to body [<<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>>]<br>12(25377) DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <2> <INVITE><br>12(25377) DEBUG: tm [t_lookup.c:949]: t_reply_matching(): DEBUG: t_reply_matching: hash 12870 label 0 branch 0<br>12(25377) DEBUG: tm [t_lookup.c:1004]: t_reply_matching(): DEBUG: t_reply_matching: reply matched (T=0x7fe2ebd13848)!<br>12(25377) DEBUG: tm [t_hooks.c:288]: run_trans_callbacks_internal(): DBG: trans=0x7fe2ebd13848, callback type 2, id 0 entered<br>12(25377) DEBUG: acc [acc_logic.c:644]: tmcb_func(): acc callback called for t(0x7fe2ebd13848) event type 2, reply code 183<br>12(25377) DEBUG: tm [t_lookup.c:1141]: t_check_msg(): DEBUG: t_check_msg: msg id=1 global id=1 T end=0x7fe2ebd13848<br>12(25377) DEBUG: tm [t_reply.c:2200]: reply_received(): DEBUG: reply_received: org. status uas=100, uac[0]=0 local=0 is_invite=1)<br>12(25377) DEBUG: <script>: incoming reply<br>12(25377) DEBUG: tm [t_reply.c:1294]: t_should_relay_response(): ->>>>>>>>> T_code=100, new_code=183<br>12(25377) DEBUG: tm [t_reply.c:1812]: relay_reply(): DEBUG: relay_reply: branch=0, save=0, relay=0 icode=0<br>12(25377) DEBUG: <core> [parser/msg_parser.c:204]: get_hdr_field(): DEBUG: get_hdr_body : content_length=388<br>12(25377) DEBUG: <core> [parser/msg_parser.c:106]: get_hdr_field(): found end of header<br>12(25377) DEBUG: <core> [msg_translator.c:2278]: generate_res_buf_from_sip_res():  old size: 948, new size: 853<br>12(25377) DEBUG: <core> [msg_translator.c:2296]: generate_res_buf_from_sip_res(): copied size: orig:125, new: 30, rest: 823 msg=<br>SIP/2.0 183 Session Progress<br>Via: SIP/2.0/TCP 192.168.1.195:19009;branch=z9hG4bK1970975121<br>Record-Route: <sip:192.168.1.195:4060;transport=tcp;lr><br>From: <<a href="mailto:sip%3Alinux_ua_0@192.168.1.195">sip:linux_ua_0@192.168.1.195</a>>;tag=604263664<br>To: <<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>>;tag=1656432204<br>Call-ID: <a href="mailto:734015646@192.168.1.195">734015646@192.168.1.195</a><br>CSeq: 2 INVITE<br>Contact: <sip:linux_ua_1@192.168.1.195:40611;transport=TCP><br>Content-Type: application/sdp<br>User-Agent: Linux 64 US-UA 1.0.1<br>Require: 100rel<br>RSeq: 1<br>Content-Length:   388<br><br>v=0<br>o=- 0 0 IN IP4 192.168.1.195<br>s=IMS_Call<br>c=IN IP4 192.168.1.195<br>t=0 0<br>m=audio 21720 RTP/AVP 99 0 8 101 <br>b=AS:64<br>a=curr:qos remote none<br>a=curr:qos local none<br>a=des:qos mandatory remote sendrecv<br>a=conf:qos remote sendrecv<br>a=des:qos mandatory local sendrecv<br>a=rtpmap:101 telephone-event/8000<br>a=fmtp:101 0-15<br>a=rtpmap:99 AMR/8000<br>a=rtpmap:0 PCMU/8000<br>a=rtpmap:8 PCMA/8000<br><br>12(25377) DEBUG: <core> [tcp_main.c:2297]: tcpconn_send_put(): tcp_send: tcp connection found (0x7fe2ebd096b0), acquiring fd<br>12(25377) DEBUG: <core> [tcp_main.c:2307]: tcpconn_send_put(): tcp_send, c= 0x7fe2ebd096b0, n=16<br>14(25379) DEBUG: <core> [tcp_main.c:3565]: handle_ser_child(): handle_ser_child: read response= 7fe2ebd096b0, 2, fd -1 from 12 (25377)<br>12(25377) DEBUG: <core> [tcp_main.c:2337]: tcpconn_send_put(): tcp_send: after receive_fd: c= 0x7fe2ebd096b0 n=8 fd=8<br>12(25377) DEBUG: <core> [tcp_main.c:2516]: tcpconn_do_send(): tcp_send: sending...<br>12(25377) DEBUG: <core> [tcp_main.c:2550]: tcpconn_do_send(): tcp_send: after real write: c= 0x7fe2ebd096b0 n=853 fd=8<br>12(25377) DEBUG: <core> [tcp_main.c:2551]: tcpconn_do_send(): tcp_send: buf=<br>SIP/2.0 183 Session Progress<br>Via: SIP/2.0/TCP 192.168.1.195:19009;branch=z9hG4bK1970975121<br>Record-Route: <sip:192.168.1.195:4060;transport=tcp;lr><br>From: <<a href="mailto:sip%3Alinux_ua_0@192.168.1.195">sip:linux_ua_0@192.168.1.195</a>>;tag=604263664<br>To: <<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>>;tag=1656432204<br>Call-ID: <a href="mailto:734015646@192.168.1.195">734015646@192.168.1.195</a><br>CSeq: 2 INVITE<br>Contact: <sip:linux_ua_1@192.168.1.195:40611;transport=TCP><br>Content-Type: application/sdp<br>User-Agent: Linux 64 US-UA 1.0.1<br>Require: 100rel<br>RSeq: 1<br>Content-Length:   388<br><br>v=0<br>o=- 0 0 IN IP4 192.168.1.195<br>s=IMS_Call<br>c=IN IP4 192.168.1.195<br>t=0 0<br>m=audio 21720 RTP/AVP 99 0 8 101 <br>b=AS:64<br>a=curr:qos remote none<br>a=curr:qos local none<br>a=des:qos mandatory remote sendrecv<br>a=conf:qos remote sendrecv<br>a=des:qos mandatory local sendrecv<br>a=rtpmap:101 telephone-event/8000<br>a=fmtp:101 0-15<br>a=rtpmap:99 AMR/8000<br>a=rtpmap:0 PCMU/8000<br>a=rtpmap:8 PCMA/8000<br><br>12(25377) DEBUG: tm [t_hooks.c:288]: run_trans_callbacks_internal(): DBG: trans=0x7fe2ebd13848, callback type 512, id 0 entered<br>12(25377) DEBUG: acc [acc_logic.c:644]: tmcb_func(): acc callback called for t(0x7fe2ebd13848) event type 512, reply code 183<br>12(25377) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>12(25377) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>12(25377) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>12(25377) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>12(25377) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>12(25377) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>12(25377) DEBUG: <core> [xavp.c:448]: xavp_destroy_list(): destroying xavp list (nil)<br>12(25377) DEBUG: <core> [receive.c:298]: receive_msg(): receive_msg: cleaning up<br>12(25377) DEBUG: <core> [io_wait.h:388]: io_watch_add(): DBG: io_watch_add(0xa33180, 5, 2, 0x7fe2ebd17030), fd_no=1<br>10(25375) DEBUG: <core> [tcp_read.c:1362]: tcp_read_req(): tcp_read_req: content-length= 392<br>10(25375) DEBUG: <core> [parser/msg_parser.c:623]: parse_msg(): SIP Request:<br>10(25375) DEBUG: <core> [parser/msg_parser.c:625]: parse_msg():  method:  <PRACK><br>10(25375) DEBUG: <core> [parser/msg_parser.c:627]: parse_msg():  uri:     <sip:linux_ua_1@192.168.1.195:40611;transport=TCP><br>10(25375) DEBUG: <core> [parser/msg_parser.c:629]: parse_msg():  version: <SIP/2.0><br>10(25375) DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK1576634775>; state=16<br>10(25375) DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of header reached, state=5<br>10(25375) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers(): parse_headers: Via found, flags=2<br>10(25375) DEBUG: <core> [parser/msg_parser.c:515]: parse_headers(): parse_headers: this is the first via<br>10(25375) DEBUG: <core> [receive.c:154]: receive_msg(): After parse_msg...<br>10(25375) DEBUG: <core> [receive.c:197]: receive_msg(): preparing to run routing scripts...<br>10(25375) DEBUG: <core> [parser/parse_addr_spec.c:176]: parse_to_param(): DEBUG: add_param: tag=1656432204<br>10(25375) DEBUG: <core> [parser/parse_addr_spec.c:898]: parse_addr_spec(): end of header reached, state=29<br>10(25375) DEBUG: <core> [parser/msg_parser.c:190]: get_hdr_field(): DEBUG: get_hdr_field: <To> [43]; uri=[<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>] <br>10(25375) DEBUG: <core> [parser/msg_parser.c:192]: get_hdr_field(): DEBUG: to body [<<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>>]<br>10(25375) DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <3> <PRACK><br>10(25375) DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value = 70 <br>10(25375) DEBUG: <core> [parser/msg_parser.c:204]: get_hdr_field(): DEBUG: get_hdr_body : content_length=392<br>10(25375) DEBUG: <core> [parser/msg_parser.c:106]: get_hdr_field(): found end of header<br>10(25375) DEBUG: <core> [parser/parse_addr_spec.c:176]: parse_to_param(): DEBUG: add_param: tag=604263664<br>10(25375) DEBUG: <core> [parser/parse_addr_spec.c:898]: parse_addr_spec(): end of header reached, state=29<br>10(25375) DEBUG: sanity [mod_sanity.c:255]: w_sanity_check(): sanity checks result: 1<br>10(25375) DEBUG: siputils [checks.c:106]: has_totag(): totag found<br>10(25375) DEBUG: rr [loose.c:90]: is_preloaded(): is_preloaded: No<br>10(25375) DEBUG: <core> [socket_info.c:583]: grep_sock_info(): grep_sock_info - checking if host==us: 13==13 && [192.168.1.195] == [192.168.1.195]<br>10(25375) DEBUG: <core> [socket_info.c:587]: grep_sock_info(): grep_sock_info - checking if port 4060 (advertise 0) matches port 40611<br>10(25375) DEBUG: <core> [socket_info.c:583]: grep_sock_info(): grep_sock_info - checking if host==us: 13==13 && [192.168.1.195] == [192.168.1.195]<br>10(25375) DEBUG: <core> [socket_info.c:587]: grep_sock_info(): grep_sock_info - checking if port 4060 (advertise 0) matches port 40611<br>10(25375) DEBUG: <core> [socket_info.c:583]: grep_sock_info(): grep_sock_info - checking if host==us: 13==13 && [192.168.1.195] == [192.168.1.195]<br>10(25375) DEBUG: <core> [socket_info.c:587]: grep_sock_info(): grep_sock_info - checking if port 4090 (advertise 0) matches port 40611<br>10(25375) DEBUG: rr [loose.c:674]: after_strict(): Next hop: 'sip:192.168.1.195:4060;transport=tcp;lr' is loose router<br>10(25375) DEBUG: rr [loose.c:724]: after_strict(): The last route URI: 'sip:192.168.1.195:4060;transport=tcp;lr'<br>10(25375) DEBUG: tm [t_lookup.c:1373]: t_newtran(): DEBUG: t_newtran: msg id=4 , global msg id=3 , T on entrance=0xffffffffffffffff<br>10(25375) DEBUG: tm [t_lookup.c:527]: t_lookup_request(): t_lookup_request: start searching: hash=12871, isACK=0<br>10(25375) DEBUG: tm [t_lookup.c:485]: matching_3261(): DEBUG: RFC3261 transaction matching failed<br>10(25375) DEBUG: tm [t_lookup.c:709]: t_lookup_request(): DEBUG: t_lookup_request: no transaction found<br>10(25375) DEBUG: tm [t_hooks.c:380]: run_reqin_callbacks_internal(): DBG: trans=0x7fe2ebd1b780, callback type 1, id 0 entered<br>10(25375) DEBUG: <core> [md5utils.c:67]: MD5StringArray(): DEBUG: MD5 calculated: 0dd1edaf37f3874c5176befe76ed5b3e<br>10(25375) DEBUG: <core> [msg_translator.c:2893]: create_via_hf(): create_via_hf: id added: <;i=2>, rcv proto=2<br>10(25375) DEBUG: <core> [msg_translator.c:206]: check_via_address(): check_via_address(192.168.1.195, 192.168.1.195, 0)<br>10(25375) DEBUG: <core> [tcp_main.c:1818]: tcp_send(): tcp_send: no open tcp connection found, opening new one<br>10(25375) DEBUG: <core> [ip_addr.c:243]: print_ip(): tcpconn_new: new tcp connection: 192.168.1.195<br>10(25375) DEBUG: <core> [tcp_main.c:1073]: tcpconn_new(): tcpconn_new: on port 4060, type 2<br>10(25375) DEBUG: <core> [tcp_main.c:1382]: tcpconn_add(): tcpconn_add: hashes: 3360:0:0, 4<br>10(25375) INFO: <core> [tcp_main.c:2753]: tcpconn_1st_send(): quick connect for 0x7fe2ebd1e5c0<br>10(25375) DEBUG: tm [t_funcs.c:394]: t_relay_to(): SER: new transaction fwd'ed<br>14(25379) DEBUG: <core> [ip_addr.c:243]: print_ip(): tcpconn_new: new tcp connection: 192.168.1.195<br>10(25375) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>14(25379) DEBUG: <core> [tcp_main.c:1073]: tcpconn_new(): tcpconn_new: on port 19785, type 2<br>10(25375) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>10(25375) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>10(25375) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>14(25379) DEBUG: <core> [tcp_main.c:1382]: tcpconn_add(): tcpconn_add: hashes: 3888:3539:528, 5<br>10(25375) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>10(25375) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>10(25375) DEBUG: <core> [xavp.c:448]: xavp_destroy_list(): destroying xavp list (nil)<br>10(25375) DEBUG: <core> [receive.c:298]: receive_msg(): receive_msg: cleaning up<br>14(25379) DEBUG: <core> [io_wait.h:388]: io_watch_add(): DBG: io_watch_add(0x9eeee0, 29, 2, 0x7fe2ebd228e0), fd_no=19<br>14(25379) DEBUG: <core> [tcp_main.c:3565]: handle_ser_child(): handle_ser_child: read response= 7fe2ebd1e5c0, 6, fd 30 from 10 (25375)<br>14(25379) DEBUG: <core> [io_wait.h:388]: io_watch_add(): DBG: io_watch_add(0x9eeee0, 30, 2, 0x7fe2ebd1e5c0), fd_no=20<br>14(25379) DEBUG: <core> [io_wait.h:610]: io_watch_del(): DBG: io_watch_del (0x9eeee0, 29, -1, 0x0) fd_no=21 called<br>14(25379) DEBUG: <core> [tcp_main.c:4219]: handle_tcpconn_ev(): tcp: DBG: sending to child, events 1<br>14(25379) DEBUG: <core> [tcp_main.c:3902]: send2child(): selected tcp worker 3 13(25378) for activity on [tcp:<a href="http://192.168.1.195:4060">192.168.1.195:4060</a>], 0x7fe2ebd228e0<br>13(25378) DEBUG: <core> [tcp_read.c:1554]: handle_io(): received n=8 con=0x7fe2ebd228e0, fd=5<br>13(25378) DEBUG: <core> [tcp_read.c:1362]: tcp_read_req(): tcp_read_req: content-length= 392<br>13(25378) DEBUG: <core> [parser/msg_parser.c:623]: parse_msg(): SIP Request:<br>13(25378) DEBUG: <core> [parser/msg_parser.c:625]: parse_msg():  method:  <PRACK><br>13(25378) DEBUG: <core> [parser/msg_parser.c:627]: parse_msg():  uri:     <sip:192.168.1.195:4060;transport=tcp;lr><br>13(25378) DEBUG: <core> [parser/msg_parser.c:629]: parse_msg():  version: <SIP/2.0><br>13(25378) DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK7423.0dd1edaf37f3874c5176befe76ed5b3e.0>; state=6<br>13(25378) DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 236, <i> = <2>; state=16<br>13(25378) DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of header reached, state=5<br>13(25378) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers(): parse_headers: Via found, flags=2<br>13(25378) DEBUG: <core> [parser/msg_parser.c:515]: parse_headers(): parse_headers: this is the first via<br>13(25378) DEBUG: <core> [receive.c:154]: receive_msg(): After parse_msg...<br>13(25378) DEBUG: <core> [receive.c:197]: receive_msg(): preparing to run routing scripts...<br>13(25378) DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK1576634775>; state=16<br>13(25378) DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of header reached, state=5<br>13(25378) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers(): parse_headers: Via found, flags=100<br>13(25378) DEBUG: <core> [parser/msg_parser.c:526]: parse_headers(): parse_headers: this is the second via<br>13(25378) DEBUG: <core> [parser/parse_addr_spec.c:176]: parse_to_param(): DEBUG: add_param: tag=1656432204<br>13(25378) DEBUG: <core> [parser/parse_addr_spec.c:898]: parse_addr_spec(): end of header reached, state=29<br>13(25378) DEBUG: <core> [parser/msg_parser.c:190]: get_hdr_field(): DEBUG: get_hdr_field: <To> [43]; uri=[<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>] <br>13(25378) DEBUG: <core> [parser/msg_parser.c:192]: get_hdr_field(): DEBUG: to body [<<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>>]<br>13(25378) DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <3> <PRACK><br>13(25378) DEBUG: maxfwd [mf_funcs.c:85]: is_maxfwd_present(): value = 69 <br>13(25378) DEBUG: <core> [parser/msg_parser.c:204]: get_hdr_field(): DEBUG: get_hdr_body : content_length=392<br>13(25378) DEBUG: <core> [parser/msg_parser.c:106]: get_hdr_field(): found end of header<br>13(25378) DEBUG: <core> [parser/parse_addr_spec.c:176]: parse_to_param(): DEBUG: add_param: tag=604263664<br>13(25378) DEBUG: <core> [parser/parse_addr_spec.c:898]: parse_addr_spec(): end of header reached, state=29<br>13(25378) DEBUG: sanity [mod_sanity.c:255]: w_sanity_check(): sanity checks result: 1<br>13(25378) DEBUG: siputils [checks.c:106]: has_totag(): totag found<br>13(25378) DEBUG: rr [loose.c:113]: find_first_route(): No Route headers found<br>13(25378) DEBUG: rr [loose.c:929]: loose_route(): There is no Route HF<br>13(25378) DEBUG: <core> [msg_translator.c:206]: check_via_address(): check_via_address(192.168.1.195, 192.168.1.195, 0)<br>13(25378) DEBUG: <core> [tcp_main.c:2281]: tcpconn_send_put(): tcp_send: send from reader (25378 (13)), reusing fd<br>13(25378) DEBUG: <core> [tcp_main.c:2516]: tcpconn_do_send(): tcp_send: sending...<br>13(25378) DEBUG: <core> [tcp_main.c:2550]: tcpconn_do_send(): tcp_send: after real write: c= 0x7fe2ebd228e0 n=386 fd=5<br>14(25379) DEBUG: <core> [io_wait.h:610]: io_watch_del(): DBG: io_watch_del (0x9eeee0, 30, -1, 0x0) fd_no=20 called<br>13(25378) DEBUG: <core> [tcp_main.c:2551]: tcpconn_do_send(): tcp_send: buf=<br>SIP/2.0 404 Not here<br>Via: SIP/2.0/TCP 192.168.1.195:4060;branch=z9hG4bK7423.0dd1edaf37f3874c5176befe76ed5b3e.0;i=2<br>Via: SIP/2.0/TCP 192.168.1.195:19009;branch=z9hG4bK1576634775<br>From: <<a href="mailto:sip%3Alinux_ua_0@192.168.1.195">sip:linux_ua_0@192.168.1.195</a>>;tag=604263664<br>To: <<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>>;tag=1656432204<br>Call-ID: <a href="mailto:734015646@192.168.1.195">734015646@192.168.1.195</a><br>CSeq: 3 PRACK<br>Server: kamailio (4.2.3 (x86_64/linux))<br>Content-Length: 0<br><br><br>14(25379) DEBUG: <core> [tcp_main.c:4219]: handle_tcpconn_ev(): tcp: DBG: sending to child, events 1<br>14(25379) DEBUG: <core> [tcp_main.c:3898]: send2child(): WARNING: send2child: no free tcp receiver,  connection passed to the least busy one (1)<br>14(25379) DEBUG: <core> [tcp_main.c:3902]: send2child(): selected tcp worker 0 10(25375) for activity on [tcp:<a href="http://192.168.1.195:4060">192.168.1.195:4060</a>], 0x7fe2ebd1e5c0<br>13(25378) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>13(25378) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>10(25375) DEBUG: <core> [tcp_read.c:1554]: handle_io(): received n=8 con=0x7fe2ebd1e5c0, fd=10<br>13(25378) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>13(25378) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>13(25378) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>13(25378) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>10(25375) DEBUG: <core> [tcp_read.c:1362]: tcp_read_req(): tcp_read_req: content-length= 0<br>13(25378) DEBUG: <core> [xavp.c:448]: xavp_destroy_list(): destroying xavp list (nil)<br>10(25375) DEBUG: <core> [parser/msg_parser.c:633]: parse_msg(): SIP Reply  (status):<br>13(25378) DEBUG: <core> [receive.c:298]: receive_msg(): receive_msg: cleaning up<br>10(25375) DEBUG: <core> [parser/msg_parser.c:635]: parse_msg():  version: <SIP/2.0><br>10(25375) DEBUG: <core> [parser/msg_parser.c:637]: parse_msg():  status:  <404><br>10(25375) DEBUG: <core> [parser/msg_parser.c:639]: parse_msg():  reason:  <Not here><br>10(25375) DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK7423.0dd1edaf37f3874c5176befe76ed5b3e.0>; state=6<br>13(25378) DEBUG: <core> [io_wait.h:388]: io_watch_add(): DBG: io_watch_add(0xa33180, 5, 2, 0x7fe2ebd228e0), fd_no=1<br>10(25375) DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 236, <i> = <2>; state=16<br>10(25375) DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of header reached, state=5<br>10(25375) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers(): parse_headers: Via found, flags=2<br>10(25375) DEBUG: <core> [parser/msg_parser.c:515]: parse_headers(): parse_headers: this is the first via<br>10(25375) DEBUG: <core> [receive.c:154]: receive_msg(): After parse_msg...<br>10(25375) DEBUG: tm [t_lookup.c:1072]: t_check_msg(): DEBUG: t_check_msg: msg id=5 global id=4 T start=0xffffffffffffffff<br>10(25375) DEBUG: <core> [parser/parse_via.c:1284]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK1576634775>; state=16<br>10(25375) DEBUG: <core> [parser/parse_via.c:2672]: parse_via(): end of header reached, state=5<br>10(25375) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers(): parse_headers: Via found, flags=62<br>10(25375) DEBUG: <core> [parser/msg_parser.c:526]: parse_headers(): parse_headers: this is the second via<br>10(25375) DEBUG: <core> [parser/parse_addr_spec.c:176]: parse_to_param(): DEBUG: add_param: tag=1656432204<br>10(25375) DEBUG: <core> [parser/parse_addr_spec.c:898]: parse_addr_spec(): end of header reached, state=29<br>10(25375) DEBUG: <core> [parser/msg_parser.c:190]: get_hdr_field(): DEBUG: get_hdr_field: <To> [43]; uri=[<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>] <br>10(25375) DEBUG: <core> [parser/msg_parser.c:192]: get_hdr_field(): DEBUG: to body [<<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>>]<br>10(25375) DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field(): get_hdr_field: cseq <CSeq>: <3> <PRACK><br>10(25375) DEBUG: tm [t_lookup.c:949]: t_reply_matching(): DEBUG: t_reply_matching: hash 12871 label 0 branch 0<br>10(25375) DEBUG: tm [t_lookup.c:1004]: t_reply_matching(): DEBUG: t_reply_matching: reply matched (T=0x7fe2ebd1b780)!<br>10(25375) DEBUG: tm [t_lookup.c:1141]: t_check_msg(): DEBUG: t_check_msg: msg id=5 global id=5 T end=0x7fe2ebd1b780<br>10(25375) DEBUG: tm [t_reply.c:2200]: reply_received(): DEBUG: reply_received: org. status uas=0, uac[0]=0 local=0 is_invite=0)<br>10(25375) DEBUG: tm [t_reply.c:1294]: t_should_relay_response(): ->>>>>>>>> T_code=0, new_code=404<br>10(25375) DEBUG: tm [t_reply.c:1812]: relay_reply(): DEBUG: relay_reply: branch=0, save=0, relay=0 icode=0<br>10(25375) DEBUG: <core> [parser/msg_parser.c:204]: get_hdr_field(): DEBUG: get_hdr_body : content_length=0<br>10(25375) DEBUG: <core> [parser/msg_parser.c:106]: get_hdr_field(): found end of header<br>10(25375) DEBUG: <core> [msg_translator.c:2278]: generate_res_buf_from_sip_res():  old size: 386, new size: 291<br>10(25375) DEBUG: <core> [msg_translator.c:2296]: generate_res_buf_from_sip_res(): copied size: orig:117, new: 22, rest: 269 msg=<br>SIP/2.0 404 Not here<br>Via: SIP/2.0/TCP 192.168.1.195:19009;branch=z9hG4bK1576634775<br>From: <<a href="mailto:sip%3Alinux_ua_0@192.168.1.195">sip:linux_ua_0@192.168.1.195</a>>;tag=604263664<br>To: <<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>>;tag=1656432204<br>Call-ID: <a href="mailto:734015646@192.168.1.195">734015646@192.168.1.195</a><br>CSeq: 3 PRACK<br>Server: kamailio (4.2.3 (x86_64/linux))<br>Content-Length: 0<br><br><br>10(25375) DEBUG: <core> [mem/shm_mem.c:111]: _shm_resize(): WARNING:vqm_resize: resize(0) called<br>10(25375) DEBUG: <core> [tcp_main.c:2281]: tcpconn_send_put(): tcp_send: send from reader (25375 (10)), reusing fd<br>10(25375) DEBUG: <core> [tcp_main.c:2516]: tcpconn_do_send(): tcp_send: sending...<br>10(25375) DEBUG: <core> [tcp_main.c:2550]: tcpconn_do_send(): tcp_send: after real write: c= 0x7fe2ebd096b0 n=291 fd=5<br>10(25375) DEBUG: <core> [tcp_main.c:2551]: tcpconn_do_send(): tcp_send: buf=<br>SIP/2.0 404 Not here<br>Via: SIP/2.0/TCP 192.168.1.195:19009;branch=z9hG4bK1576634775<br>From: <<a href="mailto:sip%3Alinux_ua_0@192.168.1.195">sip:linux_ua_0@192.168.1.195</a>>;tag=604263664<br>To: <<a href="mailto:sip%3Alinux_ua_1@192.168.1.195">sip:linux_ua_1@192.168.1.195</a>>;tag=1656432204<br>Call-ID: <a href="mailto:734015646@192.168.1.195">734015646@192.168.1.195</a><br>CSeq: 3 PRACK<br>Server: kamailio (4.2.3 (x86_64/linux))<br>Content-Length: 0<br><br><br>10(25375) DEBUG: tm [t_reply.c:1653]: cleanup_uac_timers(): DEBUG: cleanup_uac_timers: RETR/FR timers reset<br>10(25375) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>10(25375) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>10(25375) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>10(25375) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>10(25375) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>10(25375) DEBUG: <core> [usr_avp.c:643]: destroy_avp_list(): DEBUG:destroy_avp_list: destroying list (nil)<br>10(25375) DEBUG: <core> [xavp.c:448]: xavp_destroy_list(): destroying xavp list (nil)<br>10(25375) DEBUG: <core> [receive.c:298]: receive_msg(): receive_msg: cleaning up<br>10(25375) DEBUG: <core> [io_wait.h:388]: io_watch_add(): DBG: io_watch_add(0xa33180, 10, 2, 0x7fe2ebd1e5c0), fd_no=2<br><br>14(25379) CRITICAL: <core> [pass_fd.c:293]: receive_fd(): EOF on 13<br>14(25379) DEBUG: <core> [tcp_main.c:3537]: handle_ser_child(): DBG: handle_ser_child: dead child 4, pid 25369 (shutting down?)<br>14(25379) DEBUG: <core> [io_wait.h:610]: io_watch_del(): DBG: io_watch_del (0x9eeee0, 13, -1, 0x0) fd_no=19 called<br>root@Kamal:/usr/local/etc/kamailio# <br></b></i><br></div>