Bug 1704181 - Brick logs inundated with [2019-04-27 22:14:53.378047] I [dict.c:541:dict_get] (-->/usr/lib64/glusterfs/6.0/xlator/features/worm.so(+0x7241) [0x7fe857bb3241] -->/usr/lib64/glusterfs/6.0/xlator/features/locks.so(+0x1c219) [0x7fe857dda219] [Invalid argumen
Summary: Brick logs inundated with [2019-04-27 22:14:53.378047] I [dict.c:541:dict_ge...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Gluster Storage
Classification: Red Hat Storage
Component: locks
Version: rhgs-3.5
Hardware: Unspecified
OS: Unspecified
high
high
Target Milestone: ---
: RHGS 3.5.0
Assignee: Susant Kumar Palai
QA Contact: Nag Pavan Chilakam
URL:
Whiteboard:
Depends On:
Blocks: 1696809 1712322 1797985
TreeView+ depends on / blocked
 
Reported: 2019-04-29 09:32 UTC by Nag Pavan Chilakam
Modified: 2020-02-04 10:57 UTC (History)
11 users (show)

Fixed In Version: glusterfs-6.0-4
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
: 1712322 (view as bug list)
Environment:
Last Closed: 2019-10-30 12:20:55 UTC
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Product Errata RHEA-2019:3249 0 None None None 2019-10-30 12:21:18 UTC

Description Nag Pavan Chilakam 2019-04-29 09:32:08 UTC
Description of problem:
======================
brick logs are being inundated with below information messages.

[2019-04-27 22:14:53.378047] I [dict.c:541:dict_get] (-->/usr/lib64/glusterfs/6.0/xlator/features/worm.so(+0x7241) [0x7fe857bb3241] -->/usr/lib64/glusterfs/6.0/xlator/features/locks.so(+0x1c219) [0x7fe857dda219] -->/lib64/libglusterfs.so.
0(dict_get+0x94) [0x7fe86c2d7294] ) 39-dict: !this || key=trusted.glusterfs.enforce-mandatory-lock [Invalid argument

Version-Release number of selected component (if applicable):
=====================
6.0.2



Steps to Reproduce:
================
1. created a 44x(4+2), brick mux'ed EC volume
2. started to pump IOs from 4 clients, turned off other-eager lock
3. brick logs are floode with above informational messages


Expected results:
===================
the above message was not seen in previous releases.
It could be with the fact that there were some worm related fixes as part of rebase.
irrespective, flooding the logs with above messages would mean storage running out of space.

Additional info:
===============
regression

Comment 2 Nag Pavan Chilakam 2019-04-29 09:33:27 UTC
 
Volume Name: bmxecv
Type: Distributed-Disperse
Volume ID: a3386dc3-ff60-4234-92b5-021b37cdd1cb
Status: Started
Snapshot Count: 0
Number of Bricks: 22 x (4 + 2) = 132
Transport-type: tcp
Bricks:
Brick1: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick1/bmxecv
Brick2: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick1/bmxecv
Brick3: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick1/bmxecv
Brick4: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick2/bmxecv
Brick5: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick2/bmxecv
Brick6: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick2/bmxecv
Brick7: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick3/bmxecv
Brick8: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick3/bmxecv
Brick9: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick3/bmxecv
Brick10: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick4/bmxecv
Brick11: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick4/bmxecv
Brick12: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick4/bmxecv
Brick13: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick5/bmxecv
Brick14: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick5/bmxecv
Brick15: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick5/bmxecv
Brick16: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick6/bmxecv
Brick17: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick6/bmxecv
Brick18: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick6/bmxecv
Brick19: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick7/bmxecv
Brick20: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick7/bmxecv
Brick21: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick7/bmxecv
Brick22: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick8/bmxecv
Brick23: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick8/bmxecv
Brick24: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick8/bmxecv
Brick25: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick9/bmxecv
Brick26: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick9/bmxecv
Brick27: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick9/bmxecv
Brick28: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick10/bmxecv
Brick29: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick10/bmxecv
Brick30: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick10/bmxecv
Brick31: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick11/bmxecv
Brick32: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick11/bmxecv
Brick33: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick11/bmxecv
Brick34: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick12/bmxecv
Brick35: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick12/bmxecv
Brick36: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick12/bmxecv
Brick37: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick13/bmxecv
Brick38: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick13/bmxecv
Brick39: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick13/bmxecv
Brick40: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick14/bmxecv
Brick41: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick14/bmxecv
Brick42: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick14/bmxecv
Brick43: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick15/bmxecv
Brick44: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick15/bmxecv
Brick45: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick15/bmxecv
Brick46: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick16/bmxecv
Brick47: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick16/bmxecv
Brick48: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick16/bmxecv
Brick49: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick17/bmxecv
Brick50: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick17/bmxecv
Brick51: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick17/bmxecv
Brick52: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick18/bmxecv
Brick53: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick18/bmxecv
Brick54: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick18/bmxecv
Brick55: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick19/bmxecv
Brick56: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick19/bmxecv
Brick57: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick19/bmxecv
Brick58: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick20/bmxecv
Brick59: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick20/bmxecv
Brick60: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick20/bmxecv
Brick61: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick21/bmxecv
Brick62: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick21/bmxecv
Brick63: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick21/bmxecv
Brick64: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick22/bmxecv
Brick65: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick22/bmxecv
Brick66: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick22/bmxecv
Brick67: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick23/bmxecv
Brick68: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick23/bmxecv
Brick69: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick23/bmxecv
Brick70: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick24/bmxecv
Brick71: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick24/bmxecv
Brick72: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick24/bmxecv
Brick73: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick25/bmxecv
Brick74: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick25/bmxecv
Brick75: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick25/bmxecv
Brick76: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick26/bmxecv
Brick77: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick26/bmxecv
Brick78: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick26/bmxecv
Brick79: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick27/bmxecv
Brick80: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick27/bmxecv
Brick81: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick27/bmxecv
Brick82: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick28/bmxecv
Brick83: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick28/bmxecv
Brick84: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick28/bmxecv
Brick85: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick29/bmxecv
Brick86: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick29/bmxecv
Brick87: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick29/bmxecv
Brick88: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick30/bmxecv
Brick89: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick30/bmxecv
Brick90: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick30/bmxecv
Brick91: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick31/bmxecv
Brick92: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick31/bmxecv
Brick93: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick31/bmxecv
Brick94: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick32/bmxecv
Brick95: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick32/bmxecv
Brick96: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick32/bmxecv
Brick97: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick33/bmxecv
Brick98: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick33/bmxecv
Brick99: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick33/bmxecv
Brick100: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick34/bmxecv
Brick101: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick34/bmxecv
Brick102: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick34/bmxecv
Brick103: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick35/bmxecv
Brick104: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick35/bmxecv
Brick105: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick35/bmxecv
Brick106: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick36/bmxecv
Brick107: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick36/bmxecv
Brick108: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick36/bmxecv
Brick109: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick37/bmxecv
Brick110: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick37/bmxecv
Brick111: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick37/bmxecv
Brick112: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick38/bmxecv
Brick113: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick38/bmxecv
Brick114: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick38/bmxecv
Brick115: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick39/bmxecv
Brick116: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick39/bmxecv
Brick117: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick39/bmxecv
Brick118: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick40/bmxecv
Brick119: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick40/bmxecv
Brick120: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick40/bmxecv
Brick121: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick41/bmxecv
Brick122: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick41/bmxecv
Brick123: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick41/bmxecv
Brick124: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick42/bmxecv
Brick125: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick42/bmxecv
Brick126: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick42/bmxecv
Brick127: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick43/bmxecv
Brick128: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick43/bmxecv
Brick129: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick43/bmxecv
Brick130: rhs-gp-srv1.lab.eng.blr.redhat.com:/gluster/brick44/bmxecv
Brick131: rhs-gp-srv2.lab.eng.blr.redhat.com:/gluster/brick44/bmxecv
Brick132: rhs-gp-srv4.lab.eng.blr.redhat.com:/gluster/brick44/bmxecv
Options Reconfigured:
disperse.other-eager-lock: off
nfs.disable: on
cluster.brick-multiplex: enable
[root@rhs-gp-srv1 glusterfs]# gluster v get all all
Option                                  Value                                   
------                                  -----                                   
cluster.server-quorum-ratio             51                                      
cluster.enable-shared-storage           disable                                 
cluster.op-version                      70000                                   
cluster.max-op-version                  70000                                   
cluster.brick-multiplex                 enable                                  
cluster.max-bricks-per-process          250                                     
glusterd.vol_count_per_thread           100                                     
cluster.daemon-log-level                INFO                                    
[root@rhs-gp-srv1 glusterfs]#

Comment 5 Nag Pavan Chilakam 2019-04-29 12:31:57 UTC
logs and sosreports same as BZ#1704211
logs and sosreports @ http://rhsqe-repo.lab.eng.blr.redhat.com/sosreports/nchilaka//bug.1704211/servers/


Note that the log flooding possibly should have nothing to do with BZ#1704211 as the flooding issue started even before we hit brick down issue

Comment 16 Susant Kumar Palai 2019-05-21 10:54:12 UTC
Upstream patch: https://review.gluster.org/#/c/glusterfs/+/22756/

Comment 17 Susant Kumar Palai 2019-05-21 10:57:34 UTC
The upstream logs the null dict messages in "DEBUG" only but downstream has it in "INFO". I guess downstream code needs to be converted to DEBUG as well.

Comment 25 errata-xmlrpc 2019-10-30 12:20:55 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHEA-2019:3249

Comment 26 bence 2019-11-06 10:06:49 UTC
Hi, 
in my installation it is not resloved:

Centos 7 (x86_64)
glusterfs 6.6 from: mirrorlist=http://mirrorlist.centos.org?arch=$basearch&release=$releasever&repo=storage-gluster-6
(just upgraded to it, but in 6.5 it is also there)

Volume Name: ttk
Type: Replicate
Volume ID: <deleted>
Status: Started
Snapshot Count: 0
Number of Bricks: 1 x (2 + 1) = 3
Transport-type: tcp
Bricks:
Brick1: gfs1:/bricks/brick3/ttk
Brick2: gfsX:/bricks/brick3/ttk
Brick3: gfs2:/bricks/brick3/ttk (arbiter)
Options Reconfigured:
ssl.certificate-depth: 2
performance.client-io-threads: on
nfs.disable: on
transport.address-family: inet
server.ssl: on
client.ssl: on
auth.ssl-allow: *
cluster.shd-max-threads: 8
disperse.shd-wait-qlength: 2048

And on the other volume too: effectivly the same config as above

Comment 27 Netbulae 2020-02-04 10:43:58 UTC
I have the same errors on 6.7, replica 3 volumes

[2020-02-04 10:29:23.045868] I [dict.c:560:dict_get] (-->/usr/lib64/glusterfs/6.7/xlator/features/worm.so(+0x7281) [0x7f8c0609f281] -->/usr/lib64/glusterfs/6.7/xlator/features/locks.so(+0x1c259) [0x7f8c062c5259] -->/lib64/libglusterfs.so.0(dict_get+0x94) [0x7f8c19f9b254] ) 0-dict: !this || key=trusted.glusterfs.enforce-mandatory-lock [Invalid argument]
[2020-02-04 10:29:23.714027] I [dict.c:560:dict_get] (-->/usr/lib64/glusterfs/6.7/xlator/features/worm.so(+0x7281) [0x7f8c0609f281] -->/usr/lib64/glusterfs/6.7/xlator/features/locks.so(+0x1c259) [0x7f8c062c5259] -->/lib64/libglusterfs.so.0(dict_get+0x94) [0x7f8c19f9b254] ) 0-dict: !this || key=trusted.glusterfs.enforce-mandatory-lock [Invalid argumen

Comment 28 Mohit Agrawal 2020-02-04 10:57:04 UTC
(In reply to Netbulae from comment #27)
> I have the same errors on 6.7, replica 3 volumes
> 
> [2020-02-04 10:29:23.045868] I [dict.c:560:dict_get]
> (-->/usr/lib64/glusterfs/6.7/xlator/features/worm.so(+0x7281)
> [0x7f8c0609f281]
> -->/usr/lib64/glusterfs/6.7/xlator/features/locks.so(+0x1c259)
> [0x7f8c062c5259] -->/lib64/libglusterfs.so.0(dict_get+0x94) [0x7f8c19f9b254]
> ) 0-dict: !this || key=trusted.glusterfs.enforce-mandatory-lock [Invalid
> argument]
> [2020-02-04 10:29:23.714027] I [dict.c:560:dict_get]
> (-->/usr/lib64/glusterfs/6.7/xlator/features/worm.so(+0x7281)
> [0x7f8c0609f281]
> -->/usr/lib64/glusterfs/6.7/xlator/features/locks.so(+0x1c259)
> [0x7f8c062c5259] -->/lib64/libglusterfs.so.0(dict_get+0x94) [0x7f8c19f9b254]
> ) 0-dict: !this || key=trusted.glusterfs.enforce-mandatory-lock [Invalid
> argumen

Backport a patch in release-6 also to resolve the same
https://review.gluster.org/#/c/glusterfs/+/24095/


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