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

Encountered a assertion for the ols_state being set to a impossible state

Details

    • Bug
    • Resolution: Fixed
    • Major
    • Lustre 2.5.0
    • Lustre 2.4.0, Lustre 2.4.1
    • Cray Lustre 2.4 clients running on SLES11 SP2.
    • 3
    • 8552

    Description

      During a test run using Lustre 2.4 one of our clients encountered this LBUG.

      [2013-05-29 18:39:47][c7-1c1s3n3]LustreError:16573:0:(osc_lock.c:1165:osc_lock_enqueue()) ASSERTION( ols->ols_state == OLS_NEW ) failed: Impossible state: 4
      [2013-05-29 18:39:47][c7-1c1s3n3]LustreError: 16573:0
      (osc_lock.c:1165:osc_lock_enqueue()) LBUG
      [2013-05-29 18:39:47][c7-1c1s3n3] [<ffffffff81006451>] try_stack_unwind+0x161/0x1a0
      [2013-05-29 18:39:47][c7-1c1s3n3] [<ffffffff81004ca9>] dump_trace+0x89/0x440
      [2013-05-29 18:39:47][c7-1c1s3n3] [<ffffffffa013a897>] libcfs_debug_dumpstack+0x57/0x80 [libcfs]
      [2013-05-29 18:39:47][c7-1c1s3n3] [<ffffffffa013ade7>] lbug_with_loc+0x47/0xc0 [libcfs]
      [2013-05-29 18:39:47][c7-1c1s3n3] [<ffffffffa0639f55>] osc_lock_enqueue+0x725/0x8b0 [osc]
      [2013-05-29 18:39:47][c7-1c1s3n3] [<ffffffffa032d4eb>] cl_enqueue_try+0xfb/0x320 [obdclass]
      [2013-05-29 18:39:47][c7-1c1s3n3] [<ffffffffa06ccded>] lov_lock_enqueue+0x1fd/0x880 [lov]
      [2013-05-29 18:39:47][c7-1c1s3n3] [<ffffffffa032d4eb>] cl_enqueue_try+0xfb/0x320 [obdclass]
      [2013-05-29 18:39:47][c7-1c1s3n3] [<ffffffffa032e3bf>] cl_enqueue_locked+0x7f/0x1f0 [obdclass]
      [2013-05-29 18:39:47][c7-1c1s3n3] [<ffffffffa032efbe>] cl_lock_request+0x7e/0x270 [obdclass]
      [2013-05-29 18:39:47][c7-1c1s3n3] [<ffffffffa0334274>] cl_io_lock+0x394/0x5c0 [obdclass]
      [2013-05-29 18:39:47][c7-1c1s3n3] [<ffffffffa033453a>] cl_io_loop+0x9a/0x1a0 [obdclass]
      [2013-05-29 18:39:47][c7-1c1s3n3] [<ffffffffa074b90f>] ll_file_io_generic+0x33f/0x5f0 [lustre]
      [2013-05-29 18:39:47][c7-1c1s3n3] [<ffffffffa074c08b>] ll_file_aio_read+0x23b/0x290 [lustre]
      [2013-05-29 18:39:47][c7-1c1s3n3] [<ffffffffa074d002>] ll_file_read+0x1f2/0x280 [lustre]
      [2013-05-29 18:39:47][c7-1c1s3n3] [<ffffffff81135548>] vfs_read+0xc8/0x180
      [2013-05-29 18:39:47][c7-1c1s3n3] [<ffffffff8113b799>] kernel_read+0x49/0x60
      [2013-05-29 18:39:47][c7-1c1s3n3] [<ffffffff8113b885>] prepare_binprm+0xd5/0x100
      [2013-05-29 18:39:47][c7-1c1s3n3] [<ffffffff8113c670>] do_execve_common+0x1c0/0x300
      [2013-05-29 18:39:47][c7-1c1s3n3] [<ffffffff8113c83f>] do_execve+0x3f/0x50
      [2013-05-29 18:39:47][c7-1c1s3n3] [<ffffffff8100ae1e>] sys_execve+0x4e/0x80
      [2013-05-29 18:39:47][c7-1c1s3n3] [<ffffffff81316a3c>] stub_execve+0x6c/0xc0
      [2013-05-29 18:39:47][c7-1c1s3n3] [<0000000020176437>] 0x20176437
      [2013-05-29 18:39:47][c7-1c1s3n3]Kernel panic - not syncing: LBUG

      Attachments

        1. test.sh
          0.2 kB
        2. write-eintr.c
          3 kB

        Issue Links

          Activity

            [LU-3433] Encountered a assertion for the ols_state being set to a impossible state
            vitaly_fertman Vitaly Fertman added a comment - http://review.whamcloud.com/6709

            Niu, James,

            We have a candidate patch for this from Xyratex that we're testing on our end. It appears to resolve the issue, and once I'm sure it's solid, we'll make sure it's pushed upstream.

            • Patrick
            paf Patrick Farrell (Inactive) added a comment - Niu, James, We have a candidate patch for this from Xyratex that we're testing on our end. It appears to resolve the issue, and once I'm sure it's solid, we'll make sure it's pushed upstream. Patrick

            James,

            It's the same reproducer, actually. This one - as long as it's in write mode and not truncate [it might work in truncate, I haven't tested] - should reproduce LU-3020 just fine. All I changed was to tweak the timings to hit this LBUG more reliably. Without the patch for LU-3020, LU-3020 was quite easy to hit.

            Niu,

            I'm not sure if I could reproduce it - I can try a bit later. Without LU-3020, the system call is not restarted, because it returns EINTR. That changes the timing and behavior profile immensely. I don't think this was 'caused' by LU-3020, rather it was revealed by it.

            Presumably, when a system call is restarted, sometimes we wind up in this nasty state. If EINTR is returned instead (LU-3020 removed), then the system call is not restarted. It's possible we only get to this state through restarting, or it's possible that we only get there through interrupting the system call at a very specific time, regardless of the restart behavior.

            • Patrick
            paf Patrick Farrell (Inactive) added a comment - - edited James, It's the same reproducer, actually. This one - as long as it's in write mode and not truncate [it might work in truncate, I haven't tested] - should reproduce LU-3020 just fine. All I changed was to tweak the timings to hit this LBUG more reliably. Without the patch for LU-3020 , LU-3020 was quite easy to hit. Niu, I'm not sure if I could reproduce it - I can try a bit later. Without LU-3020 , the system call is not restarted, because it returns EINTR. That changes the timing and behavior profile immensely. I don't think this was 'caused' by LU-3020 , rather it was revealed by it. Presumably, when a system call is restarted, sometimes we wind up in this nasty state. If EINTR is returned instead ( LU-3020 removed), then the system call is not restarted. It's possible we only get to this state through restarting, or it's possible that we only get there through interrupting the system call at a very specific time, regardless of the restart behavior. Patrick
            simmonsja James A Simmons added a comment - - edited

            Do you have a reproducer for the LU-3020 as well. It would be nice to make both conditions work.

            simmonsja James A Simmons added a comment - - edited Do you have a reproducer for the LU-3020 as well. It would be nice to make both conditions work.

            This looks like a regression introduced by LU-3020, when I removed the fix of LU-3020, the LBUG can't be reproduced anymore, but I don't know the exact reason yet. Patrick, can you reproduce it after removing the fix of LU-3020?

            niu Niu Yawei (Inactive) added a comment - This looks like a regression introduced by LU-3020 , when I removed the fix of LU-3020 , the LBUG can't be reproduced anymore, but I don't know the exact reason yet. Patrick, can you reproduce it after removing the fix of LU-3020 ?

            Cray has recently noticed this LBUG while testing for a possible different source for the EINTR reported in LU-3020. A reproducer very similar to that one can consistently produce this bug during writes or truncates. I have not tested reads, but I'm inclined to believe it would reproduce the bug for reads as well.

            I'll attach the reproducer for this bug for write/truncate.

            Briefly, the reproducer spawns a child thread, then the parent sets up a signal handler for SIGINT with SA_RESTART set, and loops the IO operation in question (It's set up for write or truncate, and could be modified to use read), while the child spams SIGINT at the parent.

            This bug is much easier to reproduce with +trace debugging enabled. Without, it usually requires looping the reproducer, sometimes for several minutes. The provided shell script loops the reproducer.

            paf Patrick Farrell (Inactive) added a comment - - edited Cray has recently noticed this LBUG while testing for a possible different source for the EINTR reported in LU-3020 . A reproducer very similar to that one can consistently produce this bug during writes or truncates. I have not tested reads, but I'm inclined to believe it would reproduce the bug for reads as well. I'll attach the reproducer for this bug for write/truncate. Briefly, the reproducer spawns a child thread, then the parent sets up a signal handler for SIGINT with SA_RESTART set, and loops the IO operation in question (It's set up for write or truncate, and could be modified to use read), while the child spams SIGINT at the parent. This bug is much easier to reproduce with +trace debugging enabled. Without, it usually requires looping the reproducer, sometimes for several minutes. The provided shell script loops the reproducer.
            pjones Peter Jones added a comment -

            Niu

            Could you please look into this one?

            Thanks

            Peter

            pjones Peter Jones added a comment - Niu Could you please look into this one? Thanks Peter

            People

              niu Niu Yawei (Inactive)
              simmonsja James A Simmons
              Votes:
              0 Vote for this issue
              Watchers:
              16 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: