``` 某日，数据库告警最最最核心的一套数据库1节点hang，立马打开连接窗口，查看当前系统负载， 发现topas已经无法执行，过滤LOCAL=NO会话kill掉已经无法执行， 报错无法分配内存，无法连接数据库，重启操作系统，恢复服务。 ``` 事后最终定位问题，发现在执行kill会话命令报错无法分配内存，早已指明了故障原因，服务器相关指标也早已指向内存不足，只是由于以下两方面原因导致定位问题走了许多弯路，甚至一度只能猜测原因： ``` 1. AIX内存由于大部分情况下有很大一部分file cache，导致监控长期显示内存使用率均在90%以上， 所以并未真正注意AIX内存各个部分占用比例指标，导致故障服务器内存其实早已在危险边缘试探， 而我们并未及时调整。 2. 对AIX内存各个部分占比、管理方式、相关参数设置一知半解， 导致未从监控数据相关信息中发现这是由于内存不足-会话增长-内存耗尽导致。 ``` 下面就故障分析过程以及AIX内存管理分享，供大家参考。 # 1. 故障现象 - 监控系统告警数据库hang，通过已连接ssh会话查看CPU 100%，服务器hang。 - 除已经连接用户外，无法再通过ssh、sqlplus连接服务器。 **环境概述** 数据库版本11.2.0.4，操作系统AIX 7.1 # 2. 初步分析，是Oracle还是OS出了问题？ 一般对于远程连接无法执行命令，根据经验一般为swap频繁page in、page out，内存耗尽导致，那到底是哪儿出了问题呢？下面就需要结合下面两部分进行分析： - 操作系统nmon、oswatcher数据 - Oracle集群日志、数据库日志进行诊断。、 ## 2.1 数据库日志以及ASH分析 数据库以及集群日志 1. 故障节点alert日志 - 在故障前alert日志并无异常，故障期间，可以看到alert日志如下，15:29分之前日志并无异常，未截取。 - 结合报错Error 1013 during filling up usn avail cache，Oracle Mos有文档，但是与发生故障Oracle版本并不对应，现象也不匹配，所以可以作为参考。 ``` Mon Jan 11 15:29:56 2021 AP01: warning -- apply server 20, sid 6085 waiting for event (since 731 seconds): AP01: warning -- apply server 42, sid 6126 waiting for event (since 354 seconds): AP01: warning -- apply server 45, sid 3788 waiting for event (since 342 seconds): AP01: warning -- apply server 44, sid 3530 waiting for event (since 564 seconds): AP01: warning -- apply server 40, sid 2419 waiting for event (since 343 seconds): AP01: warning -- apply server 33, sid 4578 waiting for event (since 344 seconds): Mon Jan 11 15:30:30 2021 AP01: warning -- apply server 31, sid 1049 waiting for event (since 435 seconds): Mon Jan 11 15:32:07 2021 Mon Jan 11 15:32:07 2021 Mon Jan 11 15:32:07 2021 [27328748] Error 1013 during filling up usn avail cacheMon Jan 11 15:32:07 2021 [19595412] Error 1013 during filling up usn avail cache *********************************************************************** *********************************************************************** Mon Jan 11 15:32:17 2021 [16058276] Error 1013 during filling up usn avail cache Mon Jan 11 15:32:12 2021 [11799172] Error 1013 during filling up usn avail cache Mon Jan 11 15:32:19 2021 [2886074] Error 1013 during filling up usn avail cache Mon Jan 11 15:32:16 2021 ``` 2. 集群日志 - 可以看到是在节点1告警hang之后，集群监测到了异常。 - 集群日志并无相关报错信息，只是监测到1节点资源无法确定状态，置为unknown，在其集群其他crsd、cssd、agent日志中均类似，并无相关资源或进程报错。 ``` 2021-01-11 15:30:48.975: [UiServer][11311]{1:44279:29645} Done for ctx=132437ab0 2021-01-11 15:32:27.616: [ COMMCRS][11568]clsc_auth_send: (1325a2470) Connection not active 2021-01-11 15:32:38.344: [ COMMCRS][11568]Authorization failed, network error 2021-01-11 15:32:38.344: [UiServer][11568] clscanswer returned error: 3 2021-01-11 15:32:55.936: [ AGFW][9769]{0:1071:37} Agfw Proxy Server received the message: RESOURCE_STATUS[Proxy] ID 20481:912859 2021-01-11 15:32:55.936: [ AGFW][9769]{0:1071:37} Verifying msg rid = ora.asm wbxtdb01 1 2021-01-11 15:32:55.936: [ AGFW][9769]{0:1071:37} Received state change for ora.asm wbxtdb01 1 [old state = ONLINE, new state = UNKNOWN] 2021-01-11 15:32:55.936: [ AGFW][9769]{0:1071:37} Received state LABEL change for ora.asm wbxtdb01 1 [old label = Started, new label = ] 2021-01-11 15:32:55.936: [ AGFW][9769]{0:1071:37} Agfw Proxy Server sending message to PE, Contents = [MIDTo:2|OpID:3|FromA:{Invalid|Node:0|Process:0|Type:0}|ToA:{Invalid|Node:-1|Process:-1|Type:-1}|MIDFrom:0|Type:4|Pri2|Id:8026336:Ver:2] 2021-01-11 15:32:55.936: [ AGFW][9769]{0:1071:37} Agfw Proxy Server replying to the message: RESOURCE_STATUS[Proxy] ID 20481:912859 2021-01-11 15:33:20.391: [ COMMCRS][11568]clsc_auth_send: (13254d650) Connection not active 2021-01-11 15:33:22.407: [ OCRMSG][5912]prom_send: Failed to send [12] 2021-01-11 15:33:22.407: [ OCRMSG][5912]GIPC error [12] msg [gipcretConnectionLost] 2021-01-11 15:33:25.099: [ AGFW][9769]{0:1071:37} Agfw Proxy Server received the message: RESOURCE_PROBE[ora.asm wbxtdb01 1] ID 4097:17486001 2021-01-11 15:33:25.099: [ AGFW][9769]{0:1071:37} Agfw Proxy Server forwarding the message: RESOURCE_PROBE[ora.asm wbxtdb01 1] ID 4097:17486001 to the agent /u01/11.2.0/grid/bin/oraagent_grid 2021-01-11 15:33:26.200: [ COMMCRS][11568]Authorization failed, network error 2021-01-11 15:33:26.201: [UiServer][11568] clscanswer returned error: 3 2021-01-11 15:34:30.743: [ AGFW][9769]{0:1071:38} Agfw Proxy Server received the message: RESOURCE_STATUS[Proxy] ID 20481:912892 2021-01-11 15:34:30.743: [ AGFW][9769]{0:1071:38} Verifying msg rid = ora.asm wbxtdb01 1 2021-01-11 15:34:30.743: [ AGFW][9769]{0:1071:38} Received state LABEL change for ora.asm wbxtdb01 1 [old label = , new label = CHECK TIMED OUT] 2021-01-11 15:34:30.743: [ AGFW][9769]{0:1071:38} Agfw Proxy Server sending message to PE, Contents = [MIDTo:2|OpID:3|FromA:{Invalid|Node:0|Process:0|Type:0}|ToA:{Invalid|Node:-1|Process:-1|Type:-1}|MIDFrom:0|Type:4|Pri2|Id:8026352:Ver:2] 2021-01-11 15:34:30.743: [ AGFW][9769]{0:1071:38} Agfw Proxy Server replying to the message: RESOURCE_STATUS[Proxy] ID 20481:912892 2021-01-11 15:34:53.907: [ AGFW][9769]{0:1071:38} Agfw Proxy Server received the message: CMD_COMPLETED[Proxy] ID 20482:17486028 2021-01-11 15:34:53.907: [ AGFW][9769]{0:1071:38} Agfw Proxy Server replying to the message: CMD_COMPLETED[Proxy] ID 20482:17486028 2021-01-11 15:34:53.907: [ AGFW][9769]{0:1071:38} Agfw received reply from PE for resource state change for ora.asm wbxtdb01 1 2021-01-11 15:35:41.347: [UiServer][11568] CS(1324f3910)set Properties ( grid,13241e050) 2021-01-11 15:35:59.223: [UiServer][11568] CS(1325501f0)set Properties ( grid,13254f990) ``` 3. ASH信息 - 可以看到在故障前并无异常等待事件，均为正常OGG集成投递以及一些weblogic正常执行SQL会话。 - 由于此时操作系统已无法响应，所以15:30~15:36相关信息ASH中未采样到。 ## 2.2 操作系统监控数据分析 遇到数据库严重故障，操作系统的CPU、memory、I/O等信息对定位问题就变得非常重要， 不结合操作系统监控数据往往只能根据数据库残留的一些信息对故障原因进行猜测。 1. oswatcher数据 oracle 11.2.0.4 RAC会自带oswatcher，可通过下面命令查看oswatcher数据存放目录，默认30秒采样一次，保留48小时。 ``` # ps -ef|grep OSW oracle 2087 27820 0 10:01 pts/3 00:00:00 grep --color=auto OSW grid 3638 1 0 Jan21 ? 00:22:47 /bin/sh ./OSWatcher.sh 30 48 NONE /u01/app/grid/tfa/repository/suptools/db-oracle-node1/oswbb/grid/archive grid 4224 3638 0 Jan21 ? 00:01:03 /bin/sh ./OSWatcherFM.sh 48 /u01/app/grid/tfa/repository/suptools/db-oracle-node1/oswbb/grid/archive ``` 拿到oswatcher archive目录所有数据之后，可将数据拷贝至任意安装java机器或windows机器使用如下命令解析： ``` 如果解析报错[10:02:01]An exception occured in insertVmstatLists on line 0，则需要设置相应时间格式如下： # Linux export LANG=zh_US 需要英文格式时间戳，重新设置LANG变量，重新运行java -jar即可 # windows 如果是想在windows机器上解析osw文件，需要在控制面板-区域-中设置为英语(美国)即可。 命令： java -jar -Xmx512M OSWbba.jar -i /mnt/hgfs/database/oswbb/archive OSWbba.jar可以通过拷贝服务器端，也可以单独下载oswatcher使用解压后的oswbba。jar ``` - 可以看到在故障时间段15:30~15:45期间，CPU到最后15:45左右服务器hang都没有达到100%。 - 在故障期间，发生了内存交换，这说明故障期间，可用内存不足，内存耗尽。 - oswatcher还会生成每隔30秒的ps命令生成的进程信息，我们通过分析ps相关信息发现LOCAL=NO会话在故障前后如下： 在15:00到15:15分左右，LOCAL=NO会话由2800增长至3500,15:15到15:30左右，会话数维持在3500左右略有下降，在15:30到15:45服务器hang期间，会话由于得不到响应，暴涨至最高4500直到重启服务器。 **~注：所以oswatcher的ps统计信息也是非常重要的信息，可以真实判断会话总数趋势。~** 2. nmon数据 - 如果说oswatcher图粒度不够细，那么nmon数据展示则更为容易分辨趋势。 - 下面就从摘取最为重要的三个维度CPU、磁盘I/O、内存趋势图：     ## 2.3 初步分析结果 - 结合OS监控、数据库日志，我们可以初步推断为操作系统内存耗尽，引发swap使用，从I/O hdisk0达到busy 100%也可印证，导致服务器hang，进而导致数据库hang。 - 以前没注意过AIX内存管理机制，所以未对相关重要指标进行监控以及管理，导致服务器内存其实早就已经开始在危险边缘试探而我们却并未在意，最终导致业务期间会话突增700连接压垮服务器，引发故障。 - 至于应用为何突然增加700会话由于某些原因并未深究，但是这次故障也提醒了我们需要在一些服务器细化重点指标监控上注意，防患未然。 # 3. 进一步分析，服务器内存早已岌岌可危 - 为什么说服务器内存早已岌岌可危，我们从下面两张图开始分析(第二张图为第一张图的数值)：   - 看到这里，其实对AIX内存有所了解即可一眼判断，服务器内存是真的已经不足了这是因为： - %comp计算内存在故障前已经达到95%以上，内存即将耗尽。 # 4. 通过故障，了解AIX内存管理 俗话说，吃一堑长一智，其实了解清楚AIX内存管理方式以及各个指标含义，定位问题之后，发现故障很严重，但是原因远比想象简单，我们也从故障中吸取教训，下面就详细讲述AIX内存管理。 ## 4.1 AIX内存分类 AIX内存可通过用途分为两大类： ``` 1. Computational memory, also known as computational pages, consists of the pages that belong to working-storage segments or program text (executable files) segments. 2. File memory (or file pages) consists of the remaining pages. These are usually pages from permanent data files in persistent storage. ``` 上述AIX官方文档描述，引用http://blog.itpub.net/29455589/viewspace-1075369/叙述： ``` ~计算内存： 凡是进程/程序运行中用程序代码向操作系统申请的内存，全部是计算内存， 也就是说除非这个程序运行起来，除了自身代码占用的内存，一点额外的内存也不用， 否则它几乎必然会造成计算内存占用的。说“几乎”，是因为计算内存、非计算内存都是 指物理内存，如果一个程序申请了1MB内存，但一段时间没有用这部分内存， 很可能 在其他进程需要内存，且物理内存比较紧张时，按照LRU算法（Latest Recently Unused）， 被操作系统部分或全部page out到paging space中， 如果全部被page out了，可以说这个 时刻，此进程没有使用计算内存。换句话说，就是程序申请了1MB内存，那么它在某一时 刻占用的计算内存从0字节～1MB都有可能。 当进程退出，或者意外崩溃，对于操作系统 来说，它知道进程不在了，而进程申请的内存，操作系统明确知道是哪些的，在资源回收 的过程中， 会自动把这个进程申请的内存释放掉，这个过程是很快的。所以我们可以看 到：如果计算内存高企，我们把应用一停，也就是把使用计算内存最多的进程停止，计 算内存占用率立刻就下来了。~ ``` ``` ~非计算内存： 操作系统明确知道这部分内存的用途是放硬盘对应数据的，所以，显然 这部分内存不是任何进程可以控制，也就是说不可能一个程序主动要求分配多少非计算 内存或者释放多少。 这部分完全是操作系统在直接管理：分配、记录状态、使用、释 放，其他进程只可能用间接手段影响非计算内存，例如读写文件。~ ``` - 可以看到主要两部分%comp %ncomp内存组成，这两个指标可以通过topas或nmon获得。 - 从解释中可以看出，SGA与PGA所占用内存均为%comp，均需要程序自己去释放，不属于AIX VM管理范畴，所以这也就是上述案例中计算内存达到95%以上继续申请计算内存，由于内存耗尽系统使用page space导致系统hang。 ## 4.2 AIX内存控制参数 AIX内存控制参数主要为如下： ``` - minfree 最小保留内存，当内存总页数少于该值，则AIX开始steal页面，steal页面来源方式由于内存使用不同而不同，AIX 7.1 默认960 - maxfree 当内存free list不足minfree时steal页面，当free达到maxfree时停止steal，AIX 7.1 默认1088 - minperm/minperm% 最小file page数量或比例，AIX 7.1 默认3% - maxperm/maxperm% 最大file page数量或比例，AIX 7.1 默认90% - maxpin% 最大可以pin住的内存比例，默认90% - maxclient% jfs2 文件系统缓存使用client page，不能超过%maxperm，AIX 7.1 默认90% - lru_file_repage 控制当file page占用比例在%minperm与%maxperm之间时，内存管理repaging时是否steal计算内存与file page，AIX 5L默认为1，AIX 6.1默认为0,一般设置为0，AIX 7.1之后vmo命令已经无法设置该命令。 ``` 相关概念： - 当file page占用在%minperm与%maxperm之间时，当根据lru算法需要repage内存或内存不足需要steal page时，AIX 7.1会默认只steal file page，也就是不会偷计算内存。 - 当file page占用在%minperm之下时，一般来说，低于%minperm除了个别非常空闲系统以外，基本发生在计算内存占用非常大，导致file page无法获得更多内存，即物理内存紧张时，所以此时需要repage时，会同时根据lru算法steal计算内存与file page。上文例子即发生了这种情况，如果当物理内存不足，所有内存均在使用，无法repage完成内存申请，则会发生page space使用，内存耗尽，服务器hang。 ## 4.3 AIX内存配置与查看 ``` # vmo -a 查看所有vm相关设置 # vmo -a 查看虚拟内存机制相关设置 　　 # vmo -r -o minfree=1000 -o maxfree=1008 # vmo -p -o maxclient% = 90 # vmo -p -o maxperm%=90 可以指定百分比也可以指定绝对值maxperm参数 # vmo -p -o minperm%=5 可以指定百分比也可以指定绝对值minperm参数 ``` ~注：-r与-o结合，设置reboot values,-p对当前与reboot都生效，但是只能用于可动态调整参数，默认AIX page为4k，不带%为page数量。有个别参数不可动态调整，不可使用-p选项设置。~ ``` # svmon -G 查看内存使用概览 # svmon -U oracle 查看某个用户使用内存概览 ``` ## 4.4 AIX的大页 ``` # vmo -r -o lgpg_size=16777216 -o lgpg_regions=256 配置256个16M页面。 如果要为共享内存使用大页面，还需要将AIX的v_pinshm参数设置为1（默认为0）， 使VMM可以固定内存池中的页，以避免发生页面交换 # vmo -r -o maxpin%=50 最大可以pin住内存比例 # vmo -r -o v_pinshm=1 允许共享内存pin住 SQL> alter system set lock_sga=true scope=spfile sid='*'; 配置Oracle可以锁定共享内存SGA钉在内存中 ``` # 5. 需要调整AIX VM相关参数吗？ ``` AIX UNIX系统的配置策略，在默认情况下是为文件系统类应用默认的优化。 如果应用是AIX上运行的数据库类应用，则默认的AIX配置并不适用。 ``` 所以如果是作为数据库服务器，则默认的内存相关参数还是需要进行调整，可以适当调整minfree与maxfree，降低%maxperm，同样也适用于Linux，在Redhat Linux中，对应参数为vm.min_free_kbytes，但是也不建议将这些参数调整过大，调整过大将导致内存无法充分利用，会适得其反。 # 总结 ``` 1. 当故障原因定位方向正确时，会发现处处留存的线索都对的上，当方向不正确时，总会有很匪夷所思的地方。 2. 对于AIX、Linux运行不同类型服务需要设置合理参数，虽然本次故障并不是由于参数设置导致。 3. 对于监控系统，要监控一些重点指标，本次案例就是由于监控一直报各个系统内存使用率过高(大部分为 非计算内存占用)将真正计算内存占比很高的服务器的告警淹没在了平时认为可忽略的告警消息中。 ``` 下面为AIX参数官方文档解释： ``` 1. lru_file_repage AIX 7.1 vmo已经无法查询该参数 when the number of permanent memory pages (numperm) falls between minperm and maxperm (or the number of client memory pages falls between minperm and maxclient), this setting indicates whether repaging rates are considered when deciding to evict permanent memory pages or computational memory pages. Setting this to 0 tells AIX to ignore repaging rates and favor evicting permament memory pages, keeping more computational memory in RAM. The AIX 5L default is 1/true (consider the repaging rate), The AIX 6.1 default is 0/false (now a restricted setting). 2. maxpin% tunable can be used to adjust the amount of memory that can be pinned. The maxpin% tunable specifies the maximum percentage of real memory that can be pinned. 3. minperm% maxperm% If percentage of RAM occupied by file pages falls below minperm, page-replacement steals both file and computational pages. If percentage of RAM occupied by file pages is between minperm and maxperm, page-replacement steals only file pages. 4. maxclient% The maxclient parameter controls the maximum percentage of memory occupied by client-segment pages which is where Enhanced JFS file data is cached. Note that the maxclient value cannot exceed the maxperm value. Maxclient represents the maximum number of client pages that can be used for buffer cache. The enhanced JFS file system uses client pages for its buffer cache. The limit on client pages in real memory is enforced using maxclient. The LRU daemon begins to run when the number of client pages is within the number of minfree pages of maxclient 's threshold. The LRU daemon attempts to steal client pages that have not been referenced recently. If the number of file pages is lower than the value of the minperm parameter, any page that has not been referenced can be selected for replacement. Maxclient also affects NFS clients and compressed pages. Also note that maxclient is generally set to a value that is less than or equal to the maxperm parameter. 5. minfree Minimum acceptable number of real-memory page frames in the free list. When the size of the free list falls below this number, the VMM begins stealing pages. It continues stealing pages until the size of the free list reaches maxfree. 6. maxfree Maximum size to which the free list will grow by VMM page-stealing. The size of the free list may exceed this number as a result of processes terminating and freeing their working-segment pages or the deletion of files that have pages in memory. The VMM attempts to keep the size of the free list greater than or equal to minfree. When page faults or system demands cause the free list size to fall below minfree, the page-replacement algorithm runs. The size of the free list must be kept above a certain level (the default value of minfree) for several reasons. For example, the operating system's sequential-prefetch algorithm requires several frames at a time for each process that is doing sequential reads. Also, the VMM must avoid deadlocks within the operating system itself, which could occur if there were not enough space to read in a page that was required to free a page frame. ```