#!/usr/bin/env python

import errno
import ConfigParser
import logging
import logging.config
import os
import pair
import re
import select
import shutil
import socket
import struct
import sys
import time
sys.path.append("/usr/bin")
import clock
import ifconfig
import iw
import runlevel
import udhcpc
import wpa_control
import wpa_supplicant
import rc_lock

sololink_conf = "/etc/sololink.conf"
wpa_supplicant_conf = "/etc/wpa_supplicant.conf"
wpa_supplicant_back = "/etc/wpa_supplicant.back"
sololink_version_file = "/VERSION"
firmware_version_file = "/PIX_VERSION"
controller_sololink_version_file = "/tmp/PEER_SL_VERSION"
controller_firmware_version_file = "/tmp/PEER_FW_VERSION"

# defaults for items normally read from config file
controller_link_port = 5501
wifi_connect_timeout = 5.0
connect_request_interval = 1.0
connect_ack_timeout = 0.5
button_filename = "/dev/input/event0"
solo_ip = "10.1.1.10"
check_versions = True

# It is not critical that the PIN be secret. The reason for using WPS PIN is
# not the PIN's security (it is not), but that we can cause hostapd to ask us
# for the PIN, at which time get confirmation from the user.
secret_pin = 74015887

button_error = False
button_file = None

runlevel_ready = False

# Log a version mismatch once per minute
version_mismatch_log_time_us = 0
version_mismatch_log_interval_us = 60 * 1000000

controller_sololink_version = None
controller_firmware_version = None

ifname = "wlan0"

wpa = wpa_control.WpaControl(ifname)


# conditions:
#   paired/not_paired: whether network exists in wpa_supplicant.conf


def pair_button():
    """get status of pairing button

    Returns True if pairing button has been pushed since the last call to this
    function, or False otherwise.
    """
    global button_error, button_file
    if not button_error and button_file is None:
        # open on first call
        try:
            button_file = open(button_filename)
        except:
            button_error = True
            logger.error("can't open %s for reading", button_filename)
    pushed = False
    if not button_error:
        # read all events, looking for pushes and ignoring others
        while True:
            r, w, x = select.select([button_file], [], [], 0)
            if len(r) == 0:
                # no more events
                break
            # button event
            event = r[0].read(16)
            if len(event) != 16:
                logger.error("event not 16 bytes: len=%d, event=%s",
                             len(event),
                             str([hex(ord(x)) for x in event]))
            # event is:
            #   struct input_event {
            #       struct timeval time;
            #       unsigned short type;
            #       unsigned short code;
            #       unsigned int value;
            #   };
            # time:  8 bytes, not used here
            # type:  EV_SYN=0x0000, EV_KEY=0x0001
            # code:  KEY_WPS_BUTTON=0x0211
            # value: 1 on push, 0 on release
            # Fields are little endian.
            #
            # button push:
            # xx xx xx xx xx xx xx xx 01 00 11 02 01 00 00 00
            #     type=0x0001 code=0x0211 value=0x00000001
            # xx xx xx xx xx xx xx xx 00 00 00 00 00 00 00 00
            #     type=0x0000 code=0x0000 value=0x00000000
            #
            # button release:
            # xx xx xx xx xx xx xx xx 01 00 11 02 00 00 00 00
            #     type=0x0001 code=0x0211 value=0x00000000
            # xx xx xx xx xx xx xx xx 00 00 00 00 00 00 00 00
            #     type=0x0000 code=0x0000 value=0x00000000
            try:
                s, t, c, v = struct.unpack("@QHHi", event)
                if t == 0x0001 and c == 0x0211 and v == 1:
                    pushed = True
                    # keep reading events to flush out others
            except:
                logger.error("error unpacking input event: %s",
                             str([hex(ord(x)) for x in event]))
        ### end while True
    ### end if not button_error
    return pushed


# Returns:
#   First network name if there is at least one
#   None if there are no networks
def wpa_supplicant_network_get():
    """get network from wpa_supplicant.conf

    Retrieve and return ssid from network={} section in wpa_supplicant.conf.
    The first network found is returned.
    """

    try:
        d = wpa_supplicant.read(wpa_supplicant_conf)
    except:
        logger.error("can't open %s for reading", wpa_supplicant_conf)
        return None

    if "network" in d:
        for net in d["network"]:
            # net is a dictionary of net parameters
            if "ssid" in net:
                name = net["ssid"][0]
                # strip leading and trailing quotes
                if name[0] == "\"" and name[-1] == "\"":
                    name = name[1:-1]
                return name

    # no network in wpa_supplicant.conf
    return None


# Returns:
#   True - Solo is paired
#   False - Solo is not paired
def is_paired():
    # Solo is "paired" if there is a network in wpa_supplicant.conf
    ssid = wpa_supplicant_network_get()
    return (ssid is not None)


# Returns True or False
def pin_pair():
    logger.info("pin pair...")
    wpa.pin_pair(secret_pin)
    state = None
    last_state = None
    start_us = clock.gettime_us(clock.CLOCK_MONOTONIC)
    while True:
        time.sleep(0.1)
        stat = wpa.get_status()
        now_us = clock.gettime_us(clock.CLOCK_MONOTONIC)
        if "wpa_state" in stat:
            state = stat["wpa_state"]
        else:
            state = None
        if state != last_state:
            if "ssid" in stat:
                ssid = stat["ssid"]
            else:
                ssid = ""
            if "bssid" in stat:
                bssid = stat["bssid"]
            else:
                bssid = ""
            logger.debug("%0.3f %s %s %s", (now_us - start_us) / 1000000.0,
                         state, ssid, bssid)
            last_state = state
        if state == "COMPLETED":
            break
        if state == "INACTIVE":
            break
    # end while
    if state == "COMPLETED":
        wpa.set("update_config", "1")
        wpa.save()
        wpa.set("update_config", "0")
        os.system("md5sum %s > %s.md5" % \
                  (wpa_supplicant_conf, wpa_supplicant_conf))
        os.system("sync")
        logger.info("pin pair successful")
    else:
        logger.info("pin pair failed")
    return (state == "COMPLETED")


# Returns:
#   True    associated
#   False   not associated, timeout
def associate(timeout):
    logger.debug("associate")
    wpa.reconfigure()
    return wpa.network_connect(timeout)


def disassociate():
    logger.debug("disassociate")
    wpa.network_disconnect()


# Returns:
#   True    got IP
#   False   error getting IP
def get_ip():
    logger.debug("get_ip")
    udhcpc.start(ifname, hostname="solo")
    ip_mask = ifconfig.ip_mask(ifname)
    if ip_mask is None:
        logger.info("pairing failed: error getting IP address")
        udhcpc.stop()
        return False
    elif ip_mask[0] != solo_ip:
        # This happens if this Solo and another Solo both know the wifi
        # password, and:
        # 1. The controller is paired to and already connected to the other
        #    Solo. This Solo will not get the correct IP unless the controller
        #    restarts.
        # 2. The controller is paired to this Solo, but the other Solo got on
        #    the wifi network first and got the Solo IP. In that case, the
        #    other Solo will get booted off, and this Solo will get the
        #    correct IP when it retries.
        logger.info("pairing failed: not at the fixed solo IP address")
        udhcpc.stop()
        return False
    else:
        logger.info("ip address %s netmask %s", ip_mask[0], ip_mask[1])
        return True


def release_ip():
    logger.debug("release_ip")
    udhcpc.stop()


# Check network link status. If it is good (associated, have Solo IP address),
# return True. Otherwise, make sure everything is down (disassociated, udhcpc
# stopped, no IP) and return False.
#
# Returns:
#   True    associated, udhcpc running, at solo IP
#   False   not associated, udhcpc not running, no IP
def check_link():
    stat = wpa.get_status()
    if ("wpa_state" in stat) and (stat["wpa_state"] == "COMPLETED"):
        # wifi is associated
        ip_mask = ifconfig.ip_mask(ifname)
        if ip_mask and (ip_mask[0] == solo_ip):
            return True
    # something is not right; tear everything down
    network_down()
    return False


# Returns:
#   True    network is up
#   False   button was pushed (network is not up)
def network_up():
    logger.info("bringing up network...")
    if check_link():
        logger.info("network already up")
        return True
    # check_link either confirms the network is up, or makes sure it is
    # completely down
    while True:
        if associate(wifi_connect_timeout):
            if get_ip():
                logger.info("network is up")
                return True
            disassociate()
        # don't do network_remove_all here
        if wait_button(2):
            logger.info("network is down (button detected)")
            return False


def network_down():
    release_ip()
    disassociate()
    wpa.network_remove_all()


# connected to controller, advance runlevel
def go_ready():
    global runlevel_ready
    if not runlevel_ready:
        logger.info("switching to runlevel.READY")
        runlevel.set(runlevel.READY)
        runlevel_ready = True


def set_controller_versions(pkt):
    global controller_sololink_version
    global controller_firmware_version
    sololink = pkt[4:36].strip('\r\n\t\0 ')
    firmware = pkt[36:68].strip('\r\n\t\0 ')
    if controller_sololink_version == sololink and \
       controller_firmware_version == firmware:
        return;
    controller_sololink_version = sololink
    controller_firmware_version = firmware
    try:
        f = open(controller_sololink_version_file, 'w')
        f.write("%s\n" % (controller_sololink_version, ))
        f.close()
    except:
        logger.error("error writing controller sololink version to %s",
                     controller_sololink_version_file)
    try:
        f = open(controller_firmware_version_file, 'w')
        f.write("%s\n" % (controller_firmware_version, ))
        f.close()
    except:
        logger.error("error writing controller firmware version to %s",
                     controller_firmware_version_file)
    logger.info("controller version \"%s\"; firmware \"%s\"",
                controller_sololink_version, controller_firmware_version)


# Returns
#   Only if button pushed before any response from controller
def run_connected():
    global version_mismatch_log_time_us
    ack_received = None
    logger.info("establishing connection...")
    controller_adrs = (controller_ip, controller_link_port)
    confirmed = False
    pending = False
    pair_sock = socket.socket(socket.AF_INET, socket.SOCK_DGRAM)
    pair_sock.bind(("", 0)) # any port
    pair_sock.settimeout(connect_ack_timeout)
    send_error_logged = False
    recv_error_logged = False
    while True:
        need_sleep = False

        if rc_lock.locked():
            locked = 1
        else:
            locked = 0
        logger.debug("locked=%d", locked)

        conn_req = struct.pack("<BBBB32s32s",
                               pair.CMD_CONN_REQ, pair.SYS_SOLO, 0, locked,
                               solo_sololink_version, solo_firmware_version)

        try:
            pair_sock.sendto(conn_req, controller_adrs)
        except Exception as e:
            if not send_error_logged:
                logger.info("error returned from sendto (%s)" % (e))
                send_error_logged = True
            need_sleep = True
            pkt = None
        else:
            # sendto success; reset so we log the next error
            send_error_logged = False

        # If we got an error on send, we'll likely get an error from this
        # recvfrom, leading to the correct processing (same as if we skipped
        # this recvfrom).
        try:
            pkt, adrs = pair_sock.recvfrom(256)
        except socket.timeout:
            need_sleep = False
            pkt = None
        except Exception as e:
            if not recv_error_logged:
                logger.info("error returned from recvfrom (%s)" % (e))
                recv_error_logged = True
            need_sleep = True
            pkt = None
        else:
            # recvfrom success; reset so we log the next error
            recv_error_logged = False

        now_us = clock.gettime_us(clock.CLOCK_MONOTONIC)

        if pkt is None:
            if ack_received is not None and ack_received:
                # first non-reply after ack received
                logger.info("timeout waiting for ack")
                ack_received = False
            if not confirmed and wait_button(0):
                logger.info("pairing button detected")
                network_down()
                return
            if need_sleep:
                # Could be here because of timeout waiting for packet, or
                # socket error (e.g. out of range). If not a timeout, sleep
                # a bit so as not to soak the CPU sending requests.
                time.sleep(connect_request_interval)
            # back to top to send next request
            continue

        # got a reply
        if len(pkt) == pair.CONN_MSG_LEN and \
           ord(pkt[0]) == pair.CMD_CONN_ACK and \
           ord(pkt[1]) == pair.SYS_CONTROLLER:
            if ord(pkt[2]) == pair.YES:
                set_controller_versions(pkt)
                if not confirmed:
                    confirmed = True
                elif ack_received is not None and not ack_received:
                    # previous one timed out
                    logger.info("ack received after timeout")
                ack_received = True
                # Do this even if connection was already confirmed. It is
                # possible that the other side started out on the wrong
                # version, the connection was confirmed, the other side was
                # updated, and now the versions match so we should unlock.
                if (not check_versions) or (solo_sololink_version == controller_sololink_version):
                    rc_lock.unlock_version()
                else:
                    rc_lock.lock_version()
                    # logging is rate-limited here
                    if now_us > version_mismatch_log_time_us:
                        logger.info("version mismatch: solo=\"%s\", controller=\"%s\"",
                                    solo_sololink_version, controller_sololink_version)
                        version_mismatch_log_time_us = now_us + version_mismatch_log_interval_us
                # Change runlevel even if locked or versions incompatible.
                # Apps look better if there is telemetry flowing and shotmgr
                # is running
                go_ready()
            elif ord(pkt[2]) == pair.PEND:
                if not pending:
                    logger.info("connection pending")
                pending = True
            else: # pair.NO
                if not confirmed:
                    # Controller says no. This Solo knows the wifi password
                    # from a previous pairing, but the controller has since
                    # been re-paired to a different Solo.
                    logger.info("connection rejected")
                    network_down()
                    return
                else:
                    # Controller said yes to a previous connect request, but
                    # is now saying no. We are already in runlevel 4;
                    # something is really messed up. Ignore the nack.
                    logger.error("connection was up, now rejected")
        else:
            # mystery packet!
            logger.error("mystery response received: %s",
                         str([ord(c) for c in pkt]))
        time.sleep(connect_request_interval)


# Wait for pairing button
#
# Timeout = None means wait forever, else timeout in seconds
#
# Returns:
#   True    button pushed within timeout
#   False   timeout
def wait_button(timeout=None):
    if timeout is None:
        end_us = None
    else:
        end_us = clock.gettime_us(clock.CLOCK_MONOTONIC) + \
                 int(timeout * 1000000)
    while True:
        if pair_button():
            return True
        if end_us is not None and \
           clock.gettime_us(clock.CLOCK_MONOTONIC) >= end_us:
            return False
        time.sleep(0.1)


def pair_solo():
    logger.info("pairing using %s", ifname)
    # XXX update_config=0 should be default in wpa_supplicant.conf
    wpa.set("update_config", "0")
    while True:
        if is_paired():
            if network_up():
                run_connected()
        else:
            network_down()
            logger.info("waiting for pairing button")
            wait_button()
        pin_pair()


if __name__ == "__main__":

    logging.config.fileConfig(sololink_conf)
    logger = logging.getLogger("pair")

    logger.info("pair_solo.py starting")

    config = ConfigParser.SafeConfigParser()

    # if the config file is not found, an empty list is returned and the "get"
    # operations below fail
    config.read(sololink_conf)

    # read configuration items
    try:
        controller_link_port = config.getint("pairing", "controller_link_port")
        wifi_connect_timeout = \
                config.getfloat("pairing", "wifi_connect_timeout")
        connect_request_interval = \
                config.getfloat("pairing", "connect_request_interval")
        connect_ack_timeout = config.getfloat("pairing", "connect_ack_timeout")
        button_filename = config.get("pairing", "button_filename")
        solo_ip = config.get("solo", "soloIp")
        controller_ip = config.get("solo", "artooIp")
    except:
        logger.error("error reading config from %s", sololink_conf)
        sys.exit(1)

    try:
        check_versions = sololink_config.getboolean("solo", "pairCheckVersions")
    except:
        check_versions = True # default
        logger.info("using default check_versions=%s", str(check_versions))

    # read sololink version
    try:
        f = open(sololink_version_file, 'r')
        solo_sololink_version = f.readline() # still has \n
        solo_sololink_version = solo_sololink_version.strip('\r\n\t\0 ')
    except:
        logger.error("error reading version from %s", sololink_version_file)
        sys.exit(1)

    logger.info("sololink version \"%s\"", solo_sololink_version)

    # read firmware version
    try:
        f = open(firmware_version_file, 'r')
        solo_firmware_version = f.readline() # still has \n
        solo_firmware_version = solo_firmware_version.strip('\r\n\t\0 ')
    except:
        logger.error("error reading version from %s", firmware_version_file)
        solo_firmware_version = "unknown"

    logger.info("firmware version \"%s\"", solo_firmware_version)

    # If /etc/.rc_lock exists, delete it (SOLO-709)
    if os.path.isfile("/etc/.rc_lock"):
        logger.info("deleting /etc/.rc_lock")
        os.unlink("/etc/.rc_lock")

    pair_solo()
    # pair_solo never returns