Bug 200145 - kernel: FS-Cache: Duplicate cookie detected
Summary: kernel: FS-Cache: Duplicate cookie detected
Status: NEW
Alias: None
Product: File System
Classification: Unclassified
Component: NFS (show other bugs)
Hardware: Intel Linux
: P1 normal
Assignee: David Howells
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2018-06-20 04:18 UTC by D.T.
Modified: 2019-10-22 13:26 UTC (History)
27 users (show)

See Also:
Kernel Version: 4.17.2
Tree: Mainline
Regression: No


Attachments
I have the same problem: journalctl -b -p err (15.93 KB, text/plain)
2019-06-14 15:33 UTC, Lutz L.
Details
tracepoint output from the run (702.28 KB, application/gzip)
2019-10-22 13:26 UTC, Jeff Layton
Details

Description D.T. 2018-06-20 04:18:42 UTC
Description:  
  
FS-Cache: Duplicate cookie detected after updating Arch Linux yesterday. (This was the first update in a couple weeks.)  
  
Additional info:  
* package version(s)  
  
4.17.2-1-ARCH #1 SMP PREEMPT Sat Jun 16 11:08:59 UTC 2018 x86_64 GNU/Linux  
  
* config and/or log files etc.  
  
kernel: FS-Cache: Duplicate cookie detected  
kernel: FS-Cache: O-cookie c=000000001e72b895 [p=0000000089da8da7 fl=222 nc=0 na=1]  
kernel: FS-Cache: O-cookie d=00000000c3a2cbed n=00000000f757123a  
kernel: FS-Cache: O-key=[10] '040002000801c0a805c3'  
kernel: FS-Cache: N-cookie c=00000000ea48db1d [p=0000000089da8da7 fl=2 nc=0 na=1]  
kernel: FS-Cache: N-cookie d=00000000c3a2cbed n=000000000f72327e  
kernel: FS-Cache: N-key=[10] '040002000801c0a805c3'  
  
The machine is an Intel Core i7 and Asus Z170WS motherboard.  
  
Steps to reproduce:  
  
Boot system and check `journalctl -b -p err`  

(I'm sorry about the formatting. I'm not able to find formatting help.)
Comment 1 D.T. 2018-06-21 23:12:18 UTC
We are seeing this on each system (i.e., NFS client) as we update the kernels.

Linux 4.17.2-1-ARCH #1 SMP PREEMPT Sat Jun 16 11:08:59 UTC 2018 x86_64 GNU/Linux

All clients are Arch Linux and the NFS server is Arch Linux
Comment 2 Mustafa Mehmed 2018-06-25 04:08:15 UTC
Same problem here:-

Fedora 28 x86_64

# uname -r
# 4.17.2-200.fc28.x86_64

Jun 25 13:13:37 musi kernel: FS-Cache: Duplicate cookie detected
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie c=00000000db12e0e0 [p=000000009b121f93 fl=212 nc=0 na=0]
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie d=          (null) n=          (null)
Jun 25 13:13:37 musi kernel: FS-Cache: O-key=[10] '040002000801c0a8000a'
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie c=00000000c9409ef1 [p=000000009b121f93 fl=2 nc=0 na=1]
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie d=00000000d7b9b75b n=00000000e8f1ac26
Jun 25 13:13:37 musi kernel: FS-Cache: N-key=[10] '040002000801c0a8000a'
Jun 25 13:13:37 musi kernel: FS-Cache: Duplicate cookie detected
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie c=00000000db12e0e0 [p=000000009b121f93 fl=212 nc=0 na=0]
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie d=          (null) n=          (null)
Jun 25 13:13:37 musi kernel: FS-Cache: O-key=[10] '040002000801c0a8000a'
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie c=00000000964082ff [p=000000009b121f93 fl=2 nc=0 na=1]
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie d=00000000d7b9b75b n=000000001f536e83
Jun 25 13:13:37 musi kernel: FS-Cache: N-key=[10] '040002000801c0a8000a'
Jun 25 13:13:37 musi kernel: FS-Cache: Duplicate cookie detected
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie c=00000000db12e0e0 [p=000000009b121f93 fl=212 nc=0 na=0]
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie d=          (null) n=          (null)
Jun 25 13:13:37 musi kernel: FS-Cache: O-key=[10] '040002000801c0a8000a'
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie c=00000000bc41f6a5 [p=000000009b121f93 fl=2 nc=0 na=1]
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie d=00000000d7b9b75b n=000000003128b81a
Jun 25 13:13:37 musi kernel: FS-Cache: N-key=[10] '040002000801c0a8000a'
Jun 25 13:13:37 musi kernel: FS-Cache: Duplicate cookie detected
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie c=00000000db12e0e0 [p=000000009b121f93 fl=212 nc=0 na=0]
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie d=          (null) n=          (null)
Jun 25 13:13:37 musi kernel: FS-Cache: O-key=[10] '040002000801c0a8000a'
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie c=0000000053708379 [p=000000009b121f93 fl=2 nc=0 na=1]
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie d=00000000d7b9b75b n=0000000039f900f6
Jun 25 13:13:37 musi kernel: FS-Cache: N-key=[10] '040002000801c0a8000a'
Jun 25 13:13:37 musi kernel: FS-Cache: Duplicate cookie detected
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie c=00000000db12e0e0 [p=000000009b121f93 fl=212 nc=0 na=0]
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie d=          (null) n=          (null)
Jun 25 13:13:37 musi kernel: FS-Cache: O-key=[10] '040002000801c0a8000a'
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie c=000000002a007dbf [p=000000009b121f93 fl=2 nc=0 na=1]
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie d=00000000d7b9b75b n=000000007c108fe3
Jun 25 13:13:37 musi kernel: FS-Cache: N-key=[10] '040002000801c0a8000a'
Jun 25 13:13:37 musi kernel: FS-Cache: Duplicate cookie detected
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie c=000000002ab03e84 [p=000000009b121f93 fl=222 nc=0 na=1]
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie d=00000000d7b9b75b n=00000000b853a8ee
Jun 25 13:13:37 musi kernel: FS-Cache: O-key=[10] '040002000801c0a8000a'
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie c=00000000e7e093b9 [p=000000009b121f93 fl=2 nc=0 na=1]
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie d=00000000d7b9b75b n=00000000945ea721
Jun 25 13:13:37 musi kernel: FS-Cache: N-key=[10] '040002000801c0a8000a'
Jun 25 13:13:37 musi kernel: FS-Cache: Duplicate cookie detected
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie c=00000000c9409ef1 [p=000000009b121f93 fl=222 nc=0 na=1]
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie d=00000000d7b9b75b n=000000001457c555
Jun 25 13:13:37 musi kernel: FS-Cache: O-key=[10] '040002000801c0a8000a'
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie c=000000002a007dbf [p=000000009b121f93 fl=2 nc=0 na=1]
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie d=00000000d7b9b75b n=0000000058e97a5a
Jun 25 13:13:37 musi kernel: FS-Cache: N-key=[10] '040002000801c0a8000a'
Jun 25 13:13:37 musi kernel: FS-Cache: Duplicate cookie detected
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie c=00000000c9409ef1 [p=000000009b121f93 fl=222 nc=0 na=1]
Jun 25 13:13:37 musi kernel: FS-Cache: Duplicate cookie detected
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie d=          (null) n=          (null)
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie c=000000004268bcbb [p=000000009b121f93 fl=212 nc=0 na=0]
Jun 25 13:13:37 musi kernel: FS-Cache: O-key=[10] '04
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie d=          (null) n=          (null)
Jun 25 13:13:37 musi kernel: FS-Cache: O-key=[10] '
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie c=000000000b84e785 [p=000000009b121f93 fl=2 nc=0 na=1]
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie d=00000000d7b9b75b n=000000008bb85de9
Jun 25 13:13:37 musi kernel: FS-Cache: N-key=[10] '040002000801c0a8000a'
Jun 25 13:13:37 musi kernel: FS-Cache: Duplicate cookie detected
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie c=00000000843e3416 [p=000000009b121f93 fl=212 nc=0 na=0]
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie d=          (null) n=          (null)
Jun 25 13:13:37 musi kernel: FS-Cache: O-key=[10] '04000200
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie c=00000000964082ff [p=000000009b121f93 fl=2 nc=0 na=1]
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie d=00000000d7b9b75b n=0000000082425ed3
Jun 25 13:13:37 musi kernel: FS-Cache: N-key=[10] '
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie c=00000000dbf8ebfe [p=000000009b121f93 fl=2 nc=0 na=1]
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie d=00000000d7b9b75b n=00000000a1e88c70
Jun 25 13:13:37 musi kernel: FS-Cache: N-key=[10] '040002000801c0a8000a'
Jun 25 13:13:37 musi kernel: FS-Cache: Duplicate cookie detected
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie c=00000000c9409ef1 [p=000000009b121f93 fl=212 nc=0 na=0]
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie d=          (null) n=          (null)
Jun 25 13:13:37 musi kernel: FS-Cache: O-key=[10] '040002000801c0a8000a'
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie c=000000000b84e785 [p=000000009b121f93 fl=2 nc=0 na=1]
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie d=00000000d7b9b75b n=000000002de42a5c
Jun 25 13:13:37 musi kernel: FS-Cache: N-key=[10] '040002000801c0a8000a'
Jun 25 13:13:37 musi kernel: FS-Cache: Duplicate cookie detected
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie c=00000000c9409ef1 [p=000000009b121f93 fl=212 nc=0 na=0]
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie d=          (null) n=          (null)
Jun 25 13:13:37 musi kernel: FS-Cache: O-key=[10] '040002000801c0a8000a'
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie c=000000002a007dbf [p=000000009b121f93 fl=2 nc=0 na=1]
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie d=00000000d7b9b75b n=0000000071ab2f2d
Jun 25 13:13:37 musi kernel: FS-Cache: N-key=[10] '040002000801c0a8000a'
Jun 25 13:13:37 musi kernel: FS-Cache: Duplicate cookie detected
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie c=00000000964082ff [p=000000009b121f93 fl=212 nc=0 na=0]
Jun 25 13:13:37 musi kernel: FS-Cache: O-cookie d=          (null) n=          (null)
Jun 25 13:13:37 musi kernel: FS-Cache: O-key=[10] '040002000801c0a8000a'
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie c=000000002a007dbf [p=000000009b121f93 fl=2 nc=0 na=1]
Jun 25 13:13:37 musi kernel: FS-Cache: N-cookie d=00000000d7b9b75b n=000000003f381e0c
Jun 25 13:13:37 musi kernel: FS-Cache: N-key=[10] '040002000801c0a8000a'
Comment 3 Mustafa Mehmed 2018-07-02 21:52:08 UTC
Still persists for 4.17.3-200.fc28.x86_64
Comment 4 Edmund L 2018-07-08 10:33:46 UTC
Same problem since today on Archlinux client:

Linux 4.17.4-1-ARCH #1 SMP PREEMPT Tue Jul 3 15:45:09 UTC 2018 x86_64 GNU/Linux

NFS does not mount anymore, it gives an access denied error.
Comment 5 D.T. 2018-07-18 06:38:31 UTC
Still persists in 4.17.6-1-ARCH #1 SMP PREEMPT Wed Jul 11 19:14:29 UTC 2018 x86_64 GNU/Linux

On at least one system we are seeing problems with NFS shares not mounting at boot, but they can be mounted manually. Not sure if it is related, but the mounting issue is new and configuration has not changed.
Comment 6 Jason H. 2018-09-15 13:52:29 UTC
Still occurs regularly in 4.18.6.


On one system (PRODUCTION);

[    5.597516] FS-Cache: Duplicate cookie detected
[    5.597545] FS-Cache: O-cookie c=(____ptrval____) [p=(____ptrval____) fl=222 nc=0 na=1]
[    5.597568] FS-Cache: O-cookie d=(____ptrval____) n=(____ptrval____)
[    5.597589] FS-Cache: O-key=[10] '040002000801c0a8802f'
[    5.597610] FS-Cache: N-cookie c=(____ptrval____) [p=(____ptrval____) fl=2 nc=0 na=1]
[    5.597633] FS-Cache: N-cookie d=(____ptrval____) n=(____ptrval____)
[    5.597652] FS-Cache: N-key=[10] '040002000801c0a8802f'
----------------CUT----------------
[243468.028611] FS-Cache: Duplicate cookie detected
[243468.028649] FS-Cache: O-cookie c=000000005298fa9f [p=00000000fadc4f4f fl=222 nc=0 na=1]
[243468.028673] FS-Cache: O-cookie d=00000000ed593886 n=000000001d7d5f26
[243468.028693] FS-Cache: O-key=[10] '040002000801c0a8802f'
[243468.028713] FS-Cache: N-cookie c=00000000d54ce6b9 [p=00000000fadc4f4f fl=2 nc=0 na=1]
[243468.028737] FS-Cache: N-cookie d=00000000ed593886 n=00000000eff1b7bc
[243468.028756] FS-Cache: N-key=[10] '040002000801c0a8802f'


On another (OFFICE):

[    3.572751] FS-Cache: Duplicate cookie detected
[    3.572779] FS-Cache: O-cookie c=(____ptrval____) [p=(____ptrval____) fl=222 nc=0 na=1]
[    3.572803] FS-Cache: O-cookie d=(____ptrval____) n=(____ptrval____)
[    3.572823] FS-Cache: O-key=[10] '040002000801c0a8802f'
[    3.572844] FS-Cache: N-cookie c=(____ptrval____) [p=(____ptrval____) fl=2 nc=0 na=1]
[    3.572867] FS-Cache: N-cookie d=(____ptrval____) n=(____ptrval____)
[    3.572886] FS-Cache: N-key=[10] '040002000801c0a8802f'
[    3.713774] FS-Cache: Duplicate cookie detected
[    3.713801] FS-Cache: O-cookie c=(____ptrval____) [p=(____ptrval____) fl=222 nc=0 na=1]
[    3.713830] FS-Cache: O-cookie d=(____ptrval____) n=(____ptrval____)
[    3.713849] FS-Cache: O-key=[10] '040002000801c0a8802f'
[    3.713871] FS-Cache: N-cookie c=(____ptrval____) [p=(____ptrval____) fl=2 nc=0 na=1]
[    3.713893] FS-Cache: N-cookie d=(____ptrval____) n=(____ptrval____)
[    3.713913] FS-Cache: N-key=[10] '040002000801c0a8802f'
[    3.714992] FS-Cache: Duplicate cookie detected
[    3.715019] FS-Cache: O-cookie c=(____ptrval____) [p=(____ptrval____) fl=222 nc=0 na=1]
[    3.715043] FS-Cache: O-cookie d=(____ptrval____) n=(____ptrval____)
[    3.715073] FS-Cache: O-key=[10] '040002000801c0a88031'
[    3.715094] FS-Cache: N-cookie c=(____ptrval____) [p=(____ptrval____) fl=2 nc=0 na=1]
[    3.715117] FS-Cache: N-cookie d=(____ptrval____) n=(____ptrval____)
[    3.715136] FS-Cache: N-key=[10] '040002000801c0a88031'
[    3.750580] FS-Cache: Duplicate cookie detected
[    3.750607] FS-Cache: O-cookie c=(____ptrval____) [p=(____ptrval____) fl=222 nc=4 na=1]
[    3.750631] FS-Cache: O-cookie d=(____ptrval____) n=(____ptrval____)
[    3.750651] FS-Cache: O-key=[10] '040002000801c0a8802f'
[    3.750672] FS-Cache: N-cookie c=(____ptrval____) [p=(____ptrval____) fl=2 nc=0 na=1]
[    3.750695] FS-Cache: N-cookie d=(____ptrval____) n=(____ptrval____)
[    3.750714] FS-Cache: N-key=[10] '040002000801c0a8802f'
[    3.905088] CacheFiles: Loaded
[    3.914303] FS-Cache: Cache "mycache" added (type cachefiles)
[    3.914305] CacheFiles: File cache on sdb1 registered
[    3.981049] FS-Cache: Duplicate cookie detected
[    3.981075] FS-Cache: O-cookie c=(____ptrval____) [p=(____ptrval____) fl=222 nc=0 na=1]
[    3.981101] FS-Cache: O-cookie d=(____ptrval____) n=(____ptrval____)
[    3.981131] FS-Cache: O-key=[10] '040002000801c0a8802f'
[    3.981152] FS-Cache: N-cookie c=(____ptrval____) [p=(____ptrval____) fl=2 nc=0 na=1]
[    3.981211] FS-Cache: N-cookie d=(____ptrval____) n=(____ptrval____)
[    3.981227] FS-Cache: N-key=[10] '040002000801c0a8802f'
[    4.020095] FS-Cache: Duplicate cookie detected
[    4.020122] FS-Cache: O-cookie c=(____ptrval____) [p=(____ptrval____) fl=222 nc=5 na=1]
[    4.020147] FS-Cache: O-cookie d=(____ptrval____) n=(____ptrval____)
[    4.020166] FS-Cache: O-key=[10] '040002000801c0a8802f'
[    4.020187] FS-Cache: N-cookie c=(____ptrval____) [p=(____ptrval____) fl=2 nc=0 na=1]
[    4.020210] FS-Cache: N-cookie d=(____ptrval____) n=(____ptrval____)
[    4.020230] FS-Cache: N-key=[10] '040002000801c0a8802f'


[17638.919246] FS-Cache: Duplicate cookie detected
[17638.919274] FS-Cache: O-cookie c=00000000147e71bd [p=00000000ac34690f fl=222 nc=0 na=1]
[17638.919296] FS-Cache: O-cookie d=00000000ba3acacd n=00000000f633f60c
[17638.919315] FS-Cache: O-key=[10] '040002000801c0a8802f'
[17638.919336] FS-Cache: N-cookie c=000000002c444bb0 [p=00000000ac34690f fl=2 nc=0 na=1]
[17638.919358] FS-Cache: N-cookie d=00000000ba3acacd n=000000007162a1bd
[17638.919378] FS-Cache: N-key=[10] '040002000801c0a8802f'
[17638.921062] FS-Cache: Duplicate cookie detected
[17638.921086] FS-Cache: O-cookie c=00000000147e71bd [p=00000000ac34690f fl=222 nc=0 na=1]
[17638.921106] FS-Cache: O-cookie d=00000000ba3acacd n=00000000f633f60c
[17638.921122] FS-Cache: O-key=[10] '040002000801c0a8802f'
[17638.921141] FS-Cache: N-cookie c=000000003e824b22 [p=00000000ac34690f fl=2 nc=0 na=1]
[17638.922101] FS-Cache: N-cookie d=00000000ba3acacd n=00000000991d0273
[17638.922569] FS-Cache: N-key=[10] '040002000801c0a8802f'
[17638.973773] FS-Cache: Duplicate cookie detected
[17638.974432] FS-Cache: O-cookie c=00000000b0f6ec39 [p=00000000ac34690f fl=220 nc=1 na=1]
[17638.974971] FS-Cache: O-cookie d=00000000ba3acacd n=00000000fc3612f3
[17638.975490] FS-Cache: O-cookie o=0000000077bdc71b
[17638.976000] FS-Cache: O-key=[10] '040002000801c0a8802f'
[17638.976545] FS-Cache: N-cookie c=00000000147e71bd [p=00000000ac34690f fl=2 nc=0 na=1]
[17638.977010] FS-Cache: N-cookie d=00000000ba3acacd n=000000007162a1bd
[17638.977566] FS-Cache: N-key=[10] '040002000801c0a8802f'
[19593.186254] FS-Cache: Duplicate cookie detected
[19593.187265] FS-Cache: O-cookie c=00000000b0f6ec39 [p=00000000ac34690f fl=220 nc=1 na=1]
[19593.187840] FS-Cache: O-cookie d=00000000ba3acacd n=00000000fc3612f3
[19593.188302] FS-Cache: O-cookie o=0000000077bdc71b
[19593.188762] FS-Cache: O-key=[10] '040002000801c0a8802f'
[19593.189253] FS-Cache: N-cookie c=000000000001de54 [p=00000000ac34690f fl=2 nc=0 na=1]
[19593.189853] FS-Cache: N-cookie d=00000000ba3acacd n=000000001f2473c6
[19593.190398] FS-Cache: N-key=[10] '040002000801c0a8802f'


Two relevant mounts on both with the same settings. One is NFS the other NFS4. I have seen the same issue doing something similar with a SMB mount however.

192.168.128.49:<path> on /srv/shared/<path> type nfs (rw,relatime,vers=3,rsize=65536,wsize=65536,namlen=255,hard,proto=tcp,timeo=600,retrans=10,sec=sys,mountaddr=192.168.128.49,mountvers=3,mountport=46999,mountproto=udp,fsc,local_lock=none,addr=192.168.128.49)

192.168.128.47:<path> on <path> type nfs4 (rw,relatime,vers=4.0,rsize=131072,wsize=131072,namlen=255,hard,proto=tcp,timeo=600,retrans=10,sec=sys,clientaddr=192.168.128.45,fsc,local_lock=none,addr=192.168.128.47)

This will occur even with a fresh cache after a period of time/heavy access.
Comment 7 Stefan Assmann 2018-09-25 08:55:34 UTC
Also seeing this on 4.18.6.

[1480847.164687] FS-Cache: Duplicate cookie detected
[1480847.164692] FS-Cache: O-cookie c=0000000087de3563 [p=00000000b77cf9f7 fl=222 nc=0 na=1]
[1480847.164694] FS-Cache: O-cookie d=00000000e895c803 n=00000000544279fb
[1480847.164695] FS-Cache: O-key=[10] '0400020008010a1029a4'
[1480847.164701] FS-Cache: N-cookie c=00000000f1035c51 [p=00000000b77cf9f7 fl=2 nc=0 na=1]
[1480847.164702] FS-Cache: N-cookie d=00000000e895c803 n=000000002e4ef63d
[1480847.164703] FS-Cache: N-key=[10] '0400020008010a1029a4'
Comment 8 Christian Kujau 2018-11-12 02:19:03 UTC
This is still happening, seeing it here with an Ubuntu 4.19 ([201810221809](http://kernel.ubuntu.com/~kernel-ppa/mainline/v4.19/)) kernel.
Comment 9 João Magalhães 2018-11-15 22:40:05 UTC
Still seeing this on 4.19.1

[35616.806254] FS-Cache: Duplicate cookie detected
[35616.806256] FS-Cache: O-cookie c=0000000054686264 [p=000000001571c359 fl=222 nc=1 na=1]
[35616.806257] FS-Cache: O-cookie d=00000000f208744e n=000000009669a7f3
[35616.806258] FS-Cache: O-key=[8] '020001bdac10001f'
[35616.806261] FS-Cache: N-cookie c=000000004b9df41f [p=000000001571c359 fl=2 nc=0 na=1]
[35616.806261] FS-Cache: N-cookie d=00000000f208744e n=00000000f7992f3b
[35616.806262] FS-Cache: N-key=[8] '020001bdac10001f'
Comment 10 Mauro A. Meloni 2018-12-07 12:50:10 UTC
Started seeing this problem on Debian since months ago. Happens on 4.17.2 onwards, 4.18.x, 4.19.x:

```
# dmesg | egrep -i "(fs-cache|Linux version)"

[    0.000000] Linux version 4.18.0-0.bpo.1-amd64 (debian-kernel@lists.debian.org) (gcc version 6.3.0 20170516 (Debian 6.3.0-18+deb9u1)) #1 SMP Debian 4.18.6-1~bpo9+1 (2018-09-13)
[   29.192280] FS-Cache: Loaded
[   29.409773] FS-Cache: Netfs 'cifs' registered for caching
[   29.496826] FS-Cache: Duplicate cookie detected
[   29.496867] FS-Cache: O-cookie c=0000000041e46806 [p=0000000031cb431b fl=222 nc=0 na=1]
[   29.496914] FS-Cache: O-cookie d=00000000b223d91c n=00000000b2b12755
[   29.496951] FS-Cache: O-key=[8] '020001bdaad26009'
[   29.497004] FS-Cache: N-cookie c=00000000b46cd7af [p=0000000031cb431b fl=2 nc=0 na=1]
[   29.497052] FS-Cache: N-cookie d=00000000b223d91c n=000000008c79361f
[   29.497092] FS-Cache: N-key=[8] '020001bdaad26009'
[   29.497131] FS-Cache: Duplicate cookie detected
[   29.497173] FS-Cache: O-cookie c=0000000041e46806 [p=0000000031cb431b fl=222 nc=0 na=1]
[   29.497223] FS-Cache: O-cookie d=00000000b223d91c n=00000000b2b12755
[   29.497263] FS-Cache: O-key=[8] '020001bdaad26009'
[   29.497303] FS-Cache: N-cookie c=00000000e0cd3dc2 [p=0000000031cb431b fl=2 nc=0 na=1]
[   29.497351] FS-Cache: N-cookie d=00000000b223d91c n=00000000979642dd
[   29.497391] FS-Cache: N-key=[8] '020001bdaad26009'
```

```
# dmesg | egrep -i "(fs-cache|Linux version)"

[    0.000000] Linux version 4.19.7 (maurom.com) (gcc version 6.3.0 20170516 (Debian 6.3.0-18+deb9u1)) #1 SMP Thu Dec 6 08:57:06 -03 2018
[   28.172523] FS-Cache: Loaded
[   28.367743] FS-Cache: Netfs 'cifs' registered for caching
[   28.405810] FS-Cache: Duplicate cookie detected
[   28.405829] FS-Cache: O-cookie c=00000000622c2cfb [p=0000000020f157cf fl=222 nc=0 na=1]
[   28.405847] FS-Cache: O-cookie d=00000000a64ed22d n=00000000c762d573
[   28.405863] FS-Cache: O-key=[8] '020001bdaad26009'
[   28.405879] FS-Cache: N-cookie c=00000000b9d71f03 [p=0000000020f157cf fl=2 nc=0 na=1]
[   28.405897] FS-Cache: N-cookie d=00000000a64ed22d n=0000000020b8ad4c
[   28.405912] FS-Cache: N-key=[8] '020001bdaad26009'
[   28.406274] FS-Cache: Duplicate cookie detected
[   28.406290] FS-Cache: O-cookie c=00000000622c2cfb [p=0000000020f157cf fl=222 nc=0 na=1]
[   28.406309] FS-Cache: O-cookie d=00000000a64ed22d n=00000000c762d573
[   28.406324] FS-Cache: O-key=[8] '020001bdaad26009'
[   28.406339] FS-Cache: N-cookie c=00000000abc65d43 [p=0000000020f157cf fl=2 nc=0 na=1]
[   28.406357] FS-Cache: N-cookie d=00000000a64ed22d n=00000000c5a79a4d
[   28.406372] FS-Cache: N-key=[8] '020001bdaad26009'
```

However, there are no such messages when running kernel version 4.9.0

```
# dmesg | egrep -i "(fs-cache|Linux version)"

[    0.000000] Linux version 4.9.0-8-amd64 (debian-kernel@lists.debian.org) (gcc version 6.3.0 20170516 (Debian 6.3.0-18+deb9u1) ) #1 SMP Debian 4.9.130-2 (2018-10-27)
[   32.030230] FS-Cache: Loaded
[   32.507149] FS-Cache: Netfs 'cifs' registered for caching
```

At least in my case, seems related to mounting remote SMB filesystems on boot. My fstab has (partially):

```
//fs1/afolder	/media/afolder	cifs	credentials=/opt/cifs.credentials,vers=3.0,uid=username,iocharset=utf8,cache=none	0	0
//fs1/bfolder	/media/bfolder	cifs	credentials=/opt/cifs.credentials,vers=3.0,uid=username,iocharset=utf8,cache=none	0	0
//fs1/cfolder	/media/cfolder	cifs	credentials=/opt/cifs.credentials,vers=3.0,uid=username,iocharset=utf8,cache=none	0	0
```

If I disable mounting those filesystems on boot (by commenting their entries), no "Duplicate cookie" message appears, not even after mounting them the manual way via the command line.

```
# dmesg | egrep -i "(fs-cache|Linux version)"

[    0.000000] Linux version 4.19.7 (maurom.com) (gcc version 6.3.0 20170516 (Debian 6.3.0-18+deb9u1)) #1 SMP Thu Dec 6 08:57:06 -03 2018
[  120.605690] FS-Cache: Loaded
[  120.687546] FS-Cache: Netfs 'cifs' registered for caching
```

Ideas are welcome
Comment 11 Paul Szymanski 2018-12-20 23:02:22 UTC
I'm seeing this on 4.18.19 with SMBv3 mounts that are managed by autofs. This seems to happen randomly after some time. After rebooting the system the mounts ususally work again.
If someone knows an alternative to rebooting of the system I'm glad to hear.

# cat /etc/auto.home
*         -fstype=cifs,sec=krb5i,cache=strict,rw,user=&,cruid=&,cifsacl,nounix,multiuser ://example.com/home\$/&

Dec 20 12:16:43 myserver.com kernel: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3), from CIFS (SMB1). To use the less secure SMB1 dialect to access old server
Dec 20 12:16:43 myserver.com kernel: FS-Cache: Duplicate cookie detected
Dec 20 12:16:43 myserver.com kernel: FS-Cache: O-cookie c=00000000e1b5032a [p=00000000adab294a fl=222 nc=0 na=1]
Dec 20 12:16:43 myserver.com kernel: FS-Cache: O-cookie d=00000000fc0edf47 n=00000000b64ec22f
Dec 20 12:16:43 myserver.com kernel: FS-Cache: O-key=[5] '686f6d6524'
Dec 20 12:16:43 myserver.com kernel: FS-Cache: N-cookie c=000000001497883d [p=00000000adab294a fl=2 nc=0 na=1]
Dec 20 12:16:43 myserver.com kernel: FS-Cache: N-cookie d=00000000fc0edf47 n=00000000e91fcf0f
Dec 20 12:16:43 myserver.com kernel: FS-Cache: N-key=[5] '686f6d6524'
Comment 12 Paul Szymanski 2018-12-21 00:25:56 UTC
This patch [1] introduced a catalouge of maintained cookies to handle cookie collisions. However the handling of cookie collisions seems not to be implemented yet.

[1] https://github.com/torvalds/linux/commit/ec0328e46d6e5d0f17372eb90ab8e333c2ac7ca9
Comment 13 Adam Williamson 2019-01-16 19:40:17 UTC
FWIW I just started seeing this on my Fedora Rawhide desktop - I did an update, reboot, and found an SMB mount won't mount, and the logs show these "Duplicate cookie detected" errors...
Comment 14 Adam Williamson 2019-02-07 15:33:57 UTC
Still seeing this with 5.0.0-0.rc4.git3.1.fc30.x86_64 and it still appears to 100% reliably break a SMB mount, I just cannot mount it at all. This isn't as bad for others? Seems like a critical bug to me...
Comment 15 Simeon 2019-03-02 17:56:56 UTC
Can somebody confirm if this is dangerous and can potentially lead to data corruption, or it is just a harmless warning? I looked at the changes noted in comment 12, but I'm not familiar enough with the fs-cache.  

I started seeing the same  
```
FS-Cache: N-key=[10] '040002000801c0a80a0a'
FS-Cache: N-cookie d=000000000cb4ac9d n=000000002165d4be
FS-Cache: N-cookie c=000000000e05d983 [p=000000000ed8ad13 fl=2 nc=0 na=1]
FS-Cache: O-key=[10] '040002000801c0a80a0a'
FS-Cache: O-cookie d=000000000cb4ac9d n=00000000657f42b1
FS-Cache: O-cookie c=00000000fd6e1f0c [p=000000000ed8ad13 fl=222 nc=0 na=1]
FS-Cache: Duplicate cookie detected
```
warnings after switching to NFS4 from v3. Here are the fstab entries and /proc/mounts after they are being mounted  
```
url:/export1 /path1    nfs    nodev,nosuid,noauto,x-systemd.automount,x-systemd.requires=network-online.target,x-systemd.idle-timeout=5min,hard,vers=4,minorversion=1,ro    0    0
url:/export2 /path2    nfs    nodev,nosuid,noauto,x-systemd.automount,x-systemd.requires=network-online.target,x-systemd.idle-timeout=5min,hard,vers=4,minorversion=1,rw    0    0

url:/export1 /path1 nfs4 ro,nosuid,nodev,relatime,vers=4.1,rsize=131072,wsize=131072,namlen=255,hard,proto=tcp,timeo=600,retrans=2,sec=sys,clientaddr=192.168.10.100,local_lock=none,addr=192.168.10.10 0 0
url:/export2 /path2 nfs4 rw,nosuid,nodev,relatime,vers=4.1,rsize=131072,wsize=131072,namlen=255,hard,proto=tcp,timeo=600,retrans=2,sec=sys,clientaddr=192.168.10.100,local_lock=none,addr=192.168.10.10 0 0
```
The server is freeBSD(freeNAS 11.2-U1) so that's the reason for the lower wsize/rsize. I use more shares but I have some mounted as RO and some as RW. Just in case it matters - when I was running vers3 the server export was RO, but during the switch to vers4 I started to only mount as RO.  

This is on archlinux. 4.19.x and 4.20.x kernels. Started using NFSv3 only 1-2 months ago, but never saw the warnings. I know that vers4.1 supports way more state information, so more things can potentially be cached. I even found information about write caching that let me to wondering if this can be harmful in the first place.  

For about a week of using NFSv4.1 I've seen the warnings only twice. It doesn't appear to happen during heavy usage. I'm not sure but looking at the timings in my case it might have something to do with the auto unmounting. I changed the idle timeouts to 30 minutes and everything is quiet for now. Also at first glance all the mounts continue to work just fine for me even after the warnings and nothing looks broken.
Comment 16 Adam Williamson 2019-03-04 15:45:22 UTC
Oh, I should note for the record that this turned out not to actually be the problem with my CIFS mount. For some reason, it works with an explicit 'vers=3.0' but not if I let the kernel set the version. But even with the explict 'vers=3.0', the 'duplicate cookie' message shows up, so it's clearly not really *breaking* anything.

Still dunno what the problem actually is, but the mount works so I'm happy. :P
Comment 17 Jon 2019-03-17 22:02:44 UTC
Same issue on opensuse tumbleweed with kernel 5
Linux mudkip.farm 5.0.2-7-default #1 SMP Thu Mar 14 08:29:17 UTC 2019 (d1f1d19) 



[   10.993318] FS-Cache: Duplicate cookie detected
[   10.993324] FS-Cache: O-cookie c=0000000001b97f10 [p=00000000896942dd fl=222 nc=0 na=1]
[   10.993325] FS-Cache: O-cookie d=00000000722c3c7e n=0000000017d4ebeb
[   10.993327] FS-Cache: O-key=[10] '040002000801c0a80032'
[   10.993331] FS-Cache: N-cookie c=000000006683aeea [p=00000000896942dd fl=2 nc=0 na=1]
[   10.993332] FS-Cache: N-cookie d=00000000722c3c7e n=000000008389ecd4
[   10.993333] FS-Cache: N-key=[10] '040002000801c0a80032'


NFS at boot fails to mount. `mount -a` as root works fine.
Comment 18 Hoffman Cyber 2019-03-30 11:14:48 UTC
Dmesg on a nfs-server side is pristine (4.14.107-1-ARCH, core/nfs-utils 2.3.3-1), but a client (4.19.27-gentoo-r1, net-fs/nfs-utils 2.3.3) has got the same red lines at the end of dmesg.To be honest, nfs works just fine except that annoying log.
Comment 19 Albert Szostkiewicz 2019-04-07 18:11:13 UTC
Same here under:
5.0.5-200.fc29.x86_64

autofs is no longer mounting.

ipa.myh.com systemd[1]: Starting Performance Metrics Collector Daemon...
ipa.myh.com systemd[1]: Starting NFS Mount Daemon...
ipa.myh.com systemd[1]: Starting Cockpit motd updater service...
ipa.myh.com systemd[1]: Starting NFS status monitor for NFSv2/3 locking....
ipa.myh.com systemd[1]: dirsrv@IPA-MYH-COM.service: Failed to load environment files: No such file or directory
ipa.myh.com systemd[1]: dirsrv@IPA-MYH-COM.service: Failed to run 'start-pre' task: No such file or directory
ipa.myh.com systemd[1]: dirsrv@IPA-MYH-COM.service: Failed with result 'resources'.
ipa.myh.com systemd[1]: Failed to start 389 Directory Server IPA-MYH-COM..
ipa.myh.com kernel: FS-Cache: Loaded
ipa.myh.com kernel: FS-Cache: Netfs 'nfs' registered for caching
ipa.myh.com kernel: Key type dns_resolver registered
ipa.myh.com kernel: NFS: Registering the id_resolver key type
ipa.myh.com kernel: Key type id_resolver registered
ipa.myh.com kernel: Key type id_legacy registered
ipa.myh.com kernel: FS-Cache: Duplicate cookie detected
ipa.myh.com kernel: FS-Cache: O-cookie c=000000007011665d [p=00000000389e076f fl=222 nc=0 na=1]
ipa.myh.com kernel: FS-Cache: O-cookie d=          (null) n=          (null)
ipa.myh.com kernel: FS-Cache: O-key=[10] '0400020008010a000107'
ipa.myh.com kernel: FS-Cache: N-cookie c=0000000005ddac96 [p=00000000389e076f fl=2 nc=0 na=1]
ipa.myh.com kernel: FS-Cache: N-cookie d=0000000008036284 n=000000003f1eb257
ipa.myh.com kernel: FS-Cache: N-key=[10] '0400020008010a000107'
ipa.myh.com kernel: FS-Cache: Duplicate cookie detected
ipa.myh.com kernel: FS-Cache: O-cookie c=000000007011665d [p=00000000389e076f fl=212 nc=0 na=0]
ipa.myh.com kernel: FS-Cache: O-cookie d=          (null) n=          (null)
ipa.myh.com kernel: FS-Cache: O-key=[10] '0400020008010a000107'
ipa.myh.com kernel: FS-Cache: N-cookie c=00000000487556ff [p=00000000389e076f fl=2 nc=0 na=1]
ipa.myh.com kernel: FS-Cache: N-cookie d=0000000008036284 n=00000000edea5f8d
ipa.myh.com kernel: FS-Cache: N-key=[10] '0400020008010a000107'
ipa.myh.com rpc.gssd[1003]: ERROR: can't openat nfs/clnt0: No such file or directory
ipa.myh.com kernel: FS-Cache: Duplicate cookie detected
ipa.myh.com kernel: FS-Cache: O-cookie c=0000000005ddac96 [p=00000000389e076f fl=222 nc=0 na=1]
ipa.myh.com kernel: FS-Cache: O-cookie d=0000000008036284 n=000000003aa5c01a
ipa.myh.com kernel: FS-Cache: O-key=[10] '0400020008010a000107'
ipa.myh.com kernel: FS-Cache: N-cookie c=0000000076bcd936 [p=00000000389e076f fl=2 nc=0 na=1]
ipa.myh.com kernel: FS-Cache: N-cookie d=0000000008036284 n=00000000d054e55b
ipa.myh.com kernel: FS-Cache: N-key=[10] '0400020008010a000107'
ipa.myh.com kernel: FS-Cache: Duplicate cookie detected
ipa.myh.com kernel: FS-Cache: O-cookie c=0000000005ddac96 [p=00000000389e076f fl=222 nc=0 na=1]
ipa.myh.com kernel: FS-Cache: O-cookie d=0000000008036284 n=000000003aa5c01a
ipa.myh.com kernel: FS-Cache: O-key=[10] '0400020008010a000107'
ipa.myh.com kernel: FS-Cache: N-cookie c=00000000b3ba1b92 [p=00000000389e076f fl=2 nc=0 na=1]
ipa.myh.com kernel: FS-Cache: N-cookie d=0000000008036284 n=000000000e95fa2f
ipa.myh.com kernel: FS-Cache: N-key=[10] '0400020008010a000107'
ipa.myh.com rpc.gssd[1003]: ERROR: can't openat nfs/clnt6: No such file or directory
ipa.myh.com systemd[1]: pmlogger.service: Supervising process 6965 which is not our child. We'll most likely not notice when it exits.
ipa.myh.com systemd[1]: Started Performance Metrics Archive Logger.
ipa.myh.com audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=pmlogger comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
ipa.myh.com kernel: FS-Cache: Duplicate cookie detected
ipa.myh.com kernel: FS-Cache: O-cookie c=000000004384258c [p=00000000389e076f fl=212 nc=0 na=0]
ipa.myh.com kernel: FS-Cache: O-cookie d=          (null) n=          (null)
ipa.myh.com kernel: FS-Cache: O-key=[10] '0400020008010a000107'
ipa.myh.com kernel: FS-Cache: N-cookie c=00000000a878dc03 [p=00000000389e076f fl=2 nc=0 na=1]
ipa.myh.com kernel: FS-Cache: N-cookie d=0000000008036284 n=0000000005148c6c
ipa.myh.com kernel: FS-Cache: N-key=[10] '0400020008010a000107'
Comment 20 Paul Menzel 2019-04-17 10:19:28 UTC
For the record, Linux version 4.19.19 also shows this behavior.

```
2019-02-13T14:46:33.272449+01:00 holidayincambodia kernel: [    0.000000] Linux version 4.19.19.mx64.244 (root@theinternet.molgen.mpg.de) (gcc version 7.3.0 (GCC)) #1 SMP Tue Feb 5 13:01:13 
CET 2019
[…]
2019-03-14T12:40:18.869889+01:00 holidayincambodia kernel: [2498037.374943] FS-Cache: Duplicate cookie detected
2019-03-14T12:40:18.869912+01:00 holidayincambodia kernel: [2498037.374951] FS-Cache: O-cookie c=00000000aa8ea040 [p=00000000c8387bd7 fl=222 nc=0 na=1]
2019-03-14T12:40:18.869913+01:00 holidayincambodia kernel: [2498037.374951] FS-Cache: O-cookie d=00000000e3baf094 n=00000000abceffd4
2019-03-14T12:40:18.869914+01:00 holidayincambodia kernel: [2498037.374952] FS-Cache: O-key=[10] '0400020008018d0e1013'
2019-03-14T12:40:18.869916+01:00 holidayincambodia kernel: [2498037.374957] FS-Cache: N-cookie c=00000000fb4274f3 [p=00000000c8387bd7 fl=2 nc=0 na=1]
2019-03-14T12:40:18.869917+01:00 holidayincambodia kernel: [2498037.374958] FS-Cache: N-cookie d=00000000e3baf094 n=00000000ea1a1342
2019-03-14T12:40:18.869918+01:00 holidayincambodia kernel: [2498037.374958] FS-Cache: N-key=[10] '0400020008018d0e1013'
```

This is on the NFS client. We moved some servers to NFS 4.1/4.2. Maybe it is related.
Comment 21 Lutz L. 2019-06-14 15:33:55 UTC
Created attachment 283271 [details]
I have the same problem: journalctl -b -p err


Ubuntu 5.0.0-16.17-generic 5.0.8

my system crashes sometimes

is there any patch available?

Lutz
Comment 22 Jon 2019-07-15 12:46:27 UTC
Still present in 5.2.1

Jul 15 13:43:06 mudkip kernel: FS-Cache: Duplicate cookie detected
Jul 15 13:43:06 mudkip kernel: FS-Cache: O-cookie c=00000000a6f9cb93 [p=00000000bc03f84c fl=212 nc=0 na=0]
Jul 15 13:43:06 mudkip kernel: FS-Cache: O-cookie d=0000000010676a16 n=0000000010676a16
Jul 15 13:43:06 mudkip kernel: FS-Cache: O-key=[10] '040002000801c0a80032'
Jul 15 13:43:06 mudkip kernel: FS-Cache: N-cookie c=000000004ee451df [p=00000000bc03f84c fl=2 nc=0 na=1]
Jul 15 13:43:06 mudkip kernel: FS-Cache: N-cookie d=00000000bf5ab627 n=0000000061623ac9
Jul 15 13:43:06 mudkip kernel: FS-Cache: N-key=[10] '040002000801c0a80032'
Comment 23 Jeff Layton 2019-10-16 14:17:51 UTC
I can reproduce this fairly easily by running xfstests on kcephfs with fscache enabled. FWIW, I'm mounting two different directories in the same ceph filesystem and am passing a uniquifier to the fsc= option for both.

[  966.523423] libceph: client5259 fsid 9704d8a8-de76-4b99-a78d-9108304b7a52
[  966.527437] FS-Cache: Duplicate cookie detected
[  966.528599] FS-Cache: O-cookie c=0000000041d90beb [p=ffff8883c2a62000 fl=218 nc=0 na=0, cnt=1]
[  966.530638] FS-Cache: O-cookie d=0000000000000000 n=0000000000000000
[  966.532094] FS-Cache: O-cookie o=ffff888429d61000
[  966.533140] FS-Cache: O-key=[20] '9704d8a8de764b99a78d9108304b7a5274657374'
[  966.534463] FS-Cache: N-cookie c=000000006826d9cf [p=ffff8883c2a62000 fl=2 nc=0 na=1, cnt=1]
[  966.536141] FS-Cache: N-cookie d=ffffffffa04a2320 n=ffff8883af454600
[  966.537371] FS-Cache: N-key=[20] '9704d8a8de764b99a78d9108304b7a5274657374'
[  966.538700] unable to register fscache cookie for fsid 9704d8a8-de76-4b99-a78d-9108304b7a52

This is mostly happening at mount time, afaict. xfstests does a lot of mount/unmount activity and it registers and unregisters a cookie on each one.
Comment 24 Jeff Layton 2019-10-22 12:32:15 UTC
I've been playing with a patch to try and work around this:

-------------------------8<----------------------------
diff --git a/fs/fscache/cookie.c b/fs/fscache/cookie.c
index b6b7aa220e6f..df731617438d 100644
--- a/fs/fscache/cookie.c
+++ b/fs/fscache/cookie.c
@@ -201,11 +201,22 @@ struct fscache_cookie *fscache_hash_cookie(struct fscache_cookie *candidate)
 
        bucket = candidate->key_hash & (ARRAY_SIZE(fscache_cookie_hash) - 1);
        h = &fscache_cookie_hash[bucket];
-
+retry:
        hlist_bl_lock(h);
        hlist_bl_for_each_entry(cursor, p, h, hash_link) {
-               if (fscache_compare_cookie(candidate, cursor) == 0)
-                       goto collision;
+               if (fscache_compare_cookie(candidate, cursor) == 0) {
+                       if (test_bit(FSCACHE_COOKIE_ENABLED, &cursor->flags))
+                               goto collision;
+
+                       if (atomic_inc_not_zero(&cursor->usage)) {
+                               hlist_bl_unlock(h);
+                               wait_on_bit_lock(&cursor->flags, FSCACHE_COOKIE_ENABLEMENT_LOCK, TASK_UNINTERRUPTIBLE);
+                               clear_bit_unlock(FSCACHE_COOKIE_ENABLEMENT_LOCK, &cursor->flags);
+                               wake_up_bit(&cursor->flags, FSCACHE_COOKIE_ENABLEMENT_LOCK);
+                               fscache_cookie_put(cursor, fscache_cookie_put_dup_netfs);
+                               goto retry;
+                       }
+               }
        }
 
        __set_bit(FSCACHE_COOKIE_ACQUIRED, &candidate->flags);
-------------------------8<----------------------------

This seems to mostly fix the issue for me, but occasionally I'm seeing this go into an infinite loop because the usage count on the cookie never goes to zero. I suspect this is probably due to an existing refcounting bug, but I haven't been able to find it so far.

Here are some tracepoints before just before it starts looping:

-------------------------8<----------------------------
   kworker/u16:6-3636  [002] ...1   470.692923: fscache_cookie: PUT rlq c=000000005ccd9b43 u=0 p=0000000052e4f404 Nc=0 Na=1 f=12
   kworker/u16:6-3636  [002] ...1   470.692924: fscache_cookie: PUT prn c=0000000052e4f404 u=9 p=00000000fbb5c648 Nc=7 Na=1 f=20
   kworker/u16:6-3636  [002] ...1   470.692965: fscache_cookie: PUT rlq c=00000000e1093eeb u=0 p=0000000052e4f404 Nc=0 Na=1 f=12
   kworker/u16:6-3636  [002] ...1   470.692966: fscache_cookie: PUT prn c=0000000052e4f404 u=8 p=00000000fbb5c648 Nc=6 Na=1 f=20
   kworker/u16:3-517   [005] ...1   470.693005: fscache_cookie: PUT rlq c=0000000065143ec9 u=0 p=0000000052e4f404 Nc=0 Na=1 f=12
   kworker/u16:3-517   [005] ...1   470.693007: fscache_cookie: PUT prn c=0000000052e4f404 u=7 p=00000000fbb5c648 Nc=5 Na=1 f=20
   kworker/u16:6-3636  [002] ...1   470.693042: fscache_cookie: PUT rlq c=000000008acf447f u=0 p=0000000052e4f404 Nc=0 Na=1 f=12
   kworker/u16:6-3636  [002] ...1   470.693044: fscache_cookie: PUT prn c=0000000052e4f404 u=6 p=00000000fbb5c648 Nc=4 Na=1 f=20
   kworker/u16:6-3636  [002] ...1   470.695587: fscache_cookie: PUT rlq c=000000000eb22115 u=0 p=0000000052e4f404 Nc=0 Na=1 f=12
   kworker/u16:6-3636  [002] ...1   470.695589: fscache_cookie: PUT prn c=0000000052e4f404 u=5 p=00000000fbb5c648 Nc=3 Na=1 f=20
   kworker/u16:6-3636  [002] ...1   470.700372: fscache_cookie: PUT rlq c=0000000058f6b4c7 u=0 p=0000000052e4f404 Nc=0 Na=1 f=12
   kworker/u16:6-3636  [002] ...1   470.700376: fscache_cookie: PUT prn c=0000000052e4f404 u=4 p=00000000fbb5c648 Nc=2 Na=1 f=20
   kworker/u16:6-3636  [002] ...1   470.700425: fscache_cookie: PUT rlq c=000000008d0c7880 u=0 p=0000000052e4f404 Nc=0 Na=1 f=12
   kworker/u16:6-3636  [002] ...1   470.700427: fscache_cookie: PUT prn c=0000000052e4f404 u=3 p=00000000fbb5c648 Nc=1 Na=1 f=20
   kworker/u16:2-146   [005] ...1   470.700847: fscache_cookie: PUT rlq c=00000000dd21d5bd u=0 p=0000000052e4f404 Nc=0 Na=1 f=12
   kworker/u16:2-146   [005] ...1   470.700851: fscache_cookie: PUT prn c=0000000052e4f404 u=2 p=00000000fbb5c648 Nc=0 Na=1 f=20
          umount-6891  [001] ...1   470.737960: fscache_cookie: PUT rlq c=0000000052e4f404 u=1 p=00000000fbb5c648 Nc=0 Na=0 f=18
      mount.ceph-6899  [000] ...1   470.804369: fscache_cookie: PUT dnt c=0000000052e4f404 u=1 p=00000000fbb5c648 Nc=0 Na=0 f=18
      mount.ceph-6899  [000] ...1   470.813654: fscache_cookie: PUT dnt c=0000000052e4f404 u=1 p=00000000fbb5c648 Nc=0 Na=0 f=18
      mount.ceph-6899  [000] ...1   470.822925: fscache_cookie: PUT dnt c=0000000052e4f404 u=1 p=00000000fbb5c648 Nc=0 Na=0 f=18
      mount.ceph-6899  [000] ...1   470.834443: fscache_cookie: PUT dnt c=0000000052e4f404 u=1 p=00000000fbb5c648 Nc=0 Na=0 f=18
-------------------------8<----------------------------

The u= count never seems to go to 1, so I think there's a reference leaking somewhere.
Comment 25 Jeff Layton 2019-10-22 12:33:16 UTC
Erm... "The u= count never seems to go _below_ 1..."
Comment 26 Jeff Layton 2019-10-22 13:25:01 UTC
A bit more debugging. I had the kernel limit the number of retries to 100, and got this to pop:

[  570.004348] FS-Cache: Duplicate cookie detected
[  570.005397] FS-Cache: O-cookie c=000000006df0abdd [i=(null) p=ffff8883f92dc000 fl=a18 nc=0 na=0, cnt=2]
[  570.009759] FS-Cache: O-cookie d=0000000000000000 n=0000000000000000
[  570.011147] FS-Cache: O-cookie o=ffff8883f95a3400
[  570.012169] FS-Cache: O-key=[20] '74ab262f4bde400da8e9fb3248a12a3a74657374'
[  570.013544] FS-Cache: N-cookie c=000000008763dd60 [i=CEPH.fsid p=ffff8883f92dc000 fl=2 nc=0 na=1, cnt=1]
[  570.015484] FS-Cache: N-cookie d=ffffffffa049a280 n=ffff88842b4649c0
[  570.016763] FS-Cache: N-key=[20] '74ab262f4bde400da8e9fb3248a12a3a74657374'
[  570.018167] unable to register fscache cookie for fsid 74ab262f-4bde-400d-a8e9-fb3248a12a3a

# cat /proc/fs/fscache/objects 
OBJECT   PARENT   STAT CHLDN OPS OOP IPR EX READS EM EV FL S | NETFS_COOKIE_DEF TY FL NETFS_DATA       OBJECT_KEY, AUX_DATA
======== ======== ==== ===== === === === == ===== == == == = | ================ == == ================ ================
       3        0 ?CMD     1   0   0   0  0     0 6d 10 38 0 | FSDEF.netfs      IX 220         7e1ffb20 63657068, 00000000
     41a        3 ?CLR     0   3   3   0  0     0 10  0 30 0 | (null)           IX a18         d03c946b 74ab262f4bde400da8e9fb3248a12a3a74657374
     419 ffffffff DEAD     0   0   0   0  0     0  0  0  0 0 | (null)           DT a12         d03c946b b6a3030000010000feffffffffffffff, b6a3030000010000feffffffffffffff00000000ad4eadde
       0 ffffffff ?INI     1   0   0   0  0     0 6f 10 28 0 | .FS-Cache        IX 20         d03c946b

Also attaching associated trace file.
Comment 27 Jeff Layton 2019-10-22 13:26:04 UTC
Created attachment 285615 [details]
tracepoint output from the run

Note You need to log in before you can comment on or make changes to this bug.