В syslog лишь обрезки сообщений.

Автор Антон Валерьевич, 09 апреля 2018, 06:49:41

« назад - далее »

0 Пользователи и 1 гость просматривают эту тему.

Печать
Вниз Страницы1
Действия пользователя

Антон Валерьевич

09 апреля 2018, 06:49:41 Последнее редактирование: 09 апреля 2018, 06:57:53 от Антон Валерьевич
Здравствуй, уважаемое сообщество!

Имею свежеустановленный Debian Stretch
# uname -a
Linux eyes 4.9.0-6-amd64 #1 SMP Debian 4.9.82-1+deb9u3 (2018-03-02) x86_64 GNU/Linux
Машина является сервером видеонаблюдения с установленным Zoneminder'ом, однако вряд ли это вызывает проблему.

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

...
Apr  9 06:37:51 eyes systemd[649]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Apr  9 06:37:51 eyes systemd[649]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Apr  9 06:37:51 eyes systemd[649]: Reached target Sockets.
Apr  9 06:37:51 eyes systemd[649]: Reached target Basic System.
Apr  9 06:37:51 eyes systemd[649]: Reached target Default.
Apr  9 06:37:51 eyes systemd[649]: Startup finished in 10ms.
Apr  9 06:37:51 eyes systemd[1]: Started User Manager for UID 33.
Apr  9 06:37:55 eyes systemd[1]: Started Session c4 of user www-data.
Apr  9 06:37:55 eyes systemd[1]: Started Session c5 of user www-data.
Apr  9 06:37:55 eyes systemd[1]: Started Session c6 of user www-data.
Apr  9 06:37:56 eyes systemd[1]: Started Session c7 of user www-data.
Apr  9 06:37:56 eyes systemd[1]: Started Session c8 of user www-data.
Apr  9 06:37:56 eyes systemd[1]: Started Session c9 of user www-data.
Apr  9 06:37:56 eyes systemd[1]: Started Session c10 of user www-data.
Apr  9 06:37:57 eyes systemd[1]: Started Session c11 of user www-data.
Apr  9 06:37:57 eyes systemd[1]: Started Session c12 of user www-data.
Apr  9 06:37:57 eyes systemd[1]: Started Session c13 of user www-data.
Apr  9 06:37:58 eyes systemd[1]: Started Session c14 of user www-data.
Apr  9 06:37:58 eyes systemd[1]: Started Session c15 of user www-data.
Apr  9 06:37:59 eyes systemd[1]: Started Session c16 of user www-data.
Apr  9 06:37:59 eyes systemd[1]: Started Session c17 of user www-data.
Apr  9 06:38:00 eyes systemd[1]: Started Session c18 of user www-data.
Apr  9 06:38:02 eyes 57ff50ea8]
Apr  9 06:38:02 eyes lse audio output error:
Apr  9 06:38:02 eyes lseAudio server connection failure: Connection refused
Apr  9 06:38:02 eyes 57ff3aca8]
Apr  9 06:38:02 eyes lse audio output error:
Apr  9 06:38:02 eyes lseAudio server connection failure: Connection refused
Apr  9 06:38:02 eyes MJPG-streamer [821]: starting application
Apr  9 06:38:02 eyes MJPG-streamer [821]: enabling daemon mode
Apr  9 06:38:02 eyes MJPG-streamer [838]: MJPG Streamer Version.: 2.0
Apr  9 06:38:02 eyes MJPG-streamer [838]: Using V4L2 device.: /dev/video0
Apr  9 06:38:02 eyes MJPG-streamer [838]: Desired Resolution: 640 x 480
Apr  9 06:38:02 eyes MJPG-streamer [838]: Frames Per Second.: 20
Apr  9 06:38:02 eyes MJPG-streamer [838]: Format............: YUYV
Apr  9 06:38:02 eyes MJPG-streamer [838]: JPEG Quality......: 95
Apr  9 06:38:02 eyes MJPG-streamer [838]: TV-Norm...........: DEFAULT
Apr  9 06:38:03 eyes MJPG-streamer [838]: www-folder-path......: disabled
Apr  9 06:38:03 eyes MJPG-streamer [838]: HTTP TCP port........: 8081
Apr  9 06:38:03 eyes MJPG-streamer [838]: HTTP Listen Address..: (null)
Apr  9 06:38:03 eyes MJPG-streamer [838]: username:password....: disabled
Apr  9 06:38:03 eyes MJPG-streamer [838]: commands.............: enabled
Apr  9 06:38:03 eyes MJPG-streamer [838]: starting input plugin input_uvc.so
Apr  9 06:38:03 eyes MJPG-streamer [838]: starting output plugin: output_http.so (ID: 00)
Apr  9 06:38:03 eyes eated new TCP socket
Apr  9 06:38:03 eyes
Apr  9 06:38:03 eyes r connection
Apr  9 06:38:04 eyes systemd[1]: Started Session c19 of user www-data.
Apr  9 06:38:05 eyes systemd[1]: Started ZoneMinder CCTV recording and surveillance system.
Apr  9 06:38:05 eyes systemd[1]: Reached target Multi-User System.
Apr  9 06:38:05 eyes systemd[1]: Reached target Graphical Interface.
Apr  9 06:38:05 eyes systemd[1]: Starting Update UTMP about System Runlevel Changes...
Apr  9 06:38:05 eyes systemd[1]: Started Update UTMP about System Runlevel Changes.
Apr  9 06:38:05 eyes systemd[1]: Startup finished in 2.974s (kernel) + 36.096s (userspace) = 39.070s.
Apr  9 06:38:03 eyes systemd[649]: Time has been changed
Apr  9 06:38:03 eyes systemd[1]: Time has been changed
Apr  9 06:38:03 eyes systemd[1]: apt-daily.timer: Adding 8h 15min 8.996814s random time.
Apr  9 06:38:03 eyes systemd[1]: apt-daily-upgrade.timer: Adding 8.525697s random time.
Apr  9 06:38:03 eyes systemd[1]: Starting Daily apt upgrade and clean activities...
Apr  9 06:38:03 eyes able to determine our source address:
Apr  9 06:38:03 eyes is computer has an invalid IP address: 0.0.0.0
Apr  9 06:38:05 eyes systemd[1]: Started Daily apt upgrade and clean activities.
Apr  9 06:38:05 eyes systemd[1]: apt-daily-upgrade.timer: Adding 19min 56.086390s random time.
Apr  9 06:38:05 eyes systemd[1]: apt-daily-upgrade.timer: Adding 15min 656.754ms random time.
Apr  9 06:38:08 eyes able to determine our source address:
Apr  9 06:38:08 eyes is computer has an invalid IP address: 0.0.0.0
Apr  9 06:38:13 eyes able to determine our source address:
Apr  9 06:38:13 eyes is computer has an invalid IP address: 0.0.0.0
Apr  9 06:38:19 eyes 3de73bea8]
Apr  9 06:38:19 eyes lse audio output error:
Apr  9 06:38:19 eyes lseAudio server connection failure: Connection refused
Apr  9 06:38:19 eyes 3de725ca8]
Apr  9 06:38:19 eyes lse audio output error:
Apr  9 06:38:19 eyes lseAudio server connection failure: Connection refused
Apr  9 06:38:19 eyes eated new TCP socket
Apr  9 06:38:19 eyes
Apr  9 06:38:19 eyes r connection
Apr  9 06:38:25 eyes able to determine our source address:
Apr  9 06:38:25 eyes is computer has an invalid IP address: 0.0.0.0
Apr  9 06:38:30 eyes able to determine our source address:
Apr  9 06:38:30 eyes is computer has an invalid IP address: 0.0.0.0
Apr  9 06:38:35 eyes able to determine our source address:
Apr  9 06:38:35 eyes is computer has an invalid IP address: 0.0.0.0
Apr  9 06:38:40 eyes able to determine our source address:
Apr  9 06:38:40 eyes is computer has an invalid IP address: 0.0.0.0
Apr  9 06:38:40 eyes ltiFramedRTPSource::doGetNextFrame1(): The total received frame size exceeds the client's buffer size (
Apr  9 06:38:40 eyes
Apr  9 06:38:40 eyes
Apr  9 06:38:40 eyes
Apr  9 06:38:40 eyes tes of trailing data will be dropped!
Apr  9 06:38:41 eyes 83e401ca88]
Apr  9 06:38:41 eyes re vout display error:
Apr  9 06:38:41 eyes iled to change zoom
Apr  9 06:38:41 eyes 83e401ca88]
Apr  9 06:38:41 eyes re vout display error:
Apr  9 06:38:41 eyes iled to set on top
Apr  9 06:38:41 eyes 83e401ca88]
Apr  9 06:38:41 eyes re vout display error:
Apr  9 06:38:41 eyes iled to change source AR
Apr  9 06:38:41 eyes jpeg @ 0x7f83d8055140]
Apr  9 06:38:41 eyes erread 8
Apr  9 06:39:05 eyes systemd[1]: Starting Clean php session files...
Apr  9 06:39:05 eyes systemd[1]: Started Clean php session files.
Apr  9 06:40:17 eyes kernel: [  176.598528] perf: interrupt took too long (2546 > 2500), lowering kernel.perf_event_max_sample_rate to 78500
Apr  9 06:40:44 eyes systemd[1]: Created slice User Slice of root.
Apr  9 06:40:44 eyes systemd[1]: Starting User Manager for UID 0...
Apr  9 06:40:44 eyes systemd[1]: Started Session 8 of user root.
Apr  9 06:40:44 eyes systemd[1085]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Apr  9 06:40:44 eyes systemd[1085]: Listening on GnuPG cryptographic agent and passphrase cache.
Apr  9 06:40:44 eyes systemd[1085]: Listening on GnuPG cryptographic agent (access for web browsers).
Apr  9 06:40:44 eyes systemd[1085]: Reached target Paths.
Apr  9 06:40:44 eyes systemd[1085]: Reached target Timers.
Apr  9 06:40:44 eyes systemd[1085]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Apr  9 06:40:44 eyes systemd[1085]: Reached target Sockets.
Apr  9 06:40:44 eyes systemd[1085]: Reached target Basic System.
Apr  9 06:40:44 eyes systemd[1085]: Reached target Default.
Apr  9 06:40:44 eyes systemd[1085]: Startup finished in 21ms.
Apr  9 06:40:44 eyes systemd[1]: Started User Manager for UID 0.
Apr  9 06:41:12 eyes kernel: [  230.959460] perf: interrupt took too long (3201 > 3182), lowering kernel.perf_event_max_sample_rate to 62250
[свернуть]

Эти же огрызки сообщений выскакивают в момент их появления на консоли root'а прямо поверх всего, что происходит на экране.

1) В чём причина обрезания этих сообщений ?
2) Как её устранить, чтобы перейти уже к устранению собственно проблем, о которых повествуют эти сообщения ?

ogost

#1
09 апреля 2018, 08:17:36
Воспользуйтесь journalctl, возможно он выдаст вам весь лог, а не огрызок.

Антон Валерьевич

#2
09 апреля 2018, 10:16:15
К сожалению, там похожие записи отсутствуют.

ogost

#3
09 апреля 2018, 11:32:21 Последнее редактирование: 09 апреля 2018, 11:35:11 от ogost
Вангую, что это сервер без графической оболочки
Вангую так же, что возможно установлено ПО из сторонних источников. Прошу опровергнуть или подтвертить.

С переходом на systemd логами так же теперь заведует systemd, если точнее, то journalctl. Так же логи теперь бинарные, а не текстовые. Текстовые логи в /var/log образуются из этих самых бинарных логов (но это не точно, я досконально не изучал это поделие поттеринга), возможно такое обрезание логов происходит в момент записи или преобразования их из бинарного вида. Всё это гадание на кофейной гуще.

Цитата: Антон Валерьевич от 09 апреля 2018, 06:49:41Apr  9 06:38:02 eyes lse audio output error:
Apr  9 06:38:02 eyes lseAudio server connection failure: Connection refused
Фрагмент выше похоже оставило ещё одно поделие поттеринга - pulseaudio.

А dmesg тоже обрезает? Или там этих логов вообще нет?
Cообщение объединено 09 апреля 2018, 11:35:11

Вообще, похоже что начало сообщений затираются строкой даты-времени, например: Apr  9 06:38:03 eyes

Антон Валерьевич

#4
09 апреля 2018, 13:03:28 Последнее редактирование: 10 апреля 2018, 05:06:47 от Антон Валерьевич
Вангую, что это сервер без графической оболочки
Так и есть.

Вангую так же, что возможно установлено ПО из сторонних источников. Прошу опровергнуть или подтвертить.
Собственно - Zoneminder

...логи теперь бинарные, а не текстовые. Текстовые логи в /var/log образуются из этих самых бинарных логов...
В этом случае упоминание записей, хотя бы обрезков, было бы в обоих местах, а на самом деле имеется только в текстовом, считающимся вторичным, производным из бинарного.

Фрагмент выше похоже оставило ещё одно поделие поттеринга - pulseaudio.
Очевидно. Я просто НЕ задавался вопросом выпиливания лишнего.

А dmesg тоже обрезает? Или там этих логов вообще нет?
Вообще нет.
Там после загрузки только массовые
[drm:drm_edid_block_valid [drm]] *ERROR* EDID checksum is invalid, remainder is 172
Это он вроде на монитор ругается. Разберусь позже.

Итак, ситуация остаётся прежней - в syslog (и только в нём) существуют хвосты каких-то системных сообщений.
Cообщение объединено 10 апреля 2018, 05:06:47

Машина является сервером видеонаблюдения с установленным Zoneminder'ом, однако вряд ли это вызывает проблему.

Это было ошибочное предположение, именно он это и делает или что-то с ним связанное. Я удостоверился в этом несколько раз подряд перезапустив его службу - всякий раз массово сыпались эти ошибки.

Тема закрыта.
Печать
Вверх Страницы1
Действия пользователя