Page 1 of 3 1 2 3 LastLast
Results 1 to 10 of 25

Thread: Request: Add Note to Debug Log

  1. #1
    Senior Member MCroft's Avatar
    Join Date
    Feb 2009
    Posts
    248

    Default Request: Add Note to Debug Log

    Would it be useful to you all to have a command on the help menu that would let users (like me) add text to the debug log?

    I am about to start a debug log to capture an event for an upcoming bug report and it occurred to me that it would be useful to be able to add comments like "I turned on Skip Pickpocketing here." and "now I turned it off."

    Something like
    Add Note to Debug Log:_____________

    ------
    MCroft note (logdate): "Whatever I entered above."
    ------

  2. #2
    Senior Member MCroft's Avatar
    Join Date
    Feb 2009
    Posts
    248

    Default

    Well, I've got 90% of it done, which was figuring out how to add a menu item, how to call an input dialog, how to send the message to the log, how to start with the menu disabled.

    Now I want to figure out how to enable the menu when the debug log is started and turn it off when the debug log is stopped. We'll see how long that takes...

    Still interested in feedback if this is valuable, could be improved, or if I'm just teaching myself stuff...

  3. #3
    Developer Veracity's Avatar
    Join Date
    Mar 2006
    Location
    The Unseelie Court
    Posts
    13,666

    Default

    I like the idea, and will comment later after I have had a chance to sleep.

  4. #4
    Developer fronobulax's Avatar
    Join Date
    Feb 2009
    Location
    Central Virginia, USA
    Posts
    4,865

    Default

    I spent a portion of my career where the original log files were made read only and archived as soon as possible. This suggestion makes me cringe although there is no reason for me to do so.

    Question? How is the insertion point determined? If I am running one adventure at a time that is obvious, but if I am auto-adventuring for a few turns is this going to give any more than a leading or trailing comment?

    Tangentially I have often wondered about recording the commands typed into the gCLI and (optionally) merging those with log. That might be an alternative way to provide similar functionality if this doesn't work as hoped.

  5. #5
    Senior Member MCroft's Avatar
    Join Date
    Feb 2009
    Posts
    248

    Default

    I've spent a lot of my career dealing with log files that rotate daily or when they reach 4m characters, so these logs seem nice and compact.

    Log files are (to my mind) streams, so the insertion is immediate. There are definitely cases that aren't the one I thought of that I should understand. I'm not sure what you'd want in terms of the insertion point, and I can't test until rollover (story of my life...). My reasonably naive implementation just gets a string from user input and calls RequestLogger.updateDebugLog(userNote);. Obviously other options could be looked into if there's a more helpful way to do it.


    So, things to test:
    Menu item, between commands
    Menu item, auto-adventuring
    Menu item, gCLI queued commands
    Menu item, ash script running

    Ways to extend this that I've considered after reading your thoughts:
    1: add a gCLI command to do the same as the menu item. Same tests needed.
    2: add an ASH function, to allow scripts to log things.
    3: add an optional parameter to itrace/ptrace to allow criteria-based logging (e.g. "itrace -note 'this is where I lost my TPS!' tiny plastic sword"). I'm not sure if that's the ideal command, but something trigger/change based.

  6. #6
    Developer fronobulax's Avatar
    Join Date
    Feb 2009
    Location
    Central Virginia, USA
    Posts
    4,865

    Default

    I just realized I am guilty of conflating the debug log and the session log so take my previous comments with a shaker of salt.

    My comment was rooted in the idea that there are two asynchronous things going on. Any comment that, for example, is inserted into a verbose debug log which is logging all HTML to and from KoL is probably not going to be relevant to the lines in the immediate vicinity. I can construct scenarios where the comment doesn't end up in a useful place. What I have not done is any experimentation to prove or disprove the existence of those scenarios.

    On several occasions I have seen something in the gCLI, not found it in the session log and changed KoLmafia to write the information in both places. An obvious solution would be to make the gCLI output and the session log mirrors. That let's a scripter insert using print, for example. Buy the gCLI supports and renders HTML and the session log is deliberately kept to be plain, human readable text. So HTML in the gCLI is deprecated, something renders the HTML before writing to the session log or the session log is allowed to contain HTML. The benefits of any of these, minus the cost of implementing them, have not seemed to exceed the benefits of the status quo.

  7. #7
    Senior Member MCroft's Avatar
    Join Date
    Feb 2009
    Posts
    248

    Default

    For what it's worth, it inserts the comment in the middle of the sequence when auto-adventuring or maximizing. That makes sense: it calls updateDebugLog(), which writes out what it gets.

    And of course it may not be useful information or in the right place, but that's true of anything in bug reports. That's true of my own bug reports in this forum and I am a supposedly-trained tester. I just had one where Veracity had to tell me what I was seeing was a red herring (it was two different issues).

    In terms of merging gCLI and session, Would you want to add a HTML-to-plaintext library, like jsoup or Jericho? Is it valuable to mark which lines come from which source?

    A gCLI print (or similar log note) could still be"in the wrong place", because the gCLI queues commands to run after auto-adventuring, but that gets into "we can probably find a way to make it do something wrong for some circumstances".

    If the session log and debug log are easy to compare and gCLI entries and responses go into session log, then I can already do what I want with ashq print("this is my user note"). It might be better to separate out an explicit log command, but there are already a lot of commands.

  8. #8
    Developer fronobulax's Avatar
    Join Date
    Feb 2009
    Location
    Central Virginia, USA
    Posts
    4,865

    Default

    Sorry. Used a "DRINK ME" potion and wandered about looking at the differences between the session log and the debug log and asking why? I got an answer I can live with but I asked.

    If your experiments put the comment in a useful place in the debug log then it is worth continuing.

    I will expend a lot of effort to avoid dealing with Swing. There's a lot I never really understood and when I had to write it anyway I had access to both in house UI standards and a third party library that handled the fiddly bits.

    So I wonder about a (new?) ash command boolean write_to_debug_log(userNote). All it really does is RequestLogger.updateDebugLog(userNote). The return value is true if the string was written and false otherwise. For 99.44% of the cases I can think of (and easily check for) false is equivalent to "debugging is not turned on".

    void main(String userNote) {
    boolean ok = write_to_debug_log(userNote);
    }

    as a script can be invoked several ways and if the user doesn't specific the note, they will be asked for it.

    This needs a little more thought since turning on debugging will create a new file or append to an existing file AND set a flag that enables additional information to be logged. I can see cases where I want to write a note to a debug log even if the extra logging for debugging is off. I would also want to think about whether this introduces a new threat vector (as compared to using map_to_file, for example) and make sure the implementation dealt with that.

    One argument reducing my motivation for aligning the gCLI and session log is the existence of the mirror command. Turn it on in the login script and off in the logout script. Have a filename convention and then use OS scripting to rename and/or remove mirror files as necessary. A diff between the session log and the mirror log would be interesting and identify places where mafia could be changed.

    As far as the session log goes I would also investigate the cli commands logecho and logprint.

  9. #9
    Senior Member MCroft's Avatar
    Join Date
    Feb 2009
    Posts
    248

    Default

    Hey, no worries. We're discussing something that users will be a producer of and devs are the consumers of, and which I've got mostly implemented, but which I want to understand what would be most useful to you all, so I can either make a patch that works or which devs can review, fix, and I can compare to mine and learn something from.

    So, time is not of the essence here. . Anyway, apologies that this is sorta long.

    It occurred to me that there were (at least!) three ways to handle debug commands with debug off
    1. Error/Return False/Disable the menu item
    2. Turn on Debug log and log as requested (implicit activation)
    3. Turn on Debug Log, write entry, turn off debug log (temporary activation)


    My (as yet unimplemented plan) for the GUI was to disable the note command unless the log was active. I am naively convinced I can figure out how to modify the Debug menu item to also toggle the enabled/disabled field of the DebugNote menu item. I could also leave it enabled and check for isDebugging() and respond with an error if false. I might want to do that anyway, incase the debug command is invoked/disabled outside of the menu. (Aside: I noticed that I can start the debug log in the gCLI, but it doesn't toggle the Help menu from Start to Stop. Probably nobody ever starts in the gCLI and stops from the menu, but it does seem inconsistent.)

    updateDebugLog() seems to write to a predictable but not user-selectable file, and inserts a lot of header info, so I don't see a way to get it to do something nefarious at the OS level, like write a preference, script, or . We could have a truncate function to keep it to a maximum length or any other filtering effect we thought was needed (URLEncoding?). From prior log experience, we might want to make sure the log couldn't have the user credentials in them, but I'm not sure that the debug log doesn't already have them and I'm not sure if ash has the password as a variable anyway.

    As far as an ash command, boolean write_to_debug_log(userNote) sounds right to me.
    Code:
    All it really does is RequestLogger.updateDebugLog(userNote). The return value is true if the string was written and false otherwise. For 99.44% of the cases I can think of (and easily check for) false is equivalent to "debugging is not turned on".
    isDebugging() lets you test for that fast and return early, 99.44% of the time. You could also try to aggressively turn on the log, depending on the design philosophy. Same options as listed above, but ash gets its own thinking/consideration...

    Other (hard to test) cases are file deleted/partition full/out of file handles/drive dismounted/any of the normal log writing failure causes, but other things are probably failing by that point.

    updateDebugLog has 4 method signatures:
    public static final void updateDebugLog()
    public static final void updateDebugLog( final String line )
    public static final void updateDebugLog( final Throwable t )
    public static final void updateDebugLog( final Object o )

    If you want to skip the blank and instead prompt for a String (or something else that will give a string via o.toString()), that's reasonable and Ash only really has to support methods 2 and 4. And 2 may reasonably collapse into 4, because java supports String.toString() (probably for just this case).

    For my menu-based command, I was sending "-----\n${UserNote}\n-----", but I don't think you'd want that from the ash command.

    Anything else you think I should consider?

  10. #10
    Developer fronobulax's Avatar
    Join Date
    Feb 2009
    Location
    Central Virginia, USA
    Posts
    4,865

    Default

    Still processing coffee so...

    I really need to confirm that if the debug file already exists then toggling debug on will append. If so I can see a case where you want to stop debugging, insert a comment and start debugging again. That means the proposed ash command should save the value of the debugging flag, set it to true (implicitly creating or opening the file as needed), write to the log and then set the flag to the original value (implicitly closing the file if needed).

    Upon further consideration I don't see a new threat from a user controlled write to the debug file.

    If we use existing code to open, close and write I am not concerned about all the stuff that could happen at the OS level that would make the process fail. We will protect and detect however we did before and that is OK with me, in spite of my personal tendency to over-engineer things in response to low probability situations.

    I'm not sure (at least for v1.0) there is much of a case for passing anything but a string to updateDebugLog. Since the goal is human readable info in a file and the initial approach was to get a string from the user that should be fine. ASH can work around the limitation by using toString on any thing it has access to. If you are proposing a GUI element that lets a user select an arbitrary object and send it to the log (where it will be toString'ed anyway) then maybe we step back and focus on the requirements - what is needed as opposed to what could be done :-)

    Remember that this is your project. No one else seems to be interested enough to ask for it or ask that it not be done. So whenever you get a patch I will review and submit. To the extent that I can help write it you may certainly ask but...

    :-)

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •