OK, I think im making some progress...
I can now see that Kamailio is sending the invite to UM, but getting a 302 temporarely moved which is what UM does, and the contact field states CONTACT: sip:1989@10.98.6.5:5065;transport=TCP
Here is the debug from Asterisk:
-- Executing [1102@default:1] Dial("SIP/1103-0000002d", "SIP/1102|5") in new stack -- Called 1102I> -- SIP/1102-0000002e is ringing -- SIP/1102-0000002e is ringing -- SIP/1102-0000002e is ringing -- SIP/1102-0000002e is ringing -- Nobody picked up in 5000 ms -- Executing [1102@default:2] SIPAddHeader("SIP/1103-0000002d", "Diversion: sip:1102@10.98.6.5;reason=user-busy;screen=no;privacy=off") in new stack -- Executing [1102@default:3] Dial("SIP/1103-0000002d", "SIP/1989@EX-UM") in new stack -- Called 1989@EX-UM -- Got SIP response 302 "Moved Temporarily" back from 10.98.6.5 -- Now forwarding SIP/1103-0000002d to 'Local/1989@default' (thanks to SIP/EX-UM-0000002f) -- Executing [1989@default:1] Dial("Local/1989@default-a77b,2", "SIP/1989@EX-UM") in new stack [May 20 10:42:42] WARNING[5440]: app_dial.c:1263 dial_exec_full: Skipping dialing interface 'SIP/1989@EX-UM' again since it has already been dialed == Spawn extension (default, 1989, 1) exited non-zero on 'Local/1989@default-a77b,2' == Everyone is busy/congested at this time (1:0/0/1) -- Executing [1102@default:4] Dial("SIP/1103-0000002d", "SIP/1989@openser5065") in new stack -- Called 1989@openser5065 == Spawn extension (default, 1102, 4) exited non-zero on 'SIP/1103-0000002d' qa-qsuitePBX-01*CLI>
Here is the debug from kamailio. Can anyone make out what all this is?
May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [parser/msg_parser.c:612]: SIP Request: May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [parser/msg_parser.c:614]: method: <INVITE> May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [parser/msg_parser.c:616]: uri: sip:1989@10.98.6.5:5061 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [parser/msg_parser.c:618]: version: <SIP/2.0> May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 232, <branch> = <z9hG4bK214eb681>; state=6 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 235, <rport> = <n/a>; state=17 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [parser/parse_via.c:2296]: end of header reached, state=5 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [parser/msg_parser.c:500]: parse_headers: Via found, flags=2 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [parser/msg_parser.c:502]: parse_headers: this is the first via May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [receive.c:137]: After parse_msg... May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [receive.c:177]: preparing to run routing scripts... May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [parser/parse_to.c:808]: end of header reached, state=10 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [parser/msg_parser.c:174]: DEBUG: get_hdr_field: <To> [27]; uri=[sip:1989@10.98.6.5:5061] May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [parser/msg_parser.c:176]: DEBUG: to body [sip:1989@10.98.6.5:5061^M ] May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [parser/msg_parser.c:154]: get_hdr_field: cseq <CSeq>: <102> <INVITE> May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: maxfwd [mf_funcs.c:85]: value = 70 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [parser/msg_parser.c:188]: DEBUG: get_hdr_body : content_length=232 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [parser/msg_parser.c:90]: found end of header May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: rr [loose.c:108]: No Route headers found May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: rr [loose.c:907]: There is no Route HF May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [socket_info.c:485]: grep_sock_info - checking if host==us: 9==9 && [10.98.6.5] == [10.98.6.5] May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [socket_info.c:488]: grep_sock_info - checking if port 5061 matches port 5061 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: tm [t_lookup.c:1387]: DEBUG: t_newtran: msg id=1 , global msg id=0 , T on entrance=0xffffffffffffffff May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: tm [t_lookup.c:528]: t_lookup_request: start searching: hash=44018, isACK=0 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: tm [t_lookup.c:485]: DEBUG: RFC3261 transaction matching failed May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: tm [t_lookup.c:711]: DEBUG: t_lookup_request: no transaction found May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [parser/parse_to.c:179]: DEBUG: add_param: tag=as1444d940 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [parser/parse_to.c:808]: end of header reached, state=29 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: tm [t_hooks.c:374]: DBG: trans=0x7fe75afad0d8, callback type 1, id 0 entered May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: tm [t_funcs.c:351]: SER: new INVITE May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [msg_translator.c:200]: check_via_address(10.98.6.5, 10.98.6.5, 0) May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [mem/shm_mem.c:105]: WARNING:vqm_resize: resize(0) called May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: tm [t_reply.c:617]: DEBUG: reply sent out. buf=0x8a6e50: SIP/2.0 100 trying -..., shmem=0x7fe75afaf510: SIP/2.0 100 trying - May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: tm [t_reply.c:627]: DEBUG: _reply_light: finished May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [msg_translator.c:200]: check_via_address(10.98.6.5, 10.98.6.5, 0) May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [tcp_main.c:1786]: tcp_send: no open tcp connection found, opening new one May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [ip_addr.c:116]: tcpconn_new: new tcp connection: 10.98.118.20 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [tcp_main.c:1052]: tcpconn_new: on port 5060, type 2 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [tcp_main.c:1351]: tcpconn_add: hashes: 1794:0:0, 2 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [tcp_main.c:1861]: tcp_send: pending write on new connection 0x7fe75afafb48 (-1/887 bytes written) May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: tm [t_funcs.c:388]: SER: new transaction fwd'ed May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5425]: DEBUG: <core> [tcp_main.c:3067]: handle_ser_child: read response= 7fe75afafb48, 4, fd 26 from 2 (5414) May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5425]: DEBUG: <core> [io_wait.h:361]: DBG: io_watch_add(0x7ea7c0, 26, 2, 0x7fe75afafb48), fd_no=19 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) May 20 10:42:42 qa-qsuitePBX-01 last message repeated 3 times May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5414]: DEBUG: <core> [receive.c:280]: receive_msg: cleaning up May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5425]: DEBUG: <core> [io_wait.h:767]: DBG: io_watch_chg (0x7ea7c0, 26, 0x1, 0xffffffff) fd_no=20 called May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5425]: DEBUG: <core> [io_wait.h:588]: DBG: io_watch_del (0x7ea7c0, 26, -1, 0x0) fd_no=20 called May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5425]: DEBUG: <core> [tcp_main.c:3627]: tcp: DBG: sendig to child, events 1 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5425]: DEBUG: <core> [tcp_main.c:3336]: send2child: to tcp child 1 10(5422), 0x7fe75afafb48 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [tcp_read.c:884]: received n=8 con=0x7fe75afafb48, fd=7 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [tcp_read.c:713]: tcp_read_req: content-length= 0 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/msg_parser.c:622]: SIP Reply (status): May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/msg_parser.c:624]: version: <SIP/2.0> May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/msg_parser.c:626]: status: <100> May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/msg_parser.c:628]: reason: <Trying> May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/parse_to.c:808]: end of header reached, state=10 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/msg_parser.c:174]: DEBUG: get_hdr_field: <TO> [27]; uri=[sip:1989@10.98.6.5:5061] May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/msg_parser.c:176]: DEBUG: to body [sip:1989@10.98.6.5:5061^M ] May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/msg_parser.c:154]: get_hdr_field: cseq <CSEQ>: <102> <INVITE> May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 232, <branch> = <z9hG4bK2fba.ab0b4cf4.0>; state=9 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/parse_via.c:2339]: parse_via: next_via May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 232, <branch> = <z9hG4bK214eb681>; state=6 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 235, <rport> = <5060>; state=16 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/parse_via.c:2296]: end of header reached, state=5 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/msg_parser.c:500]: parse_headers: Via found, flags=2 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/msg_parser.c:502]: parse_headers: this is the first via May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [receive.c:137]: After parse_msg... May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: tm [t_lookup.c:1080]: DEBUG: t_check_msg: msg id=1 global id=0 T start=0xffffffffffffffff May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: tm [t_lookup.c:967]: DEBUG: t_reply_matching: hash 44018 label 1338290362 branch 0 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: tm [t_lookup.c:1018]: DEBUG: t_reply_matching: reply matched (T=0x7fe75afad0d8)! May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: tm [t_lookup.c:1149]: DEBUG: t_check_msg: msg id=1 global id=1 T end=0x7fe75afad0d8 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: tm [t_reply.c:1915]: DEBUG: reply_received: org. status uas=100, uac[0]=0 local=0 is_invite=1) May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: tm [t_reply.c:1059]: ->>>>>>>>> T_code=100, new_code=100 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: tm [t_reply.c:1549]: DEBUG: relay_reply: branch=0, save=0, relay=-1 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) May 20 10:42:42 qa-qsuitePBX-01 last message repeated 5 times May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [receive.c:280]: receive_msg: cleaning up May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [io_wait.h:361]: DBG: io_watch_add(0x82ea20, 7, 2, 0x7fe75afafb48), fd_no=1 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [tcp_read.c:713]: tcp_read_req: content-length= 0 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/msg_parser.c:622]: SIP Reply (status): May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/msg_parser.c:624]: version: <SIP/2.0> May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/msg_parser.c:626]: status: <302> May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/msg_parser.c:628]: reason: <Moved Temporarily> May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/parse_to.c:179]: DEBUG: add_param: tag=7a8e8e99f8 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/parse_to.c:808]: end of header reached, state=29 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/msg_parser.c:174]: DEBUG: get_hdr_field: <TO> [42]; uri=[sip:1989@10.98.6.5:5061] May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/msg_parser.c:176]: DEBUG: to body [sip:1989@10.98.6.5:5061] May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/msg_parser.c:154]: get_hdr_field: cseq <CSEQ>: <102> <INVITE> May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 232, <branch> = <z9hG4bK2fba.ab0b4cf4.0>; state=9 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/parse_via.c:2339]: parse_via: next_via May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 232, <branch> = <z9hG4bK214eb681>; state=6 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 235, <rport> = <5060>; state=16 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/parse_via.c:2296]: end of header reached, state=5 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/msg_parser.c:500]: parse_headers: Via found, flags=2 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [parser/msg_parser.c:502]: parse_headers: this is the first via May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [receive.c:137]: After parse_msg... May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: tm [t_lookup.c:1080]: DEBUG: t_check_msg: msg id=2 global id=1 T start=0xffffffffffffffff May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: tm [t_lookup.c:967]: DEBUG: t_reply_matching: hash 44018 label 1338290362 branch 0 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: tm [t_lookup.c:1018]: DEBUG: t_reply_matching: reply matched (T=0x7fe75afad0d8)! May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: tm [t_lookup.c:1149]: DEBUG: t_check_msg: msg id=2 global id=2 T end=0x7fe75afad0d8 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: tm [t_reply.c:1915]: DEBUG: reply_received: org. status uas=100, uac[0]=100 local=0 is_invite=1) May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [tcp_main.c:2017]: tcp_send: send from reader (5422 (10)), reusing fd May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [tcp_main.c:2068]: tcp_send: sending... May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [tcp_main.c:2106]: tcp_send: after real write: c= 0x7fe75afafb48 n=303 fd=7 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [tcp_main.c:2107]: tcp_send: buf= ACK sip:1989@10.98.6.5:5061 SIP/2.0^M Via: SIP/2.0/TCP 10.98.6.5:5065;branch=z9hG4bK2fba.ab0b4cf4.0^M From: "1103" sip:1103@10.98.6.5;tag=as1444d940^M TO: sip:1989@10.98.6.5:5061;tag=7a8e8e99f8^M Call-ID: 20a58e6b33d1e1f416436cab0c067a5e@10.98.6.5^M CSeq: 102 ACK^M Max-Forwards: 69^M Content-Length: 0^M ^M May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: tm [t_reply.c:1059]: ->>>>>>>>> T_code=100, new_code=302 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: tm [t_reply.c:1549]: DEBUG: relay_reply: branch=0, save=0, relay=0 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [msg_translator.c:1876]: old size: 486, new size: 429 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [msg_translator.c:1894]: build_res_from_sip_res: copied size: orig:259, new: 202, rest: 227 msg= SIP/2.0 302 Moved Temporarily^M FROM: "1103"sip:1103@10.98.6.5;tag=as1444d940^M TO: sip:1989@10.98.6.5:5061;tag=7a8e8e99f8^M CSEQ: 102 INVITE^M CALL-ID: 20a58e6b33d1e1f416436cab0c067a5e@10.98.6.5^M VIA: SIP/2.0/UDP 10.98.6.5:5060;branch=z9hG4bK214eb681;rport=5060^M CONTACT: sip:1989@10.98.6.5:5065;transport=TCP^M CONTENT-LENGTH: 0^M SERVER: RTCC/3.0.0.0^M Diversion: sip:1102@10.98.6.5;reason=user-busy;screen=no;privacy=off^M ^M May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [parser/msg_parser.c:612]: SIP Request: May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [parser/msg_parser.c:614]: method: <ACK> May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [parser/msg_parser.c:616]: uri: sip:1989@10.98.6.5:5061 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [parser/msg_parser.c:618]: version: <SIP/2.0> May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 232, <branch> = <z9hG4bK214eb681>; state=6 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [parser/parse_via.c:1283]: Found param type 235, <rport> = <n/a>; state=17 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [parser/parse_via.c:2296]: end of header reached, state=5 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [parser/msg_parser.c:500]: parse_headers: Via found, flags=2 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [parser/msg_parser.c:502]: parse_headers: this is the first via May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [receive.c:137]: After parse_msg... May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [receive.c:177]: preparing to run routing scripts... May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: sl [sl_funcs.c:335]: to late to be a local ACK! May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [parser/parse_to.c:179]: DEBUG: add_param: tag=7a8e8e99f8 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [parser/parse_to.c:808]: end of header reached, state=29 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [parser/msg_parser.c:174]: DEBUG: get_hdr_field: <To> [42]; uri=[sip:1989@10.98.6.5:5061] May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [parser/msg_parser.c:176]: DEBUG: to body [sip:1989@10.98.6.5:5061] May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [parser/msg_parser.c:154]: get_hdr_field: cseq <CSeq>: <102> <ACK> May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: maxfwd [mf_funcs.c:85]: value = 70 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [parser/msg_parser.c:188]: DEBUG: get_hdr_body : content_length=0 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [parser/msg_parser.c:90]: found end of header May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: rr [loose.c:108]: No Route headers found May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: rr [loose.c:907]: There is no Route HF May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [socket_info.c:485]: grep_sock_info - checking if host==us: 9==9 && [10.98.6.5] == [10.98.6.5] May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [socket_info.c:488]: grep_sock_info - checking if port 5061 matches port 5061 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: tm [t_lookup.c:1387]: DEBUG: t_newtran: msg id=2 , global msg id=1 , T on entrance=0xffffffffffffffff May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: tm [t_lookup.c:528]: t_lookup_request: start searching: hash=44018, isACK=1 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: tm [t_lookup.c:470]: DEBUG: RFC3261 transaction matched, tid=214eb681 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: tm [t_lookup.c:728]: DEBUG: t_lookup_request: transaction found (T=0x7fe75afad0d8) May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: tm [t_reply.c:1397]: DEBUG: cleanup_uac_timers: RETR/FR timers reset May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [timer.c:593]: timer_add called on an active timer 0x7fe75afad158 (0x7fe75adf5e30, 0x7fe75adf5e30), flags 201 May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: tm [t_funcs.c:184]: tm: put_on_wait: transaction 0x7fe75afad0d8 already on wait May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) May 20 10:42:42 qa-qsuitePBX-01 last message repeated 5 times May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5416]: DEBUG: <core> [receive.c:280]: receive_msg: cleaning up May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: tm [t_reply.c:1397]: DEBUG: cleanup_uac_timers: RETR/FR timers reset May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [usr_avp.c:629]: DEBUG:destroy_avp_list: destroying list (nil) May 20 10:42:42 qa-qsuitePBX-01 last message repeated 5 times May 20 10:42:42 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [receive.c:280]: receive_msg: cleaning up May 20 10:42:48 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [io_wait.h:588]: DBG: io_watch_del (0x82ea20, 7, -1, 0x10) fd_no=2 called May 20 10:42:48 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [tcp_read.c:811]: releasing con 0x7fe75afafb48, state 0, fd=7, id=2 May 20 10:42:48 qa-qsuitePBX-01 /usr/sbin/kamailio[5422]: DEBUG: <core> [tcp_read.c:812]: extra_data (nil) May 20 10:42:48 qa-qsuitePBX-01 /usr/sbin/kamailio[5425]: DEBUG: <core> [tcp_main.c:2855]: handle_tcp_child: reader response= 7fe75afafb48, 0 from 1 May 20 10:42:48 qa-qsuitePBX-01 /usr/sbin/kamailio[5425]: DEBUG: <core> [io_wait.h:361]: DBG: io_watch_add(0x7ea7c0, 26, 2, 0x7fe75afafb48), fd_no=19 May 20 10:42:48 qa-qsuitePBX-01 /usr/sbin/kamailio[5425]: DEBUG: <core> [tcp_main.c:2959]: handle_tcp_child: CONN_RELEASE 0x7fe75afafb48 refcnt= 1 May 20 10:44:48 qa-qsuitePBX-01 /usr/sbin/kamailio[5425]: DEBUG: <core> [tcp_main.c:3729]: tcp_main: entering timer for 0x7fe75afafb48 (ticks=884010523, timeout=884010523 (0 s), wr_timeout=884008666 (268435339 s)), write queue: 0 bytes May 20 10:44:48 qa-qsuitePBX-01 /usr/sbin/kamailio[5425]: DEBUG: <core> [tcp_main.c:3773]: tcp_main: timeout for 0x7fe75afafb48 May 20 10:44:48 qa-qsuitePBX-01 /usr/sbin/kamailio[5425]: DEBUG: <core> [io_wait.h:588]: DBG: io_watch_del (0x7ea7c0, 26, -1, 0x10) fd_no=20 called
Nelson Pereira