Серверные логи

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

Также разумеется выводится все, что разработчик решил вывести в своих методах и модулях (через console). Однако как правило таких логов мало и их следует убирать после отладки, чтобы они не засоряли лог.

В методах иногда имеет смысл оставлять логи вида console.error, в тех местах, где поведение не соответствует продуманной логике. При этом здесь речь идет не о проверке параметров, а более нештатных ситуациях. Это даст возможность при сбоях иметь информацию о том, что пошло не так. Проверка параметров, как и прочие проверки, должны обрабатываться штатным механизмом выхода из функции с соответствующим ответом (интерфейс IError).

Некоторыми аспектами вывода можно управлять, это будет описано ниже.

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

Информация в логах упорядочена и имеет определенную структуру, которую мы сейчас и опишем:

Начинается логирование со старта сервера и указания какой конфигурационный файл выбран:

Configuration file selected: config.json

Чтобы выбрать другой конфиг его нужно указать вторым (после имени js файла) параметром при запуске: “node bin/www.js testConfig.json”

Далее устанавливаются настройки MySQL взятые из конфигурации. Сообщения вида “INFO: cMysql.INIT. …”. Они выводятся через error, так же как и последующее сообщение о запуске сервера:

ERROR: 10.07.2025 12:15:07 SERVER STARTED Server time: Thu Jul 10 2025 12:15:07 GMT+0300 (Москва, стандартное время)

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

Далее сообщений в потоке error быть не должно и если они есть, то на них следует обратить внимание.

После идет информация об адресе, на котором запущен сервер

Server running at http://127.0.0.1:7011/

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

BJ ==> INFO Фоновые задачи начнут запускаться через 300

…
BJ ==> INFO Следующие задачи исключены из запуска конфигурационным файлом []

BJ ==> INFO Эти задачи будут запущены […]

Когда подключается клиент (по сокету), будет сообщение следующего вида: io.on.connection:count: 2. Когда отключается: socket on disconnect 4BOQu1pNzJJvs9lnAAAL transport close.

Обмен запросами с клиента и между методами

Все запросы проходят через внутренний API и попадают в логирование.

Информация о запросе

Запросы с клиента (будь то веб интерфейс, обращение по API или мобильное приложение) открывают цепочку запросов, а все внутренние вызовы других методов, если исходный метод еще что-то вызывает) продолжают эту цепочку, то есть становятся дочерними для вызвавших его методов. Таким образом в логах мы видим всю цепочку, кто кого вызвал.

Рассмотрим на примерах запроса.

11.07.2025 10:36:53.611 f437c7d7-db07-4ca4-876e-b0749c6e5e73: → 48DE98AA_User.get_me (fromClient) {“getRoles”:false}

11.07.2025 10:36:53.612 f437c7d7-db07-4ca4-876e-b0749c6e5e73: ← 48DE98AA_User.get_me (fromClient) ←1 UserError: noAuth -4 noAuth User.get_me { message_en: ‘Please log in.’ }

В начале идет дата и время.

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

Далее идет SID

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

Если запрос внутренний, то указывается столько символов “_” (нижнее подчеркивание), какой уровень вложенности имеет запрос.

Далее, стрелкой указано направление. Стрелка вперед это запрос, а стрелка назад - ответ.

Потом идет ID запроса, содержащее также уникальный номер и цепочку вызовов в формате <ИмяКласса>.<ИмяМетода>. При этом если следующий в цепочке метод относится к тому же классу что и родительский, то имя класса опускается.

EA55DED2_User.get_me - Access_to_operation.loadAccess - user_role.get

или
3629393D_menu.get_menu_tree - .get (тут имя класса перед “get” опускается, так как он относится тоже к классу “menu”).

Если запрос пришел извне (не внутренний), то далее идет “(fromClient):”. По нему также можно отфильтровать, чтобы не мешали внутренние запросы.

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

2025 12:45:42.477 f437c7d7-db07-4ca4-876e-b0749c6e5e73: fromClient: ← DD58E88A_User.login ←134 noToastr

Часто можно увидеть ответ “noToastr”, его возвращают методы, которые не предусматривают вывод сообщения пользователю.

Вот как выглядит набор запросов, начиная с входа извне, продолжая внутренними запросами, и завершая ответом:

11.07.2025 10:41:00.256 f437c7d7-db07-4ca4-876e-b0749c6e5e73: → D296E26E_menu.get_menu_tree (fromClient) {}

11.07.2025 10:41:00.272 f437c7d7-db07-4ca4-876e-b0749c6e5e73: _ → D296E26E_menu.get_menu_tree - .get {“where”:[{“key”:“is_visible”,“val1”:true}],“sort”:“sort_no,name”,“limit”:1000000}

11.07.2025 10:41:00.347 f437c7d7-db07-4ca4-876e-b0749c6e5e73: _ ← D296E26E_menu.get_menu_tree - .get ←75 noToastr

11.07.2025 10:41:00.348 f437c7d7-db07-4ca4-876e-b0749c6e5e73: ← D296E26E_menu.get_menu_tree (fromClient) ←92 noToastr

Система скрывает некоторые секьюрные параметры при выводе в консоль, выводя вместо них “***”, например параметр “password” в методе User.login.

Такие параметры перечислены в excludedConsoleParams в api/apiConfig и соответственно в файлах default и project. Если хотите расширить список, дополните его в файле project.ts Вы можете использовать не полное совпадение имени параметра а “начинается с” и “заканчивается на”, используя символ “*”.

Конфигурация “log:api:”

Вы можете настроить какую информацию выводить. Настройки располагаются в конфигурационном файле config/config.json в секции “log:api:”.

fromClientOnly. Позволяет отключить логирование внутренних запросов. Не отключайте на продакшене, так как это довольно ценная информация.

logStart. Выводить ли в консоль когда запрос пришел.

logFinishUserOk. Выводить ли в консоль когда запрос выполнен и отправляется клиенту, если ответ UserOk.

logFinishUserError. Выводить ли в консоль когда запрос выполнен и отправляется клиенту, если ответ UserError.

logFinishMyError. Выводить ли в консоль когда запрос выполнен и отправляется клиенту, если ответ MyError.

logFinishUnknown. Выводить ли в консоль когда запрос выполнен и отправляется клиенту, если ответ не один из вышеперечисленных типов. Такого быть не должно, заложено на всякий случай, если разработчики добавят новый тип, соответствующий IAPIResponse.

logBadCommand. Выводить ли в консоль когда запрос обращается к несуществующему методу. Не стоит включать этот параметр просто так. Такие ошибки вполне могут случаться, например когда кто-нибудь отлаживает работу с вашим сервисом по API и допускает ошибки. Хотя на продакшене можно включить, так как там никаких отладок быть не должно и если такие команды имеются, то их стоит логировать и разбираться.

Логирование SQL

Система позволяет логировать какие SQL запросы формируются. Это относится только к запросам вида SELECT.

Почему-то за все время работы не возникло необходимости логировать другие виды SQL запросов (именно SQL, так как мы видим что метод, например “modify” был вызван и с какими параметрами), поэтому это сделано не было.

В ходе своей работы ядро может делать различные дополнительные (служебные) запросы, которые помечены параметром doNotLog. Такие запросы по умолчанию скрываются из логирования, как в api, так и запросов SQL. Это можно изменить параметром ignoreDoNotLog.

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

На самом деле, ядро делает много различной работы, включая подтягивание данных из справочников по системным именам, проверок уникальности и прочего. Кроме того, система кэширования устроена довольно хитро, поэтому не всегда сходу понятно, почему система делает те или иные подзапросы (что-то из кэша, тот то из базы). Такие запросы как правило идут с флагом doNotLog, о котором уже упоминалось, и на них не стоит обращать внимания. Здесь это описано для того, чтобы вы при отладке какого-либо своего запроса, включив все логирование, были в курсе, что разные процессы могут происходить и это нормально - они обеспечивают оптимальное взаимодействие с базой, при должном уровне удобства разработки.

Ядро умеет логировать долгие запросы, такие запросы логируются в поток “error” (по умолчанию), что позволяет легко их обнаруживать и предпринимать меры. Вы можете настроить параметры для этого механизма, см. Конфигурация “log:sql:”

Конфигурация “log:sql:”

Вы можете настроить какую информацию выводить. Настройки располагаются в конфигурационном файле config/config.json в секции “log:sql:”.

countStart. Выводить ли в консоль SQL запрос на ПОДСЧЕТ перед его выполнением в БД.

countFinish. Выводить ли в консоль SQL запрос на ПОДСЧЕТ после его выполнения в БД.

selectStart. Выводить ли в консоль SQL запрос на ПОЛУЧЕНИЕ ДАННЫХ перед его выполнением в БД.

selectFinish. Выводить ли в консоль SQL запрос на ПОЛУЧЕНИЕ ДАННЫХ после его выполнения в БД.

selectFromCache. Выводить ли в консоль SQL запросы на ПОДСЧЕТ и ПОЛУЧЕНИЕ ДАННЫХ при получении их из кэша.

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

ignoreDoNotLog. Выводить выше перечисленные запросы, согласно их настройкам, в том числе и для запросов с параметром doNotLog. Иногда помогает отладить сложный случай.

debugLongSql. Включает логирование долгих запросов, даже если все остальное логирование отключено.

longSQLTime. Определяет в миллисекундах, больше какого времени должен выполняться запрос, чтобы считаться “долгим” и попадать в лог.

longSQLConsoleFn. Можно переопределить, какой метод вызывать у объекта console, при логировании долгих запросов. По умолчанию выполняется console.error(…).

Сохранение в базу данных

Система автоматически сохраняет некоторые ошибки в базу данных и их можно посмотреть через интерфейс системы. Меню System -> Лог ошибок.

По умолчанию система сохраняет ответы методов вида MyError, а также все console.error выводимые в процессе работы сервера. Также когда на сервере где-то происходит не пойманная ошибка (uncaughtException), она ловится на самом верхнем уровне и также логируется.

Исключением являются ошибки связанные с доступом к БД.

Настройка системы логирование в БД

Вы можете настроить, что именно будет логироваться в базу через интерфейс системы. Более того, эти настройки будут применены на лету, то есть вам не потребуется перезапускать сервер, чтобы изменения вступили в силу.

Настройки делаются через таблицу System -> Системные настройки (вы можете встретить устаревшее название Клиентские настройки).

Нужно изменить или создать (она может быть не создана) строку с Системным именем “LOG_ERRORS”.

В “Значении 1” перечислите через запятую типы логируемых ошибок из этого списка: ANY|NO|MYERROR|USERERROR|UNKNOWN. Если среди перечисленных будет значение NO, то никакие ошибки не будут логироваться. Если есть ANY (но нет NO), то любые типы ошибок будут логироваться.

В “Значении 2” перечислите через запятую источники логируемых ошибок из этого списка: ANY|NO|API|LOG|THROW. Значение NO и ANY работают также как и для типов. API - если ошибка в ответе от метода вызванного через внутренние API, LOG - ошибка выведенная через console.error, THROW это не пойманные ошибки.

Как указано выше, вы можете настраивать типы ошибок и источники ошибок. По умолчанию используются ANY и ANY.

Логирование с клиента по сокету

Система поддерживает возможность писать в серверный лог сообщения отправленные с клиента по сокету в канал “logFromClient”.

socket.on('logFromClient', …)

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

Такой лог выделяется в блок:

logFromClient START 1 2025.07.11 13:40:18

{ msg: ‘TEST’, abc: 489 }

logFromClient END 1

После слова START идет ID пользователя, для которого логируется.

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

Конфигурация “log:socket:”

logFromClient. Включает или отключает логирование.

logFromClientUsers.Массив с ID пользователей, для которых логировать. Можно указать “-” чтобы логировать от неавторизованных.

Лог отказов доступа

Как описано в разделе про доступы, отказы логируются в Доступ -> Отказы доступа.

Лог отказы авторизации

Аналогично отказам в доступе, также логируются неудачные попытки авторизации. Доступ -> Отказы авторизации.

Логируются поля: user_id, login, sid, user_agent, address, err.

Введенный пароль естественно не логируется

Просмотр логов на сервере

Как правило на сервере процесс развернут в контейнере и смотреть логи можно через стандартный журнал с фильтрацией по контейнеру.

Пример: journalctl --since “2025-07-03 07:00:00” --until “2025-07-03 11:00:00” CONTAINER_NAME=app | grep -C 2 “MyError”.

Если вы разворачивали сервер по инструкции в этой документации, то вы можете набрать ./start.sh log ccs_app, где ccs_app - имя сервиса.