Mittwoch, 10. April 2013

JBoss Logfiles geschickt durchsuchen

Zeitliche Abschnitte filtern

Manchmal will man nur einen bestimmten zeitlichen Abschnitt eines Logfiles durchsuchen. Gerade bei sehr umfangreichen Logdaten ist es manchmal sehr interessant, das Geschehen in einem bestimmten Zeitraum zu untersuchen.
Dazu kann man sehr wirkungsvoll das nachfolgenden Perl Skript einsetzen. Hier wird das Geschehen am 9.4.13 ab 15:00 - 16:00 herausgesucht

1:  perl -e'  
2:  open FH, "server.log" or die "err open $!\n"; $line=1;  
3:  while(<FH>){  
4:    if(/^2013-04-09 15:/){  
5:     if(!$first){  
6:       { $first = $line; }  
7:     else  
8:       { $last = $line; }  
9:    }              
10:    $line++;}  
11:  print `sed -n "$first,${last}p" server.log` if $first;  
12:  '  

Warum reicht hier nicht einfach ein 'grep' nach dem Datum mit Uhrzeit?

Treten irgendwelche Exceptions in der Zeit auf oder auch andere Outputs mit Zeilenumbruch auf, werden diese vom grep ignoriert.

Gerade bei großen Logfiles kann es schon sehr zeitsparend sein, erst einen zeitlichen Bereich herauzusuchen und dann mit 'grep' o.ä. nach Detailproblemen zu suchen.

Exceptions filtern

Angenommen man hat viele Java Exceptions, die im server.log nur sehr unübersichtlich sind, kann man sich mit nachfolgendem Skript helfen.
Die Haupt-Exceptions werden speziell mit '===========' gekennzeichnet.
1:  grep -n Exception: server.log |   
2:  perl -ne '  
3:  if(/^\d+\:2013-/g)  
4:  {print "===================================\n\n$_\n";}   
5:  else   
6:  {print "$_\n";}' | more  

Beispiel:
1:  ===================================  
2:  214:2013-04-09 00:00:02,808 ERROR [org.hibernate.ejb.AbstractEntityManagerImpl] (DefaultQuartzScheduler_Worker-0) Unable to mark for rollback on PersistenceException:   
3:  215:java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction   
4:  is not active!  
5:  380:java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction   
6:  is not active!  
7:  ===================================  
8:  508:2013-04-09 00:00:02,845 ERROR [org.jboss.aspects.tx.TxPolicy] (DefaultQuartzScheduler_Worker-0) javax.ejb.EJBTransactionRolledbackException: org.hibernate.exception.GenericJ  
9:  DBCException: Cannot open connection  
10:  510:java.lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The transaction   
11:  is not active!