Logging frustration
Posted: 22 August 2020, 18:20
I am having trouble getting logging to work and I think there are some fundamental things I'm not understanding. Is is possible that logging is not initialized until some point and log messages before that point are lost to the internet ether? Is there a way around this?
More details...
I have sprinkled self::trace() calls through out my game.php, but the only log that shows in the "request&SQL logs" is when starting getAllData(). I see this line repeated periodically throughout the logs (requesting back 1000 lines). The log timestamps show periodic jumps which correspond to me starting new games. Each section in the logs (corresponding to one Express-start / Express-stop cycle) starts with "22/08 18:48:01 [info] [M] [2332172/pickardj0] /1/pickardjgt?table=1819332" and then ends with what I think is an ajax call: "22/08 18:45:29 [notice] [T188833] [2332172/pickardj0] OK-0 485 d1 c0 e230 m179 I483 A2 V0 T0 /1/pickardjgt/pickardjgt/notificationHistory.html?table=188833&from=2&privateinc=1&history=1&testuser=2332172&dojo.preventCache=15981146779842". Logs calls during setupNewGame and the other automatic "game" states do not show up. It's not until I'm getting player interaction that the logs start to work.
In an attempt to get around this by logging to the web console, I created a "logConsole" notif with a handler that just does a "console.log(notif);". This exhibits the same behavior. Log messages fired before a player action disappear (though will err if there's a badly formatted string) but those after player action work fine.
More details...
I have sprinkled self::trace() calls through out my game.php, but the only log that shows in the "request&SQL logs" is when starting getAllData(). I see this line repeated periodically throughout the logs (requesting back 1000 lines). The log timestamps show periodic jumps which correspond to me starting new games. Each section in the logs (corresponding to one Express-start / Express-stop cycle) starts with "22/08 18:48:01 [info] [M] [2332172/pickardj0] /1/pickardjgt?table=1819332" and then ends with what I think is an ajax call: "22/08 18:45:29 [notice] [T188833] [2332172/pickardj0] OK-0 485 d1 c0 e230 m179 I483 A2 V0 T0 /1/pickardjgt/pickardjgt/notificationHistory.html?table=188833&from=2&privateinc=1&history=1&testuser=2332172&dojo.preventCache=15981146779842". Logs calls during setupNewGame and the other automatic "game" states do not show up. It's not until I'm getting player interaction that the logs start to work.
In an attempt to get around this by logging to the web console, I created a "logConsole" notif with a handler that just does a "console.log(notif);". This exhibits the same behavior. Log messages fired before a player action disappear (though will err if there's a badly formatted string) but those after player action work fine.