JAL-3628 More Cache.log.debug statements
authorBen Soares <b.soares@dundee.ac.uk>
Sat, 4 Jul 2020 12:17:42 +0000 (13:17 +0100)
committerBen Soares <b.soares@dundee.ac.uk>
Tue, 10 Nov 2020 18:16:05 +0000 (18:16 +0000)
src/jalview/gui/AlignFrame.java
src/jalview/io/BackupFiles.java

index 1f3f409..5b7a201 100644 (file)
@@ -48,6 +48,7 @@ import java.awt.print.PrinterJob;
 import java.beans.PropertyChangeEvent;
 import java.io.File;
 import java.io.FileWriter;
+import java.io.IOException;
 import java.io.PrintWriter;
 import java.net.URL;
 import java.util.ArrayList;
@@ -345,8 +346,8 @@ public class AlignFrame extends GAlignFrame implements DropTargetListener,
    */
   void init()
   {
-//       setBackground(Color.white); // BH 2019
-                 
+    // setBackground(Color.white); // BH 2019
+
     if (!Jalview.isHeadlessMode())
     {
       progressBar = new ProgressBar(this.statusPanel, this.statusBar);
@@ -1241,15 +1242,16 @@ public class AlignFrame extends GAlignFrame implements DropTargetListener,
       String shortName = title;
       if (shortName.indexOf(File.separatorChar) > -1)
       {
-        shortName = shortName.substring(
-                shortName.lastIndexOf(File.separatorChar) + 1);
+        shortName = shortName
+                .substring(shortName.lastIndexOf(File.separatorChar) + 1);
       }
-      lastSaveSuccessful = new Jalview2XML().saveAlignment(this, file, shortName);
-      
+      lastSaveSuccessful = new Jalview2XML().saveAlignment(this, file,
+              shortName);
+
       statusBar.setText(MessageManager.formatMessage(
               "label.successfully_saved_to_file_in_format", new Object[]
               { fileName, format }));
-      
+
       return;
     }
 
@@ -1283,31 +1285,78 @@ public class AlignFrame extends GAlignFrame implements DropTargetListener,
         {
           // create backupfiles object and get new temp filename destination
           boolean doBackup = BackupFiles.getEnabled();
-          BackupFiles backupfiles = doBackup ? new BackupFiles(file) : null;
+          BackupFiles backupfiles = null;
+          if (doBackup)
+          {
+            Cache.log.debug(
+                    "ALIGNFRAME making backupfiles object for " + file);
+            backupfiles = new BackupFiles(file);
+          }
           try
           {
-            String tempFilePath = doBackup ? backupfiles.getTempFilePath() : file;
-                       PrintWriter out = new PrintWriter(
-                    new FileWriter(tempFilePath));
+            String tempFilePath = doBackup ? backupfiles.getTempFilePath()
+                    : file;
+            Cache.log.debug("ALIGNFRAME setting PrintWriter");
+            PrintWriter out = new PrintWriter(new FileWriter(tempFilePath));
+
+            if (backupfiles != null)
+            {
+              Cache.log.debug("ALIGNFRAME using temp file "
+                      + backupfiles.getTempFilePath());
+            }
 
             out.print(output);
+            Cache.log.debug("ALIGNFRAME about to close file");
             out.close();
+            Cache.log.debug("ALIGNFRAME closed file");
             AlignFrame.this.setTitle(file);
             statusBar.setText(MessageManager.formatMessage(
-                  "label.successfully_saved_to_file_in_format", new Object[]
-                  { fileName, format.getName() }));
+                    "label.successfully_saved_to_file_in_format",
+                    new Object[]
+                    { fileName, format.getName() }));
             lastSaveSuccessful = true;
+          } catch (IOException e)
+          {
+            lastSaveSuccessful = false;
+            Cache.log.error(
+                    "ALIGNFRAME Something happened writing the temp file");
+            Cache.log.error(e.getMessage());
+            Cache.log.debug(e.getStackTrace());
           } catch (Exception ex)
           {
             lastSaveSuccessful = false;
-            ex.printStackTrace();
+            Cache.log.error(
+                    "ALIGNFRAME Something else happened writing the temp file");
+            Cache.log.error(ex.getMessage());
+            Cache.log.debug(ex.getStackTrace());
           }
 
           if (doBackup)
           {
             backupfiles.setWriteSuccess(lastSaveSuccessful);
+            Cache.log.debug("ALIGNFRAME writing temp file was "
+                    + (lastSaveSuccessful ? "" : "not ") + "successful");
             // do the backup file roll and rename the temp file to actual file
+            Cache.log.debug(
+                    "ALIGNFRAME about to rollBackupsAndRenameTempFile");
             lastSaveSuccessful = backupfiles.rollBackupsAndRenameTempFile();
+            Cache.log.debug(
+                    "ALIGNFRAME performed rollBackupsAndRenameTempFile "
+                            + (lastSaveSuccessful ? "" : "un")
+                            + "successfully");
+          }
+
+          if (!lastSaveSuccessful)
+          {
+            if (!Platform.isHeadless())
+            {
+              JvOptionPane.showInternalMessageDialog(AlignFrame.this,
+                      MessageManager.formatMessage(
+                              "label.couldnt_save_file", new Object[]
+                              { fileName }),
+                      MessageManager.getString("label.error_saving_file"),
+                      JvOptionPane.WARNING_MESSAGE);
+            }
           }
         }
       }
@@ -1489,7 +1538,8 @@ public class AlignFrame extends GAlignFrame implements DropTargetListener,
     final JalviewFileChooser chooser = new JalviewFileChooser(
             jalview.bin.Cache.getProperty("LAST_DIRECTORY"));
     chooser.setFileView(new JalviewFileView());
-    String tooltip = MessageManager.getString("label.load_jalview_annotations");
+    String tooltip = MessageManager
+            .getString("label.load_jalview_annotations");
     chooser.setDialogTitle(tooltip);
     chooser.setToolTipText(tooltip);
     chooser.setResponseHandler(0, new Runnable()
@@ -1782,7 +1832,8 @@ public class AlignFrame extends GAlignFrame implements DropTargetListener,
   }
 
   /**
-   * Calls AlignmentI.moveSelectedSequencesByOne with current sequence selection or the sequence under cursor in keyboard mode 
+   * Calls AlignmentI.moveSelectedSequencesByOne with current sequence selection
+   * or the sequence under cursor in keyboard mode
    * 
    * @param up
    *          or down (if !up)
@@ -1793,23 +1844,25 @@ public class AlignFrame extends GAlignFrame implements DropTargetListener,
 
     if (sg == null)
     {
-      if (viewport.cursorMode) 
+      if (viewport.cursorMode)
       {
         sg = new SequenceGroup();
-        sg.addSequence(viewport.getAlignment()
-                .getSequenceAt(alignPanel.getSeqPanel().seqCanvas.cursorY),false);
-      } else {
+        sg.addSequence(viewport.getAlignment().getSequenceAt(
+                alignPanel.getSeqPanel().seqCanvas.cursorY), false);
+      }
+      else
+      {
         return;
       }
     }
-    
+
     if (sg.getSize() < 1)
     {
-        return;
+      return;
     }
-    
+
     // TODO: JAL-3733 - add an event to the undo buffer for this !
-    
+
     viewport.getAlignment().moveSelectedSequencesByOne(sg,
             viewport.getHiddenRepSequences(), up);
     alignPanel.paintAlignment(true, false);
@@ -2419,56 +2472,61 @@ public class AlignFrame extends GAlignFrame implements DropTargetListener,
       return;
     }
 
-    Runnable okAction = new Runnable() 
-    {
-               @Override
-               public void run() 
-               {
-                   SequenceI[] cut = sg.getSequences()
-                           .toArray(new SequenceI[sg.getSize()]);
-
-                   addHistoryItem(new EditCommand(
-                           MessageManager.getString("label.cut_sequences"), Action.CUT,
-                           cut, sg.getStartRes(), sg.getEndRes() - sg.getStartRes() + 1,
-                           viewport.getAlignment()));
-
-                   viewport.setSelectionGroup(null);
-                   viewport.sendSelection();
-                   viewport.getAlignment().deleteGroup(sg);
-
-                   viewport.firePropertyChange("alignment", null,
-                           viewport.getAlignment().getSequences());
-                   if (viewport.getAlignment().getHeight() < 1)
-                   {
-                     try
-                     {
-                       AlignFrame.this.setClosed(true);
-                     } catch (Exception ex)
-                     {
-                     }
-                   }
-               }};
+    Runnable okAction = new Runnable()
+    {
+      @Override
+      public void run()
+      {
+        SequenceI[] cut = sg.getSequences()
+                .toArray(new SequenceI[sg.getSize()]);
+
+        addHistoryItem(new EditCommand(
+                MessageManager.getString("label.cut_sequences"), Action.CUT,
+                cut, sg.getStartRes(),
+                sg.getEndRes() - sg.getStartRes() + 1,
+                viewport.getAlignment()));
+
+        viewport.setSelectionGroup(null);
+        viewport.sendSelection();
+        viewport.getAlignment().deleteGroup(sg);
+
+        viewport.firePropertyChange("alignment", null,
+                viewport.getAlignment().getSequences());
+        if (viewport.getAlignment().getHeight() < 1)
+        {
+          try
+          {
+            AlignFrame.this.setClosed(true);
+          } catch (Exception ex)
+          {
+          }
+        }
+      }
+    };
 
     /*
      * If the cut affects all sequences, prompt for confirmation
      */
-    boolean wholeHeight = sg.getSize() == viewport.getAlignment().getHeight();
+    boolean wholeHeight = sg.getSize() == viewport.getAlignment()
+            .getHeight();
     boolean wholeWidth = (((sg.getEndRes() - sg.getStartRes())
             + 1) == viewport.getAlignment().getWidth()) ? true : false;
-       if (wholeHeight && wholeWidth)
-       {
-           JvOptionPane dialog = JvOptionPane.newOptionDialog(Desktop.desktop);
-               dialog.setResponseHandler(0, okAction); // 0 = OK_OPTION
-           Object[] options = new Object[] { MessageManager.getString("action.ok"),
-                   MessageManager.getString("action.cancel") };
-               dialog.showDialog(MessageManager.getString("warn.delete_all"),
-                   MessageManager.getString("label.delete_all"),
-                   JvOptionPane.DEFAULT_OPTION, JvOptionPane.PLAIN_MESSAGE, null,
-                   options, options[0]);
-       } else 
-       {
-               okAction.run();
-       }
+    if (wholeHeight && wholeWidth)
+    {
+      JvOptionPane dialog = JvOptionPane.newOptionDialog(Desktop.desktop);
+      dialog.setResponseHandler(0, okAction); // 0 = OK_OPTION
+      Object[] options = new Object[] {
+          MessageManager.getString("action.ok"),
+          MessageManager.getString("action.cancel") };
+      dialog.showDialog(MessageManager.getString("warn.delete_all"),
+              MessageManager.getString("label.delete_all"),
+              JvOptionPane.DEFAULT_OPTION, JvOptionPane.PLAIN_MESSAGE, null,
+              options, options[0]);
+    }
+    else
+    {
+      okAction.run();
+    }
   }
 
   /**
@@ -2640,8 +2698,8 @@ public class AlignFrame extends GAlignFrame implements DropTargetListener,
                 column, viewport.getAlignment());
       }
 
-      setStatus(MessageManager
-              .formatMessage("label.removed_columns", new String[]
+      setStatus(MessageManager.formatMessage("label.removed_columns",
+              new String[]
               { Integer.valueOf(trimRegion.getSize()).toString() }));
 
       addHistoryItem(trimRegion);
@@ -2690,8 +2748,8 @@ public class AlignFrame extends GAlignFrame implements DropTargetListener,
 
     addHistoryItem(removeGapCols);
 
-    setStatus(MessageManager
-            .formatMessage("label.removed_empty_columns", new Object[]
+    setStatus(MessageManager.formatMessage("label.removed_empty_columns",
+            new Object[]
             { Integer.valueOf(removeGapCols.getSize()).toString() }));
 
     // This is to maintain viewport position on first residue
@@ -2812,8 +2870,8 @@ public class AlignFrame extends GAlignFrame implements DropTargetListener,
 
     if (viewport.getViewName() == null)
     {
-      viewport.setViewName(MessageManager
-              .getString("label.view_name_original"));
+      viewport.setViewName(
+              MessageManager.getString("label.view_name_original"));
     }
 
     /*
@@ -3339,7 +3397,7 @@ public class AlignFrame extends GAlignFrame implements DropTargetListener,
       JLabel textLabel = new JLabel();
       textLabel.setText(content);
       textLabel.setBackground(Color.WHITE);
-      
+
       pane = new JPanel(new BorderLayout());
       ((JPanel) pane).setOpaque(true);
       pane.setBackground(Color.WHITE);
@@ -3469,8 +3527,8 @@ public class AlignFrame extends GAlignFrame implements DropTargetListener,
      * otherwise set the chosen colour scheme (or null for 'None')
      */
     ColourSchemeI cs = ColourSchemes.getInstance().getColourScheme(name,
-            viewport,
-            viewport.getAlignment(), viewport.getHiddenRepSequences());
+            viewport, viewport.getAlignment(),
+            viewport.getHiddenRepSequences());
     changeColour(cs);
   }
 
@@ -3853,8 +3911,7 @@ public class AlignFrame extends GAlignFrame implements DropTargetListener,
       Enumeration<String> labels = scoreSorts.keys();
       while (labels.hasMoreElements())
       {
-        addSortByAnnotScoreMenuItem(sortByAnnotScore,
-                labels.nextElement());
+        addSortByAnnotScoreMenuItem(sortByAnnotScore, labels.nextElement());
       }
       sortByAnnotScore.setVisible(scoreSorts.size() > 0);
       scoreSorts.clear();
@@ -4021,7 +4078,7 @@ public class AlignFrame extends GAlignFrame implements DropTargetListener,
     chooser.setToolTipText(
             MessageManager.getString("label.load_tree_file"));
 
-    chooser.setResponseHandler(0,new Runnable()
+    chooser.setResponseHandler(0, new Runnable()
     {
       @Override
       public void run()
@@ -4189,8 +4246,7 @@ public class AlignFrame extends GAlignFrame implements DropTargetListener,
               // Add any secondary structure prediction services
               for (int i = 0, j = secstrpr.size(); i < j; i++)
               {
-                final ext.vamsas.ServiceHandle sh = secstrpr
-                        .get(i);
+                final ext.vamsas.ServiceHandle sh = secstrpr.get(i);
                 jalview.ws.WSMenuEntryProviderI impl = jalview.ws.jws1.Discoverer
                         .getServiceClient(sh);
                 int p = secstrmenu.getItemCount();
@@ -4569,10 +4625,13 @@ public class AlignFrame extends GAlignFrame implements DropTargetListener,
               if (protocol == DataSourceType.FILE)
               {
                 File fl;
-                if (file instanceof File) {
+                if (file instanceof File)
+                {
                   fl = (File) file;
                   Platform.cacheFileData(fl);
-                } else {
+                }
+                else
+                {
                   fl = new File(fileName);
                 }
                 pdbfn = fl.getName();
@@ -5809,6 +5868,7 @@ public class AlignFrame extends GAlignFrame implements DropTargetListener,
   }
 
   private Rectangle lastFeatureSettingsBounds = null;
+
   @Override
   public void setFeatureSettingsGeometry(Rectangle bounds)
   {
index 1c8525b..91cc5fa 100644 (file)
  */
 package jalview.io;
 
-import jalview.bin.Cache;
-import jalview.gui.Desktop;
-import jalview.gui.JvOptionPane;
-import jalview.util.MessageManager;
-import jalview.util.Platform;
-
 import java.io.File;
 import java.io.IOException;
 import java.nio.file.Files;
@@ -42,6 +36,7 @@ import jalview.bin.Cache;
 import jalview.gui.Desktop;
 import jalview.gui.JvOptionPane;
 import jalview.util.MessageManager;
+import jalview.util.Platform;
 
 /*
  * BackupFiles used for manipulating (naming rolling/deleting) backup/version files when an alignment or project file is saved.
@@ -136,26 +131,37 @@ public class BackupFiles
       {
         String tempfilename = file.getName();
         File tempdir = file.getParentFile();
+        Cache.log.debug(
+                "BACKUPFILES [file!=null] attempting to create temp file "
+                        + tempfilename + " in dir " + tempdir);
         temp = File.createTempFile(tempfilename,
                 TEMP_FILE_EXT + newTempFileSuffix, tempdir);
       }
       else
       {
+        Cache.log.debug(
+                "BACKUPFILES [file==null] attempting to create default temp file "
+                        + DEFAULT_TEMP_FILE + " with extension "
+                        + TEMP_FILE_EXT);
         temp = File.createTempFile(DEFAULT_TEMP_FILE, TEMP_FILE_EXT);
       }
     } catch (IOException e)
     {
-      System.out.println(
-              "Could not create temp file to save into (IOException)");
+      Cache.log
+              .error("Could not create temp file to save to (IOException)");
+      Cache.log.error(e.getMessage());
+      Cache.log.debug(e.getStackTrace());
     } catch (Exception e)
     {
-      System.out.println("Exception ctreating temp file for saving");
+      Cache.log.error("Exception creating temp file for saving");
+      Cache.log.debug(e.getStackTrace());
     }
     this.setTempFile(temp);
   }
 
   public static void classInit()
   {
+    Cache.log.debug("BACKUPFILES classInit");
     setEnabled(Cache.getDefault(ENABLED, !Platform.isJS()));
     BackupFilesPresetEntry bfpe = BackupFilesPresetEntry
             .getSavedBackupEntry();
@@ -203,9 +209,10 @@ public class BackupFiles
       path = this.getTempFile().getCanonicalPath();
     } catch (IOException e)
     {
-      System.out.println(
+      Cache.log.error(
               "IOException when getting Canonical Path of temp file '"
                       + this.getTempFile().getName() + "'");
+      Cache.log.debug(e.getStackTrace());
     }
     return path;
   }
@@ -241,24 +248,35 @@ public class BackupFiles
             || suffix.length() == 0)
     {
       // nothing to do
+      Cache.log.debug("BACKUPFILES rollBackupFiles nothing to do." + ", "
+              + "filename: " + (file != null ? file.getName() : "null")
+              + ", " + "file exists: " + file.exists() + ", " + "enabled: "
+              + enabled + ", " + "max: " + max + ", " + "suffix: '" + suffix
+              + "'");
       return true;
     }
 
+    Cache.log.debug("BACKUPFILES rollBackupFiles starting");
+
     String dir = "";
     File dirFile;
     try
     {
       dirFile = file.getParentFile();
       dir = dirFile.getCanonicalPath();
+      Cache.log.debug("BACKUPFILES dir: " + dir);
     } catch (Exception e)
     {
-      System.out.println(
+      Cache.log.error(
               "Could not get canonical path for file '" + file + "'");
+      Cache.log.error(e.getMessage());
+      Cache.log.debug(e.getStackTrace());
       return false;
     }
     String filename = file.getName();
     String basename = filename;
 
+    Cache.log.debug("BACKUPFILES filename is " + filename);
     boolean ret = true;
     // Create/move backups up one
 
@@ -270,9 +288,13 @@ public class BackupFiles
     File[] backupFiles = dirFile.listFiles(bff);
     int nextIndexNum = 0;
 
+    Cache.log
+            .debug("BACKUPFILES backupFiles.length: " + backupFiles.length);
     if (backupFiles.length == 0)
     {
       // No other backup files. Just need to move existing file to backupfile_1
+      Cache.log.debug(
+              "BACKUPFILES no existing backup files, setting index to 1");
       nextIndexNum = 1;
     }
     else
@@ -285,6 +307,7 @@ public class BackupFiles
       if (reverseOrder)
       {
         // backup style numbering
+        Cache.log.debug("BACKUPFILES rolling files in reverse order");
 
         int tempMax = noMax ? -1 : max;
         // noMax == true means no limits
@@ -316,6 +339,7 @@ public class BackupFiles
             // no "oldest" file to delete
             previousFile = backupfile_n;
             fileToBeDeleted = null;
+            Cache.log.debug("BACKUPFILES No oldest file to delete");
             continue;
           }
 
@@ -326,6 +350,10 @@ public class BackupFiles
             File replacementFile = backupfile_n;
             long fileToBeDeletedLMT = fileToBeDeleted.lastModified();
             long replacementFileLMT = replacementFile.lastModified();
+            Cache.log.debug("BACKUPFILES fileToBeDeleted is "
+                    + fileToBeDeleted.getAbsolutePath());
+            Cache.log.debug("BACKUPFILES replacementFile is "
+                    + backupfile_n.getAbsolutePath());
 
             try
             {
@@ -338,7 +366,7 @@ public class BackupFiles
                         .format(fileToBeDeletedLMT);
                 String replacementFileLMTString = sdf
                         .format(replacementFileLMT);
-                System.out.println("WARNING! I am set to delete backupfile "
+                Cache.log.warn("WARNING! I am set to delete backupfile "
                         + fileToBeDeleted.getName()
                         + " has modification time "
                         + fileToBeDeletedLMTString
@@ -349,6 +377,11 @@ public class BackupFiles
 
                 boolean delete = confirmNewerDeleteFile(fileToBeDeleted,
                         replacementFile, true);
+                Cache.log.debug("BACKUPFILES "
+                        + (delete ? "confirmed" : "not") + " deleting file "
+                        + fileToBeDeleted.getAbsolutePath()
+                        + " which is newer than "
+                        + replacementFile.getAbsolutePath());
 
                 if (delete)
                 {
@@ -357,21 +390,27 @@ public class BackupFiles
                 }
                 else
                 {
+                  Cache.log.debug("BACKUPFILES moving "
+                          + fileToBeDeleted.getAbsolutePath() + " to "
+                          + oldestTempFile.getAbsolutePath());
                   moveFileToFile(fileToBeDeleted, oldestTempFile);
                 }
               }
               else
               {
+                Cache.log.debug("BACKUPFILES going to move "
+                        + fileToBeDeleted.getAbsolutePath() + " to "
+                        + oldestTempFile.getAbsolutePath());
                 moveFileToFile(fileToBeDeleted, oldestTempFile);
                 addDeleteFile(oldestTempFile);
               }
 
             } catch (Exception e)
             {
-              System.out.println(
+              Cache.log.error(
                       "Error occurred, probably making new temp file for '"
                               + fileToBeDeleted.getName() + "'");
-              e.printStackTrace();
+              Cache.log.error(e.getStackTrace());
             }
 
             // reset
@@ -396,19 +435,37 @@ public class BackupFiles
         // index to use for the latest backup
         nextIndexNum = 1;
       }
-      else
+      else // not reverse numbering
       {
         // version style numbering (with earliest file deletion if max files
         // reached)
 
         bfTreeMap.values().toArray(backupFiles);
+        StringBuilder bfsb = new StringBuilder();
+        for (int i = 0; i < backupFiles.length; i++)
+        {
+          if (bfsb.length() > 0)
+          {
+            bfsb.append(", ");
+          }
+          bfsb.append(backupFiles[i].getName());
+        }
+        Cache.log.debug("BACKUPFILES backupFiles: " + bfsb.toString());
 
         // noMax == true means keep all backup files
         if ((!noMax) && bfTreeMap.size() >= max)
         {
+          Cache.log.debug("BACKUPFILES noMax: " + noMax + ", " + "max: "
+                  + max + ", " + "bfTreeMap.size(): " + bfTreeMap.size());
           // need to delete some files to keep number of backups to designated
-          // max
-          int numToDelete = bfTreeMap.size() - max + 1;
+          // max.
+          // Note that if the suffix is not numbered then do not delete any
+          // backup files later or we'll delete the new backup file (there can
+          // be only one).
+          int numToDelete = suffix.indexOf(NUM_PLACEHOLDER) > -1
+                  ? bfTreeMap.size() - max + 1
+                  : 0;
+          Cache.log.debug("BACKUPFILES numToDelete: " + numToDelete);
           // the "replacement" file is the latest backup file being kept (it's
           // not replacing though)
           File replacementFile = numToDelete < backupFiles.length
@@ -421,6 +478,9 @@ public class BackupFiles
             File fileToBeDeleted = backupFiles[i];
             boolean delete = true;
 
+            Cache.log.debug(
+                    "BACKUPFILES fileToBeDeleted: " + fileToBeDeleted);
+
             boolean newer = false;
             if (replacementFile != null)
             {
@@ -435,14 +495,13 @@ public class BackupFiles
                 String replacementFileLMTString = sdf
                         .format(replacementFileLMT);
 
-                System.out
-                        .println("WARNING! I am set to delete backupfile '"
-                                + fileToBeDeleted.getName()
-                                + "' has modification time "
+                Cache.log.warn("WARNING! I am set to delete backupfile '"
+                        + fileToBeDeleted.getName()
+                        + "' has modification time "
                         + fileToBeDeletedLMTString
-                                + " which is newer than the oldest backupfile being kept '"
+                        + " which is newer than the oldest backupfile being kept '"
                         + replacementFile.getName()
-                                + "' with modification time "
+                        + "' with modification time "
                         + replacementFileLMTString);
 
                 delete = confirmNewerDeleteFile(fileToBeDeleted,
@@ -451,17 +510,23 @@ public class BackupFiles
                 {
                   // User has confirmed delete -- no need to add it to the list
                   fileToBeDeleted.delete();
+                  Cache.log.debug("BACKUPFILES deleting fileToBeDeleted: "
+                          + fileToBeDeleted);
                   delete = false;
                 }
                 else
                 {
                   // keeping file, nothing to do!
+                  Cache.log.debug("BACKUPFILES keeping fileToBeDeleted: "
+                          + fileToBeDeleted);
                 }
               }
             }
             if (delete)
             {
               addDeleteFile(fileToBeDeleted);
+              Cache.log.debug("BACKUPFILES addDeleteFile(fileToBeDeleted): "
+                      + fileToBeDeleted);
             }
 
           }
@@ -476,10 +541,15 @@ public class BackupFiles
     String latestBackupFilename = dir + File.separatorChar
             + BackupFilenameParts.getBackupFilename(nextIndexNum, basename,
                     suffix, digits);
+    Cache.log.debug("BACKUPFILES Moving old file [" + file
+            + "] to latestBackupFilename [" + latestBackupFilename + "]");
     ret |= moveFileToFile(file, new File(latestBackupFilename));
+    Cache.log.debug("BACKUPFILES moving " + latestBackupFilename + " to "
+            + file + " was " + (ret ? "" : "NOT ") + "successful");
 
     if (tidyUp)
     {
+      Cache.log.debug("BACKUPFILES tidying up files");
       tidyUpFiles();
     }
 
@@ -535,7 +605,7 @@ public class BackupFiles
         saveFile = nextTempFile(ftbd.getName(), ftbd.getParentFile());
       } catch (Exception e)
       {
-        System.out.println(
+        Cache.log.error(
                 "Error when confirming to keep backup file newer than other backup files.");
         e.printStackTrace();
       }
@@ -543,19 +613,27 @@ public class BackupFiles
               "label.newerdelete_replacement_line", new String[]
               { ftbd.getName(), rf.getName(), ftbdLMT, rfLMT, ftbdSize,
                   rfSize }));
+      // "Backup file\n''{0}''\t(modified {2}, size {4})\nis to be deleted and
+      // replaced by apparently older file \n''{1}''\t(modified {3}, size
+      // {5}).""
       messageSB.append("\n\n");
       messageSB.append(MessageManager.formatMessage(
               "label.confirm_deletion_or_rename", new String[]
               { ftbd.getName(), saveFile.getName() }));
+      // "Confirm deletion of ''{0}'' or rename to ''{1}''?"
       String[] options = new String[] {
           MessageManager.getString("label.delete"),
           MessageManager.getString("label.rename") };
 
-      confirmButton = JvOptionPane.showOptionDialog(Desktop.desktop,
-              messageSB.toString(),
-              MessageManager.getString("label.backupfiles_confirm_delete"),
-              JvOptionPane.YES_NO_OPTION, JvOptionPane.WARNING_MESSAGE,
-              null, options, options[0]);
+      confirmButton = Platform.isHeadless() ? JvOptionPane.YES_OPTION
+              : JvOptionPane.showOptionDialog(Desktop.desktop,
+                      messageSB.toString(),
+                      MessageManager.getString(
+                              "label.backupfiles_confirm_delete"),
+                      // "Confirm delete"
+                      JvOptionPane.YES_NO_OPTION,
+                      JvOptionPane.WARNING_MESSAGE, null, options,
+                      options[0]);
     }
     else
     {
@@ -563,19 +641,27 @@ public class BackupFiles
               .formatMessage("label.newerdelete_line", new String[]
               { ftbd.getName(), rf.getName(), ftbdLMT, rfLMT, ftbdSize,
                   rfSize }));
+      // "Backup file\n''{0}''\t(modified {2}, size {4})\nis to be deleted but
+      // is newer than the oldest remaining backup file \n''{1}''\t(modified
+      // {3}, size {5})."
       messageSB.append("\n\n");
       messageSB.append(MessageManager
               .formatMessage("label.confirm_deletion", new String[]
               { ftbd.getName() }));
+      // "Confirm deletion of ''{0}''?"
       String[] options = new String[] {
           MessageManager.getString("label.delete"),
           MessageManager.getString("label.keep") };
 
-      confirmButton = JvOptionPane.showOptionDialog(Desktop.desktop,
-              messageSB.toString(),
-              MessageManager.getString("label.backupfiles_confirm_delete"),
-              JvOptionPane.YES_NO_OPTION, JvOptionPane.WARNING_MESSAGE,
-              null, options, options[0]);
+      confirmButton = Platform.isHeadless() ? JvOptionPane.YES_OPTION
+              : JvOptionPane.showOptionDialog(Desktop.desktop,
+                      messageSB.toString(),
+                      MessageManager.getString(
+                              "label.backupfiles_confirm_delete"),
+                      // "Confirm delete"
+                      JvOptionPane.YES_NO_OPTION,
+                      JvOptionPane.WARNING_MESSAGE, null, options,
+                      options[0]);
     }
 
     // return should be TRUE if file is to be deleted
@@ -593,6 +679,8 @@ public class BackupFiles
         messageSB = new StringBuilder();
         messageSB.append(MessageManager
                 .getString("label.backupfiles_confirm_delete_old_files"));
+        // "Delete the following older backup files? (see the Backups tab in
+        // Preferences for more options)"
         for (int i = 0; i < deleteFiles.size(); i++)
         {
           File df = deleteFiles.get(i);
@@ -603,13 +691,17 @@ public class BackupFiles
                   new String[]
                   { sdf.format(df.lastModified()),
                       Long.toString(df.length()) }));
+          // "(modified {0}, size {1})"
         }
 
-        int confirmButton = JvOptionPane.showConfirmDialog(Desktop.desktop,
-                messageSB.toString(),
-                MessageManager
-                        .getString("label.backupfiles_confirm_delete"),
-                JvOptionPane.YES_NO_OPTION, JvOptionPane.WARNING_MESSAGE);
+        int confirmButton = Platform.isHeadless() ? JvOptionPane.YES_OPTION
+                : JvOptionPane.showConfirmDialog(Desktop.desktop,
+                        messageSB.toString(),
+                        MessageManager.getString(
+                                "label.backupfiles_confirm_delete"),
+                        // "Confirm delete"
+                        JvOptionPane.YES_NO_OPTION,
+                        JvOptionPane.WARNING_MESSAGE);
 
         doDelete = (confirmButton == JvOptionPane.YES_OPTION);
       }
@@ -623,8 +715,10 @@ public class BackupFiles
         for (int i = 0; i < deleteFiles.size(); i++)
         {
           File fileToDelete = deleteFiles.get(i);
+          Cache.log.debug(
+                  "BACKUPFILES deleting fileToDelete:" + fileToDelete);
           fileToDelete.delete();
-          System.out.println("DELETING '" + fileToDelete.getName() + "'");
+          Cache.log.warn("deleting '" + fileToDelete.getName() + "'");
         }
       }
 
@@ -659,7 +753,7 @@ public class BackupFiles
     boolean rename = false;
     if (write)
     {
-      roll = this.rollBackupFiles(false);
+      roll = this.rollBackupFiles(false); // tidyUpFiles at the end
       rename = this.renameTempFile();
     }
 
@@ -675,6 +769,7 @@ public class BackupFiles
       StringBuilder messageSB = new StringBuilder();
       messageSB.append(MessageManager.getString(
               "label.backupfiles_confirm_save_file_backupfiles_roll_wrong"));
+      // "Something possibly went wrong with the backups of this file."
       if (rename)
       {
         if (messageSB.length() > 0)
@@ -683,6 +778,7 @@ public class BackupFiles
         }
         messageSB.append(MessageManager.getString(
                 "label.backupfiles_confirm_save_new_saved_file_ok"));
+        // "The new saved file seems okay."
       }
       else
       {
@@ -692,13 +788,16 @@ public class BackupFiles
         }
         messageSB.append(MessageManager.getString(
                 "label.backupfiles_confirm_save_new_saved_file_not_ok"));
+        // "The new saved file might not be okay."
       }
 
-      int confirmButton = JvOptionPane.showConfirmDialog(Desktop.desktop,
-              messageSB.toString(),
-              MessageManager
-                      .getString("label.backupfiles_confirm_save_file"),
-              JvOptionPane.OK_OPTION, JvOptionPane.WARNING_MESSAGE);
+      int confirmButton = Platform.isHeadless() ? JvOptionPane.OK_OPTION
+              : JvOptionPane.showConfirmDialog(Desktop.desktop,
+                      messageSB.toString(),
+                      MessageManager.getString(
+                              "label.backupfiles_confirm_save_file"),
+                      // "Confirm save file"
+                      JvOptionPane.OK_OPTION, JvOptionPane.WARNING_MESSAGE);
       okay = confirmButton == JvOptionPane.OK_OPTION;
     }
     if (okay)
@@ -722,7 +821,7 @@ public class BackupFiles
       dirFile = file.getParentFile();
     } catch (Exception e)
     {
-      System.out.println(
+      Cache.log.error(
               "Could not get canonical path for file '" + file + "'");
       return new TreeMap<>();
     }
@@ -764,10 +863,15 @@ public class BackupFiles
     int pos = deleteFiles.indexOf(fileToBeDeleted);
     if (pos > -1)
     {
+      Cache.log.debug("BACKUPFILES not adding file "
+              + fileToBeDeleted.getAbsolutePath()
+              + " to the delete list (already at index" + pos + ")");
       return true;
     }
     else
     {
+      Cache.log.debug("BACKUPFILES adding file "
+              + fileToBeDeleted.getAbsolutePath() + " to the delete list");
       deleteFiles.add(fileToBeDeleted);
     }
     return ret;
@@ -780,12 +884,25 @@ public class BackupFiles
     Path newPath = Paths.get(newFile.getAbsolutePath());
     try
     {
+      // delete destination file - not usually necessary but Just In Case...
+      Cache.log.debug("BACKUPFILES deleting " + newFile.getAbsolutePath());
+      newFile.delete();
+      Cache.log.debug("BACKUPFILES moving " + oldFile.getAbsolutePath()
+              + " to " + newFile.getAbsolutePath());
       Files.move(oldPath, newPath, StandardCopyOption.REPLACE_EXISTING);
       ret = true;
+      Cache.log.debug("BACKUPFILES move seemse to have succeeded");
     } catch (IOException e)
     {
       Cache.log.warn("Could not move file '" + oldPath.toString() + "' to '"
               + newPath.toString() + "'");
+      Cache.log.error(e.getMessage());
+      Cache.log.debug(e.getStackTrace());
+      ret = false;
+    } catch (Exception e)
+    {
+      Cache.log.error(e.getMessage());
+      Cache.log.debug(e.getStackTrace());
       ret = false;
     }
     return ret;