KeyError: 'loggers'

[salanova-elliott]

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/log__2023-03-22__09-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/log__2023-03-22__09-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/log__2023-03-22__09-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]

I get the same issue

[genomewalker]

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]

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]

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]

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]

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

[ANGSD]

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]

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

name: metaDMG
channels:

• conda-forge
• bioconda
• defaults
  dependencies:
• python==3.9
• pip
• pip:
  • metaDMG[all]
  • logger-tt==1.7.0
• htslib==1.15
• cxx-compiler
• c-compiler
• eigen
• gcc_linux-64
• samtools

[salanova-elliott]

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]

@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]

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

[ksavhughes]

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.