DYN-6412 fix performance issue with feature flags, and deadlock with …

…CLI wrapper. (#14637)

* fix for null data being shown over and over

* fix issues with cli wrapper get data

* revert

* add test

* review comments add tests

* comments

* review comments

src/DynamoUtilities/CLIWrapper.cs

@@ -0,0 +1,175 @@
+using System;
+using System.ComponentModel;
+using System.Diagnostics;
+using System.IO;
+using System.Reflection;
+using System.Threading.Tasks;
+
+namespace Dynamo.Utilities
+{
+    /// <summary>
+    /// Base class for Dynamo CLI wrappers 
+    /// </summary>
+    internal abstract class CLIWrapper : IDisposable
+    {
+        protected const string endOfDataToken = @"<<<<<Eod>>>>>";
+        protected const string startofDataToken = @"<<<<<Sod>>>>>";
+        protected readonly Process process = new Process();
+        protected bool started;
+        internal event Action<string> MessageLogged;
+
+        public virtual void Dispose()
+        {
+            process.ErrorDataReceived -= Process_ErrorDataReceived;
+            KillProcess();
+        }
+
+        /// <summary>
+        /// Start the process. 
+        /// </summary>
+        /// <param name="relativeEXEPath">relative path to the exe to start.</param>
+        /// <param name="argString">argument string to pass to process.</param>
+        protected virtual void StartProcess(string relativeEXEPath, string argString)
+        {
+            ProcessStartInfo startInfo = new ProcessStartInfo
+            {
+                CreateNoWindow = true,
+                RedirectStandardOutput = true,
+                RedirectStandardInput = true,
+                RedirectStandardError = true,
+
+                UseShellExecute = false,
+                Arguments = argString,
+                FileName = GetToolPath(relativeEXEPath)
+            };
+
+            process.StartInfo = startInfo;
+            try
+            {
+                process.Start();
+                started = true;
+                //the only purpose here is to avoid deadlocks when std err gets filled up 4kb
+                //in long running processes.
+                process.ErrorDataReceived += Process_ErrorDataReceived;
+                process.BeginErrorReadLine();
+
+            }
+            catch (Win32Exception)
+            {
+                // Do nothing
+            }
+        }
+
+        private void Process_ErrorDataReceived(object sender, DataReceivedEventArgs e)
+        {
+           //do nothing, we just want to empty the error stream.
+        }
+
+
+
+        /// <summary>
+        /// Kill the CLI tool - if running
+        /// </summary>
+        protected void KillProcess()
+        {
+            if (started)
+            {
+                if (!process.HasExited)
+                {
+                    process.Kill();
+                }
+                started = false;
+            }
+            process.Dispose();
+        }
+        /// <summary>
+        /// Compute the location of the CLI tool.
+        /// </summary>
+        /// <returns>Returns full path to the CLI tool</returns>
+        protected static string GetToolPath(string relativePath)
+        {
+            var rootPath = Path.GetDirectoryName(Assembly.GetExecutingAssembly().Location) ?? throw new ArgumentNullException(nameof(Path.GetDirectoryName));
+            var toolPath = Path.Combine(rootPath,relativePath);
+            return toolPath;
+        }
+        /// <summary>
+        /// Read data from CLI tool
+        /// </summary>
+        /// <param name="timeoutms">will return empty string if we don't finish reading all data in the timeout provided in milliseconds.</param>
+        /// <returns></returns>
+        protected virtual async Task<string> GetData(int timeoutms)
+        {
+            var readStdOutTask = Task.Run(() =>
+            {
+                if (process.HasExited)
+                {
+                    return string.Empty;
+                }
+
+                using (var writer = new StringWriter())
+                {
+                    var done = false;
+                    var start = false;
+                    while (!done)
+                    {
+                        try
+                        {
+                            var line = process.StandardOutput.ReadLine();
+                            MessageLogged?.Invoke(line);
+                            if (line == null || line == startofDataToken)
+                            {
+                                start = true;
+                                continue; //don't record start token to stream.
+                            }
+
+                            if (line == null || line == endOfDataToken)
+                            {
+                                done = true;
+                            }
+                            else
+                            {
+                                //if we have started recieving valid data, start recording
+                                if (!string.IsNullOrWhiteSpace(line) && start)
+                                {
+                                    writer.WriteLine(line);
+                                }
+                            }
+                        }
+                        catch (Exception)
+                        {
+                            KillProcess();
+                            return GetCantCommunicateErrorMessage();
+                        }
+                    }
+
+                    return writer.ToString();
+                }
+            });
+            var completedTask = await Task.WhenAny(readStdOutTask, Task.Delay(TimeSpan.FromMilliseconds(timeoutms)));
+            //if the completed task was our read std out task, then return the data
+            //else we timed out, so return an empty string.
+            return completedTask == readStdOutTask ? readStdOutTask.Result : string.Empty;
+        }
+
+        protected void RaiseMessageLogged(string message)
+        {
+            MessageLogged?.Invoke(message);
+        }
+
+        /// <summary>
+        /// Can't start Error message
+        /// </summary>
+        /// <returns>Returns error message</returns>
+        protected abstract string GetCantStartErrorMessage();
+
+
+        /// <summary>
+        /// Can't communicate Error message
+        /// </summary>
+        /// <returns>Returns error message</returns>
+        protected abstract string GetCantCommunicateErrorMessage();
+
+
+
+    }
+}

src/DynamoUtilities/DynamoFeatureFlagsManager.cs

@@ -24,6 +24,16 @@ internal class DynamoFeatureFlagsManager : CLIWrapper
         private Dictionary<string, object> AllFlagsCache { get; set; }//TODO lock is likely overkill.
         private SynchronizationContext syncContext;
         internal static event Action FlagsRetrieved;
+
+        //TODO(DYN-6464)- remove this field!.
+        /// <summary>
+        /// set to true after some FF issue is logged. For now we only log once to avoid clients overwhelming the logger.
+        /// </summary>
+        private bool loggedFFIssueOnce = false;
+        /// <summary>
+        /// Timeout in ms for feature flag communication with CLI process.
+        /// </summary>
+        private const int featureFlagTimeoutMs = 5000;
 
         /// <summary>
         /// Constructor
@@ -54,18 +64,18 @@ internal void CacheAllFlags()
         {
 
             //wait for response
-            var dataFromCLI = GetData();
+            var dataFromCLI = GetData(featureFlagTimeoutMs).Result;    
             //convert from json string to dictionary.
             try
-            {  
+            {
                 AllFlagsCache = JsonConvert.DeserializeObject<Dictionary<string, object>>(dataFromCLI);
                 //invoke the flags retrieved event on the sync context which should be the main ui thread.
                 syncContext?.Send((_) =>
-                {   
+                {
                     FlagsRetrieved?.Invoke();
 
-                },null);
-                
+                }, null);
+
             }
             catch (Exception e)
             {
@@ -74,34 +84,45 @@ internal void CacheAllFlags()
         }
 
         /// <summary>
-        /// Check feature flag value, if not exist, return defaultval
+        /// Check feature flag value, if it does not exist, return the defaultval.
         /// </summary>
-        /// <typeparam name="T"></typeparam>
-        /// <param name="featureFlagKey"></param>
-        /// <param name="defaultval"></param>
+        /// <typeparam name="T">Must be a bool or string, only bool or string flags should be created unless this implementation is improved.</typeparam>
+        /// <param name="featureFlagKey">feature flag name</param>
+        /// <param name="defaultval">Currently the flag and default val MUST be a bool or string.</param>
         /// <returns></returns>
         internal T CheckFeatureFlag<T>(string featureFlagKey, T defaultval)
         {
             if(!(defaultval is bool || defaultval is string)){
-                RaiseMessageLogged("unsupported flag type");
-                return defaultval;
+                throw new ArgumentException("unsupported flag type", defaultval.GetType().ToString());
             }
             // if we have not retrieved flags from the cli return empty
-            // and log.
+            // and log once.
 
             if(AllFlagsCache == null)
-            {
-                RaiseMessageLogged("the flags cache is null, something went wrong retrieving feature flags," +
-                  " or you need to wait longer for the cache to populate, you can use the static FlagsRetrieved event for this purpose. ");
+            {   //TODO(DYN-6464) Revisit this and log more when the logger is not easily overwhelmed.
+                if (!loggedFFIssueOnce)
+                {
+                    RaiseMessageLogged(
+                        $"The flags cache was null while checking {featureFlagKey}, something went wrong retrieving feature flags," +
+                        " or you need to wait longer for the cache to populate before checking for flags, you can use the static FlagsRetrieved event for this purpose." +
+                        "This message will not be logged again, and future calls to CheckFeatureFlags will return default values!!!");
+                }
+
+                loggedFFIssueOnce = true;
                 return defaultval;
             }
-            if (AllFlagsCache.ContainsKey(featureFlagKey))
+            if (AllFlagsCache.TryGetValue(featureFlagKey, out var flagVal))
             {
-                return (T)AllFlagsCache[featureFlagKey];
+                return (T)flagVal;
             }
             else
             {
-                RaiseMessageLogged($"failed to get value for feature flag key ex: {featureFlagKey},{System.Environment.NewLine} returning default value: {defaultval}");
+                if (!loggedFFIssueOnce)
+                {
+                    RaiseMessageLogged(
+                        $"failed to get value for feature flag key ex: {featureFlagKey},{System.Environment.NewLine} returning default value: {defaultval}");
+                }
+                loggedFFIssueOnce = true;
                 return defaultval;
             }
         }