ODP.NET

Using ODP, we are testing the connection timeouts by introduce a network delay of 500ms in each direction using Wire-shark.

We tested 5 Inserts tested with a pool of size of 3. Connection Timeout=2, Command Timeout=2. The result shows the first transaction succeeds but not the last four transactions that are connection
timed out. The trace were turned on. The first transaction succeeded but above the timeout value and last four transaction time 14 seconds after they should have. The traces provided below show that all connections are almost established at the same time, but only the first transaction doesn’t time out even if it has a gap of near 13 seconds between the connection open and the insert command.

The connection was requested 9:43:21.521 with Data Source=denb1dbvast-02/SCPBLD1;User Id=scpdev1;Password=scpdev1;Pooling=True;Min Pool Size=3;Max Pool Size=3;Connection Lifetime=60;Connection Timeout=2;Incr Pool Size=1;Decr Pool Size=1;Statement Cache Size=10;Self Tuning=True;HA Events=False;Load Balancing=False

TIME:2012/09/24-09:43:21:771 TID:10c8 (ENTRY) OracleConnection::Open()
TIME:2012/09/24-09:43:21:771 TID:1ed4 (ENTRY) OracleConnection::Open()
TIME:2012/09/24-09:43:21:833 TID: 6ec (ENTRY) OracleConnection::Open()
TIME:2012/09/24-09:43:21:911 TID:12b8 (ENTRY) OracleConnection::Open()
TIME:2012/09/24-09:43:21:973 TID:1218 (ENTRY) OracleConnection::Open()
…
Followed by a series of messages exchange between DB server and Async_DB app. The total number of messages varies in the range [32, 38]
…
TIME:2012/09/24-09:43:34:517 TID:1ed4 (EXIT) OracleConnection::Open()

TIME:2012/09/24-09:43:34:532 TID:1ed4 OpsSqlPrepare2(): SQL: INSERT INTO NSC_Usage( Origin, MDN, Session_ID_PK, Off_Hook_TS, On_Hook_TS, Flag, Degraded_Status, Degraded_Filename, CCR_Origin_Host, CCR_Destination_Host, CCR_Origin_Realm, CCR_Destination_Realm, CCR_Auth_Application_ID, CCR_Service_Context_ID, CCR_Last_Request_Type, CCR_Last_Request_Number, CCR_Event_Timestamp, CCR_Subscription_ID_Type, CCR_Subscription_ID_Data, CCR_Req_Serv_Unit_CC_Time ) Values ('A','5052035787','VIP02.101624612' ,'18-MAY-11 12.00.00.000000000 PM','18-MAY-11 12.01.00.000000000 PM',128,0,'Filename','vip0101.cricket.com','realtime_A.convergys.com','cricket.com','convergys.com',4,'voice@cricket.com',3,2,'20110308192815',0,'8888888888',180 )
TIME:2012/09/24-09:43:35:609 TID:1ed4 (ENTRY) OpsSqlFreeCtx()
TIME:2012/09/24-09:43:35:609 TID:1ed4 (EXIT) OpsSqlFreeCtx(): RetCode=0 Line=163
TIME:2012/09/24-09:43:35:609 TID:1ed4 (EXIT) OpsSqlExecuteNonQuery(): RetCode=0 Line=877
TIME:2012/09/24-09:43:35:609 TID:1ed4 (EXIT) OracleCommand::ExecuteNonQuery()
TIME:2012/09/24-09:43:35:640 TID:1ed4 (ENTRY) OracleConnection::Close()
TIME:2012/09/24-09:43:35:655 TID:1ed4 (ENTRY) OpsConCheckConStatus(): (311cf8)=3218680
TIME:2012/09/24-09:43:36:576 TID:12b8 (ERROR) ODP error code=-1000; ODP message=Connection request timed out
TIME:2012/09/24-09:43:36:576 TID:1218 (ERROR) ODP error code=-1000; ODP message=Connection request timed out
TIME:2012/09/24-09:43:36:576 TID:10c8 (ERROR) ODP error code=-1000; ODP message=Connection request timed out
TIME:2012/09/24-09:43:36:607 TID: 6ec (ERROR) ODP error code=-1000; ODP message=Connection request timed out

The first Insert was sent and executed successfully.

• Why did the first transaction succeed instead of timing out?
• Why did it take 14 seconds for the other 4 connections to timeout?

Nathan