Uploaded image for project: 'Lustre'
  1. Lustre
  2. LU-3421

(ost_handler.c:1762:ost_blocking_ast()) Error -2 syncing data on lock cancel causes first ENOSPC client issues then MDS server locks up

Details

    • Bug
    • Resolution: Fixed
    • Minor
    • Lustre 2.4.1, Lustre 2.5.0
    • Lustre 2.4.0
    • RHEL6.4 running with Lutsre 2.4-rc2 and cray clients running [2.4.0-rc1 SLES11 SP1 / 2.4.0-rc2 SLES11 SP2] clients
    • 3
    • 8486

    Description

      Several times during our test shot we would encounter a situation where OSTs would report ENOSPC even tho there was enough space and inodes available. In time the MDS would become pinned and it would have to be rebooted to get a working file system again. I have attached the console logs for the MDS and OSS.

      Attachments

        Issue Links

          Activity

            [LU-3421] (ost_handler.c:1762:ost_blocking_ast()) Error -2 syncing data on lock cancel causes first ENOSPC client issues then MDS server locks up
            pjones Peter Jones added a comment -

            ok James. Do you have a timeframe for your next testshot yet?

            pjones Peter Jones added a comment - ok James. Do you have a timeframe for your next testshot yet?

            I tested your patch at small scale and it works fine. I like to keep this ticket open until our next test shot to ensure this addresses the problem. Andreas point out other issues as well.

            simmonsja James A Simmons added a comment - I tested your patch at small scale and it works fine. I like to keep this ticket open until our next test shot to ensure this addresses the problem. Andreas point out other issues as well.

            While running some tests locally, i found out that the space reserved for precreation always decreases, eventually reaches 0 and stays there. It seems that we exit from ofd_grant() at line 641:

             637         /* align grant on block size */
             638         grant &= ~((1ULL << ofd->ofd_blockbits) - 1);
             639 
             640         if (!grant)
             641                 RETURN(0);
            

            I think there are two issues:

            • ofd_grant_create() is not aggressive enough in reserving space for precreation and ends up requesting an amount of grant space smaller than a block
            • the rounding in ofd_grant() turns the <4KB allocation into 0.

            I will provide a patch.

            johann Johann Lombardi (Inactive) added a comment - While running some tests locally, i found out that the space reserved for precreation always decreases, eventually reaches 0 and stays there. It seems that we exit from ofd_grant() at line 641: 637 /* align grant on block size */ 638 grant &= ~((1ULL << ofd->ofd_blockbits) - 1); 639 640 if (!grant) 641 RETURN(0); I think there are two issues: ofd_grant_create() is not aggressive enough in reserving space for precreation and ends up requesting an amount of grant space smaller than a block the rounding in ofd_grant() turns the <4KB allocation into 0. I will provide a patch.

            This is subtracting the granted space from the available space returned to the MDS,

            This is actually only subtracting the space reserved for pre-creation for which we use the self export.

            but I think it should be adding the granted space back into os_bavail so that the MDS does not consider the grant space as "used". Otherwise, if the clients have reserved a lot of space on the OSTs they may not actually get to use it because the MDS will never allocate space there.

            I think there is nothing to add back, since only tot_dirty and tot_pending are taken into account here. Please note that tot_granted is not withdrawn anywhere.

            A secondary issue is that there is no coordination between the space granted to a specific client and the objects that the MDS allocates to that client, which would become more important as the free space is running out.

            I would agree if we were taking tot_granted out in statfs reply, however i don't think this is the case.

            There could be some kind of (IMHO complex) coordination here between the MDS and clients/OSTs, but I think it would be easier if we just got the grant shrinking code to work again, as there is no guarantee that (a) clients doing IO will have any grant at all, and (b) the clients have grant on the OSTs for which they have been asked to write on. Returning unused grant to the OSTs as the free space shrinks is the best way to ensure that there is some left for the clients actually doing IO.

            I am all for resurrecting grant shrinking, although i haven't had the opportunity to do it yet by lack of time. In fact, we might as well just disconnect (and therefore release grants) from OSTs when idle and when the replay list is empty. We could then reconnect on demand. IMHO, such a scheme would have other benefits: less clients to wait for during recovery and less PING requests.

            As for the original problem, it seems that precreate requests fails with ENOSPC on the OST:

            May 29 09:00:06 widow-oss11a4 kernel: [79146.403713] LustreError: 25344:0:(ofd_obd.c:1338:ofd_create()) routed1-OST016b: unable to precreate: rc = -28
            

            James, could you please dump the grant state on the OST by running "lctl get_param obdfilter..tot obdfilter..grant"?

            johann Johann Lombardi (Inactive) added a comment - - edited This is subtracting the granted space from the available space returned to the MDS, This is actually only subtracting the space reserved for pre-creation for which we use the self export. but I think it should be adding the granted space back into os_bavail so that the MDS does not consider the grant space as "used". Otherwise, if the clients have reserved a lot of space on the OSTs they may not actually get to use it because the MDS will never allocate space there. I think there is nothing to add back, since only tot_dirty and tot_pending are taken into account here. Please note that tot_granted is not withdrawn anywhere. A secondary issue is that there is no coordination between the space granted to a specific client and the objects that the MDS allocates to that client, which would become more important as the free space is running out. I would agree if we were taking tot_granted out in statfs reply, however i don't think this is the case. There could be some kind of (IMHO complex) coordination here between the MDS and clients/OSTs, but I think it would be easier if we just got the grant shrinking code to work again, as there is no guarantee that (a) clients doing IO will have any grant at all, and (b) the clients have grant on the OSTs for which they have been asked to write on. Returning unused grant to the OSTs as the free space shrinks is the best way to ensure that there is some left for the clients actually doing IO. I am all for resurrecting grant shrinking, although i haven't had the opportunity to do it yet by lack of time. In fact, we might as well just disconnect (and therefore release grants) from OSTs when idle and when the replay list is empty. We could then reconnect on demand. IMHO, such a scheme would have other benefits: less clients to wait for during recovery and less PING requests. As for the original problem, it seems that precreate requests fails with ENOSPC on the OST: May 29 09:00:06 widow-oss11a4 kernel: [79146.403713] LustreError: 25344:0:(ofd_obd.c:1338:ofd_create()) routed1-OST016b: unable to precreate: rc = -28 James, could you please dump the grant state on the OST by running "lctl get_param obdfilter. .tot obdfilter. .grant "?

            James, how many clients were mounting this filesystem? If each OST is 250GB, and each client gets a 32MB grant, that means 32 clients/GB of free space, so 8000 clients would essentially pin all of the available space on each client. I see something a bit strange in the code that might be causing a problem here:

            static int ofd_statfs(...)
            {
                    osfs->os_bavail -= min_t(obd_size, osfs->os_bavail,
                                             ((ofd->ofd_tot_dirty + ofd->ofd_tot_pending +
                                               osfs->os_bsize - 1) >> ofd->ofd_blockbits));
                    :
                    :
                    /* The QoS code on the MDS does not care about space reserved for
                     * precreate, so take it out. */
                    if (exp_connect_flags(exp) & OBD_CONNECT_MDS) {
                            struct filter_export_data *fed;
            
                            fed = &obd->obd_self_export->exp_filter_data;
                            osfs->os_bavail -= min_t(obd_size, osfs->os_bavail,
                                                     fed->fed_grant >> ofd->ofd_blockbits);
                    }
            

            This is subtracting the granted space from the available space returned to the MDS, but I think it should be adding the granted space back into os_bavail so that the MDS does not consider the grant space as "used". Otherwise, if the clients have reserved a lot of space on the OSTs they may not actually get to use it because the MDS will never allocate space there.

            A secondary issue is that there is no coordination between the space granted to a specific client and the objects that the MDS allocates to that client, which would become more important as the free space is running out. There could be some kind of (IMHO complex) coordination here between the MDS and clients/OSTs, but I think it would be easier if we just got the grant shrinking code to work again, as there is no guarantee that (a) clients doing IO will have any grant at all, and (b) the clients have grant on the OSTs for which they have been asked to write on. Returning unused grant to the OSTs as the free space shrinks is the best way to ensure that there is some left for the clients actually doing IO.

            adilger Andreas Dilger added a comment - James, how many clients were mounting this filesystem? If each OST is 250GB, and each client gets a 32MB grant, that means 32 clients/GB of free space, so 8000 clients would essentially pin all of the available space on each client. I see something a bit strange in the code that might be causing a problem here: static int ofd_statfs(...) { osfs->os_bavail -= min_t(obd_size, osfs->os_bavail, ((ofd->ofd_tot_dirty + ofd->ofd_tot_pending + osfs->os_bsize - 1) >> ofd->ofd_blockbits)); : : /* The QoS code on the MDS does not care about space reserved for * precreate, so take it out. */ if (exp_connect_flags(exp) & OBD_CONNECT_MDS) { struct filter_export_data *fed; fed = &obd->obd_self_export->exp_filter_data; osfs->os_bavail -= min_t(obd_size, osfs->os_bavail, fed->fed_grant >> ofd->ofd_blockbits); } This is subtracting the granted space from the available space returned to the MDS, but I think it should be adding the granted space back into os_bavail so that the MDS does not consider the grant space as "used". Otherwise, if the clients have reserved a lot of space on the OSTs they may not actually get to use it because the MDS will never allocate space there. A secondary issue is that there is no coordination between the space granted to a specific client and the objects that the MDS allocates to that client, which would become more important as the free space is running out. There could be some kind of (IMHO complex) coordination here between the MDS and clients/OSTs, but I think it would be easier if we just got the grant shrinking code to work again, as there is no guarantee that (a) clients doing IO will have any grant at all, and (b) the clients have grant on the OSTs for which they have been asked to write on. Returning unused grant to the OSTs as the free space shrinks is the best way to ensure that there is some left for the clients actually doing IO.

            The only OSS logs I have are like the one I posted here.

            simmonsja James A Simmons added a comment - The only OSS logs I have are like the one I posted here.
            bobijam Zhenyu Xu added a comment -

            James,

            Do you have OSS debug log? Want to check the reason why it reports ENOSPC while it seems there are plenty.

            bobijam Zhenyu Xu added a comment - James, Do you have OSS debug log? Want to check the reason why it reports ENOSPC while it seems there are plenty.

            I agree that osp_pre_update_status() should not be setting the status to 0 first. though I think that check to limit time we spent in osp_precreate_reserve() does not depend on the status, it's a hardlimit. and in the worst case when osp_precreate_ready_condition() missed -ENOSPC due to the race we still should leave osp_pre_update_status() up on expiration? notice the expiration point is not reset in the loop.

            bzzz Alex Zhuravlev added a comment - I agree that osp_pre_update_status() should not be setting the status to 0 first. though I think that check to limit time we spent in osp_precreate_reserve() does not depend on the status, it's a hardlimit. and in the worst case when osp_precreate_ready_condition() missed -ENOSPC due to the race we still should leave osp_pre_update_status() up on expiration? notice the expiration point is not reset in the loop.

            Andreas the lfs df -i output was pretty much what you seen below. The lfs df results were basically the same. In the last test shot we saw issues with 4 ost becoming very full but this was not the case this time.

            /lustre/routed1-OST0130_UUID 3872000 86598 3785402 2% /lustre/routed1[OST:304]
            /lustre/routed1-OST00ac_UUID 3872000 86584 3785416 2% /lustre/routed1[OST:172]
            /lustre/routed1-OST0047_UUID 3872000 86539 3785461 2% /lustre/routed1[OST:71]
            /lustre/routed1-OST01c2_UUID 3872000 85067 3786933 2% /lustre/routed1[OST:450]
            UUID Inodes IUsed IFree IUse% Mounted on

            Talking with Oleg he didn't believe it was due to grants. Each OST is 250GB in size. I also expected the real issue is happening on the OSS rather than the MDS but the admins only gathered a vmcore from the MDS.

            simmonsja James A Simmons added a comment - Andreas the lfs df -i output was pretty much what you seen below. The lfs df results were basically the same. In the last test shot we saw issues with 4 ost becoming very full but this was not the case this time. /lustre/routed1-OST0130_UUID 3872000 86598 3785402 2% /lustre/routed1 [OST:304] /lustre/routed1-OST00ac_UUID 3872000 86584 3785416 2% /lustre/routed1 [OST:172] /lustre/routed1-OST0047_UUID 3872000 86539 3785461 2% /lustre/routed1 [OST:71] /lustre/routed1-OST01c2_UUID 3872000 85067 3786933 2% /lustre/routed1 [OST:450] UUID Inodes IUsed IFree IUse% Mounted on Talking with Oleg he didn't believe it was due to grants. Each OST is 250GB in size. I also expected the real issue is happening on the OSS rather than the MDS but the admins only gathered a vmcore from the MDS.

            I uploaded the vmcore to ftp.whamcloud.com/uploads/LU-3421

            simmonsja James A Simmons added a comment - I uploaded the vmcore to ftp.whamcloud.com/uploads/ LU-3421

            James, I expect the stack trace you pointed out is not a primary cause of this problem. That looks just to be an MDS thread that is blocked waiting for a DLM lock that is held by another thread. My guess is that there is something wrong in the precreate code at ENOSPC time that is keeping the MDS threads blocked for too long a time, and this is caused by either really being out of space on the OSTs (either inodes or blocks is the same, since there is no point allocating objects on an OST with no space) or maybe false ENOSPC caused by a problem with the space grants or similar.

            It does point out that we have something wrong with the usage of the DLM locks, or similar, because we should never be blocked for such a long time holding a spinlock.

            adilger Andreas Dilger added a comment - James, I expect the stack trace you pointed out is not a primary cause of this problem. That looks just to be an MDS thread that is blocked waiting for a DLM lock that is held by another thread. My guess is that there is something wrong in the precreate code at ENOSPC time that is keeping the MDS threads blocked for too long a time, and this is caused by either really being out of space on the OSTs (either inodes or blocks is the same, since there is no point allocating objects on an OST with no space) or maybe false ENOSPC caused by a problem with the space grants or similar. It does point out that we have something wrong with the usage of the DLM locks, or similar, because we should never be blocked for such a long time holding a spinlock.

            People

              bobijam Zhenyu Xu
              simmonsja James A Simmons
              Votes:
              0 Vote for this issue
              Watchers:
              7 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: