2019-01-28 18:15:54 +01:00
|
|
|
# -*- coding: utf-8 -*-
|
|
|
|
|
|
|
|
"""Daemon for local execution of commands."""
|
|
|
|
|
|
|
|
import functools
|
|
|
|
import json
|
|
|
|
import lockfile
|
|
|
|
import logging
|
|
|
|
import logging.handlers
|
|
|
|
import os
|
2019-02-05 09:07:03 +01:00
|
|
|
import queue
|
2019-01-28 18:15:54 +01:00
|
|
|
import signal
|
2019-02-05 15:10:45 +01:00
|
|
|
import sys
|
2019-02-05 09:07:03 +01:00
|
|
|
import threading
|
2019-01-28 18:15:54 +01:00
|
|
|
import typing as T
|
|
|
|
|
|
|
|
from bot_z.bot_z import Operator
|
2019-02-05 09:07:03 +01:00
|
|
|
from bot_z.utils import Fifo, PLifo, cmd_marshal, cmd_unmarshal
|
2019-01-28 18:15:54 +01:00
|
|
|
import daemon
|
|
|
|
from selenium.webdriver.common.keys import Keys
|
|
|
|
|
|
|
|
|
2019-02-05 15:10:45 +01:00
|
|
|
daemon_format = logging.Formatter("%(levelname)s: [%(name)s] -> %(message)s")
|
|
|
|
|
|
|
|
console = logging.StreamHandler(stream=sys.stdout)
|
|
|
|
console.setFormatter(daemon_format)
|
|
|
|
console.addFilter(logging.Filter(__name__))
|
2019-01-28 18:15:54 +01:00
|
|
|
|
2019-01-28 22:25:55 +01:00
|
|
|
syslog = logging.handlers.SysLogHandler(address="/dev/log")
|
2019-02-05 15:10:45 +01:00
|
|
|
syslog.setFormatter(daemon_format)
|
2019-01-28 18:15:54 +01:00
|
|
|
|
|
|
|
logger = logging.getLogger(__name__)
|
2019-01-28 22:25:55 +01:00
|
|
|
logger.setLevel(os.environ.get("BOTZ_LOGLEVEL", logging.INFO))
|
2019-02-05 15:10:45 +01:00
|
|
|
logger.addHandler(console)
|
2019-01-28 18:15:54 +01:00
|
|
|
logger.addHandler(syslog)
|
|
|
|
logger.debug("Init at debug")
|
|
|
|
|
|
|
|
|
2019-02-05 15:11:31 +01:00
|
|
|
class StopDaemon(Exception):
|
|
|
|
"""Auxiliary exception to help stop the program in daemon mode."""
|
|
|
|
|
|
|
|
pass
|
|
|
|
|
|
|
|
|
2019-01-28 18:15:54 +01:00
|
|
|
def start_daemon(
|
|
|
|
name: str,
|
2019-02-05 09:07:03 +01:00
|
|
|
base_uri: str,
|
2019-01-28 18:15:54 +01:00
|
|
|
timeout: int = None,
|
|
|
|
proxy: T.Optional[T.Tuple[str, int]] = None,
|
|
|
|
headless: bool = True,
|
|
|
|
debug: bool = False,
|
|
|
|
) -> Operator:
|
|
|
|
"""
|
|
|
|
Spawns the Operator object.
|
|
|
|
"""
|
2019-02-05 09:07:03 +01:00
|
|
|
optional_args: T.Dict[str, T.Any] = {}
|
2019-01-28 18:15:54 +01:00
|
|
|
if timeout is not None:
|
|
|
|
optional_args["timeout"] = timeout
|
|
|
|
if proxy is not None:
|
|
|
|
optional_args["proxy"] = proxy
|
|
|
|
optional_args["headless"] = headless
|
|
|
|
optional_args["debug"] = debug
|
|
|
|
logger.info("Started Operator.")
|
|
|
|
logger.debug(
|
|
|
|
"Operator parameters: "
|
|
|
|
"{base_uri: %s, name: %s, timeout: %s, proxy: %s, headless: %s, debug: %s}",
|
|
|
|
base_uri,
|
|
|
|
name,
|
|
|
|
timeout,
|
|
|
|
proxy,
|
|
|
|
headless,
|
|
|
|
debug,
|
|
|
|
)
|
|
|
|
return Operator(base_uri=base_uri, name=name, **optional_args)
|
|
|
|
|
|
|
|
|
2019-02-05 09:07:03 +01:00
|
|
|
def operator_drop(op: Operator) -> None:
|
2019-01-28 18:15:54 +01:00
|
|
|
"""
|
|
|
|
Stops the Operator.
|
|
|
|
"""
|
|
|
|
logger.debug("Stopping Operator...")
|
|
|
|
logger.debug("Operator id: %s", id(op))
|
|
|
|
op.quit()
|
|
|
|
logger.info("Stopped Operator.")
|
|
|
|
|
|
|
|
|
2019-02-05 09:07:03 +01:00
|
|
|
def operator_reload(op: Operator) -> None:
|
2019-01-28 18:15:54 +01:00
|
|
|
"""
|
|
|
|
Reload the Operator using the same object.
|
|
|
|
"""
|
|
|
|
op_focus = op.switch_to.active_element
|
|
|
|
op_focus.send_keys(Keys.CONTROL + "Escape")
|
|
|
|
op.delete_all_cookies()
|
|
|
|
logger.info("Operator session cleaned.")
|
|
|
|
|
|
|
|
|
|
|
|
def operator_status(op: Operator, debug: bool = False) -> T.Dict[str, str]:
|
|
|
|
"""
|
|
|
|
Get the current operator status.
|
|
|
|
"""
|
|
|
|
status = {} # type: T.Dict[str, str]
|
|
|
|
status["is_logged_in"] = str(op.logged_in)
|
|
|
|
status["is_checked_in"] = str(op.checked_in)
|
|
|
|
if debug:
|
|
|
|
status["interal_state"] = str(dir(op))
|
|
|
|
logger.info("Status: %s", status)
|
|
|
|
|
|
|
|
return status
|
|
|
|
|
|
|
|
|
2019-02-05 09:07:03 +01:00
|
|
|
def operator_login(op: Operator, username: str, password: str, force: bool) -> None:
|
|
|
|
"""
|
|
|
|
Instructs the operator to perform login.
|
|
|
|
"""
|
2019-02-20 18:11:08 +01:00
|
|
|
logger.debug("Performing login...")
|
2019-02-05 09:07:03 +01:00
|
|
|
op.login(username, password, force)
|
|
|
|
logger.info("Login done.")
|
|
|
|
|
|
|
|
|
2019-02-07 12:02:42 +01:00
|
|
|
def operator_logout(op: Operator, force: bool) -> None:
|
2019-02-05 09:07:03 +01:00
|
|
|
"""
|
|
|
|
Instructs the operator to perform logout.
|
|
|
|
"""
|
2019-02-20 18:11:08 +01:00
|
|
|
logger.debug("Performing logout...")
|
2019-02-07 12:02:42 +01:00
|
|
|
op.logout(force)
|
2019-02-05 09:07:03 +01:00
|
|
|
logger.info("Logout done.")
|
|
|
|
|
|
|
|
|
2019-02-18 12:20:55 +01:00
|
|
|
def operator_checkin(op: Operator, force: bool) -> None:
|
|
|
|
"""
|
|
|
|
Instructs the operator to perform the check in.
|
|
|
|
"""
|
|
|
|
logger.debug("Performing check in...")
|
2019-02-20 18:11:08 +01:00
|
|
|
op.check_in(force)
|
2019-02-18 12:20:55 +01:00
|
|
|
logger.info("Check in done.")
|
|
|
|
|
|
|
|
|
|
|
|
def operator_checkout(op: Operator, force: bool) -> None:
|
|
|
|
"""
|
|
|
|
Instructs the operator to perform the check out.
|
|
|
|
"""
|
|
|
|
logger.debug("Performing check out...")
|
2019-02-20 18:11:08 +01:00
|
|
|
op.check_out(force)
|
2019-02-18 12:20:55 +01:00
|
|
|
logger.info("Check out done.")
|
|
|
|
|
|
|
|
|
2019-01-28 18:15:54 +01:00
|
|
|
def daemon_process(
|
|
|
|
fifo_path: str,
|
|
|
|
working_dir: str,
|
|
|
|
umask: int,
|
|
|
|
pidfile: lockfile.FileLock,
|
|
|
|
base_uri: str,
|
|
|
|
timeout: int = None,
|
|
|
|
proxy: T.Optional[T.Tuple[str, int]] = None,
|
|
|
|
headless: bool = True,
|
|
|
|
debug: bool = False,
|
|
|
|
foreground: bool = False,
|
|
|
|
) -> None:
|
|
|
|
"""
|
|
|
|
The daemon function.
|
|
|
|
"""
|
2019-02-05 15:11:31 +01:00
|
|
|
if debug:
|
|
|
|
logger.setLevel(logging.DEBUG)
|
2019-02-05 09:07:03 +01:00
|
|
|
lifo_path = os.path.join(working_dir, "botz_open_daemons.list")
|
2019-02-05 15:11:31 +01:00
|
|
|
if os.path.exists(lifo_path):
|
|
|
|
logger.warning("Lifo (%s) exists. Removing!", lifo_path)
|
|
|
|
os.remove(lifo_path)
|
2019-02-05 09:07:03 +01:00
|
|
|
|
|
|
|
starter = functools.partial(
|
|
|
|
start_daemon,
|
|
|
|
base_uri=base_uri,
|
|
|
|
timeout=timeout,
|
|
|
|
proxy=proxy,
|
|
|
|
headless=headless,
|
|
|
|
debug=debug,
|
|
|
|
)
|
|
|
|
|
2019-02-20 18:11:08 +01:00
|
|
|
def _stop_all() -> None:
|
|
|
|
logger.debug("SIGTERM...stopping all the clients...")
|
|
|
|
clients = PLifo.All(lifo_path)
|
|
|
|
with Fifo(fifo_path) as fifo:
|
|
|
|
for client in clients:
|
|
|
|
fifo.write(cmd_marshal(name=client, cmd="stop"))
|
|
|
|
|
|
|
|
def _reload_all() -> None:
|
|
|
|
logger.debug("SIGUSR1 received here.")
|
|
|
|
clients = PLifo.All(lifo_path)
|
|
|
|
with Fifo(fifo_path) as fifo:
|
|
|
|
for client in clients:
|
|
|
|
fifo.write(cmd_marshal(name=client, cmd="reload"))
|
|
|
|
|
|
|
|
def _list_all() -> None:
|
|
|
|
logger.debug("SIGUSR2 received here.")
|
|
|
|
clients = PLifo.All(lifo_path)
|
|
|
|
logger.info("Client list: %s", clients)
|
2019-02-05 09:07:03 +01:00
|
|
|
|
2019-01-28 18:15:54 +01:00
|
|
|
context = daemon.DaemonContext(
|
|
|
|
working_directory=working_dir, umask=umask, pidfile=pidfile
|
|
|
|
)
|
2019-02-05 09:07:03 +01:00
|
|
|
logger.debug("context defined")
|
2019-01-28 18:15:54 +01:00
|
|
|
context.signal_map = {
|
2019-02-20 18:11:08 +01:00
|
|
|
signal.SIGTERM: _stop_all,
|
2019-01-28 18:15:54 +01:00
|
|
|
signal.SIGHUP: "terminate",
|
2019-02-20 18:11:08 +01:00
|
|
|
signal.SIGUSR1: _reload_all,
|
|
|
|
signal.SIGUSR2: _list_all,
|
2019-02-05 09:07:03 +01:00
|
|
|
}
|
|
|
|
logger.debug("signal map defined")
|
|
|
|
cmd_map = {
|
|
|
|
"start": starter,
|
|
|
|
"stop": operator_drop,
|
|
|
|
"reload": operator_reload,
|
|
|
|
"status": operator_status,
|
|
|
|
"login": operator_login,
|
|
|
|
"logout": operator_logout,
|
2019-02-18 12:20:55 +01:00
|
|
|
"checkin": operator_checkin,
|
|
|
|
"checkout": operator_checkout,
|
2019-01-28 18:15:54 +01:00
|
|
|
}
|
2019-02-05 09:07:03 +01:00
|
|
|
logger.debug("command map defined")
|
2019-01-28 18:15:54 +01:00
|
|
|
|
|
|
|
if foreground:
|
2019-02-05 09:07:03 +01:00
|
|
|
logger.debug("Started in foreground")
|
|
|
|
try:
|
|
|
|
listen_commands(lifo_path, fifo_path, cmd_map)
|
|
|
|
except KeyboardInterrupt:
|
|
|
|
logger.info("Process killed!")
|
|
|
|
finally:
|
|
|
|
os.remove(lifo_path)
|
2019-01-28 18:15:54 +01:00
|
|
|
return
|
|
|
|
with context:
|
2019-02-05 09:07:03 +01:00
|
|
|
logger.debug("Started in background")
|
2019-02-05 15:11:31 +01:00
|
|
|
try:
|
|
|
|
listen_commands(lifo_path, fifo_path, cmd_map)
|
|
|
|
except StopDaemon:
|
|
|
|
os.remove(lifo_path)
|
|
|
|
return
|
2019-01-28 18:15:54 +01:00
|
|
|
|
|
|
|
|
2019-02-05 09:07:03 +01:00
|
|
|
def listen_client(
|
|
|
|
name: str, chan: queue.Queue, cmd_map: T.Dict[str, T.Callable]
|
|
|
|
) -> None:
|
|
|
|
"""
|
|
|
|
The listen loop for an operator instance.
|
|
|
|
"""
|
|
|
|
op = cmd_map["start"](name)
|
|
|
|
logger.debug("Started operator id: %s", id(op))
|
|
|
|
while True:
|
|
|
|
cmd = chan.get()
|
|
|
|
if cmd["name"] != name:
|
|
|
|
log.warning("Command sent to the wrong instance: %s\n%s", name, cmd)
|
|
|
|
continue
|
|
|
|
if cmd["cmd"] == "start":
|
|
|
|
logger.error("Alredy started: %s", name)
|
|
|
|
continue
|
|
|
|
if cmd["cmd"] == "stop":
|
|
|
|
logger.debug("Received command: stop")
|
|
|
|
cmd_map["stop"](op)
|
|
|
|
return
|
|
|
|
elif cmd["cmd"] == "reload":
|
|
|
|
logger.debug("Received command: reload")
|
|
|
|
cmd_map["reload"](op)
|
|
|
|
elif cmd["cmd"] == "status":
|
|
|
|
logger.debug("Received command: status")
|
|
|
|
status = cmd_map["status"](op)
|
|
|
|
logger.debug("Status: %s", status)
|
|
|
|
with Fifo(cmd["rfifo_path"], "w") as rfifo:
|
|
|
|
rfifo.write(cmd_marshal(name=cmd["name"], cmd=status))
|
2019-02-07 12:02:42 +01:00
|
|
|
elif cmd["cmd"] == "login":
|
|
|
|
logger.debug("Received command: login")
|
|
|
|
cmd_map["login"](op, cmd["username"], cmd["password"], cmd["force"])
|
|
|
|
elif cmd["cmd"] == "logout":
|
|
|
|
logger.debug("Received command: logout")
|
|
|
|
cmd_map["logout"](op, cmd["force"])
|
2019-02-18 12:20:55 +01:00
|
|
|
elif cmd["cmd"] == "checkin":
|
|
|
|
logger.debug("Received command: checkin")
|
|
|
|
cmd_map["checkin"](op, cmd["force"])
|
|
|
|
elif cmd["cmd"] == "checkout":
|
|
|
|
logger.debug("Received command: checkout")
|
|
|
|
cmd_map["checkout"](op, cmd["force"])
|
2019-02-05 09:07:03 +01:00
|
|
|
|
|
|
|
|
|
|
|
def listen_commands(
|
|
|
|
lifopath: str, fifopath: str, cmd_map: T.Dict[str, T.Callable]
|
|
|
|
) -> None:
|
2019-01-28 18:15:54 +01:00
|
|
|
"""
|
|
|
|
The main loop to listen incoming commands.
|
|
|
|
"""
|
2019-02-05 09:07:03 +01:00
|
|
|
client_chans = {}
|
2019-01-28 18:15:54 +01:00
|
|
|
while True:
|
2019-02-05 09:07:03 +01:00
|
|
|
with Fifo(fifopath) as fifo:
|
|
|
|
for cmd_str in fifo:
|
|
|
|
logger.debug("Command received in main loop: %s", cmd_str)
|
|
|
|
cmd = cmd_unmarshal(cmd_str)
|
2019-02-05 15:11:31 +01:00
|
|
|
logger.debug("Cmd unmarshalled: %s", cmd)
|
2019-02-05 09:07:03 +01:00
|
|
|
if cmd["cmd"] == "start":
|
2019-02-05 15:11:31 +01:00
|
|
|
if cmd["name"] not in client_chans:
|
|
|
|
client_chans[cmd["name"]] = queue.Queue(1)
|
|
|
|
logger.debug('Queue created for "%s".', cmd["name"])
|
|
|
|
if cmd["name"] in PLifo.All(lifopath):
|
|
|
|
logger.warning("Name %s is yet used. Not proceeding.", name)
|
|
|
|
continue
|
|
|
|
logger.debug(
|
|
|
|
'"%s" being pushed onto "%s"...', cmd["name"], lifopath
|
|
|
|
)
|
|
|
|
PLifo.Push(lifopath, cmd["name"])
|
|
|
|
logger.debug("Client %s has been newly created.", cmd["name"])
|
|
|
|
chan = client_chans.get(cmd["name"], None)
|
2019-02-05 09:07:03 +01:00
|
|
|
logger.debug("Starting new client in a thread...")
|
|
|
|
client = threading.Thread(
|
|
|
|
name=cmd["name"],
|
|
|
|
target=functools.partial(
|
2019-02-05 15:11:31 +01:00
|
|
|
listen_client, name=cmd["name"], chan=chan, cmd_map=cmd_map
|
2019-02-05 09:07:03 +01:00
|
|
|
),
|
|
|
|
)
|
|
|
|
client.start()
|
|
|
|
logger.debug('Client "%s" started.', cmd["name"])
|
|
|
|
continue
|
2019-02-05 15:11:31 +01:00
|
|
|
|
|
|
|
if cmd["cmd"] == "stop-daemon":
|
|
|
|
stop_all(client_chans)
|
|
|
|
logger.info("Daemon clients stopped. Exiting...")
|
|
|
|
raise StopDaemon
|
|
|
|
|
|
|
|
logger.debug("Opening client: %s", cmd["name"])
|
|
|
|
chan = client_chans.get(cmd["name"], None)
|
|
|
|
if chan is None:
|
|
|
|
logger.warning(
|
|
|
|
'No client found with name "%s". Skipping.', cmd["name"]
|
|
|
|
)
|
|
|
|
continue
|
|
|
|
|
|
|
|
chan.put(cmd)
|
|
|
|
|
|
|
|
|
|
|
|
def stop_all(client_chans: T.Dict[str, queue.Queue]) -> None:
|
|
|
|
"""
|
|
|
|
Send the stop command to all the clients.
|
|
|
|
"""
|
|
|
|
for name, chan in client_chans.items():
|
|
|
|
logger.debug('Stopping "%s"...', name)
|
|
|
|
chan.put({"name": name, "cmd": "stop"})
|
|
|
|
logger.info("Stopped %s.", name)
|