Log info about the caller and callee in hiddenapi denial messages.

If enforcement is enabled then log as error instead of warning.

Also add "hiddenapi:" prefix to all log messages to make it easier to
search for them.

Test: Boot and check errors in logcat
Test: 674-hiddenapi 690-hiddenapi-same-name-methods 691-hiddenapi-proxy
      817-hiddenapi 822-hiddenapi-future 999-redefine-hiddenapi
      2038-hiddenapi-jvmti-ext 2270-mh-internal-hiddenapi-use
      on host and target
Bug: 377676642
Change-Id: Ib4f790d7ab4850d398639c64f55be0d14c5c0408

7 files changed, 125 insertions, 26 deletions

diff --git a/runtime/hidden_api.cc b/runtime/hidden_api.cc
index cb1c60d93f..53010fc0f7 100644
--- a/runtime/hidden_api.cc
+++ b/runtime/hidden_api.cc
@@ -86,6 +86,21 @@ static inline std::ostream& operator<<(std::ostream& os, AccessMethod value) {
   return os;
 }
 
+static inline std::ostream& operator<<(std::ostream& os, Domain domain) {
+  switch (domain) {
+    case Domain::kCorePlatform:
+      os << "core-platform";
+      break;
+    case Domain::kPlatform:
+      os << "platform";
+      break;
+    case Domain::kApplication:
+      os << "app";
+      break;
+  }
+  return os;
+}
+
 static inline std::ostream& operator<<(std::ostream& os, const AccessContext& value)
     REQUIRES_SHARED(Locks::mutator_lock_) {
   if (!value.GetClass().IsNull()) {
@@ -99,6 +114,19 @@ static inline std::ostream& operator<<(std::ostream& os, const AccessContext& va
   return os;
 }
 
+static const char* FormatHiddenApiRuntimeFlags(uint32_t runtime_flags) {
+  switch (runtime_flags & kAccHiddenapiBits) {
+    case 0:
+      return "0";
+    case kAccPublicApi:
+      return "PublicApi";
+    case kAccCorePlatformApi:
+      return "CorePlatformApi";
+    default:
+      return "?";
+  }
+}
+
 static Domain DetermineDomainFromLocation(const std::string& dex_location,
                                           ObjPtr<mirror::ClassLoader> class_loader) {
   // If running with APEX, check `path` against known APEX locations.
@@ -126,7 +154,7 @@ static Domain DetermineDomainFromLocation(const std::string& dex_location,
   if (class_loader.IsNull()) {
     if (kIsTargetBuild && !kIsTargetLinux) {
       // This is unexpected only when running on Android.
-      LOG(WARNING) << "DexFile " << dex_location
+      LOG(WARNING) << "hiddenapi: DexFile " << dex_location
                    << " is in boot class path but is not in a known location";
     }
     return Domain::kPlatform;
@@ -326,21 +354,29 @@ void MemberSignature::Dump(std::ostream& os) const {
 
 void MemberSignature::WarnAboutAccess(AccessMethod access_method,
                                       hiddenapi::ApiList list,
-                                      bool access_denied) {
+                                      bool access_denied,
+                                      uint32_t runtime_flags,
+                                      const AccessContext& caller_context,
+                                      const AccessContext& callee_context,
+                                      EnforcementPolicy policy) {
   static std::atomic<uint64_t> log_warning_count_ = 0;
   if (log_warning_count_ > kMaxLogWarnings) {
     return;
   }
-  LOG(WARNING) << "Accessing hidden " << (type_ == kField ? "field " : "method ")
-               << Dumpable<MemberSignature>(*this) << " (" << list << ", " << access_method
-               << (access_denied ? ", denied)" : ", allowed)");
+  LOG(policy == EnforcementPolicy::kEnabled ? ERROR : WARNING)
+      << "hiddenapi: Accessing hidden " << (type_ == kField ? "field " : "method ")
+      << Dumpable<MemberSignature>(*this)
+      << " (runtime_flags=" << FormatHiddenApiRuntimeFlags(runtime_flags)
+      << ", domain=" << callee_context.GetDomain() << ", api=" << list << ") from "
+      << caller_context << " (domain=" << caller_context.GetDomain() << ") using " << access_method
+      << (access_denied ? ": denied" : ": allowed");
   if (access_denied && list.IsTestApi()) {
     // see b/177047045 for more details about test api access getting denied
-    LOG(WARNING) << "If this is a platform test consider enabling "
+    LOG(WARNING) << "hiddenapi: If this is a platform test consider enabling "
                  << "VMRuntime.ALLOW_TEST_API_ACCESS change id for this package.";
   }
   if (log_warning_count_ >= kMaxLogWarnings) {
-    LOG(WARNING) << "Reached maximum number of hidden api access warnings.";
+    LOG(WARNING) << "hiddenapi: Reached maximum number of hidden api access warnings.";
   }
   ++log_warning_count_;
 }
@@ -380,13 +416,13 @@ void MemberSignature::LogAccessToEventLog(uint32_t sampled_value,
       hs.NewHandle(mirror::String::AllocFromModifiedUtf8(soa.Self(), package_name.c_str()));
   if (soa.Self()->IsExceptionPending()) {
     soa.Self()->ClearException();
-    LOG(ERROR) << "Unable to allocate string for package name which called hidden api";
+    LOG(ERROR) << "hiddenapi: Unable to allocate string for package name which called hidden api";
   }
   Handle<mirror::String> signature_jstr =
       hs.NewHandle(mirror::String::AllocFromModifiedUtf8(soa.Self(), signature_str.str().c_str()));
   if (soa.Self()->IsExceptionPending()) {
     soa.Self()->ClearException();
-    LOG(ERROR) << "Unable to allocate string for hidden api method signature";
+    LOG(ERROR) << "hiddenapi: Unable to allocate string for hidden api method signature";
   }
   WellKnownClasses::dalvik_system_VMRuntime_hiddenApiUsed
       ->InvokeStatic<'V', 'I', 'L', 'L', 'I', 'Z'>(soa.Self(),
@@ -397,7 +433,7 @@ void MemberSignature::LogAccessToEventLog(uint32_t sampled_value,
                                                    access_denied);
   if (soa.Self()->IsExceptionPending()) {
     soa.Self()->ClearException();
-    LOG(ERROR) << "Unable to report hidden api usage";
+    LOG(ERROR) << "hiddenapi: Unable to report hidden api usage";
   }
 #else
   UNUSED(sampled_value);
@@ -551,16 +587,22 @@ uint32_t GetDexFlags(T* member) REQUIRES_SHARED(Locks::mutator_lock_) {
 
 template <typename T>
 bool HandleCorePlatformApiViolation(T* member,
+                                    uint32_t runtime_flags,
                                     const AccessContext& caller_context,
+                                    const AccessContext& callee_context,
                                     AccessMethod access_method,
                                     EnforcementPolicy policy) {
   DCHECK(policy != EnforcementPolicy::kDisabled)
       << "Should never enter this function when access checks are completely disabled";
 
   if (access_method != AccessMethod::kNone) {
-    LOG(WARNING) << "Core platform API violation: "
-                 << Dumpable<MemberSignature>(MemberSignature(member)) << " from " << caller_context
-                 << " using " << access_method;
+    LOG(policy == EnforcementPolicy::kEnabled ? ERROR : WARNING)
+        << "hiddenapi: Core platform API violation: "
+        << Dumpable<MemberSignature>(MemberSignature(member))
+        << " (runtime_flags=" << FormatHiddenApiRuntimeFlags(runtime_flags)
+        << ", domain=" << callee_context.GetDomain() << ") from " << caller_context
+        << " (domain=" << caller_context.GetDomain() << ")"
+        << " using " << access_method;
 
     // If policy is set to just warn, add kAccCorePlatformApi to access flags of
     // `member` to avoid reporting the violation again next time.
@@ -574,7 +616,13 @@ bool HandleCorePlatformApiViolation(T* member,
 }
 
 template <typename T>
-bool ShouldDenyAccessToMemberImpl(T* member, ApiList api_list, AccessMethod access_method) {
+bool ShouldDenyAccessToMemberImpl(T* member,
+                                  ApiList api_list,
+                                  uint32_t runtime_flags,
+                                  const AccessContext& caller_context,
+                                  const AccessContext& callee_context,
+                                  AccessMethod access_method)
+    REQUIRES_SHARED(Locks::mutator_lock_) {
   DCHECK(member != nullptr);
   Runtime* runtime = Runtime::Current();
   CompatFramework& compatFramework = runtime->GetCompatFramework();
@@ -622,7 +670,13 @@ bool ShouldDenyAccessToMemberImpl(T* member, ApiList api_list, AccessMethod acce
       // Print a log message with information about this class member access.
       // We do this if we're about to deny access, or the app is debuggable.
       if (kLogAllAccesses || deny_access || runtime->IsJavaDebuggable()) {
-        member_signature.WarnAboutAccess(access_method, api_list, deny_access);
+        member_signature.WarnAboutAccess(access_method,
+                                         api_list,
+                                         deny_access,
+                                         runtime_flags,
+                                         caller_context,
+                                         callee_context,
+                                         hiddenApiPolicy);
       }
 
       // If there is a StrictMode listener, notify it about this violation.
@@ -657,19 +711,30 @@ bool ShouldDenyAccessToMemberImpl(T* member, ApiList api_list, AccessMethod acce
 template uint32_t GetDexFlags<ArtField>(ArtField* member);
 template uint32_t GetDexFlags<ArtMethod>(ArtMethod* member);
 template bool HandleCorePlatformApiViolation(ArtField* member,
+                                             uint32_t runtime_flags,
                                              const AccessContext& caller_context,
+                                             const AccessContext& callee_context,
                                              AccessMethod access_method,
                                              EnforcementPolicy policy);
 template bool HandleCorePlatformApiViolation(ArtMethod* member,
+                                             uint32_t runtime_flags,
                                              const AccessContext& caller_context,
+                                             const AccessContext& callee_context,
                                              AccessMethod access_method,
                                              EnforcementPolicy policy);
 template bool ShouldDenyAccessToMemberImpl<ArtField>(ArtField* member,
                                                      ApiList api_list,
+                                                     uint32_t runtime_flags,
+                                                     const AccessContext& caller_context,
+                                                     const AccessContext& callee_context,
                                                      AccessMethod access_method);
 template bool ShouldDenyAccessToMemberImpl<ArtMethod>(ArtMethod* member,
                                                       ApiList api_list,
+                                                      uint32_t runtime_flags,
+                                                      const AccessContext& caller_context,
+                                                      const AccessContext& callee_context,
                                                       AccessMethod access_method);
+
 }  // namespace detail
 
 template <typename T>
@@ -742,7 +807,8 @@ bool ShouldDenyAccessToMember(T* member,
       DCHECK(api_list.IsValid());
 
       // Member is hidden and caller is not exempted. Enter slow path.
-      return detail::ShouldDenyAccessToMemberImpl(member, api_list, access_method);
+      return detail::ShouldDenyAccessToMemberImpl(
+          member, api_list, runtime_flags, caller_context, callee_context, access_method);
     }
 
     case Domain::kPlatform: {
@@ -765,7 +831,8 @@ bool ShouldDenyAccessToMember(T* member,
       // Access checks are not disabled, report the violation.
       // This may also add kAccCorePlatformApi to the access flags of `member`
       // so as to not warn again on next access.
-      return detail::HandleCorePlatformApiViolation(member, caller_context, access_method, policy);
+      return detail::HandleCorePlatformApiViolation(
+          member, runtime_flags, caller_context, callee_context, access_method, policy);
     }
 
     case Domain::kCorePlatform: {
diff --git a/runtime/hidden_api.h b/runtime/hidden_api.h
index 33ede321fa..f503767ed5 100644
--- a/runtime/hidden_api.h
+++ b/runtime/hidden_api.h
@@ -204,7 +204,13 @@ class MemberSignature {
 
   bool DoesPrefixMatchAny(const std::vector<std::string>& exemptions);
 
-  void WarnAboutAccess(AccessMethod access_method, ApiList list, bool access_denied);
+  void WarnAboutAccess(AccessMethod access_method,
+                       ApiList list,
+                       bool access_denied,
+                       uint32_t runtime_flags,
+                       const AccessContext& caller_context,
+                       const AccessContext& callee_context,
+                       EnforcementPolicy policy) REQUIRES_SHARED(Locks::mutator_lock_);
 
   void LogAccessToEventLog(uint32_t sampled_value, AccessMethod access_method, bool access_denied);
 
@@ -222,16 +228,21 @@ uint32_t GetDexFlags(T* member) REQUIRES_SHARED(Locks::mutator_lock_);
 
 // Handler of detected core platform API violations. Returns true if access to
 // `member` should be denied.
-template<typename T>
+template <typename T>
 bool HandleCorePlatformApiViolation(T* member,
+                                    uint32_t runtime_flags,
                                     const AccessContext& caller_context,
+                                    const AccessContext& callee_context,
                                     AccessMethod access_method,
-                                    EnforcementPolicy policy)
-    REQUIRES_SHARED(Locks::mutator_lock_);
-
-template<typename T>
-bool ShouldDenyAccessToMemberImpl(T* member, ApiList api_list, AccessMethod access_method)
-    REQUIRES_SHARED(Locks::mutator_lock_);
+                                    EnforcementPolicy policy) REQUIRES_SHARED(Locks::mutator_lock_);
+
+template <typename T>
+bool ShouldDenyAccessToMemberImpl(T* member,
+                                  ApiList api_list,
+                                  uint32_t runtime_flags,
+                                  const AccessContext& caller_context,
+                                  const AccessContext& callee_context,
+                                  AccessMethod access_method) REQUIRES_SHARED(Locks::mutator_lock_);
 
 inline ArtField* GetInterfaceMemberIfProxy(ArtField* field) { return field; }
 
diff --git a/runtime/hidden_api_test.cc b/runtime/hidden_api_test.cc
index 444ad0bd48..28f1d28c1f 100644
--- a/runtime/hidden_api_test.cc
+++ b/runtime/hidden_api_test.cc
@@ -188,11 +188,17 @@ class HiddenApiTest : public CommonRuntimeTest {
   }
 
   bool ShouldDenyAccess(hiddenapi::ApiList list) REQUIRES_SHARED(Locks::mutator_lock_) {
+    // This is only used for log messages, so its state doesn't matter.
+    const hiddenapi::AccessContext placeholder_context(/* is_trusted= */ false);
+
     // Choose parameters such that there are no side effects (AccessMethod::kNone)
     // and that the member is not on the exemptions list (here we choose one which
     // is not even in boot class path).
     return ShouldDenyAccessToMemberImpl(/* member= */ class1_field1_,
                                         list,
+                                        /* runtime_flags= */ 0,
+                                        /* caller_context= */ placeholder_context,
+                                        /* callee_context= */ placeholder_context,
                                         /* access_method= */ hiddenapi::AccessMethod::kNone);
   }
 
diff --git a/test/2038-hiddenapi-jvmti-ext/run.py b/test/2038-hiddenapi-jvmti-ext/run.py
index 4796039801..c3f6d8fb72 100644
--- a/test/2038-hiddenapi-jvmti-ext/run.py
+++ b/test/2038-hiddenapi-jvmti-ext/run.py
@@ -17,3 +17,7 @@
 
 def run(ctx, args):
   ctx.default_run(args, jvmti=True)
+
+  # Delete hiddenapi's denial errors which go to stderr on host.
+  if args.host:
+    ctx.run(fr"sed -i -E '/ E dalvikvm.* hiddenapi: /d' '{args.stderr_file}'")
diff --git a/test/674-hiddenapi/run.py b/test/674-hiddenapi/run.py
index 97b8be95c8..ea0cd1d3b5 100644
--- a/test/674-hiddenapi/run.py
+++ b/test/674-hiddenapi/run.py
@@ -24,4 +24,7 @@ def run(ctx, args):
   ctx.default_run(args, verify_soft_fail=True, secondary_compilation=False)
 
   ctx.run(fr"sed -i -E '/(JNI_OnLoad|JNI_OnUnload)/d' '{args.stdout_file}'")
-  ctx.run(fr"sed -i -E '/^dalvikvm(32|64) E [^]]+]/d' '{args.stderr_file}'")
+
+  # Delete hiddenapi's denial errors which go to stderr on host.
+  if args.host:
+    ctx.run(fr"sed -i -E '/ E dalvikvm.* hiddenapi: /d' '{args.stderr_file}'")
diff --git a/test/817-hiddenapi/run.py b/test/817-hiddenapi/run.py
index 6855da1d81..14670eb0c5 100644
--- a/test/817-hiddenapi/run.py
+++ b/test/817-hiddenapi/run.py
@@ -20,3 +20,7 @@ def run(ctx, args):
   # On gcstress configurations, an extra "JNI_OnUnload called" line may
   # be emitted. If so, remove it.
   ctx.run(fr"sed -i '/^JNI_OnUnload called$/d' '{args.stdout_file}'")
+
+  # Delete hiddenapi's denial errors which go to stderr on host.
+  if args.host:
+    ctx.run(fr"sed -i -E '/ E dalvikvm.* hiddenapi: /d' '{args.stderr_file}'")
diff --git a/test/999-redefine-hiddenapi/run.py b/test/999-redefine-hiddenapi/run.py
index 4796039801..c3f6d8fb72 100644
--- a/test/999-redefine-hiddenapi/run.py
+++ b/test/999-redefine-hiddenapi/run.py
@@ -17,3 +17,7 @@
 
 def run(ctx, args):
   ctx.default_run(args, jvmti=True)
+
+  # Delete hiddenapi's denial errors which go to stderr on host.
+  if args.host:
+    ctx.run(fr"sed -i -E '/ E dalvikvm.* hiddenapi: /d' '{args.stderr_file}'")