Интересное явление
От: SanyaVB  
Дата: 22.10.10 12:04
Оценка:
Писал фильтр для обработки изображения. В одной функции делать всю обработку тяжело(иногда идет дублирование кода, чтение усложняется и т.д.). Решил написать тестовую программу, чтобы определить как влияет разбивка кода на множество функций во имя не дублирования.

class Program
    {
        static long m_count;
        const long NUMBER_ITERATION = 1000000000;
        static DateTime m_time;
        static void Main(string[] args)
        {
            Test1();
            Test2();
            Test3();

            Console.WriteLine("Press any key ...");
            Console.ReadKey();
        }

        static void Test1()
        {
            ShowNameTest("Test1");
            m_count = 0;
            BeginTest();
            for (long i = 0; i < NUMBER_ITERATION; i++)
                m_count++;
            EndTest();
        }

        static void Test2()
        {
            ShowNameTest("Test2");
            m_count = 0;

            BeginTest();
            for (long i = 0; i < NUMBER_ITERATION / 10; i++)
            {
                UpIndex01();
                UpIndex02();
                UpIndex03();
                UpIndex04();
                UpIndex05();
                UpIndex06();
                UpIndex07();
                UpIndex08();
                UpIndex09();
                UpIndex10();
            }
            EndTest();
        }

        static void Test3()
        {
            ShowNameTest("Test3");
            m_count = 0;

            BeginTest();
            for (long i = 0; i < NUMBER_ITERATION; i++)
            {
                UpIndex01();
            }
            EndTest();
        }


        static void UpIndex01()
        {
            m_count++;
        }

        static void UpIndex02()
        {
            m_count++;
        }

        static void UpIndex03()
        {
            m_count++;
        }

        static void UpIndex04()
        {
            m_count++;
        }

        static void UpIndex05()
        {
            m_count++;
        }

        static void UpIndex06()
        {
            m_count++;
        }

        static void UpIndex07()
        {
            m_count++;
        }

        static void UpIndex08()
        {
            m_count++;
        }

        static void UpIndex09()
        {
            m_count++;
        }

        static void UpIndex10()
        {
            m_count++;
        }

        static void BeginTest()
        {
            m_time = DateTime.Now;
            ShowTime(m_time);
        }

        static void EndTest()
        {
            DateTime time = DateTime.Now;
            ShowTime(time);
            DateTime timeRunning = new DateTime(time.Ticks - m_time.Ticks);
            ShowTime(timeRunning);
            Console.WriteLine();
        }

        static void ShowTime(DateTime _time)
        {
            Console.WriteLine(_time.ToString() + ":" + _time.Millisecond);
        }

        static void ShowNameTest(string _name)
        {
            Console.WriteLine("".PadRight(15, '-'));
            Console.WriteLine(_name);
            Console.WriteLine("".PadRight(15, '-'));
        }
    }


Вот какие результаты я получил:

---------------
Test1
---------------
22.10.2010 15:54:37:375
22.10.2010 15:54:41:968
01.01.0001 0:00:04:593

---------------
Test2
---------------
22.10.2010 15:54:41:968
22.10.2010 15:54:48:687
01.01.0001 0:00:06:718

---------------
Test3
---------------
22.10.2010 15:54:48:687
22.10.2010 15:54:59:15
01.01.0001 0:00:10:328

Оказывается третий тест в котором вызывается только один метод — самый медленный, хотя я ожидал этого от второго теста. Кто нибудь может объяснить это явление?
Re: Интересное явление
От: SanyaVB  
Дата: 22.10.10 12:15
Оценка:
Кстати если еще добавить четвертый тест 

        static void Test4()
        {
            ShowNameTest("Test4");
            m_count = 0;

            BeginTest();
            for (long i = 0; i < NUMBER_ITERATION / 10; i++)
            {
                UpIndex01();
                UpIndex01();
                UpIndex01();
                UpIndex01();
                UpIndex01();
                UpIndex01();
                UpIndex01();
                UpIndex01();
                UpIndex01();
                UpIndex01();
            }
            EndTest();
        }

То он как и ожидалось чуть-чуть быстрее второго теста
---------------
Test1
---------------
22.10.2010 16:11:30:328
22.10.2010 16:11:35:328
01.01.0001 0:00:05:0


---------------
Test2
---------------
22.10.2010 16:11:35:328
22.10.2010 16:11:42:390
01.01.0001 0:00:07:62


---------------
Test3
---------------
22.10.2010 16:11:42:390
22.10.2010 16:11:52:500
01.01.0001 0:00:10:109


---------------
Test4
---------------
22.10.2010 16:11:52:500
22.10.2010 16:11:59:312
01.01.0001 0:00:06:812
Re: Интересное явление
От: hardcase Пират http://nemerle.org
Дата: 22.10.10 12:25
Оценка: +1
Здравствуйте, SanyaVB, Вы писали:

SVB>Оказывается третий тест в котором вызывается только один метод — самый медленный, хотя я ожидал этого от второго теста. Кто нибудь может объяснить это явление?

1) Такие небольшие статические методы легко инлайнятся JIT-ом.
2) В третьем тесте также происходит инлайн.

В итоге Вы фактически измерлии оптимизацию "разворачивание цикла".
/* иЗвиНите зА неРовнЫй поЧерК */
Re: Интересное явление
От: cvetkov  
Дата: 22.10.10 12:36
Оценка: 1 (1) +1
теоретически там меньше джампов.

практически: почему ты считаеш что методы не заинлайнились например?
а что если запутьить тесты несколько раз?
... << RSDN@Home 1.2.0 alpha 4 rev. 1227>>
Re[2]: Интересное явление
От: hardcase Пират http://nemerle.org
Дата: 22.10.10 12:41
Оценка:
Здравствуйте, hardcase, Вы писали:

H>Здравствуйте, SanyaVB, Вы писали:

SVB>>Оказывается третий тест в котором вызывается только один метод — самый медленный, хотя я ожидал этого от второго теста. Кто нибудь может объяснить это явление?

H>1) Такие небольшие статические методы легко инлайнятся JIT-ом.
H>2) В третьем тесте также происходит инлайн.

H>В итоге Вы фактически измерлии оптимизацию "разворачивание цикла".

Упс — фигню сказал толком не посмотревши на тесты. Действительно забавная ситуация.
Мне кажется нужно взглянуть что за код создает JIT компилятор и понять, как он интерпретируется процессором. Видимо в этом загвоздка.
/* иЗвиНите зА неРовнЫй поЧерК */
Re[2]: Интересное явление
От: SanyaVB  
Дата: 22.10.10 12:43
Оценка:
Здравствуйте, cvetkov, Вы писали:

C>теоретически там меньше джампов.

C>практически: почему ты считаеш что методы не заинлайнились например?
C>а что если запутьить тесты несколько раз?

Вот что будет, если запустить несколько раз:

---------------
Test1
---------------
22.10.2010 16:41:32:640
22.10.2010 16:41:37:531
01.01.0001 0:00:04:890

---------------
Test2
---------------
22.10.2010 16:41:37:531
22.10.2010 16:41:44:718
01.01.0001 0:00:07:187

---------------
Test3
---------------
22.10.2010 16:41:44:718
22.10.2010 16:41:55:312
01.01.0001 0:00:10:593

---------------
Test1
---------------
22.10.2010 16:41:55:312
22.10.2010 16:41:59:687
01.01.0001 0:00:04:375

---------------
Test2
---------------
22.10.2010 16:41:59:687
22.10.2010 16:42:06:640
01.01.0001 0:00:06:953

---------------
Test3
---------------
22.10.2010 16:42:06:640
22.10.2010 16:42:17:312
01.01.0001 0:00:10:671

---------------
Test1
---------------
22.10.2010 16:42:17:312
22.10.2010 16:42:21:625
01.01.0001 0:00:04:312

---------------
Test2
---------------
22.10.2010 16:42:21:625
22.10.2010 16:42:28:734
01.01.0001 0:00:07:109

---------------
Test3
---------------
22.10.2010 16:42:28:734
22.10.2010 16:42:39:375
01.01.0001 0:00:10:640
Re[3]: Интересное явление
От: Sinix  
Дата: 22.10.10 14:00
Оценка:
Здравствуйте, hardcase, Вы писали:

H>Упс — фигню сказал толком не посмотревши на тесты. Действительно забавная ситуация.

Да не, всё правильно вы сказали.
1. Инлайн
-и-
2. Ручная развёртка цикла -> повышение производительности за счёт меньшего числа джампов (cvetkov выше тож отметился)

Так что не путайте тут
Re: Интересное явление
От: andy1618 Россия  
Дата: 22.10.10 16:10
Оценка:
Здравствуйте, SanyaVB, Вы писали:

SVB>
SVB>        static void Test2()
SVB>        {
SVB>            ShowNameTest("Test2");
SVB>            m_count = 0;

SVB>            BeginTest();
SVB>            for (long i = 0; i < NUMBER_ITERATION / 10; i++)
SVB>            {
SVB>                UpIndex01();
SVB>                UpIndex02();
SVB>                UpIndex03();
SVB>                UpIndex04();
SVB>                UpIndex05();
SVB>                UpIndex06();
SVB>                UpIndex07();
SVB>                UpIndex08();
SVB>                UpIndex09();
SVB>                UpIndex10();
SVB>            }
SVB>            EndTest();
SVB>        }

SVB>        static void Test3()
SVB>        {
SVB>            ShowNameTest("Test3");
SVB>            m_count = 0;

SVB>            BeginTest();
SVB>            for (long i = 0; i < NUMBER_ITERATION; i++)
SVB>            {
SVB>                UpIndex01();
SVB>            }
SVB>            EndTest();
SVB>        }

SVB>


SVB>Оказывается третий тест в котором вызывается только один метод — самый медленный, хотя я ожидал этого от второго теста. Кто нибудь может объяснить это явление?


А что тут странного?
Во втором тесте вызовы идут пачкой друг за другом,
а в третьем тесте — после каждого вызове идёт ещё инкремент и проверка i.
Если интересно — поставьте брейкпойнт и переключитесь в окно дизассемблера.

Кстати, надеюсь, вы время измеряли в релиз — версии?
Ещё, вроде бы, на тайминг влияет то, запущена программа из-под Visual Studio или напрямую.
 
Подождите ...
Wait...
Пока на собственное сообщение не было ответов, его можно удалить.