SubmitChanges() call does not return

StanislavK · Post by **StanislavK** » Fri 29 Oct 2010 17:04

The issue may be caused by a problem in the Oracle client software. Please ensure that you are using the same OCI version on production servers and developer machines. Also, please specify the exact version of Oracle client with which the problem occurs.

The CommandTimeout property is designed for the Direct connection mode only, and should be correctly working in the 5.70.180 version of dotConnect for Oracle.

We will analyze the possible ways of setting the command timeout for the OCI connection mode, and inform you about the results.

Also, could you please specify whether the Direct connection mode is acceptable for your task?

bmarotta · Post by **bmarotta** » Wed 03 Nov 2010 14:48

Hi Stanislav,

for the Direct mode, I think we have to evaluate it. But it won't be surely done from day to night.

Currently we have the following Oracle versions:

Oracle Server: 10.2.0.4.0 - 64bi

Website Server:
oracle 9 full client Version 9.2.0.1.0
oracle 10 instant client installed. Version 10.2.0.1 (oci.dll)

What is the link between the versions in developer machines and production servers? Is there anything compiled in the code that is linked with the Oracle client version on the compiling machine?

StanislavK · Post by **StanislavK** » Thu 04 Nov 2010 13:03

We recommend you to update to newer Oracle client versions (e.g., version 10.2.0.5 of Instant Client). In the OCI connection mode, Oracle Client software is used for all interoperations with the server, hence the problems you are encountering may be caused by errors in the client.

The Direct mode is free from such problems, as it does not use Oracle Client, but has some functionality limitations.

ThomasMuellerUGIS · Post by **ThomasMuellerUGIS** » Wed 08 Dec 2010 19:03

StanislavK wrote:We recommend you to update to newer Oracle client versions (e.g., version 10.2.0.5 of Instant Client). In the OCI connection mode, Oracle Client software is used for all interoperations with the server, hence the problems you are encountering may be caused by errors in the client.

The Direct mode is free from such problems, as it does not use Oracle Client, but has some functionality limitations.

Hi Stanislav,

I'm working together with bmarotta on that issue.
We just tested Instant Client 10.2.0.5 with no sucess.
Observation remain the same.

THX,

Thomas

StanislavK · Post by **StanislavK** » Fri 10 Dec 2010 17:23

Please specify sample stack traces of the hung threads so that we can suggest where the problem originates from.

ThomasMuellerUGIS · Post by **ThomasMuellerUGIS** » Fri 17 Dec 2010 11:56

Here we go - one of many various cases.

THX,

Thomas

Code: Select all

Background
   at OciDynamicType.nativeOCIStmtExecute(HandleRef , HandleRef , HandleRef , Int32 , Int32 , Int32 , Int32 , Int32 )
   at OciDynamicType.OCIStmtExecute(HandleRef , HandleRef , HandleRef , Int32 , Int32 , Int32 , Int32 , Int32 )
   at Devart.Data.Oracle.ao.a(Int32 A_0, a4 A_1)
   at Devart.Data.Oracle.OracleCommand.InternalExecute(CommandBehavior behavior, IDisposable disposable, Int32 startRecord, Int32 maxRecords, Boolean nonQuery)
   at Devart.Common.DbCommandBase.ExecuteDbDataReader(CommandBehavior behavior, Boolean nonQuery)
   at Devart.Common.DbCommandBase.ExecuteDbDataReader(CommandBehavior behavior)
   at System.Data.Common.DbCommand.ExecuteReader(CommandBehavior behavior)
   at Devart.Data.Oracle.OracleCommand.ExecuteReader()
   at IssuanceEngine.Data.Oracle.OracleQueryWrapper.RunOracleQueryWith1Record(PumaDataContext context, String query, String queryParamName, String queryParamValue, ProcessOracleRecord processFunction) in d:\buildbot\slave\release-PuMa-b\build\PumaEngine\IssuanceEngine.Data.Oracle\OracleQueryWrapper.cs:line 51
   at IssuanceEngine.Data.Oracle.OracleQueryWrapper.RunOracleQueryWith1Long(PumaDataContext context, String query, String queryParamName, String queryParamValue) in d:\buildbot\slave\release-PuMa-b\build\PumaEngine\IssuanceEngine.Data.Oracle\OracleQueryWrapper.cs:line 89
   at IssuanceEngine.Data.Cache.DBBaseTableCache`1.GetDBCacheSCN(PumaDataContext context) in d:\buildbot\slave\release-PuMa-b\build\PumaEngine\IssuanceEngine.Data.Oracle\Cache\BaseDBCache.cs:line 485
   at IssuanceEngine.Data.Cache.DBBaseTableCache`1.GetIsCacheUpToDate(PumaDataContext context) in d:\buildbot\slave\release-PuMa-b\build\PumaEngine\IssuanceEngine.Data.Oracle\Cache\BaseDBCache.cs:line 373
   at IssuanceEngine.Data.Cache.DBBaseTableCache`1.GetIsCacheValid(PumaDataContext context) in d:\buildbot\slave\release-PuMa-b\build\PumaEngine\IssuanceEngine.Data.Oracle\Cache\BaseDBCache.cs:line 362
   at IssuanceEngine.Data.Cache.DBBaseTableCache`1.get_IsCacheValid() in d:\buildbot\slave\release-PuMa-b\build\PumaEngine\IssuanceEngine.Data.Oracle\Cache\BaseDBCache.cs:line 305
   at IssuanceEngine.Data.Cache.DBUniqueIdTableCache`1.AssureInCache(Int32 id) in d:\buildbot\slave\release-PuMa-b\build\PumaEngine\IssuanceEngine.Data.Oracle\Cache\BaseDBCache.cs:line 574
   at IssuanceEngine.Data.Cache.DBUniqueIdTableCache`1.Get(Int32 id) in d:\buildbot\slave\release-PuMa-b\build\PumaEngine\IssuanceEngine.Data.Oracle\Cache\BaseDBCache.cs:line 551
   at IssuanceEngine.Data.VwProductCombinationMetaMapping.get_ProductMetaMapping() in d:\buildbot\slave\release-PuMa-b\build\PumaEngine\IssuanceEngine.Data.Oracle\Partials\VwProductCombinationMetaMapping.cs:line 49
   at IssuanceEngine.Data.PumaDataContext.b__15(VwProductCombinationMetaMapping n) in d:\buildbot\slave\release-PuMa-b\build\PumaEngine\IssuanceEngine.Data.Oracle\IssuanceEngineDbContext.cs:line 935
   at System.Linq.Enumerable.WhereSelectListIterator`2.MoveNext()
   at System.Collections.Generic.List`1..ctor(IEnumerable`1 collection)

StanislavK · Post by **StanislavK** » Mon 20 Dec 2010 17:25

We couldn't reproduce this problem in our environment.

However, we plan to implement the support for command and connection timeouts in the OCI mode. As I can understand, setting short command timeout may be used as a workaround for these problems; please specify if this is correct. These changes will be available in one of the nearest builds of dotConnect for Oracle; we will inform you when the corresponding version is released.

bmarotta · Post by **bmarotta** » Fri 07 Jan 2011 13:26

Hi Stanislav,

although the timeout would workaround the problem, it will not solve it.

As stated before, this problem only happens under heavy usage. As there are other connections problem (like the "Handle is not initialized" exception) which was also "workarounded" by you, my guess is that there must be some run condition in the connections opening and closing that is leaving these calls in an unknown state.

Do you think this is a possible cause? That Devart is closing the connection while the result of an OCI call is still being treated by the OCI dll?

Is there anyway we can monitor the opening and closing of Oracle connections done by Devart or trace all the Oci calls?

Best regards,

StanislavK · Post by **StanislavK** » Tue 11 Jan 2011 10:25

You can use the OracleMonitor component for tracing when OracleConnections are opened and closed:
http://www.devart.com/dotconnect/oracle ... nitor.html

ThomasMuellerUGIS · Post by **ThomasMuellerUGIS** » Tue 11 Jan 2011 16:29

Hi,

we are currently using 'Devart LinqConnect Model'.
Will we have the same issues with 'Devart Entity Model'?

From my understanding there should be no difference.

Can you please confirm this?

THX alot,

Thomas

StanislavK · Post by **StanislavK** » Wed 12 Jan 2011 12:03

As we couldn't reproduce this problem, we cannot be sure that it is not LinqConnect-specific. However, since it occurs when performing basic operations, this is probable that it will persist after migrating to EF models.

bmarotta · Post by **bmarotta** » Tue 18 Jan 2011 18:44

Hi,

today I've tried the Db Monitor with no special results. I see the statements in the log, but no special reason for it to hang

LOG

2011-01-18 19:04:24,855 INFO [PumaRobot2-2011-01-18 07:00:25.6579=>()] IssuanceEngine.Data.PumaDataContext Disconnect: Description: Close connection - Extra info:
2011-01-18 19:04:24,855 INFO [PumaRobot3-2011-01-18 07:00:45.5162=>()] IssuanceEngine.Data.PumaDataContext Disconnect: Description: Close connection - Extra info:
2011-01-18 19:04:24,855 INFO [PumaRobot2-2011-01-18 07:00:25.6579=>()] IssuanceEngine.Data.PumaDataContext Prepare: Description: Prepare: SELECT t2.ID, t2.WORKFLOW_ID, t2.TASK_ID, t2.TYPE AS "TYPE", t2.PROPRITY, t2.RESP_BU_ID, t2.CREATE_DATETIME, t2.CLOSED_DATETIME, t2.MESSAGE, t2.MODIFIED_DATETIME, t2.DESCRIPTION, t2.PARENT_WORKITEM_ID, t2.GROUP_IDEN, t2.ORIGINAL_TYPE
FROM PUMA_WORKFLOW_INSTANCE t1, PUMA_WORKITEM t2
WHERE (t1.PRODUCT_ID = :p0) AND (t1.STATEFUL_OBJECT_ID IS NULL) AND (t1.ID = t2.WORKFLOW_ID) AND (NOT (t2.ID IS NULL)) AND (t2.CLOSED_DATETIME IS NULL) - Extra info:
2011-01-18 19:04:24,855 INFO [PumaRobot2-2011-01-18 07:00:25.6579=>()] IssuanceEngine.Data.PumaDataContext Execute: Description: Execute: SELECT t2.ID, t2.WORKFLOW_ID, t2.TASK_ID, t2.TYPE AS "TYPE", t2.PROPRITY, t2.RESP_BU_ID, t2.CREATE_DATETIME, t2.CLOSED_DATETIME, t2.MESSAGE, t2.MODIFIED_DATETIME, t2.DESCRIPTION, t2.PARENT_WORKITEM_ID, t2.GROUP_IDEN, t2.ORIGINAL_TYPE
FROM PUMA_WORKFLOW_INSTANCE t1, PUMA_WORKITEM t2
WHERE (t1.PRODUCT_ID = :p0) AND (t1.STATEFUL_OBJECT_ID IS NULL) AND (t1.ID = t2.WORKFLOW_ID) AND (NOT (t2.ID IS NULL)) AND (t2.CLOSED_DATETIME IS NULL) - Extra info: -1
2011-01-18 19:04:24,871 INFO [PumaRobot2-2011-01-18 07:00:25.6579=>()] IssuanceEngine.Data.PumaDataContext Disconnect: Description: Close connection - Extra info:
2011-01-18 19:04:24,871 INFO [PumaRobot2-2011-01-18 07:00:25.6579=>()] IssuanceEngine.Sotas.ProductSession Found 1 workitems to update for productId=1479917
2011-01-18 19:04:24,871 DEBUG [p526918=>GetWorkItems(WorkItemFilter[MyLineWorkItems, TasksOpenAndInProgress],0)] Puma.Util.DurationCounter GetWorkItems took 46.8753 msecs
2011-01-18 19:04:24,886 INFO [PumaRobot2-2011-01-18 07:00:25.6579=>()] IssuanceEngine.Data.PumaDataContext Prepare: Description: Prepare: SELECT t1.ID, t1.DEFINITION_ID, t1.TASK_STATUS, t1.RESPONSIBLE_BU_MEMBER_ID, t1.LOCKED_DATE_TIME, t1.END_DATE_TIME, t1.STATE_ID, t1.DUE_DATE, t1.ESCALATION_DATE
FROM PUMA_TASK_INSTANCE t1
WHERE :np0 = t1.ID - Extra info:
2011-01-18 19:04:24,886 INFO [PumaRobot2-2011-01-18 07:00:25.6579=>()] IssuanceEngine.Data.PumaDataContext Execute: Description: Execute: SELECT t1.ID, t1.DEFINITION_ID, t1.TASK_STATUS, t1.RESPONSIBLE_BU_MEMBER_ID, t1.LOCKED_DATE_TIME, t1.END_DATE_TIME, t1.STATE_ID, t1.DUE_DATE, t1.ESCALATION_DATE
FROM PUMA_TASK_INSTANCE t1
WHERE :np0 = t1.ID - Extra info: -1

Callstack where it hangs

at OciDynamicType.nativeOCIStmtExecute(HandleRef , HandleRef , HandleRef , Int32 , Int32 , Int32 , Int32 , Int32 )
at OciDynamicType.OCIStmtExecute(HandleRef , HandleRef , HandleRef , Int32 , Int32 , Int32 , Int32 , Int32 )
at Devart.Data.Oracle.ao.a(Int32 A_0, a4 A_1)
at Devart.Data.Oracle.OracleCommand.InternalExecute(CommandBehavior behavior, IDisposable disposable, Int32 startRecord, Int32 maxRecords, Boolean nonQuery)
at Devart.Common.DbCommandBase.ExecuteDbDataReader(CommandBehavior behavior, Boolean nonQuery)
at Devart.Common.DbCommandBase.ExecuteDbDataReader(CommandBehavior behavior)
at System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader()
at Devart.Data.Linq.Provider.DataProvider.a(b A_0, Object[] A_1, Object[] A_2, Object A_3)
at Devart.Data.Linq.Provider.DataProvider.a(b A_0, Object[] A_1)
at Devart.Data.Linq.Provider.DataProvider.b.a(b A_0, Object[] A_1)
at Devart.Data.Linq.Provider.DeferredQuery`3.a(TKeyQuery A_0)
at Devart.Data.Linq.Provider.DefferedEntity`4.a(TKeyQuery A_0)
at Devart.Data.Linq.Provider.DeferredSource`2.b()
at System.Linq.Enumerable.SingleOrDefault[TSource](IEnumerable`1 source)
at System.Data.Linq.EntityRef`1.get_Entity()
at IssuanceEngine.Data.WorkItem.get_Task() in d:\buildbot\slave\release-PuMa-a\build\PumaEngine\IssuanceEngine.Data.Oracle\IssuanceEngineDbContext.WorkItem.cs:line 504
at IssuanceEngine.Sotas.ProductSession.UpdateOpenWorkItems(PumaDataContext context, Product product) in d:\buildbot\slave\release-PuMa-a\build\PumaEngine\IssuanceEngine.Web\ProductSession.cs:line 159
at IssuanceEngine.Web.WorkflowExecution.ExecutionSession.c__DisplayClassed.b__ec() in d:\buildbot\slave\release-PuMa-a\build\PumaEngine\IssuanceEngine.Web\ExecutionSession.cs:line 2915
at IssuanceEngine.Web.WorkflowExecution.ExecutionSession.ExecuteWorkflowStep(PumaDataContext context, String name, Func`1 func) in d:\buildbot\slave\release-PuMa-a\build\PumaEngine\IssuanceEngine.Web\ExecutionSession.cs:line 2941
at IssuanceEngine.Web.WorkflowExecution.ExecutionSession.UpdateOpenWorkitems(PumaDataContext context, Int32 productId) in d:\buildbot\slave\release-PuMa-a\build\PumaEngine\IssuanceEngine.Web\ExecutionSession.cs:line 2911
at IssuanceEngine.BusinessObjects.Workflow.WorkflowObjectProcessThread.ProcessNextItem(IWorkflowExecutionStep next) in d:\buildbot\slave\release-PuMa-a\build\PumaEngine\IssuanceEngine.BusinessObjects\Implementation\Workflow\WorkflowObjectProcessThread.cs:line 99
at IssuanceEngine.BusinessObjects.BaseProcessThread`1.c__DisplayClass6.b__3() in d:\buildbot\slave\release-PuMa-a\build\PumaEngine\IssuanceEngine.BusinessObjects\Implementation\BaseProcessThread.cs:line 254
at IssuanceEngine.BusinessObjects.BaseProcessThread`1.CallProtected(Action method) in d:\buildbot\slave\release-PuMa-a\build\PumaEngine\IssuanceEngine.BusinessObjects\Implementation\BaseProcessThread.cs:line 350
at IssuanceEngine.BusinessObjects.BaseProcessThread`1.ProcessQueue() in d:\buildbot\slave\release-PuMa-a\build\PumaEngine\IssuanceEngine.BusinessObjects\Implementation\BaseProcessThread.cs:line 257
at IssuanceEngine.BusinessObjects.BaseProcessThread`1.MainLoop() in d:\buildbot\slave\release-PuMa-a\build\PumaEngine\IssuanceEngine.BusinessObjects\Implementation\BaseProcessThread.cs:line 205
at Puma.Utilities.Threads.ThreadManager.c__DisplayClasse.b__d() in d:\buildbot\slave\release-PuMa-a\build\PumaEngine\Puma.Utilities\Threads\ThreadManager.cs:line 335
at System.Threading.ThreadHelper.ThreadStart_Context(Object state)
at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state)
at System.Threading.ThreadHelper.ThreadStart()

Any guesses? Or should we just abandon Devart and try a different implementation?

StanislavK · Post by **StanislavK** » Fri 21 Jan 2011 14:23

The stack trace you've specified corresponds to a very common situation (the latter part of it is execution of a SELECT query via OracleCommand.ExecuteReader). We could never reproduce OCI call hangs in such situations, and we suggest that this may be a problem in the Oracle client software.

Also, we have implemented support for command and connection timeouts in the OCI connection mode. These features will be available in the nearest build, which we plan to release in about a week.

StanislavK · Post by **StanislavK** » Thu 27 Jan 2011 18:04

We have released the new 6.10.96 version of dotConnect for Oracle, which includes implementation of command and connection timeouts for the OCI connection mode. The new build can be downloaded from
http://www.devart.com/dotconnect/oracle/download.html
(the trial version) or from Registered Users' Area (for users with active subscription only):
http://secure.devart.com/

For the detailed information about the fixes and improvements available in dotConnect for Oracle 6.10.96, please refer to
http://www.devart.com/forums/viewtopic.php?t=20115