Good catch Charitha! As you explained this code might raise unforeseen
issues.
However; if we are bringing the update operation mapping before the FCM
notification; as per [1] status of the push notification will be marked as
*COMPLETED* even before executing the notification sending process. And
this will cause another issue of an inconsistent state.
Most of the time, these notification providers involves calling external
3rd party libraries(eg. MQTT, FCM...etc). Suppose there's a
RuntimeException thrown while sending the push notification. Notification
status still will be marked as COMPLETED and will not try ever again since
it is not tracked with the current try-catch block(it only catches
PushNotificationExecutionFailedException).
Thus, If we are changing the order as suggested please consider adding a
Throwable catch block(since notificationStrategy.execute() calls 3rd party
or untrusted libraries);
try {
operationMappingDAO.updateOperationMapping(operationId,
enrolmentId,
org.wso2.carbon.device.mgt.core.dto.operation.mgt.Operation.PushNotificationStatus.COMPLETED);
notificationStrategy.execute(new NotificationContext(deviceId, operation));
} catch (Throwable e) {
log.error("Error occurred while sending push notifications to " +
deviceId.getType() + " device carrying id '" +
deviceId + "'", e);
// Reschedule if push notification failed.
operationMappingDAO.updateOperationMapping(operationId,
enrolmentId,
org.wso2.carbon.device.mgt.core.dto.operation.mgt.Operation.PushNotificationStatus.SCHEDULED);
}
[1]
https://github.com/wso2/carbon-device-mgt/blob/e56fb5f4de5d8f08af879a39a412ff501cba35fc/components/device-mgt/org.wso2.carbon.device.mgt.core/src/main/java/org/wso2/carbon/device/mgt/core/operation/mgt/OperationManagerImpl.java#L196
On Tue, Jan 23, 2018 at 7:16 PM, Charitha Goonetilleke <charit...@wso2.com>
wrote:
> Hi All,
>
> I have implemented state life cycle to prevent concurrent API call from
> agent to pending operations endpoint. However issue is still appearing. I
> have tested the same scenario with Update 10 and was able to reproduce the
> issue with Update 10 pack also.
>
> However as I figured out, we are sending FCM notification before updating
> operation mapping table[1]. Due to that device received FCM notification in
> realtime as same as it is being added to the Operations DB in the server.
> So there is chance to a raise condition and as a result, we are observing
> above exception. So we might need to send FCM notification after updating
> Operation Mapping in order to prevent that. WDYT?
>
> [1] https://github.com/wso2/carbon-device-mgt/blob/master/
> components/device-mgt/org.wso2.carbon.device.mgt.core/
> src/main/java/org/wso2/carbon/device/mgt/core/operation/mgt/
> OperationManagerImpl.java#L195
>
> Thanks & Regards,
> /charithag
>
> On Tue, Jan 23, 2018 at 2:34 PM, Charitha Goonetilleke <charit...@wso2.com
> > wrote:
>
>> Hi All,
>>
>> I was able to figure out the root cause for the issue. As Geeth and
>> Rasika pointed out this is happening due to concurrent insert and update
>> query executions. The root cause for this is calling pending operations
>> endpoint more than once from a single android device at a given time. Due
>> to that concurrent insert and update happen in the DB level. Ideally a
>> device should not call pending operations endpoint simultaneously. But as
>> device may receive multiple FCM notifications within fractions of seconds,
>> it is triggering pending operation calls per notification.
>>
>> So I'm now implementing a state machine to avoid that raise condition.
>>
>> Thanks & Regards,
>> /charithag
>>
>> On Tue, Jan 23, 2018 at 2:14 PM, Rasika Perera <rasi...@wso2.com> wrote:
>>
>>> Hi All,
>>>
>>> This error has raised since two threads trying to update the DB with
>>> following requirements;
>>>
>>> Thread #1
>>> waiting to lock PUBLIC.*DM_ENROLMENT_OP_MAPPING* while
>>> locking PUBLIC.*DM_OPERATION* (exclusive), PUBLIC.*DM_COMMAND_OPERATION*
>>> (exclusive).
>>>
>>> Thread #2
>>> waiting to lock PUBLIC.DM_OPERATION while
>>> locking PUBLIC.*DM_ENROLMENT_OP_MAPPING* (exclusive), PUBLIC.
>>> *DM_DEVICE_OPERATION_RESPONSE* (exclusive).";
>>>
>>> I noticed we are already using ";LOCK_TIMEOUT=60000" (60sec) H2 DB
>>> parameter which would allow sometime to continue the thread and do the DB
>>> update.
>>>
>>> Hence, this might happen when you are holding the debug pointer in
>>> updateOperation() method or in a state where device responses burst occurs.
>>> However the latter case is very rare on other DBs(other than embedded H2).
>>> We can even minimize the chance for a such issue implementing a LOCK for
>>> calling updateOperation method(might affect the performance). WDYT?
>>>
>>> Best Regards,
>>> ~Rasika
>>>
>>> On Tue, Jan 23, 2018 at 12:39 PM, Charitha Goonetilleke <
>>> charit...@wso2.com> wrote:
>>>
>>>> Hi All,
>>>>
>>>> I have encountered following exception intermittently on IoTS Update
>>>> 11, when testing with Android device.
>>>>
>>>> [2018-01-23 12:19:51,077] [IoT-Core] ERROR -
>>>> {org.wso2.carbon.mdm.services.android.services.impl.DeviceManagementServiceImpl}
>>>> Issue in retrieving operation management service instance
>>>> org.wso2.carbon.device.mgt.common.operation.mgt.OperationManagementException:
>>>> Error occurred while updating the operation: 90 status:COMPLETED
>>>> at org.wso2.carbon.device.mgt.core.operation.mgt.OperationManag
>>>> erImpl.updateOperation(OperationManagerImpl.java:551)
>>>> at org.wso2.carbon.device.mgt.core.service.DeviceManagementProv
>>>> iderServiceImpl.updateOperation(DeviceManagementProviderServ
>>>> iceImpl.java:1426)
>>>> at org.wso2.carbon.mdm.services.android.util.AndroidDeviceUtils
>>>> .updateOperation(AndroidDeviceUtils.java:211)
>>>> at org.wso2.carbon.mdm.services.android.services.impl.DeviceMan
>>>> agementServiceImpl.updateOperations(DeviceManagementServiceI
>>>> mpl.java:184)
>>>> at org.wso2.carbon.mdm.services.android.services.impl.DeviceMan
>>>> agementServiceImpl.getPendingOperations(DeviceManagementServ
>>>> iceImpl.java:139)
>>>> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>>>> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAcce
>>>> ssorImpl.java:62)
>>>> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMe
>>>> thodAccessorImpl.java:43)
>>>> at java.lang.reflect.Method.invoke(Method.java:498)
>>>> at org.apache.cxf.service.invoker.AbstractInvoker.performInvoca
>>>> tion(AbstractInvoker.java:188)
>>>> at org.apache.cxf.service.invoker.AbstractInvoker.invoke(Abstra
>>>> ctInvoker.java:104)
>>>> at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:204)
>>>> at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:101)
>>>> at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(S
>>>> erviceInvokerInterceptor.java:58)
>>>> at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleM
>>>> essage(ServiceInvokerInterceptor.java:94)
>>>> at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(Phase
>>>> InterceptorChain.java:272)
>>>> at org.apache.cxf.transport.ChainInitiationObserver.onMessage(C
>>>> hainInitiationObserver.java:121)
>>>> at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke
>>>> (AbstractHTTPDestination.java:249)
>>>> at org.apache.cxf.transport.servlet.ServletController.invokeDes
>>>> tination(ServletController.java:248)
>>>> at org.apache.cxf.transport.servlet.ServletController.invoke(Se
>>>> rvletController.java:222)
>>>> at org.apache.cxf.transport.servlet.ServletController.invoke(Se
>>>> rvletController.java:153)
>>>> at org.apache.cxf.transport.servlet.CXFNonSpringServlet.invoke(
>>>> CXFNonSpringServlet.java:171)
>>>> at org.apache.cxf.transport.servlet.AbstractHTTPServlet.handleR
>>>> equest(AbstractHTTPServlet.java:289)
>>>> at org.apache.cxf.transport.servlet.AbstractHTTPServlet.doPut(A
>>>> bstractHTTPServlet.java:226)
>>>> at javax.servlet.http.HttpServlet.service(HttpServlet.java:653)
>>>> at org.apache.cxf.transport.servlet.AbstractHTTPServlet.service
>>>> (AbstractHTTPServlet.java:265)
>>>> at org.apache.catalina.core.ApplicationFilterChain.internalDoFi
>>>> lter(ApplicationFilterChain.java:303)
>>>> at org.apache.catalina.core.ApplicationFilterChain.doFilter(App
>>>> licationFilterChain.java:208)
>>>> at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilte
>>>> r.java:52)
>>>> at org.apache.catalina.core.ApplicationFilterChain.internalDoFi
>>>> lter(ApplicationFilterChain.java:241)
>>>> at org.apache.catalina.core.ApplicationFilterChain.doFilter(App
>>>> licationFilterChain.java:208)
>>>> at org.wso2.carbon.mdm.services.android.util.ApiOriginFilter.do
>>>> Filter(ApiOriginFilter.java:33)
>>>> at org.apache.catalina.core.ApplicationFilterChain.internalDoFi
>>>> lter(ApplicationFilterChain.java:241)
>>>> at org.apache.catalina.core.ApplicationFilterChain.doFilter(App
>>>> licationFilterChain.java:208)
>>>> at org.apache.catalina.core.StandardWrapperValve.invoke(Standar
>>>> dWrapperValve.java:218)
>>>> at org.apache.catalina.core.StandardContextValve.invoke(Standar
>>>> dContextValve.java:110)
>>>> at org.apache.catalina.authenticator.AuthenticatorBase.invoke(A
>>>> uthenticatorBase.java:506)
>>>> at org.apache.catalina.core.StandardHostValve.invoke(StandardHo
>>>> stValve.java:169)
>>>> at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorRepo
>>>> rtValve.java:103)
>>>> at org.wso2.carbon.tomcat.ext.valves.CompositeValve.continueInv
>>>> ocation(CompositeValve.java:99)
>>>> at org.wso2.carbon.tomcat.ext.valves.CarbonTomcatValve$1.invoke
>>>> (CarbonTomcatValve.java:47)
>>>> at org.wso2.carbon.webapp.mgt.TenantLazyLoaderValve.invoke(Tena
>>>> ntLazyLoaderValve.java:57)
>>>> at org.wso2.carbon.webapp.authenticator.framework.WebappAuthent
>>>> icationValve.processRequest(WebappAuthenticationValve.java:151)
>>>> at org.wso2.carbon.webapp.authenticator.framework.WebappAuthent
>>>> icationValve.invoke(WebappAuthenticationValve.java:69)
>>>> at org.wso2.carbon.tomcat.ext.valves.TomcatValveContainer.invok
>>>> eValves(TomcatValveContainer.java:47)
>>>> at org.wso2.carbon.tomcat.ext.valves.CompositeValve.invoke(Comp
>>>> ositeValve.java:62)
>>>> at org.wso2.carbon.tomcat.ext.valves.CarbonStuckThreadDetection
>>>> Valve.invoke(CarbonStuckThreadDetectionValve.java:159)
>>>> at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogVa
>>>> lve.java:962)
>>>> at org.wso2.carbon.tomcat.ext.valves.CarbonContextCreatorValve.
>>>> invoke(CarbonContextCreatorValve.java:57)
>>>> at org.apache.catalina.core.StandardEngineValve.invoke(Standard
>>>> EngineValve.java:116)
>>>> at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAd
>>>> apter.java:445)
>>>> at org.apache.coyote.http11.AbstractHttp11Processor.process(Abs
>>>> tractHttp11Processor.java:1115)
>>>> at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler
>>>> .process(AbstractProtocol.java:637)
>>>> at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun
>>>> (NioEndpoint.java:1770)
>>>> at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(N
>>>> ioEndpoint.java:1729)
>>>> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPool
>>>> Executor.java:1142)
>>>> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo
>>>> lExecutor.java:617)
>>>> at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.r
>>>> un(TaskThread.java:61)
>>>> at java.lang.Thread.run(Thread.java:745)
>>>> Caused by:
>>>> org.wso2.carbon.device.mgt.core.operation.mgt.dao.OperationManagementDAOException:
>>>> Error occurred while inserting operation response
>>>> at org.wso2.carbon.device.mgt.core.operation.mgt.dao.impl.Gener
>>>> icOperationDAOImpl.addOperationResponse(GenericOperationDAOI
>>>> mpl.java:213)
>>>> at org.wso2.carbon.device.mgt.core.operation.mgt.OperationManag
>>>> erImpl.updateOperation(OperationManagerImpl.java:544)
>>>> ... 58 more
>>>> Caused by: org.h2.jdbc.JdbcSQLException: Deadlock detected. The current
>>>> transaction was rolled back. Details: "
>>>> Session #49 (user: WSO2CARBON) on thread pool-54-thread-1 is waiting to
>>>> lock PUBLIC.DM_ENROLMENT_OP_MAPPING while locking PUBLIC.DM_OPERATION
>>>> (exclusive), PUBLIC.DM_COMMAND_OPERATION (exclusive).
>>>> Session #59 (user: WSO2CARBON) on thread http-nio-9443-exec-27 is
>>>> waiting to lock PUBLIC.DM_OPERATION while locking
>>>> PUBLIC.DM_ENROLMENT_OP_MAPPING (exclusive),
>>>> PUBLIC.DM_DEVICE_OPERATION_RESPONSE
>>>> (exclusive)."; SQL statement:
>>>> INSERT INTO DM_DEVICE_OPERATION_RESPONSE(OPERATION_ID, ENROLMENT_ID,
>>>> EN_OP_MAP_ID, OPERATION_RESPONSE, RECEIVED_TIMESTAMP) VALUES(?, ?, ?, ?, ?)
>>>> [40001-175]
>>>> at org.h2.message.DbException.getJdbcSQLException(DbException.java:332)
>>>> at org.h2.message.DbException.get(DbException.java:172)
>>>> at org.h2.message.DbException.get(DbException.java:149)
>>>> at org.h2.table.RegularTable.doLock(RegularTable.java:504)
>>>> at org.h2.table.RegularTable.lock(RegularTable.java:450)
>>>> at org.h2.constraint.ConstraintReferential.existsRow(Constraint
>>>> Referential.java:375)
>>>> at org.h2.constraint.ConstraintReferential.checkRowOwnTable(Con
>>>> straintReferential.java:367)
>>>> at org.h2.constraint.ConstraintReferential.checkRow(ConstraintR
>>>> eferential.java:310)
>>>> at org.h2.table.Table.fireConstraints(Table.java:894)
>>>> at org.h2.table.Table.fireAfterRow(Table.java:911)
>>>> at org.h2.command.dml.Insert.insertRows(Insert.java:162)
>>>> at org.h2.command.dml.Insert.update(Insert.java:115)
>>>> at org.h2.command.CommandContainer.update(CommandContainer.java:79)
>>>> at org.h2.command.Command.executeUpdate(Command.java:253)
>>>> at org.h2.jdbc.JdbcPreparedStatement.executeUpdateInternal(Jdbc
>>>> PreparedStatement.java:154)
>>>> at org.h2.jdbc.JdbcPreparedStatement.executeUpdate(JdbcPrepared
>>>> Statement.java:140)
>>>> at org.wso2.carbon.device.mgt.core.operation.mgt.dao.impl.Gener
>>>> icOperationDAOImpl.addOperationResponse(GenericOperationDAOI
>>>> mpl.java:211)
>>>> ... 59 more
>>>>
>>>>
>>>> Thanks & regards,
>>>> /charithag
>>>> --
>>>> *Charitha Goonetilleke*
>>>> Senior Software Engineer
>>>> WSO2 Inc.; http://wso2.com
>>>> lean.enterprise.middleware
>>>>
>>>> mobile: +94 77 751 3669 <%2B94777513669>
>>>> Twitter:@CharithaWs <https://twitter.com/CharithaWs>, fb: charithag
>>>> <https://www.facebook.com/charithag>, linkedin: charithag
>>>> <http://www.linkedin.com/in/charithag>
>>>>
>>>> <http://wso2.com/signature>
>>>>
>>>> --
>>>> You received this message because you are subscribed to the Google
>>>> Groups "WSO2 IoT Team Group" group.
>>>> To unsubscribe from this group and stop receiving emails from it, send
>>>> an email to iot-group+unsubscr...@wso2.com.
>>>> For more options, visit https://groups.google.com/a/wso2.com/d/optout.
>>>>
>>>
>>>
>>>
>>> --
>>> With Regards,
>>>
>>> *Rasika Perera*
>>> Senior Software Engineer
>>> LinkedIn: http://lk.linkedin.com/in/rasika90
>>>
>>> <http://wso2.com/signature>
>>>
>>> WSO2 Inc. www.wso2.com
>>> lean.enterprise.middleware
>>>
>>
>>
>>
>> --
>> *Charitha Goonetilleke*
>> Senior Software Engineer
>> WSO2 Inc.; http://wso2.com
>> lean.enterprise.middleware
>>
>> mobile: +94 77 751 3669 <%2B94777513669>
>> Twitter:@CharithaWs <https://twitter.com/CharithaWs>, fb: charithag
>> <https://www.facebook.com/charithag>, linkedin: charithag
>> <http://www.linkedin.com/in/charithag>
>>
>> <http://wso2.com/signature>
>>
>
>
>
> --
> *Charitha Goonetilleke*
> Senior Software Engineer
> WSO2 Inc.; http://wso2.com
> lean.enterprise.middleware
>
> mobile: +94 77 751 3669 <%2B94777513669>
> Twitter:@CharithaWs <https://twitter.com/CharithaWs>, fb: charithag
> <https://www.facebook.com/charithag>, linkedin: charithag
> <http://www.linkedin.com/in/charithag>
>
> <http://wso2.com/signature>
>
--
With Regards,
*Rasika Perera*
Senior Software Engineer
LinkedIn: http://lk.linkedin.com/in/rasika90
<http://wso2.com/signature>
WSO2 Inc. www.wso2.com
lean.enterprise.middleware
_______________________________________________
Dev mailing list
Dev@wso2.org
http://wso2.org/cgi-bin/mailman/listinfo/dev
