PERF: Reduz verbosidade de logs em nivel info no ciclo do cron

Rebaixa para debug uma serie de logs "heartbeat" que disparavam todo ciclo
(a cada 1 minuto) independente de qualquer mudanca real, competindo com os
logs de acao/erro que realmente importam: buscas por watermark, contagem
de tickets pendentes/monitorados, checagens de comentario ja sincronizado,
abertura de conexao GLPI/PostgreSQL, e o resumo de sincronizacao do SN
(que a margem de seguranca de 6h do watermark sempre retorna nao-vazio,
mesmo sem mudanca real de campo).

Corrige tambem um bug real encontrado em teste: no fluxo GLPI -> SN, todo
comentario historico de um ticket era sanitizado e checado contra a API do
SN a cada ciclo antes mesmo de verificar se ja tinha sido sincronizado
(ticket_updates.destiny_id). Em tickets com historico longo isso
significava dezenas de chamadas desnecessarias por minuto. Agora a
checagem local (barata) roda primeiro, e so sanitiza/consulta o SN quando
o comentario realmente ainda nao foi sincronizado.

Corrige tambem o log de configuracao do pool PostgreSQL, que imprimia
"[object Object]" por passar o objeto de config como mensagem em vez de
metadado.

LOG_LEVEL default muda de debug para info em .env.example e
.env.production, unica forma do rebaixamento acima ter efeito pratico.

Co-Authored-By: Claude Sonnet 5 <noreply@anthropic.com>

.env.example

@@ -79,7 +79,7 @@ SNGLPI_DB_PASSWORD=
 LOCATION_MAPPING_CSV_PATH=/path/to/your/location_mapping.csv
 
 # Logging
-LOG_LEVEL=debug
+LOG_LEVEL=info
 LOG_TO_CONSOLE=true
 LOG_RETENTION_DAYS=10
 LOG_DIR=logs

src/controllers/processCommentsController.js

@@ -2,11 +2,11 @@ const { fetchCommentsFromServiceNow } = require('../services/servicenowService')
 const { syncCommentsGlpitoSN, syncCommentsSNtoGlpi } = require('../services/glpiCommentService');
 const TicketSyncModel = require('../models/ticketSyncModel');
 const TicketGlpiModel = require('../models/ticketGlpiModel');
-const { logInfo } = require('../utils/logger');
+const { logDebug } = require('../utils/logger');
 
 const processCommentsController = async () => {
     const ticketsToMonitor = await TicketSyncModel.getTicketsToMonitor();
-    logInfo(`Tickets em monitoramento: ${ticketsToMonitor.length}`);
+    logDebug(`Tickets em monitoramento: ${ticketsToMonitor.length}`);
 
     for (const ticket of ticketsToMonitor) {
         const glpiStatus = await TicketGlpiModel.getTicketStatus(ticket.glpi_ticket_id);
@@ -14,7 +14,7 @@ const processCommentsController = async () => {
             // Regra de negocio: enquanto o GLPI estiver Solucionado, nao manda comentario novo
             // do SN pra dentro do chamado. A decisao de reabertura acontece em
             // processTicketLifecycleController.js, que roda antes deste controlador no ciclo.
-            logInfo(`Ticket ${ticket.glpi_ticket_id} permanece Solucionado no GLPI. Comentarios SN -> GLPI bloqueados ate reabertura.`);
+            logDebug(`Ticket ${ticket.glpi_ticket_id} permanece Solucionado no GLPI. Comentarios SN -> GLPI bloqueados ate reabertura.`);
             await syncCommentsGlpitoSN(ticket);
             continue;
         }

src/controllers/processErrorController.js

@@ -1,15 +1,15 @@
 const TicketSyncModel = require('../models/ticketSyncModel');
-const { logInfo, logError, logWarning } = require('../utils/logger');
+const { logInfo, logError, logWarning, logDebug } = require('../utils/logger');
 
 const MAX_ERROR_RETRIES = Number(process.env.MAX_ERROR_RETRIES || 5);
 
 const processErrorController = async () => {
-    logInfo('Iniciando verificação de tickets com erro...');
+    logDebug('Iniciando verificação de tickets com erro...');
     try {
         const errorTickets = await TicketSyncModel.getTicketsInErrorState();
 
         if (errorTickets.length === 0) {
-            logInfo('Nenhum ticket com erro encontrado para reprocessamento.');
+            logDebug('Nenhum ticket com erro encontrado para reprocessamento.');
             return;
         }
 

src/controllers/processSyncController.js

@@ -2,7 +2,7 @@ const TicketSnModel = require('../models/ticketSnModel');
 const TicketSyncModel = require('../models/ticketSyncModel');
 const SyncControlModel = require('../models/syncControlModel');
 const { fetchTicketsFromServiceNow: fetchTicketsApi, fetchRequestsFromServiceNow: fetchRequestsApi, fetchScItemOptionValue } = require('../services/servicenowService');
-const { logInfo, logError, logSync } = require('../utils/logger');
+const { logInfo, logError, logSync, logDebug } = require('../utils/logger');
 
 /**
  * Processa e salva um lote de tickets (incidentes ou requisicoes).
@@ -22,7 +22,7 @@ const processAndSaveTickets = async (tickets, type) => {
     };
 
     if (!tickets || tickets.length === 0) {
-        logInfo(`Nenhum ticket do tipo '${type}' para processar.`);
+        logDebug(`Nenhum ticket do tipo '${type}' para processar.`);
         return '';
     }
 
@@ -89,7 +89,7 @@ const processAndSaveTickets = async (tickets, type) => {
                     logInfo(`Ticket ${ticket.number} recebido de novo pela margem de seguranca do watermark, sem mudanca de status ('${ticketStatus}'). Ignorando reset de 'source_last'.`);
                 }
             } else {
-                logInfo(`Registro de sincronizacao para o ticket ${ticket.number?.value} ja existe. Nenhuma acao necessaria.`);
+                logDebug(`Registro de sincronizacao para o ticket ${ticket.number?.value} ja existe. Nenhuma acao necessaria.`);
             }
 
             const currentUpdateDate = parseServiceNowDate(ticket.sys_updated_on);
@@ -114,12 +114,12 @@ const processAndSaveTickets = async (tickets, type) => {
 const processSyncController = async () => {
     try {
         const watermark = await SyncControlModel.getWatermark('servicenow');
-        logInfo(`INFO: Buscando tickets do ServiceNow atualizados desde: ${watermark}`);
+        logDebug(`Buscando tickets do ServiceNow atualizados desde: ${watermark}`);
 
         const incidents = await fetchTicketsApi(watermark);
         const latestIncidentUpdate = await processAndSaveTickets(incidents, 'incidente');
 
-        logInfo('INFO: Buscando requisicoes do ServiceNow...');
+        logDebug('Buscando requisicoes do ServiceNow...');
         const requests = await fetchRequestsApi(watermark);
         const latestRequestUpdate =  await processAndSaveTickets(requests, 'requisicao');
 
@@ -131,7 +131,7 @@ const processSyncController = async () => {
             const nextWatermark = new Date(new Date(newWatermark).getTime() - sixHoursInMillis);
             await SyncControlModel.setWatermark('servicenow', nextWatermark);
         } else {
-            logInfo("Nenhum ticket novo ou atualizado encontrado. A marca d'agua nao foi alterada.");
+            logDebug("Nenhum ticket novo ou atualizado encontrado. A marca d'agua nao foi alterada.");
         }
 
     } catch (error) {

src/controllers/processTicketLifecycleController.js

@@ -12,7 +12,7 @@ const {
 } = require('../services/servicenowService');
 const { isOutOfScopeSolution, handleOutOfScopeResolution, addServiceNowClosureNoteToGlpi } = require('../services/glpiTicketService');
 const { stripHTML } = require('../utils/commentSanitizer');
-const { logInfo, logError, logWarning } = require('../utils/logger');
+const { logInfo, logError, logWarning, logDebug } = require('../utils/logger');
 
 const DEFINITIVE_CLOSE_NOTICE = 'Chamado encerrado definitivamente. Tempo para reabertura encerrado. Caso necessario, por favor abra um novo Ticket.';
 const caoaTiGroupId = process.env.SERVICENOW_CAOA_TI_GROUP_ID;
@@ -85,7 +85,7 @@ const processTicketLifecycleController = async () => {
     try {
         const tickets = await TicketSyncModel.getTicketsForClosureMonitor();
         if (!tickets.length) {
-            logInfo('Nenhum ticket ativo para monitoramento de status/fechamento.');
+            logDebug('Nenhum ticket ativo para monitoramento de status/fechamento.');
             return;
         }
 

src/data/database.js

@@ -1,7 +1,7 @@
 // src/data/database.js
 // Configuração da conexão com o banco de dados PostgreSQL
 const { Pool } = require('pg');
-const { logInfo, logError } = require('../utils/logger');
+const { logInfo, logError, logDebug } = require('../utils/logger');
 
 const poolConfig = {
   host: process.env.SNGLPI_DB_HOST ,
@@ -15,13 +15,11 @@ const pool = new Pool(poolConfig);
 
 // Log da configuração do pool para depuração (sem a senha)
 const sanitizedConfig = { ...poolConfig, password: '*****' };
-logInfo('--- Configuração do Pool PostgreSQL (Banco Intermediário) ---');
+logInfo('Configuração do Pool PostgreSQL (Banco Intermediário)', sanitizedConfig);
-logInfo(sanitizedConfig);
-logInfo('----------------------------------------------------------');
 
 // testa a conexao
 pool.on('connect', () => {
-  logInfo('Conectado ao PostgreSQL');
+  logDebug('Conectado ao PostgreSQL');
 });
 
 pool.on('error', (err) => {

src/data/glpiDataBase.js

@@ -1,7 +1,7 @@
 // src/data/glpiDatabase.js
 // Configuração da conexão com o banco de dados mariaDB do GLPI
 const mysql = require('mysql2/promise');
-const { logInfo, logError, logWarning } = require('../utils/logger'); 
+const { logError, logDebug } = require('../utils/logger');
 
 const glpiPool = mysql.createPool({
     host: process.env.GLPI_DB_HOST,
@@ -18,7 +18,7 @@ const glpiPool = mysql.createPool({
 
 // Testar conexão
 glpiPool.on('connection', (connection) => {
-    logInfo('Nova conexão GLPI estabelecida');
+    logDebug('Nova conexão GLPI estabelecida');
 });
 
 glpiPool.on('error', (err) => {

src/models/ticketSnModel.js

@@ -1,5 +1,5 @@
 const pool = require('../data/database');
-const { logInfo, logError } = require('../utils/logger');
+const { logInfo, logError, logDebug } = require('../utils/logger');
 
 class TicketSnModel {
 
@@ -94,7 +94,10 @@ class TicketSnModel {
                     action: 'insert'
                 });
             } else {
-                logInfo(`🔄 Ticket atualizado! ID: ${result.rows[0].id}`, {
+                // Fica em debug: a margem de seguranca de 6h do watermark reenvia o mesmo ticket
+                // toda vez que ele ainda esta "quente", mesmo sem mudanca real de campo. O sinal
+                // de mudanca de status de verdade ja e logado em processSyncController.js.
+                logDebug(`🔄 Ticket atualizado! ID: ${result.rows[0].id}`, {
                     ticket_id: result.rows[0].id,
                     ticket_number: values[0],
                     action: 'update'
@@ -137,7 +140,7 @@ class TicketSnModel {
             `;
 
             const result = await pool.query(query);
-            logInfo(`📋 Tickets pendentes encontrados: ${result.rows.length}`);
+            logDebug(`📋 Tickets pendentes encontrados: ${result.rows.length}`);
             return result.rows;
 
         } catch (error) {

src/services/glpiCommentService.js

@@ -1,7 +1,7 @@
 const TicketGlpiModel = require('../models/ticketGlpiModel');
 const TicketSyncModel = require('../models/ticketSyncModel');
 const TicketUpdateModel = require('../models/ticketUpdateModel');
-const { logInfo, logError } = require('../utils/logger');
+const { logInfo, logError, logDebug } = require('../utils/logger');
 const { existingCommentInServiceNow, syncCommentToServiceNow } = require('./servicenowService');
 const { sanitizeGLPIComment } = require('../utils/commentSanitizer');
 
@@ -81,26 +81,34 @@ const formatSNUpdateForGlpi = (update, options = {}) => {
 
 const syncCommentsGlpitoSN = async (ticket) => {
   try {
-    logInfo('INFO: Iniciando sincronizacao de comments do GLPI para o ServiceNow...');
+    logDebug('Iniciando sincronizacao de comments do GLPI para o ServiceNow...');
     const comments = await TicketGlpiModel.getFollowupsByItemId(ticket.glpi_ticket_id);
     await TicketSyncModel.updateLastSync(ticket.sn_ticket_id, 'glpi'); // Atualiza o timestamp
     if (!Array.isArray(comments) || comments.length === 0) {
-      logInfo(`Nenhum comentario encontrado no GLPI para o ticket GLPI ID: ${ticket.glpi_ticket_id}`);
+      logDebug(`Nenhum comentario encontrado no GLPI para o ticket GLPI ID: ${ticket.glpi_ticket_id}`);
       return;
     }
 
-    logInfo(`INFO: ${comments.length} comentarios encontrados (GLPI ID: ${ticket.glpi_ticket_id})`);
+    logDebug(`${comments.length} comentarios encontrados (GLPI ID: ${ticket.glpi_ticket_id})`);
     let hasError = false;
+    const syncId = await TicketSyncModel.getIdSyncByGlpiId(ticket.glpi_ticket_id);
 
     for (const comment of comments) {
       try {
-        const sanitized = sanitizeGLPIComment(comment);
+        // Checa idempotencia local (barato, sem chamada externa) antes de sanitizar e consultar o SN.
+        // A maioria dos comentarios de um ticket ja monitorado ha varios ciclos ja tem destiny_id
+        // gravado, entao nem precisa sanitizar nem chamar a API do SN pra saber disso.
         const existingComment = await TicketUpdateModel.getBySourceId(comment.id);
+        if (existingComment && existingComment.destiny_id) {
+          logDebug(`Comentario ${comment.id} ja sincronizado.`);
+          continue;
+        }
+
+        const sanitized = sanitizeGLPIComment(comment);
         const existsInSN = await existingCommentInServiceNow(ticket.sn_ticket_id, sanitized);
-        const syncId = await TicketSyncModel.getIdSyncByGlpiId(ticket.glpi_ticket_id);
 
         if (existingComment && existsInSN) {
-          logInfo(`INFO: Comentario ${comment.id} ja sincronizado.`);
+          logDebug(`Comentario ${comment.id} ja sincronizado.`);
           continue;
         }
 
@@ -157,7 +165,7 @@ const syncCommentsGlpitoSN = async (ticket) => {
       await TicketSyncModel.updateStatus(ticket.sn_ticket_id, finalGlpiStatus, finalSnStatus);
     }
 
-    logInfo('OK: Sincronizacao de comentarios GLPI -> SN concluida!');
+    logDebug('OK: Sincronizacao de comentarios GLPI -> SN concluida!');
   } catch (error) {
     logError(`Erro geral na sincronizacao: ${error}`);
   }
@@ -165,7 +173,7 @@ const syncCommentsGlpitoSN = async (ticket) => {
 
 
 const syncCommentsSNtoGlpi = async (comments, ticket, options = {}) => {
-    logInfo('INFO: Iniciando sincronizacao de comments do ServiceNow para o GLPI...');
+    logDebug('Iniciando sincronizacao de comments do ServiceNow para o GLPI...');
 
     const orderedComments = [...comments].sort((a, b) => {
         const aTime = new Date(a.created_at).getTime();

src/services/glpiTicketService.js

@@ -2,7 +2,7 @@ const TicketSnModel = require('../models/ticketSnModel');
 const TicketGlpiModel = require('../models/ticketGlpiModel');
 const TicketUpdateModel = require('../models/ticketUpdateModel');
 const TicketSyncModel = require('../models/ticketSyncModel');
-const { logInfo, logError } = require('../utils/logger');
+const { logInfo, logError, logDebug } = require('../utils/logger');
 const { addWorkNoteToServiceNow, updateExternalTicketInServiceNow, queueExternalTicketLinkRetry, reassignTicketInServiceNow } = require('./servicenowService');
 const { stripHTML } = require('../utils/commentSanitizer');
 
@@ -11,11 +11,11 @@ const caoaTiGroupId = process.env.SERVICENOW_CAOA_TI_GROUP_ID;
 
 const syncTicketsToGlpi = async () => {
     try {
-        logInfo('🔄 Iniciando sincronização para GLPI...');
+        logDebug('🔄 Iniciando sincronização para GLPI...');
         const pendingTickets = await TicketSnModel.getPendingTickets();
 
         if (pendingTickets.length === 0) {
-            logInfo('✅ Nenhum ticket pendente para sincronizar');
+            logDebug('✅ Nenhum ticket pendente para sincronizar');
             return;
         }
 

src/services/servicenowService.js

@@ -3,7 +3,7 @@ const axios = require('axios');
 const apiConfig = require('../../config/apiConfig');
 const { stripHTML } = require('../utils/commentSanitizer');
 const TicketSnModel = require('../models/ticketSnModel');
-const { logInfo, logError, logSync } = require('../utils/logger'); 
+const { logInfo, logError, logSync, logDebug } = require('../utils/logger');
 const TicketUpdateModel = require('../models/ticketUpdateModel');
 const TicketSyncModel = require('../models/ticketSyncModel');
 
@@ -261,7 +261,7 @@ const existingCommentInServiceNow = async (ticketId, comment) => {
 const fetchCommentsFromServiceNow = async (ticket) => {
   try {
   
-    logInfo(`Iniciando busca de comentarios/worknotes do ServiceNow para o ticket SN Ticket: ${ticket.glpi_ticket_id}`);
+    logDebug(`Iniciando busca de comentarios/worknotes do ServiceNow para o ticket SN Ticket: ${ticket.glpi_ticket_id}`);
 
     const sys_id = ticket.sys_id;
     
@@ -281,7 +281,7 @@ const fetchCommentsFromServiceNow = async (ticket) => {
             sysparm_limit: pageSize,
             sysparm_offset: offset
         };
-        logInfo(`Buscando pagina ${page} de comentarios do ticket SN Ticket: ${ticket.glpi_ticket_id}`);
+        logDebug(`Buscando pagina ${page} de comentarios do ticket SN Ticket: ${ticket.glpi_ticket_id}`);
         const response = await axios.get(apiConfig.snTableJournalConfig.baseUrl, {
             auth: apiConfig.servicenowAuthentication.auth,
             params
@@ -338,11 +338,11 @@ const fetchCommentsFromServiceNow = async (ticket) => {
         return aTime - bTime;
     });
     if (orderedComments.length === 0) {
-        logInfo(`Nenhum comentario/worknote encontrado no Service Now para o ticket GLPI ID: ${ticket.glpi_ticket_id}`);
+        logDebug(`Nenhum comentario/worknote encontrado no Service Now para o ticket GLPI ID: ${ticket.glpi_ticket_id}`);
         return [];
     }
     
-    logInfo(`Encontrado ${orderedComments.length} atualizacoes (comments/work_notes) para o ticket SN Ticket: ${ticket.glpi_ticket_id}`)
+    logDebug(`Encontrado ${orderedComments.length} atualizacoes (comments/work_notes) para o ticket SN Ticket: ${ticket.glpi_ticket_id}`)
 
 
     const commentsInserted = [];
@@ -351,7 +351,7 @@ const fetchCommentsFromServiceNow = async (ticket) => {
         const existingComment = await TicketUpdateModel.getBySourceId(comment.sys_id);     
 
         if (existingComment) {
-            logInfo(`Comentario: ${comment.sys_id} ja existe no banco de dados`, { step: 3 });
+            logDebug(`Comentario: ${comment.sys_id} ja existe no banco de dados`, { step: 3 });
             continue;
         } else {
 

src/utils/commentSanitizer.js

@@ -1,4 +1,4 @@
-const { logInfo, logWarning } = require('./logger');
+const { logDebug, logWarning } = require('./logger');
 
 const stripHTML = (html) => {
     if (!html) return '';
@@ -76,7 +76,7 @@ const sanitizeGLPIComment = (commentObj) => {
     content = stripHTML(content);
     
     if (content !== commentObj.content) {
-        logInfo('🔧 Comentário sanitizado', {
+        logDebug('🔧 Comentário sanitizado', {
             original: commentObj.content.substring(0, 100) + '...',
             cleaned: content.substring(0, 100) + '...'
         });

src/utils/logger.js

@@ -94,9 +94,15 @@ const logWarning = (message, meta = {}) => {
     logger.warn(message, meta);
 };
 
-// Log de sincronização específico
+const logDebug = (message, meta = {}) => {
+    logger.debug(message, meta);
+};
+
+// Log de sincronização específico. Fica em debug: por causa da margem de seguranca do
+// watermark, esse log dispara toda vez que ha qualquer ticket "quente" no lote, mesmo sem
+// mudanca real de campo - o sinal de mudanca de verdade e logado no chamador.
 const logSync = (service, count, type) => {
-    logger.info(`SYNC: ${service} - ${count} ${type} sincronizados`, { 
+    logger.debug(`SYNC: ${service} - ${count} ${type} sincronizados`, {
         service,
         count,
         type
@@ -108,5 +114,6 @@ module.exports = {
     logError,
     logInfo,
     logWarning,
+    logDebug,
     logSync,
 };