Openbravo Issue Tracking System - Retail Modules
View Issue Details
0036288Retail ModulesWeb POSpublic2017-06-19 19:182018-01-22 15:21
shuehner 
gorka_gil 
normalminorhave not tried
closedfixed 
5
 
RR17Q4 
marvintm
No
0036288: (Expected) duplicate pk on insert of Logclient apart from info message still logs 2* ERROR
LogClientLoader expects to see duplicate messages and logs + then ignores the duplicate row.

However apart from that INFO message 2* ERROR are logged to openbravo.log including the full json message which in some customers is a huge amount of the ERROR's messages seen per day.

Those 2*ERROR should be supressed.

Example case:
70a8a81e 2017-06-19 11:50:33,164 [ajp-bio-127.0.0.1-8009-exec-171] ERROR org.hibernate.util.JDBCExceptionReporter - Batch entry 0 inser
t into obmobc_logclient (AD_Client_ID, AD_Org_ID, Isactive, Created, Createdby, Updated, Updatedby, Deviceid, Msg, Loglevel, Cache_Sess
ion_ID, Isonline, Obmobc_Logclient_ID) values ('AA', 'BB', 'Y', '2017-6-19
11:48:57.908000 -5:0:0', 'CC', '2017-6-19 11:50:33.161000 -5:0:0', 'CC', 'DEVICEID', 'runSyncProcess: synchronization successfully done; stackTrace: https://the.url/openbravo/web/js/gen/bd5 [^]
2e366338bc6dc386ed72358a97e05_WebPOS.js:1487:483', 'Info', 'DF929F87F1334E61BCDF9ABC23837689', 'Y', '9E51244B6472BA64D4C59580D19D1A00')
 was aborted. Call getNextException to see the cause.
70a8a81e 2017-06-19 11:50:33,164 [ajp-bio-127.0.0.1-8009-exec-171] ERROR org.hibernate.util.JDBCExceptionReporter - ERROR: duplicate key value violates unique constraint "obmobc_logclient_pk"
  Detail: Key (obmobc_logclient_id)=(9E51244B6472BA64D4C59580D19D1A00) already exists.
70a8a81e 2017-06-19 11:50:33,174 [ajp-bio-127.0.0.1-8009-exec-171] INFO org.openbravo.mobile.core.utils.LogClientLoader - Found duplicated log client message with id: 9E51244B6472BA64D4C59580D19D1A00. Ignoring
.
No tags attached.
depends on backport 0037697RR17Q3.3 closed marvintm (Expected) duplicate pk on insert of Logclient apart from info message still logs 2* ERROR 
Issue History
2017-06-19 19:18shuehnerNew Issue
2017-06-19 19:18shuehnerAssigned To => Retail
2017-06-19 19:18shuehnerTriggers an Emergency Pack => No
2017-07-13 12:44maiteIssue Monitored: networkb
2017-09-07 16:35gorka_gilAssigned ToRetail => gorka_gil
2017-09-07 16:47gorka_gilNote Added: 0098889
2017-09-07 16:47gorka_gilNote Deleted: 0098889
2017-09-12 16:29gorka_gilNote Added: 0098991
2017-09-12 16:47gorka_gilNote Added: 0098992
2017-09-18 10:57gorka_gilNote Edited: 0098991bug_revision_view_page.php?bugnote_id=0098991#r15917
2017-09-18 10:59gorka_gilNote Added: 0099095
2017-09-18 11:02hgbotCheckin
2017-09-18 11:02hgbotNote Added: 0099096
2017-09-18 11:02hgbotStatusnew => resolved
2017-09-18 11:02hgbotResolutionopen => fixed
2017-09-18 11:02hgbotFixed in SCM revision => http://code.openbravo.com/erp/pmods/org.openbravo.mobile.core/rev/77be95078aa45a3a1d621db07654da0f6337e6d5 [^]
2017-09-18 11:10marvintmReview Assigned To => marvintm
2017-09-18 11:10marvintmNote Added: 0099097
2017-09-18 11:10marvintmStatusresolved => closed
2017-09-18 11:10marvintmFixed in Version => RR17Q4
2017-09-22 14:40hgbotCheckin
2017-09-22 14:40hgbotNote Added: 0099495
2017-09-26 14:05gorka_gilNote Added: 0099580
2017-09-27 15:31hgbotCheckin
2017-09-27 15:31hgbotNote Added: 0099633
2018-01-22 15:21marvintmStatusclosed => new
2018-01-22 15:21marvintmResolutionfixed => open
2018-01-22 15:21marvintmFixed in VersionRR17Q4 =>
2018-01-22 15:21marvintmStatusnew => scheduled
2018-01-22 15:21marvintmStatusscheduled => resolved
2018-01-22 15:21marvintmFixed in Version => RR17Q4
2018-01-22 15:21marvintmResolutionopen => fixed
2018-01-22 15:21marvintmStatusresolved => closed

Notes
(0098991)
gorka_gil   
2017-09-12 16:29   
(edited on: 2017-09-18 10:57)
If needed to reproduce the problem manually it will help these tips:

1) To force the sync of the log from chrome console to the backend:
OB.UTIL.processLogClientAll();

2) To generate client log lines:
OB.info('logline_info');
OB.warn('logline_warn');
OB.error('logline_error');

3) Also disabling the delete of already synchronized log, helps to have duplicated lines:

--- a/web/org.openbravo.mobile.core/source/utils/logClientSyncUtils.js Fri Sep 08 14:50:58 2017 +0200
+++ b/web/org.openbravo.mobile.core/source/utils/logClientSyncUtils.js Tue Sep 12 16:25:58 2017 +0200
@@ -15,12 +15,12 @@
 
   OB.UTIL.processLogClientAll = function () {
     // if the application is busy, delay flushing the log to the server
- if (!OB.MobileApp.model.loadingErrorsActions.executed) {
- if (OB.MobileApp.model.get('isLoggingIn') || !OB.UTIL.SynchronizationHelper.isSynchronized()) {
- OB.debug("LogClient flushing delayed");
- return false;
- }
- }
+// if (!OB.MobileApp.model.loadingErrorsActions.executed) {
+// if (OB.MobileApp.model.get('isLoggingIn') || !OB.UTIL.SynchronizationHelper.isSynchronized()) {
+// OB.debug("LogClient flushing delayed");
+// return false;
+// }
+// }
 
     // Processes log client
     if (OB.MobileApp.model.get('connectedToERP')) {
@@ -61,9 +61,9 @@
           return;
         }
         console.warn("Log client failed to log:\n" + toJson.msg);
- OB.Dal.remove(logClient, null, function (tx, err) {
- OB.UTIL.showError(err);
- });
+// OB.Dal.remove(logClient, null, function (tx, err) {
+// OB.UTIL.showError(err);
+// });
       }
     });
 
@@ -83,9 +83,9 @@
           }
         } else {
           logClients.each(function (logClient) {
- OB.Dal.remove(logClient, null, function (tx, err) {
- OB.UTIL.showError(err);
- });
+// OB.Dal.remove(logClient, null, function (tx, err) {
+// OB.UTIL.showError(err);
+// });
           });
           if (successCallback) {
             successCallback();

(0098992)
gorka_gil   
2017-09-12 16:47   
Discussed and decided for this issue that not needed to add tests.
(0099095)
gorka_gil   
2017-09-18 10:59   
Finally, after rethink, decided to add tests.

Not to test the issue itself, since is quite complex to reproduce consistently, but just to add a log and check that is added in the backend database, with the correct fields filled.
(0099096)
hgbot   
2017-09-18 11:02   
Repository: erp/pmods/org.openbravo.mobile.core
Changeset: 77be95078aa45a3a1d621db07654da0f6337e6d5
Author: Gorka Gil <gorka.gil <at> openbravo.com>
Date: Thu Sep 14 13:00:06 2017 +0200
URL: http://code.openbravo.com/erp/pmods/org.openbravo.mobile.core/rev/77be95078aa45a3a1d621db07654da0f6337e6d5 [^]

Fixed issue 36288: (Expected) duplicate pk on insert of Logclient apart from info message still logs 2* error

Controled the exception when inserting the log line in the backend, for the case of duplicate id.
To control the exception needed to not use DAL nor xsql, and use instead a prepared statement directly.

In the case of error, we do a sql in the db and if the id is in the db, is a duplicated and everthing is fine.
Note that this case of duplicate is not common case, so this query to check duplicates should not be very frequent.

A future improvement is the use of merge functionality of postgres 9.5 that has upsert, that can do inserts and
ignore the cases of duplicates. But also needed to find something similar in oracle.
Note that in the moment of fix we still support postgres 9.3 so not possible to use it.
Other option was the use of interceptors but will affect all the queries of the application so was discarded.

---
M src/org/openbravo/mobile/core/utils/LogClientLoader.java
---
(0099097)
marvintm   
2017-09-18 11:10   
Test will be added later.
(0099495)
hgbot   
2017-09-22 14:40   
Repository: erp/pmods/org.openbravo.mobile.core
Changeset: 160d673e7689936a3511512f27c24fce3603b62b
Author: Gorka Gil <gorka.gil <at> openbravo.com>
Date: Fri Sep 22 14:21:20 2017 +0200
URL: http://code.openbravo.com/erp/pmods/org.openbravo.mobile.core/rev/160d673e7689936a3511512f27c24fce3603b62b [^]

Related to issue 36288: (Expected) duplicate pk on insert of Logclient apart from info message still logs 2* error

Updated license year

---
M src/org/openbravo/mobile/core/utils/LogClientLoader.java
---
(0099580)
gorka_gil   
2017-09-26 14:05   
Repository: tools/automation/pi-mobile
Changeset: 51f5c83109d9
Author: Gorka Gil <gorka.gil <at> openbravo.com>
Date: Fri Sep 22 14:23:23 2017 +0200
URL: https://code.openbravo.com/tools/automation/pi-mobile/rev/51f5c83109d9 [^]

Related to issue 36288: (Expected) duplicate pk on insert of Logclient apart from info message still logs 2* error

Force added info and warn log
force the sync to the backend
check that are inserted into the db correctly

Note: not tested error log, since if info and warn works error should also work, and also not needed to add to the allowed errors with the risk of hide other errors.

---
M src-test/org/openbravo/test/mobile/retail/pack/selenium/tests/system/I36288_CheckLogClientLoad.java
---
(0099633)
hgbot   
2017-09-27 15:31   
Repository: erp/pmods/org.openbravo.mobile.core
Changeset: 8ffc165e44647d678ded32e97b2cb21163200ced
Author: Gorka Gil <gorka.gil <at> openbravo.com>
Date: Wed Sep 27 10:30:44 2017 +0200
URL: http://code.openbravo.com/erp/pmods/org.openbravo.mobile.core/rev/8ffc165e44647d678ded32e97b2cb21163200ced [^]

Related to issue 36288: (Expected) duplicate pk on insert of Logclient apart from info message still logs 2* error

Apply shu review

---
M src/org/openbravo/mobile/core/utils/LogClientLoader.java
---