Bug 2059396

Summary: ipa-dnskeysyncd floods /var/log/messages with DEBUG messages
Product: Red Hat Enterprise Linux 8 Reporter: Tomasz Kepczynski <tomek>
Component: ipaAssignee: Rob Crittenden <rcritten>
Status: CLOSED ERRATA QA Contact: Ganna Kaihorodova <gkaihoro>
Severity: unspecified Docs Contact: lmcgarry
Priority: unspecified    
Version: 8.5CC: brian, frenaud, gkaihoro, myusuf, rcritten, rjeffman, sumenon, tscherf
Target Milestone: rcKeywords: Triaged
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: ipa-4.9.10-1.module+el8.7.0+15691+2b2c1dd5 Doc Type: Bug Fix
Doc Text:
.Debug messages no longer logged to /var/log/messages by default Previously, the `ipa-dnskeysyncd` and `ipa-ods-exporter` daemons logged all debug messages to `/var/log/messages` by default, resulting in log files growing substantially. If required, you can now configure the debug log level by setting `debug=True` in the `/etc/ipa/dns.conf` file. For more information refer to the `default.conf(5)` man page.
Story Points: ---
Clone Of:
: 2083218 (view as bug list) Environment:
Last Closed: 2022-11-08 09:35:50 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Bug Depends On:    
Bug Blocks: 2083218    

Description Tomasz Kepczynski 2022-02-28 22:42:42 UTC
Description of problem:

I've just noticed that my /var/log/messages log file grew for nearly 1G withing las t week or so (since last rotation).

Most of the messages were produced by ipa-dnskeysyncd and vast majority of them where tagged with "DEBUG" clearly indicating them as debug messages.

rsyslog configuration DOES NOT route ANY debug level messages to any of the files.

This is the line for the /var/log/messages:

*.info;mail.none;authpriv.none;cron.none                /var/log/messages

The excerpt of the messages:
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/02fb809d-7384-bc5e-5e4f-b6323a23853b.lock
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/b9a80f92-e6ce-a8a8-5e5d-6524e4868ce9.lock
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/fc39eaf7-3564-9b91-8f90-78d959798212.lock
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/a8728635-7a4f-160d-ddc5-bef9596b1a9d.lock
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/d11c4818-e780-c6ed-e3f0-edcbbbdee7e0.lock
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/token.object
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/08ab937e-ba08-f048-5646-62f0ccf99a58.lock
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/1c723a39-a6db-9ee8-4651-d76a7cc91a84.object
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/6319c4ef-1bd6-902e-5dd9-081f3bcfc6e3.lock
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/e6d08596-8bea-66fe-74e6-3faf960da05f.object
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/704ec42b-f534-4827-27b1-0e56f7ea2565.object
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/76225839-2993-0907-0c4c-81e3ed9b0fb5.lock
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/4da28d58-41b4-20cc-3c17-ab8274b04275.object
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/af91ab94-092a-d6c7-e3e7-d17b7fa197bc.object
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/a9a4638b-3562-034d-71a7-e7280044d353.lock
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/55482eaa-262f-a972-be8c-138f7acdabb6.object
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/454a2218-5ea8-a09f-b750-7a46e3f58239.object
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/c6975e09-936d-843f-3e98-7f10caa9381a.object
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/ffd03bc1-2be0-82b9-311c-d9ded23fd09b.lock
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/df1ad250-b989-5415-1c50-959643f20fda.object
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/ed147039-af10-4166-fd6c-5d1fb9aac95a.object
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/a068caf1-e64d-f06e-10ab-310a20567e81.lock
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/55fc5277-da4f-bea7-2558-0b6fda202e4a.object
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/a17e64fa-b141-175d-b129-5b197d0ad0f5.lock
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/a9a4638b-3562-034d-71a7-e7280044d353.object
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/7bddd2dd-2402-a3ce-7276-7e34b09c7a3e.object
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/08ab937e-ba08-f048-5646-62f0ccf99a58.object
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/e14a44f5-7535-2daa-2e99-3479d2598c2d.lock
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/a599f0c7-33e5-cbda-c6cf-0261a620ddad.object
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/5e78730f-a432-321a-a0e5-4fb72b1057e6.object
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/147b9465-56e1-5824-29e4-2dd5c1d24483.lock
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/43813b8d-87f8-46f8-be4d-83bca06544c2.object
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/e8549900-e9ea-a355-00c8-467f91424217.lock
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/1c94cc1a-bf53-66a8-dcf5-e3dec0053111.object
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/18954a13-389d-60ce-63fc-1f68c578231a.lock
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/06e4d55e-5963-2b4c-d084-5a9b5464c20b.object
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/9a20b3d0-9c27-2794-ced2-3651d494f1f6.lock
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/5213f0eb-2d66-90dd-57c9-a2d5cf4a4f56.lock
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/a8728635-7a4f-160d-ddc5-bef9596b1a9d.object
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/d3d64f27-d217-5332-c6db-83f61023eccb.lock
Feb 28 23:32:27 filippa ipa-dnskeysyncd[126691]: ipaserver.dnssec.bindmgr: DEBUG    Fixing file permissions: /var/lib/ipa/dnssec/tokens/9ad363a0-d7a9-0b9a-01f3-10e007e4b61f/11cc7cc6-b969-c03a-c616-28410d2e3831.object

And much more of these and different messages.




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

filippa:~# rpm -qa ipa*
ipa-common-4.9.6-10.module_el8.5.0+2603+92118e57.noarch
ipa-server-trust-ad-4.9.6-10.module_el8.5.0+2603+92118e57.x86_64
ipa-client-4.9.6-10.module_el8.5.0+2603+92118e57.x86_64
ipa-server-common-4.9.6-10.module_el8.5.0+2603+92118e57.noarch
ipa-healthcheck-core-0.7-6.module_el8.5.0+2603+92118e57.noarch
ipa-client-common-4.9.6-10.module_el8.5.0+2603+92118e57.noarch
ipa-server-4.9.6-10.module_el8.5.0+2603+92118e57.x86_64
ipa-selinux-4.9.6-10.module_el8.5.0+2603+92118e57.noarch
ipa-server-dns-4.9.6-10.module_el8.5.0+2603+92118e57.noarch




How reproducible:
Not sure. I think there is a reason for these but I haven't pinpointed it yet. And it is not relevant to this issue. See below.



Actual results:
The debug level messages ARE flooding the files which are not configured to collect them.



Expected results:
The debug level messages ARE NOT flooding the files which are not configured to collect them.

Additional info:
I believe this is caused by incorrect logging configuration in the ipa-dnskeysyncd process. It probably is sending debug messages with the higher level than LOG_DEBUG designated for debug logging. I suspect it incorrectly uses LOG_INFO for debugging logs.

There is additional issue with the above messages. They seem to be logging information about SUCCESSFULL operation. I am not sure how useful it is. Please reconsider and drop it.

Disclosure:
Found on AlmaLinux 8.5.

Comment 1 Rob Crittenden 2022-03-09 14:16:34 UTC
debug is hardcoded as True.

I believe this can be resolved by finalizing the IPA API first and using api.env.debug instead. This would allow a user to create /etc/ipa/dns.conf to enable debugging if additional troubleshooting is needed.

Comment 2 Rob Crittenden 2022-03-15 20:36:23 UTC
Link to upstream ticket https://pagure.io/freeipa/issue/9128

Comment 7 Florence Blanc-Renaud 2022-06-02 09:22:52 UTC
Fixed upstream
master:
https://pagure.io/freeipa/c/cef6a90288d9ec0c69f74ddce93db14694ba7a76

Comment 8 Florence Blanc-Renaud 2022-06-02 12:16:36 UTC
Fixed upstream
ipa-4-9:
https://pagure.io/freeipa/c/c00286462196026337600113119eb5522b96141a

Comment 16 errata-xmlrpc 2022-11-08 09:35:50 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 (idm:client and idm:DL1 bug fix and enhancement update), 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/RHBA-2022:7540