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.

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

Cosmetic bug in @time stdout printing when msg is not nothing #50646

Closed
algunion opened this issue Jul 23, 2023 · 0 comments · Fixed by #50665
Closed

Cosmetic bug in @time stdout printing when msg is not nothing #50646

algunion opened this issue Jul 23, 2023 · 0 comments · Fixed by #50665

Comments

@algunion
Copy link

algunion commented Jul 23, 2023

When the @time macro is called using @time "message" ex, it can mess up the stdout print.

Consider the following:

function withtime(msg)
    @time msg sleep(1)
end

@info "@time x ..."

t1 = Threads.@spawn withtime("time 1")
t2 = Threads.@spawn withtime("time 2")

wait(t1)
wait(t2)

@info "@time noghing ... / e.g., @time ..."

t3 = Threads.@spawn withtime(nothing)
t4 = Threads.@spawn withtime(nothing)

wait(t3)
wait(t4)

readline()

Most of the times for the msg with non-nothing value we get a messed up printing to the stdout (and if you are lucky and get a nice print at first execution, just try again):

[ Info: @time x ...
time 1: time 2: 1.001953 seconds (768 allocations: 46.614 KiB, 1.42% compilation time)
1.001784 seconds (263 allocations: 12.469 KiB, 0.95% compilation time)

[ Info: @time noghing ... / e.g., @time ...
  1.001953 seconds (15.60 k allocations: 1.031 MiB)
  1.001822 seconds (89 allocations: 5.180 KiB, 0.69% compilation time)

The time 1: time 2: 1.001953 seconds (768 alloc... mess is caused by the following:

has_msg && print(_msg, ": ")
time_print(stdout, elapsedtime, diff.allo...

Between the print(_msg, ": ") and the time_print issuing the print statement, there is a significant time gap (enough for other tasks to be able to litter the space with whatever they want - any task that will issue a print can print between the msg: and the rest of @time content.

The solution consists in either moving the msg printing inside the time_print function or returning a string from time_print and issuing a single print statement inside the @time macro body.

@algunion algunion changed the title Issue with @time stdout printing when msg is not nothing Cosmetic bug in @time stdout printing when msg is not nothing Jul 23, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant