DevFactory/smartnat

Error reported on creation of mapping on debian 9 distro

Closed this issue · 1 comments

After creating a mapping object, smartnat attempts configuration on the instance but fails with error at two places when it triggers iptables-save with awk filter and while adding to ipset as seen in the logs.

iptables-save version: v.1.6.0

iptables-save output:

# Generated by iptables-save v1.6.0 on Thu May 16 12:08:08 2019
*mangle
:PREROUTING ACCEPT [3857:1791517]
:INPUT ACCEPT [3857:1791517]
:FORWARD ACCEPT [0:0]
:OUTPUT ACCEPT [3499:273893]
:POSTROUTING ACCEPT [3499:273893]
:SNM-PREROUTING - [0:0]
-A PREROUTING -m comment --comment "\"for SNM\"" -j SNM-PREROUTING
COMMIT
# Completed on Thu May 16 12:08:08 2019
# Generated by iptables-save v1.6.0 on Thu May 16 12:08:08 2019
*filter
:INPUT ACCEPT [7228:2692747]
:FORWARD ACCEPT [0:0]
:OUTPUT ACCEPT [5979:577631]
:KUBE-FORWARD - [0:0]
-A FORWARD -m comment --comment "kubernetes forwarding rules" -j KUBE-FORWARD
COMMIT
# Completed on Thu May 16 12:08:08 2019
# Generated by iptables-save v1.6.0 on Thu May 16 12:08:08 2019
*nat
:PREROUTING ACCEPT [21:964]
:INPUT ACCEPT [21:964]
:OUTPUT ACCEPT [36:2320]
:POSTROUTING ACCEPT [36:2320]
:KUBE-FIREWALL - [0:0]
:KUBE-LOAD-BALANCER - [0:0]
:KUBE-MARK-MASQ - [0:0]
:KUBE-NODE-PORT - [0:0]
:KUBE-POSTROUTING - [0:0]
:KUBE-SERVICES - [0:0]
:SNM-POSTROUTING-MASQ - [0:0]
:SNM-PREROUTING - [0:0]
-A PREROUTING -m comment --comment "kubernetes service portals" -j KUBE-SERVICES
-A PREROUTING -m comment --comment "\"for SNM\"" -j SNM-PREROUTING
-A OUTPUT -m comment --comment "kubernetes service portals" -j KUBE-SERVICES
-A POSTROUTING -m comment --comment "kubernetes postrouting rules" -j KUBE-POSTROUTING
-A POSTROUTING -j KUBE-POSTROUTING
-A POSTROUTING -m comment --comment "\"for SNM\"" -j SNM-POSTROUTING-MASQ
-A SNM-POSTROUTING-MASQ -m mark --mark 0x100000/0x100000 -m comment --comment "\"masquerade traffic marked in PREROUTING rules as destined for services\"" -j MASQUERADE
COMMIT
# Completed on Thu May 16 12:08:08 2019

smartnat logs snippet:

May 16 11:59:31 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:31Z" level=debug msg="adding f
inalizer info to Mapping object" name=mapping-sample5 namespace=devspaces-deploy-dev type=Mapping
May 16 11:59:31 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:31Z" level=debug msg="Mapping 
was updated during init, updating object" name=mapping-sample5 namespace=devspaces-deploy-dev type=Mapping
May 16 11:59:31 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:31Z" level=debug msg="Updating
 mapping" name=mapping-sample5 namespace=devspaces-deploy-dev type=Mapping
May 16 11:59:31 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:31Z" level=debug msg="Mapping 
update successful" name=mapping-sample5 namespace=devspaces-deploy-dev type=Mapping
May 16 11:59:31 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:31Z" level=debug msg="Getting 
mapping after update" name=mapping-sample5 namespace=devspaces-deploy-dev type=Mapping
May 16 11:59:31 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:31Z" level=info msg="Starting 
to synchronize configuration" name=mapping-sample5 namespace=devspaces-deploy-dev type=Mapping
May 16 11:59:31 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:31Z" level=debug msg="Starting
 to configure ipset" name=mapping-sample5 namespace=devspaces-deploy-dev type=Mapping
May 16 11:59:31 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:31Z" level=debug msg="Ensuring
 set Z3QBE6VKRITGDOIKP7R4FRU3 exists" name=mapping-sample5 namespace=devspaces-deploy-dev type=Mapping
May 16 11:59:31 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:31Z" level=debug msg="Ensuring
 ipset Z3QBE6VKRITGDOIKP7R4FRU3 exists"
May 16 11:59:31 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:31Z" level=debug msg="Syncing 
IPs in ipset Z3QBE6VKRITGDOIKP7R4FRU3" name=mapping-sample5 namespace=devspaces-deploy-dev type=Mapping
May 16 11:59:31 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:31Z" level=debug msg="Adding I
P 10.16.0.179 to ipset Z3QBE6VKRITGDOIKP7R4FRU3"
May 16 11:59:31 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:31Z" level=debug msg="Starting
 to configure Mark rules" name=mapping-sample5 namespace=devspaces-deploy-dev type=Mapping
May 16 11:59:31 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:31Z" level=debug msg="Checking
/creating Mark rule for ipset Z3QBE6VKRITGDOIKP7R4FRU3 and External IP 10.128.0.6" name=mapping-sample5 namespace=d
evspaces-deploy-dev type=Mapping
May 16 11:59:31 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:31Z" level=debug msg="Error ru
nning iptables-save with awk filter for table %s and chain %s: %vmangleSNM-PREROUTINGexit status 2"
May 16 11:59:31 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:31Z" level=error msg="Error se
tting up Mark: exit status 2" name=mapping-sample5 namespace=devspaces-deploy-dev type=Mapping
May 16 11:59:31 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:31Z" level=error msg="Error sy
ncing system configuration for Mapping: exit status 2" name=mapping-sample5 namespace=devspaces-deploy-dev type=Map
ping

#Below shows ipset error
May 16 11:59:32 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:32Z" level=info msg="Starting 
to synchronize configuration" name=mapping-sample5 namespace=devspaces-deploy-dev type=Mapping
May 16 11:59:32 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:32Z" level=debug msg="Starting
 to configure ipset" name=mapping-sample5 namespace=devspaces-deploy-dev type=Mapping
May 16 11:59:32 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:32Z" level=debug msg="Ensuring
 set Z3QBE6VKRITGDOIKP7R4FRU3 exists" name=mapping-sample5 namespace=devspaces-deploy-dev type=Mapping
May 16 11:59:32 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:32Z" level=debug msg="Ensuring
 ipset Z3QBE6VKRITGDOIKP7R4FRU3 exists"
May 16 11:59:32 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:32Z" level=debug msg="Syncing 
IPs in ipset Z3QBE6VKRITGDOIKP7R4FRU3" name=mapping-sample5 namespace=devspaces-deploy-dev type=Mapping
May 16 11:59:32 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:32Z" level=debug msg="Adding I
P 10.16.0.179 to ipset Z3QBE6VKRITGDOIKP7R4FRU3"
May 16 11:59:32 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:32Z" level=debug msg="Error ad
ding IP 10.16.0.179 to ipset Z3QBE6VKRITGDOIKP7R4FRU3: exit status 1, stdErr: ipset v6.30: Element cannot be added 
to the set: it's already added\n"
May 16 11:59:32 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:32Z" level=debug msg="Error ad
ding entry 10.16.0.179 to ipset Z3QBE6VKRITGDOIKP7R4FRU3"
May 16 11:59:32 aurea-dvsp-smartnat-4 smartnat-manager[2770]: time="2019-05-16T11:59:32Z" level=error msg="Error sy
ncing IPs in ipset Z3QBE6VKRITGDOIKP7R4FRU3: exit status 1" name=mapping-sample5 namespace=devspaces-deploy-dev typ

Adding info about the distro:

$> cat /etc/os-release
PRETTY_NAME="Debian GNU/Linux 9 (stretch)"
NAME="Debian GNU/Linux"
VERSION_ID="9"
VERSION="9 (stretch)"
ID=debian
HOME_URL="https://www.debian.org/"
SUPPORT_URL="https://www.debian.org/support"
BUG_REPORT_URL="https://bugs.debian.org/"