grimme-lab / xtb-python

Python API for the extended tight binding program package
https://xtb-python.readthedocs.io
GNU Lesser General Public License v3.0
101 stars 30 forks source link

Can't redirect stdout from calculator singlepoint() #31

Open craldaz opened 4 years ago

craldaz commented 4 years ago

I have an application that will be running a lot of xtb calculations. I don't want my main output to be clogged with a lot of output from xtb itself but instead would like to write this information to a different file using redirection.

Normally this is possible with contextlib in python but contextlib can't capture the stdout from Calculator.

For example, the following code still prints out the SCC iteration information to the standard output (which I don't want). It should be written to log.txt instead.

import contextlib
import numpy as np
from xtb.interface import Calculator
from xtb.utils import get_method
from xtb.interface import Environment

numbers = np.array([8, 1, 1]) 
positions = np.array([
[ 0.00000000000000, 0.00000000000000,-0.73578586109551],
[ 1.44183152868459, 0.00000000000000, 0.36789293054775],
[-1.44183152868459, 0.00000000000000, 0.36789293054775]])

calc = Calculator(get_method("GFN2-xTB"), numbers, positions)

with open('log.txt','a') as f:
    with contextlib.redirect_stdout(f):
        res = calc.singlepoint()  # energy printed is only the electronic part
E = res.get_energy()
print(E)
g = res.get_gradient()
print(g)

c = res.get_charges()
print(c) 
awvwgk commented 4 years ago

The Fortran library is writing to a formatted unit, not sure if Python is actually able to intercept this.

For this purpose you can create a formatted unit by an API call instead:

calc.set_output('log.txt')
res = calc.singlepoint()
calc.release_output()
craldaz commented 4 years ago

Thanks for the response.

This prevents output for a little while then it all dumps to stdout anyway.

For example, here I am doing a geometry optimization that calls xTB, the xTB output is suppressed until optimization step 3.

It's not super important.

 On opt step 1 for node 0
 In backtrack
 Iter: 1 Err-dQ = 5.91717e-04 RMSD: 1.61973e-02 Damp: 1.00000e+00
 Iter: 2 Err-dQ (Best) = 1.07559e-08 (5.91717e-04) RMSD: 5.02527e-05 Damp: 1.00000e+00 (Good)
 Cartesian coordinates obtained after 2 microiterations (rmsd = 5.025e-05 |dQ| = 1.076e-08)
 Decreasing DMAX to 0.05919417044389267
 dEstep=-0.7384
 Node: 0 Opt step: 1 E: -0.7384 predE: -1.1099 ratio: 0.665 gradrms: 0.00158 ss: 0.059 DMAX: 0.059
 gmax 0.0163 disp 0.6662 Ediff -0.7384 gradrms 0.0016

 updating coord basis
 Timings: Build G: 1.412 Eig: 0.465

 On opt step 2 for node 0
 updating prim hess
 In backtrack
 Iter: 1 Err-dQ = 6.82791e-04 RMSD: 1.39723e-02 Damp: 1.00000e+00
 Iter: 2 Err-dQ (Best) = 2.73348e-08 (6.82791e-04) RMSD: 5.48664e-05 Damp: 1.00000e+00 (Good)
 Cartesian coordinates obtained after 2 microiterations (rmsd = 5.487e-05 |dQ| = 2.733e-08)
 [INFO] decreasing step: does not satisfy sufficient decrease condition.
 step 0.02960
 Iter: 1 Err-dQ = 1.70698e-04 RMSD: 6.98613e-03 Damp: 1.00000e+00
 Iter: 2 Err-dQ (Best) = 1.70834e-09 (1.70698e-04) RMSD: 1.37165e-05 Damp: 1.00000e+00 (Good)
 Cartesian coordinates obtained after 2 microiterations (rmsd = 1.372e-05 |dQ| = 1.708e-09)
 Decreasing DMAX to 0.029597085221946335
 dEstep=-0.1123
 decreasing DMAX
 Node: 0 Opt step: 2 E: -0.8507 predE: -0.7656 ratio: 0.147 gradrms: 0.00278 ss: 0.030 DMAX: 0.025
 gmax 0.0400 disp 0.2874 Ediff -0.1123 gradrms 0.0028

 updating coord basis
 Timings: Build G: 1.419 Eig: 0.466

 On opt step 3 for node 0
 updating prim hess
 In backtrack
 Iter: 1 Err-dQ = 8.62347e-05 RMSD: 5.76099e-03 Damp: 1.00000e+00
 Iter: 2 Err-dQ (Best) = 2.43285e-10 (8.62347e-05) RMSD: 6.45243e-06 Damp: 1.00000e+00 (Good)
 Cartesian coordinates obtained after 2 microiterations (rmsd = 6.452e-06 |dQ| = 2.433e-10)
   1   -955.3072079 -0.955307E+03  0.598E+00    0.82       0.0  T
   2   -960.0498634 -0.474266E+01  0.316E+00    0.60       1.0  T
   3   -959.9884823  0.613810E-01  0.159E+00    0.71       1.0  T
   4   -959.8016077  0.186875E+00  0.751E-01    0.63       1.0  T
   5   -960.2461265 -0.444519E+00  0.191E-01    0.67       1.0  T
   6   -960.2606855 -0.145590E-01  0.101E-01    0.67       1.0  T
   7   -960.2639024 -0.321684E-02  0.640E-02    0.67       1.0  T
   8   -960.2670814 -0.317897E-02  0.287E-02    0.67       1.0  T
   9   -960.2677006 -0.619286E-03  0.796E-03    0.67       1.0  T
  10   -960.2676958  0.483282E-05  0.599E-03    0.67       1.0  T
  11   -960.2677149 -0.190545E-04  0.232E-03    0.67       1.8  T
  12   -960.2677166 -0.177235E-05  0.128E-03    0.67       3.3  T
  13   -960.2677168 -0.143441E-06  0.799E-04    0.67       5.3  T
  14   -960.2677170 -0.178110E-06  0.359E-04    0.67      11.7  T
     SCC iter.                  ...        1 min, 15.246 sec
     gradient                   ...        0 min,  9.483 sec
   1   -955.2950039 -0.955295E+03  0.598E+00    0.84       0.0  T
   2   -960.0359753 -0.474097E+01  0.316E+00    0.62       1.0  T
   3   -959.9602917  0.756836E-01  0.159E+00    0.73       1.0  T
   4   -959.7398188  0.220473E+00  0.795E-01    0.66       1.0  T
   5   -960.2353678 -0.495549E+00  0.195E-01    0.69       1.0  T
   6   -960.2509581 -0.155903E-01  0.101E-01    0.69       1.0  T
   7   -960.2540865 -0.312841E-02  0.653E-02    0.69       1.0  T
   8   -960.2574356 -0.334910E-02  0.286E-02    0.69       1.0  T
   9   -960.2580375 -0.601917E-03  0.815E-03    0.69       1.0  T
  10   -960.2580358  0.170290E-05  0.604E-03    0.69       1.0  T
  11   -960.2580550 -0.192064E-04  0.225E-03    0.69       1.9  T
  12   -960.2580563 -0.130665E-05  0.126E-03    0.69       3.3  T
  13   -960.2580564 -0.934145E-07  0.810E-04    0.69       5.2  T
  14   -960.2580566 -0.198629E-06  0.364E-04    0.69      11.6  T
     SCC iter.                  ...        1 min, 15.334 sec
     gradient                   ...        0 min,  9.410 sec
   1   -955.3017034 -0.955302E+03  0.598E+00    0.83       0.0  T
   2   -960.0433151 -0.474161E+01  0.316E+00    0.61       1.0  T
   3   -959.9751101  0.682051E-01  0.159E+00    0.72       1.0  T
   4   -959.7722861  0.202824E+00  0.772E-01    0.64       1.0  T
   5   -960.2410138 -0.468728E+00  0.193E-01    0.68       1.0  T
   6   -960.2560624 -0.150487E-01  0.101E-01    0.68       1.0  T
   7   -960.2592336 -0.317115E-02  0.647E-02    0.68       1.0  T
   8   -960.2625164 -0.328285E-02  0.286E-02    0.68       1.0  T
   9   -960.2631249 -0.608503E-03  0.801E-03    0.68       1.0  T
  10   -960.2631215  0.338383E-05  0.597E-03    0.68       1.0  T
  11   -960.2631402 -0.187053E-04  0.228E-03    0.68       1.8  T
  12   -960.2631418 -0.151996E-05  0.127E-03    0.68       3.3  T
  13   -960.2631419 -0.127363E-06  0.803E-04    0.68       5.2  T
  14   -960.2631421 -0.190713E-06  0.355E-04    0.68      11.9  T
     SCC iter.                  ...        1 min, 10.393 sec
     gradient                   ...        0 min, 11.980 sec
   1   -955.3038100 -0.955304E+03  0.598E+00    0.83       0.0  T
   2   -960.0450368 -0.474123E+01  0.316E+00    0.61       1.0  T
   3   -959.9757359  0.693009E-01  0.159E+00    0.72       1.0  T
   4   -959.7705083  0.205228E+00  0.775E-01    0.65       1.0  T
   5   -960.2428269 -0.472319E+00  0.193E-01    0.68       1.0  T
   6   -960.2579378 -0.151109E-01  0.101E-01    0.68       1.0  T
   7   -960.2611627 -0.322496E-02  0.653E-02    0.68       1.0  T
   8   -960.2645399 -0.337711E-02  0.284E-02    0.69       1.0  T
   9   -960.2651256 -0.585756E-03  0.794E-03    0.68       1.0  T
  10   -960.2651225  0.306501E-05  0.583E-03    0.68       1.0  T
  11   -960.2651403 -0.177369E-04  0.222E-03    0.68       1.9  T
  12   -960.2651416 -0.128284E-05  0.124E-03    0.68       3.4  T
  13   -960.2651416 -0.752927E-07  0.801E-04    0.68       5.3  T
  14   -960.2651419 -0.214702E-06  0.342E-04    0.68      12.3  T
     SCC iter.                  ...        1 min, 11.030 sec
 dEstep=-0.3042
 Node: 0 Opt step: 3 E: -1.1550 predE: -0.4588 ratio: 0.663 gradrms: 0.00248 ss: 0.025 DMAX: 0.025
 gmax 0.0274 disp 0.2370 Ediff -0.3042 gradrms 0.0025
awvwgk commented 4 years ago

There is a way to workaround the discrepancy between C/Fortran output and Python file handle described in https://github.com/grimme-lab/xtb/issues/160#issuecomment-604223623 for the old Python API, it should work with the new one as well.

kjelljorner commented 3 years ago

I encountered a similar issue in relation to the QCEngine implementation of xtb, where the default is to write output to stdout. Maybe one solution would be to allow different levels of verbosity. Currently, the harness defaults to VERBOSITY_FULL. VERBOSITY_MUTED does seem to do the trick for GFN2-xTB, but for GFN-FF there is still output printed.

https://github.com/grimme-lab/xtb-python/blob/43a680be14a664aec51036ae313187b24079660d/xtb/qcschema/harness.py#L141

awvwgk commented 3 years ago

For the tblite library I circumvented this problem by allowing the Python API to provide the IO functionality via a callback:

https://github.com/awvwgk/tblite/blob/6396909a4469146e4b2dfacc3dd890ee06223ba9/python/tblite/library.py#L77-L81

This solution will be adopted in xtb as well once we switch to the library as backend for implementing the xTB Hamiltonian. For GFN-FF this would completely resolve the problem that the Calculator can write in the __init__ step before we can actually set the verbosity or redirect the output to a file.

kjelljorner commented 3 years ago

Ok, sounds good!