Skip to contentSkip to conversation

New: ext3/4 with synchronous writes gets wedged by Postfix

Bug 13232 [email protected] 4 participants 25 messages May 5, 2009 – Jun 7, 2009 VFS

lore
Share & tools
lore

[email protected]

author
#0 lore raw

http://bugzilla.kernel.org/show_bug.cgi?id=13232

Summary: ext3/4 with synchronous writes gets wedged by Postfix
Product: File System
Version: 2.5
Kernel Version: 2.6.29.2
Platform: All
OS/Version: Linux
Tree: Mainline
Status: NEW
Severity: normal
Priority: P1
Component: ext3
AssignedTo: [email protected]
ReportedBy: [email protected]
Regression: Yes

Latest working kernel version: 2.6.28.9
Earliest failing kernel version: 2.6.29
Distribution: Ubuntu 8.04 LTS
Hardware Environment: Intel 875p chipset (ICH5), P4 with HT Software Environment: Postfix 2.5.1-2ubuntu1.2

Problem Description:

With its queue directory on an ext3 or journalled ext4 file system, mounted with the 'sync' option (or with the 'S' attribute on the individual queue directories, which is a config option for the Ubuntu package), sending more than a few messages in quick succession through Postfix causes Postfix and any other process attempting to modify the file system afterwards (e.g. by updating the atime when listing a directory) to hang in uninterruptible sleep. sync(1) will also hang afterwards. If the FS is mounted noatime, it is still possible to read from it, although trying to list the affected queue directories still causes ls to hang (the list of affected directories seems to vary, but may include at least "active" and "maildrop").

This happens whether the filesystem is on a hard disk or a RAM disk (/dev/ramX, not tmpfs). Enabling or disabling barriers, or changing the journalling mode doesn't help.

Ext2 seems to be unaffected, as does non-journalled ext4. XFS, Reiser and JFS are also fine. The hang doesn't occur if the queue directories have the 'D' attribute (and a non-sync mount) instead of 'S'.

Nothing appears in dmesg at the time of the hang, but here's the output from SysRq-W afterwards (ext3 FS, kernel 2.6.29.2, non-SMP, PREEMPT_NONE):

SysRq : Show Blocked State
task PC stack pid father
kjournald D c01384df 0 2525 2
cfcb5f0c 00000082 de27d500 c01384df cfcb5ef4 c02cb5c0 00000001 de32ca00 de324814 dd037ebc de324814 de324934 dd037ebc cfcb5f5c cfcb5f90 c01bd4bb 00000046 c0424110 de324a0c de324814 de324800 00000000 00000002 dd037e80

Call Trace:
 [<c01384df>] ? trace_hardirqs_on+0xb/0xd
 [<c01bd4bb>] journal_commit_transaction+0xea/0xeaf
 [<c02c534a>] ? _spin_unlock_irqrestore+0x38/0x3f
 [<c0138489>] ? trace_hardirqs_on_caller+0x145/0x190
 [<c012b6ee>] ? autoremove_wake_function+0x0/0x38
 [<c0122a25>] ? del_timer+0x50/0x59
 [<c01c0c75>] kjournald+0xad/0x1bb
 [<c012b6ee>] ? autoremove_wake_function+0x0/0x38
 [<c01c0bc8>] ? kjournald+0x0/0x1bb
 [<c012b442>] kthread+0x37/0x59
 [<c012b40b>] ? kthread+0x0/0x59
 [<c0103667>] kernel_thread_helper+0x7/0x10

pickup D c01384df 0 2597 2594
cfaa9e5c 00000086 df9faa80 c01384df cfaa9e44 00000282 cfaa9e74 de32ca00 cfaa9e5c c012b8b7 00000002 de324800 0000014f cfaa9e74 cfaa9e94 c01c0539 00000000 de3248c8 de324910 de324814 00000000 df9faa80 c012b6ee de3248e4

Call Trace:
 [<c01384df>] ? trace_hardirqs_on+0xb/0xd
 [<c012b8b7>] ? prepare_to_wait+0x42/0x4a
 [<c01c0539>] log_wait_commit+0x90/0xf7
 [<c012b6ee>] ? autoremove_wake_function+0x0/0x38
 [<c01bba9d>] journal_stop+0x1c8/0x288
 [<c01b4236>] __ext3_journal_stop+0x1c/0x38
 [<c01aeb96>] ext3_delete_inode+0x90/0xc2
 [<c01aeb06>] ? ext3_delete_inode+0x0/0xc2
 [<c017ab82>] generic_delete_inode+0x72/0x100
 [<c02c4ee1>] ? _spin_lock+0x3a/0x40
 [<c017ad4c>] generic_drop_inode+0x13c/0x1da
 [<c01d4068>] ? _atomic_dec_and_lock+0x10/0x38
 [<c017a4e7>] iput+0x47/0x4e
 [<c0173db0>] do_unlinkat+0xc1/0x137
 [<c0102f87>] ? sysenter_exit+0xf/0x18
 [<c0138489>] ? trace_hardirqs_on_caller+0x145/0x190
 [<c0173e36>] sys_unlink+0x10/0x12
 [<c0102f55>] sysenter_do_call+0x12/0x35

qmgr D c01384df 0 2598 2594
cfe23e60 00000082 df9fa200 c01384df cfe23e48 c02cb5c0 cfe23e78 de32cf00 cfe23e60 c012b8b7 00000002 de324800 0000014f cfe23e78 cfe23e98 c01c0539 00000000 de3248c8 de324910 de324814 00000000 df9fa200 c012b6ee cfaa9e80

Call Trace:
 [<c01384df>] ? trace_hardirqs_on+0xb/0xd
 [<c012b8b7>] ? prepare_to_wait+0x42/0x4a
 [<c01c0539>] log_wait_commit+0x90/0xf7
 [<c012b6ee>] ? autoremove_wake_function+0x0/0x38
 [<c01bba9d>] journal_stop+0x1c8/0x288
 [<c01ac11e>] ? ext3_mark_iloc_dirty+0x1d8/0x34b
 [<c01b4236>] __ext3_journal_stop+0x1c/0x38
 [<c01b309d>] ext3_unlink+0x70/0x157
 [<c0172344>] ? vfs_unlink+0x45/0xb0
 [<c0172358>] vfs_unlink+0x59/0xb0
 [<c0173e17>] do_unlinkat+0x128/0x137
 [<c0102f87>] ? sysenter_exit+0xf/0x18
 [<c0138489>] ? trace_hardirqs_on_caller+0x145/0x190
 [<c0173e36>] sys_unlink+0x10/0x12
 [<c0102f55>] sysenter_do_call+0x12/0x35

local D c01384df 0 2654 2594
de369c74 00000096 df9f8880 c01384df de369c5c 00000286 00000000 de183b80 de324814 de324800 de324814 dd037e80 de324800 de324880 de369cc4 c01bc306 c0138489 00000246 00000046 00000001 de324a0c de324814 de324814 df59c060

Call Trace:
 [<c01384df>] ? trace_hardirqs_on+0xb/0xd
 [<c01bc306>] start_this_handle+0x1c2/0x361
 [<c0138489>] ? trace_hardirqs_on_caller+0x145/0x190
 [<c012b6ee>] ? autoremove_wake_function+0x0/0x38
 [<c01bc54a>] journal_start+0xa5/0x100
 [<c01b43ac>] ext3_journal_start_sb+0x48/0x4d
 [<c01aec4c>] ext3_write_begin+0x84/0x1c6
 [<c0139fe2>] ? __lock_acquire+0x32b/0xa21
 [<c014749e>] generic_file_buffered_write+0xe1/0x292
 [<c0147a94>] __generic_file_aio_write_nolock+0x25c/0x4ab
 [<c0138489>] ? trace_hardirqs_on_caller+0x145/0x190
 [<c0147f63>] generic_file_aio_write+0x66/0xda
 [<c0138f6b>] ? validate_chain+0x3f5/0x1141
 [<c01aad03>] ext3_file_write+0x27/0xa8
 [<c016a972>] do_sync_write+0xcc/0x102
 [<c012b6ee>] ? autoremove_wake_function+0x0/0x38
 [<c016b16d>] vfs_write+0x8b/0x11f
 [<c0102f87>] ? sysenter_exit+0xf/0x18
 [<c016a8a6>] ? do_sync_write+0x0/0x102
 [<c016b577>] sys_write+0x3d/0x64
 [<c0102f55>] sysenter_do_call+0x12/0x35

postdrop D c01384df 0 2664 2663
cfcbfd6c 00000086 dd13f700 c01384df cfcbfd54 c02cb5c0 00000001 deedc780 c03a1690 c1402348 c03a1690 cfcbfd7c c1402348 cfcbfd90 cfcbfd9c c017a55b dd758c48 00000007 00000000 dd13f700 c012b726 c1402364 c1402364 00152b13

Call Trace:
 [<c01384df>] ? trace_hardirqs_on+0xb/0xd
 [<c017a55b>] __wait_on_freeing_inode+0x6d/0x88
 [<c012b726>] ? wake_bit_function+0x0/0x47
 [<c017a5b5>] find_inode_fast+0x3f/0x4a
 [<c017ba05>] insert_inode_locked+0x50/0xeb
 [<c01ab90b>] ext3_new_inode+0x738/0x88f
 [<c01bc550>] ? journal_start+0xab/0x100
 [<c01b259a>] ext3_create+0x59/0xbf
 [<c01722c4>] vfs_create+0x75/0xb0
 [<c02c4dda>] ? _spin_unlock+0x1d/0x20
 [<c01b2541>] ? ext3_create+0x0/0xbf
 [<c0174bc3>] do_filp_open+0x644/0x713
 [<c02c4dda>] ? _spin_unlock+0x1d/0x20
 [<c01692ce>] do_sys_open+0x45/0xce
 [<c0102f87>] ? sysenter_exit+0xf/0x18
 [<c0138489>] ? trace_hardirqs_on_caller+0x145/0x190
 [<c01693a3>] sys_open+0x23/0x2b
 [<c0102f55>] sysenter_do_call+0x12/0x35
Sched Debug Version: v0.08, 2.6.29.2-test #1
now at 166155.025991 msecs
  .sysctl_sched_latency                    : 20.000000
  .sysctl_sched_min_granularity            : 4.000000
  .sysctl_sched_wakeup_granularity         : 5.000000
  .sysctl_sched_child_runs_first           : 0.000001
  .sysctl_sched_features                   : 24191

cpu#0, 2798.181 MHz

  .nr_running                    : 2
  .load                          : 2048
  .nr_switches                   : 284843
  .nr_load_updates               : 6497
  .nr_uninterruptible            : 5
  .jiffies                       : 4294953911
  .next_balance                  : 0.000000
  .curr->pid                     : 2466
  .clock                         : 166154.370058
  .cpu_load[0]                   : 0
  .cpu_load[1]                   : 4
  .cpu_load[2]                   : 76
  .cpu_load[3]                   : 160
  .cpu_load[4]                   : 196

cfs_rq[0]:

  .exec_clock                    : 0.000000
  .MIN_vruntime                  : 24407.116340
  .min_vruntime                  : 24407.114218
  .max_vruntime                  : 24407.116340
  .spread                        : 0.000000
  .spread0                       : 0.000000
  .nr_running                    : 2
  .load                          : 2048
  .nr_spread_over                : 0

rt_rq[0]:

  .rt_nr_running                 : 0
  .rt_throttled                  : 0
  .rt_time                       : 0.000000
  .rt_runtime                    : 950.000000

runnable tasks:
task PID tree-key switches prio exec-runtime
sum-exec sum-sleep
----------------------------------------------------------------------------------------------------------

            Xorg  2163     24407.116340     28791   120               0        
      0               0.000000               0.000000               0.000000
R           bash  2466     24387.418829       274   120               0        
      0               0.000000               0.000000               0.000000

Steps to reproduce:

# mount -o remount,sync /var
  (or wherever queue_directory points to in the Postfix config)
# while true; do sendmail testaddr@localhost </dev/null; done

--- Comment #1 from Andrew Morton <[email protected]> 2009-05-05 21:58:17 --- (switched to email. Please respond via emailed reply-to-all, not via the bugzilla web interface).

Quoted 18 lines · On Sun, 3 May 2009 19:48:21 GMT [email protected] wrote:

http://bugzilla.kernel.org/show_bug.cgi?id=13232

Summary: ext3/4 with synchronous writes gets wedged by Postfix
Product: File System
Version: 2.5
Kernel Version: 2.6.29.2
Platform: All
OS/Version: Linux
Tree: Mainline
Status: NEW
Severity: normal
Priority: P1
Component: ext3
AssignedTo: [email protected]
ReportedBy: [email protected]
Regression: Yes

Quoted 2 lines

Latest working kernel version: 2.6.28.9
Earliest failing kernel version: 2.6.29

A very very bad regression.

Quoted 38 lines

Distribution: Ubuntu 8.04 LTS
Hardware Environment: Intel 875p chipset (ICH5), P4 with HT Software Environment: Postfix 2.5.1-2ubuntu1.2

Problem Description:

With its queue directory on an ext3 or journalled ext4 file system, mounted with the 'sync' option (or with the 'S' attribute on the individual queue directories, which is a config option for the Ubuntu package), sending more than a few messages in quick succession through Postfix causes Postfix and any other process attempting to modify the file system afterwards (e.g. by updating the atime when listing a directory) to hang in uninterruptible sleep. sync(1) will also hang afterwards. If the FS is mounted noatime, it is still possible to read from it, although trying to list the affected queue directories still causes ls to hang (the list of affected directories seems to vary, but may include at least "active" and "maildrop").

This happens whether the filesystem is on a hard disk or a RAM disk (/dev/ramX, not tmpfs). Enabling or disabling barriers, or changing the journalling mode doesn't help.

Ext2 seems to be unaffected, as does non-journalled ext4. XFS, Reiser and JFS are also fine. The hang doesn't occur if the queue directories have the 'D' attribute (and a non-sync mount) instead of 'S'.

Nothing appears in dmesg at the time of the hang, but here's the output from SysRq-W afterwards (ext3 FS, kernel 2.6.29.2, non-SMP, PREEMPT_NONE):

SysRq : Show Blocked State
task PC stack pid father
kjournald D c01384df 0 2525 2
cfcb5f0c 00000082 de27d500 c01384df cfcb5ef4 c02cb5c0 00000001 de32ca00 de324814 dd037ebc de324814 de324934 dd037ebc cfcb5f5c cfcb5f90 c01bd4bb 00000046 c0424110 de324a0c de324814 de324800 00000000 00000002 dd037e80

Quoted 13 lines
Call Trace:
 [<c01384df>] ? trace_hardirqs_on+0xb/0xd
 [<c01bd4bb>] journal_commit_transaction+0xea/0xeaf
 [<c02c534a>] ? _spin_unlock_irqrestore+0x38/0x3f
 [<c0138489>] ? trace_hardirqs_on_caller+0x145/0x190
 [<c012b6ee>] ? autoremove_wake_function+0x0/0x38
 [<c0122a25>] ? del_timer+0x50/0x59
 [<c01c0c75>] kjournald+0xad/0x1bb
 [<c012b6ee>] ? autoremove_wake_function+0x0/0x38
 [<c01c0bc8>] ? kjournald+0x0/0x1bb
 [<c012b442>] kthread+0x37/0x59
 [<c012b40b>] ? kthread+0x0/0x59
 [<c0103667>] kernel_thread_helper+0x7/0x10

I assume this is

    while (commit_transaction->t_updates) {
        DEFINE_WAIT(wait);

        prepare_to_wait(&journal->j_wait_updates, &wait,
                    TASK_UNINTERRUPTIBLE);
        if (commit_transaction->t_updates) {
            spin_unlock(&commit_transaction->t_handle_lock);
            spin_unlock(&journal->j_state_lock);
            schedule();

I'm wondering about

: commit e219cca082f52e7dfea41f3be264b7b5eb204227
: Author: Theodore Ts'o <[email protected]>
: AuthorDate: Thu Nov 6 22:37:59 2008 -0500
: Commit: Theodore Ts'o <[email protected]>
: CommitDate: Thu Nov 6 22:37:59 2008 -0500
:
: jbd: don't give up looking for space so easily in __log_wait_for_space

but that patch was present in 2.6.28.

Quoted 150 lines

pickup D c01384df 0 2597 2594
cfaa9e5c 00000086 df9faa80 c01384df cfaa9e44 00000282 cfaa9e74 de32ca00 cfaa9e5c c012b8b7 00000002 de324800 0000014f cfaa9e74 cfaa9e94 c01c0539 00000000 de3248c8 de324910 de324814 00000000 df9faa80 c012b6ee de3248e4

Call Trace:
 [<c01384df>] ? trace_hardirqs_on+0xb/0xd
 [<c012b8b7>] ? prepare_to_wait+0x42/0x4a
 [<c01c0539>] log_wait_commit+0x90/0xf7
 [<c012b6ee>] ? autoremove_wake_function+0x0/0x38
 [<c01bba9d>] journal_stop+0x1c8/0x288
 [<c01b4236>] __ext3_journal_stop+0x1c/0x38
 [<c01aeb96>] ext3_delete_inode+0x90/0xc2
 [<c01aeb06>] ? ext3_delete_inode+0x0/0xc2
 [<c017ab82>] generic_delete_inode+0x72/0x100
 [<c02c4ee1>] ? _spin_lock+0x3a/0x40
 [<c017ad4c>] generic_drop_inode+0x13c/0x1da
 [<c01d4068>] ? _atomic_dec_and_lock+0x10/0x38
 [<c017a4e7>] iput+0x47/0x4e
 [<c0173db0>] do_unlinkat+0xc1/0x137
 [<c0102f87>] ? sysenter_exit+0xf/0x18
 [<c0138489>] ? trace_hardirqs_on_caller+0x145/0x190
 [<c0173e36>] sys_unlink+0x10/0x12
 [<c0102f55>] sysenter_do_call+0x12/0x35

qmgr D c01384df 0 2598 2594
cfe23e60 00000082 df9fa200 c01384df cfe23e48 c02cb5c0 cfe23e78 de32cf00 cfe23e60 c012b8b7 00000002 de324800 0000014f cfe23e78 cfe23e98 c01c0539 00000000 de3248c8 de324910 de324814 00000000 df9fa200 c012b6ee cfaa9e80

Call Trace:
 [<c01384df>] ? trace_hardirqs_on+0xb/0xd
 [<c012b8b7>] ? prepare_to_wait+0x42/0x4a
 [<c01c0539>] log_wait_commit+0x90/0xf7
 [<c012b6ee>] ? autoremove_wake_function+0x0/0x38
 [<c01bba9d>] journal_stop+0x1c8/0x288
 [<c01ac11e>] ? ext3_mark_iloc_dirty+0x1d8/0x34b
 [<c01b4236>] __ext3_journal_stop+0x1c/0x38
 [<c01b309d>] ext3_unlink+0x70/0x157
 [<c0172344>] ? vfs_unlink+0x45/0xb0
 [<c0172358>] vfs_unlink+0x59/0xb0
 [<c0173e17>] do_unlinkat+0x128/0x137
 [<c0102f87>] ? sysenter_exit+0xf/0x18
 [<c0138489>] ? trace_hardirqs_on_caller+0x145/0x190
 [<c0173e36>] sys_unlink+0x10/0x12
 [<c0102f55>] sysenter_do_call+0x12/0x35

local D c01384df 0 2654 2594
de369c74 00000096 df9f8880 c01384df de369c5c 00000286 00000000 de183b80 de324814 de324800 de324814 dd037e80 de324800 de324880 de369cc4 c01bc306 c0138489 00000246 00000046 00000001 de324a0c de324814 de324814 df59c060

Call Trace:
 [<c01384df>] ? trace_hardirqs_on+0xb/0xd
 [<c01bc306>] start_this_handle+0x1c2/0x361
 [<c0138489>] ? trace_hardirqs_on_caller+0x145/0x190
 [<c012b6ee>] ? autoremove_wake_function+0x0/0x38
 [<c01bc54a>] journal_start+0xa5/0x100
 [<c01b43ac>] ext3_journal_start_sb+0x48/0x4d
 [<c01aec4c>] ext3_write_begin+0x84/0x1c6
 [<c0139fe2>] ? __lock_acquire+0x32b/0xa21
 [<c014749e>] generic_file_buffered_write+0xe1/0x292
 [<c0147a94>] __generic_file_aio_write_nolock+0x25c/0x4ab
 [<c0138489>] ? trace_hardirqs_on_caller+0x145/0x190
 [<c0147f63>] generic_file_aio_write+0x66/0xda
 [<c0138f6b>] ? validate_chain+0x3f5/0x1141
 [<c01aad03>] ext3_file_write+0x27/0xa8
 [<c016a972>] do_sync_write+0xcc/0x102
 [<c012b6ee>] ? autoremove_wake_function+0x0/0x38
 [<c016b16d>] vfs_write+0x8b/0x11f
 [<c0102f87>] ? sysenter_exit+0xf/0x18
 [<c016a8a6>] ? do_sync_write+0x0/0x102
 [<c016b577>] sys_write+0x3d/0x64
 [<c0102f55>] sysenter_do_call+0x12/0x35

postdrop D c01384df 0 2664 2663
cfcbfd6c 00000086 dd13f700 c01384df cfcbfd54 c02cb5c0 00000001 deedc780 c03a1690 c1402348 c03a1690 cfcbfd7c c1402348 cfcbfd90 cfcbfd9c c017a55b dd758c48 00000007 00000000 dd13f700 c012b726 c1402364 c1402364 00152b13

Call Trace:
 [<c01384df>] ? trace_hardirqs_on+0xb/0xd
 [<c017a55b>] __wait_on_freeing_inode+0x6d/0x88
 [<c012b726>] ? wake_bit_function+0x0/0x47
 [<c017a5b5>] find_inode_fast+0x3f/0x4a
 [<c017ba05>] insert_inode_locked+0x50/0xeb
 [<c01ab90b>] ext3_new_inode+0x738/0x88f
 [<c01bc550>] ? journal_start+0xab/0x100
 [<c01b259a>] ext3_create+0x59/0xbf
 [<c01722c4>] vfs_create+0x75/0xb0
 [<c02c4dda>] ? _spin_unlock+0x1d/0x20
 [<c01b2541>] ? ext3_create+0x0/0xbf
 [<c0174bc3>] do_filp_open+0x644/0x713
 [<c02c4dda>] ? _spin_unlock+0x1d/0x20
 [<c01692ce>] do_sys_open+0x45/0xce
 [<c0102f87>] ? sysenter_exit+0xf/0x18
 [<c0138489>] ? trace_hardirqs_on_caller+0x145/0x190
 [<c01693a3>] sys_open+0x23/0x2b
 [<c0102f55>] sysenter_do_call+0x12/0x35
Sched Debug Version: v0.08, 2.6.29.2-test #1
now at 166155.025991 msecs
  .sysctl_sched_latency                    : 20.000000
  .sysctl_sched_min_granularity            : 4.000000
  .sysctl_sched_wakeup_granularity         : 5.000000
  .sysctl_sched_child_runs_first           : 0.000001
  .sysctl_sched_features                   : 24191

cpu#0, 2798.181 MHz

  .nr_running                    : 2
  .load                          : 2048
  .nr_switches                   : 284843
  .nr_load_updates               : 6497
  .nr_uninterruptible            : 5
  .jiffies                       : 4294953911
  .next_balance                  : 0.000000
  .curr->pid                     : 2466
  .clock                         : 166154.370058
  .cpu_load[0]                   : 0
  .cpu_load[1]                   : 4
  .cpu_load[2]                   : 76
  .cpu_load[3]                   : 160
  .cpu_load[4]                   : 196

cfs_rq[0]:

  .exec_clock                    : 0.000000
  .MIN_vruntime                  : 24407.116340
  .min_vruntime                  : 24407.114218
  .max_vruntime                  : 24407.116340
  .spread                        : 0.000000
  .spread0                       : 0.000000
  .nr_running                    : 2
  .load                          : 2048
  .nr_spread_over                : 0

rt_rq[0]:

  .rt_nr_running                 : 0
  .rt_throttled                  : 0
  .rt_time                       : 0.000000
  .rt_runtime                    : 950.000000

runnable tasks:
task PID tree-key switches prio exec-runtime
sum-exec sum-sleep
----------------------------------------------------------------------------------------------------------

            Xorg  2163     24407.116340     28791   120               0        
      0               0.000000               0.000000               0.000000
R           bash  2466     24387.418829       274   120               0        
      0               0.000000               0.000000               0.000000

Steps to reproduce:

# mount -o remount,sync /var
  (or wherever queue_directory points to in the Postfix config)
# while true; do sendmail testaddr@localhost </dev/null; done
Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
author
#1 lore raw

[Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

http://bugzilla.kernel.org/show_bug.cgi?id=13232

Rafael J. Wysocki <[email protected]> changed:

What |Removed |Added
----------------------------------------------------------------------------

                 CC|                            |[email protected]
             Blocks|                            |12398
Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
author
#2 lore raw

[Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

In reply to [email protected]

http://bugzilla.kernel.org/show_bug.cgi?id=13232

--- Comment #2 from Jan Kara <[email protected]> 2009-05-12 16:56:04 ---
Hi,

Quoted 25 lines

(switched to email. Please respond via emailed reply-to-all, not via the bugzilla web interface).

Quoted 6 lines

SysRq : Show Blocked State
task PC stack pid father
kjournald D c01384df 0 2525 2
cfcb5f0c 00000082 de27d500 c01384df cfcb5ef4 c02cb5c0 00000001 de32ca00 de324814 dd037ebc de324814 de324934 dd037ebc cfcb5f5c cfcb5f90 c01bd4bb 00000046 c0424110 de324a0c de324814 de324800 00000000 00000002 dd037e80

Quoted 13 lines
Call Trace:
 [<c01384df>] ? trace_hardirqs_on+0xb/0xd
 [<c01bd4bb>] journal_commit_transaction+0xea/0xeaf
 [<c02c534a>] ? _spin_unlock_irqrestore+0x38/0x3f
 [<c0138489>] ? trace_hardirqs_on_caller+0x145/0x190
 [<c012b6ee>] ? autoremove_wake_function+0x0/0x38
 [<c0122a25>] ? del_timer+0x50/0x59
 [<c01c0c75>] kjournald+0xad/0x1bb
 [<c012b6ee>] ? autoremove_wake_function+0x0/0x38
 [<c01c0bc8>] ? kjournald+0x0/0x1bb
 [<c012b442>] kthread+0x37/0x59
 [<c012b40b>] ? kthread+0x0/0x59
 [<c0103667>] kernel_thread_helper+0x7/0x10

I assume this is

Quoted 9 lines
	while (commit_transaction->t_updates) {
		DEFINE_WAIT(wait);

		prepare_to_wait(&journal->j_wait_updates, &wait,
					TASK_UNINTERRUPTIBLE);
		if (commit_transaction->t_updates) {
			spin_unlock(&commit_transaction->t_handle_lock);
			spin_unlock(&journal->j_state_lock);
			schedule();

Yes.

Quoted 11 lines

I'm wondering about

: commit e219cca082f52e7dfea41f3be264b7b5eb204227
: Author: Theodore Ts'o <[email protected]>
: AuthorDate: Thu Nov 6 22:37:59 2008 -0500
: Commit: Theodore Ts'o <[email protected]>
: CommitDate: Thu Nov 6 22:37:59 2008 -0500
:
: jbd: don't give up looking for space so easily in __log_wait_for_space

but that patch was present in 2.6.28.

Hmm, I don't see what made this deadlock happening - as far as I can
see it's there for quite some time. See below...

Quoted 15 lines
Quoted 15 lines

pickup D c01384df 0 2597 2594
cfaa9e5c 00000086 df9faa80 c01384df cfaa9e44 00000282 cfaa9e74 de32ca00 cfaa9e5c c012b8b7 00000002 de324800 0000014f cfaa9e74 cfaa9e94 c01c0539 00000000 de3248c8 de324910 de324814 00000000 df9faa80 c012b6ee de3248e4

Call Trace:
 [<c01384df>] ? trace_hardirqs_on+0xb/0xd
 [<c012b8b7>] ? prepare_to_wait+0x42/0x4a
 [<c01c0539>] log_wait_commit+0x90/0xf7
 [<c012b6ee>] ? autoremove_wake_function+0x0/0x38
 [<c01bba9d>] journal_stop+0x1c8/0x288
 [<c01b4236>] __ext3_journal_stop+0x1c/0x38
 [<c01aeb96>] ext3_delete_inode+0x90/0xc2
 [<c01aeb06>] ? ext3_delete_inode+0x0/0xc2
 [<c017ab82>] generic_delete_inode+0x72/0x100
 [<c02c4ee1>] ? _spin_lock+0x3a/0x40
Quoted 8 lines
Quoted 8 lines
 [<c017ad4c>] generic_drop_inode+0x13c/0x1da
 [<c01d4068>] ? _atomic_dec_and_lock+0x10/0x38
 [<c017a4e7>] iput+0x47/0x4e
 [<c0173db0>] do_unlinkat+0xc1/0x137
 [<c0102f87>] ? sysenter_exit+0xf/0x18
 [<c0138489>] ? trace_hardirqs_on_caller+0x145/0x190
 [<c0173e36>] sys_unlink+0x10/0x12
 [<c0102f55>] sysenter_do_call+0x12/0x35

In generic_delete_inode() we mark inode as I_FREEING. Then
ext3_delete_inode() is called and because of O_SYNC it starts a transaction commit and waits for it.

Quoted 15 lines
Quoted 15 lines

postdrop D c01384df 0 2664 2663
cfcbfd6c 00000086 dd13f700 c01384df cfcbfd54 c02cb5c0 00000001 deedc780 c03a1690 c1402348 c03a1690 cfcbfd7c c1402348 cfcbfd90 cfcbfd9c c017a55b dd758c48 00000007 00000000 dd13f700 c012b726 c1402364 c1402364 00152b13

Call Trace:
 [<c01384df>] ? trace_hardirqs_on+0xb/0xd
 [<c017a55b>] __wait_on_freeing_inode+0x6d/0x88
 [<c012b726>] ? wake_bit_function+0x0/0x47
 [<c017a5b5>] find_inode_fast+0x3f/0x4a
 [<c017ba05>] insert_inode_locked+0x50/0xeb
 [<c01ab90b>] ext3_new_inode+0x738/0x88f
 [<c01bc550>] ? journal_start+0xab/0x100
 [<c01b259a>] ext3_create+0x59/0xbf
 [<c01722c4>] vfs_create+0x75/0xb0
 [<c02c4dda>] ? _spin_unlock+0x1d/0x20
Quoted 8 lines
Quoted 8 lines

[<c01b2541>] ? ext3_create+0x0/0xbf

 [<c0174bc3>] do_filp_open+0x644/0x713
 [<c02c4dda>] ? _spin_unlock+0x1d/0x20
 [<c01692ce>] do_sys_open+0x45/0xce
 [<c0102f87>] ? sysenter_exit+0xf/0x18
 [<c0138489>] ? trace_hardirqs_on_caller+0x145/0x190
 [<c01693a3>] sys_open+0x23/0x2b
 [<c0102f55>] sysenter_do_call+0x12/0x35

Here, we have started a transaction in ext3_create() and then wait in
find_inode_fast() for I_FREEING to be cleared (obviously we have reallocated the inode and squeezed the allocation before journal_stop() from the delete was called).
Nasty deadlock and I don't see how to fix it now - have to go home for
today... Tomorrow I'll have a look what we can do about it.

Honza

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
reviewer
#3 lore raw

Re: [Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

Quoted 105 lines

http://bugzilla.kernel.org/show_bug.cgi?id=13232

--- Comment #2 from Jan Kara <[email protected]> 2009-05-12 16:56:04 ---
Hi,

Quoted 25 lines

(switched to email. Please respond via emailed reply-to-all, not via the bugzilla web interface).

Quoted 6 lines

SysRq : Show Blocked State
task PC stack pid father
kjournald D c01384df 0 2525 2
cfcb5f0c 00000082 de27d500 c01384df cfcb5ef4 c02cb5c0 00000001 de32ca00 de324814 dd037ebc de324814 de324934 dd037ebc cfcb5f5c cfcb5f90 c01bd4bb 00000046 c0424110 de324a0c de324814 de324800 00000000 00000002 dd037e80

Quoted 13 lines
Call Trace:
 [<c01384df>] ? trace_hardirqs_on+0xb/0xd
 [<c01bd4bb>] journal_commit_transaction+0xea/0xeaf
 [<c02c534a>] ? _spin_unlock_irqrestore+0x38/0x3f
 [<c0138489>] ? trace_hardirqs_on_caller+0x145/0x190
 [<c012b6ee>] ? autoremove_wake_function+0x0/0x38
 [<c0122a25>] ? del_timer+0x50/0x59
 [<c01c0c75>] kjournald+0xad/0x1bb
 [<c012b6ee>] ? autoremove_wake_function+0x0/0x38
 [<c01c0bc8>] ? kjournald+0x0/0x1bb
 [<c012b442>] kthread+0x37/0x59
 [<c012b40b>] ? kthread+0x0/0x59
 [<c0103667>] kernel_thread_helper+0x7/0x10

I assume this is

Quoted 9 lines
	while (commit_transaction->t_updates) {
		DEFINE_WAIT(wait);

		prepare_to_wait(&journal->j_wait_updates, &wait,
					TASK_UNINTERRUPTIBLE);
		if (commit_transaction->t_updates) {
			spin_unlock(&commit_transaction->t_handle_lock);
			spin_unlock(&journal->j_state_lock);
			schedule();

Yes.

Quoted 11 lines

I'm wondering about

: commit e219cca082f52e7dfea41f3be264b7b5eb204227
: Author: Theodore Ts'o <[email protected]>
: AuthorDate: Thu Nov 6 22:37:59 2008 -0500
: Commit: Theodore Ts'o <[email protected]>
: CommitDate: Thu Nov 6 22:37:59 2008 -0500
:
: jbd: don't give up looking for space so easily in __log_wait_for_space

but that patch was present in 2.6.28.

Hmm, I don't see what made this deadlock happening - as far as I can
see it's there for quite some time. See below...

Quoted 15 lines
Quoted 15 lines

pickup D c01384df 0 2597 2594
cfaa9e5c 00000086 df9faa80 c01384df cfaa9e44 00000282 cfaa9e74 de32ca00 cfaa9e5c c012b8b7 00000002 de324800 0000014f cfaa9e74 cfaa9e94 c01c0539 00000000 de3248c8 de324910 de324814 00000000 df9faa80 c012b6ee de3248e4

Call Trace:
 [<c01384df>] ? trace_hardirqs_on+0xb/0xd
 [<c012b8b7>] ? prepare_to_wait+0x42/0x4a
 [<c01c0539>] log_wait_commit+0x90/0xf7
 [<c012b6ee>] ? autoremove_wake_function+0x0/0x38
 [<c01bba9d>] journal_stop+0x1c8/0x288
 [<c01b4236>] __ext3_journal_stop+0x1c/0x38
 [<c01aeb96>] ext3_delete_inode+0x90/0xc2
 [<c01aeb06>] ? ext3_delete_inode+0x0/0xc2
 [<c017ab82>] generic_delete_inode+0x72/0x100
 [<c02c4ee1>] ? _spin_lock+0x3a/0x40
Quoted 8 lines
Quoted 8 lines
 [<c017ad4c>] generic_drop_inode+0x13c/0x1da
 [<c01d4068>] ? _atomic_dec_and_lock+0x10/0x38
 [<c017a4e7>] iput+0x47/0x4e
 [<c0173db0>] do_unlinkat+0xc1/0x137
 [<c0102f87>] ? sysenter_exit+0xf/0x18
 [<c0138489>] ? trace_hardirqs_on_caller+0x145/0x190
 [<c0173e36>] sys_unlink+0x10/0x12
 [<c0102f55>] sysenter_do_call+0x12/0x35

In generic_delete_inode() we mark inode as I_FREEING. Then
ext3_delete_inode() is called and because of O_SYNC it starts a transaction commit and waits for it.

Quoted 15 lines
Quoted 15 lines

postdrop D c01384df 0 2664 2663
cfcbfd6c 00000086 dd13f700 c01384df cfcbfd54 c02cb5c0 00000001 deedc780 c03a1690 c1402348 c03a1690 cfcbfd7c c1402348 cfcbfd90 cfcbfd9c c017a55b dd758c48 00000007 00000000 dd13f700 c012b726 c1402364 c1402364 00152b13

Call Trace:
 [<c01384df>] ? trace_hardirqs_on+0xb/0xd
 [<c017a55b>] __wait_on_freeing_inode+0x6d/0x88
 [<c012b726>] ? wake_bit_function+0x0/0x47
 [<c017a5b5>] find_inode_fast+0x3f/0x4a
 [<c017ba05>] insert_inode_locked+0x50/0xeb
 [<c01ab90b>] ext3_new_inode+0x738/0x88f
 [<c01bc550>] ? journal_start+0xab/0x100
 [<c01b259a>] ext3_create+0x59/0xbf
 [<c01722c4>] vfs_create+0x75/0xb0
 [<c02c4dda>] ? _spin_unlock+0x1d/0x20
Quoted 8 lines
Quoted 8 lines

[<c01b2541>] ? ext3_create+0x0/0xbf

 [<c0174bc3>] do_filp_open+0x644/0x713
 [<c02c4dda>] ? _spin_unlock+0x1d/0x20
 [<c01692ce>] do_sys_open+0x45/0xce
 [<c0102f87>] ? sysenter_exit+0xf/0x18
 [<c0138489>] ? trace_hardirqs_on_caller+0x145/0x190
 [<c01693a3>] sys_open+0x23/0x2b
 [<c0102f55>] sysenter_do_call+0x12/0x35
Quoted 6 lines

Here, we have started a transaction in ext3_create() and then wait in
find_inode_fast() for I_FREEING to be cleared (obviously we have reallocated the inode and squeezed the allocation before journal_stop() from the delete was called).
Nasty deadlock and I don't see how to fix it now - have to go home for
today... Tomorrow I'll have a look what we can do about it.

OK, the deadlock has been introduced by ext3 variant of
261bca86ed4f7f391d1938167624e78da61dcc6b (adding Al to CC). The deadlock is really tough to avoid - we have to first allocate inode on disk so that we know the inode number. For this we need transaction open but we cannot afford waiting for old inode with same INO to be freed when we have transaction open because of the above deadlock. So we'd have to wait for inode release only after everything is done and we closed the transaction. But that would mean reordering a lot of code in ext3/namei.c so that all the dcache handling is done after all the IO is done.
Hmm, maybe we could change the delete side of the deadlock but that's
going to be tricky as well :(.
Al, any idea if we could somehow get away without waiting on
I_FREEING?

Honza

Signature · 2 lines
Jan Kara <[email protected]>
SuSE CR Labs
#4 lore raw

Re: [Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

Quoted 2 lines · Jan Kara

OK, the deadlock has been introduced by ext3 variant of
261bca86ed4f7f391d1938167624e78da61dcc6b (adding Al to CC).

What do you mean by this?

I'm puzzled why we haven't hit this before. This looks like long-standing issue; what unmasked it now?

Quoted 3 lines

The deadlock
is really tough to avoid - we have to first allocate inode on disk so that we know the inode number.

Well, the simple thing to do is to have a way of quickly determining that a particular inode number is in the I_FREEING state, and simply try to avoid using that inode number. If there are no inodes available, it can simply close the handle (since nothing else has changed at that point), wait for the current transaction to close, and then try again. That should fix the problem, I think.

- Ted

reviewer
#5 lore raw

Re: [Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

Quoted 8 lines · Theodore Tso
Quoted 2 lines · Jan Kara

OK, the deadlock has been introduced by ext3 variant of
261bca86ed4f7f391d1938167624e78da61dcc6b (adding Al to CC).

What do you mean by this?

I'm puzzled why we haven't hit this before. This looks like long-standing issue; what unmasked it now?

Unless you mount the fs with 'sync' option, hitting this is much harder
(the window is quite small in nosync case). I think that is the main reason why we didn't see this earlier.

Quoted 10 lines
Quoted 3 lines

The deadlock
is really tough to avoid - we have to first allocate inode on disk so that we know the inode number.

Well, the simple thing to do is to have a way of quickly determining that a particular inode number is in the I_FREEING state, and simply try to avoid using that inode number. If there are no inodes available, it can simply close the handle (since nothing else has changed at that point), wait for the current transaction to close, and then try again. That should fix the problem, I think.

Yes, we could work-around it like that but other filesystems might need
similar things and generally it would be nicer if we could avoid using this vfs-internal information in the filesystems. Al seems to have found some other solution without changing filesystems so that would be easier for us...

Honza

Signature · 2 lines
Jan Kara <[email protected]>
SUSE Labs, CR
maintainer
#6 lore raw

Re: [Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

In reply to Jan Kara
Quoted 6 lines · Jan Kara
Quoted 6 lines

Here, we have started a transaction in ext3_create() and then wait in
find_inode_fast() for I_FREEING to be cleared (obviously we have reallocated the inode and squeezed the allocation before journal_stop() from the delete was called).
Nasty deadlock and I don't see how to fix it now - have to go home for
today... Tomorrow I'll have a look what we can do about it.

Quoted 13 lines

OK, the deadlock has been introduced by ext3 variant of
261bca86ed4f7f391d1938167624e78da61dcc6b (adding Al to CC). The deadlock is really tough to avoid - we have to first allocate inode on disk so that we know the inode number. For this we need transaction open but we cannot afford waiting for old inode with same INO to be freed when we have transaction open because of the above deadlock. So we'd have to wait for inode release only after everything is done and we closed the transaction. But that would mean reordering a lot of code in ext3/namei.c so that all the dcache handling is done after all the IO is done.
Hmm, maybe we could change the delete side of the deadlock but that's
going to be tricky as well :(.
Al, any idea if we could somehow get away without waiting on
I_FREEING?

At which point do we actually run into deadlock on delete side? We could, in principle, skip everything like that in insert_inode_locked(), but I would rather avoid the "two inodes in icache at the same time, with the same inumber" situations completely. We might get away with that, since everything else *will* wait, so we can afford a bunch of inodes past the point in foo_delete_inode() that has cleared it in bitmap + new locked one, but if it's at all possible to avoid, I'd rather avoid it.

maintainer
#7 lore raw

Re: [Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

Quoted 21 lines · Al Viro
Quoted 6 lines · Jan Kara
Quoted 6 lines

Here, we have started a transaction in ext3_create() and then wait in
find_inode_fast() for I_FREEING to be cleared (obviously we have reallocated the inode and squeezed the allocation before journal_stop() from the delete was called).
Nasty deadlock and I don't see how to fix it now - have to go home for
today... Tomorrow I'll have a look what we can do about it.

Quoted 13 lines

OK, the deadlock has been introduced by ext3 variant of
261bca86ed4f7f391d1938167624e78da61dcc6b (adding Al to CC). The deadlock is really tough to avoid - we have to first allocate inode on disk so that we know the inode number. For this we need transaction open but we cannot afford waiting for old inode with same INO to be freed when we have transaction open because of the above deadlock. So we'd have to wait for inode release only after everything is done and we closed the transaction. But that would mean reordering a lot of code in ext3/namei.c so that all the dcache handling is done after all the IO is done.
Hmm, maybe we could change the delete side of the deadlock but that's
going to be tricky as well :(.
Al, any idea if we could somehow get away without waiting on
I_FREEING?

Quoted 7 lines

At which point do we actually run into deadlock on delete side? We could, in principle, skip everything like that in insert_inode_locked(), but I would rather avoid the "two inodes in icache at the same time, with the same inumber" situations completely. We might get away with that, since everything else *will* wait, so we can afford a bunch of inodes past the point in foo_delete_inode() that has cleared it in bitmap + new locked one, but if it's at all possible to avoid, I'd rather avoid it.

OK, that's probably the easiest way to do that, as much as I don't like it... Since iget() et.al. will not accept I_FREEING (will wait to go away and restart), and since we'd better have serialization between new/free on fs data structures anyway, we can afford simply skipping I_FREEING et.al. in insert_inode_locked().

We do that from new_inode, so it won't race with free_inode in any interesting ways and it won't race with iget (of any origin; nfsd or in case of fs corruption a lookup) since both still will wait for I_LOCK.

Tentative patch follow; folks, I would very much like review on that one, since I'm far too low on caffeine and the area is nasty.

fs/inode.c +25 -6
index 9d26490..4406952 100644
@@ -1053,13 +1053,22 @@ int insert_inode_locked(struct inode *inode)
 	struct super_block *sb = inode->i_sb;
 	ino_t ino = inode->i_ino;
 	struct hlist_head *head = inode_hashtable + hash(sb, ino);
-	struct inode *old;
 
 	inode->i_state |= I_LOCK|I_NEW;
 	while (1) {
+		struct hlist_node *node;
+		struct inode *old = NULL;
 		spin_lock(&inode_lock);
-		old = find_inode_fast(sb, head, ino);
-		if (likely(!old)) {
+		hlist_for_each_entry(old, node, head, i_hash) {
+			if (old->i_ino != ino)
+				continue;
+			if (old->i_sb != sb)
+				continue;
+			if (old->i_state & (I_FREEING|I_CLEAR|I_WILL_FREE))
+				continue;
+			break;
+		}
+		if (likely(!node)) {
 			hlist_add_head(&inode->i_hash, head);
 			spin_unlock(&inode_lock);
 			return 0;

@@ -1081,14 +1090,24 @@ int insert_inode_locked4(struct inode *inode, unsigned long hashval,
 {
 	struct super_block *sb = inode->i_sb;
 	struct hlist_head *head = inode_hashtable + hash(sb, hashval);
-	struct inode *old;
 
 	inode->i_state |= I_LOCK|I_NEW;
 
 	while (1) {
+		struct hlist_node *node;
+		struct inode *old = NULL;
+
 		spin_lock(&inode_lock);
-		old = find_inode(sb, head, test, data);
-		if (likely(!old)) {
+		hlist_for_each_entry(old, node, head, i_hash) {
+			if (old->i_sb != sb)
+				continue;
+			if (!test(old, data))
+				continue;
+			if (old->i_state & (I_FREEING|I_CLEAR|I_WILL_FREE))
+				continue;
+			break;
+		}
+		if (likely(!node)) {
 			hlist_add_head(&inode->i_hash, head);
 			spin_unlock(&inode_lock);
 			return 0;
Reviewed-by
#8 lore raw

Re: [Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

Quoted 7 lines · Al Viro

OK, that's probably the easiest way to do that, as much as I don't like it... Since iget() et.al. will not accept I_FREEING (will wait to go away and restart), and since we'd better have serialization between new/free on fs data structures anyway, we can afford simply skipping I_FREEING et.al. in insert_inode_locked().

Quoted 6 lines

We do that from new_inode, so it won't race with free_inode in any interesting ways and it won't race with iget (of any origin; nfsd or in case of fs corruption a lookup) since both still will wait for I_LOCK.

Tentative patch follow; folks, I would very much like review on that one, since I'm far too low on caffeine and the area is nasty.

Sorry for not having time to review this until now. This looks good to me.

Reviewed-by "Theodore Ts'o" <[email protected]>

So Bug #13232 is currently marked as a 2.6.28 regression; do we feel confident enough to push this to Linus for 2.6.30?

- Ted

reviewer Acked-by
#9 lore raw

Re: [Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

In reply to Al Viro
Quoted 36 lines · Al Viro
Quoted 21 lines · Al Viro
Quoted 6 lines · Jan Kara
Quoted 6 lines

Here, we have started a transaction in ext3_create() and then wait in
find_inode_fast() for I_FREEING to be cleared (obviously we have reallocated the inode and squeezed the allocation before journal_stop() from the delete was called).
Nasty deadlock and I don't see how to fix it now - have to go home for
today... Tomorrow I'll have a look what we can do about it.

Quoted 13 lines

OK, the deadlock has been introduced by ext3 variant of
261bca86ed4f7f391d1938167624e78da61dcc6b (adding Al to CC). The deadlock is really tough to avoid - we have to first allocate inode on disk so that we know the inode number. For this we need transaction open but we cannot afford waiting for old inode with same INO to be freed when we have transaction open because of the above deadlock. So we'd have to wait for inode release only after everything is done and we closed the transaction. But that would mean reordering a lot of code in ext3/namei.c so that all the dcache handling is done after all the IO is done.
Hmm, maybe we could change the delete side of the deadlock but that's
going to be tricky as well :(.
Al, any idea if we could somehow get away without waiting on
I_FREEING?

Quoted 7 lines

At which point do we actually run into deadlock on delete side? We could, in principle, skip everything like that in insert_inode_locked(), but I would rather avoid the "two inodes in icache at the same time, with the same inumber" situations completely. We might get away with that, since everything else *will* wait, so we can afford a bunch of inodes past the point in foo_delete_inode() that has cleared it in bitmap + new locked one, but if it's at all possible to avoid, I'd rather avoid it.

OK, that's probably the easiest way to do that, as much as I don't like it... Since iget() et.al. will not accept I_FREEING (will wait to go away and restart), and since we'd better have serialization between new/free on fs data structures anyway, we can afford simply skipping I_FREEING et.al. in insert_inode_locked().

Quoted 6 lines

We do that from new_inode, so it won't race with free_inode in any interesting ways and it won't race with iget (of any origin; nfsd or in case of fs corruption a lookup) since both still will wait for I_LOCK.

Tentative patch follow; folks, I would very much like review on that one, since I'm far too low on caffeine and the area is nasty.

The patch looks fine. Everyone else will either get new inode and wait
for I_LOCK or get old inode and wait for I_FREEING so everything should be fine... You can add.

Acked-by Jan Kara <[email protected]>

Honza

Quoted 59 lines
fs/inode.c +25 -6
index 9d26490..4406952 100644
@@ -1053,13 +1053,22 @@ int insert_inode_locked(struct inode *inode)
 	struct super_block *sb = inode->i_sb;
 	ino_t ino = inode->i_ino;
 	struct hlist_head *head = inode_hashtable + hash(sb, ino);
-	struct inode *old;
 
 	inode->i_state |= I_LOCK|I_NEW;
 	while (1) {
+		struct hlist_node *node;
+		struct inode *old = NULL;
 		spin_lock(&inode_lock);
-		old = find_inode_fast(sb, head, ino);
-		if (likely(!old)) {
+		hlist_for_each_entry(old, node, head, i_hash) {
+			if (old->i_ino != ino)
+				continue;
+			if (old->i_sb != sb)
+				continue;
+			if (old->i_state & (I_FREEING|I_CLEAR|I_WILL_FREE))
+				continue;
+			break;
+		}
+		if (likely(!node)) {
 			hlist_add_head(&inode->i_hash, head);
 			spin_unlock(&inode_lock);
 			return 0;

@@ -1081,14 +1090,24 @@ int insert_inode_locked4(struct inode *inode, unsigned long hashval,
 {
 	struct super_block *sb = inode->i_sb;
 	struct hlist_head *head = inode_hashtable + hash(sb, hashval);
-	struct inode *old;
 
 	inode->i_state |= I_LOCK|I_NEW;
 
 	while (1) {
+		struct hlist_node *node;
+		struct inode *old = NULL;
+
 		spin_lock(&inode_lock);
-		old = find_inode(sb, head, test, data);
-		if (likely(!old)) {
+		hlist_for_each_entry(old, node, head, i_hash) {
+			if (old->i_sb != sb)
+				continue;
+			if (!test(old, data))
+				continue;
+			if (old->i_state & (I_FREEING|I_CLEAR|I_WILL_FREE))
+				continue;
+			break;
+		}
+		if (likely(!node)) {
 			hlist_add_head(&inode->i_hash, head);
 			spin_unlock(&inode_lock);
 			return 0;
Signature · 2 lines
Jan Kara <[email protected]>
SUSE Labs, CR
reviewer
#10 lore raw

Re: [Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

In reply to Al Viro
Quoted 21 lines · Al Viro
Quoted 6 lines · Jan Kara
Quoted 6 lines

Here, we have started a transaction in ext3_create() and then wait in
find_inode_fast() for I_FREEING to be cleared (obviously we have reallocated the inode and squeezed the allocation before journal_stop() from the delete was called).
Nasty deadlock and I don't see how to fix it now - have to go home for
today... Tomorrow I'll have a look what we can do about it.

Quoted 13 lines

OK, the deadlock has been introduced by ext3 variant of
261bca86ed4f7f391d1938167624e78da61dcc6b (adding Al to CC). The deadlock is really tough to avoid - we have to first allocate inode on disk so that we know the inode number. For this we need transaction open but we cannot afford waiting for old inode with same INO to be freed when we have transaction open because of the above deadlock. So we'd have to wait for inode release only after everything is done and we closed the transaction. But that would mean reordering a lot of code in ext3/namei.c so that all the dcache handling is done after all the IO is done.
Hmm, maybe we could change the delete side of the deadlock but that's
going to be tricky as well :(.
Al, any idea if we could somehow get away without waiting on
I_FREEING?

Quoted 7 lines

At which point do we actually run into deadlock on delete side? We could, in principle, skip everything like that in insert_inode_locked(), but I would rather avoid the "two inodes in icache at the same time, with the same inumber" situations completely. We might get away with that, since everything else *will* wait, so we can afford a bunch of inodes past the point in foo_delete_inode() that has cleared it in bitmap + new locked one, but if it's at all possible to avoid, I'd rather avoid it.

The ordering we see on delete when the filesystem is mounted with 'sync'
option is:
DELETE CREATE
generic_delete_inode()
set I_FREEING
ext3_delete_inode
get transaction handle
do work
get transaction handle ext3_new_inode()
reallocate inode insert_inode_locked()
stop transaction, wait for it to commit
(waiting for CREATE process to drop its
transaction reference)

Now similar race can happen even without 'sync' mount option but it's
much harder to hit:
DELETE CREATE
generic_delete_inode()
set I_FREEING
ext3_delete_inode
get transaction handle ext3_new_inode()
reallocate inode insert_inode_locked()
try to get transaction handle -
- transaction is too big so we send
current transaction to commit which
again waits for CREATE to drop its
reference.

Honza

Signature · 2 lines
Jan Kara <[email protected]>
SUSE Labs, CR
author
#11 lore raw

[Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

In reply to [email protected]

http://bugzilla.kernel.org/show_bug.cgi?id=13232

--- Comment #3 from Jan Kara <[email protected]> 2009-05-13 13:48:04 ---

Quoted 105 lines

http://bugzilla.kernel.org/show_bug.cgi?id=13232

--- Comment #2 from Jan Kara <[email protected]> 2009-05-12 16:56:04 ---
Hi,

Quoted 25 lines

(switched to email. Please respond via emailed reply-to-all, not via the bugzilla web interface).

Quoted 6 lines

SysRq : Show Blocked State
task PC stack pid father
kjournald D c01384df 0 2525 2
cfcb5f0c 00000082 de27d500 c01384df cfcb5ef4 c02cb5c0 00000001 de32ca00 de324814 dd037ebc de324814 de324934 dd037ebc cfcb5f5c cfcb5f90 c01bd4bb 00000046 c0424110 de324a0c de324814 de324800 00000000 00000002 dd037e80

Quoted 13 lines
Call Trace:
 [<c01384df>] ? trace_hardirqs_on+0xb/0xd
 [<c01bd4bb>] journal_commit_transaction+0xea/0xeaf
 [<c02c534a>] ? _spin_unlock_irqrestore+0x38/0x3f
 [<c0138489>] ? trace_hardirqs_on_caller+0x145/0x190
 [<c012b6ee>] ? autoremove_wake_function+0x0/0x38
 [<c0122a25>] ? del_timer+0x50/0x59
 [<c01c0c75>] kjournald+0xad/0x1bb
 [<c012b6ee>] ? autoremove_wake_function+0x0/0x38
 [<c01c0bc8>] ? kjournald+0x0/0x1bb
 [<c012b442>] kthread+0x37/0x59
 [<c012b40b>] ? kthread+0x0/0x59
 [<c0103667>] kernel_thread_helper+0x7/0x10

I assume this is

Quoted 9 lines
	while (commit_transaction->t_updates) {
		DEFINE_WAIT(wait);

		prepare_to_wait(&journal->j_wait_updates, &wait,
					TASK_UNINTERRUPTIBLE);
		if (commit_transaction->t_updates) {
			spin_unlock(&commit_transaction->t_handle_lock);
			spin_unlock(&journal->j_state_lock);
			schedule();

Yes.

Quoted 11 lines

I'm wondering about

: commit e219cca082f52e7dfea41f3be264b7b5eb204227
: Author: Theodore Ts'o <[email protected]>
: AuthorDate: Thu Nov 6 22:37:59 2008 -0500
: Commit: Theodore Ts'o <[email protected]>
: CommitDate: Thu Nov 6 22:37:59 2008 -0500
:
: jbd: don't give up looking for space so easily in __log_wait_for_space

but that patch was present in 2.6.28.

Hmm, I don't see what made this deadlock happening - as far as I can
see it's there for quite some time. See below...

Quoted 15 lines
Quoted 15 lines

pickup D c01384df 0 2597 2594
cfaa9e5c 00000086 df9faa80 c01384df cfaa9e44 00000282 cfaa9e74 de32ca00 cfaa9e5c c012b8b7 00000002 de324800 0000014f cfaa9e74 cfaa9e94 c01c0539 00000000 de3248c8 de324910 de324814 00000000 df9faa80 c012b6ee de3248e4

Call Trace:
 [<c01384df>] ? trace_hardirqs_on+0xb/0xd
 [<c012b8b7>] ? prepare_to_wait+0x42/0x4a
 [<c01c0539>] log_wait_commit+0x90/0xf7
 [<c012b6ee>] ? autoremove_wake_function+0x0/0x38
 [<c01bba9d>] journal_stop+0x1c8/0x288
 [<c01b4236>] __ext3_journal_stop+0x1c/0x38
 [<c01aeb96>] ext3_delete_inode+0x90/0xc2
 [<c01aeb06>] ? ext3_delete_inode+0x0/0xc2
 [<c017ab82>] generic_delete_inode+0x72/0x100
 [<c02c4ee1>] ? _spin_lock+0x3a/0x40
Quoted 8 lines
Quoted 8 lines
 [<c017ad4c>] generic_drop_inode+0x13c/0x1da
 [<c01d4068>] ? _atomic_dec_and_lock+0x10/0x38
 [<c017a4e7>] iput+0x47/0x4e
 [<c0173db0>] do_unlinkat+0xc1/0x137
 [<c0102f87>] ? sysenter_exit+0xf/0x18
 [<c0138489>] ? trace_hardirqs_on_caller+0x145/0x190
 [<c0173e36>] sys_unlink+0x10/0x12
 [<c0102f55>] sysenter_do_call+0x12/0x35

In generic_delete_inode() we mark inode as I_FREEING. Then
ext3_delete_inode() is called and because of O_SYNC it starts a transaction commit and waits for it.

Quoted 15 lines
Quoted 15 lines

postdrop D c01384df 0 2664 2663
cfcbfd6c 00000086 dd13f700 c01384df cfcbfd54 c02cb5c0 00000001 deedc780 c03a1690 c1402348 c03a1690 cfcbfd7c c1402348 cfcbfd90 cfcbfd9c c017a55b dd758c48 00000007 00000000 dd13f700 c012b726 c1402364 c1402364 00152b13

Call Trace:
 [<c01384df>] ? trace_hardirqs_on+0xb/0xd
 [<c017a55b>] __wait_on_freeing_inode+0x6d/0x88
 [<c012b726>] ? wake_bit_function+0x0/0x47
 [<c017a5b5>] find_inode_fast+0x3f/0x4a
 [<c017ba05>] insert_inode_locked+0x50/0xeb
 [<c01ab90b>] ext3_new_inode+0x738/0x88f
 [<c01bc550>] ? journal_start+0xab/0x100
 [<c01b259a>] ext3_create+0x59/0xbf
 [<c01722c4>] vfs_create+0x75/0xb0
 [<c02c4dda>] ? _spin_unlock+0x1d/0x20
Quoted 8 lines
Quoted 8 lines

[<c01b2541>] ? ext3_create+0x0/0xbf

 [<c0174bc3>] do_filp_open+0x644/0x713
 [<c02c4dda>] ? _spin_unlock+0x1d/0x20
 [<c01692ce>] do_sys_open+0x45/0xce
 [<c0102f87>] ? sysenter_exit+0xf/0x18
 [<c0138489>] ? trace_hardirqs_on_caller+0x145/0x190
 [<c01693a3>] sys_open+0x23/0x2b
 [<c0102f55>] sysenter_do_call+0x12/0x35
Quoted 6 lines

Here, we have started a transaction in ext3_create() and then wait in
find_inode_fast() for I_FREEING to be cleared (obviously we have reallocated the inode and squeezed the allocation before journal_stop() from the delete was called).
Nasty deadlock and I don't see how to fix it now - have to go home for
today... Tomorrow I'll have a look what we can do about it.

OK, the deadlock has been introduced by ext3 variant of
261bca86ed4f7f391d1938167624e78da61dcc6b (adding Al to CC). The deadlock is really tough to avoid - we have to first allocate inode on disk so that we know the inode number. For this we need transaction open but we cannot afford waiting for old inode with same INO to be freed when we have transaction open because of the above deadlock. So we'd have to wait for inode release only after everything is done and we closed the transaction. But that would mean reordering a lot of code in ext3/namei.c so that all the dcache handling is done after all the IO is done.
Hmm, maybe we could change the delete side of the deadlock but that's
going to be tricky as well :(.
Al, any idea if we could somehow get away without waiting on
I_FREEING?

Honza

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
author
#12 lore raw

[Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

In reply to [email protected]

http://bugzilla.kernel.org/show_bug.cgi?id=13232

--- Comment #4 from Theodore Tso <[email protected]> 2009-05-13 16:07:33 ---

Quoted 2 lines · Jan Kara

OK, the deadlock has been introduced by ext3 variant of
261bca86ed4f7f391d1938167624e78da61dcc6b (adding Al to CC).

What do you mean by this?

I'm puzzled why we haven't hit this before. This looks like long-standing issue; what unmasked it now?

Quoted 3 lines

The deadlock
is really tough to avoid - we have to first allocate inode on disk so that we know the inode number.

Well, the simple thing to do is to have a way of quickly determining that a particular inode number is in the I_FREEING state, and simply try to avoid using that inode number. If there are no inodes available, it can simply close the handle (since nothing else has changed at that point), wait for the current transaction to close, and then try again. That should fix the problem, I think.

- Ted

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
author
#13 lore raw

[Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

In reply to [email protected]

http://bugzilla.kernel.org/show_bug.cgi?id=13232

Vincent Li <[email protected]> changed:

What |Removed |Added
----------------------------------------------------------------------------
CC| |[email protected]

--- Comment #5 from Vincent Li <[email protected]> 2009-05-13 16:18:57 --- I tried to run Postfix on ubuntu 9.04 server version and followed the reporduce command, had the same problem.

kernel version: 2.6.30-rc4
Distribution: Ubuntu 9.04
Software Environment: Postfix 2.5.1-2ubuntu1.2

also have following message poping up on control terminal:

[844,700070] INFO: task kjournald: 628 blocked for more than 120 seconds, [844,700148] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this meassage.

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
author
#14 lore raw

[Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

In reply to [email protected]

http://bugzilla.kernel.org/show_bug.cgi?id=13232

--- Comment #6 from Anonymous Emailer <[email protected]> 2009-05-13 16:52:56 ---
Reply-To: [email protected]

Quoted 6 lines · Jan Kara
Quoted 6 lines

Here, we have started a transaction in ext3_create() and then wait in
find_inode_fast() for I_FREEING to be cleared (obviously we have reallocated the inode and squeezed the allocation before journal_stop() from the delete was called).
Nasty deadlock and I don't see how to fix it now - have to go home for
today... Tomorrow I'll have a look what we can do about it.

Quoted 13 lines

OK, the deadlock has been introduced by ext3 variant of
261bca86ed4f7f391d1938167624e78da61dcc6b (adding Al to CC). The deadlock is really tough to avoid - we have to first allocate inode on disk so that we know the inode number. For this we need transaction open but we cannot afford waiting for old inode with same INO to be freed when we have transaction open because of the above deadlock. So we'd have to wait for inode release only after everything is done and we closed the transaction. But that would mean reordering a lot of code in ext3/namei.c so that all the dcache handling is done after all the IO is done.
Hmm, maybe we could change the delete side of the deadlock but that's
going to be tricky as well :(.
Al, any idea if we could somehow get away without waiting on
I_FREEING?

At which point do we actually run into deadlock on delete side? We could, in principle, skip everything like that in insert_inode_locked(), but I would rather avoid the "two inodes in icache at the same time, with the same inumber" situations completely. We might get away with that, since everything else *will* wait, so we can afford a bunch of inodes past the point in foo_delete_inode() that has cleared it in bitmap + new locked one, but if it's at all possible to avoid, I'd rather avoid it.

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
author
#15 lore raw

[Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

In reply to [email protected]

http://bugzilla.kernel.org/show_bug.cgi?id=13232

--- Comment #7 from Anonymous Emailer <[email protected]> 2009-05-13 18:13:42 ---
Reply-To: [email protected]

Quoted 21 lines · Al Viro
Quoted 6 lines · Jan Kara
Quoted 6 lines

Here, we have started a transaction in ext3_create() and then wait in
find_inode_fast() for I_FREEING to be cleared (obviously we have reallocated the inode and squeezed the allocation before journal_stop() from the delete was called).
Nasty deadlock and I don't see how to fix it now - have to go home for
today... Tomorrow I'll have a look what we can do about it.

Quoted 13 lines

OK, the deadlock has been introduced by ext3 variant of
261bca86ed4f7f391d1938167624e78da61dcc6b (adding Al to CC). The deadlock is really tough to avoid - we have to first allocate inode on disk so that we know the inode number. For this we need transaction open but we cannot afford waiting for old inode with same INO to be freed when we have transaction open because of the above deadlock. So we'd have to wait for inode release only after everything is done and we closed the transaction. But that would mean reordering a lot of code in ext3/namei.c so that all the dcache handling is done after all the IO is done.
Hmm, maybe we could change the delete side of the deadlock but that's
going to be tricky as well :(.
Al, any idea if we could somehow get away without waiting on
I_FREEING?

Quoted 7 lines

At which point do we actually run into deadlock on delete side? We could, in principle, skip everything like that in insert_inode_locked(), but I would rather avoid the "two inodes in icache at the same time, with the same inumber" situations completely. We might get away with that, since everything else *will* wait, so we can afford a bunch of inodes past the point in foo_delete_inode() that has cleared it in bitmap + new locked one, but if it's at all possible to avoid, I'd rather avoid it.

OK, that's probably the easiest way to do that, as much as I don't like it... Since iget() et.al. will not accept I_FREEING (will wait to go away and restart), and since we'd better have serialization between new/free on fs data structures anyway, we can afford simply skipping I_FREEING et.al. in insert_inode_locked().

We do that from new_inode, so it won't race with free_inode in any interesting ways and it won't race with iget (of any origin; nfsd or in case of fs corruption a lookup) since both still will wait for I_LOCK.

Tentative patch follow; folks, I would very much like review on that one, since I'm far too low on caffeine and the area is nasty.

fs/inode.c +12 -3
index 9d26490..4406952 100644
@@ -1053,13 +1053,22 @@ int insert_inode_locked(struct inode *inode)
     struct super_block *sb = inode->i_sb;
     ino_t ino = inode->i_ino;
     struct hlist_head *head = inode_hashtable + hash(sb, ino);
-    struct inode *old;
 
     inode->i_state |= I_LOCK|I_NEW;
     while (1) {
+        struct hlist_node *node;
+        struct inode *old = NULL;
         spin_lock(&inode_lock);
-        old = find_inode_fast(sb, head, ino);
-        if (likely(!old)) {
+        hlist_for_each_entry(old, node, head, i_hash) {
+            if (old->i_ino != ino)
+                continue;
+            if (old->i_sb != sb)
+                continue;
+            if (old->i_state & (I_FREEING|I_CLEAR|I_WILL_FREE))
+                continue;
+            break;
+        }
+        if (likely(!node)) {
             hlist_add_head(&inode->i_hash, head);
             spin_unlock(&inode_lock);
             return 0;

@@ -1081,14 +1090,24 @@ int insert_inode_locked4(struct inode *inode, unsigned

long hashval,

 {
     struct super_block *sb = inode->i_sb;
     struct hlist_head *head = inode_hashtable + hash(sb, hashval);

- struct inode *old;

     inode->i_state |= I_LOCK|I_NEW;

     while (1) {
+        struct hlist_node *node;
+        struct inode *old = NULL;
+
         spin_lock(&inode_lock);
-        old = find_inode(sb, head, test, data);
-        if (likely(!old)) {
+        hlist_for_each_entry(old, node, head, i_hash) {

+ if (old->i_sb != sb)
+ continue;
+ if (!test(old, data))
+ continue;
+ if (old->i_state & (I_FREEING|I_CLEAR|I_WILL_FREE))
+ continue;
+ break;
+ }

+        if (likely(!node)) {
             hlist_add_head(&inode->i_hash, head);
             spin_unlock(&inode_lock);
             return 0;
Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
author
#16 lore raw

[Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

In reply to [email protected]

http://bugzilla.kernel.org/show_bug.cgi?id=13232

--- Comment #8 from Jan Kara <[email protected]> 2009-05-18 12:45:23 ---

Quoted 8 lines · Theodore Tso
Quoted 2 lines · Jan Kara

OK, the deadlock has been introduced by ext3 variant of
261bca86ed4f7f391d1938167624e78da61dcc6b (adding Al to CC).

What do you mean by this?

I'm puzzled why we haven't hit this before. This looks like long-standing issue; what unmasked it now?

Unless you mount the fs with 'sync' option, hitting this is much harder
(the window is quite small in nosync case). I think that is the main reason why we didn't see this earlier.

Quoted 10 lines
Quoted 3 lines

The deadlock
is really tough to avoid - we have to first allocate inode on disk so that we know the inode number.

Well, the simple thing to do is to have a way of quickly determining that a particular inode number is in the I_FREEING state, and simply try to avoid using that inode number. If there are no inodes available, it can simply close the handle (since nothing else has changed at that point), wait for the current transaction to close, and then try again. That should fix the problem, I think.

Yes, we could work-around it like that but other filesystems might need
similar things and generally it would be nicer if we could avoid using this vfs-internal information in the filesystems. Al seems to have found some other solution without changing filesystems so that would be easier for us...

Honza

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
author
#17 lore raw

[Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

In reply to [email protected]

http://bugzilla.kernel.org/show_bug.cgi?id=13232

--- Comment #9 from Jan Kara <[email protected]> 2009-05-18 12:54:00 ---

Quoted 21 lines · Al Viro
Quoted 6 lines · Jan Kara
Quoted 6 lines

Here, we have started a transaction in ext3_create() and then wait in
find_inode_fast() for I_FREEING to be cleared (obviously we have reallocated the inode and squeezed the allocation before journal_stop() from the delete was called).
Nasty deadlock and I don't see how to fix it now - have to go home for
today... Tomorrow I'll have a look what we can do about it.

Quoted 13 lines

OK, the deadlock has been introduced by ext3 variant of
261bca86ed4f7f391d1938167624e78da61dcc6b (adding Al to CC). The deadlock is really tough to avoid - we have to first allocate inode on disk so that we know the inode number. For this we need transaction open but we cannot afford waiting for old inode with same INO to be freed when we have transaction open because of the above deadlock. So we'd have to wait for inode release only after everything is done and we closed the transaction. But that would mean reordering a lot of code in ext3/namei.c so that all the dcache handling is done after all the IO is done.
Hmm, maybe we could change the delete side of the deadlock but that's
going to be tricky as well :(.
Al, any idea if we could somehow get away without waiting on
I_FREEING?

Quoted 7 lines

At which point do we actually run into deadlock on delete side? We could, in principle, skip everything like that in insert_inode_locked(), but I would rather avoid the "two inodes in icache at the same time, with the same inumber" situations completely. We might get away with that, since everything else *will* wait, so we can afford a bunch of inodes past the point in foo_delete_inode() that has cleared it in bitmap + new locked one, but if it's at all possible to avoid, I'd rather avoid it.

The ordering we see on delete when the filesystem is mounted with 'sync'
option is:
DELETE CREATE
generic_delete_inode()
set I_FREEING
ext3_delete_inode
get transaction handle
do work
get transaction handle ext3_new_inode()
reallocate inode insert_inode_locked()
stop transaction, wait for it to commit
(waiting for CREATE process to drop its
transaction reference)

Now similar race can happen even without 'sync' mount option but it's
much harder to hit:
DELETE CREATE
generic_delete_inode()
set I_FREEING
ext3_delete_inode
get transaction handle ext3_new_inode()
reallocate inode insert_inode_locked()
try to get transaction handle -
- transaction is too big so we send
current transaction to commit which
again waits for CREATE to drop its
reference.

Honza

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
author Reviewed-by Theodore Ts'o
#18 lore raw

[Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

In reply to [email protected]

http://bugzilla.kernel.org/show_bug.cgi?id=13232

--- Comment #10 from Theodore Tso <[email protected]> 2009-05-18 13:16:04 ---

Quoted 7 lines · Al Viro

OK, that's probably the easiest way to do that, as much as I don't like it... Since iget() et.al. will not accept I_FREEING (will wait to go away and restart), and since we'd better have serialization between new/free on fs data structures anyway, we can afford simply skipping I_FREEING et.al. in insert_inode_locked().

Quoted 6 lines

We do that from new_inode, so it won't race with free_inode in any interesting ways and it won't race with iget (of any origin; nfsd or in case of fs corruption a lookup) since both still will wait for I_LOCK.

Tentative patch follow; folks, I would very much like review on that one, since I'm far too low on caffeine and the area is nasty.

Sorry for not having time to review this until now. This looks good to me.

Reviewed-by "Theodore Ts'o" <[email protected]>

So Bug #13232 is currently marked as a 2.6.28 regression; do we feel confident enough to push this to Linus for 2.6.30?

- Ted

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
author Acked-by Jan Kara
#19 lore raw

[Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

In reply to [email protected]

http://bugzilla.kernel.org/show_bug.cgi?id=13232

--- Comment #11 from Jan Kara <[email protected]> 2009-05-18 14:10:15 ---

Quoted 36 lines · Al Viro
Quoted 21 lines · Al Viro
Quoted 6 lines · Jan Kara
Quoted 6 lines

Here, we have started a transaction in ext3_create() and then wait in
find_inode_fast() for I_FREEING to be cleared (obviously we have reallocated the inode and squeezed the allocation before journal_stop() from the delete was called).
Nasty deadlock and I don't see how to fix it now - have to go home for
today... Tomorrow I'll have a look what we can do about it.

Quoted 13 lines

OK, the deadlock has been introduced by ext3 variant of
261bca86ed4f7f391d1938167624e78da61dcc6b (adding Al to CC). The deadlock is really tough to avoid - we have to first allocate inode on disk so that we know the inode number. For this we need transaction open but we cannot afford waiting for old inode with same INO to be freed when we have transaction open because of the above deadlock. So we'd have to wait for inode release only after everything is done and we closed the transaction. But that would mean reordering a lot of code in ext3/namei.c so that all the dcache handling is done after all the IO is done.
Hmm, maybe we could change the delete side of the deadlock but that's
going to be tricky as well :(.
Al, any idea if we could somehow get away without waiting on
I_FREEING?

Quoted 7 lines

At which point do we actually run into deadlock on delete side? We could, in principle, skip everything like that in insert_inode_locked(), but I would rather avoid the "two inodes in icache at the same time, with the same inumber" situations completely. We might get away with that, since everything else *will* wait, so we can afford a bunch of inodes past the point in foo_delete_inode() that has cleared it in bitmap + new locked one, but if it's at all possible to avoid, I'd rather avoid it.

OK, that's probably the easiest way to do that, as much as I don't like it... Since iget() et.al. will not accept I_FREEING (will wait to go away and restart), and since we'd better have serialization between new/free on fs data structures anyway, we can afford simply skipping I_FREEING et.al. in insert_inode_locked().

Quoted 6 lines

We do that from new_inode, so it won't race with free_inode in any interesting ways and it won't race with iget (of any origin; nfsd or in case of fs corruption a lookup) since both still will wait for I_LOCK.

Tentative patch follow; folks, I would very much like review on that one, since I'm far too low on caffeine and the area is nasty.

The patch looks fine. Everyone else will either get new inode and wait
for I_LOCK or get old inode and wait for I_FREEING so everything should be fine... You can add.

Acked-by Jan Kara <[email protected]>

Honza

Quoted 59 lines
fs/inode.c +25 -6
index 9d26490..4406952 100644
@@ -1053,13 +1053,22 @@ int insert_inode_locked(struct inode *inode)
 	struct super_block *sb = inode->i_sb;
 	ino_t ino = inode->i_ino;
 	struct hlist_head *head = inode_hashtable + hash(sb, ino);
-	struct inode *old;
 
 	inode->i_state |= I_LOCK|I_NEW;
 	while (1) {
+		struct hlist_node *node;
+		struct inode *old = NULL;
 		spin_lock(&inode_lock);
-		old = find_inode_fast(sb, head, ino);
-		if (likely(!old)) {
+		hlist_for_each_entry(old, node, head, i_hash) {
+			if (old->i_ino != ino)
+				continue;
+			if (old->i_sb != sb)
+				continue;
+			if (old->i_state & (I_FREEING|I_CLEAR|I_WILL_FREE))
+				continue;
+			break;
+		}
+		if (likely(!node)) {
 			hlist_add_head(&inode->i_hash, head);
 			spin_unlock(&inode_lock);
 			return 0;

@@ -1081,14 +1090,24 @@ int insert_inode_locked4(struct inode *inode, unsigned long hashval,
 {
 	struct super_block *sb = inode->i_sb;
 	struct hlist_head *head = inode_hashtable + hash(sb, hashval);
-	struct inode *old;
 
 	inode->i_state |= I_LOCK|I_NEW;
 
 	while (1) {
+		struct hlist_node *node;
+		struct inode *old = NULL;
+
 		spin_lock(&inode_lock);
-		old = find_inode(sb, head, test, data);
-		if (likely(!old)) {
+		hlist_for_each_entry(old, node, head, i_hash) {
+			if (old->i_sb != sb)
+				continue;
+			if (!test(old, data))
+				continue;
+			if (old->i_state & (I_FREEING|I_CLEAR|I_WILL_FREE))
+				continue;
+			break;
+		}
+		if (likely(!node)) {
 			hlist_add_head(&inode->i_hash, head);
 			spin_unlock(&inode_lock);
 			return 0;
Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
author
#20 lore raw

[Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

In reply to [email protected]

http://bugzilla.kernel.org/show_bug.cgi?id=13232

--- Comment #12 from Theodore Tso <[email protected]> 2009-05-19 20:38:32 --- Created an attachment (id=21436)
--> (http://bugzilla.kernel.org/attachment.cgi?id=21436)
Proposed patch from Al Viro

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
author
#21 lore raw

[Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

In reply to [email protected]

http://bugzilla.kernel.org/show_bug.cgi?id=13232

Theodore Tso <[email protected]> changed:

What |Removed |Added
----------------------------------------------------------------------------

  Attachment #21436|application/octet-stream    |text/plain
          mime type|                            |
  Attachment #21436|0                           |1
           is patch|                            |
Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
author
#22 lore raw

[Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

In reply to [email protected]

http://bugzilla.kernel.org/show_bug.cgi?id=13232

Theodore Tso <[email protected]> changed:

What |Removed |Added
----------------------------------------------------------------------------
CC| |[email protected]

--- Comment #13 from Theodore Tso <[email protected]> 2009-06-07 19:56:04 --- This patch is now in the upstream kernel, so it will be in 2.6.30.

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
author
#23 lore raw

[Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

In reply to [email protected]

http://bugzilla.kernel.org/show_bug.cgi?id=13232

Theodore Tso <[email protected]> changed:

What |Removed |Added
----------------------------------------------------------------------------

             Status|NEW                         |RESOLVED
         Resolution|                            |CODE_FIX
Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.
author
#24 lore raw

[Bug 13232] ext3/4 with synchronous writes gets wedged by Postfix

In reply to [email protected]

http://bugzilla.kernel.org/show_bug.cgi?id=13232

Rafael J. Wysocki <[email protected]> changed:

What |Removed |Added
----------------------------------------------------------------------------
Status|RESOLVED |CLOSED

Signature · 3 lines
Configure bugmail: http://bugzilla.kernel.org/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are watching the assignee of the bug.