Skip to content

Oracle - 41. page

Tuxedo IPC 优化

[ID 1532550.1]

IPC 技术简介

IPC 被划分为三组操作系统级可调参数，分别为“信号量”、“消息”和“共享内存”。在深入研究 IPC 优化之前，我们首先来看一看上述各个独立功能的性质。

 

信号量

信号量是一种可以在操作系统级别设置的标志，用于提供一般的建议锁定机制（与文件锁相似）。信号量将某个资源锁定后，操作系统中的其他程序将无法访问该资源。您可以使用信号量来控制对文件、共享内存或任何其他需要限制访问的资源的访问权限。

想象一下那些争夺同一资源（例如某个文件）的进程所面临的问题。（此处的资源可能是任何东西，例如磁盘分区、共享内存段或打印机）。如果一个进程正在修改某个文件，而与此同时，另一个进程正在读取该文件，则后者可能会看到半新半旧的信息。如果两个进程同时修改该文件的内容，则很可能会得到一堆乱码。

为了防止此类情况发生，通常会使用一个信号量来保护共享资源。信号量初始化为“1”，表示资源可用。进程在访问资源之前，会首先检查信号量的值。如果值为 1，进程会立即将该值降为 0（表明该资源不再处于空闲状态），然后在确知其他进程无法执行相同操作的情况下对该资源执行所有必要的操作。如果信号量为 0，则进程必须先等待该值恢复到 1，然后再检查或修改该资源。在进程完成对资源的访问之后，它需要将信号量返回到 1，从而允许其他进程继续进行操作。

T信号量的基本功能在于，您可以对它进行设置、检查（以查看是否已设置），或者您可以等到信号量被清除，然后再进行设置。

有关信号量的一个复杂之处在于，在对信号量操作进行编程时，您请求的不是单个信号量，而是一个信号量组。您可以请求只包含一个信号量的信号量组，但 Tuxedo 不会这么做，因此，它只需创建一个信号量组即可获取大量信号量。

参与 Tuxedo 应用程序的每个进程都需要信号量。应用程序会在启动时检查操作系统中已配置的信号量的数量。如果已配置的数量不够多，启动将失败。


消息队列和消息

消息队列和消息为操作系统中的不同进程提供了一种用于传输消息并由此进行通信的机制。消息队列可在进程之间共享，并且，由一个进程放入队列的消息可以被其他进程提取。

Oracle Tuxedo 系统使用 UNIX 系统消息和消息队列进行客户端/服务器通信。此类消息的示例包括服务请求、服务回复、会话消息、未经请求的通知消息、管理消息和事务控制消息。

每个 MSSQ 组（Multiple Servers, Single Queue）的多个服务器程序和单个服务器程序都相应地有一个用于接收请求的消息队列。每个客户端本身也都相应地拥有用于接收回复的消息队列。指定 REPLYQ 参数的服务器程序则会拥有各自独立的回复队列。

调整内核消息参数对于适当优化应用程序而言至关重要。如果值不恰当，可能会造成无法启动或性能严重下降。

共享内存

顾名思义，“共享内存”是指操作系统中两个或多个进程之间共享的内存。通常，操作系统在执行某个进程时，会为该进程分配单独的内存空间，因而，所分配的内存范围只能由该进程使用。各个进程在自己的内存空间内运行时，它们之间互相影响的可能性就大大降低了。当这些进程开始通过共享内存的使用共享内存空间时，某个进程破坏共享内存的可能性会大大增加。

在 Tuxedo 环境中，共享内存用于 Bulletin Board 以及工作站侦听器（Workstation Listener，WSL) 进程的控制表。应用程序可能也会将共享内存用于其他用途。

Tuxedo 对 IPC 资源的使用

如前所述，Tuxedo 会大量使用来自操作系统的 IPC 资源。

附加到 Tuxedo Bulletin Board 的每个进程或线程都需要 UNIX 信号量。其中包括 native 客户端、服务器、WSH、WSL、BBL、TMS、Bridge、Domain 网关以及所有其他系统进程，例如 event broker 或 /Q 进程。

在Tuxedo启动之前，UNIX会预先分配信号量。在信号量过少的情况下，Tuxedo 系统会无法正常启动且会报告错误，表明信号量缺乏。因此，通常很容易确定操作系统的信号量是否过少。

消息队列的不同之处在于，它们由 Tuxedo 动态分配。每个 native 客户端和 WSH 都需要回复消息队列。每个服务器都需要请求队列，但多个服务器可以通过 RQADDR 参数共享请求队列（MSSQ 集）。多个服务器还可以拥有回复队列；如果设置了 REPLYQ=Y 开关，每个服务器都可以获得回复队列，即使是在 MSSQ 集中，也是如此。

此外，即使没有明确的规定，系统服务器也常常会分配回复队列，例如 TMS 服务器和 Domain 网关。由于消息队列是动态分配的（尤其是在动态调整 Tuxedo Server 数量的情况下），因此很难事先预测应用程序是否会出现消息队列问题。

共享内容由 Bulletin Board 以及其他子系统（例如 /WS、/Q、/Domain）使用。Bulletin Board 的大小由不同的 UBBCONFIG 参数控制，例如 MAXACCESSERS、MAXGTT、MAXSERVERS、MAXSERVICES。事实上，UBBCONFIG 中以 MAX 开头的几乎所有属性都会影响 Bulletin Board 的最终大小。

定义 IPC 限制

出于快速处理的目的，大多数 IPC 和共享内存 Bulletin Board 表都是静态分配的，因此对其进行正确优化至关重要。如果其大小过大，内存和 IPC 资源会出现过度消耗；如果其大小过小，便很容易超出限制，从而导致进程失败。

UBBconfig 文件下 RESOURCES 节中的以下可优化参数与 IPC 大小相关：

  • MAXACCESSERS – 一个节点上允许附加到 TUXEDO 系统的所有进程的最大数量。它不是所有进程的总和，而是进程最多的节点上的进程数量。默认值为 50。（您可以在每个计算机上重写 MACHINES 节中的 MAXACCESSERS。）
  • MAXSERVERS – 应用程序中服务器进程的最大数量，包括所有管理服务器（例如 BBL 和 TMS）。它是所有节点上服务器进程的总和。默认值为 50。
  • MAXSERVICES – 应用程序中可以发布的不同服务的最大数量。它是系统中所有服务的总和。默认值为 100。（设置此值时，请将默认值作为针对系统资源保留的数量。）

增加 MAXACCESSERS 的代价是，每增加一个访问器，节点就需要增加一个信号量。除了由 MAXACCESSERS 值添加的信号量开销外，系统进程也存在少量固定信号量开销。增加 MAXSERVERS 和 MAXSERVICES 的代价是，需要为各个服务器、服务和客户端项分别保留少量的共享内存。设置这些参数的目的是为应用程序的未来扩展做准备。尤其要仔细检查 MAXACCESSERS。

此外，还有三个参数会影响 IPC 大小，即 MAXGTT、MAXINTERFACES 和 MAXCONV：

  • MAXGTT – 指定在任何时候均受 Tuxedo 应用程序支持的全局事务的最大数量。修改此值将改变共享内存开销。
  • MAXINTERFACES – 指定此 Tuxedo 应用程序 CORBA 接口的最大数量。默认值为 100。修改此值将改变信号量和共享内存开销。
  • MAXCONV – 指定可在计算机上同时进行的会话的最大数量。MAXCONV 的值必须大于 0 且小于 32,768。在具有会话服务器的计算机上，默认值为 10，除此以外则为 1。修改此值将改变共享内存开销。

请注意，如果要评估修改这些参数所产生的影响，其计算过程非常复杂。最好使用 tmloadcf –c 或 tmboot –c 作为替代来获取 IPC 大小信息。

 

了解 Tuxedo IPC

首次尝试确定 IPC 的正确设置时，第一步只需在您尝试为其配置 IPC 资源的系统环境中对 ubbconfig 文件运行命令

 

tmloadcf –c [ubbconfig file]

 

即可。

运行此命令将生成类似以下内容的输出：

 

Ipc sizing (minimum /T values only) …

Fixed Minimums Per Processor

SHMMIN: 1
SHMALL: 1
SEMMAP: SEMMNI

Variable Minimums Per Processor

SEMUME,           A                             SHMMAX
SEMMNU,           *                               *
Node                    SEMMNS  SEMMSL  SEMMSL  SEMMNI  MSGMNI  MSGMAP  SHMSEG
——                  ——  ——  ——  ——  ——  ——  ——
PRODUCTIONMACH             105      13     100   A + 1      31      62    173K

where 1 <= A <= 8.

The number of expected application clients per processor should be added to each MSGMNI value.

 

在上表中，A 表示值介于 1 和 8 之间的变量。您可以用“A * SEMMS”列下的值（在本例中为 100）除 SEMMSL 的值（在本例中为 13），来确定 A 的值（在本例中，100/13 = 7.69 或四舍五入到 8）。得出 A 的值后，您就可以确定 SEMMNI，它等于 A + 1，在本例中即为 9。

列出的这些值是操作系统中各个属性可以设置的最小值。遗憾的是，tmloadcf –c 方法未涵盖所有对环境的 IPC 设置，且所示值只表示实际情况中运行系统环境所需的最小值。

一种更为完整的方法是，独立调整各个 IPC 资源的大小。这种做法需要统一的方法来执行。附加的 Excel 电子表格（请参阅附件：Tuxedo_IPC_Calculator.xls）中概述了下列方法，该方法可帮助您确定正确的值。

在开始调整 IPC 资源的大小之前，必须先了解和记录以下项目。下面的表格中有一栏是空白的，您可以使用该表格来帮助调整 IPC 的大小。

 

属性 描述 您的值
Servers 此节点上配置的 Tuxedo Server 的总数量。该节点是运行 Tuxedo 的物理计算机，因此这个数量不应包括在其他计算机上运行的服务器程序数量。
Servers with ReplyQ 已配置 REPLYQ=Y选项的 Tuxedo Server。
Servers in MSSQ 在MSSQ组中配置的服务器程序的总数量。
Total MSSQ Sets 实际的MSSQ组的总数量（相对于一组服务器程序的数量）。
Native Clients 环境中 native 客户端的数量（不是通过工作站处理器连接的客户端）。
Largest Message Size 系统将传输的最大消息大小。
Average Message Size 系统正在传输的消息的平均大小。
Message Queue Size 系统中 IPC 消息队列的大小，此值由在操作系统中设置的 MSGMNB 属性确定。
Total Inflight Messages 在任何时候系统中可能会发行的消息总数（如果您不知道具体的值，请将此属性设置得高一点）。
Total /Q Queuespaces 系统中 /Q 队列空间总数。
MAXWSCLIENTS 可与此计算机连接的工作站客户端的最大数量。此属性在 UBBConfig 中设置。
MAXACCESORS 按照 UBBConfig 文件 *RESOURCES 节中的内容进行设置。

 

上述属性需要在 UNIX 或 Windows 环境中进行配置。如果是在 UNIX 中配置这些属性，请与当地的系统管理员联系，以获取有关设置实施的帮助。如果是在 Windows 中进行更改，则请双击 Windows 控制面板中的“Oracle Tuxedo”（或“BEA Administration（BEA 管理）”）图标。有关如何通过 Windows 工具使用和配置 IPC 资源的详细信息，请参考如下文档：

http://download.oracle.com/docs/cd/E13161_01/tuxedo/docs10gr3/nt/ntadmin.html#wp418757

现在，我们来检查一下每个可能的 IPC 配置选项及其用途和正确的值。请注意，在查看下面的结构和公式时，默认值设置所示的是 Oracle 或操作系统供应商通常会推荐的设置。显然，每个供应商可能会针对其自身的操作系统推荐不同的值，但是您可以将这些值用作在整个操作系统中进行设置的参考值（请经常查看的操作系统手册，以确认系统环境中的设置和范围）。最小值设置指定可使用哪个公式来确定此属性可以设置的最小值，以使 Tuxedo 系统正常运行。最小值只应作为指示值使用，若将属性的值设置为最小值，在以后其他应用程序需要操作系统中的 IPC 资源或者 Tuxedo 系统发生扩展时，很可能会引起某些问题。

因此，正确的值通常介于最小值和所提供的默认值之间。如果无法肯定，请使用接近默认值的值，因为默认值提供了可伸缩性空间，同时也为平台上的其他 Tuxedo 实例提供了空间。请注意，IPC 设置会在操作系统中分配真实的内存。如果不需要使用大量资源，请不要在操作系统中分配过多的资源，因为这样会导致性能问题。

Oracle 针对每个平台提供了建议的 IPC 设置。这些建议的设置被称为“平台数据表”，Tuxedo 10gR3 的建议设置可通过以下链接找到：

http://download.oracle.com/docs/cd/E13161_01/tuxedo/docs10gr3/install/inspds.html

SEMMNS

 

完整名称： 信号量的最大数量
用途： Semmns 定义系统范围内可以分配给用户的单个 IPC 信号量的最大数量。
默认值： 1024
最小值设置： 至少设置为 MAXACCESSERS – MAXWSCLIENTS + 13

 

SEMMNI

 

完整名称： 信号量组的最大数量
用途： Semmni 指定可以同时存在于系统中的 IPC 信号量组的最大数量。
默认值： 1024
最小值设置： 使用命令 tmloadcf –c 确定此属性的适当值。

 

SEMMSL

 

完整名称： 每个标识符可具有的 IPC 信号量的最大数量
用途： Semmsl 指定每个信号量标识符可具有的单个 IPC 信号量的最大数量。
默认值： 2048
最小值设置： SEMMNS / SEMMNI

 

SEMMAP

 

完整名称： 信号量资源图的最大大小
用途： Semmap 指定用于在共享内存中分配新 IPC 信号量的可用空间资源图的大小。
默认值： 1024
最小值设置： SEMMNI + 2


SEMMNU

 

完整名称： 信号量 undo 结构的最大数量
用途： Semmnu 指定进程的 IPC undo 结构的最大数量
默认值： 1024
最小值设置： 与 SEMMNS 相同

 

SEMUME

 

完整名称： 挂起的 undo 操作的最大数量
用途： Semume 指定某给定进程可以在其上挂起 undo 操作的 IPC 信号量的最大数量。
默认值： 1024
最小值设置： 与 SEMMNS 相同


SHMMAX

 

完整名称： 最大共享内存大小
用途： Shmmax 指定系统范围内最大可允许的共享内存段大小。
默认值： 4194304 (4MB)
最小值设置： BBL 的大小很难确定，但 SHMMAX 必须大于 BBL 的大小。我们建议对该值保留系统默认值（通常介于 4MB 和 64MB 之间）。请注意，此设置仅针对 Tuxedo 所使用的 BBL。如果曾有其他应用程序在计算机上运行且使用了共享内存，则还必须根据该应用程序的共享内存使用情况对这一数字进行验证。


SHMSEG

 

完整名称： 每个进程的共享内存段数量
用途： Shmseg 定义每个进程的共享内存段的最大数量
默认值： 500
最小值设置： 对于繁忙的应用程序，必须至少设置为 32 到 64。任何小于 SHMMNI 的值均有效，稍高一点也可以接受。


SHMMNI

 

完整名称： 共享内存段的数量
用途： Shmmni 定义系统中共享内存段标识符的数量
默认值： 100 至 400，具体取决于您的系统环境
最小值设置： Tuxedo 要求 BLL 和每个 /Q 队列空间都有共享内存段。系统环境中的其他应用程序可能也需要共享内存段。通常情况下，100 即可，但在某些情况下可能需要更高的值。再次提醒，这一设置具体取决于运行 Tuxedo 应用程序的同一计算机上运行的其他应用程序，且应当根据具体情况进行处理。


SHMMIN

 

完整名称： 共享内存段的最小大小
用途： Shmmin 指定系统环境中共享内存段的最小大小。
默认值： 1
最小值设置： 设置为 1，即允许系统为共享内存段分配最低 1 字节的空间。


MSGMNI

 

完整名称： 消息标识符的最大数量
用途：

Msgmni 指定计算机上允许的系统范围内的消息队列的最大数量。
默认值： 256 至 512，具体取决于系统环境
最小值设置： MAXACCESSORS + (Servers with ReplyQ – Servers in MSSQ) + MSSQ组总数 + 7


MSGMAP

 

完整名称： 消息资源图大小
用途： Msgmap 指定 IPC 消息空间资源图中的条目数量
默认值： 8130
最小值设置： MSGTQL + 2 或 3。此设置取决于具体的平台。有关更多信息，请参阅您的平台数据表。


MSGMAX

 

完整名称： 消息最大大小
用途： Msgmax 定义最大的 IPC 消息大小（以字节为单位）
默认值： 65536
最小值设置： MSGMNB 的 75%


MSGMNB

 

完整名称： 消息队列的最大字节数
用途： Msgmnb 定义单个 IPC 消息队列上的最大字节数
默认值： 65536
最小值设置： 65536，您可以将它设置得更低，但是标准的 Tuxedo 队列大小是 65536 (64K)，诸如 128K 和 256K 之类的值也是可以的。但请注意，每个拥有队列的 Tuxedo Server 在开始构建队列时都会尽数使用这些内存。


MSGSSZ

 

完整名称： 消息段大小
用途： Msgssz 指定 IPC 消息段中的字节数
默认值： 64
最小值设置： 通常设置为 8、16、32 或 64（消息段大小以字节为单位）

 

MSGTQL

 

完整名称： 消息总数
用途： Msgtql 定义在任何时候系统中的 IPC 消息的最大数量
默认值： 1024 至 8128，具体取决于您的系统环境
最小值设置： 在任何时候 Tuxedo 系统中可能会发行的消息的最大数量。请务必将此值设置得足够大，以便能够处理所有发行的消息。如果该值过小，系统性能可能会降低。


MSGSEG

 

完整名称： 消息段
用途： Msgseg 定义系统中的 IPC 消息段数量
默认值： 介于 8192 和 32767 之间，具体取决于您的系统环境
最小值设置： 设置为 (Average Message Size * Maximum Message Headers)/MSGSSZ


IPC 命令

下面列出了一些有用的 IPC 命令，可用于查看和处理您的 Tuxedo 应用程序的 IPC 数据。

ipcs

ipcs 实用程序用于输出活动的进程间进行通信所使用的IPC资源相关信息。显示的信息由提供的选项控制。如果没有这些选项，有关当前在系统中处于活动状态的消息队列、共享内存和信号量的信息会以短格式形式输出。

一些较为有用的选项包括：

 

选项 描述
-b 输出有关最大允许大小的信息：消息队列上消息的最大字节数、共享内存段的大小以及每个信号量组中的信号量数量。
-o 输出有关未决使用情况的信息：队列上的消息数量、消息队列上消息的字节总数以及附加到共享内存段的进程数量。
-q 输出有关活动消息队列的信息。
-s 输出有关活动信号量的信息。
-m 输出有关活动共享内存段的信息。


ipcs示例：ipcs -boq

下面给出了 ipcs –boq 命令的输出内容。–b 显示队列上的消息的最大字节数量，-o 显示队列上的消息数量，–q 指定我们仅显示有关队列的信息（即，不显示有关共享内存或信号量的信息）。

 

IPCS status from BEA_segV8.1 as of Wed Jun 22 10:41:54 2005
>T     ID     KEY        MODE       OWNER    GROUP CBYTES  QNUM QBYTES
Message Queues:
q    513 0x0000bea2 -Rrw-rw-rw-        0        0      0     0  65536
q    770 0x00000000 -Rrw-rw-rw-        0        0      0     0  65536
q    515 0x00000000 -Rrw-rw-rw-        0        0      0     0  65536
q      4 0x00000000 –rw-rw-rw-        0        0  11396    37  65536

 

在上述输出内容中，我们可以看到 ID 为 4 的队列有 37 条消息 (QNUM)，队列上有 11396 字节 (CBYTES)。

我们还可以在 MODE 列中看到队列的 UNIX 风格权限，而 OWNER 和 GROUP 列表示了队列所有者和所在的组。所有三类 IPC（信号量、队列和共享内存）都有这些列。

有关 ipcs 命令的更多信息，请参阅 UNIX 使用手册。

ipcrm

ipcrm 用于删除一个或多个消息队列、信号量或共享内存段。在出现灾难性的 Tuxedo 系统故障而不得不 kill Tuxedo 进程之后，通常会使用此命令。在这种情况下，Tuxedo Server 无法释放其 IPC 资源，我们需要手动进行操作。

使用 ipcs 命令输出 ID 列中的 ID，我们可以确定要清除的单个 IPC 资源。相关的选项包括：

 

选项 描述
-m <ID> 删除 ID 为 <ID> 的共享内存段。
-s <ID> 删除 ID 为 <ID> 的信号量。
-q <ID> 删除 ID 为 <ID> 的消息队列。

 

因此，假设 ipcs –boq 命令的输出如下：

 

IPCS status from BEA_segV8.1 as of Wed Jun 22 10:41:54 2005
T     ID     KEY        MODE       OWNER    GROUP CBYTES  QNUM QBYTES
Message Queues:
q    513 0x0000bea2 -Rrw-rw-rw-        0        0      0     0  65536
q    770 0x00000000 -Rrw-rw-rw-        0        0      0     0  65536
q    515 0x00000000 -Rrw-rw-rw-        0        0      0     0  65536
q      4 0x00000000 –rw-rw-rw-        0        0  11396    37  65536

 

我们可以使用以下命令删除所有消息队列：

 

Ipcrm –q 513 –q 770 –q 515 –q 4

 

此命令将删除 ID 为 513、770、515 和 4 的队列。–m 和 –s 选项的用法与 –q 完全相同。


tmipcrm

tmipcrm 用于清除由 Tuxedo ATMI 应用程序分配的 IPC 资源，例如共享内存、消息队列和信号量。此命令通常在出现异常错误情况（例如故障关机）之后运行。在正常情况下，Tuxedo ATMI 系统会在关闭时清除所有已分配的 IPC 资源。将被删除的 IPC 资源包括那些由核心 Tuxedo ATMI 系统和工作站组件所使用的资源。

tmipcrm 只在本地服务器上运作；它不清除处于 Tuxedo 配置中的远程计算机上的 IPC 资源。您必须将 TUXCONFIG 文件的名称指定为 TUXCONFIG 环境变量的值，或在命令行上指定该名称。TUXCONFIG 文件必须存在且必须是可读的。

只有管理员或其他拥有适当权限的人才能成功运行此命令。此命令假设它可以附加到 Bulletin Board (BB) 的共享内存段，并尝试删除存储在 Bulletin Board 中并从中引用的 IPC 资源。此类删除尝试可能会因系统上的其他情况而失败。如果检测到失败，将会进行报告。

支持以下选项：

 

选项 描述
-y 对所有提示均给出肯定回答。
-n 不删除 IPC 资源，而是在标准输出中显示 IPC 资源列表。

 

tmipcrm的输出示例：

 

$ tmipcrm /home/user/apps/tuxconfig
Looking for IPC resources in TUXCONFIG file /home/user/apps/tuxconfig
The following IPC resources were found:
Message Queues:
0x2345
0x3456

Semaphores:
0x34567
0x45678

Shared Memory:
0x45678
0x56789
Remove these IPC resources (y/n)?: y
Removing IPC resources  done!


bbsread

为了检查此配置的本地 IPC 资源，启动了 tmadmin 会话并运行了 bbsread 命令。bbsread 的输出如下所示：

bbsread Output

 

SITE1> bbsread
IPC resources for the bulletin board on machine SITE1:
SHARED MEMORY:          Key: 0x1013c38
SEGMENT 0:
ID: 15730
Size: 36924
Attached processes: 12
Last attach/detach by: 4181

This semaphore is the system semaphore
SEMAPHORE:              Key: 0x1013c38
Id: 15666
|  semaphore |  current |   last   | # waiting |
|   number   |  status  | accesser | processes |
|———————————————-|
|     0      |   free   |   4181   |     0     |
|———————————————-|
This semaphore set is part of the user-level semaphore
SEMAPHORE:              Key: IPC_PRIVATE
Id: 11572
|  semaphore |  current |   last   | # waiting |
|   number   |  status  | accesser | processes |
|———————————————-|
|      0     |  locked  |   4181   |     0     |
|      1     |  locked  |   4181   |     0     |
|      2     |  locked  |   4181   |     0     |
|      3     |  locked  |   4181   |     0     |
|      4     |  locked  |   4181   |     0     |
|      5     |  locked  |   4181   |     0     |
|      6     |  locked  |   4181   |     0     |
|      7     |  locked  |   4181   |     0     |
|      8     |  locked  |   4181   |     0     |
|      9     |  locked  |   4181   |     0     |
|     10     |  locked  |   4181   |     0     |
|     11     |  locked  |   4181   |     0     |
|     12     |  locked  |   4181   |     0     |
|     13     |  locked  |   4181   |     0     |
|————|———-|———-|———–|

 

bbsread 命令的输出分为两个部分，即共享内存和信号量。

共享内存

共享内存输出分为若干个段，每个段都拥有自己的 ID。在所有 IPC 资源中，段 ID 是唯一的，它也是您在运行 ipcs –m 命令时会看到的 ID。

对于共享内存的每个段，系统会显示以下一些项目：

 

项目 描述
ID IPC 资源的唯一 ID
Size 共享内存段的大小（以字节为单位）
Attached processes 显示附加到共享内存段的活动进程数量。这些进程包括 BBL、WSH 进程、Tuxedo Server 等。
Last attach/detach by 显示最后一个连接到共享内存段的进程的进程 ID。


信号量

请务必注意，ipcs 命令的信号量输出的 ID 是信号量组的 ID，并且这些信号量组所包含的是实际的信号量。bbsread 命令的输出显示系统中信号量的某个部分。这些信号量按其信号量组 ID 进行分组，该 ID 是由 ipcs 命令显示的 ID，也是传递到 ipcrm 命令的 –s 选项的 ID。

每个信号量组的所有信号量都会显示在输出中，表示这些信号量是处于锁定状态还是空闲状态（当前状态）、最后使用信号量的进程 ID（最后一个访问器）以及正在等待使用该信号量的进程数量（等待进程数）。

从这个输出中，我们可以确定 Tuxedo 域内的信号量活动状态。

IPC 的常见故障排查

如何在应用程序无法正常关闭时使用 IPC 工具

通过 tmshutdown 命令正常关闭 Tuxedo 应用程序时，所有 IPC 资源都会从系统中删除。但是在某些情况下，应用程序可能无法正常关闭，一些偏离的 IPC 资源可能会保留在系统中。如果发生此类情况，您可能无法重新启动该应用程序。

解决此问题的一个方法是，使用可调用系统 ipcs 命令的脚本删除 IPC 资源，并扫描特定用户帐户所有的全部 IPC 资源。但是，此方法很难辨别不同的 IPC 资源集；一些资源可能属于 Tuxedo 系统，一些可能属于特定的 Tuxedo 应用程序，而另外一些可能属于与 Tuxedo 系统毫不相关的应用程序。能够辨别这些资源集非常重要；误删 IPC 资源可能会严重损坏应用程序。

通过 Tuxedo IPC 工具（即 tmipcrm 命令），您可以删除活动应用程序中由 Tuxedo 系统分配的 IPC 资源（也就是说，此操作仅适用于核心 Tuxedo 和工作站组件）。

用于删除 IPC 资源的 tmipcrm 命令位于 TUXDIR/bin 中。此命令可读取二进制配置文件 (TUXCONFIG)，并附加到使用此文件中所含信息的 Bulletin Board。tmipcrm 只在本地服务器计算机上运作；它不清除处于 Tuxedo 配置中的远程计算机上的 IPC 资源。

若要运行此命令，请在命令行上输入该命令，如下所示：

 

tmipcrm [-y] [-n] [TUXCONFIG_file]

 

IPC 工具会列出由 Tuxedo 系统使用的所有 IPC 资源，并给出删除选项。

注意：只有在命令行中正确设置了 TUXCONFIG 环境变量或指定了相应的 TUXCONFIG 文件的情况下，此命令才起作用。

Oracle 数据技术 | Guang Cai Li | |   texudo ipc

浅谈log buffer space等待事件

什么是log buffer space？

该等待事件问进程等待log buffer空间，因为此时写入log buffer的redo entry速度要高于lgwr 将redo entry写入online redolog的速度，导致log buffer塞满进而产生log buffer space等待事件。深入一点解释就是在往log buffer写入redo entry时候要先获取redo allocation latch，在获取该latch后开始寻获log buffer中剩余的空闲区域写入数据，如果此时没有剩余空间给与写入redo entry则发生log buffer space等待事件，此时可能也会等待log file switch completion事件，因为如果此时遭遇redo online log写满的情况则会发生log switch的情况，在切换过程 logbuffer瞬间写满日志，lgwr进程等待切换结束则出现switch相关等待事件，同时在切换完成后由于大量进程瞬间往log buffer space写入redo entry导致buffer塞满则此时等待log buffer space事件。

应该搜集那些信息来分析’log buffer space’等待事件？

1.发生此事件时候的日志切换频率
2.实例的内存设置以及AWR或者statspack报告
3.发生此事件时候实例的日志切换频率
4.发生此事件时候系统的整体IO负载
5.如果为Dataguard环境，检查DG的模式以及日志传输的延时情况

触发’log buffer space’等待事件的原因？

1.系统IO能力不足
2.日志切换过于频繁
3.过小的log buffer
4.Dataguard在最大可用模式以上保护级别的络传输效率低下

如何处理log buffer space等待事件？

导致log buffer space的原因前面分析过了，针对前面的情况大致的列出一些处理思路。
1.系统IO能力不足这个在log file sync的讨论中介绍过了该如何处理，尽量提升io能力，将redo log放在io能力高的存储上
2.日志切换过于频繁这个时候一般都会导致log buffer space和log file switch completion的等待，如果日志小了，频繁的切换会导致此2个事件的产生，所以一般建议将redo设置大一些，并放在io能力高的文件系统
3.过小的log buffer，这个情况和2有相似点，可能同时存在redo logfile size过小，log bufer过小的情况，再此时如果把log buffer设置大点log file sync等待就可能增加，所以针对不同的log buffer大小对log buffer space事件的影响做个测试验证下。

测试：

1.构建T1表10w条记录
2.在log buffer 256k时候update t1表
3.在log buffer 10m时候update t1表
然后分别确认2和3的log buffer space等待情况

1.构建T1表

SQL> select count(*) from t1;

  COUNT(*)
----------
     150068

SQL> insert into t1 select * from t1;

150068 rows created.

SQL> commit;

Commit complete.

SQL> select count(*) from t1;

  COUNT(*)
----------
    300136

SQL> alter table t1 add num number;

Table altered.

SQL> alter table t1 modify num varchar2(200);

Table altered.

SQL> select num from t1 where rownum < 2;

NUM
--------------------------------------------------------------------------------
AAAMr8AAEAAAAA8AAA

2.在log buffer 2M时候update t1表

在表t1中更新30w条数据，同时观察等待
SQL> show sga

Total System Global Area  318767104 bytes
Fixed Size                  1267260 bytes
Variable Size             100665796 bytes
Database Buffers          213909504 bytes
Redo Buffers                2924544 bytes
SQL> conn luda/luda
Connected.
SQL> @sess_stat
SP2-0158: unknown SET option "header"

EVENT                                                            TOTAL_WAITS TIME_WAITED
---------------------------------------------------------------- ----------- -----------
SQL*Net message from client                                               11        4439
db file sequential read                                                   55           0
SQL*Net message to client                                                 12           0

SQL> update t1 set object_name='LUDATOU',num=rowid;

300408 rows updated.

SQL> @sess_stat
SP2-0158: unknown SET option "header"

EVENT                                                            TOTAL_WAITS TIME_WAITED
---------------------------------------------------------------- ----------- -----------
SQL*Net message from client                                               14        8837
log buffer space                                                          11          37
log file switch completion                                                 8           7
db file scattered read                                                   544           6
events in waitclass Other                                                 31           1
SQL*Net message to client                                                 15           0
db file sequential read                                                   70           0
观察整体的等待

SQL> @snaper all,out 5 3 214

-- Session Snapper v2.02 by Tanel Poder ( http://www.tanelpoder.com )

----------------------------------------------------------------------------------------------------------------------
    SID, USERNAME  , TYPE, STATISTIC                               ,         DELTA, HDELTA/SEC,    %TIME, GRAPH
----------------------------------------------------------------------------------------------------------------------
    214, LUDA      , STAT, opened cursors cumulative               ,           198,       39.6,
    214, LUDA      , STAT, user calls                              ,             2,         .4,
    214, LUDA      , STAT, recursive calls                         ,          2007,      401.4,
    214, LUDA      , STAT, recursive cpu usage                     ,            12,        2.4,
    214, LUDA      , STAT, session logical reads                   ,        390254,     78.05k,
    214, LUDA      , STAT, CPU used by this session                ,           198,       39.6,
    214, LUDA      , STAT, DB time                                 ,           261,       52.2,
    214, LUDA      , STAT, user I/O wait time                      ,             6,        1.2,
    214, LUDA      , STAT, session uga memory                      ,         65464,     13.09k,
    214, LUDA      , STAT, session uga memory max                  ,         65464,     13.09k,
    214, LUDA      , STAT, messages sent                           ,           365,         73,
    214, LUDA      , STAT, session pga memory                      ,         65536,     13.11k,
    214, LUDA      , STAT, session pga memory max                  ,         65536,     13.11k,
    214, LUDA      , STAT, enqueue requests                        ,           836,      167.2,
    214, LUDA      , STAT, enqueue conversions                     ,           113,       22.6,
    214, LUDA      , STAT, enqueue releases                        ,           834,      166.8,
    214, LUDA      , STAT, physical read total IO requests         ,           559,      111.8,
    214, LUDA      , STAT, physical read total multi block requests,           544,      108.8,
    214, LUDA      , STAT, physical read total bytes               ,      35151872,      7.03M,
    214, LUDA      , STAT, db block gets                           ,        383374,     76.67k,
    214, LUDA      , STAT, db block gets from cache                ,        383374,     76.67k,
    214, LUDA      , STAT, consistent gets                         ,          6880,      1.38k,
    214, LUDA      , STAT, consistent gets from cache              ,          6880,      1.38k,
    214, LUDA      , STAT, consistent gets - examination           ,          1695,        339,
    214, LUDA      , STAT, physical reads                          ,          4291,      858.2,
    214, LUDA      , STAT, physical reads cache                    ,          4291,      858.2,
    214, LUDA      , STAT, physical read IO requests               ,           559,      111.8,
    214, LUDA      , STAT, physical read bytes                     ,      35151872,      7.03M,
    214, LUDA      , STAT, db block changes                        ,        655501,     131.1k,
    214, LUDA      , STAT, change write time                       ,           105,         21,
    214, LUDA      , STAT, redo synch writes                       ,             1,         .2,
    214, LUDA      , STAT, free buffer requested                   ,         13313,      2.66k,
    214, LUDA      , STAT, switch current to new buffer            ,          4241,      848.2,
    214, LUDA      , STAT, write clones created in foreground      ,             3,         .6,
    214, LUDA      , STAT, physical reads cache prefetch           ,          3732,      746.4,
    214, LUDA      , STAT, shared hash latch upgrades - no wait    ,             5,          1,
    214, LUDA      , STAT, calls to kcmgcs                         ,           132,       26.4,
    214, LUDA      , STAT, calls to kcmgas                         ,          9027,      1.81k,
    214, LUDA      , STAT, calls to get snapshot scn: kcmgss       ,           786,      157.2,
    214, LUDA      , STAT, redo entries                            ,        326611,     65.32k,
    214, LUDA      , STAT, redo size                               ,      96942748,     19.39M,
    214, LUDA      , STAT, redo buffer allocation retries          ,            15,          3,
    214, LUDA      , STAT, redo log space requests                 ,             8,        1.6,
    214, LUDA      , STAT, redo log space wait time                ,             7,        1.4,
    214, LUDA      , STAT, redo ordering marks                     ,          4744,      948.8,
    214, LUDA      , STAT, redo subscn max counts                  ,          6443,      1.29k,
    214, LUDA      , STAT, undo change vector size                 ,      37734184,      7.55M,
    214, LUDA      , STAT, no work - consistent read gets          ,          2974,      594.8,
    214, LUDA      , STAT, cleanouts only - consistent read gets   ,          1661,      332.2,
    214, LUDA      , STAT, immediate (CR) block cleanout applicatio,          1661,      332.2,
    214, LUDA      , STAT, deferred (CURRENT) block cleanout applic,          2582,      516.4,
    214, LUDA      , STAT, commit txn count during cleanout        ,          1661,      332.2,
    214, LUDA      , STAT, cleanout - number of ktugct calls       ,          1661,      332.2,
    214, LUDA      , STAT, IMU Flushes                             ,             1,         .2,
    214, LUDA      , STAT, table scans (short tables)              ,           173,       34.6,
    214, LUDA      , STAT, table scans (long tables)               ,             1,         .2,
    214, LUDA      , STAT, table scan rows gotten                  ,        325791,     65.16k,
    214, LUDA      , STAT, table scan blocks gotten                ,          4607,      921.4,
    214, LUDA      , STAT, table fetch by rowid                    ,             9,        1.8,
    214, LUDA      , STAT, cluster key scans                       ,             8,        1.6,
    214, LUDA      , STAT, cluster key scan block gets             ,             8,        1.6,
    214, LUDA      , STAT, rows fetched via callback               ,             1,         .2,
    214, LUDA      , STAT, index crx upgrade (positioned)          ,             2,         .4,
    214, LUDA      , STAT, index fetch by key                      ,            11,        2.2,
    214, LUDA      , STAT, index scans kdiixs1                     ,            14,        2.8,
    214, LUDA      , STAT, session cursor cache hits               ,           177,       35.4,
    214, LUDA      , STAT, session cursor cache count              ,             1,         .2,
    214, LUDA      , STAT, cursor authentications                  ,             2,         .4,
    214, LUDA      , STAT, buffer is pinned count                  ,        296391,     59.28k,
    214, LUDA      , STAT, buffer is not pinned count              ,            26,        5.2,
    214, LUDA      , STAT, workarea executions - optimal           ,             5,          1,
    214, LUDA      , STAT, parse time cpu                          ,             1,         .2,
    214, LUDA      , STAT, parse time elapsed                      ,             1,         .2,
    214, LUDA      , STAT, parse count (total)                     ,           188,       37.6,
    214, LUDA      , STAT, parse count (hard)                      ,             6,        1.2,
    214, LUDA      , STAT, execute count                           ,           198,       39.6,
    214, LUDA      , STAT, bytes sent via SQL*Net to client        ,           147,       29.4,
    214, LUDA      , STAT, bytes received via SQL*Net from client  ,           208,       41.6,
    214, LUDA      , STAT, SQL*Net roundtrips to/from client       ,             1,         .2,
    214, LUDA      , STAT, sorts (memory)                          ,             9,        1.8,
    214, LUDA      , STAT, sorts (rows)                            ,            33,        6.6,
    214, LUDA      , TIME, hard parse elapsed time                 ,          7721,     1.54ms,      .2%, |          |
    214, LUDA      , TIME, repeated bind elapsed time              ,            23,      4.6us,      .0%, |          |
    214, LUDA      , TIME, parse time elapsed                      ,         17186,     3.44ms,      .3%, |          |
    214, LUDA      , TIME, DB CPU                                  ,       1980114,   396.02ms,    39.6%, |@@@@      |
    214, LUDA      , TIME, sql execute elapsed time                ,       2544856,   508.97ms,    50.9%, |@@@@@@    |
    214, LUDA      , TIME, DB time                                 ,       2547798,   509.56ms,    51.0%, |@@@@@@    |
    214, LUDA      , WAIT, log buffer space                        ,        373101,    74.62ms,     7.5%, |@         |
    214, LUDA      , WAIT, log file switch completion              ,         73175,    14.64ms,     1.5%, |@         |
    214, LUDA      , WAIT, db file sequential read                 ,          1750,      350us,      .0%, |          |
    214, LUDA      , WAIT, db file scattered read                  ,         59996,       12ms,     1.2%, |@         |
    214, LUDA      , WAIT, SQL*Net message to client               ,             4,       .8us,      .0%, |          |
    214, LUDA      , WAIT, SQL*Net message from client             ,       1448235,   289.65ms,    29.0%, |@@@       |
--  End of snap 1, end=2014-07-16 16:34:54, seconds=5

通过以上测试我们可以发现，在2M左右大小的log buffer中，更新表t1过程总体产生的log buffer space等待为74.62ms，log buffer space等待触发次数11次.
继续第二步测试。

3.在log buffer 10M时候update t1表

SQL> conn luda/luda
Connected.
SQL>  update t1 set object_name='LUDATOU',num=rowid;

300408 rows updated.

SQL> @sess_stat
SP2-0158: unknown SET option "header"

EVENT                                                            TOTAL_WAITS TIME_WAITED
---------------------------------------------------------------- ----------- -----------
SQL*Net message from client                                               12        2951
log file switch (checkpoint incomplete)                                    4         112
log file switch completion                                                 5          45
events in waitclass Other                                                  4          11
db file scattered read                                                   544           5
Data file init write                                                      21           4
log buffer space                                                           2           2
control file parallel write                                                9           1
SQL*Net message to client                                                 13           0
db file parallel read                                                      1           0
db file single write                                                       3           0
control file sequential read                                              60           0
db file sequential read                                                   71           0

13 rows selected.

同时观测总体等待
SQL>  @snaper all,out 5 3 214


-- Session Snapper v2.02 by Tanel Poder ( http://www.tanelpoder.com )

----------------------------------------------------------------------------------------------------------------------
    SID, USERNAME  , TYPE, STATISTIC                               ,         DELTA, HDELTA/SEC,    %TIME, GRAPH
----------------------------------------------------------------------------------------------------------------------
    214, LUDA      , STAT, opened cursors cumulative               ,            80,         16,
    214, LUDA      , STAT, opened cursors current                  ,             1,         .2,
    214, LUDA      , STAT, user calls                              ,             1,         .2,
    214, LUDA      , STAT, recursive calls                         ,           955,        191,
    214, LUDA      , STAT, recursive cpu usage                     ,             9,        1.8,
    214, LUDA      , STAT, session logical reads                   ,        344227,     68.85k,
    214, LUDA      , STAT, CPU used by this session                ,           196,       39.2,
    214, LUDA      , STAT, user I/O wait time                      ,             7,        1.4,
    214, LUDA      , STAT, messages sent                           ,           107,       21.4,
    214, LUDA      , STAT, session pga memory                      ,       4587520,     917.5k,
    214, LUDA      , STAT, session pga memory max                  ,       4587520,     917.5k,
    214, LUDA      , STAT, enqueue waits                           ,             1,         .2,
    214, LUDA      , STAT, enqueue requests                        ,           220,         44,
    214, LUDA      , STAT, enqueue conversions                     ,            26,        5.2,
    214, LUDA      , STAT, enqueue releases                        ,           218,       43.6,
    214, LUDA      , STAT, physical read total IO requests         ,           575,        115,
    214, LUDA      , STAT, physical read total multi block requests,           513,      102.6,
    214, LUDA      , STAT, physical read total bytes               ,      33865728,      6.77M,
    214, LUDA      , STAT, physical write total IO requests        ,            32,        6.4,
    214, LUDA      , STAT, physical write total multi block request,            10,          2,
    214, LUDA      , STAT, physical write total bytes              ,      10797056,      2.16M,
    214, LUDA      , STAT, db block gets                           ,        335817,     67.16k,
    214, LUDA      , STAT, db block gets from cache                ,        335817,     67.16k,
    214, LUDA      , STAT, consistent gets                         ,          8410,      1.68k,
    214, LUDA      , STAT, consistent gets from cache              ,          8410,      1.68k,
    214, LUDA      , STAT, consistent gets - examination           ,          4064,      812.8,
    214, LUDA      , STAT, physical reads                          ,          4050,        810,
    214, LUDA      , STAT, physical reads cache                    ,          4050,        810,
    214, LUDA      , STAT, physical read IO requests               ,           531,      106.2,
    214, LUDA      , STAT, physical read bytes                     ,      33177600,      6.64M,
    214, LUDA      , STAT, db block changes                        ,        611828,    122.37k,
    214, LUDA      , STAT, prefetch clients - default              ,             1,         .2,
    214, LUDA      , STAT, change write time                       ,            49,        9.8,
    214, LUDA      , STAT, free buffer requested                   ,         12576,      2.52k,
    214, LUDA      , STAT, switch current to new buffer            ,          4030,        806,
    214, LUDA      , STAT, physical reads cache prefetch           ,          3522,      704.4,
    214, LUDA      , STAT, shared hash latch upgrades - no wait    ,             3,         .6,
    214, LUDA      , STAT, calls to kcmgcs                         ,             5,          1,
    214, LUDA      , STAT, calls to kcmgas                         ,          8532,      1.71k,
    214, LUDA      , STAT, calls to get snapshot scn: kcmgss       ,           273,       54.6,
    214, LUDA      , STAT, redo entries                            ,        305759,     61.15k,
    214, LUDA      , STAT, redo size                               ,      91112824,     18.22M,
    214, LUDA      , STAT, redo buffer allocation retries          ,             7,        1.4,
    214, LUDA      , STAT, redo log space requests                 ,             6,        1.2,
    214, LUDA      , STAT, redo log space wait time                ,            59,       11.8,
    214, LUDA      , STAT, redo ordering marks                     ,          4489,      897.8,
    214, LUDA      , STAT, redo subscn max counts                  ,          8528,      1.71k,
    214, LUDA      , STAT, undo change vector size                 ,      35556100,      7.11M,
    214, LUDA      , STAT, no work - consistent read gets          ,           133,       26.6,
    214, LUDA      , STAT, cleanouts only - consistent read gets   ,          4030,        806,
    214, LUDA      , STAT, immediate (CR) block cleanout applicatio,          4030,        806,
    214, LUDA      , STAT, commit txn count during cleanout        ,          4030,        806,
    214, LUDA      , STAT, cleanout - number of ktugct calls       ,          4030,        806,
    214, LUDA      , STAT, auto extends on undo tablespace         ,             2,         .4,
    214, LUDA      , STAT, IMU pool not allocated                  ,             1,         .2,
    214, LUDA      , STAT, IMU- failed to get a private strand     ,             1,         .2,
    214, LUDA      , STAT, table scans (short tables)              ,            55,         11,
    214, LUDA      , STAT, table scans (long tables)               ,             1,         .2,
    214, LUDA      , STAT, table scan rows gotten                  ,        313370,     62.67k,
    214, LUDA      , STAT, table scan blocks gotten                ,          4135,        827,
    214, LUDA      , STAT, table fetch by rowid                    ,             9,        1.8,
    214, LUDA      , STAT, cluster key scans                       ,             8,        1.6,
    214, LUDA      , STAT, cluster key scan block gets             ,             8,        1.6,
    214, LUDA      , STAT, rows fetched via callback               ,             1,         .2,
    214, LUDA      , STAT, index crx upgrade (positioned)          ,             2,         .4,
    214, LUDA      , STAT, index fetch by key                      ,            11,        2.2,
    214, LUDA      , STAT, index scans kdiixs1                     ,            14,        2.8,
    214, LUDA      , STAT, session cursor cache hits               ,            59,       11.8,
    214, LUDA      , STAT, cursor authentications                  ,             2,         .4,
    214, LUDA      , STAT, buffer is pinned count                  ,        285420,     57.08k,
    214, LUDA      , STAT, buffer is not pinned count              ,            26,        5.2,
    214, LUDA      , STAT, workarea executions - optimal           ,             5,          1,
    214, LUDA      , STAT, parse time cpu                          ,             1,         .2,
    214, LUDA      , STAT, parse count (total)                     ,            70,         14,
    214, LUDA      , STAT, parse count (hard)                      ,             6,        1.2,
    214, LUDA      , STAT, execute count                           ,            80,         16,
    214, LUDA      , STAT, bytes received via SQL*Net from client  ,           194,       38.8,
    214, LUDA      , STAT, sorts (memory)                          ,             9,        1.8,
    214, LUDA      , STAT, sorts (rows)                            ,            33,        6.6,
    214, LUDA      , TIME, hard parse elapsed time                 ,          7737,     1.55ms,      .2%, |          |
    214, LUDA      , TIME, repeated bind elapsed time              ,            46,      9.2us,      .0%, |          |
    214, LUDA      , TIME, parse time elapsed                      ,         11032,     2.21ms,      .2%, |          |
    214, LUDA      , TIME, DB CPU                                  ,       1620000,      324ms,    32.4%, |@@@@      |
    214, LUDA      , TIME, sql execute elapsed time                ,       2440182,   488.04ms,    48.8%, |@@@@@     |
    214, LUDA      , TIME, DB time                                 ,       2442540,   488.51ms,    48.9%, |@@@@@     |
    214, LUDA      , WAIT, Data file init write                    ,         25778,     5.16ms,      .5%, |@         |
    214, LUDA      , WAIT, control file sequential read            ,           447,     89.4us,      .0%, |          |
    214, LUDA      , WAIT, control file parallel write             ,          6142,     1.23ms,      .1%, |          |
    214, LUDA      , WAIT, log buffer space                        ,         19503,      3.9ms,      .4%, |          |
    214, LUDA      , WAIT, log file switch (checkpoint incomplete) ,        127979,     25.6ms,     2.6%, |@         |
    214, LUDA      , WAIT, log file switch completion              ,        446061,    89.21ms,     8.9%, |@         |
    214, LUDA      , WAIT, db file sequential read                 ,           419,     83.8us,      .0%, |          |
    214, LUDA      , WAIT, db file scattered read                  ,         49967,     9.99ms,     1.0%, |@         |
    214, LUDA      , WAIT, db file single write                    ,           998,    199.6us,      .0%, |          |
    214, LUDA      , WAIT, SQL*Net message from client             ,       2462840,   492.57ms,    49.3%, |@@@@@     |

通过测试3可以发现在10m左右的log buffer 中log buffer space总的等待时间为3.9ms，总体等待次数2次。

测试3和测试2说明了在log buffer加大的情况下，log buffer space等待次数降低，但是log file switch completion等待也随着增加，所以调整log buffer space从整体的等待来看加大log buffer并不是绝对的。
另一种方法来降低log buffer space的办法就是减少redo的产生量，比如nologging或者直接路径写。

4.DG中的日志传输延时影响

在这种情况中可以参考前面的gc block lost中网络的调整，保证日志的传输效率。
还有一种就是压缩日志大小。

Oracle 数据技术 浅谈oracle技术系列 等待事件 | Guang Cai Li | |   log buffer space

浅谈log file sync等待事件诊断（三）

提供一个辅助诊断log file sync的脚本，该脚本有助于诊断log file sync时候锁需要的数据库相关信息的获取，具体如下：

-- NAME: LFSDIAG.SQL
-- ------------------------------------------------------------------------
-- AUTHOR: Michael Polaski - Oracle Support Services
-- ------------------------------------------------------------------------
-- PURPOSE:
-- This script is intended to provide a user friendly guide to troubleshoot
-- log file sync waits. The script will look at important parameters involved
-- in log file sync waits, log file sync wait histogram data, and the script
-- will look at the worst average log file sync times in the active session
-- history data and AWR data and dump information to help determine why those
-- times were the highest. The script will create a file called
-- lfsdiag_<timestamp>.out in your local directory.

set echo off
set feedback off
column timecol new_value timestamp
column spool_extension new_value suffix
select to_char(sysdate,'Mondd_hh24mi') timecol,
'.out' spool_extension from sys.dual;
column output new_value dbname
select value || '_' output
from v$parameter where name = 'db_name';
spool lfsdiag_&&dbname&&timestamp&&suffix
set trim on
set trims on
set lines 140
set pages 100
set verify off
alter session set optimizer_features_enable = '10.2.0.4';

PROMPT LFSDIAG DATA FOR &&dbname&&timestamp
PROMPT Note: All timings are in milliseconds (1000 milliseconds = 1 second)

PROMPT
PROMPT IMPORTANT PARAMETERS RELATING TO LOG FILE SYNC WAITS:
column name format a40 wra
column value format a40 wra
select inst_id, name, value from gv$parameter
where ((value is not null and name like '%log_archive%') or
name like '%commit%' or name like '%event=%' or name like '%lgwr%')
and name not in (select name from gv$parameter where (name like '%log_archive_dest_state%'
and value = 'enable') or name = 'log_archive_format')
order by 1,2,3;

PROMPT
PROMPT ASH THRESHOLD...
PROMPT
PROMPT This will be the threshold in milliseconds for average log file sync
PROMPT times. This will be used for the next queries to look for the worst
PROMPT 'log file sync' minutes. Any minutes that have an average log file
PROMPT sync time greater than the threshold will be analyzed further.
column threshold_in_ms new_value threshold format 999999999.999
select min(threshold_in_ms) threshold_in_ms
from (select inst_id, to_char(sample_time,'Mondd_hh24mi') minute,
avg(time_waited)/1000 threshold_in_ms
from gv$active_session_history
where event = 'log file sync'
group by inst_id,to_char(sample_time,'Mondd_hh24mi')
order by 3 desc)
where rownum <= 10;

PROMPT
PROMPT ASH WORST MINUTES FOR LOG FILE SYNC WAITS:
PROMPT
PROMPT APPROACH: These are the minutes where the avg log file sync time
PROMPT was the highest (in milliseconds).
column minute format a12 tru
column event format a30 tru
column program format a40 tru
column total_wait_time format 999999999999.999
column avg_time_waited format 999999999999.999
select to_char(sample_time,'Mondd_hh24mi') minute, inst_id, event,
sum(time_waited)/1000 TOTAL_WAIT_TIME , count(*) WAITS,
avg(time_waited)/1000 AVG_TIME_WAITED
from gv$active_session_history
where event = 'log file sync'
group by to_char(sample_time,'Mondd_hh24mi'), inst_id, event
having avg(time_waited)/1000 > &&threshold
order by 1,2;

PROMPT
PROMPT ASH LFS BACKGROUND PROCESS WAITS DURING WORST MINUTES:
PROMPT
PROMPT APPROACH: What is LGWR doing when 'log file sync' waits
PROMPT are happening? LMS info may be relevent for broadcast
PROMPT on commit and LNS data may be relevant for dataguard.
PROMPT If more details are needed see the ASH DETAILS FOR WORST
PROMPT MINUTES section at the bottom of the report.
column inst format 999
column minute format a12 tru
column event format a30 tru
column program format a40 wra
select to_char(sample_time,'Mondd_hh24mi') minute, inst_id inst, program, event,
sum(time_waited)/1000 TOTAL_WAIT_TIME , count(*) WAITS,
avg(time_waited)/1000 AVG_TIME_WAITED
from gv$active_session_history
where to_char(sample_time,'Mondd_hh24mi') in (select to_char(sample_time,'Mondd_hh24mi')
from gv$active_session_history
where event = 'log file sync'
group by to_char(sample_time,'Mondd_hh24mi'), inst_id
having avg(time_waited)/1000 > &&threshold and sum(time_waited)/1000 > 1)
and (program like '%LGWR%' or program like '%LMS%' or
program like '%LNS%' or event = 'log file sync')
group by to_char(sample_time,'Mondd_hh24mi'), inst_id, program, event
order by 1,2,3,5 desc, 4;

PROMPT
PROMPT HISTOGRAM DATA FOR LFS AND OTHER RELATED WAITS:
PROMPT
PROMPT APPROACH: Look at the wait distribution for log file sync waits
PROMPT by looking at "wait_time_milli". Look at the high wait times then
PROMPT see if you can correlate those with other related wait events.
column event format a40 wra
select inst_id, event, wait_time_milli, wait_count
from gv$event_histogram
where event in ('log file sync','gcs log flush sync',
'log file parallel write','wait for scn ack',
'log file switch completion','gc cr grant 2-way',
'gc buffer busy','gc current block 2-way') or
event like '%LGWR%' or event like '%LNS%'
order by 2 desc,1,3;

PROMPT
PROMPT ORDERED BY WAIT_TIME_MILLI
select inst_id, event, wait_time_milli, wait_count
from gv$event_histogram
where event in ('log file sync','gcs log flush sync',
'log file parallel write','wait for scn ack',
'log file switch completion','gc cr grant 2-way',
'gc buffer busy','gc current block 2-way')
or event like '%LGWR%' or event like '%LNS%'
order by 3,1,2 desc;

PROMPT
PROMPT REDO WRITE STATS
PROMPT
PROMPT "redo write time" in centiseconds (100 per second)
PROMPT 11.1: "redo write broadcast ack time" in centiseconds (100 per second)
PROMPT 11.2: "redo write broadcast ack time" in microseconds (1000 per millisecond)
column value format 99999999999999999999
column milliseconds format 99999999999999.999
select v.version, ss.inst_id, ss.name, ss.value,
decode(substr(version,1,4),
'11.1',decode (name,'redo write time',value*10,
'redo write broadcast ack time',value*10),
'11.2',decode (name,'redo write time',value*10,
'redo write broadcast ack time',value/1000),
decode (name,'redo write time',value*10)) milliseconds
from gv$sysstat ss, v$instance v
where name like 'redo write%' and value > 0
order by 1,2,3;

PROMPT
PROMPT AWR WORST AVG LOG FILE SYNC SNAPS:
PROMPT
PROMPT APPROACH: These are the AWR snaps where the average 'log file sync'
PROMPT times were the highest.
column begin format a12 tru
column end format a12 tru
column name format a13 tru
select dhs.snap_id, dhs.instance_number inst, to_char(dhs.begin_interval_time,'Mondd_hh24mi') BEGIN,
to_char(dhs.end_interval_time,'Mondd_hh24mi') END,
en.name, se.time_waited_micro/1000 total_wait_time, se.total_waits,
se.time_waited_micro/1000 / se.total_waits avg_time_waited
from dba_hist_snapshot dhs, wrh$_system_event se, v$event_name en
where (dhs.snap_id = se.snap_id and dhs.instance_number = se.instance_number)
and se.event_id = en.event_id and en.name = 'log file sync' and
dhs.snap_id in (select snap_id from (
select se.snap_id, se.time_waited_micro/1000 / se.total_waits avg_time_waited
from wrh$_system_event se, v$event_name en
where se.event_id = en.event_id and en.name = 'log file sync'
order by avg_time_waited desc)
where rownum < 4)
order by 1,2;

PROMPT
PROMPT AWR REDO WRITE STATS
PROMPT
PROMPT "redo write time" in centiseconds (100 per second)
PROMPT 11.1: "redo write broadcast ack time" in centiseconds (100 per second)
PROMPT 11.2: "redo write broadcast ack time" in microseconds (1000 per millisecond)
column stat_name format a30 tru
select v.version, ss.snap_id, ss.instance_number inst, sn.stat_name, ss.value,
decode(substr(version,1,4),
'11.1',decode (stat_name,'redo write time',value*10,
'redo write broadcast ack time',value*10),
'11.2',decode (stat_name,'redo write time',value*10,
'redo write broadcast ack time',value/1000),
decode (stat_name,'redo write time',value*10)) milliseconds
from wrh$_sysstat ss, wrh$_stat_name sn, v$instance v
where ss.stat_id = sn.stat_id
and sn.stat_name like 'redo write%' and ss.value > 0
and ss.snap_id in (select snap_id from (
select se.snap_id, se.time_waited_micro/1000 / se.total_waits avg_time_waited
from wrh$_system_event se, v$event_name en
where se.event_id = en.event_id and en.name = 'log file sync'
order by avg_time_waited desc)
where rownum < 4)
order by 1,2,3;

PROMPT
PROMPT AWR LFS AND OTHER RELATED WAITS FOR WORST LFS AWRs:
PROMPT
PROMPT APPROACH: These are the AWR snaps where the average 'log file sync'
PROMPT times were the highest. Look at related waits at those times.
column name format a40 tru
select se.snap_id, se.instance_number inst, en.name,
se.total_waits, se.time_waited_micro/1000 total_wait_time,
se.time_waited_micro/1000 / se.total_waits avg_time_waited
from wrh$_system_event se, v$event_name en
where se.event_id = en.event_id and (en.name in
('log file sync','gcs log flush sync',
'log file parallel write','wait for scn ack',
'log file switch completion','gc cr grant 2-way',
'gc buffer busy','gc current block 2-way')
or en.name like '%LGWR%' or en.name like '%LNS%')
and se.snap_id in (select snap_id from (
select se.snap_id, se.time_waited_micro/1000 / se.total_waits avg_time_waited
from wrh$_system_event se, v$event_name en
where se.event_id = en.event_id and en.name = 'log file sync'
order by avg_time_waited desc)
where rownum < 4)
order by 1, 6 desc;

PROMPT
PROMPT AWR HISTOGRAM DATA FOR LFS AND OTHER RELATED WAITS FOR WORST LFS AWRs:
PROMPT Note: This query won't work on 10.2 - ORA-942
PROMPT
PROMPT APPROACH: Look at the wait distribution for log file sync waits
PROMPT by looking at "wait_time_milli". Look at the high wait times then
PROMPT see if you can correlate those with other related wait events.
select eh.snap_id, eh.instance_number inst, en.name, eh.wait_time_milli, eh.wait_count
from wrh$_event_histogram eh, v$event_name en
where eh.event_id = en.event_id and
(en.name in ('log file sync','gcs log flush sync',
'log file parallel write','wait for scn ack',
'log file switch completion','gc cr grant 2-way',
'gc buffer busy','gc current block 2-way')
or en.name like '%LGWR%' or en.name like '%LNS%')
and snap_id in (select snap_id from (
select se.snap_id, se.time_waited_micro/1000 / se.total_waits avg_time_waited
from wrh$_system_event se, v$event_name en
where se.event_id = en.event_id and en.name = 'log file sync'
order by avg_time_waited desc)
where rownum < 4)
order by 1,3 desc,2,4;

PROMPT
PROMPT ORDERED BY WAIT_TIME_MILLI
PROMPT Note: This query won't work on 10.2 - ORA-942
select eh.snap_id, eh.instance_number inst, en.name, eh.wait_time_milli, eh.wait_count
from wrh$_event_histogram eh, v$event_name en
where eh.event_id = en.event_id and
(en.name in ('log file sync','gcs log flush sync',
'log file parallel write','wait for scn ack',
'log file switch completion','gc cr grant 2-way',
'gc buffer busy','gc current block 2-way')
or en.name like '%LGWR%' or en.name like '%LNS%')
and snap_id in (select snap_id from (
select se.snap_id, se.time_waited_micro/1000 / se.total_waits avg_time_waited
from wrh$_system_event se, v$event_name en
where se.event_id = en.event_id and en.name = 'log file sync'
order by avg_time_waited desc)
where rownum < 4)
order by 1,4,2,3 desc;

PROMPT
PROMPT ASH DETAILS FOR WORST MINUTES:
PROMPT
PROMPT APPROACH: If you cannot determine the problem from the data
PROMPT above, you may need to look at the details of what each session
PROMPT is doing during each 'bad' snap. Most likely you will want to
PROMPT note the times of the high log file sync waits, look at what
PROMPT LGWR is doing at those times, and go from there...
column program format a45 wra
column sample_time format a25 tru
column event format a30 tru
column time_waited format 999999.999
column p1 format a40 tru
column p2 format a40 tru
column p3 format a40 tru
select sample_time, inst_id inst, session_id, program, event, time_waited/1000 TIME_WAITED,
p1text||': '||p1 p1,p2text||': '||p2 p2,p3text||': '||p3 p3
from gv$active_session_history
where to_char(sample_time,'Mondd_hh24mi') in (select
to_char(sample_time,'Mondd_hh24mi')
from gv$active_session_history
where event = 'log file sync'
group by to_char(sample_time,'Mondd_hh24mi'), inst_id
having avg(time_waited)/1000 > &&threshold)
and time_waited > 0.5
order by 1,2,3,4,5;

select to_char(sysdate,'Mondd hh24:mi:ss') TIME from dual;

spool off

PROMPT
PROMPT OUTPUT FILE IS: lfsdiag_&&dbname&&timestamp&&suffix
PROMPT

该脚本输出结果大致如下：

LFSDIAG DATA FOR DBM_Oct10_1307
Note: All timings are in milliseconds (1000 milliseconds = 1 second)

IMPORTANT PARAMETERS RELATING TO LOG FILE SYNC WAITS:

   INST_ID NAME                                     VALUE
---------- ---------------------------------------- ----------------------------------------
         1 commit_logging
         1 commit_point_strength                    1
         1 commit_wait
         1 commit_write
         1 log_archive_local_first                  TRUE
         1 log_archive_max_processes                4
         1 log_archive_min_succeed_dest             1
         1 log_archive_start                        FALSE
         1 log_archive_trace                        0
         2 commit_logging
         2 commit_point_strength                    1
         2 commit_wait
         2 commit_write
         2 log_archive_local_first                  TRUE
         2 log_archive_max_processes                4
         2 log_archive_min_succeed_dest             1
         2 log_archive_start                        FALSE
         2 log_archive_trace                        0

ASH THRESHOLD...

This will be the threshold in milliseconds for average log file sync
times. This will be used for the next queries to look for the worst
'log file sync' minutes. Any minutes that have an average log file
sync time greater than the threshold will be analyzed further.

THRESHOLD_IN_MS
---------------
           .000

ASH WORST MINUTES FOR LOG FILE SYNC WAITS:

APPROACH: These are the minutes where the avg log file sync time
was the highest (in milliseconds).

MINUTE          INST_ID EVENT                            TOTAL_WAIT_TIME      WAITS   AVG_TIME_WAITED
------------ ---------- ------------------------------ ----------------- ---------- -----------------
Oct01_0111            2 log file sync                               .807          1              .807
Oct02_0600            2 log file sync                              4.308          1             4.308
Oct09_0043            2 log file sync                            999.805          1           999.805

ASH LFS BACKGROUND PROCESS WAITS DURING WORST MINUTES:

APPROACH: What is LGWR doing when 'log file sync' waits
are happening? LMS info may be relevent for broadcast
on commit and LNS data may be relevant for dataguard.
If more details are needed see the ASH DETAILS FOR WORST
MINUTES section at the bottom of the report.

MINUTE       INST PROGRAM                                  EVENT                            TOTAL_WAIT_TIME      WAITS   AVG_TIME_WAITED
------------ ---- ---------------------------------------- ------------------------------ ----------------- ---------- -----------------
Oct02_0600      2 oracle@racnode1.us.oracle.com (LGWR)    log file parallel write                    4.088          1             4.088
Oct02_0600      2 oracle@racnode1.us.oracle.com (M000)    log file sync                              4.308          1             4.308
Oct09_0043      2 oracle@racnode1.us.oracle.com (LGWR)    log file parallel write                 1000.738          1          1000.738
Oct09_0043      2 sqlplus@racnode1.us.oracle.com (TNS V1- log file sync                            999.805          1           999.805
                  V3)


HISTOGRAM DATA FOR LFS AND OTHER RELATED WAITS:

APPROACH: Look at the wait distribution for log file sync waits
by looking at "wait_time_milli". Look at the high wait times then
see if you can correlate those with other related wait events.

   INST_ID EVENT                                    WAIT_TIME_MILLI WAIT_COUNT
---------- ---------------------------------------- --------------- ----------
         2 wait for scn ack                                       1          0
         2 wait for scn ack                                       2          0
         2 wait for scn ack                                       4          0
         2 wait for scn ack                                       8          1
         1 log file sync                                          1      10247
         1 log file sync                                          2        435
         1 log file sync                                          4        122
         1 log file sync                                          8         33
         1 log file sync                                         16          4
         1 log file sync                                         32          2
         1 log file sync                                         64          2
         1 log file sync                                        128          1
         1 log file sync                                        256          1
         1 log file sync                                        512          0
....................................
Oracle 数据技术 浅谈oracle技术系列 等待事件 | Guang Cai Li |

浅谈log file sync等待事件诊断（二）

原因3：用户提交过于频繁导致log file sync

在这种情况下，过多的 commit 活动可能会导致性能问题，因为把 redo 从日志缓冲区刷新到重做日志可能会导致等待’log file sync’。
如果’log file sync’的平均等待时间比’log file parallel write’高很多，这意味着大部分时间等待不是由于等待 redo 的写入，因而问题的原因不是 IO 慢导致。，其他时间可能是 CPU 活动竞争，而且是过多的 commit 导致的最常见的竞争。此外，如果’log file sync’的平均等待时间低，但等待次数高，那么应用程序可能 commit 过于频繁。

在 AWR 或 Statspack 报告中，如果每次 commit/rollback 的平均 user calls（”user calls/(user commits+user rollbacks)”） 小于 30， 表明 commit 过于频繁。
建议

  • 如果有很多短事务，看是否可能把这些事务组合在一起，从而减少 commit 操作。 因为每一个 commit 都必须收到相关 REDO 已写到磁盘上的确认，额外的 commit 会显著的增加开销。虽然 Oracle 可以将某些 commit 组合在一起，通过事务的批处理来减少commit的总体数量还是可以带来非常有益的效果。
  • 看看是否有操作可以使用 COMMIT NOWAIT 选项 （使用前应明白该选项会带来的后果）。
  • 看看是否有操作可以使用 NOLOGGING/ UNRECOVERABLE 选项完成（在不追求可恢复的情况下）。

 

经过已经分析，大概可以得出一个思路，尽量结合与lgwr有关的等待事件一起结合起来定位问题，此时应该检查awr或者statspack的等待事件。

11g新特性：
在oracle 11.2版本中引入了 Adaptive Log File sync，由参数_use_adaptive_log_file_sync控制，该参数在11.2.0.1和11.2.0.2默认设置为 false。
从 11.2.0.3 开始默认是 true。 当启用时，Oracle 可以在两种方法之间切换：

Post/wait，传统发布写重做日志完成的方法
Polling，一种新的方法，其中前台进程会检查 LGWR 是否已写完成。

该特性在一定情况下也会造成log file sync等待大量增加。

当log file sync等待事件是由于RAC节点之间SCN同步引起的，其解决方法如下：
1、检查LMS进程数量是否足够。
2、检查系统CPU资源是否足够。
3、检查RAC节点之间的私有通信是否正常。
4、设置隐含参数_immediate_commit_propagation为false，禁用immediate commit propagation特性。
RAC节点之间CR块传递
Oracle为了保证Instance Recovery实例恢复机制，而要求每一个current block在本地节点local instance被修改后(modify/update) 必须要将该current block相关的redo 写入到logfile 后（要求LGWR必须完成写入后才能返回)，才能由LMS进程传输给其他节点使用。

Oracle 数据技术 浅谈oracle技术系列 等待事件 | Guang Cai Li | |   log file sync