RFC: fixing kernel oops on interrupted COMMIT from nfs_commit_file

RFC: fixing kernel oops on interrupted COMMIT from nfs_commit_file

[Olga Kornievskaia]

Hi folks,

Looking for suggestions on how to fix a kernel oops.

It's possible that there is a ctrl-c when the COMMIT is send. In case
of the COPY, it calls
nfs_commit_file() which calls wait_on_commit() that is interrupted by
the crtl-c and frees the nfs_page request. So when asynchronous COMMIT
rpc comes back it tried to use the nfs_page request and gets the oops.

I think typical uses of nfs_commit_inode() are never interruptible at
least I wasn't able to trigger it.

The only way I can think of fixing the problem is to change
wait_on_commit() from a TASK_KILLABLE to TASK_UNINTERRUPTIBLE but I'm
not sure if this is the right solution

diff --git a/fs/nfs/write.c b/fs/nfs/write.c
index abb2c8a..aefff49 100644
--- a/fs/nfs/write.c
+++ b/fs/nfs/write.c
@@ -1557,7 +1557,7 @@ static void nfs_writeback_result(struct rpc_task *task,
 static int wait_on_commit(struct nfs_mds_commit_info *cinfo)
 {
  return wait_on_atomic_t(&cinfo->rpcs_out,
- nfs_wait_atomic_killable, TASK_KILLABLE);
+ nfs_wait_atomic_killable, TASK_UNINTERRUPTIBLE);
 }

 static void nfs_commit_begin(struct nfs_mds_commit_info *cinfo)

[  207.717883] BUG: unable to handle kernel NULL pointer dereference
at           (null)
[  207.720748] IP: __list_del_entry_valid+0x29/0xd0
[  207.722079] PGD 0
[  207.722080]
[  207.723167] Oops: 0000 [#1] SMP
[  207.723988] Modules linked in: nfsv4 dns_resolver nfs rfcomm fuse
xt_CHECKSUM ipt_MASQUERADE nf_nat_masquerade_ipv4 tun ip6t_rpfilter
ipt_REJECT nf_reject_ipv4 ip6t_REJECT nf_reject_ipv6 xt_conntrack
ip_set nfnetlink ebtable_nat ebtable_broute bridge stp llc
ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6
ip6table_mangle ip6table_security ip6table_raw iptable_nat
nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack
libcrc32c iptable_mangle iptable_security iptable_raw ebtable_filter
ebtables ip6table_filter ip6_tables iptable_filter bnep
vmw_vsock_vmci_transport vsock dm_mirror dm_region_hash dm_log dm_mod
snd_seq_midi snd_seq_midi_event coretemp crct10dif_pclmul crc32_pclmul
ghash_clmulni_intel pcbc btusb btrtl btbcm btintel snd_ens1371
aesni_intel snd_ac97_codec ppdev ac97_bus
[  207.741809]  crypto_simd snd_seq cryptd glue_helper bluetooth
uvcvideo vmw_balloon pcspkr snd_pcm videobuf2_vmalloc videobuf2_memops
videobuf2_v4l2 videobuf2_core videodev snd_rawmidi snd_timer nfit
snd_seq_device snd libnvdimm sg rfkill soundcore vmw_vmci shpchp
i2c_piix4 parport_pc parport nfsd acpi_cpufreq auth_rpcgss nfs_acl
lockd grace sunrpc ip_tables ext4 jbd2 mbcache sr_mod cdrom sd_mod
ata_generic pata_acpi vmwgfx drm_kms_helper syscopyarea sysfillrect
sysimgblt fb_sys_fops ttm drm ahci libahci ata_piix crc32c_intel
libata mptspi scsi_transport_spi serio_raw mptscsih e1000 mptbase
i2c_core
[  207.757915] CPU: 0 PID: 95 Comm: kworker/0:2 Not tainted 4.11.0-rc5+ #110
[  207.759797] Hardware name: VMware, Inc. VMware Virtual
Platform/440BX Desktop Reference Platform, BIOS 6.00 07/02/2015
[  207.762838] Workqueue: nfsiod rpc_async_release [sunrpc]
[  207.764355] task: ffff88007a7ada00 task.stack: ffffc90002c08000
[  207.766047] RIP: 0010:__list_del_entry_valid+0x29/0xd0
[  207.767516] RSP: 0018:ffffc90002c0bd98 EFLAGS: 00010207
[  207.769026] RAX: ffff88007472cc80 RBX: ffff88007472d500 RCX: ffff88007b61aae0
[  207.771273] RDX: dead000000000200 RSI: ffff880079782c40 RDI: ffff88007472d500
[  207.773887] RBP: ffffc90002c0bd98 R08: 0000000000000000 R09: ffff88007955b2b8
[  207.775276] R10: ffff88007955b2f0 R11: ffffea0001bf8200 R12: ffff880079782c00
[  207.776649] R13: 0000000000000000 R14: ffff880079782dd8 R15: ffff880079782dc8
[  207.778087] FS:  0000000000000000(0000) GS:ffff88007b600000(0000)
knlGS:0000000000000000
[  207.780238] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  207.781485] CR2: 0000000000000000 CR3: 0000000072c0b000 CR4: 00000000001406f0
[  207.782995] Call Trace:
[  207.783603]  nfs_commit_release_pages+0x98/0x240 [nfs]
[  207.784756]  nfs_commit_release+0x16/0x30 [nfs]
[  207.785687]  rpc_free_task+0x30/0x70 [sunrpc]
[  207.786580]  rpc_async_release+0x12/0x20 [sunrpc]
[  207.787747]  process_one_work+0x165/0x410
[  207.789456]  worker_thread+0x137/0x4c0
[  207.791053]  kthread+0x101/0x140
[  207.792164]  ? rescuer_thread+0x3b0/0x3b0
[  207.793345]  ? kthread_park+0x90/0x90
[  207.794407]  ret_from_fork+0x2c/0x40
[  207.795431] Code: 00 00 55 48 8b 07 48 ba 00 01 00 00 00 00 ad de
4c 8b 47 08 48 89 e5 48 39 d0 74 27 48 ba 00 02 00 00 00 00 ad de 49
39 d0 74 7e <4d> 8b 00 4c 39 c7 75 55 4c 8b 40 08 4c 39 c7 75 2b b8 01
00 00
[  207.800010] RIP: __list_del_entry_valid+0x29/0xd0 RSP: ffffc90002c0bd98
[  207.801524] CR2: 0000000000000000
[  207.802302] ---[ end trace 4b559c9b50350277 ]---
[  207.803242] Kernel panic - not syncing: Fatal exception
[  207.805361] Kernel Offset: disabled
[  207.806434] ---[ end Kernel panic - not syncing: Fatal exception

Re: RFC: fixing kernel oops on interrupted COMMIT from nfs_commit_file

[Trond Myklebust]

T24gVGh1LCAyMDE3LTA0LTEzIGF0IDE0OjAwIC0wNDAwLCBPbGdhIEtvcm5pZXZza2FpYSB3cm90
ZToNCj4gSGkgZm9sa3MsDQo+IA0KPiBMb29raW5nIGZvciBzdWdnZXN0aW9ucyBvbiBob3cgdG8g
Zml4IGEga2VybmVsIG9vcHMuDQo+IA0KPiBJdCdzIHBvc3NpYmxlIHRoYXQgdGhlcmUgaXMgYSBj
dHJsLWMgd2hlbiB0aGUgQ09NTUlUIGlzIHNlbmQuIEluIGNhc2UNCj4gb2YgdGhlIENPUFksIGl0
IGNhbGxzDQo+IG5mc19jb21taXRfZmlsZSgpIHdoaWNoIGNhbGxzIHdhaXRfb25fY29tbWl0KCkg
dGhhdCBpcyBpbnRlcnJ1cHRlZCBieQ0KPiB0aGUgY3J0bC1jIGFuZCBmcmVlcyB0aGUgbmZzX3Bh
Z2UgcmVxdWVzdC4gU28gd2hlbiBhc3luY2hyb25vdXMNCj4gQ09NTUlUDQo+IHJwYyBjb21lcyBi
YWNrIGl0IHRyaWVkIHRvIHVzZSB0aGUgbmZzX3BhZ2UgcmVxdWVzdCBhbmQgZ2V0cyB0aGUNCj4g
b29wcy4NCj4gDQoNCklzIHRoYXQgY2FsbCB0byBuZnNfZnJlZV9yZXF1ZXN0KCkgaW4gbmZzX2Nv
bW1pdF9maWxlKCkgY29ycmVjdD8gSXQNCmxvb2tzIHRvIG1lIGFzIGlmIHRoZSBzYW1lIHJlcXVl
c3Qgd2lsbCBiZSBmcmVlZCBpbg0KbmZzX2NvbW1pdF9yZWxlYXNlX3BhZ2VzKCkuDQoNCkFubmE/
DQoNCi0tIA0KVHJvbmQgTXlrbGVidXN0DQpMaW51eCBORlMgY2xpZW50IG1haW50YWluZXIsIFBy
aW1hcnlEYXRhDQp0cm9uZC5teWtsZWJ1c3RAcHJpbWFyeWRhdGEuY29tDQo=

Re: RFC: fixing kernel oops on interrupted COMMIT from nfs_commit_file

[Olga Kornievskaia]

On Thu, Apr 13, 2017 at 2:51 PM, Trond Myklebust
<trondmy@primarydata.com> wrote:
> On Thu, 2017-04-13 at 14:00 -0400, Olga Kornievskaia wrote:
>> Hi folks,
>>
>> Looking for suggestions on how to fix a kernel oops.
>>
>> It's possible that there is a ctrl-c when the COMMIT is send. In case
>> of the COPY, it calls
>> nfs_commit_file() which calls wait_on_commit() that is interrupted by
>> the crtl-c and frees the nfs_page request. So when asynchronous
>> COMMIT
>> rpc comes back it tried to use the nfs_page request and gets the
>> oops.
>>
>
> Is that call to nfs_free_request() in nfs_commit_file() correct?

yes, nfs_commit_file() creates a new request via nfs_create_request()
and in the end if calls nfs_free_request();

> It looks to me as if the same request will be freed in
> nfs_commit_release_pages().

so nfs_commit_release_pages() thru the
nfs_unlock_and_release_request() is going to call
nfs_release_request() from req->wb_kref.. I'm not sure if this is
setup(?) for the copy commit path?

Otherwise, it would have seem that we'd be doing a double free and I
haven't seen that in testing (not that it can't be true)...



>
> Anna?
>
> --
> Trond Myklebust
> Linux NFS client maintainer, PrimaryData
> trond.myklebust@primarydata.com

Re: RFC: fixing kernel oops on interrupted COMMIT from nfs_commit_file

[Anna Schumaker]

On 04/13/2017 03:07 PM, Olga Kornievskaia wrote:
> On Thu, Apr 13, 2017 at 2:51 PM, Trond Myklebust
> <trondmy@primarydata.com> wrote:
>> On Thu, 2017-04-13 at 14:00 -0400, Olga Kornievskaia wrote:
>>> Hi folks,
>>>
>>> Looking for suggestions on how to fix a kernel oops.
>>>
>>> It's possible that there is a ctrl-c when the COMMIT is send. In case
>>> of the COPY, it calls
>>> nfs_commit_file() which calls wait_on_commit() that is interrupted by
>>> the crtl-c and frees the nfs_page request. So when asynchronous
>>> COMMIT
>>> rpc comes back it tried to use the nfs_page request and gets the
>>> oops.
>>>
>>
>> Is that call to nfs_free_request() in nfs_commit_file() correct?
> 
> yes, nfs_commit_file() creates a new request via nfs_create_request()
> and in the end if calls nfs_free_request();
> 
>> It looks to me as if the same request will be freed in
>> nfs_commit_release_pages().
> 
> so nfs_commit_release_pages() thru the
> nfs_unlock_and_release_request() is going to call
> nfs_release_request() from req->wb_kref.. I'm not sure if this is
> setup(?) for the copy commit path?
> 
> Otherwise, it would have seem that we'd be doing a double free and I
> haven't seen that in testing (not that it can't be true)...

I haven't seen any double-free messages during my testing either, so I thought it was okay.  It's possible I'm wrong, though.  I wonder if this is something that memory poisoning can help figure out?

Anna

> 
> 
> 
>>
>> Anna?
>>
>> --
>> Trond Myklebust
>> Linux NFS client maintainer, PrimaryData
>> trond.myklebust@primarydata.com

Re: RFC: fixing kernel oops on interrupted COMMIT from nfs_commit_file

[Anna Schumaker]

On 04/13/2017 03:16 PM, Anna Schumaker wrote:
> 
> 
> On 04/13/2017 03:07 PM, Olga Kornievskaia wrote:
>> On Thu, Apr 13, 2017 at 2:51 PM, Trond Myklebust
>> <trondmy@primarydata.com> wrote:
>>> On Thu, 2017-04-13 at 14:00 -0400, Olga Kornievskaia wrote:
>>>> Hi folks,
>>>>
>>>> Looking for suggestions on how to fix a kernel oops.
>>>>
>>>> It's possible that there is a ctrl-c when the COMMIT is send. In case
>>>> of the COPY, it calls
>>>> nfs_commit_file() which calls wait_on_commit() that is interrupted by
>>>> the crtl-c and frees the nfs_page request. So when asynchronous
>>>> COMMIT
>>>> rpc comes back it tried to use the nfs_page request and gets the
>>>> oops.
>>>>
>>>
>>> Is that call to nfs_free_request() in nfs_commit_file() correct?
>>
>> yes, nfs_commit_file() creates a new request via nfs_create_request()
>> and in the end if calls nfs_free_request();
>>
>>> It looks to me as if the same request will be freed in
>>> nfs_commit_release_pages().
>>
>> so nfs_commit_release_pages() thru the
>> nfs_unlock_and_release_request() is going to call
>> nfs_release_request() from req->wb_kref.. I'm not sure if this is
>> setup(?) for the copy commit path?
>>
>> Otherwise, it would have seem that we'd be doing a double free and I
>> haven't seen that in testing (not that it can't be true)...
> 
> I haven't seen any double-free messages during my testing either, so I thought it was okay.  It's possible I'm wrong, though.  I wonder if this is something that memory poisoning can help figure out?

After some experimenting, I can still use the nfs_page after nfs_commit_inode() has returned withotu any memory issues.

> 
> Anna
> 
>>
>>
>>
>>>
>>> Anna?
>>>
>>> --
>>> Trond Myklebust
>>> Linux NFS client maintainer, PrimaryData
>>> trond.myklebust@primarydata.com

Re: RFC: fixing kernel oops on interrupted COMMIT from nfs_commit_file

[Olga Kornievskaia]

On Thu, Apr 13, 2017 at 4:13 PM, Anna Schumaker
<Anna.Schumaker@netapp.com> wrote:
>
>
> On 04/13/2017 03:16 PM, Anna Schumaker wrote:
>>
>>
>> On 04/13/2017 03:07 PM, Olga Kornievskaia wrote:
>>> On Thu, Apr 13, 2017 at 2:51 PM, Trond Myklebust
>>> <trondmy@primarydata.com> wrote:
>>>> On Thu, 2017-04-13 at 14:00 -0400, Olga Kornievskaia wrote:
>>>>> Hi folks,
>>>>>
>>>>> Looking for suggestions on how to fix a kernel oops.
>>>>>
>>>>> It's possible that there is a ctrl-c when the COMMIT is send. In case
>>>>> of the COPY, it calls
>>>>> nfs_commit_file() which calls wait_on_commit() that is interrupted by
>>>>> the crtl-c and frees the nfs_page request. So when asynchronous
>>>>> COMMIT
>>>>> rpc comes back it tried to use the nfs_page request and gets the
>>>>> oops.
>>>>>
>>>>
>>>> Is that call to nfs_free_request() in nfs_commit_file() correct?
>>>
>>> yes, nfs_commit_file() creates a new request via nfs_create_request()
>>> and in the end if calls nfs_free_request();
>>>
>>>> It looks to me as if the same request will be freed in
>>>> nfs_commit_release_pages().
>>>
>>> so nfs_commit_release_pages() thru the
>>> nfs_unlock_and_release_request() is going to call
>>> nfs_release_request() from req->wb_kref.. I'm not sure if this is
>>> setup(?) for the copy commit path?
>>>
>>> Otherwise, it would have seem that we'd be doing a double free and I
>>> haven't seen that in testing (not that it can't be true)...
>>
>> I haven't seen any double-free messages during my testing either, so I thought it was okay.  It's possible I'm wrong, though.  I wonder if this is something that memory poisoning can help figure out?
>
> After some experimenting, I can still use the nfs_page after nfs_commit_inode() has returned withotu any memory issues.

I think perhaps nfs_commit_file() needs to call nfs_release_request()
instead of directly calling nfs_free_request(). nfs_release_request
does a put on wb_kref and once it's 0 it'll call release.

So I think with that change my ctrl-c no longer produces the oops
either. I'll test a bit more and I'll send another patch.



>
>>
>> Anna
>>
>>>
>>>
>>>
>>>>
>>>> Anna?
>>>>
>>>> --
>>>> Trond Myklebust
>>>> Linux NFS client maintainer, PrimaryData
>>>> trond.myklebust@primarydata.com

Re: RFC: fixing kernel oops on interrupted COMMIT from nfs_commit_file

[Trond Myklebust]

T24gVGh1LCAyMDE3LTA0LTEzIGF0IDE2OjEzIC0wNDAwLCBBbm5hIFNjaHVtYWtlciB3cm90ZToN
Cj4gDQo+IE9uIDA0LzEzLzIwMTcgMDM6MTYgUE0sIEFubmEgU2NodW1ha2VyIHdyb3RlOg0KPiA+
IA0KPiA+IA0KPiA+IE9uIDA0LzEzLzIwMTcgMDM6MDcgUE0sIE9sZ2EgS29ybmlldnNrYWlhIHdy
b3RlOg0KPiA+ID4gT24gVGh1LCBBcHIgMTMsIDIwMTcgYXQgMjo1MSBQTSwgVHJvbmQgTXlrbGVi
dXN0DQo+ID4gPiA8dHJvbmRteUBwcmltYXJ5ZGF0YS5jb20+IHdyb3RlOg0KPiA+ID4gPiBPbiBU
aHUsIDIwMTctMDQtMTMgYXQgMTQ6MDAgLTA0MDAsIE9sZ2EgS29ybmlldnNrYWlhIHdyb3RlOg0K
PiA+ID4gPiA+IEhpIGZvbGtzLA0KPiA+ID4gPiA+IA0KPiA+ID4gPiA+IExvb2tpbmcgZm9yIHN1
Z2dlc3Rpb25zIG9uIGhvdyB0byBmaXggYSBrZXJuZWwgb29wcy4NCj4gPiA+ID4gPiANCj4gPiA+
ID4gPiBJdCdzIHBvc3NpYmxlIHRoYXQgdGhlcmUgaXMgYSBjdHJsLWMgd2hlbiB0aGUgQ09NTUlU
IGlzIHNlbmQuDQo+ID4gPiA+ID4gSW4gY2FzZQ0KPiA+ID4gPiA+IG9mIHRoZSBDT1BZLCBpdCBj
YWxscw0KPiA+ID4gPiA+IG5mc19jb21taXRfZmlsZSgpIHdoaWNoIGNhbGxzIHdhaXRfb25fY29t
bWl0KCkgdGhhdCBpcw0KPiA+ID4gPiA+IGludGVycnVwdGVkIGJ5DQo+ID4gPiA+ID4gdGhlIGNy
dGwtYyBhbmQgZnJlZXMgdGhlIG5mc19wYWdlIHJlcXVlc3QuIFNvIHdoZW4NCj4gPiA+ID4gPiBh
c3luY2hyb25vdXMNCj4gPiA+ID4gPiBDT01NSVQNCj4gPiA+ID4gPiBycGMgY29tZXMgYmFjayBp
dCB0cmllZCB0byB1c2UgdGhlIG5mc19wYWdlIHJlcXVlc3QgYW5kIGdldHMNCj4gPiA+ID4gPiB0
aGUNCj4gPiA+ID4gPiBvb3BzLg0KPiA+ID4gPiA+IA0KPiA+ID4gPiANCj4gPiA+ID4gSXMgdGhh
dCBjYWxsIHRvIG5mc19mcmVlX3JlcXVlc3QoKSBpbiBuZnNfY29tbWl0X2ZpbGUoKQ0KPiA+ID4g
PiBjb3JyZWN0Pw0KPiA+ID4gDQo+ID4gPiB5ZXMsIG5mc19jb21taXRfZmlsZSgpIGNyZWF0ZXMg
YSBuZXcgcmVxdWVzdCB2aWENCj4gPiA+IG5mc19jcmVhdGVfcmVxdWVzdCgpDQo+ID4gPiBhbmQg
aW4gdGhlIGVuZCBpZiBjYWxscyBuZnNfZnJlZV9yZXF1ZXN0KCk7DQo+ID4gPiANCj4gPiA+ID4g
SXQgbG9va3MgdG8gbWUgYXMgaWYgdGhlIHNhbWUgcmVxdWVzdCB3aWxsIGJlIGZyZWVkIGluDQo+
ID4gPiA+IG5mc19jb21taXRfcmVsZWFzZV9wYWdlcygpLg0KPiA+ID4gDQo+ID4gPiBzbyBuZnNf
Y29tbWl0X3JlbGVhc2VfcGFnZXMoKSB0aHJ1IHRoZQ0KPiA+ID4gbmZzX3VubG9ja19hbmRfcmVs
ZWFzZV9yZXF1ZXN0KCkgaXMgZ29pbmcgdG8gY2FsbA0KPiA+ID4gbmZzX3JlbGVhc2VfcmVxdWVz
dCgpIGZyb20gcmVxLT53Yl9rcmVmLi4gSSdtIG5vdCBzdXJlIGlmIHRoaXMgaXMNCj4gPiA+IHNl
dHVwKD8pIGZvciB0aGUgY29weSBjb21taXQgcGF0aD8NCj4gPiA+IA0KPiA+ID4gT3RoZXJ3aXNl
LCBpdCB3b3VsZCBoYXZlIHNlZW0gdGhhdCB3ZSdkIGJlIGRvaW5nIGEgZG91YmxlIGZyZWUNCj4g
PiA+IGFuZCBJDQo+ID4gPiBoYXZlbid0IHNlZW4gdGhhdCBpbiB0ZXN0aW5nIChub3QgdGhhdCBp
dCBjYW4ndCBiZSB0cnVlKS4uLg0KPiA+IA0KPiA+IEkgaGF2ZW4ndCBzZWVuIGFueSBkb3VibGUt
ZnJlZSBtZXNzYWdlcyBkdXJpbmcgbXkgdGVzdGluZyBlaXRoZXIsDQo+ID4gc28gSSB0aG91Z2h0
IGl0IHdhcyBva2F5LsKgwqBJdCdzIHBvc3NpYmxlIEknbSB3cm9uZywgdGhvdWdoLsKgwqBJDQo+
ID4gd29uZGVyIGlmIHRoaXMgaXMgc29tZXRoaW5nIHRoYXQgbWVtb3J5IHBvaXNvbmluZyBjYW4g
aGVscCBmaWd1cmUNCj4gPiBvdXQ/DQo+IA0KPiBBZnRlciBzb21lIGV4cGVyaW1lbnRpbmcsIEkg
Y2FuIHN0aWxsIHVzZSB0aGUgbmZzX3BhZ2UgYWZ0ZXINCj4gbmZzX2NvbW1pdF9pbm9kZSgpIGhh
cyByZXR1cm5lZCB3aXRob3R1IGFueSBtZW1vcnkgaXNzdWVzLg0KPiANCg0KV2FpdC4uLg0KDQpP
Sywgc28gbmZzX3NjYW5fY29tbWl0X2xpc3QoKSBkb2VzIGluZGVlZCB0YWtlIGEgcmVmZXJlbmNl
IHRvIHRoZSByZXEtDQo+d2Jfa3JlZiwgc28gdGhhdCBiYWxhbmNlcyB0aGUgY2FsbCB0byBuZnNf
cmVsZWFzZV9yZXF1ZXN0KCkgaW4NCm5mc19jb21taXRfcmVsZWFzZV9wYWdlcygpLCBob3dldmVy
IGl0IGFsc28gbWVhbnMgdGhhdCB5b3Ugc2hvdWxkIG5vdA0KYmUgY2FsbGluZyBuZnNfZnJlZV9y
ZXF1ZXN0KCksIHNpbmNlIGRvaW5nIHNvIGNpcmN1bXZlbnRzIHRoZQ0KcmVmY291bnRpbmcgbWVj
aGFuaXNtLg0KDQpTZWNvbmRseSwgaWYgeW91IHdhbnQgdG8gcmVsZWFzZSB0aGUgcmVxdWVzdCBh
bmQgeW91IGFyZSBub3Qgc3VyZQ0Kd2hldGhlciBvciBub3QgaXQgZ290IGNsZWFyZWQgb2ZmIHRo
ZSBpbm9kZSdzIGNpbmZvIGNvbW1pdCBsaXN0IHlldCwNCnlvdSBtYXkgYWxzbyBuZWVkIHRvIGxv
Y2sgdGhhdCByZXF1ZXN0IGFuZCBjYWxsDQpuZnNfY2xlYXJfcmVxdWVzdF9jb21taXQoKS4NCg0K
LS0gDQpUcm9uZCBNeWtsZWJ1c3QNCkxpbnV4IE5GUyBjbGllbnQgbWFpbnRhaW5lciwgUHJpbWFy
eURhdGENCnRyb25kLm15a2xlYnVzdEBwcmltYXJ5ZGF0YS5jb20NCg==

Re: RFC: fixing kernel oops on interrupted COMMIT from nfs_commit_file

[Olga Kornievskaia]

On Thu, Apr 13, 2017 at 4:50 PM, Trond Myklebust
<trondmy@primarydata.com> wrote:
> On Thu, 2017-04-13 at 16:13 -0400, Anna Schumaker wrote:
>>
>> On 04/13/2017 03:16 PM, Anna Schumaker wrote:
>> >
>> >
>> > On 04/13/2017 03:07 PM, Olga Kornievskaia wrote:
>> > > On Thu, Apr 13, 2017 at 2:51 PM, Trond Myklebust
>> > > <trondmy@primarydata.com> wrote:
>> > > > On Thu, 2017-04-13 at 14:00 -0400, Olga Kornievskaia wrote:
>> > > > > Hi folks,
>> > > > >
>> > > > > Looking for suggestions on how to fix a kernel oops.
>> > > > >
>> > > > > It's possible that there is a ctrl-c when the COMMIT is send.
>> > > > > In case
>> > > > > of the COPY, it calls
>> > > > > nfs_commit_file() which calls wait_on_commit() that is
>> > > > > interrupted by
>> > > > > the crtl-c and frees the nfs_page request. So when
>> > > > > asynchronous
>> > > > > COMMIT
>> > > > > rpc comes back it tried to use the nfs_page request and gets
>> > > > > the
>> > > > > oops.
>> > > > >
>> > > >
>> > > > Is that call to nfs_free_request() in nfs_commit_file()
>> > > > correct?
>> > >
>> > > yes, nfs_commit_file() creates a new request via
>> > > nfs_create_request()
>> > > and in the end if calls nfs_free_request();
>> > >
>> > > > It looks to me as if the same request will be freed in
>> > > > nfs_commit_release_pages().
>> > >
>> > > so nfs_commit_release_pages() thru the
>> > > nfs_unlock_and_release_request() is going to call
>> > > nfs_release_request() from req->wb_kref.. I'm not sure if this is
>> > > setup(?) for the copy commit path?
>> > >
>> > > Otherwise, it would have seem that we'd be doing a double free
>> > > and I
>> > > haven't seen that in testing (not that it can't be true)...
>> >
>> > I haven't seen any double-free messages during my testing either,
>> > so I thought it was okay.  It's possible I'm wrong, though.  I
>> > wonder if this is something that memory poisoning can help figure
>> > out?
>>
>> After some experimenting, I can still use the nfs_page after
>> nfs_commit_inode() has returned withotu any memory issues.
>>
>
> Wait...
>
> OK, so nfs_scan_commit_list() does indeed take a reference to the req-
>>wb_kref, so that balances the call to nfs_release_request() in
> nfs_commit_release_pages(), however it also means that you should not
> be calling nfs_free_request(), since doing so circumvents the
> refcounting mechanism.
>

Right now when req is created in nfs_commit_file() it starts out with wb_kref=1.
After calling, nfs_scan_commit_list() wb_kref=2
Now if in normal operations
nfs_commit_release_pages will drop that to 1
And then calling nfs_release_commit in nfs_commit_file() will finally
drop to 0 and release.
If ctrl-c happened,
then nfs_commit_file will drop the ref first but will not free it and
that will allow the commit to proceed and finish the rpc?

> Secondly, if you want to release the request and you are not sure
> whether or not it got cleared off the inode's cinfo commit list yet,
> you may also need to lock that request and call
> nfs_clear_request_commit().

Looking at what the function does, I don't see why this is needed.
"wb_page" is NULL for this type of commit and there is no pnfs in this
case.

[PATCH 1/1] NFS fixing kernel oops on interrupted COMMIT from nfs_commit_file

[Olga Kornievskaia]

nfs_commit_file() should use the nfs_release_commit() to use the
refcounting mechanism. Otherwise it can lead to the following
oops if COMMIT was interrupted by a signal.
[  207.717883] BUG: unable to handle kernel NULL pointer dereference
at           (null)
[  207.720748] IP: __list_del_entry_valid+0x29/0xd0
[  207.722079] PGD 0
[  207.722080]
[  207.723167] Oops: 0000 [#1] SMP
[  207.723988] Modules linked in: nfsv4 dns_resolver nfs rfcomm fuse
xt_CHECKSUM ipt_MASQUERADE nf_nat_masquerade_ipv4 tun ip6t_rpfilter
ipt_REJECT nf_reject_ipv4 ip6t_REJECT nf_reject_ipv6 xt_conntrack
ip_set nfnetlink ebtable_nat ebtable_broute bridge stp llc
ip6table_nat nf_conntrack_ipv6 nf_defrag_ipv6 nf_nat_ipv6
ip6table_mangle ip6table_security ip6table_raw iptable_nat
nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack
libcrc32c iptable_mangle iptable_security iptable_raw ebtable_filter
ebtables ip6table_filter ip6_tables iptable_filter bnep
vmw_vsock_vmci_transport vsock dm_mirror dm_region_hash dm_log dm_mod
snd_seq_midi snd_seq_midi_event coretemp crct10dif_pclmul crc32_pclmul
ghash_clmulni_intel pcbc btusb btrtl btbcm btintel snd_ens1371
aesni_intel snd_ac97_codec ppdev ac97_bus
[  207.741809]  crypto_simd snd_seq cryptd glue_helper bluetooth
uvcvideo vmw_balloon pcspkr snd_pcm videobuf2_vmalloc videobuf2_memops
videobuf2_v4l2 videobuf2_core videodev snd_rawmidi snd_timer nfit
snd_seq_device snd libnvdimm sg rfkill soundcore vmw_vmci shpchp
i2c_piix4 parport_pc parport nfsd acpi_cpufreq auth_rpcgss nfs_acl
lockd grace sunrpc ip_tables ext4 jbd2 mbcache sr_mod cdrom sd_mod
ata_generic pata_acpi vmwgfx drm_kms_helper syscopyarea sysfillrect
sysimgblt fb_sys_fops ttm drm ahci libahci ata_piix crc32c_intel
libata mptspi scsi_transport_spi serio_raw mptscsih e1000 mptbase
i2c_core
[  207.757915] CPU: 0 PID: 95 Comm: kworker/0:2 Not tainted 4.11.0-rc5+ #110
[  207.759797] Hardware name: VMware, Inc. VMware Virtual
Platform/440BX Desktop Reference Platform, BIOS 6.00 07/02/2015
[  207.762838] Workqueue: nfsiod rpc_async_release [sunrpc]
[  207.764355] task: ffff88007a7ada00 task.stack: ffffc90002c08000
[  207.766047] RIP: 0010:__list_del_entry_valid+0x29/0xd0
[  207.767516] RSP: 0018:ffffc90002c0bd98 EFLAGS: 00010207
[  207.769026] RAX: ffff88007472cc80 RBX: ffff88007472d500 RCX: ffff88007b61aae0
[  207.771273] RDX: dead000000000200 RSI: ffff880079782c40 RDI: ffff88007472d500
[  207.773887] RBP: ffffc90002c0bd98 R08: 0000000000000000 R09: ffff88007955b2b8
[  207.775276] R10: ffff88007955b2f0 R11: ffffea0001bf8200 R12: ffff880079782c00
[  207.776649] R13: 0000000000000000 R14: ffff880079782dd8 R15: ffff880079782dc8
[  207.778087] FS:  0000000000000000(0000) GS:ffff88007b600000(0000)
knlGS:0000000000000000
[  207.780238] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  207.781485] CR2: 0000000000000000 CR3: 0000000072c0b000 CR4: 00000000001406f0
[  207.782995] Call Trace:
[  207.783603]  nfs_commit_release_pages+0x98/0x240 [nfs]
[  207.784756]  nfs_commit_release+0x16/0x30 [nfs]
[  207.785687]  rpc_free_task+0x30/0x70 [sunrpc]
[  207.786580]  rpc_async_release+0x12/0x20 [sunrpc]
[  207.787747]  process_one_work+0x165/0x410
[  207.789456]  worker_thread+0x137/0x4c0
[  207.791053]  kthread+0x101/0x140
[  207.792164]  ? rescuer_thread+0x3b0/0x3b0
[  207.793345]  ? kthread_park+0x90/0x90
[  207.794407]  ret_from_fork+0x2c/0x40
[  207.795431] Code: 00 00 55 48 8b 07 48 ba 00 01 00 00 00 00 ad de
4c 8b 47 08 48 89 e5 48 39 d0 74 27 48 ba 00 02 00 00 00 00 ad de 49
39 d0 74 7e <4d> 8b 00 4c 39 c7 75 55 4c 8b 40 08 4c 39 c7 75 2b b8 01
00 00
[  207.800010] RIP: __list_del_entry_valid+0x29/0xd0 RSP: ffffc90002c0bd98
[  207.801524] CR2: 0000000000000000
[  207.802302] ---[ end trace 4b559c9b50350277 ]---
[  207.803242] Kernel panic - not syncing: Fatal exception
[  207.805361] Kernel Offset: disabled
[  207.806434] ---[ end Kernel panic - not syncing: Fatal exception

Signed-off-by: Olga Kornievskaia <kolga@netapp.com>
---
 fs/nfs/write.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/fs/nfs/write.c b/fs/nfs/write.c
index abb2c8a..c4ceb79 100644
--- a/fs/nfs/write.c
+++ b/fs/nfs/write.c
@@ -1743,7 +1743,7 @@ int nfs_commit_file(struct file *file, struct nfs_write_verifier *verf)
 	if (ret > 0)
 		ret = 0;
 
-	nfs_free_request(req);
+	nfs_release_request(req);
 out_put:
 	put_nfs_open_context(open);
 	return ret;
-- 
1.8.3.1

Re: RFC: fixing kernel oops on interrupted COMMIT from nfs_commit_file

[Trond Myklebust]

T24gRnJpLCAyMDE3LTA0LTE0IGF0IDExOjU2IC0wNDAwLCBPbGdhIEtvcm5pZXZza2FpYSB3cm90
ZToNCj4gT24gVGh1LCBBcHIgMTMsIDIwMTcgYXQgNDo1MCBQTSwgVHJvbmQgTXlrbGVidXN0DQo+
IDx0cm9uZG15QHByaW1hcnlkYXRhLmNvbT4gd3JvdGU6DQo+ID4gDQo+ID4gU2Vjb25kbHksIGlm
IHlvdSB3YW50IHRvIHJlbGVhc2UgdGhlIHJlcXVlc3QgYW5kIHlvdSBhcmUgbm90IHN1cmUNCj4g
PiB3aGV0aGVyIG9yIG5vdCBpdCBnb3QgY2xlYXJlZCBvZmYgdGhlIGlub2RlJ3MgY2luZm8gY29t
bWl0IGxpc3QNCj4gPiB5ZXQsDQo+ID4geW91IG1heSBhbHNvIG5lZWQgdG8gbG9jayB0aGF0IHJl
cXVlc3QgYW5kIGNhbGwNCj4gPiBuZnNfY2xlYXJfcmVxdWVzdF9jb21taXQoKS4NCj4gDQo+IExv
b2tpbmcgYXQgd2hhdCB0aGUgZnVuY3Rpb24gZG9lcywgSSBkb24ndCBzZWUgd2h5IHRoaXMgaXMg
bmVlZGVkLg0KPiAid2JfcGFnZSIgaXMgTlVMTCBmb3IgdGhpcyB0eXBlIG9mIGNvbW1pdCBhbmQg
dGhlcmUgaXMgbm8gcG5mcyBpbg0KPiB0aGlzDQo+IGNhc2UuDQoNClNvbWV0aGluZyBuZWVkcyB0
byBlbnN1cmUgdGhhdCB0aGUgcmVxdWVzdCBpcyBub3Qgc2l0dGluZyBvbiBhIGNvbW1pdA0KbGlz
dC4gVGhhdCBjYW4gaGFwcGVuIGlmIHRoZSBjb21taXQgc3VjY2VlZGVkLCBidXQgcmV0dXJuZWQg
YSBkaWZmZXJlbnQNCnZlcmlmaWVyLCBvciBpdCBjYW4gaGFwcGVuIGlmIG5mc19zY2FuX2NvbW1p
dCgpIGV4aXRzIGVhcmx5Lg0KDQotLSANClRyb25kIE15a2xlYnVzdA0KTGludXggTkZTIGNsaWVu
dCBtYWludGFpbmVyLCBQcmltYXJ5RGF0YQ0KdHJvbmQubXlrbGVidXN0QHByaW1hcnlkYXRhLmNv
bQ0K

Re: RFC: fixing kernel oops on interrupted COMMIT from nfs_commit_file

[Olga Kornievskaia]

On Fri, Apr 14, 2017 at 3:16 PM, Trond Myklebust
<trondmy@primarydata.com> wrote:
> On Fri, 2017-04-14 at 11:56 -0400, Olga Kornievskaia wrote:
>> On Thu, Apr 13, 2017 at 4:50 PM, Trond Myklebust
>> <trondmy@primarydata.com> wrote:
>> >
>> > Secondly, if you want to release the request and you are not sure
>> > whether or not it got cleared off the inode's cinfo commit list
>> > yet,
>> > you may also need to lock that request and call
>> > nfs_clear_request_commit().
>>
>> Looking at what the function does, I don't see why this is needed.
>> "wb_page" is NULL for this type of commit and there is no pnfs in
>> this
>> case.
>
> Something needs to ensure that the request is not sitting on a commit
> list. That can happen if the commit succeeded, but returned a different
> verifier, or it can happen if nfs_scan_commit() exits early.

First point I'd like you to consider is that your last statement as a
separate problem that needs to be solved with a different patch.

Secondly, I don't understand how to determine "if nfs_commit_file()
isn't sure whether or not request got cleared off the inode's cinfo
commit list". There are two cases you pointed to 1) verifier mismatch
and 2) nfs_scan_commit didn't even get to the request (caz INT_MAX
commits were queued before that)?

For the verifier mismatch: "NFS_CONTEXT_RESEND_WRITES" is set. So
nfs_commit_file() can check for that. But I guess I'm not sure what is
suppose to be done? Resend the commit or resend the copy?

I don't really understand how to handle #2. nfs_commit_inode() return
from doing INT_MAX commits but not doing the commit that it was
suppose to do nfs_commit_file() asked and I'm at a loss how to
determine that. Shouldn't there have been a loop somewhere that
handles *all* commit requests and not just INT_MAX requests. Is this
problem not a problem from the nfs_commit_file() but rather a generic
problem?

Re: RFC: fixing kernel oops on interrupted COMMIT from nfs_commit_file

[Olga Kornievskaia]

On Fri, Apr 14, 2017 at 5:17 PM, Olga Kornievskaia <aglo@umich.edu> wrote:
> On Fri, Apr 14, 2017 at 3:16 PM, Trond Myklebust
> <trondmy@primarydata.com> wrote:
>> On Fri, 2017-04-14 at 11:56 -0400, Olga Kornievskaia wrote:
>>> On Thu, Apr 13, 2017 at 4:50 PM, Trond Myklebust
>>> <trondmy@primarydata.com> wrote:
>>> >
>>> > Secondly, if you want to release the request and you are not sure
>>> > whether or not it got cleared off the inode's cinfo commit list
>>> > yet,
>>> > you may also need to lock that request and call
>>> > nfs_clear_request_commit().
>>>
>>> Looking at what the function does, I don't see why this is needed.
>>> "wb_page" is NULL for this type of commit and there is no pnfs in
>>> this
>>> case.
>>
>> Something needs to ensure that the request is not sitting on a commit
>> list. That can happen if the commit succeeded, but returned a different
>> verifier, or it can happen if nfs_scan_commit() exits early.
>
> First point I'd like you to consider is that your last statement as a
> separate problem that needs to be solved with a different patch.
>
> Secondly, I don't understand how to determine "if nfs_commit_file()
> isn't sure whether or not request got cleared off the inode's cinfo
> commit list". There are two cases you pointed to 1) verifier mismatch
> and 2) nfs_scan_commit didn't even get to the request (caz INT_MAX
> commits were queued before that)?
>
> For the verifier mismatch: "NFS_CONTEXT_RESEND_WRITES" is set. So
> nfs_commit_file() can check for that. But I guess I'm not sure what is
> suppose to be done? Resend the commit or resend the copy?
>
> I don't really understand how to handle #2. nfs_commit_inode() return
> from doing INT_MAX commits but not doing the commit that it was
> suppose to do nfs_commit_file() asked and I'm at a loss how to
> determine that. Shouldn't there have been a loop somewhere that
> handles *all* commit requests and not just INT_MAX requests. Is this
> problem not a problem from the nfs_commit_file() but rather a generic
> problem?

Taking a different approach to fixing it by getting rid of
nfs_commit_file() and for the synchronous COPY appending COMMIT to the
compound. For the asynchronous COPY, I propose to just add a function
nfs4_proc_copy() that uses existing callback functions and just sends
the commit without messing with the commit path.