search

mkjeff / secs4net

SECS-II/HSMS-SS/GEM implementation on .NET
https://mkjeff.github.io/secs4net/
MIT License
443 stars 195 forks source link

analysis first s1f13 incorrect，and then T6 outtime occured。[Net6] #75

Closed shuzhx closed 1 year ago

shuzhx commented 1 year ago

Application is passive. set T6=10sec ，linkTestEnable=true 1、 start application ， 2 、recieve [SelectRequest] and then send [SelectResponse] 3、Host（Active） send S1F13 msg immediately ### 'S1F13'W <L [0] <A[2] AA> <A[1] q>

. 4、And Then this bug may occur。 when after LinkTestRequest，report T6 timeout 5、reconnect , and then send s1f13 ,all is Ok.

Debug info ：

[0x7FFBF546FEE0] ANOMALY: use of REX.w is meaningless (default operand size is 64) [0x7FFBF546ADC0] ANOMALY: use of REX.w is meaningless (default operand size is 64) libpng warning: iCCP: cHRM chunk does not match sRGB 2022-12-15 15:36:24.1698|Info|SECS ConnectionState change:Connecting 2022-12-15 15:36:24.1698|Info|HSMSState ->Disc 2022-12-15 15:36:24.6417|Info|SECS ConnectionState change:Connected 2022-12-15 15:36:24.6417|Info|HSMSState ->Disc 2022-12-15 15:36:24.6417|Info|Start T7 Timer: 10 sec. 2022-12-15 15:36:24.6512|Info|Recieve socket data：len=14 00 00 00 0A FF FF 00 00 00 01 80 00 00 0B ### //get selectedRequest 1:Read data from reader,required=4，[0,14],data=00 00 00 0A FF FF 00 00 00 01 80 00 00 0B Get new message with length: 10,data=00 00 00 0A Get message(id:8000000B) header 2022-12-15 15:36:24.6668|Info|Receive Control message: SelectRequest 2022-12-15 15:36:24.7040|Info|Sent Control Message: SelectResponse[id=0x8000000B] 2022-12-15 15:36:24.7073|Info|Recieve socket data：len=14 00 00 00 0A FF FF 00 00 00 05 80 00 00 0C 2022-12-15 15:36:24.7073|Info|SECS ConnectionState change:Selected 2022-12-15 15:36:24.7073|Info|HSMSState Change,Disc->Conn 2022-12-15 15:36:24.7073|Info|HSMSState ->Conn 2022-12-15 15:36:24.7073|Info|Stop T7 Timer 1:Read data from reader,required=4，[0,14],data=00 00 00 0A FF FF 00 00 00 05 80 00 00 0C Get new message with length: 10,data=00 00 00 0A Get message(id:8000000C) header 2022-12-15 15:36:24.7073|Info|Receive Control message: LinkTestRequest 2022-12-15 15:36:24.7073|Info|Sent Control Message: LinkTestResponse[id=0x8000000C] 2022-12-15 15:36:26.3150|Info|Recieve socket data：len=14 00 00 00 13 00 00 81 0D 00 00 00 00 00 20 ### //recieve s1f13 msg head 2022-12-15 15:36:26.3150|Info|Recieve socket data：len=9 01 02 41 02 41 41 41 01 71 ### //recieve s1f13 msg body 2:Read data from reader,required=4，[0,9],data=00 00 00 13 00 00 81 0D 00 00 00 00 00 20 01 02 41 02 41 41 41 01 71 Get new message with length: 19,data=00 00 00 13 Get message(id:00000020) header Get data message(id:00000020) with total bytes: 19 and decoded directly
Get new message with length: 37814849,data=02 41 02 41 ### 37814849 ???? so long??? 1:require 10,but not enough ，data=41 41 01 71,AdvanceTo=》[5,9] 2022-12-15 15:36:26.3366|Info|<--[32] 'S1F13'W ### analysis incorrect <L [0]

.

2022-12-15 15:36:26.3665|Info|-->[32] S1F14:'S1F14' <L [2] <B [1] 0x00> <L [0]

.

2022-12-15 15:36:34.1775|Info|Sent Control Message: LinkTestRequest[id=0x63C14577] 2022-12-15 15:36:34.1775|Info|Recieve socket data：len=14 00 00 00 0A FF FF 00 00 00 06 63 C1 45 77 ### recieve LinkTestResponse 2:Read data from reader,required=10，[5,14],data=41 41 01 71 00 00 00 0A FF FF 00 00 00 06 63 C1 45 77
Get message(id:000AFFFF) header Decoded List[0] Get data message(id:000AFFFF) decoded by data chunked Get new message with length: 1635,data=00 00 06 63 2022-12-15 15:36:34.1775|Info|<--[720895] 'S1F113' <L [0]

.

1:require 10,but not enough ，data=C1 45 77,AdvanceTo=》[11,14]

NLog.Logger 2022-12-15 15:36:39.2069|Error|T6 Timeout[id=0x63C14577]: 5 sec. ### //T6 timeout NLog.Logger 2022-12-15 15:36:39.2069|Error|T6 Timeout[id=0x63C14577]: 5 sec. 2022-12-15 15:36:39.2069|Info|SECS ConnectionState change:Retry 2022-12-15 15:36:39.2069|Info|HSMSState Change,Conn->Disc 2022-12-15 15:36:39.2069|Info|HSMSState ->Disc 2022-12-15 15:36:39.2641|Info|SECS ConnectionState change:Connecting 2022-12-15 15:36:39.2641|Info|HSMSState ->Disc

And This problem does not occur frequently，It is easy to appear when starting。

shuzhx commented 1 year ago

image image

FirstSpan length=0 ,so itemContentLengthByteCount is zero。

image change code like this , and then work OK.