Oinker logs may be reported by an FPC carrying subscribers.
Routing-engine CPU typically is not high (such as 78% idle, which is 22% utilized), but the FPC CPU utilization was above 80%, spiking to 95 or 100% occasionally.
Logs similar to these might be seen:
Feb 11 20:02:04 MX960_RE0 fpc5 Oinker: Function Packet Transfer Periodic (0x10cd4000) took 220 us Feb 11 20:33:05 MX960_RE0 fpc5 Oinker: Function Packet Transfer Periodic (0x10cd4000) took 337 us Feb 11 20:35:34 MX960_RE0 fpc5 Oinker: Function MPC (0x1005ebfc) took 204 us Feb 11 20:36:34 MX960_RE0 fpc5 Oinker: Function Packet Transfer Periodic (0x10cd4000) took 437 us Feb 11 20:50:48 MX960_RE0 fpc5 Oinker: Function Syslog (0x100925f8) took 415 us
Feb 11 20:02:04 MX960_RE0 fpc5 Oinker: Function Packet Transfer Periodic (0x10cd4000) took 220 us Feb 11 20:33:05 MX960_RE0 fpc5 Oinker: Function Packet Transfer Periodic (0x10cd4000) took 337 us Feb 11 20:35:34 MX960_RE0 fpc5 Oinker: Function MPC (0x1005ebfc) took 204 us Feb 11 20:36:34 MX960_RE0 fpc5 Oinker: Function Packet Transfer Periodic (0x10cd4000) took 437 us
Feb 11 20:50:48 MX960_RE0 fpc5 Oinker: Function Syslog (0x100925f8) took 415 us
Oinker logs are Emergency level, so they may print to the router Admin's ssh or telnet session if any logs are configured to print to the router admin's ssh and telnet sessions. That configuration area is "system syslog user *". For example, with the following config, Oinker logs will be printed to a router admin's ssh session:
labuser@MX960_RE0# show system syslog user * | display set set system syslog user * any emergency
Packet Transfer Periodic is a function that checks the health of the Packet Transfer Engine periodically by ensuring that it has not undergone any wedge. Oinker is a check that is introduced to ensure that the periodic functions are executed quickly, this time is set at 200usec. If the CPU spends greater than 200usec, then a message is logged in the messages indicating the same. These logs may not be a root cause; they can be a symptom of high resource utilization on an FPC, such as high CPU.
Check " show chassis fpc " to see if the FPC reporting these logs has high CPU, such as the 84% CPU below:
show chassis fpc
labuser@MX960_RE0> show chassis fpc 5 Temp CPU Utilization (%) CPU Utilization (%) Memory Utilization (%) Slot State (C) Total Interrupt 1min 5min 15min DRAM (MB) Heap Buffer 5 Online 54 84 55 84 84 84 3584 9 25
This type of output can assist in determining if the Oinker logs correlate with a DDOS violation. Below, we see a DDOS_PROTOCOL_VIOLATION_SET log for protocol/exception ARP:aggregate shortly before the Oinker logs starts. There were no Oinker logs that day prior to the DDOS violation.
labuser@MX960_RE0> show log messages | match "DDOS|Oinker" | match "fpc5|fpc 5" | find "Feb 11" Feb 11 19:51:38 MX960_RE0 jddosd[5127]: DDOS_PROTOCOL_VIOLATION_SET: Warning: Host-bound traffic for protocol/exception ARP:aggregate exceeded its allowed bandwidth at fpc 5 for 1 times, started at 2019-02-11 19:51:36 UTC Feb 11 20:02:04 MX960_RE0 fpc5 Oinker: Function Packet Transfer Periodic (0x10cd4000) took 220 us Feb 11 20:33:05 MX960_RE0 fpc5 Oinker: Function Packet Transfer Periodic (0x10cd4000) took 337 us Feb 11 20:35:34 MX960_RE0 fpc5 Oinker: Function MPC (0x1005ebfc) took 204 us
In this example, the subscriber's subinterface was disabled. Then the FPC5 CPU dropped to between 22% and 32% utilization, and the Oinker logs stopped.
labuser@MX960_RE0> show chassis fpc 5 Temp CPU Utilization (%) CPU Utilization (%) Memory Utilization (%) Slot State (C) Total Interrupt 1min 5min 15min DRAM (MB) Heap Buffer 5 Online 55 22 1 21 22 22 3584 9 25
Please contact your JTAC representative for assistance to determine which subscriber subinterface may be causing the ARP flood. The subscriber's subinterface can be disabled until the issue can be corrected on the subscriber's CPE (Customer Permises Equipment).
show ddos-protection protocols arp
2020-06-02: Added explanation for the terms, "Packet Transfer Periodic" and "Oinker" in the Cause section.