more logging

.github/actions/spell-check/expect.txt

@@ -37,6 +37,7 @@ akamaihd
 ALarger
 alekhyareddy
 alertsolid
+alignas
 ALIGNLEFT
 ALLAPPS
 Alloc
@@ -127,6 +128,8 @@ Autorun
 AUTOSIZECOLUMNS
 autoupdate
 AValid
+avialable
+AYUV
 azurecr
 azurewebsites
 backend
@@ -191,6 +194,7 @@ buildtransitive
 BValue
 bytearray
 callbackptr
+Camer
 CANRENAME
 Captureascreenshot
 CAPTURECHANGED
@@ -400,6 +404,7 @@ dcomp
 DComposition
 ddd
 ddee
+ddf
 Deact
 declspec
 decltype
@@ -444,6 +449,7 @@ DFactory
 Dialpad
 diffing
 difftime
+DIIRFLAG
 dimm
 dirname
 dirs
@@ -499,6 +505,10 @@ dupenv
 dutil
 DVASPECT
 DVASPECTINFO
+DVH
+DVHD
+DVSD
+DVSL
 DVTARGETDEVICE
 dw
 DWindow
@@ -518,6 +528,8 @@ dword
 dworigin
 dwrite
 dxgi
+dxgiformat
+dxguid
 EABF
 EAC
 EACB
@@ -621,6 +633,7 @@ EFFE
 efgh
 EFile
 egistry
+elif
 ELogo
 elseif
 Emoji
@@ -629,6 +642,7 @@ ENABLEDPOPUP
 endforeach
 endif
 endl
+endpointvolume
 endregion
 Enque
 ENTERSIZEMOVE
@@ -715,7 +729,9 @@ filesystem
 FILETIME
 FILETYPE
 FILEVERSION
+Filtergraph
 Filterkeyboard
+Filterx
 finalizer
 findstr
 FIXEDFILEINFO
@@ -744,6 +760,7 @@ FTYPE
 FULLNAME
 fullscreen
 func
+Functiondiscoverykeys
 fwlink
 fwrite
 fx
@@ -753,6 +770,7 @@ GAC
 gacutil
 Gamebar
 GBs
+GCLP
 gcnew
 gdi
 gdiplus
@@ -795,9 +813,11 @@ hashcode
 hbitmap
 hbmp
 hbr
+HBRBACKGROUND
 HBRUSH
 hc
 hcblack
+HCERTSTORE
 hcwhite
 hdc
 HDF
@@ -809,7 +829,9 @@ hdrop
 HDS
 HEB
 helptext
-HGLOBAL
+HEVC
+hfile
+hglobal
 hh
 hhk
 HHmmss
@@ -883,11 +905,13 @@ IApp
 IApplication
 IAppx
 IAsync
+IAudio
 IAuto
 IBackground
 IBase
 IBeam
 IBind
+ICapture
 icase
 iccex
 ICEBLUE
@@ -940,9 +964,11 @@ IFancy
 ifdef
 IFeatures
 IFile
+IFilter
 ifndef
 IFolder
 ifstream
+IGraph
 IIcon
 iid
 IImage
@@ -961,6 +987,8 @@ IMAGERESIZEREXT
 IMain
 IMarkdown
 ime
+IMedia
+IMem
 imeutil
 img
 IMoniker
@@ -1019,6 +1047,7 @@ IObject
 iobjectwithsitesetsite
 IOle
 iolewindowcontextsensitivehelp
+iomanip
 iostream
 ip
 IPackage
@@ -1040,6 +1069,7 @@ IProperty
 IPublic
 IQuery
 IRead
+IReference
 IReflect
 IRegistered
 IRegistration
@@ -1082,7 +1112,9 @@ IVector
 IView
 IVirtual
 IWeb
+IWIC
 ixx
+IYUV
 IZone
 IZoom
 JArray
@@ -1129,6 +1161,7 @@ keyup
 Kf
 KILLFOCUS
 Knownfolders
+KSPROPERTY
 Kybd
 LAlt
 lambson
@@ -1151,6 +1184,7 @@ Ldone
 LEFTSCROLLBAR
 lego
 len
+LEQ
 LError
 Lessthan
 LEVELID
@@ -1253,6 +1287,7 @@ MAINICON
 Mainwindow
 majortype
 makeappx
+makecab
 MAKEINTRESOURCE
 MAKEINTRESOURCEW
 MAKELPARAM
@@ -1270,6 +1305,7 @@ MATCHMODE
 MAXIMIZEBOX
 MAXSHORTCUTSIZE
 maxversiontested
+MBs
 MBUTTON
 MBUTTONDBLCLK
 MBUTTONDOWN
@@ -1281,6 +1317,7 @@ mdpreviewhandler
 MEDIASUBTYPE
 MEDIATYPE
 Melman
+memcmp
 memcpy
 memset
 Mensching
@@ -1292,8 +1329,17 @@ messageboxes
 METACHARSET
 metadata
 metafile
+mfapi
 mfc
 mfcribbon
+mfidl
+mfobjects
+mfplat
+mfreadwrite
+Mfsensorgroup
+mftransform
+mfuuid
+mic
 microsoft
 Midl
 mii
@@ -1305,10 +1351,12 @@ MINIMIZEBOX
 miniz
 MINMAXINFO
 Miracast
+mirophone
 mixin
 MJPG
 mkdir
 MLogo
+mmdeviceapi
 MMI
 mockapi
 MODECHANGE
@@ -1372,6 +1420,7 @@ mutex
 mutexes
 muxc
 mvvm
+myfile
 MYICON
 myuri
 NAMECHANGE
@@ -1409,6 +1458,7 @@ netsh
 netstandard
 Neue
 newcolor
+newdev
 newitem
 newpath
 newrow
@@ -1433,6 +1483,7 @@ nodoc
 noexcept
 NOFRAMES
 NOINHERITLAYOUT
+NOINTERFACE
 NOLINKINFO
 NOMINMAX
 NOMOVE
@@ -1520,6 +1571,7 @@ Openthe
 openxmlformats
 OPTIMIZEFORINVOKE
 OPTIONSGROUP
+ORAW
 ORPHANEDDIALOGTITLE
 oss
 ostr
@@ -1530,6 +1582,7 @@ osx
 otating
 OUTOFCONTEXT
 OUTOFMEMORY
+outpin
 Outptr
 outro
 OVERLAPPEDWINDOW
@@ -1589,6 +1642,7 @@ Pipelinhttps
 pipename
 pitem
 PKBDLLHOOKSTRUCT
+PKEY
 placeholders
 plib
 PLK
@@ -1610,6 +1664,7 @@ popd
 popup
 POPUPWINDOW
 posix
+Postion
 powerappscds
 powerlauncher
 powerpreview
@@ -1622,6 +1677,7 @@ powertoyssetup
 Powrprof
 ppenum
 ppidl
+ppmt
 pprm
 pproc
 ppsi
@@ -1638,11 +1694,13 @@ precomp
 Preinstalled
 preload
 PREMULTIPLIED
+preperty
 prevhost
 previewer
 PREVIEWGROUP
 PREVIEWHANDLERFRAMEINFO
 previewpane
+previouscamera
 PREVIOUSVERSIONSINSTALLED
 prevpane
 prgms
@@ -1689,6 +1747,7 @@ pw
 pwa
 pwcs
 PWSTR
+pwsz
 pwtd
 px
 Qand
@@ -1734,13 +1793,17 @@ refactor
 refactoring
 REFCLSID
 refcount
+REFGUID
 REFIID
 REGCLS
 regedit
 regex
+REGFILTER
+REGFILTERPINS
 REGISTERCLASSFAILED
 registrypath
 regkey
+REGPINTYPES
 reimplementing
 reloadable
 Remapper
@@ -1791,6 +1854,7 @@ RKey
 RMENU
 RNumber
 roadmap
+robocopy
 Roboto
 roslyn
 royvou
@@ -1890,6 +1954,7 @@ Shl
 shldisp
 shlobj
 shlwapi
+shmem
 shobjidl
 SHORTCUTATLEAST
 shortcutcontrol
@@ -1927,6 +1992,7 @@ SIZENESW
 SIZENS
 SIZENWSE
 sizeof
+sizeread
 SIZEWE
 sketchapp
 SKIPOWNPROCESS
@@ -1952,6 +2018,7 @@ spesi
 spinbuttonref
 splitwstring
 spoprod
+sprintf
 spsi
 spsia
 spsrif
@@ -2044,6 +2111,7 @@ swprintf
 SYMED
 Symlink
 SYMOPT
+SYNCMFT
 SYNCPAINT
 sys
 SYSCHAR
@@ -2116,6 +2184,7 @@ TLayout
 tlb
 tlbimp
 tmp
+TMPVAR
 TNP
 todo
 toggleleft
@@ -2136,12 +2205,14 @@ towlower
 towupper
 tracelogging
 traies
+transparrent
 TRAYMOUSEMESSAGE
 TRK
 trl
 truetype
 trunc
 tslint
+tspan
 TStr
 tsx
 tt
@@ -2176,6 +2247,7 @@ ul
 ULARGE
 ULLONG
 ulong
+ULONGLONG
 umd
 unchecks
 uncomment
@@ -2203,6 +2275,7 @@ unknwn
 UNLEN
 unlicense
 Unmap
+unmute
 UNORM
 Unpublish
 unregister
@@ -2239,16 +2312,20 @@ uv
 uwp
 UWPUI
 uxtheme
+UYVY
 validmodulename
 vcamp
 vccorlib
+vcdl
 VCINSTALLDIR
+vcm
 vcomp
 vcredist
 VCRT
 vcruntime
 vcvars
 vcxproj
+vdi
 VDId
 vec
 VERBSONLY
@@ -2262,6 +2339,7 @@ vid
 VIDEOINFOHEADER
 viewbox
 viewmodel
+vih
 virtualization
 Visibletrue
 Visio
@@ -2305,6 +2383,9 @@ wcscpy
 wcslen
 wcsncmp
 wcsnicmp
+wdk
+wdksetup
+wdkvsix
 wdp
 wdupenv
 weakme
@@ -2377,6 +2458,7 @@ wmonk
 wmp
 WMSYSKEYDOWN
 WMSYSKEYUP
+WMV
 wnd
 WNDCLASS
 WNDCLASSEX
@@ -2406,8 +2488,10 @@ wstring
 wstringstream
 wsz
 WTS
+wtsapi
 WTSAT
 wu
+WVC
 Wwan
 www
 wxs
@@ -2421,7 +2505,7 @@ XBUTTON
 XBUTTONDBLCLK
 XBUTTONDOWN
 XBUTTONUP
-XCOPY
+xcopy
 XDiff
 XDocument
 XElement

src/modules/videoconference/VideoConferenceProxyFilter/VideoCaptureDevice.cpp

@@ -371,6 +371,7 @@ const char* GetMediaSubTypeString(const GUID& guid)
 
 std::optional<VideoStreamFormat> SelectBestMediaType(wil::com_ptr_nothrow<IPin>& pin)
 {
+    VERBOSE_LOG;
     wil::com_ptr_nothrow<IEnumMediaTypes> mediaTypeEnum;
     if (pin->EnumMediaTypes(&mediaTypeEnum); !mediaTypeEnum)
     {
@@ -385,23 +386,28 @@ std::optional<VideoStreamFormat> SelectBestMediaType(wil::com_ptr_nothrow<IPin>&
         {
             continue;
         }
+        LOG("Inspecting media type");
         auto format = reinterpret_cast<VIDEOINFOHEADER*>(mt->pbFormat);
-        if (!format->AvgTimePerFrame)
+        if (!format || !format->AvgTimePerFrame)
         {
+            LOG("VideoInfoHeader not found");
             continue;
         }
         const auto formatAvgFPS = 10000000LL / format->AvgTimePerFrame;
         if (format->AvgTimePerFrame > bestFormat.avgFrameTime || formatAvgFPS < MINIMAL_FPS_ALLOWED)
         {
+            LOG("Skipping mediatype due to low fps");
             continue;
         }
         if (format->bmiHeader.biWidth < bestFormat.width || format->bmiHeader.biHeight < bestFormat.height)
         {
+            LOG("Skipping mediatype due to low fps");
             continue;
         }
 
         if (mt->subtype != MEDIASUBTYPE_YUY2 && mt->subtype != MEDIASUBTYPE_MJPG && mt->subtype != MEDIASUBTYPE_NV12)
         {
+            LOG("Skipping mediatype due to unsupported subtype");
             continue;
         }
         bestFormat.avgFrameTime = format->AvgTimePerFrame;
@@ -413,7 +419,7 @@ std::optional<VideoStreamFormat> SelectBestMediaType(wil::com_ptr_nothrow<IPin>&
     {
         return std::nullopt;
     }
-    LOG("Selected media format:");
+    LOG(L"Selected media format:");
     LOG(GetMediaSubTypeString(bestFormat.mediaType->subtype));
     return std::move(bestFormat);
 }
@@ -440,6 +446,7 @@ std::vector<VideoCaptureDeviceInfo> VideoCaptureDevice::ListAll()
     wil::com_ptr_nothrow<IMoniker> moniker;
     while (enumMoniker->Next(1, &moniker, &_) == S_OK)
     {
+        LOG("Inspecting moniker");
         VideoCaptureDeviceInfo deviceInfo;
 
         wil::com_ptr_nothrow<IPropertyBag> propertyData;
@@ -488,6 +495,7 @@ std::vector<VideoCaptureDeviceInfo> VideoCaptureDevice::ListAll()
 
         while (pinsEnum->Next(1, &pin, &_) == S_OK)
         {
+            LOG("Inspecting pin");
             // Skip pins which do not belong to capture category
             GUID category{};
             DWORD __;
@@ -505,6 +513,7 @@ std::vector<VideoCaptureDeviceInfo> VideoCaptureDevice::ListAll()
                 continue;
             }
 
+            LOG("Found a pin of suitable category and direction, selecting format");
             auto bestFormat = SelectBestMediaType(pin);
             if (!bestFormat)
             {

src/modules/videoconference/VideoConferenceProxyFilter/VideoCaptureProxyFilter.cpp

@@ -468,7 +468,7 @@ HRESULT VideoCaptureProxyFilter::EnumPins(IEnumPins** ppEnum)
     VERBOSE_LOG;
     if (!ppEnum)
     {
-        LOG("EnumPins: null arg provided!");
+        LOG("EnumPins: null arg provided");
         return E_POINTER;
     }
     std::unique_lock<std::mutex> lock{ _worker_mutex };

src/modules/videoconference/VideoConferenceShared/Logging.cpp

@@ -9,17 +9,20 @@
 
 #include <mfapi.h>
 
+#pragma warning(disable: 4127)
+
 static std::mutex logMutex;
 constexpr inline size_t maxLogSizeMegabytes = 10;
+constexpr inline bool alwaysLogVerbose = true;
 
-void LogToFile(std::string what, const bool verbose)
+void LogToFile(std::wstring what, const bool verbose)
 {
     std::error_code _;
     const auto tempPath = std::filesystem::temp_directory_path(_);
     if (verbose)
     {
         const bool verboseIndicatorFilePresent = std::filesystem::exists(tempPath / L"PowerToysVideoConferenceVerbose.flag", _);
-        if (!verboseIndicatorFilePresent)
+        if (!alwaysLogVerbose && !verboseIndicatorFilePresent)
         {
             return;
         }
@@ -49,7 +52,7 @@ void LogToFile(std::string what, const bool verbose)
         // Truncate the log file to zero
         std::filesystem::resize_file(logFilePath, 0, __);
     }
-    std::ofstream myfile;
+    std::wofstream myfile;
     myfile.open(logFilePath, std::fstream::app);
 
     static const auto newLaunch = [&] {
@@ -61,6 +64,12 @@ void LogToFile(std::string what, const bool verbose)
     myfile.close();
 }
 
+void LogToFile(std::string what, const bool verbose)
+{
+    std::wstring native{ begin(what), end(what) };
+    LogToFile(std::move(native), verbose);
+}
+
 std::string toMediaTypeString(GUID subtype)
 {
     if (subtype == MFVideoFormat_YUY2)

src/modules/videoconference/VideoConferenceShared/Logging.h

@@ -5,6 +5,7 @@
 #include <system_error>
 
 void LogToFile(std::string what, const bool verbose = false);
+void LogToFile(std::wstring what, const bool verbose = false);
 std::string toMediaTypeString(GUID subtype);
 
 #define RETURN_IF_FAILED_WITH_LOGGING(val)                                                             \

src/modules/videoconference/VideoConferenceShared/MicrophoneDevice.cpp

@@ -8,7 +8,7 @@ MicrophoneDevice::MicrophoneDevice(wil::com_ptr_nothrow<IMMDevice> device, wil::
 {
     if (!_device || !_endpoint)
     {
-        throw std::logic_error("MicrophoneDevice was initialized with null objects!");
+        throw std::logic_error("MicrophoneDevice was initialized with null objects");
     }
     _device->GetId(&_id);
     wil::com_ptr_nothrow<IPropertyStore> props;