View Issue Details

IDProjectCategoryView StatusLast Update
0001723Far ManagerKeyboardpublic2013-02-28 08:04
Reportersezal Assigned Tovskirdin  
PrioritynormalSeverityminorReproducibilityalways
Status closedResolutionfixed 
PlatformLinuxOSUbuntuOS Version10.10
Product Version2.0 
Summary0001723: загрузка CPU в режиме простоя
Descriptionпод линукс/Wine Far прекрасно работает, но в режиме простоя загружает на 30% процессор. Судя по всему причиной является основной цикл keyboard.cpp::GetInputRecord, который *каждую* милисекунду вызывает PluginSynchroManager.Process() и несколько других второстепенных проверок.

Я не специалист в области разработки таких приложений, но прощу обратить внимание на этот тикет, т.к. это проблема не только linux-пользователей - под windows она просто менее заметна, но имеет место.

Мое субъективное видение оптимизации основного цикла:

1. увеличение зарержки хотя бы до 10мс (keyboard.cpp:827)

2. если п.1 не возможен по каким-то причинам, то целесообразно оставить в основном цикле только Console.PeekInput + самые-самы важные проверки.

3. PluginSynchroManager.Process() не вызывать так часто, т.к. он судя по всему использует ресурсоемкие вещи - мютексы. Перенести его в уже имеющийся блок

if (!(LoopCount & 15))
{

}

4. второстепенные вещи как IsZoomed, IsFullscreen, Events.EnvironmentChangeEvent.Signaled и т.п. вызывать не чаще чем раз в 100мс.

Вкладываю логи всех вызовов в отладочном режиме wine в режиме простоя:
far_wine_debug.txt - 3 основных цикла - закономерность налицо.
far_wine_full_debug.txt - один основной цикл, но с максимальной детализацией.
TagsNo tags attached.
Build2354

Relationships

related to 0001927 closed2useven10 100% CPU load of host system while Far is on idle state! 
related to 0002045 closed2useven10 Win+Up (Windows standart MAXMIMIZE short-cut) not working 

Activities

sezal

2011-03-01 15:32

reporter  

far_wine_debug.txt (1,871 bytes)   
user32.IsZoomed(0001004e) ret=00488846
KERNEL32.GetConsoleDisplayMode(0034ec98) ret=0040c14d
KERNEL32.WaitForSingleObject(0000006c,00000000) ret=004f6402
KERNEL32.WaitForSingleObject(00000068,00000000) ret=004888ae
KERNEL32.GetStdHandle(fffffff6) ret=0040c535
KERNEL32.PeekConsoleInputW(0000002b,006202cc,00000001,0034ece4) ret=0040c548
KERNEL32.Sleep(00000001) ret=00488935
KERNEL32.GetStdHandle(fffffff6) ret=0040bd88
KERNEL32.GetConsoleMode(0000002b,0034eca0) ret=0040c011
KERNEL32.WaitForSingleObject(00000050,ffffffff) ret=004da03a
KERNEL32.ReleaseMutex(00000050) ret=004da074
KERNEL32.GetConsoleWindow() ret=0048883f

user32.IsZoomed(0001004e) ret=00488846
KERNEL32.GetConsoleDisplayMode(0034ec98) ret=0040c14d
KERNEL32.WaitForSingleObject(0000006c,00000000) ret=004f6402
KERNEL32.WaitForSingleObject(00000068,00000000) ret=004888ae
KERNEL32.GetStdHandle(fffffff6) ret=0040c535
KERNEL32.PeekConsoleInputW(0000002b,006202cc,00000001,0034ece4) ret=0040c548
KERNEL32.Sleep(00000001) ret=00488935
KERNEL32.GetStdHandle(fffffff6) ret=0040bd88
KERNEL32.GetConsoleMode(0000002b,0034eca0) ret=0040c011
KERNEL32.WaitForSingleObject(00000050,ffffffff) ret=004da03a
KERNEL32.ReleaseMutex(00000050) ret=004da074
KERNEL32.GetConsoleWindow() ret=0048883f

user32.IsZoomed(0001004e) ret=00488846
KERNEL32.GetConsoleDisplayMode(0034ec98) ret=0040c14d
KERNEL32.WaitForSingleObject(0000006c,00000000) ret=004f6402
KERNEL32.WaitForSingleObject(00000068,00000000) ret=004888ae
KERNEL32.GetStdHandle(fffffff6) ret=0040c535
KERNEL32.PeekConsoleInputW(0000002b,006202cc,00000001,0034ece4) ret=0040c548
KERNEL32.Sleep(00000001) ret=00488935
KERNEL32.GetStdHandle(fffffff6) ret=0040bd88
KERNEL32.GetConsoleMode(0000002b,0034eca0) ret=0040c011
KERNEL32.WaitForSingleObject(00000050,ffffffff) ret=004da03a
KERNEL32.ReleaseMutex(00000050) ret=004da074
KERNEL32.GetConsoleWindow() ret=0048883f
far_wine_debug.txt (1,871 bytes)   

sezal

2011-03-01 15:33

reporter  

far_wine_full_debug.txt (2,818 bytes)   
Call user32.IsZoomed(0001004e) ret=00488846
 set_window_info( flags=0000, is_unicode=0, handle=0001004e, style=00000000, ex_style=00000000, id=00000000, instance=00000000, user_data=00000000, extra_offset=-1, extra_size=0, extra_value=00000000 )
 set_window_info() = 0 { old_style=34ce0000, old_ex_style=00000100, old_instance=68340000, old_user_data=00000000, old_extra_value=00000000, old_id=00000000 }
Ret  user32.IsZoomed() retval=00000000 ret=00488846
Call KERNEL32.GetConsoleDisplayMode(0034ec98) ret=0040c14d
trace:console:GetConsoleDisplayMode semi-stub: 0x34ec98
Ret  KERNEL32.GetConsoleDisplayMode() retval=00000001 ret=0040c14d
Call KERNEL32.WaitForSingleObject(0000006c,00000000) ret=004f6402
 select( flags=4, cookie=0034e998, signal=0000, prev_apc=0000, timeout=0, result={}, handles={006c} )
 select() = TIMEOUT { timeout=1cbd2cc96d0135a (+0.0000000), call={APC_NONE}, apc_handle=0000 }
Ret  KERNEL32.WaitForSingleObject() retval=00000102 ret=004f6402
Call KERNEL32.WaitForSingleObject(00000068,00000000) ret=004888ae
 select( flags=4, cookie=0034e9a8, signal=0000, prev_apc=0000, timeout=0, result={}, handles={0068} )
 select() = TIMEOUT { timeout=1cbd2cc96d0154e (+0.0000000), call={APC_NONE}, apc_handle=0000 }
Ret  KERNEL32.WaitForSingleObject() retval=00000102 ret=004888ae
Call KERNEL32.GetStdHandle(fffffff6) ret=0040c535
Ret  KERNEL32.GetStdHandle() retval=0000002b ret=0040c535
Call KERNEL32.PeekConsoleInputW(0000002b,006202cc,00000001,0034ece4) ret=0040c548
 read_console_input( handle=0028, flush=0 )
 read_console_input() = 0 { read=0, rec={} }
Ret  KERNEL32.PeekConsoleInputW() retval=00000001 ret=0040c548
Call KERNEL32.Sleep(00000001) ret=00488935
Ret  KERNEL32.Sleep() retval=00000000 ret=00488935
Call KERNEL32.GetStdHandle(fffffff6) ret=0040bd88
Ret  KERNEL32.GetStdHandle() retval=0000002b ret=0040bd88
Call KERNEL32.GetConsoleMode(0000002b,0034eca0) ret=0040c011
 get_console_mode( handle=0028 )
 get_console_mode() = 0 { mode=152 }
Ret  KERNEL32.GetConsoleMode() retval=00000001 ret=0040c011
Call KERNEL32.WaitForSingleObject(00000050,ffffffff) ret=004da03a
 select( flags=4, cookie=0034e988, signal=0000, prev_apc=0000, timeout=infinite, result={}, handles={0050} )
 select() = 0 { timeout=infinite, call={APC_NONE}, apc_handle=0000 }
Ret  KERNEL32.WaitForSingleObject() retval=00000000 ret=004da03a
Call KERNEL32.ReleaseMutex(00000050) ret=004da074
 release_mutex( handle=0050 )
 release_mutex() = 0 { prev_count=00000001 }
Ret  KERNEL32.ReleaseMutex() retval=00000001 ret=004da074
Call KERNEL32.GetConsoleWindow() ret=0048883f
 get_console_input_info( handle=0000 )
 get_console_input_info() = 0 { history_mode=0, history_size=50, history_index=0, edition_mode=0, input_cp=0, output_cp=0, win=0001004e, title=L"" }
Ret  KERNEL32.GetConsoleWindow() retval=0001004e ret=0048883f
far_wine_full_debug.txt (2,818 bytes)   

sezal

2011-03-08 12:19

reporter  

keyboard.diff (2,200 bytes)   
Index: keyboard.cpp
===================================================================
--- keyboard.cpp	(revision 5783)
+++ keyboard.cpp	(working copy)
@@ -736,27 +736,33 @@
 
 	for (;;)
 	{
-		// "�����" �� ����������/�������������� ���� �������
-		if (ZoomedState!=IsZoomed(Console.GetWindow()) && IconicState==IsIconic(Console.GetWindow()))
-		{
-			ZoomedState=!ZoomedState;
-			ChangeVideoMode(ZoomedState);
-		}
+    	if (!(LoopCount & 15 ))
+    	{
+            // "�����" �� ����������/�������������� ���� �������
+            if (ZoomedState!=IsZoomed(Console.GetWindow()) && IconicState==IsIconic(Console.GetWindow()))
+            {
+                ZoomedState=!ZoomedState;
+                ChangeVideoMode(ZoomedState);
+            }
 
-		bool CurrentFullscreenState=IsFullscreen();
-		if(CurrentFullscreenState && !FullscreenState)
-		{
-			ChangeVideoMode(25,80);
-		}
-		FullscreenState=CurrentFullscreenState;
+            bool CurrentFullscreenState=IsFullscreen();
+            if(CurrentFullscreenState && !FullscreenState)
+            {
+                ChangeVideoMode(25,80);
+            }
+            FullscreenState=CurrentFullscreenState;
+    	 
+        }
+    	if (!(LoopCount & 127 ))
+    	{
+    		Window.Check();
 
-		Window.Check();
-
-		if(Events.EnvironmentChangeEvent.Signaled())
-		{
-			ReloadEnvironment();
-		}
-
+            if(Events.EnvironmentChangeEvent.Signaled())
+            {
+                ReloadEnvironment();
+            }
+        }
+        
 		Console.PeekInput(*rec, 1, ReadCount);
 
 		/* $ 26.04.2001 VVM
@@ -824,7 +830,7 @@
 		}
 
 		ScrBuf.Flush();
-		Sleep(1);
+		Sleep(10);
 
 		// �������� ������� ������� ����������� ��
 		if (Opt.Mouse) // � ����� �� ��� �������???
@@ -916,12 +922,12 @@
 				rec->EventType=KEY_EVENT;
 				return(KEY_IDLE);
 			}
-		}
 
-		if (PluginSynchroManager.Process())
-		{
-			memset(rec,0,sizeof(*rec));
-			return KEY_NONE;
+            if (PluginSynchroManager.Process())
+            {
+                memset(rec,0,sizeof(*rec));
+                return KEY_NONE;
+            }
 		}
 
 		LoopCount++;
keyboard.diff (2,200 bytes)   

sezal

2011-03-08 12:21

reporter   bugnote:0006490

вложил патч. Загрузка упала до 0-1%

vskirdin

2011-03-09 09:14

administrator   bugnote:0006502

предлагаю следующее.
после устаканивая Far 3.x я этот патч применю "на покататься" - а там видно будет.
сейчас пока сложно что-то сказать...

DrKnS

2011-03-09 09:52

administrator   bugnote:0006503

> Мое субъективное видение оптимизации основного цикла:

Моё не менее субъективное видение оптимизации основного цикла:

1. Оптимизировать wine::IsZoomed();
2. Оптимизировать wine::GetConsoleDisplayMode();
3. Оптимизировать wine::WaitForSingleObject();
4. Оптимизировать wine::GetStdHandle();
5. Оптимизировать wine::ReleaseMutex();
6. Оптимизировать wine::GetConsoleWindow().

sezal

2011-03-09 10:10

reporter   bugnote:0006504

куда лучше сослаться на кривой wine и в основном цикле напрягать процессор с задержкой 1мс вызывая кучу ненужных проверок. Я специализируюсь в другой области, но мне хватило 10 минут, чтобы понять, что основной цикл фар далеко не оптимален, а wine просто проявил это. Для своих нужд я уже собрал фар, поделился своими мыслями, патчем. Ваше дело оптимизировать его или нет.

DrKnS

2011-03-09 10:25

administrator   bugnote:0006507

> куда лучше сослаться на кривой wine и в основном цикле напрягать процессор с задержкой 1мс вызывая кучу ненужных проверок

Я вот ни в одном windows загрузки процессора не наблюдаю.
Следовательно, вызываемые функции в wine реализованы хуже, чем в windows.
Поэтому да, wine именно кривой.

> Для своих нужд я уже собрал фар, поделился своими мыслями, патчем.

Рад за вас, честно.
Но вы не первый и не последний, желающий "улучшить" работу программ в wine правкой этих программ.
А если бы вы поделитесь патчем с разработчиками wine - как ни странно, стало бы лучше сразу всем - и пользователям новых версий far, и пользователям старых версий far (которые уже никто править не будет), и пользователям стапицот других программ, выполняющих подобные элементарные проверки в основном цикле.

antonk

2011-08-24 17:02

reporter   bugnote:0007516

Last edited: 2011-08-24 17:20

Обнаружил загрузку CPU 30-40%
Host OS: Debian GNU/Linux, Oracle VirtualBox 4.1.0
Guest OS: Windows XP SP3

Far20b1807.x86.20110203.msi

при работе одновременно с Embarcadero Delphi XE 15.0 процессор загружен на 30-40%,
причём вся загрузка числится за Far (не важно с плагинами или без).

Выгрузка Delphi XE или Far - освобождает процессор.
Только при наличии XE - Far ест процессор.

Возможно MS реализация WaitForSingleObject(); ReleaseMutex(); вызывает инструкции с lock префиксом, которые внутри Virtualbox обрабатываются неоптимально.

Физический процессор без аппаратной виртуализации (Pentium D 915)

См. картинку: Основной поток Far проводит всё время в ядре вызывая огромное количество переключений контекстов.

antonk

2011-08-24 17:14

reporter  

Screenshot-9.png (190,441 bytes)   
Screenshot-9.png (190,441 bytes)   

altaveron

2011-12-01 07:59

reporter   bugnote:0008016

В VMWare загрузка еще выше! Пожалуйста, исправьте эту ошибку! Пользоваться Far в виртуальной операционной системе фактически невозможно. Можно ли где-то переписать пропатченную версию Far?

2useven10

2011-12-01 10:16

developer   bugnote:0008017

пробуйте -- http://mini-gnu.googlecode.com/files/Far3-Mantis1723-32.7z

antonk

2012-01-05 15:42

reporter   bugnote:0008317

Last edited: 2012-01-05 15:49

В VirtualBox 4.1.8 проблема сократилась до 0.8-6% CPU
Вроде бы они там свой Guru Meditation переписали (сократили накладные расходы на системные вызовы)

Попробовал скачанный файл
http://mini-gnu.googlecode.com/files/Far3-Mantis1723-32.7z
- загрузка ещё меньше (периодически пробуждается 0.9-2%)

2useven10

2012-01-09 14:26

developer   bugnote:0008329

"на покататься" -- 2353

antonk

2012-01-10 13:27

reporter   bugnote:0008348

3.0 build 2354 x86 - OK
0.8% CPU периодически
Context Switch delta - 50 ... 200

vskirdin

2012-04-27 13:56

administrator   bugnote:0009070

закрываем Инц?

2useven10

2012-04-27 14:28

developer   bugnote:0009072

imho - можно.
хотя частично оптимизацию пришлось откатить из-за 0002045.
но сами виртуальные машины со времени заведения инца ведут себя гораздо лучше.

Issue History

Date Modified Username Field Change
2011-03-01 15:32 sezal New Issue
2011-03-01 15:32 sezal File Added: far_wine_debug.txt
2011-03-01 15:33 sezal File Added: far_wine_full_debug.txt
2011-03-08 12:19 sezal File Added: keyboard.diff
2011-03-08 12:21 sezal Note Added: 0006490
2011-03-09 09:13 vskirdin Assigned To => vskirdin
2011-03-09 09:13 vskirdin Status new => assigned
2011-03-09 09:14 vskirdin Note Added: 0006502
2011-03-09 09:52 DrKnS Note Added: 0006503
2011-03-09 10:10 sezal Note Added: 0006504
2011-03-09 10:25 DrKnS Note Added: 0006507
2011-08-24 17:02 antonk Note Added: 0007516
2011-08-24 17:04 antonk Note Edited: 0007516
2011-08-24 17:14 antonk File Added: Screenshot-9.png
2011-08-24 17:20 antonk Note Edited: 0007516
2011-12-01 05:03 2useven10 Relationship added related to 0001927
2011-12-01 07:59 altaveron Note Added: 0008016
2011-12-01 10:16 2useven10 Note Added: 0008017
2012-01-05 15:42 antonk Note Added: 0008317
2012-01-05 15:47 antonk Note Edited: 0008317
2012-01-05 15:49 antonk Note Edited: 0008317
2012-01-09 14:26 2useven10 Note Added: 0008329
2012-01-10 13:27 antonk Note Added: 0008348
2012-03-09 07:21 2useven10 Relationship added related to 0002045
2012-04-27 13:56 vskirdin Note Added: 0009070
2012-04-27 14:28 2useven10 Note Added: 0009072
2013-02-28 08:04 vskirdin Build => 2354
2013-02-28 08:04 vskirdin Status assigned => closed
2013-02-28 08:04 vskirdin Resolution open => fixed