In my current main project, I want all of my game’s output to be logged to file–and ideally all to a single file. It seems to me that, should I want to get output from users, log-files are likely to be much more convenient for them and more reliable for me–and much more so if there’s only one file to locate and send.
However, I’m really not sure that I’m approaching logging in a sensible manner, and could use some feedback and/or advice, please.
Here is what I’m currently doing:
I’m setting “Notify”'s output-stream pointer to a MultiplexStream that I instantiate, then setting “sys.stdout” and “sys.stderr” to new file-objects. All of the above point to the same file.
However, is it wise to have–presumably–three separate objects writing to the same file? I could perhaps use a single file-object for the two “sys”-variables, but I don’t know whether that’s a good idea, either. And indeed, I think that I’ve seen some cases of lines seeming to be cut off in part.
Furthermore, even the above doesn’t seem to catch quite everything–I believe that I’ve seen at least some output still being printed to terminal, and not ending up in the file.
There are a few ways to go about logging. I’d recommend choosing one way and stick to it and not split it up to various loggers, especially things like print calls are simply not designed for real logging. In my earlier projects I used a dual approach of redirecting Panda3Ds output to one file and then only used pythons logging module for my personal game logs, but in the future I’m planing on using the Notifier class (Panda3Ds logging system) more often instead of pythons logging module.
With the Notifier system, you could simply create new categories for all your classes or however granular you need it with something like this:
notify = DirectNotifyGlobal.directNotify.newCategory("YourCategoryName")
# And use it like this. debug could also be error or warning for different log levels
notify.debug("some message")
# Very useful for checking which functions got called at which point in time
notify.debugStateCall()
Another plus is, that you can set the configuration of the categories from within the prc config files.
I’m not that fond of file handling with multiple pointers to one file, but I guess it’s not the best you could do. It either has to wait until one write call is done and could slow down the writing process dramatically or another possibility is, that the write calls simply interfere with one another resulting in jagged lines in the outfile.
In theory that should be sufficient to get Panda3Ds output to the log file. If there still is some terminal output, check if it’s really that of Panda3D and maybe show it here that we can check the cause of it being written to terminal rather then the log file.
I think that I tried the Notifier class at some point, and again found some (non-“print”) output being missed. Perhaps it was things like Python exceptions, the output of which might be important to have in the case of crashes!
I think that I have seen this, indeed. :/
I’m still seeing the following, at the least:
Known pipe types:
glxGraphicsPipe
(all display modules loaded.)
:device(warning): /dev/input/event6 is not readable, some features will be unavailable.
Hm, do you have an example of a python method or class that creates such an exception output? I guess it’s not your own code, is it? Otherwise, just add a log call that you pass the exception to it, usually all log systems can handle that using the error log level call.
You need to call it prior to initializing showbase for those messages to go in the log file.
It is my code, but I’m thinking more of unexpected exceptions; bugs and crashes not foreseen. (And, now considering that, of not wanting to put near-absolutely everything in try-except blocks. ^^; )
Ah, right, of course–that was a silly mistake! Thank you for catching that. ^^;
If you don’t want to use an application wide try block, you could either register an atexit function or overwrite the exception handler. Here’s a simple sample of how to do so:
import sys
import atexit
# atexit way...
def myfunc():
print(" - After exception handler - ")
# use sys.last_* for exception info. May not be set!
print(sys.last_type, sys.last_value, sys.last_traceback)
atexit.register(myfunc)
# exception hook way...
def myExHandler(ex_type, ex_value, ex_traceback):
print(" - Custom exception handler for uncought exceptions - ")
sys.excepthook = myExHandler
# our test exception
raise Exception("Custom Exception")
Hmm… Messages printed by a custom DirectNotify category don’t seem to be sent to a file specified to Notify (the latter having been given a MultiplexStream, to which a Filename has been added via “addFile”).
The MultiplexStream is, I believe, constructed before the DirectNotify category is made.
This is how I’m associating the file with Notify:
# "Common" is simply a class of mine that
# most other classes are given access to.
Common.nout = MultiplexStream()
Notify.ptr().setOstreamPtr(Common.nout, 0)
Common.nout.addFile(filename)
On another note, I was surprised to find that the above-mentioned “addFile” method opens its file in “append” mode. I’m inclined to think that logs being overwritten seems preferable–after all, appending the log-file would seem to potentially both make it harder to find the start of the relevant log in the case of a crash, and build up a large file in the case that the program is run frequently.
To that end, and not finding a better-looking way to circumvent the issue–although I may have missed one–I’m currently, when logging is initiated at the start of the program, unlinking the log-file if it exists. (Via the “unlink” method of the “Filename” class.)
But I’m unsure of whether that’s wise, so–is this a bad idea?
Having searched around a little more, I really am stuck as to why my logging messages aren’t directed to the designated file.
The manual seems to suggest that the above code should be sufficient, and what threads I found in a(n admittedly quick) forum-search didn’t provide many possible explanations. I did try passing in my MultiplexStream (I think that it was) into my call to “newCategory”, if I recall correctly, and I’ve added a call to “setLogging(True)” on the object returned by “newCategory”, but thus far to no avail. :/
What might I be doing wrong? Or is this a bug on the Panda-side, perhaps?
[edit]
No, wait, I seem to have found the answer!
As noted in this post, setting the “streamWriter” variable of “base.notify.class” is also called for, it seems.
I would still appreciate input on the second point in my previous post, regarding whether unlinking my log-file with each run is unwise, but otherwise I’m glad to say that logging seems to be working now!
