Changeset 190 for shepherd

Timestamp:

11/07/06 00:26:22 (7 years ago)

Author:

lincoln

Message:

consolidate logging into tv_grab_au via call_prog, remove all logging from shepherd

Files:

• shepherd (modified) (52 diffs)

shepherd

@@ -22 +22 @@
 #                        (e.g. flag HDTV programmes, augment with IMDb etc.)
 
-my $version = '0.2.32';
+my $version = '0.2.33';
 
 # Changelog:
@@ -56 +56 @@
 # 0.2.31  : split tv_grab_au (install/test/upgrade/enable/disable) from
 #           shepherd (grab/reconcile/postprocess)
+# 0.2.33  : remove logging (tv_grab_au does it for us)
 
 BEGIN { *CORE::GLOBAL::die = \&my_die; }
@@ -133 +134 @@
 my $config_file =   "$CWD/$progname.conf";
 my $channels_file = "$CWD/channels.conf";
-my $log_file = "$CWD/$progname.log";
 my $days = 7;
 my $missing;
@@ -172 +172 @@
 
 &get_remaining_command_line_options;
-&open_logfile unless ($opt->{nolog});
 
 &process_setup_commands;
@@ -190 +189 @@
 }
 
-&log("Done.\n");
-&close_logfile() unless $opt->{nolog};
-
 # ---------------------------------------------------------------------------
 # --- Subroutines
@@ -205 +201 @@
     my $used_grabbers = 0;
 
-    &log("\nGrabber stage.\n");
+    printf "\nGrabber stage.\n";
 
     &analyze_plugin_data("",1);    
@@ -216 +212 @@
         $components->{$grabber}->{laststatus} = "unknown";
 
-        &log((sprintf "\nSHEPHERD: Using grabber: (%d) %s\n", $used_grabbers, $grabber));
+        printf "\nSHEPHERD: Using grabber: (%d) %s\n", $used_grabbers, $grabber;
 
         my $output = "$CWD/grabbers/$grabber/output.xmltv";
@@ -230 +226 @@
         if (query_config($grabber, 'category') == 1)
         {
-            &log("$grabber is Category 1: grabbing timeslice.\n") if ($debug);
+            printf "$grabber is Category 1: grabbing timeslice.\n" if ($debug);
 
             record_requested_chandays($grabber, $timeslice);
@@ -266 +262 @@
         else
         {
-            &log("$grabber is category 2: grabbing everything.\n") if ($debug);
+            printf "$grabber is category 2: grabbing everything.\n" if ($debug);
             $comm .= " --days $days" if ($days);
             $comm .= " --offset $opt->{offset}" if ($opt->{offset});
@@ -276 +272 @@
         my $retval = 0;
         if ((defined $opt->{dontcallgrabbers}) && ($opt->{dontcallgrabbers})) {
-            &log("SHEPHERD: not calling grabber because of --dontcallgrabbers option, but will instead use existing $output\n");
-            &log("SHEPHERD: would have called: $comm\n") if ($debug);
+            printf "SHEPHERD: not calling grabber because of --dontcallgrabbers option, but will instead use existing $output\n";
+            printf "SHEPHERD: would have called: $comm\n" if ($debug);
         } else {
-            &log("SHEPHERD: Excuting command: $comm\n");
+            printf "SHEPHERD: Excuting command: $comm\n";
             chdir "$CWD/grabbers/$grabber/";
             $retval = call_prog($comm);
@@ -286 +282 @@
 
         if ($retval != 0) {
-            &log("grabber returned with non-zero return code $retval: assuming it failed.\n");
+            printf "grabber returned with non-zero return code $retval: assuming it failed.\n";
             next;
         }
@@ -305 +301 @@
             my $list = List::Compare->new($missing_before, $missing_after);
             my @grabbed = $list->get_symmetric_difference();
-            &log("Grabbed: " . join (', ', @grabbed) . ".\n") if ($debug);
+            printf "Grabbed: " . join (', ', @grabbed) . ".\n" if ($debug);
             record_cached($grabber, @grabbed);
             write_config_file();
@@ -316 +312 @@
     if ($used_grabbers == 0)
     {
-        &log("No valid grabbers installed/enabled!\n");
+        printf "No valid grabbers installed/enabled!\n";
         return;
     }
@@ -322 +318 @@
     unless ($grabber_found_all_data)
     {
-        &log("SHEPHERD: Ran through ALL grabbers but still missing data!!! :(\n");
+        printf "SHEPHERD: Ran through ALL grabbers but still missing data!!! :(\n";
         return;
     }
@@ -360 +356 @@
     if ($debug)
     {
-        &log((sprintf "Best timeslice: day%s of channels %s (%d chandays).\n",
+        printf "Best timeslice: day%s of channels %s (%d chandays).\n",
                     ($timeslice->{start} == $timeslice->{stop} ?
                         " $timeslice->{start}" :
                         "s $timeslice->{start} - $timeslice->{stop}"),
                     join(', ', @{$timeslice->{chans}}),
-                    $timeslice->{chandays}));
+                    $timeslice->{chandays};
     }
 
@@ -372 +368 @@
     if ($debug)
     {
-        &log("Grabber selection:\n");
+        printf "Grabber selection:\n";
         foreach (sort { $gscore->{$b} <=> $gscore->{$a} } keys %$gscore)
         {
@@ -383 +379 @@
             if ($opt->{randomize})
             {
-                &log((sprintf "%15s %6.1f%% %9s %s\n", 
+                printf "%15s %6.1f%% %9s %s\n", 
                         $_, 
                         ($total ? 100* $score / $total : 0), 
                         "$score pts",
-                        $cstr));
+                        $cstr;
             }
             else
             {
-                &log((sprintf   "%15s %4s pts %s\n", 
+                printf "%15s %4s pts %s\n", 
                         $_, 
                         $score,
-                        $cstr));
+                        $cstr;
             }
         }
@@ -413 +409 @@
             unless ($components->{$grabber}->{lastdata})
             {
-                &log("Need to build title translation list for transitional grabber $grabber.\n");
+                printf "Need to build title translation list for transitional grabber $grabber.\n";
                 return select_grabber($grabber, $gscore) if ($gscore->{$grabber});
-                &log("WARNING: Can't run $grabber to build title translation list!\n");
+                printf "WARNING: Can't run $grabber to build title translation list!\n";
             }
         }
@@ -459 +455 @@
     my ($grabber, $gscore) = @_;
 
-    &log("Selected $grabber.\n") if ($debug);
+    printf "Selected $grabber.\n" if ($debug);
     if (query_config($grabber, 'category') == 2)
     {
@@ -497 +493 @@
         {
             $key = cut_down_missing($grabber);
-            # &log("Grabber $grabber is Category 1: comparing capability to best timeslice.\n") if ($debug);
+            # printf "Grabber $grabber is Category 1: comparing capability to best timeslice.\n" if ($debug);
         }
         else
         {
             $key = $missing;
-            # &log("Grabber $grabber is Category 2: comparing capability to all wanted channels and days.\n") if ($debug);
+            # printf "Grabber $grabber is Category 2: comparing capability to all wanted channels and days.\n" if ($debug);
         }
 
@@ -515 +511 @@
                 my $val = supports_day($grabber, $day);
                 next unless ($val);
-                # &log("Day $day:") if ($debug);
+                # printf "Day $day:" if ($debug);
                 foreach my $ch (@{$key->{$day}})
                 {
                     if (supports_channel($grabber, $ch, $day))
                     {
-                        # &log(" $ch") if ($debug);
+                        # printf " $ch" if ($debug);
                         $hits += $val;
                     }
                 }
-                # &log("\n") if $debug;
+                # printf "\n" if $debug;
                 $hits = 1 if ($hits > 0 and $hits < 1);
             }
@@ -556 +552 @@
                             $score;
             }
-            &log("$str.\n");
+            printf "$str.\n";
         }
 
@@ -586 +582 @@
                 $total -= $gscore->{$_};
                 $gscore->{$_} = 0;
-                &log("Zeroing grabber $_ due to low data quality.\n") if ($debug);
+                printf "Zeroing grabber $_ due to low data quality.\n" if ($debug);
             }
         }
@@ -611 +607 @@
     unless (defined $channels_supported)
     {
-        &log("WARNING: Grabber $grabber has no channel support " .
-              "specified in config.\n");
+        printf "WARNING: Grabber $grabber has no channel support " .
+              "specified in config.\n";
         $channels_supported = '';
     }
@@ -686 +682 @@
     if ($debug)
     {
-        &log("Need data for days " . join(", ", sort keys %$m) . 
-             " ($chandays chandays).\n");
+        printf "Need data for days " . join(", ", sort keys %$m) . 
+             " ($chandays chandays).\n";
     }
     return $m;
@@ -737 +733 @@
     my ($grabber, @grabbed) = @_;
 
-    &log("Recording cache for grabber $grabber.\n") if ($debug);
+    printf "Recording cache for grabber $grabber.\n" if ($debug);
 
     my $gcache = $components->{$grabber}->{cached};
@@ -788 +784 @@
     my ($grabber, $slice) = @_;
 
-    &log("Recording timeslice request; will not request these chandays " .
-         "from $grabber again.\n") if ($debug);
+    printf "Recording timeslice request; will not request these chandays " .
+         "from $grabber again.\n" if ($debug);
 
     my @requested;
@@ -848 +844 @@
 
     if (! -r $output) {
-        &log((sprintf "SHEPHERD: Warning: plugin '%s' output file '%s' does not exist\n",$plugin,$output));
+        printf "SHEPHERD: Warning: plugin '%s' output file '%s' does not exist\n",$plugin,$output;
         return;
     }
 
     my $this_plugin = $plugin_data->{$plugin};
-    &log((sprintf "SHEPHERD: Started parsing XMLTV from '%s' in '%s' .. any errors below are from parser:\n",$plugin,$output));
+    printf "SHEPHERD: Started parsing XMLTV from '%s' in '%s' .. any errors below are from parser:\n",$plugin,$output;
     eval { $this_plugin->{xmltv} = XMLTV::parsefiles($output); };
-    &log((sprintf "SHEPHERD: Completed XMLTV parsing from '%s'\n",$plugin));
+    printf "SHEPHERD: Completed XMLTV parsing from '%s'\n",$plugin;
 
     if (!($this_plugin->{xmltv})) {
-        &log("WARNING: Plugin $plugin didn't seem to return any valid XMLTV!\n");
+        printf "WARNING: Plugin $plugin didn't seem to return any valid XMLTV!\n";
         return;
     }
@@ -884 +880 @@
         if (!defined $chan_xml_list{($prog->{channel})}) {
             $this_plugin->{progs_with_unknown_channel}++;
-            &log((sprintf " - WARNING: plugin '%s' returned data for unknown channel '%s': ignored.\n",$plugin,$prog->{channel}));
+            printf " - WARNING: plugin '%s' returned data for unknown channel '%s': ignored.\n",$plugin,$prog->{channel};
             $chan_xml_list{($prog->{channel})} = 1;     # so we warn only once
         }
@@ -901 +897 @@
 
             if (!$t1 || !$t2) {
-                &log((sprintf " - WARNING: plugin '%s' returned programme data with invalid timestamp format: \"%s\": can't parse.\n",
-                    $plugin,(!$t1 ? $prog->{start} : $prog->{stop}))) if (!$this_plugin->{progs_with_invalid_date});
+                printf " - WARNING: plugin '%s' returned programme data with invalid timestamp format: \"%s\": can't parse.\n",
+                    $plugin,(!$t1 ? $prog->{start} : $prog->{stop}) if (!$this_plugin->{progs_with_invalid_date});
                 $this_plugin->{progs_with_invalid_date}++;
                 next;
@@ -943 +939 @@
 
     # print some stats about what we saw!
-    &log((sprintf "SHEPHERD: %s '%s' returned data for %d channels, %d programmes, %dd%02dh%02dm%02ds duration, %s%s\n",
+    printf "SHEPHERD: %s '%s' returned data for %d channels, %d programmes, %dd%02dh%02dm%02ds duration, %s%s\n",
         ucfirst($plugintype), $plugin, $seen_channels_with_data, $this_plugin->{programmes},
         int($this_plugin->{total_duration} / 86400),            # days
@@ -950 +946 @@
         int($this_plugin->{total_duration} % 60),               # sec
         (defined $this_plugin->{earliest_data_seen} ? (strftime "%a %e %b %H:%M - ", localtime($this_plugin->{earliest_data_seen})) : 'no data'),
-        (defined $this_plugin->{latest_data_seen} ? (strftime "%a %e %b %H:%M", localtime($this_plugin->{latest_data_seen})) : '')));
+        (defined $this_plugin->{latest_data_seen} ? (strftime "%a %e %b %H:%M", localtime($this_plugin->{latest_data_seen})) : '');
 
     $this_plugin->{laststatus} = sprintf "%dch/%dpr/%dhrs %s-%s",
@@ -966 +962 @@
 {
     my ($analysistype,$quiet) = @_;
-    &log("SHEPHERD: $analysistype:\n") unless $quiet;
+    printf "SHEPHERD: $analysistype:\n" unless $quiet;
 
     my $total_channels = 0;
@@ -1108 +1104 @@
             }
         }
-        &log($statusstring) unless $quiet;
+        printf $statusstring unless $quiet;
 
         delete $channel_data->{$ch}->{analysis} if (defined $channel_data->{$ch}->{analysis});
@@ -1114 +1110 @@
     }
 
-    &log((sprintf " > OVERALL: %s\n", ($overall_data_ok ? "PASS" : "FAIL"))) unless $quiet;
+    printf " > OVERALL: %s\n", ($overall_data_ok ? "PASS" : "FAIL") unless $quiet;
 
     return $overall_data_ok; # return 1 for good, 0 for need more
@@ -1235 +1231 @@
 sub reconcile_data
 {
-    &log("\nReconciling data:\n\n");
+    printf "\nReconciling data:\n\n";
 
     my $num_grabbers = 0;
@@ -1241 +1237 @@
     my @input_file_list;
 
-    &log("Preferred title preferences from '$pref_title_source'\n")
+    printf "Preferred title preferences from '$pref_title_source'\n"
         if ((defined $pref_title_source) &&
             ($plugin_data->{$pref_title_source}) &&
             ($plugin_data->{$pref_title_source}->{valid}));
 
-    &log("Preference for whose data we prefer as follows:\n");
+    printf "Preference for whose data we prefer as follows:\n";
     foreach my $proggy (sort { $components->{$b}->{config}->{quality} <=> $components->{$a}->{config}->{quality} } query_grabbers()) {
         if ((!$components->{$proggy}->{disabled}) && ($plugin_data->{$proggy}) && ($plugin_data->{$proggy}->{valid})) {
             $num_grabbers++;
-            &log((sprintf "  %d. %s (%s)\n", $num_grabbers, $proggy, $plugin_data->{$proggy}->{output_filename}));
+            printf "  %d. %s (%s)\n", $num_grabbers, $proggy, $plugin_data->{$proggy}->{output_filename};
 
             $input_files .= $plugin_data->{$proggy}->{output_filename}." ";
@@ -1269 +1265 @@
         if ((!$reconciler_found_all_data) && ($grabber_found_all_data)) {
             # urgh.  this reconciler did a bad bad thing ...
-            &log("SHEPHERD: XML data from reconciler $reconciler appears bogus, will try to use another reconciler\n");
+            printf "SHEPHERD: XML data from reconciler $reconciler appears bogus, will try to use another reconciler\n";
         } else {
-            &log("SHEPHERD: Data from reconciler $reconciler looks good\n");
+            printf "SHEPHERD: Data from reconciler $reconciler looks good\n";
             $input_postprocess_file = $plugin_data->{$reconciler}->{output_filename};
         }
@@ -1280 +1276 @@
     if ($input_postprocess_file eq "") {
         # no reconcilers worked!!
-        &log("SHEPHERD: WARNING: No reconcilers seemed to work!  Falling back to concatenating the data together!\n");
+        printf "SHEPHERD: WARNING: No reconcilers seemed to work!  Falling back to concatenating the data together!\n";
 
         my %w_args = ();
@@ -1304 +1300 @@
     # first time around: feed in reconciled data ($input_postprocess_file)
 
-    &log("\nPostprocessing stage:\n");
+    printf "\nPostprocessing stage:\n";
 
     foreach my $postprocessor (sort { $components->{$a} <=> $components->{$b} } query_postprocessors()) {
@@ -1314 +1310 @@
         if ($found_all_data) {
             # accept what this postprocessor did to our output ...
-            &log("SHEPHERD: accepting output from postprocessor $postprocessor, feeding it into next stage\n");
+            printf "SHEPHERD: accepting output from postprocessor $postprocessor, feeding it into next stage\n";
             $input_postprocess_file = $plugin_data->{$postprocessor}->{output_filename};
             delete $components->{$postprocessor}->{conescutive_failures} if (defined $components->{$postprocessor}->{conescutive_failures});
@@ -1321 +1317 @@
 
         # urgh.  this postprocessor did a bad bad thing ...
-        &log("SHEPHERD: XML data from postprocessor $postprocessor rejected, using XML from previous stage\n");
+        printf "SHEPHERD: XML data from postprocessor $postprocessor rejected, using XML from previous stage\n";
 
         if (defined $components->{$postprocessor}->{conescutive_failures}) {
@@ -1328 +1324 @@
             $components->{$postprocessor}->{conescutive_failures} = 1;
         }
-        &log((sprintf "SHEPHERD: Postprocessor \"%s\" has now failed %d times in a row.  %d more and it will be automatically disabled.\n",
+        printf "SHEPHERD: Postprocessor \"%s\" has now failed %d times in a row.  %d more and it will be automatically disabled.\n",
             $postprocessor,
             $components->{$postprocessor}->{conescutive_failures},
-            ($policy{postprocessor_disable_failure_threshold} - $components->{$postprocessor}->{conescutive_failures})));
+            ($policy{postprocessor_disable_failure_threshold} - $components->{$postprocessor}->{conescutive_failures});
 
         if ($components->{$postprocessor}->{conescutive_failures} >= $policy{postprocessor_disable_failure_threshold}) {
-            &log("SHEPHERD: Disabling Postprocessor \"$postprocessor\".\n");
+            printf "SHEPHERD: Disabling Postprocessor \"$postprocessor\".\n";
             $components->{$postprocessor}->{disabled} = 1;
         }
@@ -1352 +1348 @@
     $components->{$data_processor_name}->{laststatus} = "unknown";
 
-    &log((sprintf "\nSHEPHERD: Using %s: %s\n",$data_processor_type,$data_processor_name));
+    printf "\nSHEPHERD: Using %s: %s\n",$data_processor_type,$data_processor_name;
 
     my $output = sprintf "%s/%ss/%s/output.xmltv",$CWD,$data_processor_type,$data_processor_name;
@@ -1371 +1367 @@
 
     $comm .= " $input_files";
-    &log("SHEPHERD: Excuting command: $comm\n");
+    printf "SHEPHERD: Excuting command: $comm\n";
 
     my $dir = sprintf "%s/%ss/%s/",$CWD,$data_processor_type,$data_processor_name;
@@ -1379 +1375 @@
 
     if ($retval != 0) {
-        &log("$data_processor_type returned with non-zero return code $retval: assuming it failed.\n");
+        printf "$data_processor_type returned with non-zero return code $retval: assuming it failed.\n";
         return 0;
     }
@@ -1418 +1414 @@
 
     if (!(open(INFILE,"<$input_postprocess_file"))) {
-        &log((sprintf "WARNING: could not open input file \"%s\": %s\n", $input_postprocess_file, $!));
-        &log("Output XMLTV data may be damanged as a result!\n");
+        printf "WARNING: could not open input file \"%s\": %s\n", $input_postprocess_file, $!;
+        printf "Output XMLTV data may be damanged as a result!\n";
     } else {
         while (<INFILE>) {
@@ -1428 +1424 @@
     }
 
-    &log("Final output stored in $output_filename.\n");
+    printf "Final output stored in $output_filename.\n";
 }
 
@@ -1489 +1485 @@
 }
 
-sub open_logfile
-{
-    printf "Logging to $log_file.\n";
-    open(LOG_FILE,">>$log_file") || die "can't open log file $log_file for writing: $!\n";
-
-    my $now = localtime(time);
-    printf LOG_FILE "$progname version $version started at $now\n\n";
-}
-
-sub close_logfile
-{
-    close(LOG_FILE);
-}
-
-sub log
-{
-    my $entry = shift;
-    print $entry;
-    printf LOG_FILE "%s",$entry unless $opt->{nolog};
-}
-
 sub call_prog
 {
     my $prog = shift;
     if (!(open(PROG,"$prog|"))) {
-        &log("warning: couldn't exec \"$prog\": $!\n");
+        printf "warning: couldn't exec \"$prog\": $!\n";
         return -1;
     }
     while(<PROG>) {
-        &log($_);
+        printf $_;
     }
     close(PROG);
 
     if ($? == -1) {
-        &log("Failed to execute prog: $!\n");
+        printf "Failed to execute prog: $!\n";
         return -1;
     } elsif ($? & 127) {
-        &log((sprintf "prog died with signal %d, %s coredump\n",
-          ($? & 127),  ($? & 128) ? "with" : "without"));
+        printf "prog died with signal %d, %s coredump\n",
+          ($? & 127),  (($? & 128) ? "with" : "without");
         return $?;
     } else {
-        &log((sprintf "prog exited with value %d\n", $? >> 8)) if ($debug or $?);
+        printf "prog exited with value %d\n", ($? >> 8) if ($debug or $?);
         return ($? >> 8);
     }
@@ -1633 +1608 @@
               'enable=s'        => \$opt->{enable},
 
-              'nolog'           => \$opt->{nolog},
-
               'days=i'          => \$days,
               'offset=i'        => \$opt->{offset},
@@ -1694 +1667 @@
     --capabilities        Report capabilities to XMLTV
 
-    --nolog               Don't write a logfile
 };
     exit 0;
@@ -1710 +1682 @@
     # check if we are in an eval()
     if ($^S) {
-        printf STDERR "  shepherd caught a die() within eval{} from file $file line $line\n";
+        printf "  shepherd caught a die() within eval{} from file $file line $line\n";
     } else {
-            printf STDERR "\nDIE: line %d in file %s\n",$line,$file;
+            printf "\nDIE: line %d in file %s\n",$line,$file;
             if ($arg) {
                 CORE::die($arg,@rest);