Difference in logging between Ray Actors and processes

How severe does this issue affect your experience of using Ray?

  • None: Just asking a question out of curiosity

Hey!

I’ve found a similar discussion here, but it didn’t really solve my problem. I’m trying to configure logging in my Ray Actors in a proper way and understand what’s going on underneath.

Until now, I’ve simply configured logger in each Actor and everything worked fine. I know that Python built-in logger is not multiprocessing-safe, but still, this piece of code works:

import logging
from multiprocessing import Process

LOG = logging.getLogger(__name__)


def setup_logger():
    logging.basicConfig(level=logging.INFO)


def child():
    LOG.info("Message from child")


def main():
    setup_logger()

    LOG.info("Message from main")

    p = Process(target=child)
    p.start()
    p.join()

    LOG.info("Message from main 2")


if __name__ == "__main__":
    main()

So, I thought using Ray Actors should work the same (at least when the actors are placed on the same machine):

import logging

import ray

LOG = logging.getLogger(__name__)


def setup_logger():
    logging.basicConfig(level=logging.INFO)


@ray.remote
class Actor:
    def __init__(self):
        LOG.info("Message from actor on init")

    def log(self):
        LOG.info("Message from actor on log")


def main():
    ray.init(
        configure_logging=False, namespace="testing", local_mode=False, log_to_driver=False
    )

    setup_logger()

    LOG.info("Message from main")

    actor_ref = Actor.remote()
    ray.get(actor_ref.log.remote())

    LOG.info("Message from main 2")


if __name__ == "__main__":
    main()

Unfortunately, it doesn’t (no logs from actor), even if I use a regular file to write output:

def setup_logger():
    logging.basicConfig(level=logging.INFO, filename="log.txt")

If I add setup_logger to Actor.__init__, then it works again:

@ray.remote
class Actor:
    def __init__(self):
        setup_logger()
        LOG.info("Message from actor on init")

And that’s the way I am using for years.

But now I am trying to understand why is it needed:

  • I understand that an actor is launched in a new worker,
  • the new worker is created as a separate process,
  • now, how the separate process is being created? Is it forked from the driver process? If so, why the configured logger is not replicated in the new memory space?

Ray starts worker processes a bit differently from multiprocessing. The raylet (a per-node C++ scheduler process) forks new worker processes for each driver (your main() function) as needed, based on queued task and actor requests and the amount of resources remaining. Each worker then runs a python script to initialize the worker state, then accepts actor or task requests from the raylet for execution.

This is why the actor process doesn’t inherit the logger from the driver and in general, you should not expect the actor to inherit state from the driver that isn’t explicitly passed to the actor’s constructor or closure-captured in the actor class definition.

By the way, did configure_logging=True work for your needs? If not, feel free to provide more info about how this could be improved here or open a feature request on GitHub.