Ottenere risultati diversi per getStackTrace() [2] .getMethodName()

Question

Per scopi di registrazione, ho creato un metodo logTitle() che stampa il nome del metodo di chiamata per i nostri test TestNG. Il codice di esempio è sotto.

@Test 
public void test1() throws Exception { 
    method1(); 
} 

public static void method1() throws Exception { 
    Utils.logTitle(2); 
} 

...

public static void logTitle(Integer level) throws Exception { 

    // Gets calling method name 
    String method = Thread.currentThread().getStackTrace()[2].getMethodName(); 
    // This would get current method name 
    switch (level) { 
    case 1: 
     logger.info("======================================================="); 
     logger.info(method); 
     logger.info("======================================================="); 
     break; 
    case 2: 
     logger.info("------------------------------------"); 
     logger.info(method); 
     logger.info("------------------------------------"); 
     break; 
    case 3: 
     logger.info("---------------------"); 
     logger.info(method); 
     logger.info("---------------------"); 
     break; 
    case 4: 
     logger.info("--------- " + method + " ------------"); 
     break; 
    default: 
     logger.info(method); 
    } 
} 

Il problema è che sto ottenendo risultati diversi per logTitle() su due macchine diverse. laptop

di ognuno restituisce correttamente:

2016-06-20 14:22:06 INFO - ------------------------------------ 
2016-06-20 14:22:06 INFO - method1 
2016-06-20 14:22:06 INFO - ------------------------------------ 

nostri dev box unix rendimenti diversamente:

2016-06-20 14:42:26 INFO - ------------------------------------ 
2016-06-20 14:42:26 INFO - logTitle 
2016-06-20 14:42:26 INFO - ------------------------------------ 

questo funziona correttamente sul computer portatile di tutti gli altri, non solo la casella UNIX dev. Penso che la scatola di sviluppo di unix stia usando la versione di Java di IBM, mentre tutti gli altri usano la versione di Oracle di Java, ma non sono sicuro se questo sia il colpevole o meno.

Qualche idea?

Answer 1

penso che la sua profondità specifica che causa il problema, che è 2 nel vostro scenario.

Così, invece di scrivere

String method = Thread.currentThread().getStackTrace()[2].getMethodName(); 

se si scrive

StackTraceElement[] ste = Thread.currentThread().getStackTrace(); 
String method = null; 
boolean doNext = false; 
for (StackTraceElement s : ste) { 
     if (doNext) { 
      method = s.getMethodName(); 
      return; 
     } 
     doNext = s.getMethodName().equals("getStackTrace"); 
    } 

Esso funziona solo per JDK 1.5 +

L'altra opzione è la seguente:

String method = new Object(){}.getClass().getEnclosingMethod().getName(); 

o un più lento o ption sarà:

String method = new Exception().getStackTrace()[0].getMethodName(); 

Poiché ciò creerà un'istanza di Eccezione ogni volta.

Spero che ti aiuti.

Answer 2

Il modo più semplice per ottenere un nome di metodo di prova è utilizzare uno @BeforeMethod e iniettare il Method. Vedere la documentazione di TestNG, here.

Basta memorizzare il nome da qualche parte e usarlo nel log (perché non in un @AfterMethod?)

Answer 3

Credo che il comportamento è JVM specifica. In passato mi si avvicinò con questa soluzione:

// find first stack trace entry that is not in this class 
Optional<StackTraceElement> ste = Iterables.tryFind(
     Arrays.asList(new RuntimeException().getStackTrace()), 
     new Predicate<StackTraceElement>() { 
      @Override 
      public boolean apply(StackTraceElement input) { 
       return !input.getClassName().equals(PutYourClassHere.class.getName()); 
      } 
     }); 

if (ste.isPresent()) { 
    LOG.trace("Method called by: {}.{}", ste.get().getClassName(), ste.get().getMethodName()); 
} 

Il frammento sta usando Google Guava, perché questo è per Java 7. Se si dispone di Java 8, è possibile utilizzare Streams API e lambda. Ho effettuato il controllo ste.isPresent() perché ho rilevato una traccia di stack vuota una volta. Per quanto mi ricordo, Oracle JVM sta saltando le tracce dello stack quando la stessa eccezione viene lanciata più e più volte.

EDIT: Java 8 modo

Optional<StackTraceElement> ste = Arrays.stream(new RuntimeException().getStackTrace()) 
      .filter(x -> !x.getClassName().equals(Utils.class.getName())) 
      .findFirst(); 

Answer 4

Log4J finds the method name con la ricerca lungo la traccia dello stack fino a trovare il nome della classe di destinazione che si deve superare, quindi legge il nome del metodo.

Nel codice, è possibile utilizzare una tecnica simile - invece di un metodo statico Utils si potrebbe creare un'istanza nel tuo test, passando nella classe del test:

Utils utils = new Utils(MyTest.class); 

quindi utilizzare il già citato tecnica di ricerca nel metodo Utils.logTitle().

Utils.logTitle() cerca in avanti attraverso gli elementi di traccia stack di un oggetto Throwable appena creato finché non trova il primo elemento con la classe di destinazione desiderata.

Answer 5

Da Javadoc:

Alcune macchine virtuali possono, in alcune circostanze, omettere uno o più stack frame dalla traccia dello stack.Nel caso estremo, una macchina virtuale che non ha informazioni sulla traccia di stack relative a questo gettabile è autorizzata a restituire una matrice a lunghezza zero da questo metodo.

Quindi, l'unico modo garantito per farlo è utilizzare gli aspetti o raccogliere traccia dello stack con un altro modo personalizzato. Ma è possibile combinare questo approccio con fallback in qualche modo per ottenere il nome del metodo corrente (nel caso in cui il metodo logTitle sarà in linea). Può essere trovato here, per esempio. Di nuovo, nessuna garanzia, ma migliori possibilità.

Answer 6

La mia ipotesi, e come detto da MeBigFatGuy. Ciò può accadere a causa delle diverse implementazioni/impostazioni predefinite del compilatore JIT della JVM IBM/Oracle quando si esegue l'ottimizzazione del metodo inlining.

vi suggerisco l'esecuzione del codice nella casella di unix dev con

-Xjit:disableInlining 

e vedere se il problema scompare.

Se questo funzionerà per voi, potrebbe andare bene per il test, ma come indicato nella risposta Alexey Adamovskiy non possiamo credere che java sia consistente nei frame dello stack.

Consulta anche:

• Would Java inline method(s) during optimization?
• Selectively disabling the JIT compiler
• Java method inlining performance considerations

Answer 7

Log4j 2 utilizza il nome classe completo del Logger per individuare la classe e il metodo da cui è stato chiamato il Logger. Il codice per trovare la posizione segue di seguito. Sentiti libero di usarlo.

Si noti che il loop inizia dal fondo della stacktrace; questo è necessario per rilevare casi eccezionali in cui il logger è chiamato in modo ricorsivo (forse dal metodo toString() di un oggetto che è stato registrato). In questi casi vogliamo segnalare la prima classe/metodo che ha chiamato il Logger, non l'ultimo, quindi non abbiamo altra scelta che percorrere la traccia dello stack dal basso verso l'alto.

public static StackTraceElement calcLocation(final String fqcnOfLogger) { 
    if (fqcnOfLogger == null) { 
     return null; 
    } 
    // LOG4J2-1029 new Throwable().getStackTrace is faster 
    // than Thread.currentThread().getStackTrace(). 
    final StackTraceElement[] stackTrace = new Throwable().getStackTrace(); 
    StackTraceElement last = null; 
    for (int i = stackTrace.length - 1; i > 0; i--) { 
     final String className = stackTrace[i].getClassName(); 
     if (fqcnOfLogger.equals(className)) { 
      return last; 
     } 
     last = stackTrace[i]; 
    } 
    return null; 
}