My Oracle Support Banner

ACFS Directory rang locking issue lead hang and state data (Doc ID 2712542.1)

Last updated on MARCH 03, 2021

Applies to:

Oracle Database - Enterprise Edition - Version 19.8.0.0.0 and later
Information in this document applies to any platform.

Symptoms

Intermittently ACFS filesystem reporting stale information and corruption.
We have separate acfs directory for each nodes.
Initially fsck was ran and fixed it.again issue reported on another directory .

F 4586568.123/200908104506 amex_TH_disconn[350880] ASSERTION FAILURE: 0 File /scratch/builds/aime/aime_usm_946124/el7uek4_112_x86_64/usm/src/ofs/driver/./gen/ofsgenmeta.c Line 4953
K 4586568.123/200908104506 amex_TH_disconn[350880] KsDumpStack: See stack call traceback in /var/log/messages
A 4586568.124 HM: Assertion dump. Lines start "A 350880 "
A 350880 4586568.124 HM assertion output
A 350880 name:amex_TH_disconn pid:350880
A 350880 tsd:0xffff8899f9803138 l_OfsVolNum:5
A 350880 current_record_seq_cnt:140
A 350880 total_elapsed_secs:0 hang_elapsed_secs:0
A 350880 record_cnt:18 lock_cnt:12 func_cnt:6
A 350880 last_rec_rem:OfsAllocateMemory
A 350880 Hang Manager stack dump for tid:0xffff88955560d400
A 350880 0 F ofs_meta_get_int
A 350880 0 F ofsgenmeta.c line:3856
A 350880 0 F elapsed_secs:0 seq_num:140
A 350880 1 F ofs_meta_refblk_int
A 350880 1 F ofsgenmeta.c line:2630
A 350880 1 F elapsed_secs:0 seq_num:127
A 350880 2 L LH_DirRangeMetaDataLock type:168
A 350880 2 L ofsgendlm.c line:11076
A 350880 2 L LHV:LH_DirRangeLockGrouping:166 LHV2:LH_NOTHING:0
A 350880 2 L id1:0xffff882ed635eb48 id2:0x0000000000000000
A 350880 2 L mode:0x24:LH_KSRWLOCK,LH_SHARED
A 350880 2 L state:held prev_tid:0xffff888a5feb0e00
A 350880 2 L blocked_ticks:0 held_ticks:1
A 350880 2 L elapsed_secs:0 seq_num:126
A 350880 3 L LH_DirRangeDLMLock type:167
A 350880 3 L ofsgendirnode.c line:3285
A 350880 3 L LHV:LH_DirRangeLockGrouping:166 LHV2:LH_NOTHING:0
A 350880 3 L id1:0x000000000000458d id2:0x0000000000000004
A 350880 3 L nsid:0x100000000002cc02 mode:0x120:LH_SHARED,LH_DLM
A 350880 3 L state:held prev_tid:0x0000000000000000
A 350880 3 L blocked_ticks:0 held_ticks:1
A 350880 3 L elapsed_secs:0 seq_num:123
A 350880 4 F ofs_directory_ref_dir_node
A 350880 4 F ofsgendirnode.c line:3258
A 350880 4 F elapsed_secs:0 seq_num:122
A 350880 5 L LH_DirRangeMetaDataLock type:168
A 350880 5 L ofsgendlm.c line:11076
A 350880 5 L LHV:LH_DirRangeLockGrouping:166 LHV2:LH_NOTHING:0
A 350880 5 L id1:0xffff882bee694908 id2:0x0000000000000000
A 350880 5 L mode:0x24:LH_KSRWLOCK,LH_SHARED
A 350880 5 L state:held prev_tid:0xffff888a5feb0e00
A 350880 5 L blocked_ticks:0 held_ticks:1
A 350880 5 L elapsed_secs:0 seq_num:93
A 350880 6 L LH_DirRangeDLMLock type:167
A 350880 6 L ofsgendirnode.c line:3285
A 350880 6 L LHV:LH_DirRangeLockGrouping:166 LHV2:LH_NOTHING:0
A 350880 6 L id1:0x000000000000458d id2:0x0000000000000174
A 350880 6 L nsid:0x100000000002cc02 mode:0x120:LH_SHARED,LH_DLM
A 350880 6 L state:held prev_tid:0x0000000000000000
A 350880 6 L blocked_ticks:2 held_ticks:1
A 350880 6 L elapsed_secs:0 seq_num:90
A 350880 7 F ofs_directory_lock_ranges_for_insert
A 350880 7 F ofsgendirnode.c line:6208
A 350880 7 F elapsed_secs:0 seq_num:57
A 350880 8 F OfsGenCreate
A 350880 8 F ofsgencreate.c line:15702
A 350880 8 F elapsed_secs:0 seq_num:56
A 350880 9 L LH_FETAFreeBlkDLMLock type:128
A 350880 9 L ofsgenfeta.c line:3281
A 350880 9 L LHV:LH_FileGrouping:125 LHV2:LH_NOTHING:0
A 350880 9 L id1:0x0000000000405fd5 id2:0x0000000000000000
A 350880 9 L nsid:0x100000000002cc02 mode:0x140:LH_EXCLUSIVE,LH_DLM
A 350880 9 L state:held prev_tid:0x0000000000000000
A 350880 9 L blocked_ticks:0 held_ticks:3
A 350880 9 L elapsed_secs:0 seq_num:48
A 350880 10 L LH_DirExtentsLock type:124
A 350880 10 L ofsgendlm.c line:11234
A 350880 10 L LHV:LH_DirGrouping:121 LHV2:LH_NOTHING:0
A 350880 10 L id1:0xffff882b60b7aee0 id2:0x0000000000000000
A 350880 10 L mode:0x44:LH_KSRWLOCK,LH_EXCLUSIVE
A 350880 10 L state:held prev_tid:0xffff88955560d400
A 350880 10 L blocked_ticks:4586568121 held_ticks:3
A 350880 10 L elapsed_secs:4586568 seq_num:28
A 350880 11 L LH_DirDLMLock type:122
A 350880 11 L ofsgenfeta.c line:2639
A 350880 11 L LHV:LH_DirGrouping:121 LHV2:LH_NOTHING:0
A 350880 11 L id1:0x000000000000458d id2:0x0000000000000001
A 350880 11 L nsid:0x100000000002cc02 mode:0x140:LH_EXCLUSIVE,LH_DLM
A 350880 11 L state:held prev_tid:0x0000000000000000
A 350880 11 L blocked_ticks:4586568121 held_ticks:3
A 350880 11 L elapsed_secs:4586568 seq_num:17
A 350880 12 L LH_DirMetaDataLock type:123
A 350880 12 L ofsliniops.c line:2969
A 350880 12 L LHV:LH_DirGrouping:121 LHV2:LH_DirGrouping:121
A 350880 12 L id1:0xffff882b60b7ae18 id2:0x0000000000000000
A 350880 12 L mode:0x24:LH_KSRWLOCK,LH_SHARED

A 350880 16 L LHV:LH_RlogsModifyingVOPsLock:88 LHV2:LH_NOTHING:0
A 350880 16 L id1:0xffff8833c01aa488 id2:0x0000000000000000
A 350880 16 L mode:0x24:LH_KSRWLOCK,LH_SHARED
A 350880 16 L state:held prev_tid:0xffff889ad20a7000
A 350880 16 L blocked_ticks:0 held_ticks:3
A 350880 16 L elapsed_secs:0 seq_num:3
A 350880 17 F ofs_create_int
A 350880 17 F ofsliniops.c line:2678
A 350880 17 F elapsed_secs:0 seq_num:1
K 4586568.124/200908104506 amex_TH_disconn[350880] Free stack space lows OKS:2048 ACFS:2048 ADVM:2048
###!!!@@@ KsLog Tail/Start @@@!!!###
smWrRb) total (IOs 759038, offloaded 759038 (0 bio, 0 cpu), inlined 0) lists 740128
asmIoPoolLog(UsmWrRb) rd (threads=16, ioperth=16) wr (threads=16, ioperth=16)
V 4437409.016 multipath[117916] asmIoPoolLog(UsmRdBb) total (IOs 1108, offloaded 0 (0 bio, 0 cpu), inlined 1108) lists 0
asmIoPoolLog(UsmRdBb) rd (threads=16, ioperth=16) wr (threads=16, ioperth=16)

File_name:: Fokslog.0

Sep 8 10:45:06 xxxxxxxxx iscsid[17656]: iscsid: deleting a scheduled/waiting thread!
Sep 8 10:45:06 xxxxxxxxx systemd-logind[9909]: New session 26401 of user starbatch.
Sep 8 10:45:06 xxxxxxxxx systemd[1]: Started Session 26401 of user starbatch.
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.361818] [Oracle ACFS] ASSERTION FAILURE: 0 File: /scratch/builds/aime/aime_usm_946124/el7uek4_112_x86_64/usm/src/ofs/driver/./gen/ofsgenmeta.c: Line: 4953
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.361823] KsDumpStack: Stack call traceback
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.361826] CPU: 31 PID: 350880 Comm: amex_TH_disconn Tainted: P O 4.1.12-124.30.1.el7uek.x86_64 #2
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.361828] Hardware name: Oracle Corporation ORACLE SERVER X7-2/ASM, MB, X7-2, BIOS 41060400 05/20/2019
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.361830] 0000000000000286 00000000a6455331 ffff88901dac3708 ffffffff8174ff04
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.361834] ffffffffc0f01f98 0000000000001359 ffff88901dac3718 ffffffffc08abeab
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.361836] ffff88901dac3758 ffffffffc0bdeb19 ffff88901dac3758 00000000a9b3b000
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.361838] Call Trace:
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.361848] [<ffffffff8174ff04>] dump_stack+0x63/0x81
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.361866] [<ffffffffc08abeab>] KsDumpStack+0x3b/0x40 [oracleoks]
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.361906] [<ffffffffc0bdeb19>] OfsDoAssertion+0x1c9/0x210 [oracleacfs]
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.361926] [<ffffffffc0bdb533>] ofs_meta_get_int+0x40a3/0x4ac0 [oracleacfs]
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.361946] [<ffffffffc0bdc162>] ofs_meta_refblk_int+0x212/0x660 [oracleacfs]
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.361964] [<ffffffffc0b617a7>] ofs_directory_ref_dir_node+0x127/0x380 [oracleacfs]
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.361981] [<ffffffffc0b69192>] ofs_directory_lock_ranges_for_insert+0x1b2/0xcc0 [oracleacfs]
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.361997] [<ffffffffc0b44848>] OfsGenCreate+0x228/0x32a0 [oracleacfs]
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362006] [<ffffffffc08bfdbe>] ? KsLHHMRecFnRemoveInt+0x2fe/0x360 [oracleoks]
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362026] [<ffffffffc0bdec90>] ? OfsAllocateMemory+0x130/0x240 [oracleacfs]
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362056] [<ffffffffc0d9a526>] ofs_create_int+0xa66/0x23e0 [oracleacfs]
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362084] [<ffffffffc0d9c28c>] ofs_create+0x2c/0x30 [oracleacfs]
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362089] [<ffffffff8122c4bb>] vfs_create+0xdb/0x140
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362091] [<ffffffff8122f6fd>] do_last+0x9fd/0x1280
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362094] [<ffffffff8123000f>] path_openat+0x8f/0x630
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362099] [<ffffffff811d06f5>] ? handle_pte_fault+0xd75/0x1700
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362102] [<ffffffff811f2751>] ? alloc_pages_current+0x91/0x100
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362105] [<ffffffff81231b89>] do_filp_open+0x49/0xc0
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362108] [<ffffffff8123ef77>] ? __alloc_fd+0xa7/0x130
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362112] [<ffffffff8121ee87>] do_sys_open+0x137/0x240
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362115] [<ffffffff81138fb6>] ? __audit_syscall_exit+0x1e6/0x280
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362117] [<ffffffff8121efae>] SyS_open+0x1e/0x20
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362123] [<ffffffff81758cf6>] system_call_fastpath+0x18/0xee
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362161] A 4586568.124 HM: Assertion dump. Lines start "A 350880 "
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362176] A 350880 4586568.124 HM assertion output
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362189] A 350880 name:amex_TH_disconn pid:350880
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362202] A 350880 tsd:0xffff8899f9803138 l_OfsVolNum:5
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362203] A 350880 current_record_seq_cnt:140
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362205] A 350880 total_elapsed_secs:0 hang_elapsed_secs:0
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362206] A 350880 record_cnt:18 lock_cnt:12 func_cnt:6
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362208] A 350880 last_rec_rem:OfsAllocateMemory
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362209] A 350880 Hang Manager stack dump for tid:0xffff88955560d400
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362213] A 350880 0 F ofs_meta_get_int
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362215] A 350880 0 F ofsgenmeta.c line:3856
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362216] A 350880 0 F elapsed_secs:0 seq_num:140
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362219] A 350880 1 F ofs_meta_refblk_int
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362220] A 350880 1 F ofsgenmeta.c line:2630
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362221] A 350880 1 F elapsed_secs:0 seq_num:127
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362232] A 350880 2 L LH_DirRangeMetaDataLock type:168
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362233] A 350880 2 L ofsgendlm.c line:11076
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362235] A 350880 2 L LHV:LH_DirRangeLockGrouping:166 LHV2:LH_NOTHING:0
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362236] A 350880 2 L id1:0xffff882ed635eb48 id2:0x0000000000000000
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362237] A 350880 2 L mode:0x24:LH_KSRWLOCK,LH_SHARED
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362239] A 350880 2 L state:held prev_tid:0xffff888a5feb0e00
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362240] A 350880 2 L blocked_ticks:0 held_ticks:1
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362241] A 350880 2 L elapsed_secs:0 seq_num:126
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362249] A 350880 3 L LH_DirRangeDLMLock type:167
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362250] A 350880 3 L ofsgendirnode.c line:3285
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362251] A 350880 3 L LHV:LH_DirRangeLockGrouping:166 LHV2:LH_NOTHING:0
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362253] A 350880 3 L id1:0x000000000000458d id2:0x0000000000000004
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362254] A 350880 3 L nsid:0x100000000002cc02 mode:0x120:LH_SHARED,LH_DLM
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362255] A 350880 3 L state:held prev_tid:0x0000000000000000
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362257] A 350880 3 L blocked_ticks:0 held_ticks:1
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362258] A 350880 3 L elapsed_secs:0 seq_num:123
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362261] A 350880 4 F ofs_directory_ref_dir_node
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362262] A 350880 4 F ofsgendirnode.c line:3258
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362263] A 350880 4 F elapsed_secs:0 seq_num:122
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362270] A 350880 5 L LH_DirRangeMetaDataLock type:168
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362271] A 350880 5 L ofsgendlm.c line:11076
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362272] A 350880 5 L LHV:LH_DirRangeLockGrouping:166 LHV2:LH_NOTHING:0
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362274] A 350880 5 L id1:0xffff882bee694908 id2:0x0000000000000000
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362275] A 350880 5 L mode:0x24:LH_KSRWLOCK,LH_SHARED
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362276] A 350880 5 L state:held prev_tid:0xffff888a5feb0e00
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362277] A 350880 5 L blocked_ticks:0 held_ticks:1
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362279] A 350880 5 L elapsed_secs:0 seq_num:93
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362285] A 350880 6 L LH_DirRangeDLMLock type:167
Sep 8 10:45:06 xxxxxxxxx kernel: [291213.362286] A 350880 6 L ofsgendirnode.c line:3285

File_name:: messages

 

 

Cause

To view full details, sign in with your My Oracle Support account.

Don't have a My Oracle Support account? Click to get started!


In this Document
Symptoms
Cause
Solution
References


My Oracle Support provides customers with access to over a million knowledge articles and a vibrant support community of peers and Oracle experts.