Re: Lockup in wait_transaction_locked under memory pressure

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Today I observed the issue again, this time on a different server. What
is particularly strange is the fact that the OOM wasn't triggered for
the cgroup, whose tasks have entered D state. There were a couple of
SSHD processes and an RSYNC performing some backup tasks. Here is what
the stacktrace for the rsync looks like:

crash> set 18308
    PID: 18308
COMMAND: "rsync"
   TASK: ffff883d7c9b0a30  [THREAD_INFO: ffff881773748000]
    CPU: 1
  STATE: TASK_UNINTERRUPTIBLE
crash> bt
PID: 18308  TASK: ffff883d7c9b0a30  CPU: 1   COMMAND: "rsync"
 #0 [ffff88177374ac60] __schedule at ffffffff815ab152
 #1 [ffff88177374acb0] schedule at ffffffff815ab76e
 #2 [ffff88177374acd0] schedule_timeout at ffffffff815ae5e5
 #3 [ffff88177374ad70] io_schedule_timeout at ffffffff815aad6a
 #4 [ffff88177374ada0] bit_wait_io at ffffffff815abfc6
 #5 [ffff88177374adb0] __wait_on_bit at ffffffff815abda5
 #6 [ffff88177374ae00] wait_on_page_bit at ffffffff8111fd4f
 #7 [ffff88177374ae50] shrink_page_list at ffffffff81135445
 #8 [ffff88177374af50] shrink_inactive_list at ffffffff81135845
 #9 [ffff88177374b060] shrink_lruvec at ffffffff81135ead
#10 [ffff88177374b150] shrink_zone at ffffffff811360c3
#11 [ffff88177374b220] shrink_zones at ffffffff81136eff
#12 [ffff88177374b2a0] do_try_to_free_pages at ffffffff8113712f
#13 [ffff88177374b300] try_to_free_mem_cgroup_pages at ffffffff811372be
#14 [ffff88177374b380] try_charge at ffffffff81189423
#15 [ffff88177374b430] mem_cgroup_try_charge at ffffffff8118c6f5
#16 [ffff88177374b470] __add_to_page_cache_locked at ffffffff8112137d
#17 [ffff88177374b4e0] add_to_page_cache_lru at ffffffff81121618
#18 [ffff88177374b510] pagecache_get_page at ffffffff8112170b
#19 [ffff88177374b560] grow_dev_page at ffffffff811c8297
#20 [ffff88177374b5c0] __getblk_slow at ffffffff811c91d6
#21 [ffff88177374b600] __getblk_gfp at ffffffff811c92c1
#22 [ffff88177374b630] ext4_ext_grow_indepth at ffffffff8124565c
#23 [ffff88177374b690] ext4_ext_create_new_leaf at ffffffff81246ca8
#24 [ffff88177374b6e0] ext4_ext_insert_extent at ffffffff81246f09
#25 [ffff88177374b750] ext4_ext_map_blocks at ffffffff8124a848
#26 [ffff88177374b870] ext4_map_blocks at ffffffff8121a5b7
#27 [ffff88177374b910] mpage_map_one_extent at ffffffff8121b1fa
#28 [ffff88177374b950] mpage_map_and_submit_extent at ffffffff8121f07b
#29 [ffff88177374b9b0] ext4_writepages at ffffffff8121f6d5
#30 [ffff88177374bb20] do_writepages at ffffffff8112c490
#31 [ffff88177374bb30] __filemap_fdatawrite_range at ffffffff81120199
#32 [ffff88177374bb80] filemap_flush at ffffffff8112041c
#33 [ffff88177374bb90] ext4_alloc_da_blocks at ffffffff81219da1
#34 [ffff88177374bbb0] ext4_rename at ffffffff81229b91
#35 [ffff88177374bcd0] ext4_rename2 at ffffffff81229e32
#36 [ffff88177374bce0] vfs_rename at ffffffff811a08a5
#37 [ffff88177374bd60] SYSC_renameat2 at ffffffff811a3ffc
#38 [ffff88177374bf60] sys_renameat2 at ffffffff811a408e
#39 [ffff88177374bf70] sys_rename at ffffffff8119e51e
#40 [ffff88177374bf80] system_call_fastpath at ffffffff815afa89
    RIP: 00002ba0169b61d7  RSP: 00007ffde830f428  RFLAGS: 00000206
    RAX: ffffffffffffffda  RBX: ffffffff815afa89  RCX: 00002ba016a2e007
    RDX: 0000000000000000  RSI: 00007ffde83126f0  RDI: 00007ffde83106f0
    RBP: 00007ffde83106f0   R8: 0000000000000000   R9: 0000000000000000
    R10: 0000000000000000  R11: 0000000000000202  R12: ffffffff8119e51e
    R13: ffff88177374bf78  R14: ffffffff811a408e  R15: ffff88177374bf68
    ORIG_RAX: 0000000000000052  CS: 0033  SS: 002b


All the other processes in the container have locked up when trying to
access file system resources. The SSHD processes for example have
blocked on tryng to access /var/log/btmp:

PID: 11919  TASK: ffff8815613c1460  CPU: 2   COMMAND: "sshd"
 #0 [ffff880158d03c70] __schedule at ffffffff815ab152
 #1 [ffff880158d03cc0] schedule at ffffffff815ab76e
 #2 [ffff880158d03ce0] schedule_preempt_disabled at ffffffff815ab9de
 #3 [ffff880158d03cf0] __mutex_lock_slowpath at ffffffff815ad505
 #4 [ffff880158d03d50] mutex_lock at ffffffff815ad59b
 #5 [ffff880158d03d70] ext4_file_write_iter at ffffffff8121477b
 #6 [ffff880158d03e30] new_sync_write at ffffffff81194047
 #7 [ffff880158d03f00] vfs_write at ffffffff8119445e
 #8 [ffff880158d03f30] sys_write at ffffffff81194bda
 #9 [ffff880158d03f80] system_call_fastpath at ffffffff815afa89
    RIP: 00002adf56857790  RSP: 00007fffaf514788  RFLAGS: 00000206
    RAX: ffffffffffffffda  RBX: ffffffff815afa89  RCX: 00002adf568657f7
    RDX: 0000000000000180  RSI: 00007fffaf5147a0  RDI: 0000000000000005
    RBP: 0000000000000005   R8: 00002adf53ebf7a0   R9: 0000000080000000
    R10: 0000000000000001  R11: 0000000000000246  R12: 00007fffaf514740
    R13: 0000000000000180  R14: 0000000000000000  R15: 00007fffaf5147a0
    ORIG_RAX: 0000000000000001  CS: 0033  SS: 002b

Except for one which has blocked with the following stack:
PID: 7833   TASK: ffff88175b3ba8c0  CPU: 3   COMMAND: "sshd"
 #0 [ffff88001d983960] __schedule at ffffffff815ab152
 #1 [ffff88001d9839b0] schedule at ffffffff815ab76e
 #2 [ffff88001d9839d0] wait_transaction_locked at ffffffff81264265
 #3 [ffff88001d983a30] add_transaction_credits at ffffffff81264540
 #4 [ffff88001d983ab0] start_this_handle at ffffffff81264824
 #5 [ffff88001d983b60] jbd2__journal_start at ffffffff81265220
 #6 [ffff88001d983bc0] __ext4_journal_start_sb at ffffffff8124bb49
 #7 [ffff88001d983c10] ext4_dirty_inode at ffffffff8121da5c
 #8 [ffff88001d983c30] __mark_inode_dirty at ffffffff811be5c3
 #9 [ffff88001d983c70] generic_update_time at ffffffff811ae9c5
#10 [ffff88001d983cb0] file_update_time at ffffffff811ae632
#11 [ffff88001d983d10] __generic_file_write_iter at ffffffff811226c2
#12 [ffff88001d983d70] ext4_file_write_iter at ffffffff81214814
#13 [ffff88001d983e30] new_sync_write at ffffffff81194047
#14 [ffff88001d983f00] vfs_write at ffffffff8119445e
#15 [ffff88001d983f30] sys_write at ffffffff81194bda
#16 [ffff88001d983f80] system_call_fastpath at ffffffff815afa89
    RIP: 00002adf56857790  RSP: 00007fffaf514788  RFLAGS: 00000206
    RAX: ffffffffffffffda  RBX: ffffffff815afa89  RCX: 00002adf568657f7
    RDX: 0000000000000180  RSI: 00007fffaf5147a0  RDI: 0000000000000005
    RBP: 0000000000000005   R8: 00002adf53ebf7a0   R9: 0000000080000000
    R10: 0000000000000001  R11: 0000000000000246  R12: 00007fffaf514740
    R13: 0000000000000180  R14: 0000000000000000  R15: 00007fffaf5147a0
    ORIG_RAX: 0000000000000001  CS: 0033  SS: 002b


So basically what I have managed to determine so far is that "something"
(this is the bit which I've yet to uncover, hopefully with your help)
starves the file system of resources. Which causes processes to block in
the jbd2_journal_start path. The other SSHD processes essentially block
on the i_mutex of the /var/log/btmp (nothing unusual).

So I guess the most interesting bit here is the stack of the rsync
process, so it is blocking on trying to free some pages, yet the OOM
hasn't triggered. Also, I did try increasing the memory of the cgroup
from 6 to 8 gigs and nothing changes (and this is logical when you think
about it, since everything is in D, state).

Currently, our only way to fix issue like that is to restart the whole
node since there is no way to forcefully remove the block device the
file system is hosted on (which is a device mapper target).



--
To unsubscribe from this list: send the line "unsubscribe linux-ext4" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html



[Index of Archives]     [Reiser Filesystem Development]     [Ceph FS]     [Kernel Newbies]     [Security]     [Netfilter]     [Bugtraq]     [Linux FS]     [Yosemite National Park]     [MIPS Linux]     [ARM Linux]     [Linux Security]     [Linux RAID]     [Samba]     [Device Mapper]     [Linux Media]

  Powered by Linux