Add metrics logging logic
...for bad packet lengths and duplicate seqnos.
Bug: 244578445, 245275823
Test: Built and ran emulator
Change-Id: I65cc5b4347e6d85417b8d643f4a4a93b628ae401
diff --git a/stream-servers/FrameBuffer.h b/stream-servers/FrameBuffer.h
index 022ea13..0fa3863 100644
--- a/stream-servers/FrameBuffer.h
+++ b/stream-servers/FrameBuffer.h
@@ -630,6 +630,9 @@
std::unique_ptr<BorrowedImageInfo> borrowColorBufferForDisplay(uint32_t colorBufferHandle);
HealthMonitor<>& getHealthMonitor();
+ emugl::MetricsLogger& getMetricsLogger() {
+ return *m_logger;
+ }
private:
FrameBuffer(int p_width, int p_height, bool useSubWindow);
diff --git a/stream-servers/RenderThread.cpp b/stream-servers/RenderThread.cpp
index 664c8c6..5425ed9 100644
--- a/stream-servers/RenderThread.cpp
+++ b/stream-servers/RenderThread.cpp
@@ -348,6 +348,7 @@
}
GfxApiLogger gfxLogger;
+ auto& metricsLogger = FrameBuffer::getFB()->getMetricsLogger();
uint32_t* seqnoPtr = nullptr;
@@ -454,6 +455,7 @@
.processName = processName,
.gfxApiLogger = &gfxLogger,
.healthMonitor = &FrameBuffer::getFB()->getHealthMonitor(),
+ .metricsLogger = &metricsLogger,
};
last = tInfo.m_vkInfo->m_vkDec.decode(readBuf.buf(), readBuf.validData(), ioStream,
seqnoPtr, context);
diff --git a/stream-servers/vulkan/VkDecoder.cpp b/stream-servers/vulkan/VkDecoder.cpp
index 743bef3..ba5b424 100644
--- a/stream-servers/vulkan/VkDecoder.cpp
+++ b/stream-servers/vulkan/VkDecoder.cpp
@@ -30,6 +30,7 @@
#include "VkDecoder.h"
#include <functional>
+#include <optional>
#include <unordered_map>
#include "VkDecoderGlobalState.h"
@@ -37,6 +38,7 @@
#include "VulkanDispatch.h"
#include "VulkanStream.h"
#include "base/BumpPool.h"
+#include "base/Metrics.h"
#include "base/System.h"
#include "base/Tracing.h"
#include "common/goldfish_vk_marshaling.h"
@@ -48,6 +50,10 @@
#include "host-common/logging.h"
#include "stream-servers/IOStream.h"
+#define MAX_PACKET_LENGTH (400 * 1024 * 1024) // 400MB
+
+using android::base::MetricEventBadPacketLength;
+using android::base::MetricEventDuplicateSequenceNum;
using emugl::vkDispatch;
using namespace goldfish_vk;
@@ -62,7 +68,8 @@
m_boxedHandleCreateMapping(m_state),
m_boxedHandleDestroyMapping(m_state),
m_boxedHandleUnwrapAndDeleteMapping(m_state),
- m_boxedHandleUnwrapAndDeletePreserveBoxedMapping(m_state) {}
+ m_boxedHandleUnwrapAndDeletePreserveBoxedMapping(m_state),
+ m_prevSeqno(std::nullopt) {}
VulkanStream* stream() { return &m_vkStream; }
VulkanMemReadingStream* readStream() { return &m_vkMemReadingStream; }
@@ -84,6 +91,7 @@
BoxedHandleUnwrapAndDeleteMapping m_boxedHandleUnwrapAndDeleteMapping;
android::base::BumpPool m_pool;
BoxedHandleUnwrapAndDeletePreserveBoxedMapping m_boxedHandleUnwrapAndDeletePreserveBoxedMapping;
+ std::optional<uint32_t> m_prevSeqno;
};
VkDecoder::VkDecoder() : mImpl(new VkDecoder::Impl()) {}
@@ -106,6 +114,7 @@
const char* processName = context.processName;
auto& gfx_logger = *context.gfxApiLogger;
auto& healthMonitor = *context.healthMonitor;
+ auto& metricsLogger = *context.metricsLogger;
if (len < 8) return 0;
bool queueSubmitWithCommandsEnabled =
feature_is_enabled(kFeature_VulkanQueueSubmitWithCommands);
@@ -117,6 +126,13 @@
while (end - ptr >= 8) {
uint32_t opcode = *(uint32_t*)ptr;
uint32_t packetLen = *(uint32_t*)(ptr + 4);
+
+ // packetLen should be at least 8 (op code and packet length) and should not be excessively large
+ if (packetLen < 8 || packetLen > MAX_PACKET_LENGTH) {
+ WARN("Bad packet length %d detected, decode may fail", packetLen);
+ metricsLogger.logMetricEvent(MetricEventBadPacketLength{.len = packetLen});
+ }
+
if (end - ptr < packetLen) return ptr - (unsigned char*)buf;
gfx_logger.record(ptr, std::min(size_t(packetLen + 8), size_t(end - ptr)));
stream()->setStream(ioStream);
@@ -134,6 +150,13 @@
uint32_t seqno;
memcpy(&seqno, *readStreamPtrPtr, sizeof(uint32_t));
*readStreamPtrPtr += sizeof(uint32_t);
+ if (m_prevSeqno && seqno == m_prevSeqno.value()) {
+ WARN(
+ "Seqno %d is the same as previously processed on thread %d. It might be a "
+ "duplicate command.",
+ seqno, getCurrentThreadId());
+ metricsLogger.logMetricEvent(MetricEventDuplicateSequenceNum{.opcode = opcode});
+ }
if (seqnoPtr && !m_forSnapshotLoad) {
{
auto watchdog =
@@ -162,6 +185,7 @@
__asm__ __volatile__("pause;");
#endif
}
+ m_prevSeqno = seqno;
}
}
}
@@ -32196,7 +32220,7 @@
if (queueSubmitWithCommandsEnabled)
__atomic_fetch_add(seqnoPtr, 1, __ATOMIC_SEQ_CST);
m_state->on_vkQueueFlushCommandsGOOGLE(&m_pool, queue, commandBuffer, dataSize,
- pData, gfx_logger);
+ pData, context);
vkStream->unsetHandleMapping();
vkReadStream->setReadPos((uintptr_t)(*readStreamPtrPtr) -
(uintptr_t)snapshotTraceBegin);
diff --git a/stream-servers/vulkan/VkDecoderContext.h b/stream-servers/vulkan/VkDecoderContext.h
index a80d6a4..7b3f1f2 100644
--- a/stream-servers/vulkan/VkDecoderContext.h
+++ b/stream-servers/vulkan/VkDecoderContext.h
@@ -15,11 +15,15 @@
#pragma once
+#include <memory>
+
#include "base/GfxApiLogger.h"
#include "base/HealthMonitor.h"
+#include "base/Metrics.h"
struct VkDecoderContext {
const char* processName = nullptr;
emugl::GfxApiLogger* gfxApiLogger = nullptr;
emugl::HealthMonitor<>* healthMonitor = nullptr;
+ emugl::MetricsLogger* metricsLogger = nullptr;
};
\ No newline at end of file
diff --git a/stream-servers/vulkan/VkDecoderGlobalState.cpp b/stream-servers/vulkan/VkDecoderGlobalState.cpp
index de9b2cc..5b05d76 100644
--- a/stream-servers/vulkan/VkDecoderGlobalState.cpp
+++ b/stream-servers/vulkan/VkDecoderGlobalState.cpp
@@ -27,6 +27,7 @@
#include "VkAndroidNativeBuffer.h"
#include "VkCommonOperations.h"
#include "VkDecoderSnapshot.h"
+#include "VkDecoderContext.h"
#include "VkFormatUtils.h"
#include "VulkanDispatch.h"
#include "VulkanStream.h"
@@ -70,6 +71,8 @@
using android::base::ConditionVariable;
using android::base::Lock;
using android::base::ManagedDescriptor;
+using android::base::MetricEventBadPacketLength;
+using android::base::MetricEventDuplicateSequenceNum;
using android::base::DescriptorType;
using android::base::Optional;
using android::base::StaticLock;
@@ -4678,13 +4681,13 @@
void on_vkQueueFlushCommandsGOOGLE(android::base::BumpPool* pool, VkQueue queue,
VkCommandBuffer boxed_commandBuffer, VkDeviceSize dataSize,
- const void* pData, GfxApiLogger& gfxLogger) {
+ const void* pData, const VkDecoderContext& context) {
(void)queue;
VkCommandBuffer commandBuffer = unbox_VkCommandBuffer(boxed_commandBuffer);
VulkanDispatch* vk = dispatch_VkCommandBuffer(boxed_commandBuffer);
VulkanMemReadingStream* readStream = readstream_VkCommandBuffer(boxed_commandBuffer);
- subDecode(readStream, vk, boxed_commandBuffer, commandBuffer, dataSize, pData, gfxLogger);
+ subDecode(readStream, vk, boxed_commandBuffer, commandBuffer, dataSize, pData, context);
}
VkDescriptorSet getOrAllocateDescriptorSetFromPoolAndId(VulkanDispatch* vk, VkDevice device,
@@ -8030,8 +8033,8 @@
VkQueue queue,
VkCommandBuffer commandBuffer,
VkDeviceSize dataSize, const void* pData,
- GfxApiLogger& gfxLogger) {
- mImpl->on_vkQueueFlushCommandsGOOGLE(pool, queue, commandBuffer, dataSize, pData, gfxLogger);
+ const VkDecoderContext& context) {
+ mImpl->on_vkQueueFlushCommandsGOOGLE(pool, queue, commandBuffer, dataSize, pData, context);
}
void VkDecoderGlobalState::on_vkQueueCommitDescriptorSetUpdatesGOOGLE(
diff --git a/stream-servers/vulkan/VkDecoderGlobalState.h b/stream-servers/vulkan/VkDecoderGlobalState.h
index 257adc2..c854763 100644
--- a/stream-servers/vulkan/VkDecoderGlobalState.h
+++ b/stream-servers/vulkan/VkDecoderGlobalState.h
@@ -20,6 +20,7 @@
#include <utility>
#include <vector>
+#include "VkDecoderContext.h"
#include "VkQsriTimeline.h"
#include "VulkanDispatch.h"
#include "VulkanHandleMapping.h"
@@ -582,7 +583,7 @@
// VK_GOOGLE_gfxstream
void on_vkQueueFlushCommandsGOOGLE(android::base::BumpPool* pool, VkQueue queue,
VkCommandBuffer commandBuffer, VkDeviceSize dataSize,
- const void* pData, emugl::GfxApiLogger& gfxLogger);
+ const void* pData, const VkDecoderContext& context);
void on_vkQueueCommitDescriptorSetUpdatesGOOGLE(
android::base::BumpPool* pool, VkQueue queue, uint32_t descriptorPoolCount,
const VkDescriptorPool* pDescriptorPools, uint32_t descriptorSetCount,
diff --git a/stream-servers/vulkan/VkSubDecoder.cpp b/stream-servers/vulkan/VkSubDecoder.cpp
index 1c472c3..45ac925 100644
--- a/stream-servers/vulkan/VkSubDecoder.cpp
+++ b/stream-servers/vulkan/VkSubDecoder.cpp
@@ -27,9 +27,12 @@
// python3 $VULKAN_REGISTRY_SCRIPTS_DIR/genvk.py -registry $VULKAN_REGISTRY_XML_DIR/vk.xml cereal -o $CEREAL_OUTPUT_DIR
//
#define MAX_STACK_ITEMS 16
+#define MAX_PACKET_LENGTH (400 * 1024 * 1024) // 400MB
size_t subDecode(VulkanMemReadingStream* readStream, VulkanDispatch* vk, void* boxed_dispatchHandle,
void* dispatchHandle, VkDeviceSize dataSize, const void* pData,
- GfxApiLogger& gfx_logger) {
+ const VkDecoderContext& context) {
+ auto& gfx_logger = *context.gfxApiLogger;
+ auto& metricsLogger = *context.metricsLogger;
uint32_t count = 0;
unsigned char* buf = (unsigned char*)pData;
android::base::BumpPool* pool = readStream->pool();
@@ -39,6 +42,13 @@
while (end - ptr >= 8) {
uint32_t opcode = *(uint32_t*)ptr;
uint32_t packetLen = *(uint32_t*)(ptr + 4);
+
+ // packetLen should be at least 8 (op code and packet length) and should not be excessively large
+ if (packetLen < 8 || packetLen > MAX_PACKET_LENGTH) {
+ WARN("Bad packet length %d detected, subdecode may fail", packetLen);
+ metricsLogger.logMetricEvent(MetricEventBadPacketLength{.len = packetLen});
+ }
+
if (end - ptr < packetLen) return ptr - (unsigned char*)buf;
gfx_logger.record(ptr, std::min(size_t(packetLen + 8), size_t(end - ptr)));
readStream->setBuf((uint8_t*)(ptr + 8));
