2016-02-23 41 views
6

Sono un lettore di lunga data, ma autore di prima lettura.Errore Java PrintWriter

Attualmente sto cercando di implementare un logger con AspectJ nel nostro codebase. AspectJ sembra funzionare bene, ma sto incontrando errori Java estremamente strani. Sono uno sviluppatore di lunga data C++ e .Net che si sta ancora adattando al mondo di Java, quindi mi scuso se questa è una domanda stupida.

Il mio codice sta tentando di intercettare le eccezioni e registrare le informazioni pertinenti in un file di testo. Il trapping funziona bene, ma ho notato che quando ho distribuito, non ricevo alcun dato. Ho aperto il mio file di classe in un decompilatore Java e ho notato che PrintWriter sembra generare un errore. Non ho mai visto un problema come questo, quindi spero che tu possa avere qualche intuizione.

package mil.uscg.c3cen.vic.aspect; 

import java.io.BufferedWriter; 
import java.io.File; 
import java.io.FileWriter; 
import java.io.IOException; 
import java.io.PrintWriter; 
import org.aspectj.lang.annotation.Aspect; 
import org.aspectj.lang.annotation.AfterThrowing; 
import org.aspectj.lang.JoinPoint; 

@Aspect 
public class LoggingAspect 
{ 
    private final String LOG_FILE = "aspectLog.txt"; 
    private final File file = new File(LOG_FILE); 

    private LoggingAspect() 
    { 

    } 

    private void logException(String msg) 
    { 
     try 
     { 
      if(!file.exists()) 
       file.createNewFile(); 
     } 
     catch(IOException e) 
     { 

     } 

     try (FileWriter fw = new FileWriter(file); 
       BufferedWriter bw = new BufferedWriter(fw); 
       PrintWriter pw = new PrintWriter(bw)) 
     { 
      pw.println(msg); 
     } 
     catch(IOException e) 
     { 

     } 
    } 

    private String getSimpleFunctionInfo(String className, String  function, Object[] args) 
    { 
     StringBuilder builder = new StringBuilder(); 
     builder.append(". Method: "); 
     builder.append(className); 
     builder.append("."); 
     builder.append(function); 

     if(args.length == 0) 
     { 
      builder.append("()"); 
      return builder.toString(); 
     } 

     builder.append("("); 

     for(Object o : args) 
     { 
      builder.append(o.toString()); 
      builder.append(","); 
     } 
     // Replace the comma for the last param with a closing parenthesis 
     int len = builder.length(); 
     builder.replace(len -1, len, ")"); 

     return builder.toString(); 
    } 

    // Returns a formatted exception. "Exception.ErrorMessage" 
    private String getSimpleExceptionInfo(String name, String msg) 
    { 
     StringBuilder builder = new StringBuilder(); 
     builder.append("Exception caught: "); 
     builder.append(name); 
     builder.append(". Message: "); 
     builder.append(msg); 
     return builder.toString(); 
    } 


    @AfterThrowing(pointcut = "execution(* mil.uscg.c3cen.*.*.*(..)) " 
     //+ "&& !within(mil.uscg.c3cen.vic.aspect.*) " 
     , throwing = "excep") 
    public void afterThrowing(JoinPoint jp, Throwable excep) throws Throwable 
    { 
     String ex = getSimpleExceptionInfo(excep.getClass().getSimpleName(), 
                  excep.getMessage()); 

     String name = getSimpleFunctionInfo(jp.getSignature().getDeclaringType().getSimpleName(), 
                   jp.getSignature().getName(), 
                   jp.getArgs()); 

     StringBuilder builder = new StringBuilder(); 
     builder.append(ex); 
     builder.append(name); 

     logException(builder.toString()); 
    } 
} 

Tutto sembra come ci si aspetterebbe nel file di classe, ad eccezione della funzione logException.

/* Error */ 
    private void logException(String msg) 
    { 
    // Byte code: 
    // 0: aload_0 
    // 1: getfield 25 mil/uscg/c3cen/vic/aspect/LoggingAspect:file Ljava/io/File; 
    // 4: invokevirtual 32 java/io/File:exists()Z 
    // 7: ifne +15 -> 22 
    // 10: aload_0 
    // 11: getfield 25 mil/uscg/c3cen/vic/aspect/LoggingAspect:file Ljava/io/File; 
    // 14: invokevirtual 36 java/io/File:createNewFile ()Z 
    // 17: pop 
    // 18: goto +4 -> 22 
    // 21: pop 
    // 22: aconst_null 
    // 23: astore_2 
    // 24: aconst_null 
    // 25: astore_3 
    // 26: new 39 java/io/FileWriter 
    // 29: dup 
    // 30: aload_0 
    // 31: getfield 25 mil/uscg/c3cen/vic/aspect/LoggingAspect:file Ljava/io/File; 
    // 34: invokespecial 41 java/io/FileWriter:<init> (Ljava/io/File;)V 
    // 37: astore 4 
    // 39: new 44 java/io/BufferedWriter 
    // 42: dup 
    // 43: aload 4 
    // 45: invokespecial 46 java/io/BufferedWriter:<init> (Ljava/io/Writer;)V 
    // 48: astore 5 
    // 50: new 49 java/io/PrintWriter 
    // 53: dup 
    // 54: aload 5 
    // 56: invokespecial 51 java/io/PrintWriter:<init> (Ljava/io/Writer;)V 
    // 59: astore 6 
    // 61: aload 6 
    // 63: aload_1 
    // 64: invokevirtual 52 java/io/PrintWriter:println (Ljava/lang/String;)V 
    // 67: aload 6 
    // 69: ifnull +24 -> 93 
    // 72: aload 6 
    // 74: invokevirtual 55 java/io/PrintWriter:close ()V 
    // 77: goto +16 -> 93 
    // 80: astore_2 
    // 81: aload 6 
    // 83: ifnull +8 -> 91 
    // 86: aload 6 
    // 88: invokevirtual 55 java/io/PrintWriter:close ()V 
    // 91: aload_2 
    // 92: athrow 
    // 93: aload 5 
    // 95: ifnull +43 -> 138 
    // 98: aload 5 
    // 100: invokevirtual 58 java/io/BufferedWriter:close ()V 
    // 103: goto +35 -> 138 
    // 106: astore_3 
    // 107: aload_2 
    // 108: ifnonnull +8 -> 116 
    // 111: aload_3 
    // 112: astore_2 
    // 113: goto +13 -> 126 
    // 116: aload_2 
    // 117: aload_3 
    // 118: if_acmpeq +8 -> 126 
    // 121: aload_2 
    // 122: aload_3 
    // 123: invokevirtual 59 java/lang/Throwable:addSuppressed (Ljava/lang/Throwable;)V 
    // 126: aload 5 
    // 128: ifnull +8 -> 136 
    // 131: aload 5 
    // 133: invokevirtual 58 java/io/BufferedWriter:close ()V 
    // 136: aload_2 
    // 137: athrow 
    // 138: aload 4 
    // 140: ifnull +66 -> 206 
    // 143: aload 4 
    // 145: invokevirtual 65 java/io/FileWriter:close ()V 
    // 148: goto +58 -> 206 
    // 151: astore_3 
    // 152: aload_2 
    // 153: ifnonnull +8 -> 161 
    // 156: aload_3 
    // 157: astore_2 
    // 158: goto +13 -> 171 
    // 161: aload_2 
    // 162: aload_3 
    // 163: if_acmpeq +8 -> 171 
    // 166: aload_2 
    // 167: aload_3 
    // 168: invokevirtual 59 java/lang/Throwable:addSuppressed (Ljava/lang/Throwable;)V 
    // 171: aload 4 
    // 173: ifnull +8 -> 181 
    // 176: aload 4 
    // 178: invokevirtual 65 java/io/FileWriter:close ()V 
    // 181: aload_2 
    // 182: athrow 
    // 183: astore_3 
    // 184: aload_2 
    // 185: ifnonnull +8 -> 193 
    // 188: aload_3 
    // 189: astore_2 
    // 190: goto +13 -> 203 
    // 193: aload_2 
    // 194: aload_3 
    // 195: if_acmpeq +8 -> 203 
    // 198: aload_2 
    // 199: aload_3 
    // 200: invokevirtual 59 java/lang/Throwable:addSuppressed (Ljava/lang/Throwable;)V 
    // 203: aload_2 
    // 204: athrow 
    // 205: pop 
    // 206: return 
    // Line number table: 
    // Java source line #28 -> byte code offset #0 
    // Java source line #29 -> byte code offset #10 
    // Java source line #30 -> byte code offset #18 
    // Java source line #31 -> byte code offset #21 
    // Java source line #36 -> byte code offset #22 
    // Java source line #36 -> byte code offset #26 
    // Java source line #37 -> byte code offset #39 
    // Java source line #38 -> byte code offset #50 
    // Java source line #40 -> byte code offset #61 
    // Java source line #41 -> byte code offset #67 
    // Java source line #42 -> byte code offset #205 
    // Java source line #46 -> byte code offset #206 
    // Local variable table: 
    // start length slot name signature 
    // 0 207 0 this LoggingAspect 
    // 0 207 1 msg String 
    // 23 1 2 localObject1 Object 
    // 80 28 2 localObject2 Object 
    // 112 92 2 localObject3 Object 
    // 25 1 3 localObject4 Object 
    // 106 17 3 localThrowable1 Throwable 
    // 151 17 3 localThrowable2 Throwable 
    // 183 17 3 localThrowable3 Throwable 
    // 37 140 4 fw java.io.FileWriter 
    // 48 84 5 bw java.io.BufferedWriter 
    // 59 28 6 pw java.io.PrintWriter 
    // 21 1 12 localIOException1 java.io.IOException 
    // 205 1 13 localIOException2 java.io.IOException 
    // Exception table: 
    // from to target type 
    // 0 18 21 java/io/IOException 
    // 61 67 80 finally 
    // 50 93 106 finally 
    // 39 138 151 finally 
    // 26 183 183 finally 
    // 22 205 205 java/io/IOException 
    } 

Questo mi ha davvero bloccato, quindi qualsiasi informazione sarà estremamente apprezzata. Grazie!

+0

ho pensato che era la sintassi corretta per sfruttare la gestione automatica delle risorse in Java. Ho capito che questo era l'equivalente della funzione di utilizzo in C#, dove le risorse sono garantite per essere chiuse, come si farebbe normalmente in un blocco finale. – FretlessMayhem

+1

@CalvinP. Queste righe sono tra parentesi perché sfrutta l'istruzione try-with-resources. Si prega di dare un'occhiata qui per undestand il suo codice, se non siete a conoscenza di ciò che significa [collegamento] (https://docs.oracle.com/javase/tutorial/essential/exceptions/tryResourceClose.html) – angryip

+1

Ah, appena visto il javadocs e tu hai ragione. L'istruzione try dovrebbe avere successo, supponendo che si stia utilizzando Java SE 7 o successivo. @angryip lo ha letteralmente visto prima che tu abbia fornito il link, ma grazie. –

risposta

1

Beh, non hai davvero detto qual è il problema. Se hai problemi con l'eccezione non rilevata in logException, basta prenderlo e investigare. Molto probabilmente si tratta di un problema di autorizzazione all'apertura del file o forse (su Windows ad esempio) il sistema operativo non consente l'accesso al file da più thread.

Per la seconda domanda: il codice byte è chiaro. La prima parte è abbastanza semplice e segue il codice che hai scritto. La seconda parte gestisce la chiusura delle risorse e l'aggiunta di eccezioni potenzialmente rilevate come soppresse a eccezione già sollevata. È un po 'lungo ma di nuovo segue l'inizializzazione della risorsa in direzione opposta.

+1

non sono sicuro di come il codice byte sia abbastanza chiaro. "/ * Errore * /" solleva sicuramente una bandiera per me. – angryip

2

Ok, ho provato con Java 8 e AspectJ 1.8.8 corrente. Il tuo aspetto funziona come previsto (l'ho compilato senza modifiche). È solo un po 'complicato e dovrebbe essere semplificato. Inoltre, potresti aver erroneamente conteggiato il numero di .* nel tuo pointcut.

Se aggiungo System.out.println(jp); all'inizio del tuo metodo di consulenza in modo da vedere qualcosa sulla console ed eseguire l'aspetto contro questa classe di driver di esempio ...

package mil.uscg.c3cen.foo; 

public class Application { 
    public static void main(String[] args) { 
     for (int i = 0; i < 3; i++) { 
      try { 
       doSomething(); 
      } 
      catch (Exception e) {} 
     } 
    } 

    public static void doSomething() { 
     System.out.println("Calculation result = " + multiply(add(3, 4), 5)); 
     System.out.println("Calculation result = " + divide(add(5, 6), 0)); 
    } 

    private static int add(int summand1, int summand2) { 
     return summand1 + summand2; 
    } 

    private static int multiply(int factor1, int factor2) { 
     return factor1 * factor2; 
    } 

    private static int divide(int dividend, int divisor) { 
     return dividend/divisor; 
    } 
} 

... il log della console si presenta come questo:

Calculation result = 35 
execution(int mil.uscg.c3cen.foo.Application.divide(int, int)) 
execution(void mil.uscg.c3cen.foo.Application.doSomething()) 
Calculation result = 35 
execution(int mil.uscg.c3cen.foo.Application.divide(int, int)) 
execution(void mil.uscg.c3cen.foo.Application.doSomething()) 
Calculation result = 35 
execution(int mil.uscg.c3cen.foo.Application.divide(int, int)) 
execution(void mil.uscg.c3cen.foo.Application.doSomething()) 

come si può vedere, solo i metodi gettando eccezione la gerarchia di richiamo (fino a quando non vengono catturati) vengono registrati, come previsto. Il file di registro aspectLog.txt ha questo contenuto:

Exception caught: ArithmeticException. Message:/by zero. Method: Application.main([Ljava.lang.String;@f6f4d33) 

cosa migliorare:

  • Forse si vuole avere un pointcut più stabile rivolte a tutti i sottopacchetti di mil.uscg.c3cen. La sintassi per "tutte le esecuzioni di metodi all'interno di quel pacchetto e tutti i relativi pacchetti secondari" sarebbe execution(* mil.uscg.c3cen..*(..)).
  • C'è un bug nella logica di utilizzo del file di registro: ogni volta che si verifica la prima eccezione e il file di registro non esiste ancora, viene registrato e il file di registro viene immediatamente chiuso. Qualsiasi eccezione successiva non verrà mai registrata, il che probabilmente non è ciò che desideri.Probabilmente si desidera che più eccezioni vengano registrate nello stesso file finché la JVM è attiva e funzionante. Pertanto, non si desidera chiudere il file di registro dopo ogni scrittura, ma aver cura di ciò in un hook di arresto JVM alla fine della vita di JVM. Provare con risorse (auto-chiudibili) è utile solo se si desidera veramente chiuderle dopo aver eseguito una determinata parte del codice. A proposito, puoi evitare il blocco dello shutdown eseguendo il flushing dello scrittore su base regolare, ad es. dopo ogni chiamata println.
  • Qui non sto discutendo di problemi di threading e sincronizzazione, che richiederebbero ancora più attenzione. Supponiamo che tu abbia un'applicazione a thread singolo.
  • Forse si desidera intercettare le eccezioni nei costruttori e aggiungerli al proprio pointcut.

migliorata & aspetto semplificato:

package mil.uscg.c3cen.vic.aspect; 

import java.io.FileNotFoundException; 
import java.io.FileOutputStream; 
import java.io.PrintWriter; 

import org.aspectj.lang.JoinPoint; 
import org.aspectj.lang.annotation.AfterThrowing; 
import org.aspectj.lang.annotation.Aspect; 

@Aspect 
public class LoggingAspect { 
    private static final String LOG_FILE = "aspectLog.txt"; 

    private final PrintWriter logWriter; 

    public LoggingAspect() throws FileNotFoundException { 
     logWriter = new PrintWriter(new FileOutputStream(LOG_FILE)); 
     Runtime.getRuntime().addShutdownHook(new Thread() { 
      @Override 
      public void run() { 
       logWriter.close(); 
      } 
     }); 
    } 

    @AfterThrowing(
     pointcut = 
      "(execution(* mil.uscg.c3cen..*(..)) || execution(mil.uscg.c3cen..new(..)))" + 
      " && !within(mil.uscg.c3cen.vic.aspect..*) ", 
     throwing = "excep" 
    ) 
    public void afterThrowing(JoinPoint jp, Throwable excep) throws Throwable { 
     //System.out.println(excep + " -> " + jp); 
     logWriter.println(excep + " -> " + jp); 
    } 
} 

esempio di codice esteso con un costruttore un'eccezione: log

package mil.uscg.c3cen.foo; 

public class Application { 
    public Application() { 
     System.out.println(1/0); 
    } 

    public static void doSomething() { 
     System.out.println("Calculation result = " + multiply(add(3, 4), 5)); 
     System.out.println("Calculation result = " + divide(add(5, 6), 0)); 
    } 

    private static int add(int summand1, int summand2) { 
     return summand1 + summand2; 
    } 

    private static int multiply(int factor1, int factor2) { 
     return factor1 * factor2; 
    } 

    private static int divide(int dividend, int divisor) { 
     return dividend/divisor; 
    } 

    public static void main(String[] args) { 
     for (int i = 0; i < 3; i++) { 
      try { 
       doSomething(); 
      } 
      catch (Exception e) {} 
     } 
     try { 
      new Application(); 
     } 
     catch (Exception e) {} 
    } 
} 

Console:

Calculation result = 35 
Calculation result = 35 
Calculation result = 35 

file di registro:

java.lang.ArithmeticException:/by zero -> execution(int mil.uscg.c3cen.foo.Application.divide(int, int)) 
java.lang.ArithmeticException:/by zero -> execution(void mil.uscg.c3cen.foo.Application.doSomething()) 
java.lang.ArithmeticException:/by zero -> execution(int mil.uscg.c3cen.foo.Application.divide(int, int)) 
java.lang.ArithmeticException:/by zero -> execution(void mil.uscg.c3cen.foo.Application.doSomething()) 
java.lang.ArithmeticException:/by zero -> execution(int mil.uscg.c3cen.foo.Application.divide(int, int)) 
java.lang.ArithmeticException:/by zero -> execution(void mil.uscg.c3cen.foo.Application.doSomething()) 
java.lang.ArithmeticException:/by zero -> execution(mil.uscg.c3cen.foo.Application()) 

Guardate l'ultima riga, ci si vede l'eccezione nel costruttore.

Se si vuole abbellire l'uscita di registrazione un'eccezione un po ', simile a quello che il vostro aspetto originario fa, fare questo:

logWriter.println(excep.getClass().getSimpleName() + " -> " + jp.getSignature()); 

Poi il file di registro diventa:

ArithmeticException -> int mil.uscg.c3cen.foo.Application.divide(int, int) 
ArithmeticException -> void mil.uscg.c3cen.foo.Application.doSomething() 
ArithmeticException -> int mil.uscg.c3cen.foo.Application.divide(int, int) 
ArithmeticException -> void mil.uscg.c3cen.foo.Application.doSomething() 
ArithmeticException -> int mil.uscg.c3cen.foo.Application.divide(int, int) 
ArithmeticException -> void mil.uscg.c3cen.foo.Application.doSomething() 
ArithmeticException -> mil.uscg.c3cen.foo.Application() 
+0

Questo ha aiutato SOSTANZIALMENTE. Grazie mille. Cambiando il pointcut al tuo suggerimento cablato in modo impeccabile il sistema. Non mi rendevo conto che la corrispondenza con caratteri jolly era diversa in quell'istanza. Inoltre, grazie per il suggerimento su Prova con risorse. Questo è tutto nuovo per me, e non mi sono reso conto che era solo per uso singolo. L'utilizzo di flush ha risolto il problema e ora registra splendidamente. – FretlessMayhem

+0

Sono felice di poterti aiutare. Grazie in anticipo per aver accettato e revocato la mia risposta. – kriegaex