diff --git a/.importlinter b/.importlinter index f77ea24b39..c979095b7f 100644 --- a/.importlinter +++ b/.importlinter @@ -18,6 +18,7 @@ forbidden_modules = openpilot.teleoprtc openpilot.tinygrad ignore_imports = + # remove these openpilot.selfdrive.car.card -> openpilot.common.realtime openpilot.selfdrive.car.card -> openpilot.selfdrive.controls.lib.events openpilot.selfdrive.car.interfaces -> openpilot.selfdrive.controls.lib.events @@ -26,16 +27,13 @@ ignore_imports = openpilot.selfdrive.car.tests.test_models -> openpilot.tools.lib.route openpilot.selfdrive.car.tests.test_models -> openpilot.system.hardware.hw openpilot.selfdrive.car.tests.test_models -> openpilot.selfdrive.test.helpers - openpilot.selfdrive.car.isotp_parallel_query -> openpilot.common.swaglog - openpilot.selfdrive.car.fw_versions -> openpilot.common.swaglog - openpilot.selfdrive.car.disable_ecu -> openpilot.common.swaglog - openpilot.selfdrive.car.vin -> openpilot.common.swaglog - openpilot.selfdrive.car.ecu_addrs -> openpilot.common.swaglog - openpilot.selfdrive.car.car_helpers -> openpilot.common.swaglog openpilot.selfdrive.car.car_helpers -> openpilot.system.version openpilot.selfdrive.car.interfaces -> openpilot.selfdrive.controls.lib.drive_helpers openpilot.selfdrive.car.tests.test_car_interfaces -> openpilot.selfdrive.controls.lib.latcontrol_angle openpilot.selfdrive.car.tests.test_car_interfaces -> openpilot.selfdrive.controls.lib.longcontrol openpilot.selfdrive.car.tests.test_car_interfaces -> openpilot.selfdrive.controls.lib.latcontrol_torque openpilot.selfdrive.car.tests.test_car_interfaces -> openpilot.selfdrive.controls.lib.latcontrol_pid + + # these are okay + openpilot.selfdrive.car.card -> openpilot.common.swaglog unmatched_ignore_imports_alerting = warn diff --git a/common/swaglog.py b/common/swaglog.py index ba81318234..d009f00e76 100644 --- a/common/swaglog.py +++ b/common/swaglog.py @@ -104,6 +104,15 @@ class UnixDomainSocketHandler(logging.Handler): pass +class ForwardingHandler(logging.Handler): + def __init__(self, target_logger): + super().__init__() + self.target_logger = target_logger + + def emit(self, record): + self.target_logger.handle(record) + + def add_file_handler(log): """ Function to add the file log handler to swaglog. diff --git a/selfdrive/car/__init__.py b/selfdrive/car/__init__.py index 28ec4ad187..0cdc6e9d8d 100644 --- a/selfdrive/car/__init__.py +++ b/selfdrive/car/__init__.py @@ -1,4 +1,5 @@ # functions common among cars +import logging from collections import namedtuple from dataclasses import dataclass from enum import IntFlag, ReprEnum, EnumType @@ -12,6 +13,11 @@ from openpilot.common.numpy_fast import clip, interp from openpilot.common.utils import Freezable from openpilot.selfdrive.car.docs_definitions import CarDocs +# set up logging +carlog = logging.getLogger('carlog') +carlog.setLevel(logging.INFO) +carlog.propagate = False + DT_CTRL = 0.01 # car state and control loop timestep (s) # kg of standard extra cargo to count for drive, gas, etc... diff --git a/selfdrive/car/car_helpers.py b/selfdrive/car/car_helpers.py index 66097339b1..4fdcc1f90c 100644 --- a/selfdrive/car/car_helpers.py +++ b/selfdrive/car/car_helpers.py @@ -4,12 +4,12 @@ from collections.abc import Callable from cereal import car from openpilot.common.params import Params +from openpilot.selfdrive.car import carlog from openpilot.selfdrive.car.interfaces import get_interface_attr from openpilot.selfdrive.car.fingerprints import eliminate_incompatible_cars, all_legacy_fingerprint_cars from openpilot.selfdrive.car.vin import get_vin, is_valid_vin, VIN_UNKNOWN from openpilot.selfdrive.car.fw_versions import get_fw_versions_ordered, get_present_ecus, match_fw_to_car, set_obd_multiplexing from openpilot.selfdrive.car.mock.values import CAR as MOCK -from openpilot.common.swaglog import cloudlog import cereal.messaging as messaging from openpilot.selfdrive.car import gen_empty_fingerprint from openpilot.system.version import get_build_metadata @@ -127,12 +127,12 @@ def fingerprint(logcan, sendcan, num_pandas): if cached_params is not None and len(cached_params.carFw) > 0 and \ cached_params.carVin is not VIN_UNKNOWN and not disable_fw_cache: - cloudlog.warning("Using cached CarParams") + carlog.warning("Using cached CarParams") vin_rx_addr, vin_rx_bus, vin = -1, -1, cached_params.carVin car_fw = list(cached_params.carFw) cached = True else: - cloudlog.warning("Getting VIN & FW versions") + carlog.warning("Getting VIN & FW versions") # enable OBD multiplexing for VIN query # NOTE: this takes ~0.1s and is relied on to allow sendcan subscriber to connect in time set_obd_multiplexing(params, True) @@ -149,9 +149,9 @@ def fingerprint(logcan, sendcan, num_pandas): cached = False if not is_valid_vin(vin): - cloudlog.event("Malformed VIN", vin=vin, error=True) + carlog.error({"event": "Malformed VIN", "vin": vin}) vin = VIN_UNKNOWN - cloudlog.warning("VIN %s", vin) + carlog.warning("VIN %s", vin) params.put("CarVin", vin) # disable OBD multiplexing for CAN fingerprinting and potential ECU knockouts @@ -178,9 +178,9 @@ def fingerprint(logcan, sendcan, num_pandas): car_fingerprint = fixed_fingerprint source = car.CarParams.FingerprintSource.fixed - cloudlog.event("fingerprinted", car_fingerprint=car_fingerprint, source=source, fuzzy=not exact_match, cached=cached, - fw_count=len(car_fw), ecu_responses=list(ecu_rx_addrs), vin_rx_addr=vin_rx_addr, vin_rx_bus=vin_rx_bus, - fingerprints=repr(finger), fw_query_time=fw_query_time, error=True) + carlog.error({"event": "fingerprinted", "car_fingerprint": car_fingerprint, "source": source, "fuzzy": not exact_match, + "cached": cached, "fw_count": len(car_fw), "ecu_responses": list(ecu_rx_addrs), "vin_rx_addr": vin_rx_addr, + "vin_rx_bus": vin_rx_bus, "fingerprints": repr(finger), "fw_query_time": fw_query_time}) return car_fingerprint, finger, vin, car_fw, source, exact_match @@ -194,7 +194,7 @@ def get_car(logcan, sendcan, experimental_long_allowed, num_pandas=1): candidate, fingerprints, vin, car_fw, source, exact_match = fingerprint(logcan, sendcan, num_pandas) if candidate is None: - cloudlog.event("car doesn't match any fingerprints", fingerprints=repr(fingerprints), error=True) + carlog.error({"event": "car doesn't match any fingerprints", "fingerprints": repr(fingerprints)}) candidate = "MOCK" CarInterface, _, _ = interfaces[candidate] diff --git a/selfdrive/car/card.py b/selfdrive/car/card.py index 37f51b9aba..929d98fd9e 100755 --- a/selfdrive/car/card.py +++ b/selfdrive/car/card.py @@ -10,9 +10,10 @@ from panda import ALTERNATIVE_EXPERIENCE from openpilot.common.params import Params from openpilot.common.realtime import config_realtime_process, Priority, Ratekeeper +from openpilot.common.swaglog import cloudlog, ForwardingHandler from openpilot.selfdrive.pandad import can_list_to_can_capnp -from openpilot.selfdrive.car import DT_CTRL +from openpilot.selfdrive.car import DT_CTRL, carlog from openpilot.selfdrive.car.car_helpers import get_car, get_one_can from openpilot.selfdrive.car.interfaces import CarInterfaceBase from openpilot.selfdrive.controls.lib.events import Events @@ -21,6 +22,9 @@ REPLAY = "REPLAY" in os.environ EventName = car.CarEvent.EventName +# forward +carlog.addHandler(ForwardingHandler(cloudlog)) + class Car: CI: CarInterfaceBase diff --git a/selfdrive/car/disable_ecu.py b/selfdrive/car/disable_ecu.py index 1f731f0344..5229b519a8 100755 --- a/selfdrive/car/disable_ecu.py +++ b/selfdrive/car/disable_ecu.py @@ -1,6 +1,6 @@ #!/usr/bin/env python3 +from openpilot.selfdrive.car import carlog from openpilot.selfdrive.car.isotp_parallel_query import IsoTpParallelQuery -from openpilot.common.swaglog import cloudlog EXT_DIAG_REQUEST = b'\x10\x03' EXT_DIAG_RESPONSE = b'\x50\x03' @@ -14,26 +14,26 @@ def disable_ecu(logcan, sendcan, bus=0, addr=0x7d0, sub_addr=None, com_cont_req= This is used to disable the radar in some cars. Openpilot will emulate the radar. WARNING: THIS DISABLES AEB!""" - cloudlog.warning(f"ecu disable {hex(addr), sub_addr} ...") + carlog.warning(f"ecu disable {hex(addr), sub_addr} ...") for i in range(retry): try: query = IsoTpParallelQuery(sendcan, logcan, bus, [(addr, sub_addr)], [EXT_DIAG_REQUEST], [EXT_DIAG_RESPONSE], debug=debug) for _, _ in query.get_data(timeout).items(): - cloudlog.warning("communication control disable tx/rx ...") + carlog.warning("communication control disable tx/rx ...") query = IsoTpParallelQuery(sendcan, logcan, bus, [(addr, sub_addr)], [com_cont_req], [COM_CONT_RESPONSE], debug=debug) query.get_data(0) - cloudlog.warning("ecu disabled") + carlog.warning("ecu disabled") return True except Exception: - cloudlog.exception("ecu disable exception") + carlog.exception("ecu disable exception") - cloudlog.error(f"ecu disable retry ({i + 1}) ...") - cloudlog.error("ecu disable failed") + carlog.error(f"ecu disable retry ({i + 1}) ...") + carlog.error("ecu disable failed") return False diff --git a/selfdrive/car/ecu_addrs.py b/selfdrive/car/ecu_addrs.py index 0ff827593e..2c79a4f633 100755 --- a/selfdrive/car/ecu_addrs.py +++ b/selfdrive/car/ecu_addrs.py @@ -4,10 +4,9 @@ import time import cereal.messaging as messaging from panda.python.uds import SERVICE_TYPE -from openpilot.selfdrive.car import make_tester_present_msg +from openpilot.selfdrive.car import make_tester_present_msg, carlog from openpilot.selfdrive.car.fw_query_definitions import EcuAddrBusType from openpilot.selfdrive.pandad import can_list_to_can_capnp -from openpilot.common.swaglog import cloudlog def _is_tester_present_response(msg: capnp.lib.capnp._DynamicStructReader, subaddr: int = None) -> bool: @@ -45,7 +44,7 @@ def get_ecu_addrs(logcan: messaging.SubSocket, sendcan: messaging.PubSocket, que for packet in can_packets: for msg in packet.can: if not len(msg.dat): - cloudlog.warning("ECU addr scan: skipping empty remote frame") + carlog.warning("ECU addr scan: skipping empty remote frame") continue subaddr = None if (msg.address, None, msg.src) in responses else msg.dat[0] @@ -56,7 +55,7 @@ def get_ecu_addrs(logcan: messaging.SubSocket, sendcan: messaging.PubSocket, que print(f"Duplicate ECU address: {hex(msg.address)}") ecu_responses.add((msg.address, subaddr, msg.src)) except Exception: - cloudlog.exception("ECU addr scan exception") + carlog.exception("ECU addr scan exception") return ecu_responses diff --git a/selfdrive/car/fw_versions.py b/selfdrive/car/fw_versions.py index 4bb6413d01..317c5ca1f9 100755 --- a/selfdrive/car/fw_versions.py +++ b/selfdrive/car/fw_versions.py @@ -9,7 +9,7 @@ import capnp import panda.python.uds as uds from cereal import car from openpilot.common.params import Params -from openpilot.common.swaglog import cloudlog +from openpilot.selfdrive.car import carlog from openpilot.selfdrive.car.ecu_addrs import get_ecu_addrs from openpilot.selfdrive.car.fingerprints import FW_VERSIONS from openpilot.selfdrive.car.fw_query_definitions import AddrType, EcuAddrBusType, FwQueryConfig, LiveFwVersions, OfflineFwVersions @@ -97,7 +97,7 @@ def match_fw_to_car_fuzzy(live_fw_versions: LiveFwVersions, match_brand: str = N # if there are enough matches. FIXME: parameterize this or require all ECUs to exist like exact matching if match and len(matched_ecus) >= 2: if log: - cloudlog.error(f"Fingerprinted {match} using fuzzy match. {len(matched_ecus)} matching ECUs") + carlog.error(f"Fingerprinted {match} using fuzzy match. {len(matched_ecus)} matching ECUs") return {match} else: return set() @@ -230,11 +230,11 @@ def get_brand_ecu_matches(ecu_rx_addrs: set[EcuAddrBusType]) -> dict[str, set[Ad def set_obd_multiplexing(params: Params, obd_multiplexing: bool): if params.get_bool("ObdMultiplexingEnabled") != obd_multiplexing: - cloudlog.warning(f"Setting OBD multiplexing to {obd_multiplexing}") + carlog.warning(f"Setting OBD multiplexing to {obd_multiplexing}") params.remove("ObdMultiplexingChanged") params.put_bool("ObdMultiplexingEnabled", obd_multiplexing) params.get_bool("ObdMultiplexingChanged", block=True) - cloudlog.warning("OBD multiplexing set successfully") + carlog.warning("OBD multiplexing set successfully") def get_fw_versions_ordered(logcan, sendcan, vin: str, ecu_rx_addrs: set[EcuAddrBusType], timeout: float = 0.1, num_pandas: int = 1, @@ -331,7 +331,7 @@ def get_fw_versions(logcan, sendcan, query_brand: str = None, extra: OfflineFwVe car_fw.append(f) except Exception: - cloudlog.exception("FW query exception") + carlog.exception("FW query exception") return car_fw diff --git a/selfdrive/car/isotp_parallel_query.py b/selfdrive/car/isotp_parallel_query.py index b5158f2126..c5f74a8156 100644 --- a/selfdrive/car/isotp_parallel_query.py +++ b/selfdrive/car/isotp_parallel_query.py @@ -3,9 +3,9 @@ from collections import defaultdict from functools import partial import cereal.messaging as messaging -from openpilot.common.swaglog import cloudlog -from openpilot.selfdrive.pandad import can_list_to_can_capnp +from openpilot.selfdrive.car import carlog from openpilot.selfdrive.car.fw_query_definitions import AddrType +from openpilot.selfdrive.pandad import can_list_to_can_capnp from panda.python.uds import CanClient, IsoTpMessage, FUNCTIONAL_ADDRS, get_rx_addr_for_tx_addr @@ -109,7 +109,7 @@ class IsoTpParallelQuery: try: dat, rx_in_progress = msg.recv() except Exception: - cloudlog.exception(f"Error processing UDS response: {tx_addr}") + carlog.exception(f"Error processing UDS response: {tx_addr}") request_done[tx_addr] = True continue @@ -123,7 +123,7 @@ class IsoTpParallelQuery: # Log unexpected empty responses if len(dat) == 0: - cloudlog.error(f"iso-tp query empty response: {tx_addr}") + carlog.error(f"iso-tp query empty response: {tx_addr}") request_done[tx_addr] = True continue @@ -143,10 +143,10 @@ class IsoTpParallelQuery: error_code = dat[2] if len(dat) > 2 else -1 if error_code == 0x78: response_timeouts[tx_addr] = time.monotonic() + self.response_pending_timeout - cloudlog.error(f"iso-tp query response pending: {tx_addr}") + carlog.error(f"iso-tp query response pending: {tx_addr}") else: request_done[tx_addr] = True - cloudlog.error(f"iso-tp query bad response: {tx_addr} - 0x{dat.hex()}") + carlog.error(f"iso-tp query bad response: {tx_addr} - 0x{dat.hex()}") # Mark request done if address timed out cur_time = time.monotonic() @@ -154,12 +154,12 @@ class IsoTpParallelQuery: if cur_time - response_timeouts[tx_addr] > 0: if not request_done[tx_addr]: if request_counter[tx_addr] > 0: - cloudlog.error(f"iso-tp query timeout after receiving partial response: {tx_addr}") + carlog.error(f"iso-tp query timeout after receiving partial response: {tx_addr}") elif tx_addr in addrs_responded: - cloudlog.error(f"iso-tp query timeout while receiving response: {tx_addr}") + carlog.error(f"iso-tp query timeout while receiving response: {tx_addr}") # TODO: handle functional addresses # else: - # cloudlog.error(f"iso-tp query timeout with no response: {tx_addr}") + # carlog.error(f"iso-tp query timeout with no response: {tx_addr}") request_done[tx_addr] = True # Break if all requests are done (finished or timed out) @@ -167,7 +167,7 @@ class IsoTpParallelQuery: break if cur_time - start_time > total_timeout: - cloudlog.error("iso-tp query timeout while receiving data") + carlog.error("iso-tp query timeout while receiving data") break return results diff --git a/selfdrive/car/tests/test_fw_fingerprint.py b/selfdrive/car/tests/test_fw_fingerprint.py index f6f6ed86d7..02e13d3ab9 100644 --- a/selfdrive/car/tests/test_fw_fingerprint.py +++ b/selfdrive/car/tests/test_fw_fingerprint.py @@ -322,11 +322,11 @@ class TestFwFingerprintTiming: # TODO: replace this with full fingerprint simulation testing # https://github.com/commaai/panda/pull/1329 - def fake_cloudlog_exception(*args, **kwargs): + def fake_carlog_exception(*args, **kwargs): raise mocker.patch("openpilot.selfdrive.car.fw_versions.set_obd_multiplexing", lambda *args: None) - mocker.patch("openpilot.common.swaglog.cloudlog.exception", fake_cloudlog_exception) + mocker.patch("openpilot.selfdrive.car.carlog.exception", fake_carlog_exception) fake_socket = FakeSocket() for brand in FW_QUERY_CONFIGS.keys(): with subtests.test(brand=brand): diff --git a/selfdrive/car/vin.py b/selfdrive/car/vin.py index e8c9c58042..d662f9a7de 100755 --- a/selfdrive/car/vin.py +++ b/selfdrive/car/vin.py @@ -3,9 +3,9 @@ import re import cereal.messaging as messaging from panda.python.uds import get_rx_addr_for_tx_addr, FUNCTIONAL_ADDRS +from openpilot.selfdrive.car import carlog from openpilot.selfdrive.car.isotp_parallel_query import IsoTpParallelQuery from openpilot.selfdrive.car.fw_query_definitions import STANDARD_VIN_ADDRS, StdQueries -from openpilot.common.swaglog import cloudlog VIN_UNKNOWN = "0" * 17 VIN_RE = "[A-HJ-NPR-Z0-9]{17}" @@ -50,12 +50,12 @@ def get_vin(logcan, sendcan, buses, timeout=0.1, retry=2, debug=False): if vin.startswith(b'\x11'): vin = vin[1:18] - cloudlog.error(f"got vin with {request=}") + carlog.error(f"got vin with {request=}") return get_rx_addr_for_tx_addr(addr, rx_offset=rx_offset), bus, vin.decode() except Exception: - cloudlog.exception("VIN query exception") + carlog.exception("VIN query exception") - cloudlog.error(f"vin query retry ({i+1}) ...") + carlog.error(f"vin query retry ({i+1}) ...") return -1, -1, VIN_UNKNOWN