Openbravo Issue Tracking System - Retail Modules
View Issue Details
IDProjectCategoryView StatusDate SubmittedLast Update
0036288Retail ModulesWeb POSpublic2017-06-19 19:182018-01-22 15:21
Reportershuehner 
Assigned Togorka_gil 
PrioritynormalSeverityminorReproducibilityhave not tried
StatusclosedResolutionfixed 
PlatformOS5OS Version
Product Version 
Target VersionFixed in VersionRR17Q4 
Merge Request Status
Review Assigned Tomarvintm
OBNetwork customer
Support ticket
Regression level
Regression date
Regression introduced in release
Regression introduced by commit
Triggers an Emergency PackNo
Summary0036288: (Expected) duplicate pk on insert of Logclient apart from info message still logs 2* ERROR
DescriptionLogClientLoader 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
Steps To Reproduce.
Proposed Solution
Additional Information
TagsNo tags attached.
Relationships
depends on backport 0037697RR17Q3.3 closed marvintm (Expected) duplicate pk on insert of Logclient apart from info message still logs 2* ERROR 
Attached Files
Issue History
Date ModifiedUsernameFieldChange
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:43maiteResolution time => 1501711200
2017-07-13 12:44maiteIssue Monitored: networkb
2017-08-04 14:16marvintmResolution time1501711200 => 1502748000
2017-08-21 08:23marvintmResolution time1502748000 => 1504130400
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
---