Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_msg: SIP Request: 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_msg:  method:  <INVITE> 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_msg:  uri:     <sip:1001@vmopensips1.skycomuk.com:5060> 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_msg:  version: <SIP/2.0> 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: flags=2 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1f688db07e3542d3a>; state=16 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_via: end of header reached, state=5 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: via found, flags=2 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: this is the first via 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:receive_msg: After parse_msg... 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:receive_msg: preparing to run routing scripts... 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: flags=100 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:maxfwd:is_maxfwd_present: value = 70  
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: flags=8 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_to: end of header reached, state=10 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_to: display={"1001"}, ruri={sip:1001@vmopensips1.skycomuk.com:5060} 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:get_hdr_field: <To> [49]; uri=[sip:1001@vmopensips1.skycomuk.com:5060]  
 ]   7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:get_hdr_field: to body ["1001" <sip:1001@vmopensips1.skycomuk.com:5060>
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:uri:has_totag: no totag 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: flags=78 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:get_hdr_field: cseq <CSeq>: <6436> <INVITE> 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:tm:t_lookup_request: start searching: hash=16284, isACK=0 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:tm:matching_3261: RFC3261 transaction matching failed 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_msg: SIP Request: 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:tm:t_lookup_request: no transaction found 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_msg:  method:  <INVITE> 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_to_param: tag=6392ae5f12 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_msg:  uri:     <sip:1001@vmopensips1.skycomuk.com:5060> 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_to: end of header reached, state=29 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_msg:  version: <SIP/2.0> 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_to: display={"1000"}, ruri={sip:1000@vmopensips1.skycomuk.com:5060} 
Jan  7 09:22:09 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_headers: flags=2 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: checking if host==us: 24==9 &&  [vmopensips1.skycomuk.com] == [127.0.0.1] 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1f688db07e3542d3a>; state=16 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_via: end of header reached, state=5 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: checking if host==us: 24==11 &&  [vmopensips1.skycomuk.com] == [10.150.0.33] 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_headers: via found, flags=2 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_headers: this is the first via 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: checking if host==us: 24==13 &&  [vmopensips1.skycomuk.com] == [212.84.166.33] 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20836]: DBG:core:receive_msg: After parse_msg... 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20836]: DBG:core:receive_msg: preparing to run routing scripts... 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: checking if host==us: 24==9 &&  [vmopensips1.skycomuk.com] == [127.0.0.1] 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_msg: SIP Request: 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_headers: flags=100 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_msg:  method:  <INVITE> 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20836]: DBG:maxfwd:is_maxfwd_present: value = 70  
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: checking if host==us: 24==11 &&  [vmopensips1.skycomuk.com] == [10.150.0.33] 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_msg:  uri:     <sip:1001@vmopensips1.skycomuk.com:5060> 
Jan  7 09:22:10 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_headers: flags=8 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_msg:  version: <SIP/2.0> 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_to: end of header reached, state=10 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: checking if host==us: 24==13 &&  [vmopensips1.skycomuk.com] == [212.84.166.33] 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_headers: flags=2 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_to: display={"1001"}, ruri={sip:1001@vmopensips1.skycomuk.com:5060} 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20835]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1f688db07e3542d3a>; state=16 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20836]: DBG:core:get_hdr_field: <To> [49]; uri=[sip:1001@vmopensips1.skycomuk.com:5060]  
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: flags=10000 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_via: end of header reached, state=5 
 ]   7 09:22:11 vmopensips1 /sbin/opensips[20836]: DBG:core:get_hdr_field: to body ["1001" <sip:1001@vmopensips1.skycomuk.com:5060>
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20835]: DBG:core:get_hdr_field: content_length=595 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_headers: via found, flags=2 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20836]: DBG:uri:has_totag: no totag 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20835]: DBG:core:get_hdr_field: found end of header 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_headers: this is the first via 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_headers: flags=78 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20835]: DBG:auth:pre_auth: credentials with given realm not found 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20837]: DBG:core:receive_msg: After parse_msg... 
Jan  7 09:22:11 vmopensips1 /sbin/opensips[20836]: DBG:core:get_hdr_field: cseq <CSeq>: <6436> <INVITE> 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20835]: DBG:auth:reserve_nonce_index: second= 1, sec_monit= -1,  index= 0 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20837]: DBG:core:receive_msg: preparing to run routing scripts... 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20836]: DBG:tm:t_lookup_request: start searching: hash=16284, isACK=0 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20835]: DBG:auth:build_auth_hf: nonce index= 0 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_headers: flags=100 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20836]: DBG:tm:matching_3261: RFC3261 transaction matching failed 
 '   7 09:22:12 vmopensips1 /sbin/opensips[20835]: DBG:auth:build_auth_hf: 'Proxy-Authenticate: Digest realm="vmopensips1.skycomuk.com", nonce="4d26db62000000005a481811987f903105543127c6b1e8ff"
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20837]: DBG:maxfwd:is_maxfwd_present: value = 70  
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20836]: DBG:tm:t_lookup_request: no transaction found 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: flags=ffffffffffffffff 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_headers: flags=8 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_to_param: tag=6392ae5f12 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20835]: DBG:core:check_ip_address: params 212.84.170.85, 212.84.170.85, 0 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_msg: SIP Request: 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_to: end of header reached, state=10 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_to: end of header reached, state=29 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20835]: DBG:core:destroy_avp_list: destroying list (nil) 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_msg:  method:  <INVITE> 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_to: display={"1001"}, ruri={sip:1001@vmopensips1.skycomuk.com:5060} 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_to: display={"1000"}, ruri={sip:1000@vmopensips1.skycomuk.com:5060} 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20835]: DBG:core:receive_msg: cleaning up 
Jan  7 09:22:12 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_msg:  uri:     <sip:1001@vmopensips1.skycomuk.com:5060> 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20837]: DBG:core:get_hdr_field: <To> [49]; uri=[sip:1001@vmopensips1.skycomuk.com:5060]  
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: checking if host==us: 24==9 &&  [vmopensips1.skycomuk.com] == [127.0.0.1] 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_msg: SIP Request: 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_msg:  version: <SIP/2.0> 
 ]   7 09:22:13 vmopensips1 /sbin/opensips[20837]: DBG:core:get_hdr_field: to body ["1001" <sip:1001@vmopensips1.skycomuk.com:5060>
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_msg:  method:  <ACK> 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_headers: flags=2 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20837]: DBG:uri:has_totag: no totag 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: checking if host==us: 24==11 &&  [vmopensips1.skycomuk.com] == [10.150.0.33] 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_msg:  uri:     <sip:1001@vmopensips1.skycomuk.com:5060> 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1f688db07e3542d3a>; state=16 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_headers: flags=78 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_msg:  version: <SIP/2.0> 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_via: end of header reached, state=5 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20837]: DBG:core:get_hdr_field: cseq <CSeq>: <6436> <INVITE> 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: checking if host==us: 24==13 &&  [vmopensips1.skycomuk.com] == [212.84.166.33] 
Jan  7 09:22:13 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: flags=2 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_headers: via found, flags=2 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20837]: DBG:tm:t_lookup_request: start searching: hash=16284, isACK=0 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1f688db07e3542d3a>; state=16 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_headers: this is the first via 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20837]: DBG:tm:matching_3261: RFC3261 transaction matching failed 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: checking if host==us: 24==9 &&  [vmopensips1.skycomuk.com] == [127.0.0.1] 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_via: end of header reached, state=5 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20838]: DBG:core:receive_msg: After parse_msg... 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20837]: DBG:tm:t_lookup_request: no transaction found 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: via found, flags=2 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20838]: DBG:core:receive_msg: preparing to run routing scripts... 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_to_param: tag=6392ae5f12 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: checking if host==us: 24==11 &&  [vmopensips1.skycomuk.com] == [10.150.0.33] 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: this is the first via 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_headers: flags=100 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_to: end of header reached, state=29 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20835]: DBG:core:receive_msg: After parse_msg... 
Jan  7 09:22:14 vmopensips1 /sbin/opensips[20838]: DBG:maxfwd:is_maxfwd_present: value = 70  
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_to: display={"1000"}, ruri={sip:1000@vmopensips1.skycomuk.com:5060} 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: checking if host==us: 24==13 &&  [vmopensips1.skycomuk.com] == [212.84.166.33] 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20835]: DBG:core:receive_msg: preparing to run routing scripts... 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_headers: flags=8 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: checking if host==us: 24==9 &&  [vmopensips1.skycomuk.com] == [127.0.0.1] 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20836]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20835]: DBG:sl:sl_filter_ACK: to late to be a local ACK! 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_to: end of header reached, state=10 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_headers: flags=10000 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: flags=100 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_to: display={"1001"}, ruri={sip:1001@vmopensips1.skycomuk.com:5060} 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: checking if host==us: 24==11 &&  [vmopensips1.skycomuk.com] == [10.150.0.33] 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20836]: DBG:core:get_hdr_field: content_length=595 
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20835]: DBG:maxfwd:is_maxfwd_present: value = 70  
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20838]: DBG:core:get_hdr_field: <To> [49]; uri=[sip:1001@vmopensips1.skycomuk.com:5060]  
Jan  7 09:22:15 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20836]: DBG:core:get_hdr_field: found end of header 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: flags=8 
 ]   7 09:22:16 vmopensips1 /sbin/opensips[20838]: DBG:core:get_hdr_field: to body ["1001" <sip:1001@vmopensips1.skycomuk.com:5060>
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: checking if host==us: 24==13 &&  [vmopensips1.skycomuk.com] == [212.84.166.33] 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20836]: DBG:auth:pre_auth: credentials with given realm not found 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_to_param: tag=c97b4d1cb1f3d0da549e06a8d482ef63.5f56 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20838]: DBG:uri:has_totag: no totag 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20836]: DBG:auth:reserve_nonce_index: second= 6, sec_monit= -1,  index= 1 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_to: end of header reached, state=29 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_headers: flags=78 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: checking if host==us: 24==9 &&  [vmopensips1.skycomuk.com] == [127.0.0.1] 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20836]: DBG:auth:build_auth_hf: nonce index= 1 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_to: display={"1001"}, ruri={sip:1001@vmopensips1.skycomuk.com:5060} 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20838]: DBG:core:get_hdr_field: cseq <CSeq>: <6436> <INVITE> 
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
 '   7 09:22:16 vmopensips1 /sbin/opensips[20836]: DBG:auth:build_auth_hf: 'Proxy-Authenticate: Digest realm="vmopensips1.skycomuk.com", nonce="4d26db6600000001d69ce33126031746bdf4735e3f0f922d"
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20835]: DBG:core:get_hdr_field: <To> [91]; uri=[sip:1001@vmopensips1.skycomuk.com:5060]  
Jan  7 09:22:16 vmopensips1 /sbin/opensips[20838]: DBG:tm:t_lookup_request: start searching: hash=16284, isACK=0 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: checking if host==us: 24==11 &&  [vmopensips1.skycomuk.com] == [10.150.0.33] 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20836]: DBG:core:parse_headers: flags=ffffffffffffffff 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20835]: DBG:core:get_hdr_field: to body ["1001" <sip:1001@vmopensips1.skycomuk.com:5060>] 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20838]: DBG:tm:matching_3261: RFC3261 transaction matching failed 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20836]: DBG:core:check_ip_address: params 212.84.170.85, 212.84.170.85, 0 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20835]: DBG:uri:has_totag: totag found 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20838]: DBG:tm:t_lookup_request: no transaction found 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: checking if host==us: 24==13 &&  [vmopensips1.skycomuk.com] == [212.84.166.33] 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20836]: DBG:core:destroy_avp_list: destroying list (nil) 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: flags=200 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_to_param: tag=6392ae5f12 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20837]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20836]: DBG:core:receive_msg: cleaning up 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20835]: DBG:core:get_hdr_field: cseq <CSeq>: <6436> <ACK> 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_to: end of header reached, state=29 
Jan  7 09:22:17 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_headers: flags=10000 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20835]: DBG:core:get_hdr_field: content_length=0 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_to: display={"1000"}, ruri={sip:1000@vmopensips1.skycomuk.com:5060} 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20837]: DBG:core:get_hdr_field: content_length=595 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20835]: DBG:core:get_hdr_field: found end of header 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: checking if host==us: 24==9 &&  [vmopensips1.skycomuk.com] == [127.0.0.1] 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20837]: DBG:core:get_hdr_field: found end of header 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20835]: DBG:rr:find_first_route: No Route headers found 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20837]: DBG:auth:pre_auth: credentials with given realm not found 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20835]: DBG:rr:loose_route: There is no Route HF 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: checking if host==us: 24==11 &&  [vmopensips1.skycomuk.com] == [10.150.0.33] 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20837]: DBG:auth:reserve_nonce_index: second= 8, sec_monit= -1,  index= 2 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20835]: DBG:core:parse_headers: flags=78 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20837]: DBG:auth:build_auth_hf: nonce index= 2 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20835]: DBG:tm:t_lookup_request: start searching: hash=16284, isACK=1 
Jan  7 09:22:18 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: checking if host==us: 24==13 &&  [vmopensips1.skycomuk.com] == [212.84.166.33] 
 '   7 09:22:19 vmopensips1 /sbin/opensips[20837]: DBG:auth:build_auth_hf: 'Proxy-Authenticate: Digest realm="vmopensips1.skycomuk.com", nonce="4d26db6900000002df907eceab9018f0d8b6f41664c24279"
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20835]: DBG:tm:matching_3261: RFC3261 transaction matching failed 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20837]: DBG:core:parse_headers: flags=ffffffffffffffff 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20835]: DBG:tm:t_lookup_request: no transaction found 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: checking if host==us: 24==9 &&  [vmopensips1.skycomuk.com] == [127.0.0.1] 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20837]: DBG:core:check_ip_address: params 212.84.170.85, 212.84.170.85, 0 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20835]: DBG:core:destroy_avp_list: destroying list (nil) 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20837]: DBG:core:destroy_avp_list: destroying list (nil) 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20835]: DBG:core:receive_msg: cleaning up 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: checking if host==us: 24==11 &&  [vmopensips1.skycomuk.com] == [10.150.0.33] 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20837]: DBG:core:receive_msg: cleaning up 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: checking if host==us: 24==13 &&  [vmopensips1.skycomuk.com] == [212.84.166.33] 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20838]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060 
Jan  7 09:22:19 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_headers: flags=10000 
Jan  7 09:22:20 vmopensips1 /sbin/opensips[20838]: DBG:core:get_hdr_field: content_length=595 
Jan  7 09:22:20 vmopensips1 /sbin/opensips[20838]: DBG:core:get_hdr_field: found end of header 
Jan  7 09:22:20 vmopensips1 /sbin/opensips[20838]: DBG:auth:pre_auth: credentials with given realm not found 
Jan  7 09:22:20 vmopensips1 /sbin/opensips[20838]: DBG:auth:reserve_nonce_index: second= 10, sec_monit= -1,  index= 3 
Jan  7 09:22:20 vmopensips1 /sbin/opensips[20838]: DBG:auth:build_auth_hf: nonce index= 3 
 '   7 09:22:20 vmopensips1 /sbin/opensips[20838]: DBG:auth:build_auth_hf: 'Proxy-Authenticate: Digest realm="vmopensips1.skycomuk.com", nonce="4d26db6a0000000330a51f25bde49628253cc14e3458c505"
Jan  7 09:22:20 vmopensips1 /sbin/opensips[20838]: DBG:core:parse_headers: flags=ffffffffffffffff 
Jan  7 09:22:20 vmopensips1 /sbin/opensips[20838]: DBG:core:check_ip_address: params 212.84.170.85, 212.84.170.85, 0 
Jan  7 09:22:20 vmopensips1 /sbin/opensips[20838]: DBG:core:destroy_avp_list: destroying list (nil) 
Jan  7 09:22:20 vmopensips1 /sbin/opensips[20838]: DBG:core:receive_msg: cleaning up