2 # -*- coding: utf-8 -*-
5 # Copyright 2018 Telefonica S.A.
7 # Licensed under the Apache License, Version 2.0 (the "License"); you may
8 # not use this file except in compliance with the License. You may obtain
9 # a copy of the License at
11 # http://www.apache.org/licenses/LICENSE-2.0
13 # Unless required by applicable law or agreed to in writing, software
14 # distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
15 # WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
16 # License for the specific language governing permissions and limitations
28 import logging
.handlers
32 from osm_lcm
import ns
33 from osm_lcm
import vim_sdn
34 from osm_lcm
import netslice
35 from osm_lcm
import ROclient
37 from time
import time
, sleep
38 from osm_lcm
.lcm_utils
import versiontuple
, LcmException
, TaskRegistry
, LcmExceptionExit
39 from osm_lcm
import version
as lcm_version
, version_date
as lcm_version_date
41 from osm_common
import dbmemory
, dbmongo
, fslocal
, msglocal
, msgkafka
42 from osm_common
import version
as common_version
43 from osm_common
.dbbase
import DbException
44 from osm_common
.fsbase
import FsException
45 from osm_common
.msgbase
import MsgException
46 from os
import environ
, path
47 from random
import choice
as random_choice
48 from n2vc
import version
as n2vc_version
50 if os
.getenv('OSMLCM_PDB_DEBUG', None) is not None:
54 __author__
= "Alfonso Tierno"
55 min_RO_version
= "6.0.2"
56 min_n2vc_version
= "0.0.2"
58 min_common_version
= "0.1.19"
59 # uncomment if LCM is installed as library and installed, and get them from __init__.py
60 # lcm_version = '0.1.41'
61 # lcm_version_date = '2019-06-19'
62 health_check_file
= path
.expanduser("~") + "/time_last_ping" # TODO find better location for this file
67 ping_interval_pace
= 120 # how many time ping is send once is confirmed all is running
68 ping_interval_boot
= 5 # how many time ping is sent when booting
70 def __init__(self
, config_file
, loop
=None):
72 Init, Connect to database, filesystem storage, and messaging
73 :param config: two level dictionary with configuration. Top level should contain 'database', 'storage',
81 self
.pings_not_received
= 1
82 self
.consecutive_errors
= 0
83 self
.first_start
= False
86 self
.logger
= logging
.getLogger('lcm')
88 self
.worker_id
= self
.get_process_id()
90 config
= self
.read_config_file(config_file
)
93 "endpoint_url": "http://{}:{}/openmano".format(config
["RO"]["host"], config
["RO"]["port"]),
94 "tenant": config
.get("tenant", "osm"),
95 "logger_name": "lcm.ROclient",
99 self
.vca_config
= config
["VCA"]
101 self
.loop
= loop
or asyncio
.get_event_loop()
104 log_format_simple
= "%(asctime)s %(levelname)s %(name)s %(filename)s:%(lineno)s %(message)s"
105 log_formatter_simple
= logging
.Formatter(log_format_simple
, datefmt
='%Y-%m-%dT%H:%M:%S')
106 config
["database"]["logger_name"] = "lcm.db"
107 config
["storage"]["logger_name"] = "lcm.fs"
108 config
["message"]["logger_name"] = "lcm.msg"
109 if config
["global"].get("logfile"):
110 file_handler
= logging
.handlers
.RotatingFileHandler(config
["global"]["logfile"],
111 maxBytes
=100e6
, backupCount
=9, delay
=0)
112 file_handler
.setFormatter(log_formatter_simple
)
113 self
.logger
.addHandler(file_handler
)
114 if not config
["global"].get("nologging"):
115 str_handler
= logging
.StreamHandler()
116 str_handler
.setFormatter(log_formatter_simple
)
117 self
.logger
.addHandler(str_handler
)
119 if config
["global"].get("loglevel"):
120 self
.logger
.setLevel(config
["global"]["loglevel"])
122 # logging other modules
123 for k1
, logname
in {"message": "lcm.msg", "database": "lcm.db", "storage": "lcm.fs"}.items():
124 config
[k1
]["logger_name"] = logname
125 logger_module
= logging
.getLogger(logname
)
126 if config
[k1
].get("logfile"):
127 file_handler
= logging
.handlers
.RotatingFileHandler(config
[k1
]["logfile"],
128 maxBytes
=100e6
, backupCount
=9, delay
=0)
129 file_handler
.setFormatter(log_formatter_simple
)
130 logger_module
.addHandler(file_handler
)
131 if config
[k1
].get("loglevel"):
132 logger_module
.setLevel(config
[k1
]["loglevel"])
133 self
.logger
.critical("starting osm/lcm version {} {}".format(lcm_version
, lcm_version_date
))
135 # check version of N2VC
136 # TODO enhance with int conversion or from distutils.version import LooseVersion
137 # or with list(map(int, version.split(".")))
138 if versiontuple(n2vc_version
) < versiontuple(min_n2vc_version
):
139 raise LcmException("Not compatible osm/N2VC version '{}'. Needed '{}' or higher".format(
140 n2vc_version
, min_n2vc_version
))
141 # check version of common
142 if versiontuple(common_version
) < versiontuple(min_common_version
):
143 raise LcmException("Not compatible osm/common version '{}'. Needed '{}' or higher".format(
144 common_version
, min_common_version
))
147 # TODO check database version
148 if config
["database"]["driver"] == "mongo":
149 self
.db
= dbmongo
.DbMongo()
150 self
.db
.db_connect(config
["database"])
151 elif config
["database"]["driver"] == "memory":
152 self
.db
= dbmemory
.DbMemory()
153 self
.db
.db_connect(config
["database"])
155 raise LcmException("Invalid configuration param '{}' at '[database]':'driver'".format(
156 config
["database"]["driver"]))
158 if config
["storage"]["driver"] == "local":
159 self
.fs
= fslocal
.FsLocal()
160 self
.fs
.fs_connect(config
["storage"])
162 raise LcmException("Invalid configuration param '{}' at '[storage]':'driver'".format(
163 config
["storage"]["driver"]))
165 # copy message configuration in order to remove 'group_id' for msg_admin
166 config_message
= config
["message"].copy()
167 config_message
["loop"] = self
.loop
168 if config_message
["driver"] == "local":
169 self
.msg
= msglocal
.MsgLocal()
170 self
.msg
.connect(config_message
)
171 self
.msg_admin
= msglocal
.MsgLocal()
172 config_message
.pop("group_id", None)
173 self
.msg_admin
.connect(config_message
)
174 elif config_message
["driver"] == "kafka":
175 self
.msg
= msgkafka
.MsgKafka()
176 self
.msg
.connect(config_message
)
177 self
.msg_admin
= msgkafka
.MsgKafka()
178 config_message
.pop("group_id", None)
179 self
.msg_admin
.connect(config_message
)
181 raise LcmException("Invalid configuration param '{}' at '[message]':'driver'".format(
182 config
["message"]["driver"]))
183 except (DbException
, FsException
, MsgException
) as e
:
184 self
.logger
.critical(str(e
), exc_info
=True)
185 raise LcmException(str(e
))
187 # contains created tasks/futures to be able to cancel
188 self
.lcm_tasks
= TaskRegistry(self
.worker_id
, self
.db
, self
.logger
)
190 self
.ns
= ns
.NsLcm(self
.db
, self
.msg
, self
.fs
, self
.lcm_tasks
, self
.ro_config
, self
.vca_config
, self
.loop
)
191 self
.netslice
= netslice
.NetsliceLcm(self
.db
, self
.msg
, self
.fs
, self
.lcm_tasks
, self
.ro_config
,
192 self
.vca_config
, self
.loop
)
193 self
.vim
= vim_sdn
.VimLcm(self
.db
, self
.msg
, self
.fs
, self
.lcm_tasks
, self
.ro_config
, self
.loop
)
194 self
.wim
= vim_sdn
.WimLcm(self
.db
, self
.msg
, self
.fs
, self
.lcm_tasks
, self
.ro_config
, self
.loop
)
195 self
.sdn
= vim_sdn
.SdnLcm(self
.db
, self
.msg
, self
.fs
, self
.lcm_tasks
, self
.ro_config
, self
.loop
)
197 async def check_RO_version(self
):
202 ro_server
= ROclient
.ROClient(self
.loop
, **self
.ro_config
)
203 ro_version
= await ro_server
.get_version()
204 if versiontuple(ro_version
) < versiontuple(min_RO_version
):
205 raise LcmException("Not compatible osm/RO version '{}'. Needed '{}' or higher".format(
206 ro_version
, min_RO_version
))
207 self
.logger
.info("Connected to RO version {}".format(ro_version
))
209 except ROclient
.ROClientException
as e
:
211 error_text
= "Error while connecting to RO on {}: {}".format(self
.ro_config
["endpoint_url"], e
)
213 self
.logger
.critical(error_text
)
214 raise LcmException(error_text
)
215 if last_error
!= error_text
:
216 last_error
= error_text
217 self
.logger
.error(error_text
+ ". Waiting until {} seconds".format(5*tries
))
218 await asyncio
.sleep(5)
220 async def test(self
, param
=None):
221 self
.logger
.debug("Starting/Ending test task: {}".format(param
))
223 async def kafka_ping(self
):
224 self
.logger
.debug("Task kafka_ping Enter")
225 consecutive_errors
= 0
227 kafka_has_received
= False
228 self
.pings_not_received
= 1
231 await self
.msg_admin
.aiowrite(
233 {"from": "lcm", "to": "lcm", "worker_id": self
.worker_id
, "version": lcm_version
},
235 # time between pings are low when it is not received and at starting
236 wait_time
= self
.ping_interval_boot
if not kafka_has_received
else self
.ping_interval_pace
237 if not self
.pings_not_received
:
238 kafka_has_received
= True
239 self
.pings_not_received
+= 1
240 await asyncio
.sleep(wait_time
, loop
=self
.loop
)
241 if self
.pings_not_received
> 10:
242 raise LcmException("It is not receiving pings from Kafka bus")
243 consecutive_errors
= 0
247 except Exception as e
:
248 # if not first_start is the first time after starting. So leave more time and wait
249 # to allow kafka starts
250 if consecutive_errors
== 8 if not first_start
else 30:
251 self
.logger
.error("Task kafka_read task exit error too many errors. Exception: {}".format(e
))
253 consecutive_errors
+= 1
254 self
.logger
.error("Task kafka_read retrying after Exception {}".format(e
))
255 wait_time
= 2 if not first_start
else 5
256 await asyncio
.sleep(wait_time
, loop
=self
.loop
)
258 def kafka_read_callback(self
, topic
, command
, params
):
261 if topic
!= "admin" and command
!= "ping":
262 self
.logger
.debug("Task kafka_read receives {} {}: {}".format(topic
, command
, params
))
263 self
.consecutive_errors
= 0
264 self
.first_start
= False
266 if command
== "exit":
267 raise LcmExceptionExit
268 elif command
.startswith("#"):
270 elif command
== "echo":
275 elif command
== "test":
276 asyncio
.Task(self
.test(params
), loop
=self
.loop
)
280 if command
== "ping" and params
["to"] == "lcm" and params
["from"] == "lcm":
281 if params
.get("worker_id") != self
.worker_id
:
283 self
.pings_not_received
= 0
285 with
open(health_check_file
, "w") as f
:
287 except Exception as e
:
288 self
.logger
.error("Cannot write into '{}' for healthcheck: {}".format(health_check_file
, e
))
291 if command
== "instantiate":
292 # self.logger.debug("Deploying NS {}".format(nsr_id))
294 nslcmop_id
= nslcmop
["_id"]
295 nsr_id
= nslcmop
["nsInstanceId"]
296 task
= asyncio
.ensure_future(self
.ns
.instantiate(nsr_id
, nslcmop_id
))
297 self
.lcm_tasks
.register("ns", nsr_id
, nslcmop_id
, "ns_instantiate", task
)
299 elif command
== "terminate":
300 # self.logger.debug("Deleting NS {}".format(nsr_id))
302 nslcmop_id
= nslcmop
["_id"]
303 nsr_id
= nslcmop
["nsInstanceId"]
304 self
.lcm_tasks
.cancel(topic
, nsr_id
)
305 task
= asyncio
.ensure_future(self
.ns
.terminate(nsr_id
, nslcmop_id
))
306 self
.lcm_tasks
.register("ns", nsr_id
, nslcmop_id
, "ns_terminate", task
)
308 elif command
== "action":
309 # self.logger.debug("Update NS {}".format(nsr_id))
311 nslcmop_id
= nslcmop
["_id"]
312 nsr_id
= nslcmop
["nsInstanceId"]
313 task
= asyncio
.ensure_future(self
.ns
.action(nsr_id
, nslcmop_id
))
314 self
.lcm_tasks
.register("ns", nsr_id
, nslcmop_id
, "ns_action", task
)
316 elif command
== "scale":
317 # self.logger.debug("Update NS {}".format(nsr_id))
319 nslcmop_id
= nslcmop
["_id"]
320 nsr_id
= nslcmop
["nsInstanceId"]
321 task
= asyncio
.ensure_future(self
.ns
.scale(nsr_id
, nslcmop_id
))
322 self
.lcm_tasks
.register("ns", nsr_id
, nslcmop_id
, "ns_scale", task
)
324 elif command
== "show":
327 db_nsr
= self
.db
.get_one("nsrs", {"_id": nsr_id
})
328 print("nsr:\n _id={}\n operational-status: {}\n config-status: {}"
329 "\n detailed-status: {}\n deploy: {}\n tasks: {}"
330 "".format(nsr_id
, db_nsr
["operational-status"], db_nsr
["config-status"],
331 db_nsr
["detailed-status"],
332 db_nsr
["_admin"]["deployed"], self
.lcm_ns_tasks
.get(nsr_id
)))
333 except Exception as e
:
334 print("nsr {} not found: {}".format(nsr_id
, e
))
337 elif command
== "deleted":
338 return # TODO cleaning of task just in case should be done
339 elif command
in ("terminated", "instantiated", "scaled", "actioned"): # "scaled-cooldown-time"
341 elif topic
== "nsi": # netslice LCM processes (instantiate, terminate, etc)
342 if command
== "instantiate":
343 # self.logger.debug("Instantiating Network Slice {}".format(nsilcmop["netsliceInstanceId"]))
345 nsilcmop_id
= nsilcmop
["_id"] # slice operation id
346 nsir_id
= nsilcmop
["netsliceInstanceId"] # slice record id
347 task
= asyncio
.ensure_future(self
.netslice
.instantiate(nsir_id
, nsilcmop_id
))
348 self
.lcm_tasks
.register("nsi", nsir_id
, nsilcmop_id
, "nsi_instantiate", task
)
350 elif command
== "terminate":
351 # self.logger.debug("Terminating Network Slice NS {}".format(nsilcmop["netsliceInstanceId"]))
353 nsilcmop_id
= nsilcmop
["_id"] # slice operation id
354 nsir_id
= nsilcmop
["netsliceInstanceId"] # slice record id
355 self
.lcm_tasks
.cancel(topic
, nsir_id
)
356 task
= asyncio
.ensure_future(self
.netslice
.terminate(nsir_id
, nsilcmop_id
))
357 self
.lcm_tasks
.register("nsi", nsir_id
, nsilcmop_id
, "nsi_terminate", task
)
359 elif command
== "show":
362 db_nsir
= self
.db
.get_one("nsirs", {"_id": nsir_id
})
363 print("nsir:\n _id={}\n operational-status: {}\n config-status: {}"
364 "\n detailed-status: {}\n deploy: {}\n tasks: {}"
365 "".format(nsir_id
, db_nsir
["operational-status"], db_nsir
["config-status"],
366 db_nsir
["detailed-status"],
367 db_nsir
["_admin"]["deployed"], self
.lcm_netslice_tasks
.get(nsir_id
)))
368 except Exception as e
:
369 print("nsir {} not found: {}".format(nsir_id
, e
))
372 elif command
== "deleted":
373 return # TODO cleaning of task just in case should be done
374 elif command
in ("terminated", "instantiated", "scaled", "actioned"): # "scaled-cooldown-time"
376 elif topic
== "vim_account":
377 vim_id
= params
["_id"]
378 if command
== "create":
379 task
= asyncio
.ensure_future(self
.vim
.create(params
, order_id
))
380 self
.lcm_tasks
.register("vim_account", vim_id
, order_id
, "vim_create", task
)
382 elif command
== "delete":
383 self
.lcm_tasks
.cancel(topic
, vim_id
)
384 task
= asyncio
.ensure_future(self
.vim
.delete(params
, order_id
))
385 self
.lcm_tasks
.register("vim_account", vim_id
, order_id
, "vim_delete", task
)
387 elif command
== "show":
388 print("not implemented show with vim_account")
391 elif command
== "edit":
392 task
= asyncio
.ensure_future(self
.vim
.edit(params
, order_id
))
393 self
.lcm_tasks
.register("vim_account", vim_id
, order_id
, "vim_edit", task
)
395 elif topic
== "wim_account":
396 wim_id
= params
["_id"]
397 if command
== "create":
398 task
= asyncio
.ensure_future(self
.wim
.create(params
, order_id
))
399 self
.lcm_tasks
.register("wim_account", wim_id
, order_id
, "wim_create", task
)
401 elif command
== "delete":
402 self
.lcm_tasks
.cancel(topic
, wim_id
)
403 task
= asyncio
.ensure_future(self
.wim
.delete(params
, order_id
))
404 self
.lcm_tasks
.register("wim_account", wim_id
, order_id
, "wim_delete", task
)
406 elif command
== "show":
407 print("not implemented show with wim_account")
410 elif command
== "edit":
411 task
= asyncio
.ensure_future(self
.wim
.edit(params
, order_id
))
412 self
.lcm_tasks
.register("wim_account", wim_id
, order_id
, "wim_edit", task
)
415 _sdn_id
= params
["_id"]
416 if command
== "create":
417 task
= asyncio
.ensure_future(self
.sdn
.create(params
, order_id
))
418 self
.lcm_tasks
.register("sdn", _sdn_id
, order_id
, "sdn_create", task
)
420 elif command
== "delete":
421 self
.lcm_tasks
.cancel(topic
, _sdn_id
)
422 task
= asyncio
.ensure_future(self
.sdn
.delete(params
, order_id
))
423 self
.lcm_tasks
.register("sdn", _sdn_id
, order_id
, "sdn_delete", task
)
425 elif command
== "edit":
426 task
= asyncio
.ensure_future(self
.sdn
.edit(params
, order_id
))
427 self
.lcm_tasks
.register("sdn", _sdn_id
, order_id
, "sdn_edit", task
)
429 self
.logger
.critical("unknown topic {} and command '{}'".format(topic
, command
))
431 async def kafka_read(self
):
432 self
.logger
.debug("Task kafka_read Enter with worker_id={}".format(self
.worker_id
))
433 # future = asyncio.Future()
434 self
.consecutive_errors
= 0
435 self
.first_start
= True
436 while self
.consecutive_errors
< 10:
438 topics
= ("ns", "vim_account", "wim_account", "sdn", "nsi")
439 topics_admin
= ("admin", )
440 await asyncio
.gather(
441 self
.msg
.aioread(topics
, self
.loop
, self
.kafka_read_callback
),
442 self
.msg_admin
.aioread(topics_admin
, self
.loop
, self
.kafka_read_callback
, group_id
=False)
445 except LcmExceptionExit
:
446 self
.logger
.debug("Bye!")
448 except Exception as e
:
449 # if not first_start is the first time after starting. So leave more time and wait
450 # to allow kafka starts
451 if self
.consecutive_errors
== 8 if not self
.first_start
else 30:
452 self
.logger
.error("Task kafka_read task exit error too many errors. Exception: {}".format(e
))
454 self
.consecutive_errors
+= 1
455 self
.logger
.error("Task kafka_read retrying after Exception {}".format(e
))
456 wait_time
= 2 if not self
.first_start
else 5
457 await asyncio
.sleep(wait_time
, loop
=self
.loop
)
459 # self.logger.debug("Task kafka_read terminating")
460 self
.logger
.debug("Task kafka_read exit")
465 self
.loop
.run_until_complete(self
.check_RO_version())
467 self
.loop
.run_until_complete(asyncio
.gather(
472 # self.logger.debug("Terminating cancelling creation tasks")
473 # self.lcm_tasks.cancel("ALL", "create")
475 # while self.is_pending_tasks():
476 # self.logger.debug("Task kafka_read terminating. Waiting for tasks termination")
477 # await asyncio.sleep(2, loop=self.loop)
480 # self.lcm_tasks.cancel("ALL", "ALL")
484 self
.db
.db_disconnect()
486 self
.msg
.disconnect()
488 self
.msg_admin
.disconnect()
490 self
.fs
.fs_disconnect()
492 def read_config_file(self
, config_file
):
493 # TODO make a [ini] + yaml inside parser
494 # the configparser library is not suitable, because it does not admit comments at the end of line,
495 # and not parse integer or boolean
497 with
open(config_file
) as f
:
499 for k
, v
in environ
.items():
500 if not k
.startswith("OSMLCM_"):
502 k_items
= k
.lower().split("_")
505 if k_items
[1] in ("ro", "vca"):
506 # put in capital letter
507 k_items
[1] = k_items
[1].upper()
510 for k_item
in k_items
[1:-1]:
512 if k_items
[-1] == "port":
513 c
[k_items
[-1]] = int(v
)
516 except Exception as e
:
517 self
.logger
.warn("skipping environ '{}' on exception '{}'".format(k
, e
))
520 except Exception as e
:
521 self
.logger
.critical("At config file '{}': {}".format(config_file
, e
))
525 def get_process_id():
527 Obtain a unique ID for this process. If running from inside docker, it will get docker ID. If not it
528 will provide a random one
531 # Try getting docker id. If fails, get pid
533 with
open("/proc/self/cgroup", "r") as f
:
534 text_id_
= f
.readline()
535 _
, _
, text_id
= text_id_
.rpartition("/")
536 text_id
= text_id
.replace('\n', '')[:12]
542 return ''.join(random_choice("0123456789abcdef") for _
in range(12))
546 print("""Usage: {} [options]
547 -c|--config [configuration_file]: loads the configuration file (default: ./lcm.cfg)
548 --health-check: do not run lcm, but inspect kafka bus to determine if lcm is healthy
549 -h|--help: shows this help
550 """.format(sys
.argv
[0]))
551 # --log-socket-host HOST: send logs to this host")
552 # --log-socket-port PORT: send logs using this port (default: 9022)")
560 with
open(health_check_file
, "r") as f
:
561 last_received_ping
= f
.read()
563 if time() - float(last_received_ping
) < Lcm
.ping_interval_pace
+ 10:
572 if __name__
== '__main__':
575 # load parameters and configuration
581 opts
, args
= getopt
.getopt(sys
.argv
[1:], "hc:", ["config=", "help", "health-check"])
582 # TODO add "log-socket-host=", "log-socket-port=", "log-file="
585 if o
in ("-h", "--help"):
588 elif o
in ("-c", "--config"):
590 elif o
== "--health-check":
592 # elif o == "--log-socket-port":
593 # log_socket_port = a
594 # elif o == "--log-socket-host":
595 # log_socket_host = a
596 # elif o == "--log-file":
599 assert False, "Unhandled option"
602 if not path
.isfile(config_file
):
603 print("configuration file '{}' does not exist".format(config_file
), file=sys
.stderr
)
606 for config_file
in (__file__
[:__file__
.rfind(".")] + ".cfg", "./lcm.cfg", "/etc/osm/lcm.cfg"):
607 if path
.isfile(config_file
):
610 print("No configuration file 'lcm.cfg' found neither at local folder nor at /etc/osm/", file=sys
.stderr
)
612 lcm
= Lcm(config_file
)
614 except (LcmException
, getopt
.GetoptError
) as e
:
615 print(str(e
), file=sys
.stderr
)