search

psi-rking / optking

optking: A molecular geometry optimization program
BSD 3-Clause "New" or "Revised" License
20 stars 14 forks source link

ircprogress.log output repetitve #32

Closed JonathonMisiewicz closed 2 years ago

JonathonMisiewicz commented 5 years ago

I need to fix an IRC bug for my own research, and in doing so, I've come across a problem in the current ircprogress.log printing code. When running the IRC test case, the ircprogress.log file displays the expected output several times over, interspersed with brief fragments of other lines. See the example file. My testing shows there are two issues:

  1. The IRC code adds handlers to the same file multiple times. This causes the code to try to write the IRC progress to the same file, several times.
  2. When you fix that bug, the first line will become filled with \x00 bytes. There are as many \x00 bytes as there are truncated characters. I've constructed a minimal working example of this to confirm that the issue is truncation. This likely has to do with the fact that although I truncated the file, the logger has had the file open the entire time, behind the scenes. Of course opening a file twice, removing characters with one open, and then editing it in the other will lead to problems.

Simply writing the ircprogress.log file each time would eliminate these issues. Is there a reason why we're using logging? I'm not familiar with the design principles/interfacing requirements of PyOptking. Logging is great when you want to filter whether the message gets written, but we always want the ircprogress.log file written. Additionally, logging assumes that you can print messages one-by-one. That isn't the case for us. We want to print a message, wait for a potentially expensive electronic computation to finish, and then replace the message we printed earlier. That is not what the logging module is for.

AlexHeide commented 2 years ago

I never really addressed the questions raised here. ~4 years ago at Georgia Tech optking was meant to be the first piece / dependency of psi4 that moved to python logging to easily synchronize output between psi4 and various components. You are correct that the irc progress file isn't really a log since we're erasing it. I have kept it as a log so that it can be redirected easily to psi4's log files and optking's log file as needed down the road.

The repetitive printing was finally fixed in the way too large #67 when the logging system was configured so that it could inherit from psi4's logger if psi4 calls optking. The logs are now created appropriately as child loggers and the ircprogress handler is only assigned to the irc's logger