IDLE_TIME DOES NOT WORK TO SPECIFY WHEN A SESSION IS AUTOMATICALLY SNIPPED

Problem statement:

IDLE_TIME DOES NOT WORK TO SPECIFY WHEN A SESSION IS AUTOMATICALLY SNIPPED

---

Hdr: 3315723 9.2.0.1.0 RDBMS 9.2.0.1.0 PRODID-5 PORTID-453 
Abstract:       IDLE_TIME DOES NOT WORK TO SPECIFY WHEN A SESSION IS AUTOMATICALLY SNIPPED 
*** 12/12/03 10:48 am *** 
TAR: 
---- 
3536104.995 
. 
PROBLEM: 
-------- 
Why do idle sessions DO NOT get snipped (v$session.status) as soon as  
IDLE_TIME is reached? 
. 
Also if sessions are eventually snipped by Oracle (post the time that  
IDLE_TIME criteria has been met), how can we tell (dictionary view) exactly  
when Oracle snipped the session and use this information to correlate to the  
last time the session was inactive? The data from V$SESSION.LAST_CALL_ET does  
not help since this column continues to change even after the session has been  
snipped.to  
. 
. 
DIAGNOSTIC ANALYSIS: 
-------------------- 
Tested in-house. 
. 
WORKAROUND: 
----------- 
Do not use IDLE_SESSION 
. 
RELATED BUGS: 
------------- 
Bug 940247 (not reproducible), however this bug is for sessions that get  
snipped before IDLE_TIME expiration. 
  
. 
REPRODUCIBILITY: 
---------------- 
Everytime 
. 
TEST CASE: 
---------- 
I used 9203 on Sun (should be reproducible 
SESSION A 
~~~~~~~~~~~~ 
Connect / as sysdba; 
show parameter resource_limit   < -- make sure it is set to TRUE 
. 
Create profile idle_test limit idle_time 1; 
. 
create user idle_test_user identified by idle_test_user 
default tablespace users temporary tablespace temp 
quota 5m on users 
profile idle_test; 
. 
Grant connect,create session to idle_test_user; 
. 
. 
SESSION B 
~~~~~~~~~~~~ 
	set time on; 
	connect idle_test_user/idle_test_user; 
	Select * from user_resource_limits;  < -- wait 1 minute 
. 
. 
SESSION A 
~~~~~~~~~~~~ 
alter session set nls_date_format='dd-mm-rr hh24:mi:ss'; 
username='IDLE_TEST_USER'; 
select sysdate from dual; 
. 
. 
NOTE: The session does not get SNIPPED at the minute mark. Sometimes it gets  
snipped 3-6 times longer than what was specified by IDLE_TIME. 
. 
STACK TRACE: 
------------ 
NA 
. 
SUPPORTING INFORMATION: 
----------------------- 
NA 
. 
24 HOUR CONTACT INFORMATION FOR P1 BUGS: 
---------------------------------------- 
NA 
. 
DIAL-IN INFORMATION: 
-------------------- 
NA 
. 
IMPACT DATE: 
------------ 
NA 
. 
*** 12/12/03 10:49 am *** (CHG: Sta-&gt;16) 
*** 12/12/03 12:20 pm *** (CHG: Asg-&gt;NEW OWNER) 
*** 12/12/03 06:24 pm *** 
*** 12/12/03 06:25 pm *** (CHG: Sta-&gt;10) 
*** 12/14/03 09:53 am *** (CHG: Sta-&gt;16) 
*** 12/14/03 09:53 am *** 
From the TAR: 
  Created a profile with an IDLE_TIME parameter of 1 (minute).   
  Assigned a test ID, SE1, to the profile.  
  open an SQLPUS session, connect as SE1 and issue a simple select command.  
  Open a second session and connect as SYSTEM. Monitor the STATUS and  
  LAST_CALL_ET for the SE1 session.  
  The status should change from INACTIVE to SNIPPED after 60 seconds.  
  Instead it takes from  132 to 171 seconds for the status to change.  
  If I issue a command from the SE1 session after 60 seconds, but before the  
  status has been SNIPPED, the command  runs and the LAST_CALL_ET is reset. 
  If I issue the command after the status is SNIPPED, the command fails with 
  the ORA-02396 as expected. 
  I need to able to explain the discrepancy between the IDLE_TIME parameter 
  and the acutal time out, if not correct it. 
. 
In my case, no sessions were snipped before the set value for IDLE_TIME.  
However, the time that the sessions stayed INACTIVE and when these actually  
get SNIPPED, are never exactly at the time that IDLE_TIME is set or  
predictable at what time after IDLE_TIME has passed. It appears that IDLE_TIME  
works in the sense of disconnecting sessions, but not when one would expect  
(ie, from the value given to it) 
. 
*** 12/23/03 06:05 pm *** 
*** 12/23/03 06:05 pm *** (CHG: Sta-&gt;10) 
*** 12/24/03 01:20 pm *** (CHG: Sta-&gt;16) 
*** 12/24/03 01:20 pm *** 
. 
Test 1 (30 minutes) 
=================== 
. 
LAST_CALL_ET 
		------------------------------ -------- ----------------- ------------ 
		IDLE_TEST_USER                 INACTIVE 24-12-03 09:57:06         1857 
. 
LAST_CALL_ET 
		------------------------------ -------- ----------------- ------------ 
		IDLE_TEST_USER                 SNIPED   24-12-03 09:57:06         1863 
. 
. 
Test 2 (30 minutes) 
=================== 
. 
LAST_CALL_ET 
		------------------------------ -------- ----------------- ------------ 
		IDLE_TEST_USER                 INACTIVE 24-12-03 10:30:26         1891 
. 
LAST_CALL_ET 
		------------------------------ -------- ----------------- ------------ 
		IDLE_TEST_USER                 SNIPED   24-12-03 10:30:26         1893 
. 
Test 3 (30 minutes) 
=================== 
. 
LAST_CALL_ET 
		------------------------------ -------- ----------------- ------------ 
		IDLE_TEST_USER                 INACTIVE 24-12-03 12:56:43         1878 
. 
LAST_CALL_ET 
		------------------------------ -------- ----------------- ------------ 
		IDLE_TEST_USER                 SNIPED   24-12-03 12:56:43         1881 
. 
. 
Test 4 (5 minutes) 
================== 
. 
LAST_CALL_ET 
		------------------------------ -------- ----------------- ------------ 
		IDLE_TEST_USER                 INACTIVE 24-12-03 13:49:51          418 
. 
LAST_CALL_ET 
		------------------------------ -------- ----------------- ------------ 
		IDLE_TEST_USER                 SNIPED   24-12-03 13:49:51          418 
. 
Test 5 (5 minutes) 
================== 
. 
LAST_CALL_ET 
		------------------------------ -------- ----------------- ------------ 
		IDLE_TEST_USER                 INACTIVE 24-12-03 14:01:36          418 
. 
LAST_CALL_ET 
		------------------------------ -------- ----------------- ------------ 
		IDLE_TEST_USER                 SNIPED   24-12-03 14:01:36          418 
. 
. 
. 
Test 6 (5 minutes) 
================== 
. 
LAST_CALL_ET 
		------------------------------ -------- ----------------- ------------ 
		IDLE_TEST_USER                 INACTIVE 24-12-03 14:09:41          419 
. 
LAST_CALL_ET 
		------------------------------ -------- ----------------- ------------ 
		IDLE_TEST_USER                 SNIPED   24-12-03 14:09:41          419 
. 
. 
. 
Observations: 
Test1: Session was snipped 59 seconds after idle_time setting. 
Test2: Session was snipped 1 minute and 40 seconds after idle_time setting. 
Test3: Session was snipped 1 minute and 22 seconds after idle_time setting. 
Test4: Session was snipped 2 minutes after idle_time setting 
Test5: Session was snipped 2 minutes after idle_time setting 
Test6: Session was snipped 2 minutes after idle_time setting 
. 
Questions: 
1) Why do sessions do not get snipped at exactly the time directed by  
IDLE_TIME?  
2) Is there a dictionary view that one can use to find out the exact time that  
a session was snipped due to inactivity? 
   LAST_CALL_ET cannot be used for this purpose since its value continues to  
increase even after the session has been snipped. 
*** 12/26/03 11:51 am *** 
*** 12/29/03 07:41 pm *** (CHG: Sta-&gt;10) 
*** 12/29/03 07:41 pm *** 
*** 12/30/03 09:34 am *** (CHG: Sta-&gt;16) 
*** 12/30/03 09:34 am *** 
Thx for the update above. We will await dev's response. 
Also, we still need to know if there is any data dictionary view that can show  
(accurately, if possible) how long a session has been sniped due to incativity  
by PMON. See details on this on previous update (questions at the end).   
*** 12/30/03 03:59 pm *** (CHG: Sta-&gt;32) 
*** 12/30/03 03:59 pm *** 
It's not a bug that the session is not sniped immediately after idle time 
expires.  PMON does the idle time check only once per minute, so it can 
take up to idle_time+60 for an idle session to be noticed.  It may take a 
bit longer if PMON is very busy. If it takes much longer, there may be a 
problem (PMON may be stuck, for example).  
*** 12/30/03 04:04 pm *** 
*** 12/31/03 04:33 am ***