Skip to content
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.

Sign up for GitHub

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

ENH: Replace print calls with Logger.log #86

Open
wants to merge 1 commit into
base: master
Choose a base branch
from
Open

ENH: Replace print calls with Logger.log #86

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
25 changes: 15 additions & 10 deletions noodles/display/dumb_term.py
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,8 +1,12 @@
import logging

from .pretty_term import OutStream
from ..workflow import FunctionNode
from inspect import Parameter
import sys

logger = logging.getLogger("noodles")


def _format_arg_list(a, v):
if len(a) == 0:
Expand Down Expand Up @@ -32,9 +36,8 @@ def __init__(self, error_filter=None):

def print_message(self, key, msg):
if key in self.jobs:
print("{1:12} | {2}".format(
key, '['+msg.upper()+']', self.jobs[key]['name']),
file=sys.stderr)
logger.info("{1:12} | {2}".format(
key, '['+msg.upper()+']', self.jobs[key]['name']))

def add_job(self, key, name):
self.jobs[key] = {'name': name}
Expand All @@ -50,21 +53,20 @@ def report(self):
self.out << "[ERROR!]\n\n"

for job, e in self.errors:
msg = 'ERROR '
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No need to manually prefix ERROR if it's already included via the logging level.

if 'display' in job.hints:
msg += job.hints['display'].format(
msg = job.hints['display'].format(
**job.bound_args.arguments)
else:
msg += 'calling {} with {}'.format(
msg = 'calling {} with {}'.format(
job.foo.__name__, dict(job.bound_args.arguments)
)

print(msg)
logger.error(msg)
err_msg = self.error_filter(e)
if err_msg:
print(err_msg)
logger.error(err_msg)
else:
print(e)
logger.error(e)

def __call__(self, msg):
key, status, data, err = msg
Expand Down Expand Up @@ -96,7 +98,10 @@ def __exit__(self, exc_type, exc_val, exc_tb):
self.out << "\n" << "User interrupt detected, abnormal exit.\n"
return True

print("Internal error encountered. Contact the developers.")
logger.critical(
"Internal error encountered. Contact the developers.",
exc_info=exc_val,
)
Comment on lines +101 to +104
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

An example of a logging message where a traceback will be included.

Copy link
Author

@BvB93 BvB93 May 25, 2022 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

An example of such a tracebacked logging output from https://github.com/SCM-NV/nano-qmflows/runs/6536779272?check_suite_focus=true:

Click to expand logging output 
INFO     nanoqm:input_validation.py:191 path to basis added to cp2k settings
INFO     nanoqm:initialization.py:59 Using nano-qmflows version: 0.12.1 
INFO     nanoqm:initialization.py:60 nano-qmflows path is: /opt/hostedtoolcache/Python/3.10.4/x64/lib/python3.10/site-packages/nanoqm
INFO     nanoqm:initialization.py:61 Working directory is: /tmp/nanoqm
INFO     nanoqm:initialization.py:62 Data will be stored in HDF5 file: /tmp/pytest-of-runner/pytest-0/test_workflow_IPR0/Cd33Se33.hdf5
INFO     nanoqm:initialization.py:177 An initial Calculation will be computed as guess for the wave function
INFO     nanoqm:tools.py:22 Starting single point calculation.
INFO     nanoqm:initialization.py:59 Using nano-qmflows version: 0.12.1 
INFO     nanoqm:initialization.py:60 nano-qmflows path is: /opt/hostedtoolcache/Python/3.10.4/x64/lib/python3.10/site-packages/nanoqm
INFO     nanoqm:initialization.py:61 Working directory is: /tmp/nanoqm
INFO     nanoqm:initialization.py:62 Data will be stored in HDF5 file: /tmp/pytest-of-runner/pytest-0/test_workflow_IPR0/Cd33Se33.hdf5
INFO     nanoqm:initialization.py:177 An initial Calculation will be computed as guess for the wave function
INFO     nanoqm:workflow_single_points.py:41 starting!
INFO     nanoqm:components.py:114 point_0 has been scheduled
INFO     nanoqm:components.py:224 Total energy of point 0 is: -1832.3239105553077
ERROR    noodles:scheduler.py:105 Uncaught error running job 140216626697056
Traceback (most recent call last):
  File "/opt/hostedtoolcache/Python/3.10.4/x64/lib/python3.10/site-packages/noodles/run/worker.py", line 34, in run_job
    result = node.apply()
  File "/opt/hostedtoolcache/Python/3.10.4/x64/lib/python3.10/site-packages/noodles/workflow/model.py", line 57, in apply
    return self.foo(*self.bound_args.args, **self.bound_args.kwargs)
  File "/opt/hostedtoolcache/Python/3.10.4/x64/lib/python3.10/site-packages/nanoqm/schedule/components.py", line 159, in store_molecular_orbitals
    save_orbitals_in_hdf5(mos, config, dict_input["job_name"])
  File "/opt/hostedtoolcache/Python/3.10.4/x64/lib/python3.10/site-packages/nanoqm/schedule/components.py", line 173, in save_orbitals_in_hdf5
    dump_orbitals_to_hdf5(mos, config, job_name)
  File "/opt/hostedtoolcache/Python/3.10.4/x64/lib/python3.10/site-packages/nanoqm/schedule/components.py", line 202, in dump_orbitals_to_hdf5
    store_arrays_in_hdf5(config.path_hdf5, path_property, array)
  File "/opt/hostedtoolcache/Python/3.10.4/x64/lib/python3.10/site-packages/nanoqm/common.py", line 288, in store_arrays_in_hdf5
    dset = f5.require_dataset(paths, shape=np.shape(
  File "/opt/hostedtoolcache/Python/3.10.4/x64/lib/python3.10/site-packages/h5py/_hl/group.py", line 239, in require_dataset
    raise TypeError("Shapes do not match (existing %s vs new %s)" % (dset.shape, shape))
TypeError: Shapes do not match (existing (80,) vs new (100,))

return False

self.report()
Expand Down
9 changes: 7 additions & 2 deletions noodles/display/pretty.py
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,4 +1,7 @@
# from .termapp import TermApp
import logging

logger = logging.getLogger("noodles")


class Display:
Expand Down Expand Up @@ -26,8 +29,10 @@ def __exit__(self, exc_type, exc_val, exc_tb):
if exc_type is SystemExit:
return False

print("Internal error encountered. Contact the developers: \n",
exc_type, exc_val)
logger.critical(
"Internal error encountered. Contact the developers",
exc_info=exc_val,
)
return False

self.report()
29 changes: 17 additions & 12 deletions noodles/display/simple.py
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,6 +1,10 @@
from .pretty_term import OutStream
import sys

import logging

logger = logging.getLogger("noodles")


class Display:
"""A modest display to track jobs being run. The message being printed
Expand Down Expand Up @@ -62,37 +66,35 @@ def report(self):
self.out << "There were warnings: \n\n"

for job, w in self.messages:
msg = 'WARNING '
if job.hints and 'display' in job.hints:
msg += job.hints['display'].format(
msg = job.hints['display'].format(
**job.bound_args.arguments)
else:
msg += 'calling {} with {}'.format(
msg = 'calling {} with {}'.format(
job.foo.__name__, dict(job.bound_args.arguments)
)
print(msg)
print(w)
logger.warning(msg)
logger.warning(w)

else:
self.out << "╰─(" << ['fg', 240, 100, 60] << "ERROR!" \
<< ['reset'] << ")\n\n"

for job, e in self.errors:
msg = 'ERROR '
if job.hints and 'display' in job.hints:
msg += job.hints['display'].format(
msg = job.hints['display'].format(
**job.bound_args.arguments)
else:
msg += 'calling {} with {}'.format(
msg = 'calling {} with {}'.format(
job.foo.__name__, dict(job.bound_args.arguments)
)

print(msg)
logger.error(msg)
err_msg = self.error_filter(e)
if err_msg:
print(err_msg)
logger.error(err_msg)
else:
print(e)
logger.error(e)

def __call__(self, q):
self.q = q
Expand All @@ -112,7 +114,10 @@ def __exit__(self, exc_type, exc_val, exc_tb):
<< ['reset']
return True

print("Internal error encountered. Contact the developers.")
logger.critical(
"Internal error encountered. Contact the developers.",
exc_info=exc_val,
)
return False

self.report()
Expand Down
27 changes: 15 additions & 12 deletions noodles/display/simple_nc.py
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,5 +1,8 @@
from .pretty_term import OutStream
import sys
import logging

logger = logging.getLogger("noodles")


class Display:
Expand Down Expand Up @@ -115,34 +118,32 @@ def report(self):
self.out << "There were warnings: \n\n"

for job, w in self.messages:
msg = 'WARNING '
if job.hints and 'display' in job.hints:
msg += job.hints['display'].format(
msg = job.hints['display'].format(
**job.bound_args.arguments)
else:
msg += 'calling {} with {}'.format(
msg = 'calling {} with {}'.format(
job.foo.__name__, dict(job.bound_args.arguments)
)
print(msg)
print(w)
logger.warning(msg)
logger.warning(w)

else:
self.out << self.chars['line-bl'] << self.chars['line-hor'] \
<< "(" << ['fg', 240, 100, 60] << "ERROR!" \
<< ['reset'] << ")\n\n"

for job, e in self.errors:
msg = 'ERROR '
if job.hints and 'display' in job.hints:
msg += job.hints['display'].format(
msg = job.hints['display'].format(
**job.bound_args.arguments)
else:
msg += 'calling {} with {}'.format(
msg = 'calling {} with {}'.format(
job.foo.__name__, dict(job.bound_args.arguments)
)

print(msg)
print(e)
logger.error(msg)
logger.error(e)

def __call__(self, msg):
key, status, data, err_msg = msg
Expand All @@ -164,8 +165,10 @@ def __exit__(self, exc_type, exc_val, exc_tb):
if exc_type is SystemExit:
return False

print("Internal error encountered. Contact the developers: \n",
exc_type, exc_val)
logger.critical(
f"Internal error encountered. Contact the developers.",
exc_info=exc_val,
)
return False

self.report()
25 changes: 15 additions & 10 deletions noodles/pilot_job.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,7 @@
> python3 -m noodles.worker -online [-use <worker>]
"""

import logging
import argparse
import sys
import uuid
Expand All @@ -34,6 +35,8 @@

from .run.remote.io import (JSONObjectReader, JSONObjectWriter)

logger = logging.getLogger("noodles")


def run_online_mode(args):
"""Run jobs.
Expand All @@ -46,9 +49,9 @@ def run_online_mode(args):

Messages can be encoded as either JSON or MessagePack.
"""
print("\033[47;30m Netherlands\033[48;2;0;174;239;37m▌"
"\033[38;2;255;255;255me\u20d2Science\u20d2\033[37m▐"
"\033[47;30mcenter \033[m Noodles worker", file=sys.stderr)
logger.info("\033[47;30m Netherlands\033[48;2;0;174;239;37m▌"
"\033[38;2;255;255;255me\u20d2Science\u20d2\033[37m▐"
"\033[47;30mcenter \033[m Noodles worker")

if args.n == 1:
registry = look_up(args.registry)()
Expand All @@ -72,7 +75,7 @@ def run_online_mode(args):
if isinstance(msg, JobMessage):
key, job = msg
elif msg is EndOfWork:
print("received EndOfWork, bye", file=sys.stderr)
logger.info("received EndOfWork, bye")
sys.exit(0)
elif isinstance(msg, tuple):
key, job = msg
Expand All @@ -88,17 +91,19 @@ def run_online_mode(args):
os.chdir("noodles-{0}".format(key.hex))

if args.verbose:
print("worker: ",
job.foo.__name__,
job.bound_args.args,
job.bound_args.kwargs,
file=sys.stderr, flush=True)
logger.info(
f"worker: {job.foo.__name__} {job.bound_args.args} {job.bound_args.kwarg}"
)
for handler in logger.handlers:
handler.flush()
Comment on lines +97 to +98
Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm not even 100% sure if flushing is required for the stderr stream, but for now I'm just mimicking the previous print semantics as close as possible.


with redirect_stdout(sys.stderr):
result = run_job(key, job)

if args.verbose:
print("result: ", result.value, file=sys.stderr, flush=True)
logger.info(f"result: {result.value}")
for handler in logger.handlers:
handler.flush()

if args.jobdirs:
# parent directory
Expand Down
7 changes: 5 additions & 2 deletions noodles/prov/sqlite.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@
once a non-workflow result is known.
"""

import logging
import sqlite3
from pathlib import Path
from threading import Lock
Expand All @@ -40,6 +41,8 @@
except ImportError:
import json

logger = logging.getLogger("noodles")


schema = '''
create table if not exists "jobs" (
Expand Down Expand Up @@ -193,8 +196,8 @@ def store_result(self, key, status, value, _):
return

if key not in self.jobs:
print("WARNING: store_result called but job not in registry:\n"
" race condition? Not doing anything.\n", file=sys.stderr)
logger.warnings("store_result called but job not in registry:\n"
" race condition? Not doing anything.\n")
return

with self.lock:
Expand Down
5 changes: 4 additions & 1 deletion noodles/run/config.py
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,7 +1,10 @@
import logging
import configparser
from typing import (List)
from ..lib import (look_up)

logger = logging.getLogger("noodles")


runners = [
# ======================================================================= #
Expand Down Expand Up @@ -145,7 +148,7 @@ def run_with_config(config_file, workflow, machine=None):

machine = config.get('default', 'machine', fallback=machine)
if machine is None:
print("No machine given, running local in single thread.")
logger.info("No machine given, running local in single thread.")
runner = find_runner(name='single', features=[])
settings = {}

Expand Down
10 changes: 6 additions & 4 deletions noodles/run/job_keeper.py
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,3 +1,4 @@
import logging
import uuid
import time
import json
Expand All @@ -7,6 +8,8 @@
from ..lib import (coroutine, EndOfQueue)
from .messages import (JobMessage, EndOfWork)

logger = logging.getLogger("noodles")


class JobKeeper(dict):
def __init__(self, keep=False):
Expand Down Expand Up @@ -34,8 +37,8 @@ def store_result(self, key, status, value, err):
return

if key not in self:
print("WARNING: store_result called but job not in registry:\n"
" race condition? Not doing anything.\n", file=sys.stderr)
logger.warning("store_result called but job not in registry:\n"
" race condition? Not doing anything.\n")
return

with self.lock:
Expand All @@ -50,8 +53,7 @@ def message(self):
if msg is EndOfQueue:
return
if msg is None:
print("Warning: `None` received where not expected.",
file=sys.stderr)
logger.warning("`None` received where not expected.")
return

key, status, value, err = msg
Expand Down
Loading