国产xxxx99真实实拍_久久不雅视频_高清韩国a级特黄毛片_嗯老师别我我受不了了小说

資訊專欄INFORMATION COLUMN

oracle監聽自動重啟問題記錄

IT那活兒 / 3120人閱讀
oracle監聽自動重啟問題記錄


問題背景


有一段時間,某數據庫在整點期間總是會發出幾條連接失敗的告警，如下

2019-08-14 10:00:22, 29.211.?.?/??db can not connect, Warning from 5.223-mon_pri_conn.sh!


分析過程


1.分析監聽日志發現監聽存在重啟行為

14-AUG-2019 10:00:16 * (CONNECT_DATA=(SERVICE_NAME=dbinst1)(CID=(PROGRAM=sqlplus)(HOST=localhost.bss_rh6_dqjkj01_35.176)(USER=ftpuser))) * (ADDRESS=(PROTOCOL=tcp)(HOST=29.211.35.176)(PORT=19573)) * establish * dbinst1 * 0
2019-08-14T10:00:17.907210+08:00
14-AUG-2019 10:00:17 * (CONNECT_DATA=(CID=(PROGRAM=)(HOST=__jdbc__)(USER=))(SERVICE_NAME=dbinst1)) * (ADDRESS=(PROTOCOL=tcp)(HOST=29.211.177.93)(PORT=63570)) * establish * dbinst1 * 12518
TNS-12518: TNS:listener could not hand off client connection   <-----10:00:17監聽開始異常

 TNS-12540: TNS:internal limit restriction exceeded
14-AUG-2019 10:00:17 * (CONNECT_DATA=(CID=(PROGRAM=)(HOST=__jdbc__)(USER=))(SERVICE_NAME=dbinst1)) * (ADDRESS=(PROTOCOL=tcp)(HOST=29.211.31.19)(PORT=43753)) * establish * dbinst1 * 12518
TNS-12518: TNS:listener could not hand off client connection
 TNS-12540: TNS:internal limit restriction exceeded
14-AUG-2019 10:00:17 * (CONNECT_DATA=(CID=(PROGRAM=)(HOST=__jdbc__)(USER=))(SERVICE_NAME=dbinst1)) * (ADDRESS=(PROTOCOL=tcp)(HOST=29.211.35.160)(PORT=15812)) * establish * dbinst1 * 12518
TNS-12518: TNS:listener could not hand off client connection
 TNS-12540: TNS:internal limit restriction exceeded

....

14-AUG-2019 10:00:20 * 12582
TNS-12582: TNS:invalid operation
 TNS-12615: TNS:preempt error
Error listening on: (ADDRESS=(PROTOCOL=ipc)(PARTIAL=yes)(QUEUESIZE=1))
14-AUG-2019 10:00:21 * establish * 1159
TNS-01159: Internal connection limit has been reached; listener has shut down <---10:00:21監聽自動重啟 TNS-12540: TNS:internal limit restriction exceeded
No longer listening on: (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=29.211.16.112)(PORT=1521)))
No longer listening on: (DESCRIPTION=(ADDRESS=(PROTOCOL=ipc)(KEY=LISTENER)))
No longer listening on: (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=29.211.16.131)(PORT=1521)))
2019-08-14T10:00:46.748331+08:00
System parameter file is /u01/app/12.2.0/grid/network/admin/listener.ora

---異常前每秒短連接

     11 14-AUG-2019 09:59:55
      1 14-AUG-2019 09:59:56
      1 14-AUG-2019 09:59:57
      1 14-AUG-2019 09:59:59
     18 14-AUG-2019 10:00:00
     16 14-AUG-2019 10:00:01
     13 14-AUG-2019 10:00:02
      4 14-AUG-2019 10:00:03
      6 14-AUG-2019 10:00:04
     10 14-AUG-2019 10:00:05 <-----監聽重啟前存在大量的短連接行為
     53 14-AUG-2019 10:00:06
     35 14-AUG-2019 10:00:07
     47 14-AUG-2019 10:00:08
     65 14-AUG-2019 10:00:09
     105 14-AUG-2019 10:00:10
     61 14-AUG-2019 10:00:11
     31 14-AUG-2019 10:00:12
     38 14-AUG-2019 10:00:13
      5 14-AUG-2019 10:00:15
      3 14-AUG-2019 10:00:16

---異常整個期間數據庫等待事件正常，無明顯高消耗



2.排查問題期間的os負載情況

OSWBB_ARCHIVE_DEST /u01/osw/oswbb/archive

zzz ***Wed Aug 14 10:00:10 CST 2019

procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu-----

 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st

31  6      0 446655712  33212 1998720    0    0     1     3    0    0  1  1 98  0  0
21 22      0 446779968  35236 2008236    0    0 16300    96 259964 240440 11  3 83  3  0
25 27      0 446795360  37040 2020368    0    0 29096    48 235608 212541 11  3 82  4  0
zzz ***Wed Aug 14 10:00:24 CST 2019
procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 6 18      0 443893696  72420 2204804    0    0     1     3    0    0  1  1 98  0  0
13 12      0 444055840  74432 2228936    0    0 22880    16 90258 85804  5  2 88  6  0
 6 17      0 444172864  76036 2250128    0    0 19980   100 70041 61176  4  3 86  7  0
zzz ***Wed Aug 14 10:00:36 CST 2019
procs -----------memory---------- ---swap-- -----io---- --system-- -----cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 6 20      0 444360928  83052 2341764    0    0     1     3    0    0  1  1 98  0  0
 6 24      0 444552928  83740 2098432    0    0  4436  1212 67242 61741  4  3 85  8  0
125 220      0 444898240  84812 2102292    0    0  3892  1544 174504 140362 12 13 55 19  0


1.10秒的時候 r21 b22, 該機器為ssd存儲，平常cpu-b不到5，這里值已經有點異常

2.36秒的時候出現r 125 b220，可能為監聽重啟積壓導致，且異常時間點在監聽重啟后，不能確認是該問題導致故障。




top - 10:00:36 up 288 days, 14:24,  2 users,  load average: 215.59, 68.64, 29.25
Tasks: 8823 total,  15 running, 8808 sleeping,   0 stopped,   0 zombie
Cpu(s):  8.4%us,  2.2%sy,  0.0%ni, 88.6%id,  0.6%wa,  0.0%hi,  0.3%si,  0.0%st
Mem:  1058551988k total, 611291252k used, 447260736k free,    87332k buffers
Swap: 20971516k total,        0k used, 20971516k free,  2151908k cached


1.近一分鐘load達到215，且較5分鐘、15分鐘load值出現直線上升。

2.通常在linux平臺 load avg為系統整體load, 包含 cpu load, io load等等.簡單理解為 R+D狀態的process,不代表cpu使用率，但load高一定存在某一方面的高負載情況.



重點排查一下異常期間的ps 數據，排除S(sleep)狀態進程，可以看到大量的IO相關D進程

[oracle@dbserver1 tmp]$ cat /tmp/ps1024.txt  | awk {print $1,$9,$10,$13,$14} | sort  | uniq -c
    454 oracle filp_o D oracledbinst11 (LOCAL=NO)    <-----通過排查filp_o為linux 打開文件的內核函數      3 oracle get_wr D oracledbinst11 (LOCAL=NO)
     35 oracle lookup D oracledbinst11 (LOCAL=NO)
      1 oracle lookup D ora_m001_dbinst11 
      1 oracle - R ps -aeo
     16 oracle sync_b D oracledbinst11 (LOCAL=NO)
      1 root ? R /bin/netstat -ap
      2 root ? R /bin/ps -p
[oracle@dbserver1 tmp]$ 

[oracle@dbserver1 tmp]$ cat /tmp/ps1024.txt | grep 10:00 | awk {print $1,$9,$10,$11,$13,$14}  | sort | uniq -c
    112 oracle filp_o D 10:00:14 oracledbinst11 (LOCAL=NO)        <---------                           10:00:14建立的短連接 112

115 oracle filp_o D 10:00:15 oracledbinst11 (LOCAL=NO)        <---------                            10:00:15建立的短連接 115 積壓的大量短連接積處于filp_o 狀態，io可能存在異常

     75 oracle filp_o D 10:00:16 oracledbinst11 (LOCAL=NO)
      9 oracle filp_o D 10:00:17 oracledbinst11 (LOCAL=NO)
      1 oracle filp_o D 10:00:36 oracledbinst11 (LOCAL=NO)
      6 oracle lookup D 10:00:12 oracledbinst11 (LOCAL=NO)
     38 oracle lookup D 10:00:13 oracledbinst11 (LOCAL=NO)
     33 oracle lookup D 10:00:14 oracledbinst11 (LOCAL=NO)
     33 oracle lookup D 10:00:15 oracledbinst11 (LOCAL=NO)
     47 oracle lookup D 10:00:16 oracledbinst11 (LOCAL=NO)
     17 oracle lookup D 10:00:17 oracledbinst11 (LOCAL=NO)
      5 oracle lookup D 10:00:18 oracledbinst11 (LOCAL=NO)


排查ash信息再次確認數據庫負載較低，io響應也在毫秒級，無明顯異常

使用strace跟蹤測試建立連接期間，發現監聽派生 LOCAL=NO進程后會讀取大量的ORACLE_HOME本地lib庫,并進一步排查/u01文件系統狀態

[oracle@dbserver1 tmp]$  cat /tmp/stsqlplus.txt | grep 12.2.0/db
126319 open("/u01/app/oracle/product/12.2.0/db/lib/libsqlplus.so", O_RDONLY) = 3
126319 open("/u01/app/oracle/product/12.2.0/db/lib/libclntsh.so.12.1", O_RDONLY) = 3
126319 open("/u01/app/oracle/product/12.2.0/db/lib/libclntshcore.so.12.1", O_RDONLY) = 3
126319 open("/u01/app/oracle/product/12.2.0/db/lib/libmql1.so", O_RDONLY) = 3
126319 open("/u01/app/oracle/product/12.2.0/db/lib/libipc1.so", O_RDONLY) = 3
126319 open("/u01/app/oracle/product/12.2.0/db/lib/libnnz12.so", O_RDONLY) = 3


[oracle@dbserver1 tmp]$ lsblk 
NAME            MAJ:MIN   RM   SIZE RO TYPE MOUNTPOINT
sda               8:0      0 837.3G  0 disk 
sda1            8:1      0     1G  0 part /boot
sda2            8:2      0   100G  0 part /
sda3            8:3      0    20G  0 part [SWAP]
sda4            8:4      0     1K  0 part 
sda5            8:5      0    20G  0 part /opt
sda6            8:6      0    20G  0 part /usr
sda7            8:7      0    20G  0 part /var/log
sda8            8:8      0   200G  0 part /u01                                       <-sda8 本地盤掛在的$ORACLE_HOME,核查是否存在問題sdb               8:16     0   1.5T  0 disk 

.....
sdo               8:224    0    30G  0 disk 
sdp               8:240    0   300G  0 disk 
sdq              65:0      0   300G  0 disk 
sdr              65:16     0     2T  0 disk 
asm!oradata-127 251:65025  0     2T  0 disk 

zzz ***Wed Aug 14 10:00:11 CST 2019
avg-cpu:  %user   %nice %system %iowait  %steal   %idle
      11.35    0.00    2.83    3.21    0.00   82.61

<-------cpu整體使用率不高，iowait整體也不高Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await  svctm  %util
sda 169.00     5.00  642.00    8.00 29000.00    52.00    89.39    10.19   35.69   2.54 100.00      

<-------- sda-- /u01--ORACLE_HOME文件系統IO居高不下 await出現明顯等待 
sdb 0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
sdc 0.00     0.00  223.00   24.00  5640.00   452.00    49.33     0.08    0.33   0.25   6.10

zzz ***Wed Aug 14 10:00:24 CST 2019
Device:         rrqm/s   wrqm/s     r/s     w/s    rkB/s    wkB/s avgrq-sz avgqu-sz   await  svctm  %util
sda  176.00     1.00  656.00   25.00 23552.00   104.00    57.73    15.94   43.65   3.47 100.00    

<--------sda-- /u01--ORACLE_HOME文件系統 iowait持續居高不下 
sdb  0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
sdc  0.00     0.00   40.00   20.00   336.00   3



問題原因


1.通過與應用側溝通了解到在整點期間app營業廳會推出搶購活動導致短連接明顯的上升

2.主機管理員反饋由于本地盤RAID出現故障盤導致響應異常,以至于大量短連接掛死在ORACLE_HOME的lib庫讀取上，達到監聽隊列上限值后引發監聽重啟.


改進措施


1.推進應用程序短連接進行連接池化整改。

2.更換本地盤為SSD存儲提升ORACLE_HOME的讀寫性能。


注:本次故障版本為oracle12.2，在oracle12c之后的版本中，數據庫會持續寫出大量的垃圾trace信息不僅影響IO性能且影響文件系統正常使用率,建議多帶帶指定diag目錄以及使用SSD存儲安裝ORACLE_HOME 。


END




文章版權歸作者所有，未經允許請勿轉載,若此文章存在違規行為，您可以聯系管理員刪除。

轉載請注明本文地址：http://specialneedsforspecialkids.com/yun/130031.html

相關文章

  • Oracle APEX 系列文章4：在阿里云上打造屬于你自己的APEX完整開發環境 (安裝XE, O

    摘要：更多關于阿里云彈性公網的介紹請移步這里。你下載的版本可能比鋼哥的高，不過安裝步驟是一樣的。總結至此，數據庫的完整開發環境就搭建好了。在接下來的文章里，鋼哥將帶你做進一步的優化，敬請期待。 本文是鋼哥的Oracle APEX系列文章中的其中一篇，完整 Oracle APEX 系列文章如下： Oracle APEX 系列文章1：Oracle APEX, 讓你秒變全棧開發的黑科技 Orac...

    pepperwang 評論0 收藏0

發表評論

0條評論

IT那活兒

男|高級講師

TA的文章

閱讀更多
最新活動
閱讀需要支付1元查看
<