[LIB] ErrorLogger 1.1.5 - Errors Made Beautiful!

Discussion in 'Resources' started by Icyene, Oct 13, 2012.

Thread Status:
Not open for further replies.
  1. Offline

    Icyene

    Tired of asking users to give you an error log? Do they not have the error log? Do you require any more information? Are they completely new to command line and do not know how to copy+paste?

    Save the hassle: use ErrorLogger!

    ErrorLogger is a lightweight class which saves you grief. It completely replaces the normal Bukkit reporting system, to catch the maximum amount of errors. At 169 lines in length (and getting smaller), here is what it does:

    • Reflects itself into the Bukkit logger, to catch all errors caught by Bukkit.
    • Reflects itself into the JavaPlugin logger, to catch errors on startup etc.
    • Creates an exception handler for all uncaught exceptions. Catches errors not caught by a try/catch statement.
    • Displays a user friendly, information-rich error message to the user, so they don't get frightened.
    • Saves that error to a file, so they can easily report it to you.
    • Uses first 6 characters of MD5 of String to write to the file. Meaning, no files containing duplicate errors!
    The info returned is practically everything you need to know in most cases!

    Here's a small example. I deliberately made a command in my nonexistant plugin "Derp" crash. Here is what the default Bukkit output looks like:

    Default Bukkit Error Catcher (open)

    Code:
    Unexpected exception while parsing console command "troll":
     
    org.bukkit.command.CommandException: Unhandled exception executing command 'troll' in plugin Derp v0.0.1
            at org.bukkit.command.PluginCommand.execute(PluginCommand.java:42)
            at org.bukkit.command.SimpleCommandMap.dispatch(SimpleCommandMap.java:168)
            at org.bukkit.craftbukkit.CraftServer.dispatchCommand(CraftServer.java:498)
            at org.bukkit.craftbukkit.CraftServer.dispatchServerCommand(CraftServer.java:490)
            at net.minecraft.server.DedicatedServer.ai(DedicatedServer.java:249)
            at net.minecraft.server.DedicatedServer.q(DedicatedServer.java:214)
            at net.minecraft.server.MinecraftServer.p(MinecraftServer.java:473)
            at net.minecraft.server.MinecraftServer.run(MinecraftServer.java:405)
            at net.minecraft.server.ThreadServerApplication.run(SourceFile:539)
    Caused by: java.lang.ArrayIndexOutOfBoundsException: 0
            .....
            ... 8 more
    


    It looks... intimidating. Now, the ErrorLogger output:

    ErrorLogger (open)

    Code:
    =============Derp has encountered an error!=============
    Stacktrace:
    org.bukkit.command.CommandException: Unhandled exception executing command 'troll' in plugin Derp v0.0.1
            at org.bukkit.command.PluginCommand.execute(PluginCommand.java:42)
            at org.bukkit.command.SimpleCommandMap.dispatch(SimpleCommandMap.java:168)
            at org.bukkit.craftbukkit.CraftServer.dispatchCommand(CraftServer.java:498)
            at org.bukkit.craftbukkit.CraftServer.dispatchServerCommand(CraftServer.java:490)
            at net.minecraft.server.DedicatedServer.ai(DedicatedServer.java:249)
            at net.minecraft.server.DedicatedServer.q(DedicatedServer.java:214)
            at net.minecraft.server.MinecraftServer.p(MinecraftServer.java:473)
            at net.minecraft.server.MinecraftServer.run(MinecraftServer.java:405)
            at net.minecraft.server.ThreadServerApplication.run(SourceFile:539)
    Caused by: java.lang.ArrayIndexOutOfBoundsException: 0
            .....
            ... 8 more
     
    Derp version: 0.0.1
    Bukkit message: Unexpected exception while parsing console command "troll"
    Plugins loaded: [GMail, Google, Yahoo]
    CraftBukkit version: 1.3.2-R1.0
    Java version: 1.6.0_20
    OS info: amd64 Linux, 2.6.38.2-grsec-dotcloud-ec2
    Please report this error to the Derp ticket tracker (insert ticket tracker here)!
    Error was minor; Derp will continue operating.
    This has been saved to the file ./Derp/errors/Derp_24ad10.error.log
    ===========================Derp ===========================
    


    See something in there you want, or something you'd like to add? You can! This error is also stored in your plugins folder, under the /errors folder. Also changeable!

    How it works
    If you like sneaky hacky things, then you might enjoy this.

    To handle plugin errors, ErrorLogger creates a custom PluginLogger. It makes it so that every log call must first be checked if it contains a traceback. This is determined by the plugin's package name, but once again can be modified.

    Some errors (e.g. event errors) are not logged by the plugin logger, but rather by a central Bukkit logger. This adds large complexity to the task.

    While the logger used by the plugin is one-size-fit-all, it is fitted to the plugin running it: it will only report the errors to that plugin. This inherently brings problems of, to quote Comphenix, "plugins stepping on each other's toes". My solution? Use a client-server model. The first plugin that injects the logger becomes the "server", with all subsequent plugins being "clients". How do they communicate? They use a registry-inspired method. A map containing all the registered clients and the root server are stored as a system property: "__ErrorLogger__"! Upon encountering an error, ErrorLogger will run a quick search over all the items in the __ErrorLogger__ map, and check for their packages. If they exist, let that client handle it!

    Lastly, it also catches more obscure errors, errors that are very complex in nature, and which Bukkit nor MineCraft can catch. It does this by creating a Thread.DefaultUncaughtExceptionHandler, and listening for errors.

    How do I use it?
    This is truly the simplest part. In your onEnable, simply call
    Code:Java
    1.  
    2. ErrorLogger.register(this, "YourPluginName", "YourPluginPackage", "YourTicketTracker");
    3.  

    That's it! That's all you have to do: ErrorLogger will handle everything else!



    Questions? Ask below!

    Note alot of the comments do not fit with this current post: they relate to ErrorLogger while it was still in development, and this was a tutorial.

    Placeholder

    EDIT by Moderator: merged posts, please use the edit button instead of double posting.
     
    Last edited by a moderator: May 29, 2016
    Skyost, xTrollxDudex, GregMC and 3 others like this.
  2. Offline

    Comphenix

    Interesting idea, but I'm not really convinced that intercepting log-messages with a regular expression is the best approach.

    For one, it relies on the actual error message format, which could change in the future. This could occur if Bukkit added support for multiple language packs, or needed to rearrange the message parameters. Plugins shouldn't really rely on the exact format of error messages, as it essentially turns them into fixed "APIs" that suddenly has to be maintained. That's exactly why Java added the "getStackTrace"-method, as hundreds of programs were parsing the output of Exception.toString(), effectively making that part of the main API.

    A second problem is the lack of context. Yes, you can get the exception from the LogRecord, but you have to parse the message itself to get the current task ID. And if you do that, then you're definitely asking for trouble.

    But for me, the biggest problem is that this method only really support synchronous tasks. For anything else, you still have to wrap the methods in a try-catch handler. And it would be very neat if you could do this on event handlers as well.

    So, I think a much better method is to "proxy" the PluginManager and BukkitScheduler classes, and wrap the event handlers and runnables in try-catch-methods. That way, you can get the actual event or task involved in the error, as well as the method being more future-proof.

    I've written two classes that does just that - LoggedPluginManager and LoggedScheduler. You can get them here:
    https://gist.github.com/3886658

    Using it is very simple:
    Code:java
    1. public class ExampleMod extends JavaPlugin {
    2.  
    3. @Override
    4. public void onEnable() {
    5.  
    6. LoggedPluginManager events = new LoggedPluginManager(this) {
    7. @Override
    8. protected void customHandler(Event event, Throwable e) {
    9. getLogger().log(Level.SEVERE, "Custom handler for " +
    10. ToStringBuilder.reflectionToString(event, ToStringStyle.MULTI_LINE_STYLE), e);
    11. }
    12. };
    13. LoggedScheduler scheduler = new LoggedScheduler(this) {
    14. @Override
    15. protected void customHandler(int taskID, Throwable e) {
    16. getLogger().log(Level.SEVERE, "Custom error: Task " + taskID + " caused an exception.", e);
    17. }
    18. };
    19.  
    20. events.registerEvents(new Listener() {
    21. @EventHandler
    22. public void onInventoryClickEvent(InventoryClickEvent event) {
    23. throw new RuntimeException("Problem?");
    24. }
    25. }, this);
    26.  
    27. scheduler.scheduleSyncDelayedTask(this, new Runnable() {
    28. @Override
    29. public void run() {
    30. throw new RuntimeException("Problem!");
    31. }
    32. });
    33. }
    34. }

    Since the two classes implement PluginManager and BukkitScheduler respectively, they can be inserted into pretty much any code-base without significant change.
     
    Skyost and Icyene like this.
  3. Offline

    Icyene

    Comphenix

    Definitely a way to do it, but I would still stick to mine.


    It hasn't changed for the past months, and very likely longer. If it did, instead of using a regex, something among the lines of using a Levenshtein algorithm against the log would work. If it resembles a traceback, it can be assumed that is is a traceback. An implementation of the Levenshtein algorithm in Java can be found here. One can also use a lexical matcher, such as this one. Even a Soundex matcher. Not particularly sure about the usefulness of Soundex in the scenario, but its definitely an option. In terms of speed, from highest performance to lowest: Soundex, Levenshtein, lexical matcher. In terms of results: lexical matcher, Levenshtein, Soundex.

    Most times the task ID is useless anyways, as most errors manifest themselves as convenient stack traces.

    And yet those are the hardest to intercept, as Bukkit catches the error. All uncaught errors can be caught by a custom error handler, making it work via Thread.setDefaultUncaughtExceptionHandler. Any error that is not caught by the scheduler will still be handled. This includes things like event errors. Yes, this WOULD catch errors from other plugins. Just add a filter by errorString.contains(PLUGIN_NAME) to get past that.
    Definitely a viable option, but that turns a ~100-line standalone class into a 2-class gargantuan with over 400 lines. That would put it as the largest class in most plugins, for a small feature.

    I'm heading off to bed now, but tomorrow I shall update the original post to also use a default uncaught exception handler to catch errors thrown outside of a task.

    Comphenix
    Couldn't resist, wrote it fast. Works fully.

    I updated it to catch uncaught exceptions, as well as added regexes to match all (if not, please correct me) Bukkit - caught error messages.

    For lack of a better place, I have put it here. I made generateErrorLog also take a String of where the error occurred, for better pinpointing of the location the error occurred. Can be compacted to a much smaller file, too.

    EDIT by Moderator: merged posts, please use the edit button instead of double posting.
     
    Last edited by a moderator: May 29, 2016
  4. Offline

    Comphenix

    Wait, they haven't changed it for how long? That's actually worse than I thought. If you'd written this "hack" only a couple of months ago you'd already been in trouble.

    Looking at the commit log, it seems that it was most recently changed in a commit on Aug 22, 2012. That changed the format of the error message from "Task of '{plugin name}' generated an exception", which was added on Apr 18, 2011, to "Task {task id} for {plugin name} generated an exception". That's certainly enough to break a regular expression, if you didn't anticipate it changing.

    Now, I don't actually think it's likely they'll change it - certainly, there's not a whole lot extra they can add to the error message. Though, a language pack isn't that unimaginable. But mostly, I think it's bad practice, and should be avoided. :|

    Fuzzy matching is cool, I'll grant you, but it's neither trivial nor that efficient. The big trouble is pin-pointing the exact cut-off point where you extremely rarely reject a hit (a false negative), yet also minimize the number of false positives. You have to account for the fact that the logger is used to print arbitrary statements from the plugin, and that the string you're trying to match is not constant. True, the differences are generally known in advance (like plugin name and task ID), but I still think this complication is just unnecessary.

    Right. It's more useful when you're dealing with event exceptions, as the event object can be seen as a convenient "register" dump. :)

    You might use the unique task ID if you're trying to clean up after it has crashed, but it's indeed useless for debugging.

    You can always shove a try-catch-block in the main body of the runnable though. :p

    It's bigger, but most of it is just mindless code - tons of repeated "delegate" statements for implementing the proxy class. You could just remove the proxy altogether, and put the remaining methods in a few utility classes. But where's the fun in that? :p

    I admit that there are a few problems with my method. One, it relies on the current implementation of how the plugin manager adds events to the HandlerList, so if that were to change, the LoggedPluginManager would break. Secondly, the proxy part MAY need to be updated if Bukkit (possibly) adds more methods to either PluginManager or BukkitScheduler. I could solve this by using a dynamic proxy, but I decided not to bother with it. It's either slower (using java.reflect.proxy), or far more complicated (dynamic code generation).

    But don't get me wrong - overall, I really like the idea. It's good to add more detailed debug information than the bog-standard version in Bukkit, and I also like that you're separating the error reports into different folders for different plugins. The question "Please post the full stack trace" is far too common when I'm dealing with error reports, so it's always a good thing to automate the process a little. Sending the "error file" might yield far more useful information than what the person at the time could dig up in the main log file. Especially considering the ballooning size of that thing. :p

    With a full feature-rich library, plugins could implement semi-automated error reporting for nothing. It would help plugin authors tremendously, not just in dealing with problems that are already reported, but also in getting a better picture of what kind of issues people are grappling with.

    I'm just critical of the technical implementation, that's all. Otherwise this is great. :D

    That does look nice, but are you sure you tested every part of it? When I was working on catching unhandled exceptions in even handlers, I couldn't get it to work with your logger injection.

    I think it's because it's getting passed to the main logger, as it doesn't include the name of the plugin causing the error in brackets:
    EDIT by Moderator: merged posts, please use the edit button instead of double posting.
     
    Last edited by a moderator: May 29, 2016
  5. Offline

    Icyene

    Comphenix
    Sorry if I came off a bit irritable yesterday: my phone had been stolen, had a fever, and heater in house failed to work :/.

    That said:

    Hmm, didn't notice that :p

    I actually wrote this for a plugin of mine, and decided to share it with the world. The plugin dabbles in NMS code either way, so it would have to be updated regardless.

    Or even simpler, regex to match package names! Check for that regex, check for PLUGIN_NAME. If both exist, its probably an error log. It might be a dog, but if it looks like an error log, handle it like an error log :)

    The driving factor for making this was a user who reported "The plugin doesn't exist in /list, and none of the commands do anything. No errors are given, either." :/

    Dynamic code generation would also bloat it :) A proxy would work, since the logger is rarely called to display tracebacks (hopefully). But inheritance is so much easier.

    Ah, I didn't test that. Not a biggy: its a one-size-fit-all logger anyways. All I need to do is find the main logger.

    EDIT: Got it to work with the main logger, but now NPE's on getStackTrace. Its here.

    Initializing it IS a bit different:

    Code:Java
    1.  
    2. private void initErrorLogging() throws NoSuchFieldException, IllegalAccessException {
    3. ErrorLogger log = new ErrorLogger(this);
    4. Field logger = JavaPlugin.class.getDeclaredField("logger");
    5. logger.setAccessible(true);
    6. logger.set(this, log);
    7. Field logger_mc = MinecraftServer.class.getDeclaredField("log");
    8. logger_mc.setAccessible(true);
    9. Field cb_mcs = CraftServer.class.getDeclaredField("console");
    10. cb_mcs.setAccessible(true);
    11. logger_mc.set(cb_mcs, log);
    12. }
    13.  

    Double reflection :). One to get the MinecraftServer from the CraftServer (console), and the other to get/set the logger for the MCServer.

    Comphenix
    Done!

    Made it catch all logs sent by Bukkit and JavaPlugin, as long as they contain the package name. Also added a 'Bukkit message:' part to the StringBuilder. That just displays info that Bukkit provides, such as "Task blahblah has generated an exception". So no parsing needed, even to get the task ID.

    Also, due to the use of package name, this will survive any localization efforts.

    Additionally, to make this more usable, I overloaded ErrorLog to also take tracker location, plugin name etc.

    Plugin disabling code is now automatic, using PluginManager.disablePlugin.

    It's here :)

    Definitely not the most beautiful code; the StringBuilder appending looks like a wall, but it does work.

    Now all that needs to be done to make this fully useable is add a variable number of '='s for the ending line. Right now it only looks nice if PLUGIN_NAME.length() == 5, as it was fitted for my plugin "Storm" :p

    EDIT by Moderator: merged posts, please use the edit button instead of double posting.
     
    Last edited by a moderator: May 29, 2016
  6. Offline

    Comphenix

    Ingenious. :D

    That should be fairly solid, at least as long as Bukkit is using the log(Level, String, Trowable) method. :p

    Though, what happens when multiple plugins use your method? Won't they step on each others toes? Maybe not in the case of the local PluginLogger, but the logger in MinecraftServer and CraftServer might cause conflicts.

    I guess you can either create a small standalone library, convert the PluginLogger to a proxy class, or use a client-server model.

    In the last method you'd add a check in the initialization code to test if the specific log classes have already been hooked. If not, the current plugin hooks them and proceeds as normal. This plugin is then known as the server

    If the log classes have been hooked, the plugin instead registers a listener. It then becomes a client, and the server is responsible for informing each client of any subsequent "exceptions". Once a server unloads, it properly reverts the hooked classes and passes on its duty to the next client on the list (or just quits, if there isn't any clients left).

    It's a bit complicated, but that's what you have to deal with if you're hooking global classes. :p

    What about the event object? I can contain a good deal of useful information:
    You should use more of Guava and Apache Commons in your code. :p

    That's extremely easy to perform with StringUtils.center(String, int, char). Sure, it's not hard to write yourself, but then again, you didn't. It's usually something you just put off until you get the basic functionality working. But by using the already existing implementation you get it functioning at once.

    Of course, Apache Commons is a fairly recent addition, but I can't see them removing a dependency like that.
     
    Icyene likes this.
  7. Offline

    Icyene

    Comphenix
    Thanks for the feedback :)


    Correct. For the JavaPlugin, its only for the plugin using it, but the MCServer WILL conflict. I think I should make this class event-driven. So even if there are multiple plugins using this, bad things won't happen.


    The 'Bukkit message:' section is just whatever Bukkit makes the message be. That includes the event info, if it appears in the normal log.


    While you were writing this, I actually did make it have the variable number of '='s. and used ExceptionUtils.getStackTrace instead of my own. This :p


    I've started on the event-driven part. Probably will take a while, as I'm also trying to install Windows on an EEEPC without an external disk drive ;/
     
    Comphenix likes this.
  8. Offline

    Comphenix

    Right. Unfortunately, it doesn't:
    Code:
    2012-07-12 04:15:22 [SEVERE] Could not pass event BlockBreakEvent to ExperienceMod
    org.bukkit.event.EventException
        at org.bukkit.plugin.java.JavaPluginLoader$1.execute(JavaPluginLoader.java:304)
        at org.bukkit.plugin.RegisteredListener.callEvent(RegisteredListener.java:62)
        at org.bukkit.plugin.TimedRegisteredListener.callEvent(TimedRegisteredListener.java:30)
    The version I quoted in the post above was from my own custom logger.

    Not that it's necessarily that useful. But I do like to include dumps of the calling parameters and the current state in my own custom error reporter. It's a static class with a list of every global "parameter" (essentially, classes that contain the current configuration, state, ect.), and the report can be supplied with the parameters of the calling method. But of course, I (stupidly) added a try-catch to every listener method manually ...
     
    Icyene likes this.
  9. Offline

    Icyene

    Comphenix
    Fixed a bug which caused the server to alias under the first registered plugin, and used more Apache, as you suggested :p

    A surprising amount of things can be compacted with Apache. I got over 60 lines into one line...

    The aliasing bug was fixed by registering differently. When setting for the server, use reflection to set PluginLogger.pluginName to "". This makes it not require a completely different logger. Also, to keep plugins from not conflicting, I switched to using System.property as a registry, where all ErrorLoggers can get crucial information on how to behave. I also cleaned it up, so it doesn't hurt as much to look at :p

    Also, to keep the loggers from conflicting, I used your server/client idea, and use System.Properties to store a "registry". This is in the format:

    Code:
    {Plugin=[Name, Package, TicketTracker, Endline]}
    
    I simply used a .replace and .split statement to turn that into a HashMap<String, List<String>>. The first plugin which loads ErrorLogger reads from this registry for Bukkit-logged errors, and displays the message needed.

    Anyways, thanks for your input! Your ideas really helped :D
     
    Comphenix likes this.
  10. Offline

    Icyene

  11. Offline

    Icyene

    ErrorLogger 0.0.4 is ready!
    Two key changes in this version:
    • File names now include the simple name of the exception. Allows for finding critical errors easily.
    • Fixed a corner case where a NullPointer could occur.
     
  12. Offline

    xXSniperzzXx_SD


    So i got a very nasty and giant error, the only part of it that is related to the plugin that is told about in the error, is the ErrorLogger

    http://dev.bukkit.org/server-mods/infected-core/tickets/17-heres-a-bug-i-got/Just Use <Ctrl> + F then type Infected, It's about half way down the page


    Line 70

    Line 36
     
  13. Offline

    Icyene

    Strange. I would assume that an error occurred in the ExceptionUtils.getStackTrace (which I daresay might be Apache's fault), yet since that code is before the checking whether the error occurred in the error logger, the anti-StackOverflow measures I took are rendered null and void.

    Change that section to:

    Code:Java
    1.  
    2. String ERROR = "", NAME = "", TICKETS = "", ENDL = "";
    3.  
    4. try {
    5. ERROR = ExceptionUtils.getStackTrace(thrown);
    6. NAME = "";
    7. TICKETS = "";
    8. ENDL = "";
    9. } catch (Exception e) {
    10. return true;
    11. }
    12.  


    That way if the error DOES occur, it is caught and handled WITHOUT a StackOverflow.
     
  14. Offline

    Uniclaw

    Wow, nice :D ! But one thing: Eclipse say's, that the Method getProperty don't exists - how i fix that?
     
  15. Offline

    Icyene

    Uniclaw import static java.lang.System.getProperty, or append 'System.' before each getProperty.
     
  16. Offline

    Uniclaw

    Thanks :D !
     
    Icyene likes this.
  17. Offline

    xXSniperzzXx_SD

    When i try to get a number that's null, this doesn't produce any errors, so i sat there for 30 mins trying to find out why something wouldn't work but didn't create errors... If you need the exact code just reply to me, if you don't reply to me when you fix it :p
     
  18. Offline

    Icyene

    Code please :) I have noticed this happening as well, but it happens seemingly randomly. Make sure that the code in question is NOT in a try/catch blocks: ErrorLogger cannot catch errors caught in your try catches, even if they dispose of the error silently.
     
  19. Offline

    xXSniperzzXx_SD

    I'm to lazy to use any try catches, plus i don't know how to use em properly :p Give me a day, i ended up fixing the error earlier, so i need to replicate it now....
     
  20. Offline

    lucasdidur

    Hello,

    I can do this?

    Code:
    ErrorLogger.register(this, "MyPlugin", "com.me.myplugin.*", "http://lalala.com");
    
     
  21. Offline

    Icyene

    lucasdidur Yes, just remove the "*". ErrorLogger uses a simple Stacktrace.contains(thePackageString), so you don't need any wildcards. If you add wildcards, contains will usually return false.
     
  22. Offline

    xXSniperzzXx_SD

    Ok, so i can't seem to replicate the error causing.. I'll continue on with my plugin and if it happens again i'll make sure to post code :p
     
  23. Offline

    lucasdidur

    I'm getting some error:

    The method getProperty(String) is undefined for the type ErrorLogger


    Could you add all imports on source file?

    @Edit
    Fix adding System.getProperty()
     
  24. Offline

    Icyene

    lucasdidur

    Or do import static java.lang.System.getProperty. I used a static import because its cleaner than adding System. to every getProperty, of which there are quite a few.
     
  25. Offline

    Icyene

    ErrorLogger 1.1.5 released

    This version fixes all bugs which have been found, the most critical being the one discovered by xXSniperzzXx_SD . This version also contains all imports, for those having trouble finding which classes to import.
     
  26. Offline

    xXSniperzzXx_SD

    Yay! My name was said! Oh and i guess an update is good too....

    lol, I'll inform you if anymore errors appear :p
     
  27. Offline

    xXSniperzzXx_SD

    Icyene
    Spigot produces a bug when the plugin is launched

    http://pastie.org/5500161
    was the error i got, from what i can tell line 168
    Code:
    mcLogger = MinecraftServer.class.getDeclaredField("log");
    is trying to get a class that is apparently not in spigot, i was wondering if this is something you can fix, or if i report it to the makers of Spigot
     
  28. Offline

    bob7

    I love it!
     
  29. Offline

    Icyene

    'Tis a Spigot issue. They renamed net.minecraft.server to net.minecraft.server.v1_4_5, breaking everything using native MC code :'-(
     
  30. Offline

    xXSniperzzXx_SD

    Oh but couldn't we just check if that class is null, and if it is use the other class?
     
Thread Status:
Not open for further replies.

Share This Page