Re: Trigger not firing!!!!!!!!!!(URGENT)
- From: "Radoulov, Dimitre" <cichomitiko@xxxxxxxxx>
- To: <Rich.Jesse@xxxxxxxxxxxxxxxxx>, <oracle-l@xxxxxxxxxxxxx>
- Date: Thu, 9 Jun 2005 16:11:50 +0200
Hmm ... I'm still thinkin' that it logs all the sessions and commits without
autonomous transaction:
16:00:07 SQL> CREATE OR REPLACE TRIGGER logon_audit AFTER LOGON ON DATABASE
16:00:18 2 BEGIN
16:00:18 3 execute immediate
16:00:18 4 'alter session set events ''10046 trace name context
forever,level 12'' ';
16:00:24 5 insert into sys.log_info
16:00:24 6 values(sysdate,ora_client_ip_address,ora_login_user);
16:00:24 7 END;
16:00:24 8 /
Trigger created.
Elapsed: 00:00:00.31
16:00:25 SQL> conn test/test@dbarepo1
Connected.
16:00:32 SQL> select 'X' from dual;
'
-
X
Elapsed: 00:00:00.01
16:00:42 SQL> exit
I think the first commit is here(rlbk=0):
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=222 op='TABLE ACCESS FULL DUAL (cr=3 r=0
w=0 time=99 us)'
XCTEND rlbk=0, rd_only=0 -----> !!!
WAIT #0: nam='log file sync' ela= 22244 p1=7 p2=0 p3=0
$ view dbarepo1_ora_13832.trc
"dbarepo1_ora_13832.trc" [Read only] 210 lines, 11911 characters
/app/oracle/admin/dbarepo1/udump/dbarepo1_ora_13832.trc
Oracle9i Enterprise Edition Release 9.2.0.4.0 - Production
With the Partitioning, OLAP and Oracle Data Mining options
JServer Release 9.2.0.4.0 - Production
ORACLE_HOME = /app/oracle/product/9i
System name: SunOS
Node name: ess038
Release: 5.8
Version: Generic_117350-02
Machine: sun4u
Instance name: dbarepo1
Redo thread mounted by this instance: 1
Oracle process number: 10
Unix process pid: 13832, image: oracle@ess038 (TNS V1-V3)
*** SESSION ID:(10.512) 2005-06-09 16:00:32.019
APPNAME mod='sqlplus@ess038 (TNS V1-V3)' mh=0 act='' ah=0
=====================
PARSING IN CURSOR #2 len=69 dep=2 uid=0 oct=42 lid=0 tim=7017570116495
hv=3841573810 ad='2ef4ce98'
alter session set events '10046 trace name context forever,level 12'
END OF STMT
EXEC #2:c=0,e=5064,p=0,cr=0,cu=0,mis=1,r=0,dep=2,og=4,tim=7017570109425
=====================
PARSING IN CURSOR #2 len=77 dep=2 uid=0 oct=2 lid=0 tim=7017570171198
hv=3939809092 ad='2dcbfa40'
INSERT into sys.log_info
values(sysdate,ora_client_ip_address,ora_login_user)
END OF STMT
PARSE
#2:c=30000,e=54187,p=0,cr=0,cu=0,mis=1,r=0,dep=2,og=4,tim=7017570171180
BINDS #2:
EXEC #2:c=0,e=29846,p=0,cr=1,cu=7,mis=0,r=1,dep=2,og=4,tim=7017570201411
=====================
PARSING IN CURSOR #1 len=182 dep=1 uid=0 oct=47 lid=0 tim=7017570201634
hv=2221084585 ad='2ef55a24'
BEGIN
execute immediate
'alter session set events ''10046 trace name context forever,level 12'' ';
insert into sys.log_info
values(sysdate,ora_client_ip_address,ora_login_user);
END;
END OF STMT
EXEC #1:c=30000,e=98628,p=0,cr=1,cu=7,mis=1,r=1,dep=1,og=4,tim=7017570201619
WAIT #0: nam='log file sync' ela= 24885 p1=5 p2=0 p3=0
WAIT #0: nam='SQL*Net message to client' ela= 5 p1=1413697536 p2=1 p3=0
WAIT #0: nam='SQL*Net message from client' ela= 1261 p1=1413697536 p2=1 p3=0
WAIT #0: nam='SQL*Net message to client' ela= 3 p1=1413697536 p2=1 p3=0
WAIT #0: nam='SQL*Net message from client' ela= 177 p1=1413697536 p2=1 p3=0
WAIT #0: nam='SQL*Net message to client' ela= 3 p1=1413697536 p2=1 p3=0
WAIT #0: nam='SQL*Net message from client' ela= 392 p1=1413697536 p2=1 p3=0
WAIT #0: nam='SQL*Net message to client' ela= 2 p1=1413697536 p2=1 p3=0
WAIT #0: nam='SQL*Net message from client' ela= 247 p1=1413697536 p2=1 p3=0
WAIT #1: nam='SQL*Net message to client' ela= 2 p1=1413697536 p2=1 p3=0
WAIT #1: nam='SQL*Net message from client' ela= 370 p1=1413697536 p2=1 p3=0
=====================
PARSING IN CURSOR #1 len=22 dep=0 uid=24 oct=3 lid=24 tim=7017570243386
hv=4119976668 ad='2dddf5ac'
SELECT USER FROM DUAL
END OF STMT
PARSE #1:c=0,e=1991,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,tim=7017570243373
WAIT #1: nam='SQL*Net message to client' ela= 3 p1=1413697536 p2=1 p3=0
WAIT #1: nam='SQL*Net message from client' ela= 445 p1=1413697536 p2=1 p3=0
BINDS #1:
EXEC #1:c=0,e=131,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=7017570244540
WAIT #1: nam='SQL*Net message to client' ela= 3 p1=1413697536 p2=1 p3=0
WAIT #1: nam='SQL*Net message from client' ela= 196 p1=1413697536 p2=1 p3=0
WAIT #1: nam='SQL*Net message to client' ela= 2 p1=1413697536 p2=1 p3=0
FETCH #1:c=0,e=332,p=0,cr=3,cu=0,mis=0,r=1,dep=0,og=4,tim=7017570245287
WAIT #1: nam='SQL*Net message from client' ela= 213 p1=1413697536 p2=1 p3=0
=====================
PARSING IN CURSOR #2 len=116 dep=1 uid=0 oct=3 lid=0 tim=7017570247066
hv=431456802 ad='2df28dd8'
select
o.owner#,o.name,o.namespace,o.remoteowner,o.linkname,o.subname,o.dataobj#,o.flags
from obj$ o where o.obj#=:1
END OF STMT
PARSE #2:c=0,e=1169,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=0,tim=7017570247054
BINDS #2:
bind 0: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=08 oacfl2=1 size=24
offset=0
bfp=feb6b8b4 bln=22 avl=03 flg=05
value=222
EXEC #2:c=0,e=5986,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=7017570253476
FETCH #2:c=0,e=89,p=0,cr=3,cu=0,mis=0,r=1,dep=1,og=4,tim=7017570253667
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=222 op='TABLE ACCESS FULL DUAL (cr=3 r=0
w=0 time=190 us)'
WAIT #0: nam='SQL*Net message to client' ela= 4 p1=1413697536 p2=1 p3=0
WAIT #0: nam='SQL*Net message from client' ela= 436 p1=1413697536 p2=1 p3=0
=====================
PARSING IN CURSOR #1 len=40 dep=0 uid=24 oct=3 lid=24 tim=7017570272481
hv=62978080 ad='2ddd8554'
SELECT NULL FROM DUAL FOR UPDATE NOWAIT
END OF STMT
PARSE #1:c=0,e=10309,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,tim=7017570272468
BINDS #1:
EXEC #1:c=0,e=501,p=0,cr=3,cu=2,mis=0,r=0,dep=0,og=4,tim=7017570273272
WAIT #1: nam='SQL*Net message to client' ela= 3 p1=1413697536 p2=1 p3=0
WAIT #1: nam='SQL*Net message from client' ela= 7525 p1=1413697536 p2=1 p3=0
STAT #1 id=1 cnt=0 pid=0 pos=1 obj=0 op='FOR UPDATE (cr=0 r=0 w=0 time=0
us)'
STAT #1 id=2 cnt=1 pid=1 pos=1 obj=222 op='TABLE ACCESS FULL DUAL (cr=3 r=0
w=0 time=81 us)'
=====================
PARSING IN CURSOR #2 len=37 dep=1 uid=0 oct=3 lid=0 tim=7017570289615
hv=3468666020 ad='2de2fce4'
select text from view$ where rowid=:1
END OF STMT
PARSE #2:c=0,e=679,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=0,tim=7017570289602
BINDS #2:
bind 0: dty=11 mxl=16(16) mal=00 scl=00 pre=00 oacflg=18 oacfl2=1 size=16
offset=0
bfp=feb6cf8c bln=16 avl=16 flg=05
value=0000146B.0012.0001
EXEC #2:c=0,e=664,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=7017570290575
FETCH #2:c=0,e=74,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=4,tim=7017570290747
=====================
PARSING IN CURSOR #3 len=116 dep=2 uid=0 oct=3 lid=0 tim=7017570291201
hv=431456802 ad='2df28dd8'
select
o.owner#,o.name,o.namespace,o.remoteowner,o.linkname,o.subname,o.dataobj#,o.flags
from obj$ o where o.obj#=:1
END OF STMT
PARSE #3:c=0,e=264,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=4,tim=7017570291189
BINDS #3:
bind 0: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=08 oacfl2=1 size=24
offset=0
bfp=feb69928 bln=22 avl=02 flg=05
value=62
EXEC #3:c=0,e=249,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=4,tim=7017570291838
FETCH #3:c=0,e=63,p=0,cr=3,cu=0,mis=0,r=1,dep=2,og=4,tim=7017570291991
STAT #2 id=1 cnt=1 pid=0 pos=1 obj=62 op='TABLE ACCESS BY USER ROWID VIEW$
(cr=1 r=0 w=0 time=45 us)'
=====================
PARSING IN CURSOR #1 len=161 dep=0 uid=24 oct=3 lid=24 tim=7017570299877
hv=3096433403 ad='2ddd5930'
SELECT ATTRIBUTE,SCOPE,NUMERIC_VALUE,CHAR_VALUE,DATE_VALUE FROM
SYSTEM.PRODUCT_PRIVS WHERE (UPPER('SQL*Plus') LIKE UPPER(PRODUC
T)) AND (UPPER(USER) LIKE USERID)
END OF STMT
PARSE
#1:c=10000,e=18160,p=0,cr=5,cu=0,mis=1,r=0,dep=0,og=4,tim=7017570299863
BINDS #1:
EXEC #1:c=0,e=97,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=7017570300268
WAIT #1: nam='SQL*Net message to client' ela= 4 p1=1413697536 p2=1 p3=0
FETCH #1:c=0,e=81,p=0,cr=3,cu=0,mis=0,r=0,dep=0,og=4,tim=7017570300545
WAIT #1: nam='SQL*Net message from client' ela= 610 p1=1413697536 p2=1 p3=0
=====================
PARSING IN CURSOR #2 len=116 dep=1 uid=0 oct=3 lid=0 tim=7017570301820
hv=431456802 ad='2df28dd8'
select
o.owner#,o.name,o.namespace,o.remoteowner,o.linkname,o.subname,o.dataobj#,o.flags
from obj$ o where o.obj#=:1
END OF STMT
PARSE #2:c=0,e=109,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=7017570301808
BINDS #2:
bind 0: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=08 oacfl2=1 size=24
offset=0
bfp=feb699a0 bln=22 avl=03 flg=05
value=6253
EXEC #2:c=0,e=243,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=7017570302488
FETCH #2:c=0,e=72,p=0,cr=3,cu=0,mis=0,r=1,dep=1,og=4,tim=7017570302692
STAT #1 id=1 cnt=0 pid=0 pos=1 obj=6253 op='TABLE ACCESS FULL
SQLPLUS_PRODUCT_PROFILE (cr=3 r=0 w=0 time=73 us)'
WAIT #1: nam='SQL*Net message to client' ela= 3 p1=1413697536 p2=1 p3=0
WAIT #1: nam='SQL*Net message from client' ela= 205 p1=1413697536 p2=1 p3=0
=====================
PARSING IN CURSOR #2 len=37 dep=1 uid=0 oct=3 lid=0 tim=7017570304529
hv=3468666020 ad='2de2fce4'
select text from view$ where rowid=:1
END OF STMT
PARSE #2:c=0,e=98,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=7017570304516
BINDS #2:
bind 0: dty=11 mxl=16(16) mal=00 scl=00 pre=00 oacflg=18 oacfl2=1 size=16
offset=0
bfp=feb6cf8c bln=16 avl=16 flg=05
value=0000146B.0012.0001
EXEC #2:c=0,e=234,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=7017570305052
FETCH #2:c=0,e=59,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=4,tim=7017570305203
STAT #2 id=1 cnt=1 pid=0 pos=1 obj=62 op='TABLE ACCESS BY USER ROWID VIEW$
(cr=1 r=0 w=0 time=34 us)'
=====================
PARSING IN CURSOR #1 len=183 dep=0 uid=24 oct=3 lid=24 tim=7017570306550
hv=2009857449 ad='2dd2d330'
SELECT CHAR_VALUE FROM SYSTEM.PRODUCT_PRIVS WHERE (UPPER('SQL*Plus') LIKE
UPPER(PRODUCT)) AND ((UPPER(USER) LIKE USERID) OR
(USERID = 'PUBLIC')) AND (UPPER(ATTRIBUTE) = 'ROLES')
END OF STMT
PARSE #1:c=0,e=2928,p=0,cr=2,cu=0,mis=1,r=0,dep=0,og=4,tim=7017570306537
WAIT #1: nam='SQL*Net message to client' ela= 3 p1=1413697536 p2=1 p3=0
WAIT #1: nam='SQL*Net message from client' ela= 258 p1=1413697536 p2=1 p3=0
BINDS #1:
EXEC #1:c=0,e=94,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=7017570307488
WAIT #1: nam='SQL*Net message to client' ela= 3 p1=1413697536 p2=1 p3=0
WAIT #1: nam='SQL*Net message from client' ela= 167 p1=1413697536 p2=1 p3=0
FETCH #1:c=0,e=69,p=0,cr=3,cu=0,mis=0,r=0,dep=0,og=4,tim=7017570307940
WAIT #1: nam='SQL*Net message to client' ela= 3 p1=1413697536 p2=1 p3=0
WAIT #1: nam='SQL*Net message from client' ela= 166 p1=1413697536 p2=1 p3=0
STAT #1 id=1 cnt=0 pid=0 pos=1 obj=6253 op='TABLE ACCESS FULL
SQLPLUS_PRODUCT_PROFILE (cr=3 r=0 w=0 time=64 us)'
WAIT #1: nam='SQL*Net message to client' ela= 3 p1=1413697536 p2=1 p3=0
WAIT #1: nam='SQL*Net message from client' ela= 417 p1=1413697536 p2=1 p3=0
=====================
PARSING IN CURSOR #1 len=54 dep=0 uid=24 oct=47 lid=24 tim=7017570310717
hv=1432236634 ad='2dd2ab50'
BEGIN DBMS_APPLICATION_INFO.SET_MODULE(:1,NULL); END;
END OF STMT
PARSE #1:c=0,e=1499,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=0,tim=7017570310703
BINDS #1:
bind 0: dty=1 mxl=32(08) mal=00 scl=00 pre=00 oacflg=03 oacfl2=0 size=32
offset=0
bfp=feb5f830 bln=32 avl=08 flg=05
value="SQL*Plus"
APPNAME mod='SQL*Plus' mh=3669949024 act='' ah=4029777240
WAIT #1: nam='SQL*Net message to client' ela= 5 p1=1413697536 p2=1 p3=0
EXEC #1:c=10000,e=17649,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=4,tim=7017570328584
WAIT #1: nam='SQL*Net message from client' ela= 333 p1=1413697536 p2=1 p3=0
=====================
PARSING IN CURSOR #1 len=40 dep=0 uid=24 oct=3 lid=24 tim=7017570331112
hv=4282642546 ad='2dd29388'
SELECT DECODE('A','A','1','2') FROM DUAL
END OF STMT
PARSE #1:c=0,e=1764,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,tim=7017570331099
BINDS #1:
EXEC #1:c=0,e=93,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=7017570331496
WAIT #1: nam='SQL*Net message to client' ela= 5 p1=1413697536 p2=1 p3=0
FETCH #1:c=0,e=145,p=0,cr=3,cu=0,mis=0,r=1,dep=0,og=4,tim=7017570331825
WAIT #1: nam='SQL*Net message from client' ela= 554 p1=1413697536 p2=1 p3=0
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=222 op='TABLE ACCESS FULL DUAL (cr=3 r=0
w=0 time=99 us)'
XCTEND rlbk=0, rd_only=0
WAIT #0: nam='log file sync' ela= 22244 p1=7 p2=0 p3=0
WAIT #0: nam='SQL*Net message to client' ela= 3 p1=1413697536 p2=1 p3=0
*** 2005-06-09 16:00:42.333
WAIT #0: nam='SQL*Net message from client' ela= 9826344 p1=1413697536 p2=1
p3=0
=====================
PARSING IN CURSOR #1 len=20 dep=0 uid=24 oct=3 lid=24 tim=7017580183675
hv=1477081359 ad='2ef39fdc'
select 'X' from dual
END OF STMT
PARSE #1:c=0,e=1372,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,tim=7017580183659
BINDS #1:
EXEC #1:c=0,e=221,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=7017580184152
WAIT #1: nam='SQL*Net message to client' ela= 6 p1=1413697536 p2=1 p3=0
FETCH #1:c=0,e=159,p=0,cr=3,cu=0,mis=0,r=1,dep=0,og=4,tim=7017580184511
WAIT #1: nam='SQL*Net message from client' ela= 651 p1=1413697536 p2=1 p3=0
FETCH #1:c=0,e=2,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=7017580185440
WAIT #1: nam='SQL*Net message to client' ela= 3 p1=1413697536 p2=1 p3=0
WAIT #1: nam='SQL*Net message from client' ela= 2234471 p1=1413697536 p2=1
p3=0
XCTEND rlbk=0, rd_only=1
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=222 op='TABLE ACCESS FULL OBJ#(222) (cr=3
r=0 w=0 time=134 us)'
But, it commits even if the user issues rollback or fail to exit correctly:
16:05:36 SQL> select * from sys.log_info;
no rows selected
Elapsed: 00:00:00.01
16:05:49 SQL> conn test/test@dbarepo1;
Connected.
16:05:58 SQL> conn / as sysdba
Connected.
16:06:03 SQL> select * from sys.log_info;
LOGIN_DAT IPADDS USERNAME
--------- -------------------- ------------------------------
09-JUN-05 10.44.19.31 TEST
09-JUN-05 SYS
Elapsed: 00:00:00.00
16:06:04 SQL> conn test/test@dbarepo1
Connected.
16:06:12 SQL> rollback;
Rollback complete.
Elapsed: 00:00:00.01
16:06:17 SQL> conn / as sysdba
Connected.
16:06:20 SQL> select * from sys.log_info;
LOGIN_DAT IPADDS USERNAME
--------- -------------------- ------------------------------
09-JUN-05 10.44.19.31 TEST
09-JUN-05 SYS
09-JUN-05 10.44.19.31 TEST
09-JUN-05 SYS
Elapsed: 00:00:00.00
16:06:24 SQL> conn test/test@dbarepo1
Connected.
16:08:19 SQL> Killed
$ sqlplus '/ as sysdba'
SQL*Plus: Release 9.2.0.4.0 - Production on Thu Jun 9 16:08:39 2005
Copyright (c) 1982, 2002, Oracle Corporation. All rights reserved.
Connected to:
Oracle9i Enterprise Edition Release 9.2.0.4.0 - Production
With the Partitioning, OLAP and Oracle Data Mining options
JServer Release 9.2.0.4.0 - Production
16:08:40 SQL> select * from sys.log_info;
LOGIN_DAT IPADDS USERNAME
--------- -------------------- ------------------------------
09-JUN-05 10.44.19.31 TEST
09-JUN-05 SYS
09-JUN-05 10.44.19.31 TEST
09-JUN-05 SYS
09-JUN-05 10.44.19.31 TEST
09-JUN-05 SYS
6 rows selected.
Elapsed: 00:00:00.01
Cheers
Dimitre Radoulov
ETNØTEAM
----- Original Message -----
From: "Jesse, Rich" <Rich.Jesse@xxxxxxxxxxxxxxxxx>
To: <oracle-l@xxxxxxxxxxxxx>
Sent: Thursday, June 09, 2005 3:53 PM
Subject: RE: Trigger not firing!!!!!!!!!!(URGENT)
> Hi Dimitre,
>
> Some programs may auto-commit or auto-rollback on disconnect. Check a
> 10046 trace to see where the COMMIT happens. The row stays, so
> logically it must happen somewhere in the connection, right?
>
> Oooh, a LOGON trigger for a 10046 trace! :)
>
> Rich
>
> -----Original Message-----
> From: Radoulov, Dimitre [mailto:cichomitiko@xxxxxxxxx]=20
> Sent: Thursday, June 09, 2005 8:38 AM
> To: Jesse, Rich; oracle-l@xxxxxxxxxxxxx
> Subject: Re: Trigger not firing!!!!!!!!!!(URGENT)
>
>
>> 3) Wouldn't it be "better" if a procedure with a PRAGMA
>> AUTONOMOUS_TRANSACTION were called to do this, including the
> obligitory
>> COMMIT, thereby helping ensure that all connections (not just from the
>> SQL*Plus program) are logged?
>
> Why do you think that only the sqlplus's sessions will be logged?
>
>
> Regards
> Dimitre Radoulov
> --
> //www.freelists.org/webpage/oracle-l
--
//www.freelists.org/webpage/oracle-l
Other related posts:
