57 views

Why opening an incident record might freeze the browser and eventually time out the transaction



Overview


Occasionally, trying to open an incident record, might cause the browser to quit loading and eventually timing out the user transaction. Reviewing the incident record from a list view, can show that the record is being continuously updated every ~10 seconds.

A deeper investigation in the instance transaction logs helps identified a root cause. There can be various reasons that can cause this issue to occur. This article will be detailing the causes found in a specific duplicate data entry scenario.

 

Cause


When the affected task record was created from the relevant record producer, a duplicate key entry issue occurred as shown in the localhost log shown below.

2017-12-11 07:59:04 (868) Default-thread-3 DACADF9CDB030B0038BB62EB0B9619A0 SEVERE *** ERROR *** FAILED TRYING TO EXECUTE ON CONNECTION 12: INSERT INTO task (`admin_override`, `made_sla`, `watch_list`, `upon_reject`,

`sys_updated_on`, `auto_request`, `u_transaction_sent_to_stars`, `number`, `sys_updated_by`, `u_quality_check`, `opened_by`, `sys_created_on`, `sys_domain`, `state`, `sys_created_by`, `u_resolved`, `knowledge`, `u_no_separation`, `u_reopen`, `impact`, `u_work_notes_counter`, `active`, `priority`, `calendar_stc`, `opened_at`, `business_duration`, `a_ref_1`, `approval_set`, `u_comments_counter`, `short_description`, `assignment_group`, `description`, `calendar_duration`, `u_source`, `notify`, `sys_class_name`, `u_date_created`, `sys_id`, `contact_type`, `a_ref_10`, `incident_state`, `urgency`, `u_chase_counter`, `u_local`, `company`, `reassignment_count`, `u_servicedesk_perimeter`, `severity`, `variables`, `approval`, `sys_mod_count`, `u_project_linked`, `backordered`, `a_ref_6`, `upon_approval`, `escalation`) VALUES(...) /* 

Unique Key violation detected by database (Duplicate entry '2cda1f90db430b0038bb62eb0b96193c' for key 'PRIMARY')

java.sql.SQLIntegrityConstraintViolationException: Duplicate entry '2cda1f90db430b0038bb62eb0b96193c' for key 'PRIMARY'
at org.mariadb.jdbc.internal.SQLExceptionMapper.get(SQLExceptionMapper.java:132)
at org.mariadb.jdbc.internal.SQLExceptionMapper.throwException(SQLExceptionMapper.java:106)
at org.mariadb.jdbc.MySQLStatement.executeQueryEpilog(MySQLStatement.java:268)
at org.mariadb.jdbc.MySQLStatement.execute(MySQLStatement.java:296)
at org.mariadb.jdbc.MySQLStatement.execute(MySQLStatement.java:387)
at sun.reflect.GeneratedMethodAccessor22.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.glide.db.StatementWrapper.invoke(StatementWrapper.java:40)
at com.sun.proxy.$Proxy7.execute(Unknown Source)
at com.glide.db.DBI.executeStatement0(DBI.java:921)
at com.glide.db.DBI.executeStatement(DBI.java:877)
at com.glide.db.DBI.executeStatement(DBI.java:850)
at com.glide.db.DBAction.executeAsResultSet(DBAction.java:283)
at com.glide.db.DBCompositeAction.executeAsResultSet(DBCompositeAction.java:139)
at com.glide.db.DBCompositeAction.executeAsResultSet0(DBCompositeAction.java:92)
at com.glide.db.DBAction.executeAndReturnTable(DBAction.java:247)
at com.glide.db.DBAction.executeNormal(DBAction.java:236)
at com.glide.db.DBAction.executeAndReturnException(DBAction.java:197)
at com.glide.script.GlideRecordITable.insert(GlideRecordITable.java:122)
at com.glide.script.GlideRecord.insert(GlideRecord.java:4532)
at com.glide.script.GlideRecord.insert(GlideRecord.java:4459)
at com.glideapp.servicecatalog.valve.ProducerValve.produceItem(ProducerValve.java:272)
at com.glideapp.servicecatalog.valve.ProducerValve.before(ProducerValve.java:96)
at com.glideapp.servicecatalog.valve.ValveProcessor.beforeProcessor(ValveProcessor.java:47)
at sun.reflect.GeneratedMethodAccessor2067.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.mozilla.javascript.MemberBox.invoke(MemberBox.java:138)
at org.mozilla.javascript.NativeJavaMethod.call(NativeJavaMethod.java:292)
at org.mozilla.javascript.ScriptRuntime.doCall(ScriptRuntime.java:2574)
at org.mozilla.javascript.optimizer.OptRuntime.callN(OptRuntime.java:52)
at org.mozilla.javascript.gen._refname__1438._c_executeProcessor_1(<refname>:8)
at org.mozilla.javascript.gen._refname__1438.call(<refname>)
at org.mozilla.javascript.ScriptRuntime.doCall2(ScriptRuntime.java:2642)
at org.mozilla.javascript.ScriptRuntime.doCall(ScriptRuntime.java:2579)
at org.mozilla.javascript.optimizer.OptRuntime.callName0(OptRuntime.java:74)
at org.mozilla.javascript.gen._refname__1438._c_script_0(<refname>:1)
at org.mozilla.javascript.gen._refname__1438.call(<refname>)
at org.mozilla.javascript.ContextFactory.doTopCall(ContextFactory.java:563)
at org.mozilla.javascript.ScriptRuntime.doTopCall(ScriptRuntime.java:3432)
at org.mozilla.javascript.gen._refname__1438.call(<refname>)
at org.mozilla.javascript.gen._refname__1438.exec(<refname>)
at com.glide.script.ScriptEvaluator.execute(ScriptEvaluator.java:259)
at com.glide.script.ScriptEvaluator.evaluateString(ScriptEvaluator.java:110)
at com.glide.script.ScriptEvaluator.evaluateString(ScriptEvaluator.java:76)
at com.glide.script.ScriptEvaluator.evaluateString(ScriptEvaluator.java:67)
at com.glide.script.Evaluator.evaluateString(Evaluator.java:91)
at com.glide.processors.ScriptedProcessor.process(ScriptedProcessor.java:70)
at com.glide.processors.AProcessor.runProcessor(AProcessor.java:415)
at com.glide.processors.AProcessor.processTransaction(AProcessor.java:186)
at com.glide.processors.ProcessorRegistry.process0(ProcessorRegistry.java:178)
at com.glide.processors.ProcessorRegistry.process(ProcessorRegistry.java:167)
at com.glide.ui.GlideServletTransaction.process(GlideServletTransaction.java:49)
at com.glide.sys.Transaction.run(Transaction.java:1977)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: org.mariadb.jdbc.internal.common.QueryException: Duplicate entry '2cda1f90db430b0038bb62eb0b96193c' for key 'PRIMARY'
at org.mariadb.jdbc.internal.mysql.MySQLProtocol.getResult(MySQLProtocol.java:995)
at org.mariadb.jdbc.internal.mysql.MySQLProtocol.executeQuery(MySQLProtocol.java:1050)
at org.mariadb.jdbc.internal.mysql.MySQLProtocol.executeQuery(MySQLProtocol.java:1030)
at org.mariadb.jdbc.MySQLStatement.execute(MySQLStatement.java:289)
...

This duplicate entry error could have happened due to a race condition of submitting the record producer twice, one immediately following the other. This could be an edge case, however, the error caused all the asynchronous Business Rules in place to run in an infinite loop, so creating events which eventually kept updating the affected task record for every ~10 seconds. 

These repeated updates generate huge amount of audit data on the record. Because of the huge audit, the record can not get loaded nor rendered by the browser. In fact, while trying to open the record, the [sys_history_line] table gets dynamically populated from the main [sys_audit] table, in a very large transaction that ends up being timed out.

 

Solution


  1. Temporarily remove the activity formatter from the form to restore usability.
  2. Identify, deactivate, and reactivate the asynchronus business rules on the record. This should stop the continuous update events.
  3. Remove the redundant unwanted audit entries from the system. This can be done contacting SN customer support.

Article Information

Last Updated:2018-01-11 05:17:30
Published:2018-01-11