gem/oq-engine — pull request #974 by larsbutler (2012-12-06 16:46:48+00:00)
Title: Cleaner progress logging

Something I've been wanting to clean up for a while... this basically just gives us more consistent logging functionality. Instead of having to call special functions in the `logs` module to do progress reporting, we just call `logs.LOG.progress`, same as we do with `logs.LOG.debug` or `logs.LOG.warn`.

Also, the indentation of progress messages was a bit strange, so I simplified it.

The only calculator specific change I made here was in the Disaggregation hazard calculator. A `progress` message is reported when the calculation finishes hazard curve computation and moves on to disaggregation. I thought it would be useful to display this information to the user, since disaggregation tasks take more computation time than hazard curve tasks. (When running a small calculation, it is obvious when the calculation phase changes because the calculation appears to "slow down" and progress messages become less frequent.)

Here is some sample progress output from a disagg hazard calculation:

[2012-12-06 17:34:39,719 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** pre_executing (hazard)
[2012-12-06 17:34:39,721 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** initializing sources
[2012-12-06 17:34:39,804 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** initializing site model
[2012-12-06 17:34:39,806 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** initializing realizations
[2012-12-06 17:34:39,878 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** executing (hazard)
[2012-12-06 17:34:41,084 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** > hazard 8% complete
[2012-12-06 17:34:41,094 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** > hazard 16% complete
[2012-12-06 17:34:42,181 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** > hazard 25% complete
[2012-12-06 17:34:42,224 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** > hazard 33% complete
[2012-12-06 17:34:43,143 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** > hazard 41% complete
[2012-12-06 17:34:43,173 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** > hazard 50% complete
[2012-12-06 17:34:44,864 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** > hazard 58% complete
[2012-12-06 17:34:44,956 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** > hazard 66% complete
[2012-12-06 17:34:44,957 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** > Hazard curve computation complete
[2012-12-06 17:34:44,958 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** > Starting disaggregation
[2012-12-06 17:35:18,093 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** > hazard 75% complete
[2012-12-06 17:35:18,121 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** > hazard 83% complete
[2012-12-06 17:35:18,261 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** > hazard 91% complete
[2012-12-06 17:35:18,322 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** > hazard 100% complete
[2012-12-06 17:35:18,325 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** hazard calculation 100% complete
[2012-12-06 17:35:18,331 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** post_executing (hazard)
[2012-12-06 17:35:18,340 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** post_processing (hazard)
[2012-12-06 17:35:18,347 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** export (hazard)
[2012-12-06 17:35:18,356 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** clean_up (hazard)
[2012-12-06 17:35:18,371 #319 1.0.0.127.in-addr.arpa PROGRESS MainProcess/13903 root] ** complete (hazard)

I demonstrated these disaggregation progress changes to Dr. Monelli and he agrees that this is relevant and useful information, for the reasons I explained above.