Skip to content

Added Logging Handler Names & windows pytest support #812

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
wants to merge 7 commits into
base: master
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
19 changes: 10 additions & 9 deletions meshtastic/__init__.py
Original file line number Diff line number Diff line change
Expand Up @@ -129,6 +129,7 @@ def onConnection(interface, topic=pub.AUTO_TOPIC): # called when we (re)connect

publishingThread = DeferredExecution("publishing")

logger = logging.getLogger(__name__)

class ResponseHandler(NamedTuple):
"""A pending response callback, waiting for a response to one of our messages"""
Expand Down Expand Up @@ -160,31 +161,31 @@ def _onTextReceive(iface, asDict):
#
# Usually btw this problem is caused by apps sending binary data but setting the payload type to
# text.
logging.debug(f"in _onTextReceive() asDict:{asDict}")
logger.debug(f"in _onTextReceive() asDict:{asDict}")
try:
asBytes = asDict["decoded"]["payload"]
asDict["decoded"]["text"] = asBytes.decode("utf-8")
except Exception as ex:
logging.error(f"Malformatted utf8 in text message: {ex}")
logger.error(f"Malformatted utf8 in text message: {ex}")
_receiveInfoUpdate(iface, asDict)


def _onPositionReceive(iface, asDict):
"""Special auto parsing for received messages"""
logging.debug(f"in _onPositionReceive() asDict:{asDict}")
logger.debug(f"in _onPositionReceive() asDict:{asDict}")
if "decoded" in asDict:
if "position" in asDict["decoded"] and "from" in asDict:
p = asDict["decoded"]["position"]
logging.debug(f"p:{p}")
logger.debug(f"p:{p}")
p = iface._fixupPosition(p)
logging.debug(f"after fixup p:{p}")
logger.debug(f"after fixup p:{p}")
# update node DB as needed
iface._getOrCreateByNum(asDict["from"])["position"] = p


def _onNodeInfoReceive(iface, asDict):
"""Special auto parsing for received messages"""
logging.debug(f"in _onNodeInfoReceive() asDict:{asDict}")
logger.debug(f"in _onNodeInfoReceive() asDict:{asDict}")
if "decoded" in asDict:
if "user" in asDict["decoded"] and "from" in asDict:
p = asDict["decoded"]["user"]
Expand All @@ -198,7 +199,7 @@ def _onNodeInfoReceive(iface, asDict):

def _onTelemetryReceive(iface, asDict):
"""Automatically update device metrics on received packets"""
logging.debug(f"in _onTelemetryReceive() asDict:{asDict}")
logger.debug(f"in _onTelemetryReceive() asDict:{asDict}")
if "from" not in asDict:
return

Expand All @@ -222,7 +223,7 @@ def _onTelemetryReceive(iface, asDict):
updateObj = telemetry.get(toUpdate)
newMetrics = node.get(toUpdate, {})
newMetrics.update(updateObj)
logging.debug(f"updating {toUpdate} metrics for {asDict['from']} to {newMetrics}")
logger.debug(f"updating {toUpdate} metrics for {asDict['from']} to {newMetrics}")
node[toUpdate] = newMetrics

def _receiveInfoUpdate(iface, asDict):
Expand All @@ -234,7 +235,7 @@ def _receiveInfoUpdate(iface, asDict):

def _onAdminReceive(iface, asDict):
"""Special auto parsing for received messages"""
logging.debug(f"in _onAdminReceive() asDict:{asDict}")
logger.debug(f"in _onAdminReceive() asDict:{asDict}")
if "decoded" in asDict and "from" in asDict and "admin" in asDict["decoded"]:
adminMessage = asDict["decoded"]["admin"]["raw"]
iface._getOrCreateByNum(asDict["from"])["adminSessionPassKey"] = adminMessage.session_passkey
Expand Down
37 changes: 20 additions & 17 deletions meshtastic/__main__.py
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@
from types import ModuleType

import argparse

argcomplete: Union[None, ModuleType] = None
try:
import argcomplete # type: ignore
Expand Down Expand Up @@ -62,12 +63,14 @@
from meshtastic.protobuf import channel_pb2, config_pb2, portnums_pb2
from meshtastic.version import get_active_version

logger = logging.getLogger(__name__)

def onReceive(packet, interface) -> None:
"""Callback invoked when a packet arrives"""
args = mt_config.args
try:
d = packet.get("decoded")
logging.debug(f"in onReceive() d:{d}")
logger.debug(f"in onReceive() d:{d}")

# Exit once we receive a reply
if (
Expand Down Expand Up @@ -101,7 +104,7 @@ def onConnection(interface, topic=pub.AUTO_TOPIC) -> None: # pylint: disable=W0
def checkChannel(interface: MeshInterface, channelIndex: int) -> bool:
"""Given an interface and channel index, return True if that channel is non-disabled on the local node"""
ch = interface.localNode.getChannelByChannelIndex(channelIndex)
logging.debug(f"ch:{ch}")
logger.debug(f"ch:{ch}")
return ch and ch.role != channel_pb2.Channel.Role.DISABLED


Expand All @@ -114,7 +117,7 @@ def _printSetting(config_type, uni_name, pref_value, repeated):
else:
pref_value = meshtastic.util.toStr(pref_value)
print(f"{str(config_type.name)}.{uni_name}: {str(pref_value)}")
logging.debug(f"{str(config_type.name)}.{uni_name}: {str(pref_value)}")
logger.debug(f"{str(config_type.name)}.{uni_name}: {str(pref_value)}")

name = splitCompoundName(comp_name)
wholeField = name[0] == name[1] # We want the whole field
Expand All @@ -123,8 +126,8 @@ def _printSetting(config_type, uni_name, pref_value, repeated):
# Note: protobufs has the keys in snake_case, so snake internally
snake_name = meshtastic.util.camel_to_snake(name[1])
uni_name = camel_name if mt_config.camel_case else snake_name
logging.debug(f"snake_name:{snake_name} camel_name:{camel_name}")
logging.debug(f"use camel:{mt_config.camel_case}")
logger.debug(f"snake_name:{snake_name} camel_name:{camel_name}")
logger.debug(f"use camel:{mt_config.camel_case}")

# First validate the input
localConfig = node.localConfig
Expand Down Expand Up @@ -198,8 +201,8 @@ def setPref(config, comp_name, raw_val) -> bool:
snake_name = meshtastic.util.camel_to_snake(name[-1])
camel_name = meshtastic.util.snake_to_camel(name[-1])
uni_name = camel_name if mt_config.camel_case else snake_name
logging.debug(f"snake_name:{snake_name}")
logging.debug(f"camel_name:{camel_name}")
logger.debug(f"snake_name:{snake_name}")
logger.debug(f"camel_name:{camel_name}")

objDesc = config.DESCRIPTOR
config_part = config
Expand All @@ -223,7 +226,7 @@ def setPref(config, comp_name, raw_val) -> bool:
val = meshtastic.util.fromStr(raw_val)
else:
val = raw_val
logging.debug(f"valStr:{raw_val} val:{val}")
logger.debug(f"valStr:{raw_val} val:{val}")

if snake_name == "wifi_psk" and len(str(raw_val)) < 8:
print("Warning: network.wifi_psk must be 8 or more characters.")
Expand Down Expand Up @@ -603,7 +606,7 @@ def onConnected(interface):
time.sleep(1)
if interface.gotResponse:
break
logging.debug(f"end of gpio_rd")
logger.debug(f"end of gpio_rd")

if args.gpio_watch:
bitmask = int(args.gpio_watch, 16)
Expand Down Expand Up @@ -1059,7 +1062,7 @@ def setSimpleConfig(modem_preset):
# Even if others said we could close, stay open if the user asked for a tunnel
closeNow = False
if interface.noProto:
logging.warning(f"Not starting Tunnel - disabled by noProto")
logger.warning(f"Not starting Tunnel - disabled by noProto")
else:
if args.tunnel_net:
tunnel.Tunnel(interface, subnet=args.tunnel_net)
Expand Down Expand Up @@ -1250,14 +1253,14 @@ def create_power_meter():
meter = SimPowerSupply()

if meter and v:
logging.info(f"Setting power supply to {v} volts")
logger.info(f"Setting power supply to {v} volts")
meter.v = v
meter.powerOn()

if args.power_wait:
input("Powered on, press enter to continue...")
else:
logging.info("Powered-on, waiting for device to boot")
logger.info("Powered-on, waiting for device to boot")
time.sleep(5)


Expand Down Expand Up @@ -1312,7 +1315,7 @@ def common():
args.seriallog = "none" # assume no debug output in this case

if args.deprecated is not None:
logging.error(
logger.error(
"This option has been deprecated, see help below for the correct replacement..."
)
parser.print_help(sys.stderr)
Expand All @@ -1331,18 +1334,18 @@ def common():
logfile = sys.stdout
elif args.seriallog == "none":
args.seriallog = None
logging.debug("Not logging serial output")
logger.debug("Not logging serial output")
logfile = None
else:
logging.info(f"Logging serial output to {args.seriallog}")
logger.info(f"Logging serial output to {args.seriallog}")
# Note: using "line buffering"
# pylint: disable=R1732
logfile = open(args.seriallog, "w+", buffering=1, encoding="utf8")
mt_config.logfile = logfile

subscribe()
if args.ble_scan:
logging.debug("BLE scan starting")
logger.debug("BLE scan starting")
for x in BLEInterface.scan():
print(f"Found: name='{x.name}' address='{x.address}'")
meshtastic.util.our_exit("BLE scan finished", 0)
Expand Down Expand Up @@ -1433,7 +1436,7 @@ def common():
while True:
time.sleep(1000)
except KeyboardInterrupt:
logging.info("Exiting due to keyboard interrupt")
logger.info("Exiting due to keyboard interrupt")

# don't call exit, background threads might be running still
# sys.exit(0)
Expand Down
3 changes: 2 additions & 1 deletion meshtastic/analysis/__main__.py
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,7 @@

import argparse
import logging
from pathlib import Path
from typing import cast, List

import dash_bootstrap_components as dbc # type: ignore[import-untyped]
Expand Down Expand Up @@ -190,7 +191,7 @@ def main():
parser = create_argparser()
args = parser.parse_args()
if not args.slog:
args.slog = f"{root_dir()}/latest"
args.slog = str(Path(root_dir(), "latest"))

app = create_dash(slog_path=args.slog)
port = 8051
Expand Down
33 changes: 17 additions & 16 deletions meshtastic/ble_interface.py
Original file line number Diff line number Diff line change
Expand Up @@ -23,6 +23,7 @@
FROMNUM_UUID = "ed9da18c-a800-4f66-a670-aa7547e34453"
LEGACY_LOGRADIO_UUID = "6c6fd238-78fa-436b-aacf-15c5be1ef2e2"
LOGRADIO_UUID = "5a3d6e49-06e6-4423-9944-e9de8cdf9547"
logger = logging.getLogger(__name__)


class BLEInterface(MeshInterface):
Expand All @@ -44,19 +45,19 @@ def __init__(

self.should_read = False

logging.debug("Threads starting")
logger.debug("Threads starting")
self._want_receive = True
self._receiveThread: Optional[Thread] = Thread(
target=self._receiveFromRadioImpl, name="BLEReceive", daemon=True
)
self._receiveThread.start()
logging.debug("Threads running")
logger.debug("Threads running")

self.client: Optional[BLEClient] = None
try:
logging.debug(f"BLE connecting to: {address if address else 'any'}")
logger.debug(f"BLE connecting to: {address if address else 'any'}")
self.client = self.connect(address)
logging.debug("BLE connected")
logger.debug("BLE connected")
except BLEInterface.BLEError as e:
self.close()
raise e
Expand All @@ -69,13 +70,13 @@ def __init__(
if self.client.has_characteristic(LOGRADIO_UUID):
self.client.start_notify(LOGRADIO_UUID, self.log_radio_handler)

logging.debug("Mesh configure starting")
logger.debug("Mesh configure starting")
self._startConfig()
if not self.noProto:
self._waitConnected(timeout=60.0)
self.waitForConfig()

logging.debug("Register FROMNUM notify callback")
logger.debug("Register FROMNUM notify callback")
self.client.start_notify(FROMNUM_UUID, self.from_num_handler)

# We MUST run atexit (if we can) because otherwise (at least on linux) the BLE device is not disconnected
Expand All @@ -99,7 +100,7 @@ def from_num_handler(self, _, b: bytes) -> None: # pylint: disable=C0116
Note: this method does not need to be async because it is just setting a bool.
"""
from_num = struct.unpack("<I", bytes(b))[0]
logging.debug(f"FROMNUM notify: {from_num}")
logger.debug(f"FROMNUM notify: {from_num}")
self.should_read = True

async def log_radio_handler(self, _, b): # pylint: disable=C0116
Expand All @@ -114,7 +115,7 @@ async def log_radio_handler(self, _, b): # pylint: disable=C0116
)
self._handleLogLine(message)
except google.protobuf.message.DecodeError:
logging.warning("Malformed LogRecord received. Skipping.")
logger.warning("Malformed LogRecord received. Skipping.")

async def legacy_log_radio_handler(self, _, b): # pylint: disable=C0116
log_radio = b.decode("utf-8").replace("\n", "")
Expand All @@ -124,7 +125,7 @@ async def legacy_log_radio_handler(self, _, b): # pylint: disable=C0116
def scan() -> List[BLEDevice]:
"""Scan for available BLE devices."""
with BLEClient() as client:
logging.info("Scanning for BLE devices (takes 10 seconds)...")
logger.info("Scanning for BLE devices (takes 10 seconds)...")
response = client.discover(
timeout=10, return_adv=True, service_uuids=[SERVICE_UUID]
)
Expand Down Expand Up @@ -186,19 +187,19 @@ def _receiveFromRadioImpl(self) -> None:
retries: int = 0
while self._want_receive:
if self.client is None:
logging.debug(f"BLE client is None, shutting down")
logger.debug(f"BLE client is None, shutting down")
self._want_receive = False
continue
try:
b = bytes(self.client.read_gatt_char(FROMRADIO_UUID))
except BleakDBusError as e:
# Device disconnected probably, so end our read loop immediately
logging.debug(f"Device disconnected, shutting down {e}")
logger.debug(f"Device disconnected, shutting down {e}")
self._want_receive = False
except BleakError as e:
# We were definitely disconnected
if "Not connected" in str(e):
logging.debug(f"Device disconnected, shutting down {e}")
logger.debug(f"Device disconnected, shutting down {e}")
self._want_receive = False
else:
raise BLEInterface.BLEError("Error reading BLE") from e
Expand All @@ -208,15 +209,15 @@ def _receiveFromRadioImpl(self) -> None:
retries += 1
continue
break
logging.debug(f"FROMRADIO read: {b.hex()}")
logger.debug(f"FROMRADIO read: {b.hex()}")
self._handleFromRadio(b)
else:
time.sleep(0.01)

def _sendToRadioImpl(self, toRadio) -> None:
b: bytes = toRadio.SerializeToString()
if b and self.client: # we silently ignore writes while we are shutting down
logging.debug(f"TORADIO write: {b.hex()}")
logger.debug(f"TORADIO write: {b.hex()}")
try:
self.client.write_gatt_char(
TORADIO_UUID, b, response=True
Expand All @@ -234,7 +235,7 @@ def close(self) -> None:
try:
MeshInterface.close(self)
except Exception as e:
logging.error(f"Error closing mesh interface: {e}")
logger.error(f"Error closing mesh interface: {e}")

if self._want_receive:
self._want_receive = False # Tell the thread we want it to stop
Expand Down Expand Up @@ -263,7 +264,7 @@ def __init__(self, address=None, **kwargs) -> None:
self._eventThread.start()

if not address:
logging.debug("No address provided - only discover method will work.")
logger.debug("No address provided - only discover method will work.")
return

self.bleak_client = BleakClient(address, **kwargs)
Expand Down
Loading
Loading