p2p_daemon.py 25 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624
  1. import asyncio
  2. import json
  3. import logging
  4. import os
  5. import secrets
  6. from collections.abc import AsyncIterable as AsyncIterableABC
  7. from contextlib import closing, suppress
  8. from dataclasses import dataclass
  9. from datetime import datetime
  10. from importlib.resources import path
  11. from typing import Any, AsyncIterator, Awaitable, Callable, Dict, List, Optional, Sequence, Tuple, Type, TypeVar, Union
  12. from google.protobuf.message import Message
  13. from multiaddr import Multiaddr
  14. import hivemind.hivemind_cli as cli
  15. import hivemind.p2p.p2p_daemon_bindings.p2pclient as p2pclient
  16. from hivemind.p2p.p2p_daemon_bindings.control import DEFAULT_MAX_MSG_SIZE, P2PDaemonError, P2PHandlerError
  17. from hivemind.p2p.p2p_daemon_bindings.datastructures import PeerID, PeerInfo, StreamInfo
  18. from hivemind.proto.p2pd_pb2 import RPCError
  19. from hivemind.utils.asyncio import as_aiter, asingle
  20. from hivemind.utils.logging import get_logger, golog_level_to_python, loglevel, python_level_to_golog
  21. from hivemind.utils import get_free_port
  22. logger = get_logger(__name__)
  23. P2PD_FILENAME = "p2pd"
  24. @dataclass(frozen=True)
  25. class P2PContext(object):
  26. handle_name: str
  27. local_id: PeerID
  28. remote_id: PeerID = None
  29. class P2P:
  30. """
  31. This class is responsible for establishing peer-to-peer connections through NAT and/or firewalls.
  32. It creates and manages a libp2p daemon (https://libp2p.io) in a background process,
  33. then terminates it when P2P is shut down. In order to communicate, a P2P instance should
  34. either use one or more initial_peers that will connect it to the rest of the swarm or
  35. use the public IPFS network (https://ipfs.io).
  36. For incoming connections, P2P instances add RPC handlers that may be accessed by other peers:
  37. - `P2P.add_protobuf_handler` accepts a protobuf message and returns another protobuf
  38. - `P2P.add_binary_stream_handler` transfers raw data using bi-directional streaming interface
  39. To access these handlers, a P2P instance can `P2P.call_protobuf_handler`/`P2P.call_binary_stream_handler`,
  40. using the recipient's unique `P2P.peer_id` and the name of the corresponding handler.
  41. """
  42. HEADER_LEN = 8
  43. BYTEORDER = "big"
  44. MESSAGE_MARKER = b"\x00"
  45. ERROR_MARKER = b"\x01"
  46. END_OF_STREAM = RPCError()
  47. DHT_MODE_MAPPING = {
  48. "auto": {"dht": 1},
  49. "server": {"dhtServer": 1},
  50. "client": {"dhtClient": 1},
  51. }
  52. FORCE_REACHABILITY_MAPPING = {
  53. "public": {"forceReachabilityPublic": 1},
  54. "private": {"forceReachabilityPrivate": 1},
  55. }
  56. _UNIX_SOCKET_PREFIX = "/unix/tmp/hivemind-"
  57. def __init__(self):
  58. self.peer_id = None
  59. self._client = None
  60. self._child = None
  61. self._alive = False
  62. self._reader_task = None
  63. self._listen_task = None
  64. @classmethod
  65. async def create(
  66. cls,
  67. initial_peers: Optional[Sequence[Union[Multiaddr, str]]] = None,
  68. *,
  69. announce_maddrs: Optional[Sequence[Union[Multiaddr, str]]] = None,
  70. auto_nat: bool = True,
  71. conn_manager: bool = True,
  72. dht_mode: str = "server",
  73. force_reachability: Optional[str] = None,
  74. host_maddrs: Optional[Sequence[Union[Multiaddr, str]]] = ("/ip4/127.0.0.1/tcp/0",),
  75. identity_path: Optional[str] = None,
  76. idle_timeout: float = 30,
  77. nat_port_map: bool = True,
  78. quic: bool = False,
  79. relay_hop_limit: int = 0,
  80. startup_timeout: float = 15,
  81. tls: bool = True,
  82. use_auto_relay: bool = False,
  83. use_ipfs: bool = False,
  84. use_relay: bool = True,
  85. use_relay_hop: bool = False,
  86. use_relay_discovery: bool = False,
  87. persistent_conn_max_msg_size: int = DEFAULT_MAX_MSG_SIZE,
  88. ) -> "P2P":
  89. """
  90. Start a new p2pd process and connect to it.
  91. :param initial_peers: List of bootstrap peers
  92. :param auto_nat: Enables the AutoNAT service
  93. :param announce_maddrs: Visible multiaddrs that the peer will announce
  94. for external connections from other p2p instances
  95. :param conn_manager: Enables the Connection Manager
  96. :param dht_mode: libp2p DHT mode (auto/client/server).
  97. Defaults to "server" to make collaborations work in local networks.
  98. Details: https://pkg.go.dev/github.com/libp2p/go-libp2p-kad-dht#ModeOpt
  99. :param force_reachability: Force reachability mode (public/private)
  100. :param host_maddrs: Multiaddrs to listen for external connections from other p2p instances
  101. :param identity_path: Path to a pre-generated private key file. If defined, makes the peer ID deterministic.
  102. May be generated using ``./p2p-keygen`` from ``go-libp2p-daemon``.
  103. :param idle_timeout: kill daemon if client has been idle for a given number of
  104. seconds before opening persistent streams
  105. :param nat_port_map: Enables NAT port mapping
  106. :param quic: Enables the QUIC transport
  107. :param relay_hop_limit: sets the hop limit for hop relays
  108. :param startup_timeout: raise a P2PDaemonError if the daemon does not start in ``startup_timeout`` seconds
  109. :param tls: Enables TLS1.3 channel security protocol
  110. :param use_auto_relay: enables autorelay
  111. :param use_ipfs: Bootstrap to IPFS (incompatible with initial_peers)
  112. :param use_relay: enables circuit relay
  113. :param use_relay_hop: enables hop for relay
  114. :param use_relay_discovery: enables passive discovery for relay
  115. :return: a wrapper for the p2p daemon
  116. """
  117. assert not (
  118. initial_peers and use_ipfs
  119. ), "User-defined initial_peers and use_ipfs=True are incompatible, please choose one option"
  120. self = cls()
  121. with path(cli, P2PD_FILENAME) as p:
  122. p2pd_path = p
  123. socket_uid = secrets.token_urlsafe(8)
  124. self._daemon_listen_maddr = Multiaddr(cls._UNIX_SOCKET_PREFIX + f"p2pd-{socket_uid}.sock")
  125. self._client_listen_maddr = Multiaddr(cls._UNIX_SOCKET_PREFIX + f"p2pclient-{socket_uid}.sock")
  126. need_bootstrap = bool(initial_peers) or use_ipfs
  127. process_kwargs = cls.DHT_MODE_MAPPING.get(dht_mode, {"dht": 0})
  128. process_kwargs.update(cls.FORCE_REACHABILITY_MAPPING.get(force_reachability, {}))
  129. for param, value in [
  130. ("bootstrapPeers", initial_peers),
  131. ("hostAddrs", host_maddrs),
  132. ("announceAddrs", announce_maddrs),
  133. ]:
  134. if value:
  135. process_kwargs[param] = self._maddrs_to_str(value)
  136. if identity_path is not None:
  137. process_kwargs["id"] = identity_path
  138. proc_args = self._make_process_args(
  139. str(p2pd_path),
  140. autoRelay=use_auto_relay,
  141. autonat=auto_nat,
  142. b=need_bootstrap,
  143. connManager=conn_manager,
  144. idleTimeout=f"{idle_timeout}s",
  145. listen=self._daemon_listen_maddr,
  146. natPortMap=nat_port_map,
  147. quic=quic,
  148. relay=use_relay,
  149. relayDiscovery=use_relay_discovery,
  150. relayHop=use_relay_hop,
  151. relayHopLimit=relay_hop_limit,
  152. tls=tls,
  153. persistentConnMaxMsgSize=persistent_conn_max_msg_size,
  154. **process_kwargs,
  155. )
  156. env = os.environ.copy()
  157. env.setdefault("GOLOG_LOG_LEVEL", python_level_to_golog(loglevel))
  158. env["GOLOG_LOG_FMT"] = "json"
  159. logger.debug(f"Launching {proc_args}")
  160. self._child = await asyncio.subprocess.create_subprocess_exec(
  161. *proc_args, stdout=asyncio.subprocess.PIPE, stderr=asyncio.subprocess.STDOUT, env=env
  162. )
  163. self._alive = True
  164. ready = asyncio.Future()
  165. self._reader_task = asyncio.create_task(self._read_outputs(ready))
  166. try:
  167. await asyncio.wait_for(ready, startup_timeout)
  168. except asyncio.TimeoutError:
  169. await self.shutdown()
  170. raise P2PDaemonError(f"Daemon failed to start in {startup_timeout:.1f} seconds")
  171. self._client = await p2pclient.Client.create(
  172. control_maddr=self._daemon_listen_maddr,
  173. listen_maddr=self._client_listen_maddr,
  174. persistent_conn_max_msg_size=persistent_conn_max_msg_size,
  175. )
  176. await self._ping_daemon()
  177. return self
  178. @classmethod
  179. async def replicate(cls, daemon_listen_maddr: Multiaddr) -> "P2P":
  180. """
  181. Connect to existing p2p daemon
  182. :param daemon_listen_maddr: multiaddr of the existing p2p daemon
  183. :return: new wrapper for the existing p2p daemon
  184. """
  185. self = cls()
  186. # There is no child under control
  187. # Use external already running p2pd
  188. self._child = None
  189. self._alive = True
  190. socket_uid = secrets.token_urlsafe(8)
  191. self._daemon_listen_maddr = daemon_listen_maddr
  192. self._client_listen_maddr = Multiaddr(cls._UNIX_SOCKET_PREFIX + f"p2pclient-{socket_uid}.sock")
  193. self._client = await p2pclient.Client.create(self._daemon_listen_maddr, self._client_listen_maddr)
  194. await self._ping_daemon()
  195. return self
  196. async def _ping_daemon(self) -> None:
  197. self.peer_id, self._visible_maddrs = await self._client.identify()
  198. logger.debug(f"Launched p2pd with peer id = {self.peer_id}, host multiaddrs = {self._visible_maddrs}")
  199. async def get_visible_maddrs(self, latest: bool = False) -> List[Multiaddr]:
  200. """
  201. Get multiaddrs of the current peer that should be accessible by other peers.
  202. :param latest: ask the P2P daemon to refresh the visible multiaddrs
  203. """
  204. if latest:
  205. _, self._visible_maddrs = await self._client.identify()
  206. if not self._visible_maddrs:
  207. raise ValueError(f"No multiaddrs found for peer {self.peer_id}")
  208. p2p_maddr = Multiaddr(f"/p2p/{self.peer_id.to_base58()}")
  209. return [addr.encapsulate(p2p_maddr) for addr in self._visible_maddrs]
  210. async def list_peers(self) -> List[PeerInfo]:
  211. return list(await self._client.list_peers())
  212. async def wait_for_at_least_n_peers(self, n_peers: int, attempts: int = 3, delay: float = 1) -> None:
  213. for _ in range(attempts):
  214. peers = await self._client.list_peers()
  215. if len(peers) >= n_peers:
  216. return
  217. await asyncio.sleep(delay)
  218. raise RuntimeError("Not enough peers")
  219. @property
  220. def daemon_listen_maddr(self) -> Multiaddr:
  221. return self._daemon_listen_maddr
  222. @staticmethod
  223. async def send_raw_data(data: bytes, writer: asyncio.StreamWriter, *, chunk_size: int = 2 ** 16) -> None:
  224. writer.write(len(data).to_bytes(P2P.HEADER_LEN, P2P.BYTEORDER))
  225. data = memoryview(data)
  226. n = 0
  227. for offset in range(0, len(data), chunk_size):
  228. writer.write(data[offset : offset + chunk_size])
  229. await writer.drain()
  230. @staticmethod
  231. async def receive_raw_data(reader: asyncio.StreamReader) -> bytes:
  232. header = await reader.readexactly(P2P.HEADER_LEN)
  233. content_length = int.from_bytes(header, P2P.BYTEORDER)
  234. buf = bytearray(content_length)
  235. view = memoryview(buf)
  236. for offset in range(0, content_length, 2 ** 16):
  237. chunk_len = min(content_length - offset, 2 ** 16)
  238. buf[offset : offset + chunk_len] = await reader.readexactly(chunk_len)
  239. return buf
  240. TInputProtobuf = TypeVar("TInputProtobuf")
  241. TOutputProtobuf = TypeVar("TOutputProtobuf")
  242. @staticmethod
  243. async def send_protobuf(protobuf: Union[TOutputProtobuf, RPCError], writer: asyncio.StreamWriter) -> None:
  244. if isinstance(protobuf, RPCError):
  245. writer.write(P2P.ERROR_MARKER)
  246. else:
  247. writer.write(P2P.MESSAGE_MARKER)
  248. await P2P.send_raw_data(protobuf.SerializeToString(), writer)
  249. @staticmethod
  250. async def receive_protobuf(
  251. input_protobuf_type: Type[Message], reader: asyncio.StreamReader
  252. ) -> Tuple[Optional[TInputProtobuf], Optional[RPCError]]:
  253. msg_type = await reader.readexactly(1)
  254. if msg_type == P2P.MESSAGE_MARKER:
  255. protobuf = input_protobuf_type()
  256. protobuf.ParseFromString(await P2P.receive_raw_data(reader))
  257. return protobuf, None
  258. elif msg_type == P2P.ERROR_MARKER:
  259. protobuf = RPCError()
  260. protobuf.ParseFromString(await P2P.receive_raw_data(reader))
  261. return None, protobuf
  262. else:
  263. raise TypeError("Invalid Protobuf message type")
  264. TInputStream = AsyncIterator[TInputProtobuf]
  265. TOutputStream = AsyncIterator[TOutputProtobuf]
  266. async def _add_protobuf_stream_handler(
  267. self,
  268. name: str,
  269. handler: Callable[[TInputStream, P2PContext], TOutputStream],
  270. input_protobuf_type: Type[Message],
  271. max_prefetch: int = 5,
  272. ) -> None:
  273. """
  274. :param max_prefetch: Maximum number of items to prefetch from the request stream.
  275. ``max_prefetch <= 0`` means unlimited.
  276. :note: Since the cancel messages are sent via the input stream,
  277. they will not be received while the prefetch buffer is full.
  278. """
  279. async def _handle_stream(
  280. stream_info: StreamInfo, reader: asyncio.StreamReader, writer: asyncio.StreamWriter
  281. ) -> None:
  282. context = P2PContext(
  283. handle_name=name,
  284. local_id=self.peer_id,
  285. remote_id=stream_info.peer_id,
  286. )
  287. requests = asyncio.Queue(max_prefetch)
  288. async def _read_stream() -> P2P.TInputStream:
  289. while True:
  290. request = await requests.get()
  291. if request is None:
  292. break
  293. yield request
  294. async def _process_stream() -> None:
  295. try:
  296. async for response in handler(_read_stream(), context):
  297. try:
  298. await P2P.send_protobuf(response, writer)
  299. except Exception:
  300. # The connection is unexpectedly closed by the caller or broken.
  301. # The loglevel is DEBUG since the actual error will be reported on the caller
  302. logger.debug("Exception while sending response:", exc_info=True)
  303. break
  304. except Exception as e:
  305. logger.warning("Handler failed with the exception:", exc_info=True)
  306. with suppress(Exception):
  307. # Sometimes `e` is a connection error, so it is okay if we fail to report `e` to the caller
  308. await P2P.send_protobuf(RPCError(message=str(e)), writer)
  309. with closing(writer):
  310. processing_task = asyncio.create_task(_process_stream())
  311. try:
  312. while True:
  313. receive_task = asyncio.create_task(P2P.receive_protobuf(input_protobuf_type, reader))
  314. await asyncio.wait({processing_task, receive_task}, return_when=asyncio.FIRST_COMPLETED)
  315. if processing_task.done():
  316. receive_task.cancel()
  317. return
  318. if receive_task.done():
  319. try:
  320. request, _ = await receive_task
  321. except asyncio.IncompleteReadError: # Connection is closed (the client cancelled or died)
  322. return
  323. await requests.put(request) # `request` is None for the end-of-stream message
  324. except Exception:
  325. logger.warning("Exception while receiving requests:", exc_info=True)
  326. finally:
  327. processing_task.cancel()
  328. await self.add_binary_stream_handler(name, _handle_stream)
  329. async def _iterate_protobuf_stream_handler(
  330. self, peer_id: PeerID, name: str, requests: TInputStream, output_protobuf_type: Type[Message]
  331. ) -> TOutputStream:
  332. _, reader, writer = await self.call_binary_stream_handler(peer_id, name)
  333. async def _write_to_stream() -> None:
  334. async for request in requests:
  335. await P2P.send_protobuf(request, writer)
  336. await P2P.send_protobuf(P2P.END_OF_STREAM, writer)
  337. with closing(writer):
  338. writing_task = asyncio.create_task(_write_to_stream())
  339. try:
  340. while True:
  341. try:
  342. response, err = await P2P.receive_protobuf(output_protobuf_type, reader)
  343. except asyncio.IncompleteReadError: # Connection is closed
  344. break
  345. if err is not None:
  346. raise P2PHandlerError(f"Failed to call handler `{name}` at {peer_id}: {err.message}")
  347. yield response
  348. await writing_task
  349. finally:
  350. writing_task.cancel()
  351. async def add_protobuf_handler(
  352. self,
  353. name: str,
  354. handler: Callable[
  355. [Union[TInputProtobuf, TInputStream], P2PContext], Union[Awaitable[TOutputProtobuf], TOutputStream]
  356. ],
  357. input_protobuf_type: Type[Message],
  358. *,
  359. stream_input: bool = False,
  360. stream_output: bool = False,
  361. ) -> None:
  362. """
  363. :param stream_input: If True, assume ``handler`` to take ``TInputStream``
  364. (not just ``TInputProtobuf``) as input.
  365. :param stream_output: If True, assume ``handler`` to return ``TOutputStream``
  366. (not ``Awaitable[TOutputProtobuf]``).
  367. """
  368. if not stream_input and not stream_output:
  369. await self._add_protobuf_unary_handler(name, handler, input_protobuf_type)
  370. return
  371. async def _stream_handler(requests: P2P.TInputStream, context: P2PContext) -> P2P.TOutputStream:
  372. input = requests if stream_input else await asingle(requests)
  373. output = handler(input, context)
  374. if isinstance(output, AsyncIterableABC):
  375. async for item in output:
  376. yield item
  377. else:
  378. yield await output
  379. await self._add_protobuf_stream_handler(name, _stream_handler, input_protobuf_type)
  380. async def _add_protobuf_unary_handler(
  381. self,
  382. handle_name: str,
  383. handler: Callable[[TInputProtobuf, P2PContext], Awaitable[TOutputProtobuf]],
  384. input_protobuf_type: Type[Message],
  385. ) -> None:
  386. """
  387. Register a request-response (unary) handler. Unary requests and responses
  388. are sent through persistent multiplexed connections to the daemon for the
  389. sake of reducing the number of open files.
  390. :param handle_name: name of the handler (protocol id)
  391. :param handler: function handling the unary requests
  392. :param input_protobuf_type: protobuf type of the request
  393. """
  394. async def _unary_handler(request: bytes, remote_id: PeerID) -> bytes:
  395. input_serialized = input_protobuf_type.FromString(request)
  396. context = P2PContext(
  397. handle_name=handle_name,
  398. local_id=self.peer_id,
  399. remote_id=remote_id,
  400. )
  401. response = await handler(input_serialized, context)
  402. return response.SerializeToString()
  403. await self._client.add_unary_handler(handle_name, _unary_handler)
  404. async def call_protobuf_handler(
  405. self,
  406. peer_id: PeerID,
  407. name: str,
  408. input: Union[TInputProtobuf, TInputStream],
  409. output_protobuf_type: Type[Message],
  410. ) -> Awaitable[TOutputProtobuf]:
  411. if not isinstance(input, AsyncIterableABC):
  412. return await self._call_unary_protobuf_handler(peer_id, name, input, output_protobuf_type)
  413. responses = self._iterate_protobuf_stream_handler(peer_id, name, input, output_protobuf_type)
  414. return await asingle(responses)
  415. async def _call_unary_protobuf_handler(
  416. self,
  417. peer_id: PeerID,
  418. handle_name: str,
  419. input: TInputProtobuf,
  420. output_protobuf_type: Type[Message],
  421. ) -> Awaitable[TOutputProtobuf]:
  422. serialized_input = input.SerializeToString()
  423. response = await self._client.call_unary_handler(peer_id, handle_name, serialized_input)
  424. return output_protobuf_type.FromString(response)
  425. def iterate_protobuf_handler(
  426. self,
  427. peer_id: PeerID,
  428. name: str,
  429. input: Union[TInputProtobuf, TInputStream],
  430. output_protobuf_type: Type[Message],
  431. ) -> TOutputStream:
  432. requests = input if isinstance(input, AsyncIterableABC) else as_aiter(input)
  433. return self._iterate_protobuf_stream_handler(peer_id, name, requests, output_protobuf_type)
  434. def _start_listening(self) -> None:
  435. async def listen() -> None:
  436. async with self._client.listen():
  437. await asyncio.Future() # Wait until this task will be cancelled in _terminate()
  438. self._listen_task = asyncio.create_task(listen())
  439. async def add_binary_stream_handler(self, name: str, handler: p2pclient.StreamHandler) -> None:
  440. if self._listen_task is None:
  441. self._start_listening()
  442. await self._client.stream_handler(name, handler)
  443. async def call_binary_stream_handler(
  444. self, peer_id: PeerID, handler_name: str
  445. ) -> Tuple[StreamInfo, asyncio.StreamReader, asyncio.StreamWriter]:
  446. return await self._client.stream_open(peer_id, (handler_name,))
  447. def __del__(self):
  448. self._terminate()
  449. @property
  450. def is_alive(self) -> bool:
  451. return self._alive
  452. async def shutdown(self) -> None:
  453. self._terminate()
  454. if self._child is not None:
  455. await self._child.wait()
  456. def _terminate(self) -> None:
  457. if self._client is not None:
  458. self._client.close()
  459. if self._listen_task is not None:
  460. self._listen_task.cancel()
  461. if self._reader_task is not None:
  462. self._reader_task.cancel()
  463. self._alive = False
  464. if self._child is not None and self._child.returncode is None:
  465. self._child.terminate()
  466. logger.debug(f"Terminated p2pd with id = {self.peer_id}")
  467. with suppress(FileNotFoundError):
  468. os.remove(self._daemon_listen_maddr["unix"])
  469. with suppress(FileNotFoundError):
  470. os.remove(self._client_listen_maddr["unix"])
  471. @staticmethod
  472. def _make_process_args(*args, **kwargs) -> List[str]:
  473. proc_args = []
  474. proc_args.extend(str(entry) for entry in args)
  475. proc_args.extend(
  476. f"-{key}={P2P._convert_process_arg_type(value)}" if value is not None else f"-{key}"
  477. for key, value in kwargs.items()
  478. )
  479. return proc_args
  480. @staticmethod
  481. def _convert_process_arg_type(val: Any) -> Any:
  482. if isinstance(val, bool):
  483. return int(val)
  484. return val
  485. @staticmethod
  486. def _maddrs_to_str(maddrs: List[Multiaddr]) -> str:
  487. return ",".join(str(addr) for addr in maddrs)
  488. async def _read_outputs(self, ready: asyncio.Future) -> None:
  489. last_line = None
  490. while True:
  491. line = await self._child.stdout.readline()
  492. if not line: # Stream closed
  493. break
  494. last_line = line.rstrip().decode(errors="ignore")
  495. self._log_p2pd_message(last_line)
  496. if last_line.startswith("Peer ID:"):
  497. ready.set_result(None)
  498. if not ready.done():
  499. ready.set_exception(P2PDaemonError(f"Daemon failed to start: {last_line}"))
  500. @staticmethod
  501. def _log_p2pd_message(line: str) -> None:
  502. if '"logger"' not in line: # User-friendly info from p2pd stdout
  503. logger.debug(line, extra={"caller": "p2pd"})
  504. return
  505. try:
  506. record = json.loads(line)
  507. caller = record["caller"]
  508. level = golog_level_to_python(record["level"])
  509. if level <= logging.WARNING:
  510. # Many Go loggers are excessively verbose (e.g. show warnings for unreachable peers),
  511. # so we downgrade INFO and WARNING messages to DEBUG.
  512. # The Go verbosity can still be controlled via the GOLOG_LOG_LEVEL env variable.
  513. # Details: https://github.com/ipfs/go-log#golog_log_level
  514. level = logging.DEBUG
  515. message = record["msg"]
  516. if "error" in record:
  517. message += f": {record['error']}"
  518. logger.log(
  519. level,
  520. message,
  521. extra={
  522. "origin_created": datetime.strptime(record["ts"], "%Y-%m-%dT%H:%M:%S.%f%z").timestamp(),
  523. "caller": caller,
  524. },
  525. )
  526. except Exception:
  527. # Parsing errors are unlikely, but we don't want to lose these messages anyway
  528. logger.warning(line, extra={"caller": "p2pd"})
  529. logger.exception("Failed to parse go-log message:")