SSE. Задержка отображения содержимого вкладок

[san]

При включенном режиме SSE, при попытке обновить страницу некоторые вкладки не отображаются сразу, приходится долго ждать.
После нажатия Ctrl+F5 появляется "шапка" с вкладками, однако вкладки: Платы, TDM, Генератор, Чат остаются пустыми, на длительное время (40+ секунд). Замечу, что если происходит какое-то событие(авария, сообщение в чате) содержимое вкладок сразу отображается.
r1955
Chrome 84.0.4147.105(64 бит)

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

[alx]

Можешь приложить сюда дамп обмена по HTTP при загрузке страницы?

[san]

Вот ​дамп.
Браузер 192.168.0.5
SW-01 192.168.1.52

Запись начал перед обновлением страницы. Содержимое вкладки "Платы" отобразилось примерно через минуту, после чего запись закончил.

[alx]

Поведение хоста мне кажется очень странным...

17:42:16.745298 IP 192.168.0.5.54685 > 192.168.1.52.80: Flags [P.], seq 4904:5390, ack 175827, win 61441, length 486: HTTP: GET /events HTTP/1.1
17:42:17.214963 IP 192.168.0.5.54721 > 192.168.1.52.80: Flags [P.], seq 7083:7722, ack 34706, win 16092, length 639: HTTP: POST /api.php HTTP/1.1
17:42:17.236822 IP 192.168.1.52.80 > 192.168.0.5.54721: Flags [P.], seq 34706:35664, ack 7722, win 5279, length 958: HTTP: HTTP/1.1 200 OK
17:42:48.387377 IP 192.168.0.5.54721 > 192.168.1.52.80: Flags [P.], seq 7722:8361, ack 35664, win 16425, length 639: HTTP: POST /api.php HTTP/1.1
17:42:48.410524 IP 192.168.1.52.80 > 192.168.0.5.54721: Flags [P.], seq 35664:36622, ack 8361, win 5279, length 958: HTTP: HTTP/1.1 200 OK
17:43:17.156597 IP 192.168.0.5.54721 > 192.168.1.52.80: Flags [P.], seq 8361:8998, ack 36622, win 16185, length 637: HTTP: POST /api.php HTTP/1.1

Первая строчка - запрос от браузера к серверу. В ответ от сервера на порт 54685 - полная тишина, нет даже TCP ACK, что уже странно, учитывая что сервер живой, и мы видим, как по другим соединениям TCP идет обмен... Но что еще более странно, клиентская сторона, отправив данные и не получив в ответ ACK, не делает никаких повторных посылок...

Точно ли приложенный дамп полный? Какие фильтры использовались? Не было ли в процессе обмена каких-нибудь сообщений ICMP, которые не попали в дамп? Где (на клиенте, на сервере, между ними) был сделан этот дамп?

[alx]

Приходят в голову мысли о каких-то конфликтах адресов...

Попробуй воспроизвести проблему на "Нижнем самурае" (192.168.0.60 или [2a03:1ac0:2e92:d910:ad:c2ff:fe00:e1]).

[alx]

Вот как должно быть:

16:07:50.787019 IP6 (flowlabel 0x9357c, hlim 64, next-header TCP (6) payload length: 559) 2a02:2698:22:24bd::b851.48186 > 2a03:1ac0:2e92:d910:ad:c2ff:fe00:e1.80: Flags [P.], cksum 0x3ef5 (incorrect -> 0x0f72), seq 2134:2661, ack 1080, win 501, options [nop,nop,TS val 1853634997 ecr 278025409], length 527: HTTP, length: 527
	GET /events HTTP/1.1
	Host: [2a03:1ac0:2e92:d910:ad:c2ff:fe00:e1]
	Connection: keep-alive
	Accept: text/event-stream
	Cache-Control: no-cache
	User-Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/84.0.4147.105 Safari/537.36
	Referer: http://[2a03:1ac0:2e92:d910:ad:c2ff:fe00:e1]/
	Accept-Encoding: gzip, deflate
	Accept-Language: ru-RU,ru;q=0.9,en-US;q=0.8,en;q=0.7
	Cookie: login=admin; time=1596884863; password=****************; nonce=2459fffeb95d8957427718a3cc811dfc
	
16:07:50.828566 IP6 (class 0x04, hlim 61, next-header TCP (6) payload length: 32) 2a03:1ac0:2e92:d910:ad:c2ff:fe00:e1.80 > 2a02:2698:22:24bd::b851.48186: Flags [.], cksum 0xf66f (correct), ack 2661, win 3036, options [nop,nop,TS val 278025869 ecr 1853634997], length 0
16:07:51.006138 IP6 (class 0x04, hlim 61, next-header TCP (6) payload length: 268) 2a03:1ac0:2e92:d910:ad:c2ff:fe00:e1.80 > 2a02:2698:22:24bd::b851.48186: Flags [P.], cksum 0x3c96 (correct), seq 1080:1316, ack 2661, win 3036, options [nop,nop,TS val 278026045 ecr 1853634997], length 236: HTTP, length: 236
	HTTP/1.1 200 OK
	Transfer-Encoding: chunked
	Connection: keep-alive
	Cache-Control: no-cache
	Content-Type: text/event-stream; charset=utf-8
	Date: Sat, 08 Aug 2020 11:07:50 GMT
	
	31
	retry: 5000
	data: {"type":"resync"}
	id: 1104601
	
	
16:07:51.006224 IP6 (flowlabel 0x9357c, hlim 64, next-header TCP (6) payload length: 32) 2a02:2698:22:24bd::b851.48186 > 2a03:1ac0:2e92:d910:ad:c2ff:fe00:e1.80: Flags [.], cksum 0x3ce6 (incorrect -> 0xfddf), ack 1316, win 501, options [nop,nop,TS val 1853635216 ecr 278026045], length 0

Получив событие типа "resync" браузер запрашивает текущее состояние блока - список плат, список аварий и т.п. В твоем эксперименте этого события почему-то не приходит, поэтому и список плат не запрашивается.

[alx]

Replying to alx:

Где (на клиенте, на сервере, между ними) был сделан этот дамп?

Судя по некорректным контрольным суммам IP в запросах, дамп был сделан на стороне клиента. Было бы интересно посмотреть, что видно на стороне сервера. А еще лучше - одновременно и там, и там...

[san]

Точно ли приложенный дамп полный?

Точно не полный, какие фильтры я не вспомню уже, но ​вот нефильтрованный дамп.

Попробуй воспроизвести проблему на "Нижнем самурае"

Визуально воспроизводится аналогично.

[alx]

Replying to san:

Точно не полный, какие фильтры я не вспомню уже, но ​вот нефильтрованный дамп.

Вот, совсем другое дело. Видно, что ответ браузер получил. Следовательно, проблема на его стороне.

А в консоли браузера ошибок нет?

[alx]

Попробуй сейчас открыть "Нижний самурай". Я заметил, что события сервера парсились функцией parseJSON(), тогда как во всех остальных местах использовалась собственная обертка evalJSON(). Хотя скорее всего никакой разницы не будет, так как обе функции - обертки нативной функции JSON.parse()... Мой Хром работает одинаково с обоими вариантами, но вдруг твоему что-то не понравилось...

[san]

Открыл Самурай, разницы не заметил, ошибок в консоли нет.

[alx]

Подобавлял вывод контрольных точек в консоль. Обнови, пожалуйста, страничку в "Нижнем самурае" и скажи, что напишет в консоль.

[san]

Все 4 надписи появились только спустя длительное время, во время отображения содержимого вкладки

[alx]

Я здаюсь. Все контрольный точки пройдены. "checkpoint 4" - самая последняя. В следующей за ней строке отправляется запрос "board", которого твой браузер, судя по дампу, почему-то не отправляет... Необъяснимо...

[san]

Так они пройдены только ПОСЛЕ длительного ожидания...

[san]

Ещё заметил, что при установке в консоли уровня вывода "Verbose", после обновления страницы постепенно накапливаются какие-то сообщения:

[alx]

Replying to san:

Все 4 надписи появились только спустя длительное время, во время отображения содержимого вкладки

А-а-а... Сообщение "checkpoint 1" выводится немедленно после получения любого сообщения. Как мы видим по дампу, сообщение {"type":"resync"} передается немедленно после подключения браузера, и браузер его принимает. Но обработчик события вызывает, как ты пишешь, спустя длительное время. Следовательно, проблема сидит где-то внутри барузера. Странно только, что тот же самый браузер у меня работает нормально... Возможно, проблема связана не с кодом самого (или не только с кодом самого) браузера, а какой-то используемой библиотекой, которая в наших системах отличается...

Что с этим делать - непонятно... Путь пока тикет повисит, вдруг появятся какие-нибудь идеи...

[alx]

Я только что заметил, что браузер начинает обрабатывать сообщение после того как через минуту бездействия сервер передает в соединение пустой комментарий ":\n" (keep-alive для предотвращения разъединения). Возникла мысль попробовать передавать это сразу после первого сообщения.

Попробуй еще раз открыть "Нижний самурай".

[san]

Также, пустая вкладка висит минуту...

Ещё браузер "просыпается" и отображает содержимое вкладки если происходит какой-нибудь ивент, например авария.

[alx]

В порядке шаманства: вычитал где-то о том, что надо послать в самом начале 2 килобайта мусора (закомментаренного), почему-то было написано, что это надо для IE (вообще-то IE не поддерживает SSE). Сделал это в "Нижнем самурае". Попробуй, не будет ли каких-либо улучшений?

И правильно ли я понимаю, что после запроса и отрисовки списка плат задержек с реакцией на события уже не наблюдается?

[san]

Попробовал, улучшений не вижу.
Да, никаких задержек событий не наблюдается, проблема только с задержкой первого вывода содержимого вкладки.

[san]

В r1975 ничего похожего не замечаю.
После нажатия Ctrl+F5 сразу отображается всё содержимое.
Chrome 86.0.4240.193(64 бит)

Толи в хроме пофиксили что-то, толи у нас что-то изменилось.
Вообщем сейчас всё хорошо.