# # Copyright (c) 2001-2015 NetApp, Inc., All Rights Reserved # Any use, modification, or distribution is prohibited # without prior written consent from NetApp, Inc. # # ## @summary EventLogDetector Task Module ## @author dl-nacl-dev@netapp.com ## @status shared ## @pod here =head1 NAME NACL::MTask::EventLogDetector =head1 DESCRIPTION This task is to be used for validating the ems logs for presence or absence of given message/regex. Many testcases require verification that certain event log messages have or have not been triggered. This package provides methods for selecting the time ranges between which the event log messages will be verified (for presence/absence) of the given ems message or regex. # Example : test which calls check() by default when $detector->stop() is called. use NACL::MTask::EventLogDetector; ... my $detector = NACL::MTask::EventLogDetector->new( command_interface => $Node, check_for_all_presence => [ 'message.must.occur' ], check_for_absence => [ 'should.not.occur' ], ); $detector->start(); ... # Perform any operation here ... $detector->stop(); # will call check by default # End test # Example : test which explicitly calls check(). use NACL::MTask::EventLogDetector; ... my $detector = NACL::MTask::EventLogDetector->new( command_interface => $Node, check_for_all_presence => [ 'message.must.occur' ], check_for_absence => [ 'should.not.occur' ], ); $detector->start(); ... # Perform any operation here ... $detector->stop('check' => 0); # Do wait/or some other operations $detector->check(); # End test =cut package NACL::MTask::EventLogDetector; use strict; use warnings; use base qw(NACL::MTask::MTask); use NATE::Log qw(log_global); my $Log = log_global(); my $may_enter = $Log->may_enter(); my $may_exit = $Log->may_exit(); use Params::Validate qw(validate validate_with BOOLEAN HASHREF OBJECT ARRAYREF SCALAR UNDEF); use NATE::Exceptions::Argument qw(:try); use NACL::C::Exceptions::TimeNotSynchronised qw(:try); use NACL::Exceptions::EventCheckFailure qw(:try); use NACL::CS::ClusterDate; use Time::Local; use NACL::C::Component; #use NACL::CS::EventLog; use NACL::CS::EventLog; use NACL::C::EventConfig; use Data::Dumper; use DateTime; use NATE::BaseException qw(:try); my $Infinity = 9**9**9; my $DATE_RE_WO_BE = qr/\"?\d{1,2}\/\d{1,2}\/\d{4}\s\d{1,2}:\d{1,2}:\d{1,2}(\s[\-\+]\d{1,2}:\d{1,2})?\"?/; my $DATE_RE = qr/^$DATE_RE_WO_BE$/; use NATE::ParamSet qw(param_global); my $OP_RE = qr/^[>=<]{1,2}$/; =head1 METHODS =head2 new my $detector = Task::EventLogDetector->new( command_interface => $Node, ); Create a EventLogDetector object that can be used to check for the presence or absence of events during a time range. =over =item Options =over =item C<< check_for_all_presence => $array_ref >> ( Optional, defaults to reference to an empty array ) Reference to a list of events names to check. If any of the given event names are not found, throws a NACL::Exceptions::EventCheckFailure exception with appropriate error message. =item C<< check_for_absence => $array_ref >> ( Optional, defaults to reference to an empty array ) Reference to a list of events names to check. If any of the given event names are found, throws a NACL::Exceptions::EventCheckFailure exception with appropriate error message. =item C<< check_for_any_presence => $array_ref >> ( Optional, defaults to reference to an empty array ) Reference to a list of events names to check. If none of the given event names are found, throws a NACL::Exceptions::EventCheckFailure exception with appropriate error message. =item C<< command_interface => $ci >> (Required, isa NACL::C::Node or NACL::STask::Node ) The command interface on which to read and verify the event logs. =back =back =cut use Class::MethodMaker [ new => [ '-hash', '-init', 'new' ], scalar => 'node', scalar => 'events', scalar => [ { -read_cb => sub { my ($self, $curr_val) = @_; my $new_val = $self->_event_time_read_cb(val => $curr_val, field => 'event_begin_time'); return $new_val; } }, 'event_begin_time', ], scalar => [ { -read_cb => sub { my ($self, $curr_val) = @_; my $new_val = $self->_event_time_read_cb(val => $curr_val, field => 'event_end_time'); return $new_val; } }, 'event_end_time', ], scalar => 'check_for_all_presence', scalar => 'check_for_absence', scalar => 'check_for_any_presence', scalar => 'operation', scalar => 'count', scalar => [ { -type => 'NACL::C::CommandInterface::ONTAP' }, 'command_interface' ], scalar => 'nacltask_field', # Private. scalar => '_timezone', scalar => '_event_begin_time_utc', scalar => '_event_end_time_utc', ]; # Validate the parameters sub init { $Log->enter() if $may_enter; my $self = shift; my %opts = validate_with( params => \@_, spec => { command_interface => { type => OBJECT }, events => { type => ARRAYREF, optional => 1 }, check_for_all_presence => { type => ARRAYREF, optional => 1 }, check_for_absence => { type => ARRAYREF, optional => 1 }, check_for_any_presence => { type => ARRAYREF, optional => 1 }, node => { type => SCALAR, optional => 1 }, event_begin_time => { type => SCALAR, optional => 1 }, event_end_time => { type => SCALAR, optional => 1 }, 'count' => { type => SCALAR, optional => 1 }, 'nacltask_field' => { type => SCALAR, optional => 1 }, 'operation' => { type => SCALAR, optional => 1, regex => $OP_RE }, %{ NACL::C::Component->_common_validate_spec_without_ci() } }, ); $Log->exit() if $may_exit; } =head2 start $detector->start(); (Instance method) Marks the time stamp which will be used as the start point for events to be validated. This does not have any return value. Instead, it updates the time stamp on the instance with the key "event_begin_time". After the "start" method is called, the user can access the event begin time through the object like, my $event_start_time = $detector->event_begin_time(); =cut sub start { $Log->enter() if $may_enter; my $self = shift; my %opts = validate_with( params => \@_, spec => NACL::C::Component->_common_validate_spec_without_ci() ); my $ci = $self->command_interface(); my $date_object = $self->_get_cluster_date( 'command_interface' => $ci, %opts ); $self->_event_begin_time_utc($date_object->utc_date()); $Log->exit() if $may_exit; } =head2 stop $detector->stop(); (Instance method) Marks the time stamp which will be used as the start point for events to be validated. By default, this method internally calls check() to validate the logs unless the param 'check' is passed with value 0. Any point after the "stop" method is called, the user can access the event end time through the object as, my $event_end_time = $detector->event_end_time(); =over =item Options =over =item C<< check_for_all_presence => $array_ref >> ( Optional, defaults to reference to an empty array ) Reference to a list of events names to check. If any of the given event names are not found, throws a NACL::Exceptions::EventCheckFailure exception with appropriate error message. When this option is used, 'stop' method has following exit behavior. If exception is not thrown it returns list of matched L objects in list context. Or returns first element of list in scalar context. If exception is thrown, the exception object provides two supporting methods. matched_events - list of L objects that matched from check_for_all_presence list unmatched_events - list of strings/regEx in check_for_all_presence that did not match. =item C<< check_for_absence => $array_ref >> ( Optional, defaults to reference to an empty array ) Reference to a list of events names to check. If any of the given event names are found, throws a NACL::Exceptions::EventCheckFailure exception with appropriate error message. =item C<< check_for_any_presence => $array_ref >> ( Optional, defaults to reference to an empty array ) Reference to a list of events names to check. If none of the given event names are found, throws a NACL::Exceptions::EventCheckFailure exception with appropriate error message. =item C<< check => 0|1 >> ( Optional, defaults to 1 if not provided ) This param is checked to see if the log verification has to be triggered when stop() is called. Unless it is 'check' => 0, this method calls check(). =item C<< ignore_if_unsynchronized => $boolean >> ( Optional, defaults to "0" ) Boolean parameter if set to "1", will ignore the "Error: The time does not appear to be synchronised across this cluster" error. =back =back =cut sub stop { $Log->enter() if $may_enter; my $self = shift; my %opts = validate_with( params => \@_, spec => { check => { type => SCALAR, default => 1 }, %{ NACL::C::Component->_common_validate_spec_without_ci() }, ignore_if_unsynchronized => { type => BOOLEAN, default => 0 }, }, allow_extra => 1 ); my $ci = $self->command_interface(); my $date_object = $self->_get_cluster_date( 'command_interface' => $ci, %opts ); my $utc_date = $date_object->utc_date(); $self->_event_end_time_utc($utc_date); if ($opts{check}) { delete $opts{check}; $opts{timezone} = $date_object->timezone(); my @return_obj; #Pass NACL_RETRY_INTERVAL as multiple of 5 my $retry_time = param_global->get('NACL_RETRY_INTERVAL') || 0; try { @return_obj = $self->check(%opts); } catch NACL::Exceptions::EventCheckFailure with { my $ex = shift; $Log->comment("Failed with: ". $ex->text()); if(!$retry_time) { $Log->comment("As wait interval is 0, dont wait and throw caught exception"); $ex->throw(); } else{ LABEL: { try{ $Log->comment("\nRetrying it once again with sleep of 5 sec "); sleep(5); $retry_time -=5; my $end_time = $self->_get_cluster_date( 'command_interface' => $ci, %opts )->utc_date(); $self->_event_end_time_utc($end_time); @return_obj = $self->check(%opts); } catch NACL::Exceptions::EventCheckFailure with { $ex->throw() if($retry_time <= 0); goto LABEL; }; } } }; $Log->exit() if $may_exit; return wantarray ? @return_obj : $return_obj[0] } $Log->exit() if $may_exit; } =head2 check $detector->check(); or $detector->check(check_for_all_presence=>['wafl.iron.mount.times'], count=> 1, operation => '>='); (Instance method) NACL::MTask::EventLogDetector->check( 'command_interface' => $ci, 'node' => $node, 'check_for_all_presence' => ['message.must.occur'], 'event_begin_time' => $begin_time, 'event_end_time ' => $end_time ); (Class method) Verifies the events occurred during the time frame between start() and stop() methods been called based on the options provided. NACL::Exceptions::EventCheckFailure with the appropriate message will be thrown if the verification fails. =over =item Options =over =item C<< event_begin_time => $begin_time >> (mandatory for class method call) Begin time to check for event logs. Date should be either the in the format "MM/DD/YYYY HH:MM:SS" =item C<< event_end_time => $end_time >> (mandatory for class method call) Begin time to check for event logs. Date should be either the in the format "MM/DD/YYYY HH:MM:SS" =item C<< check_for_all_presence => $array_ref >> ( Optional, defaults to reference to an empty array ) Reference to a list of events names/Regexp to check. If any of the given event names are not found, throws a NACL::Exceptions::EventCheckFailure exception with appropriate error message. When this option is used, 'check' method has following exit behavior. If exception is not thrown it returns list of matched L objects in list context. Or returns first element of list in scalar context. If exception is thrown, the exception object provides two supporting methods. matched_events - list of L objects that matched from check_for_all_presence list unmatched_events - list of strings/regEx in check_for_all_presence that did not match. =item C<< events => $array_ref >> ( Mandatory for class method, Not Applicable for instance method ) Reference to a list of NACL::CS::EventLog objects from which the events will be validated. =item C<< check_for_absence => $array_ref >> ( Optional, defaults to reference to an empty array ) Reference to a list of events names/Regexp to check. If any of the given event names are found, throws a NACL::Exceptions::EventCheckFailure exception with appropriate error message. =item C<< check_for_any_presence => $array_ref >> ( Optional, defaults to reference to an empty array ) Reference to a list of events names/Regexp to check. If none of the given event names are found, throws a NACL::Exceptions::EventCheckFailure exception with appropriate error message. =item C<< ignore_if_unsynchronized => $boolean >> ( Optional, defaults to "0" ) Boolean parameter if set to "1", will ignore the "Error: The time does not appear to be synchronised across this cluster" error. =item C<< count => $no_of_logs >> ( Optional ) Count is the number to be validated using the operation explained below with the number of times a given message/event has appeared in the given time limit. This count is applicable for single logs and check_for_all_presence. =item C<< operation => $scalar >> ( Optional ) Possible option: >=, ==, <=, >, < This is the operation used to validate the given "count" with the number of times the given event/message has appeared in the the given time frame.Validates the number of logs(count) against this operation. =item C<< nacltask_field => $scalar >> ( Optional, Defaults to 'messagename' ) Possible option: messagename,event nacltask_field can be used by the user to specify the field against which the pattern/regexp passed to 'check_for_absence' or 'check_for_all_presence' or 'check_for_any_presence' will be checked. =item C<< nacltask_filter => $hash_ref >> ( mandatory ) Reference to a hash of event criterias. =back =back =cut sub check { $Log->enter() if $may_enter; my $self = shift; my %opts = validate_with( params => \@_, spec => { %{ $self->_check_validate_spec() }, %{ NACL::C::Component->_common_validate_spec_without_ci() }, timezone => { type => SCALAR, optional => 1 }, nacltask_field => { type => SCALAR, callbacks => { "Value of 'nacltask_field' should be 'messagename' or 'event'" => sub { $_[0] =~ /^(messagename|event)$/ }, }, optional => 1, }, nacltask_filter => { type => HASHREF, default => {} }, }, allow_extra => 1 ); my $filter = delete $opts{nacltask_filter}; my $fields = delete $opts{nacltask_field} || $self->nacltask_field() || 'messagename' ; if (ref $self) { my $timezone = delete $opts{timezone} || $self->command_interface()->get_timezone(); $self->_timezone($timezone) } my $begin_time = $opts{'event_begin_time'} || $self->event_begin_time(); my $end_time = $opts{'event_end_time'} || $self->event_end_time(); #Reset the timezone $self->_timezone_reset(); my $ci = $opts{'command_interface'} || $self->command_interface(); my $count = $opts{'count'} || $self->count(); my $operation = $opts{'operation'} || $self->operation(); my ( $validate_timestamp, $begin_localtime, $end_localtime ); my $ignore_if_unsynchronized = delete $opts{'ignore_if_unsynchronized'}; # Validating the begin and end time stamps in case of instance method call # for class method call, it would be validated in validate_with(..). if ( !( $begin_time && $end_time ) ) { $Log->exit() if $may_exit; NATE::Exceptions::Argument->throw( "It is mandatory to call start() and stop() before calling check()" ); } # ensure atleast one of the check criteria is provided as param my $check_for_absence = $opts{'check_for_absence'} || $self->check_for_absence(); my $check_for_any_presence = $opts{'check_for_any_presence'} || $self->check_for_any_presence(); my $check_for_all_presence = $opts{'check_for_all_presence'} || $self->check_for_all_presence(); if ( defined($count) && defined($operation) && $#$check_for_all_presence > 0 ) { $Log->exit() if $may_exit; NATE::Exceptions::Argument->throw( "count and operation are applicaple only for single logs under check_for_all_presence" ); } if (!( $check_for_absence || $check_for_any_presence || $check_for_all_presence ) ) { $Log->exit() if $may_exit; NATE::Exceptions::Argument->throw( "It is mandatory to specify atleast one of these parameters \(check_for_absence, check_for_any_presence, check_for_all_presence\)" ); } if (ref($self)) { my %filter_opts = %{$filter}; if ($ci->is_cmode()) { my $date_range = $begin_time . '..' . $end_time; $filter_opts{'time'} = $date_range; } else { # Calculate the time period between event start and begin time my $time_interval = $self->_calculate_time_diff( time_1 => $end_time, time_2 => $begin_time ); $filter_opts{'time-interval'} = $time_interval; } my $node = $opts{'node'} || $self->node(); $filter_opts{'node'} = $node if defined $node; my @check_any_presence_array = (); if( defined ($check_for_any_presence)){ @check_any_presence_array = @{$check_for_any_presence}; } my @check_all_presence_array = (); if( defined ($check_for_all_presence)){ @check_all_presence_array = @{$check_for_all_presence}; } my @check_presence = (@check_all_presence_array, @check_any_presence_array); my $has_regex; for my $val (@check_presence){ if(ref $val eq 'Regexp'){ $has_regex = 1; last; } } my $fields; if((!$has_regex) && (! defined ($check_for_absence))){ $filter_opts{'messagename'} = join '|',@check_presence if(@check_presence); } my @event_state_objs; my $flag = 1; AGAIN : try { @event_state_objs = NACL::CS::EventLog->fetch( 'command_interface' => $ci, 'filter' => \%filter_opts, 'allow_empty' => 1, ); if ( ( !@event_state_objs ) && ( $flag > 0 ) ) { try { # Setting log size value to 10000 NACL::C::EventConfig->modify( command_interface => $ci, maxlogshowsize => '10000', ); $flag = 0; goto AGAIN; } catch NATE::BaseException with { # suppressing here }; } elsif ( $flag == 0 ) { try { # Reset log size value to 2048 NACL::C::EventConfig->modify( command_interface => $ci, maxlogshowsize => '2048', ); } catch NATE::BaseException with { # suppressing here }; } } catch NACL::C::Exceptions::TimeNotSynchronised with { my $ex = shift; if ($ignore_if_unsynchronized) { $Log->debug("Ignoring the time un-synchronized error"); @event_state_objs = $ex->state_objects(); } else { $Log->exit() if $may_exit; $ex->throw(); } }; $self->events(\@event_state_objs); $validate_timestamp = 0; } else { $validate_timestamp = 1; # Convert the time stamp into localtime to perform second level of time validation of events. $begin_localtime = _convert_to_localtime($begin_time); $end_localtime = _convert_to_localtime($end_time); } my $events = $opts{'events'} || $self->events(); if ( !( scalar @{$events} ) ) { if ( $check_for_any_presence || $check_for_all_presence ) { NACL::Exceptions::EventCheckFailure->throw("No events to check"); } # if only check_for_absence is provided and no events to find, just return return; } # Convert the time stamp into localtime to perform second level of time validation of events. my ( $any_present, @all_presence_msgs, @track_all_presence_msgs ); @all_presence_msgs = @track_all_presence_msgs = @{$check_for_all_presence} if ( ref $check_for_all_presence eq "ARRAY" ); my @matched_events_any; my @matched_events_all; my @matched_events; foreach my $event ( @{$events} ) { my $field_name = $event->$fields(); # If the user has given the time range skip all # those events which doesn't fall under the given time range if ($validate_timestamp) { my $event_local_time = _convert_to_localtime($event->time()); if ( ($event_local_time < $begin_localtime) || ($event_local_time > $end_localtime) ) { next; } } if ( defined $check_for_absence && _check_for_message_or_regex( $check_for_absence, $field_name ) ) { $Log->exit() if $may_exit; NACL::Exceptions::EventCheckFailure->throw( "Unexpected $fields found !", 'unmatched_events' => [$field_name] ); } if (defined $check_for_any_presence && _check_for_message_or_regex( $check_for_any_presence, $field_name ) ) { push @matched_events_any, $event; if ( defined $check_for_all_presence && $check_for_absence ) { $any_present = 1; } else { $Log->exit() if $may_exit; return wantarray ? @matched_events_any : $matched_events_any[0]; } } if ( defined $check_for_all_presence ) { my $msg_found = _check_for_message_or_regex( \@all_presence_msgs, $field_name ); if ($msg_found) { push @matched_events_all, $event; @track_all_presence_msgs = grep !/\Q$msg_found\E/, @track_all_presence_msgs; } } } @matched_events = ( @matched_events_any, @matched_events_all ); my $err_msg; my %exception_args; if ( $check_for_any_presence && ( !$any_present ) ) { $err_msg = "No matching events found for the following messages,\n"; $err_msg .=NACL::ComponentUtils::Dumper($check_for_any_presence); $exception_args{'unmatched_events'} = $check_for_any_presence; } if ( ($check_for_all_presence) && (@track_all_presence_msgs) ) { if ( $exception_args{'unmatched_events'} ) { $exception_args{'unmatched_events'} = [ @{ $exception_args{'unmatched_events'} }, @track_all_presence_msgs ]; } else { $exception_args{'unmatched_events'} = [@track_all_presence_msgs]; } $err_msg .= "No matching events found for the following messages,\n"; $err_msg .=NACL::ComponentUtils::Dumper( $exception_args{'unmatched_events'} ); $exception_args{'matched_events'} = [@matched_events]; } if ( $check_for_all_presence && $count && $operation ) { if (! eval( @matched_events_all . $operation . $count ) ) { $err_msg .= "Number of events expected ($operation $count) didn't found." .NACL::ComponentUtils::Dumper( \@matched_events_all ); } } if ($err_msg) { $Log->exit() if $may_exit; NACL::Exceptions::EventCheckFailure->throw( $err_msg, %exception_args ); } $Log->exit() if $may_exit; return wantarray ? @matched_events : $matched_events[0]; } =head2 wait my @matching_event_log_objs = $EventLog->wait( 'nacltask_filter' => { 'event' => "wafl.iron.start: Starting wafliron on volume " . $volname, 'time' => '>"' . $time . '"', }, 'timeout' => $timeout, 'polling_interval' => 5, ); my $first_matching_event_log_obj = $event_log->wait(...); (Instance method) NACL::MTask::EventLogDetector->wait( 'command_interface' => $ci, 'node' => $node, 'nacltask_filter' => { 'event' => "wafl.iron.start: Starting wafliron on volume " . $volname, 'time' => '>"' . $time . '"', }, 'timeout' => $timeout, 'polling_interval' => 5, ); (Class method) Waits for the given event within the time criteria specified. If the events happen, then it returns the matching events. But if event not found within the given time critieria NACL::Exceptions::EventCheckFailure will be thrown. =over =item Options =over =item C<< event_begin_time => $begin_time >> (Optional) Begin time to check for event logs. Date should be in the format "MM/DD/YYYY HH:MM:SS". If this option value is not provided, one of the following is considered. (same order) 1. event_begin_time from the instance 2. range mentioned in the filter for time criteria 3. current filer time =item C<< command_interface => $ci >> (mandatory for class method call) See L =item C<< nacltask_filter => $hash_ref >> ( mandatory ) Reference to a hash of event criterias. =over =item C<< event => $event >> ( mandatory ) Event name or event description for which the method need to wait for. This value is matched with the 'event' field of the NACL::CS::EventLog object and not checked for exact match. i.e. even if the partial string of 'event' field of NACL::CS::EventLog object is matched, it is considered as the event found. It doesn't accept multiple events. =item C<< time => $time >> ( mandatory ) This defines the time criteria for the event to filter. Time parameter can be given as a specific date/time, a range of times (e.g., "08/01/2011 07:00:00".."08/01/2011 07:30:00"), or using operators such as ">" and "<" can be used. =back =item C<< timeout => $timeout >> ( Optional ) Timeout value to wait for the event. Default: infinite. =item C<< polling_interval => $interval >> (Optional) This is the interval (in seconds) after which the value of the attribute will be polled. If not specified it defaults to 10 seconds. All of the other various options to L<< NACL::C::EventLog->find|lib-NACL-C-EventLog-pm/find >> =item C<< ignore_if_unsynchronized => $boolean >> ( Optional, defaults to "0" ) Boolean parameter if set to "1", will ignore the "Error: The time does not appear to be synchronised across this cluster" error. =back =back =cut sub wait { $Log->enter() if $may_enter; my $pkg_or_obj = shift; my %opts = validate_with( params => \@_, spec => $pkg_or_obj->_wait_validate_spec(), allow_extra => 1, ); my $pkg = ref($pkg_or_obj) || $pkg_or_obj; my $ci = $opts{command_interface} || $pkg_or_obj->command_interface(); my $mode = $ci->mode(); my $polling_interval = $opts{polling_interval}; my $ignore_if_unsynchronized = delete $opts{'ignore_if_unsynchronized'}; # For 7mode, time is a mandatory and it is period of time for which # the events need to be fetched. Hence it needs to be calculated # as the difference between the start time and (given end time or # current system time. # the order in which this method calculates this is, # 1. difference betweem the range spefified in the 'time' attribute # of the filter. # 2. difference betweem the time specified in the option 'event_begin_time' # and the current system time. # 3. difference between the instance variable (event_begin_time) and current # system time # Please note that this is only in case of 7Mode # for CMode, only the start time is considered. my $event_begin_time; $event_begin_time = delete $opts{event_begin_time} || $pkg_or_obj->event_begin_time(); my $nacltask_filter = delete $opts{nacltask_filter}; my $event = delete $nacltask_filter->{event}; my %common_options; $pkg->_copy_common_component_params_with_ci( source => \%opts, target => \%common_options, ); my $time = delete $nacltask_filter->{time}; if ( defined $time && $time =~ /\.\./ ) { $event_begin_time = ( split /\.\./, $time )[0]; } if ( !$event_begin_time ) { $event_begin_time = $pkg->_get_sysdate(%common_options); } my %event_time_criteria; if ($time) { $time =~ /^(?:(<|>)?\=?)?($DATE_RE_WO_BE)$/; my $event_time = $2; if($event_time !~ /^\"/ && $event_time !~ /\"$/ ){ $time =~ s/$event_time/\"$event_time\"/; $event_time = '"' . $event_time . '"'; } if ( $time =~ /\/ ) { $event_time_criteria{after} = $event_time; } if ( $time =~ /\=/ ) { $event_time_criteria{at} = $event_time; } } my $timeout = $opts{timeout} ? ( time() + $opts{timeout} ) : $Infinity; my $no_events_found = 1; my @matched_events; while ( time() <= $timeout && !@matched_events ) { my %event_filter; if ( $mode eq "CMode" ) { if ( $event_time_criteria{before} ) { $event_filter{'time'} = $event_begin_time . '..' . $event_time_criteria{before}; } else { $event_filter{'time'} = $time; } } else { # Calculate the time period between event start time and current time my $c_time = $pkg->_get_sysdate( 'command_interface' => $ci, %common_options ); my $time_interval = $pkg->_calculate_time_diff( time_1 => $c_time, time_2 => $event_begin_time ); $event_filter{'time-interval'} = $time_interval; } my $node = $opts{'node'} || $pkg->node(); $event_filter{'node'} = $node if defined $node; my @event_state_objs; try { @event_state_objs = NACL::CS::EventLog->fetch( 'command_interface' => $ci, 'filter' => { %{$nacltask_filter}, %event_filter }, 'requested_fields' => [qw(messagename event time)] ); } catch NACL::Exceptions::NoElementsFound with { my $ex = shift; if ( $ex->text() =~ /No matching event/i ) { $Log->debug( sub { "No elements found, hence retrying after $polling_interval seconds"; } ); } } catch NACL::C::Exceptions::TimeNotSynchronised with { my $ex = shift; if ($ignore_if_unsynchronized) { $Log->debug("Ignoring the time un-synchronized error"); @event_state_objs = $ex->state_objects(); } else { $Log->exit() if $may_exit; $ex->throw(); } }; if (@event_state_objs) { $no_events_found = 0; foreach my $event_state_obj (@event_state_objs) { # Validate the event time next if ( !$pkg->_verfy_event_time( %event_time_criteria, event => $event_state_obj ) ); if ($event_state_obj->event() =~ /$event/) { push @matched_events, $event_state_obj; } } } Tharn::snooze $polling_interval; } if (@matched_events) { $Log->exit() if $may_exit; return wantarray ? @matched_events : $matched_events[0]; } my $error = "Event message: " . $event . " not found"; if ($no_events_found) { $error = "No events found, hence check failed"; } $Log->exit() if $may_exit; NACL::Exceptions::EventCheckFailure->throw( $error, 'unmatched_events' => [$event] ); } =head2 disable_event_suppression $detector->disable_event_suppression(); (Instance method) NACL::MTask::EventLogDetector->disable_event_suppression( 'command_interface' => $ci, ); (Class method) Disable the event suppression on filer. This method is not applicable for 7Mode. =cut sub disable_event_suppression { $Log->enter() if $may_enter; my $pkg_or_obj = shift; my %opts = validate_with( params => \@_, spec => $pkg_or_obj->_event_suppression_validate_spec(), allow_extra => 1, ); my $pkg = ref($pkg_or_obj) || $pkg_or_obj; my $ci = $opts{command_interface} || $pkg_or_obj->command_interface(); NACL::C::EventConfig->modify( command_interface => $ci, suppression => 'off', ); $Log->exit() if $may_exit; } =head2 enable_event_suppression $detector->enable_event_suppression(); (Instance method) NACL::MTask::EventLogDetector->enable_event_suppression( 'command_interface' => $ci, ); (Class method) Enable the event suppression on filer. This method is not applicable for 7Mode. =cut sub enable_event_suppression { $Log->enter() if $may_enter; my $pkg_or_obj = shift; my %opts = validate_with( params => \@_, spec => $pkg_or_obj->_event_suppression_validate_spec(), allow_extra => 1, ); my $pkg = ref($pkg_or_obj) || $pkg_or_obj; my $ci = $opts{command_interface} || $pkg_or_obj->command_interface(); NACL::C::EventConfig->modify( command_interface => $ci, suppression => 'on', ); $Log->exit() if $may_exit; } # Helper method to verify the event time with the given criteria sub _verfy_event_time { my $self = shift; my %opts = validate_with( params => \@_, spec => { before => { regex => $DATE_RE, optional => 1 }, after => { regex => $DATE_RE, optional => 1 }, at => { regex => $DATE_RE, optional => 1 }, event => { type => OBJECT } } ); my $event_time = _convert_to_localtime( $opts{event}->time() ); my $is_at_valid; # if only 'at' is requested, validate and return # if 'at' is requested along with '<' or '>', check if the # time stamp of event matches the given value for the attribute 'at' if ( $opts{at} ) { my $local_time = _convert_to_localtime( $opts{at} ); if ( $event_time != $local_time ) { if ( !( $opts{before} || $opts{after} ) ) { return 0 if ( $event_time != $local_time ); } else { $is_at_valid = 0; } } else { $is_at_valid = 1; } } if ( $opts{before} ) { my $local_time = _convert_to_localtime( $opts{before} ); return 0 if ( ( $event_time > $local_time ) || $is_at_valid ); } if ( $opts{after} ) { my $local_time = _convert_to_localtime( $opts{after} ); return 0 if ( ( $event_time < $local_time ) || $is_at_valid ); } return 1; } # Checks if the given message or regex matches the event log message sub _check_for_message_or_regex { my ( $msg_or_regex_to_check, $field_name ) = @_; foreach my $msg_or_regex ( @{$msg_or_regex_to_check} ) { if ( ref $msg_or_regex eq 'Regexp' ) { if ( $field_name =~ /$msg_or_regex/ ) { $Log->exit() if $may_exit; return $msg_or_regex; } } else { if ( $field_name eq $msg_or_regex ) { $Log->exit() if $may_exit; return $msg_or_regex; } } } $Log->exit() if $may_exit; return 0; } # This helper function converts the given date string into localtime sub _convert_to_localtime { $Log->enter() if $may_enter; my ($date_string) = shift; if ($date_string =~ /\d{10}/) { $Log->exit() if $may_exit; return $date_string; } $date_string =~ s/\"//g; my ( $mon, $mday, $year, $hour, $min, $sec ) = split /\s|\/|\:/, $date_string; my $local_time; $mon--; eval { $local_time = timelocal( $sec, $min, $hour, $mday, $mon, $year ); }; # Validate timestamp if ($@) { $Log->exit() if $may_exit; NATE::Exceptions::Argument->throw( "Invalid date: " . $@ ); } $Log->exit() if $may_exit; return $local_time; } # Validate spec for wait method call. sub _wait_validate_spec { my $self = shift; my %common_options = ( nacltask_filter => { type => HASHREF }, event_begin_time => { regex => qr/^$DATE_RE$/, optional => 1 }, timeout => { type => SCALAR, default => $Infinity }, polling_interval => { type => SCALAR, default => 10 }, ignore_if_unsynchronized => { type => BOOLEAN, default => 0 }, ); if ( ref $self ) { return { %common_options, %{ NACL::C::Component->_common_validate_spec_without_ci() } }; } else { return { %common_options, %{ NACL::C::Component->_common_validate_spec() } }; } } # Validate spec for wait method call. sub _event_suppression_validate_spec { my $self = shift; if ( ref $self ) { return { %{ NACL::C::Component->_common_validate_spec_without_ci() } }; } else { return { %{ NACL::C::Component->_common_validate_spec() } }; } } # Returns validate spec for check() method based on if the check() is invoked as instance method or class method sub _check_validate_spec { my $self = shift; if ( ref($self) ) { return { 'check_for_all_presence' => { type => ARRAYREF, optional => 1 }, 'check_for_absence' => { type => ARRAYREF, optional => 1 }, 'check_for_any_presence' => { type => ARRAYREF, optional => 1 }, 'node' => { type => SCALAR, optional => 1 }, 'ignore_if_unsynchronized' => { type => BOOLEAN, default => 0 }, 'count' => { type => SCALAR, optional => 1 }, 'operation' => { type => SCALAR, optional => 1, regex => $OP_RE }, }; } else { return { 'event_begin_time' => { type => SCALAR }, 'event_end_time' => { type => SCALAR }, 'node' => { type => SCALAR, optional => 1 }, 'events' => { type => ARRAYREF, callbacks => { "All of the CS objects provided must be of type 'NACL::CS::EventLog'" => sub { my $el_cs_objs = $_[0]; foreach my $el_cs_obj ( @{$el_cs_objs} ) { return 0 if ( !$el_cs_obj->isa("NACL::CS::EventLog") ); } return 1; } } }, 'check_for_all_presence' => { type => ARRAYREF, optional => 1 }, 'check_for_absence' => { type => ARRAYREF, optional => 1 }, 'check_for_any_presence' => { type => ARRAYREF, optional => 1 }, 'command_interface' => { type => OBJECT }, 'ignore_if_unsynchronized' => { type => BOOLEAN, default => 0 }, 'count' => { type => SCALAR, optional => 1 }, 'operation' => { type => SCALAR, optional => 1, regex => $OP_RE }, }; } } # Helper method to return the sysdate of the filer sub _get_sysdate { $Log->enter() if $may_enter; my $self = shift; my %opts = validate_with( params => \@_, spec => { 'command_interface' => { type => OBJECT, optional => 1 } }, allow_extra => 1 ); my $ci = $opts{command_interface} || $self->command_interface(); my $date_object = $self->_get_cluster_date( 'command_interface' => $ci, %opts ); $Log->exit() if $may_exit; return $date_object->date(); } sub _calculate_time_diff { my $self = shift; my %opts = validate_with( params => \@_, spec => { 'time_1' => { regex => qr/^"?\d{1,2}\/\d{1,2}\/\d{4}\s\d{1,2}:\d{1,2}:\d{1,2}"?$/ }, 'time_2' => { regex => qr/^"?\d{1,2}\/\d{1,2}\/\d{4}\s\d{1,2}:\d{1,2}:\d{1,2}"?$/ }, }, ); $opts{time_1} =~ s/\"//g; $opts{time_2} =~ s/\"//g; my @time1 = split( /\/|\s|:/, $opts{time_1} ); my @time2 = split( /\/|\s|:/, $opts{time_2} ); $time1[0] = $time1[0] - 1; $time2[0] = $time2[0] - 1; my $epoch_time_1 = timelocal( ( map { s/^0*//; $_ } ( @time1[ 5, 4, 3, 1, 0, 2 ] ) ) ); my $epoch_time_2 = timelocal( ( map { s/^0*//; $_ } ( @time2[ 5, 4, 3, 1, 0, 2 ] ) ) ); return $epoch_time_1 - $epoch_time_2; } sub _get_cluster_date { $Log->enter() if $may_enter; my ($self, @args) = @_; my %opts = validate_with( params => \@args, spec => { 'command_interface' => { type => OBJECT, optional => 1 }, check => { type => SCALAR, default => 0 },}, allow_extra => 1 ); my $ci = $opts{command_interface} || $self->command_interface(); my @fields = qw(utc-date); #Timezone is required only in case of CMode. if ($ci->is_cmode && $opts{check}) { push @fields,'timezone'; } $Log->exit() if $may_exit; return NACL::CS::ClusterDate->fetch( 'command_interface' => $ci, filter => { node => $ci->name }, 'requested_fields' => [@fields], ); } sub _convert_utc_to_local { my ($self, $time) = @_; my $timezone; ## w.r.t burt974474 'cluster date show' ## fails intermittently with error ## "node_date_iterator::get_imp()" took longer than 25 seconds ## adding a retry logic here NACL::GeneralUtils::nacl_method_retry( code => sub { $timezone = $self->_timezone() || $self->command_interface()->get_timezone(); }, tries_count => 5, sleep_time => 5, exceptions => 'NACL::APISet::Exceptions::ResponseException' ); return $time if ($timezone =~ /UTC/i || $timezone =~ /Factory/i) ; $time =~ s/\"//g; my ($mon, $mday, $year, $hour, $min, $sec) = split /\s|\/|\:/, $time; my $dt = DateTime->new( year => $year, month => $mon, day => $mday, hour => $hour, minute => $min, second => $sec, time_zone => 'UTC', ); $dt->set_time_zone($timezone); my $mdy = $dt->mdy('/'); my $hms = $dt->hms(); my $new_time = "$mdy $hms"; return $new_time; } ## end sub _convert_utc_to_local sub _event_time_read_cb { $Log->enter() if $may_enter; my ($self, @args) = @_; my %opts = validate_with( params => \@args, spec => { val => {type => SCALAR | UNDEF}, field => {type => SCALAR}, }, ); # If invoked as a package call, just return return if (!ref $self); # Attribute is already set, so use its value return $opts{val} if (defined $opts{val}); # If we've reached here, then it's an instance call without # an existing value, so determine this from the utc value. my $field = $opts{field}; my $utc_field = "_${field}_utc"; my $utc_field_isset = "${utc_field}_isset"; if ($self->$utc_field_isset()) { my $utc_val = $self->$utc_field(); $Log->exit() if $may_exit; return $self->_convert_utc_to_local($utc_val); } $Log->exit() if $may_exit; return; } ## end sub _event_time_read_cb 1;