FS#52098 - ferm.service gets started to early in boot process and might depend on a dynamic ip which is not set

Attached to Project: Community Packages
Opened by Florian (nougad) - Friday, 09 December 2016, 22:44 GMT
Last edited by Doug Newgard (Scimmia) - Friday, 09 December 2016, 23:39 GMT
Task Type Bug Report
Category Packages
Status Closed
Assigned To No-one
Architecture All
Severity Medium
Priority Normal
Reported Version
Due in Version Undecided
Due Date Undecided
Percent Complete 100%
Votes 0
Private No

Details

Description: ferm.service has as dependencies:

Before=network-pre.target
Wants=network-pre.target

But the network might not be setup completely on network-pre.target.


Additional info:
* package version(s): community/ferm 2.3-1, core/libsystemd 232-4
* config and/or log files etc.

To show the problem I changed ferm.service and added "--lines --slow" to see the line which actual breaks. Also I added "LogLevel=debug" in /etc/systemd/system.conf.

The ferm.conf contains a simple port forward:

@def $net = (ens3); # the interface with the ip 192.168.101.76
@def $fw = (192.168.101.76); # the ip of the ens3 interface
def &FORWARD_PORT($proto, $port, $dest) = {
table nat chain PREROUTING interface $net daddr $fw proto $proto dport $port DNAT to $dest; # << this line fails
table filter chain FORWARD interface $net outerface br0 daddr $dest proto $proto dport $port ACCEPT;
}
&FORWARD_PORT(tcp, 5269, 10.219.7.125);


$ journalctl -b -u ferm -u systemd-networkd -u network.target -u network-pre.target
Dec 09 23:19:27 virtarch systemd[1]: ferm.service: Passing 0 fds to service
Dec 09 23:19:27 virtarch systemd[1]: ferm.service: About to execute: /usr/bin/ferm --lines --slow /etc/ferm.conf
Dec 09 23:19:27 virtarch systemd[1]: ferm.service: Forked /usr/bin/ferm as 260
Dec 09 23:19:27 virtarch systemd[1]: ferm.service: Changed dead -> start
Dec 09 23:19:27 virtarch systemd[1]: Starting for Easy Rule Making...
Dec 09 23:19:27 virtarch systemd[260]: ferm.service: Executing: /usr/bin/ferm --lines --slow /etc/ferm.conf
Dec 09 23:19:27 virtarch ferm[260]: /sbin/iptables -t nat -P PREROUTING ACCEPT
Dec 09 23:19:27 virtarch ferm[260]: /sbin/iptables -t nat -P POSTROUTING ACCEPT
Dec 09 23:19:27 virtarch ferm[260]: /sbin/iptables -t nat -F
Dec 09 23:19:27 virtarch ferm[260]: /sbin/iptables -t nat -X
Dec 09 23:19:27 virtarch ferm[260]: /sbin/iptables -t nat -A PREROUTING --in-interface ens3 --destination 192.168.101.76 --protocol tcp --dport 5269 --jump DNAT
Dec 09 23:19:27 virtarch ferm[260]: iptables v1.6.0: DNAT: option "--to-destination" must be specified
Dec 09 23:19:27 virtarch ferm[260]: Try `iptables -h' or 'iptables --help' for more information.
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -P FORWARD ACCEPT
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -P OUTPUT ACCEPT
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -P INPUT ACCEPT
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -F
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -X
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -P INPUT DROP
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -A FORWARD --match conntrack --ctstate INVALID --jump DROP
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -A FORWARD --match conntrack --ctstate ESTABLISHED,RELATED --jump ACCEPT
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -A FORWARD --protocol icmpv6 --in-interface br0 --out-interface ens3 --jump ACCEPT
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -A FORWARD --protocol icmpv6 --in-interface br0 --out-interface ens3 --jump ACCEPT
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -A FORWARD --protocol icmpv6 --in-interface br0 --out-interface br0 --jump ACCEPT
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -A FORWARD --protocol icmpv6 --in-interface br0 --out-interface br0 --jump ACCEPT
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -A OUTPUT --match conntrack --ctstate INVALID --jump DROP
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -A OUTPUT --match conntrack --ctstate ESTABLISHED,RELATED --jump ACCEPT
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -A INPUT --in-interface lo --jump ACCEPT
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -A INPUT --protocol icmpv6 --icmpv6-type echo-request --jump ACCEPT
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -A INPUT --protocol tcp --dport ssh --jump ACCEPT
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -A INPUT --match conntrack --ctstate INVALID --jump DROP
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -A INPUT --match conntrack --ctstate ESTABLISHED,RELATED --jump ACCEPT
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -A INPUT --protocol tcp --in-interface ens3 --dport ssh --jump ACCEPT
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -A INPUT --protocol udp --in-interface br0 --sport bootpc --dport bootps --jump ACCEPT
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -A INPUT --protocol udp --in-interface br0 --dport domain --jump ACCEPT
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -A INPUT --protocol icmpv6 --in-interface br0 --jump ACCEPT
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -A INPUT --match limit --limit 3/min --limit-burst 10 --jump LOG --log-prefix 'INPUT-DROP: ' --log-level debug
Dec 09 23:19:27 virtarch ferm[260]: /sbin/ip6tables -t filter -A INPUT --jump DROP
Dec 09 23:19:27 virtarch ferm[260]: Firewall rules rolled back.
Dec 09 23:19:27 virtarch systemd[1]: ferm.service: Child 260 belongs to ferm.service
Dec 09 23:19:27 virtarch systemd[1]: ferm.service: Main process exited, code=exited, status=1/FAILURE
Dec 09 23:19:27 virtarch systemd[1]: ferm.service: Changed start -> failed
Dec 09 23:19:27 virtarch systemd[1]: ferm.service: Job ferm.service/start finished, result=failed
Dec 09 23:19:27 virtarch systemd[1]: Failed to start for Easy Rule Making.
Dec 09 23:19:27 virtarch systemd[1]: ferm.service: Unit entered failed state.
Dec 09 23:19:27 virtarch systemd[1]: ferm.service: Failed with result 'exit-code'.
Dec 09 23:19:27 virtarch systemd[1]: ferm.service: cgroup is empty
Dec 09 23:19:27 virtarch systemd[1]: network-pre.target: Job network-pre.target/start finished, result=done
Dec 09 23:19:27 virtarch systemd[1]: Reached target Network (Pre).
Dec 09 23:19:27 virtarch systemd[1]: systemd-networkd.service: ConditionCapability=CAP_NET_ADMIN succeeded.
Dec 09 23:19:27 virtarch systemd[1]: systemd-networkd.service: Passing 1 fds to service
Dec 09 23:19:27 virtarch systemd[1]: systemd-networkd.service: About to execute: /usr/lib/systemd/systemd-networkd
Dec 09 23:19:27 virtarch systemd[1]: systemd-networkd.service: Forked /usr/lib/systemd/systemd-networkd as 399
Dec 09 23:19:27 virtarch systemd[1]: systemd-networkd.service: Changed dead -> start
Dec 09 23:19:27 virtarch systemd[1]: Starting Network Service...
Dec 09 23:19:27 virtarch systemd[399]: systemd-networkd.service: Executing: /usr/lib/systemd/systemd-networkd
Dec 09 23:19:27 virtarch systemd[1]: systemd-networkd.service: Got notification message from PID 399 (WATCHDOG=1)
Dec 09 23:19:27 virtarch systemd-networkd[399]: br0: netdev ready
Dec 09 23:19:27 virtarch systemd-networkd[399]: Enumeration completed
Dec 09 23:19:27 virtarch systemd[1]: systemd-networkd.service: Got notification message from PID 399 (READY=1, STATUS=Processing requests...)
Dec 09 23:19:27 virtarch systemd[1]: systemd-networkd.service: Changed start -> running
Dec 09 23:19:27 virtarch systemd[1]: systemd-networkd.service: Job systemd-networkd.service/start finished, result=done
Dec 09 23:19:27 virtarch systemd[1]: Started Network Service.
Dec 09 23:19:27 virtarch systemd[1]: network.target: Job network.target/start finished, result=done
Dec 09 23:19:27 virtarch systemd[1]: Reached target Network.
Dec 09 23:19:27 virtarch systemd-networkd[399]: ens3: Renamed to eth0
Dec 09 23:19:27 virtarch systemd-networkd[399]: eth0: Renamed to ens3
Dec 09 23:19:27 virtarch systemd-networkd[399]: ens3: IPv6 enabled for interface: Success
Dec 09 23:19:27 virtarch systemd-networkd[399]: ens3: Gained carrier
Dec 09 23:19:27 virtarch systemd-networkd[399]: ens3: DHCPv4 address 192.168.101.76/24 via 192.168.101.1 ### <<< ip set - ferm can start
Dec 09 23:19:27 virtarch systemd-networkd[399]: br0: IPv6 enabled for interface: Success
Dec 09 23:19:27 virtarch systemd-networkd[399]: br0: Gained carrier
Dec 09 23:19:29 virtarch systemd-networkd[399]: ens3: Gained IPv6LL
Dec 09 23:19:29 virtarch systemd-networkd[399]: ens3: Configured
Dec 09 23:19:29 virtarch systemd-networkd[399]: br0: Gained IPv6LL

$ cat /etc/systemd/network/wired.network
[Match]
Name=ens*

[Network]
DHCP=v4
IPForward=yes

Steps to reproduce:
* config systemd-networkd
* install ferm
* add ferm config with hardcoded ip
* reboot
* ferm will be started before systemd-networkd and will fail because it can't find the hardcoded ip
This task depends upon

Closed by  Doug Newgard (Scimmia)
Friday, 09 December 2016, 23:39 GMT
Reason for closing:  Not a bug
Additional comments about closing:  Configuration issue

Loading...