Slowdown detection with many lines

[maije]

Information

• OS: Windows
• Version: [e.g. 0.45.0]
• Terminal: Visual Studio Console & Windows PowerShell

Describe the bug
Detected that Spectre.Console is faster than Console.Writeline from 100 lines until 20K lines. Then, it's performance drops until taking twice the time to print 50K lines or even 10 times slower with 100K lines.

To Reproduce
I prepared a small program to do the testing, for your consideration:

namespace ReproduceSpectreConsoleSlowDown
{
    class Program
    {
        static void Main(string[] args)
        {
            const int reps = 5;
            int[] sizes = new int[] { /* 10, 100, 1000, 10000,*/ 50000 };
            float[] spectreMeans = new float[sizes.Length];
            float[] consoleMeans = new float[sizes.Length];

            for (int k = 0; k < sizes.Length; k++)
            {
                List<string> output = new List<string>(sizes[k]);
                for (int i = 0; i < sizes[k]; i++)
                    output.Add(string.Format("change{0}", i));

                int[] spectreResults = new int[reps];
                int[] consoleResults = new int[reps];
                int sumSpectreResults = 0;
                int sumConsoleResults = 0;

                for (int i = 0; i < reps; i++)
                {
                    consoleResults[i] = PrintChangesWithDefaultConsole(output);
                    spectreResults[i] = PrintChangesWithAnsiConsole(output);

                    sumSpectreResults += spectreResults[i];
                    sumConsoleResults += consoleResults[i];
                }

                spectreMeans[k] = (float)sumSpectreResults / reps;
                consoleMeans[k] = (float)sumConsoleResults / reps;
            }

            for (int i = 0; i < spectreMeans.Length; i++)
            {
                Console.WriteLine(string.Format("Spectre mean time for {0} elements: {1} ms", sizes[i], spectreMeans[i]));
                Console.WriteLine(string.Format("Console mean time for {0} elements: {1} ms", sizes[i], consoleMeans[i]));
            }
        }

        static public int PrintChangesWithAnsiConsole(List<string> output)
        {

            if (output == null || output.Count == 0)
                throw new Exception("output cannot be null or empty.");

            int ini = Environment.TickCount;

            const string consoleColor = "blue";
            //const string consoleColor = "#00FFFF";
            const string shortDescription = "Desc";

            var root = new Tree("");

            TreeNode changes = root.AddNode(
                string.Format("[{0}]{1}[/]", consoleColor, shortDescription));

            Table table = new Table().RoundedBorder();

            table.AddColumns(new string[] { "col1", "col2", "col3" });

            foreach (string str in output)
                table.AddRow(new string[] { str, str, str });

            changes.AddNode(table);
            
            AnsiConsole.Write(root);

            return Environment.TickCount - ini;
        }
        static public int PrintChangesWithDefaultConsole(List<string> output)
        {
            int ini = Environment.TickCount;

            if (output == null || output.Count == 0)
                throw new Exception("output cannot be null or empty.");

            string spacing = GetCharRep(' ', SPACING);

            PrintTableHeader(string.Format("{0}{1}{2}{3}{4}", "col1", spacing, "col2", spacing, "col3")) ;
            foreach (string str in output)
                PrintLine(string.Format("{0}  {1}  {2}", str, str, str));                    

            return Environment.TickCount - ini;
        }

        static void PrintTableHeader(string formatedHeader)
        {
            string separator = GetCharRep('-', formatedHeader.Length + MARGIN * 2);

            Console.WriteLine(separator);
            PrintLine(formatedHeader);
            Console.WriteLine(separator);

        }

        static void PrintLine(string line)
        {
            string space = GetCharRep();
            Console.WriteLine(string.Format("{0}{1}{2}{3}{4}", '|', space, line, space, '|'));
        }
        static string GetCharRep(char c = ' ', int times = MARGIN)
        {
            return new string(' ', times);
        }

        const int SPACING = 7;
        const int MARGIN = 2;
    }
}

Expected behavior
We have detected when printing 100K lines withing tables of 3 columns, that using Sprectre.Console takes up to 103 seconds in average while we are printing with Console.Writeline the same amouint of lines in 11 seconds. I'm not saying that it should take the same, just the difference seems too big and keeps on growing with the number of files.

Screenshots

Additional context
I'm not sure whether the preprocessing is lagging the overall times, maybe it is just a compromise solution, but JIC the might be a memory issue somewhere. We are working with Version Control and it is not rare that, when creating a new repo, there might be hundreds of thousands of new files to upload. If we do an status with that amount of private files, it gets frozen for almost 2 minutes.

---

Please upvote 👍 this issue if you are interested in it.

[phil-scott-78]

An easy answer here is that we really don't recommend outputting that many rows with one IRenderable. Way out of the scope of how things are designed to work, it'd be best to break that apart to keep things running smoothly and consistently. No matter what, we are going to need the entire batch of output before we start writing so there will always be delays over outputting smaller items.

BUT, this is a performance issue, so I did a quick profile. Looks like the issue is that on TableRowCollection.Add we are returning the index of the most recently added item. To do so we are using the IndexOf operator. For smaller items this isn't a big deal, but once you get up to 50,000 items the default comparer is looking at a ton of data to see if things are equal and it does this on every call to Add. For 50,000 calls I saw 1,249,291,134 calls to System.Object.Equals alone.

I would suspect a much simpler TableRow comparer that checked if the object reference equals would improve performance across the board and be potentially worth adding.

[phil-scott-78]

Thought some more about this. Might be a bit hacky, but removing indexOf altogether and just returning _list.Count - 1 yields this result and should still be valid.

Spectre mean time for 50000 elements: 1750 ms
Console mean time for 50000 elements: 2281 ms

[jaimefinat]

Yes, I confirm the removal of IndexOf fixed the performance issue and now spectre.console is more than twice faster than System.Console in my experiments (50K elements and 5 repetitions):

Spectre mean time for 50000 elements: 3406.2 ms
Console mean time for 50000 elements: 7640.6 ms

Are you doing a pull request with this?