LMS 3.0 - Syslog Report problem

Unanswered Question
Dec 20th, 2007
User Badges:

Hi,


I'm having a problem generating the syslog reports, where if either 24-hours or unexpected devices report type is selected with all the devices to run against after awhile (in about 2 - 3 min) I get the Tomcat error 500 with java.lang.StringIndexOutOfBoundsException: String index out of range: -9


The other reports seem like ok (the Severity summary or Reload), this makes me think that there could be a message in the SyslogDB that has some weird format or something, so when the report engine comes across one, it quits.

Are there any well known troubleshooting scenarios for such problems or the one way is to reinitilize the rme db?


Thanks

  • 1
  • 2
  • 3
  • 4
  • 5
Overall Rating: 0 (0 ratings)
Loading.
Joe Clarke Thu, 12/20/2007 - 09:52
User Badges:
  • Cisco Employee,
  • Hall of Fame,

    Founding Member

What is the full text of the exception?

dmitry Thu, 12/20/2007 - 15:42
User Badges:

Here it is:


java.lang.StringIndexOutOfBoundsException: String index out of range: -9

java.lang.String.substring(String.java:1768)

com.cisco.nm.uii.reports.SimpleTableTextColumn.compare(SimpleTableTextColumn.java:62)

java.util.Arrays.mergeSort(Arrays.java:1284)

java.util.Arrays.mergeSort(Arrays.java:1296)

java.util.Arrays.mergeSort(Arrays.java:1296)

java.util.Arrays.mergeSort(Arrays.java:1296)

java.util.Arrays.mergeSort(Arrays.java:1295)

java.util.Arrays.mergeSort(Arrays.java:1296)

java.util.Arrays.mergeSort(Arrays.java:1295)

java.util.Arrays.mergeSort(Arrays.java:1295)

java.util.Arrays.mergeSort(Arrays.java:1295)

java.util.Arrays.mergeSort(Arrays.java:1296)

java.util.Arrays.mergeSort(Arrays.java:1296)

java.util.Arrays.mergeSort(Arrays.java:1295)

java.util.Arrays.sort(Arrays.java:1223)

java.util.Collections.sort(Collections.java:159)

com.cisco.nm.uii.reports.TabularTablePersist.indexSortableColumn(TabularTablePersist.java:537)

com.cisco.nm.uii.reports.TabularTablePersist.privateIndexAllSortableColumns(TabularTablePersist.java:356)

com.cisco.nm.uii.reports.TabularTablePersist.indexAllSortableColumns(TabularTablePersist.java:333)

com.cisco.nm.uii.reports.TabularTable.indexAllSortableColumns(TabularTable.java:67)

com.cisco.nm.rmeng.sa.ui.reports.datagenerators.ReportDataGenerator.generateReport(ReportDataGenerator.java:594)

com.cisco.nm.rmeng.sa.ui.reports.action.SyslogReportsAction.perform(SyslogReportsAction.java:275)

org.apache.struts.action.ActionServlet.processActionPerform(ActionServlet.java:1786)

org.apache.struts.action.ActionServlet.process(ActionServlet.java:1585)

org.apache.struts.action.ActionServlet.doPost(ActionServlet.java:509)

javax.servlet.http.HttpServlet.service(HttpServlet.java:709)

javax.servlet.http.HttpServlet.service(HttpServlet.java:802)

com.cisco.nm.cmf.util.AccessLogFilter.doFilter(Unknown Source)



note The full stack trace of the root cause is available in the Apache Tomcat/5.5.17 logs.



Some notes:

- the exception above is from 24-hours report, for unexpected devices report the exception almost the same: the java.lang.StringIndexOutOfBoundsException: String index out of range: has -52 instead of -9


- in the tomcat log /opt/CSCOpx/MDC/tomcat/logs/stdout.log:


a lot of INFo messages like this about the accessLogFilter and then the exception itself


[Thu Dec 20 18:33:17 EST 2007] DoLicenseCheck Returned:true

Dec 20, 2007 6:33:18 PM org.apache.catalina.core.ApplicationContext log

INFO: action: UIIController processActionForward does not have a screenID so no authorization was done for /WEB-INF/screens/uii/hosTree.jsp.

AccessLogFilter: Thu Dec 20 18:33:22 EST 2007- From: 10.224.102.106 - UserName: XXXX - RequestURI = /rme/SyslogReports.do - Cookies: JSESSIONID=91853107797133270CE11973AE10D047;jsessionid=CD7D38D843D81314D4E1616B18703637;MICEcookie=CD7D38D843D81314D4E1616B18703637;

[Thu Dec 20 18:33:22 EST 2007] CoreContextNexus ValidateConnection:true

[Thu Dec 20 18:33:22 EST 2007] Invoke doLicenseCheck!

[Thu Dec 20 18:33:22 EST 2007] DoLicenseCheck Returned:true

Dec 20, 2007 6:34:30 PM org.apache.catalina.core.StandardWrapperValve invoke

SEVERE: Servlet.service() for servlet action threw exception


From here it is the acual exception text which is showing up in the browser (I posted it above)

Joe Clarke Thu, 12/20/2007 - 17:13
User Badges:
  • Cisco Employee,
  • Hall of Fame,

    Founding Member

I found the problem, and I have a patch, but I would love to know the messages you're getting. I had to construct a custom message to reproduce this, but I'd like a real world example when I file the bug.


To get the patch, open a TAC service request, and have them contact me directly.

dmitry Fri, 12/21/2007 - 15:03
User Badges:

Thanks for looking into it, will go ahead and open up a TAC case.


There are ~500 devices sending the syslog messages including the DMVPN related stuff, VPN3000 messages, AS5400 dial-up server messages. Will be very hard to locate one (or may be more than one) unless there is some debug that can be enabled to show where exactly the exception is happening in the query with references to the cause

Joe Clarke Fri, 12/21/2007 - 15:16
User Badges:
  • Cisco Employee,
  • Hall of Fame,

    Founding Member

The interesting message will contain a '<'.

dmitry Fri, 12/21/2007 - 15:27
User Badges:

Here we go:


Dec 15 17:13:54 mrkmccrtr11.net.otn.local 1985: -Process= "", ipl= 1, pid= 73, -Traceback= 0x612DA868 0x6001D94C

0x6001D9B0 0x615D0A10 0x60087C5C 0x606488F8 0x6064CD60 0x601EC6C8 0x606B1D7C 0x602DCF04


The actual traceback is suppose to be a "cosmetic" bug on c7200s with 12.4.15T1, so far it has not crashed (the fix for it in 12.4.16.13T had a broken AAA, so no use)

Joe Clarke Fri, 12/21/2007 - 16:26
User Badges:
  • Cisco Employee,
  • Hall of Fame,

    Founding Member

That's not a well-formed syslog message, so it would have never made it into the database. There should be one with a FACILITY-SEVERITY-MNEMONIC tag that also has a '<' in it.

dmitry Fri, 12/21/2007 - 18:44
User Badges:

Ok, found it, from the dial up server:


Dec 21 13:43:52 mrkmccasm01.net.otn.local 1381: Dec 21 13:43:51 EST: %MODEMCALLRECORD-6-PM_TERSE_CALL_RECORD: DS0 slot/contr/chan=1/0/14, slot/port=3/7, call_id=1F3, userid=fht-tor, ip=10.224.137.3, calling=(n/a), called=XXXXXXXX std=V.34+, prot=LAP-M, comp=V.42bis, init-rx/tx b-rate=28800/33600, finl-rx/tx b-rate=28800/33600, rbs=0, d-pad=None, retr=0, sq=5, snr=40, rx/tx chars=18136/19726, bad=0, rx/tx ec=112/146, bad=0, time=29, finl-state=Steady, disc(radius)=user-request/PPP Receive Term, disc(modem)=1F03 /Requested by host/DTR dropped



And from the VPN3000:


ec 21 11:51:14 thunderbay-tr-backup.XXX.com 435481: 2007 Dec 21 11:51:15.550 EST -5:00 %AUTH-4-5: RPT=5: 205.X.Y.Z: Authentication rejected: Reason = Unspecified handle = 543, server = 10.227.240.129, user = XXXX, domain =



Another one from the VPN3000 when it throws a dump of the IPSEC connection (have not had time set the filter on the syslog in LMS for the IPSEC junk):


Dec 20 15:34:17 vpn3030-13.xxxxxx.com 1450253: 2007 Dec 20 15:34:18.210 EST -5:00 %IPSEC-5-0: RPT=21438: 0000: 015484F0 0002D41D BACE8032 475D31A4 .T.........2G]1. 0010: 45000038 00000000 8001D4C7 0AE0CF01 E..8............ 0020: 0AE0813C 030105A8 00E0CF13 45000030 ...<........E..0 0030: 6D220000 7A116CB2 0AE0813C 0AE0CFEC m"..z.l....<.... 0040: 37A737A7 001CB7F8 01020304 05060604 7.7............. 0050: A09723AA C77BA849 E1356E81 FD9E9377 ..#..{.I.5n....w 0060: 20332033 8280FFFF FFFFFFFF FFFFFFFF 3 3............ 0070: FFFFA709 01FE4CE8 D86AA2BD 4F61A4A5 ......L..j..Oa..

andrewswanson Mon, 02/25/2008 - 04:13
User Badges:
  • Bronze, 100 points or more

hello

we're having the same problem with our vpn 3000 - can view Notifications but get the following for Informational:


HTTP Status 500 -

________________________________________

type Exception report

message

description The server encountered an internal error () that prevented it from fulfilling this request.

exception

java.lang.StringIndexOutOfBoundsException: String index out of range: -16

java.lang.String.substring(String.java:1768)

com.cisco.nm.uii.reports.SimpleTableTextColumn.compare(SimpleTableTextColumn.java:50)

java.util.Arrays.mergeSort(Arrays.java:1284)

java.util.Arrays.mergeSort(Arrays.java:1295)

java.util.Arrays.mergeSort(Arrays.java:1295)

java.util.Arrays.mergeSort(Arrays.java:1295)

java.util.Arrays.mergeSort(Arrays.java:1295)

java.util.Arrays.mergeSort(Arrays.java:1295)

java.util.Arrays.mergeSort(Arrays.java:1295)

java.util.Arrays.mergeSort(Arrays.java:1295)

java.util.Arrays.mergeSort(Arrays.java:1295)

java.util.Arrays.sort(Arrays.java:1223)

java.util.Collections.sort(Collections.java:159)

com.cisco.nm.uii.reports.TabularTablePersist.indexSortableColumn(TabularTablePersist.java:537)

com.cisco.nm.uii.reports.TabularTablePersist.privateIndexAllSortableColumns(TabularTablePersist.java:356)

com.cisco.nm.uii.reports.TabularTablePersist.indexAllSortableColumns(TabularTablePersist.java:333)

com.cisco.nm.uii.reports.TabularTable.indexAllSortableColumns(TabularTable.java:67)

com.cisco.nm.rmeng.sa.ui.reports.datagenerators.ReportDataGenerator.generateSeverityLevelReport(ReportDataGenerator.java:2753)

com.cisco.nm.rmeng.sa.ui.reports.action.SyslogReportDetailsAction.perform(SyslogReportDetailsAction.java:239)

org.apache.struts.action.ActionServlet.processActionPerform(ActionServlet.java:1786)

org.apache.struts.action.ActionServlet.process(ActionServlet.java:1585)

org.apache.struts.action.ActionServlet.doGet(ActionServlet.java:491)

javax.servlet.http.HttpServlet.service(HttpServlet.java:689)

javax.servlet.http.HttpServlet.service(HttpServlet.java:802)

com.cisco.nm.cmf.util.AccessLogFilter.doFilter(Unknown Source)

note The full stack trace of the root cause is available in the Apache Tomcat/5.5.17 logs.


is there a patch for this? we're running latest lms 3 on windows.

thanks

andy

Joe Clarke Mon, 02/25/2008 - 08:50
User Badges:
  • Cisco Employee,
  • Hall of Fame,

    Founding Member

Yes, there is a patch available by calling the TAC, and referencing the bug CSCsl97698.

Actions

This Discussion