Hi All,

As said i tested with debug=3 and got two set of logs..

1 - User A succesfully send IM to User B ( with tcp)

2 - User B try to send IM to User B ( with tcp ) = FAIL

Kindly help me understand what is happening ..

1. I could see that there i 2 via headers added by Kamailio server.

2. I tested with

sudo kamcmd core.tcp_list

I get 2 connection ( with 2 users registred with TCP)

But when i try to send message from User 2 to User 1, i see that 1 more connection is added.

But here the port is confusing. becuase the other 2 tcp connection shows the rport of the users. But with the 3rd connection the port is shown as 5060..

I am attaching the log below. Also i am attaching the log file your reference ,

ubuntu@ubuntu-desktop:/var/log$ tail -f kamailio.log

Jun 21 11:51:44 ubuntu-desktop /usr/local/sbin/kamailio[11056]: last message repeated 5 times
Jun 21 11:51:44 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [xavp.c:365]: destroying xavp list (nil)
Jun 21 11:51:44 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
Jun 21 11:51:44 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [io_wait.h:390]: DBG: io_watch_add(0x827f2a0, 6, 2, 0xb34f0b90), fd_no=1
Jun 21 11:51:50 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [io_wait.h:617]: DBG: io_watch_del (0x827f2a0, 6, -1, 0x10) fd_no=2 called
Jun 21 11:51:50 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [tcp_read.c:1285]: releasing con 0xb34f0b90, state 1, fd=6, id=3
Jun 21 11:51:50 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [tcp_read.c:1286]: extra_data (nil)
Jun 21 11:51:50 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [tcp_main.c:3381]: handle_tcp_child: reader response= b34f0b90, 1 from 2
Jun 21 11:51:50 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [io_wait.h:390]: DBG: io_watch_add(0x825d060, 33, 2, 0xb34f0b90), fd_no=23
Jun 21 11:51:50 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [tcp_main.c:3511]: handle_tcp_child: CONN_RELEASE 0xb34f0b90 refcnt= 1
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [io_wait.h:617]: DBG: io_watch_del (0x825d060, 33, -1, 0x0) fd_no=24 called
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [tcp_main.c:4298]: tcp: DBG: sending to child, events 1
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [tcp_main.c:3969]: selected tcp worker 3 16(11057) for activity on [tcp:43.88.79.137:5060], 0xb34f0b90
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [tcp_read.c:1358]: received n=4 con=0xb34f0b90, fd=6
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [tcp_read.c:1168]: tcp_read_req: content-length= 5
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [parser/msg_parser.c:624]: SIP Request:
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [parser/msg_parser.c:626]: method: <MESSAGE>
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [parser/msg_parser.c:628]: uri:     <sip:sard7@43.88.79.137>
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [parser/msg_parser.c:630]: version: <SIP/2.0>
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 235, <rport> = <n/a>; state=6
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 232, <branch> = <z9hG4bK11639>; state=16
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, state=5
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via found, flags=2
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: this is the first via
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [receive.c:149]: After parse_msg...
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [receive.c:190]: preparing to run routing scripts...
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=10
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [parser/msg_parser.c:188]: DEBUG: get_hdr_field: <To> [34]; uri=[sip:sard7@43.88.79.137]
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: to body ["sard7" <sip:sard7@43.88.79.137>#015#012]
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [parser/msg_parser.c:168]: get_hdr_field: cseq <CSeq>: <20> <MESSAGE>
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: maxfwd [mf_funcs.c:85]: value = 70
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [parser/msg_parser.c:202]: DEBUG: get_hdr_body : content_length=5
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [parser/msg_parser.c:104]: found end of header
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [parser/parse_to.c:178]: DEBUG: add_param: tag=29636
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=29
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: sanity [mod_sanity.c:255]: sanity checks result: 1
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: siputils [checks.c:103]: no totag
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=1 global id=0 T start=0xffffffff
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: tm [t_lookup.c:527]: t_lookup_request: start searching: hash=38277, isACK=0
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: tm [t_lookup.c:709]: DEBUG: t_lookup_request: no transaction found
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: tm [t_lookup.c:1148]: DEBUG: t_check_msg: msg id=1 global id=1 T end=(nil)
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==9 && [43.88.79.137] == [127.0.0.1]
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==12 && [43.88.79.137] == [43.88.79.137]
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: registrar [lookup.c:181]: contact for [sard7] found by address
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: tm [t_lookup.c:1379]: DEBUG: t_newtran: msg id=1 , global msg id=1 , T on entrance=(nil)
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: tm [t_lookup.c:527]: t_lookup_request: start searching: hash=38277, isACK=0
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: tm [t_lookup.c:709]: DEBUG: t_lookup_request: no transaction found
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: tm [t_hooks.c:374]: DBG: trans=0xb34f1de8, callback type 1, id 0 entered
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [msg_translator.c:2496]: create_via_hf: id added: <;i=3>, rcv proto=2
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [msg_translator.c:206]: check_via_address(43.88.108.53, 43.88.108.53, 0)
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [tcp_main.c:1843]: tcp_send: no open tcp connection found, opening new one
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [ip_addr.c:247]: tcpconn_new: new tcp connection: 43.88.109.14
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [tcp_main.c:1089]: tcpconn_new: on port 5060, type 2
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [tcp_main.c:1403]: tcpconn_add: hashes: 1600:1269:0, 4
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [tcp_main.c:2733]: pending write on new connection 0xb34f3538 (-1/439 bytes written)
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: tm [t_funcs.c:388]: SER: new transaction fwd'ed
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: last message repeated 5 times
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [xavp.c:365]: destroying xavp list (nil)
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [io_wait.h:390]: DBG: io_watch_add(0x827f2a0, 6, 2, 0xb34f0b90), fd_no=1
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [tcp_main.c:3620]: handle_ser_child: read response= b34f3538, 5, fd 34 from 16 (11057)
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [io_wait.h:390]: DBG: io_watch_add(0x825d060, 34, 2, 0xb34f3538), fd_no=23
Jun 21 11:53:29 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [io_wait.h:796]: DBG: io_watch_chg (0x825d060, 34, 0x1, 0xffffffff) fd_no=24 called
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [io_wait.h:617]: DBG: io_watch_del (0x825d060, 34, -1, 0x0) fd_no=24 called
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [tcp_main.c:4298]: tcp: DBG: sending to child, events 1
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [tcp_main.c:3969]: selected tcp worker 0 13(11054) for activity on [tcp:43.88.79.137:5060], 0xb34f3538
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [tcp_read.c:1358]: received n=4 con=0xb34f3538, fd=6
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [tcp_read.c:1168]: tcp_read_req: content-length= 0
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [parser/msg_parser.c:634]: SIP Reply (status):
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [parser/msg_parser.c:636]: version: <SIP/2.0>
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [parser/msg_parser.c:638]: status: <200>
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [parser/msg_parser.c:640]: reason: <OK>
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 232, <branch> = <z9hG4bK5859.a75f15f4.0>; state=6
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 236, <i> = <3>; state=16
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, state=5
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via found, flags=2
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: this is the first via
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [receive.c:149]: After parse_msg...
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=2 global id=1 T start=(nil)
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 235, <rport> = <64935>; state=6
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 232, <branch> = <z9hG4bK11639>; state=16
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, state=5
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via found, flags=22
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [parser/msg_parser.c:524]: parse_headers: this is the second via
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [parser/parse_to.c:178]: DEBUG: add_param: tag=12730
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=29
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [parser/msg_parser.c:188]: DEBUG: get_hdr_field: <To> [44]; uri=[sip:sard7@43.88.79.137]
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: to body ["sard7" <sip:sard7@43.88.79.137>]
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [parser/msg_parser.c:168]: get_hdr_field: cseq <CSeq>: <20> <MESSAGE>
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: tm [t_lookup.c:965]: DEBUG: t_reply_matching: hash 38277 label 1330771322 branch 0
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: tm [t_lookup.c:1016]: DEBUG: t_reply_matching: reply matched (T=0xb34f1de8)!
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: tm [t_lookup.c:1148]: DEBUG: t_check_msg: msg id=2 global id=2 T end=0xb34f1de8
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: tm [t_reply.c:2081]: DEBUG: reply_received: org. status uas=0, uac[0]=0 local=0 is_invite=0)
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: tm [t_reply.c:1204]: ->>>>>>>>> T_code=0, new_code=200
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: tm [t_reply.c:1702]: DEBUG: relay_reply: branch=0, save=0, relay=0
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [parser/msg_parser.c:202]: DEBUG: get_hdr_body : content_length=0
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [parser/msg_parser.c:104]: found end of header
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [msg_translator.c:1933]: old size: 337, new size: 272
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [msg_translator.c:1951]: build_res_from_sip_res: copied size: orig:81, new: 16, rest: 256 msg=#012SIP/2.0 200 OK#015#012Via: SIP/2.0/TCP 43.88.108.53:5060;rport=64935;branch=z9hG4bK11639#015#012From: <sip:sard4@43.88.79.137>;tag=29636#015#012To: "sard7" <sip:sard7@43.88.79.137>;tag=12730#015#012Call-ID: 4226#015#012CSeq: 20 MESSAGE#015#012User-Agent: Linphone/3.5.2 (eXosip2/3.6.0)#015#012Content-Length: 0#015#012#015#012
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [mem/shm_mem.c:111]: WARNING:vqm_resize: resize(0) called
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [tcp_main.c:2332]: tcp_send: tcp connection found (0xb34f0b90), acquiring fd
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [tcp_main.c:2343]: tcp_send, c= 0xb34f0b90, n=8
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [tcp_main.c:3620]: handle_ser_child: read response= b34f0b90, 2, fd -1 from 13 (11054)
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [tcp_main.c:2373]: tcp_send: after receive_fd: c= 0xb34f0b90 n=4 fd=10
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [tcp_main.c:2552]: tcp_send: sending...
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [tcp_main.c:2586]: tcp_send: after real write: c= 0xb34f0b90 n=272 fd=10
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [tcp_main.c:2587]: tcp_send: buf=#012SIP/2.0 200 OK#015#012Via: SIP/2.0/TCP 43.88.108.53:5060;rport=64935;branch=z9hG4bK11639#015#012From: <sip:sard4@43.88.79.137>;tag=29636#015#012To: "sard7" <sip:sard7@43.88.79.137>;tag=12730#015#012Call-ID: 4226#015#012CSeq: 20 MESSAGE#015#012User-Agent: Linphone/3.5.2 (eXosip2/3.6.0)#015#012Content-Length: 0#015#012#015#012
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: tm [t_reply.c:1543]: DEBUG: cleanup_uac_timers: RETR/FR timers reset
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: last message repeated 5 times
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [xavp.c:365]: destroying xavp list (nil)
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
Jun 21 11:53:30 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [io_wait.h:390]: DBG: io_watch_add(0x827f2a0, 6, 2, 0xb34f3538), fd_no=1
Jun 21 11:53:35 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [io_wait.h:617]: DBG: io_watch_del (0x827f2a0, 6, -1, 0x10) fd_no=2 called
Jun 21 11:53:35 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [tcp_read.c:1285]: releasing con 0xb34f0b90, state 1, fd=6, id=3
Jun 21 11:53:35 ubuntu-desktop /usr/local/sbin/kamailio[11057]: DEBUG: <core> [tcp_read.c:1286]: extra_data (nil)
Jun 21 11:53:35 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [tcp_main.c:3381]: handle_tcp_child: reader response= b34f0b90, 1 from 3
Jun 21 11:53:35 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [io_wait.h:390]: DBG: io_watch_add(0x825d060, 33, 2, 0xb34f0b90), fd_no=23
Jun 21 11:53:35 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [tcp_main.c:3511]: handle_tcp_child: CONN_RELEASE 0xb34f0b90 refcnt= 1
Jun 21 11:53:36 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [io_wait.h:617]: DBG: io_watch_del (0x827f2a0, 6, -1, 0x10) fd_no=2 called
Jun 21 11:53:36 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [tcp_read.c:1285]: releasing con 0xb34f3538, state 1, fd=6, id=4
Jun 21 11:53:36 ubuntu-desktop /usr/local/sbin/kamailio[11054]: DEBUG: <core> [tcp_read.c:1286]: extra_data (nil)
Jun 21 11:53:36 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [tcp_main.c:3381]: handle_tcp_child: reader response= b34f3538, 1 from 0
Jun 21 11:53:36 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [io_wait.h:390]: DBG: io_watch_add(0x825d060, 34, 2, 0xb34f3538), fd_no=24
Jun 21 11:53:36 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [tcp_main.c:3511]: handle_tcp_child: CONN_RELEASE 0xb34f3538 refcnt= 1

================================================== Secnario when IM- Fail=======================

Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [io_wait.h:617]: DBG: io_watch_del (0x825d060, 31, -1, 0x0) fd_no=25 called
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [tcp_main.c:4298]: tcp: DBG: sending to child, events 1
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [tcp_main.c:3969]: selected tcp worker 1 14(11055) for activity on [tcp:43.88.79.137:5060], 0xb34ef8a0
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [tcp_read.c:1358]: received n=4 con=0xb34ef8a0, fd=6
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [tcp_read.c:1168]: tcp_read_req: content-length= 5
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/msg_parser.c:624]: SIP Request:
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/msg_parser.c:626]: method: <MESSAGE>
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/msg_parser.c:628]: uri:     <sip:sard4@43.88.79.137>
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/msg_parser.c:630]: version: <SIP/2.0>
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 235, <rport> = <n/a>; state=6
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 232, <branch> = <z9hG4bK29470>; state=16
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, state=5
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via found, flags=2
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: this is the first via
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [receive.c:149]: After parse_msg...
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [receive.c:190]: preparing to run routing scripts...
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=10
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/msg_parser.c:188]: DEBUG: get_hdr_field: <To> [34]; uri=[sip:sard4@43.88.79.137]
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: to body ["sard4" <sip:sard4@43.88.79.137>#015#012]
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/msg_parser.c:168]: get_hdr_field: cseq <CSeq>: <20> <MESSAGE>
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: maxfwd [mf_funcs.c:85]: value = 70
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/msg_parser.c:202]: DEBUG: get_hdr_body : content_length=5
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/msg_parser.c:104]: found end of header
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/parse_to.c:178]: DEBUG: add_param: tag=17990
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=29
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: sanity [mod_sanity.c:255]: sanity checks result: 1
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: siputils [checks.c:103]: no totag
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=2 global id=1 T start=(nil)
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: tm [t_lookup.c:527]: t_lookup_request: start searching: hash=1628, isACK=0
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: tm [t_lookup.c:709]: DEBUG: t_lookup_request: no transaction found
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: tm [t_lookup.c:1148]: DEBUG: t_check_msg: msg id=2 global id=2 T end=(nil)
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==9 && [43.88.79.137] == [127.0.0.1]
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [socket_info.c:583]: grep_sock_info - checking if host==us: 12==12 && [43.88.79.137] == [43.88.79.137]
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [socket_info.c:587]: grep_sock_info - checking if port 5060 (advertise 0) matches port 5060
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: registrar [lookup.c:181]: contact for [sard4] found by address
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: tm [t_lookup.c:1379]: DEBUG: t_newtran: msg id=2 , global msg id=2 , T on entrance=(nil)
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: tm [t_lookup.c:527]: t_lookup_request: start searching: hash=1628, isACK=0
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: tm [t_lookup.c:709]: DEBUG: t_lookup_request: no transaction found
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: tm [t_hooks.c:374]: DBG: trans=0xb34f1de8, callback type 1, id 0 entered
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [msg_translator.c:2496]: create_via_hf: id added: <;i=2>, rcv proto=2
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [msg_translator.c:206]: check_via_address(43.88.109.14, 43.88.109.14, 0)
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [tcp_main.c:1843]: tcp_send: no open tcp connection found, opening new one
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [ip_addr.c:247]: tcpconn_new: new tcp connection: 43.88.108.53
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [tcp_main.c:1089]: tcpconn_new: on port 5060, type 2
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [tcp_main.c:1403]: tcpconn_add: hashes: 2555:2894:0, 5
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [tcp_main.c:2733]: pending write on new connection 0xb34f4f58 (-1/439 bytes written)
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: tm [t_funcs.c:388]: SER: new transaction fwd'ed
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: last message repeated 5 times
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [xavp.c:365]: destroying xavp list (nil)
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [io_wait.h:390]: DBG: io_watch_add(0x827f2a0, 6, 2, 0xb34ef8a0), fd_no=1
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [tcp_main.c:3620]: handle_ser_child: read response= b34f4f58, 5, fd 35 from 14 (11055)
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [io_wait.h:390]: DBG: io_watch_add(0x825d060, 35, 2, 0xb34f4f58), fd_no=24
Jun 21 11:54:03 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [io_wait.h:796]: DBG: io_watch_chg (0x825d060, 35, 0x1, 0xffffffff) fd_no=25 called
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [tcp_read.c:1168]: tcp_read_req: content-length= 5
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/msg_parser.c:624]: SIP Request:
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/msg_parser.c:626]: method: <MESSAGE>
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/msg_parser.c:628]: uri:     <sip:sard4@43.88.79.137>
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/msg_parser.c:630]: version: <SIP/2.0>
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 235, <rport> = <n/a>; state=6
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 232, <branch> = <z9hG4bK29470>; state=16
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, state=5
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via found, flags=2
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: this is the first via
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [receive.c:149]: After parse_msg...
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [receive.c:190]: preparing to run routing scripts...
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=10
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/msg_parser.c:188]: DEBUG: get_hdr_field: <To> [34]; uri=[sip:sard4@43.88.79.137]
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: to body ["sard4" <sip:sard4@43.88.79.137>#015#012]
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/msg_parser.c:168]: get_hdr_field: cseq <CSeq>: <20> <MESSAGE>
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: maxfwd [mf_funcs.c:85]: value = 70
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/msg_parser.c:202]: DEBUG: get_hdr_body : content_length=5
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/msg_parser.c:104]: found end of header
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/parse_to.c:178]: DEBUG: add_param: tag=17990
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=29
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: sanity [mod_sanity.c:255]: sanity checks result: 1
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: siputils [checks.c:103]: no totag
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=3 global id=2 T start=0xffffffff
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: tm [t_lookup.c:527]: t_lookup_request: start searching: hash=1628, isACK=0
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: tm [t_lookup.c:470]: DEBUG: RFC3261 transaction matched, tid=29470
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: tm [t_lookup.c:726]: DEBUG: t_lookup_request: transaction found (T=0xb34f1de8)
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: tm [t_lookup.c:1148]: DEBUG: t_check_msg: msg id=3 global id=3 T end=0xb34f1de8
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: tm [t_reply.c:1483]: DBG: t_retransmit_reply: nothing to retransmit
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: last message repeated 5 times
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [xavp.c:365]: destroying xavp list (nil)
Jun 21 11:54:04 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [io_wait.h:617]: DBG: io_watch_del (0x825d060, 35, -1, 0x0) fd_no=25 called
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [tcp_main.c:4298]: tcp: DBG: sending to child, events 1
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [tcp_main.c:3969]: selected tcp worker 2 15(11056) for activity on [tcp:43.88.79.137:5060], 0xb34f4f58
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [tcp_read.c:1358]: received n=4 con=0xb34f4f58, fd=6
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [tcp_read.c:1168]: tcp_read_req: content-length= 0
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [parser/msg_parser.c:634]: SIP Reply (status):
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [parser/msg_parser.c:636]: version: <SIP/2.0>
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [parser/msg_parser.c:638]: status: <480>
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [parser/msg_parser.c:640]: reason: <Temporarily Unavailable>
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 232, <branch> = <z9hG4bKc56.5c477096.0>; state=6
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 236, <i> = <2>; state=16
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, state=5
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via found, flags=2
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: this is the first via
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [receive.c:149]: After parse_msg...
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: tm [t_lookup.c:1079]: DEBUG: t_check_msg: msg id=2 global id=1 T start=(nil)
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 235, <rport> = <60840>; state=6
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [parser/parse_via.c:1286]: Found param type 232, <branch> = <z9hG4bK29470>; state=16
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [parser/parse_via.c:2561]: end of header reached, state=5
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [parser/msg_parser.c:511]: parse_headers: Via found, flags=22
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [parser/msg_parser.c:524]: parse_headers: this is the second via
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [parser/parse_to.c:178]: DEBUG: add_param: tag=278a8a835a2e4f92aca1f8bc3899ef93
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [parser/parse_to.c:802]: end of header reached, state=29
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [parser/msg_parser.c:188]: DEBUG: get_hdr_field: <To> [71]; uri=[sip:sard4@43.88.79.137]
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: to body ["sard4" <sip:sard4@43.88.79.137>]
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [parser/msg_parser.c:168]: get_hdr_field: cseq <CSeq>: <20> <MESSAGE>
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: tm [t_lookup.c:965]: DEBUG: t_reply_matching: hash 1628 label 1762096325 branch 0
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: tm [t_lookup.c:1016]: DEBUG: t_reply_matching: reply matched (T=0xb34f1de8)!
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: tm [t_lookup.c:1148]: DEBUG: t_check_msg: msg id=2 global id=2 T end=0xb34f1de8
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: tm [t_reply.c:2081]: DEBUG: reply_received: org. status uas=0, uac[0]=0 local=0 is_invite=0)
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: tm [t_reply.c:1204]: ->>>>>>>>> T_code=0, new_code=480
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: tm [t_reply.c:1702]: DEBUG: relay_reply: branch=0, save=0, relay=0
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [parser/msg_parser.c:202]: DEBUG: get_hdr_body : content_length=0
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [parser/msg_parser.c:104]: found end of header
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [msg_translator.c:1933]: old size: 343, new size: 279
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [msg_translator.c:1951]: build_res_from_sip_res: copied size: orig:101, new: 37, rest: 242 msg=#012SIP/2.0 480 Temporarily Unavailable#015#012Via: SIP/2.0/TCP 43.88.109.14:5060;rport=60840;branch=z9hG4bK29470#015#012From: <sip:sard7@43.88.79.137>;tag=17990#015#012To: "sard4" <sip:sard4@43.88.79.137>;tag=278a8a835a2e4f92aca1f8bc3899ef93#015#012Call-ID: 25806#015#012CSeq: 20 MESSAGE#015#012Content-Length: 0#015#012#015#012
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [mem/shm_mem.c:111]: WARNING:vqm_resize: resize(0) called
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [tcp_main.c:2332]: tcp_send: tcp connection found (0xb34ef8a0), acquiring fd
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [tcp_main.c:2343]: tcp_send, c= 0xb34ef8a0, n=8
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [tcp_main.c:3620]: handle_ser_child: read response= b34ef8a0, 2, fd -1 from 15 (11056)
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [tcp_main.c:2373]: tcp_send: after receive_fd: c= 0xb34ef8a0 n=4 fd=10
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [tcp_main.c:2552]: tcp_send: sending...
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [tcp_main.c:2586]: tcp_send: after real write: c= 0xb34ef8a0 n=279 fd=10
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [tcp_main.c:2587]: tcp_send: buf=#012SIP/2.0 480 Temporarily Unavailable#015#012Via: SIP/2.0/TCP 43.88.109.14:5060;rport=60840;branch=z9hG4bK29470#015#012From: <sip:sard7@43.88.79.137>;tag=17990#015#012To: "sard4" <sip:sard4@43.88.79.137>;tag=278a8a835a2e4f92aca1f8bc3899ef93#015#012Call-ID: 25806#015#012CSeq: 20 MESSAGE#015#012Content-Length: 0#015#012#015#012
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: tm [t_reply.c:1543]: DEBUG: cleanup_uac_timers: RETR/FR timers reset
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: last message repeated 5 times
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [xavp.c:365]: destroying xavp list (nil)
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
Jun 21 11:54:07 ubuntu-desktop /usr/local/sbin/kamailio[11056]: DEBUG: <core> [io_wait.h:390]: DBG: io_watch_add(0x827f2a0, 6, 2, 0xb34f4f58), fd_no=1
Jun 21 11:54:10 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [io_wait.h:617]: DBG: io_watch_del (0x827f2a0, 6, -1, 0x10) fd_no=2 called
Jun 21 11:54:10 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [tcp_read.c:1285]: releasing con 0xb34ef8a0, state 1, fd=6, id=2
Jun 21 11:54:10 ubuntu-desktop /usr/local/sbin/kamailio[11055]: DEBUG: <core> [tcp_read.c:1286]: extra_data (nil)
Jun 21 11:54:10 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [tcp_main.c:3381]: handle_tcp_child: reader response= b34ef8a0, 1 from 1
Jun 21 11:54:10 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [io_wait.h:390]: DBG: io_watch_add(0x825d060, 31, 2, 0xb34ef8a0), fd_no=24
Jun 21 11:54:10 ubuntu-desktop /usr/local/sbin/kamailio[11058]: DEBUG: <core> [tcp_main.c:3511]: handle_tcp_child: CONN_RELEASE 0xb34ef8a0 refcnt= 1

Regards
Sunil C

On Sun, Jun 23, 2013 at 8:55 PM, Daniel-Constantin Mierla <miconda@gmail.com> wrote:

Hello,

run with debug=3 and see the log messages. I guess there is a mismatch on local socket and remote socket conditions that result in creating a new connection.

Cheers,
Daniel
On 6/21/13 1:47 PM, Sunil Chandrasekharan wrote:
Hi All

Today i could find some information from the logs.

When i tested the command :

sudo kamcmd core.tcp_list

I get 2 connection ( with 2 users regitred with TCP)

But when i try to send message from User 2 to User 1, i see that 1 more connection is added.

But here the port is confusing. becuase the other 2 tcp connection shows the rport of the users. But with the 3rd connection the port is shown as 5060..

I feel Kamailio is adding a new TCP connection instead of using the existing connection between the client and Kamailio with the rport number.

I read that we can use (force_rport()) , but i could not understand how to use it . Alo when i gave

force_rport=yes inside the global parameter of Kamaili.cfg file, i still face the same issue.

This issue exists even when User 2 try to call/IM to User 1.

my laptop is User 1. But i can send IM/Call User 2 succeessfully. I dont understand how my machine can send IM/call successfully, and why no other user can do the same?

Kindly support me

On Thu, Jun 20, 2013 at 5:27 PM, Sunil Chandrasekharan <sunil.kainat@gmail.com> wrote:

Hi All,

I tested again today by disabling the presence module.

Still i could not make TCP based IM working with Kamailio.

I checked the tcp-connection-lifetime =3605.

Still i get 480 Temperory un available.

Step 1 : login/register on two lin phones ( on differnt PC)

Step 2: from PC 1 (user A) send message to user B

Step 3: user B receive the mesage.

Step 4. Send message from User B to User A

Result : 480 Temperory unavailable.

1. I feel user A connection is getting closed . Hence not able to reach user A.

2. I also see User A and User B message contruct has 2 Via headers.

There is no change or anything abnormal happening.

Kindly help me forward to get tcp based IM working between two clients.

On Tue, Jun 18, 2013 at 2:27 PM, Sunil Chandrasekharan <sunil.kainat@gmail.com> wrote:

Hi ,

I used open internet, i really doubt if there is any NAT issue here.

But my config file(kamailio.cfg) shows : tcp-connection-lifetime=3605

But i dont know what is the registration expire time . How can i see the registration expire time?

also my lin phone sends keep alive right?

can you please help me how can i see connection close parameter during forward/reply? i dont know where to set them?

Please suggest me the correct link to find tcp paremeter and cook book.

On Tue, Jun 18, 2013 at 2:06 PM, Daniel-Constantin Mierla <miconda@gmail.com> wrote:

Hello,

On 6/17/13 7:09 AM, Sunil Chandrasekharan wrote:

Hi All,

I have set up Kamailio 3.3 on Ubuntu machine.I created two user test 1 and test 2.
I could use Presence and also i was able to register to Kamailio server and exchange presence status with each other.

Details- I used TCP protocol .

testing methods - Linphone, a sample application.

I am able to register succesfully with (TCP) on to kamailio server using Lin phone and sample application.
I am able to update presence status of the users.

Issue :

When i try to send messages between two users ( using TCP )

1. from Sample application, when i try to send message, i get 420 temporarily Unavailable error from server.
2. from Lin phone 3.5.2, i was able to send messages ( sue TCP) but when the other user try to reply back , i get same error

480 Temporarily Unavailable. error from server.

I want a support to understand why i get error while sending messages with TCP via Kamailio server.

I am able to succeesfully send and receive messages when i use UDP from my sample application and Lin phone.

if the phones are behind nat, be sure the tcp connection lifetime is higher than the registration expire and that you don't set connection close after forward/reply. Look at core cookbook for the appropriate tcp parameter and config functions.

Cheers,
Daniel

--
Daniel-Constantin Mierla - http://www.asipto.com
http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
Kamailio Advanced Training, San Francisco, USA - June 24-27, 2013
* http://asipto.com/u/katu *

_______________________________________________
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
sr-users@lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
_______________________________________________
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
sr-users@lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
-- 
Daniel-Constantin Mierla - http://www.asipto.com
http://twitter.com/#!/miconda - http://www.linkedin.com/in/miconda
_______________________________________________
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
sr-users@lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users