What could possibly explain this weird Log.v() behavior?

Question

In a very short and simple LVL callback function, I have:

public void applicationError(ApplicationErrorCode errorCode) {
  Log.v(getMethodName(2), "TID: " + android.os.Process.myTid());
  Log.v("applicationError()", "TID: " + android.os.Process.myTid());
  if (!isFinishing()) { // Don't update UI if Activity is finishing.
    String result = String.format(getString(R.string.application_error), errorCode);
    displayResult(result);
  }

this callback is a method member of

 private class MyLicenseCheckerCallback implements LicenseCheckerCallback 

and the getMethodName() defined as the application's activity method:

 public static String getMethodName(final int depth)
  {
    final StackTraceElement[] ste = Thread.currentThread().getStackTrace();

    String retStr = ste[depth+1].getClassName() + "." + ste[depth+1].getMethodName();

    if (retStr == null)
      retStr = "This is weird.";
    else if (retStr.length() < 1)
      retStr = "This is even weirder.";

    return retStr;
  }

Now, the weird part:

LogCat always displays the 2nd Log.v() but never displays the 1st Log.v()!

At first, I thought that perhaps retStr is either null or empty, but the logs clearly don't show anything like that.

In other methods calling Log.v(getMethodName(2), "TID: " + android.os.Process.myTid()); everything works fine.

What could possibly explain this weird and inconsistent Log.v() behavior?

UPDATE: I implemented the 1st part in CheGuaVerra's answer and this is the interesting log I got:

06-16 01:02:57.080: INFO/First(835): Log.v
06-16 01:02:57.080: INFO/First(835): [ 06-16 01:02:57.080   835:0x34b V/com.example.baseapp.googlepaid.MyActivityGooglePaid$MyLicenseCheckerCallback.applTID: 843
06-16 01:02:57.080: INFO/Second(835): Log.v
06-16 01:02:57.080: VERBOSE/applicationError()(835): TID: 843

UPDATE 2: I implemented the both parts in CheGuaVerra's answer and this is the interesting log I got:

06-16 10:13:22.588: INFO/First(1122): Log.v
06-16 10:13:22.588: INFO/getMethodName(1122): Start
06-16 10:13:22.588: INFO/getMethodName(1122): [ 06-16 10:13:22.588  1122:0x46a V/com.example.baseapp.googlepaid.MyActivityGooglePaid$MyLicenseCheckerCallback.applTID: 1130
06-16 10:13:22.588: INFO/Second(1122): Log.v
06-16 10:13:22.588: VERBOSE/applicationError()(1122): TID: 1130

Is it possible that Thread.currentThread().getStackTrace()[depth+1].getMethodName() simply doesn't "like" being called from the UI thread?

Also, it seems that Log.v() doesn't like weird strings like [ 06-16 10:13:22.588 1122:0x46a V/com.example.baseapp.googlepaid.MyActivityGooglePaid$MyLicenseCheckerCallback.appl.

Answer 1

Did you try to do something like this to trace it out?

public void applicationError(ApplicationErrorCode errorCode) {     
  Log.i("First", "Log.v");

  Log.v(getMethodName(2), "TID: " + android.os.Process.myTid());

  Log.i("Second", "Log.v");

  Log.v("applicationError()", "TID: " + android.os.Process.myTid());

  if (!isFinishing()) { // Don't update UI if Activity is finishing.
    String result = String.format(getString(R.string.application_error), errorCode);

  displayResult(result);
}


 public static String getMethodName(final int depth)
  {
    Log.i("getMethodName", "Start");
    final StackTraceElement[] ste = Thread.currentThread().getStackTrace();

    String retStr = ste[depth+1].getClassName() + "." + ste[depth+1].getMethodName();

    if (retStr == null)
      retStr = "This is weird.";
    else if (retStr.length() < 1)
      retStr = "This is even weirder.";

    Log.i("getMethodeName", retStr);

    return retStr;
  }