metaDMG-dev / metaDMG-core

metaDMG
MIT License
6 stars 5 forks source link

KeyError: 'loggers' #11

Open salanova-elliott opened 1 year ago

salanova-elliott commented 1 year ago

Hello,

I am running into some trouble while executing metaDMG on both my personal computer and an HPC cluster (both Linux). I built metaDMG-cpp using this conda environment:

conda create -n metaDMG-cpp python=3.9 eigen htslib cxx-compiler gsl

And then used the environment.yaml file from metaDMG-core to install metaDMG. metaDMG config produces the expected config.yaml file with metaDMG-cpp pointing to the correct location, but running metaDMG compute throws KeyError: 'loggers' that's maybe related to a package dependency? conda list shows that logger-tt is installed in the environment. Both the cluster and my personal computer have thrown this same error, any idea what it could be related to?

Full error text follows:

/home/lel047/.conda/envs/metaDMG/lib/python3.9/site-packages/metaDMG/cli/cli.py:324 in compute │ │ │ │ 321 │ from metaDMG.fit import get_logger_port_and_path, run_workflow, setup_logger │ │ 322 │ │ │ 323 │ log_port, log_path = get_logger_port_and_path() │ │ ❱ 324 │ setup_logger(log_port=log_port, log_path=log_path) │ │ 325 │ │ │ 326 │ configs = utils.make_configs( │ │ 327 │ │ config_file=config_file, │ │ │ │ ╭─────────────────────────────────────────── locals ───────────────────────────────────────────╮ │ │ │ config_file = PosixPath('config.yaml') │ │ │ │ force = False │ │ │ │ get_logger_port_and_path = <function get_logger_port_and_path at 0x7feb30df5700> │ │ │ │ log_path = 'logs/log2023-03-2209-53-11.log' │ │ │ │ log_port = 51816 │ │ │ │ run_workflow = <function run_workflow at 0x7feb40ab20d0> │ │ │ │ setup_logger = <function setup_logger at 0x7feb30df54c0> │ │ │ │ utils = <module 'metaDMG.utils' from │ │ │ │ '/home/lel047/.conda/envs/metaDMG/lib/python3.9/site-packages/me… │ │ │ ╰──────────────────────────────────────────────────────────────────────────────────────────────╯ │ │ │ │ /home/lel047/.conda/envs/metaDMG/lib/python3.9/site-packages/metaDMG/loggers/loggers.py:29 in │ │ setup_logger │ │ │ │ 26 │ with resources.path("metaDMG.loggers", "log_config.yaml") as p: │ │ 27 │ │ log_config_path = p │ │ 28 │ │ │ ❱ 29 │ setup_logging( │ │ 30 │ │ config_path=str(log_config_path), │ │ 31 │ │ log_path=log_path, │ │ 32 │ │ port=log_port, │ │ │ │ ╭─────────────────────────────────────────── locals ───────────────────────────────────────────╮ │ │ │ log_config_path = PosixPath('/home/lel047/.conda/envs/metaDMG/lib/python3.9/site-packages/m… │ │ │ │ log_path = 'logs/log2023-03-2209-53-11.log' │ │ │ │ log_port = 51816 │ │ │ │ p = PosixPath('/home/lel047/.conda/envs/metaDMG/lib/python3.9/site-packages/m… │ │ │ ╰──────────────────────────────────────────────────────────────────────────────────────────────╯ │ │ │ │ /home/lel047/.conda/envs/metaDMG/lib/python3.9/site-packages/logger_tt/init.py:196 in │ │ setup_logging │ │ │ │ 193 │ │ │ 194 │ # load config from file │ │ 195 │ config = load_from_file(cfgpath) │ │ ❱ 196 │ remove_unused_handlers(config) │ │ 197 │ logger_tt_cfg = config.pop('logger_tt', {}) │ │ 198 │ if current_process().name == 'MainProcess': │ │ 199 │ │ ensure_path(config, log_path) # create log path if not exist │ │ │ │ ╭─────────────────────────────────────────── locals ───────────────────────────────────────────╮ │ │ │ cfgpath = PosixPath('/home/lel047/.conda/envs/metaDMG/lib/python3.9/site-packages/… │ │ │ │ config = { │ │ │ │ │ 'version': 1, │ │ │ │ │ 'disable_existing_loggers': False, │ │ │ │ │ 'formatters': { │ │ │ │ │ │ 'simple': { │ │ │ │ │ │ │ 'format': '[%(asctime)s] | %(name)s:%(lineno)d | │ │ │ │ %(levelname)s | %(message)s', │ │ │ │ │ │ │ 'datefmt': '%Y-%m-%d %H:%M:%S', │ │ │ │ │ │ │ 'class': 'logger_tt.core.DefaultFormatter' │ │ │ │ │ │ }, │ │ │ │ │ │ 'brief': { │ │ │ │ │ │ │ 'format': '%(message)s', │ │ │ │ │ │ │ 'datefmt': '%Y-%m-%d %H:%M:%S', │ │ │ │ │ │ │ 'class': 'logger_tt.core.DefaultFormatter' │ │ │ │ │ │ } │ │ │ │ │ }, │ │ │ │ │ 'handlers': { │ │ │ │ │ │ 'console': { │ │ │ │ │ │ │ 'class': 'rich.logging.RichHandler', │ │ │ │ │ │ │ 'level': 'INFO', │ │ │ │ │ │ │ 'formatter': 'brief', │ │ │ │ │ │ │ 'show_time': True, │ │ │ │ │ │ │ 'show_level': True, │ │ │ │ │ │ │ 'show_path': False, │ │ │ │ │ │ │ 'rich_tracebacks': True, │ │ │ │ │ │ │ 'log_time_format': '%Y-%m-%d %H:%M:%S' │ │ │ │ │ │ }, │ │ │ │ │ │ 'error_file_handler': { │ │ │ │ │ │ │ 'class': 'logging.FileHandler', │ │ │ │ │ │ │ 'level': 'DEBUG', │ │ │ │ │ │ │ 'formatter': 'simple', │ │ │ │ │ │ │ 'filename': 'logs/log.txt', │ │ │ │ │ │ │ 'encoding': 'utf8' │ │ │ │ │ │ } │ │ │ │ │ }, │ │ │ │ │ 'root': { │ │ │ │ │ │ 'level': 'DEBUG', │ │ │ │ │ │ 'handlers': ['console', 'error_file_handler'] │ │ │ │ │ }, │ │ │ │ │ 'logger_tt': { │ │ │ │ │ │ 'suppress': ['numba', 'jax'], │ │ │ │ │ │ 'suppress_level_below': 'WARNING', │ │ │ │ │ │ 'capture_print': False, │ │ │ │ │ │ 'strict': False, │ │ │ │ │ │ 'guess_level': False, │ │ │ │ │ │ 'full_context': 0, │ │ │ │ │ │ 'use_multiprocessing': True, │ │ │ │ │ │ 'limit_line_length': 1000, │ │ │ │ │ │ 'analyze_raise_statement': False │ │ │ │ │ } │ │ │ │ } │ │ │ │ config_path = '/home/lel047/.conda/envs/metaDMG/lib/python3.9/site-packages/metaDMG/lo… │ │ │ │ log_path = 'logs/log2023-03-2209-53-11.log' │ │ │ │ logger_tt_config = {'port': 51816} │ │ │ ╰──────────────────────────────────────────────────────────────────────────────────────────────╯ │ │ │ │ /home/lel047/.conda/envs/metaDMG/lib/python3.9/site-packages/logger_tt/init.py:148 in │ │ remove_unused_handlers │ │ │ │ 145 │ """ │ │ 146 │ all_handlers = list(config['handlers']) │ │ 147 │ used_handlers = config['root']['handlers'] │ │ ❱ 148 │ for name in config['loggers']: │ │ 149 │ │ handlers = config['loggers'][name]["handlers"] │ │ 150 │ │ used_handlers.extend(handlers) │ │ 151 │ │ │ │ ╭─────────────────────────────────────────── locals ───────────────────────────────────────────╮ │ │ │ all_handlers = ['console', 'error_file_handler'] │ │ │ │ config = { │ │ │ │ │ 'version': 1, │ │ │ │ │ 'disable_existing_loggers': False, │ │ │ │ │ 'formatters': { │ │ │ │ │ │ 'simple': { │ │ │ │ │ │ │ 'format': '[%(asctime)s] | %(name)s:%(lineno)d | %(levelname)s | │ │ │ │ %(message)s', │ │ │ │ │ │ │ 'datefmt': '%Y-%m-%d %H:%M:%S', │ │ │ │ │ │ │ 'class': 'logger_tt.core.DefaultFormatter' │ │ │ │ │ │ }, │ │ │ │ │ │ 'brief': { │ │ │ │ │ │ │ 'format': '%(message)s', │ │ │ │ │ │ │ 'datefmt': '%Y-%m-%d %H:%M:%S', │ │ │ │ │ │ │ 'class': 'logger_tt.core.DefaultFormatter' │ │ │ │ │ │ } │ │ │ │ │ }, │ │ │ │ │ 'handlers': { │ │ │ │ │ │ 'console': { │ │ │ │ │ │ │ 'class': 'rich.logging.RichHandler', │ │ │ │ │ │ │ 'level': 'INFO', │ │ │ │ │ │ │ 'formatter': 'brief', │ │ │ │ │ │ │ 'show_time': True, │ │ │ │ │ │ │ 'show_level': True, │ │ │ │ │ │ │ 'show_path': False, │ │ │ │ │ │ │ 'rich_tracebacks': True, │ │ │ │ │ │ │ 'log_time_format': '%Y-%m-%d %H:%M:%S' │ │ │ │ │ │ }, │ │ │ │ │ │ 'error_file_handler': { │ │ │ │ │ │ │ 'class': 'logging.FileHandler', │ │ │ │ │ │ │ 'level': 'DEBUG', │ │ │ │ │ │ │ 'formatter': 'simple', │ │ │ │ │ │ │ 'filename': 'logs/log.txt', │ │ │ │ │ │ │ 'encoding': 'utf8' │ │ │ │ │ │ } │ │ │ │ │ }, │ │ │ │ │ 'root': { │ │ │ │ │ │ 'level': 'DEBUG', │ │ │ │ │ │ 'handlers': ['console', 'error_file_handler'] │ │ │ │ │ }, │ │ │ │ │ 'logger_tt': { │ │ │ │ │ │ 'suppress': ['numba', 'jax'], │ │ │ │ │ │ 'suppress_level_below': 'WARNING', │ │ │ │ │ │ 'capture_print': False, │ │ │ │ │ │ 'strict': False, │ │ │ │ │ │ 'guess_level': False, │ │ │ │ │ │ 'full_context': 0, │ │ │ │ │ │ 'use_multiprocessing': True, │ │ │ │ │ │ 'limit_line_length': 1000, │ │ │ │ │ │ 'analyze_raise_statement': False │ │ │ │ │ } │ │ │ │ } │ │ │ │ used_handlers = ['console', 'error_file_handler'] │ │ │ ╰──────────────────────────────────────────────────────────────────────────────────────────────╯ │ ╰──────────────────────────────────────────────────────────────────────────────────────────────────╯ KeyError: 'loggers'

vincentvendius commented 1 year ago

I get the same issue

genomewalker commented 1 year ago

In the meantime, update metaDMG to the latest version and do in the env where you have metaDMG installed:

pip install logger-tt==1.7.0
salanova-elliott commented 1 year ago

Thanks for the help @genomewalker. Reverting logger-tt to 1.7.0 allowed the compute command to progress, but now it looks to be running into another cryptic error. This is from the log file:

[2023-04-19 14:20:41] | root:185 | DEBUG | _____New log started__ [2023-04-19 14:20:41] | root:186 | DEBUG | Log config file: /home/lel047/.conda/envs/metaDMG/lib/python3.9/site-packages/metaDMG/loggers/log_config.yaml [2023-04-19 14:20:41] | root:153 | DEBUG | Logging server started! [2023-04-19 14:20:41] | metaDMG.loggers.loggers:40 | DEBUG | Running metaDMG version 0.38.0. [2023-04-19 14:20:41] | metaDMG.loggers.loggers:41 | DEBUG | Using port 61712 for logging. [2023-04-19 14:20:41] | metaDMG.utils:160 | INFO | Using config.yaml as config file. [2023-04-19 14:20:41] | metaDMG.fit.workflow:27 | INFO | Running metaDMG on 1 files in total. [2023-04-19 14:20:41] | metaDMG.fit.workflow:34 | INFO | Running the samples in serial (sequentially), each using 1 core(s). [2023-04-19 14:20:41] | metaDMG.fit.serial:290 | INFO | cv28 | Getting LCA. [2023-04-19 14:20:41] | metaDMG.fit.serial:310 | INFO | cv28 | LCA has to be computed. This can take a while, please wait. [2023-04-19 14:20:41] | metaDMG.fit.serial:317 | DEBUG | cv28 | /bettik/lel047/src/metaDMG-cpp/metaDMG-cpp lca -bam cv28.all_sorted.sam.gz -outnames data/tmp/cv28/cv28 -names /bettik/lel047/data/taxonomy/names.dmp -nodes /bettik/lel047/data/taxonomy/nodes.dmp -acc2tax /bettik/lel047/data/KapCop/combined_taxid_accssionNO_20223103 -simscorelow 0.95 -simscorehigh 1.0 -minmapq 0 -howmany 15 -weighttype 1 -fix_ncbi 1 -tempfolder data/tmp/cv28/ [2023-04-19 14:20:41] | metaDMG.fit.serial:273 | DEBUG | cv28 | -> metaDMG version: 0.2-46-gedaf069 (htslib: 1.17) build(Mar 21 2023 16:20:29) [2023-04-19 14:20:41] | metaDMG.fit.serial:273 | DEBUG | cv28 | #/bettik/lel047/src/metaDMG-cpp/metaDMG-cpp lca -bam cv28.all_sorted.sam.gz -outnames data/tmp/cv28/cv28 -names /bettik/lel047/data/taxonomy/names.dmp -nodes /bettik/lel047/data/taxonomy/nodes.dmp -acc2tax /bettik/lel047/data/KapCop/combined_taxid_accssionNO_20223103 -simscorelow 0.95 -simscorehigh 1.0 -minmapq 0 -howmany 15 -weighttype 1 -fix_ncbi 1 -tempfolder data/tmp/cv28/ [2023-04-19 14:20:41] | metaDMG.fit.serial:273 | DEBUG | cv28 | -> Will output lca results in file: 'data/tmp/cv28/cv28.lca.gz' [2023-04-19 14:20:41] | metaDMG.fit.serial:273 | DEBUG | cv28 | -> [thread1] Will read header [2023-04-19 14:20:41] | metaDMG.fit.serial:273 | DEBUG | cv28 | -> Will output lca distribution in file: 'data/tmp/cv28/cv28.stat' [2023-04-19 14:20:41] | metaDMG.fit.serial:273 | DEBUG | cv28 | -> Will output lca weight in file: 'data/tmp/cv28/cv28.wlca' [2023-04-19 14:20:41] | metaDMG.fit.serial:273 | DEBUG | cv28 | -> Will output log info (problems) in file: 'data/tmp/cv28/cv28.log' [2023-04-19 14:24:29] | root:219 | ERROR | cv28 | metadamageError with run_LCA. See log-file for more information. Traceback (most recent call last): File "/home/lel047/.conda/envs/metaDMG/lib/python3.9/site-packages/metaDMG/fit/serial.py", line 536, in run_single_config run_cpp(config, force=force)

File "/home/lel047/.conda/envs/metaDMG/lib/python3.9/site-packages/metaDMG/fit/serial.py", line 377, in run_cpp run_LCA(config, force=force)

File "/home/lel047/.conda/envs/metaDMG/lib/python3.9/site-packages/metaDMG/fit/serial.py", line 318, in run_LCA run_command_helper(config, command_LCA)

File "/home/lel047/.conda/envs/metaDMG/lib/python3.9/site-packages/metaDMG/fit/serial.py", line 260, in run_command_helper return handle_returncode(command, line, counter)

File "/home/lel047/.conda/envs/metaDMG/lib/python3.9/site-packages/metaDMG/fit/serial.py", line 244, in handle_returncode raise metadamageError(s) metaDMG.errors.metadamageError: /bettik/lel047/src/metaDMG-cpp/metaDMG-cpp lca -bam cv28.all_sorted.sam.gz -outnames data/tmp/cv28/cv28 -names /bettik/lel047/data/taxonomy/names.dmp -nodes /bettik/lel047/data/taxonomy/nodes.dmp -acc2tax /bettik/lel047/data/KapCop/combined_taxid_accssionNO_20223103 -simscorelow 0.95 -simscorehigh 1.0 -minmapq 0 -howmany 15 -weighttype 1 -fix_ncbi 1 -tempfolder data/tmp/cv28/ did not terminate properly. See log file for more information. [2023-04-19 14:24:29] | metaDMG.fit.workflow:50 | ERROR | 1 error(s) occurred during the computation.

genomewalker commented 1 year ago

hi @salanova-elliott are you running the latest version of the cpp code?

if yes, can you send the output of:

/bettik/lel047/src/metaDMG-cpp/metaDMG-cpp lca -bam cv28.all_sorted.sam.gz -outnames data/tmp/cv28/cv28 -names /bettik/lel047/data/taxonomy/names.dmp -nodes /bettik/lel047/data/taxonomy/nodes.dmp -acc2tax /bettik/lel047/data/KapCop/combined_taxid_accssionNO_20223103 -simscorelow 0.95 -simscorehigh 1.0 -minmapq 0 -howmany 15 -weighttype 1 -fix_ncbi 1 -tempfolder data/tmp/cv28/
salanova-elliott commented 1 year ago

The cpp code was cloned on March 21, that seems to be the latest version?

The output of the command you provided is:

-> metaDMG version: 0.2-46-gedaf069 (htslib: 1.17) build(Mar 21 2023 16:20:29)

/bettik/lel047/src/metaDMG-cpp/metaDMG-cpp lca -bam cv28.all_sorted.sam.gz -outnames data/tmp/cv28/cv28 -names /bettik/lel047/data/taxonomy/names.dmp -nodes /bettik/lel047/data/taxonomy/nodes.dmp -acc2tax /bettik/lel047/data/KapCop/combined_taxid_accssionNO_20223103 -simscorelow 0.95 -simscorehigh 1.0 -minmapq 0 -howmany 15 -weighttype 1 -fix_ncbi 1 -tempfolder data/tmp/cv28/

-> Will output lca results in file:     'data/tmp/cv28/cv28.lca.gz'
-> [thread1] Will read header

metaDMG-cpp: ngsLCA_cli.cpp:268: pars* get_pars(int, char**): Assertion `p->fp1' failed. Aborted

genomewalker commented 1 year ago

Looks like something is wrong with the SAM file. Pinging @ANGSD on this

ANGSD commented 1 year ago

Sorry for joining so late. The output information is not as helpful as it could be. It has problems opening the file: data/tmp/cv28/cv28.lca.gz. Do you know if the subfolder data/tmp/cv28 exists?

vincentvendius commented 1 year ago

I don't know if this will help, but you can create a functioning metaDMG environment using this environment.yaml configuration:

name: metaDMG channels:

salanova-elliott commented 1 year ago

Apologies for the delayed response.

@ANGSD the subfolders do exist

@vincentvendius Thanks for the environment.yaml, I can get everything to build fine using the metaDMG.cpp I built previously. It's still running into an unspecified error when using this environment though (although at a much earlier point than previous). Here's from the log file:

[2023-05-31 11:26:02] | root:185 | DEBUG | _____New log started__ [2023-05-31 11:26:02] | root:186 | DEBUG | Log config file: /home/lel047/.conda/envs/metaDMG/lib/python3.9/site-packages/metaDMG/loggers/log_config.yaml [2023-05-31 11:26:02] | root:153 | DEBUG | Logging server started! [2023-05-31 11:26:02] | metaDMG.loggers.loggers:40 | DEBUG | Running metaDMG version 0.38.0. [2023-05-31 11:26:02] | metaDMG.loggers.loggers:41 | DEBUG | Using port 61834 for logging. [2023-05-31 11:26:02] | metaDMG.utils:160 | INFO | Using config.yaml as config file. [2023-05-31 11:26:02] | metaDMG.fit.workflow:27 | INFO | Running metaDMG on 1 files in total. [2023-05-31 11:26:02] | metaDMG.fit.workflow:34 | INFO | Running the samples in serial (sequentially), each using 1 core(s). [2023-05-31 11:26:02] | metaDMG.fit.serial:290 | INFO | cv28 | Getting LCA. [2023-05-31 11:26:02] | metaDMG.fit.serial:310 | INFO | cv28 | LCA has to be computed. This can take a while, please wait. [2023-05-31 11:26:02] | metaDMG.fit.serial:317 | DEBUG | cv28 | /bettik/lel047/src/metaDMG-cpp/metaDMG.cpp lca -bam cv28.all_sorted.sam.gz -outnames data/tmp/cv28/cv28 -names /bettik/lel047/taxonomy/names.dmp -nodes /bettik/lel047/taxonomy/nodes.dmp -acc2tax combined_taxid_accssionNO_20223103 -simscorelow 0.95 -simscorehigh 1.0 -minmapq 0 -howmany 15 -weighttype 1 -fix_ncbi 0 -tempfolder data/tmp/cv28/ [2023-05-31 11:26:02] | metaDMG.fit.workflow:50 | ERROR | 1 error(s) occurred during the computation.

cwanket commented 1 year ago

@salanova-elliott did you find a solution to the last error message? I am running into the same problem currently and the log file is not very helpful.

salanova-elliott commented 1 year ago

I have unfortunately not found a solution, but I haven't been troubleshooting since June. I just went back to mapDamage instead

ksavhughes commented 1 week ago

Hi @salanova-elliott I think I might have a suggestion for how to solve this!

I think it is an issue with the metaDMG-ccp build. I'll just share what worked for me and hope it helps you.

I followed these instructions for the metaDMG-ccp build instead (https://github.com/miwipe/metaDMG_installation) and the compute command worked for me. I was having the same error: [2024-11-15 12:59:14] | root:237 | ERROR | alignment | metadamageError with run_LCA. See log-file for more information.