qvm icon indicating copy to clipboard operation
qvm copied to clipboard

Published 20 hours ago • verified publisher icon quil-lang

Note default log level in README ?

Open jlapeyre opened this issue 4 years ago • 2 comments

The cli help string notes that the default log-level is debug. In some cases, this causes significant cpu usage. It's easy to turn off, but a user might not notice this. Or like me, it might take a few minutes to diagnose.

Explaining this in the README might be useful.

OTOH, I found my answer in the help string. I only discovered that it's not in the README when I started this issue.

jlapeyre avatar Oct 29 '19 00:10 jlapeyre

Just curious: what were you doing that logging was a significant bottleneck? Calling the "expectation" endpoint? That's the only place I see where qvm-app is logging in a loop. Every other request type should result in only a few 10s of log messages per request. Or was it just lots of short requests in parallel?

appleby avatar Oct 29 '19 01:10 appleby

The following repeatedly. There are 2200 lines in 1s. The program has parameterized gates. I change the parameters and run program in a loop.

Oct 15 21:03:05 ribot qvm[12718]: <134>1 2019-10-16T04:03:05Z ribot qvm 12718 - - 127.0.0.1 - [2019-10-15 21:03:05] "POST /qvm HTTP/1.1" 200 294 "-" "python-requests/2.22.0"
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Got "expectation" request from API key/User ID: NIL / NIL
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Making qvm of 4 qubits
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computing initial state for expectation value computation on PURE-STATE-QVM
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Finished state prep in 1 ms.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Copying prepared state.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Copied prepared state in 0 ms.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computing the expectation value of the first operator.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computed first expectation value in 0 ms.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computing the expectation value of the second operator.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computed second expectation value in 0 ms.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computing the expectation value of the third operator.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computed third expectation value in 0 ms.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computing the expectation value of the fourth operator.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computed fourth expectation value in 0 ms.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computing the expectation value of the fifth operator.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computed fifth expectation value in 0 ms.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computing the expectation value of the sixth operator.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computed sixth expectation value in 0 ms.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computing the expectation value of the seventh operator.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computed seventh expectation value in 0 ms.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computing the expectation value of the eighth operator.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computed eighth expectation value in 0 ms.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computing the expectation value of the ninth operator.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computed ninth expectation value in 0 ms.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computing the expectation value of the tenth operator.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computed tenth expectation value in 0 ms.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computing the expectation value of the eleventh operator.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computed eleventh expectation value in 0 ms.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computing the expectation value of the twelfth operator.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computed twelfth expectation value in 0 ms.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computing the expectation value of the thirteenth operator.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computed thirteenth expectation value in 0 ms.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computing the expectation value of the fourteenth operator.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computed fourteenth expectation value in 0 ms.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computing the expectation value of the fifteenth operator.
Oct 15 21:03:05 ribot qvm[12718]: <135>1 2019-10-16T04:03:05Z ribot qvm 12718 - - [127.0.0.1 Session:510] Computed fifteenth expectation value in 0 ms.

jlapeyre avatar Oct 29 '19 02:10 jlapeyre