0027625: Add log to help with the analysis of the underlying processes

# HG changeset patch
# User Rafa Alonso <rafael.alonso@openbravo.com>
# Date 1411057350 -7200
#      Thu Sep 18 18:22:30 2014 +0200
# Node ID fa4a270a95951d6037999e23bed56e139ac3527a
# Parent  66894335d44066e46e68322a52db863a1d7273a7
Issue 27625: Log for underlying processes

diff -r 66894335d440 -r fa4a270a9595 web/org.openbravo.mobile.core/source/component/ob-terminal-component.js
--- a/web/org.openbravo.mobile.core/source/component/ob-terminal-component.js	Thu Sep 18 17:08:02 2014 +0200
+++ b/web/org.openbravo.mobile.core/source/component/ob-terminal-component.js	Thu Sep 18 18:22:30 2014 +0200
@@ -201,6 +201,7 @@
   },
 
   resizeWindow: function () {
+    OB.warn("resizeWindow. Next: none" );
     var winHeight = window.innerHeight,
         winWidth = window.innerWidth,
         percentage, appHeight = 700;
@@ -271,6 +272,7 @@
     //this.inherited(args);
     OB.MobileApp.model.initializeCommonComponents();
     this.terminal.on('initializedCommonComponents', function () {
+      OB.warn("'initializedCommonComponents'. Next: resizeWindow");
       var me = this;
 
       if (!initialized) {
@@ -294,6 +296,7 @@
         }, this);
 
         this.terminal.on('change:connectedToERP', function (model) {
+          OB.UTIL.logConnectivityStatus(model.get('connectedToERP'), 'connectedToERP');
           if (model.get('loggedOffline') !== undefined) {
             if (model.get('connectedToERP')) {
               //We will do an additional request to verify whether the connection is still active or not
diff -r 66894335d440 -r fa4a270a9595 web/org.openbravo.mobile.core/source/data/ob-datasource.js
--- a/web/org.openbravo.mobile.core/source/data/ob-datasource.js	Thu Sep 18 17:08:02 2014 +0200
+++ b/web/org.openbravo.mobile.core/source/data/ob-datasource.js	Thu Sep 18 18:22:30 2014 +0200
@@ -125,6 +125,7 @@
         serviceSuccess(inResponse, callback);
       },
       fail: function (inSender, inResponse) {
+        OB.error("servicePOST fail (" + timeout + "): " + source + ", " + inSender);
         this.processHasFailed = true;
         inResponse = inResponse || {};
         if (inSender && inSender === "timeout") {
@@ -155,6 +156,11 @@
         serviceSuccess(inResponse, callback);
       },
       fail: function (inSender, inResponse) {
+        if (inSender && inSender === 401) {
+          OB.warn("(" + inSender + ") Non authorized: " + source);
+        } else {
+          OB.error("(" + inSender + ") " + source);
+        }
         if (!this.ignoreForConnectionStatus) {
           OB.MobileApp.model.triggerOffLine();
         }
diff -r 66894335d440 -r fa4a270a9595 web/org.openbravo.mobile.core/source/data/ob-model.js
--- a/web/org.openbravo.mobile.core/source/data/ob-model.js	Thu Sep 18 17:08:02 2014 +0200
+++ b/web/org.openbravo.mobile.core/source/data/ob-model.js	Thu Sep 18 18:22:30 2014 +0200
@@ -44,8 +44,11 @@
           handleAs: 'text',
           cacheBust: false
         }).response(function (inSender, inResponse) {
+          OB.warn("registerModel (" + modelParam.prototype.modelName + ") success");
           eval(inResponse);
           modelParam.prototype.structureLoaded = true;
+        }).error(function () {
+          OB.error("Critical: registerModel (" + modelParam.prototype.modelName + ") fail.");
         }).go();
 
         return;
diff -r 66894335d440 -r fa4a270a9595 web/org.openbravo.mobile.core/source/model/ob-terminal-model.js
--- a/web/org.openbravo.mobile.core/source/model/ob-terminal-model.js	Thu Sep 18 17:08:02 2014 +0200
+++ b/web/org.openbravo.mobile.core/source/model/ob-terminal-model.js	Thu Sep 18 18:22:30 2014 +0200
@@ -156,6 +156,7 @@
     this.on('window:ready', this.renderContainerWindow); // When the active window is loaded, the window is rendered with the renderContainerWindow function
     this.on('terminalInfoLoaded', this.processPropertyLoaders);
     this.on('propertiesLoadersReady', function () {
+      OB.warn("propertiesLoadersReady. Next: renderMain");
       this.loadRegisteredWindows();
       this.renderMain();
     }, this);
@@ -206,6 +207,7 @@
   },
 
   processPropertyLoaders: function () {
+    OB.warn("processPropertyLoaders starts. next: allPropertiesLoaded");
     var termInfo;
     if (this.get('loggedOffline')) {
       termInfo = JSON.parse(this.usermodel.get('terminalinfo'));
@@ -246,6 +248,7 @@
   //me.propertiesReady(properties) should be executed by loadFunction of each property
   allPropertiesLoaded: function () {
     OB.info('properties has been loaded successfully', this.attributes);
+    OB.warn("allPropertiesLoaded. Next: 'propertiesLoadersReady' trigger");
     var undef;
     this.loggingIn = false;
     //core
@@ -263,6 +266,7 @@
   },
 
   navigate: function (route) {
+    OB.warn("Navigating to '" + route + "'");
     this.router.navigate(route, {
       trigger: true
     });
@@ -272,6 +276,7 @@
    * Loads registered windows and calls renderMain method implemented by each app
    */
   renderTerminalMain: function () {
+    OB.warn("renderTerminalMain. Next: loadTerminalInfo");
     if (this.renderMain) {
       this.loadTerminalInfo();
     } else {
@@ -283,12 +288,15 @@
    * Loads all needed stuff for the terminal such as permissions, Application...
    */
   loadTerminalInfo: function () {
+    OB.warn("loadTerminalInfo. Next: triggerLoadTerminalInfoReady");
     var me = this,
         loadQueue = {};
 
     function triggerLoadTerminalInfoReady() {
+      OB.warn("triggerLoadTerminalInfoReady. Next: 'terminalInfoLoaded' trigger");
       if (OB.UTIL.queueStatus(loadQueue)) {
         me.setUserModelOnline(function () {
+          OB.warn("'terminalInfoLoaded' trigger. Next: processPropertyLoaders");
           me.trigger('terminalInfoLoaded');
         });
       }
@@ -328,6 +336,7 @@
       method: 'GET',
       handleAs: 'text'
     }).response(function (inSender, inResponse) {
+      OB.warn("applicationFormatUrl success");
       eval(inResponse); //...we have an OB variable local to this function
       // we want to 'export' some properties to global OB
       window.OB.Application = OB.Application;
@@ -336,10 +345,13 @@
       window.OB.Constants = OB.Constants;
       loadQueue.application = true;
       triggerLoadTerminalInfoReady();
+    }).error(function (inSender) {
+      OB.warn("applicationFormatUrl fail: " + inSender);
     }).go();
   },
 
   initLocalDB: function (loadQueue, triggerLoadTerminalInfoReady) {
+    OB.warn("initLocalDB");
     loadQueue.localDB = false;
 
     var undef, wsql = window.openDatabase !== undef,
@@ -389,6 +401,7 @@
         return;
       }
       //Version of the database changed, we need to drop the tables so they can be created again
+      OB.warn("db.version changed '" + db.version + "' - '" + dbInfo.version + "'");
       dropTables();
       loadQueue.localDB = true;
       triggerLoadTerminalInfoReady();
@@ -405,6 +418,7 @@
    * Invoked from initComponents in terminal view
    */
   initializeCommonComponents: function () {
+    OB.warn("initializeCommonComponents. Next: loginUtilsParams success");
     var me = this,
         params = {};
     window.localStorage.setItem('LOGINTIMER', new Date().getTime());
@@ -421,6 +435,7 @@
       contentType: 'application/json;charset=utf-8',
       data: params,
       success: function (inSender, inResponse) {
+        OB.warn("loginUtilsParams success. Next: 'initializedCommonComponents' event");
         OB.appCaption = inResponse.appCaption;
         if (_.isEmpty(inResponse.labels) || _.isNull(inResponse.labels) || _.isUndefined(inResponse.labels)) {
           OB.I18N.labels = JSON.parse(window.localStorage.getItem('I18NLabels'));
@@ -469,6 +484,11 @@
         // we are likely offline. Attempt to navigate to the login page
         OB.I18N.labels = JSON.parse(window.localStorage.getItem('I18NLabels'));
         OB.Format = JSON.parse(window.localStorage.getItem('AppFormat'));
+        if (!OB.I18N.labels || !OB.Format) {
+          OB.error("The labels or formats are not available. WebPOS needs a server connection to proceed");
+        } else {
+          OB.warn("loaded labels and format from cache. Next: 'initializedCommonComponents' event");
+        }
         me.trigger('initializedCommonComponents');
         // Notifying view component that I'm rendered so login page can be
         // shown if needed
@@ -493,8 +513,10 @@
       return;
     }
     if (!OB.MobileApp.view.$.containerWindow) {
+      OB.error("Critical: renderLogin fail");
       return;
     }
+    OB.warn("renderLogin. Next: none");
 
     OB.MobileApp.view.$.containerWindow.destroyComponents();
     OB.MobileApp.view.$.containerWindow.createComponent({
@@ -892,9 +914,11 @@
       timeout: 20000,
       contentType: 'application/json;charset=utf-8',
       success: function (inSender, inResponse) {
+        OB.warn("org.openbravo.mobile.core.logout success");
         me.closeSession();
       },
       fail: function (inSender, inResponse) {
+        OB.error("org.openbravo.mobile.core.logout fail");
         me.closeSession();
       }
     });
@@ -914,9 +938,11 @@
       timeout: 20000,
       contentType: 'application/json;charset=utf-8',
       success: function (inSender, inResponse) {
+        OB.warn("org.openbravo.mobile.core.logout success");
         me.triggerLogout();
       },
       fail: function (inSender, inResponse) {
+        OB.error("org.openbravo.mobile.core.logout fail");
         me.triggerLogout();
       }
     });
@@ -988,7 +1014,7 @@
   },
 
   saveTerminalInfo: function () {
-    OB.info('saving terminal info:', this.attributes);
+    OB.warn("saving terminal info: '" + this.attributes.terminalName + "'");
     //In online mode, we save the terminal information in the local db
     this.usermodel.set('terminalinfo', JSON.stringify(this));
     OB.Dal.save(this.usermodel, function () {}, function () {
diff -r 66894335d440 -r fa4a270a9595 web/org.openbravo.mobile.core/source/utils/ob-utilities.js
--- a/web/org.openbravo.mobile.core/source/utils/ob-utilities.js	Thu Sep 18 17:08:02 2014 +0200
+++ b/web/org.openbravo.mobile.core/source/utils/ob-utilities.js	Thu Sep 18 18:22:30 2014 +0200
@@ -128,6 +128,17 @@
     }
   };
 
+  OB.UTIL.lastConnectivityStatus = false; // false: offline, true: online
+  OB.UTIL.lastConnectivityOrigin = false; // false: offline, true: online
+  OB.UTIL.logConnectivityStatus = function (currentStatus, origin, message) {
+    if(OB.UTIL.lastConnectivityOrigin === origin && OB.UTIL.lastConnectivityStatus === currentStatus) {
+      return;
+    }
+    OB.UTIL.lastConnectivityStatus = currentStatus;
+    OB.UTIL.lastConnectivityOrigin = origin;
+    OB.warn("Connectivity status changed to '" + (currentStatus ? 'online' : 'offline') + "' in '" + origin + "'" + (message ? (": " + message) : ""));
+  };
+
   OB.UTIL.checkConnectivityStatus = function (connectedCallback, notConnectedCallback) {
     var ajaxParams, currentlyConnected = OB.MobileApp.model.get('connectedToERP');
     var oldContext = OB.MobileApp.model.get('context');
@@ -138,7 +149,9 @@
       }, function (data) {
         var newContext;
         if (data && data.exception) {
+          OB.warn('checkConnectivityStatus: Exception in request to ContextInformation:'+ data.exception);
           OB.MobileApp.model.logout();
+          return;
         }
         if (data[0]) {
           newContext = data[0];
@@ -165,6 +178,7 @@
         success: function (inSender, inResponse) {
           if (currentlyConnected !== true) {
             if (OB.MobileApp.model) {
+              OB.warn('checkConnectivityStatus: request to sesionActive successfull. Triggering online');
               OB.MobileApp.model.triggerOnLine();
             }
           }
@@ -175,6 +189,7 @@
         fail: function (inSender, inResponse) {
           if (currentlyConnected !== false) {
             if (OB.MobileApp.model) {
+              OB.warn('checkConnectivityStatus: request to sesionActive failed. Triggering offline');
               OB.MobileApp.model.triggerOffLine();
             }
           }

# HG changeset patch
# User Rafa Alonso <rafael.alonso@openbravo.com>
# Date 1411057425 -7200
#      Thu Sep 18 18:23:45 2014 +0200
# Node ID 081e3a0380d92a0fc39dfbedf5ea54361298c13b
# Parent  c2614191a5cbe2c1d3c7f25866bc81e4956c557b
Issue 27625: Log for underlying processes

diff -r c2614191a5cb -r 081e3a0380d9 web/org.openbravo.retail.posterminal/js/login/model/login-model.js
--- a/web/org.openbravo.retail.posterminal/js/login/model/login-model.js	Thu Sep 18 16:30:46 2014 +0200
+++ b/web/org.openbravo.retail.posterminal/js/login/model/login-model.js	Thu Sep 18 18:23:45 2014 +0200
@@ -346,8 +346,10 @@
       var i, paymentcashcurrency, paymentcash, paymentlegacy, max, loadModelsIncFunc;
       if (!OB.UTIL.isSupportedBrowser()) {
         OB.MobileApp.model.renderLogin();
+        OB.error("renderMain fail: incompatible browser");
         return false;
       }
+      OB.warn("renderMain. Next: 'ready' event");
       OB.DS.commonParams = OB.DS.commonParams || {};
       OB.DS.commonParams = {
         client: this.get('terminal').client,
@@ -389,9 +391,11 @@
         var minIncRefresh = this.get('terminal').terminalType.minutestorefreshdatainc * 60 * 1000;
         if (minIncRefresh) {
           if (!OB.MobileApp.model.get('FullRefreshWasDone')) {
+            OB.warn("Performing incremental refresh" );
             OB.MobileApp.model.loadModels(null, true);
           }
           loadModelsIncFunc = function () {
+            OB.warn("Performing incremental refresh" );
             OB.MobileApp.model.loadModels(null, true);
           };
           setInterval(loadModelsIncFunc, minIncRefresh);
diff -r c2614191a5cb -r 081e3a0380d9 web/org.openbravo.retail.posterminal/js/utils/ordersSyncUtils.js
--- a/web/org.openbravo.retail.posterminal/js/utils/ordersSyncUtils.js	Thu Sep 18 16:30:46 2014 +0200
+++ b/web/org.openbravo.retail.posterminal/js/utils/ordersSyncUtils.js	Thu Sep 18 18:23:45 2014 +0200
@@ -64,6 +64,7 @@
         // a-> timeout -> Don't remove from local DB. We are not sure if the information was or not processed. If yes we will send again the orders and the mechanism to detect duplicates will act.
         // b-> At least one error -> Remove the orders which was saved in the backend (correctly or as an error). Don't remove those which failed.
         if (data.exception && data.exception.status && data.exception.status.timeout) {
+          OB.warn("OrderLoader (a): Server not available, keeping " + orders.length + " orders in local");
           //FLOW A
           orders.each(function (order) {
             order.set('isbeingprocessed', 'N');
@@ -73,8 +74,10 @@
           });
         } else {
           // FLOW B
+          OB.warn("OrderLoader (b1):  Error in " + orders.length + " orders...");
           if (data.exception && data.exception.status && data.exception.status.errorids && data.exception.status.errorids.length > 0) {
             var notProcessedOrders = data.exception.status.errorids;
+            var removedCount = 0;
             orders.each(function (order) {
               var isErrorId = _.find(notProcessedOrders, function (errId) {
                 if (order.get('id') === errId) {
@@ -90,12 +93,16 @@
                 if (model) {
                   model.get('orderList').remove(order);
                 }
+                removedCount += 1;
                 OB.Dal.remove(order, null, function (tx, err) {
+                  removedCount -= 1;
                   OB.UTIL.showError(err);
                 });
               }
             });
+            OB.warn("OrderLoader (b2): Error in " + (orders.length - removedCount) + " orders. Removed " + removedCount + " correctly sent to the server");
           } else {
+            OB.warn("OrderLoader (c): Server not available, keeping " + orders.length + " orders in local");
             //Others, Again flow A. Don't remove from local DB.
             orders.each(function (order) {
               order.set('isbeingprocessed', 'N');
@@ -110,13 +117,17 @@
         }
       } else {
         // NORMAL FLOW: Orders have been processed, delete them
+        OB.warn("OrderLoader (d1): " + orders.length + " orders correctly sent to the server. Removing from local...");
         var me = this;
         me.updatedLastDocNumber = false;
+        var removedCount2 = 0;
         orders.each(function (order) {
           if (model) {
             model.get('orderList').remove(order);
           }
+          removedCount2 += 1;
           OB.Dal.remove(order, null, function (tx, err) {
+            removedCount2 -= 1;
             OB.UTIL.showError(err);
           });
           // update the terminal info with the last document number sent to backoffice
@@ -135,6 +146,7 @@
           }
         });
         // if has been updated the last doc number then terminalinfo is updated
+        OB.warn("OrderLoader (d2): " + orders.length + " orders correctly sent to the server. Removed " + removedCount2 + " from local.");
         if (me.updatedLastDocNumber) {
           OB.POS.terminal.terminal.saveTerminalInfo();
         }