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

statahead: stat fails after a dir migration

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Unresolved
    • Icon: Medium Medium
    • None
    • None
    • None
    • 3
    • 9223372036854775807

      Reproducer:

      lctl set_param fail_loc=0x1801; sleep 1
      lfs migrate -m 1 testdir; stat testdir/testfile{1..10} > /dev/null
      lctl set_param fail_val=0
      lfs migrate -m 1 testdir/
      stat testdir/testfile11 tat: cannot statx 'testdir/testfile11': Input/output error
      

      dmesg:

      [54784.659028] LustreError: 748790:0:(mdt_reint.c:2644:mdt_reint_migrate()) lustre-MDT0000: migrate [0x240000402:0xef3:0x0]/testfile30 failed: rc = -5
      [54785.252797] LustreError: 768539:0:(lcommon_cl.c:187:cl_file_inode_init()) lustre: failed to initialize cl_object [0x240000402:0xf1d:0x0]: rc = -5
      [54785.253104] LustreError: 768539:0:(llite_lib.c:3890:ll_prep_inode()) lustre: new_inode - fatal error: rc = -5
      

      debug_log:

      00020000:00000002:6.0:1786534846.750452:0:768539:0:(lov_object.c:167:lov_init_sub()) ....osc@000000008f32bbb7id: 0x2c0000401:557 idx: 1 gen: 0 kms_valid: 1 kms 0 rc: 0 force_sync: 0 min_xid: 0 size: 0 mtime: 178
      6534840 atime: 1786534840 ctime: 1786534840 blocks: 0
      00020000:00000002:6.0:1786534846.750452:0:768539:0:(lov_object.c:167:lov_init_sub()) } header@0000000006a737de
      00020000:00000002:6.0:1786534846.750452:0:768539:0:(lov_object.c:167:lov_init_sub()) 
      00000002:00000001:2.0:1786534846.750452:0:669652:0:(mdc_locks.c:778:mdc_finish_enqueue()) Process entered
      00010000:00000001:2.0:1786534846.750452:0:669652:0:(ldlm_lock.c:612:__ldlm_handle2lock()) Process entered
      00000020:00000001:2.0:1786534846.750452:0:669652:0:(lustre_handles.c:129:class_handle2object()) Process entered
      00020000:00000002:6.0:1786534846.750453:0:768539:0:(lov_object.c:167:lov_init_sub()) } header@000000005fbcd63f
      00020000:00000002:6.0:1786534846.750453:0:768539:0:(lov_object.c:167:lov_init_sub()) owned.
      00020000:00000002:6.0:1786534846.750453:0:768539:0:(lov_object.c:168:lov_init_sub()) header@000000007550b2db[0x100, 1, [0x240000402:0xf1d:0x0] hash]
      00010000:00000001:3.0:1786534846.750453:0:669636:0:(ldlm_lock.c:2502:ldlm_lock_cancel()) Process entered
      00000004:00000001:3.0:1786534846.750453:0:669636:0:(mdt_handler.c:3882:mdt_blocking_ast()) Process entered
      00000004:00000001:3.0:1786534846.750453:0:669636:0:(mdt_handler.c:3884:mdt_blocking_ast()) Process leaving (rc=0 : 0 : 0)
      00000020:00000040:2.0:1786534846.750453:0:669652:0:(lustre_handles.c:147:class_handle2object()) GET ldlm ffff8c2b3b307400 refcount=3
      00000020:00000001:2.0:1786534846.750453:0:669652:0:(lustre_handles.c:154:class_handle2object()) Process leaving (rc=18446616716037354496 : -127357672197120 : ffff8c2b3b307400)
      00020000:00000002:6.0:1786534846.750454:0:768539:0:(lov_object.c:168:lov_init_sub()) try to own.
      00020000:00000001:6.0:1786534846.750454:0:768539:0:(lov_object.c:259:lov_init_raid0()) Process leaving (rc=18446744073709551611 : -5 : fffffffffffffffb)
      00010000:00000001:3.0:1786534846.750454:0:669636:0:(ldlm_lock.c:410:ldlm_lock_destroy_nolock()) Process entered
      00010000:00000001:3.0:1786534846.750454:0:669636:0:(ldlm_lock.c:354:ldlm_lock_destroy_internal()) Process entered
      00010000:00000001:3.0:1786534846.750454:0:669636:0:(ldlm_lock.c:261:ldlm_lock_remove_from_lru_check()) Process entered
      00010000:00000001:2.0:1786534846.750454:0:669652:0:(ldlm_lock.c:634:__ldlm_handle2lock()) Process leaving (rc=18446616716037354496 : -127357672197120 : ffff8c2b3b307400)
      00010000:00000001:2.0:1786534846.750454:0:669652:0:(ldlm_lock.c:612:__ldlm_handle2lock()) Process entered
      00000020:00000001:2.0:1786534846.750454:0:669652:0:(lustre_handles.c:129:class_handle2object()) Process entered
      00020000:00000001:6.0:1786534846.750455:0:768539:0:(lov_object.c:815:lov_init_composite()) Process leaving
      00020000:00000001:6.0:1786534846.750455:0:768539:0:(lov_object.c:1433:lov_object_init()) Process leaving via out_lsm (rc=18446744073709551611 : -5 : 0xfffffffffffffffb)
      00010000:00000001:3.0:1786534846.750455:0:669636:0:(ldlm_lock.c:264:ldlm_lock_remove_from_lru_check()) Process leaving (rc=0 : 0 : 0)
      00000020:00000040:3.0:1786534846.750455:0:669636:0:(lustre_handles.c:107:class_handle_unhash_nolock()) removing object ffff8c2b2092e600 with handle 0xa0069a83612a57b9 from hash
      00000020:00000040:2.0:1786534846.750455:0:669652:0:(lustre_handles.c:147:class_handle2object()) GET ldlm ffff8c2b3b307400 refcount=4
      00000020:00000001:2.0:1786534846.750455:0:669652:0:(lustre_handles.c:154:class_handle2object()) Process leaving (rc=18446616716037354496 : -127357672197120 : ffff8c2b3b307400)
      00020000:00000001:6.0:1786534846.750456:0:768539:0:(lov_object.c:1438:lov_object_init()) Process leaving (rc=18446744073709551611 : -5 : fffffffffffffffb)
      
      ...
      00000020:00000001:6.0:1786534846.750470:0:768539:0:(lu_object.c:936:lu_object_find_at()) Process leaving (rc=18446744073709551611 : -5 : fffffffffffffffb)
      00000080:00020000:6.0:1786534846.750470:0:768539:0:(lcommon_cl.c:187:cl_file_inode_init()) lustre: failed to initialize cl_object [0x240000402:0xf1d:0x0]: rc = -5
      ...
      00000080:00000001:6.0:1786534846.750767:0:768539:0:(llite_lib.c:3376:ll_read_inode2()) Process leaving (rc=18446744073709551611 : -5 : fffffffffffffffb)
      ..
      00000080:00000001:6.0:1786534846.750931:0:768539:0:(llite_lib.c:3891:ll_prep_inode()) Process leaving via out (rc=18446744073709551611 : -5 : 0xfffffffffffffffb)
      

      ll_prep_inode() seems to fail because osc object are still used by the inode referenced by the statahead thread.

      This bug seems to be hit on racer test.

            qian_wc Qian Yingjin
            eaujames Etienne Aujames
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

              Created:
              Updated: