[SR-Users] Need help in routing configuration

Nelson Pereira npereira at protus.com
Thu May 20 16:47:56 CEST 2010


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 at 10.98.6.5:5065;transport=TCP>

Here is the debug from Asterisk:

    -- Executing [1102 at 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 at default:2] SIPAddHeader("SIP/1103-0000002d", "Diversion: <sip:1102 at 10.98.6.5>;reason=user-busy;screen=no;privacy=off") in new stack
    -- Executing [1102 at default:3] Dial("SIP/1103-0000002d", "SIP/1989 at EX-UM") in new stack
    -- Called 1989 at EX-UM
    -- Got SIP response 302 "Moved Temporarily" back from 10.98.6.5
    -- Now forwarding SIP/1103-0000002d to 'Local/1989 at default' (thanks to SIP/EX-UM-0000002f)
    -- Executing [1989 at default:1] Dial("Local/1989 at default-a77b,2", "SIP/1989 at EX-UM") in new stack
[May 20 10:42:42] WARNING[5440]: app_dial.c:1263 dial_exec_full: Skipping dialing interface 'SIP/1989 at EX-UM' again since it has already been dialed
  == Spawn extension (default, 1989, 1) exited non-zero on 'Local/1989 at default-a77b,2'
  == Everyone is busy/congested at this time (1:0/0/1)
    -- Executing [1102 at default:4] Dial("SIP/1103-0000002d", "SIP/1989 at openser5065") in new stack
    -- Called 1989 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 10.98.6.5>;tag=as1444d940^M TO: <sip:1989 at 10.98.6.5:5061>;tag=7a8e8e99f8^M Call-ID: 20a58e6b33d1e1f416436cab0c067a5e at 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 at 10.98.6.5>;tag=as1444d940^M TO: <sip:1989 at 10.98.6.5:5061>;tag=7a8e8e99f8^M CSEQ: 102 INVITE^M CALL-ID: 20a58e6b33d1e1f416436cab0c067a5e at 10.98.6.5^M VIA: SIP/2.0/UDP 10.98.6.5:5060;branch=z9hG4bK214eb681;rport=5060^M CONTACT: <sip:1989 at 10.98.6.5:5065;transport=TCP>^M CONTENT-LENGTH: 0^M SERVER: RTCC/3.0.0.0^M Diversion: <sip:1102 at 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 at 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 at 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 at 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



More information about the sr-users mailing list