Bug 1274702

Summary: Data Tiering:tier log not collecting information regarding file demotes
Product: [Red Hat Storage] Red Hat Gluster Storage Reporter: Nag Pavan Chilakam <nchilaka>
Component: tierAssignee: Bug Updates Notification Mailing List <rhs-bugs>
Status: CLOSED WORKSFORME QA Contact: Nag Pavan Chilakam <nchilaka>
Severity: medium Docs Contact:
Priority: high    
Version: rhgs-3.1CC: asrivast, hgowtham, rhs-bugs, storage-qa-internal, vagarwal
Target Milestone: ---Keywords: ZStream
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2015-10-29 07:29:38 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 1260923    

Description Nag Pavan Chilakam 2015-10-23 12:07:33 UTC
Description of problem:
=========================
While the tier log is successfully registering file promotions as below, However it is not collecting file demotes. We need to collect even file demote logs.
t to spain-hot-dht
[2015-10-23 11:50:02.295761] I [MSGID: 109038] [tier.c:476:tier_migrate_using_query_file] 0-spain-tier-dht: Tier 1 src_subvol spain-cold-dht file cz.50
[2015-10-23 11:50:02.297320] I [dht-rebalance.c:1103:dht_migrate_file] 0-spain-tier-dht: /dir1/cz.50: attempting to move from spain-cold-dht to spain-hot-dht
[2015-10-23 11:50:02.315276] W [dht-rebalance.c:1247:dht_migrate_file] 0-spain-tier-dht: /dir1/cz.50: failed to fsync on spain-hot-dht (Structure needs cleaning)
[2015-10-23 11:50:02.329477] I [MSGID: 109022] [dht-rebalance.c:1430:dht_migrate_file] 0-spain-tier-dht: completed migration of /dir1/cz.50 from subvolume spain-cold-dht to spain-hot-dht





See in below case, while there were about 50 file demotes no log was collected for the same period:

[root@zod ~]# gluster v tier spain status;gluster v rebal spain status
Node                 Promoted files       Demoted files        Status              
---------            ---------            ---------            ---------           
localhost            135                  0                    in progress         
yarrow               0                    82                   in progress         
volume rebalance: spain: success: 
                                    Node Rebalanced-files          size       scanned      failures       skipped               status   run time in secs
                               ---------      -----------   -----------   -----------   -----------   -----------         ------------     --------------
                               localhost              133        0Bytes           235             1             0          in progress            3201.00
                                  yarrow               81        0Bytes           317           234             0          in progress            3201.00
volume rebalance: spain: success: 
[root@zod ~]# 
[root@zod ~]# 
[root@zod ~]# 
[root@zod ~]# gluster v tier spain status;gluster v rebal spain status
Node                 Promoted files       Demoted files        Status              
---------            ---------            ---------            ---------           
localhost            135                  0                    in progress         
yarrow               0                    144                  in progress         
volume rebalance: spain: success: 






====================================================================================
[2015-10-23 11:57:16.235489] I [MSGID: 109028] [dht-rebalance.c:3327:gf_defrag_status_get] 0-glusterfs: Rebalance is in progress. Time taken is 3201.00 secs
[2015-10-23 11:57:16.235529] I [MSGID: 109028] [dht-rebalance.c:3331:gf_defrag_status_get] 0-glusterfs: Files migrated: 133, size: 0, lookups: 235, failures: 1, skipped: 0
[2015-10-23 11:57:16.263824] I [MSGID: 109028] [dht-rebalance.c:3327:gf_defrag_status_get] 0-glusterfs: Rebalance is in progress. Time taken is 3201.00 secs
[2015-10-23 11:57:16.263827] I [MSGID: 109028] [dht-rebalance.c:3331:gf_defrag_status_get] 0-glusterfs: Files migrated: 133, size: 0, lookups: 235, failures: 1, skipped: 0


[2015-10-23 12:03:36.334669] I [MSGID: 109028] [dht-rebalance.c:3327:gf_defrag_status_get] 0-glusterfs: Rebalance is in progress. Time taken is 3581.00 secs
[2015-10-23 12:03:36.334712] I [MSGID: 109028] [dht-rebalance.c:3331:gf_defrag_status_get] 0-glusterfs: Files migrated: 133, size: 0, lookups: 235, failures: 1, skipped: 0
[2015-10-23 12:03:36.367673] I [MSGID: 109028] [dht-rebalance.c:3327:gf_defrag_status_get] 0-glusterfs: Rebalance is in progress. Time taken is 3581.00 secs
[2015-10-23 12:03:36.367676] I [MSGID: 109028] [dht-rebalance.c:3331:gf_defrag_status_get] 0-glusterfs: Files migrated: 133, size: 0, lookups: 235, failures: 1, skipped: 0





Version-Release number of selected component (if applicable):
=============================================================
glusterfs-server-3.7.5-0.3.el7rhgs.x86_64





Steps to Reproduce:

1.create a tier volume, enable ctr
2.create a file and wait for it to get demoted
3, while waiting, keep viewing the <volume>-tier.log
4, It can be seen no information of demote is captured.
5. Now once demoted, access the file to heat it and it can be seen that when file is promoted, a message is logged as below:


[2015-10-23 11:50:02.332072] I [MSGID: 109038] [tier.c:476:tier_migrate_using_query_file] 0-spain-tier-dht: Tier 1 src_subvol spain-cold-dht file cz.6
[2015-10-23 11:50:02.333618] I [dht-rebalance.c:1103:dht_migrate_file] 0-spain-tier-dht: /dir1/cz.6: attempting to move from spain-cold-dht to spain-hot-dht
[2015-10-23 11:50:02.351629] W [dht-rebalance.c:1247:dht_migrate_file] 0-spain-tier-dht: /dir1/cz.6: failed to fsync on spain-hot-dht (Structure needs cleaning)
[2015-10-23 11:50:02.365699] I [MSGID: 109022] [dht-rebalance.c:1430:dht_migrate_file] 0-spain-tier-dht: completed migration of /dir1/cz.6 from subvolume spain-cold-dht to spain-hot-dht

Comment 3 hari gowtham 2015-10-29 07:29:38 UTC
I tried to recreate the bug and found the log for demotion being the same as the log for promotion.

It looks like the demotion is also being logged for each file as mentioned below:

===============================================================================

[2015-10-29 05:37:49.261900] I [MSGID: 109038] [tier.c:493:tier_migrate_using_query_file] 0-v1-tier-dht: Tier 0 src_subvol v1-hot-dht file file100.txt
[2015-10-29 05:37:49.262963] I [dht-rebalance.c:1184:dht_migrate_file] 0-v1-tier-dht: /file100.txt: attempting to move from v1-hot-dht to v1-cold-dht
[2015-10-29 05:37:49.335305] I [MSGID: 109022] [dht-rebalance.c:1554:dht_migrate_file] 0-v1-tier-dht: completed migration of /file100.txt from subvolume v1-hot-dht to v1-cold-dht

===============================================================================

I'm closing this bug as of now. If you find the bug occuring later please feel free to file it.