[PATCH 0/3] reiser4: another batch of fixes for 4.2.

[PATCH 0/3] reiser4: another batch of fixes for 4.2.

[Ivan Shapovalov]

These are the fixes for issues I've discovered during migration to 4.2.
Last one is a real issue causing a reproducible oops in my configuration,
first two are byproducts.

Ivan Shapovalov (3):
  reiser4: remove last traces of JNODE_NEW in the debugging code.
  reiser4: call account_page_redirty() on re-dirtying pages before giving them to entd.
  reiser4: in our own sync writes, mark pages dirty before marking them writeback.

 fs/reiser4/entd.c   | 1 +
 fs/reiser4/jnode.c  | 3 +--
 fs/reiser4/wander.c | 2 ++
 3 files changed, 4 insertions(+), 2 deletions(-)

-- 
2.6.0

[PATCH 1/3] reiser4: remove last traces of JNODE_NEW in the debugging code.

[Ivan Shapovalov]

Signed-off-by: Ivan Shapovalov <intelfx100@gmail.com>
---

JNODE_NEW was removed in commit b5e0c1d881a88b55dfae466cb2227e0598a513cd
"reiser4: Improve truncate (->setattr)".

 fs/reiser4/jnode.c | 3 +--
 1 file changed, 1 insertion(+), 2 deletions(-)

diff --git a/fs/reiser4/jnode.c b/fs/reiser4/jnode.c
index e0c9e0c..43af7e9 100644
--- a/fs/reiser4/jnode.c
+++ b/fs/reiser4/jnode.c
@@ -1846,7 +1846,7 @@ static void info_jnode(const char *prefix /* prefix to print */ ,
 	}
 
 	printk
-	    ("%s: %p: state: %lx: [%s%s%s%s%s%s%s%s%s%s%s%s%s%s%s%s%s], level: %i,"
+	    ("%s: %p: state: %lx: [%s%s%s%s%s%s%s%s%s%s%s%s%s%s%s%s], level: %i,"
 	     " block: %s, d_count: %d, x_count: %d, "
 	     "pg: %p, atom: %p, lock: %i:%i, type: %s, ", prefix, node,
 	     node->state,
@@ -1863,7 +1863,6 @@ static void info_jnode(const char *prefix /* prefix to print */ ,
 	     jnode_state_name(node, JNODE_RIP),
 	     jnode_state_name(node, JNODE_MISSED_IN_CAPTURE),
 	     jnode_state_name(node, JNODE_WRITEBACK),
-	     jnode_state_name(node, JNODE_NEW),
 	     jnode_state_name(node, JNODE_DKSET),
 	     jnode_state_name(node, JNODE_REPACK),
 	     jnode_state_name(node, JNODE_CLUSTER_PAGE),
-- 
2.6.0

[PATCH 2/3] reiser4: call account_page_redirty() on re-dirtying pages before giving them to entd.

[Ivan Shapovalov]

I guess we want that to rollback effects of account_page_dirtied()
in set_page_dirty_notag().

Signed-off-by: Ivan Shapovalov <intelfx100@gmail.com>
---

As always -- I'm not sure that this change is correct, but it seems so.

 fs/reiser4/entd.c | 1 +
 1 file changed, 1 insertion(+)

diff --git a/fs/reiser4/entd.c b/fs/reiser4/entd.c
index bff4bfa..c254e71 100644
--- a/fs/reiser4/entd.c
+++ b/fs/reiser4/entd.c
@@ -303,6 +303,7 @@ int write_page_by_ent(struct page *page, struct writeback_control *wbc)
 	 * write it - it will remain dirty
 	 */
 	set_page_dirty_notag(page);
+	account_page_redirty(page);
 
 	/*
 	 * pin inode in memory, unlock page, entd_flush will iput. We can not
-- 
2.6.0

[PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Ivan Shapovalov]

Ref.: https://www.mail-archive.com/linux-f2fs-devel%40lists.sourceforge.net/msg02745.html

Signed-off-by: Ivan Shapovalov <intelfx100@gmail.com>
---

Lustre seemed to encounter the same oops and fixed it in a different way, removing
set_page_writeback() altogether:
https://lkml.org/lkml/2015/7/30/806

We cannot just remove the call to set_page_writeback() at least because later
we wait on PG_Writeback flag of that page (in jwait_io())... What is meant by
"synchronous write" in that Lustre patch? Is our write "synchronous" in the
same sense? I don't know VFS well. Cc'ing Oleg.

 fs/reiser4/wander.c | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/fs/reiser4/wander.c b/fs/reiser4/wander.c
index ce20d50..0e2c105 100644
--- a/fs/reiser4/wander.c
+++ b/fs/reiser4/wander.c
@@ -782,7 +782,9 @@ static int write_jnodes_to_disk_extent(
 					node_plugin_by_node(JZNODE(cur))->csum(JZNODE(cur), 0);
 				zrelse(JZNODE(cur));
 			}
+
 			ClearPageError(pg);
+			set_page_dirty_notag(pg);
 			set_page_writeback(pg);
 
 			if (get_current_context()->entd) {
-- 
2.6.0

Re: [PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Edward Shishkin]

Hi Ivan,

On 10/09/2015 01:16 PM, Ivan Shapovalov wrote:
> Ref.: https://www.mail-archive.com/linux-f2fs-devel%40lists.sourceforge.net/msg02745.html

Do you have a stack trace for reiser4?
How to reproduce it?

>
> Signed-off-by: Ivan Shapovalov <intelfx100@gmail.com>
> ---
>
> Lustre seemed to encounter the same oops and fixed it in a different way, removing
> set_page_writeback() altogether:
> https://lkml.org/lkml/2015/7/30/806
>
> We cannot just remove the call to set_page_writeback() at least because later
> we wait on PG_Writeback flag of that page (in jwait_io())... What is meant by
> "synchronous write" in that Lustre patch? Is our write "synchronous" in the
> same sense?


Nop.
This is a generic function, it doesn't differentiate the writes.

Thanks,
Edward.

>   I don't know VFS well. Cc'ing Oleg.
>
>   fs/reiser4/wander.c | 2 ++
>   1 file changed, 2 insertions(+)
>
> diff --git a/fs/reiser4/wander.c b/fs/reiser4/wander.c
> index ce20d50..0e2c105 100644
> --- a/fs/reiser4/wander.c
> +++ b/fs/reiser4/wander.c
> @@ -782,7 +782,9 @@ static int write_jnodes_to_disk_extent(
>   					node_plugin_by_node(JZNODE(cur))->csum(JZNODE(cur), 0);
>   				zrelse(JZNODE(cur));
>   			}
> +
>   			ClearPageError(pg);
> +			set_page_dirty_notag(pg);
>   			set_page_writeback(pg);
>   
>   			if (get_current_context()->entd) {

Re: [PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Ivan Shapovalov]

[-- Attachment #1: Type: text/plain, Size: 2087 bytes --]

On 2015-10-09 at 15:27 +0200, Edward Shishkin wrote:
> Hi Ivan,
> 
> On 10/09/2015 01:16 PM, Ivan Shapovalov wrote:
> > Ref.: https://www.mail-archive.com/linux-f2fs-devel%40lists.sourcef
> > orge.net/msg02745.html
> 
> Do you have a stack trace for reiser4?
> How to reproduce it?

I'll rebuild the kernel without the fix and provide you with the oops'
stacktrace asap.

I guess that it's tied to the config. In my case, it is reproducible on
each boot, just as the DE starts up and something issues the first
fsync().

> 
> > 
> > Signed-off-by: Ivan Shapovalov <intelfx100@gmail.com>
> > ---
> > 
> > Lustre seemed to encounter the same oops and fixed it in a
> > different way, removing
> > set_page_writeback() altogether:
> > https://lkml.org/lkml/2015/7/30/806
> > 
> > We cannot just remove the call to set_page_writeback() at least
> > because later
> > we wait on PG_Writeback flag of that page (in jwait_io())... What
> > is meant by
> > "synchronous write" in that Lustre patch? Is our write
> > "synchronous" in the
> > same sense?
> 
> 
> Nop.
> This is a generic function, it doesn't differentiate the writes.

Well, that lustre vvp_page_prep_write() is generic as well, and that
patch adds a conditional to differentiate sync/async writes. What is
meant by "sync" in that context? sync == page is locked until I/O ends?
Or something else?

-- 
Ivan Shapovalov / intelfx /

> >   I don't know VFS well. Cc'ing Oleg.
> > 
> >   fs/reiser4/wander.c | 2 ++
> >   1 file changed, 2 insertions(+)
> > 
> > diff --git a/fs/reiser4/wander.c b/fs/reiser4/wander.c
> > index ce20d50..0e2c105 100644
> > --- a/fs/reiser4/wander.c
> > +++ b/fs/reiser4/wander.c
> > @@ -782,7 +782,9 @@ static int write_jnodes_to_disk_extent(
> >   					node_plugin_by_node(JZNOD
> > E(cur))->csum(JZNODE(cur), 0);
> >   				zrelse(JZNODE(cur));
> >   			}
> > +
> >   			ClearPageError(pg);
> > +			set_page_dirty_notag(pg);
> >   			set_page_writeback(pg);
> >   
> >   			if (get_current_context()->entd) {
> 



[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 213 bytes --]

Re: [PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Edward Shishkin]

On 10/09/2015 03:50 PM, Ivan Shapovalov wrote:
> On 2015-10-09 at 15:27 +0200, Edward Shishkin wrote:
>> Hi Ivan,
>>
>> On 10/09/2015 01:16 PM, Ivan Shapovalov wrote:
>>> Ref.: https://www.mail-archive.com/linux-f2fs-devel%40lists.sourcef
>>> orge.net/msg02745.html
>> Do you have a stack trace for reiser4?
>> How to reproduce it?
> I'll rebuild the kernel without the fix and provide you with the oops'
> stacktrace asap.
>
> I guess that it's tied to the config. In my case, it is reproducible on
> each boot, just as the DE starts up and something issues the first
> fsync().


Yes, let's try to find the culprit who doesn't set i_wb...


>
>>> Signed-off-by: Ivan Shapovalov <intelfx100@gmail.com>
>>> ---
>>>
>>> Lustre seemed to encounter the same oops and fixed it in a
>>> different way, removing
>>> set_page_writeback() altogether:
>>> https://lkml.org/lkml/2015/7/30/806
>>>
>>> We cannot just remove the call to set_page_writeback() at least
>>> because later
>>> we wait on PG_Writeback flag of that page (in jwait_io())... What
>>> is meant by
>>> "synchronous write" in that Lustre patch? Is our write
>>> "synchronous" in the
>>> same sense?
>>
>> Nop.
>> This is a generic function, it doesn't differentiate the writes.
> Well, that lustre vvp_page_prep_write() is generic as well, and that
> patch adds a conditional to differentiate sync/async writes. What is
> meant by "sync" in that context? sync == page is locked until I/O ends?
> Or something else?


Why do you need this?
Reiser4 doesn't lock pages for IO ;)
At least, for formatted nodes..

Edward.

Re: [PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Ivan Shapovalov]

[-- Attachment #1: Type: text/plain, Size: 6248 bytes --]

On 2015-10-09 at 16:55 +0200, Edward Shishkin wrote:

> 
> On 10/09/2015 03:50 PM, Ivan Shapovalov wrote:

> > On 2015-10-09 at 15:27 +0200, Edward Shishkin wrote:

> > > Hi Ivan,
> > > 
> > > On 10/09/2015 01:16 PM, Ivan Shapovalov wrote:

> > > > Ref.: https://www.mail-archive.com/linux-f2fs-devel%40lists.sou
> > > > rcef
> > > > orge.net/msg02745.html
> > > Do you have a stack trace for reiser4?
> > > How to reproduce it?
> > I'll rebuild the kernel without the fix and provide you with the
> > oops'
> > stacktrace asap.
> > 
> > I guess that it's tied to the config. In my case, it is
> > reproducible on
> > each boot, just as the DE starts up and something issues the first
> > fsync().
> 
> 
> Yes, let's try to find the culprit who doesn't set i_wb...

So, here is the oops:

==== cut here ====

<1>[    8.653781] BUG: unable to handle kernel NULL pointer dereference at 00000000000000a8
<1>[    8.653808] IP: [<ffffffff8124ba3a>] __percpu_counter_add+0x1a/0x90
<4>[    8.653828] PGD 0
<4>[    8.653836] Oops: 0000 [#1] PREEMPT SMP
<4>[    8.653849] Modules linked in: fuse ctr ccm bnep joydev arc4 snd_hda_codec_realtek snd_hda_codec_generic snd_hda_codec_hdmi iwlmvm btusb btintel mac80211 bluetooth uvcvideo iTCO_wdt iTCO_vendor_support videobuf2_vmalloc videobuf2_memops videobuf2_core mousedev v4l2_common videodev x86_pkg_temp_thermal intel_powerclamp coretemp intel_rapl crc32_pclmul sha256_ssse3 crc16 sha256_generic hmac drbg snd_hda_intel iwlwifi snd_hda_codec aesni_intel aes_x86_64 ablk_helper snd_hwdep cfg80211 e1000e psmouse snd_hda_core cryptd lrw input_leds gf128mul glue_helper i2c_i801 snd_pcm thinkpad_acpi serio_raw pcspkr rtsx_pci_ms memstick mei_me lpc_ich mei snd_timer ptp snd pps_core thermal soundcore wmi nvram tpm_tis led_class rfkill tpm battery ac intel_smartconnect evdev processor sch_fq_codel tcp_yeah tcp_vegas vboxpci(O) vboxnetflt(O) vboxnetadp(O) vboxdrv(O) nfs fscache lockd grace sunrpc bbswitch(O) efivarfs ip_tables x_tables reiser4 sr_mod cdrom sd_mod hid_logitech_hidpp hid_logitech_dj usbhid hid rtsx_pci_sdmmc mmc_core i915 ahci libahci crc32c_intel i2c_algo_bit intel_gtt libata ehci_pci xhci_pci drm_kms_helper ehci_hcd xhci_hcd scsi_mod rtsx_pci mfd_core drm usbcore usb_common i2c_core video thermal_sys hwmon button
<4>[    8.654235] CPU: 1 PID: 141 Comm: kworker/u16:3 Tainted: G           O    4.2.0-pf2-intelfx-00190-gc800b69 #1
<4>[    8.654258] Hardware name: LENOVO 20BEA008RT/20BEA008RT, BIOS GMET70WW (2.18 ) 03/05/2015
<4>[    8.654279] Workqueue: writeback wb_workfn (flush-8:0)
<4>[    8.654294] task: ffff8800b736c380 ti: ffff88007f804000 task.ti: ffff88007f804000
<4>[    8.654311] RIP: 0010:[<ffffffff8124ba3a>]  [<ffffffff8124ba3a>] __percpu_counter_add+0x1a/0x90
<4>[    8.654333] RSP: 0018:ffff88007f807848  EFLAGS: 00010082
<4>[    8.654351] RAX: 0000000000000003 RBX: ffffea00089d91c0 RCX: 0000000000000001
<4>[    8.654368] RDX: 0000000000000020 RSI: 0000000000000001 RDI: 0000000000000088
<4>[    8.654384] RBP: ffff88007f807868 R08: 0000000000000000 R09: ffff88022aeb86b8
<4>[    8.654401] R10: 00000000fffffffa R11: 0000000000000000 R12: 0000000000000088
<4>[    8.654417] R13: 0000000000000001 R14: ffff88022cb04800 R15: ffff8800bad084a0
<4>[    8.654435] FS:  0000000000000000(0000) GS:ffff88023e240000(0000) knlGS:0000000000000000
<4>[    8.654454] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4>[    8.654467] CR2: 00000000000000a8 CR3: 000000000180b000 CR4: 00000000001406e0
<4>[    8.654484] Stack:
<4>[    8.654490]  ffff880234938000 ffffea00089d91c0 ffff8800bad08600 ffff8800bad08618
<4>[    8.654511]  ffff88007f8078c8 ffffffff810f3e59 ffff88007f807908 0000000000000292
<4>[    8.654532]  0000000000000000 ffff88007f908198 ffff8800b5ec23c0 ffff8800b5ec23c0
<4>[    8.654554] Call Trace:
<4>[    8.654563]  [<ffffffff810f3e59>] __test_set_page_writeback+0xd9/0x1c0
<4>[    8.654586]  [<ffffffffc03a5ad0>] write_jnodes_to_disk_extent+0x1b0/0x460 [reiser4]
<4>[    8.654606]  [<ffffffffc03a6003>] write_jnode_list+0x83/0xc0 [reiser4]
<4>[    8.654626]  [<ffffffffc03aabf8>] reiser4_write_fq+0x78/0x1c0 [reiser4]
<4>[    8.654644]  [<ffffffffc03a540a>] flush_current_atom+0x3ba/0x850 [reiser4]
<4>[    8.654663]  [<ffffffffc039f53a>] ? txnh_get_atom+0x2a/0x90 [reiser4]
<4>[    8.654682]  [<ffffffffc03a0e1c>] flush_some_atom+0x10c/0x4d0 [reiser4]
<4>[    8.654700]  [<ffffffffc03afc9e>] reiser4_writeout+0x14e/0x240 [reiser4]
<4>[    8.654719]  [<ffffffffc03abeec>] reiser4_writeback_inodes+0x9c/0x130 [reiser4]
<4>[    8.654738]  [<ffffffff81226c53>] ? fprop_fraction_percpu+0x33/0x90
<4>[    8.654754]  [<ffffffff8117a999>] writeback_sb_inodes+0x99/0xc0
<4>[    8.654769]  [<ffffffff8117aa47>] __writeback_inodes_wb+0x87/0xb0
<4>[    8.654784]  [<ffffffff8117ac1b>] wb_writeback+0x1ab/0x1d0
<4>[    8.654797]  [<ffffffff8117ad3a>] wb_workfn+0xfa/0x380
<4>[    8.654811]  [<ffffffff8106eaa8>] ? try_to_wake_up+0x268/0x420
<4>[    8.654827]  [<ffffffff81063366>] process_one_work+0x126/0x3c0
<4>[    8.654841]  [<ffffffff81063643>] worker_thread+0x43/0x4a0
<4>[    8.654855]  [<ffffffff81063600>] ? process_one_work+0x3c0/0x3c0
<4>[    8.654871]  [<ffffffff81068ea3>] kthread+0xd3/0xf0
<4>[    8.654884]  [<ffffffff81068dd0>] ? kthread_worker_fn+0x160/0x160
<4>[    8.654901]  [<ffffffff814641df>] ret_from_fork+0x3f/0x70
<4>[    8.654916]  [<ffffffff81068dd0>] ? kthread_worker_fn+0x160/0x160
<4>[    8.654930] Code: c3 b8 ff ff ff ff c3 66 2e 0f 1f 84 00 00 00 00 00 55 48 89 e5 41 55 49 89 f5 41 54 49 89 fc 53 48 83 ec 08 65 ff 05 d6 ee db 7e <48> 8b 47 20 48 63 ca 65 8b 18 48 63 db 48 01 f3 48 39 cb 7d 0a
<1>[    8.655040] RIP  [<ffffffff8124ba3a>] __percpu_counter_add+0x1a/0x90
<4>[    8.655058]  RSP <ffff88007f807848>
<4>[    8.655067] CR2: 00000000000000a8
<4>[    8.655077] ---[ end trace 3db0fa7adb9580c7 ]---

==== cut here ====

-- 
Ivan Shapovalov / intelfx /


[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 213 bytes --]

Re: [PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Oleg Drokin]

On Oct 9, 2015, at 12:13 PM, Ivan Shapovalov wrote:

> On 2015-10-09 at 16:55 +0200, Edward Shishkin wrote:
> 
>> 
>> On 10/09/2015 03:50 PM, Ivan Shapovalov wrote:
> 
>>> On 2015-10-09 at 15:27 +0200, Edward Shishkin wrote:
> 
>>>> Hi Ivan,
>>>> 
>>>> On 10/09/2015 01:16 PM, Ivan Shapovalov wrote:
> 
>>>>> Ref.: https://www.mail-archive.com/linux-f2fs-devel%40lists.sou
>>>>> rcef
>>>>> orge.net/msg02745.html
>>>> Do you have a stack trace for reiser4?
>>>> How to reproduce it?
>>> I'll rebuild the kernel without the fix and provide you with the
>>> oops'
>>> stacktrace asap.
>>> 
>>> I guess that it's tied to the config. In my case, it is
>>> reproducible on
>>> each boot, just as the DE starts up and something issues the first
>>> fsync().
>> 
>> 
>> Yes, let's try to find the culprit who doesn't set i_wb...
> 
> So, here is the oops:

I suspect this will not help you much.
What you probably need to do is to add an assertion of some sort when the page
is inserted into this list (on which you later do waiting for writeback) and
it's not dirty.
Either that or you might be able to see in the coe right away where such
addition is made without markign the page dirty.


Bye,
    Oleg

Re: [PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Ivan Shapovalov]

[-- Attachment #1: Type: text/plain, Size: 1627 bytes --]

On 2015-10-09 at 12:27 -0400, Oleg Drokin wrote:
> On Oct 9, 2015, at 12:13 PM, Ivan Shapovalov wrote:
> 
> > On 2015-10-09 at 16:55 +0200, Edward Shishkin wrote:
> > 
> > > 
> > > On 10/09/2015 03:50 PM, Ivan Shapovalov wrote:
> > 
> > > > On 2015-10-09 at 15:27 +0200, Edward Shishkin wrote:
> > 
> > > > > Hi Ivan,
> > > > > 
> > > > > On 10/09/2015 01:16 PM, Ivan Shapovalov wrote:
> > 
> > > > > > Ref.: https://www.mail-archive.com/linux-f2fs-devel%40lists
> > > > > > .sou
> > > > > > rcef
> > > > > > orge.net/msg02745.html
> > > > > Do you have a stack trace for reiser4?
> > > > > How to reproduce it?
> > > > I'll rebuild the kernel without the fix and provide you with
> > > > the
> > > > oops'
> > > > stacktrace asap.
> > > > 
> > > > I guess that it's tied to the config. In my case, it is
> > > > reproducible on
> > > > each boot, just as the DE starts up and something issues the
> > > > first
> > > > fsync().
> > > 
> > > 
> > > Yes, let's try to find the culprit who doesn't set i_wb...
> > 
> > So, here is the oops:
> 
> I suspect this will not help you much.
> What you probably need to do is to add an assertion of some sort when
> the page
> is inserted into this list (on which you later do waiting for
> writeback) and
> it's not dirty.
> Either that or you might be able to see in the coe right away where
> such
> addition is made without markign the page dirty.

Indeed. I'm thinking the same as I read the code.
Did I say that I don't know neither reiser4 nor VFS well?.. :)

Thanks for the advice, anyway.

-- 
Ivan Shapovalov / intelfx /


[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 213 bytes --]

Re: [PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Ivan Shapovalov]

[-- Attachment #1: Type: text/plain, Size: 1628 bytes --]

On 2015-10-09 at 16:55 +0200, Edward Shishkin wrote:
> 
> On 10/09/2015 03:50 PM, Ivan Shapovalov wrote:
> > On 2015-10-09 at 15:27 +0200, Edward Shishkin wrote:
> > > Hi Ivan,
> > > 
> > > On 10/09/2015 01:16 PM, Ivan Shapovalov wrote:
> > > > Ref.: https://www.mail-archive.com/linux-f2fs-devel%40lists.sou
> > > > rcef
> > > > orge.net/msg02745.html
> > > Do you have a stack trace for reiser4?
> > > How to reproduce it?
> > I'll rebuild the kernel without the fix and provide you with the
> > oops'
> > stacktrace asap.
> > 
> > I guess that it's tied to the config. In my case, it is
> > reproducible on
> > each boot, just as the DE starts up and something issues the first
> > fsync().
> 
> 
> Yes, let's try to find the culprit who doesn't set i_wb...

So, here are the traces I've got after adding an
assert(PageDirty(node->pg)) to queue_jnode():
/* captured by hand as these are panics, not oopses */

1.

queue_jnode()
unformatted_make_reloc()
assign_real_blocknrs()
forward_relocate_unformatted()
forward_alloc_unformatted_journal()
? coord_num_units()
handle_pos_on_twig()
flush_current_atom()
flush_some_atom()
reiser4_writeout()
reiser4_writeback_inodes()
<...>

2.

znode_make_reloc()
forward_alloc_formatted_wa()
? zload_ra()
allocate_znode()
alloc_pos_and_ancestors()
flush_current_atom()
reiser4_txn_end()
? reiser4_txn_end()
reiser4_txn_restart_current()
force_commit_atom()
? reiser4_txn_restart_current()
txnmgr_force_commit_all()
writepages_cryptcompress()
reiser4_writepages_dispatch()
<...>
sys_fsync()

-- 
Ivan Shapovalov / intelfx /


[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 213 bytes --]

Re: [PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Edward Shishkin]

[-- Attachment #1: Type: text/plain, Size: 2416 bytes --]

On 10/09/2015 07:14 PM, Ivan Shapovalov wrote:
> On 2015-10-09 at 16:55 +0200, Edward Shishkin wrote:
>> On 10/09/2015 03:50 PM, Ivan Shapovalov wrote:
>>> On 2015-10-09 at 15:27 +0200, Edward Shishkin wrote:
>>>> Hi Ivan,
>>>>
>>>> On 10/09/2015 01:16 PM, Ivan Shapovalov wrote:
>>>>> Ref.: https://www.mail-archive.com/linux-f2fs-devel%40lists.sou
>>>>> rcef
>>>>> orge.net/msg02745.html
>>>> Do you have a stack trace for reiser4?
>>>> How to reproduce it?
>>> I'll rebuild the kernel without the fix and provide you with the
>>> oops'
>>> stacktrace asap.
>>>
>>> I guess that it's tied to the config. In my case, it is
>>> reproducible on
>>> each boot, just as the DE starts up and something issues the first
>>> fsync().
>>
>> Yes, let's try to find the culprit who doesn't set i_wb...
> So, here are the traces I've got after adding an
> assert(PageDirty(node->pg)) to queue_jnode():
> /* captured by hand as these are panics, not oopses */
>
> 1.
>
> queue_jnode()
> unformatted_make_reloc()
> assign_real_blocknrs()
> forward_relocate_unformatted()
> forward_alloc_unformatted_journal()
> ? coord_num_units()
> handle_pos_on_twig()
> flush_current_atom()
> flush_some_atom()
> reiser4_writeout()
> reiser4_writeback_inodes()
> <...>
>
> 2.
>
> znode_make_reloc()
> forward_alloc_formatted_wa()
> ? zload_ra()
> allocate_znode()
> alloc_pos_and_ancestors()
> flush_current_atom()
> reiser4_txn_end()
> ? reiser4_txn_end()
> reiser4_txn_restart_current()
> force_commit_atom()
> ? reiser4_txn_restart_current()
> txnmgr_force_commit_all()
> writepages_cryptcompress()
> reiser4_writepages_dispatch()
> <...>
> sys_fsync()
>


Thanks Ivan.
Not a good news, TBH...

For formatted nodes we can continue to narrow down the problem
(see the attached patch). For unformatted nodes only code review
can help. Normally, all modifications of unformatted nodes should
look like the following:

struct page *page = jnode_page(node);
lock_page(page);
char *data = kmap(page);
/* modifications are going here */
kunmap(page);
set_page_dirty_nobuffers(page); /* somebody forgets to do this */
unlock_page(page);

Modifications of formatted nodes should look like the following:

longterm_lock_znode(node);
zload(node);
/* modifications are going here */
zrelse(node);
znode_make_dirty(node); /* somebody forgets to do this */
longterm_unlock_znode();

Anyway, we can use your patch 3 as a temporal fixup.

Thanks,
Edward.

[-- Attachment #2: reiser4-debug-formatted-make-dirty.patch --]
[-- Type: text/x-patch, Size: 415 bytes --]

---
 fs/reiser4/lock.c |    5 +++++
 1 file changed, 5 insertions(+)

--- a/fs/reiser4/lock.c
+++ b/fs/reiser4/lock.c
@@ -641,6 +641,11 @@ void longterm_unlock_znode(lock_handle *
 			zput(node);
 			return;
 		}
+		if (znode_page(node) != NULL)
+			if (!PageDirty(znode_page(node))) {
+				warning("", "releasing last write-lock, but page is fishily clean");
+				dump_stack();
+			}
 	}
 
 	if (handle->signaled)

Re: [PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Dušan Čolić]

On Fri, Oct 9, 2015 at 10:23 PM, Edward Shishkin
<edward.shishkin@gmail.com> wrote:
> On 10/09/2015 07:14 PM, Ivan Shapovalov wrote:
>>
>> On 2015-10-09 at 16:55 +0200, Edward Shishkin wrote:
>>>
>>> On 10/09/2015 03:50 PM, Ivan Shapovalov wrote:
>>>>
>>>> On 2015-10-09 at 15:27 +0200, Edward Shishkin wrote:
>>>>>
>>>>> Hi Ivan,
>>>>>
>>>>> On 10/09/2015 01:16 PM, Ivan Shapovalov wrote:
>>>>>>
>>>>>> Ref.: https://www.mail-archive.com/linux-f2fs-devel%40lists.sou
>>>>>> rcef
>>>>>> orge.net/msg02745.html
>>>>>
>>>>> Do you have a stack trace for reiser4?
>>>>> How to reproduce it?
>>>>
>>>> I'll rebuild the kernel without the fix and provide you with the
>>>> oops'
>>>> stacktrace asap.
>>>>
>>>> I guess that it's tied to the config. In my case, it is
>>>> reproducible on
>>>> each boot, just as the DE starts up and something issues the first
>>>> fsync().
>>>
>>>
>>> Yes, let's try to find the culprit who doesn't set i_wb...
>>
>> So, here are the traces I've got after adding an
>> assert(PageDirty(node->pg)) to queue_jnode():
>> /* captured by hand as these are panics, not oopses */
>>
>> 1.
>>
>> queue_jnode()
>> unformatted_make_reloc()
>> assign_real_blocknrs()
>> forward_relocate_unformatted()
>> forward_alloc_unformatted_journal()
>> ? coord_num_units()
>> handle_pos_on_twig()
>> flush_current_atom()
>> flush_some_atom()
>> reiser4_writeout()
>> reiser4_writeback_inodes()
>> <...>
>>
>> 2.
>>
>> znode_make_reloc()
>> forward_alloc_formatted_wa()
>> ? zload_ra()
>> allocate_znode()
>> alloc_pos_and_ancestors()
>> flush_current_atom()
>> reiser4_txn_end()
>> ? reiser4_txn_end()
>> reiser4_txn_restart_current()
>> force_commit_atom()
>> ? reiser4_txn_restart_current()
>> txnmgr_force_commit_all()
>> writepages_cryptcompress()
>> reiser4_writepages_dispatch()
>> <...>
>> sys_fsync()
>>
>
>
> Thanks Ivan.
> Not a good news, TBH...
>
> For formatted nodes we can continue to narrow down the problem
> (see the attached patch). For unformatted nodes only code review
> can help. Normally, all modifications of unformatted nodes should
> look like the following:
>
> struct page *page = jnode_page(node);
> lock_page(page);
> char *data = kmap(page);
> /* modifications are going here */
> kunmap(page);
> set_page_dirty_nobuffers(page); /* somebody forgets to do this */
> unlock_page(page);
>
> Modifications of formatted nodes should look like the following:
>
> longterm_lock_znode(node);
> zload(node);
> /* modifications are going here */
> zrelse(node);
> znode_make_dirty(node); /* somebody forgets to do this */
> longterm_unlock_znode();
>
I can easily reproduce these problems with
xfstests/generic/013,014,015,023,029.... and
reiser4-debug-formatted-make-dirty.patch
./check -s r4Hybrid -s r4ccHybrid -g quick

PLATFORM      -- Linux/i686 reiser4 4.2.1
MKFS_OPTIONS  -- /dev/hda7
MOUNT_OPTIONS -- -o noatime /dev/hda7 /mnt/scratch


A lot of following in logs:

Oct 10 11:10:28 reiser4 kernel: reiser4[kworker/u2:2(7908)]:
longterm_unlock_znode (fs/reiser4/lock.c:646)[]:
Oct 10 11:10:28 reiser4 kernel: WARNING: releasing last write-lock,
but page is fishily clean
Oct 10 11:10:28 reiser4 kernel: CPU: 0 PID: 7908 Comm: kworker/u2:2
Not tainted 4.2.1 #2
Oct 10 11:10:28 reiser4 kernel: Hardware name: System Manufacturer
System Name/A7V8X, BIOS ASUS A7V8X ACPI BIOS Revision 1014 04/21/2004
Oct 10 11:10:28 reiser4 kernel: Workqueue: writeback wb_workfn (flush-3:0)
Oct 10 11:10:28 reiser4 kernel: de846638 de846638 dc093c74 c135e99e
dc093cb0 c112b7c0 c1404058 dd0e2430
Oct 10 11:10:28 reiser4 kernel: 00001ee4 c1376238 c13fdd65 00000286
c13f52e3 c112eb83 00000000 d1bd9244
Oct 10 11:10:28 reiser4 kernel: de846600 c145166c dc093cd8 dc093d10
c1134cba 00000020 00000000 c113535b
Oct 10 11:10:28 reiser4 kernel: Call Trace:
Oct 10 11:10:28 reiser4 kernel: [<c135e99e>] dump_stack+0x16/0x18
Oct 10 11:10:28 reiser4 kernel: [<c112b7c0>] longterm_unlock_znode+0x1e0/0x200
Oct 10 11:10:28 reiser4 kernel: [<c112eb83>] ? coord_next_unit+0x63/0xd0
Oct 10 11:10:28 reiser4 kernel: [<c1134cba>] scan_unformatted+0x3ca/0x460
Oct 10 11:10:28 reiser4 kernel: [<c113535b>] ? flush_current_atom+0x4ab/0x920
Oct 10 11:10:28 reiser4 kernel: [<c1134e5c>] scan_common+0x10c/0x160
Oct 10 11:10:28 reiser4 kernel: [<c1135378>] flush_current_atom+0x4c8/0x920
Oct 10 11:10:28 reiser4 kernel: [<c1130d45>] ? atom_free+0x65/0x70
Oct 10 11:10:28 reiser4 kernel: [<c1150e2a>] ?
writepages_cryptcompress+0x11a/0x180
Oct 10 11:10:28 reiser4 kernel: [<c1131b66>] flush_some_atom+0xa6/0x260
Oct 10 11:10:28 reiser4 kernel: [<c1087a4b>] ? mapping_tagged+0xb/0x10
Oct 10 11:10:28 reiser4 kernel: [<c113de99>] reiser4_writeout+0x89/0x180
Oct 10 11:10:28 reiser4 kernel: [<c10d070e>] ?
generic_writeback_sb_inodes+0x18e/0x270
Oct 10 11:10:28 reiser4 kernel: [<c113ad74>] reiser4_writeback_inodes+0x64/0xf0
Oct 10 11:10:28 reiser4 kernel: [<c11a75eb>] ? fprop_fraction_percpu+0x2b/0x80
Oct 10 11:10:28 reiser4 kernel: [<c113ad10>] ? reiser4_show_options+0xa0/0xa0
Oct 10 11:10:28 reiser4 kernel: [<c10d086f>] writeback_sb_inodes+0x7f/0xa0
Oct 10 11:10:28 reiser4 kernel: [<c10d09c5>] wb_writeback+0x95/0x120
Oct 10 11:10:28 reiser4 kernel: [<c10d0b00>] wb_workfn+0xb0/0x2b0
Oct 10 11:10:28 reiser4 kernel: [<c1047630>] ? __dequeue_entity+0x20/0x40
Oct 10 11:10:28 reiser4 kernel: [<c1047901>] ? pick_next_task_fair+0xb1/0x130
Oct 10 11:10:28 reiser4 kernel: [<c103c671>] process_one_work+0xd1/0x290
Oct 10 11:10:28 reiser4 kernel: [<c103c916>] worker_thread+0xe6/0x3c0
Oct 10 11:10:28 reiser4 kernel: [<c103c830>] ? process_one_work+0x290/0x290
Oct 10 11:10:28 reiser4 kernel: [<c1040be5>] kthread+0x95/0xb0
Oct 10 11:10:28 reiser4 kernel: [<c1361e00>] ret_from_kernel_thread+0x20/0x30
Oct 10 11:10:28 reiser4 kernel: [<c1040b50>] ? __kthread_parkme+0x60/0x60
Oct 10 11:10:28 reiser4 kernel: reiser4[kworker/u2:2(7908)]:
longterm_unlock_znode (fs/reiser4/lock.c:646)[]:
Oct 10 11:10:28 reiser4 kernel: WARNING: releasing last write-lock,
but page is fishily clean
Oct 10 11:10:28 reiser4 kernel: CPU: 0 PID: 7908 Comm: kworker/u2:2
Not tainted 4.2.1 #2
Oct 10 11:10:28 reiser4 kernel: Hardware name: System Manufacturer
System Name/A7V8X, BIOS ASUS A7V8X ACPI BIOS Revision 1014 04/21/2004
Oct 10 11:10:28 reiser4 kernel: Workqueue: writeback wb_workfn (flush-3:0)
Oct 10 11:10:28 reiser4 kernel: dc093d80 dc093d80 dc093cec c135e99e
dc093d28 c112b7c0 c1404058 dd0e2430
Oct 10 11:10:28 reiser4 kernel: 00001ee4 c1376238 c13fdd65 00000286
c13f52e3 dc093d70 00000000 d1bd9244
Oct 10 11:10:28 reiser4 kernel: dc093dd4 de846600 d4c39460 dc093dac
c1135655 00000040 dc093d40 c1130d45
Oct 10 11:10:28 reiser4 kernel: Call Trace:
Oct 10 11:10:28 reiser4 kernel: [<c135e99e>] dump_stack+0x16/0x18
Oct 10 11:10:28 reiser4 kernel: [<c112b7c0>] longterm_unlock_znode+0x1e0/0x200
Oct 10 11:10:28 reiser4 kernel: [<c1135655>] flush_current_atom+0x7a5/0x920
Oct 10 11:10:28 reiser4 kernel: [<c1130d45>] ? atom_free+0x65/0x70
Oct 10 11:10:28 reiser4 kernel: [<c1131b66>] flush_some_atom+0xa6/0x260
Oct 10 11:10:28 reiser4 kernel: [<c1087a4b>] ? mapping_tagged+0xb/0x10
Oct 10 11:10:28 reiser4 kernel: [<c113de99>] reiser4_writeout+0x89/0x180
Oct 10 11:10:28 reiser4 kernel: [<c10d070e>] ?
generic_writeback_sb_inodes+0x18e/0x270
Oct 10 11:10:28 reiser4 kernel: [<c113ad74>] reiser4_writeback_inodes+0x64/0xf0
Oct 10 11:10:28 reiser4 kernel: [<c11a75eb>] ? fprop_fraction_percpu+0x2b/0x80
Oct 10 11:10:28 reiser4 kernel: [<c113ad10>] ? reiser4_show_options+0xa0/0xa0
Oct 10 11:10:28 reiser4 kernel: [<c10d086f>] writeback_sb_inodes+0x7f/0xa0
Oct 10 11:10:28 reiser4 kernel: [<c10d09c5>] wb_writeback+0x95/0x120
Oct 10 11:10:28 reiser4 kernel: [<c10d0b00>] wb_workfn+0xb0/0x2b0
Oct 10 11:10:28 reiser4 kernel: [<c1047630>] ? __dequeue_entity+0x20/0x40
Oct 10 11:10:28 reiser4 kernel: [<c1047901>] ? pick_next_task_fair+0xb1/0x130
Oct 10 11:10:28 reiser4 kernel: [<c103c671>] process_one_work+0xd1/0x290
Oct 10 11:10:28 reiser4 kernel: [<c103c916>] worker_thread+0xe6/0x3c0
Oct 10 11:10:28 reiser4 kernel: [<c103c830>] ? process_one_work+0x290/0x290
Oct 10 11:10:28 reiser4 kernel: [<c1040be5>] kthread+0x95/0xb0
Oct 10 11:10:28 reiser4 kernel: [<c1361e00>] ret_from_kernel_thread+0x20/0x30
Oct 10 11:10:28 reiser4 kernel: [<c1040b50>] ? __kthread_parkme+0x60/0x60
Oct 10 11:10:28 reiser4 kernel: reiser4[kworker/u2:2(7908)]:
longterm_unlock_znode (fs/reiser4/lock.c:646)[]:
Oct 10 11:10:28 reiser4 kernel: WARNING: releasing last write-lock,
but page is fishily clean
Oct 10 11:10:28 reiser4 kernel: CPU: 0 PID: 7908 Comm: kworker/u2:2
Not tainted 4.2.1 #2
Oct 10 11:10:28 reiser4 kernel: Hardware name: System Manufacturer
System Name/A7V8X, BIOS ASUS A7V8X ACPI BIOS Revision 1014 04/21/2004
Oct 10 11:10:28 reiser4 kernel: Workqueue: writeback wb_workfn (flush-3:0)
Oct 10 11:10:28 reiser4 kernel: de8466fc de8466fc dc093ce0 c135e99e
dc093d1c c112b7c0 c1404058 dd0e2430
Oct 10 11:10:28 reiser4 kernel: 00001ee4 c1376238 c13fdd65 00000286
c13f52e3 00000000 00000000 d1bd9244
Oct 10 11:10:28 reiser4 kernel: de8466e8 de846600 d4c39460 dc093d28
c1132e6b dc093dd4 dc093dac c11354ed
Oct 10 11:10:28 reiser4 kernel: Call Trace:
Oct 10 11:10:28 reiser4 kernel: [<c135e99e>] dump_stack+0x16/0x18
Oct 10 11:10:28 reiser4 kernel: [<c112b7c0>] longterm_unlock_znode+0x1e0/0x200
Oct 10 11:10:28 reiser4 kernel: [<c1132e6b>] pos_stop+0x1b/0x50
Oct 10 11:10:28 reiser4 kernel: [<c11354ed>] flush_current_atom+0x63d/0x920
Oct 10 11:10:28 reiser4 kernel: [<c1130d45>] ? atom_free+0x65/0x70
Oct 10 11:10:28 reiser4 kernel: [<c1131b66>] flush_some_atom+0xa6/0x260
Oct 10 11:10:28 reiser4 kernel: [<c1087a4b>] ? mapping_tagged+0xb/0x10
Oct 10 11:10:28 reiser4 kernel: [<c113de99>] reiser4_writeout+0x89/0x180
Oct 10 11:10:28 reiser4 kernel: [<c10d070e>] ?
generic_writeback_sb_inodes+0x18e/0x270
Oct 10 11:10:28 reiser4 kernel: [<c113ad74>] reiser4_writeback_inodes+0x64/0xf0
Oct 10 11:10:28 reiser4 kernel: [<c11a75eb>] ? fprop_fraction_percpu+0x2b/0x80
Oct 10 11:10:28 reiser4 kernel: [<c113ad10>] ? reiser4_show_options+0xa0/0xa0
Oct 10 11:10:28 reiser4 kernel: [<c10d086f>] writeback_sb_inodes+0x7f/0xa0
Oct 10 11:10:28 reiser4 kernel: [<c10d09c5>] wb_writeback+0x95/0x120
Oct 10 11:10:28 reiser4 kernel: [<c10d0b00>] wb_workfn+0xb0/0x2b0
Oct 10 11:10:28 reiser4 kernel: [<c1047630>] ? __dequeue_entity+0x20/0x40
Oct 10 11:10:28 reiser4 kernel: [<c1047901>] ? pick_next_task_fair+0xb1/0x130
Oct 10 11:10:28 reiser4 kernel: [<c103c671>] process_one_work+0xd1/0x290
Oct 10 11:10:28 reiser4 kernel: [<c103c916>] worker_thread+0xe6/0x3c0
Oct 10 11:10:28 reiser4 kernel: [<c103c830>] ? process_one_work+0x290/0x290
Oct 10 11:10:28 reiser4 kernel: [<c1040be5>] kthread+0x95/0xb0
Oct 10 11:10:28 reiser4 kernel: [<c1361e00>] ret_from_kernel_thread+0x20/0x30
Oct 10 11:10:28 reiser4 kernel: [<c1040b50>] ? __kthread_parkme+0x60/0x60


> Anyway, we can use your patch 3 as a temporal fixup.
>
> Thanks,
> Edward.

Re: [PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Ivan Shapovalov]

[-- Attachment #1: Type: text/plain, Size: 10213 bytes --]

On 2015-10-09 at 22:23 +0200, Edward Shishkin wrote:
> On 10/09/2015 07:14 PM, Ivan Shapovalov wrote:
> > On 2015-10-09 at 16:55 +0200, Edward Shishkin wrote:
> > > On 10/09/2015 03:50 PM, Ivan Shapovalov wrote:
> > > > On 2015-10-09 at 15:27 +0200, Edward Shishkin wrote:
> > > > > Hi Ivan,
> > > > > 
> > > > > On 10/09/2015 01:16 PM, Ivan Shapovalov wrote:
> > > > > > Ref.: https://www.mail-archive.com/linux-f2fs-devel%40lists
> > > > > > .sou
> > > > > > rcef
> > > > > > orge.net/msg02745.html
> > > > > Do you have a stack trace for reiser4?
> > > > > How to reproduce it?
> > > > I'll rebuild the kernel without the fix and provide you with
> > > > the
> > > > oops'
> > > > stacktrace asap.
> > > > 
> > > > I guess that it's tied to the config. In my case, it is
> > > > reproducible on
> > > > each boot, just as the DE starts up and something issues the
> > > > first
> > > > fsync().
> > > 
> > > Yes, let's try to find the culprit who doesn't set i_wb...
> > So, here are the traces I've got after adding an
> > assert(PageDirty(node->pg)) to queue_jnode():
> > /* captured by hand as these are panics, not oopses */
> > 
> > 1.
> > 
> > queue_jnode()
> > unformatted_make_reloc()
> > assign_real_blocknrs()
> > forward_relocate_unformatted()
> > forward_alloc_unformatted_journal()
> > ? coord_num_units()
> > handle_pos_on_twig()
> > flush_current_atom()
> > flush_some_atom()
> > reiser4_writeout()
> > reiser4_writeback_inodes()
> > <...>
> > 
> > 2.
> > 
> > znode_make_reloc()
> > forward_alloc_formatted_wa()
> > ? zload_ra()
> > allocate_znode()
> > alloc_pos_and_ancestors()
> > flush_current_atom()
> > reiser4_txn_end()
> > ? reiser4_txn_end()
> > reiser4_txn_restart_current()
> > force_commit_atom()
> > ? reiser4_txn_restart_current()
> > txnmgr_force_commit_all()
> > writepages_cryptcompress()
> > reiser4_writepages_dispatch()
> > <...>
> > sys_fsync()
> > 
> 
> 
> Thanks Ivan.
> Not a good news, TBH...
> 
> For formatted nodes we can continue to narrow down the problem
> (see the attached patch).

Having applied the patch, I saw loads and loads of warnings (in ~10
distinct stacktraces), but no panics or oopses in the initial location.
The false positives are possible, right?

The traces:

1.
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffff8145ddac>] dump_stack+0x4c/0x6e
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc033cc88>] longterm_unlock_znode+0x738/0xe80 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc036de5c>] scan_by_coord+0x62c/0xed0 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc036e86d>] scan_unformatted+0x16d/0x320 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc032b1f0>] ? incr_load_count+0x20/0xd0 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc036ed9b>] scan_common+0x37b/0x790 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc0370074>] flush_current_atom+0xec4/0x1b40 [reiser4]
<...>

2.
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffff8145ddac>] dump_stack+0x4c/0x6e
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc033cc88>] longterm_unlock_znode+0x738/0xe80 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc036b952>] neighbor_in_slum.constprop.12+0x82/0x1c0 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc036bc4a>] handle_pos_on_formatted+0x1ba/0xa40 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc036c546>] handle_pos_on_leaf+0x16/0x80 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc0370400>] flush_current_atom+0x1250/0x1b40 [reiser4]
<...>

3.
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffff8145ddac>] dump_stack+0x4c/0x6e
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc033cc88>] longterm_unlock_znode+0x738/0xe80 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc032f0c3>] unlock_carry_level+0xb3/0xd80 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc032fdb0>] done_carry_level+0x20/0x1f0 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc0332036>] reiser4_carry+0x396/0x7b0 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc032bc0c>] ? reiser4_add_obj+0x9c/0x370 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc033fb4a>] insert_into_item+0x1fa/0x610 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc033ffd4>] reiser4_resize_item+0x74/0x190 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03ec314>] add_entry_cde+0x104/0x2f0 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc0329af5>] ? znode_invariant+0x3a5/0xd50 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03aa19e>] reiser4_rename2_common+0xbce/0x1140 [reiser4]
<...>

4.
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffff8145ddac>] dump_stack+0x4c/0x6e
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc033cc88>] longterm_unlock_znode+0x738/0xe80 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03f48af>] free_item_convert_data+0x3f/0x150 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03f5656>] detach_convert_idata+0x26/0x110 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03fd0f6>] convert_ctail+0x1016/0x2060 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03648ba>] convert_node+0x22a/0xd30 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc032b40d>] ? zrelse+0x1d/0x70 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc036bfc2>] handle_pos_on_formatted+0x532/0xa40 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc036c546>] handle_pos_on_leaf+0x16/0x80 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc0370400>] flush_current_atom+0x1250/0x1b40 [reiser4]
<...>

5.
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc033cc88>] longterm_unlock_znode+0x738/0xe80 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc032f0c3>] unlock_carry_level+0xb3/0xd80 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc032fdb0>] done_carry_level+0x20/0x1f0 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc0332036>] reiser4_carry+0x396/0x7b0 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc032bc0c>] ? reiser4_add_obj+0x9c/0x370 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc033edda>] insert_with_carry_by_coord+0xea/0x250 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03d6016>] ? free_space_node40+0x16/0x170 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc033f3c6>] insert_by_coord+0x166/0x360 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03fa16f>] ctail_insert_unprepped_cluster+0x1df/0x750 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03c98e3>] prepare_logical_cluster+0x753/0x17f0 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03cabdf>] do_write_cryptcompress+0x25f/0xed0 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc0347a69>] ? is_in_reiser4_context+0x19/0x30 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03ce8d1>] write_cryptcompress+0xa1/0x1d0 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03477fa>] ? _reiser4_init_context+0x6a/0xf0 [reiser4]
Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03bcc66>] reiser4_write_dispatch+0x166/0x4f0 [reiser4]
<...>

6.
Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffff8145ddac>] dump_stack+0x4c/0x6e
Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc033cc88>] longterm_unlock_znode+0x738/0xe80 [reiser4]
Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc036611a>] move_flush_pos+0xba/0x2c0 [reiser4]
Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc036c10e>] handle_pos_on_formatted+0x67e/0xa40 [reiser4]
Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc036c546>] handle_pos_on_leaf+0x16/0x80 [reiser4]
Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc0370400>] flush_current_atom+0x1250/0x1b40 [reiser4]
<...>

7.
Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffff8145ddac>] dump_stack+0x4c/0x6e
Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc033cc88>] longterm_unlock_znode+0x738/0xe80 [reiser4]
Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc03f48af>] free_item_convert_data+0x3f/0x150 [reiser4]
Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc03f5656>] detach_convert_idata+0x26/0x110 [reiser4]
Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc03fd0f6>] convert_ctail+0x1016/0x2060 [reiser4]
Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc03648ba>] convert_node+0x22a/0xd30 [reiser4]
Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc0363b9e>] ? znode_check_flushprepped+0xfe/0x360 [reiser4]
Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc036bb28>] handle_pos_on_formatted+0x98/0xa40 [reiser4]
Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc036c546>] handle_pos_on_leaf+0x16/0x80 [reiser4]
Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc0370400>] flush_current_atom+0x1250/0x1b40 [reiser4]
<...>

...and so on.

I didn't check the code yet; I'll probably try with that assertion converted into warning and split into two
(one for formatted and another for unformatted nodes), so that I could check what type of nodes is responsible
for generating the final oops in set_page_writeback().

> For unformatted nodes only code review
> can help. Normally, all modifications of unformatted nodes should
> look like the following:
> 
> struct page *page = jnode_page(node);
> lock_page(page);
> char *data = kmap(page);
> /* modifications are going here */
> kunmap(page);
> set_page_dirty_nobuffers(page); /* somebody forgets to do this */
> unlock_page(page);
> 
> Modifications of formatted nodes should look like the following:
> 
> longterm_lock_znode(node);
> zload(node);
> /* modifications are going here */
> zrelse(node);
> znode_make_dirty(node); /* somebody forgets to do this */
> longterm_unlock_znode();
> 
> Anyway, we can use your patch 3 as a temporal fixup.

The most persistent things are those conseived as the most temporary
ones... ;)

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 213 bytes --]

Re: [PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Edward Shishkin]

On 10/10/2015 12:44 PM, Ivan Shapovalov wrote:
> On 2015-10-09 at 22:23 +0200, Edward Shishkin wrote:
>> On 10/09/2015 07:14 PM, Ivan Shapovalov wrote:
>>> On 2015-10-09 at 16:55 +0200, Edward Shishkin wrote:
>>>> On 10/09/2015 03:50 PM, Ivan Shapovalov wrote:
>>>>> On 2015-10-09 at 15:27 +0200, Edward Shishkin wrote:
>>>>>> Hi Ivan,
>>>>>>
>>>>>> On 10/09/2015 01:16 PM, Ivan Shapovalov wrote:
>>>>>>> Ref.: https://www.mail-archive.com/linux-f2fs-devel%40lists
>>>>>>> .sou
>>>>>>> rcef
>>>>>>> orge.net/msg02745.html
>>>>>> Do you have a stack trace for reiser4?
>>>>>> How to reproduce it?
>>>>> I'll rebuild the kernel without the fix and provide you with
>>>>> the
>>>>> oops'
>>>>> stacktrace asap.
>>>>>
>>>>> I guess that it's tied to the config. In my case, it is
>>>>> reproducible on
>>>>> each boot, just as the DE starts up and something issues the
>>>>> first
>>>>> fsync().
>>>> Yes, let's try to find the culprit who doesn't set i_wb...
>>> So, here are the traces I've got after adding an
>>> assert(PageDirty(node->pg)) to queue_jnode():
>>> /* captured by hand as these are panics, not oopses */
>>>
>>> 1.
>>>
>>> queue_jnode()
>>> unformatted_make_reloc()
>>> assign_real_blocknrs()
>>> forward_relocate_unformatted()
>>> forward_alloc_unformatted_journal()
>>> ? coord_num_units()
>>> handle_pos_on_twig()
>>> flush_current_atom()
>>> flush_some_atom()
>>> reiser4_writeout()
>>> reiser4_writeback_inodes()
>>> <...>
>>>
>>> 2.
>>>
>>> znode_make_reloc()
>>> forward_alloc_formatted_wa()
>>> ? zload_ra()
>>> allocate_znode()
>>> alloc_pos_and_ancestors()
>>> flush_current_atom()
>>> reiser4_txn_end()
>>> ? reiser4_txn_end()
>>> reiser4_txn_restart_current()
>>> force_commit_atom()
>>> ? reiser4_txn_restart_current()
>>> txnmgr_force_commit_all()
>>> writepages_cryptcompress()
>>> reiser4_writepages_dispatch()
>>> <...>
>>> sys_fsync()
>>>
>>
>> Thanks Ivan.
>> Not a good news, TBH...
>>
>> For formatted nodes we can continue to narrow down the problem
>> (see the attached patch).
> Having applied the patch, I saw loads and loads of warnings (in ~10
> distinct stacktraces), but no panics or oopses in the initial location.
> The false positives are possible, right?


Yes, a lot of ones and nothing interesting.
The same for Dushan's logs. Sorry for bad idea..

Thanks,
Edward.


>
> The traces:
>
> 1.
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffff8145ddac>] dump_stack+0x4c/0x6e
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc033cc88>] longterm_unlock_znode+0x738/0xe80 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc036de5c>] scan_by_coord+0x62c/0xed0 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc036e86d>] scan_unformatted+0x16d/0x320 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc032b1f0>] ? incr_load_count+0x20/0xd0 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc036ed9b>] scan_common+0x37b/0x790 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc0370074>] flush_current_atom+0xec4/0x1b40 [reiser4]
> <...>
>
> 2.
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffff8145ddac>] dump_stack+0x4c/0x6e
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc033cc88>] longterm_unlock_znode+0x738/0xe80 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc036b952>] neighbor_in_slum.constprop.12+0x82/0x1c0 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc036bc4a>] handle_pos_on_formatted+0x1ba/0xa40 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc036c546>] handle_pos_on_leaf+0x16/0x80 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc0370400>] flush_current_atom+0x1250/0x1b40 [reiser4]
> <...>
>
> 3.
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffff8145ddac>] dump_stack+0x4c/0x6e
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc033cc88>] longterm_unlock_znode+0x738/0xe80 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc032f0c3>] unlock_carry_level+0xb3/0xd80 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc032fdb0>] done_carry_level+0x20/0x1f0 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc0332036>] reiser4_carry+0x396/0x7b0 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc032bc0c>] ? reiser4_add_obj+0x9c/0x370 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc033fb4a>] insert_into_item+0x1fa/0x610 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc033ffd4>] reiser4_resize_item+0x74/0x190 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03ec314>] add_entry_cde+0x104/0x2f0 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc0329af5>] ? znode_invariant+0x3a5/0xd50 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03aa19e>] reiser4_rename2_common+0xbce/0x1140 [reiser4]
> <...>
>
> 4.
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffff8145ddac>] dump_stack+0x4c/0x6e
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc033cc88>] longterm_unlock_znode+0x738/0xe80 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03f48af>] free_item_convert_data+0x3f/0x150 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03f5656>] detach_convert_idata+0x26/0x110 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03fd0f6>] convert_ctail+0x1016/0x2060 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03648ba>] convert_node+0x22a/0xd30 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc032b40d>] ? zrelse+0x1d/0x70 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc036bfc2>] handle_pos_on_formatted+0x532/0xa40 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc036c546>] handle_pos_on_leaf+0x16/0x80 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc0370400>] flush_current_atom+0x1250/0x1b40 [reiser4]
> <...>
>
> 5.
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc033cc88>] longterm_unlock_znode+0x738/0xe80 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc032f0c3>] unlock_carry_level+0xb3/0xd80 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc032fdb0>] done_carry_level+0x20/0x1f0 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc0332036>] reiser4_carry+0x396/0x7b0 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc032bc0c>] ? reiser4_add_obj+0x9c/0x370 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc033edda>] insert_with_carry_by_coord+0xea/0x250 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03d6016>] ? free_space_node40+0x16/0x170 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc033f3c6>] insert_by_coord+0x166/0x360 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03fa16f>] ctail_insert_unprepped_cluster+0x1df/0x750 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03c98e3>] prepare_logical_cluster+0x753/0x17f0 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03cabdf>] do_write_cryptcompress+0x25f/0xed0 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc0347a69>] ? is_in_reiser4_context+0x19/0x30 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03ce8d1>] write_cryptcompress+0xa1/0x1d0 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03477fa>] ? _reiser4_init_context+0x6a/0xf0 [reiser4]
> Oct 10 00:28:42 intelfx-laptop kernel:  [<ffffffffc03bcc66>] reiser4_write_dispatch+0x166/0x4f0 [reiser4]
> <...>
>
> 6.
> Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffff8145ddac>] dump_stack+0x4c/0x6e
> Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc033cc88>] longterm_unlock_znode+0x738/0xe80 [reiser4]
> Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc036611a>] move_flush_pos+0xba/0x2c0 [reiser4]
> Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc036c10e>] handle_pos_on_formatted+0x67e/0xa40 [reiser4]
> Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc036c546>] handle_pos_on_leaf+0x16/0x80 [reiser4]
> Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc0370400>] flush_current_atom+0x1250/0x1b40 [reiser4]
> <...>
>
> 7.
> Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffff8145ddac>] dump_stack+0x4c/0x6e
> Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc033cc88>] longterm_unlock_znode+0x738/0xe80 [reiser4]
> Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc03f48af>] free_item_convert_data+0x3f/0x150 [reiser4]
> Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc03f5656>] detach_convert_idata+0x26/0x110 [reiser4]
> Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc03fd0f6>] convert_ctail+0x1016/0x2060 [reiser4]
> Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc03648ba>] convert_node+0x22a/0xd30 [reiser4]
> Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc0363b9e>] ? znode_check_flushprepped+0xfe/0x360 [reiser4]
> Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc036bb28>] handle_pos_on_formatted+0x98/0xa40 [reiser4]
> Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc036c546>] handle_pos_on_leaf+0x16/0x80 [reiser4]
> Oct 10 00:28:43 intelfx-laptop kernel:  [<ffffffffc0370400>] flush_current_atom+0x1250/0x1b40 [reiser4]
> <...>
>
> ...and so on.
>
> I didn't check the code yet; I'll probably try with that assertion converted into warning and split into two
> (one for formatted and another for unformatted nodes), so that I could check what type of nodes is responsible
> for generating the final oops in set_page_writeback().
>
>> For unformatted nodes only code review
>> can help. Normally, all modifications of unformatted nodes should
>> look like the following:
>>
>> struct page *page = jnode_page(node);
>> lock_page(page);
>> char *data = kmap(page);
>> /* modifications are going here */
>> kunmap(page);
>> set_page_dirty_nobuffers(page); /* somebody forgets to do this */
>> unlock_page(page);
>>
>> Modifications of formatted nodes should look like the following:
>>
>> longterm_lock_znode(node);
>> zload(node);
>> /* modifications are going here */
>> zrelse(node);
>> znode_make_dirty(node); /* somebody forgets to do this */
>> longterm_unlock_znode();
>>
>> Anyway, we can use your patch 3 as a temporal fixup.
> The most persistent things are those conseived as the most temporary
> ones... ;)

Re: [PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Oleg Drokin]

On Oct 10, 2015, at 11:03 AM, Edward Shishkin wrote:
>>> 
>>> For formatted nodes we can continue to narrow down the problem
>>> (see the attached patch).
>> Having applied the patch, I saw loads and loads of warnings (in ~10
>> distinct stacktraces), but no panics or oopses in the initial location.
>> The false positives are possible, right?
> 
> 
> Yes, a lot of ones and nothing interesting.
> The same for Dushan's logs. Sorry for bad idea..

Actually the idea might not be as bad as you think.

This is because not every page that you forgot to call page_dirty on
will cause a crash.
Only the pages that had never ever had been set dirty.
So in a lot of cases the crash does not happen because the page got
dirtied by a normal path somewhere else and then cleared by normal
means, but i_wb remains with that page forever until it's fully torn down
from the pagecache.

Bye,
    Oleg

Re: [PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Edward Shishkin]

On 10/10/2015 06:51 PM, Oleg Drokin wrote:
> On Oct 10, 2015, at 11:03 AM, Edward Shishkin wrote:
>>>> For formatted nodes we can continue to narrow down the problem
>>>> (see the attached patch).
>>> Having applied the patch, I saw loads and loads of warnings (in ~10
>>> distinct stacktraces), but no panics or oopses in the initial location.
>>> The false positives are possible, right?
>> Yes, a lot of ones and nothing interesting.
>> The same for Dushan's logs. Sorry for bad idea..
> Actually the idea might not be as bad as you think.
>
> This is because not every page that you forgot to call page_dirty on
> will cause a crash.
> Only the pages that had never ever had been set dirty.
> So in a lot of cases the crash does not happen because the page got
> dirtied by a normal path somewhere else and then cleared by normal
> means, but i_wb remains with that page forever until it's fully torn down
> from the pagecache.

I wanted something more efficient than simply code review..
However, in all paths found by Ivan I see that pages are not
obliged to become dirty in write-locking sessions..

Edward.

Re: [PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Edward Shishkin]

On 10/10/2015 12:44 PM, Ivan Shapovalov wrote:
[...]
> I didn't check the code yet; I'll probably try with that assertion converted into warning and split into two
> (one for formatted and another for unformatted nodes), so that I could check what type of nodes is responsible
> for generating the final oops in set_page_writeback().

I suppose that oops happens on unformatted nodes, because
all formatted nodes have the same host - a special "fake" inode
with number 1, which gets i_wb at mount time (init_fake_inode()
calls inode_attach_wb()).

Edward.

>
>> For unformatted nodes only code review
>> can help. Normally, all modifications of unformatted nodes should
>> look like the following:
>>
>> struct page *page = jnode_page(node);
>> lock_page(page);
>> char *data = kmap(page);
>> /* modifications are going here */
>> kunmap(page);
>> set_page_dirty_nobuffers(page); /* somebody forgets to do this */
>> unlock_page(page);
>>
>> Modifications of formatted nodes should look like the following:
>>
>> longterm_lock_znode(node);
>> zload(node);
>> /* modifications are going here */
>> zrelse(node);
>> znode_make_dirty(node); /* somebody forgets to do this */
>> longterm_unlock_znode();
>>
>> Anyway, we can use your patch 3 as a temporal fixup.
> The most persistent things are those conseived as the most temporary
> ones... ;)

Re: [PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Ivan Shapovalov]

[-- Attachment #1: Type: text/plain, Size: 2412 bytes --]

On 2015-10-12 at 11:07 +0200, Edward Shishkin wrote:
> On 10/10/2015 12:44 PM, Ivan Shapovalov wrote:
> [...]
> > I didn't check the code yet; I'll probably try with that assertion
> > converted into warning and split into two
> > (one for formatted and another for unformatted nodes), so that I
> > could check what type of nodes is responsible
> > for generating the final oops in set_page_writeback().
> 
> I suppose that oops happens on unformatted nodes, because
> all formatted nodes have the same host - a special "fake" inode
> with number 1, which gets i_wb at mount time (init_fake_inode()
> calls inode_attach_wb()).
> 
> Edward.

So, I've added three non-fatal checks right before
set_page_writeback():
- PageDirty(pg)
- JF_ISSET(cur, JNODE_DIRTY)
- pg->mapping->host->i_wb != NULL

In almost all times when either of the checks is triggered,
the first two checks are triggered at once (i. e. neither page nor
jnode is dirty, but i_wb is not NULL). This happens with both formatted
nodes (jnode_is_znode), unformatted nodes (jnode_is_unformatted) and
other nodes.

And, finally, there are very few warnings where jnode _is_ dirty, but
the page _isn't_. On the first such warning i_wb is also NULL. And,
just as you've suspected, this happens with an unformatted node.

I'll try to add a backtrace buffer into struct jnode and generate a
backtrace there on each jnode dirtying attempt... and then print it for
the problematic jnode.

-- 
Ivan Shapovalov / intelfx /

> 
> > 
> > > For unformatted nodes only code review
> > > can help. Normally, all modifications of unformatted nodes should
> > > look like the following:
> > > 
> > > struct page *page = jnode_page(node);
> > > lock_page(page);
> > > char *data = kmap(page);
> > > /* modifications are going here */
> > > kunmap(page);
> > > set_page_dirty_nobuffers(page); /* somebody forgets to do this */
> > > unlock_page(page);
> > > 
> > > Modifications of formatted nodes should look like the following:
> > > 
> > > longterm_lock_znode(node);
> > > zload(node);
> > > /* modifications are going here */
> > > zrelse(node);
> > > znode_make_dirty(node); /* somebody forgets to do this */
> > > longterm_unlock_znode();
> > > 
> > > Anyway, we can use your patch 3 as a temporal fixup.
> > The most persistent things are those conseived as the most
> > temporary
> > ones... ;)

[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 213 bytes --]

Re: [PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Ivan Shapovalov]

[-- Attachment #1: Type: text/plain, Size: 3068 bytes --]

On 2015-10-14 at 13:05 +0300, Ivan Shapovalov wrote:
> On 2015-10-12 at 11:07 +0200, Edward Shishkin wrote:
> > [...]
> 
> So, I've added three non-fatal checks right before
> set_page_writeback():
> - PageDirty(pg)
> - JF_ISSET(cur, JNODE_DIRTY)
> - pg->mapping->host->i_wb != NULL
> 
> In almost all times when either of the checks is triggered,
> the first two checks are triggered at once (i. e. neither page nor
> jnode is dirty, but i_wb is not NULL). This happens with both
> formatted
> nodes (jnode_is_znode), unformatted nodes (jnode_is_unformatted) and
> other nodes.
> 
> And, finally, there are very few warnings where jnode _is_ dirty, but
> the page _isn't_. On the first such warning i_wb is also NULL. And,
> just as you've suspected, this happens with an unformatted node.
> 
> I'll try to add a backtrace buffer into struct jnode and generate a
> backtrace there on each jnode dirtying attempt... and then print it
> for
> the problematic jnode.
> 

So, here it is. On all occurrences the backtrace is the same.

Oct 14 13:51:54 intelfx-laptop kernel: reiser4[xdg-user-dirs-g(2040)]: write_jnodes_to_disk_extent (fs/reiser4/wander.c:807)[intelfx-8888]:
                                       WARNING: on writeback: jnode (unformatted): BAD-PAGE BAD-INODE-i_wb
Oct 14 13:51:54 intelfx-laptop kernel: BAD-INODE-i_wb, stacktrace of last jnode dirtying follows:   [<ffffffff8101119a>] save_stack_trace+0x2a/0x50
Oct 14 13:51:54 intelfx-laptop kernel:    [<ffffffffc03a5e6f>] jnode_make_dirty_locked+0xcf/0x770 [reiser4]
Oct 14 13:51:54 intelfx-laptop kernel:    [<ffffffffc04550a1>] insert_first_extent+0x211/0x610 [reiser4]
Oct 14 13:51:54 intelfx-laptop kernel:    [<ffffffffc0458c21>] reiser4_update_extent+0xe1/0x300 [reiser4]
Oct 14 13:51:54 intelfx-laptop kernel:    [<ffffffffc0402125>] find_or_create_extent+0xa5/0x800 [reiser4]
Oct 14 13:51:54 intelfx-laptop kernel:    [<ffffffffc040733b>] replace+0x11b/0x290 [reiser4]
Oct 14 13:51:54 intelfx-laptop kernel:    [<ffffffffc040825a>] tail2extent+0x66a/0xcc0 [reiser4]
Oct 14 13:51:54 intelfx-laptop kernel:    [<ffffffffc03ffe51>] unpack.isra.6+0x121/0x270 [reiser4]
Oct 14 13:51:54 intelfx-laptop kernel:    [<ffffffffc040516d>] mmap_unix_file+0x12d/0x1c0 [reiser4]
Oct 14 13:51:54 intelfx-laptop kernel:    [<ffffffffc040bb9e>] reiser4_mmap_dispatch+0x7e/0x320 [reiser4]
Oct 14 13:51:54 intelfx-laptop kernel:    [<ffffffff81118131>] mmap_region+0x3d1/0x670
Oct 14 13:51:54 intelfx-laptop kernel:    [<ffffffff81118723>] do_mmap_pgoff+0x353/0x400
Oct 14 13:51:54 intelfx-laptop kernel:    [<ffffffff81103861>] vm_mmap_pgoff+0x71/0xc0
Oct 14 13:51:54 intelfx-laptop kernel:    [<ffffffff81116c3d>] SyS_mmap_pgoff+0x1dd/0x250
Oct 14 13:51:54 intelfx-laptop kernel:    [<ffffffff81008406>] SyS_mmap+0x16/0x20
Oct 14 13:51:54 intelfx-laptop kernel:    [<ffffffff81463e17>] entry_SYSCALL_64_fastpath+0x12/0x6a

-- 
Ivan Shapovalov / intelfx /


[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 213 bytes --]

Re: [PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Ivan Shapovalov]

[-- Attachment #1: Type: text/plain, Size: 2026 bytes --]

On 2015-10-14 at 13:55 +0300, Ivan Shapovalov wrote:
> On 2015-10-14 at 13:05 +0300, Ivan Shapovalov wrote:
> > On 2015-10-12 at 11:07 +0200, Edward Shishkin wrote:
> > > [...]
> > 
> > So, I've added three non-fatal checks right before
> > set_page_writeback():
> > - PageDirty(pg)
> > - JF_ISSET(cur, JNODE_DIRTY)
> > - pg->mapping->host->i_wb != NULL
> > 
> > In almost all times when either of the checks is triggered,
> > the first two checks are triggered at once (i. e. neither page nor
> > jnode is dirty, but i_wb is not NULL). This happens with both
> > formatted
> > nodes (jnode_is_znode), unformatted nodes (jnode_is_unformatted)
> > and
> > other nodes.
> > 
> > And, finally, there are very few warnings where jnode _is_ dirty,
> > but
> > the page _isn't_. On the first such warning i_wb is also NULL. And,
> > just as you've suspected, this happens with an unformatted node.
> > 
> > I'll try to add a backtrace buffer into struct jnode and generate a
> > backtrace there on each jnode dirtying attempt... and then print it
> > for
> > the problematic jnode.
> > 
> 
> So, here it is. On all occurrences the backtrace is the same.
>
> [...]


Hmm. This obvious fix "works",  but causes an assertion on rootfs unmount:

"list_empty(&get_super_private(super)->all_jnodes)" in init_super.c:55 (no maintainer-id).

Why?

---
 fs/reiser4/plugin/file/tail_conversion.c | 1 +
 1 file changed, 1 insertion(+)

diff --git a/fs/reiser4/plugin/file/tail_conversion.c b/fs/reiser4/plugin/file/tail_conversion.c
index 6ffa900..3b4e77d 100644
--- a/fs/reiser4/plugin/file/tail_conversion.c
+++ b/fs/reiser4/plugin/file/tail_conversion.c
@@ -175,6 +175,7 @@ static int replace(struct inode *inode, struct page **pages, unsigned nr_pages,
 								i_mapping));
 		if (result)
 			break;
+		set_page_dirty_notag(pages[i]);
 		unlock_page(pages[i]);
 		result = find_or_create_extent(pages[i]);
 		if (result) {
-- 
2.6.1

-- 
Ivan Shapovalov / intelfx /


[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 213 bytes --]

Re: [PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Edward Shishkin]

Hello,

So the tail conversion is the culprit?
It's quite realistic...
I am currently on vacations,
I'll take a look at this at the end of October
more carefully.

Thanks!
Edward.



On 10/14/2015 09:06 PM, Ivan Shapovalov wrote:
> On 2015-10-14 at 13:55 +0300, Ivan Shapovalov wrote:
>> On 2015-10-14 at 13:05 +0300, Ivan Shapovalov wrote:
>>> On 2015-10-12 at 11:07 +0200, Edward Shishkin wrote:
>>>> [...]
>>> So, I've added three non-fatal checks right before
>>> set_page_writeback():
>>> - PageDirty(pg)
>>> - JF_ISSET(cur, JNODE_DIRTY)
>>> - pg->mapping->host->i_wb != NULL
>>>
>>> In almost all times when either of the checks is triggered,
>>> the first two checks are triggered at once (i. e. neither page nor
>>> jnode is dirty, but i_wb is not NULL). This happens with both
>>> formatted
>>> nodes (jnode_is_znode), unformatted nodes (jnode_is_unformatted)
>>> and
>>> other nodes.
>>>
>>> And, finally, there are very few warnings where jnode _is_ dirty,
>>> but
>>> the page _isn't_. On the first such warning i_wb is also NULL. And,
>>> just as you've suspected, this happens with an unformatted node.
>>>
>>> I'll try to add a backtrace buffer into struct jnode and generate a
>>> backtrace there on each jnode dirtying attempt... and then print it
>>> for
>>> the problematic jnode.
>>>
>> So, here it is. On all occurrences the backtrace is the same.
>>
>> [...]
>
> Hmm. This obvious fix "works",  but causes an assertion on rootfs unmount:
>
> "list_empty(&get_super_private(super)->all_jnodes)" in init_super.c:55 (no maintainer-id).
>
> Why?
>
> ---
>   fs/reiser4/plugin/file/tail_conversion.c | 1 +
>   1 file changed, 1 insertion(+)
>
> diff --git a/fs/reiser4/plugin/file/tail_conversion.c b/fs/reiser4/plugin/file/tail_conversion.c
> index 6ffa900..3b4e77d 100644
> --- a/fs/reiser4/plugin/file/tail_conversion.c
> +++ b/fs/reiser4/plugin/file/tail_conversion.c
> @@ -175,6 +175,7 @@ static int replace(struct inode *inode, struct page **pages, unsigned nr_pages,
>   								i_mapping));
>   		if (result)
>   			break;
> +		set_page_dirty_notag(pages[i]);
>   		unlock_page(pages[i]);
>   		result = find_or_create_extent(pages[i]);
>   		if (result) {

Re: [PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Ivan Shapovalov]

[-- Attachment #1: Type: text/plain, Size: 2805 bytes --]

On 2015-10-15 at 19:20 +0200, Edward Shishkin wrote:
> Hello,
> 
> So the tail conversion is the culprit?
> It's quite realistic...
> I am currently on vacations,
> I'll take a look at this at the end of October
> more carefully.
> 
> Thanks!
> Edward.

I've done a bit more testing, and the encountered panic at unmount does
not depend on my proposed fix. Hence I'll resend the initial patchset.

-- 
Ivan Shapovalov / intelfx /

> 
> 
> 
> On 10/14/2015 09:06 PM, Ivan Shapovalov wrote:
> > On 2015-10-14 at 13:55 +0300, Ivan Shapovalov wrote:
> > > On 2015-10-14 at 13:05 +0300, Ivan Shapovalov wrote:
> > > > On 2015-10-12 at 11:07 +0200, Edward Shishkin wrote:
> > > > > [...]
> > > > So, I've added three non-fatal checks right before
> > > > set_page_writeback():
> > > > - PageDirty(pg)
> > > > - JF_ISSET(cur, JNODE_DIRTY)
> > > > - pg->mapping->host->i_wb != NULL
> > > > 
> > > > In almost all times when either of the checks is triggered,
> > > > the first two checks are triggered at once (i. e. neither page
> > > > nor
> > > > jnode is dirty, but i_wb is not NULL). This happens with both
> > > > formatted
> > > > nodes (jnode_is_znode), unformatted nodes
> > > > (jnode_is_unformatted)
> > > > and
> > > > other nodes.
> > > > 
> > > > And, finally, there are very few warnings where jnode _is_
> > > > dirty,
> > > > but
> > > > the page _isn't_. On the first such warning i_wb is also NULL.
> > > > And,
> > > > just as you've suspected, this happens with an unformatted
> > > > node.
> > > > 
> > > > I'll try to add a backtrace buffer into struct jnode and
> > > > generate a
> > > > backtrace there on each jnode dirtying attempt... and then
> > > > print it
> > > > for
> > > > the problematic jnode.
> > > > 
> > > So, here it is. On all occurrences the backtrace is the same.
> > > 
> > > [...]
> > 
> > Hmm. This obvious fix "works",  but causes an assertion on rootfs
> > unmount:
> > 
> > "list_empty(&get_super_private(super)->all_jnodes)" in
> > init_super.c:55 (no maintainer-id).
> > 
> > Why?
> > 
> > ---
> >   fs/reiser4/plugin/file/tail_conversion.c | 1 +
> >   1 file changed, 1 insertion(+)
> > 
> > diff --git a/fs/reiser4/plugin/file/tail_conversion.c
> > b/fs/reiser4/plugin/file/tail_conversion.c
> > index 6ffa900..3b4e77d 100644
> > --- a/fs/reiser4/plugin/file/tail_conversion.c
> > +++ b/fs/reiser4/plugin/file/tail_conversion.c
> > @@ -175,6 +175,7 @@ static int replace(struct inode *inode, struct
> > page **pages, unsigned nr_pages,
> >   								i
> > _mapping));
> >   		if (result)
> >   			break;
> > +		set_page_dirty_notag(pages[i]);
> >   		unlock_page(pages[i]);
> >   		result = find_or_create_extent(pages[i]);
> >   		if (result) {
> 



[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 213 bytes --]

Re: [PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Ivan Shapovalov]

[-- Attachment #1: Type: text/plain, Size: 469 bytes --]

On 2015-10-15 at 19:20 +0200, Edward Shishkin wrote:
> Hello,
> 
> So the tail conversion is the culprit?
> It's quite realistic...
> I am currently on vacations,
> I'll take a look at this at the end of October
> more carefully.
> 
> Thanks!
> Edward.

Hi Edward,

what's the status of this? Do you have a bit of time to spend looking
at the fixes? :)

[Dropped Oleg from Cc: in order not to annoy him anymore.]

-- 
Ivan Shapovalov / intelfx /


[-- Attachment #2: This is a digitally signed message part --]
[-- Type: application/pgp-signature, Size: 213 bytes --]

Re: [PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Edward Shishkin]

On 11/04/2015 07:09 PM, Ivan Shapovalov wrote:
> On 2015-10-15 at 19:20 +0200, Edward Shishkin wrote:
>> Hello,
>>
>> So the tail conversion is the culprit?
>> It's quite realistic...
>> I am currently on vacations,
>> I'll take a look at this at the end of October
>> more carefully.
>>
>> Thanks!
>> Edward.
> Hi Edward,
>
> what's the status of this? Do you have a bit of time to spend looking
> at the fixes? :)


Hi Ivan,

Sorry, I was on a business trip in China where Google is prohibited
with all its services (including gmail), so I wasn't able to receive emails.

Edward.

Re: [PATCH 3/3] reiser4: in our own sync writes, mark pages dirty before marking them writeback.

[Oleg Drokin]

Hello!

On Oct 9, 2015, at 7:16 AM, Ivan Shapovalov wrote:

> Ref.: https://www.mail-archive.com/linux-f2fs-devel%40lists.sourceforge.net/msg02745.html
> 
> Signed-off-by: Ivan Shapovalov <intelfx100@gmail.com>
> ---
> 
> Lustre seemed to encounter the same oops and fixed it in a different way, removing
> set_page_writeback() altogether:
> https://lkml.org/lkml/2015/7/30/806
> 
> We cannot just remove the call to set_page_writeback() at least because later
> we wait on PG_Writeback flag of that page (in jwait_io())... What is meant by
> "synchronous write" in that Lustre patch? Is our write "synchronous" in the
> same sense? I don't know VFS well. Cc'ing Oleg.

In case of Lustre synchronous write is a special kind of write where the
client sends the RPC to server right away from the write syscall
(as opposed to using wrteback cache) because it lacks server credits
or quote to cache the write.
The bug in Lustre case was that set_page_writeback was called on a page
that was not dirtied previously, that's why getting rid of set_page_writeback
made sense (since the page was not making the cache, no point in accounting for
it).

If you do cache the dirty page, you cannot get rid of this page_dirty setting,
and instead you just need to ensure the page was marked dirty beforehand,
most likely at some place that really set the page dirty, but forgot to tell VFS.

Probably look at who added the page into this list that you are iterating in this function?

> 
> fs/reiser4/wander.c | 2 ++
> 1 file changed, 2 insertions(+)
> 
> diff --git a/fs/reiser4/wander.c b/fs/reiser4/wander.c
> index ce20d50..0e2c105 100644
> --- a/fs/reiser4/wander.c
> +++ b/fs/reiser4/wander.c
> @@ -782,7 +782,9 @@ static int write_jnodes_to_disk_extent(
> 					node_plugin_by_node(JZNODE(cur))->csum(JZNODE(cur), 0);
> 				zrelse(JZNODE(cur));
> 			}
> +
> 			ClearPageError(pg);
> +			set_page_dirty_notag(pg);
> 			set_page_writeback(pg);
> 
> 			if (get_current_context()->entd) {
> -- 
> 2.6.0