Using the logger

EMD has a built in logger which can be tuned to print out the progress of an analysis to the console, to a file or both.

Logger Basics

The logger must be initialised by calling emd.logger.set_up. All subsequent calls to functions in the EMD library will then print output messages according to the logger specification.

# sphinx_gallery_thumbnail_path = '_static/emd_logger_thumb.png'

# Import numpy for later
import numpy as np

# Import EMD and initialise the logger
import emd
emd.logger.set_up()

Out:

EMD Logger Started

The detail of logger output can be tuned by changing the logger level. The available levels are CRITICAL (only print output when the program is about to crash), WARNING (only print output when something unusual is happening or an analysis is potentially wrong), INFO (print general statements about which processes are running) and DEBUG (print loads of info including details of computations).

The default level is INFO, so if we re-initialise the logger on DEBUG we get more detailed outputs

emd.logger.set_up(level='DEBUG')

Out:

EMD Logger Started
EMD logger: handler 'console' level set to 'DEBUG'
EMD v0.3.2 installed in /home/docs/checkouts/readthedocs.org/user_builds/emd/envs/v0.3.2/lib/python3.7/site-packages/emd-0.3.2-py3.7.egg/emd

Lets explore the logger by running some a few sifts. Here we create a simple simulated oscillation and run a standard sift with default options.

# Initialise the logger with default settings (level=INFO)
emd.logger.set_up()

# Generate a simulation
peak_freq = 12
sample_rate = 512
seconds = 60
noise_std = .5
x = emd.utils.ar_simulate(peak_freq, sample_rate, seconds, noise_std=noise_std, random_seed=42, r=.99)

# Run a standard sift
imf = emd.sift.sift(x)

Out:

EMD Logger Started
STARTED: sift
COMPLETED: sift

With the level on INFO the logger tells us that the sift is running but not much else. If we change the logger level to DEBUG we get more output about how the sift is performing.

The level of an initialised logger can be changed using emd.logger.set_level.

emd.logger.set_level('DEBUG')

# Run a standard sift
imf = emd.sift.sift(x)

Out:

EMD logger: handler 'console' level set to 'DEBUG'
STARTED: sift
Input data size: 30720
Input Sift Args: {}
Sift stopped by SD-thresh in 2 iters with sd 0.05664176704990448
Sift stopped by SD-thresh in 5 iters with sd 0.06283402907052435
Sift stopped by SD-thresh in 2 iters with sd 0.048927574345043905
Sift stopped by SD-thresh in 2 iters with sd 0.01231149885729101
Sift stopped by SD-thresh in 2 iters with sd 0.030758751114656337
Sift stopped by SD-thresh in 2 iters with sd 0.027676835649722117
Sift stopped by SD-thresh in 2 iters with sd 0.08732602958363617
Sift stopped by SD-thresh in 2 iters with sd 0.030741108906213382
Sift stopped by SD-thresh in 2 iters with sd 0.04525277817295578
Sift stopped by SD-thresh in 3 iters with sd 0.010923938943932562
Finishing sift: IMF has no extrema
Returning 11 imfs
COMPLETED: sift

If we don’t want to change the logger level for our whole script, some functions allow us to override the logger level for a single call to the function.

Any functions with the verbose option in ‘Other Parameters’ can override the logger level. Here we run a sift on WARNING and should see no outputs.

imf = emd.sift.sift(x, verbose='WARNING')

We can also disable the logger altogether for a section of code using emd.logger.disable and then restart it using emd.logger.enable.

Here we disable logging for a sift call and renable it afterwards.

emd.logger.disable()
imf = emd.sift.sift(x)
emd.logger.enable()

Out:

EMD logging disabled
EMD logging enabled

Advanced Logging

This section contains some logger optionality for more advanced use cases.

Firstly, we can supplement the EMD logger output from a script by loading the EMD logger into a script and adding our own logger calls. In this example, we load the logger and add some custom updates. To print some output at the INFO level through the logger, we call logger.info.

# Initialised EMD logger
emd.logger.set_up(level='DEBUG')

# Load logger into this script
import logging
logger = logging.getLogger('emd')

# Check the time
import time
tic = time.perf_counter()

# Run a sift
logger.info('Now starting my new analysis')
imf = emd.sift.sift(x)

# Check time again
toc = time.perf_counter()

# Print sift run-time
elapsed = toc - tic
logger.info('My new analysis finished in {0:4f} seconds'.format(elapsed))

Out:

EMD Logger Started
EMD logger: handler 'console' level set to 'DEBUG'
EMD v0.3.2 installed in /home/docs/checkouts/readthedocs.org/user_builds/emd/envs/v0.3.2/lib/python3.7/site-packages/emd-0.3.2-py3.7.egg/emd
Now starting my new analysis
STARTED: sift
Input data size: 30720
Input Sift Args: {}
Sift stopped by SD-thresh in 2 iters with sd 0.05664176704990448
Sift stopped by SD-thresh in 5 iters with sd 0.06283402907052435
Sift stopped by SD-thresh in 2 iters with sd 0.048927574345043905
Sift stopped by SD-thresh in 2 iters with sd 0.01231149885729101
Sift stopped by SD-thresh in 2 iters with sd 0.030758751114656337
Sift stopped by SD-thresh in 2 iters with sd 0.027676835649722117
Sift stopped by SD-thresh in 2 iters with sd 0.08732602958363617
Sift stopped by SD-thresh in 2 iters with sd 0.030741108906213382
Sift stopped by SD-thresh in 2 iters with sd 0.04525277817295578
Sift stopped by SD-thresh in 3 iters with sd 0.010923938943932562
Finishing sift: IMF has no extrema
Returning 11 imfs
COMPLETED: sift
My new analysis finished in 0.216711 seconds

This output respects the overall logger level, so info statements will be printed at levels INFO and DEBUG but suppressed if the overall logger level is at WARNING or CRITICAL.

Try changing the logger level in the example above to see the effect on the following output.

Next, we define an analysis function which runs a sift followed by a frequency transform and simple cycle analysis. We’ll run this example a few times in the next sections.

Note that we’ve included some custom logger calls and a temporary logger override on the mask_sift

def my_analysis(x):

    # Check time, and load the logger into the session
    tic = time.perf_counter()
    import logging
    logger = logging.getLogger('emd')

    # Print start-up message
    logger.info('Starting my example analysis')
    logger.info('----------------------------')

    # Run a mask-sift with detailed logging
    imf = emd.sift.mask_sift(x, verbose='DEBUG')

    # Compute frequency stats
    IP, IF, IA = emd.spectra.frequency_transform(imf, sample_rate, 'nht')
    logger.info('Avg frequency of IMF-2 is {0:2f}Hz'.format(np.average(IF[:, 2], weights=IA[:, 2])))

    # Find cycles in IMF-2
    mask = IA[:, 2] > .05
    cycles = emd.cycles.get_cycle_inds(IP, return_good=True, mask=mask)

    # Compute cycle stats
    cycle_freq = emd.cycles.get_cycle_stat(cycles[:, 2], IF[:, 2], mode='compressed', func=np.mean)[1:]
    cycle_freq_std = emd.cycles.get_cycle_stat(cycles[:, 2], IF[:, 2], mode='compressed', func=np.std)[1:]
    cycle_amp = emd.cycles.get_cycle_stat(cycles[:, 2], IA[:, 2], mode='compressed', func=np.mean)[1:]

    # Print some cycle correlations
    logger.info('Freq-Amp correlation: r={0:2f}'.format(np.corrcoef(cycle_freq, cycle_amp)[0, 1]))
    logger.info('Amp-FreqStd correlation: r={0:2f}'.format(np.corrcoef(cycle_freq, cycle_freq_std)[0, 1]))

    # Print the elapsed time of the analysis
    toc = time.perf_counter()
    elapsed = toc - tic
    logger.info('My new analysis finished in {0:4f} seconds'.format(elapsed))

    return cycle_freq, cycle_amp

We can run this function as normal and inspect the logger outputs as they appear in the console.

# Run the analysis
freq, amp = my_analysis(x)

Out:

Starting my example analysis
----------------------------
EMD logger: handler 'console' level set to 'DEBUG'
STARTED: mask_sift
Input data size: 30720
Input Sift Args: {'verbose': 'DEBUG'}
Computing first mask frequency with method zc
Getting first IMF with no mask
Sift stopped by SD-thresh in 2 iters with sd 0.05664176704990448
Found first mask frequency of 0.1708251953125
Sifting IMF-0
Defining masks with freq 0.1708251953125 and amp 8485.836434524743 at 4 phases
Sifting IMF-1
Defining masks with freq 0.08541259765625 and amp 3556.224118915407 at 4 phases
Sifting IMF-2
Defining masks with freq 0.042706298828125 and amp 1608.2616300332552 at 4 phases
Sifting IMF-3
Defining masks with freq 0.0213531494140625 and amp 7517.928089072154 at 4 phases
Sifting IMF-4
Defining masks with freq 0.01067657470703125 and amp 461.363440642795 at 4 phases
Sifting IMF-5
Defining masks with freq 0.005338287353515625 and amp 573.1334896292291 at 4 phases
Sifting IMF-6
Defining masks with freq 0.0026691436767578127 and amp 284.1455818020958 at 4 phases
Sifting IMF-7
Defining masks with freq 0.0013345718383789063 and amp 243.86432091314475 at 4 phases
Sifting IMF-8
Defining masks with freq 0.0006672859191894532 and amp 128.0235576653978 at 4 phases
Finishing sift: reached max number of imfs (9)
Returning 9 imfs
COMPLETED: mask_sift
EMD logger: handler 'console' level set to 'DEBUG'
STARTED: compute frequency stats
computing on 30720 samples over 9 imfs at sample rate 512
Using Amplitude-Normalised Hilbert transform
STARTED: Amplitude-Normalise
Normalising 30720 samples across 9 IMFs
Using pchip interpolation with threshold of 1e-10 and max_iters 3
Normalise of IMF-2-0 complete in 3 iters (val=0.0)
Normalise of IMF-4-0 complete in 3 iters (val=0.0)
Normalise of IMF-5-0 complete in 3 iters (val=0.0)
Normalise of IMF-6-0 complete in 3 iters (val=0.0)
Normalise of IMF-7-0 complete in 3 iters (val=0.0)
Normalise of IMF-8-0 complete in 3 iters (val=0.0)
COMPLETED: Amplitude-Normalise
COMPLETED: compute frequency stats. Returning 9 imfs
Avg frequency of IMF-2 is 11.973992Hz
STARTED: get cycle indices
Checking get_cycle_inds inputs - Adding dummy dimension to input 'mask'
computing on 30720 samples over 9 IMFs
30325 (98.71%) samples masked out
found 131 cycles in IMF-0
found 446 cycles in IMF-1
found 696 cycles in IMF-2
found 355 cycles in IMF-3
found 215 cycles in IMF-4
found 106 cycles in IMF-5
found 44 cycles in IMF-6
found 20 cycles in IMF-7
found 3 cycles in IMF-8
COMPLETED: get cycle indices
STARTED: get cycle stats
computing stats for 696 cycles over 30720 samples
computing metric <function mean at 0x7fb611cdc050> and returning compressed-array
COMPLETED: get cycle stats
STARTED: get cycle stats
computing stats for 696 cycles over 30720 samples
computing metric <function std at 0x7fb611cdc290> and returning compressed-array
COMPLETED: get cycle stats
STARTED: get cycle stats
computing stats for 696 cycles over 30720 samples
computing metric <function mean at 0x7fb611cdc050> and returning compressed-array
COMPLETED: get cycle stats
Freq-Amp correlation: r=-0.365759
Amp-FreqStd correlation: r=0.575526
My new analysis finished in 2.028716 seconds

We can see a lot of information about which processes were running as the logger is set to INFO. If we configure the logger to run on WARNING level, we should only see output about potential errors. This can be useful when running familiar code where you only need output when something potentially strange is going on.

So in this case, after changing to WARNING we should only see output from the mask_sift call (as this has a logger override to DEBUG). All other output is suppressed.

# Change logger level
emd.logger.set_level('WARNING')

# Run the analysis
freq, amp = my_analysis(x)

Out:

STARTED: mask_sift
Input data size: 30720
Input Sift Args: {'verbose': 'DEBUG'}
Computing first mask frequency with method zc
Getting first IMF with no mask
Sift stopped by SD-thresh in 2 iters with sd 0.05664176704990448
Found first mask frequency of 0.1708251953125
Sifting IMF-0
Defining masks with freq 0.1708251953125 and amp 8485.836434524743 at 4 phases
Sifting IMF-1
Defining masks with freq 0.08541259765625 and amp 3556.224118915407 at 4 phases
Sifting IMF-2
Defining masks with freq 0.042706298828125 and amp 1608.2616300332552 at 4 phases
Sifting IMF-3
Defining masks with freq 0.0213531494140625 and amp 7517.928089072154 at 4 phases
Sifting IMF-4
Defining masks with freq 0.01067657470703125 and amp 461.363440642795 at 4 phases
Sifting IMF-5
Defining masks with freq 0.005338287353515625 and amp 573.1334896292291 at 4 phases
Sifting IMF-6
Defining masks with freq 0.0026691436767578127 and amp 284.1455818020958 at 4 phases
Sifting IMF-7
Defining masks with freq 0.0013345718383789063 and amp 243.86432091314475 at 4 phases
Sifting IMF-8
Defining masks with freq 0.0006672859191894532 and amp 128.0235576653978 at 4 phases
Finishing sift: reached max number of imfs (9)
Returning 9 imfs
COMPLETED: mask_sift

If we’re dealing with logger output from multiple sources or perhaps from multiple analyses running in parallel, then we can add a prefix to the logger to help distinguish the output coming from each. This can be specified when initialising the logger.

For example, here we reun the analysis function with a logger prefix indicating that we’re processing Subject 001.

# Initialise logger with a prefix
emd.logger.set_up(level='DEBUG', prefix='Subj001')

# Run the analysis
freq, amp = my_analysis(x)

Out:

Subj001 EMD Logger Started
Subj001 EMD logger: handler 'console' level set to 'DEBUG'
Subj001 EMD v0.3.2 installed in /home/docs/checkouts/readthedocs.org/user_builds/emd/envs/v0.3.2/lib/python3.7/site-packages/emd-0.3.2-py3.7.egg/emd
Subj001 Starting my example analysis
Subj001 ----------------------------
Subj001 EMD logger: handler 'console' level set to 'DEBUG'
Subj001 STARTED: mask_sift
Subj001 Input data size: 30720
Subj001 Input Sift Args: {'verbose': 'DEBUG'}
Subj001 Computing first mask frequency with method zc
Subj001 Getting first IMF with no mask
Subj001 Sift stopped by SD-thresh in 2 iters with sd 0.05664176704990448
Subj001 Found first mask frequency of 0.1708251953125
Subj001 Sifting IMF-0
Subj001 Defining masks with freq 0.1708251953125 and amp 8485.836434524743 at 4 phases
Subj001 Sifting IMF-1
Subj001 Defining masks with freq 0.08541259765625 and amp 3556.224118915407 at 4 phases
Subj001 Sifting IMF-2
Subj001 Defining masks with freq 0.042706298828125 and amp 1608.2616300332552 at 4 phases
Subj001 Sifting IMF-3
Subj001 Defining masks with freq 0.0213531494140625 and amp 7517.928089072154 at 4 phases
Subj001 Sifting IMF-4
Subj001 Defining masks with freq 0.01067657470703125 and amp 461.363440642795 at 4 phases
Subj001 Sifting IMF-5
Subj001 Defining masks with freq 0.005338287353515625 and amp 573.1334896292291 at 4 phases
Subj001 Sifting IMF-6
Subj001 Defining masks with freq 0.0026691436767578127 and amp 284.1455818020958 at 4 phases
Subj001 Sifting IMF-7
Subj001 Defining masks with freq 0.0013345718383789063 and amp 243.86432091314475 at 4 phases
Subj001 Sifting IMF-8
Subj001 Defining masks with freq 0.0006672859191894532 and amp 128.0235576653978 at 4 phases
Subj001 Finishing sift: reached max number of imfs (9)
Subj001 Returning 9 imfs
Subj001 COMPLETED: mask_sift
Subj001 EMD logger: handler 'console' level set to 'DEBUG'
Subj001 STARTED: compute frequency stats
Subj001 computing on 30720 samples over 9 imfs at sample rate 512
Subj001 Using Amplitude-Normalised Hilbert transform
Subj001 STARTED: Amplitude-Normalise
Subj001 Normalising 30720 samples across 9 IMFs
Subj001 Using pchip interpolation with threshold of 1e-10 and max_iters 3
Subj001 Normalise of IMF-2-0 complete in 3 iters (val=0.0)
Subj001 Normalise of IMF-4-0 complete in 3 iters (val=0.0)
Subj001 Normalise of IMF-5-0 complete in 3 iters (val=0.0)
Subj001 Normalise of IMF-6-0 complete in 3 iters (val=0.0)
Subj001 Normalise of IMF-7-0 complete in 3 iters (val=0.0)
Subj001 Normalise of IMF-8-0 complete in 3 iters (val=0.0)
Subj001 COMPLETED: Amplitude-Normalise
Subj001 COMPLETED: compute frequency stats. Returning 9 imfs
Subj001 Avg frequency of IMF-2 is 11.973992Hz
Subj001 STARTED: get cycle indices
Subj001 Checking get_cycle_inds inputs - Adding dummy dimension to input 'mask'
Subj001 computing on 30720 samples over 9 IMFs
Subj001 30325 (98.71%) samples masked out
Subj001 found 131 cycles in IMF-0
Subj001 found 446 cycles in IMF-1
Subj001 found 696 cycles in IMF-2
Subj001 found 355 cycles in IMF-3
Subj001 found 215 cycles in IMF-4
Subj001 found 106 cycles in IMF-5
Subj001 found 44 cycles in IMF-6
Subj001 found 20 cycles in IMF-7
Subj001 found 3 cycles in IMF-8
Subj001 COMPLETED: get cycle indices
Subj001 STARTED: get cycle stats
Subj001 computing stats for 696 cycles over 30720 samples
Subj001 computing metric <function mean at 0x7fb611cdc050> and returning compressed-array
Subj001 COMPLETED: get cycle stats
Subj001 STARTED: get cycle stats
Subj001 computing stats for 696 cycles over 30720 samples
Subj001 computing metric <function std at 0x7fb611cdc290> and returning compressed-array
Subj001 COMPLETED: get cycle stats
Subj001 STARTED: get cycle stats
Subj001 computing stats for 696 cycles over 30720 samples
Subj001 computing metric <function mean at 0x7fb611cdc050> and returning compressed-array
Subj001 COMPLETED: get cycle stats
Subj001 Freq-Amp correlation: r=-0.365759
Subj001 Amp-FreqStd correlation: r=0.575526
Subj001 My new analysis finished in 2.047723 seconds

Finally, we can direct the logger output into a text file as well as the console.

# Define a temporary file
import tempfile
log_file = tempfile.NamedTemporaryFile(prefix="ExampleEMDLog", suffix='.log').name
# OR uncomment this line and define your own filepath
# log_file = /path/to/my/log_file.log

# Initialise the logger with a prefix and a text file
emd.logger.set_up(level='INFO', prefix='Subj001', log_file=log_file)

# Run the analysis
freq, amp = my_analysis(x)

Out:

Subj001 EMD Logger Started
Subj001 EMD logger: handler 'console' level set to 'INFO'
Subj001 logging to file: /tmp/ExampleEMDLogz_kirdqu.log
Subj001 Starting my example analysis
Subj001 ----------------------------
Subj001 EMD logger: handler 'console' level set to 'DEBUG'
Subj001 STARTED: mask_sift
Subj001 Input data size: 30720
Subj001 Input Sift Args: {'verbose': 'DEBUG'}
Subj001 Computing first mask frequency with method zc
Subj001 Getting first IMF with no mask
Subj001 Sift stopped by SD-thresh in 2 iters with sd 0.05664176704990448
Subj001 Found first mask frequency of 0.1708251953125
Subj001 Sifting IMF-0
Subj001 Defining masks with freq 0.1708251953125 and amp 8485.836434524743 at 4 phases
Subj001 Sifting IMF-1
Subj001 Defining masks with freq 0.08541259765625 and amp 3556.224118915407 at 4 phases
Subj001 Sifting IMF-2
Subj001 Defining masks with freq 0.042706298828125 and amp 1608.2616300332552 at 4 phases
Subj001 Sifting IMF-3
Subj001 Defining masks with freq 0.0213531494140625 and amp 7517.928089072154 at 4 phases
Subj001 Sifting IMF-4
Subj001 Defining masks with freq 0.01067657470703125 and amp 461.363440642795 at 4 phases
Subj001 Sifting IMF-5
Subj001 Defining masks with freq 0.005338287353515625 and amp 573.1334896292291 at 4 phases
Subj001 Sifting IMF-6
Subj001 Defining masks with freq 0.0026691436767578127 and amp 284.1455818020958 at 4 phases
Subj001 Sifting IMF-7
Subj001 Defining masks with freq 0.0013345718383789063 and amp 243.86432091314475 at 4 phases
Subj001 Sifting IMF-8
Subj001 Defining masks with freq 0.0006672859191894532 and amp 128.0235576653978 at 4 phases
Subj001 Finishing sift: reached max number of imfs (9)
Subj001 Returning 9 imfs
Subj001 COMPLETED: mask_sift
Subj001 EMD logger: handler 'console' level set to 'INFO'
Subj001 STARTED: compute frequency stats
Subj001 Using Amplitude-Normalised Hilbert transform
Subj001 STARTED: Amplitude-Normalise
Subj001 Normalise of IMF-2-0 complete in 3 iters (val=0.0)
Subj001 Normalise of IMF-4-0 complete in 3 iters (val=0.0)
Subj001 Normalise of IMF-5-0 complete in 3 iters (val=0.0)
Subj001 Normalise of IMF-6-0 complete in 3 iters (val=0.0)
Subj001 Normalise of IMF-7-0 complete in 3 iters (val=0.0)
Subj001 Normalise of IMF-8-0 complete in 3 iters (val=0.0)
Subj001 COMPLETED: Amplitude-Normalise
Subj001 COMPLETED: compute frequency stats. Returning 9 imfs
Subj001 Avg frequency of IMF-2 is 11.973992Hz
Subj001 STARTED: get cycle indices
Subj001 found 131 cycles in IMF-0
Subj001 found 446 cycles in IMF-1
Subj001 found 696 cycles in IMF-2
Subj001 found 355 cycles in IMF-3
Subj001 found 215 cycles in IMF-4
Subj001 found 106 cycles in IMF-5
Subj001 found 44 cycles in IMF-6
Subj001 found 20 cycles in IMF-7
Subj001 found 3 cycles in IMF-8
Subj001 COMPLETED: get cycle indices
Subj001 STARTED: get cycle stats
Subj001 COMPLETED: get cycle stats
Subj001 STARTED: get cycle stats
Subj001 COMPLETED: get cycle stats
Subj001 STARTED: get cycle stats
Subj001 COMPLETED: get cycle stats
Subj001 Freq-Amp correlation: r=-0.365759
Subj001 Amp-FreqStd correlation: r=0.575526
Subj001 My new analysis finished in 2.044189 seconds

The log file is a simple text file containing very detailed outputs of which functions were executed and when. Here we read the log file and print its contents to the console.

Note that the log file contains a much more detailed output that the console!

# Open the text file and print its contents
with open(log_file, 'r') as f:
    txt = f.read()
print(txt)

Out:

[2020-12-09 23:35:08] Subj001 - INFO - emd.logger:83 -               set_up() : EMD Logger Started
[2020-12-09 23:35:08] Subj001 - INFO - emd.logger:104 -            set_level() : EMD logger: handler 'console' level set to 'INFO'
[2020-12-09 23:35:08] Subj001 - INFO - emd.logger:93 -               set_up() : logging to file: /tmp/ExampleEMDLogz_kirdqu.log
[2020-12-09 23:35:08] Subj001 - DEBUG - emd.logger:95 -               set_up() : EMD v0.3.2 installed in /home/docs/checkouts/readthedocs.org/user_builds/emd/envs/v0.3.2/lib/python3.7/site-packages/emd-0.3.2-py3.7.egg/emd
[2020-12-09 23:35:08] Subj001 - INFO - emd.emd_tutorial_04_utils_02_logger:149 -          my_analysis() : Starting my example analysis
[2020-12-09 23:35:08] Subj001 - INFO - emd.emd_tutorial_04_utils_02_logger:150 -          my_analysis() : ----------------------------
[2020-12-09 23:35:08] Subj001 - INFO - emd.logger:104 -            set_level() : EMD logger: handler 'console' level set to 'DEBUG'
[2020-12-09 23:35:08] Subj001 - INFO - emd.logger:169 -          sift_logger() : STARTED: mask_sift
[2020-12-09 23:35:08] Subj001 - DEBUG - emd.logger:180 -          sift_logger() : Input data size: 30720
[2020-12-09 23:35:08] Subj001 - DEBUG - emd.logger:183 -          sift_logger() : Input Sift Args: {'verbose': 'DEBUG'}
[2020-12-09 23:35:08] Subj001 - INFO - emd.sift:701 -       get_mask_freqs() : Computing first mask frequency with method zc
[2020-12-09 23:35:08] Subj001 - INFO - emd.sift:702 -       get_mask_freqs() : Getting first IMF with no mask
[2020-12-09 23:35:08] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.05664176704990448
[2020-12-09 23:35:08] Subj001 - INFO - emd.sift:710 -       get_mask_freqs() : Found first mask frequency of 0.1708251953125
[2020-12-09 23:35:08] Subj001 - INFO - emd.sift:861 -            mask_sift() : Sifting IMF-0
[2020-12-09 23:35:08] Subj001 - INFO - emd.sift:668 -    get_next_imf_mask() : Defining masks with freq 0.1708251953125 and amp 8485.836434524743 at 4 phases
[2020-12-09 23:35:08] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.051433553727880464
[2020-12-09 23:35:08] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.05282331480228545
[2020-12-09 23:35:08] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.05145257832747228
[2020-12-09 23:35:08] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.05056821228948898
[2020-12-09 23:35:08] Subj001 - INFO - emd.sift:861 -            mask_sift() : Sifting IMF-1
[2020-12-09 23:35:08] Subj001 - INFO - emd.sift:668 -    get_next_imf_mask() : Defining masks with freq 0.08541259765625 and amp 3556.224118915407 at 4 phases
[2020-12-09 23:35:08] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 4 iters with sd 0.04071573272177828
[2020-12-09 23:35:08] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 4 iters with sd 0.027414108167777628
[2020-12-09 23:35:08] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 4 iters with sd 0.09782533912260609
[2020-12-09 23:35:08] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 4 iters with sd 0.09501807150854386
[2020-12-09 23:35:08] Subj001 - INFO - emd.sift:861 -            mask_sift() : Sifting IMF-2
[2020-12-09 23:35:08] Subj001 - INFO - emd.sift:668 -    get_next_imf_mask() : Defining masks with freq 0.042706298828125 and amp 1608.2616300332552 at 4 phases
[2020-12-09 23:35:08] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 1 iters with sd 0.04018680535704688
[2020-12-09 23:35:08] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 1 iters with sd 0.037274049627270975
[2020-12-09 23:35:08] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 1 iters with sd 0.04313593273634201
[2020-12-09 23:35:08] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 1 iters with sd 0.04044484549779488
[2020-12-09 23:35:08] Subj001 - INFO - emd.sift:861 -            mask_sift() : Sifting IMF-3
[2020-12-09 23:35:08] Subj001 - INFO - emd.sift:668 -    get_next_imf_mask() : Defining masks with freq 0.0213531494140625 and amp 7517.928089072154 at 4 phases
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 1 iters with sd 0.02311449826816189
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 1 iters with sd 0.023270781644301717
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 1 iters with sd 0.023279133074431444
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 1 iters with sd 0.023200937911373717
[2020-12-09 23:35:09] Subj001 - INFO - emd.sift:861 -            mask_sift() : Sifting IMF-4
[2020-12-09 23:35:09] Subj001 - INFO - emd.sift:668 -    get_next_imf_mask() : Defining masks with freq 0.01067657470703125 and amp 461.363440642795 at 4 phases
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.029257566065274177
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.04515429323094207
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.036136462626618
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.038056695560170335
[2020-12-09 23:35:09] Subj001 - INFO - emd.sift:861 -            mask_sift() : Sifting IMF-5
[2020-12-09 23:35:09] Subj001 - INFO - emd.sift:668 -    get_next_imf_mask() : Defining masks with freq 0.005338287353515625 and amp 573.1334896292291 at 4 phases
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.01146450751823223
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.012545965410550499
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.014488330671354672
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.011308775737486567
[2020-12-09 23:35:09] Subj001 - INFO - emd.sift:861 -            mask_sift() : Sifting IMF-6
[2020-12-09 23:35:09] Subj001 - INFO - emd.sift:668 -    get_next_imf_mask() : Defining masks with freq 0.0026691436767578127 and amp 284.1455818020958 at 4 phases
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.015014045862336673
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.07582910915852298
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.035701615426124336
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.04259998659959668
[2020-12-09 23:35:09] Subj001 - INFO - emd.sift:861 -            mask_sift() : Sifting IMF-7
[2020-12-09 23:35:09] Subj001 - INFO - emd.sift:668 -    get_next_imf_mask() : Defining masks with freq 0.0013345718383789063 and amp 243.86432091314475 at 4 phases
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 3 iters with sd 0.010299195834260194
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.011260012469416322
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.028417952274682298
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.01063480894017288
[2020-12-09 23:35:09] Subj001 - INFO - emd.sift:861 -            mask_sift() : Sifting IMF-8
[2020-12-09 23:35:09] Subj001 - INFO - emd.sift:668 -    get_next_imf_mask() : Defining masks with freq 0.0006672859191894532 and amp 128.0235576653978 at 4 phases
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.014397097059087798
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.04601395027273485
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.033646337957216305
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.03538460389625099
[2020-12-09 23:35:09] Subj001 - INFO - emd.sift:878 -            mask_sift() : Finishing sift: reached max number of imfs (9)
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.logger:191 -          sift_logger() : Returning 9 imfs
[2020-12-09 23:35:09] Subj001 - INFO - emd.logger:196 -          sift_logger() : COMPLETED: mask_sift
[2020-12-09 23:35:09] Subj001 - INFO - emd.logger:104 -            set_level() : EMD logger: handler 'console' level set to 'INFO'
[2020-12-09 23:35:09] Subj001 - INFO - emd.spectra:90 -  frequency_transform() : STARTED: compute frequency stats
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.spectra:95 -  frequency_transform() : computing on 30720 samples over 9 imfs at sample rate 512
[2020-12-09 23:35:09] Subj001 - INFO - emd.spectra:108 -  frequency_transform() : Using Amplitude-Normalised Hilbert transform
[2020-12-09 23:35:09] Subj001 - INFO - emd.utils:66 -  amplitude_normalise() : STARTED: Amplitude-Normalise
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.utils:69 -  amplitude_normalise() : Normalising 30720 samples across 9 IMFs
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.utils:74 -  amplitude_normalise() : Using pchip interpolation with threshold of 1e-10 and max_iters 3
[2020-12-09 23:35:09] Subj001 - INFO - emd.utils:113 -  amplitude_normalise() : Normalise of IMF-2-0 complete in 3 iters (val=0.0)
[2020-12-09 23:35:09] Subj001 - INFO - emd.utils:113 -  amplitude_normalise() : Normalise of IMF-4-0 complete in 3 iters (val=0.0)
[2020-12-09 23:35:09] Subj001 - INFO - emd.utils:113 -  amplitude_normalise() : Normalise of IMF-5-0 complete in 3 iters (val=0.0)
[2020-12-09 23:35:09] Subj001 - INFO - emd.utils:113 -  amplitude_normalise() : Normalise of IMF-6-0 complete in 3 iters (val=0.0)
[2020-12-09 23:35:09] Subj001 - INFO - emd.utils:113 -  amplitude_normalise() : Normalise of IMF-7-0 complete in 3 iters (val=0.0)
[2020-12-09 23:35:09] Subj001 - INFO - emd.utils:113 -  amplitude_normalise() : Normalise of IMF-8-0 complete in 3 iters (val=0.0)
[2020-12-09 23:35:09] Subj001 - INFO - emd.utils:123 -  amplitude_normalise() : COMPLETED: Amplitude-Normalise
[2020-12-09 23:35:09] Subj001 - INFO - emd.spectra:168 -  frequency_transform() : COMPLETED: compute frequency stats. Returning 9 imfs
[2020-12-09 23:35:09] Subj001 - INFO - emd.emd_tutorial_04_utils_02_logger:157 -          my_analysis() : Avg frequency of IMF-2 is 11.973992Hz
[2020-12-09 23:35:09] Subj001 - INFO - emd.cycles:231 -       get_cycle_inds() : STARTED: get cycle indices
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.support:227 -            ensure_2d() : Checking get_cycle_inds inputs - Adding dummy dimension to input 'mask'
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.cycles:239 -       get_cycle_inds() : computing on 30720 samples over 9 IMFs
[2020-12-09 23:35:09] Subj001 - DEBUG - emd.cycles:241 -       get_cycle_inds() : 30325 (98.71%) samples masked out
[2020-12-09 23:35:10] Subj001 - INFO - emd.cycles:322 -       get_cycle_inds() : found 131 cycles in IMF-0
[2020-12-09 23:35:10] Subj001 - INFO - emd.cycles:322 -       get_cycle_inds() : found 446 cycles in IMF-1
[2020-12-09 23:35:10] Subj001 - INFO - emd.cycles:322 -       get_cycle_inds() : found 696 cycles in IMF-2
[2020-12-09 23:35:10] Subj001 - INFO - emd.cycles:322 -       get_cycle_inds() : found 355 cycles in IMF-3
[2020-12-09 23:35:10] Subj001 - INFO - emd.cycles:322 -       get_cycle_inds() : found 215 cycles in IMF-4
[2020-12-09 23:35:10] Subj001 - INFO - emd.cycles:322 -       get_cycle_inds() : found 106 cycles in IMF-5
[2020-12-09 23:35:10] Subj001 - INFO - emd.cycles:322 -       get_cycle_inds() : found 44 cycles in IMF-6
[2020-12-09 23:35:10] Subj001 - INFO - emd.cycles:322 -       get_cycle_inds() : found 20 cycles in IMF-7
[2020-12-09 23:35:10] Subj001 - INFO - emd.cycles:322 -       get_cycle_inds() : found 3 cycles in IMF-8
[2020-12-09 23:35:10] Subj001 - INFO - emd.cycles:324 -       get_cycle_inds() : COMPLETED: get cycle indices
[2020-12-09 23:35:10] Subj001 - INFO - emd.cycles:355 -       get_cycle_stat() : STARTED: get cycle stats
[2020-12-09 23:35:10] Subj001 - DEBUG - emd.cycles:360 -       get_cycle_stat() : computing stats for 696 cycles over 30720 samples
[2020-12-09 23:35:10] Subj001 - DEBUG - emd.cycles:361 -       get_cycle_stat() : computing metric <function mean at 0x7fb611cdc050> and returning compressed-array
[2020-12-09 23:35:10] Subj001 - INFO - emd.cycles:385 -       get_cycle_stat() : COMPLETED: get cycle stats
[2020-12-09 23:35:10] Subj001 - INFO - emd.cycles:355 -       get_cycle_stat() : STARTED: get cycle stats
[2020-12-09 23:35:10] Subj001 - DEBUG - emd.cycles:360 -       get_cycle_stat() : computing stats for 696 cycles over 30720 samples
[2020-12-09 23:35:10] Subj001 - DEBUG - emd.cycles:361 -       get_cycle_stat() : computing metric <function std at 0x7fb611cdc290> and returning compressed-array
[2020-12-09 23:35:10] Subj001 - INFO - emd.cycles:385 -       get_cycle_stat() : COMPLETED: get cycle stats
[2020-12-09 23:35:10] Subj001 - INFO - emd.cycles:355 -       get_cycle_stat() : STARTED: get cycle stats
[2020-12-09 23:35:10] Subj001 - DEBUG - emd.cycles:360 -       get_cycle_stat() : computing stats for 696 cycles over 30720 samples
[2020-12-09 23:35:10] Subj001 - DEBUG - emd.cycles:361 -       get_cycle_stat() : computing metric <function mean at 0x7fb611cdc050> and returning compressed-array
[2020-12-09 23:35:10] Subj001 - INFO - emd.cycles:385 -       get_cycle_stat() : COMPLETED: get cycle stats
[2020-12-09 23:35:10] Subj001 - INFO - emd.emd_tutorial_04_utils_02_logger:169 -          my_analysis() : Freq-Amp correlation: r=-0.365759
[2020-12-09 23:35:10] Subj001 - INFO - emd.emd_tutorial_04_utils_02_logger:170 -          my_analysis() : Amp-FreqStd correlation: r=0.575526
[2020-12-09 23:35:10] Subj001 - INFO - emd.emd_tutorial_04_utils_02_logger:175 -          my_analysis() : My new analysis finished in 2.044189 seconds

If we want this extra detailed output in the console as well, we can specify the console_format when setting up the logger.

# Initialise logger with a verbose console format
emd.logger.set_up(level='DEBUG', prefix='Subj001', console_format='verbose')

# Run the analysis
freq, amp = my_analysis(x)

Out:

Subj001 EMD Logger Started
Subj001 EMD logger: handler 'console' level set to 'DEBUG'
[2020-12-09 23:35:10,453] Subj001 - INFO - emd.logger:129 -           set_format() : EMD logger: handler console format changed to verbose
[2020-12-09 23:35:10,456] Subj001 - DEBUG - emd.logger:95 -               set_up() : EMD v0.3.2 installed in /home/docs/checkouts/readthedocs.org/user_builds/emd/envs/v0.3.2/lib/python3.7/site-packages/emd-0.3.2-py3.7.egg/emd
[2020-12-09 23:35:10,456] Subj001 - INFO - emd.emd_tutorial_04_utils_02_logger:149 -          my_analysis() : Starting my example analysis
[2020-12-09 23:35:10,456] Subj001 - INFO - emd.emd_tutorial_04_utils_02_logger:150 -          my_analysis() : ----------------------------
[2020-12-09 23:35:10,456] Subj001 - INFO - emd.logger:104 -            set_level() : EMD logger: handler 'console' level set to 'DEBUG'
[2020-12-09 23:35:10,456] Subj001 - INFO - emd.logger:169 -          sift_logger() : STARTED: mask_sift
[2020-12-09 23:35:10,456] Subj001 - DEBUG - emd.logger:180 -          sift_logger() : Input data size: 30720
[2020-12-09 23:35:10,456] Subj001 - DEBUG - emd.logger:183 -          sift_logger() : Input Sift Args: {'verbose': 'DEBUG'}
[2020-12-09 23:35:10,456] Subj001 - INFO - emd.sift:701 -       get_mask_freqs() : Computing first mask frequency with method zc
[2020-12-09 23:35:10,457] Subj001 - INFO - emd.sift:702 -       get_mask_freqs() : Getting first IMF with no mask
[2020-12-09 23:35:10,486] Subj001 - DEBUG - emd.sift:193 -              sd_stop() : Sift stopped by SD-thresh in 2 iters with sd 0.05664176704990448
[2020-12-09 23:35:10,486] Subj001 - INFO - emd.sift:710 -       get_mask_freqs() : Found first mask frequency of 0.1708251953125
[2020-12-09 23:35:10,487] Subj001 - INFO - emd.sift:861 -            mask_sift() : Sifting IMF-0
[2020-12-09 23:35:10,487] Subj001 - INFO - emd.sift:668 -    get_next_imf_mask() : Defining masks with freq 0.1708251953125 and amp 8485.836434524743 at 4 phases
[2020-12-09 23:35:10,706] Subj001 - INFO - emd.sift:861 -            mask_sift() : Sifting IMF-1
[2020-12-09 23:35:10,706] Subj001 - INFO - emd.sift:668 -    get_next_imf_mask() : Defining masks with freq 0.08541259765625 and amp 3556.224118915407 at 4 phases
[2020-12-09 23:35:10,927] Subj001 - INFO - emd.sift:861 -            mask_sift() : Sifting IMF-2
[2020-12-09 23:35:10,928] Subj001 - INFO - emd.sift:668 -    get_next_imf_mask() : Defining masks with freq 0.042706298828125 and amp 1608.2616300332552 at 4 phases
[2020-12-09 23:35:11,049] Subj001 - INFO - emd.sift:861 -            mask_sift() : Sifting IMF-3
[2020-12-09 23:35:11,049] Subj001 - INFO - emd.sift:668 -    get_next_imf_mask() : Defining masks with freq 0.0213531494140625 and amp 7517.928089072154 at 4 phases
[2020-12-09 23:35:11,170] Subj001 - INFO - emd.sift:861 -            mask_sift() : Sifting IMF-4
[2020-12-09 23:35:11,171] Subj001 - INFO - emd.sift:668 -    get_next_imf_mask() : Defining masks with freq 0.01067657470703125 and amp 461.363440642795 at 4 phases
[2020-12-09 23:35:11,292] Subj001 - INFO - emd.sift:861 -            mask_sift() : Sifting IMF-5
[2020-12-09 23:35:11,292] Subj001 - INFO - emd.sift:668 -    get_next_imf_mask() : Defining masks with freq 0.005338287353515625 and amp 573.1334896292291 at 4 phases
[2020-12-09 23:35:11,414] Subj001 - INFO - emd.sift:861 -            mask_sift() : Sifting IMF-6
[2020-12-09 23:35:11,414] Subj001 - INFO - emd.sift:668 -    get_next_imf_mask() : Defining masks with freq 0.0026691436767578127 and amp 284.1455818020958 at 4 phases
[2020-12-09 23:35:11,536] Subj001 - INFO - emd.sift:861 -            mask_sift() : Sifting IMF-7
[2020-12-09 23:35:11,537] Subj001 - INFO - emd.sift:668 -    get_next_imf_mask() : Defining masks with freq 0.0013345718383789063 and amp 243.86432091314475 at 4 phases
[2020-12-09 23:35:11,658] Subj001 - INFO - emd.sift:861 -            mask_sift() : Sifting IMF-8
[2020-12-09 23:35:11,658] Subj001 - INFO - emd.sift:668 -    get_next_imf_mask() : Defining masks with freq 0.0006672859191894532 and amp 128.0235576653978 at 4 phases
[2020-12-09 23:35:11,779] Subj001 - INFO - emd.sift:878 -            mask_sift() : Finishing sift: reached max number of imfs (9)
[2020-12-09 23:35:11,779] Subj001 - DEBUG - emd.logger:191 -          sift_logger() : Returning 9 imfs
[2020-12-09 23:35:11,780] Subj001 - INFO - emd.logger:196 -          sift_logger() : COMPLETED: mask_sift
[2020-12-09 23:35:11,780] Subj001 - INFO - emd.logger:104 -            set_level() : EMD logger: handler 'console' level set to 'DEBUG'
[2020-12-09 23:35:11,780] Subj001 - INFO - emd.spectra:90 -  frequency_transform() : STARTED: compute frequency stats
[2020-12-09 23:35:11,780] Subj001 - DEBUG - emd.spectra:95 -  frequency_transform() : computing on 30720 samples over 9 imfs at sample rate 512
[2020-12-09 23:35:11,780] Subj001 - INFO - emd.spectra:108 -  frequency_transform() : Using Amplitude-Normalised Hilbert transform
[2020-12-09 23:35:11,780] Subj001 - INFO - emd.utils:66 -  amplitude_normalise() : STARTED: Amplitude-Normalise
[2020-12-09 23:35:11,780] Subj001 - DEBUG - emd.utils:69 -  amplitude_normalise() : Normalising 30720 samples across 9 IMFs
[2020-12-09 23:35:11,780] Subj001 - DEBUG - emd.utils:74 -  amplitude_normalise() : Using pchip interpolation with threshold of 1e-10 and max_iters 3
[2020-12-09 23:35:11,834] Subj001 - INFO - emd.utils:113 -  amplitude_normalise() : Normalise of IMF-2-0 complete in 3 iters (val=0.0)
[2020-12-09 23:35:11,855] Subj001 - INFO - emd.utils:113 -  amplitude_normalise() : Normalise of IMF-4-0 complete in 3 iters (val=0.0)
[2020-12-09 23:35:11,865] Subj001 - INFO - emd.utils:113 -  amplitude_normalise() : Normalise of IMF-5-0 complete in 3 iters (val=0.0)
[2020-12-09 23:35:11,875] Subj001 - INFO - emd.utils:113 -  amplitude_normalise() : Normalise of IMF-6-0 complete in 3 iters (val=0.0)
[2020-12-09 23:35:11,885] Subj001 - INFO - emd.utils:113 -  amplitude_normalise() : Normalise of IMF-7-0 complete in 3 iters (val=0.0)
[2020-12-09 23:35:11,895] Subj001 - INFO - emd.utils:113 -  amplitude_normalise() : Normalise of IMF-8-0 complete in 3 iters (val=0.0)
[2020-12-09 23:35:11,895] Subj001 - INFO - emd.utils:123 -  amplitude_normalise() : COMPLETED: Amplitude-Normalise
[2020-12-09 23:35:12,048] Subj001 - INFO - emd.spectra:168 -  frequency_transform() : COMPLETED: compute frequency stats. Returning 9 imfs
[2020-12-09 23:35:12,048] Subj001 - INFO - emd.emd_tutorial_04_utils_02_logger:157 -          my_analysis() : Avg frequency of IMF-2 is 11.973992Hz
[2020-12-09 23:35:12,049] Subj001 - INFO - emd.cycles:231 -       get_cycle_inds() : STARTED: get cycle indices
[2020-12-09 23:35:12,049] Subj001 - DEBUG - emd.support:227 -            ensure_2d() : Checking get_cycle_inds inputs - Adding dummy dimension to input 'mask'
[2020-12-09 23:35:12,049] Subj001 - DEBUG - emd.cycles:239 -       get_cycle_inds() : computing on 30720 samples over 9 IMFs
[2020-12-09 23:35:12,049] Subj001 - DEBUG - emd.cycles:241 -       get_cycle_inds() : 30325 (98.71%) samples masked out
[2020-12-09 23:35:12,102] Subj001 - INFO - emd.cycles:322 -       get_cycle_inds() : found 131 cycles in IMF-0
[2020-12-09 23:35:12,159] Subj001 - INFO - emd.cycles:322 -       get_cycle_inds() : found 446 cycles in IMF-1
[2020-12-09 23:35:12,182] Subj001 - INFO - emd.cycles:322 -       get_cycle_inds() : found 696 cycles in IMF-2
[2020-12-09 23:35:12,199] Subj001 - INFO - emd.cycles:322 -       get_cycle_inds() : found 355 cycles in IMF-3
[2020-12-09 23:35:12,211] Subj001 - INFO - emd.cycles:322 -       get_cycle_inds() : found 215 cycles in IMF-4
[2020-12-09 23:35:12,221] Subj001 - INFO - emd.cycles:322 -       get_cycle_inds() : found 106 cycles in IMF-5
[2020-12-09 23:35:12,229] Subj001 - INFO - emd.cycles:322 -       get_cycle_inds() : found 44 cycles in IMF-6
[2020-12-09 23:35:12,236] Subj001 - INFO - emd.cycles:322 -       get_cycle_inds() : found 20 cycles in IMF-7
[2020-12-09 23:35:12,241] Subj001 - INFO - emd.cycles:322 -       get_cycle_inds() : found 3 cycles in IMF-8
[2020-12-09 23:35:12,241] Subj001 - INFO - emd.cycles:324 -       get_cycle_inds() : COMPLETED: get cycle indices
[2020-12-09 23:35:12,241] Subj001 - INFO - emd.cycles:355 -       get_cycle_stat() : STARTED: get cycle stats
[2020-12-09 23:35:12,241] Subj001 - DEBUG - emd.cycles:360 -       get_cycle_stat() : computing stats for 696 cycles over 30720 samples
[2020-12-09 23:35:12,241] Subj001 - DEBUG - emd.cycles:361 -       get_cycle_stat() : computing metric <function mean at 0x7fb611cdc050> and returning compressed-array
[2020-12-09 23:35:12,322] Subj001 - INFO - emd.cycles:385 -       get_cycle_stat() : COMPLETED: get cycle stats
[2020-12-09 23:35:12,322] Subj001 - INFO - emd.cycles:355 -       get_cycle_stat() : STARTED: get cycle stats
[2020-12-09 23:35:12,322] Subj001 - DEBUG - emd.cycles:360 -       get_cycle_stat() : computing stats for 696 cycles over 30720 samples
[2020-12-09 23:35:12,322] Subj001 - DEBUG - emd.cycles:361 -       get_cycle_stat() : computing metric <function std at 0x7fb611cdc290> and returning compressed-array
[2020-12-09 23:35:12,418] Subj001 - INFO - emd.cycles:385 -       get_cycle_stat() : COMPLETED: get cycle stats
[2020-12-09 23:35:12,418] Subj001 - INFO - emd.cycles:355 -       get_cycle_stat() : STARTED: get cycle stats
[2020-12-09 23:35:12,418] Subj001 - DEBUG - emd.cycles:360 -       get_cycle_stat() : computing stats for 696 cycles over 30720 samples
[2020-12-09 23:35:12,418] Subj001 - DEBUG - emd.cycles:361 -       get_cycle_stat() : computing metric <function mean at 0x7fb611cdc050> and returning compressed-array
[2020-12-09 23:35:12,498] Subj001 - INFO - emd.cycles:385 -       get_cycle_stat() : COMPLETED: get cycle stats
[2020-12-09 23:35:12,499] Subj001 - INFO - emd.emd_tutorial_04_utils_02_logger:169 -          my_analysis() : Freq-Amp correlation: r=-0.365759
[2020-12-09 23:35:12,499] Subj001 - INFO - emd.emd_tutorial_04_utils_02_logger:170 -          my_analysis() : Amp-FreqStd correlation: r=0.575526
[2020-12-09 23:35:12,499] Subj001 - INFO - emd.emd_tutorial_04_utils_02_logger:175 -          my_analysis() : My new analysis finished in 2.042851 seconds