[OpenSIPS-Users] Permission function causing Termination

Nathaniel L Keeling III keeling at akan-tech.com
Sat Jan 19 05:24:04 CET 2013


Hello,

I am using the permission module to validate the IP:PORT of an incoming 
request. When executing the "check_address" function, I am not getting a 
return from the function call and after 4 tries opensips crashes. I am 
running version 1.8.2 on solaris sparc 64. I have included the code that 
is being executed and part of the output from the log file when trying 
to debug.

xlog("checking if the request is from a valid IP source 
..............................................................");

     if(check_address("1","$si","$sp","$proto")) {
         xlog("L_INFO", "INFO:callerid:$ci|log|call originated from 
external pstn gateway sources");
         setflag(26);

     } else {

xlog("checking if the request is from a valid internal IP source 
=========================================..........................");

         if (ds_is_in_list("$si", "$sp", "1", "1")) {
             xlog("L_INFO", "INFO:callerid:$ci|log|call originated from 
internal sources");
             setflag(27);
             setbflag(27);
         } else {
             xlog("L_WARN", "WARN:callerid:$ci|end|SIP messages is not 
from a valid IP address and port: $si:$sp");
             sl_send_reply("503", "Rawr!!");
             exit;
         }
     }

Thanks

Nathaniel
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.opensips.org/pipermail/users/attachments/20130118/d0d5678c/attachment-0001.htm>
-------------- next part --------------
Jan 18 21:55:27 -f opensips.log[6619]: [ID 292666 local1.debug] DBG:core:parse_msg: SIP Request:
Jan 18 21:55:27 -f opensips.log[6619]: [ID 776402 local1.debug] DBG:core:parse_msg:  method:  <INVITE>
Jan 18 21:55:27 -f opensips.log[6619]: [ID 700387 local1.debug] DBG:core:parse_msg:  uri:     <sip:18035568206 at kwesi-chicago-pstn1.akan.us.com:0>
Jan 18 21:55:27 -f opensips.log[6619]: [ID 641661 local1.debug] DBG:core:parse_msg:  version: <SIP/2.0>
Jan 18 21:55:27 -f opensips.log[6619]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=2
Jan 18 21:55:27 -f opensips.log[6619]: [ID 202288 local1.debug] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK8877.cf25.0>; state=16
Jan 18 21:55:27 -f opensips.log[6619]: [ID 218084 local1.debug] DBG:core:parse_via: end of header reached, state=5
Jan 18 21:55:27 -f opensips.log[6619]: [ID 636936 local1.debug] DBG:core:parse_headers: via found, flags=2
Jan 18 21:55:27 -f opensips.log[6619]: [ID 481110 local1.debug] DBG:core:parse_headers: this is the first via
Jan 18 21:55:27 -f opensips.log[6619]: [ID 911547 local1.debug] DBG:core:receive_msg: After parse_msg...
Jan 18 21:55:27 -f opensips.log[6619]: [ID 451678 local1.debug] DBG:core:receive_msg: preparing to run routing scripts...
Jan 18 21:55:27 -f opensips.log[6619]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=8
Jan 18 21:55:27 -f opensips.log[6619]: [ID 202288 local1.debug] DBG:core:parse_via_param: found param type 234, <received> = <208.54.44.182>; state=6
Jan 18 21:55:27 -f opensips.log[6619]: [ID 202288 local1.debug] DBG:core:parse_via_param: found param type 235, <rport> = <27909>; state=6
Jan 18 21:55:27 -f opensips.log[6619]: [ID 202288 local1.debug] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKPjZWlg6sNodl2bMahPlKLIjUnv3EFzLA5Y>; state=16
Jan 18 21:55:27 -f opensips.log[6619]: [ID 218084 local1.debug] DBG:core:parse_via: end of header reached, state=5
Jan 18 21:55:27 -f opensips.log[6619]: [ID 636936 local1.debug] DBG:core:parse_headers: via found, flags=8
Jan 18 21:55:27 -f opensips.log[6619]: [ID 903840 local1.debug] DBG:core:parse_headers: parse_headers: this is the second via
Jan 18 21:55:27 -f opensips.log[6619]: [ID 218084 local1.debug] DBG:core:parse_to: end of header reached, state=10
Jan 18 21:55:27 -f opensips.log[6619]: [ID 841317 local1.debug] DBG:core:parse_to: display={}, ruri={sip:18035568206 at kwesi-chicago-sip1.akan.us.com}
Jan 18 21:55:27 -f opensips.log[6619]: [ID 993225 local1.debug] DBG:core:get_hdr_field: <To> [50]; uri=[sip:18035568206 at kwesi-chicago-sip1.akan.us.com] 
Jan 18 21:55:27 -f opensips.log[6619]: [ID 159376 local1.debug] DBG:core:get_hdr_field: to body [<sip:18035568206 at kwesi-chicago-sip1.akan.us.com>^M
Jan 18 21:55:27 -f ]
Jan 18 21:55:27 -f opensips.log[6619]: [ID 221271 local1.debug] DBG:core:buf_init: initializing...
Jan 18 21:55:27 -f opensips.log[6619]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=40
Jan 18 21:55:27 -f opensips.log[6619]: [ID 197553 local1.info] INFO:callerid:pRZXZ-m52nqqRCPmFwAeYZTEvwNURv.x|start|recieved udp request INVITE sip:18035568206 at kwesi-chicago-pstn1.akan.us.com:0
Jan 18 21:55:27 -f opensips.log[6619]: [ID 197553 local1.info] INFO:callerid:pRZXZ-m52nqqRCPmFwAeYZTEvwNURv.x|log|source 209.252.110.38:5060
Jan 18 21:55:27 -f opensips.log[6619]: [ID 858957 local1.debug] DBG:core:parse_to_param: tag=WoaIpBzrSr0MN9wcIgqaYhauQvui-4s2
Jan 18 21:55:27 -f opensips.log[6619]: [ID 218084 local1.debug] DBG:core:parse_to: end of header reached, state=29
Jan 18 21:55:27 -f opensips.log[6619]: [ID 841317 local1.debug] DBG:core:parse_to: display={"Nathaniel  Keeling III"}, ruri={sip:nkeeling3 at akanvoice.com}
Jan 18 21:55:27 -f opensips.log[6619]: [ID 197553 local1.info] INFO:callerid:pRZXZ-m52nqqRCPmFwAeYZTEvwNURv.x|log|from sip:nkeeling3 at akanvoice.com
Jan 18 21:55:27 -f opensips.log[6619]: [ID 197553 local1.info] INFO:callerid:pRZXZ-m52nqqRCPmFwAeYZTEvwNURv.x|log|to sip:18035568206 at kwesi-chicago-sip1.akan.us.com
Jan 18 21:55:27 -f opensips.log[6619]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=ffffffffffffffff
Jan 18 21:55:27 -f opensips.log[6619]: [ID 601073 local1.debug] DBG:core:get_hdr_field: cseq <CSeq>: <8090> <INVITE>
Jan 18 21:55:27 -f opensips.log[6619]: [ID 457772 local1.debug] DBG:core:get_hdr_field: content_length=374
Jan 18 21:55:27 -f opensips.log[6619]: [ID 183338 local1.debug] DBG:core:get_hdr_field: found end of header
Jan 18 21:55:27 -f opensips.log[6619]: [ID 663030 local1.debug] DBG:core:decode_mime_type: Decoding MIME type for:[application/sdp]
Jan 18 21:55:27 -f opensips.log[6619]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=ffffffffffffffff
Jan 18 21:55:27 -f last message repeated 1 time
Jan 18 21:55:27 -f opensips.log[6619]: [ID 804473 local1.debug] DBG:core:parse_methods: methods 0x1F6F
Jan 18 21:55:27 -f opensips.log[6619]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=ffffffffffffffff
Jan 18 21:55:27 -f opensips.log[6619]: [ID 307322 local1.debug] DBG:core:parse_supported: parsing [Supported: replaces, 100rel, timer, norefersub^M
Jan 18 21:55:27 -f ] 10038a310
Jan 18 21:55:27 -f opensips.log[6619]: [ID 129309 local1.debug] DBG:maxfwd:w_process_maxfwd_header: value 67 decreased to 30
Jan 18 21:55:27 -f opensips.log[6619]: [ID 197553 local1.error] checking if the request is from a valid IP source  ..............................................................
Jan 18 21:55:27 -f opensips.log[6620]: [ID 292666 local1.debug] DBG:core:parse_msg: SIP Request:
Jan 18 21:55:27 -f opensips.log[6620]: [ID 776402 local1.debug] DBG:core:parse_msg:  method:  <INVITE>
Jan 18 21:55:27 -f opensips.log[6620]: [ID 700387 local1.debug] DBG:core:parse_msg:  uri:     <sip:18035568206 at kwesi-chicago-pstn1.akan.us.com:0>
Jan 18 21:55:27 -f opensips.log[6620]: [ID 641661 local1.debug] DBG:core:parse_msg:  version: <SIP/2.0>
Jan 18 21:55:27 -f opensips.log[6620]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=2
Jan 18 21:55:27 -f opensips.log[6620]: [ID 202288 local1.debug] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK8877.cf25.0>; state=16
Jan 18 21:55:27 -f opensips.log[6620]: [ID 218084 local1.debug] DBG:core:parse_via: end of header reached, state=5
Jan 18 21:55:27 -f opensips.log[6620]: [ID 636936 local1.debug] DBG:core:parse_headers: via found, flags=2
Jan 18 21:55:27 -f opensips.log[6620]: [ID 481110 local1.debug] DBG:core:parse_headers: this is the first via
Jan 18 21:55:27 -f opensips.log[6620]: [ID 911547 local1.debug] DBG:core:receive_msg: After parse_msg...
Jan 18 21:55:27 -f opensips.log[6620]: [ID 451678 local1.debug] DBG:core:receive_msg: preparing to run routing scripts...
Jan 18 21:55:27 -f opensips.log[6620]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=8
Jan 18 21:55:27 -f opensips.log[6620]: [ID 202288 local1.debug] DBG:core:parse_via_param: found param type 234, <received> = <208.54.44.182>; state=6
Jan 18 21:55:27 -f opensips.log[6620]: [ID 202288 local1.debug] DBG:core:parse_via_param: found param type 235, <rport> = <27909>; state=6
Jan 18 21:55:27 -f opensips.log[6620]: [ID 202288 local1.debug] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKPjZWlg6sNodl2bMahPlKLIjUnv3EFzLA5Y>; state=16
Jan 18 21:55:27 -f opensips.log[6620]: [ID 218084 local1.debug] DBG:core:parse_via: end of header reached, state=5
Jan 18 21:55:27 -f opensips.log[6620]: [ID 636936 local1.debug] DBG:core:parse_headers: via found, flags=8
Jan 18 21:55:27 -f opensips.log[6620]: [ID 903840 local1.debug] DBG:core:parse_headers: parse_headers: this is the second via
Jan 18 21:55:27 -f opensips.log[6620]: [ID 218084 local1.debug] DBG:core:parse_to: end of header reached, state=10
Jan 18 21:55:27 -f opensips.log[6620]: [ID 841317 local1.debug] DBG:core:parse_to: display={}, ruri={sip:18035568206 at kwesi-chicago-sip1.akan.us.com}
Jan 18 21:55:27 -f opensips.log[6620]: [ID 993225 local1.debug] DBG:core:get_hdr_field: <To> [50]; uri=[sip:18035568206 at kwesi-chicago-sip1.akan.us.com] 
Jan 18 21:55:27 -f opensips.log[6620]: [ID 159376 local1.debug] DBG:core:get_hdr_field: to body [<sip:18035568206 at kwesi-chicago-sip1.akan.us.com>^M
Jan 18 21:55:27 -f ]
Jan 18 21:55:27 -f opensips.log[6620]: [ID 221271 local1.debug] DBG:core:buf_init: initializing...
Jan 18 21:55:27 -f opensips.log[6620]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=40
Jan 18 21:55:27 -f opensips.log[6620]: [ID 197553 local1.info] INFO:callerid:pRZXZ-m52nqqRCPmFwAeYZTEvwNURv.x|start|recieved udp request INVITE sip:18035568206 at kwesi-chicago-pstn1.akan.us.com:0
Jan 18 21:55:27 -f opensips.log[6620]: [ID 197553 local1.info] INFO:callerid:pRZXZ-m52nqqRCPmFwAeYZTEvwNURv.x|log|source 209.252.110.38:5060
Jan 18 21:55:27 -f opensips.log[6620]: [ID 858957 local1.debug] DBG:core:parse_to_param: tag=WoaIpBzrSr0MN9wcIgqaYhauQvui-4s2
Jan 18 21:55:27 -f opensips.log[6620]: [ID 218084 local1.debug] DBG:core:parse_to: end of header reached, state=29
Jan 18 21:55:27 -f opensips.log[6620]: [ID 841317 local1.debug] DBG:core:parse_to: display={"Nathaniel  Keeling III"}, ruri={sip:nkeeling3 at akanvoice.com}
Jan 18 21:55:27 -f opensips.log[6620]: [ID 197553 local1.info] INFO:callerid:pRZXZ-m52nqqRCPmFwAeYZTEvwNURv.x|log|from sip:nkeeling3 at akanvoice.com
Jan 18 21:55:27 -f opensips.log[6620]: [ID 197553 local1.info] INFO:callerid:pRZXZ-m52nqqRCPmFwAeYZTEvwNURv.x|log|to sip:18035568206 at kwesi-chicago-sip1.akan.us.com
Jan 18 21:55:27 -f opensips.log[6620]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=ffffffffffffffff
Jan 18 21:55:27 -f opensips.log[6620]: [ID 601073 local1.debug] DBG:core:get_hdr_field: cseq <CSeq>: <8090> <INVITE>
Jan 18 21:55:27 -f opensips.log[6620]: [ID 457772 local1.debug] DBG:core:get_hdr_field: content_length=374
Jan 18 21:55:27 -f opensips.log[6620]: [ID 183338 local1.debug] DBG:core:get_hdr_field: found end of header
Jan 18 21:55:27 -f opensips.log[6620]: [ID 663030 local1.debug] DBG:core:decode_mime_type: Decoding MIME type for:[application/sdp]
Jan 18 21:55:27 -f opensips.log[6620]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=ffffffffffffffff
Jan 18 21:55:27 -f last message repeated 1 time
Jan 18 21:55:27 -f opensips.log[6620]: [ID 804473 local1.debug] DBG:core:parse_methods: methods 0x1F6F
Jan 18 21:55:27 -f opensips.log[6620]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=ffffffffffffffff
Jan 18 21:55:27 -f opensips.log[6620]: [ID 307322 local1.debug] DBG:core:parse_supported: parsing [Supported: replaces, 100rel, timer, norefersub^M
Jan 18 21:55:27 -f ] 10038a310
Jan 18 21:55:27 -f opensips.log[6620]: [ID 129309 local1.debug] DBG:maxfwd:w_process_maxfwd_header: value 67 decreased to 30
Jan 18 21:55:27 -f opensips.log[6620]: [ID 197553 local1.error] checking if the request is from a valid IP source  ..............................................................
Jan 18 21:55:28 -f opensips.log[6622]: [ID 292666 local1.debug] DBG:core:parse_msg: SIP Request:
Jan 18 21:55:28 -f opensips.log[6622]: [ID 776402 local1.debug] DBG:core:parse_msg:  method:  <INVITE>
Jan 18 21:55:28 -f opensips.log[6622]: [ID 700387 local1.debug] DBG:core:parse_msg:  uri:     <sip:18035568206 at kwesi-chicago-pstn1.akan.us.com:0>
Jan 18 21:55:28 -f opensips.log[6622]: [ID 641661 local1.debug] DBG:core:parse_msg:  version: <SIP/2.0>
Jan 18 21:55:28 -f opensips.log[6622]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=2
Jan 18 21:55:28 -f opensips.log[6622]: [ID 202288 local1.debug] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK8877.cf25.0>; state=16
Jan 18 21:55:28 -f opensips.log[6622]: [ID 218084 local1.debug] DBG:core:parse_via: end of header reached, state=5
Jan 18 21:55:28 -f opensips.log[6622]: [ID 636936 local1.debug] DBG:core:parse_headers: via found, flags=2
Jan 18 21:55:28 -f opensips.log[6622]: [ID 481110 local1.debug] DBG:core:parse_headers: this is the first via
Jan 18 21:55:28 -f opensips.log[6622]: [ID 911547 local1.debug] DBG:core:receive_msg: After parse_msg...
Jan 18 21:55:28 -f opensips.log[6622]: [ID 451678 local1.debug] DBG:core:receive_msg: preparing to run routing scripts...
Jan 18 21:55:28 -f opensips.log[6622]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=8
Jan 18 21:55:28 -f opensips.log[6622]: [ID 202288 local1.debug] DBG:core:parse_via_param: found param type 234, <received> = <208.54.44.182>; state=6
Jan 18 21:55:28 -f opensips.log[6622]: [ID 202288 local1.debug] DBG:core:parse_via_param: found param type 235, <rport> = <27909>; state=6
Jan 18 21:55:28 -f opensips.log[6622]: [ID 202288 local1.debug] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKPjZWlg6sNodl2bMahPlKLIjUnv3EFzLA5Y>; state=16
Jan 18 21:55:28 -f opensips.log[6622]: [ID 218084 local1.debug] DBG:core:parse_via: end of header reached, state=5
Jan 18 21:55:28 -f opensips.log[6622]: [ID 636936 local1.debug] DBG:core:parse_headers: via found, flags=8
Jan 18 21:55:28 -f opensips.log[6622]: [ID 903840 local1.debug] DBG:core:parse_headers: parse_headers: this is the second via
Jan 18 21:55:28 -f opensips.log[6622]: [ID 218084 local1.debug] DBG:core:parse_to: end of header reached, state=10
Jan 18 21:55:28 -f opensips.log[6622]: [ID 841317 local1.debug] DBG:core:parse_to: display={}, ruri={sip:18035568206 at kwesi-chicago-sip1.akan.us.com}
Jan 18 21:55:28 -f opensips.log[6622]: [ID 993225 local1.debug] DBG:core:get_hdr_field: <To> [50]; uri=[sip:18035568206 at kwesi-chicago-sip1.akan.us.com] 
Jan 18 21:55:28 -f opensips.log[6622]: [ID 159376 local1.debug] DBG:core:get_hdr_field: to body [<sip:18035568206 at kwesi-chicago-sip1.akan.us.com>^M
Jan 18 21:55:28 -f ]
Jan 18 21:55:28 -f opensips.log[6622]: [ID 221271 local1.debug] DBG:core:buf_init: initializing...
Jan 18 21:55:28 -f opensips.log[6622]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=40
Jan 18 21:55:28 -f opensips.log[6622]: [ID 197553 local1.info] INFO:callerid:pRZXZ-m52nqqRCPmFwAeYZTEvwNURv.x|start|recieved udp request INVITE sip:18035568206 at kwesi-chicago-pstn1.akan.us.com:0
Jan 18 21:55:28 -f opensips.log[6622]: [ID 197553 local1.info] INFO:callerid:pRZXZ-m52nqqRCPmFwAeYZTEvwNURv.x|log|source 209.252.110.38:5060
Jan 18 21:55:28 -f opensips.log[6622]: [ID 858957 local1.debug] DBG:core:parse_to_param: tag=WoaIpBzrSr0MN9wcIgqaYhauQvui-4s2
Jan 18 21:55:28 -f opensips.log[6622]: [ID 218084 local1.debug] DBG:core:parse_to: end of header reached, state=29
Jan 18 21:55:28 -f opensips.log[6622]: [ID 841317 local1.debug] DBG:core:parse_to: display={"Nathaniel  Keeling III"}, ruri={sip:nkeeling3 at akanvoice.com}
Jan 18 21:55:28 -f opensips.log[6622]: [ID 197553 local1.info] INFO:callerid:pRZXZ-m52nqqRCPmFwAeYZTEvwNURv.x|log|from sip:nkeeling3 at akanvoice.com
Jan 18 21:55:28 -f opensips.log[6622]: [ID 197553 local1.info] INFO:callerid:pRZXZ-m52nqqRCPmFwAeYZTEvwNURv.x|log|to sip:18035568206 at kwesi-chicago-sip1.akan.us.com
Jan 18 21:55:28 -f opensips.log[6622]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=ffffffffffffffff
Jan 18 21:55:28 -f opensips.log[6622]: [ID 601073 local1.debug] DBG:core:get_hdr_field: cseq <CSeq>: <8090> <INVITE>
Jan 18 21:55:28 -f opensips.log[6622]: [ID 457772 local1.debug] DBG:core:get_hdr_field: content_length=374
Jan 18 21:55:28 -f opensips.log[6622]: [ID 183338 local1.debug] DBG:core:get_hdr_field: found end of header
Jan 18 21:55:28 -f opensips.log[6622]: [ID 663030 local1.debug] DBG:core:decode_mime_type: Decoding MIME type for:[application/sdp]
Jan 18 21:55:28 -f opensips.log[6622]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=ffffffffffffffff
Jan 18 21:55:28 -f last message repeated 1 time
Jan 18 21:55:28 -f opensips.log[6622]: [ID 804473 local1.debug] DBG:core:parse_methods: methods 0x1F6F
Jan 18 21:55:28 -f opensips.log[6622]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=ffffffffffffffff
Jan 18 21:55:28 -f opensips.log[6622]: [ID 307322 local1.debug] DBG:core:parse_supported: parsing [Supported: replaces, 100rel, timer, norefersub^M
Jan 18 21:55:28 -f ] 10038a310
Jan 18 21:55:28 -f opensips.log[6622]: [ID 129309 local1.debug] DBG:maxfwd:w_process_maxfwd_header: value 67 decreased to 30
Jan 18 21:55:28 -f opensips.log[6622]: [ID 197553 local1.error] checking if the request is from a valid IP source  ..............................................................
Jan 18 21:55:31 -f opensips.log[6626]: [ID 292666 local1.debug] DBG:core:parse_msg: SIP Request:
Jan 18 21:55:32 -f opensips.log[6626]: [ID 776402 local1.debug] DBG:core:parse_msg:  method:  <INVITE>
Jan 18 21:55:32 -f opensips.log[6626]: [ID 700387 local1.debug] DBG:core:parse_msg:  uri:     <sip:18035568206 at kwesi-chicago-pstn1.akan.us.com:0>
Jan 18 21:55:32 -f opensips.log[6626]: [ID 641661 local1.debug] DBG:core:parse_msg:  version: <SIP/2.0>
Jan 18 21:55:32 -f opensips.log[6626]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=2
Jan 18 21:55:32 -f opensips.log[6626]: [ID 202288 local1.debug] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK8877.cf25.0>; state=16
Jan 18 21:55:32 -f opensips.log[6626]: [ID 218084 local1.debug] DBG:core:parse_via: end of header reached, state=5
Jan 18 21:55:32 -f opensips.log[6626]: [ID 636936 local1.debug] DBG:core:parse_headers: via found, flags=2
Jan 18 21:55:32 -f opensips.log[6626]: [ID 481110 local1.debug] DBG:core:parse_headers: this is the first via
Jan 18 21:55:32 -f opensips.log[6626]: [ID 911547 local1.debug] DBG:core:receive_msg: After parse_msg...
Jan 18 21:55:32 -f opensips.log[6626]: [ID 451678 local1.debug] DBG:core:receive_msg: preparing to run routing scripts...
Jan 18 21:55:32 -f opensips.log[6626]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=8
Jan 18 21:55:32 -f opensips.log[6626]: [ID 202288 local1.debug] DBG:core:parse_via_param: found param type 234, <received> = <208.54.44.182>; state=6
Jan 18 21:55:32 -f opensips.log[6626]: [ID 202288 local1.debug] DBG:core:parse_via_param: found param type 235, <rport> = <27909>; state=6
Jan 18 21:55:32 -f opensips.log[6626]: [ID 202288 local1.debug] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKPjZWlg6sNodl2bMahPlKLIjUnv3EFzLA5Y>; state=16
Jan 18 21:55:32 -f opensips.log[6626]: [ID 218084 local1.debug] DBG:core:parse_via: end of header reached, state=5
Jan 18 21:55:32 -f opensips.log[6626]: [ID 636936 local1.debug] DBG:core:parse_headers: via found, flags=8
Jan 18 21:55:32 -f opensips.log[6626]: [ID 903840 local1.debug] DBG:core:parse_headers: parse_headers: this is the second via
Jan 18 21:55:32 -f opensips.log[6626]: [ID 218084 local1.debug] DBG:core:parse_to: end of header reached, state=10
Jan 18 21:55:32 -f opensips.log[6626]: [ID 841317 local1.debug] DBG:core:parse_to: display={}, ruri={sip:18035568206 at kwesi-chicago-sip1.akan.us.com}
Jan 18 21:55:32 -f opensips.log[6626]: [ID 993225 local1.debug] DBG:core:get_hdr_field: <To> [50]; uri=[sip:18035568206 at kwesi-chicago-sip1.akan.us.com] 
Jan 18 21:55:32 -f opensips.log[6626]: [ID 159376 local1.debug] DBG:core:get_hdr_field: to body [<sip:18035568206 at kwesi-chicago-sip1.akan.us.com>^M
Jan 18 21:55:32 -f ]
Jan 18 21:55:32 -f opensips.log[6626]: [ID 221271 local1.debug] DBG:core:buf_init: initializing...
Jan 18 21:55:32 -f opensips.log[6626]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=40
Jan 18 21:55:32 -f opensips.log[6626]: [ID 197553 local1.info] INFO:callerid:pRZXZ-m52nqqRCPmFwAeYZTEvwNURv.x|start|recieved udp request INVITE sip:18035568206 at kwesi-chicago-pstn1.akan.us.com:0
Jan 18 21:55:32 -f opensips.log[6626]: [ID 197553 local1.info] INFO:callerid:pRZXZ-m52nqqRCPmFwAeYZTEvwNURv.x|log|source 209.252.110.38:5060
Jan 18 21:55:32 -f opensips.log[6626]: [ID 858957 local1.debug] DBG:core:parse_to_param: tag=WoaIpBzrSr0MN9wcIgqaYhauQvui-4s2
Jan 18 21:55:32 -f opensips.log[6626]: [ID 218084 local1.debug] DBG:core:parse_to: end of header reached, state=29
Jan 18 21:55:32 -f opensips.log[6626]: [ID 841317 local1.debug] DBG:core:parse_to: display={"Nathaniel  Keeling III"}, ruri={sip:nkeeling3 at akanvoice.com}
Jan 18 21:55:32 -f opensips.log[6626]: [ID 197553 local1.info] INFO:callerid:pRZXZ-m52nqqRCPmFwAeYZTEvwNURv.x|log|from sip:nkeeling3 at akanvoice.com
Jan 18 21:55:32 -f opensips.log[6626]: [ID 197553 local1.info] INFO:callerid:pRZXZ-m52nqqRCPmFwAeYZTEvwNURv.x|log|to sip:18035568206 at kwesi-chicago-sip1.akan.us.com
Jan 18 21:55:32 -f opensips.log[6626]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=ffffffffffffffff
Jan 18 21:55:32 -f opensips.log[6626]: [ID 601073 local1.debug] DBG:core:get_hdr_field: cseq <CSeq>: <8090> <INVITE>
Jan 18 21:55:32 -f opensips.log[6626]: [ID 457772 local1.debug] DBG:core:get_hdr_field: content_length=374
Jan 18 21:55:32 -f opensips.log[6626]: [ID 183338 local1.debug] DBG:core:get_hdr_field: found end of header
Jan 18 21:55:32 -f opensips.log[6626]: [ID 663030 local1.debug] DBG:core:decode_mime_type: Decoding MIME type for:[application/sdp]
Jan 18 21:55:32 -f opensips.log[6626]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=ffffffffffffffff
Jan 18 21:55:32 -f last message repeated 1 time
Jan 18 21:55:32 -f opensips.log[6626]: [ID 804473 local1.debug] DBG:core:parse_methods: methods 0x1F6F
Jan 18 21:55:32 -f opensips.log[6626]: [ID 497291 local1.debug] DBG:core:parse_headers: flags=ffffffffffffffff
Jan 18 21:55:32 -f opensips.log[6626]: [ID 307322 local1.debug] DBG:core:parse_supported: parsing [Supported: replaces, 100rel, timer, norefersub^M
Jan 18 21:55:32 -f ] 10038a310
Jan 18 21:55:32 -f opensips.log[6626]: [ID 129309 local1.debug] DBG:maxfwd:w_process_maxfwd_header: value 67 decreased to 30
Jan 18 21:55:32 -f opensips.log[6626]: [ID 197553 local1.error] checking if the request is from a valid IP source  ..............................................................
Jan 18 21:56:10 -f opensips.log[6646]: [ID 569889 local1.crit] CRITICAL:core:receive_fd: EOF on 15
Jan 18 21:56:10 -f opensips.log[6646]: [ID 424375 local1.debug] DBG:core:handle_ser_child: dead child 3, pid 6620 (shutting down?)
Jan 18 21:56:10 -f opensips.log[6646]: [ID 730621 local1.debug] DBG:core:io_watch_del: io_watch_del (10031b770, 15, 0, 0x0) fd_no=38 called
Jan 18 21:56:11 -f opensips.log[6646]: [ID 569889 local1.crit] CRITICAL:core:receive_fd: EOF on 14
Jan 18 21:56:11 -f opensips.log[6646]: [ID 424375 local1.debug] DBG:core:handle_ser_child: dead child 2, pid 6619 (shutting down?)
Jan 18 21:56:11 -f opensips.log[6646]: [ID 730621 local1.debug] DBG:core:io_watch_del: io_watch_del (10031b770, 14, 0, 0x0) fd_no=37 called
Jan 18 21:56:11 -f opensips.log[6646]: [ID 569889 local1.crit] CRITICAL:core:receive_fd: EOF on 17
Jan 18 21:56:11 -f opensips.log[6646]: [ID 424375 local1.debug] DBG:core:handle_ser_child: dead child 5, pid 6622 (shutting down?)
Jan 18 21:56:11 -f opensips.log[6646]: [ID 730621 local1.debug] DBG:core:io_watch_del: io_watch_del (10031b770, 17, 1, 0x0) fd_no=36 called
Jan 18 21:56:11 -f opensips.log[6617]: [ID 603640 local1.debug] DBG:core:handle_sigs: status = 139
Jan 18 21:56:11 -f opensips.log[6617]: [ID 825934 local1.info] INFO:core:handle_sigs: child process 6622 exited by a signal 11
Jan 18 21:56:11 -f opensips.log[6617]: [ID 644926 local1.info] INFO:core:handle_sigs: core was generated
Jan 18 21:56:11 -f opensips.log[6617]: [ID 603640 local1.debug] DBG:core:handle_sigs: status = 139
Jan 18 21:56:11 -f opensips.log[6617]: [ID 825934 local1.info] INFO:core:handle_sigs: child process 6619 exited by a signal 11
Jan 18 21:56:11 -f opensips.log[6617]: [ID 644926 local1.info] INFO:core:handle_sigs: core was generated
Jan 18 21:56:11 -f opensips.log[6617]: [ID 603640 local1.debug] DBG:core:handle_sigs: status = 139
Jan 18 21:56:11 -f opensips.log[6617]: [ID 825934 local1.info] INFO:core:handle_sigs: child process 6620 exited by a signal 11
Jan 18 21:56:11 -f opensips.log[6617]: [ID 644926 local1.info] INFO:core:handle_sigs: core was not generated
Jan 18 21:56:11 -f opensips.log[6617]: [ID 196586 local1.info] INFO:core:handle_sigs: terminating due to SIGCHLD
Jan 18 21:56:11 -f opensips.log[6618]: [ID 167723 local1.info] INFO:core:sig_usr: signal 15 received
Jan 18 21:56:11 -f opensips.log[6618]: [ID 243188 local1.notice] Memory status (pkg):
Jan 18 21:56:11 -f opensips.log[6618]: [ID 706386 local1.notice] fm_status (100360b70):
Jan 18 21:56:11 -f opensips.log[6618]: [ID 934816 local1.notice]  heap size= 4194304
Jan 18 21:56:11 -f opensips.log[6618]: [ID 708471 local1.notice]  used= 116584, used+overhead=170608, free=4077720
Jan 18 21:56:11 -f opensips.log[6618]: [ID 333860 local1.notice]  max used (+overhead)= 170608
Jan 18 21:56:11 -f opensips.log[6618]: [ID 603380 local1.notice] dumping free list:
Jan 18 21:56:11 -f opensips.log[6618]: [ID 167177 local1.notice] hash =   1 fragments no.:     4, unused:     0
Jan 18 21:56:11 -f               bucket size:         8 -         8 (first         8)
Jan 18 21:56:11 -f opensips.log[6618]: [ID 167177 local1.notice] hash = 2056 fragments no.:     1, unused:     0
Jan 18 21:56:11 -f               bucket size:   2097152 -   4194304 (first   4023016)
Jan 18 21:56:11 -f opensips.log[6618]: [ID 547356 local1.notice] TOTAL:      5 free fragments = 4023048 free bytes
Jan 18 21:56:11 -f opensips.log[6618]: [ID 834414 local1.notice] TOTAL: 4023016 large bytes
Jan 18 21:56:11 -f opensips.log[6618]: [ID 657264 local1.notice] TOTAL: 24 overhead
Jan 18 21:56:11 -f opensips.log[6618]: [ID 635845 local1.notice] -----------------------------
Jan 18 21:56:11 -f opensips.log[6621]: [ID 167723 local1.info] INFO:core:sig_usr: signal 15 received
Jan 18 21:56:11 -f opensips.log[6621]: [ID 243188 local1.notice] Memory status (pkg):
Jan 18 21:56:11 -f opensips.log[6621]: [ID 706386 local1.notice] fm_status (100360b70):
Jan 18 21:56:11 -f opensips.log[6621]: [ID 934816 local1.notice]  heap size= 4194304
Jan 18 21:56:11 -f opensips.log[6621]: [ID 708471 local1.notice]  used= 106504, used+overhead=159952, free=4087800
Jan 18 21:56:11 -f opensips.log[6621]: [ID 333860 local1.notice]  max used (+overhead)= 159952
Jan 18 21:56:11 -f opensips.log[6621]: [ID 603380 local1.notice] dumping free list:
Jan 18 21:56:11 -f opensips.log[6621]: [ID 167177 local1.notice] hash =   1 fragments no.:     4, unused:     0
Jan 18 21:56:11 -f               bucket size:         8 -         8 (first         8)
Jan 18 21:56:11 -f opensips.log[6621]: [ID 167177 local1.notice] hash = 2056 fragments no.:     1, unused:     0
Jan 18 21:56:11 -f               bucket size:   2097152 -   4194304 (first   4033672)
Jan 18 21:56:11 -f opensips.log[6621]: [ID 547356 local1.notice] TOTAL:      5 free fragments = 4033704 free bytes
Jan 18 21:56:11 -f opensips.log[6621]: [ID 834414 local1.notice] TOTAL: 4033672 large bytes
Jan 18 21:56:11 -f opensips.log[6621]: [ID 657264 local1.notice] TOTAL: 24 overhead
Jan 18 21:56:11 -f opensips.log[6621]: [ID 635845 local1.notice] -----------------------------
Jan 18 21:56:12 -f opensips.log[6623]: [ID 167723 local1.info] INFO:core:sig_usr: signal 15 received
Jan 18 21:56:12 -f opensips.log[6623]: [ID 243188 local1.notice] Memory status (pkg):
Jan 18 21:56:12 -f opensips.log[6623]: [ID 706386 local1.notice] fm_status (100360b70):
Jan 18 21:56:12 -f opensips.log[6623]: [ID 934816 local1.notice]  heap size= 4194304
Jan 18 21:56:12 -f opensips.log[6623]: [ID 708471 local1.notice]  used= 106504, used+overhead=159952, free=4087800
Jan 18 21:56:12 -f opensips.log[6623]: [ID 333860 local1.notice]  max used (+overhead)= 159952
Jan 18 21:56:12 -f opensips.log[6623]: [ID 603380 local1.notice] dumping free list:
Jan 18 21:56:12 -f opensips.log[6623]: [ID 167177 local1.notice] hash =   1 fragments no.:     4, unused:     0
Jan 18 21:56:12 -f               bucket size:         8 -         8 (first         8)



More information about the Users mailing list