[Bug 78] New: bad index in extract CallerData

http://bugzilla.qos.ch/show_bug.cgi?id=78 Summary: bad index in extract CallerData Product: logback-classic Version: unspecified Platform: Macintosh OS/Version: Mac OS Status: NEW Severity: blocker Priority: P1 Component: Other AssignedTo: logback-dev@qos.ch ReportedBy: hansm@science.uva.nl CC: hansm@science.uva.nl Below is code from CallerData (logback 0.9.7) This gives an error as shown below. java.lang.ArrayIndexOutOfBoundsException: -1 at ch.qos.logback.classic.spi.CallerData.extract(CallerData.java:101) at ch.qos.logback.classic.spi.LoggingEvent.getCallerData(LoggingEvent.java:246) In my code (Eclipse RCP) LoggingEvent's are collected by an appender in a java.util.List. Then a Jface TableViewer is allocated and the input set to that list. The processing of the accumulated LoggingEvents now each throw the ArrayIndexOutOfBoundsException. After registering the viewer containing object with the appender, new incoming LoggingEvents are given to the viewer and are processed without problem. It looks like the "int found" has kept its value of -1, presumably because the equals in line 88 never becomes true. I am inclined to consider this a bug, or at least unsafe coding, because a bad index in certain circumstances can reach the code in line 101. The code in lines 86-97 does not guarantee that a bad index cannot occur. 78 public static CallerData[] extract(Throwable t, String fqnOfInvokingClass) { 79 if (t == null) { 80 return null; 81 } 82 83 StackTraceElement[] steArray = t.getStackTrace(); 84 CallerData[] callerDataArray; 85 86 int found = -1; 87 for (int i = 0; i < steArray.length; i++) { 88 if(steArray[i].getClassName().equals(fqnOfInvokingClass)) { 89 // the caller is assumed to be the next stack frame, hence the +1. 90 found = i + 1; 91 } else { 92 if(found != -1) { 93 break; 94 } 95 } 96 97 } 98 99 callerDataArray = new CallerData[steArray.length - found]; 100 for (int i = found; i < steArray.length; i++) { 101 callerDataArray[i-found] = new CallerData(steArray[i]); 102 } 103 return callerDataArray; 104 } 105 -- Configure bugmail: http://bugzilla.qos.ch/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are the assignee for the bug, or are watching the assignee.

http://bugzilla.qos.ch/show_bug.cgi?id=78 noreply.ceki@qos.ch changed: What |Removed |Added ---------------------------------------------------------------------------- Status|NEW |ASSIGNED ------- Comment #1 from noreply.ceki@qos.ch 2007-06-06 10:05 ------- Hi Hans,
From what you describe, it looks like the caller data is inaccessible due to the fact that the processing of the event is done at a later time. If you look into the ch.qos.logback.classic.spi.LoggingEvent class, you find a method called prepareForDeferredProcessing(), which as the name indicates, prepares the logging event for later processing by initializing fields that can be correctly initialized when the event is created and not later.
For some reason, the extraction of caller data is not part of the method, it probably should be. Is it possible for you to build logback? -- Configure bugmail: http://bugzilla.qos.ch/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are the assignee for the bug, or are watching the assignee.

http://bugzilla.qos.ch/show_bug.cgi?id=78 ------- Comment #2 from hansm@science.uva.nl 2007-06-09 11:44 ------- In Reaction to the email I received (somehow I could not reply to it directly): I must admit overlooking "public void prepareForDeferredProcessing()" as a possible solution because I did not fully understood the remark to the "asynchronous logging" (thinking it not being applicable in mys case, having all my code running on the same thread). I tried it, BUT it did not work. Looking into the source I saw this method (gets) and returns the name of the current thread. That proved not to be sufficient. However, the workaround I did find is calling the LoggingEvent method getCallerData() before putting away the logEvent for later use. This will store the caller data into the LoggingEvent, albeit of the cost of doing this even if it might not be needed later. But it prevents the ArrayIndexOutOfBoundsException. Allow me to make the following comment: The fact that the code allows the callerDataArray to be called with index -1 makes it inherently unsafe, no matter what caused it. It is my humble opinion that no code should allow this happen, if there is any possibility of preventing this in a natural way. If one calls the offending behaviour a bug is of course a matter of opinion. However because the use can be caught unaware by the ArrayIndexOutOfBoundsException -- at least that is how it happened how to me -- my advice would be to guard this code, for example by returning a zero length array in the case found==-1; as far as I can see than no useful output results but no error either. Would this be a viable proposition apart from always filling in the callerDataArray? Hans van der Meer -- Configure bugmail: http://bugzilla.qos.ch/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are the assignee for the bug, or are watching the assignee.

http://bugzilla.qos.ch/show_bug.cgi?id=78 noreply.ceki@qos.ch changed: What |Removed |Added ---------------------------------------------------------------------------- Status|ASSIGNED |RESOLVED Resolution| |FIXED ------- Comment #3 from noreply.ceki@qos.ch 2007-08-21 19:47 ------- Hello Hans, Problem fixed along the lines you suggested. Thank you for researching this bug. See also http://svn.qos.ch/viewvc?view=rev&revision=1566 -- Configure bugmail: http://bugzilla.qos.ch/userprefs.cgi?tab=email ------- You are receiving this mail because: ------- You are the assignee for the bug, or are watching the assignee.
participants (1)
-
bugzilla-daemon@pixie.qos.ch