Tool/software:
During long term tests with multiple Ethernet/IP devices, we detected a sporadic communication interruption. In case of the issue, wireshark showed that the PLC was sending the EIP-Frames, but the affected device had stopped sending frames (switch functionality was still working). After timeout, the PLC automatically initiated a forward open and the communication runs again (without the need for a device restart).
Further investigations - with internal logging - showed that in case of the issue, the EIP-Stack is handling already processed frames an additional time (See Following log lines in yellow show repetition). Because the LWIPIF_input_cb is the callback for the icssg_emac for the rx packages, we are thinking there might be an issue with the data transfer PRU -> SRAM -> Application.
In case of the error, the Ethernet/IP device internally creates its process data, but did not receive the PLC frames (the opposite behaviour we can see on wireshark).
My questions are:
- is this a known issue? We are using SDK 9.00.00 recent SDK is 9.02.00. Comparing the PRU firmwares we can see modifications in code. Is it possible to fix it with the recent PRU firmware? What was changed between these two versions?
- what mechanism is used to avoid concurrent access to SRAM of PRU and R5F. Reading the code of icssg_emac.c I found no hint how the memory is locked to avoid multiple access.
- what happens in case of an overflow if a queue was not read out fast enough? Could this lead to such an behaviour?
25009: 3832756395: LWIPIF_input_cb sequenzNr (4506626), first
25010: 3832756601: USER_NetworkUDPReceive sequenzNr (4506626)
25011: 3832756980: IO_NotifyFrame: Consumption OK! (Cons=0x700638D8/CID=0x80CA0001:4506626) - (Status:0x70096F78 0)
25012: 3832757291: IO_Produce_Action (CID=0x7957AED:4506659)
25013: 3832757789: SO_API_SendTo produce sequenzNr (4506659)
25014: 3832757849: EIP_OS_txPacket produce sequenzNr (4506659)
25015: 3832758541: LWIPIF_input_cb sequenzNr (4506627), first
25016: 3832758986: USER_NetworkUDPReceive sequenzNr (4506627)
25017: 3832759470: IO_NotifyFrame: Consumption OK! (Cons=0x700638D8/CID=0x80CA0001:4506627) - (Status:0x70096F78 0)
25018: 3832759563: IO_Produce_Action (CID=0x7957AED:4506660)
25019: 3832759902: SO_API_SendTo produce sequenzNr (4506660)
25020: 3832759955: EIP_OS_txPacket produce sequenzNr (4506660)
25021: 3832760462: LWIPIF_input_cb sequenzNr (4506628), first
25022: 3832760670: USER_NetworkUDPReceive sequenzNr (4506628)
25023: 3832761059: IO_NotifyFrame: Consumption OK! (Cons=0x700638D8/CID=0x80CA0001:4506628) - (Status:0x70096F78 0)
25024: 3832761354: IO_Produce_Action (CID=0x7957AED:4506661)
25025: 3832761637: SO_API_SendTo produce sequenzNr (4506661)
25026: 3832761683: EIP_OS_txPacket produce sequenzNr (4506661)
25027: 3832762973: LWIPIF_input_cb sequenzNr (4506629), first
25028: 3832763250: IO_Produce_Action (CID=0x7957AED:4506662)
25029: 3832763448: USER_NetworkUDPReceive sequenzNr (4506629)
25030: 3832763829: IO_NotifyFrame: Consumption OK! (Cons=0x700638D8/CID=0x80CA0001:4506629) - (Status:0x70096F78 0)
25031: 3832764003: SO_API_SendTo produce sequenzNr (4506662)
25032: 3832764055: EIP_OS_txPacket produce sequenzNr (4506662)
25033: 3832764504: LWIPIF_input_cb sequenzNr (4506630), first
25034: 3832764688: USER_NetworkUDPReceive sequenzNr (4506630)
25035: 3832765056: IO_NotifyFrame: Consumption OK! (Cons=0x700638D8/CID=0x80CA0001:4506630) - (Status:0x70096F78 0)
25036: 3832765328: IO_Produce_Action (CID=0x7957AED:4506663)
25037: 3832765689: SO_API_SendTo produce sequenzNr (4506663)
25038: 3832765752: EIP_OS_txPacket produce sequenzNr (4506663)
25039: 3832766382: LWIPIF_input_cb sequenzNr (4506631), first
25040: 3832766581: USER_NetworkUDPReceive sequenzNr (4506631)
25041: 3832766984: IO_NotifyFrame: Consumption OK! (Cons=0x700638D8/CID=0x80CA0001:4506631) - (Status:0x70096F78 0)
25042: 3832767299: IO_Produce_Action (CID=0x7957AED:4506664)
25043: 3832767807: SO_API_SendTo produce sequenzNr (4506664)
25044: 3832767853: EIP_OS_txPacket produce sequenzNr (4506664)
25045: 3832768515: LWIPIF_input_cb sequenzNr (4506632), first
25046: 3832768966: USER_NetworkUDPReceive sequenzNr (4506632)
25047: 3832769474: IO_NotifyFrame: Consumption OK! (Cons=0x700638D8/CID=0x80CA0001:4506632) - (Status:0x70096F78 0)
25048: 3832769569: IO_Produce_Action (CID=0x7957AED:4506665)
25049: 3832769893: SO_API_SendTo produce sequenzNr (4506665)
25050: 3832769939: EIP_OS_txPacket produce sequenzNr (4506665)
25051: 3832770446: LWIPIF_input_cb sequenzNr (4506633), first
25052: 3832770629: USER_NetworkUDPReceive sequenzNr (4506633)
25053: 3832771022: IO_NotifyFrame: Consumption OK! (Cons=0x700638D8/CID=0x80CA0001:4506633) - (Status:0x70096F78 0)
25054: 3832771337: IO_Produce_Action (CID=0x7957AED:4506666)
25055: 3832771612: SO_API_SendTo produce sequenzNr (4506666)
25056: 3832771663: EIP_OS_txPacket produce sequenzNr (4506666)
25057: 3832772352: LWIPIF_input_cb sequenzNr (4506634), first
25058: 3832772515: USER_NetworkUDPReceive sequenzNr (4506634)
25059: 3832772855: IO_NotifyFrame: Consumption OK! (Cons=0x700638D8/CID=0x80CA0001:4506634) - (Status:0x70096F78 0)
25060: 3832773310: IO_Produce_Action (CID=0x7957AED:4506667)
25061: 3832773574: SO_API_SendTo produce sequenzNr (4506667)
25062: 3832773618: EIP_OS_txPacket produce sequenzNr (4506667)
25063: 3832774468: LWIPIF_input_cb sequenzNr (4506635), first
25064: 3832774646: USER_NetworkUDPReceive sequenzNr (4506635)
25065: 3832775039: IO_NotifyFrame: Consumption OK! (Cons=0x700638D8/CID=0x80CA0001:4506635) - (Status:0x70096F78 0)
25066: 3832775323: IO_Produce_Action (CID=0x7957AED:4506668)
25067: 3832775652: SO_API_SendTo produce sequenzNr (4506668)
25068: 3832775694: EIP_OS_txPacket produce sequenzNr (4506668)
25069: 3832776400: LWIPIF_input_cb sequenzNr (4506636), first
25070: 3832776588: USER_NetworkUDPReceive sequenzNr (4506636)
25071: 3832776943: IO_NotifyFrame: Consumption OK! (Cons=0x700638D8/CID=0x80CA0001:4506636) - (Status:0x70096F78 0)
25072: 3832777297: IO_Produce_Action (CID=0x7957AED:4506669)
25073: 3832777795: SO_API_SendTo produce sequenzNr (4506669)
25074: 3832777849: EIP_OS_txPacket produce sequenzNr (4506669)
25075: 3832778527: LWIPIF_input_cb sequenzNr (4506637), first
25076: 3832778777: USER_NetworkUDPReceive sequenzNr (4506637)
25077: 3832779298: IO_NotifyFrame: Consumption OK! (Cons=0x700638D8/CID=0x80CA0001:4506637) - (Status:0x70096F78 0)
25078: 3832779386: IO_Produce_Action (CID=0x7957AED:4506670)
25079: 3832779691: SO_API_SendTo produce sequenzNr (4506670)
25080: 3832779745: EIP_OS_txPacket produce sequenzNr (4506670)
25081: 3832780592: LWIPIF_input_cb sequenzNr (0), first
25082: 3832781320: IO_Produce_Action (CID=0x7957AED:4506671)
25083: 3832781624: SO_API_SendTo produce sequenzNr (4506671)
25084: 3832781674: EIP_OS_txPacket produce sequenzNr (4506671)
25085: 3832782580: LWIPIF_input_cb sequenzNr (0), counter (24)
25086: 3832782605: LWIPIF_input_cb sequenzNr (289406976), first
25087: 3832783287: IO_Produce_Action (CID=0x7957AED:4506672)
25088: 3832783528: SO_API_SendTo produce sequenzNr (4506672)
25089: 3832783580: EIP_OS_txPacket produce sequenzNr (4506672)
25091: 3832783758: LWIPIF_input_cb sequenzNr (0), first
25092: 3832785351: IO_Produce_Action (CID=0x7957AED:4506673)
25093: 3832785633: SO_API_SendTo produce sequenzNr (4506673)
25094: 3832785684: EIP_OS_txPacket produce sequenzNr (4506673)
25095: 3832786776: LWIPIF_input_cb sequenzNr (0), counter (40)
25096: 3832786803: LWIPIF_input_cb sequenzNr (4506628), first
25097: 3832786984: USER_NetworkUDPReceive sequenzNr (4506628)
25098: 3832787119: IO_NotifyFrame : Old Transaction Number Frame(4506628) Cons(4506637)
25099: 3832787285: IO_Produce_Action (CID=0x7957AED:4506674)
25100: 3832787514: LWIPIF_input_cb sequenzNr (4506629), first
25101: 3832787878: SO_API_SendTo produce sequenzNr (4506674)
25102: 3832787929: EIP_OS_txPacket produce sequenzNr (4506674)
25103: 3832788070: USER_NetworkUDPReceive sequenzNr (4506629)
25104: 3832788289: IO_NotifyFrame : Old Transaction Number Frame(4506629) Cons(4506637)
25105: 3832788546: LWIPIF_input_cb sequenzNr (4506630), first
25106: 3832788826: USER_NetworkUDPReceive sequenzNr (4506630)
25107: 3832788922: IO_NotifyFrame : Old Transaction Number Frame(4506630) Cons(4506637)
25108: 3832788988: LWIPIF_input_cb sequenzNr (4506631), first
25109: 3832789140: USER_NetworkUDPReceive sequenzNr (4506631)
25110: 3832789287: IO_Produce_Action (CID=0x7957AED:4506675)
25111: 3832789537: LWIPIF_input_cb sequenzNr (4506632), first
25112: 3832789665: IO_NotifyFrame : Old Transaction Number Frame(4506631) Cons(4506637)
25113: 3832789740: LWIPIF_input_cb sequenzNr (4506633), first
25114: 3832789878: SO_API_SendTo produce sequenzNr (4506675)
25115: 3832789919: EIP_OS_txPacket produce sequenzNr (4506675)
25116: 3832790029: USER_NetworkUDPReceive sequenzNr (4506632)
25117: 3832790126: IO_NotifyFrame : Old Transaction Number Frame(4506632) Cons(4506637)
25118: 3832790501: USER_NetworkUDPReceive sequenzNr (4506633)
25119: 3832790590: IO_NotifyFrame : Old Transaction Number Frame(4506633) Cons(4506637)
25120: 3832790676: LWIPIF_input_cb sequenzNr (4506634), first
25121: 3832790842: USER_NetworkUDPReceive sequenzNr (4506634)
25122: 3832790930: IO_NotifyFrame : Old Transaction Number Frame(4506634) Cons(4506637)
25123: 3832791008: LWIPIF_input_cb sequenzNr (4506635), first
25124: 3832791124: USER_NetworkUDPReceive sequenzNr (4506635)
25125: 3832791335: IO_NotifyFrame : Old Transaction Number Frame(4506635) Cons(4506637)
25126: 3832791387: IO_Produce_Action (CID=0x7957AED:4506676)
25127: 3832791633: LWIPIF_input_cb sequenzNr (4506636), first
25128: 3832791796: SO_API_SendTo produce sequenzNr (4506676)
25129: 3832791842: EIP_OS_txPacket produce sequenzNr (4506676)
25130: 3832791968: USER_NetworkUDPReceive sequenzNr (4506636)
25131: 3832792090: IO_NotifyFrame : Old Transaction Number Frame(4506636) Cons(4506637)
25132: 3832792382: LWIPIF_input_cb sequenzNr (4506637), first
25133: 3832792539: USER_NetworkUDPReceive sequenzNr (4506637)
25134: 3832792790: LWIPIF_input_cb sequenzNr (0), first
25135: 3832793285: IO_Produce_Action (CID=0x7957AED:4506677)
25136: 3832793579: SO_API_SendTo produce sequenzNr (4506677)
25137: 3832793628: EIP_OS_txPacket produce sequenzNr (4506677)
25138: 3832794860: LWIPIF_input_cb sequenzNr (0), counter (24)
25139: 3832794889: LWIPIF_input_cb sequenzNr (289406976), first
25140: 3832795304: IO_Produce_Action (CID=0x7957AED:4506678)
25141: 3832795664: SO_API_SendTo produce sequenzNr (4506678)
25142: 3832795715: EIP_OS_txPacket produce sequenzNr (4506678)
25143: 3832796660: LWIPIF_input_cb sequenzNr (289406976), counter (17)
25144: 3832796690: LWIPIF_input_cb sequenzNr (0), first