From b8f8dd72361fff9d7a6de854dc7a326fdba5cd97 Mon Sep 17 00:00:00 2001
From: Robbert van der Helm <mail@robbertvanderhelm.nl>
Date: Thu, 29 Apr 2021 00:38:10 +0200
Subject: [PATCH] Log cached audioMasterGetTime() calls

Just like we log cached VST3 function calls.
---
 src/common/logging/vst2.cpp    |  7 ++++++-
 src/common/logging/vst2.h      |  3 ++-
 src/wine-host/bridges/vst2.cpp | 11 +++++++++--
 3 files changed, 17 insertions(+), 4 deletions(-)

diff --git a/src/common/logging/vst2.cpp b/src/common/logging/vst2.cpp
index 9241a1ae..1b0c1c50 100644
--- a/src/common/logging/vst2.cpp
+++ b/src/common/logging/vst2.cpp
@@ -449,7 +449,8 @@ void Vst2Logger::log_event_response(
     int opcode,
     intptr_t return_value,
     const EventResultPayload& payload,
-    const std::optional<EventResultPayload>& value_payload) {
+    const std::optional<EventResultPayload>& value_payload,
+    bool from_cache) {
     if (BOOST_UNLIKELY(logger.verbosity >= Logger::Verbosity::most_events)) {
         if (should_filter_event(is_dispatch, opcode)) {
             return;
@@ -516,6 +517,10 @@ void Vst2Logger::log_event_response(
                 }},
             payload);
 
+        if (from_cache) {
+            message << " (from cache)";
+        }
+
         log(message.str());
     }
 }
diff --git a/src/common/logging/vst2.h b/src/common/logging/vst2.h
index 1cfa103d..ede2696e 100644
--- a/src/common/logging/vst2.h
+++ b/src/common/logging/vst2.h
@@ -74,7 +74,8 @@ class Vst2Logger {
         int opcode,
         intptr_t return_value,
         const EventResultPayload& payload,
-        const std::optional<EventResultPayload>& value_payload);
+        const std::optional<EventResultPayload>& value_payload,
+        bool from_cache = false);
 
     /**
      * The underlying logger instance we're wrapping.
diff --git a/src/wine-host/bridges/vst2.cpp b/src/wine-host/bridges/vst2.cpp
index 0f1f8aba..dd0fb193 100644
--- a/src/wine-host/bridges/vst2.cpp
+++ b/src/wine-host/bridges/vst2.cpp
@@ -607,10 +607,17 @@ intptr_t Vst2Bridge::host_callback(AEffect* effect,
             if (cached_time_info) {
                 // This cached value is temporary, so we'll still use the
                 // regular time info storing mechanism
-                // TODO: Log when we hit this cache so it doesn't get hidden
                 last_time_info = *cached_time_info;
+                const intptr_t result =
+                    reinterpret_cast<intptr_t>(&last_time_info);
 
-                return reinterpret_cast<intptr_t>(&last_time_info);
+                // Make sure that these cached events don't get lost in the logs
+                logger.log_event(false, opcode, index, value,
+                                 WantsVstTimeInfo{}, option, std::nullopt);
+                logger.log_event_response(false, opcode, result, last_time_info,
+                                          std::nullopt, true);
+
+                return result;
             }
         } break;
     }