add more log messages

AlternativePlayCount/Common.pm

@@ -88,7 +88,7 @@ sub createBackup {
 		main::DEBUGLOG && $log->is_debug && $log->debug('Found '.$trackcount.($trackcount == 1 ? ' track' : ' tracks').' with values in the APC database');
 
 		print $output "<?xml version=\"1.0\" encoding=\"UTF-8\" ?>\n";
-		print $output "<!-- Backup of APC Database Values -->\n";
+		print $output "<!-- Backup of APC database values for ".$trackcount.($trackcount == 1 ? " track" : " tracks")." -->\n";
 		print $output "<!-- ".$backuptimestamp." -->\n";
 		print $output "<AlternativePlayCount>\n";
 		for my $APCTrack (@APCTracks) {
@@ -112,15 +112,13 @@ sub createBackup {
 			print $output "\t<track>\n\t\t<url>".$BACKUPtrackURL."</url>\n\t\t<urlmd5>".$BACKUPtrackURLmd5."</urlmd5>\n\t\t<relurl>".$BACKUPrelFilePath."</relurl>\n\t\t<playcount>".$BACKUPplayCount."</playcount>\n\t\t<lastplayed>".$BACKUPlastPlayed."</lastplayed>\n\t\t<skipcount>".$BACKUPskipCount."</skipcount>\n\t\t<lastskipped>".$BACKUPlastSkipped."</lastskipped>\n\t\t<dynpsval>".$BACKUPdynPSval."</dynpsval>\n\t\t<remote>".$BACKUPremote."</remote>\n\t\t<musicbrainzid>".$BACKUPtrackMBID."</musicbrainzid>\n\t</track>\n";
 		}
 		print $output "</AlternativePlayCount>\n";
-
-		print $output "<!-- This backup contains ".$trackcount.($trackcount == 1 ? " track" : " tracks")." -->\n";
 		close $output;
 		my $ended = time() - $started;
 		main::DEBUGLOG && $log->is_debug && $log->debug('Backup completed after '.$ended.' seconds.');
 
 		cleanupBackups();
 	} else {
-		main::DEBUGLOG && $log->is_debug && $log->debug('Info: no tracks in APC database');
+		main::INFOLOG && $log->is_info && $log->info('No tracks with play/skip counts in APC database');
 	}
 	$prefs->set('status_creatingbackup', 0);
 }

AlternativePlayCount/Plugin.pm

@@ -56,7 +56,7 @@ my $serverPrefs = preferences('server');
 my $prefs = preferences('plugin.alternativeplaycount');
 
 my ($ratingslight_enabled, %restoreitem, $currentKey, $inTrack, $inValue, $backupParser, $backupParserNB, $restorestarted, %itemNames);
-my $opened = 0;
+my ($opened, $restoreCount) = 0;
 
 sub initPlugin {
 	my $class = shift;
@@ -926,13 +926,15 @@ sub restoreFromBackup {
 	}
 
 	$prefs->set('status_restoringfrombackup', 1);
+	$restoreCount = 0;
 	$restorestarted = time();
 	my $restorefile = $prefs->get('restorefile');
 
 	if ($restorefile) {
 		if ($clearallbeforerestore) {
 			resetAPCDatabase(1);
 		}
+		main::INFOLOG && $log->is_info && $log->info('Starting restore from backup file');
 		initRestore();
 		Slim::Utils::Scheduler::add_task(\&restoreScanFunction);
 	} else {
@@ -1016,7 +1018,7 @@ sub doneScanning {
 	close(BACKUPFILE);
 
 	my $ended = time() - $restorestarted;
-	main::DEBUGLOG && $log->is_debug && $log->debug('Restore completed after '.$ended.' seconds.');
+	main::INFOLOG && $log->is_info && $log->info('Restore completed after '.$ended.' seconds. Restored '.$restoreCount.($restoreCount == 1 ? ' track.' : ' tracks.').' Restore count listed here may be slightly higher (e.g. +1) than the correct number stated in the backup file.');
 	sleep(1.5); # if task is removed too soon from scheduler => undef val as sub ref error
 	Slim::Utils::Scheduler::remove_task(\&restoreScanFunction);
 	$prefs->set('isTSlegacyBackupFile', 0);
@@ -1035,6 +1037,7 @@ sub handleStartElement {
 	}
 	if ($element eq 'TrackStat') {
 		$prefs->set('isTSlegacyBackupFile', 1);
+		main::DEBUGLOG && $log->is_debug && $log->debug('Is TS legacy backup file');
 	}
 }
 
@@ -1117,13 +1120,15 @@ sub handleEndElement {
 				my $playCount = (!$curTrack->{'playCount'} ? "null" : $curTrack->{'playCount'});
 				my $lastPlayed = (!$curTrack->{'lastPlayed'} ? "null" : $curTrack->{'lastPlayed'});
 				$sqlstatement .= "set playCount = $playCount, lastPlayed = $lastPlayed ";
+				main::DEBUGLOG && $log->is_debug && $log->debug("Setting these values for track: playCount = $playCount, lastPlayed = $lastPlayed\n");
 			} else {
 				my $playCount = ($curTrack->{'playcount'} == 0 ? "null" : $curTrack->{'playcount'});
 				my $lastPlayed = ($curTrack->{'lastplayed'} == 0 ? "null" : $curTrack->{'lastplayed'});
 				my $skipCount = ($curTrack->{'skipcount'} == 0 ? "null" : $curTrack->{'skipcount'});
 				my $lastSkipped = ($curTrack->{'lastskipped'} == 0 ? "null" : $curTrack->{'lastskipped'});
 				my $dynPSval = ($curTrack->{'dynpsval'} == 0 ? "null" : $curTrack->{'dynpsval'});
 				$sqlstatement .= "set playCount = $playCount, lastPlayed = $lastPlayed, skipCount = $skipCount, lastSkipped = $lastSkipped, dynPSval = $dynPSval";
+				main::DEBUGLOG && $log->is_debug && $log->debug("Setting these values for track: playCount = $playCount, lastPlayed = $lastPlayed, skipCount = $skipCount, lastSkipped = $lastSkipped, dynPSval = $dynPSval\n");
 			}
 
 			if ($trackURLmd5) {
@@ -1133,6 +1138,7 @@ sub handleEndElement {
 				$sqlstatement .= " where musicbrainz_id = \"$trackMBID\"";
 			}
 			executeSQLstat($sqlstatement);
+			$restoreCount++;
 		}
 		%restoreitem = ();
 	}

AlternativePlayCount/install.xml

@@ -3,7 +3,7 @@
 	<id>af18a10e-3810-ee03-55f4-87cca698a191</id>
 	<name>PLUGIN_ALTERNATIVEPLAYCOUNT</name>
 	<module>Plugins::AlternativePlayCount::Plugin</module>
-	<version>1.5.9</version>
+	<version>1.6.0</version>
 	<description>PLUGIN_ALTERNATIVEPLAYCOUNT_DESC</description>
 	<creator>AF</creator>
 	<importmodule>Plugins::AlternativePlayCount::Importer</importmodule>

AlternativePlayCount/strings.txt

@@ -332,7 +332,7 @@ PLUGIN_ALTERNATIVEPLAYCOUNT_SETTINGS_RESTORE_NOXMLFILE
 	FR	Merci de sélectionner un ficher XML valide créé avec <i>Nombre de Lectures Alternatif</i> !
 
 PLUGIN_ALTERNATIVEPLAYCOUNT_SETTINGS_RESTORE_INPROGESS
-	EN	restoring...
+	EN	preparing to start restore as a background task...
 	FR	restauration...
 
 PLUGIN_ALTERNATIVEPLAYCOUNT_SETTINGS_RESTORE_CLEARALLBEFORE