michael@0: /* This Source Code Form is subject to the terms of the Mozilla Public
michael@0:  * License, v. 2.0. If a copy of the MPL was not distributed with this
michael@0:  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
michael@0: 
michael@0: "use strict";
michael@0: 
michael@0: const Cu = Components.utils;
michael@0: const Cc = Components.classes;
michael@0: const Ci = Components.interfaces;
michael@0: 
michael@0: Cu.import("resource://gre/modules/osfile.jsm");
michael@0: Cu.import("resource://gre/modules/Promise.jsm");
michael@0: 
michael@0: // Make it possible to mock out timers for testing
michael@0: let MakeTimer = () => Cc["@mozilla.org/timer;1"].createInstance(Ci.nsITimer);
michael@0: 
michael@0: this.EXPORTED_SYMBOLS = ["DeferredSave"];
michael@0: 
michael@0: // If delay parameter is not provided, default is 50 milliseconds.
michael@0: const DEFAULT_SAVE_DELAY_MS = 50;
michael@0: 
michael@0: Cu.import("resource://gre/modules/Log.jsm");
michael@0: //Configure a logger at the parent 'DeferredSave' level to format
michael@0: //messages for all the modules under DeferredSave.*
michael@0: const DEFERREDSAVE_PARENT_LOGGER_ID = "DeferredSave";
michael@0: let parentLogger = Log.repository.getLogger(DEFERREDSAVE_PARENT_LOGGER_ID);
michael@0: parentLogger.level = Log.Level.Warn;
michael@0: let formatter = new Log.BasicFormatter();
michael@0: //Set parent logger (and its children) to append to
michael@0: //the Javascript section of the Browser Console
michael@0: parentLogger.addAppender(new Log.ConsoleAppender(formatter));
michael@0: //Set parent logger (and its children) to
michael@0: //also append to standard out
michael@0: parentLogger.addAppender(new Log.DumpAppender(formatter));
michael@0: 
michael@0: //Provide the ability to enable/disable logging
michael@0: //messages at runtime.
michael@0: //If the "extensions.logging.enabled" preference is
michael@0: //missing or 'false', messages at the WARNING and higher
michael@0: //severity should be logged to the JS console and standard error.
michael@0: //If "extensions.logging.enabled" is set to 'true', messages
michael@0: //at DEBUG and higher should go to JS console and standard error.
michael@0: Cu.import("resource://gre/modules/Services.jsm");
michael@0: 
michael@0: const PREF_LOGGING_ENABLED = "extensions.logging.enabled";
michael@0: const NS_PREFBRANCH_PREFCHANGE_TOPIC_ID = "nsPref:changed";
michael@0: 
michael@0: /**
michael@0: * Preference listener which listens for a change in the
michael@0: * "extensions.logging.enabled" preference and changes the logging level of the
michael@0: * parent 'addons' level logger accordingly.
michael@0: */
michael@0: var PrefObserver = {
michael@0:  init: function PrefObserver_init() {
michael@0:    Services.prefs.addObserver(PREF_LOGGING_ENABLED, this, false);
michael@0:    Services.obs.addObserver(this, "xpcom-shutdown", false);
michael@0:    this.observe(null, NS_PREFBRANCH_PREFCHANGE_TOPIC_ID, PREF_LOGGING_ENABLED);
michael@0:  },
michael@0: 
michael@0:  observe: function PrefObserver_observe(aSubject, aTopic, aData) {
michael@0:    if (aTopic == "xpcom-shutdown") {
michael@0:      Services.prefs.removeObserver(PREF_LOGGING_ENABLED, this);
michael@0:      Services.obs.removeObserver(this, "xpcom-shutdown");
michael@0:    }
michael@0:    else if (aTopic == NS_PREFBRANCH_PREFCHANGE_TOPIC_ID) {
michael@0:      let debugLogEnabled = false;
michael@0:      try {
michael@0:        debugLogEnabled = Services.prefs.getBoolPref(PREF_LOGGING_ENABLED);
michael@0:      }
michael@0:      catch (e) {
michael@0:      }
michael@0:      if (debugLogEnabled) {
michael@0:        parentLogger.level = Log.Level.Debug;
michael@0:      }
michael@0:      else {
michael@0:        parentLogger.level = Log.Level.Warn;
michael@0:      }
michael@0:    }
michael@0:  }
michael@0: };
michael@0: 
michael@0: PrefObserver.init();
michael@0: 
michael@0: /**
michael@0:  * A module to manage deferred, asynchronous writing of data files
michael@0:  * to disk. Writing is deferred by waiting for a specified delay after
michael@0:  * a request to save the data, before beginning to write. If more than
michael@0:  * one save request is received during the delay, all requests are
michael@0:  * fulfilled by a single write.
michael@0:  *
michael@0:  * @constructor
michael@0:  * @param aPath
michael@0:  *        String representing the full path of the file where the data
michael@0:  *        is to be written.
michael@0:  * @param aDataProvider
michael@0:  *        Callback function that takes no argument and returns the data to
michael@0:  *        be written. If aDataProvider returns an ArrayBufferView, the
michael@0:  *        bytes it contains are written to the file as is.
michael@0:  *        If aDataProvider returns a String the data are UTF-8 encoded
michael@0:  *        and then written to the file.
michael@0:  * @param [optional] aDelay
michael@0:  *        The delay in milliseconds between the first saveChanges() call
michael@0:  *        that marks the data as needing to be saved, and when the DeferredSave
michael@0:  *        begins writing the data to disk. Default 50 milliseconds.
michael@0:  */
michael@0: this.DeferredSave = function (aPath, aDataProvider, aDelay) {
michael@0:   // Create a new logger (child of 'DeferredSave' logger)
michael@0:   // for use by this particular instance of DeferredSave object
michael@0:   let leafName = OS.Path.basename(aPath);
michael@0:   let logger_id = DEFERREDSAVE_PARENT_LOGGER_ID + "." + leafName;
michael@0:   this.logger = Log.repository.getLogger(logger_id);
michael@0: 
michael@0:   // @type {Deferred|null}, null when no data needs to be written
michael@0:   // @resolves with the result of OS.File.writeAtomic when all writes complete
michael@0:   // @rejects with the error from OS.File.writeAtomic if the write fails,
michael@0:   //          or with the error from aDataProvider() if that throws.
michael@0:   this._pending = null;
michael@0: 
michael@0:   // @type {Promise}, completes when the in-progress write (if any) completes,
michael@0:   //       kept as a resolved promise at other times to simplify logic.
michael@0:   //       Because _deferredSave() always uses _writing.then() to execute
michael@0:   //       its next action, we don't need a special case for whether a write
michael@0:   //       is in progress - if the previous write is complete (and the _writing
michael@0:   //       promise is already resolved/rejected), _writing.then() starts
michael@0:   //       the next action immediately.
michael@0:   //
michael@0:   // @resolves with the result of OS.File.writeAtomic
michael@0:   // @rejects with the error from OS.File.writeAtomic
michael@0:   this._writing = Promise.resolve(0);
michael@0: 
michael@0:   // Are we currently waiting for a write to complete
michael@0:   this.writeInProgress = false;
michael@0: 
michael@0:   this._path = aPath;
michael@0:   this._dataProvider = aDataProvider;
michael@0: 
michael@0:   this._timer = null;
michael@0: 
michael@0:   // Some counters for telemetry
michael@0:   // The total number of times the file was written
michael@0:   this.totalSaves = 0;
michael@0: 
michael@0:   // The number of times the data became dirty while
michael@0:   // another save was in progress
michael@0:   this.overlappedSaves = 0;
michael@0: 
michael@0:   // Error returned by the most recent write (if any)
michael@0:   this._lastError = null;
michael@0: 
michael@0:   if (aDelay && (aDelay > 0))
michael@0:     this._delay = aDelay;
michael@0:   else
michael@0:     this._delay = DEFAULT_SAVE_DELAY_MS;
michael@0: }
michael@0: 
michael@0: this.DeferredSave.prototype = {
michael@0:   get dirty() {
michael@0:     return this._pending || this.writeInProgress;
michael@0:   },
michael@0: 
michael@0:   get lastError() {
michael@0:     return this._lastError;
michael@0:   },
michael@0: 
michael@0:   // Start the pending timer if data is dirty
michael@0:   _startTimer: function() {
michael@0:     if (!this._pending) {
michael@0:       return;
michael@0:     }
michael@0: 
michael@0:       this.logger.debug("Starting timer");
michael@0:     if (!this._timer)
michael@0:       this._timer = MakeTimer();
michael@0:     this._timer.initWithCallback(() => this._deferredSave(),
michael@0:                                  this._delay, Ci.nsITimer.TYPE_ONE_SHOT);
michael@0:   },
michael@0: 
michael@0:   /**
michael@0:    * Mark the current stored data dirty, and schedule a flush to disk
michael@0:    * @return A Promise<integer> that will be resolved after the data is written to disk;
michael@0:    *         the promise is resolved with the number of bytes written.
michael@0:    */
michael@0:   saveChanges: function() {
michael@0:       this.logger.debug("Save changes");
michael@0:     if (!this._pending) {
michael@0:       if (this.writeInProgress) {
michael@0:           this.logger.debug("Data changed while write in progress");
michael@0:         this.overlappedSaves++;
michael@0:       }
michael@0:       this._pending = Promise.defer();
michael@0:       // Wait until the most recent write completes or fails (if it hasn't already)
michael@0:       // and then restart our timer
michael@0:       this._writing.then(count => this._startTimer(), error => this._startTimer());
michael@0:     }
michael@0:     return this._pending.promise;
michael@0:   },
michael@0: 
michael@0:   _deferredSave: function() {
michael@0:     let pending = this._pending;
michael@0:     this._pending = null;
michael@0:     let writing = this._writing;
michael@0:     this._writing = pending.promise;
michael@0: 
michael@0:     // In either the success or the exception handling case, we don't need to handle
michael@0:     // the error from _writing here; it's already being handled in another then()
michael@0:     let toSave = null;
michael@0:     try {
michael@0:       toSave = this._dataProvider();
michael@0:     }
michael@0:     catch(e) {
michael@0:         this.logger.error("Deferred save dataProvider failed", e);
michael@0:       writing.then(null, error => {})
michael@0:         .then(count => {
michael@0:           pending.reject(e);
michael@0:         });
michael@0:       return;
michael@0:     }
michael@0: 
michael@0:     writing.then(null, error => {return 0;})
michael@0:     .then(count => {
michael@0:         this.logger.debug("Starting write");
michael@0:       this.totalSaves++;
michael@0:       this.writeInProgress = true;
michael@0: 
michael@0:       OS.File.writeAtomic(this._path, toSave, {tmpPath: this._path + ".tmp"})
michael@0:       .then(
michael@0:         result => {
michael@0:           this._lastError = null;
michael@0:           this.writeInProgress = false;
michael@0:               this.logger.debug("Write succeeded");
michael@0:           pending.resolve(result);
michael@0:         },
michael@0:         error => {
michael@0:           this._lastError = error;
michael@0:           this.writeInProgress = false;
michael@0:               this.logger.warn("Write failed", error);
michael@0:           pending.reject(error);
michael@0:         });
michael@0:     });
michael@0:   },
michael@0: 
michael@0:   /**
michael@0:    * Immediately save the dirty data to disk, skipping
michael@0:    * the delay of normal operation. Note that the write
michael@0:    * still happens asynchronously in the worker
michael@0:    * thread from OS.File.
michael@0:    *
michael@0:    * There are four possible situations:
michael@0:    * 1) Nothing to flush
michael@0:    * 2) Data is not currently being written, in-memory copy is dirty
michael@0:    * 3) Data is currently being written, in-memory copy is clean
michael@0:    * 4) Data is being written and in-memory copy is dirty
michael@0:    *
michael@0:    * @return Promise<integer> that will resolve when all in-memory data
michael@0:    *         has finished being flushed, returning the number of bytes
michael@0:    *         written. If all in-memory data is clean, completes with the
michael@0:    *         result of the most recent write.
michael@0:    */
michael@0:   flush: function() {
michael@0:     // If we have pending changes, cancel our timer and set up the write
michael@0:     // immediately (_deferredSave queues the write for after the most
michael@0:     // recent write completes, if it hasn't already)
michael@0:     if (this._pending) {
michael@0:         this.logger.debug("Flush called while data is dirty");
michael@0:       if (this._timer) {
michael@0:         this._timer.cancel();
michael@0:         this._timer = null;
michael@0:       }
michael@0:       this._deferredSave();
michael@0:     }
michael@0: 
michael@0:     return this._writing;
michael@0:   }
michael@0: };