Zone timer dump from Envisa Link 4

[pos42]

Hi

I have 2-3 times this year had a zone timer dump from my Envisalink 4 card. Today I lost the connection to the Envisa link card. When I managed to reconnect, the Envisalink card threw a zone timer dump at me. I know what the Envisalink API spec says.

It seems it will take some time to decode it. Has any one here info about how to decode it?

615F3FF89FDEFFFF3FF7AFD00000FFD000000000000ECFFC1FBC1FB00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000006

What does this tell me?
And most important. How can I tell why it happened? Of course I want to know if anything is faulty.

Many thanks in advance
Peo

[mikep]

It does what the API says reporting the time since each zone was restored. It doesn't report any errors so it's not indicating a fault. Decoding it is exactly as specified in the spec. I don't believe it's ever sent unsolicited, at least not that I've noticed.

[pos42]

Hi

I have seen this dump only after the EnvisaLink has been unresponsive. I have my own LUA service talking to the Envisa Link card. And as said, this happens 2-3 times a year maybe. It was working normally polling the Envisa Link successfully. And just like that the Envisa Link did not answer. So my service restarts and tries to login again. That fails. It is like the Envisa Link is updating firmware or so. After a few attempts my service manage to connect again. At that time the Envisa Link trows this dump. And then it it working again.... Everything is taking around 3 minutes... I have checked the switch ports and the system running the LUA DSC integration service. Nothing strange. Just like the Envisa Link rebooted...

Any clue what is happening.


This is from my syslog just before and during the reconnection/re-initialization.

Code: Select all

Nov 14 18:28:41 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:29:17 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:29:53 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:30:29 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:31:05 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:31:35 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:32:12 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:32:48 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:33:24 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:33:47 DSCengine Zone: 011 ZPIRLivingRUP: breached
Nov 14 18:33:47 DSCengine Partition Not Ready - Partition: 1
Nov 14 18:33:49 DSCengine Zone: 011 ZPIRLivingRUP: restored
Nov 14 18:33:50 DSCengine Partition Ready - Partition: 1
Nov 14 18:33:56 DSCengine Zone: 011 ZPIRLivingRUP: breached
Nov 14 18:34:38 DSCengine PROBLEM! pollTimer not updated. Probably a connection problem to EnvisaLink
Nov 14 18:34:38 DSCengine Session to DSC alarm is dead or login has failed, so we start over again. GOOD BYE!
Nov 14 18:34:43 DSCengine ---STARTING DSC ENGINE SERVICE---
Nov 14 18:34:43 DSCengine VD: DSCpresenter already exist ID: 1014
Nov 14 18:34:43 DSCengine VD: DSCpresenter with ID: 1014 modified
Nov 14 18:34:43 DSCengine Inserting zone ZPIRHallway to presenter device
Nov 14 18:34:44 DSCengine REQEST [200][0][2342]
Nov 14 18:34:44 DSCengine Zone additon to presenter device OK for zone: ZPIRHallway
Nov 14 18:34:44 DSCengine Inserting zone ZPIRKitchen to presenter device
Nov 14 18:34:44 DSCengine REQEST [200][0][2519]
Nov 14 18:34:44 DSCengine Zone additon to presenter device OK for zone: ZPIRKitchen
Nov 14 18:34:44 DSCengine Inserting zone ZPIRLivingR to presenter device
Nov 14 18:34:45 DSCengine REQEST [200][0][2697]
Nov 14 18:34:45 DSCengine Zone additon to presenter device OK for zone: ZPIRLivingR
Nov 14 18:34:45 DSCengine Inserting zone ZPIROffice to presenter device
Nov 14 18:34:45 DSCengine REQEST [200][0][2872]
Nov 14 18:34:45 DSCengine Zone additon to presenter device OK for zone: ZPIROffice
Nov 14 18:34:45 DSCengine Inserting zone ZPIRLaundry to presenter device
Nov 14 18:34:46 DSCengine REQEST [200][0][3050]
Nov 14 18:34:46 DSCengine Zone additon to presenter device OK for zone: ZPIRLaundry
Nov 14 18:34:46 DSCengine Inserting zone ZCentralUnit to presenter device
Nov 14 18:34:46 DSCengine REQEST [200][0][3234]
Nov 14 18:34:46 DSCengine Zone additon to presenter device OK for zone: ZCentralUnit
Nov 14 18:34:46 DSCengine Inserting zone ZFrontDoor to presenter device
Nov 14 18:34:47 DSCengine REQEST [200][0][3406]
Nov 14 18:34:47 DSCengine Zone additon to presenter device OK for zone: ZFrontDoor
Nov 14 18:34:47 DSCengine Inserting zone ZGLASSLivR to presenter device
Nov 14 18:34:48 DSCengine REQEST [200][0][3581]
Nov 14 18:34:48 DSCengine Zone additon to presenter device OK for zone: ZGLASSLivR
Nov 14 18:34:48 DSCengine Inserting zone ZGLASSLivRUP to presenter device
Nov 14 18:34:49 DSCengine REQEST [200][0][3762]
Nov 14 18:34:49 DSCengine Zone additon to presenter device OK for zone: ZGLASSLivRUP
Nov 14 18:34:49 DSCengine Inserting zone ZPIRLivingRUP to presenter device
Nov 14 18:34:49 DSCengine REQEST [200][0][3949]
Nov 14 18:34:49 DSCengine Zone additon to presenter device OK for zone: ZPIRLivingRUP
Nov 14 18:34:49 DSCengine Inserting zone ZGarageDoor to presenter device
Nov 14 18:34:50 DSCengine REQEST [200][0][4124]
Nov 14 18:34:50 DSCengine Zone additon to presenter device OK for zone: ZGarageDoor
Nov 14 18:34:50 DSCengine Inserting zone ZPIRGarage to presenter device
Nov 14 18:34:51 DSCengine REQEST [200][0][4299]
Nov 14 18:34:51 DSCengine Zone additon to presenter device OK for zone: ZPIRGarage
Nov 14 18:34:51 DSCengine Inserting zone ZSMOKELivRUP to presenter device
Nov 14 18:34:52 DSCengine REQEST [200][0][4480]
Nov 14 18:34:52 DSCengine Zone additon to presenter device OK for zone: ZSMOKELivRUP
Nov 14 18:34:52 DSCengine VD: DSCpartition1 already exist ID: 1015
Nov 14 18:34:52 DSCengine VD: DSCpartition1 with ID: 1015 modified
Nov 14 18:34:52 DSCengine VD: DSCpartition2 already exist ID: 1016
Nov 14 18:34:53 DSCengine VD: DSCpartition2 with ID: 1016 modified
Nov 14 18:34:53 DSCengine VD: DSClogger already exist ID: 996
Nov 14 18:34:55 DSCengine VD: DSClogger with ID: 996 modified
Nov 14 18:34:56 DSCengine Setting presenter device STATUS to UNKNOWN as we cannot know DSC unit status before any ARM/DISARM event occured
Nov 14 18:34:57 DSCengine Setting DSC_P1_ArmedStatus global variable to UNKNOWN as we cannot know DSC unit status before any ARM/DISARM event occured
Nov 14 18:34:57 DSCengine Setting DSC_P2_ArmedStatus global variable to UNKNOWN as we cannot know DSC unit status before any ARM/DISARM event occured
Nov 14 18:34:57 DSCengine Session start
Nov 14 18:34:57 DSCengine Contacting server...
Nov 14 18:34:57 DSCengine Setting presenter device ACPOWER to OK at startup. >>>> This is an assumption <<<< as we have no events yet
Nov 14 18:34:57 DSCengine Setting global variable DSC_AC_Power_Fail to 0 at startup. >>>> This is an assumption <<<< as we have no events yet
Nov 14 18:34:57 DSCengine Setting global variable ZPIRHallway to unknown status in presenter device GUI initialization
Nov 14 18:34:57 DSCengine Setting global variable ZPIRKitchen to unknown status in presenter device GUI initialization
Nov 14 18:34:57 DSCengine Setting global variable ZPIRLivingR to unknown status in presenter device GUI initialization
Nov 14 18:34:57 DSCengine Setting global variable ZPIROffice to unknown status in presenter device GUI initialization
Nov 14 18:34:57 DSCengine Setting global variable ZPIRLaundry to unknown status in presenter device GUI initialization
Nov 14 18:34:57 DSCengine Setting global variable ZCentralUnit to unknown status in presenter device GUI initialization
Nov 14 18:34:57 DSCengine Setting global variable ZFrontDoor to unknown status in presenter device GUI initialization
Nov 14 18:34:57 DSCengine Setting global variable ZGLASSLivR to unknown status in presenter device GUI initialization
Nov 14 18:34:57 DSCengine Setting global variable ZGLASSLivRUP to unknown status in presenter device GUI initialization
Nov 14 18:34:57 DSCengine Setting global variable ZPIRLivingRUP to unknown status in presenter device GUI initialization
Nov 14 18:34:57 DSCengine Setting global variable ZGarageDoor to unknown status in presenter device GUI initialization
Nov 14 18:34:57 DSCengine Setting global variable ZPIRGarage to unknown status in presenter device GUI initialization
Nov 14 18:34:57 DSCengine Setting global variable ZSMOKELivRUP to unknown status in presenter device GUI initialization
Nov 14 18:36:07 DSCengine PROBLEM! pollTimer not updated. Probably a connection problem to EnvisaLink
Nov 14 18:36:07 DSCengine Session to DSC alarm is dead or login has failed, so we start over again. GOOD BYE!
Nov 14 18:36:13 DSCengine ---STARTING DSC ENGINE SERVICE---
Nov 14 18:36:13 DSCengine VD: DSCpresenter already exist ID: 1014
Nov 14 18:36:13 DSCengine VD: DSCpresenter with ID: 1014 modified
Nov 14 18:36:13 DSCengine Inserting zone ZPIRHallway to presenter device
Nov 14 18:36:13 DSCengine REQEST [200][0][2301]
Nov 14 18:36:13 DSCengine Zone additon to presenter device OK for zone: ZPIRHallway
Nov 14 18:36:13 DSCengine Inserting zone ZPIRKitchen to presenter device
Nov 14 18:36:14 DSCengine REQEST [200][0][2478]
Nov 14 18:36:14 DSCengine Zone additon to presenter device OK for zone: ZPIRKitchen
Nov 14 18:36:14 DSCengine Inserting zone ZPIRLivingR to presenter device
Nov 14 18:36:14 DSCengine REQEST [200][0][2656]
Nov 14 18:36:14 DSCengine Zone additon to presenter device OK for zone: ZPIRLivingR
Nov 14 18:36:14 DSCengine Inserting zone ZPIROffice to presenter device
Nov 14 18:36:15 DSCengine REQEST [200][0][2831]
Nov 14 18:36:15 DSCengine Zone additon to presenter device OK for zone: ZPIROffice
Nov 14 18:36:15 DSCengine Inserting zone ZPIRLaundry to presenter device
Nov 14 18:36:15 DSCengine REQEST [200][0][3009]
Nov 14 18:36:15 DSCengine Zone additon to presenter device OK for zone: ZPIRLaundry
Nov 14 18:36:15 DSCengine Inserting zone ZCentralUnit to presenter device
Nov 14 18:36:16 DSCengine REQEST [200][0][3190]
Nov 14 18:36:16 DSCengine Zone additon to presenter device OK for zone: ZCentralUnit
Nov 14 18:36:16 DSCengine Inserting zone ZFrontDoor to presenter device
Nov 14 18:36:16 DSCengine REQEST [200][0][3365]
Nov 14 18:36:16 DSCengine Zone additon to presenter device OK for zone: ZFrontDoor
Nov 14 18:36:16 DSCengine Inserting zone ZGLASSLivR to presenter device
Nov 14 18:36:17 DSCengine REQEST [200][0][3540]
Nov 14 18:36:17 DSCengine Zone additon to presenter device OK for zone: ZGLASSLivR
Nov 14 18:36:17 DSCengine Inserting zone ZGLASSLivRUP to presenter device
Nov 14 18:36:18 DSCengine REQEST [200][0][3721]
Nov 14 18:36:18 DSCengine Zone additon to presenter device OK for zone: ZGLASSLivRUP
Nov 14 18:36:18 DSCengine Inserting zone ZPIRLivingRUP to presenter device
Nov 14 18:36:19 DSCengine REQEST [200][0][3905]
Nov 14 18:36:19 DSCengine Zone additon to presenter device OK for zone: ZPIRLivingRUP
Nov 14 18:36:19 DSCengine Inserting zone ZGarageDoor to presenter device
Nov 14 18:36:19 DSCengine REQEST [200][0][4083]
Nov 14 18:36:19 DSCengine Zone additon to presenter device OK for zone: ZGarageDoor
Nov 14 18:36:19 DSCengine Inserting zone ZPIRGarage to presenter device
Nov 14 18:36:20 DSCengine REQEST [200][0][4258]
Nov 14 18:36:20 DSCengine Zone additon to presenter device OK for zone: ZPIRGarage
Nov 14 18:36:20 DSCengine Inserting zone ZSMOKELivRUP to presenter device
Nov 14 18:36:21 DSCengine REQEST [200][0][4439]
Nov 14 18:36:21 DSCengine Zone additon to presenter device OK for zone: ZSMOKELivRUP
Nov 14 18:36:21 DSCengine VD: DSCpartition1 already exist ID: 1015
Nov 14 18:36:22 DSCengine VD: DSCpartition1 with ID: 1015 modified
Nov 14 18:36:22 DSCengine VD: DSCpartition2 already exist ID: 1016
Nov 14 18:36:22 DSCengine VD: DSCpartition2 with ID: 1016 modified
Nov 14 18:36:22 DSCengine VD: DSClogger already exist ID: 996
Nov 14 18:36:24 DSCengine VD: DSClogger with ID: 996 modified
Nov 14 18:36:26 DSCengine Setting presenter device STATUS to UNKNOWN as we cannot know DSC unit status before any ARM/DISARM event occured
Nov 14 18:36:26 DSCengine Setting DSC_P1_ArmedStatus global variable to UNKNOWN as we cannot know DSC unit status before any ARM/DISARM event occured
Nov 14 18:36:26 DSCengine Setting DSC_P2_ArmedStatus global variable to UNKNOWN as we cannot know DSC unit status before any ARM/DISARM event occured
Nov 14 18:36:26 DSCengine Session start
Nov 14 18:36:26 DSCengine Contacting server...
Nov 14 18:36:26 DSCengine Request for password, sent after socket setup # API CODE:5053CD#015
Nov 14 18:36:26 DSCengine Password sent
Nov 14 18:36:26 DSCengine Login interaction - Password Correct, session established # API CODE:5000052A#015#0125051CB#015
Nov 14 18:36:26 DSCengine Setting presenter device ACPOWER to OK at startup. >>>> This is an assumption <<<< as we have no events yet
Nov 14 18:36:26 DSCengine Setting global variable DSC_AC_Power_Fail to 0 at startup. >>>> This is an assumption <<<< as we have no events yet
Nov 14 18:36:26 DSCengine Setting global variable ZPIRHallway to unknown status in presenter device GUI initialization
Nov 14 18:36:26 DSCengine Setting global variable ZPIRKitchen to unknown status in presenter device GUI initialization
Nov 14 18:36:26 DSCengine Setting global variable ZPIRLivingR to unknown status in presenter device GUI initialization
Nov 14 18:36:26 DSCengine Setting global variable ZPIROffice to unknown status in presenter device GUI initialization
Nov 14 18:36:26 DSCengine Setting global variable ZPIRLaundry to unknown status in presenter device GUI initialization
Nov 14 18:36:26 DSCengine Setting global variable ZCentralUnit to unknown status in presenter device GUI initialization
Nov 14 18:36:26 DSCengine Setting global variable ZFrontDoor to unknown status in presenter device GUI initialization
Nov 14 18:36:26 DSCengine Setting global variable ZGLASSLivR to unknown status in presenter device GUI initialization
Nov 14 18:36:26 DSCengine Setting global variable ZGLASSLivRUP to unknown status in presenter device GUI initialization
Nov 14 18:36:26 DSCengine Setting global variable ZPIRLivingRUP to unknown status in presenter device GUI initialization
Nov 14 18:36:26 DSCengine Setting global variable ZGarageDoor to unknown status in presenter device GUI initialization
Nov 14 18:36:26 DSCengine Setting global variable ZPIRGarage to unknown status in presenter device GUI initialization
Nov 14 18:36:26 DSCengine Setting global variable ZSMOKELivRUP to unknown status in presenter device GUI initialization
Nov 14 18:36:26 DSCengine Not handled codes from alarm  # API CODE:615F3FF89FDEFFFF3FF7AFD00000FFD000000000000ECFFC1FBC1FB00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000006
Nov 14 18:37:02 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:37:38 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:38:14 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:38:50 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:39:26 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:40:03 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:40:39 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:41:15 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:41:51 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:42:27 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:43:03 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:43:39 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:44:15 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:44:51 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:45:27 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:46:03 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:46:39 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:47:15 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:47:46 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:48:22 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:48:58 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:49:34 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:50:10 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:50:46 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:50:47 DSCengine Zone: 005 ZPIRLaundry: breached
Nov 14 18:50:47 DSCengine Partition Not Ready - Partition: 1
Nov 14 18:50:48 DSCengine Zone: 001 ZPIRHallway: breached
Nov 14 18:50:49 DSCengine Zone: 005 ZPIRLaundry: restored
Nov 14 18:50:50 DSCengine Zone: 001 ZPIRHallway: restored
Nov 14 18:50:50 DSCengine Partition Ready - Partition: 1
Nov 14 18:51:05 DSCengine Zone: 001 ZPIRHallway: breached
Nov 14 18:51:07 DSCengine Zone: 001 ZPIRHallway: restored
Nov 14 18:51:08 DSCengine Partition Ready - Partition: 1
Nov 14 18:51:14 DSCengine Zone: 001 ZPIRHallway: breached
Nov 14 18:51:17 DSCengine Zone: 001 ZPIRHallway: restored
Nov 14 18:51:17 DSCengine Partition Ready - Partition: 1
Nov 14 18:51:17 DSCengine Poll response received - TCP session to EnvisaLink is active. Good...
Nov 14 18:51:20 DSCengine Zone: 001 ZPIRHallway: breached
Nov 14 18:51:22 DSCengine Zone: 001 ZPIRHallway: restored
Nov 14 18:51:22 DSCengine Partition Ready - Partition: 1
Nov 14 18:51:42 DSCengine Zone: 007 ZFrontDoor: breached
Nov 14 18:51:45 DSCengine Zone: 007 ZFrontDoor: restored
Nov 14 18:51:45 DSCengine Partition Ready - Partition: 1

[mikep]

Are you asking about the zone timer dump or about the unsolicited disconnect?
A network interruption can stop the poll messages and the envisalink will disconnect.
The zone timer dump should only be in response to a request which would have me looking for an application error.
There's not enough information in this log to figure out what's wrong, you'd need a network capture to find a network or envisalink problem.

[pos42]

Hi

I actually ask about both...

I can see in the fw logs and cisco switch port stats and status info that the networks has been flawless. This also goes in line with the fact that no service on the network has dropped any connection at all. The Envisalink just got unavailable. And it seems the zone dump only comes when the envisalink has gone unavailable for these 3 minutes. The dump does not come during ordinary envisalink restarts.

when you do a restart of envisalink, this is a quick task. But in this particular case the envisalink is unavailable for approx 3 minutes. The rest of the network ans well as the client holding my service has not lost any network connections.

Tnx
/Peo

[pos42]

To add to my last post...

I do *not* send any "008" code to trigger a zone dump (615). I do not even have capability added in the code to do so... The Envisa Link simply does this on its own.... bug in Envisa link?

Peo

[mikep]

Could well be a bug or even a hardware fault. Perhaps if you have a network packet capture that shows it's on the envisalink side K-man will jump in. Without that it's hard to tell where the fault lies.

If the envisalink considers a client still connected it won't close the connection until it times out or is reset; it will connect reset any new attempt to connect until the first clears. Because of this you can't be sure the envisalink is unresponsive for 3 minutes, it may just be refusing to accept the new connection.

You might be able to force the error for a capture by disconnecting the lan connection on your client and reconnecting when it decides it's time to start over.

[K-Man]

There is a case where we send the zone-timer dump asynchronously and that is when we have a potentionally stalled TCP connection and another connection comes in. Normally the second connection is just dropped but in order to test the state of the connection we force a timer dump. If it fails then we drop the existing connection and allow the new one.

I know this isn't documented but it is there to make sure a stalled TCP connection doesn't hold up a reconnection from the client. A user proposed this a long long time ago and it made it into the code.

Regardless, your application needs to be able to accept ANY asynchronous data from the Envisalink, including the timer dump.

K

[pos42]

Thanks @K-Man !

Ok. Now I know why this zone-timer dump comes And of course I accept ANY asynchronous data. The data API command I have not implemented I still log and write out if debug level is high enough in the application. That is why I see this dump in the log. Unfortunately a virtual device in Fibaro Home Center 2 is limited to around 2000 rows of LUA code. So to implement more (like decode these dumps or use them actively) I have to write more efficient code constructions as I am near the 2000 row limit.


B t w… Is there a special reason why you force a zone-timer dump and not just a “poll”?


As you say the TCP session is probably stale, even though I have no other glitches, I then think it must be the Fibaro Home center home automation box that holds the code talking to the Envisalink that has a problem internally. The Fibaro home center box does not have any more services with constantly connected sessions. So therefor this could probably happened there without me noticing it. If I have time I maybe mirror the switch port and record everything sent and received on TCP 4021 to be able to be 100% sure that it is the Fibaro box. If it happens again I mean…



I have this in my main loop early....

Code: Select all

--snip--
if string.match(token, '^500') then
    if string.match(token, '^50000025')  then -- Check result of socket poll status. If ok, we reset poll timer
      pollTimer = os.time() -- We reset pollTimer as we have seen a poll response from EnvisaLink
      if DEBUG >= 1 then fibaro:debug('Poll response received - TCP session is active. Good...') end
      if SYSLOG == 1 then syslogserver('Poll response received - TCP session is active. Good...') end
    elseif string.match(token, '^500') then
      if DEBUG >= 1 then fibaro:debug('Previous command received successfully') end
      if SYSLOG == 1 then syslogserver('Previous command received successfully') end 
    end
elseif
--snip--

Later in the main loop I have...

Code: Select all

--snip--
if os.time() - pollTimer > 70 then  -- Keep alive handling. PollTimer is updated when we receive a poll response from EnvisaLink. Here we check for it. If we missed two 30s polls (incl some program work time) we exit program and start over
    if DEBUG >= 1 then fibaro:debug('PROBLEM! pollTimer not updated. A connection problem to EnvisaLink') end
    if SYSLOG == 1 then syslogserver('PROBLEM! pollTimer not updated. A connection problem to EnvisaLink') end
    alive = 0 
  else
    if os.time() - pollTimer > 30 then -- time to write a poll request as it was more than 30s ago
      local byte, errorCode = tcpSocket:write('00090\r\n')
      if errorCode > 0 then
        if SYSLOG == 1 then syslogserver('Error code is: ' .. errorCode .. ' Failed to communicate with EnvisaLink doing keep alive request!') end
        fibaro:debug('Error code is: ' .. errorCode .. ' Failed to communicate with EnvisaLink doing keep alive request!')
      end
    end
  end 
--snip--

And if it took to long, i.e the current time minus my pollTimer is more than 70s I consider the session not valid.
Then I exit the application and try to start over. I wait around 5s before I allow a reconnect after fail to not be too agressive.

Do you think I should adjust my timers?

[mikep]

A poll is always from the client and while a poll response might work, it, like the timer dump, feels more like it should only be sent in response rather than unsolicited. I would have been tempted to use something a little less heavy like an LED status update, but what it's doing does make sense. If there's a willingness to break backwards compatibility (already happened with 616) an outgoing poll / are you there type command would've worked as well.