Загадочная проблема "прогрессивного замедления" в цикле выполнения / drawRect

Question

Вот настоящая загадка.

Представьте, что вы выполняете обычный процесс рисования сложного изображения вне экрана (CGLayer), и вы периодически обновляете изображение на экране во время рисования.

Как вы знаете, способ сделать это: запустить большой процесс рисования в фоновом режиме и вызвать на передний план для setNeedsDisplays по желанию, вызывая обновление изображения. Это тривиально и достигается с помощью двух строк кода.

Однако, когда вы делаете это, возникает загадочная проблема: время, затрачиваемое на каждый цикл рисования, увеличивается с каждым разом, становясь непригодным для использования. Кроме того, время может меняться хаотично.

Это известная ошибка iOS или? Кто-нибудь видел это раньше?

Вот очень простое и понятное приложение, которое демонстрирует проблему:

http://www.fileswap.com/dl/p8lU3gAi/stepwiseDrawingV2.zip.html

Пример вывода ниже.

кто-нибудь знает, почему это произошло? Это очень странное поведение со стороны ОС.

Позже... FELZ разработал поразительный обходной путь. Felz копирует CGLayer один раз в каждом раунде. Это полностью останавливает странное поведение.

Однако до сих пор нет четкого понимания того, что, черт возьми, именно происходило: отсюда, буквально, где используется время, когда проявляется странная проблема?

И вот длинный пример вывода...

Обратите внимание, что иногда вы получаете "вдвойне странный" результат, подобный следующему: он демонстрирует "нормальное" причудливое поведение: время увеличивается с каждым разом. Однако время от времени время снижается до "невероятно быстрого" в течение пары раундов, а затем возвращается. Странно, да? Кроме того, если вы работаете на симуляторе, быстро переходите назад и вперед к несвязанным приложениям на вашем Mac для получения "еще более странных" результатов.

Хотя Фельц дал прекрасный рабочий ответ, фактический механизм все еще остается загадкой.

:26:56.697 stepwiseDrawing[5334:1a03] time difference was     0
:26:56.707 stepwiseDrawing[5334:1a03] time difference was    10
:26:56.717 stepwiseDrawing[5334:1a03] time difference was    10
:26:56.744 stepwiseDrawing[5334:1a03] time difference was    27
:26:56.771 stepwiseDrawing[5334:1a03] time difference was    27
:26:56.807 stepwiseDrawing[5334:1a03] time difference was    37
:26:56.829 stepwiseDrawing[5334:1a03] time difference was    22
:26:56.864 stepwiseDrawing[5334:1a03] time difference was    35
:26:56.891 stepwiseDrawing[5334:1a03] time difference was    28
:26:56.936 stepwiseDrawing[5334:1a03] time difference was    45
:26:56.949 stepwiseDrawing[5334:1a03] time difference was    12
:26:56.981 stepwiseDrawing[5334:1a03] time difference was    32
:26:57.008 stepwiseDrawing[5334:1a03] time difference was    27
:26:57.041 stepwiseDrawing[5334:1a03] time difference was    33
:26:57.074 stepwiseDrawing[5334:1a03] time difference was    34
:26:57.109 stepwiseDrawing[5334:1a03] time difference was    34
:26:57.143 stepwiseDrawing[5334:1a03] time difference was    35
:26:57.179 stepwiseDrawing[5334:1a03] time difference was    36
:26:57.220 stepwiseDrawing[5334:1a03] time difference was    42
:26:57.271 stepwiseDrawing[5334:1a03] time difference was    51
:26:57.312 stepwiseDrawing[5334:1a03] time difference was    40
:26:57.356 stepwiseDrawing[5334:1a03] time difference was    45
:26:57.400 stepwiseDrawing[5334:1a03] time difference was    44
:26:57.447 stepwiseDrawing[5334:1a03] time difference was    46
:26:57.493 stepwiseDrawing[5334:1a03] time difference was    46
:26:57.542 stepwiseDrawing[5334:1a03] time difference was    49
:26:57.593 stepwiseDrawing[5334:1a03] time difference was    50
:26:57.707 stepwiseDrawing[5334:1a03] time difference was   114
:26:57.766 stepwiseDrawing[5334:1a03] time difference was    58
:26:57.801 stepwiseDrawing[5334:1a03] time difference was    36
:26:57.856 stepwiseDrawing[5334:1a03] time difference was    55
:26:57.918 stepwiseDrawing[5334:1a03] time difference was    62
:26:57.976 stepwiseDrawing[5334:1a03] time difference was    58
:26:58.039 stepwiseDrawing[5334:1a03] time difference was    62
:26:58.101 stepwiseDrawing[5334:1a03] time difference was    63
:26:58.165 stepwiseDrawing[5334:1a03] time difference was    63
:26:58.229 stepwiseDrawing[5334:1a03] time difference was    64
:26:58.294 stepwiseDrawing[5334:1a03] time difference was    66
:26:58.365 stepwiseDrawing[5334:1a03] time difference was    70
:26:58.436 stepwiseDrawing[5334:1a03] time difference was    72
:26:58.507 stepwiseDrawing[5334:1a03] time difference was    70
:26:58.572 stepwiseDrawing[5334:1a03] time difference was    65
:26:58.652 stepwiseDrawing[5334:1a03] time difference was    81
:26:58.726 stepwiseDrawing[5334:1a03] time difference was    74
:26:58.809 stepwiseDrawing[5334:1a03] time difference was    82
:26:58.879 stepwiseDrawing[5334:1a03] time difference was    70
:26:58.965 stepwiseDrawing[5334:1a03] time difference was    87
:26:59.043 stepwiseDrawing[5334:1a03] time difference was    77
:26:59.126 stepwiseDrawing[5334:1a03] time difference was    83
:26:59.210 stepwiseDrawing[5334:1a03] time difference was    84
:26:59.215 stepwiseDrawing[5334:1a03] time difference was     6
:26:59.310 stepwiseDrawing[5334:1a03] time difference was    95
:26:59.397 stepwiseDrawing[5334:1a03] time difference was    87
:26:59.486 stepwiseDrawing[5334:1a03] time difference was    89
:26:59.577 stepwiseDrawing[5334:1a03] time difference was    91
:26:59.668 stepwiseDrawing[5334:1a03] time difference was    91
:26:59.768 stepwiseDrawing[5334:1a03] time difference was   100
:26:59.856 stepwiseDrawing[5334:1a03] time difference was    88
:26:59.857 stepwiseDrawing[5334:1a03] time difference was     1
:26:59.965 stepwiseDrawing[5334:1a03] time difference was   108
:27:00.064 stepwiseDrawing[5334:1a03] time difference was   100
:27:00.165 stepwiseDrawing[5334:1a03] time difference was   101
:27:00.268 stepwiseDrawing[5334:1a03] time difference was   103
:27:00.371 stepwiseDrawing[5334:1a03] time difference was   103
:27:00.377 stepwiseDrawing[5334:1a03] time difference was     7
:27:00.493 stepwiseDrawing[5334:1a03] time difference was   115
:27:00.601 stepwiseDrawing[5334:1a03] time difference was   108
:27:00.710 stepwiseDrawing[5334:1a03] time difference was   109
:27:00.820 stepwiseDrawing[5334:1a03] time difference was   111
:27:00.939 stepwiseDrawing[5334:1a03] time difference was   119
:27:01.053 stepwiseDrawing[5334:1a03] time difference was   114
:27:01.162 stepwiseDrawing[5334:1a03] time difference was   108
:27:01.278 stepwiseDrawing[5334:1a03] time difference was   116
:27:01.396 stepwiseDrawing[5334:1a03] time difference was   118
:27:01.515 stepwiseDrawing[5334:1a03] time difference was   119
:27:01.637 stepwiseDrawing[5334:1a03] time difference was   122
:27:01.648 stepwiseDrawing[5334:1a03] time difference was    11
:27:01.769 stepwiseDrawing[5334:1a03] time difference was   121
:27:01.775 stepwiseDrawing[5334:1a03] time difference was     6
:27:01.910 stepwiseDrawing[5334:1a03] time difference was   135
:27:01.911 stepwiseDrawing[5334:1a03] time difference was     1
:27:02.045 stepwiseDrawing[5334:1a03] time difference was   134
:27:02.175 stepwiseDrawing[5334:1a03] time difference was   131
:27:02.314 stepwiseDrawing[5334:1a03] time difference was   139
:27:02.441 stepwiseDrawing[5334:1a03] time difference was   127
:27:02.586 stepwiseDrawing[5334:1a03] time difference was   145
:27:02.715 stepwiseDrawing[5334:1a03] time difference was   129
:27:02.853 stepwiseDrawing[5334:1a03] time difference was   138
:27:03.000 stepwiseDrawing[5334:1a03] time difference was   146
:27:03.133 stepwiseDrawing[5334:1a03] time difference was   134
:27:03.276 stepwiseDrawing[5334:1a03] time difference was   142
:27:03.419 stepwiseDrawing[5334:1a03] time difference was   143
:27:03.564 stepwiseDrawing[5334:1a03] time difference was   145
:27:03.717 stepwiseDrawing[5334:1a03] time difference was   153
:27:03.858 stepwiseDrawing[5334:1a03] time difference was   141
:27:04.008 stepwiseDrawing[5334:1a03] time difference was   149
:27:04.159 stepwiseDrawing[5334:1a03] time difference was   151
:27:04.318 stepwiseDrawing[5334:1a03] time difference was   159
:27:04.471 stepwiseDrawing[5334:1a03] time difference was   153
:27:04.620 stepwiseDrawing[5334:1a03] time difference was   149
:27:04.778 stepwiseDrawing[5334:1a03] time difference was   158
:27:04.939 stepwiseDrawing[5334:1a03] time difference was   161
:27:05.098 stepwiseDrawing[5334:1a03] time difference was   160
:27:05.269 stepwiseDrawing[5334:1a03] time difference was   171
:27:05.433 stepwiseDrawing[5334:1a03] time difference was   164
:27:05.600 stepwiseDrawing[5334:1a03] time difference was   166
:27:05.765 stepwiseDrawing[5334:1a03] time difference was   165
:27:05.932 stepwiseDrawing[5334:1a03] time difference was   167
:27:06.107 stepwiseDrawing[5334:1a03] time difference was   175
:27:06.269 stepwiseDrawing[5334:1a03] time difference was   163
:27:06.441 stepwiseDrawing[5334:1a03] time difference was   171
:27:06.617 stepwiseDrawing[5334:1a03] time difference was   176
:27:06.798 stepwiseDrawing[5334:1a03] time difference was   181
:27:06.971 stepwiseDrawing[5334:1a03] time difference was   173
:27:07.154 stepwiseDrawing[5334:1a03] time difference was   183
:27:07.326 stepwiseDrawing[5334:1a03] time difference was   172
:27:07.513 stepwiseDrawing[5334:1a03] time difference was   187
:27:07.689 stepwiseDrawing[5334:1a03] time difference was   176
:27:07.875 stepwiseDrawing[5334:1a03] time difference was   185
:27:08.059 stepwiseDrawing[5334:1a03] time difference was   184
:27:08.251 stepwiseDrawing[5334:1a03] time difference was   192
:27:08.432 stepwiseDrawing[5334:1a03] time difference was   181
:27:08.620 stepwiseDrawing[5334:1a03] time difference was   188
:27:08.811 stepwiseDrawing[5334:1a03] time difference was   190
:27:09.004 stepwiseDrawing[5334:1a03] time difference was   193
:27:09.195 stepwiseDrawing[5334:1a03] time difference was   191
:27:09.393 stepwiseDrawing[5334:1a03] time difference was   198
:27:09.590 stepwiseDrawing[5334:1a03] time difference was   197
:27:09.795 stepwiseDrawing[5334:1a03] time difference was   205
:27:09.989 stepwiseDrawing[5334:1a03] time difference was   193
:27:10.189 stepwiseDrawing[5334:1a03] time difference was   200
:27:10.392 stepwiseDrawing[5334:1a03] time difference was   203
:27:10.600 stepwiseDrawing[5334:1a03] time difference was   208
:27:10.801 stepwiseDrawing[5334:1a03] time difference was   202
:27:11.006 stepwiseDrawing[5334:1a03] time difference was   205
:27:11.220 stepwiseDrawing[5334:1a03] time difference was   213
:27:11.430 stepwiseDrawing[5334:1a03] time difference was   210
:27:11.633 stepwiseDrawing[5334:1a03] time difference was   203
:27:11.843 stepwiseDrawing[5334:1a03] time difference was   210
:27:12.055 stepwiseDrawing[5334:1a03] time difference was   213
:27:12.276 stepwiseDrawing[5334:1a03] time difference was   220
:27:12.484 stepwiseDrawing[5334:1a03] time difference was   208
:27:12.700 stepwiseDrawing[5334:1a03] time difference was   216
:27:12.919 stepwiseDrawing[5334:1a03] time difference was   219
:27:13.145 stepwiseDrawing[5334:1a03] time difference was   226
:27:13.360 stepwiseDrawing[5334:1a03] time difference was   215
:27:13.584 stepwiseDrawing[5334:1a03] time difference was   224
:27:13.813 stepwiseDrawing[5334:1a03] time difference was   229
:27:14.049 stepwiseDrawing[5334:1a03] time difference was   236
:27:14.269 stepwiseDrawing[5334:1a03] time difference was   220
:27:14.496 stepwiseDrawing[5334:1a03] time difference was   228
:27:14.725 stepwiseDrawing[5334:1a03] time difference was   229
:27:14.963 stepwiseDrawing[5334:1a03] time difference was   238
:27:15.196 stepwiseDrawing[5334:1a03] time difference was   232
:27:15.423 stepwiseDrawing[5334:1a03] time difference was   227
:27:15.657 stepwiseDrawing[5334:1a03] time difference was   235
:27:15.901 stepwiseDrawing[5334:1a03] time difference was   243
:27:16.133 stepwiseDrawing[5334:1a03] time difference was   232
:27:16.372 stepwiseDrawing[5334:1a03] time difference was   240
:27:16.613 stepwiseDrawing[5334:1a03] time difference was   241
:27:16.863 stepwiseDrawing[5334:1a03] time difference was   250
:27:17.101 stepwiseDrawing[5334:1a03] time difference was   238
:27:17.346 stepwiseDrawing[5334:1a03] time difference was   245
:27:17.593 stepwiseDrawing[5334:1a03] time difference was   247
:27:17.849 stepwiseDrawing[5334:1a03] time difference was   256
:27:18.093 stepwiseDrawing[5334:1a03] time difference was   244
:27:18.344 stepwiseDrawing[5334:1a03] time difference was   251
:27:18.603 stepwiseDrawing[5334:1a03] time difference was   260
:27:18.854 stepwiseDrawing[5334:1a03] time difference was   251
:27:19.114 stepwiseDrawing[5334:1a03] time difference was   259
:27:19.376 stepwiseDrawing[5334:1a03] time difference was   263
:27:19.646 stepwiseDrawing[5334:1a03] time difference was   270
:27:19.927 stepwiseDrawing[5334:1a03] time difference was   281
:27:20.202 stepwiseDrawing[5334:1a03] time difference was   274
:27:20.460 stepwiseDrawing[5334:1a03] time difference was   259
:27:20.743 stepwiseDrawing[5334:1a03] time difference was   283
:27:21.011 stepwiseDrawing[5334:1a03] time difference was   268
:27:21.281 stepwiseDrawing[5334:1a03] time difference was   270
:27:21.563 stepwiseDrawing[5334:1a03] time difference was   282
:27:21.848 stepwiseDrawing[5334:1a03] time difference was   284
:27:22.126 stepwiseDrawing[5334:1a03] time difference was   278
:27:22.398 stepwiseDrawing[5334:1a03] time difference was   272
:27:22.677 stepwiseDrawing[5334:1a03] time difference was   279
:27:22.970 stepwiseDrawing[5334:1a03] time difference was   293
:27:23.258 stepwiseDrawing[5334:1a03] time difference was   288
:27:23.545 stepwiseDrawing[5334:1a03] time difference was   287
:27:23.834 stepwiseDrawing[5334:1a03] time difference was   289
:27:24.122 stepwiseDrawing[5334:1a03] time difference was   288
:27:24.413 stepwiseDrawing[5334:1a03] time difference was   292
:27:24.708 stepwiseDrawing[5334:1a03] time difference was   295
:27:25.002 stepwiseDrawing[5334:1a03] time difference was   294
:27:25.303 stepwiseDrawing[5334:1a03] time difference was   301
:27:25.585 stepwiseDrawing[5334:1a03] time difference was   282
:27:25.880 stepwiseDrawing[5334:1a03] time difference was   294
:27:26.174 stepwiseDrawing[5334:1a03] time difference was   294
:27:26.470 stepwiseDrawing[5334:1a03] time difference was   296
:27:26.475 stepwiseDrawing[5334:1a03] time difference was     5
:27:26.777 stepwiseDrawing[5334:1a03] time difference was   302
:27:27.077 stepwiseDrawing[5334:1a03] time difference was   299
:27:27.373 stepwiseDrawing[5334:1a03] time difference was   297

Answer 1

Сначала позвольте мне сказать, что это была интересная головоломка. Мне было очень весело работать над этим. Хороший вопрос и хороший пример кода.

Вот мой взгляд на возможный ответ:

Проблема, которую я вижу, заключается в следующем. CGLayer отлично подходит для многократного рисования, потому что они кэшируют их рендеринг в плоское изображение. Кэш становится недействительным, когда к контексту добавляются дополнительные операции. Когда это происходит, CGLayer отображается снова. Замедление является причиной, потому что код поддерживает один CGLayer (offscreenPrefabCGL), контекст которого изменяется на каждой итерации цикла в paintActualGutsOfHugeImage. Поскольку последовательность операций в контексте offscreenPrefabCGL растет с каждым цветком, каждый рендеринг занимает больше времени. Это объясняет увеличение времени для каждого дисплея.

Я вижу два решения:

1. Клип нового рендеринга в частности в PaintView. Вместо того, чтобы аннулировать полное представление, аннулируйте только тот CGRect, который действительно нуждается в перерисовке. Это, как я понимаю, решение, предложенное @v01d.
2. Свести слой. Вместо того, чтобы держать один CGLayer, копируйте CGLayer на каждую итерацию. Это сохраняет плоское изображение в слое, которое очень быстро рендерится.

Я реализовал (2) с хорошими результатами. Первые 100 цветов быстрее, а затем он стабилизируется через 120 мс (в устройстве). Я проверил мою модифицированную версию до 2000 цветов.

Моя модифицированная версия находится в:

http://dl.dropbox.com/u/9866261/felz_mod_stepwiseDrawingV2.zip

Answer 2

EDIT2:

Вот рабочий (без замедления) проект отладки: http://bit.ly/eukSgR

Этот проект ни в коем случае не является оптимальным.

Что здесь интересно, так это необходимость растрового контекста. CGLayer кеширует ваше изображение и вызывает ваше прогрессивное замедление. С растровым контекстом он вынужден визуализироваться; и затем вы просто помещаете эти пиксели в CALayer UIView в drawRect:.

Я думаю, чтобы получить большую скорость, вы можете использовать setNeedsDisplayInRect: чтобы минимизировать область для перерисовки.

Но, кроме, может быть, оптимизации или двух здесь и там, проталкивание пикселей через UIView всегда будет медленнее, чем полное выполнение этого на GPU через, скажем, GL.

Answer 3

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