diff --git a/modules/Bio/EnsEMBL/Hive/AnalysisStats.pm b/modules/Bio/EnsEMBL/Hive/AnalysisStats.pm index 34c1cdc153e1f7b29975fb107a25f64b0f9ca7c5..e9c6fbe7d3c71dfe8b178c89f1df491d5ba2fce1 100644 --- a/modules/Bio/EnsEMBL/Hive/AnalysisStats.pm +++ b/modules/Bio/EnsEMBL/Hive/AnalysisStats.pm @@ -299,20 +299,15 @@ sub job_count_breakout { } -sub print_stats { - my $self = shift @_; - - printf("%-27s(%2d) ", $self->get_analysis->logic_name, $self->analysis_id ); - print $self->toString."\n"; -} - - sub toString { my $self = shift @_; my $analysis = $self->get_analysis; - my $output = sprintf("%11s jobs(Sem:%d, Rdy:%d, InProg:%d, Done+Pass:%d, Fail:%d)=%d Ave_msec:%d, workers(Running:%d, Reqired:%d) ", + my $output .= sprintf("%-27s(%2d) %11s jobs(Sem:%d, Rdy:%d, InProg:%d, Done+Pass:%d, Fail:%d)=%d Ave_msec:%d, workers(Running:%d, Reqired:%d) ", + $analysis->logic_name, + $self->analysis_id, + $self->status, $self->semaphored_job_count, @@ -329,7 +324,7 @@ sub toString { ); $output .= ' h.cap:' .( defined($self->hive_capacity) ? $self->hive_capacity : '-' ) .' a.cap:' .( defined($analysis->analysis_capacity) ? $analysis->analysis_capacity : '-') - ." (sync'd " .$self->seconds_since_last_update." sec ago)", + ." (sync'd " .$self->seconds_since_last_update." sec ago)"; return $output; } diff --git a/modules/Bio/EnsEMBL/Hive/Queen.pm b/modules/Bio/EnsEMBL/Hive/Queen.pm index e3d5a1d8b5e730a6614a5dc1f292e4633b95c1e7..57c7d8feee37b035111230127e4f22a6260490d2 100644 --- a/modules/Bio/EnsEMBL/Hive/Queen.pm +++ b/modules/Bio/EnsEMBL/Hive/Queen.pm @@ -748,7 +748,7 @@ sub print_analysis_status { my $list_of_analyses = $filter_analysis ? [$filter_analysis] : $self->db->get_AnalysisAdaptor->fetch_all; foreach my $analysis (sort {$a->dbID <=> $b->dbID} @$list_of_analyses) { - $analysis->stats->print_stats(); + print $analysis->stats->toString . "\n"; } } diff --git a/modules/Bio/EnsEMBL/Hive/Scheduler.pm b/modules/Bio/EnsEMBL/Hive/Scheduler.pm index b8a7274cf93112b880c5f5d513a91fb6d376f6b5..2aefd4e18dba91e7ecd97b49fb21a17ee6d9b29e 100644 --- a/modules/Bio/EnsEMBL/Hive/Scheduler.pm +++ b/modules/Bio/EnsEMBL/Hive/Scheduler.pm @@ -53,8 +53,9 @@ sub schedule_workers_resync_if_necessary { # combined mapping: my $analysis_id2rc_name = { map { $_ => $rc_id2name->{ $analysis_id2rc_id->{ $_ }} } keys %$analysis_id2rc_id }; - my ($workers_to_submit_by_meadow_type_rc_name, $total_workers_required) + my ($workers_to_submit_by_meadow_type_rc_name, $total_workers_required, $log_buffer) = schedule_workers($queen, $valley, $filter_analysis, $meadow_capacity_by_type, $analysis_id2rc_name); + print $log_buffer; unless( $total_workers_required ) { print "\nScheduler: according to analysis_stats no workers are required... let's see if resync can fix it.\n" ; @@ -68,8 +69,9 @@ sub schedule_workers_resync_if_necessary { print "Scheduler: re-synchronizing the Hive...\n"; $queen->synchronize_hive($filter_analysis); - ($workers_to_submit_by_meadow_type_rc_name, $total_workers_required) + ($workers_to_submit_by_meadow_type_rc_name, $total_workers_required, $log_buffer) = schedule_workers($queen, $valley, $filter_analysis, $meadow_capacity_by_type, $analysis_id2rc_name); + print $log_buffer; } # adjustment for pending workers: @@ -110,19 +112,16 @@ sub schedule_workers { : @{ $queen->db->get_AnalysisStatsAdaptor->fetch_all_by_suitability_rc_id_meadow_type() }; unless(@suitable_analyses) { - print "Scheduler could not find any suitable analyses to start with\n"; - return ({}, 0); + return ({}, 0, "Scheduler could not find any suitable analyses to start with\n"); } # the pre-pending-adjusted outcome will be stored here: my %workers_to_submit_by_meadow_type_rc_name = (); - my $total_workers_required = 0; + my $log_buffer = ''; my $default_meadow_type = $valley->get_default_meadow()->type; - my $available_submit_limit = $valley->config_get('SubmitWorkersMax'); - my $submit_capacity = Bio::EnsEMBL::Hive::Limiter->new( 'Max number of Workers submitted this iteration', $valley->config_get('SubmitWorkersMax') ); my $queen_capacity = Bio::EnsEMBL::Hive::Limiter->new( 'Total reciprocal capacity of the Hive', 1.0 - $queen->get_hive_current_load() ); @@ -175,14 +174,14 @@ sub schedule_workers { my $this_rc_name = $analysis_id2rc_name->{ $analysis_stats->analysis_id }; $workers_to_submit_by_meadow_type_rc_name{ $this_meadow_type }{ $this_rc_name } += $extra_workers_this_analysis; - $analysis_stats->print_stats(); - printf("Before checking the Valley for pending jobs, Scheduler allocated $extra_workers_this_analysis x $this_meadow_type:$this_rc_name extra workers for '%s' [%.4f hive_load remaining]\n", + $log_buffer .= $analysis_stats->toString . "\n"; + $log_buffer .= sprintf("Before checking the Valley for pending jobs, Scheduler allocated $extra_workers_this_analysis x $this_meadow_type:$this_rc_name extra workers for '%s' [%.4f hive_load remaining]\n", $analysis->logic_name, $queen_capacity->available_capacity, ); } - return (\%workers_to_submit_by_meadow_type_rc_name, $total_workers_required); + return (\%workers_to_submit_by_meadow_type_rc_name, $total_workers_required, $log_buffer); } diff --git a/modules/Bio/EnsEMBL/Hive/Worker.pm b/modules/Bio/EnsEMBL/Hive/Worker.pm index fc0ba822bb2488d2108cf97408af90f3bcf87e98..73790a4cf5111bc3786456746a8a395f726f428a 100644 --- a/modules/Bio/EnsEMBL/Hive/Worker.pm +++ b/modules/Bio/EnsEMBL/Hive/Worker.pm @@ -593,7 +593,7 @@ sub run { $self->adaptor->register_worker_death($self, 1); if($self->debug) { - $self->worker_say( 'AnalysisStats :'.$self->analysis->stats->toString ) if($self->analysis_id()); + $self->worker_say( 'AnalysisStats : '.$self->analysis->stats->toString ) if($self->analysis_id()); $self->worker_say( 'dbc '.$self->adaptor->db->dbc->disconnect_count. ' disconnect cycles' ); } @@ -669,7 +669,7 @@ sub run_one_batch { $self->adaptor->safe_synchronize_AnalysisStats($self->analysis->stats); if($self->debug) { - $self->worker_say( "Stats : ".$self->analysis->stats->toString ); + $self->worker_say( 'AnalysisStats : '.$self->analysis->stats->toString ); $self->worker_say( 'claimed '.scalar(@{$jobs}).' jobs to process' ); }