[SR-Users] Kamailio 1.5.4 - Pike module ignoring remove_latancy parameter

Miguel Baptista miguel.baptista at uninett.no
Mon Sep 20 16:34:08 CEST 2010 

Hi Daniel,

Here goes the log with debug=4:

    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:sanity:sanity_check: all sanity checks passed
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:get_hdr_field: <To> [44]; uri=[sip:MyUser at test.com] 
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:maxfwd:is_maxfwd_present: value = 70 
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:get_hdr_field: to body ["MyUser Akademia"
    <sip:MyUser at test.com>^M ]
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:pike:mark_node: search on branch 158 (top=0xb59c6030)
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:get_hdr_field: cseq <CSeq>: <66> <REGISTER>
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:pike:mark_node: only first 4 were matched!
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_headers: flags=20
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:pike:pike_check_req: src IP [yyy.yyy.yyy.yyy],node=0xb59c6800;
    hits=[2,0],[7,11] node_flags=6 func_flags=0
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_headers: flags=20
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:pike:remove_from_timer: 0xb59c6810 from
    0xb59baa60(0xb59c6920,0xb59c6810)
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_headers: flags=2000
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:pike:append_to_timer: 0xb59c6810 in
    0xb59baa60(0xb59c6920,0xb59c6920)
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:get_hdr_field: content_length=0
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:siputils:has_totag: no totag
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_headers: flags=ffffffffffffffff
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:core:grep_sock_info: checking if host==us: 11==13 &&  [test.com]
    == [XXX.XXX.XXX.XXX]
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:get_hdr_field: found end of header
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:core:grep_sock_info: checking if port 5060 matches port 5060
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_headers: flags=8000
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:core:grep_sock_info: no match for: [test.com:5060]
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_headers: flags=40000
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:core:grep_aliases: comparing host [0:test.com:5060] with us
    [1:sip:5060]
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_headers: flags=ffffffffffffffff
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:core:grep_aliases: comparing host [0:test.com:5060] with us
    [1:sip.test.com:5060]
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:sanity:sanity_check: all sanity checks passed
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:core:grep_aliases: comparing host [0:test.com:5060] with us
    [1:test.com:5060]
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:maxfwd:is_maxfwd_present: value = 70 
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:core:grep_aliases: match found for: [0:test.com:5060]
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:pike:mark_node: search on branch 158 (top=0xb59c6030)
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:core:check_self: host == me
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:pike:mark_node: only first 4 were matched!
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:core:parse_headers: flags=78
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:pike:pike_check_req: src IP [yyy.yyy.yyy.yyy],node=0xb59c6800;
    hits=[2,0],[7,12] node_flags=14 func_flags=6
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:tm:t_lookup_request: start searching: hash=27431, isACK=0
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:pike:remove_from_timer: 0xb59c6810 from
    0xb59baa60(0xb59c6810,0xb59c6920)
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:tm:matching_3261: RFC3261 transaction matching failed
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:pike:append_to_timer: 0xb59c6810 in
    0xb59baa60(0xb59c6920,0xb59c6920)
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:tm:t_lookup_request: no transaction found
    *Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]: PIKE -
    BLOCKing ip yyy.yyy.yyy.yyy, node=0xb59c6800 *
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]: retcode of
    t_check_trans is -1 
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]: Warning:
    too many requests from yyy.yyy.yyy.yyy:5060\
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]: Entered the
    Register method 
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_headers: flags=ffffffffffffffff
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]: r[2] route #2
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:check_via_address: params yyy.yyy.yyy.yyy, yyy.yyy.yyy.yyy, 0
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]: r[2]
    REGISTER - src_ip=yyy.yyy.yyy.yyy from_uri=sip:MyUser at test.com
    to_uri=sip:test.com 
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:destroy_avp_list: destroying list (nil)
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:core:parse_headers: flags=ffffffffffffffff
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:receive_msg: cleaning up
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:core:check_via_address: params yyy.yyy.yyy.yyy, yyy.yyy.yyy.yyy, 0
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:core:parse_headers: flags=4000
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:auth:pre_auth: credentials with given realm not found
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    r[HANDLE_REGISTER] req. missing authentication nonce
    (yyy.yyy.yyy.yyy) REGISTER sip:MyUser at test.com
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:auth:reserve_nonce_index: second= 18, sec_monit= 4,  index= 21
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:auth:build_auth_hf: nonce index= 21
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:auth:build_auth_hf: 'WWW-Authenticate: Digest realm="test.com",
    nonce="4c976daa0000001585e4d53c23338f5a8a5961f42da924a6"^M '
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:sl:send_reply: reply in stateless mode (sl)
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:core:parse_headers: flags=ffffffffffffffff
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:core:check_via_address: params yyy.yyy.yyy.yyy, yyy.yyy.yyy.yyy, 0
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:core:destroy_avp_list: destroying list (nil)
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16384]:
    DBG:core:receive_msg: cleaning up
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_msg: SIP Request:
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_msg:  method:  <REGISTER>
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_msg:  uri:     <sip:test.com>
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_msg:  version: <SIP/2.0>
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_headers: flags=2
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_via_param: found param type 232, <branch> =
    <z9hG4bK-f2xowcc2pr58>; state=6
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_via_param: found param type 235, <rport> = <n/a>;
    state=17
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_via: end of header reached, state=5
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_headers: via found, flags=2
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_headers: this is the first via
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:receive_msg: After parse_msg...
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:receive_msg: preparing to run routing scripts...
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]: Start main
    route
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_headers: flags=10
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_to_param: tag=i07t4f83ih
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_to: end of header reached, state=29
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_to: display={"MyUser Akademia"},
    ruri={sip:MyUser at test.com}
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]: r[0]
    REGISTER - src_ip=yyy.yyy.yyy.yyy from_uri=sip:MyUser at test.com
    to_uri=sip:test.com
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_headers: flags=78
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_to: end of header reached, state=10
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_to: display={"MyUser Akademia"},
    ruri={sip:MyUser at test.com}
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:get_hdr_field: <To> [44]; uri=[sip:MyUser at test.com] 
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:get_hdr_field: to body ["MyUser Akademia"
    <sip:MyUser at test.com>^M ]
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:get_hdr_field: cseq <CSeq>: <66> <REGISTER>
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_headers: flags=20
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_headers: flags=20
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_headers: flags=2000
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:get_hdr_field: content_length=0
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_headers: flags=ffffffffffffffff
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:get_hdr_field: found end of header
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_headers: flags=8000
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_headers: flags=40000
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_headers: flags=ffffffffffffffff
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:sanity:sanity_check: all sanity checks passed
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:maxfwd:is_maxfwd_present: value = 70 
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:pike:mark_node: search on branch 158 (top=0xb59c6030)
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:pike:mark_node: only first 4 were matched!
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:pike:pike_check_req: src IP [yyy.yyy.yyy.yyy],node=0xb59c6800;
    hits=[2,0],[7,13] node_flags=14 func_flags=2
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:pike:remove_from_timer: 0xb59c6810 from
    0xb59baa60(0xb59c6810,0xb59c6920)
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:pike:append_to_timer: 0xb59c6810 in
    0xb59baa60(0xb59c6920,0xb59c6920)
    Sep 20 16:19:56 sip /home/kamailio/sbin/kamailio[16382]: Warning:
    too many requests from yyy.yyy.yyy.yyy:5060\
    Sep 20 16:19:57 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:parse_headers: flags=ffffffffffffffff
    Sep 20 16:19:57 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:check_via_address: params yyy.yyy.yyy.yyy, yyy.yyy.yyy.yyy, 0
    Sep 20 16:19:57 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:destroy_avp_list: destroying list (nil)
    Sep 20 16:19:57 sip /home/kamailio/sbin/kamailio[16382]:
    DBG:core:receive_msg: cleaning up
    *Sep 20 16:20:36 sip /home/kamailio/sbin/kamailio[16385]: PIKE -
    UNBLOCKing node 0xb59c6800 *

Any ideas?

Regards,

Miguel Baptista

On 16.09.2010 10:17, Daniel-Constantin Mierla wrote:
> Hello,
>
> can you get a verbose debug log (debug=4)?
>
> Thanks,
> Daniel
>
> On 9/10/10 1:58 PM, MyUser Baptista wrote:
>> Hi All,
>>
>> I'm running kamailio-1.5.4-tls and I want to enable pike module in it.
>> I did some test but it isn't working properly. I mean it isn't acting
>> according to the /remove_latancy/ parameter. When an IP address is
>> blocked (cause it triggered the pike module), it should be blocked
>> for the amount of time (seconds I presumed) defined on the
>> /remove_latancy /parameter, right? but it isn't
>>
>> Here is my pike module config (it's just a test config)
>>  
>> #  ---- Pike --- /* we are usign default values. We should tunning it
>> up */
>> modparam("pike", "sampling_time_unit", 30)    
>> modparam("pike", "reqs_density_per_unit", 10)
>> modparam("pike", "remove_latency", 3600)     
>> modparam("pike", "pike_log_level",-1)
>>
>>
>> and here is the output
>>
>> /Sep 10 *13:33:35* sip /home/kamailio/sbin/kamailio[21414]: PIKE -
>> BLOCKing ip XXX.XXX.XXX.XXX, node=0xb5a2eb58
>> Sep 10 13:33:35 sip /home/kamailio/sbin/kamailio[21414]: Warning: too
>> many requests from XXX.XXX.XXX.XXX:5060
>> Sep 10 *13:34:12* sip /home/kamailio/sbin/kamailio[21420]: PIKE -
>> UNBLOCKing node 0xb5a2eb58
>> ...
>>
>> Sep 10 *13:35:22* sip /home/kamailio/sbin/kamailio[21418]: PIKE -
>> BLOCKing ip XXX.XXX.XXX.XXX,, node=0xb5a2eb58
>> Sep 10 13:35:22 sip /home/kamailio/sbin/kamailio[21418]: Warning: too
>> many requests from XXX.XXX.XXX.XXX,:5060
>> Sep 10 *13:36:12* sip /home/kamailio/sbin/kamailio[21420]: PIKE -
>> UNBLOCKing node 0xb5a2eb58
>> /
>> Shouldn't it be blocked for 3600 seconds?
>>  
>> Then I changed the /remove_latancy/ parameter to /modparam("pike",
>> "remove_latency", 334500)    /
>> /
>> Sep 10 *13:37:09* sip /home/kamailio/sbin/kamailio[21462]: PIKE -
>> BLOCKing ip XXX.XXX.XXX.XXX,, node=0xb5986b90
>> Sep 10 13:37:09 sip /home/kamailio/sbin/kamailio[21462]: Warning: too
>> many requests from XXX.XXX.XXX.XXX,:5060
>> Sep 10 *13:37:52* sip /home/kamailio/sbin/kamailio[21466]: PIKE -
>> UNBLOCKing node 0xb5986b90
>> /
>> but the it didn't seem to have any real difference.
>>
>> Any ideas? /
>> /
>> Best Regards,
>>
>> MyUser Baptista
>>
>>
>> _______________________________________________
>> SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
>> sr-users at lists.sip-router.org
>> http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
>>     
>
> -- 
> Daniel-Constantin Mierla
> http://www.asipto.com

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20100920/14af0bc2/attachment-0001.htm>

More information about the sr-users mailing list