Bugzilla (bugzilla.redhat.com) will be under maintenance for infrastructure upgrades and will not be available on July 31st between 12:30 AM - 05:30 AM UTC. We appreciate your understanding and patience. You can follow status.redhat.com for details.
Bug 1649877 - init script does not tell errors via correct syslog level
Summary: init script does not tell errors via correct syslog level
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: ipset
Version: 7.6
Hardware: Unspecified
OS: Unspecified
medium
medium
Target Milestone: rc
: ---
Assignee: Stefano Brivio
QA Contact: Tomas Dolezal
Marc Muehlfeld
URL:
Whiteboard:
Depends On:
Blocks: 1654714 NST_77ReleaseNotes
TreeView+ depends on / blocked
 
Reported: 2018-11-14 16:47 UTC by Tomas Dolezal
Modified: 2019-08-06 13:00 UTC (History)
5 users (show)

Fixed In Version: ipset-7.1-1
Doc Type: Bug Fix
Doc Text:
.Error logging in the `ipset` service has been improved Previously, the `ipset` service did not report configuration errors with a meaningful severity in the `systemd` logs. The severity level for invalid configuration entries was only `informational`, and the service did not report errors for an unusable configuration. As a consequence, it was difficult for administrators to identify and troubleshoot issues in the `ipset` service's configuration. With this update, `ipset` reports configuration issues as `warnings` in `systemd` logs and, if the service fails to start, it logs an entry with the `error` severity including further details. As a result, it is now easier to troubleshoot issues in the configuration of the `ipset` service.
Clone Of:
: 1683711 (view as bug list)
Environment:
Last Closed: 2019-08-06 13:00:07 UTC
Target Upstream Version:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Bugzilla 1646666 0 urgent CLOSED ipset-service fails to load ipsets with set dependencies 2021-02-22 00:41:40 UTC
Red Hat Bugzilla 1647096 1 None None None 2021-01-20 06:05:38 UTC
Red Hat Bugzilla 1650297 0 high CLOSED error in configuration prevents the rest from loading 2021-02-22 00:41:40 UTC
Red Hat Product Errata RHBA-2019:2158 0 None None None 2019-08-06 13:00:23 UTC

Internal Links: 1646666 1647096 1650297

Description Tomas Dolezal 2018-11-14 16:47:56 UTC
Description of problem:
Since release 6.38 the initscript started using configuration files in a directory without proper checking whether they are correctly applied.
Previously, any configuration error resulted in a failed service start.

The error is also not referring to any specific plase, there should be a pointer to file or command where the failure has occurred.

With unreliable (ref bz1649836) output of initscript on stderr/stdout, it would be safer to emit service failure. The service, if not running (or unsuccessfully started) it should be in failed state anyway.

(!) As seen bellow with '0file', configuration error may cause incomplete/none sets to be loaded while the service has successfully started.

There should be a filter for files so that custom backups or other files could reside in directory with configuration. currently all 'save' files have .set suffix, this could be the filter along with ignoring directories.

Version-Release number of selected component (if applicable):
ipset-6.38-3.el7_6.x86_64
ipset-6.38-2.el7.x86_64

How reproducible:
always

Steps to Reproduce:
ipset restore <<EOF
create asetlist list:set size 8
create set1 hash:net,port family inet hashsize 65536 maxelem 262144 counters
create set2 hash:net,port,net family inet hashsize 65536 maxelem 262144 counters
add asetlist set1
add asetlist set2
EOF
service ipset save
service ipset restart
systemctl status -l 

mkdir /etc/sysconfig/ipset.d/0dir
service ipset restart
systemctl status -l

echo 'add invalid entry' > /etc/sysconfig/ipset.d/0file
service ipset restart
systemctl status -l

Actual results:
>for unpatched -2 release:
● ipset.service - IP sets for iptables
   Loaded: loaded (/usr/lib/systemd/system/ipset.service; disabled; vendor preset: disabled)
   Active: active (exited) since Wed 2018-11-14 11:38:18 EST; 2s ago
  Process: 24377 ExecStop=/usr/libexec/ipset/ipset.start-stop stop (code=exited, status=0/SUCCESS)
  Process: 24388 ExecStart=/usr/libexec/ipset/ipset.start-stop start (code=exited, status=0/SUCCESS)
 Main PID: 24388 (code=exited, status=0/SUCCESS)

Nov 14 11:38:18 host-8-251-5.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped IP sets for iptables.
Nov 14 11:38:18 host-8-251-5.host.centralci.eng.rdu2.redhat.com systemd[1]: Starting IP sets for iptables...
Nov 14 11:38:18 host-8-251-5.host.centralci.eng.rdu2.redhat.com ipset.start-stop[24388]: ipset v6.38: Error in line 2: Set to be added/deleted/tested as element does not exist.
Nov 14 11:38:18 host-8-251-5.host.centralci.eng.rdu2.redhat.com ipset.start-stop[24388]: ipset: Failed to restore configured sets
Nov 14 11:38:18 host-8-251-5.host.centralci.eng.rdu2.redhat.com systemd[1]: Started IP sets for iptables.


>ipset-6.38-3.el7_6.x86_64 with 0dir:
● ipset.service - IP sets for iptables
   Loaded: loaded (/usr/lib/systemd/system/ipset.service; disabled; vendor preset: disabled)
   Active: active (exited) since Wed 2018-11-14 11:40:10 EST; 1min 2s ago
  Process: 24477 ExecStop=/usr/libexec/ipset/ipset.start-stop stop (code=exited, status=0/SUCCESS)
  Process: 24488 ExecStart=/usr/libexec/ipset/ipset.start-stop start (code=exited, status=0/SUCCESS)
 Main PID: 24488 (code=exited, status=0/SUCCESS)

Nov 14 11:40:10 host-8-251-5.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped IP sets for iptables.
Nov 14 11:40:10 host-8-251-5.host.centralci.eng.rdu2.redhat.com systemd[1]: Starting IP sets for iptables...
Nov 14 11:40:10 host-8-251-5.host.centralci.eng.rdu2.redhat.com ipset.start-stop[24488]: head: error reading ‘/etc/sysconfig/ipset.d/0dir’: Is a directory
Nov 14 11:40:10 host-8-251-5.host.centralci.eng.rdu2.redhat.com ipset.start-stop[24488]: tail: error reading ‘/etc/sysconfig/ipset.d/0dir’: Is a directory
Nov 14 11:40:10 host-8-251-5.host.centralci.eng.rdu2.redhat.com systemd[1]: Started IP sets for iptables.

>ipset-6.38-3.el7_6.x86_64 with 0dir and 0file:
>NO IPSETS ARE LOADED
● ipset.service - IP sets for iptables
   Loaded: loaded (/usr/lib/systemd/system/ipset.service; disabled; vendor preset: disabled)
   Active: active (exited) since Wed 2018-11-14 11:42:21 EST; 11s ago
  Process: 24526 ExecStop=/usr/libexec/ipset/ipset.start-stop stop (code=exited, status=0/SUCCESS)
  Process: 24537 ExecStart=/usr/libexec/ipset/ipset.start-stop start (code=exited, status=0/SUCCESS)
 Main PID: 24537 (code=exited, status=0/SUCCESS)

Nov 14 11:42:21 host-8-251-5.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped IP sets for iptables.
Nov 14 11:42:21 host-8-251-5.host.centralci.eng.rdu2.redhat.com systemd[1]: Starting IP sets for iptables...
Nov 14 11:42:21 host-8-251-5.host.centralci.eng.rdu2.redhat.com ipset.start-stop[24537]: head: error reading ‘/etc/sysconfig/ipset.d/0dir’: Is a directory
Nov 14 11:42:21 host-8-251-5.host.centralci.eng.rdu2.redhat.com ipset.start-stop[24537]: tail: error reading ‘/etc/sysconfig/ipset.d/0dir’: Is a directory
Nov 14 11:42:21 host-8-251-5.host.centralci.eng.rdu2.redhat.com ipset.start-stop[24537]: ipset v6.38: Error in line 1: The set with the given name does not exist
Nov 14 11:42:21 host-8-251-5.host.centralci.eng.rdu2.redhat.com ipset.start-stop[24537]: ipset: Failed to restore configured sets
Nov 14 11:42:21 host-8-251-5.host.centralci.eng.rdu2.redhat.com systemd[1]: Started IP sets for iptables.


Expected results:
ipset-6.29-1.el7.x86_64:
● ipset.service - IP sets for iptables
   Loaded: loaded (/usr/lib/systemd/system/ipset.service; disabled; vendor preset: disabled)
   Active: failed (Result: exit-code) since Tue 2018-11-13 14:01:07 EST; 2s ago
  Process: 21405 ExecStop=/usr/libexec/ipset/ipset.start-stop stop (code=exited, status=0/SUCCESS)
  Process: 21414 ExecStart=/usr/libexec/ipset/ipset.start-stop start (code=exited, status=1/FAILURE)
 Main PID: 21414 (code=exited, status=1/FAILURE)

Nov 13 14:01:07 host-8-240-104.host.centralci.eng.rdu2.redhat.com systemd[1]: Stopped IP sets for iptables.
Nov 13 14:01:07 host-8-240-104.host.centralci.eng.rdu2.redhat.com systemd[1]: Starting IP sets for iptables...
Nov 13 14:01:07 host-8-240-104.host.centralci.eng.rdu2.redhat.com ipset.start-stop[21414]: ipset v6.29: Error in line 1: The set with the given name does not exist
Nov 13 14:01:07 host-8-240-104.host.centralci.eng.rdu2.redhat.com systemd[1]: ipset.service: main process exited, code=exited, status=1/FAILURE
Nov 13 14:01:07 host-8-240-104.host.centralci.eng.rdu2.redhat.com systemd[1]: Failed to start IP sets for iptables.
Nov 13 14:01:07 host-8-240-104.host.centralci.eng.rdu2.redhat.com systemd[1]: Unit ipset.service entered failed state.
Nov 13 14:01:07 host-8-240-104.host.centralci.eng.rdu2.redhat.com systemd[1]: ipset.service failed.


Additional info:

Comment 4 Tomas Dolezal 2018-11-14 17:23:53 UTC
ref bug 1649836 comment 4:
As msekletar suggested, journalctl --sync should be used before the script ends with newer kernel/systemd to prevent journal loosing connection of produced output with the ipset.service

Comment 9 Tomas Dolezal 2018-11-15 18:52:49 UTC
as per comment 6 and irc communication, i've created bug 1650297 for issue with errors in configuration preventing a best-effort load of the correct rest of it.

this bug is to fix logging in a way that messages are shown with correct level of 'error' in journal of associated 'ipset.service' systemd service.

the service also should fail if the sets are not correctly loaded, but this is yet to be decided.

Comment 20 errata-xmlrpc 2019-08-06 13:00:07 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/RHBA-2019:2158


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