Both our PTX routers are generating error logs in vast quantities. PTX2 has generated these logs for months, and PTX1 has recently started generating the same output.
Questions:
- Can you please clarify what these errors mean and what causes them?
- Are they indicative of a service-impacting issue? If so, what would be the consequences?
- How do we get rid of these errors?
Jun 16 11:26:03.644 2025 JTAC evo-aftmand-bt[18143]: [t:18316] [Error] Jexpr: Invalid counter ID is sent for Read userType:OVFM_L2D_OUT_CNTR counterId:6
Jun 16 11:26:03.645 2025 JTAC evo-aftmand-bt[18143]: [bt] #1 JexprOfMgrCntrFarm::read(unsigned int, unsigned long*, unsigned long*, unsigned long*, unsigned long*)+0x147
Jun 16 11:26:03.645 2025 JTAC evo-aftmand-bt[18143]: [bt] #2 JexprStatsOverflowMgrInst::read(CntrUserType, unsigned int, unsigned long*, unsigned long*, unsigned long*, unsigned long*)+0x7d
Jun 16 11:26:03.645 2025 JTAC evo-aftmand-bt[18143]: [bt] #3 JexprStatsOverflowManager::read(unsigned short, CntrUserType, unsigned int, unsigned long*, unsigned long*, unsigned long*, unsigned long*)+0xf7
Jun 16 11:26:03.645 2025 JTAC evo-aftmand-bt[18143]: [bt] #4 JexprHandleCounter::readInterfaceCounters(unsigned char, unsigned int const&, CntrUserType const&, unsigned long&, unsigned long&, unsigned long&, unsigned long&)+0x175
Jun 16 11:26:03.645 2025 JTAC evo-aftmand-bt[18143]: [bt] #5 JexprHandleCounter::read(unsigned long&, unsigned long&, unsigned long&, unsigned long&, CntrUserType) const+0x20f
Jun 16 11:26:03.645 2025 JTAC evo-aftmand-bt[18143]: [bt] #6 JexprHandleDualCounter::read(unsigned long&, unsigned long&, unsigned long&, unsigned long&, CntrUserType) const+0x2a
Jun 16 11:26:03.646 2025 JTAC evo-aftmand-bt[18143]: [bt] #7 EmExprCounter::info(std::unique_ptr > const&) const+0x19d
Jun 16 11:26:03.646 2025 JTAC evo-aftmand-bt[18143]: [bt] #8 EmTelemetryWatcherEntry::timerFired(std::weak_ptr)+0x6e0
Jun 16 11:26:03.646 2025 JTAC evo-aftmand-bt[18143]: [bt] #9 std::_Function_handler), std::_Bind))(std::weak_ptr)> >::_M_invoke(std::_Any_data const&, std::weak_ptr&&)+0x48
Jun 16 11:26:03.646 2025 JTAC evo-aftmand-bt[18143]: [bt] #10 AftTimer::execFunc(boost::system::error_code const&)+0xd9
Jun 16 11:26:03.646 2025 JTAC evo-aftmand-bt[18143]: [bt] #12 void boost::asio::detail::strand_service::dispatch, boost::system::error_code const&), boost::_bi::list2 >, boost::arg<1> (*)()> >, boost::system::error_code> >(boost::asio::detail::strand_service::strand_impl*&, boost::asio::detail::binder1, boost::system::error_code const&), boost::_bi::list2 >, boost::arg<1> (*)()> >, boost::system::error_code>&)+0x8a
Jun 16 11:26:03.647 2025 JTAC evo-aftmand-bt[18143]:
Jun 16 11:26:03.648 2025 JTAC evo-aftmand-bt[18143]: [bt] #14 boost::asio::detail::wait_handler, boost::system::error_code const&), boost::_bi::list2 >, boost::arg<1> (*)()> >, boost::asio::detail::is_continuation_if_running>, boost::asio::detail::io_object_executor >::do_complete(void*, boost::asio::detail::scheduler_operation*, boost::system::error_code const&, unsigned long)+0x54d
Jun 16 11:26:03.649 2025 JTAC evo-aftmand-bt[18143]: [bt] #15 boost::asio::detail::scheduler::run(boost::system::error_code&)+0x4eb
Jun 16 11:26:03.649 2025 JTAC evo-aftmand-bt[18143]: [t:18316] [Error] Jexpr: Bitmap: num_units=256 size=16384 utilized=0.0610352% Used=10 lastUnitIdx=0 mask=8000000000000000 BM_UNIT_SIZE=64 BM[ 0]= 0000000000000000000000000000000000000000000001110101111110000000 = 0x75f80 BM[64-16256]= 254 rows of empty bits BM[16320]= 0000000000000000000000000000000000000000000000000000000000000000 = 0x0
Jun 16 11:26:03.649 2025 JTAC evo-aftmand-bt[18143]: [t:18316] [Error] Jexpr: JexprStatsOverflowMgrInst: Read: Failed to read to counter userType:OVFM_L2D_OUT_CNTR cntrId:6 rc:Generic failure rcValue:1001
Jun 16 11:26:03.649 2025 JTAC evo-aftmand-bt[18143]: [t:18316] [Error] Jexpr: Overflow Manager: Read: Failed to read to counter pfeInst:1 userType:OVFM_L2D_OUT_CNTR cntrId:6 rc:Generic failure rcValue:1001
Jun 16 11:26:05.644 2025 JTAC evo-aftmand-bt[18143]: [t:18315] [Error] Jexpr: Invalid counter ID is sent for Read userType:OVFM_L2D_OUT_CNTR counterId:6
Jun 16 11:26:05.645 2025 JTAC evo-aftmand-bt[18143]: [bt] #1 JexprOfMgrCntrFarm::read(unsigned int, unsigned long*, unsigned long*, unsigned long*, unsigned long*)+0x147
Jun 16 11:26:05.645 2025 JTAC evo-aftmand-bt[18143]: [bt] #2 JexprStatsOverflowMgrInst::read(CntrUserType, unsigned int, unsigned long*, unsigned long*, unsigned long*, unsigned long*)+0x7d
Jun 16 11:26:05.645 2025 JTAC evo-aftmand-bt[18143]: [bt] #3 JexprStatsOverflowManager::read(unsigned short, CntrUserType, unsigned int, unsigned long*, unsigned long*, unsigned long*, unsigned long*)+0xf7
Jun 16 11:26:05.646 2025 JTAC evo-aftmand-bt[18143]: [bt] #4 JexprHandleCounter::readInterfaceCounters(unsigned char, unsigned int const&, CntrUserType const&, unsigned long&, unsigned long&, unsigned long&, unsigned long&)+0x175
Jun 16 11:26:05.646 2025 JTAC evo-aftmand-bt[18143]: [bt] #5 JexprHandleCounter::read(unsigned long&, unsigned long&, unsigned long&, unsigned long&, CntrUserType) const+0x20f
Jun 16 11:26:05.646 2025 JTAC evo-aftmand-bt[18143]: [bt] #6 JexprHandleDualCounter::read(unsigned long&, unsigned long&, unsigned long&, unsigned long&, CntrUserType) const+0x2a
Jun 16 11:26:05.646 2025 JTAC evo-aftmand-bt[18143]: [bt] #7 EmExprCounter::info(std::unique_ptr > const&) const+0x19d
Jun 16 11:26:05.646 2025 JTAC evo-aftmand-bt[18143]: [bt] #8 EmTelemetryWatcherEntry::timerFired(std::weak_ptr)+0x6e0
Jun 16 11:26:05.646 2025 JTAC evo-aftmand-bt[18143]: [bt] #9 std::_Function_handler), std::_Bind))(std::weak_ptr)> >::_M_invoke(std::_Any_data const&, std::weak_ptr&&)+0x48
Jun 16 11:26:05.646 2025 JTAC evo-aftmand-bt[18143]: [bt] #10 AftTimer::execFunc(boost::system::error_code const&)+0xd9
Jun 16 11:26:05.646 2025 JTAC evo-aftmand-bt[18143]: [bt] #11 /usr/lib64/libaftutils.so.0
Jun 16 11:26:05.646 2025 JTAC evo-aftmand-bt[18143]: [bt] #12 void boost::asio::detail::strand_service::dispatch, boost::system::error_code const&), boost::_bi::list2 >, boost::arg<1> (*)()> >, boost::system::error_code> >(boost::asio::detail::strand_service::strand_impl*&, boost::asio::detail::binder1, boost::system::error_code const&), boost::_bi::list2 >, boost::arg<1> (*)()> >, boost::system::error_code>&)+0x8a
Jun 16 11:26:05.647 2025 JTAC evo-aftmand-bt[18143]:
Jun 16 11:26:05.648 2025 JTAC evo-aftmand-bt[18143]: [bt] #14 boost::asio::detail::wait_handler, boost::system::error_code const&), boost::_bi::list2 >, boost::arg<1> (*)()> >, boost::asio::detail::is_continuation_if_running>, boost::asio::detail::io_object_executor >::do_complete(void*, boost::asio::detail::scheduler_operation*, boost::system::error_code const&, unsigned long)+0x54d
Jun 16 11:26:05.649 2025 JTAC evo-aftmand-bt[18143]: [bt] #15 boost::asio::detail::scheduler::run(boost::system::error_code&)+0x4eb
Jun 16 11:26:05.649 2025 JTAC evo-aftmand-bt[18143]: [t:18315] [Error] Jexpr: Bitmap: num_units=256 size=16384 utilized=0.0610352% Used=10 lastUnitIdx=0 mask=8000000000000000 BM_UNIT_SIZE=64 BM[ 0]= 0000000000000000000000000000000000000000000001110101111110000000 = 0x75f80 BM[64-16256]= 254 rows of empty bits BM[16320]= 0000000000000000000000000000000000000000000000000000000000000000 = 0x0
Jun 16 11:26:05.649 2025 JTAC evo-aftmand-bt[18143]: [t:18315] [Error] Jexpr: JexprStatsOverflowMgrInst: Read: Failed to read to counter userType:OVFM_L2D_OUT_CNTR cntrId:6 rc:Generic failure rcValue:1001
Jun 16 11:26:05.649 2025 JTAC evo-aftmand-bt[18143]: [t:18315] [Error] Jexpr: Overflow Manager: Read: Failed to read to counter pfeInst:1 userType:OVFM_L2D_OUT_CNTR cntrId:6 rc:Generic failure rcValue:1001
This issue has to do with statistics logic for service provider layer2 IFL's & issue is specific to base L2.
The overflow stats manager keeps a bitmask of the IFL l2d's to fetch from the ASIC and background thread in EM periodically calls read from this module to fetch IFL stats. The error indicates that the index for which the stats is being read is not set in the bitmask for the overflow stats manager.
Issue will be seen if the config has l2 IFLs defined.
This is fixed via internal PR1839972
RCA:
AE counter handle was not being intialised from the 2nd child onwards on a PFE (i.e. for cases when L2d was not alloced). This resulted in detachL2IflCounter not being called if the order of child removal was not the same as addition.
Resolved-In:
evo:24.4R1-EVO evo:24.4R2-EVO evo:25.1R1-EVO