#!/usr/bin/env python3
#
# Check power status via the Epever charge controller and perform safe shutdown
# if running on battery power alone and battery is below safe threshold (25V)
# with input power off.
#
# When safe shutdown is deemed necessary:
#   1. log a message to the systemlog and restart services to force netsync
#   2. configure load output in timer mode
#   3. turn off load after short delay, then re-enable after fixed duration
#   4. halt and power off system with 'systemctl poweroff'

import sys
import os
import time
from datetime import datetime, timedelta
from pymodbus.client import ModbusSerialClient as ModbusClient
from pymodbus import ModbusException
import serial.rs485
import glob
import logging
from logging.handlers import RotatingFileHandler

# supported serial devices
# devices will be located by checking "/dev/serial/by-id/<pattern>"
# e.g. /dev/serial/by-id/usb-1a86_USB_Single_Serial_589A041798-if00
SERIAL_DEVICES = [
  {
    'name': 'XR21B1411',
    'pattern': '*XR21B1411*',
    'invert_rts': True
  },
  {
    'name': 'CH343',
    'pattern': '*1a86_USB*',
    'invert_rts': False
  }
]

# default options
dry_run = False
debug = False
verbose = False
is_boot = False
write_to_blockgraph = True
port = None
invert_rts = False
battery_threshold_critical = 23  # shutdown if battery voltage is below [V], even if epever programming fails
battery_threshold_off = 25  # shutdown if battery voltage is below [V]
battery_threshold_on = 26   # turn on on boot if above this [V]
solar_threshold = 50        # ok if power input above [W]
shutdown_delay = timedelta(minutes=1)
sleep_duration = timedelta(hours=1)

# usage message
HELP_MSG = f'''
Usage: safe_shutdown [OPTIONS]

Options:
  -h, --help           Print usage and exit
  -B, --boot           Calling while booting, means we are recovering from power down
  -d, --dry-run        Print changes only, do not apply (implies -v)
  -D, --debug          Log additional info
  -v, --verbose        Print status information to console
  -c, --stdout         Print to stdout only, do not write to blockgraph
  -i, --invert-rts     Invert RTS logic level
  port=PORT            Set modbus port (e.g. /dev/ttyUSB0)
  delay=SECONDS        Set delay before load disabled. Default: {int(shutdown_delay.total_seconds())}s
  sleep=SECONDS        Set duration before load re-enabled. Default: {int(sleep_duration.total_seconds())}s
  battery_critical=VOLTAGE_V    Voltage threshold below which battery is considered CRITICAL
                       Default: {battery_threshold_critical}V
  battery_off=VOLTAGE_V    Voltage threshold below which battery is considered LOW
                       Default: {battery_threshold_off}V
  battery_on=VOLTAGE_V    Voltage threshold above which battery is considered recoverd
                       Default: {battery_threshold_on}V
  solar=POWER_W        Output power threshold above which solar is considered UP
                       (0 to disable). Default: {solar_threshold}W         
'''

# collect user arguments
for arg in sys.argv[1:]:
  if arg in ('-h', '--help', 'help'):
    print(HELP_MSG)
    sys.exit(0)
  elif arg in ('-B', '--boot'):
    is_boot = True
  elif arg in ('-D', '--debug'):
    debug = True
  elif arg in ('-v', '--verbose'):
    verbose = True
  elif arg in ('-d', '--dry-run'):
    print('Dry run mode active')
    dry_run = True
    write_to_blockgraph = False
    verbose = True
  elif arg in ('-c', '--stdout'):
    write_to_blockgraph = False
  elif arg in ('-i', '--invert-rts'):
    invert_rts = True
  elif 'port=' in arg:
    port = arg.split('=', maxsplit=1)[1]
  elif 'delay=' in arg:
    shutdown_delay = timedelta(seconds=float(arg.split('=', maxsplit=1)[1]))
  elif 'sleep=' in arg:
    sleep_duration = timedelta(seconds=float(arg.split('=', maxsplit=1)[1]))
  elif 'battery_off=' in arg:
    battery_threshold_off = float(arg.split('=', maxsplit=1)[1])
  elif 'battery_on=' in arg:
    battery_threshold_on = float(arg.split('=', maxsplit=1)[1])
  elif 'solar=' in arg:
    solar_threshold = float(arg.split('=', maxsplit=1)[1])
  else:
    print(f'Invalid argument "{arg}"')
    sys.exit(1)

# Create 32bit int from two 16bit ones
def combine_LH(lo, hi):
  L = lo.to_bytes(2, byteorder='big', signed=False)
  H = hi.to_bytes(2, byteorder='big', signed=False)
  return int.from_bytes(H + L, byteorder='big', signed=True)

def init_logging():
  formatter = logging.Formatter("%(asctime)s - %(module)s - %(levelname)s - %(message)s")
  if debug:
    log_level = logging.DEBUG
  else:
    log_level = logging.INFO

  # get/reset default logger
  logger = logging.getLogger()
  logger.handlers.clear()
  logger.setLevel(log_level)

  # if verbose, log to stdout
  if verbose:
    console_handler = logging.StreamHandler(sys.stdout)
    console_handler.setLevel(log_level)
    console_handler.setFormatter(formatter)
    logger.addHandler(console_handler)

  # always log to file
  log_path = '/var/signalytic/log/power-management'
  os.makedirs(os.path.dirname(log_path), exist_ok=True)
  file_handler = RotatingFileHandler(filename=log_path, maxBytes=1048576, backupCount=3)
  file_handler.setLevel(log_level)
  file_handler.setFormatter(formatter)
  logger.addHandler(file_handler)

def exit_on_error(msg):
  if 'client' in globals():
    client.close()
  logging.error(msg)
  if write_to_blockgraph:
    os.system(f"bgsystemlog -l ERROR -s POWER -m 'safe_shutdown: {msg}'")
  sys.exit(1)

# initialize logging module
init_logging()

# if not specified, try to find a suitable serial device from known devices
if port is None:
  for dev in SERIAL_DEVICES:
    name = dev['name']
    pattern = dev['pattern']
    portlink = glob.glob(f'/dev/serial/by-id/{pattern}')
    if portlink:
      if len(portlink) > 1:
        logging.warning(f'Multiple serial devices found matching "{pattern}"')
      port = os.path.realpath(portlink[0])
      invert_rts = dev.get('invert_rts', False)
      break

# check serial device present
if not port or not os.path.exists(port):
  exit_on_error(f'Serial device not found: {port}')

# print configuration
logging.info('Safe shutdown script starting...')
logging.debug(f'  port: {port} (invert_rts={invert_rts})')
logging.debug(f'  write to blockgraph: {write_to_blockgraph}')
logging.debug(f'  dry run: {dry_run}')
logging.debug(f'  shutdown delay: {shutdown_delay}')
logging.debug(f'  sleep duration: {sleep_duration}')
logging.debug(f'  battery_off threshold: {battery_threshold_off}')
logging.debug(f'  battery_on threshold: {battery_threshold_on}')
logging.debug(f'  solar threshold: {solar_threshold}')
logging.debug(f'  boot: {is_boot}')

# initialize client
client = ModbusClient(port=port, baudrate=115200, timeout=5, retries=5)
if not client.connect():
  logging.error('client failed to connect')
  sys.exit(1)
if invert_rts:
  client.socket.rs485_mode = serial.rs485.RS485Settings(
    rts_level_for_tx=False,
    rts_level_for_rx=True,
  )

# Read all status
try:
  result = client.read_input_registers(0x331A, 1, 1)
  if result.isError(): exit_on_error(f"Received error from device ({result})")
  else: battery_voltage = result.registers[0] / 100.
  result = client.read_input_registers(0x3102, 2, 1)
  if result.isError(): exit_on_error(f"Received error from device ({result})")
  else: solar_power = combine_LH(result.registers[0], result.registers[1]) / 100.
  result = client.read_holding_registers(0x906A, 1, 1)        # 0x906A default load on/off in manual mode - ON = 1
  if result.isError(): exit_on_error(f"Received error from device ({result})")
  else: load_manual_mode = result.registers[0]
  result = client.read_holding_registers(0x903D, 1, 1)        # 0x903D load control mode - Manual Control = 0x0000
  if result.isError(): exit_on_error(f"Received error from device ({result})")
  else: load_control_mode = result.registers[0]
except ModbusException as exc:
  exit_on_error(f"Received ModbusException({exc}) from library")

# Derived variables: evaluate against configured thresholds
critical_battery = battery_voltage < battery_threshold_critical
low_battery = battery_voltage < battery_threshold_off
high_battery = battery_voltage > battery_threshold_on
solar_up = solar_power > solar_threshold

logging.info('Charger Status')
logging.info(f'  Timer managed: {"TRUE" if (load_control_mode==3) else "FALSE"}')
if critical_battery:
  logging.info(f'  battery: {battery_voltage}V (CRITICAL)')
elif low_battery:
  logging.info(f'  battery: {battery_voltage}V (LOW)')
elif high_battery:
  logging.info(f'  battery: {battery_voltage}V (HIGH)')
else:
  logging.info(f'  battery: {battery_voltage}V (OK)')
logging.info(f'  solar: {solar_power}W ({"UP" if solar_up else "DOWN"})')

# If we are booting because a timer woke us up:
#   - check if we have power and voltage above OFF threshold, or against
#     voltage above ON threshold
# In all other cases we only evaluate the battery voltage against the OFF threshold.
# What this does is if we missed a charge spurt somehow that left sufficient power
# we still boot up.
# The outcome of this is setting do_shutdown to either True or False.
do_shutdown = low_battery
if is_boot and (load_control_mode == 3):
  logging.debug('Booting after safe shutdown')
  do_shutdown = not ( high_battery or ( solar_up and not low_battery ) )

# If we are not shutting down, we are running normally. Manual load control and on:
if not do_shutdown:
  logging.info('No shutdown needed')
  if load_manual_mode == 0:
    logging.debug('set default load on/off in manual mode -> ON')
    if not dry_run:
      client.write_registers(0x906A, 1, 1)
  if load_control_mode != 0:
    logging.debug('set load control mode -> Manual Control')
    if not dry_run:
      client.write_registers(0x903D, 0, 1)

# power insufficient - initiate safe shutdown
else:
  logging.info('Initiating safe shutdown')
  # notify system of shutdown
  if write_to_blockgraph:
    os.system("bgsystemlog -l WARNING -s POWER -m 'Initiating safe shutdown'")
    time.sleep(5)
  now = datetime.utcnow()
  logging.debug(f'set RTC -> {now.isoformat()}')
  # set timing controls
  # 0x903D load control mode - Timing Control = 0x0003
  # 0x9042 Timing conrol (turn on time1) - second
  # 0x9043 Timing conrol (turn on time1) - minute
  # 0x9044 Timing conrol (turn on time1) - hour
  # 0x9045 Timing conrol (turn off time1) - second
  # 0x9046 Timing conrol (turn off time1) - minute
  # 0x9047 Timing conrol (turn off time1) - hour
  off_time = now + shutdown_delay
  on_time = off_time + sleep_duration
  logging.debug(f'set off time -> {off_time.strftime("%H:%M:%S")}')
  logging.debug(f'set on time -> {on_time.strftime("%H:%M:%S")}')
  logging.debug('set load control mode -> Timer Control')
  if not dry_run:
    # update rtc with current system time
    # 0x9013 RTC - 7-0 = second, 15-8 = minute
    # 0x9014 RTC - 7-0 = hour, 15-8 = day
    # 0x9015 RTC - 7-0 = month, 15-8 = year
    reg_ms = now.second + (now.minute << 8)
    reg_hd = now.hour + (now.day << 8)
    reg_my = now.month + ((now.year - 2000) << 8)

    success = False
    max_attempts = 10
    writes = (
      (0x9013, [reg_ms, reg_hd, reg_my]),
      (0x9042, [on_time.second, on_time.minute, on_time.hour, off_time.second, off_time.minute, off_time.hour]),
      (0x903D, [3])
    )
    attempt = 0
    while attempt < max_attempts:
      attempt += 1
      try:
        for addr, values in writes:
          client.write_registers(addr, values, slave=1)
          check = client.read_holding_registers(address=addr, count=len(values), slave=1)
          if check.registers != values:
            raise Exception(f'Register check failed ({addr}): {check.registers} != {values}')
        success = True
        break
      except ModbusException as e:
        logging.error(f'Failed to configure TIMER control mode ({attempt}/{max_attempts}): {e}')
        time.sleep(0.1*attempt)  # wait for 100ms up to 1s
      except Exception as e:
        logging.error(f'Failed to configure TIMER control mode ({attempt}/{max_attempts}): {e}')
        time.sleep(0.1*attempt)  # wait for 100ms up to 1s

    # close modbus connection and exit, shutdown if required
    client.close()
    if success:
      os.system(f"bgsystemlog -l INFO -s POWER -m 'Shutting down (retries={attempt-1})'")
      time.sleep(5)
      logging.info(f'Shutting down (retries={attempt-1})')
      os.system('shutdown now')
    elif critical_battery:
      os.system("bgsystemlog -l ERROR -s POWER -m 'Shutting down without programming epever'")
      time.sleep(5)
      logging.warning(f'Shutting down without programming epever')
      os.system('shutdown now')
    else:
      logging.warning(f'Skipping shutdown')
      os.system("bgsystemlog -l ERROR -s POWER -m 'Failed to program epever for safe shutdown'")

