Invocation Counter is mismatching randomly in latest version of Gurux

Forum Rules

Before commenting read Forum rules

Don't comment the topic if you have a new question.

You can create a new topic selecting correct category from Gurux Forum and then create a new topic selecting "New Topic" from the top left.

By thirumalesh , 1 December, 2020
Forums
Gurux.DLMS

Inbetween the Communication Invocation Counter is not getting incremented , and because of that comunication is failing. Below is the log where you can see

[ 167674] *ERR*(20036C38/10) CosemSecurity.cpp:536 Validate invocation counter. Source: 0; Received: 11406; Previous: 11406; Current: 11406; Result: 1;

and after that Gurux gave the same invocation Counter

[ 187945] *ERR*(20036C38/10) CosemSecurity.cpp:536 Validate invocation counter. Source: 0; Received: 11406; Previous: 11407; Current: 11407; Result: 0;

Please Check the log

[ 128001] *ERR*(20036C38/10) CosemCryptoBase.cpp:515 rSecurityStatus.m_u64InvocationCounter = 11400 , rSecurityStatus.m_u64PreviousInvocationCounter = 0
[ 128004] INFO (20036C38/9) CosemLayer.cpp:736 PDU Security OK; Encrypted: 1; Authenticated: 1; Compressed: 0
[ 128005] INFO (20036C38/9) CosemLayer.cpp:856 Decrypted pdu request (13 bytes): C001C1000F0000280000FF0400
[ 128009] INFO (20036C38/9) CosemLayer.cpp:784 Un-encrypted response data: C401C100090760857405080103
[ 128012] INFO (20036C38/9) CosemLayer.cpp:1380 Data request. 1 -> 32/17; Data (32 bytes): CC1E30000008116A12D0B94DC395E0F3399A5AFD39B8B2FF997DCA7BDC02326D
[ 128043] DBG (537300312) TransportLayerHemrod.cpp:974 PULL DATA LENGTH = 40

[ 128044] INFO (20036C38/0) Dispatcher.cpp:73 Data Confirm. 32/17 -> 1;
[ 128045] INFO (20036C38/9) CosemLayer.cpp:1685 On DATA CONFIRM 1, Success
[ 128051] DBG (537300824) TransportLayerHemrod.cpp:393 -- PULL - SEND REQUEST --

[ 128056] DBG (537300824) TransportLayerHemrod.cpp:403 -- PULL - SEND REQUEST Data Length = 40--

[ 133966] DBG (537300824) TransportLayerHemrod.cpp:633 -- RECEIVE INDICATION --

[ 133971] DBG (537300824) TransportLayerHemrod.cpp:664 -- PULL - RECEIVE INDICATION Data Length = 40--

[ 133978] INFO (20031FC4/0) Dispatcher.cpp:57 Data indication. 32/17 -> 1;
[ 133983] INFO (20036C38/9) CosemLayer.cpp:430 Data indication. Length: 32; Data: C81E3000002C89535264099F31A7ADA707B4D06A960A395AFC95AFBB158D63DE
[ 133988] *ERR*(20036C38/10) CosemSecurity.cpp:536 Validate invocation counter. Source: 0; Received: 11401; Previous: 11401; Current: 11401; Result: 1;
[ 133990] *ERR*(20036C38/10) CosemCryptoBase.cpp:515 rSecurityStatus.m_u64InvocationCounter = 11401 , rSecurityStatus.m_u64PreviousInvocationCounter = 0
[ 133993] INFO (20036C38/9) CosemLayer.cpp:736 PDU Security OK; Encrypted: 1; Authenticated: 1; Compressed: 0
[ 133994] INFO (20036C38/9) CosemLayer.cpp:856 Decrypted pdu request (13 bytes): C001C1000F0000280000FF0500
[ 133998] INFO (20036C38/9) CosemLayer.cpp:784 Un-encrypted response data: C401C10002060418001E1D1202001204C811060F000900
[ 134002] INFO (20036C38/9) CosemLayer.cpp:1380 Data request. 1 -> 32/17; Data (42 bytes): CC283000000812E8D9E56A14F4F41B4F352AAF8227F36276C4688A052CBD6D3E9B9AD2409B9215ED4F55
[ 134007] DBG (537300312) TransportLayerHemrod.cpp:974 PULL DATA LENGTH = 50

[ 134008] INFO (20036C38/0) Dispatcher.cpp:73 Data Confirm. 32/17 -> 1;
[ 134010] INFO (20036C38/9) CosemLayer.cpp:1685 On DATA CONFIRM 1, Success
[ 134013] DBG (537300824) TransportLayerHemrod.cpp:393 -- PULL - SEND REQUEST --

[ 134044] DBG (537300824) TransportLayerHemrod.cpp:403 -- PULL - SEND REQUEST Data Length = 50--

[ 140048] DBG (537300824) TransportLayerHemrod.cpp:633 -- RECEIVE INDICATION --

[ 140053] DBG (537300824) TransportLayerHemrod.cpp:664 -- PULL - RECEIVE INDICATION Data Length = 40--

[ 140059] INFO (20031FC4/0) Dispatcher.cpp:57 Data indication. 32/17 -> 1;
[ 140065] INFO (20036C38/9) CosemLayer.cpp:430 Data indication. Length: 32; Data: C81E3000002C8A7BC3B2055FBAE36827AD0266EA1DA2F90F0860718866867863
[ 140069] *ERR*(20036C38/10) CosemSecurity.cpp:536 Validate invocation counter. Source: 0; Received: 11402; Previous: 11402; Current: 11402; Result: 1;
[ 140071] *ERR*(20036C38/10) CosemCryptoBase.cpp:515 rSecurityStatus.m_u64InvocationCounter = 11402 , rSecurityStatus.m_u64PreviousInvocationCounter = 0
[ 140074] INFO (20036C38/9) CosemLayer.cpp:736 PDU Security OK; Encrypted: 1; Authenticated: 1; Compressed: 0
[ 140075] INFO (20036C38/9) CosemLayer.cpp:856 Decrypted pdu request (13 bytes): C001C1000F0000280000FF0600
[ 140079] INFO (20036C38/9) CosemLayer.cpp:784 Un-encrypted response data: C401C100090760857405080205
[ 140082] INFO (20036C38/9) CosemLayer.cpp:1380 Data request. 1 -> 32/17; Data (32 bytes): CC1E300000081384C1A46EEAE0D713CD223DE39E7CB4283682B0C89A2D7F4E14
[ 140086] DBG (537300312) TransportLayerHemrod.cpp:974 PULL DATA LENGTH = 40

[ 140088] INFO (20036C38/0) Dispatcher.cpp:73 Data Confirm. 32/17 -> 1;
[ 140089] INFO (20036C38/9) CosemLayer.cpp:1685 On DATA CONFIRM 1, Success
[ 140094] DBG (537300824) TransportLayerHemrod.cpp:393 -- PULL - SEND REQUEST --

[ 140099] DBG (537300824) TransportLayerHemrod.cpp:403 -- PULL - SEND REQUEST Data Length = 40--

[ 146173] DBG (537300824) TransportLayerHemrod.cpp:633 -- RECEIVE INDICATION --

[ 146178] DBG (537300824) TransportLayerHemrod.cpp:664 -- PULL - RECEIVE INDICATION Data Length = 40--

[ 146187] INFO (20031FC4/0) Dispatcher.cpp:57 Data indication. 32/17 -> 1;
[ 146193] INFO (20036C38/9) CosemLayer.cpp:430 Data indication. Length: 32; Data: C81E3000002C8BBD96F839403637C74472C95CE86103F9EF147309DB846DD35F
[ 146197] *ERR*(20036C38/10) CosemSecurity.cpp:536 Validate invocation counter. Source: 0; Received: 11403; Previous: 11403; Current: 11403; Result: 1;
[ 146199] *ERR*(20036C38/10) CosemCryptoBase.cpp:515 rSecurityStatus.m_u64InvocationCounter = 11403 , rSecurityStatus.m_u64PreviousInvocationCounter = 0
[ 146202] INFO (20036C38/9) CosemLayer.cpp:736 PDU Security OK; Encrypted: 1; Authenticated: 1; Compressed: 0
[ 146203] INFO (20036C38/9) CosemLayer.cpp:856 Decrypted pdu request (13 bytes): C001C1000F0000280000FF0800
[ 146207] INFO (20036C38/9) CosemLayer.cpp:784 Un-encrypted response data: C401C1001602
[ 146209] INFO (20036C38/9) CosemLayer.cpp:1380 Data request. 1 -> 32/17; Data (25 bytes): CC173000000814650E97C464E1F064B6B707406A27287B0883
[ 146213] DBG (537300312) TransportLayerHemrod.cpp:974 PULL DATA LENGTH = 33

[ 146214] INFO (20036C38/0) Dispatcher.cpp:73 Data Confirm. 32/17 -> 1;
[ 146216] INFO (20036C38/9) CosemLayer.cpp:1685 On DATA CONFIRM 1, Success
[ 146217] DBG (537300824) TransportLayerHemrod.cpp:393 -- PULL - SEND REQUEST --

[ 146227] DBG (537300824) TransportLayerHemrod.cpp:403 -- PULL - SEND REQUEST Data Length = 33--

[ 152302] DBG (537300824) TransportLayerHemrod.cpp:633 -- RECEIVE INDICATION --

[ 152307] DBG (537300824) TransportLayerHemrod.cpp:664 -- PULL - RECEIVE INDICATION Data Length = 40--

[ 152316] INFO (20031FC4/0) Dispatcher.cpp:57 Data indication. 32/17 -> 1;
[ 152321] INFO (20036C38/9) CosemLayer.cpp:430 Data indication. Length: 32; Data: C81E3000002C8C31A8197F26F34E331F60326FAC708E055E3599F0026C63126C
[ 152326] *ERR*(20036C38/10) CosemSecurity.cpp:536 Validate invocation counter. Source: 0; Received: 11404; Previous: 11404; Current: 11404; Result: 1;
[ 152328] *ERR*(20036C38/10) CosemCryptoBase.cpp:515 rSecurityStatus.m_u64InvocationCounter = 11404 , rSecurityStatus.m_u64PreviousInvocationCounter = 0
[ 152331] INFO (20036C38/9) CosemLayer.cpp:736 PDU Security OK; Encrypted: 1; Authenticated: 1; Compressed: 0
[ 152332] INFO (20036C38/9) CosemLayer.cpp:856 Decrypted pdu request (13 bytes): C001C1000F0000280000FF0900
[ 152336] INFO (20036C38/9) CosemLayer.cpp:784 Un-encrypted response data: C401C100090600002B0000FF
[ 152339] INFO (20036C38/9) CosemLayer.cpp:1380 Data request. 1 -> 32/17; Data (31 bytes): CC1D30000008159F28D3B56C4FEA3A6E88B96AB01CE13C999CE6783FD015EB
[ 152343] DBG (537300312) TransportLayerHemrod.cpp:974 PULL DATA LENGTH = 39

[ 152344] INFO (20036C38/0) Dispatcher.cpp:73 Data Confirm. 32/17 -> 1;
[ 152346] INFO (20036C38/9) CosemLayer.cpp:1685 On DATA CONFIRM 1, Success
[ 152347] DBG (537300824) TransportLayerHemrod.cpp:393 -- PULL - SEND REQUEST --

[ 152352] DBG (537300824) TransportLayerHemrod.cpp:403 -- PULL - SEND REQUEST Data Length = 39--

[ 158762] DBG (537300824) TransportLayerHemrod.cpp:633 -- RECEIVE INDICATION --

[ 158778] DBG (537300824) TransportLayerHemrod.cpp:664 -- PULL - RECEIVE INDICATION Data Length = 40--

[ 158786] INFO (20031FC4/0) Dispatcher.cpp:57 Data indication. 32/17 -> 1;
[ 158791] INFO (20036C38/9) CosemLayer.cpp:430 Data indication. Length: 32; Data: C81E3000002C8DEB30E41FCA36A9522DF36A9FE0CDA16311BD95FFAE1FC0EDEC
[ 158796] *ERR*(20036C38/10) CosemSecurity.cpp:536 Validate invocation counter. Source: 0; Received: 11405; Previous: 11405; Current: 11405; Result: 1;
[ 158798] *ERR*(20036C38/10) CosemCryptoBase.cpp:515 rSecurityStatus.m_u64InvocationCounter = 11405 , rSecurityStatus.m_u64PreviousInvocationCounter = 0
[ 158801] INFO (20036C38/9) CosemLayer.cpp:736 PDU Security OK; Encrypted: 1; Authenticated: 1; Compressed: 0
[ 158802] INFO (20036C38/9) CosemLayer.cpp:856 Decrypted pdu request (13 bytes): C001C1000F0000280002FF0200
[ 158856] INFO (20036C38/9) CosemLayer.cpp:784 Un-encrypted response data: C402C10000000001008204A7018201780204120011110009060000290000FF0202010202030F0116010002030F02160100010102020F011600020412000F110109060000280000FF0202010902030F0116010002030F02160101040F010F020F030F0402030F0316010002030F0416010002030F0516010002030F0616010002030F0716000002030F0816010002030F09160100010402020F01160102020F02160002020F03160002020F041600020412000F110109060000280002FF0202010902030F0116010002030F02160101040F010F020F030F0402030F0316010002030F0416010002030F0516010002030F0616010002030F0716000002030F0816010002030F09160100010402020F01160102020F02160002020F03160002020F041600020412004011000906
[ 158897] INFO (20036C38/9) CosemLayer.cpp:1380 Data request. 1 -> 32/17; Data (1224 bytes): CC8204C43000000816378C61F9350426C1DC1287F14E2BA4D1BBCFA8CA0579064AA6EC15A17B97A34CE1C144A829A82067E5A87489E7C23C10DB5A1727383BDB8D575ACE854CDFDA615DF458EDE61E2ACF44ED6BBB445EC9A47533A302DAB4BB4F1FBF4A37A16F53F2BDA9A5FAFC7C09C6821327ABB9EB0089A3FA1ED13790C5E482D5770088F476AF5A1C04C2E0EC3C6BB2B1A9E7B7AFCB5F4943FDA3354A3B7258454DFCDD35C91959A4DCAAD06F5AFE91B5CBAFA8C31E038FACAD75BAA4[ 167653] DBG (537300824) TransportLayerHemrod.cpp:633 -- RECEIVE INDICATION --

[ 167658] DBG (537300824) TransportLayerHemrod.cpp:664 -- PULL - RECEIVE INDICATION Data Length = 34--

[ 167665] INFO (20031FC4/0) Dispatcher.cpp:57 Data indication. 32/17 -> 1;
[ 167671] INFO (20036C38/9) CosemLayer.cpp:430 Data indication. Length: 26; Data: C8183000002C8EBDF9BF3B9EE100B870C8EE3EB12865FE8AD814
[ 167674] *ERR*(20036C38/10) CosemSecurity.cpp:536 Validate invocation counter. Source: 0; Received: 11406; Previous: 11406; Current: 11406; Result: 1;
[ 167676] *ERR*(20036C38/10) CosemCryptoBase.cpp:515 rSecurityStatus.m_u64InvocationCounter = 11406 , rSecurityStatus.m_u64PreviousInvocationCounter = 0
[ 167679] INFO (20036C38/9) CosemLayer.cpp:736 PDU Security OK; Encrypted: 1; Authenticated: 1; Compressed: 0
[ 167681] INFO (20036C38/9) CosemLayer.cpp:856 Decrypted pdu request (7 bytes): C002C100000001
[ 167710] INFO (20036C38/9) CosemLayer.cpp:784 Un-encrypted response data: C402C10000000002008204A70116000204120001110009060100000200FF0202010202030F0116010002030F0216010001000204120001110009060100000208FF0202010202030F0116010002030F0216010001000204120001110009060101000200FF0202010202030F0116010002030F0216010001000204120001110009060102000200FF0202010202030F0116010002030F0216010001000204120001110009060101000208FF0202010202030F0116010002030F0216010001000204120007110109060100630E00FF0202010802030F0116010002030F02160101010F0102030F0316010002030F0416010002030F0516010002030F0616010002030F0716010002030F08160100010202020F01160002020F0216000204120007110109060100630100FF020201
[ 167750] INFO (20036C38/9) CosemLayer.cpp:1380 Data request. 1 -> 32/17; Data (1224 bytes): CC8204C43000000817BA7F63685A527EF49274B5763B0B4057B30A0C28439EDAB2318B8938398914213C737A38D7C190FD3504F151D72F5D7858CE045CE8578EA2BD5E068CB1F531A11DD472522A875A2D0BD319A738E756BAB082995C79EC0A79A29C6FCCD531B9062205508EC23F2962DE3D6F358C0B949F8B69BF5589B7E92968E1E5C7ECEE15E038448BF66A4078852F26B99D680FFA06D4B80D8DDAF3DD8E712B6D0A97F5FFCB14768627A2DF3D5DEEA37B4E5CF66C6BEA3912A77483576DF32CD5F82CF6AF8E99D31C704039EDF048D936F997693914782C6F360A9C4E77821D52209D1C4D49714228D5F6FA60FBA81267EA0E32D064FF930F1E2D84365C3497CAF2B492E954575C37465D0EEE088A30E9CCE6DAD68FBC393012E023E2512EE2BA2EA03B73DFE0C085CC307617DE3CAAA7B50B82546735300DFC4CF14360956CCC990421053AE0D5E6AB47281005296D98D7DCB5451F16E8E02AE0E54910C0C32BDF4B47F2401926453B5E6B0D6F6C56FC3AC2A933356431324F5D93E7D54C96B6067721573E39F8C9DF879873B578659D01FB681DB810A1C394C9EF336FD394F0A61925EFBC72CC254B58BED1F9ED3A6A60B41495EBEDCB8618714965156626EF81A68F7310250659F4F7C891AEEB2149D2F1DBFFE9993199168943A3ADE6203664B87A06C0B6140271095D377FE1C66E05866F301CCC963B3E60F9A00D1111801E3DBF3E1E0AC5F9BCEA39F04F1C40046AE9E00152B7B281841F11D07FF7C2D18214B12CCB451A37281F89A20B88808BC0DC4711CA5490AD23873F2D25F0B45DF46BFFA6DECD11BC353A5B63A8D0453A45FE6444C7A17391014B95E16B207FC20AE9CFC782CBC79416F7D4CF81BA116761D118AAE758F600C7007DE0E50A91BFD2F01334DB61A0EC3871293A2611CD4F65E7F37F74CDF924C0E888E4D92E56BF539C91476FC5C42CB01FDB22F47E13DCF0C818B330837B67F8E4A4A61AA4AC61C1077FC333A4FA6D9EEA8A33E90A224D02C6226D4B5DA038B4847F2FB32D09D232DD99A951ACE27121462BAA7734006AA431E2C8A88ED696A6F27330B99B5D28BEDAF14AB40CDB5C4EC442C18EB6F02BAEAAB9C676AF34BB14107F92EC0B2807E285634A511FE9AFFF8F9DD265F48FC7B84C8208000446B2A2175078458214EE25484C0D193292058A36CEB818012353357C5F22EDBD87179088BF4DFCAE5D6B6EF2F35C8EF39740D823A1AA5FA8EC606DB8F3F41CA7A64570E013B41438F985913722BE2937FBCB44A5F322F76E3EC3C4440AAC94919F4838EBDF0706022BB4D02E6F20A21C131A85D97D600B8B3447A0D49AC636AAA3FD409525D463E6BFC135DB08DED7A5873B57983A34ACF83EE8F5BFE315731114B8A8828F5DA201FBB91DB697D9A9B49B29588CD02351B7573DCD9B42937D472CAEBF8B3ACD5AD074C9B7610123DEF2A2BCD50C346F28EDECDC9E99B061953C932CCE746A275347484FEEF3BC5CB343CF3C8DBAD956D6D921FF73736F7E60ED7B2D12EC896DDDA150C580460309D9B35BCEEA03B12B2E4106E11E87514D9A8768DFEEC7035D424F4BC9C6CB56A1FE8CA9575374585EE712749A2143E196FD69A199B5F3F31C544802FC1689875F5449967252DE6E4FBCF573B5A2622E20A260E166EC12583625A95ADB258A65CEFF5EF61E382A7DF2E488C4720[ 187862] DBG (537300824) TransportLayerHemrod.cpp:633 -- RECEIVE INDICATION --

[ 187867] DBG (537300824) TransportLayerHemrod.cpp:664 -- PULL - RECEIVE INDICATION Data Length = 34--

[ 187876] INFO (20031FC4/0) Dispatcher.cpp:57 Data indication. 32/17 -> 1;
[ 187882] INFO (20036C38/9) CosemLayer.cpp:430 Data indication. Length: 26; Data: C8183000002C8EBDF9BF3B9EE100B870C8EE3EB12865FE8AD814
[ 187945] *ERR*(20036C38/10) CosemSecurity.cpp:536 Validate invocation counter. Source: 0; Received: 11406; Previous: 11407; Current: 11407; Result: 0;
[ 187947] *ERR*(20036C38/10) CosemCryptoBase.cpp:515 rSecurityStatus.m_u64InvocationCounter = 11406 , rSecurityStatus.m_u64PreviousInvocationCounter = 0
[ 187950] *ERR*(20036C38/9) CosemLayer.cpp:830 Security error.
[ 187951] INFO (20036C38/9) CosemErrorHandler.cpp:193 Error: 30
[ 187952] INFO (20036C38/9) CosemLayer.cpp:1380 Data request. 1 -> 32/17; Data (3 bytes): D80101
[ 187953] DBG (537300312) TransportLayerHemrod.cpp:974 PULL DATA LENGTH = 11

[ 187955] INFO (20036C38/0) Dispatcher.cpp:73 Data Confirm. 32/17 -> 1;
[ 187956] INFO (20036C38/9) CosemLayer.cpp:1685 On DATA CONFIRM 1, Success
[ 187960] DBG (537300824) TransportLayerHemrod.cpp:393 -- PULL - SEND REQUEST --

[ 187965] DBG (537300824) TransportLayerHemrod.cpp:403 -- PULL - SEND REQUEST Data Length = 11--

[ 222500] DBG (537300824) TransportLayerHemrod.cpp:820 -- CLOSE INDICATION --

[ 222510] DBG (537300824) TransportLayerHemrod.cpp:850 -- CLOSE INDICATION RESPONSE --

If the above log is not clear , post downloading the attachment rename it to txt so that you can see the logs

thirumalesh

5 years 6 months ago

On Communication Retry of Gurux Invocation Counter is not incremented in latest Gurux Version GuruX Version 8.1.2011.1101

Image

Kurumi

5 years 6 months ago

Hi,

We have tested this. Can you tell then the Invocation Counter is not increased in your mind?

BR,
Mikko

thirumalesh

5 years 6 months ago

On Communication Retry of Gurux Invocation Counter is not incremented in latest Gurux Version GuruX Version 8.1.2011.1101. Because of this Communication and Meter is Failing and Gives
Error: GetObjects failed. Meter returns Service not allowed exception
Please check the attachment

Image

Kurumi

5 years 6 months ago

Hi,

Yes, Invocation Counter hasn't newer been increased because there is a historical reason for that.
Some older meters can't handle if the IC is not exactly correct.

In your case, the meter has sent the reply, and then it's lost on its way. Now IC is not increased and your meter rejects the next re-try.

In theory, increasing IC for re-try is easy, but there are several cases where it's causing problems if a message is lost after it's sent from the meter. for example, if data is written to the meter in multiple blocks is causing problems if one block is lost.

I need to think this a little bit and find a way how we can handle this in a generic way and keep legacy support.

BR,
Mikko