summaryrefslogtreecommitdiffstats
path: root/ipc/mscom/InterceptorLog.cpp
diff options
context:
space:
mode:
authorMatt A. Tobin <mattatobin@localhost.localdomain>2018-02-02 04:16:08 -0500
committerMatt A. Tobin <mattatobin@localhost.localdomain>2018-02-02 04:16:08 -0500
commit5f8de423f190bbb79a62f804151bc24824fa32d8 (patch)
tree10027f336435511475e392454359edea8e25895d /ipc/mscom/InterceptorLog.cpp
parent49ee0794b5d912db1f95dce6eb52d781dc210db5 (diff)
downloadUXP-5f8de423f190bbb79a62f804151bc24824fa32d8.tar
UXP-5f8de423f190bbb79a62f804151bc24824fa32d8.tar.gz
UXP-5f8de423f190bbb79a62f804151bc24824fa32d8.tar.lz
UXP-5f8de423f190bbb79a62f804151bc24824fa32d8.tar.xz
UXP-5f8de423f190bbb79a62f804151bc24824fa32d8.zip
Add m-esr52 at 52.6.0
Diffstat (limited to 'ipc/mscom/InterceptorLog.cpp')
-rw-r--r--ipc/mscom/InterceptorLog.cpp466
1 files changed, 466 insertions, 0 deletions
diff --git a/ipc/mscom/InterceptorLog.cpp b/ipc/mscom/InterceptorLog.cpp
new file mode 100644
index 000000000..c2cd3c7df
--- /dev/null
+++ b/ipc/mscom/InterceptorLog.cpp
@@ -0,0 +1,466 @@
+/* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 2 -*- */
+/* vim: set ts=8 sts=2 et sw=2 tw=80: */
+/* This Source Code Form is subject to the terms of the Mozilla Public
+ * License, v. 2.0. If a copy of the MPL was not distributed with this
+ * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
+
+#include "mozilla/mscom/InterceptorLog.h"
+
+#include "MainThreadUtils.h"
+#include "mozilla/ClearOnShutdown.h"
+#include "mozilla/DebugOnly.h"
+#include "mozilla/mscom/Registration.h"
+#include "mozilla/Mutex.h"
+#include "mozilla/Services.h"
+#include "mozilla/StaticPtr.h"
+#include "mozilla/TimeStamp.h"
+#include "mozilla/Unused.h"
+#include "nsAppDirectoryServiceDefs.h"
+#include "nsDirectoryServiceDefs.h"
+#include "nsDirectoryServiceUtils.h"
+#include "nsIFileStreams.h"
+#include "nsIObserver.h"
+#include "nsIObserverService.h"
+#include "nsNetUtil.h"
+#include "nsPrintfCString.h"
+#include "nsTArray.h"
+#include "nsThreadUtils.h"
+#include "nsXPCOMPrivate.h"
+#include "nsXULAppAPI.h"
+#include "prenv.h"
+
+#include <callobj.h>
+
+using mozilla::DebugOnly;
+using mozilla::mscom::ArrayData;
+using mozilla::mscom::FindArrayData;
+using mozilla::Mutex;
+using mozilla::MutexAutoLock;
+using mozilla::NewNonOwningRunnableMethod;
+using mozilla::services::GetObserverService;
+using mozilla::StaticAutoPtr;
+using mozilla::TimeDuration;
+using mozilla::TimeStamp;
+using mozilla::Unused;
+
+namespace {
+
+class ShutdownEvent final : public nsIObserver
+{
+public:
+ NS_DECL_ISUPPORTS
+ NS_DECL_NSIOBSERVER
+
+private:
+ ~ShutdownEvent() {}
+};
+
+NS_IMPL_ISUPPORTS(ShutdownEvent, nsIObserver)
+
+class Logger
+{
+public:
+ explicit Logger(const nsACString& aLeafBaseName);
+ bool IsValid()
+ {
+ MutexAutoLock lock(mMutex);
+ return !!mThread;
+ }
+ void LogQI(HRESULT aResult, IUnknown* aTarget, REFIID aIid, IUnknown* aInterface);
+ void LogEvent(ICallFrame* aCallFrame, IUnknown* aTargetInterface);
+ nsresult Shutdown();
+
+private:
+ void OpenFile();
+ void Flush();
+ void CloseFile();
+ void AssertRunningOnLoggerThread();
+ bool VariantToString(const VARIANT& aVariant, nsACString& aOut, LONG aIndex = 0);
+ static double GetElapsedTime();
+
+ nsCOMPtr<nsIFile> mLogFileName;
+ nsCOMPtr<nsIOutputStream> mLogFile; // Only accessed by mThread
+ Mutex mMutex; // Guards mThread and mEntries
+ nsCOMPtr<nsIThread> mThread;
+ nsTArray<nsCString> mEntries;
+};
+
+Logger::Logger(const nsACString& aLeafBaseName)
+ : mMutex("mozilla::com::InterceptorLog::Logger")
+{
+ MOZ_ASSERT(NS_IsMainThread());
+ nsCOMPtr<nsIFile> logFileName;
+ GeckoProcessType procType = XRE_GetProcessType();
+ nsAutoCString leafName(aLeafBaseName);
+ nsresult rv;
+ if (procType == GeckoProcessType_Default) {
+ leafName.AppendLiteral("-Parent-");
+ rv = NS_GetSpecialDirectory(NS_OS_TEMP_DIR, getter_AddRefs(logFileName));
+ } else if (procType == GeckoProcessType_Content) {
+ leafName.AppendLiteral("-Content-");
+#if defined(MOZ_CONTENT_SANDBOX)
+ rv = NS_GetSpecialDirectory(NS_APP_CONTENT_PROCESS_TEMP_DIR,
+ getter_AddRefs(logFileName));
+#else
+ rv = NS_GetSpecialDirectory(NS_OS_TEMP_DIR,
+ getter_AddRefs(logFileName));
+#endif // defined(MOZ_CONTENT_SANDBOX)
+ } else {
+ return;
+ }
+ if (NS_FAILED(rv)) {
+ return;
+ }
+ DWORD pid = GetCurrentProcessId();
+ leafName.AppendPrintf("%u.log", pid);
+ // Using AppendNative here because Windows
+ rv = logFileName->AppendNative(leafName);
+ if (NS_FAILED(rv)) {
+ return;
+ }
+ mLogFileName.swap(logFileName);
+
+ nsCOMPtr<nsIObserverService> obsSvc = GetObserverService();
+ nsCOMPtr<nsIObserver> shutdownEvent = new ShutdownEvent();
+ rv = obsSvc->AddObserver(shutdownEvent, NS_XPCOM_SHUTDOWN_THREADS_OBSERVER_ID,
+ false);
+ if (NS_FAILED(rv)) {
+ return;
+ }
+
+ nsCOMPtr<nsIRunnable> openRunnable(
+ NewNonOwningRunnableMethod(this, &Logger::OpenFile));
+ rv = NS_NewNamedThread("COM Intcpt Log", getter_AddRefs(mThread),
+ openRunnable);
+ if (NS_FAILED(rv)) {
+ obsSvc->RemoveObserver(shutdownEvent, NS_XPCOM_SHUTDOWN_THREADS_OBSERVER_ID);
+ }
+}
+
+void
+Logger::AssertRunningOnLoggerThread()
+{
+#if defined(DEBUG)
+ nsCOMPtr<nsIThread> curThread;
+ if (NS_FAILED(NS_GetCurrentThread(getter_AddRefs(curThread)))) {
+ return;
+ }
+ MutexAutoLock lock(mMutex);
+ MOZ_ASSERT(curThread == mThread);
+#endif
+}
+
+void
+Logger::OpenFile()
+{
+ AssertRunningOnLoggerThread();
+ MOZ_ASSERT(mLogFileName && !mLogFile);
+ NS_NewLocalFileOutputStream(getter_AddRefs(mLogFile), mLogFileName,
+ PR_WRONLY | PR_CREATE_FILE | PR_TRUNCATE,
+ PR_IRUSR | PR_IWUSR | PR_IRGRP);
+}
+
+void
+Logger::CloseFile()
+{
+ AssertRunningOnLoggerThread();
+ MOZ_ASSERT(mLogFile);
+ if (!mLogFile) {
+ return;
+ }
+ Flush();
+ mLogFile->Close();
+ mLogFile = nullptr;
+}
+
+nsresult
+Logger::Shutdown()
+{
+ MOZ_ASSERT(NS_IsMainThread());
+ nsresult rv = mThread->Dispatch(NewNonOwningRunnableMethod(this,
+ &Logger::CloseFile),
+ NS_DISPATCH_NORMAL);
+ NS_WARNING_ASSERTION(NS_SUCCEEDED(rv), "Dispatch failed");
+
+ rv = mThread->Shutdown();
+ NS_WARNING_ASSERTION(NS_SUCCEEDED(rv), "Shutdown failed");
+ return NS_OK;
+}
+
+bool
+Logger::VariantToString(const VARIANT& aVariant, nsACString& aOut, LONG aIndex)
+{
+ switch (aVariant.vt) {
+ case VT_DISPATCH: {
+ aOut.AppendPrintf("(IDispatch*) 0x%0p", aVariant.pdispVal);
+ return true;
+ }
+ case VT_DISPATCH | VT_BYREF: {
+ aOut.AppendPrintf("(IDispatch*) 0x%0p", (aVariant.ppdispVal)[aIndex]);
+ return true;
+ }
+ case VT_UNKNOWN: {
+ aOut.AppendPrintf("(IUnknown*) 0x%0p", aVariant.punkVal);
+ return true;
+ }
+ case VT_UNKNOWN | VT_BYREF: {
+ aOut.AppendPrintf("(IUnknown*) 0x%0p", (aVariant.ppunkVal)[aIndex]);
+ return true;
+ }
+ case VT_VARIANT | VT_BYREF: {
+ return VariantToString((aVariant.pvarVal)[aIndex], aOut);
+ }
+ case VT_I4 | VT_BYREF: {
+ aOut.AppendPrintf("%d", aVariant.plVal[aIndex]);
+ return true;
+ }
+ case VT_UI4 | VT_BYREF: {
+ aOut.AppendPrintf("%u", aVariant.pulVal[aIndex]);
+ return true;
+ }
+ case VT_I4: {
+ aOut.AppendPrintf("%d", aVariant.lVal);
+ return true;
+ }
+ case VT_UI4: {
+ aOut.AppendPrintf("%u", aVariant.ulVal);
+ return true;
+ }
+ case VT_EMPTY: {
+ aOut.AppendLiteral("(empty VARIANT)");
+ return true;
+ }
+ case VT_NULL: {
+ aOut.AppendLiteral("(null VARIANT)");
+ return true;
+ }
+ case VT_BSTR: {
+ aOut.AppendPrintf("\"%S\"", aVariant.bstrVal);
+ return true;
+ }
+ case VT_BSTR | VT_BYREF: {
+ aOut.AppendPrintf("\"%S\"", *aVariant.pbstrVal);
+ return true;
+ }
+ default: {
+ aOut.AppendPrintf("(VariantToString failed, VARTYPE == 0x%04hx)",
+ aVariant.vt);
+ return false;
+ }
+ }
+}
+
+/* static */ double
+Logger::GetElapsedTime()
+{
+ TimeStamp ts = TimeStamp::Now();
+ bool inconsistent;
+ TimeDuration duration = ts - TimeStamp::ProcessCreation(inconsistent);
+ return duration.ToMicroseconds();
+}
+
+void
+Logger::LogQI(HRESULT aResult, IUnknown* aTarget, REFIID aIid, IUnknown* aInterface)
+{
+ if (FAILED(aResult)) {
+ return;
+ }
+ double elapsed = GetElapsedTime();
+
+ nsPrintfCString line("%fus\t0x%0p\tIUnknown::QueryInterface\t([in] ", elapsed,
+ aTarget);
+
+ WCHAR buf[39] = {0};
+ if (StringFromGUID2(aIid, buf, mozilla::ArrayLength(buf))) {
+ line.AppendPrintf("%S", buf);
+ } else {
+ line.AppendLiteral("(IID Conversion Failed)");
+ }
+ line.AppendPrintf(", [out] 0x%p)\t0x%08X\n", aInterface, aResult);
+
+ MutexAutoLock lock(mMutex);
+ mEntries.AppendElement(line);
+ mThread->Dispatch(NewNonOwningRunnableMethod(this, &Logger::Flush),
+ NS_DISPATCH_NORMAL);
+}
+
+void
+Logger::LogEvent(ICallFrame* aCallFrame, IUnknown* aTargetInterface)
+{
+ // (1) Gather info about the call
+ double elapsed = GetElapsedTime();
+
+ CALLFRAMEINFO callInfo;
+ HRESULT hr = aCallFrame->GetInfo(&callInfo);
+ if (FAILED(hr)) {
+ return;
+ }
+
+ PWSTR interfaceName = nullptr;
+ PWSTR methodName = nullptr;
+ hr = aCallFrame->GetNames(&interfaceName, &methodName);
+ if (FAILED(hr)) {
+ return;
+ }
+
+ // (2) Serialize the call
+ nsPrintfCString line("%fus\t0x%p\t%S::%S\t(", elapsed,
+ aTargetInterface, interfaceName, methodName);
+
+ CoTaskMemFree(interfaceName);
+ interfaceName = nullptr;
+ CoTaskMemFree(methodName);
+ methodName = nullptr;
+
+ // Check for supplemental array data
+ const ArrayData* arrayData = FindArrayData(callInfo.iid, callInfo.iMethod);
+
+ for (ULONG paramIndex = 0; paramIndex < callInfo.cParams; ++paramIndex) {
+ CALLFRAMEPARAMINFO paramInfo;
+ hr = aCallFrame->GetParamInfo(paramIndex, &paramInfo);
+ if (SUCCEEDED(hr)) {
+ line.AppendLiteral("[");
+ if (paramInfo.fIn) {
+ line.AppendLiteral("in");
+ }
+ if (paramInfo.fOut) {
+ line.AppendLiteral("out");
+ }
+ line.AppendLiteral("] ");
+ }
+ VARIANT paramValue;
+ hr = aCallFrame->GetParam(paramIndex, &paramValue);
+ if (SUCCEEDED(hr)) {
+ if (arrayData && paramIndex == arrayData->mArrayParamIndex) {
+ VARIANT lengthParam;
+ hr = aCallFrame->GetParam(arrayData->mLengthParamIndex, &lengthParam);
+ if (SUCCEEDED(hr)) {
+ line.AppendLiteral("{ ");
+ for (LONG i = 0; i < *lengthParam.plVal; ++i) {
+ VariantToString(paramValue, line, i);
+ if (i < *lengthParam.plVal - 1) {
+ line.AppendLiteral(", ");
+ }
+ }
+ line.AppendLiteral(" }");
+ } else {
+ line.AppendPrintf("(GetParam failed with HRESULT 0x%08X)", hr);
+ }
+ } else {
+ VariantToString(paramValue, line);
+ }
+ } else {
+ line.AppendPrintf("(GetParam failed with HRESULT 0x%08X)", hr);
+ }
+ if (paramIndex < callInfo.cParams - 1) {
+ line.AppendLiteral(", ");
+ }
+ }
+ line.AppendLiteral(")\t");
+
+ HRESULT callResult = aCallFrame->GetReturnValue();
+ line.AppendPrintf("0x%08X\n", callResult);
+
+ // (3) Enqueue event for logging
+ MutexAutoLock lock(mMutex);
+ mEntries.AppendElement(line);
+ mThread->Dispatch(NewNonOwningRunnableMethod(this, &Logger::Flush),
+ NS_DISPATCH_NORMAL);
+}
+
+void
+Logger::Flush()
+{
+ AssertRunningOnLoggerThread();
+ MOZ_ASSERT(mLogFile);
+ if (!mLogFile) {
+ return;
+ }
+ nsTArray<nsCString> linesToWrite;
+ { // Scope for lock
+ MutexAutoLock lock(mMutex);
+ linesToWrite.SwapElements(mEntries);
+ }
+
+ for (uint32_t i = 0, len = linesToWrite.Length(); i < len; ++i) {
+ uint32_t bytesWritten;
+ nsCString& line = linesToWrite[i];
+ nsresult rv = mLogFile->Write(line.get(), line.Length(), &bytesWritten);
+ NS_WARN_IF(NS_FAILED(rv));
+ }
+}
+
+StaticAutoPtr<Logger> sLogger;
+
+NS_IMETHODIMP
+ShutdownEvent::Observe(nsISupports* aSubject, const char* aTopic,
+ const char16_t* aData)
+{
+ if (strcmp(aTopic, NS_XPCOM_SHUTDOWN_THREADS_OBSERVER_ID)) {
+ MOZ_ASSERT(false);
+ return NS_ERROR_NOT_IMPLEMENTED;
+ }
+ MOZ_ASSERT(sLogger);
+ Unused << NS_WARN_IF(NS_FAILED(sLogger->Shutdown()));
+ nsCOMPtr<nsIObserver> kungFuDeathGrip(this);
+ nsCOMPtr<nsIObserverService> obsSvc = GetObserverService();
+ obsSvc->RemoveObserver(this, aTopic);
+ return NS_OK;
+}
+} // anonymous namespace
+
+
+static bool
+MaybeCreateLog(const char* aEnvVarName)
+{
+ MOZ_ASSERT(NS_IsMainThread());
+ MOZ_ASSERT(XRE_IsContentProcess() || XRE_IsParentProcess());
+ MOZ_ASSERT(!sLogger);
+ const char* leafBaseName = PR_GetEnv(aEnvVarName);
+ if (!leafBaseName) {
+ return false;
+ }
+ nsDependentCString strLeafBaseName(leafBaseName);
+ if (strLeafBaseName.IsEmpty()) {
+ return false;
+ }
+ sLogger = new Logger(strLeafBaseName);
+ if (!sLogger->IsValid()) {
+ sLogger = nullptr;
+ return false;
+ }
+ ClearOnShutdown(&sLogger);
+ return true;
+}
+
+namespace mozilla {
+namespace mscom {
+
+/* static */ bool
+InterceptorLog::Init()
+{
+ static const bool isEnabled = MaybeCreateLog("MOZ_MSCOM_LOG_BASENAME");
+ return isEnabled;
+}
+
+/* static */ void
+InterceptorLog::QI(HRESULT aResult, IUnknown* aTarget, REFIID aIid, IUnknown* aInterface)
+{
+ if (!sLogger) {
+ return;
+ }
+ sLogger->LogQI(aResult, aTarget, aIid, aInterface);
+}
+
+/* static */ void
+InterceptorLog::Event(ICallFrame* aCallFrame, IUnknown* aTargetInterface)
+{
+ if (!sLogger) {
+ return;
+ }
+ sLogger->LogEvent(aCallFrame, aTargetInterface);
+}
+
+} // namespace mscom
+} // namespace mozilla
+