starlingx/config
Code Issues Proposed changes

Add log messages to IPSec Auth Server and Client

Browse Source 
This commit adds log messages to the IPSec Auth server
and client following the requirements bellow:

- Debug, info and error log levels should be present in client code.
- Log should include level indicator after date and time stamp
- Default log level is info
- Logs should be present in a log file at /var/log directory

Test Plan:
PASS: In a DX controller-0 acting as IPsec Auth server and a
      worker-0 acting as IPsec Auth client, execute the command
      'sudo ipsec-client pxecontroller' and see the log messages
      generated in the screen and in the file /var/log/ipsec-auth.log

Story: 2010940
Task: 49464

Co-Authored-By: Manoel Benedito Neto <manoel.beneditoneto@windriver.com>

Change-Id: Icbdc299022c19e0c1513e0fcb9429494b3a87d04
Signed-off-by: Leonardo Mendes <Leonardo.MendesSantana@windriver.com>
This commit is contained in:
Leonardo Mendes 2024-01-19 18:02:20 -03:00
parent fcf284bd5b
commit 6832b04298
11 changed files with 186 additions and 75 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

2
sysinv/ipsec-auth/debian/deb_folder/ipsec-auth.dirs
View File

@ -1 +1,3 @@
lib/systemd/system
etc/syslog-ng/conf.d
etc/logrotate.d

2
sysinv/ipsec-auth/debian/deb_folder/ipsec-auth.install
View File

@ -1 +1,3 @@
lib/systemd/system/ipsec-server.service
etc/syslog-ng/conf.d/ipsec-auth.conf
etc/logrotate.d/ipsec-auth.conf

2
sysinv/ipsec-auth/debian/deb_folder/rules
View File

@ -5,6 +5,8 @@ ROOT := $(CURDIR)/debian/tmp
dh $@
override_dh_install:
install -m 644 -p -D ipsec-server.service ${ROOT}/lib/systemd/system/ipsec-server.service
install -m 644 -p -D ipsec-auth.syslog ${ROOT}/etc/syslog-ng/conf.d/ipsec-auth.conf
install -m 644 -p -D ipsec-auth.logrotate ${ROOT}/etc/logrotate.d/ipsec-auth.conf
dh_install
override_dh_installsystemd:
dh_installsystemd --no-enable ipsec-server.service

14
sysinv/ipsec-auth/files/ipsec-auth.logrotate Normal file
View File

@ -0,0 +1,14 @@
/var/log/ipsec-auth.log
{
nodateext
size 10M
start 1
rotate 20
missingok
notifempty
compress
sharedscripts
postrotate
systemctl reload syslog-ng > /dev/null 2>&1 || true
endscript
}

12
sysinv/ipsec-auth/files/ipsec-auth.syslog Normal file
View File

@ -0,0 +1,12 @@
template t_auth {
template("${R_YEAR}-${R_MONTH}-${R_DAY}T${R_HOUR}:${R_MIN}:${R_SEC}.${R_MSEC} ${MSG}\n");
template-escape(no);
};
filter f_ipsecclient { facility(local6) and program(ipsec-client); };
filter f_ipsecserver { facility(local6) and program(ipsec-server); };
destination d_ipsecauth { file("/var/log/ipsec-auth.log" template(t_auth));};
log { source(s_src); filter(f_ipsecclient); destination(d_ipsecauth); };
log { source(s_src); filter(f_ipsecserver); destination(d_ipsecauth); };

19
sysinv/sysinv/sysinv/sysinv/cmd/ipsec_client.py
View File

@ -8,9 +8,14 @@ import os
import sys
import textwrap
from oslo_config import cfg
from oslo_log import log as logging
from sysinv.ipsec_auth.client.client import Client
from sysinv.ipsec_auth.common import constants
LOG = logging.getLogger(__name__)
CONF = cfg.CONF
def main():
if not os.geteuid() == 0:
@ -37,6 +42,9 @@ def main():
help="IPsec Auth Server's host address")
parser.add_argument("-p", "--port", metavar='<port>', type=int,
help='Port number (Default: ' + str(port) + ')')
parser.add_argument('-d', "--debug", action="store_true",
help="If enabled, the logging level will be set "
"to DEBUG instead of the default INFO level.")
parser.add_argument("-o", "--opcode", metavar='<opcode>',
type=int, choices=[1, 2, 3],
help='Operational code (Default: ' + str(opcode) + ')')
@ -50,6 +58,17 @@ def main():
if args.opcode:
opcode = args.opcode
logging.register_options(CONF)
logging.set_defaults()
CONF.set_default("use_syslog", True)
CONF.set_default("syslog_log_facility", "local6")
if args.debug:
CONF.set_default("debug", True)
logging.setup(CONF, 'ipsec-client')
if not os.path.exists(constants.TMP_DIR_IPSEC_KEYS):
os.makedirs(constants.TMP_DIR_IPSEC_KEYS)

19
sysinv/sysinv/sysinv/sysinv/cmd/ipsec_server.py
View File

@ -8,9 +8,14 @@ import os
import sys
import textwrap
from oslo_config import cfg
from oslo_log import log as logging
from sysinv.ipsec_auth.common import constants
from sysinv.ipsec_auth.server.server import IPsecServer
LOG = logging.getLogger(__name__)
CONF = cfg.CONF
def main():
if not os.geteuid() == 0:
@ -35,10 +40,24 @@ def main():
parser.add_argument("-p", "--port", metavar='<port>', type=int,
help='Port number (Default: ' + str(port) + ')')
parser.add_argument('-d', "--debug", action="store_true",
help="If enabled, the logging level will be set "
"to DEBUG instead of the default INFO level.")
args = parser.parse_args()
if args.port:
port = args.port
logging.register_options(CONF)
logging.set_defaults()
CONF.set_default("use_syslog", True)
CONF.set_default("syslog_log_facility", "local6")
if args.debug:
CONF.set_default("debug", True)
logging.setup(CONF, 'ipsec-server')
server = IPsecServer(port)
server.run()

50
sysinv/sysinv/sysinv/sysinv/ipsec_auth/client/client.py
View File

@ -17,11 +17,15 @@ from cryptography.hazmat.primitives import hashes
from cryptography.hazmat.primitives import serialization
from cryptography.x509.oid import NameOID
from oslo_log import log as logging
from sysinv.ipsec_auth.client import config
from sysinv.ipsec_auth.common.constants import State
from sysinv.ipsec_auth.common import constants
from sysinv.ipsec_auth.common import utils
LOG = logging.getLogger(__name__)
class Client(object):
@ -96,23 +100,23 @@ class Client(object):
puk1_data = utils.load_data(constants.TMP_PUK1_FILE)
puc_data = utils.load_data(constants.TRUSTED_CA_CERT_PATH)
print(" Generate PRK2.")
LOG.info("Generate RSA Private Key (PRK2).")
prk2 = self._generate_prk2()
print(" Generate AK1.")
LOG.info("Generate AES Key (AK1).")
ak1 = self._generate_ak1(puk1_data)
print(" Generate CSR.")
LOG.info("Generate Certificate Request (CSR).")
csr = self._create_csr(prk2)
print(" Encrypt CSR w/ AK1.")
LOG.info("Encrypt CSR w/ AK1.")
iv, ecsr = utils.symmetric_encrypt_data(csr, ak1)
print(" Encrypt AK1 and IV w/ PUK1")
LOG.info("Encrypt AK1 and IV w/ PUK1")
eak1 = utils.asymmetric_encrypt_data(puk1_data, ak1)
eiv = utils.asymmetric_encrypt_data(puk1_data, iv)
print(" Hash OTS Token, eAK1 and eCSR.")
LOG.info("Hash OTS Token, eAK1 and eCSR.")
hash_algorithm = hashes.SHA256()
hasher = hashes.Hash(hash_algorithm)
hasher.update(bytes(self.ots_token, 'utf-8'))
@ -132,10 +136,11 @@ class Client(object):
def _handle_rcvd_data(self, data):
print(' received {!r}'.format(data))
LOG.debug("Received {!r})".format(data))
msg = json.loads(data.decode('utf-8'))
if self.state == State.STAGE_2:
LOG.info("Received IPSec Auth Response")
self.ots_token = msg['token']
self.hostname = msg['hostname']
key = base64.b64decode(msg['pub_key'])
@ -145,12 +150,14 @@ class Client(object):
data = bytes.fromhex(self.ots_token) + msg['pub_key'].encode('utf-8')
if not utils.verify_signed_hash(ca_cert, digest, data):
msg = "Hash validation failed"
raise Exception(msg)
LOG.exception("%s" % msg)
return False
utils.save_data(constants.TMP_PUK1_FILE, key)
utils.save_data(constants.TRUSTED_CA_CERT_PATH, ca_cert)
if self.state == State.STAGE_4:
LOG.info("Received IPSec Auth CSR Response")
cert = base64.b64decode(msg['cert'])
network = msg['network']
digest = base64.b64decode(msg['hash'])
@ -160,7 +167,8 @@ class Client(object):
data = msg['cert'].encode('utf-8') + network.encode('utf-8')
if not utils.verify_signed_hash(ca_cert, digest, data):
msg = "Hash validation failed"
raise Exception(msg)
LOG.exception("Hash validation failed")
return False
cert_file = constants.CERT_NAME_PREFIX + \
self.hostname[constants.UNIT_HOSTNAME] + '.crt'
@ -174,7 +182,7 @@ class Client(object):
else:
self.local_addr = utils.get_ip_addr(self.ifname)
print(" Generating config files and restart ipsec")
LOG.info("Generating config files and restart ipsec")
strong = config.StrongswanPuppet(self.hostname[constants.UNIT_HOSTNAME],
self.local_addr, network)
strong.generate_file()
@ -183,21 +191,26 @@ class Client(object):
if puppet_cf.stderr:
err = "Error: %s" % (puppet_cf.stderr.decode("utf-8"))
msg = "Failed to create strongswan config files: %s" % err
raise Exception(msg)
LOG.exception("Failed to create strongswan config files: %s" % err)
return False
return True
def _handle_send_data(self, data):
payload = None
if self.state == State.STAGE_1:
payload = self._generate_message_1()
print(' sending {!r}'.format(payload))
LOG.info("Sending IPSec Auth Request")
elif self.state == State.STAGE_3:
payload = self._generate_message_3()
print(' sending {!r}'.format(payload))
LOG.info("Sending IPSec Auth CSR Request")
LOG.debug("Sending {!r})".format(payload))
return payload
def run(self):
print('connecting to {} port {}'.format(*(self.host, self.port)))
LOG.info("Connecting to %s port %s" % (self.host, self.port))
sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
sock.connect((self.host, self.port))
sock.setblocking(False)
@ -215,11 +228,12 @@ class Client(object):
while keep_running:
for key, mask in sel.select(timeout=1):
connection = key.fileobj
print(f'{self.state}')
LOG.debug("State{}".format(self.state))
if mask & selectors.EVENT_READ:
self.data = connection.recv(8192)
self._handle_rcvd_data(self.data)
if not self._handle_rcvd_data(self.data):
raise ConnectionAbortedError("Error receiving data from server")
sel.modify(sock, selectors.EVENT_WRITE)
self.state = utils.get_next_state(self.state)
@ -232,7 +246,7 @@ class Client(object):
if self.state == State.STAGE_5:
keep_running = False
print('shutting down')
LOG.info("Shutting down")
sel.unregister(connection)
connection.close()
sel.close()

2
sysinv/sysinv/sysinv/sysinv/ipsec_auth/client/config.py
View File

@ -178,5 +178,5 @@ class StrongswanPuppet(object):
with open(filepath, 'w') as f:
yaml.dump(config, f, sort_keys=False, default_flow_style=False)
except Exception:
LOG.exception("failed to write config file: %s" % filepath)
LOG.exception("Failed to write config file: %s" % filepath)
raise

42
sysinv/sysinv/sysinv/sysinv/ipsec_auth/common/utils.py
View File

@ -31,6 +31,10 @@ from cryptography.hazmat.primitives.ciphers import Cipher
from cryptography.hazmat.primitives.ciphers import algorithms
from cryptography.hazmat.primitives.ciphers import modes
from oslo_log import log as logging
LOG = logging.getLogger(__name__)
def get_next_state(state):
'''Get the next IPsec Auth state whenever a Stage is finished.
@ -98,18 +102,22 @@ def get_management_interface():
def get_ip_addr(ifname):
s = socket.socket(socket.AF_INET, socket.SOCK_DGRAM)
ifstruct = struct.pack('256s', bytes(ifname[:15], 'utf-8'))
info = fcntl.ioctl(s.fileno(), constants.SIOCGIFADDR, ifstruct)
return socket.inet_ntoa(info[20:24])
try:
ifstruct = struct.pack('256s', bytes(ifname[:15], 'utf-8'))
info = fcntl.ioctl(s.fileno(), constants.SIOCGIFADDR, ifstruct)
return socket.inet_ntoa(info[20:24])
except Exception as e:
LOG.exception("Error getting ip address: %s" % (e))
def get_hw_addr(ifname):
s = socket.socket(socket.AF_INET, socket.SOCK_DGRAM)
ifstruct = struct.pack('256s', bytes(ifname[:15], 'utf-8'))
info = fcntl.ioctl(s.fileno(), constants.SIOCGIFHWADDR, ifstruct)
return ':'.join('%02x' % b for b in info[18:24])
try:
ifstruct = struct.pack('256s', bytes(ifname[:15], 'utf-8'))
info = fcntl.ioctl(s.fileno(), constants.SIOCGIFHWADDR, ifstruct)
return ':'.join('%02x' % b for b in info[18:24])
except Exception as e:
LOG.exception("Error getting mac address: %s" % (e))
def get_client_hostname_and_mgmt_subnet(mac_addr):
@ -302,7 +310,7 @@ def kube_apply_certificate_request(body):
# Delete the CertificateRequest if it is already created or check for possible errors
if name in str(get_cr.stdout):
print(f' deleting previously created {name} CertificateRequest.')
LOG.debug('Deleting previously created %s CertificateRequest.' % name)
cmd_delete = ['kubectl', '--kubeconfig', KUBERNETES_ADMIN_CONF,
'-n', constants.NAMESPACE_DEPLOYMENT, 'delete',
constants.CERTIFICATE_REQUEST_RESOURCE, name]
@ -310,8 +318,8 @@ def kube_apply_certificate_request(body):
check=False)
elif get_cr.stderr and 'NotFound' not in str(get_cr.stderr):
err = "Error: %s" % (get_cr.stderr.decode("utf-8"))
msg = "Failed to retrieve CertificateRequest resource info. %s" % (err)
raise Exception(msg)
LOG.exception("Failed to retrieve CertificateRequest resource info. %s" % (err))
return
# Create CertificateRequest resource in kubernetes
cr_body = yaml.safe_dump(body, default_flow_style=False)
@ -323,9 +331,9 @@ def kube_apply_certificate_request(body):
if create_cr.stderr:
err = "Error: %s" % (create_cr.stderr.decode("utf-8"))
msg = "Failed to create CertificateRequest %s/%s. %s" \
% (constants.NAMESPACE_DEPLOYMENT, name, err)
raise Exception(msg)
LOG.exception("Failed to create CertificateRequest %s/%s. %s"
% (constants.NAMESPACE_DEPLOYMENT, name, err))
return
# Get Certificate from recently created resource in kubernetes
cmd_get_certificate = ['-o', "jsonpath='{.status.certificate}'"]
@ -336,8 +344,8 @@ def kube_apply_certificate_request(body):
if signed_cert.stderr:
err = "Error: %s" % (signed_cert.stderr.decode("utf-8"))
msg = "Failed to retrieve %s/%s's Certificate. %s" \
% (constants.NAMESPACE_DEPLOYMENT, name, err)
raise Exception(msg)
LOG.exception("Failed to retrieve %s/%s's Certificate. %s"
% (constants.NAMESPACE_DEPLOYMENT, name, err))
return
return signed_cert.stdout.decode("utf-8").strip("'")

97
sysinv/sysinv/sysinv/sysinv/ipsec_auth/server/server.py
View File

@ -9,6 +9,8 @@ import os
import selectors
import socket
from oslo_log import log as logging
from sysinv.common import kubernetes
from sysinv.common import rest_api
from sysinv.ipsec_auth.common import constants
@ -19,6 +21,8 @@ from cryptography.hazmat.backends import default_backend
from cryptography.hazmat.primitives import serialization
from cryptography.hazmat.primitives.asymmetric import rsa
LOG = logging.getLogger(__name__)
class IPsecServer(object):
@ -30,18 +34,20 @@ class IPsecServer(object):
def run(self):
'''Start accepting connections in TCP server'''
self._create_pid_file()
ssocket = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
ssocket.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
ssocket.setblocking(False)
ssocket.bind(constants.TCP_SERVER)
ssocket.listen()
self.sel.register(ssocket, selectors.EVENT_READ, None)
try:
ssocket = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
ssocket.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
ssocket.setblocking(False)
ssocket.bind(constants.TCP_SERVER)
ssocket.listen()
self._create_pid_file()
LOG.info("---- IPSec Auth Server started ----")
self.sel.register(ssocket, selectors.EVENT_READ, None)
while self.keep_running:
print("waiting for connection...")
for key, _ in self.sel.select(timeout=1):
if key.data is None:
self._accept(key.fileobj)
@ -50,16 +56,18 @@ class IPsecServer(object):
connection = key.data
connection.handle_messaging(sock, self.sel)
except KeyboardInterrupt:
print('Server interrupted.')
finally:
print('Shutting down.')
self.sel.close()
LOG.exception('Server interrupted')
except OSError:
LOG.exception('System Error')
except Exception:
LOG.exception('An unknown exception occurred')
self.sel.close()
def _accept(self, sock):
'''Callback for new connections'''
connection, addr = sock.accept()
connection.setblocking(False)
print(f'accept({addr})')
LOG.info("Accept: {}".format(addr))
events = selectors.EVENT_READ
self.sel.register(connection, events, IPsecConnection())
@ -71,7 +79,7 @@ class IPsecServer(object):
with open(pidfile, 'w') as f:
f.write(pid)
print(f"PID file created: {pidfile}")
LOG.debug("PID file created: %s" % pidfile)
class IPsecConnection(object):
@ -96,28 +104,24 @@ class IPsecConnection(object):
try:
client_address = sock.getpeername()
data = sock.recv(4096)
print(' state: %s' % (self.state))
print(f' read({client_address})')
LOG.debug("Read({})".format(client_address))
if data:
# A readable client socket has data
print(' received {!r}'.format(data))
LOG.debug("Received {!r}".format(data))
self.state = utils.get_next_state(self.state)
print(' changing to state: %s' % (self.state))
print(' preparing payload')
LOG.debug("Preparing payload")
msg = self._handle_write(data)
print(' sending payload')
sock.sendall(msg)
self.state = utils.get_next_state(self.state)
print(' changing to state: %s' % (self.state))
elif self.state == State.STAGE_5 or not data:
# Interpret empty result as closed connection
print(f' closing connection with {client_address}')
LOG.info("Closing connection with {}".format(client_address))
sock.close()
sel.unregister(sock)
except Exception as e:
# Interpret empty result as closed connection
print(' %s' % (e))
print(' closing.')
LOG.exception("%s" % (e))
LOG.error("Closing. {}".format(sock.getpeername()))
sock.close()
sel.unregister(sock)
@ -128,11 +132,15 @@ class IPsecConnection(object):
data = json.loads(recv_message.decode('utf-8'))
payload = {}
if not self.ca_key or not self.ca_crt:
raise ValueError('Failed to retrieve system-local-ca information')
if self.state == State.STAGE_2:
LOG.info("Received IPSec Auth request")
if not self._validate_client_connection(data):
msg = "Connection refused with client due to invalid info " \
"received in payload."
raise ConnectionAbortedError(msg)
raise ConnectionRefusedError(msg)
mac_addr = data["mac_addr"]
client_data = utils.get_client_hostname_and_mgmt_subnet(mac_addr)
@ -150,7 +158,10 @@ class IPsecConnection(object):
payload["ca_cert"] = self.ca_crt.decode("utf-8")
payload["hash"] = hash_payload.decode("utf-8")
LOG.info("Sending IPSec Auth Response")
if self.state == State.STAGE_4:
LOG.info("Received IPSec Auth CSR request")
eiv = base64.b64decode(data["eiv"])
eak1 = base64.b64decode(data['eak1'])
ecsr = base64.b64decode(data['ecsr'])
@ -162,10 +173,13 @@ class IPsecConnection(object):
if not utils.verify_encrypted_hash(self.ca_key, ehash,
self.ots_token, eak1, ecsr):
msg = "Hash validation failed."
raise ConnectionAbortedError(msg)
raise ValueError('Hash validation failed.')
self.signed_cert = self._sign_cert_request(cert_request)
if not self.signed_cert:
raise ValueError('Unable to sign certificate request')
cert = bytes(self.signed_cert, 'utf-8')
network = bytes(self.mgmt_subnet, 'utf-8')
hash_payload = utils.hash_and_sign_payload(self.ca_key, cert + network)
@ -174,14 +188,17 @@ class IPsecConnection(object):
payload["network"] = self.mgmt_subnet
payload["hash"] = hash_payload.decode("utf-8")
LOG.info("Sending IPSec Auth CSR Response")
payload = json.dumps(payload)
print(f" payload: {payload}")
LOG.debug("Payload: %s" % payload)
except AttributeError as e:
raise Exception('Failed to read attribute from payload. Error: %s' % e)
except ConnectionAbortedError as e:
except ConnectionRefusedError as e:
raise Exception('IPsec Server stage failed. Error: %s' % e)
except ValueError as e:
raise Exception('Failed to decode message. Error: %s' % e)
raise Exception('Failed to decode message or inappropriate '
'argument value. Error: %s' % e)
except TypeError as e:
raise Exception('Failed to read values from payload. '
'Values of attributes must be str. Error: %s' % e)
@ -194,19 +211,19 @@ class IPsecConnection(object):
hashed_item = message.pop('hash')
hashed_payload = utils.hash_payload(message)
if hashed_item != hashed_payload:
print(' Inconsistent hash of payload.')
LOG.error("Inconsistent hash of payload.")
return False
op_code = int(message["op"])
if op_code not in constants.SUPPORTED_OP_CODES:
print(' Operation not supported.')
LOG.error("Operation not supported.")
return False
token = rest_api.get_token(constants.REGION_NAME)
sysinv_ihost_url = constants.PXECONTROLLER_URL + '/v1/ihosts/'
hosts_info = rest_api.rest_api_request(token, 'GET', sysinv_ihost_url)
if not hosts_info:
print(' Failed to retrieve hosts list.')
LOG.error("Failed to retrieve hosts list.")
return False
uuid = None
@ -225,7 +242,7 @@ class IPsecConnection(object):
op_code == constants.OP_CODE_INITIAL_AUTH and inv_state != '' or \
op_code == constants.OP_CODE_CERT_RENEWAL and \
inv_state != constants.INV_STATE_INVENTORIED:
print(' Invalid host information.')
LOG.error("Invalid host information.")
return False
if op_code == constants.OP_CODE_INITIAL_AUTH and inv_state == '':
@ -239,7 +256,7 @@ class IPsecConnection(object):
if not rest_api.rest_api_request(token, "POST", api_cmd,
api_cmd_headers=api_cmd_headers,
api_cmd_payload=api_cmd_payload):
print(' Failed to update host inventory state.')
LOG.error("Failed to update host inventory state.")
return False
return True
@ -264,11 +281,13 @@ class IPsecConnection(object):
secret = self.kubeapi.kube_get_secret(constants.SECRET_SYSTEM_LOCAL_CA,
constants.NAMESPACE_CERT_MANAGER)
if not secret:
raise Exception("TLS secret is unreachable.")
LOG.error("TLS secret is unreachable.")
return
data = bytes(secret.data.get(attr, None), "utf-8")
if not data:
raise Exception(f"Failed to retrieve system-local-ca's {attr} info.")
LOG.error("Failed to retrieve %s info." % attr)
return
if attr == self.CA_KEY:
data = base64.b64decode(data)