From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1753250AbYAGFd1 (ORCPT ); Mon, 7 Jan 2008 00:33:27 -0500 Received: (majordomo@vger.kernel.org) by vger.kernel.org id S1750954AbYAGFdR (ORCPT ); Mon, 7 Jan 2008 00:33:17 -0500 Received: from mail.gmx.net ([213.165.64.20]:52262 "HELO mail.gmx.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with SMTP id S1754668AbYAGFdO (ORCPT ); Mon, 7 Jan 2008 00:33:14 -0500 X-Authenticated: #14349625 X-Provags-ID: V01U2FsdGVkX19EhLoM7YZEGCjAQ0/2nvheyPbZzKewuKDuP5E26a JBYwD0WpzP5WRc Subject: Re: [vm] writing to UDF DVD+RW (/dev/sr0) while under memory pressure: box ==> doorstop From: Mike Galbraith To: Andrew Morton Cc: LKML In-Reply-To: <20080106122954.d8f04c98.akpm@linux-foundation.org> References: <1199447212.4529.13.camel@homer.simson.net> <1199612533.4384.54.camel@homer.simson.net> <1199642470.3927.12.camel@homer.simson.net> <20080106122954.d8f04c98.akpm@linux-foundation.org> Content-Type: text/plain Date: Mon, 07 Jan 2008 06:33:08 +0100 Message-Id: <1199683988.3718.49.camel@homer.simson.net> Mime-Version: 1.0 X-Mailer: Evolution 2.12.0 Content-Transfer-Encoding: 7bit X-Y-GMX-Trusted: 0 Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Sun, 2008-01-06 at 12:29 -0800, Andrew Morton wrote: > On Sun, 06 Jan 2008 19:01:10 +0100 Mike Galbraith wrote: > > > > > On Sun, 2008-01-06 at 10:42 +0100, Mike Galbraith wrote: > > > FWIW, here's box having same seizure writing to /dev/pktcdvd/sr0. > > > > Ugh, horrid device IO ==> horrid VM AFIKT. I'll continue rummaging, but > > I wonder, am I doing something _so_ stupid as to warrant zero response? > > > > Copying linux-mm might have helped. Bad time of year, too. Thanks for the reply, I was getting alll paranoid that I was being really dense, ergo the ping. > >From the traces it looks like all IO has stopped and everyone is waiting > (directly or indirectly) for certain IO completions. Is that really true, > or is IO still dribbling along? It's dribbling along. I drastically improved the situation by bouncing people off the exclusion wall instead of synchronizing, but the poor sod who acquires prune_mutex is in purgatory for a very long time. (undoes butchery) > >From the kswapd0 trace it would appear that UDF is doing synchronous writes > (udf_update_inode->sync_dirty_buffer) which perhaps is making things > mightily slow. Even synchronous writes shouldn't cause minutes long hangs surely :) This /dev/sr0 IO seems to be getting jammed up something terrible. I formatted the dvd ext2 and tried the same copy. It didn't jam up the whole box (well, yet, it's still zooming along at mach 0.0000000001) doing parallel kbuilds, but when I started a bonnie, the poor thing instantly got nailed to the floor. I kill -9'd it about a half an hour ago, and it has yet to respond. Every now and again there's a burst of activity from cp, but bonnie is stuck for the duration it seems. I'll find out. The 515MB cp finished after an hour and change. When bonnie exits I'll be able to see what the throughput was. bonnie finally exited. uptime is now 1:22. cp started right after boot... throughput very bad. I would almost swear I copied to that dvd drive when it was /dev/hdc (before I upgraded to openSuSE 10.3 and got all modern) and it worked well enough to not attract my attention. I guess I need to figure out how to reacquire /dev/hdc and try again. [ 1687.358723] SysRq : Show Blocked State [ 1687.358729] task PC stack pid father [ 1687.358729] pdflush D 00000140 0 156 2 [ 1687.358729] ee172de4 00000046 e0791550 00000140 00000008 00000000 00000000 00b00000 [ 1687.358729] b0d3bb78 00000188 b040d300 b040d300 ef8ab5f0 ef8ab83c b180c300 ee172000 [ 1687.358729] 00000000 ee2c5550 ef9cb200 ee2c5550 00000003 00000000 ef871ee4 0041706e [ 1687.358729] Call Trace: [ 1687.358729] [] io_schedule+0x4f/0x89 [ 1687.358729] [] sync_buffer+0x30/0x34 [ 1687.358729] [] __wait_on_bit+0x42/0x5e [ 1687.358729] [] sync_buffer+0x0/0x34 [ 1687.358729] [] out_of_line_wait_on_bit+0x67/0x6f [ 1687.358729] [] sync_buffer+0x0/0x34 [ 1687.358729] [] wake_bit_function+0x0/0x3c [ 1687.358729] [] __wait_on_buffer+0x24/0x29 [ 1687.358729] [] __bread+0x55/0x8a [ 1687.358729] [] ext2_get_inode+0xbe/0x109 [ext2] [ 1687.358729] [] ext2_update_inode+0x39/0x331 [ext2] [ 1687.358729] [] mpage_bio_submit+0x19/0x1d [ 1687.358729] [] ext2_get_block+0x0/0x761 [ext2] [ 1687.358729] [] __writeback_single_inode+0x228/0x306 [ 1687.358729] [] apic_timer_interrupt+0x28/0x30 [ 1687.358729] [] _atomic_dec_and_lock+0x31/0x5c [ 1687.358729] [] sync_sb_inodes+0x1c3/0x294 [ 1687.358729] [] writeback_inodes+0x7d/0xac [ 1687.358729] [] background_writeout+0x98/0xb7 [ 1687.358729] [] pdflush+0x0/0x1d4 [ 1687.358730] [] pdflush+0x107/0x1d4 [ 1687.358730] [] background_writeout+0x0/0xb7 [ 1687.358730] [] kthread+0x34/0x56 [ 1687.358730] [] kthread+0x0/0x56 [ 1687.358730] [] kernel_thread_helper+0x7/0x1c [ 1687.358730] ======================= [ 1687.358730] hald-addon-st D ee990bc0 0 2330 2284 [ 1687.358730] ee990bd4 00000082 00000002 ee990bc0 ee990bb8 00000000 00000000 8334c2ad [ 1687.358730] 00000273 b180c300 b040d300 b040d300 ee21c8b0 ee21cafc b180c300 ee990000 [ 1687.358730] ee990be8 00000000 ee398740 00248b9d ee2c5550 ee2c5550 00000000 00000003 [ 1687.358730] Call Trace: [ 1687.358730] [] schedule_timeout+0x69/0xa1 [ 1687.358730] [] scsi_request_fn+0x210/0x351 [scsi_mod] [ 1687.358730] [] del_timer+0x52/0x5a [ 1687.358730] [] cfq_set_request+0xc2/0x2ff [ 1687.358730] [] wait_for_common+0x6a/0x101 [ 1687.358730] [] default_wake_function+0x0/0xc [ 1687.358730] [] blk_execute_rq+0x72/0xb3 [ 1687.358730] [] blk_end_sync_rq+0x0/0x23 [ 1687.358730] [] default_wake_function+0x0/0xc [ 1687.358730] [] get_request_wait+0x1b/0x173 [ 1687.358730] [] scsi_execute+0xc7/0xdb [scsi_mod] [ 1687.358730] [] scsi_execute_req+0x6d/0xd0 [scsi_mod] [ 1687.358730] [] scsi_test_unit_ready+0x56/0x95 [scsi_mod] [ 1687.358730] [] sr_media_change+0x3a/0x223 [sr_mod] [ 1687.358730] [] sr_drive_status+0x53/0x65 [sr_mod] [ 1687.358730] [] scsi_test_unit_ready+0x56/0x95 [scsi_mod] [ 1687.358730] [] media_changed+0x47/0x7e [cdrom] [ 1687.358730] [] cdrom_ioctl+0x275/0xdca [cdrom] [ 1687.358730] [] __link_path_walk+0x9ea/0xd06 [ 1687.358730] [] media_changed+0x47/0x7e [cdrom] [ 1687.358730] [] sr_block_ioctl+0x47/0x80 [sr_mod] [ 1687.358730] [] blkdev_driver_ioctl+0x55/0x5e [ 1687.358730] [] blkdev_ioctl+0x217/0x7c8 [ 1687.358730] [] get_unused_fd_flags+0xb5/0xce [ 1687.358730] [] kobject_get+0xf/0x13 [ 1687.358730] [] get_disk+0x1b/0x80 [ 1687.358730] [] exact_lock+0x7/0xd [ 1687.358730] [] kobj_lookup+0x157/0x172 [ 1687.358730] [] kobject_get+0xf/0x13 [ 1687.358730] [] sr_block_open+0x70/0x81 [sr_mod] [ 1687.358730] [] do_open+0xb5/0x28b [ 1687.358730] [] blkdev_open+0x25/0x53 [ 1687.358730] [] __dentry_open+0x17f/0x1d9 [ 1687.358730] [] nameidata_to_filp+0x31/0x3a [ 1687.358730] [] blkdev_open+0x0/0x53 [ 1687.358730] [] do_filp_open+0x39/0x40 [ 1687.358730] [] check_pgt_cache+0x1b/0x1f [ 1687.358730] [] block_ioctl+0x18/0x1d [ 1687.358730] [] block_ioctl+0x0/0x1d [ 1687.358730] [] do_ioctl+0x1f/0x6d [ 1687.358730] [] vfs_ioctl+0x203/0x27f [ 1687.358730] [] do_sys_open+0xab/0xc0 [ 1687.358730] [] sys_ioctl+0x56/0x68 [ 1687.358730] [] sysenter_past_esp+0x5f/0x85 [ 1687.358730] ======================= [ 1687.358730] cp D b011fcc6 0 4301 3844 [ 1687.358730] cc4b4b94 00200082 b180c300 b011fcc6 30cf0ee6 00000008 00000000 00000000 [ 1687.358730] b0d3bb7a 00000188 b040d300 b040d300 ee1b18f0 ee1b1b3c b180c300 cc4b4000 [ 1687.358730] b1809a40 ee2c5550 edd57740 ee2c5550 00000004 00000000 ef824558 0041706e [ 1687.358730] Call Trace: [ 1687.358730] [] hrtick_start_fair+0xa8/0x150 [ 1687.358730] [] io_schedule+0x4f/0x89 [ 1687.358730] [] sync_buffer+0x30/0x34 [ 1687.358730] [] __wait_on_bit_lock+0x3d/0x5f [ 1687.358730] [] sync_buffer+0x0/0x34 [ 1687.358730] [] out_of_line_wait_on_bit_lock+0x67/0x6f [ 1687.358730] [] sync_buffer+0x0/0x34 [ 1687.358730] [] wake_bit_function+0x0/0x3c [ 1687.358730] [] __lock_buffer+0x29/0x2e [ 1687.358730] [] __bread+0x77/0x8a [ 1687.358730] [] ext2_get_inode+0xbe/0x109 [ext2] [ 1687.358730] [] ext2_update_inode+0x39/0x331 [ext2] [ 1687.358730] [] mpage_bio_submit+0x19/0x1d [ 1687.358730] [] ext2_get_block+0x0/0x761 [ext2] [ 1687.358730] [] __writeback_single_inode+0x228/0x306 [ 1687.358730] [] _atomic_dec_and_lock+0x31/0x5c [ 1687.358730] [] sync_sb_inodes+0x1c3/0x294 [ 1687.358730] [] writeback_inodes+0x7d/0xac [ 1687.358730] [] balance_dirty_pages_ratelimited_nr+0x21f/0x33f [ 1687.358730] [] generic_file_buffered_write+0x1c1/0x655 [ 1687.358730] [] ext3_readpages+0x0/0x15 [ext3] [ 1687.358730] [] __generic_file_aio_write_nolock+0x2ad/0x50d [ 1687.358730] [] current_fs_time+0x13/0x15 [ 1687.358730] [] generic_file_aio_write+0x65/0xd3 [ 1687.358730] [] do_sync_write+0xd2/0x10e [ 1687.358730] [] tick_sched_timer+0x0/0xbf [ 1687.358730] [] autoremove_wake_function+0x0/0x35 [ 1687.358730] [] do_sync_write+0x0/0x10e [ 1687.358730] [] vfs_write+0xa4/0x14a [ 1687.358730] [] sys_write+0x41/0x6a [ 1687.358730] [] sysenter_past_esp+0x5f/0x85 [ 1687.358730] ======================= [ 1687.358730] bonnie D eee95dcc 0 5328 3749 [ 1687.358730] eee95de0 00200086 00000002 eee95dcc eee95dc4 00000000 00000000 b0145bda [ 1687.358730] 3c876200 eee95da8 b040d300 b040d300 e16c2470 e16c26bc b180c300 eee95000 [ 1687.358730] 000004b3 ee2c5550 edd573c0 0024876a b01dc8d2 b01436cd 00000000 00000003 [ 1687.358730] Call Trace: [ 1687.358730] [] clockevents_program_event+0x9a/0x12e [ 1687.358730] [] generic_unplug_device+0x15/0x21 [ 1687.358730] [] getnstimeofday+0x2f/0xd7 [ 1687.358730] [] io_schedule+0x4f/0x89 [ 1687.358730] [] sync_buffer+0x30/0x34 [ 1687.358730] [] __wait_on_bit_lock+0x3d/0x5f [ 1687.358730] [] sync_buffer+0x0/0x34 [ 1687.358730] [] out_of_line_wait_on_bit_lock+0x67/0x6f [ 1687.358730] [] sync_buffer+0x0/0x34 [ 1687.358730] [] wake_bit_function+0x0/0x3c [ 1687.358730] [] __lock_buffer+0x29/0x2e [ 1687.358730] [] __bread+0x77/0x8a [ 1687.358730] [] ext2_get_inode+0xbe/0x109 [ext2] [ 1687.358730] [] ext2_update_inode+0x39/0x331 [ext2] [ 1687.358730] [] mpage_bio_submit+0x19/0x1d [ 1687.358730] [] ext2_get_block+0x0/0x761 [ext2] [ 1687.358730] [] __writeback_single_inode+0x228/0x306 [ 1687.358730] [] find_get_pages_tag+0x75/0x84 [ 1687.358730] [] reschedule_interrupt+0x28/0x30 [ 1687.358730] [] _atomic_dec_and_lock+0x31/0x5c [ 1687.358730] [] sync_sb_inodes+0x1c3/0x294 [ 1687.358730] [] sync_inodes_sb+0x7e/0x8f [ 1687.358730] [] __sync_inodes+0x76/0xa5 [ 1687.358730] [] sync_inodes+0x11/0x2c [ 1687.358730] [] do_sync+0x14/0x63 [ 1687.358730] [] sys_sync+0xa/0x17 [ 1687.358730] [] sysenter_past_esp+0x5f/0x85 [ 1687.358730] ======================= [ 1687.358730] pdflush D ee25dee0 0 14924 2 [ 1687.358730] ee25def4 00000046 00000002 ee25dee0 ee25ded8 00000000 00000000 b03a53c0 [ 1687.358730] aadc0469 00000188 b040d300 b040d300 dc20ce30 dc20d07c b180c300 ee25d000 [ 1687.358730] 00000202 b0443e00 ee244c80 002491c9 ee25df04 b0134a01 ffffffff 00000003 [ 1687.358730] Call Trace: [ 1687.358730] [] process_timeout+0x0/0x5 [ 1687.358730] [] schedule_timeout+0x44/0xa1 [ 1687.358730] [] process_timeout+0x0/0x5 [ 1687.358730] [] schedule_timeout+0x3f/0xa1 [ 1687.358730] [] io_schedule_timeout+0x54/0x93 [ 1687.358730] [] congestion_wait+0x4d/0x61 [ 1687.358730] [] autoremove_wake_function+0x0/0x35 [ 1687.358730] [] wb_kupdate+0x9c/0xe2 [ 1687.358730] [] pdflush+0x0/0x1d4 [ 1687.358730] [] pdflush+0x107/0x1d4 [ 1687.358730] [] wb_kupdate+0x0/0xe2 [ 1687.358730] [] kthread+0x34/0x56 [ 1687.358730] [] kthread+0x0/0x56 [ 1687.358730] [] kernel_thread_helper+0x7/0x1c [ 1687.358730] =======================