diff --git a/src/fiberhome/manager.js b/src/fiberhome/manager.js index 91ad5af..13062f1 100644 --- a/src/fiberhome/manager.js +++ b/src/fiberhome/manager.js @@ -223,20 +223,21 @@ class FiberhomeManager { }); // Verificar se a resposta está completa (formato Fiberhome) - if ((dataBuffer.includes('COMPLD') || - dataBuffer.includes('M COMPLD') || - dataBuffer.includes('DENY') || - dataBuffer.includes(';')) && !responseReceived) { + // + // IMPORTANTE: respostas com muitas ONUs são enviadas em múltiplos blocos: + // bloco 1 → termina com ">" (mais dados a seguir), contém COMPLD + // bloco 2 → termina com ";" (fim real), também contém COMPLD + // Resolver apenas no ";" garante que todos os blocos foram recebidos. + // Resolver no primeiro COMPLD causaria leitura prematura, deixando os + // blocos restantes no buffer TCP para a próxima chamada consumir por engano. + const terminadorFinal = dataBuffer.includes(';'); + const deny = dataBuffer.includes('DENY'); + + if ((terminadorFinal || deny) && !responseReceived) { responseReceived = true; this.tl1Connection.removeListener('data', dataHandler); - if (dataBuffer.includes('COMPLD') || dataBuffer.includes('M COMPLD')) { - this.logger.debug('Comando TL1 executado com sucesso'); - resolve({ - success: true, - data: dataBuffer - }); - } else if (dataBuffer.includes('DENY')) { + if (deny) { this.logger.warn('Comando TL1 negado pelo equipamento'); resolve({ success: false, @@ -244,10 +245,10 @@ class FiberhomeManager { data: dataBuffer }); } else { - this.logger.debug('Resposta TL1 válida recebida'); + this.logger.debug('Comando TL1 executado com sucesso'); resolve({ success: true, - data: dataBuffer // Aceitar resposta válida + data: dataBuffer }); } } @@ -258,13 +259,13 @@ class FiberhomeManager { // Enviar comando TL1 formato Fiberhome this.tl1Connection.write(comando + '\r\n'); - // Timeout para resposta + // Timeout para resposta (aumentado para suportar respostas multi-bloco) setTimeout(() => { if (!responseReceived) { this.tl1Connection.removeListener('data', dataHandler); reject(new Error('Timeout aguardando resposta TL1')); } - }, 15000); + }, 30000); }); } catch (error) { @@ -393,13 +394,22 @@ class FiberhomeManager { `LST-ONULANINFO::OLTID=${oltId},PONID=${ponEncontrada},ONUIDTYPE=ONU_NUMBER,ONUID=${numeroONU},ONUPORT=NA-NA-NA-1:CTAG::;` ]; - this.logger.debug('Executando comandos TL1 detalhados:', comandosDetalhados); + this.logger.debug('Executando comandos TL1 detalhados (sequencial):', comandosDetalhados); - const [resultadoEstado, resultadoDDM, resultadoLAN] = await Promise.all([ - this.executarComandoTL1(comandosDetalhados[0]), - this.executarComandoTL1(comandosDetalhados[1]), - this.executarComandoTL1(comandosDetalhados[2]) - ]); + // IMPORTANTE: o socket TL1 é compartilhado — Promise.all faz os três handlers + // ouvirem o mesmo buffer e todos resolvem com o primeiro ';' recebido. + // Por isso os comandos DEVEM ser executados sequencialmente. + console.log('[TL1-DIAG] Iniciando sequência LST-ONUSTATE...'); + const resultadoEstado = await this.executarComandoTL1(comandosDetalhados[0]); + console.log(`[TL1-DIAG] LST-ONUSTATE concluído: success=${resultadoEstado.success}`); + + console.log('[TL1-DIAG] Iniciando sequência LST-OMDDM...'); + const resultadoDDM = await this.executarComandoTL1(comandosDetalhados[1]); + console.log(`[TL1-DIAG] LST-OMDDM concluído: success=${resultadoDDM.success}`); + + console.log('[TL1-DIAG] Iniciando sequência LST-ONULANINFO...'); + const resultadoLAN = await this.executarComandoTL1(comandosDetalhados[2]); + console.log(`[TL1-DIAG] LST-ONULANINFO concluído: success=${resultadoLAN.success}`); // Adicionar dados coletados onuEncontrada.estadoGeral = resultadoEstado.success ? resultadoEstado.data : null; @@ -640,11 +650,24 @@ class FiberhomeManager { this.logger.debug('Processando respostas dos comandos TL1 detalhados'); for (const resposta of dadosONU.detalhados) { + // ── DIAGNÓSTICO TL1 (sempre visível no console) ────────────────── + const _cmdLabel = resposta?.comando?.split('::')[0] || '???'; + console.log(`\n[TL1-DIAG] ════ ${_cmdLabel} ════`); + console.log(`[TL1-DIAG] success: ${resposta?.success}`); + if (resposta?.response) { + // Log da resposta completa, linha por linha, para facilitar análise + console.log('[TL1-DIAG] resposta completa:'); + resposta.response.replace(/\r/g, '').split('\n').forEach((l, i) => { + console.log(`[TL1-DIAG] L${String(i).padStart(2,'0')}: ${JSON.stringify(l)}`); + }); + } else { + console.log('[TL1-DIAG] (sem resposta/data)'); + } + // ───────────────────────────────────────────────────────────────── + // Pular respostas com DENY ou sem dados if (!resposta || !resposta.response || resposta.success === false) { - if (resposta && !resposta.success) { - this.logger.warn(`⚠️ Comando retornou DENY: ${resposta.comando}`); - } + console.log(`[TL1-DIAG] ⚠️ PULANDO: success=false (DENY ou erro) para ${_cmdLabel}`); continue; } @@ -663,15 +686,14 @@ class FiberhomeManager { // Processar LST-OMDDM (potência ótica) // Resposta: ONUID RxPower RxPowerR TxPower TxPowerR CurrTxBias ... if (resposta.comando && resposta.comando.includes('LST-OMDDM')) { - this.logger.debug('LST-OMDDM raw:', dados.substring(0, 500)); - // Normalizar CRLF e dividir em linhas const linhas = dados.replace(/\r/g, '').split('\n'); - // Encontrar header: linha que contém 'ONUID' (pode não ter 'RxPower' se quebrou) + // Encontrar header: linha que contém 'ONUID' e 'RxPower' ou 'TxPower' const headerIndex = linhas.findIndex(l => /\bONUID\b/i.test(l) && (/\bRxPower\b/i.test(l) || /\bTxPower\b/i.test(l)) ); + console.log(`[TL1-DIAG] OMDDM headerIndex=${headerIndex}, totalLinhas=${linhas.length}`); if (headerIndex !== -1) { // Encontrar linha de dados (após header — tem pelo menos um número decimal) @@ -681,50 +703,53 @@ class FiberhomeManager { !/COMPLD|total_blocks|block_number|FH_/i.test(l) && /[+-]?\d+[,.]\d+/.test(l) ); + console.log(`[TL1-DIAG] OMDDM linhaDados: ${JSON.stringify(linhaDados)}`); if (linhaDados) { - // Usar split por qualquer whitespace (suporta tanto tab quanto espaço simples/múltiplo) const headers = linhas[headerIndex].trim().split(/\s+/); const valores = linhaDados.trim().split(/\s+/); - this.logger.debug(`📊 LST-OMDDM headers (${headers.length}): [${headers.join('][')}]`); - this.logger.debug(`📊 LST-OMDDM valores (${valores.length}): [${valores.join('][')}]`); + console.log(`[TL1-DIAG] OMDDM headers(${headers.length}): [${headers.join('][')}]`); + console.log(`[TL1-DIAG] OMDDM valores(${valores.length}): [${valores.join('][')}]`); const colIdx = (name) => headers.findIndex(h => h.toLowerCase() === name.toLowerCase()); const rxIdx = colIdx('RxPower'); const txIdx = colIdx('TxPower'); + console.log(`[TL1-DIAG] OMDDM rxIdx=${rxIdx} txIdx=${txIdx}`); // Nota: no TL1 FiberHome, RxPower = sinal que a OLT recebe (= TX da ONU) // TxPower = sinal que a OLT envia (= RX da ONU) // Posições fixas de fallback: ONUID=0, RxPower=1, TxPower=3 const oltRxRaw = (rxIdx >= 0 ? valores[rxIdx] : valores[1])?.replace(',', '.'); const oltTxRaw = (txIdx >= 0 ? valores[txIdx] : valores[3])?.replace(',', '.'); + console.log(`[TL1-DIAG] OMDDM oltRxRaw=${oltRxRaw} oltTxRaw=${oltTxRaw}`); const COMP_RX = 2.7; const COMP_TX = -2.7; if (oltRxRaw && oltRxRaw !== '--' && !isNaN(parseFloat(oltRxRaw))) { resultado.txPower = `${(parseFloat(oltRxRaw) + COMP_RX).toFixed(2)} dBm`; - this.logger.info(`✅ TxPower ONU ← OLT RxPower ${oltRxRaw} → ${resultado.txPower}`); + console.log(`[TL1-DIAG] ✅ TxPower ONU ← OLT RxPower ${oltRxRaw} → ${resultado.txPower}`); } if (oltTxRaw && oltTxRaw !== '--' && !isNaN(parseFloat(oltTxRaw))) { resultado.rxPower = `${(parseFloat(oltTxRaw) + COMP_TX).toFixed(2)} dBm`; - this.logger.info(`✅ RxPower ONU ← OLT TxPower ${oltTxRaw} → ${resultado.rxPower}`); + console.log(`[TL1-DIAG] ✅ RxPower ONU ← OLT TxPower ${oltTxRaw} → ${resultado.rxPower}`); } } else { - this.logger.warn('⚠️ LST-OMDDM: header encontrado mas sem linha de dados numéricos'); - this.logger.debug('LST-OMDDM linhas:', linhas.slice(headerIndex, headerIndex + 5).join(' | ')); + console.log('[TL1-DIAG] ⚠️ OMDDM: header encontrado mas nenhuma linha com número decimal após ele'); + linhas.slice(headerIndex, headerIndex + 6).forEach((l, i) => + console.log(`[TL1-DIAG] pós-header L${i}: ${JSON.stringify(l)}`) + ); } } else { // Header não encontrado — regex direto no buffer como último recurso - this.logger.warn('⚠️ LST-OMDDM: header ONUID não encontrado, tentando regex'); - this.logger.debug('LST-OMDDM resposta completa:', dados); - // Procurar primeiro número negativo após "COMPLD" = RxPower + console.log('[TL1-DIAG] ⚠️ OMDDM: header ONUID+RxPower não encontrado, tentando regex'); const rxDireto = dados.match(/(-\d+\.\d+)/); if (rxDireto) { - // Sem contexto de coluna: assume que é OLT RxPower (=TX da ONU) const v = parseFloat(rxDireto[1]) + 2.7; resultado.txPower = `${v.toFixed(2)} dBm`; - this.logger.info(`✅ TxPower ONU via regex último recurso → ${resultado.txPower}`); + console.log(`[TL1-DIAG] TxPower ONU via regex último recurso → ${resultado.txPower}`); + } else { + console.log('[TL1-DIAG] ⚠️ OMDDM: regex também falhou, rxPower permanece N/A'); } } } @@ -732,16 +757,15 @@ class FiberhomeManager { // Processar LST-ONULANINFO (porta ethernet) // Resposta: AdminStatus OperStatus DUPLEX PVID VLANPRIORITY SPEED if (resposta.comando && resposta.comando.includes('LST-ONULANINFO')) { - this.logger.debug('LST-ONULANINFO raw:', dados.substring(0, 400)); const linhasLan = dados.replace(/\r/g, '').split('\n'); // Localizar header: contém AdminStatus ou OperStatus const headerLanIdx = linhasLan.findIndex(l => /AdminStatus/i.test(l) || /OperStatus/i.test(l) ); + console.log(`[TL1-DIAG] LAN headerLanIdx=${headerLanIdx}, totalLinhas=${linhasLan.length}`); if (headerLanIdx !== -1) { - // Usar split por qualquer whitespace (suporta espaço simples e múltiplo) const headers = linhasLan[headerLanIdx].trim().split(/\s+/); // Linha de dados: próxima linha não-vazia que contenha UP ou DOWN const linhaDados = linhasLan.slice(headerLanIdx + 1).find(l => @@ -750,21 +774,24 @@ class FiberhomeManager { !/COMPLD|total_blocks|block_number/i.test(l) && /\b(UP|DOWN|DISABLE|ENABLE)\b/i.test(l) ); + console.log(`[TL1-DIAG] LAN linhaDados: ${JSON.stringify(linhaDados)}`); if (linhaDados) { const valores = linhaDados.trim().split(/\s+/); const hLower = headers.map(h => h.toLowerCase()); - this.logger.debug(`📊 LAN headers (${headers.length}): [${headers.join('][')}]`); - this.logger.debug(`📊 LAN valores (${valores.length}): [${valores.join('][')}]`); + console.log(`[TL1-DIAG] LAN headers(${headers.length}): [${headers.join('][')}]`); + console.log(`[TL1-DIAG] LAN valores(${valores.length}): [${valores.join('][')}]`); const idxOper = hLower.findIndex(h => h === 'operstatus'); const idxSpeed = hLower.findIndex(h => h === 'speed'); const idxDuplex= hLower.findIndex(h => h === 'duplex'); + console.log(`[TL1-DIAG] LAN idxOper=${idxOper} idxSpeed=${idxSpeed} idxDuplex=${idxDuplex}`); // Fallback posições: AdminStatus=0, OperStatus=1, Duplex=2, PVID=3, VLANPRI=4, Speed=5 const operVal = idxOper >= 0 ? valores[idxOper] : valores[1]; const speedVal = idxSpeed >= 0 ? valores[idxSpeed] : valores[5]; const duplexVal= idxDuplex>= 0 ? valores[idxDuplex]: valores[2]; + console.log(`[TL1-DIAG] LAN operVal=${operVal} speedVal=${speedVal} duplexVal=${duplexVal}`); const isUp = /^up$/i.test(operVal); const speedClean = speedVal && !/^(--|auto)$/i.test(speedVal) ? speedVal : null; @@ -779,17 +806,19 @@ class FiberhomeManager { status: isUp ? 'active' : 'inactive', speed: speedLabel }; - this.logger.info(`✅ Porta LAN 1: ${isUp ? 'UP' : 'DOWN'} ${speedLabel || ''}`); + console.log(`[TL1-DIAG] ✅ Porta LAN 1: ${isUp ? 'UP' : 'DOWN'} speed=${speedLabel}`); } else { - this.logger.warn('⚠️ LST-ONULANINFO: header encontrado mas sem linha de dados (UP/DOWN)'); - this.logger.debug('LAN linhas após header:', linhasLan.slice(headerLanIdx, headerLanIdx + 5)); + console.log('[TL1-DIAG] ⚠️ LAN: header encontrado mas nenhuma linha com UP/DOWN após ele'); + linhasLan.slice(headerLanIdx, headerLanIdx + 6).forEach((l, i) => + console.log(`[TL1-DIAG] pós-header L${i}: ${JSON.stringify(l)}`) + ); } } else { // Fallback: detectar UP/DOWN em qualquer lugar da resposta - this.logger.warn('⚠️ LST-ONULANINFO: header AdminStatus/OperStatus não encontrado, usando fallback'); - this.logger.debug('LAN resposta completa:', dados); + console.log('[TL1-DIAG] ⚠️ LAN: header AdminStatus/OperStatus não encontrado, usando fallback'); const upMatch = /\bUP\b/.test(dados); const downMatch = /\bDOWN\b/i.test(dados); + console.log(`[TL1-DIAG] LAN fallback: upMatch=${upMatch} downMatch=${downMatch}`); if (upMatch || downMatch) { const speedMatch = dados.match(/\b(\d+[MG])\b/i); resultado.portasEthernet[0] = { @@ -797,6 +826,7 @@ class FiberhomeManager { status: upMatch ? 'active' : 'inactive', speed: speedMatch ? speedMatch[1] : null }; + console.log(`[TL1-DIAG] LAN via fallback: ${upMatch ? 'UP' : 'DOWN'} speed=${speedMatch?.[1]}`); } } }