Junos OS

Hello community,

I have a strange behavior regarding a MACSec connection between an EX4300 and an EX3400

We get a ton of Syslog messages from the EX3400 with the following message:

{master:0}
root@vx-sw-b7-01> show log messages | last 10
Jul 3 07:57:24 vx-sw-b7-01 dc-pfe: BMACSEC Error: API bmacsec_event_handler((int)macsec_addr) at bcm_macsec_event_handler:562 -> Invalid parameter
Jul 3 07:57:24 vx-sw-b7-01 fpc0 BMACSEC Error: API bmacsec_event_handler((int)macsec_addr) at bcm_macsec_event_handler:562 -> Invalid parameter
Jul 3 07:57:30 vx-sw-b7-01 dc-pfe: BMACSEC Error: API bmacsec_event_handler((int)macsec_addr) at bcm_macsec_event_handler:562 -> Invalid parameter
Jul 3 07:57:30 vx-sw-b7-01 fpc0 BMACSEC Error: API bmacsec_event_handler((int)macsec_addr) at bcm_macsec_event_handler:562 -> Invalid parameter
Jul 3 07:57:36 vx-sw-b7-01 dc-pfe: BMACSEC Error: API bmacsec_event_handler((int)macsec_addr) at bcm_macsec_event_handler:562 -> Invalid parameter
Jul 3 07:57:36 vx-sw-b7-01 fpc0 BMACSEC Error: API bmacsec_event_handler((int)macsec_addr) at bcm_macsec_event_handler:562 -> Invalid parameter
Jul 3 07:57:42 vx-sw-b7-01 dc-pfe: BMACSEC Error: API bmacsec_event_handler((int)macsec_addr) at bcm_macsec_event_handler:562 -> Invalid parameter
Jul 3 07:57:42 vx-sw-b7-01 fpc0 BMACSEC Error: API bmacsec_event_handler((int)macsec_addr) at bcm_macsec_event_handler:562 -> Invalid parameter
Jul 3 07:57:48 vx-sw-b7-01 dc-pfe: BMACSEC Error: API bmacsec_event_handler((int)macsec_addr) at bcm_macsec_event_handler:562 -> Invalid parameter
Jul 3 07:57:48 vx-sw-b7-01 fpc0 BMACSEC Error: API bmacsec_event_handler((int)macsec_addr) at bcm_macsec_event_handler:562 -> Invalid parameter

I am not able to find any informations regarding that error.

There are no error messages regarding MACSec on the EX4300.

Some additional informations:

EX3400:

{master:0}
root@vx-sw-b7-01> show security macsec connections
Interface name: ge-0/0/0
CA name: b6
Cipher suite: GCM-AES-128 Encryption: on
Key server offset: 0 Include SCI: yes
Replay protect: off Replay window: 0
Outbound secure channels
SC Id: B8:C2:53:EF:6F:CB/1
Outgoing packet number: 533673428
Secure associations
AN: 2 Status: inuse Create time: 00:00:00
Inbound secure channels
SC Id: CC:E1:94:29:36:83/1
Secure associations
AN: 2 Status: inuse Create time: 00:00:00

I see, that the time is at 00:00:00 everytime I refresh.

security {
macsec {
connectivity-association b6 {
security-mode static-cak;
include-sci;
pre-shared-key {
ckn XXXXXXX;
cak "XXXXXXXXX"; ## SECRET-DATA
}
}
interfaces {
ge-0/0/0 {
connectivity-association b6;
}
}
}
}

EX4300:

{master:0}
root@vx-core-b6-01> show security macsec connections
Interface name: ge-4/0/0
CA name: b7
Cipher suite: GCM-AES-128 Encryption: on
Key server offset: 0 Include SCI: yes
Replay protect: off Replay window: 0
Outbound secure channels
SC Id: CC:E1:94:29:36:83/1
Outgoing packet number: 2875638813
Secure associations
AN: 2 Status: inuse Create time: 5d 22:48:39
Inbound secure channels
SC Id: B8:C2:53:EF:6F:CB/1
Secure associations
AN: 2 Status: inuse Create time: 5d 22:48:39

security {
macsec {
connectivity-association b7 {
security-mode static-cak;
mka {
key-server-priority 1;
}
pre-shared-key {
ckn XXXXX;
cak "XXXXX"; ## SECRET-DATA
}
}
ge-4/0/0 {
connectivity-association b7;
}
}
}

It still looks like the connection between the EX3400 and EX4300 is encrypted, but can someone clarify what that error means and why it is occuring so frequent? 

Thank you,

Julian_V

Hi Julian,

What is the Junos version on the EX.

What I read in internal cases are that these messages are generated due to additional debugging enabled in Junos starting from 18.2. What is your code version.

Hence, these messages are informational and can be ignored or filtered.

Note:- You may follow KB22177 for filtering the said message.

Regards,

Rahul

#Juniper_CFTS

Hey Rahul,

thank you for your answer!

Currently both devices are running JunOS 18.3R1.

But I only get these messages from the EX3400, but not from the EX4300.

This is the syslog configuration from the devices:

EX3400:

root@vx-sw-b7-01# show system syslog
host 192.168.1.100 {
authorization error;
daemon error;
ftp none;
security error;
kernel error;
user none;
dfc error;
external error;
firewall none;
pfe error;
conflict-log error;
change-log error;
interactive-commands none;
source-address 192.168.7.40;
}
file messages {
any error;
authorization info;
}
file interactive-commands {
interactive-commands error;
}

EX4300:

xvee@vx-core-b6-01# show system syslog
host 192.168.1.100 {
authorization error;
daemon error;
ftp none;
security error;
kernel error;
user none;
dfc error;
external error;
firewall none;
pfe error;
conflict-log error;
change-log any;
interactive-commands none;
source-address 192.168.1.1;
}
file messages {
any notice;
authorization info;
}
file interactive-commands {
interactive-commands any;
}

This is the exact Syslog message from our Graylog:

facility

level

message

source

timestamp

Do you have some additional informations for me? For example why the "Status: inuse Create time" is on 00:00:00 on the EX3400, but not on the EX4300? Or why the log level is on warning and not on informational?

Thank you,

Julian_V

Hi Julian,

QUE:- why the "Status: inuse Create time" is on 00:00:00 on the EX3400, but not on the EX4300?

:- This is strange, "in use" shows that the associations is thr and both inbound and outbound associations is visible.

Did you check if you had any flaps omn teh said interface and after that macsec went to a stuck time state ??

ANy knowhow of when it went into the said state?

QUE:- Or why the log level is on warning and not on informational?
J:- This is a debug log and hence a warning, but as per cases reported and response from engineering the same can be listed as informational and can be ignored. Junos logging wont explicitly log it as informational.

-RAhul

Hey Rahul, 

thank you for your answers.

1)

root@vx-sw-b7-01> show interfaces ge-0/0/0
Physical interface: ge-0/0/0, Enabled, Physical link is Up
Interface index: 648, SNMP ifIndex: 514
Description: MacSec Trunk zu VC
Link-level type: Ethernet, MTU: 1514, LAN-PHY mode, Link-mode: Full-duplex, Speed: Auto, BPDU Error: None,
Loop Detect PDU Error: None, Ethernet-Switching Error: None, MAC-REWRITE Error: None, Loopback: Disabled,
Source filtering: Disabled, Flow control: Disabled, Auto-negotiation: Enabled, Remote fault: Online,
Media type: Copper, IEEE 802.3az Energy Efficient Ethernet: Disabled, Auto-MDIX: Enabled
Device flags : Present Running
Interface flags: SNMP-Traps Internal: 0x4000
Link flags : None
CoS queues : 12 supported, 12 maximum usable queues
Current address: b8:c2:53:ef:6f:cb, Hardware address: b8:c2:53:ef:6f:cb
Last flapped : 1970-01-01 02:39:45 UTC (2583w0d 03:27 ago)
Input rate : 4234936 bps (914 pps)
Output rate : 12690648 bps (1207 pps)
Active alarms : None
Active defects : None
PCS statistics Seconds
Bit errors 0
Errored blocks 0
Ethernet FEC statistics Errors
FEC Corrected Errors 0
FEC Uncorrected Errors 0
FEC Corrected Errors Rate 0
FEC Uncorrected Errors Rate 0
PRBS Statistics : Disabled
Interface transmit statistics: Disabled

Logical interface ge-0/0/0.0 (Index 555) (SNMP ifIndex 555)
Flags: Up SNMP-Traps 0x24024000 Encapsulation: Ethernet-Bridge
Input packets : 6682657
Output packets: 2278226
Protocol eth-switch, MTU: 1514
Flags: Is-Primary, Trunk-Mode

I Think the "Last flapped" time is wrong. The interface was simply up, before the switch got his time from our ntp server. I flapped the Interface manually and this is the output now:

root@vx-sw-b7-01> show interfaces ge-0/0/0
Physical interface: ge-0/0/0, Enabled, Physical link is Up
Interface index: 648, SNMP ifIndex: 514
Description: MacSec Trunk zu VC
Link-level type: Ethernet, MTU: 1514, LAN-PHY mode, Link-mode: Full-duplex, Speed: Auto, BPDU Error: None,
Loop Detect PDU Error: None, Ethernet-Switching Error: None, MAC-REWRITE Error: None, Loopback: Disabled,
Source filtering: Disabled, Flow control: Disabled, Auto-negotiation: Enabled, Remote fault: Online,
Media type: Copper, IEEE 802.3az Energy Efficient Ethernet: Disabled, Auto-MDIX: Enabled
Device flags : Present Running
Interface flags: SNMP-Traps Internal: 0x4000
Link flags : None
CoS queues : 12 supported, 12 maximum usable queues
Current address: b8:c2:53:ef:6f:cb, Hardware address: b8:c2:53:ef:6f:cb
Last flapped : 2019-07-04 06:40:15 UTC (00:19:25 ago)
Input rate : 5228232 bps (2551 pps)
Output rate : 9539160 bps (941 pps)
Active alarms : None
Active defects : None
PCS statistics Seconds
Bit errors 0
Errored blocks 0
Ethernet FEC statistics Errors
FEC Corrected Errors 0
FEC Uncorrected Errors 0
FEC Corrected Errors Rate 0
FEC Uncorrected Errors Rate 0
PRBS Statistics : Disabled
Interface transmit statistics: Disabled

Logical interface ge-0/0/0.0 (Index 555) (SNMP ifIndex 555)
Flags: Up SNMP-Traps 0x24024000 Encapsulation: Ethernet-Bridge
Input packets : 6692511
Output packets: 2281164
Protocol eth-switch, MTU: 1514
Flags: Is-Primary, Trunk-Mode

But still, the "Status: inuse Create time" is on 00:00:00 after I disabled the interface and enabled it again:

root@vx-sw-b7-01> show security macsec connections
Interface name: ge-0/0/0
CA name: b6
Cipher suite: GCM-AES-128 Encryption: on
Key server offset: 0 Include SCI: yes
Replay protect: off Replay window: 0
Outbound secure channels
SC Id: B8:C2:53:EF:6F:CB/1
Outgoing packet number: 1040013
Secure associations
AN: 3 Status: inuse Create time: 00:00:00
Inbound secure channels
SC Id: CC:E1:94:29:36:83/1
Secure associations
AN: 3 Status: inuse Create time: 00:00:00

Strange behaviour.

2)

So you are telling me, that this is common behaviour to throw like 300 debug messages per minute? Is there something official, like a KB or anything? Dont get me wrong, I simply want to be sure that everything is allright with our encrypted connection and our data is safe.

The strange thing is simply, that on our EX4300 everything is fine. No syslog messages and  "Status: inuse Create time" has a fitting time.

Thank you for your time Rahul,

Julian_V

Hi Julian,

Firstly, We do not have a Kb written for the said log while I am writing this post. [I will make sure we write one and update this forum post].

Secondly, Regarding the create time stuck at 0:0, I believe the NTP not sync and the time stuck back to Epoc(1970) is the cause of the stuck "create time". Interface flap might not recover the stuck macsec timer.

I propose to reboot the EX3400 to revert the stuck timer for the macsec timer.  If that is not the possibility I suggest open a JTAC case to get a recovery without reboot.

Regards,

Rahul

As Agreed:-

Please find the KB:- https://kb.juniper.net/kb34795

Hello

The error messages is seen due to the EX3400 chipset and the junos code. That is why you only see it on ex3400 and not on ex4300. These are generated due to the additional debugging capabilities added in the code and can be safely ignored. You can filter the logs messages with the following kb

https://kb.juniper.net/InfoCenter/index?page=content&id=KB9382

Thanks