Background-dedup doesn't start as scheduled
Applies to
ONTAP 9.8
Issue
sis.log
reports that background-dedup doesn't start as scheduled.- Normal log:
Sun Dec 5 21:00:05 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-2222222222] /vol/vol2 [sid: 1638705605] Begin (schedule)
Sun Dec 5 21:00:05 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-2222222222] /vol/vol2 [sid: 1638705605] Begin (sis auto check)
Sun Dec 5 21:00:05 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-2222222222] /vol/vol2 [sid: 1638705605] Verify
Mon Dec 6 00:01:00 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-2222222222] /vol/vol2 [sid: 0] Info (Dedupe operation is pausing)
Mon Dec 6 00:01:02 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-2222222222] /vol/vol2 [sid: 1638705605] Stats (blks gathered 0,finger prints sorted 0,dups found 0,new dups found 0,blks deduped 0,finger prints checked 3808887990,finger prints deleted 78346019)
Mon Dec 6 00:01:02 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-2222222222] /vol/vol2 [sid: 0] Error (Operation was stopped because it exceeded the specified duration)
Mon Dec 6 21:00:00 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-2222222222] /vol/vol2 [sid: 1638705605] Sis Restart (Restarting from Checking_pass1 stage )
Mon Dec 6 21:00:00 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-2222222222] /vol/vol2 [sid: 1638705605] Begin (sis auto check)
Mon Dec 6 21:00:00 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-2222222222] /vol/vol2 [sid: 1638705605] Verify
Mon Dec 6 21:21:16 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-2222222222] /vol/vol2 [sid: 1638705605] Merge (375819487 stale entries)
Mon Dec 6 21:29:28 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-2222222222] /vol/vol2 [sid: 1638705605] Sis Verify Phase End
Mon Dec 6 21:29:28 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-2222222222] /vol/vol2 [sid: 1638705605] Stats (blks gathered 0,finger prints sorted 0,dups found 0,new dups found 0,blks deduped 0,finger prints checked 1259516360,finger prints deleted 375819487)
Mon Dec 6 21:29:28 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-2222222222] /vol/vol2 [sid: 0] Info (Generating aggr FPDB from volume FPDB)
Mon Dec 6 22:27:49 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-2222222222] /vol/vol2 [sid: 1638705605] Compress Preproc (165911192 entries)
Mon Dec 6 22:31:42 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-2222222222] /vol/vol2 [sid: 1638705605] Compressing
Mon Dec 6 23:14:06 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-2222222222] /vol/vol2 [sid: 1638705605] Dedup Pass1 (6072616 dup entries)
Mon Dec 6 23:14:17 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-2222222222] /vol/vol2 [sid: 1638705605] Dedup Pass2 (4584484 dup entries)
Mon Dec 6 23:14:30 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-2222222222] /vol/vol2 [sid: 1638705605] Sharing (0 return status)
Mon Dec 6 23:25:07 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-2222222222] /vol/vol2 [sid: 1638705605] Stats (blks gathered 0,finger prints sorted 4198869991,dups found 6072616,new dups found 4584484,blks deduped 9435650,finger prints checked 0,finger prints deleted 0)
Mon Dec 6 23:25:07 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-2222222222] /vol/vol2 [sid: 1638705605] End (173499964 KB)
- Abnormal log:
Tue Dec 7 11:39:21 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-00000000000000] /vol/vol1 [sid: 1638609900] Sort (5169799464 fp entries)
Tue Dec 7 12:38:59 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-00000000000000] /vol/vol1 [sid: 1638609900] Dedup Pass1 (0 dup entries)
Tue Dec 7 12:39:00 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-00000000000000] /vol/vol1 [sid: 1638609900] Dedup Pass2 (1128045815 dup entries)
Tue Dec 7 13:02:14 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-00000000000000] /vol/vol1 [sid: 1638609900] Sharing (0 return status)
Tue Dec 7 20:18:18 JST 2021 [Vserver UUID: a2833bce-2000-11ec-bf03-00000000000000] /vol/vol1 [sid: 0] Info (Generating volume FPDB from aggr FPDB)