前言

今天在检查之前搭建的 Oracle 19c RAC 测试环境时,发现 node1、node2 两个节点的系统日志中一直重复出现 iSCSI 通信错误:

connection1:0: detected comm error (1020)
iscsid: re-opening session
iscsid: connecting to 192.168.1.116:3260
iscsid: login response status 0000
iscsid: connection1:0 is operational after recovery

在这里插入图片描述
在这里插入图片描述
从日志看,iSCSI 会话每隔几秒就会中断一次,然后由 iscsid 自动重新登录。

比较奇怪的是:

  • node1、node2 同时出现相同问题;
  • StarWind Target 正常;
  • iSCSI 登录返回状态为 0000;
  • 会话恢复后几秒钟又再次断开。

一开始我把排查方向放在了网络和 StarWind 服务端,最后才发现真正的问题不是网络,而是两台 RAC 节点使用了完全相同的 iSCSI InitiatorName。

一、环境信息

项目内容
数据库版本Oracle Database 19c
Grid InfrastructureOracle Grid Infrastructure 19c
Grid Home/u01/app/19.3.0/grid
节点1node1,192.168.10.101
节点2node2,192.168.10.102
iSCSI TargetStarWind
Target IP192.168.1.116
iSCSI 端口3260
ASM Targetiqn.2008-08.com.starwindsoftware:192.168.1.116-asm
DGASM Targetiqn.2008-08.com.starwindsoftware:192.168.1.116-dgasm
存储用途Oracle RAC ASM 共享磁盘
处理方式保留 node1 运行,停止 node2 后修改 InitiatorName

本次环境拓扑大致如下:

                     ┌────────────────────┐
                     │     StarWind       │
                     │  192.168.1.116     │
                     │      TCP 3260      │
                     └─────────┬──────────┘
                               │
                    iSCSI Shared Storage
                               │
               ┌───────────────┴───────────────┐
               │                               │
       ┌───────▼────────┐              ┌───────▼────────┐
       │     node1      │              │     node2      │
       │ 192.168.10.101 │              │ 192.168.10.102 │
       │     orcl1      │              │     orcl2      │
       └────────────────┘              └────────────────┘

二、问题现象

2.1 node2 不断出现 comm error (1020)

node2 日志中不断重复下面的内容:

Aug  6 12:20:04 node2 iscsid: re-opening session 1 (reopen_cnt 0)
Aug  6 12:20:06 node2 iscsid: connecting to 192.168.1.116:3260
Aug  6 12:20:07 node2 iscsid: connected local port 49820 to 192.168.1.116:3260
Aug  6 12:20:07 node2 iscsid: login response status 0000
Aug  6 12:20:07 node2 iscsid: connection1:0 is operational after recovery
connection1:0: detected comm error (1020)

会话恢复成功后,只能维持几秒钟,随后又再次出现:

detected comm error (1020)

然后继续:

re-opening session
connecting
login response status 0000
operational after recovery

这种过程一直循环。

在这里插入图片描述

2.2 node1 也出现相同问题

检查 node1 后发现,并不是单个节点异常,node1 同样在重复:

connection1:0: detected comm error (1020)
iscsid: re-opening session
iscsid: connecting to 192.168.1.116:3260
iscsid: login response status 0000
iscsid: connection1:0 is operational after recovery

在这里插入图片描述

两个节点都连接同一个 Target:

192.168.1.116:3260

并且都出现相同的会话中断。

这个时候初步怀疑的方向主要有:

  1. StarWind iSCSI 服务异常;
  2. StarWind 所在系统网卡异常;
  3. iSCSI 网络链路存在抖动;
  4. 两个节点存在相同的客户端配置错误。

三、初步排查

3.1 检查 Target 是否能够正常发现

分别在 node1、node2 执行:

iscsiadm -m discovery -t st -p 192.168.1.116

返回:

192.168.1.116:3260,-1 iqn.2008-08.com.starwindsoftware:192.168.1.116-asm
192.168.1.116:3260,-1 iqn.2008-08.com.starwindsoftware:192.168.1.116-dgasm

在这里插入图片描述
在这里插入图片描述

说明两个 Target 都可以正常发现。

3.2 检查当前 iSCSI 会话

iscsiadm -m session

可以看到 ASM 和 DGASM 两个会话:

tcp: [1] 192.168.1.116:3260,1 iqn.2008-08.com.starwindsoftware:192.168.1.116-asm
tcp: [2] 192.168.1.116:3260,1 iqn.2008-08.com.starwindsoftware:192.168.1.116-dgasm

Target 可以发现,会话也能建立。

从前面的日志还可以看到:

login response status 0000

说明登录过程本身能够成功。

真正的问题是:

登录成功
    ↓
会话恢复
    ↓
几秒后通信再次中断
    ↓
重新登录

所以这并不是简单的 Target 地址错误或者 Target 不存在。

3.3 检查共享磁盘

执行:

for host in /sys/class/scsi_host/host*; do
    echo "- - -" > "$host/scan"
done

lsblk

在这里插入图片描述
在这里插入图片描述

可以看到 ASM 相关磁盘和 multipath 设备仍然存在。

这说明在自动恢复期间,操作系统暂时还能重新识别共享盘。

但是 iSCSI 会话几秒钟断开一次,对于 Oracle RAC、ASM、OCR 和 Voting Disk 来说风险非常大。

四、关键发现:两个节点的 InitiatorName 完全相同

继续对比 node1、node2 的 iSCSI 客户端配置。

分别执行:

echo "HOST=$(hostname)"
cat /etc/iscsi/initiatorname.iscsi

node1 输出:

HOST=node1
InitiatorName=iqn.1988-12.com.oracle:3286eec73661

在这里插入图片描述

node2 输出:

HOST=node2
InitiatorName=iqn.1988-12.com.oracle:3286eec73661

在这里插入图片描述

可以看到:

node1 和 node2 使用了完全相同的 InitiatorName。

iSCSI InitiatorName 相当于 iSCSI 客户端的唯一身份。iSCSI Target 和 Initiator 都具有唯一标识,InitiatorName 保存在 /etc/iscsi/initiatorname.iscsi 中。

本次两台虚拟机最初是通过克隆方式创建,克隆后没有重新生成 InitiatorName,导致两个 RAC 节点以同一个 IQN 连接 StarWind。

结合现象,问题过程大致如下:

node1 使用 IQN-A 登录 StarWind
              ↓
node2 也使用相同的 IQN-A 登录
              ↓
两个节点在存储端表现为同一个 Initiator 身份
              ↓
会话产生冲突或被重新建立
              ↓
node1、node2 不断出现 comm error (1020)
              ↓
iscsid 自动重新登录
              ↓
两个节点继续互相影响

五、处理思路

因为这是 Oracle RAC 环境,共享盘正在被 ASM 和 Clusterware 使用,所以不能直接在两个节点都在线的情况下修改 InitiatorName 或重启 iscsid

本次处理思路如下:

确认 node1 状态正常
        ↓
保留 node1 继续运行
        ↓
停止 node2 的 Clusterware
        ↓
退出 node2 的 iSCSI 会话
        ↓
为 node2 生成新的 InitiatorName
        ↓
重新启动 iscsid 并登录 Target
        ↓
确认共享盘和 multipath 正常
        ↓
启动 node2 Clusterware
        ↓
检查 RAC、ASM 和 iSCSI 日志

六、处理过程

6.1 确认 node1 可以正常运行

在 node1 检查集群资源:

/u01/app/19.3.0/grid/bin/crsctl stat res -t

检查 ASM 磁盘组:

su - grid -c 'asmcmd lsdg'

确认:

  • node1 的 ASM 正常;
  • DATA、OCR 磁盘组为 MOUNTED
  • Offline_disks=0
  • 数据库实例正常;
  • node1 可以继续承载集群资源。

在这里插入图片描述

这里发现我的ARCH归档盘不见了… 后续再排查吧…

6.2 停止 node2 Clusterware

停止 node2:

/u01/app/19.3.0/grid/bin/crsctl stop crs

在这里插入图片描述

6.3 备份 node2 原有配置

修改前先备份 InitiatorName:

cp -a /etc/iscsi/initiatorname.iscsi \
/root/initiatorname.iscsi.before_fix

保存当前 iSCSI 会话:

iscsiadm -m session -P 3 \
> /root/iscsi-session-before-fix.txt

保存 multipath 状态:

multipath -ll \
> /root/multipath-before-fix.txt

确认旧 IQN:

cat /etc/iscsi/initiatorname.iscsi

在这里插入图片描述

6.4 为 node2 生成新的 InitiatorName

执行:

NEWIQN=$(/sbin/iscsi-iname -p iqn.1988-12.com.oracle)

保存生成结果:

printf '%s\n' "$NEWIQN" | tee /root/node2-new-initiator.iqn

本次生成的新 IQN 为:

iqn.1988-12.com.oracle:b397725d693

在这里插入图片描述

对比修改前后:

node1:
iqn.1988-12.com.oracle:3286eec73661

node2:
iqn.1988-12.com.oracle:b397725d693

现在两个节点的 InitiatorName 已经不同。

6.5 退出 node2 的 iSCSI 会话

退出 ASM Target:

iscsiadm -m node \
-T iqn.2008-08.com.starwindsoftware:192.168.1.116-asm \
-p 192.168.1.116:3260 \
--logout

退出 DGASM Target:

iscsiadm -m node \
-T iqn.2008-08.com.starwindsoftware:192.168.1.116-dgasm \
-p 192.168.1.116:3260 \
--logout

在这里插入图片描述

确认没有活动会话:

iscsiadm -m session

在这里插入图片描述

6.6 写入新的 InitiatorName

读取刚刚生成的新 IQN:

NEWIQN=$(cat /root/node2-new-initiator.iqn)

写入配置文件:

printf 'InitiatorName=%s\n' "$NEWIQN" \
> /etc/iscsi/initiatorname.iscsi

确认配置:

cat /etc/iscsi/initiatorname.iscsi

在这里插入图片描述

重启 iscsid:

systemctl restart iscsid

6.7 重新发现并登录 Target

重新发现 Target:

iscsiadm -m discovery \
-t sendtargets \
-p 192.168.1.116:3260

登录 ASM Target:

iscsiadm -m node \
-T iqn.2008-08.com.starwindsoftware:192.168.1.116-asm \
-p 192.168.1.116:3260 \
--login

登录 DGASM Target:

iscsiadm -m node \
-T iqn.2008-08.com.starwindsoftware:192.168.1.116-dgasm \
-p 192.168.1.116:3260 \
--login

在这里插入图片描述
在这里插入图片描述

6.8 重新扫描 SCSI 设备

for host in /sys/class/scsi_host/host*; do
    echo "- - -" > "$host/scan"
done

等待 udev 处理完成:

udevadm settle

在这里插入图片描述

刷新 multipath:

multipath -r

检查磁盘:

lsblk
multipath -ll

确认原来的共享磁盘和 multipath 设备重新出现。

七、验证新的 iSCSI 会话

执行:

iscsiadm -m session -P 1

可以看到两个 Target 都已登录:
在这里插入图片描述

这里最关键的是:

Iface Initiatorname: iqn.1988-12.com.oracle:b397725d693

说明当前会话已经使用 node2 的新 InitiatorName,而不是原来的重复 IQN。

八、启动 node2 Clusterware

确认共享盘和 multipath 正常后,启动 node2:

/u01/app/19.3.0/grid/bin/crsctl start crs

在这里插入图片描述

等待一段时间后检查集群资源:

/u01/app/19.3.0/grid/bin/crsctl stat res -t

检查 ASM:

su - grid -c 'asmcmd lsdg'

在这里插入图片描述

九、确认 comm error (1020) 不再出现

最后分别在 node1、node2 使用 root 用户执行:

journalctl --since "30 minutes ago" | \
grep -Ei 'detected comm error|re-opening session|operational after recovery'

两台节点均没有任何输出。

为了进一步观察,也可以实时监控五分钟:

timeout 300 journalctl -f -n 0 --no-pager | \
grep --line-buffered -Ei \
'detected comm error|re-opening session|operational after recovery'

五分钟内没有新的输出,说明 iSCSI 会话已经稳定。

十、处理结果对比

检查项修复前修复后
node1 InitiatorNameiqn.1988-12.com.oracle:3286eec73661保持不变
node2 InitiatorName与 node1 完全相同iqn.1988-12.com.oracle:b397725d693
iSCSI 会话每隔几秒断开并恢复持续保持 LOGGED IN
系统日志反复出现 comm error (1020)最近30分钟无新增错误
ASM会话不断抖动,存在磁盘离线风险DATA、OCR 正常挂载
RAC存在实例或节点异常风险两个实例均正常运行
StarWind 客户端身份两节点使用同一 IQN两节点使用不同 IQN

十一、总结

这次问题比较容易被误判为网络故障。

因为从日志表面看:

连接成功
登录成功
会话恢复
几秒后通信错误

再加上 node1、node2 同时出现问题,很容易直接把方向放到交换机、网卡或者 StarWind 服务端。

但继续对比两个节点的基础配置后才发现,真正的问题是两个节点使用了相同的 InitiatorName。

几个需要注意的点:

  1. 通过模板或克隆方式创建 Linux 虚拟机后,一定要检查 /etc/iscsi/initiatorname.iscsi。

    主机名、IP 地址改了,不代表 iSCSI InitiatorName 也会自动改变。

  2. 同一个共享 Target 可以被多个节点访问,但每个节点必须使用自己的 Initiator 身份。

    iSCSI InitiatorName 是存储端区分客户端的重要标识,不能简单复制。

  3. 看到 login response status 0000 不能直接判断 iSCSI 正常。

    它只能说明当次登录成功,还要继续观察会话是否稳定,是否存在 re-opening session 和 comm error。

  4. RAC 环境不能直接在线修改 InitiatorName。

    修改前应先停止待处理节点的数据库、ASM 和 Clusterware,确保该节点不再使用共享盘。

  5. 生产或集群环境操作前一定要备份。

    至少保留:

    /etc/iscsi/initiatorname.iscsi
    iscsiadm -m session -P 3
    multipath -ll
    crsctl stat res -t
    asmcmd lsdg
    
  6. 修复不能只看磁盘重新出现。

    最终需要同时验证:

    InitiatorName 是否唯一
    iSCSI Session 是否 LOGGED IN
    multipath 路径是否正常
    ASM 磁盘组是否 MOUNTED
    RAC 资源是否 ONLINE
    comm error 日志是否停止
    

接下来把ARCH问题解决一下…


附录:常用检查命令

查看 InitiatorName

echo "HOST=$(hostname)"
cat /etc/iscsi/initiatorname.iscsi

发现 iSCSI Target

iscsiadm -m discovery -t sendtargets -p 192.168.1.116:3260

查看 iSCSI 会话

iscsiadm -m session
iscsiadm -m session -P 1
iscsiadm -m session -P 3

查看磁盘和多路径

lsblk
multipath -ll

扫描 SCSI 总线

for host in /sys/class/scsi_host/host*; do
    echo "- - -" > "$host/scan"
done

查询 Grid Home

cat /etc/oracle/olr.loc

停止和启动本节点 Clusterware

/u01/app/19.3.0/grid/bin/crsctl stop crs

/u01/app/19.3.0/grid/bin/crsctl start crs

查看集群资源

/u01/app/19.3.0/grid/bin/crsctl stat res -t

查看 ASM 磁盘组

su - grid -c 'asmcmd lsdg'

检查 iSCSI 异常日志

journalctl --since "30 minutes ago" | \
grep -Ei 'detected comm error|re-opening session|operational after recovery'

实时观察 iSCSI 日志

timeout 300 journalctl -f -n 0 --no-pager | \
grep --line-buffered -Ei \
'detected comm error|re-opening session|operational after recovery'
Logo

北京人形旗下天工造物具身智能开源社区,聚焦具身天工与慧思开物两大平台

更多推荐