ben-denham / labtech

Easily run experiment permutations with multi-processing and caching
https://ben-denham.github.io/labtech/
GNU General Public License v3.0
7 stars 1 forks source link

Excessive print output from mermaid example in CLI on Windows #16

Closed nathanjmcdougall closed 4 months ago

nathanjmcdougall commented 5 months ago

Similar to #14, running the mermaid example from the README from the CLI (rather than an interactive IPython session) seems to spam the console with 12 times. As of ef08cfee7f1db905b04c2fa9e2ff7c15d4ce03d4, this is no longer <IPython.core.display.Markdown object> but instead, a text representation of the diagram.

ben-denham commented 4 months ago

Interesting! I have been unable to replicate this from a Python 3.10 console in either PowerShell or Command Prompt on Windows 10. Are there any other factors in your setup that you think might be causing this? What Python version are you running? For reference, here's what I'm seeing in command prompt:

image

nathanjmcdougall commented 4 months ago

A few things:

  1. I was running the code from a file rather than in a terminal. Actually I was just running the test file dependents_and_mermaid.py.
  2. I wonder whether it is tqdm related. I have noticed that sometimes when using tqdm I get issues where output is repeated if I move/resize the window while it is running. However this issue is consistent so I am not sure.
  3. When I try to run the code directly in the terminal as per your screenshot above I actually get spawn process errors. I don't have time right now to look into this further but it seems unrelated, but worth investigating further.
  4. I am using Powershell from within VS Code. Nothing else unusual I don't think.
ben-denham commented 4 months ago

Thanks @nathanjmcdougall

  1. Good to know. I wouldn't expect this to really make a difference though.
  2. Interesting idea, I've just added https://github.com/ben-denham/labtech/commit/82b7eeccd78d75d776fc7aae2345e01d6aebaa26 to see if that makes terminal resizing any better (though it won't fix already-printed lines)
  3. Would be keen to see those errors, maybe paste a screenshot in a separate issue?
  4. Could you please see if you can get the same issue running straight in Powershell - not in VS Code? Just to try and isolate the issue.
nathanjmcdougall commented 4 months ago

@ben-denham

  1. Yeah, but I get inconsistent results between the two approaches (see point 3) so it's definitely relevant
  2. Sorry, I wasn't clear, I meant in general when using tqdm on my setup, not for labtech in particular. 3-4 I'll work on now.
nathanjmcdougall commented 4 months ago

Regarding point 4, here is the issue reproduced within Powershell only, without using VS Code:

image

``` PS C:\Users\namc> cd Repositories/labtech PS C:\Users\namc\Repositories\labtech> .venv\Scripts\activate (.venv) PS C:\Users\namc\Repositories\labtech> poetry run python tests\integration\readme\dependents_and_mermaid.py classDiagram direction BT class DependentTask DependentTask : SlowTask slow_task DependentTask : int multiplier DependentTask : run() int class SlowTask SlowTask : int base SlowTask : run() int DependentTask <-- SlowTask: slow_task DependentTask: 0/10 [00:00, ?tasks/s] | | 0% [? remaining]classDiagram direction BT class DependentTask DependentTask : SlowTask slow_task DependentTask : int multiplier DependentTask : run() int class SlowTask SlowTask : int base SlowTask : run() int DependentTask <-- SlowTask: slow_task classDiagram direction BTs at 20:46:00. Up to top 10 by start_time: class DependentTask DependentTask : SlowTask slow_task DependentTask : int multiplier DependentTask : run() int class SlowTask SlowTask : int base SlowTask : run() int DependentTask <-- SlowTask: slow_task classDiagram direction BT class DependentTask DependentTask : SlowTask slow_task DependentTask : int multiplier DependentTask : run() int class SlowTask SlowTask : int base SlowTask : run() int DependentTask <-- SlowTask: slow_task classDiagram direction BT class DependentTask DependentTask : SlowTask slow_task DependentTask : int multiplier DependentTask : run() int class SlowTask SlowTask : int base SlowTask : run() int DependentTask <-- SlowTask: slow_task DependentTask: 1/10 [00:01, 1.84s/tasks] |██████████████▎ | 10% [00:16 remaining]classDiagram direction BT class DependentTask DependentTask : SlowTask slow_task DependentTask : int multiplier DependentTask : run() int class SlowTask SlowTask : int base SlowTask : run() int DependentTask <-- SlowTask: slow_task classDiagram direction BT class DependentTask DependentTask : SlowTask slow_task DependentTask : int multiplier DependentTask : run() int class SlowTask SlowTask : int base SlowTask : run() int DependentTask <-- SlowTask: slow_taskclassDiagram direction BT class DependentTask DependentTask : SlowTask slow_task DependentTask : int multiplier DependentTask : run() int class SlowTask SlowTask : int base SlowTask : run() int DependentTask <-- SlowTask: slow_task classDiagram direction BT class DependentTask DependentTask : SlowTask slow_task DependentTask : int multiplier DependentTask : run() int class SlowTask SlowTask : int base SlowTask : run() int DependentTask <-- SlowTask: slow_task classDiagram direction BT class DependentTask DependentTask : SlowTask slow_task DependentTask : int multiplier DependentTask : run() int class SlowTask SlowTask : int base SlowTask : run() int DependentTask <-- SlowTask: slow_task classDiagram direction BT class DependentTask DependentTask : SlowTask slow_task DependentTask : int multiplier DependentTask : run() int class SlowTask SlowTask : int base SlowTask : run() int DependentTask <-- SlowTask: slow_task classDiagram 0 active tasks as at 20:46:01. Up to top 10 by start_time: [0, 1764, 3528, 5292, 7056, 8820, 10584, 12348, 14112, 15876] classDiagramtTask <-- SlowTask: slow_task direction BT0/10 [00:02, 4.67tasks/s] |██████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████| 100% [00:00 remaining] 0 active tasks as at 20:46:01. Up to top 10 by start_time: class DependentTask:46:01. Up to top 10 by start_time: DependentTask : SlowTask slow_task DependentTask : int multiplier DependentTask : run() int class SlowTask SlowTask : int base SlowTask : run() int DependentTask <-- SlowTask: slow_task ```
nathanjmcdougall commented 4 months ago

Regarding point 3, see #25.

ben-denham commented 4 months ago

Aha, I was able to reproduce the issue by running the specific test as a module just as you did.

The cause of the issue is that the diagram-printing lines are at the top-level of module and unguarded by if __name__ == '__main__':, which means they will be re-executed whenever the module is loaded. With the default multiprocessing start_method of 'spawn' on Windows, the module will be reloaded at the start of each subprocess (skipping over anything guarded by if __name__ == '__main__':), printing the diagram from each subprocess.

I've fixed this by moving the diagram printing under if __name__ == '__main__': in https://github.com/ben-denham/labtech/commit/ddb677cc09f76d9b55ebede04cd0bb1d1a27ea22

nathanjmcdougall commented 4 months ago

Okay, but then won't those lines be untested/unexecuted in the test suite? Might be better to add those lines to the README itself but exclude then from the integration tests.

On Sat, 25 May 2024, 12:05 pm Dr Ben Denham, @.***> wrote:

Aha, I was able to reproduce the issue by running the specific test as a module just as you did.

The cause of the issue is that the diagram-printing lines are at the top-level of module and unguarded by if name == 'main':, which means they will be re-executed whenever the module is loaded. With the default multiprocessing start_method of 'spawn' on Windows, the module will be reloaded at the start of each subprocess (skipping over anything guarded by if name == 'main':), printing the diagram from each subprocess.

I've fixed this by moving the diagram printing under if name == 'main': in ddb677c https://github.com/ben-denham/labtech/commit/ddb677cc09f76d9b55ebede04cd0bb1d1a27ea22

— Reply to this email directly, view it on GitHub https://github.com/ben-denham/labtech/issues/16#issuecomment-2130533202, or unsubscribe https://github.com/notifications/unsubscribe-auth/AEN5SMPHX5OJ335D55ISOZDZD7IWFAVCNFSM6AAAAABGWSAI66VHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDCMZQGUZTGMRQGI . You are receiving this because you were mentioned.Message ID: @.***>

ben-denham commented 4 months ago

They'll still be executed, but only once in the main process instead of repeatedly in each subprocess. I've updated the test to check for exactly one diagram in the output: https://github.com/ben-denham/labtech/commit/ddb677cc09f76d9b55ebede04cd0bb1d1a27ea22#diff-eb0ef88a399d99af6bfcec93c9fdbb2e4656d6f3cc05150ef6bf4fe736d721a6R35

nathanjmcdougall commented 4 months ago

Ah, great!

On Sat, 25 May 2024, 5:31 pm Dr Ben Denham, @.***> wrote:

They'll still be executed, but only once in the main process instead of repeatedly in each subprocess. I've updated the test to check for exactly one diagram in the output: ddb677c

diff-eb0ef88a399d99af6bfcec93c9fdbb2e4656d6f3cc05150ef6bf4fe736d721a6R35

https://github.com/ben-denham/labtech/commit/ddb677cc09f76d9b55ebede04cd0bb1d1a27ea22#diff-eb0ef88a399d99af6bfcec93c9fdbb2e4656d6f3cc05150ef6bf4fe736d721a6R35

— Reply to this email directly, view it on GitHub https://github.com/ben-denham/labtech/issues/16#issuecomment-2130788268, or unsubscribe https://github.com/notifications/unsubscribe-auth/AEN5SMN5J477LQMCAP7UF2TZEAO45AVCNFSM6AAAAABGWSAI66VHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDCMZQG44DQMRWHA . You are receiving this because you were mentioned.Message ID: @.***>