tb_watcher.py 18 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520
  1. """tensorboard watcher."""
  2. from __future__ import annotations
  3. import glob
  4. import logging
  5. import os
  6. import queue
  7. import socket
  8. import sys
  9. import threading
  10. import time
  11. from typing import TYPE_CHECKING, Any
  12. import wandb
  13. from wandb import util
  14. from wandb.plot import CustomChart
  15. from wandb.sdk.lib import filesystem
  16. from . import run as internal_run
  17. if TYPE_CHECKING:
  18. from queue import PriorityQueue
  19. from tensorboard.backend.event_processing.event_file_loader import EventFileLoader
  20. from tensorboard.compat.proto.event_pb2 import ProtoEvent
  21. from wandb.proto.wandb_internal_pb2 import RunRecord
  22. from wandb.sdk.lib.filesystem import FilesDict
  23. from ..interface.interface_queue import InterfaceQueue
  24. from .settings_static import SettingsStatic
  25. HistoryDict = dict[str, Any]
  26. # Give some time for tensorboard data to be flushed
  27. SHUTDOWN_DELAY = 5
  28. ERROR_DELAY = 5
  29. REMOTE_FILE_TOKEN = "://"
  30. logger = logging.getLogger(__name__)
  31. def _link_and_save_file(
  32. path: str, base_path: str, interface: InterfaceQueue, settings: SettingsStatic
  33. ) -> None:
  34. # TODO(jhr): should this logic be merged with Run.save()
  35. files_dir = settings.files_dir
  36. file_name = os.path.relpath(path, base_path)
  37. abs_path = os.path.abspath(path)
  38. wandb_path = os.path.join(files_dir, file_name)
  39. filesystem.mkdir_exists_ok(os.path.dirname(wandb_path))
  40. # We overwrite existing symlinks because namespaces can change in Tensorboard
  41. if os.path.islink(wandb_path) and abs_path != os.readlink(wandb_path):
  42. os.remove(wandb_path)
  43. os.symlink(abs_path, wandb_path)
  44. elif not os.path.exists(wandb_path):
  45. os.symlink(abs_path, wandb_path)
  46. # TODO(jhr): need to figure out policy, live/throttled?
  47. interface.publish_files(
  48. dict(files=[(filesystem.GlobStr(glob.escape(file_name)), "live")])
  49. )
  50. def is_tfevents_file_created_by(
  51. path: str, hostname: str | None, start_time: float | None
  52. ) -> bool:
  53. """Check if a path is a tfevents file.
  54. Optionally checks that it was created by [hostname] after [start_time].
  55. tensorboard tfevents filename format:
  56. https://github.com/tensorflow/tensorboard/blob/f3f26b46981da5bd46a5bb93fcf02d9eb7608bc1/tensorboard/summary/writer/event_file_writer.py#L81
  57. tensorflow tfevents filename format:
  58. https://github.com/tensorflow/tensorflow/blob/8f597046dc30c14b5413813d02c0e0aed399c177/tensorflow/core/util/events_writer.cc#L68
  59. """
  60. if not path:
  61. raise ValueError("Path must be a nonempty string")
  62. basename = os.path.basename(path)
  63. if basename.endswith((".profile-empty", ".sagemaker-uploaded")):
  64. return False
  65. fname_components = basename.split(".")
  66. try:
  67. tfevents_idx = fname_components.index("tfevents")
  68. except ValueError:
  69. return False
  70. # check the hostname, which may have dots
  71. if hostname is not None:
  72. for i, part in enumerate(hostname.split(".")):
  73. try:
  74. fname_component_part = fname_components[tfevents_idx + 2 + i]
  75. except IndexError:
  76. return False
  77. if part != fname_component_part:
  78. return False
  79. if start_time is not None:
  80. try:
  81. created_time = int(fname_components[tfevents_idx + 1])
  82. except (ValueError, IndexError):
  83. return False
  84. # Ensure that the file is newer then our start time, and that it was
  85. # created from the same hostname.
  86. # TODO: we should also check the PID (also contained in the tfevents
  87. # filename). Can we assume that our parent pid is the user process
  88. # that wrote these files?
  89. if created_time < int(start_time):
  90. return False
  91. return True
  92. class TBWatcher:
  93. _logdirs: dict[str, TBDirWatcher]
  94. _watcher_queue: PriorityQueue
  95. def __init__(
  96. self,
  97. settings: SettingsStatic,
  98. run_proto: RunRecord,
  99. interface: InterfaceQueue,
  100. force: bool = False,
  101. ) -> None:
  102. self._logdirs = {}
  103. self._consumer: TBEventConsumer | None = None
  104. self._settings = settings
  105. self._interface = interface
  106. self._run_proto = run_proto
  107. self._force = force
  108. # TODO(jhr): do we need locking in this queue?
  109. self._watcher_queue = queue.PriorityQueue()
  110. wandb.tensorboard.reset_state() # type: ignore
  111. def _calculate_namespace(self, logdir: str, rootdir: str) -> str | None:
  112. namespace: str | None
  113. dirs = list(self._logdirs) + [logdir]
  114. if os.path.isfile(logdir):
  115. filename = os.path.basename(logdir)
  116. else:
  117. filename = ""
  118. if rootdir == "":
  119. rootdir = util.to_forward_slash_path(
  120. os.path.dirname(os.path.commonprefix(dirs))
  121. )
  122. # Tensorboard loads all tfevents files in a directory and prepends
  123. # their values with the path. Passing namespace to log allows us
  124. # to nest the values in wandb
  125. # Note that we strip '/' instead of os.sep, because elsewhere we've
  126. # converted paths to forward slash.
  127. namespace = logdir.replace(filename, "").replace(rootdir, "").strip("/")
  128. # TODO: revisit this heuristic, it exists because we don't know the
  129. # root log directory until more than one tfevents file is written to
  130. if len(dirs) == 1 and namespace not in ["train", "validation"]:
  131. namespace = None
  132. else:
  133. namespace = logdir.replace(filename, "").replace(rootdir, "").strip("/")
  134. return namespace
  135. def add(self, logdir: str, save: bool, root_dir: str) -> None:
  136. logdir = util.to_forward_slash_path(logdir)
  137. root_dir = util.to_forward_slash_path(root_dir)
  138. if logdir in self._logdirs:
  139. return
  140. namespace = self._calculate_namespace(logdir, root_dir)
  141. # TODO(jhr): implement the deferred tbdirwatcher to find namespace
  142. if not self._consumer:
  143. self._consumer = TBEventConsumer(
  144. self, self._watcher_queue, self._run_proto, self._settings
  145. )
  146. self._consumer.start()
  147. tbdir_watcher = TBDirWatcher(
  148. self, logdir, save, namespace, self._watcher_queue, self._force
  149. )
  150. self._logdirs[logdir] = tbdir_watcher
  151. tbdir_watcher.start()
  152. def finish(self) -> None:
  153. for tbdirwatcher in self._logdirs.values():
  154. tbdirwatcher.shutdown()
  155. for tbdirwatcher in self._logdirs.values():
  156. tbdirwatcher.finish()
  157. if self._consumer:
  158. self._consumer.finish()
  159. class TBDirWatcher:
  160. def __init__(
  161. self,
  162. tbwatcher: TBWatcher,
  163. logdir: str,
  164. save: bool,
  165. namespace: str | None,
  166. queue: PriorityQueue,
  167. force: bool = False,
  168. ) -> None:
  169. self.directory_watcher = util.get_module(
  170. "tensorboard.backend.event_processing.directory_watcher",
  171. required="Please install tensorboard package",
  172. )
  173. # self.event_file_loader = util.get_module(
  174. # "tensorboard.backend.event_processing.event_file_loader",
  175. # required="Please install tensorboard package",
  176. # )
  177. self.tf_compat = util.get_module(
  178. "tensorboard.compat", required="Please install tensorboard package"
  179. )
  180. self._tbwatcher = tbwatcher
  181. self._generator = self.directory_watcher.DirectoryWatcher(
  182. logdir, self._loader(save, namespace), self._is_our_tfevents_file
  183. )
  184. self._thread = threading.Thread(target=self._thread_except_body)
  185. self._first_event_timestamp = None
  186. self._shutdown = threading.Event()
  187. self._queue = queue
  188. self._file_version = None
  189. self._namespace = namespace
  190. self._logdir = logdir
  191. self._hostname = socket.gethostname()
  192. self._force = force
  193. self._process_events_lock = threading.Lock()
  194. def start(self) -> None:
  195. self._thread.start()
  196. def _is_our_tfevents_file(self, path: str) -> bool:
  197. """Check if a path has been modified since launch and contains tfevents."""
  198. if not path:
  199. raise ValueError("Path must be a nonempty string")
  200. path = self.tf_compat.tf.compat.as_str_any(path)
  201. if self._force:
  202. return is_tfevents_file_created_by(path, None, None)
  203. else:
  204. return is_tfevents_file_created_by(
  205. path, self._hostname, self._tbwatcher._settings.x_start_time
  206. )
  207. def _loader(
  208. self, save: bool = True, namespace: str | None = None
  209. ) -> EventFileLoader:
  210. """Incredibly hacky class generator to optionally save / prefix tfevent files."""
  211. _loader_interface = self._tbwatcher._interface
  212. _loader_settings = self._tbwatcher._settings
  213. try:
  214. from tensorboard.backend.event_processing import event_file_loader
  215. except ImportError:
  216. raise Exception("Please install tensorboard package")
  217. class EventFileLoader(event_file_loader.EventFileLoader):
  218. def __init__(self, file_path: str) -> None:
  219. super().__init__(file_path)
  220. if save:
  221. if REMOTE_FILE_TOKEN in file_path:
  222. logger.warning(
  223. "Not persisting remote tfevent file: %s", file_path
  224. )
  225. else:
  226. # TODO: save plugins?
  227. logdir = os.path.dirname(file_path)
  228. parts = list(os.path.split(logdir))
  229. if namespace and parts[-1] == namespace:
  230. parts.pop()
  231. logdir = os.path.join(*parts)
  232. _link_and_save_file(
  233. path=file_path,
  234. base_path=logdir,
  235. interface=_loader_interface,
  236. settings=_loader_settings,
  237. )
  238. return EventFileLoader
  239. def _process_events(self, shutdown_call: bool = False) -> None:
  240. try:
  241. with self._process_events_lock:
  242. for event in self._generator.Load():
  243. self.process_event(event)
  244. except (
  245. self.directory_watcher.DirectoryDeletedError,
  246. StopIteration,
  247. RuntimeError,
  248. OSError,
  249. ) as e:
  250. # When listing s3 the directory may not yet exist, or could be empty
  251. logger.debug("Encountered tensorboard directory watcher error: %s", e)
  252. if not self._shutdown.is_set() and not shutdown_call:
  253. time.sleep(ERROR_DELAY)
  254. def _thread_except_body(self) -> None:
  255. try:
  256. self._thread_body()
  257. except Exception:
  258. logger.exception("generic exception in TBDirWatcher thread")
  259. raise
  260. def _thread_body(self) -> None:
  261. """Check for new events every second."""
  262. shutdown_time: float | None = None
  263. while True:
  264. self._process_events()
  265. if self._shutdown.is_set():
  266. now = time.time()
  267. if not shutdown_time:
  268. shutdown_time = now + SHUTDOWN_DELAY
  269. elif now > shutdown_time:
  270. break
  271. time.sleep(1)
  272. def process_event(self, event: ProtoEvent) -> None:
  273. # print("\nEVENT:::", self._logdir, self._namespace, event, "\n")
  274. if self._first_event_timestamp is None:
  275. self._first_event_timestamp = event.wall_time
  276. if event.HasField("file_version"):
  277. self._file_version = event.file_version
  278. if event.HasField("summary"):
  279. self._queue.put(Event(event, self._namespace))
  280. def shutdown(self) -> None:
  281. self._process_events(shutdown_call=True)
  282. self._shutdown.set()
  283. def finish(self) -> None:
  284. self.shutdown()
  285. self._thread.join()
  286. class Event:
  287. """An event wrapper to enable priority queueing."""
  288. def __init__(self, event: ProtoEvent, namespace: str | None):
  289. self.event = event
  290. self.namespace = namespace
  291. self.created_at = time.time()
  292. def __lt__(self, other: Event) -> bool:
  293. return self.event.wall_time < other.event.wall_time
  294. class TBEventConsumer:
  295. """Consume tfevents from a priority queue.
  296. There should always only be one of these per run_manager. We wait for 10 seconds of
  297. queued events to reduce the chance of multiple tfevent files triggering out of order
  298. steps.
  299. """
  300. def __init__(
  301. self,
  302. tbwatcher: TBWatcher,
  303. queue: PriorityQueue,
  304. run_proto: RunRecord,
  305. settings: SettingsStatic,
  306. delay: int = 10,
  307. ) -> None:
  308. self._tbwatcher = tbwatcher
  309. self._queue = queue
  310. self._thread = threading.Thread(target=self._thread_except_body)
  311. self._shutdown = threading.Event()
  312. self.tb_history = TBHistory()
  313. self._delay = delay
  314. # This is a bit of a hack to get file saving to work as it does in the user
  315. # process. Since we don't have a real run object, we have to define the
  316. # datatypes callback ourselves.
  317. def datatypes_cb(fname: filesystem.GlobStr) -> None:
  318. files: FilesDict = dict(files=[(fname, "now")])
  319. self._tbwatcher._interface.publish_files(files)
  320. # this is only used for logging artifacts
  321. self._internal_run = internal_run.InternalRun(run_proto, settings, datatypes_cb)
  322. self._internal_run._set_internal_run_interface(self._tbwatcher._interface)
  323. def start(self) -> None:
  324. self._start_time = time.time()
  325. self._thread.start()
  326. def finish(self) -> None:
  327. self._delay = 0
  328. self._shutdown.set()
  329. self._thread.join()
  330. while not self._queue.empty():
  331. event = self._queue.get(True, 1)
  332. if event:
  333. self._handle_event(event, history=self.tb_history)
  334. items = self.tb_history._get_and_reset()
  335. for item in items:
  336. self._save_row(
  337. item,
  338. )
  339. def _thread_except_body(self) -> None:
  340. try:
  341. self._thread_body()
  342. except Exception:
  343. logger.exception("generic exception in TBEventConsumer thread")
  344. raise
  345. def _thread_body(self) -> None:
  346. while True:
  347. try:
  348. event = self._queue.get(True, 1)
  349. # Wait self._delay seconds from consumer start before logging events
  350. if (
  351. time.time() < self._start_time + self._delay
  352. and not self._shutdown.is_set()
  353. ):
  354. self._queue.put(event)
  355. time.sleep(0.1)
  356. continue
  357. except queue.Empty:
  358. event = None
  359. if self._shutdown.is_set():
  360. break
  361. if event:
  362. self._handle_event(event, history=self.tb_history)
  363. items = self.tb_history._get_and_reset()
  364. for item in items:
  365. self._save_row(
  366. item,
  367. )
  368. # flush uncommitted data
  369. self.tb_history._flush()
  370. items = self.tb_history._get_and_reset()
  371. for item in items:
  372. self._save_row(item)
  373. def _handle_event(
  374. self, event: ProtoEvent, history: TBHistory | None = None
  375. ) -> None:
  376. wandb.tensorboard._log( # type: ignore
  377. event.event,
  378. step=event.event.step,
  379. namespace=event.namespace,
  380. history=history,
  381. )
  382. def _save_row(self, row: HistoryDict) -> None:
  383. chart_keys = set()
  384. for k, v in row.items():
  385. if isinstance(v, CustomChart):
  386. chart_keys.add(k)
  387. v.set_key(k)
  388. self._tbwatcher._interface.publish_config(
  389. key=v.spec.config_key,
  390. val=v.spec.config_value,
  391. )
  392. for k in chart_keys:
  393. chart = row.pop(k)
  394. if isinstance(chart, CustomChart):
  395. row[chart.spec.table_key] = chart.table
  396. self._tbwatcher._interface.publish_history(
  397. self._internal_run,
  398. row,
  399. publish_step=False,
  400. )
  401. class TBHistory:
  402. _data: HistoryDict
  403. _added: list[HistoryDict]
  404. def __init__(self) -> None:
  405. self._step = 0
  406. self._step_size = 0
  407. self._data = dict()
  408. self._added = []
  409. def _flush(self) -> None:
  410. if not self._data:
  411. return
  412. # A single tensorboard step may have too much data
  413. # we just drop the largest keys in the step if it does.
  414. # TODO: we could flush the data across multiple steps
  415. if self._step_size > util.MAX_LINE_BYTES:
  416. metrics = [(k, sys.getsizeof(v)) for k, v in self._data.items()]
  417. metrics.sort(key=lambda t: t[1], reverse=True)
  418. bad = 0
  419. dropped_keys = []
  420. for k, v in metrics:
  421. # TODO: (cvp) Added a buffer of 100KiB, this feels rather brittle.
  422. if self._step_size - bad < util.MAX_LINE_BYTES - 100000:
  423. break
  424. else:
  425. bad += v
  426. dropped_keys.append(k)
  427. del self._data[k]
  428. wandb.termwarn(
  429. f"Step {self._step} exceeds max data limit, dropping {len(dropped_keys)} of the largest keys:"
  430. )
  431. print("\t" + ("\n\t".join(dropped_keys))) # noqa: T201
  432. self._data["_step"] = self._step
  433. self._added.append(self._data)
  434. self._step += 1
  435. self._step_size = 0
  436. def add(self, d: HistoryDict) -> None:
  437. self._flush()
  438. self._data = dict()
  439. self._data.update(self._track_history_dict(d))
  440. def _track_history_dict(self, d: HistoryDict) -> HistoryDict:
  441. e = {}
  442. for k in d:
  443. e[k] = d[k]
  444. self._step_size += sys.getsizeof(e[k])
  445. return e
  446. def _row_update(self, d: HistoryDict) -> None:
  447. self._data.update(self._track_history_dict(d))
  448. def _get_and_reset(self) -> list[HistoryDict]:
  449. added = self._added[:]
  450. self._added = []
  451. return added