前阵子刚写过11g密码延迟登陆的新特性,11g oracle在登陆密码输入错误时候不会立刻中断这个连接而会递增等待时间,这有可能在失败登陆N次以后达到一个很长的阀值(10s),从而导致session 大量积压导致问题的严重化,今天就碰到了问题,PMS team在转换密钥的时候出现了问题,应用一直狂连数据库,但是由于密码不正确,延迟登陆导致latch无法释放:

[oracle@db-38 ~]$ ora active
17:15:10 up 153 days, 7:09, 4 users, load average: 4.05, 2.06, 1.51

SID USERNAME MACHINE EVENT PARAM W WT SQL ST LT LOGON_TIME
—— ———- ———————- —————————— ——————– —- —- —————————- — —— ———-
13 PMS_DATA JDBC Thin Client library cache lock 70041699512/69922707 0 1 /05uqdabhzncdc A 712 712
592/5177346

1518 JDBC Thin Client library cache lock 70041699512/69873934 0 23 / A 3326 3325
872/5177347

47 JDBC Thin Client library cache lock 70041699512/69871194 0 512 / A 3265 3264
728/5177347

66 PMS_DATA JDBC Thin Client library cache lock 70041699512/69368085 0 4 /05uqdabhzncdc A 712 712
936/5177346

81 JDBC Thin Client library cache lock 70041699512/69462971 0 65 / A 3265 3264
488/5177347

112 JDBC Thin Client library cache lock 70041699512/69462926 0 287 / A 3265 3264
384/5177347

143 PMS_DATA JDBC Thin Client library cache lock 70041699512/69465605 0 10 /05uqdabhzncdc A 353 353
904/5177346

175 PMS_DATA JDBC Thin Client library cache lock 70041699512/69879432 0 4 /05uqdabhzncdc A 353 353
952/5177346

176 JDBC Thin Client library cache lock 70041699512/69871148 0 35 / A 3265 3264
456/5177347

205 PMS_DATA JDBC Thin Client library cache lock 70041699512/69741301 0 4 /05uqdabhzncdc A 334 334
968/5177346

206 JDBC Thin Client library cache lock 70041699512/69334255 0 8 / A 3203 3203
792/5177347

230 PMS_DATA JDBC Thin Client library cache lock 70041699512/69873526 0 4 /05uqdabhzncdc A 334 334
240/5177346

239 JDBC Thin Client library cache lock 70041699512/69982781 0 899 / A 3203 3203
552/5177347

269 JDBC Thin Client library cache lock 70041699512/69581692 0 8 / A 3203 3203
904/5177347

273 JDBC Thin Client library cache lock 70041699512/69975729 0 #### / A 3203 3203
320/5177347

274 PMS_DATA JDBC Thin Client library cache lock 70041699512/69463830 0 4 /05uqdabhzncdc A 334 334
936/5177346

306 JDBC Thin Client library cache lock 70041699512/69462865 0 662 / A 3203 3203
160/5177347

328 JDBC Thin Client library cache lock 70041699512/69873315 0 299 / A 3265 3264
720/5177347

335 PMS_DATA JDBC Thin Client library cache lock 70041699512/69919546 0 4 /05uqdabhzncdc A 334 334
800/5177346

337 JDBC Thin Client library cache lock 70041699512/69334200 0 #### / A 3203 3203
328/5177347

370 JDBC Thin Client library cache lock 70041699512/69462821 0 341 / A 3203 3203
472/5177347

393 PMS_DATA JDBC Thin Client library cache lock 70041699512/69876983 0 1 /05uqdabhzncdc A 334 334
216/5177346

421 PMS_DATA JDBC Thin Client library cache lock 70041699512/69334639 0 4 /05uqdabhzncdc A 334 334
728/5177346

496 PMS_DATA JDBC Thin Client library cache lock 70041699512/69739562 0 4 /05uqdabhzncdc A 334 334
568/5177346

518 PMS_DATA JDBC Thin Client library cache lock 70041699512/69463187 0 4 /05uqdabhzncdc A 334 334
296/5177346

558 PMS_DATA JDBC Thin Client library cache lock 70041699512/69339321 0 16 /05uqdabhzncdc A 334 333
544/5177346

589 PMS_DATA JDBC Thin Client library cache lock 70041699512/69337381 0 10 /05uqdabhzncdc A 334 333
088/5177346

614 JDBC Thin Client library cache lock 70041699512/70146651 0 917 / A 3203 3203
208/5177347

686 JDBC Thin Client library cache lock 70041699512/70146811 0 209 / A 3326 3325
256/5177347

742 JDBC Thin Client library cache lock 70041699512/69738879 0 509 / A 3203 3203
880/5177347

810 JDBC Thin Client library cache lock 70041699512/70146851 #### #### / A 3326 3326
312/5177347

877 JDBC Thin Client library cache lock 70041699512/69736715 0 830 / A 3326 3325
880/5177347

911 PMS_DATA JDBC Thin Client library cache lock 70041699512/69463812 0 4 /05uqdabhzncdc A 733 733

SID USERNAME MACHINE EVENT PARAM W WT SQL ST LT LOGON_TIME
—— ———- ———————- —————————— ——————– —- —- —————————- — —— ———-
480/5177346

969 PMS_DATA JDBC Thin Client library cache lock 70041699512/70147770 0 4 /05uqdabhzncdc A 733 733
208/5177346

998 PMS_DATA JDBC Thin Client library cache lock 70041699512/69764944 0 16 /05uqdabhzncdc A 733 733
880/5177346

1026 JDBC Thin Client library cache lock 70041699512/69464853 0 353 / A 3326 3326
984/5177347

1028 PMS_DATA JDBC Thin Client library cache lock 70041699512/69747146 0 16 /05uqdabhzncdc A 353 353
824/5177346

1061 JDBC Thin Client library cache lock 70041699512/69871277 0 2 / A 3265 3264
816/5177347

1089 JDBC Thin Client library cache lock 70041699512/69335003 0 248 / A 3203 3203
432/5177347

14 JDBC Thin Client library cache lock 70041699512/70146744 0 563 / A 3265 3264
072/5177347

1103 JDBC Thin Client library cache lock 70041699512/69871239 0 308 / A 3265 3264
832/5177347

1133 JDBC Thin Client library cache lock 70041699512/69463104 0 131 / A 3448 3448
696/5177347

1163 PMS_DATA JDBC Thin Client library cache lock 70041699512/69339111 0 4 /05uqdabhzncdc A 712 712
248/5177346

1199 PMS_DATA JDBC Thin Client library cache lock 70041699512/69580040 0 1 /05uqdabhzncdc A 712 712
392/5177346

1200 JDBC Thin Client library cache lock 70041699512/69463060 0 275 / A 3448 3448
496/5177347

1261 PMS_DATA JDBC Thin Client library cache lock 70041699512/70147768 0 16 /05uqdabhzncdc A 712 712
072/5177346

1357 PMS_DATA JDBC Thin Client library cache lock 70041699512/69883770 0 1 /05uqdabhzncdc A 712 712
240/5177346

1358 JDBC Thin Client library cache lock 70041699512/69334294 0 221 / A 3326 3325
504/5177347

1383 PMS_DATA JDBC Thin Client library cache lock 70041699512/69335098 0 10 /05uqdabhzncdc A 712 712
912/5177346

1390 JDBC Thin Client library cache lock 70041699512/69990749 0 395 / A 3326 3325
464/5177347

1419 PMS_DATA JDBC Thin Client library cache lock 70041699512/69463259 0 16 /05uqdabhzncdc A 712 712
200/5177346

1423 JDBC Thin Client library cache lock 70041699512/69579445 0 230 / A 3326 3325
616/5177347

1443 PMS_DATA JDBC Thin Client library cache lock 70041699512/69986146 0 4 /05uqdabhzncdc A 712 712
008/5177346

1456 JDBC Thin Client library cache lock 70041699512/69966048 0 23 / A 3326 3325
672/5177347

1487 JDBC Thin Client library cache lock 70041699512/70146756 0 #### / A 3326 3325
696/5177347

1511 PMS_DATA JDBC Thin Client library cache lock 70041699512/69463648 0 4 /05uqdabhzncdc A 712 712
872/5177346

1097 WMS_SH6 plsqldev.exe db file sequential read 14/933621/1 0 0 0dpbfbpz8sp8a/0dpbfbpz8sp8a A 189 14688

查找到对应机器为:xen-staging08-vm13,通过trigger 定位到session信息 与xen-staging08-vm13一致,通过kill 此machine的所有session 压力暂时得到缓解,通过与应用沟通发现今天在打jar包的时候密码出现问题。trigger 如下:

记录用户登录失败触发器:
CREATE OR REPLACE TRIGGER logon_denied_to_alert
AFTER servererror ON DATABASE
DECLARE
message VARCHAR2(168);
ip VARCHAR2(15);
v_os_user VARCHAR2(80);
v_module VARCHAR2(50);
v_action VARCHAR2(50);
v_pid VARCHAR2(10);
v_sid NUMBER;
v_program VARCHAR2(48);
BEGIN
IF (ora_is_servererror(1017)) THEN

— get ip FOR remote connections :
IF upper(sys_context(‘userenv’, ‘network_protocol’)) = ‘TCP’ THEN
ip := sys_context(‘userenv’, ‘ip_address’);
END IF;

SELECT sid INTO v_sid FROM sys.v_$mystat WHERE rownum < 2; SELECT p.spid, v.program INTO v_pid, v_program FROM v$process p, v$session v WHERE p.addr = v.paddr AND v.sid = v_sid; v_os_user := sys_context('userenv', 'os_user'); dbms_application_info.read_module(v_module, v_action); message := to_char(SYSDATE, 'YYYYMMDD HH24MISS') || ' logon denied from ' || nvl(ip, 'localhost') || ' ' || v_pid || ' ' || v_os_user || ' with ' || v_program || ' – ' || v_module || ' ' || v_action; sys.dbms_system.ksdwrt(2, message); END IF; END; / [oracle@db-38 ~]$ tailalert Thu May 24 17:19:24 2012 20120524 171924 logon denied from 10.63.0.118 19195 deploy with JDBC Thin Client ? JDBC Thin Client


通过ADR 的 Oracle Net diagnostic 也可以查找如下信息:

adrci> show alert

Choose the alert log from the following homes to view:

1: diag/tnslsnr/db-38/listener
2: diag/rdbms/wmssh6/wmssh6
Q: to quit

Please select option: 1
Output the results to file: /tmp/alert_8079_47814_listener_5.ado

2012-05-24 17:03:18.734000 +08:00
24-MAY-2012 17:03:18 * (CONNECT_DATA=(SID=wmssh6)(CID=(PROGRAM=JDBC Thin Client)(HOST=__jdbc__)(USER=deploy))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.63.0.118)(PORT=54578)) * establish * wmssh6 * 0
24-MAY-2012 17:03:18 * (CONNECT_DATA=(SID=wmssh6)(CID=(PROGRAM=JDBC Thin Client)(HOST=__jdbc__)(USER=deploy))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.63.0.118)(PORT=54579)) * establish * wmssh6 * 0
24-MAY-2012 17:03:18 * (CONNECT_DATA=(SID=wmssh6)(CID=(PROGRAM=JDBC Thin Client)(HOST=__jdbc__)(USER=deploy))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.63.0.118)(PORT=54577)) * establish * wmssh6 * 0
24-MAY-2012 17:03:18 * (CONNECT_DATA=(SID=wmssh6)(CID=(PROGRAM=JDBC Thin Client)(HOST=__jdbc__)(USER=deploy))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.63.0.118)(PORT=54582)) * establish * wmssh6 * 0
24-MAY-2012 17:03:18 * (CONNECT_DATA=(SID=wmssh6)(CID=(PROGRAM=JDBC Thin Client)(HOST=__jdbc__)(USER=deploy))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.63.0.118)(PORT=54586)) * establish * wmssh6 * 0
24-MAY-2012 17:03:18 * (CONNECT_DATA=(SID=wmssh6)(CID=(PROGRAM=JDBC Thin Client)(HOST=__jdbc__)(USER=deploy))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.63.0.118)(PORT=54581)) * establish * wmssh6 * 0
24-MAY-2012 17:03:18 * (CONNECT_DATA=(SID=wmssh6)(CID=(PROGRAM=JDBC Thin Client)(HOST=__jdbc__)(USER=deploy))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.63.0.118)(PORT=54585)) * establish * wmssh6 * 0
24-MAY-2012 17:03:18 * (CONNECT_DATA=(SID=wmssh6)(CID=(PROGRAM=JDBC Thin Client)(HOST=__jdbc__)(USER=deploy))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.63.0.118)(PORT=54584)) * establish * wmssh6 * 0
24-MAY-2012 17:03:18 * (CONNECT_DATA=(SID=wmssh6)(CID=(PROGRAM=JDBC Thin Client)(HOST=__jdbc__)(USER=deploy))) * (ADDRESS=(PROTOCOL=tcp)(HOST=10.63.0.118)(PORT=54583)) * establish * wmssh6 * 0

可以发现大量登陆信息 配合trigger信息 可以更好的诊断问题。


reference:

Using and Disabling the Automatic Diagnostic Repository (ADR) with Oracle Net for 11g [ID 454927.1]