Re: kernel messages. Re: reiser4 firefox hangs due to fsync, sysrq-t dump

[butdiene <butdiene@yahoo.com>]

I disabled reiser4-config and compile kernel again, then I got firefox hang
again, following are kernel messages,

Dec 30 07:03:03 localhost kernel: edward-1555: atom ffff8100bcb1cb00 has
max_nr_pointers (12)
Dec 30 07:03:03 localhost kernel: edward-1555: atom ffff8100bcb1c940 has
max_nr_pointers (21)
Dec 30 07:03:03 localhost kernel: edward-1555: atom ffff8100bd217780 has
max_nr_pointers (85)
Dec 30 07:03:04 localhost kernel: edward-1555: atom ffff8100bd2175c0 has
max_nr_pointers (257)
Dec 30 07:04:02 localhost kernel: edward-1555: atom ffff8100bcb1ccc0 has
max_nr_pointers (258)
Dec 30 07:04:05 localhost kernel: edward-1555: atom ffff8100bd2175c0 has
max_nr_pointers (479)
Dec 30 07:07:03 localhost kernel: edward-1555: atom ffff8100acf294c0 has
max_nr_pointers (517)
Dec 30 07:07:36 localhost kernel: edward-1555: atom ffff810096f3b100 has
max_nr_pointers (1338)
Dec 30 07:07:41 localhost kernel: edward-1555: atom ffff810095d50d00 has
max_nr_pointers (2874)
Dec 30 07:07:46 localhost kernel: edward-1555: atom ffff810095ed9800 has
max_nr_pointers (4434)
Dec 30 07:07:51 localhost kernel: edward-1555: atom ffff810095ff2600 has
max_nr_pointers (5810)
Dec 30 07:07:57 localhost kernel: edward-1555: atom ffff81009592d380 has
max_nr_pointers (6640)
Dec 30 07:08:01 localhost kernel: edward-1555: atom ffff810095afaa80 has
max_nr_pointers (7931)
Dec 30 07:08:06 localhost kernel: edward-1555: atom ffff810095bf0640 has
max_nr_pointers (9156)
Dec 30 07:08:11 localhost kernel: edward-1555: atom ffff810095d5f300 has
max_nr_pointers (9474)
Dec 30 07:08:16 localhost kernel: edward-1555: atom ffff8100961919c0 has
max_nr_pointers (11512)
Dec 30 07:08:18 localhost kernel: edward-1555: atom ffff810096192a00 has
max_nr_pointers (11530)
Dec 30 07:08:21 localhost kernel: edward-1555: atom ffff810096192a00 has
max_nr_pointers (13947)


butdiene wrote:
> 
> Hi Edward,
> 
> the small patch make it impossible for me to get firefox hang for session
> 1. or I should say it may hang for seconds, but wake up when the hard
> drive still busy, while previously, firefox never wakes up unless the hdd
> is idle again, and firefox usually hangs for minutes instead of seconds.
> nevertheless, I get kernel messages from /var/log/messages for whatever I
> tried but failed to hang firefox,
> 
> I removed custom mount options, so /proc/mounts is the same for both
> sessions,
> /dev/root / reiser4
> rw,atom_max_size=0x2f20c,atom_max_age=0x927c0,atom_min_size=0x100,atom_max_flushers=0x1,cbk_cache_slots=0x10
> 0 0
> 
> session1, kernel messages (I post only the debug messages from the patch),
> if you would like to read the whole thing, let me know:
> 
>  http://www.nabble.com/file/p14546580/kernel-messages1 kernel-messages1 
> 
> session 2:
> 
> I did dd for 12GB, for my 3GB ram: dd if=/dev/zero of=/tmp/tmp-dump.txt
> bs=65536 count=196608 && sync
> 
> mount options are the same as in session 1, and system rebooted between
> these two sessions.
> 
> kernel messages:  http://www.nabble.com/file/p14546580/kernel-messages2
> kernel-messages2 
> 
> also, the patch doesn't apply cleanly, since I'm not user -mm source, the
> following is the patch from my manual editing:
> 
>  http://www.nabble.com/file/p14546580/reiser4-shishkin.patch
> reiser4-shishkin.patch 
> 
> thanks!
> 
> 
> Edward Shishkin-2 wrote:
>> 
>> On 12/29/07, butdiene <butdiene@yahoo.com> wrote:
>>>
>>> I'm not sure about what I'm doing. with a patch for
>>> optimal_io_size=4096*1024
>>> and atom_max_size=0x800, it improves a lot.
>> 
>> Not sure about it: reiser4 just keeps the optimal_io_size in a superblock
>> to return this for stat, fstat (2), etc., and doesn't use if for anything
>> else.
>> Maybe firefox uses it somehow - I didn't investigate.
>> 
>> The following is a stacktrace where your firefox hangs. It seems there is
>> an atom size "leak". To confirm it, please apply the attached patch and
>> perform 2 working sessions (better with REISER4_DEBUG is on):
>> session 1:
>> just reproduce the firefox hang;
>> session 2:
>> dd if=/dev/zero of=xxx bs=65536 count=yyy && sync
>> where xxx - a file on your root partition, yyy is a count to write ~4
>> amount
>> of RAM (if possible).
>> Reboot before each session. Send me kernel messages for both sessions
>> with cat /proc/mounts output.
>> 
>> Thanks,
>> Edward.
>> 
>> Dec 26 17:40:49 localhost firefox-bin   D ffff810073495c78     0  8030  
>> 8011
>> Dec 26 17:40:49 localhost ffff810073495be8 0000000000000086
>> ffff81005ce39728 ffff81005ce39728
>> Dec 26 17:40:49 localhost ffff8100bf0b4dd0 ffff810073495b98
>> 0000000000000008 ffffffff806b4c00
>> Dec 26 17:40:49 localhost ffffffff806b4c00 ffffffff806b1c00
>> ffffffff806b4c00 ffff8100b3a80140
>> Dec 26 17:40:49 localhost Call Trace:
>> Dec 26 17:40:49 localhost [<ffffffff802580f1>] sync_page+0x0/0x42
>> Dec 26 17:40:49 localhost [<ffffffff804d36f0>] io_schedule+0x28/0x34
>> Dec 26 17:40:49 localhost [<ffffffff8025812f>] sync_page+0x3e/0x42
>> Dec 26 17:40:49 localhost [<ffffffff804d3c27>] __wait_on_bit+0x40/0x6e
>> Dec 26 17:40:49 localhost [<ffffffff802582ab>] wait_on_page_bit+0x6c/0x72
>> Dec 26 17:40:49 localhost [<ffffffff80246b70>] wake_bit_function+0x0/0x23
>> Dec 26 17:40:49 localhost [<ffffffff802b8b78>] jwait_io+0x25/0x37
>> Dec 26 17:40:49 localhost [<ffffffff802c97a7>]
>> reiser4_write_logs+0x988/0xbee
>> Dec 26 17:40:49 localhost [<ffffffff802c35c9>]
>> get_current_atom_locked_nocheck+0x37/0x3e
>> Dec 26 17:40:49 localhost [<ffffffff802c3a10>]
>> reiser4_txn_end+0x355/0x4e5
>> Dec 26 17:40:49 localhost [<ffffffff802c28ea>]
>> reiser4_atom_wait_event+0x9a/0xa1
>> Dec 26 17:40:49 localhost [<ffffffff802c3ba9>]
>> reiser4_txn_restart+0x9/0x17
>> Dec 26 17:40:49 localhost [<ffffffff802c3c13>]
>> force_commit_atom+0x47/0x4b
>> Dec 26 17:40:49 localhost [<ffffffff802c3e75>]
>> txnmgr_force_commit_all+0xbb/0x130
>> Dec 26 17:40:49 localhost [<ffffffff802d5780>]
>> reiser4_sync_common+0x37/0x57
>> Dec 26 17:40:49 localhost [<ffffffff802965b6>] do_fsync+0x52/0x88
>> Dec 26 17:40:49 localhost [<ffffffff8029660f>] __do_fsync+0x23/0x36
>> Dec 26 17:40:49 localhost [<ffffffff8020b76e>] system_call+0x7e/0x83
>> Dec 26 17:40:49 localhost
>> 
>>>
>>> /dev/root / reiser4
>>> rw,atom_max_size=0x800,atom_max_age=0x927c0,atom_min_size=0x100,atom_max_flushers=0x1,cbk_cache_slots=0x10
>>> 0 0
>>>
>>>
>>> --- linux.0/fs/reiser4/reiser4.h        2007-12-28 16:30:59.000000000
>>> -0600
>>> +++ linux.1/fs/reiser4/reiser4.h        2007-12-28 16:31:40.000000000
>>> -0600
>>> @@ -197,7 +197,7 @@
>>>
>>>     Can be overwritten by optimal_io_size mount option.
>>>  */
>>> -#define REISER4_OPTIMAL_IO_SIZE (64 * 1024)
>>> +#define REISER4_OPTIMAL_IO_SIZE (4096 * 1024)
>>>
>>>  /* see comments in inode.c:oid_to_uino() */
>>>  #define REISER4_UINO_SHIFT (1 << 30)
>>>
>>>
>>>
>>>
>>> butdiene wrote:
>>> >
>>> > Hi,
>>> >
>>> > the file contains several sysrq-t dumps when firefox hangs,
>>> >
>>> >  http://www.nabble.com/file/p14514445/reiser4-sysrq-t.txt.bz2
>>> > reiser4-sysrq-t.txt.bz2
>>> >
>>> > thanks!
>>> >
>>>
>>> --
>>> View this message in context:
>>> http://www.nabble.com/reiser4-firefox-hangs-due-to-fsync%2C-sysrq-t-dump-tp14514445p14533387.html
>>> Sent from the ReiserFS - General mailing list archive at Nabble.com.
>>>
>>> -
>>> To unsubscribe from this list: send the line "unsubscribe
>>> reiserfs-devel" in
>>> the body of a message to majordomo@vger.kernel.org
>>> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>>>
>> 
>> diff -urN linux-2.6.23-mm1-orig/fs/reiser4/super.h
>> linux-2.6.23-mm1/fs/reiser4/super.h
>> --- linux-2.6.23-mm1-orig/fs/reiser4/super.h	2007-12-29
>> 19:53:04.837605194 +0300
>> +++ linux-2.6.23-mm1/fs/reiser4/super.h	2007-12-29 20:04:11.136691674
>> +0300
>> @@ -262,7 +262,7 @@
>>  
>>  	/* operations for objects on this file system */
>>  	struct object_ops ops;
>> -
>> +	__u32 atom_max_nrpointers;
>>  	/*
>>  	 * structure to maintain d_cursors. See plugin/file_ops_readdir.c for
>>  	 * more details
>> diff -urN linux-2.6.23-mm1-orig/fs/reiser4/txnmgr.c
>> linux-2.6.23-mm1/fs/reiser4/txnmgr.c
>> --- linux-2.6.23-mm1-orig/fs/reiser4/txnmgr.c	2007-12-29
>> 19:53:04.869613413 +0300
>> +++ linux-2.6.23-mm1/fs/reiser4/txnmgr.c	2007-12-29 22:02:40.671070164
>> +0300
>> @@ -1235,6 +1235,30 @@
>>  	    atom->txnh_count == atom->nr_waiters && atom_should_commit(atom);
>>  }
>>  
>> +static void check_print_atom_nrpointers (txn_atom * atom)
>> +{
>> +	reiser4_super_info_data *sbinfo = get_current_super_private();
>> +
>> +	spin_lock_reiser4_super(sbinfo);
>> +	if ((unsigned)atom_pointer_count(atom) > sbinfo->atom_max_nrpointers) {
>> +		sbinfo->atom_max_nrpointers = atom_pointer_count(atom);
>> +#if REISER4_DEBUG
>> +		printk("edward-1555: atom %p has max_nr_pointers (%d), clean (%d),
>> dirty (%d)\n",
>> +		       atom, atom_pointer_count(atom), atom->clean, atom->dirty);
>> +#else
>> +		printk("edward-1555: atom %p has max_nr_pointers (%d)\n",
>> +		       atom, atom_pointer_count(atom));
>> +#endif
>> +	}
>> +	if (atom_is_committable(atom) &&
>> +	    (unsigned)atom_pointer_count(atom) == sbinfo->atom_max_nrpointers)
>> {
>> +		printk("edward-1556: commit atom %p with max nrpointers %d\n",
>> +		       atom, sbinfo->atom_max_nrpointers);
>> +		dump_stack();
>> +	}
>> +	spin_unlock_reiser4_super(sbinfo);
>> +}
>> +
>>  /* called periodically from ktxnmgrd to commit old atoms. Releases
>> ktxnmgrd spin
>>   * lock at exit */
>>  int commit_some_atoms(txn_mgr * mgr)
>> @@ -1264,6 +1288,7 @@
>>  		 * first test without taking atom spin lock, whether it is
>>  		 * eligible for committing at all
>>  		 */
>> +		check_print_atom_nrpointers(atom);
>>  		if (atom_is_committable(atom)) {
>>  			/* now, take spin lock and re-check */
>>  			spin_lock_atom(atom);
>> @@ -1683,7 +1708,7 @@
>>  			   flusher */
>>  			reiser4_atom_set_stage(cd->atom, ASTAGE_CAPTURE_WAIT);
>>  			cd->atom->flags |= ATOM_FORCE_COMMIT;
>> -
>> +			check_print_atom_nrpointers(cd->atom);
>>  			result =
>>  			    commit_current_atom(&cd->nr_written, &cd->atom);
>>  			if (result != 0 && result != -E_REPEAT)
>> 
>> 
> 
> 

-- 
View this message in context: http://www.nabble.com/reiser4-firefox-hangs-due-to-fsync%2C-sysrq-t-dump-tp14514445p14547147.html
Sent from the ReiserFS - General mailing list archive at Nabble.com.