speedata / publisher

speedata Publisher - a professional database Publishing system
https://www.speedata.de/
GNU Affero General Public License v3.0
292 stars 36 forks source link

info about total runtime #426

Closed pr-apes closed 1 year ago

pr-apes commented 1 year ago

@pgundlach,

I have just executed a run with a filter before and I got the following time info:

Total run time: 585.0335ms

My impression is that it took way longer than half a second (about 3-4 seconds).

My guess is that the time measurement doesn't include filter execution.

If that is so, would it be possible that it could include it?

Many thanks for your help.

pgundlach commented 1 year ago

I doubt that it does not include the filter run:

The start time is set in https://github.com/speedata/publisher/blob/develop/src/go/sp/sp/sp.go#L104 - the init function that gets called first and and the duration is shown after the main loop is completed: https://github.com/speedata/publisher/blob/develop/src/go/sp/sp/sp.go#L1237

But I might be wrong and have overlooked something.

pr-apes commented 1 year ago

@pgundlach,

this seems to be more complex than I first thought.

I run Publisher from a batch file:

sp --dummy --filter %~n0.lua --quiet ^
  --jobname %randomizer% -v randomizer=%randomizer% ^
  -v cfn=%cfn% ^
  -v completepath=%completepath% ^
  -v filename="%~n1" -v extension=%~x1
sp clean --jobname %randomizer% --quiet

And inside the filter, I have:

runtime.execute({"sp", "-s", "--quiet", … })
runtime.execute({"sp", "clean", "--quiet", … })

The only time info I get is for sp clean in the batch file.

But I don't get time info for any of the runtime.execute({"sp"}) in the filter (which makes total sense to me) and also for the sp --dummy in the batch file (which I think it should be given).

Or am I missing something about when Publisher shows time information?

Many thanks for your help.

pgundlach commented 1 year ago

The option --quiet discards any output, so no execution time is printed. So it looks as if it works as intended.

pgundlach commented 1 year ago

The option --quiet discards any output, so no execution time is printed. So it looks as if it works as intended.

Forget this comment... I'll have a look

pgundlach commented 1 year ago

The output from sp --quiet && sp clean --quiet where the first sp process starts a three second sub-process is

Run speedata publisher
Total run time: 3.098485833s
Removing publisher-aux.xml
Removing publisher.finished
Removing publisher.protocol
Removing publisher.status
Removing publisher.vars
Total run time: 758.667µs

so you should get two messages with Total run time:...

pr-apes commented 1 year ago

Sorry, totally my fault. I downloaded latest again and after reinstalling it it worked fine:

>sp --quiet && sp clean --quiet
Run speedata publisher
Total run time: 883.0505ms
Removing publisher-aux.xml
Removing publisher.finished
Removing publisher.protocol
Removing publisher.status
Removing publisher.vars
Total run time: 659.0371ms

BTW, sp clean --quiet seems to be ≈ ×1000 faster in your computer than in mine (SSD may be the culprit 😅).

Sorry for the noise again and many thanks for your help.