Очень медленная генерация сертификатов discobot на нашем сервере

Поддержка
1

Мы активно предлагаем нашим новым участникам пройти обучающий курс discobot, и довольно многие сталкиваются с проблемой, которую мы уже наблюдали в предыдущем (тестовом) экземпляре Discourse: сертификат в последнем сообщении генерируется и появляется очень долго, без каких-либо указаний на то, что он загружается или генерируется. Под «очень долго» я имею в виду период в 10–20 секунд — этого достаточно, чтобы кто-то потерял терпение. Я проверил на meta, и там всё происходит мгновенно.

Я заметил, что сертификат можно сгенерировать по требованию, используя URL /discobot/certificate.svg?date=Oct+28+2020&user_id=123, поэтому я провёл несколько тестов. Сначала всё было мгновенно. Но как только я начал использовать идентификаторы пользователей, которые недавно не проходили обучающий курс, мне приходилось ждать 10–20 секунд (после первого генерирования оно происходит быстро, поэтому я предполагаю, что где-то есть кэш). Также во время ожидания я получал некоторые ошибки 500, которые, по-видимому, были вызваны каким-то таймаутом, поскольку при следующем обновлении страницы всё работало.

В логах (/logs) я вижу предупреждение, не знаю, связано ли оно с проблемой:

Failed to process hijacked response correctly : Net::ReadTimeout

traceback 
/usr/local/lib/ruby/2.6.0/net/protocol.rb:217:in `rbuf_fill'

/usr/local/lib/ruby/2.6.0/net/protocol.rb:191:in `readuntil'

/usr/local/lib/ruby/2.6.0/net/protocol.rb:201:in `readline'

/usr/local/lib/ruby/2.6.0/net/http/response.rb:40:in `read_status_line'

/usr/local/lib/ruby/2.6.0/net/http/response.rb:29:in `read_new'

/usr/local/lib/ruby/2.6.0/net/http.rb:1509:in `block in transport_request'

/usr/local/lib/ruby/2.6.0/net/http.rb:1506:in `catch'

/usr/local/lib/ruby/2.6.0/net/http.rb:1506:in `transport_request'

/usr/local/lib/ruby/2.6.0/net/http.rb:1479:in `request'

rack-mini-profiler-2.0.2/lib/patches/net_patches.rb:9:in `block in request_with_mini_profiler'

rack-mini-profiler-2.0.2/lib/mini_profiler/profiling_methods.rb:39:in `step'

rack-mini-profiler-2.0.2/lib/patches/net_patches.rb:8:in `request_with_mini_profiler'

/var/www/discourse/lib/final_destination.rb:370:in `block in safe_get'

/var/www/discourse/lib/final_destination.rb:414:in `block in safe_session'

/usr/local/lib/ruby/2.6.0/net/http.rb:920:in `start'

/usr/local/lib/ruby/2.6.0/net/http.rb:605:in `start'

/var/www/discourse/lib/final_destination.rb:411:in `safe_session'

/var/www/discourse/lib/final_destination.rb:362:in `safe_get'

/var/www/discourse/lib/final_destination.rb:131:in `get'

/var/www/discourse/lib/final_destination.rb:152:in `get'

/var/www/discourse/lib/file_helper.rb:55:in `download'

/var/www/discourse/plugins/discourse-narrative-bot/plugin.rb:113:in `fetch_avatar'

/var/www/discourse/plugins/discourse-narrative-bot/plugin.rb:98:in `block in generate'

/var/www/discourse/lib/hijack.rb:56:in `instance_eval'

/var/www/discourse/lib/hijack.rb:56:in `block in hijack'

/var/www/discourse/lib/scheduler/defer.rb:94:in `block in do_work'

rails_multisite-2.3.0/lib/rails_multisite/connection_management.rb:68:in `with_connection'

/var/www/discourse/lib/scheduler/defer.rb:89:in `do_work'

/var/www/discourse/lib/scheduler/defer.rb:79:in `block (2 levels) in start_thread'

Я так понимаю, что сертификат генерируется локально, без каких-либо внешних сетевых запросов?

Сервер — t3a.medium (4 ГБ памяти), форум не особенно загружен (~0,4 нагрузки, ещё много свободной памяти). Во время ожидания генерации сертификата загрузка процессора не менялась, так что это, по-видимому, не является узким местом.

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

Не уверен, что я на правильном пути, но если я несколько раз обновлял URL сертификата, то в итоге получал ошибку с предложением замедлиться. Существует ли какой-то механизм ограничения частоты запросов по URL, который может мешать здесь, если многие люди генерируют сертификаты по одному и тому же пути URL? Возможно, нет, но я не понимаю, почему это происходит. Любые подсказки будут приняты с благодарностью.

3

Этот маршрут действительно медленный, так как он новый.

Вместо того чтобы пытаться ускорить его, может быть, мы можем изменить текст сообщения, чтобы сообщить пользователю, что Discobot готовит что-то и это займёт минуту?

5

Я не знал, что это известно как медленный процесс. Если уж на то пошло, думаю, обновление поста с указанием этого факта могло бы помочь, но я всё ещё ожидаю, что некоторые люди откажутся от этого, если ожидание будет долгим.

Должен сказать, что 10–20 секунд на генерацию кажутся необычно долгими для вывода уже существующего SVG (предполагаю?), заполненного каким-то текстом? Насколько я могу судить, это не похоже на ограничение по процессору. В чём здесь узкое место?

6

Я думал отредактировать текст здесь, чтобы добавить фразу «Пожалуйста, подождите, я создаю для вас что-то крутое!» на предыдущем шаге… но на try.discourse.org генерация сертификата происходит ОЧЕНЬ быстро:

image
image1540×881 107 KB

Временная метка последнего шага discobot: 2 ноября, 18:46 1604371566089
Временная метка шага генерации сертификата discobot: 2 ноября, 18:46 1604371567470

Я точно не знаю, в каких единицах измеряются эти временные метки, но это разница в 1381.

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

1604373488630
1604373492182

Это разница в 3552… и я буквально отправлял сообщение максимально быстро, используя вставку и сочетания клавиш!

Так что… ваш сервер просто… ужасен или что-то в этом роде?

7

Я полагаю, речь идет о генерации изображения сертификата, а не о публикации.

8

Я действительно говорю о генерации сертификата — а не о ответном сообщении, которое его встраивает (оно выполняется быстро). Вот какую проблему это вызывает у некоторых наших участников:

image
image556×333 3.72 KB

Нет, t3a.medium — это экземпляр среднего уровня, и нагрузка не высокая.

Как я уже говорил, проблема, похоже, не связана с процессором, потому что пока я жду завершения запроса, например, /discobot/certificate.svg?date=Oct+28+2020&user_id=123, процессор не работает интенсивнее, чем в любое другое время (а в остальное время он тоже не сильно загружен).

Проблема, по-видимому, связана с тайм-аутом сетевого запроса:

Аватар на сертификате, похоже, представляет собой blob data:image/png;base64. Судя по всему, происходит попытка скачать аватар, которая приводит к тайм-ауту? Возможно, именно это замедляет процесс?

Для контекста: на форуме используется SSO, а аватары хранятся по HTTPS-URL на S3. Я пробовал скачивать некоторые из этих аватаров изнутри Docker-контейнера, и это работает почти мгновенно — проблем с фаерволом и т.п. нет. Всё остальное на форуме работает быстро, кроме генерации сертификата, которая занимает много времени.

Готов продолжить отладку, если мне подскажут, что именно проверять.

9

У меня изображение появилось почти мгновенно на try.discourse.org. Я не заметил значительной задержки — максимум полсекунды, если вообще была? Попробуйте сами, если не верите мне!

Поэтому я возвращаюсь к тому, что говорил изначально: почему на вашем сервере это так медленно, а на try.discourse.org — так быстро?

11

Именно… Вот по этому поводу я и пытаюсь получить поддержку.

Понимаю, что это ситуация типа «на моей машине работает», которой вообще не должно быть с Docker, но, увы, вот мы и здесь, и похоже, что я не единственный в такой ситуации.

Буду признателен за любые подсказки, как с моей стороны отладить это.

12

Я потратил некоторое время на изучение этой проблемы, и, похоже, дело в том, что discourse-narrative-bot блокируется при попытке получить аватар пользователя для включения в сертификат. Вот здесь:

Этот форум использует SSO, а аватары — это URL-адреса Amazon S3, которые работают быстро и не имеют ограничений по частоте запросов со стороны Amazon. Тем не менее, эта функция запрашивает URL-адрес аватара следующего вида:

https://forum.tld/user_avatar/forum.tld/username/240/18705_2.png

Могут ли ошибки тайм-аута, замедляющие генерацию сертификатов, быть связаны с попаданием под ограничение частоты запросов самого Discourse? Либо из-за того, что аватары запрашиваются слишком быстро с самого экземпляра Discourse, либо из-за слишком частых запросов к Amazon S3, когда несколько пользователей одновременно проходят обучение с помощью бота?

13

Интересно. Мы встраиваем изображение в формате base64. Интересно, почему мы не просто сослались на внешний ресурс в теге SVG image :thinking:

Я углубился в историю плагина вплоть до момента, когда мы впервые добавили это:

И, похоже, мы всегда использовали встроенные аватары в формате base64.

РЕДАКТИРОВАНИЕ: После некоторых исследований выяснилось, что мы используем base64, потому что сертификат загружается через HTML-тег img. Чтобы получить более дешёвые аватары, нам пришлось бы перейти на тег object, который по умолчанию заблокирован в нашей CSP. Или же встроить весь SVG прямо в содержимое поста. Думаю, iframe — наш лучший вариант.

У меня есть FIX: Make discobot certificate gen faster/non blocking by xfalcox · Pull Request #11344 · discourse/discourse · GitHub для комментариев от @tgxworld.

14

Я предположил, что SVG с встроенным avatar в base64 использовалась по той же причине, по которой «так делался» логотип: чтобы сертификат мог быть снимком в момент времени — возможно, сохранённым получателем, без каких-либо внешних зависимостей, чтобы он всё ещё отображался позже точно так же.

Подход с iframe препятствует его лёгкому распространению и хвастовству в посте. Не знаю, насколько это распространено на других форумах, но я видел, как некоторые наши пользователи делают это, просто копируя URL изображения.

Если использовать ссылку на внешний ресурс, не сработает ли здесь <image>, чтобы избежать необходимости менять allowed_iframes?

15

Именно это и делает вышеупомянутый PR, если вы его прочитаете :grimacing:

Однако, если вы загружаете SVG с помощью HTML-тега img, как мы делаем сейчас, внешние изображения, содержащиеся в тегах SVG image, не будут загружаться. Для этого необходимо использовать либо object, либо iframe.

16

Очевидно, мне недостаточно много известно о SVG. Подход с использованием iframe предотвращает цитирование/копирование сертификата, но тем не менее я рад, что проблема каким-то образом решается, так как это исправит нашу проблему, а также проблему отсутствующего логотипа на сертификате. :+1:

17

@mentalstring Я только что объединил новый код генерации сертификатов. Теперь это должно работать намного быстрее.

18

Отлично, что это объединено. :+1:

Мы работаем в ветке stable, и у меня сейчас нет хорошего способа протестировать это. Но если fetch_avatar больше не используется, я ожидаю, что ошибки Net::ReadTimeout исчезнут с этим обновлением. Помечаю задачу как решённую и открою её снова, если по какой-то причине мы снова столкнёмся с той же проблемой при обновлении. Спасибо!