Zipgateway session issue


#1

using with zware hcapi lib,
when I try to register again within 5 seconds after deleting the device, error occurs with below log.

************ Releasing DHCP entry for node 71
10137897 -------type: 1
10137905 ZIP_EVENT_NM_VIRT_NODE_REMOVE_DONE triggered
10137907 Sending network management reply
10137910 ZIP_EVENT_NETWORK_MANAGEMENT_DONE triggered
10137911 NetworkManagement_SendNodeList_To_Unsolicited
10138031 Sending network management reply
10138033 create new client session
10138033 New client session allocated
10138037 Sending node list to Unsolicited Destination 1
10138039 DTLS: DTLS read failed
lipaddr: fd00:aaaa::0003 lport: 41230
ripaddr: ::ffff:c0a8:7701 rport: 41230
10138040
10138043 DTLS: DTLS read failed
lipaddr: fd00:aaaa::0003 lport: 41230
ripaddr: ::ffff:c0a8:7701 rport: 41230
10138074 DTLS: DTLS read failed
lipaddr: fd00:aaaa::0003 lport: 41230
ripaddr: ::ffff:c0a8:7701 rport: 41230
10138077 DTLS: DTLS read failed
lipaddr: fd00:aaaa::0003 lport: 41230
ripaddr: ::ffff:c0a8:7701 rport: 41230
10138079 DTLS: Client handshake done
lipaddr: fd00:aaaa::0003 lport: 41230
ripaddr: ::ffff:c0a8:7701 rport: 41230
10138083 nm_fsm_post_event event: NM_EV_FRAME_RECEIVED state: NM_IDLE
10138084 NetworkManagementCommandHandler 52 3
10138084 Age is seconds 253
10138089 Sending network management reply
10138936 nm_fsm_post_event event: NM_EV_FRAME_RECEIVED state: NM_IDLE
10138936 NetworkManagementCommandHandler 4d 8
dynamic
ECDH Public key is
48879-54838-61008-40132-
27713-57256-39780-21524-
53854-36761-15611-54314-
34880-28766-11377-54593-
10139149 Sending network management reply
10139154 nm_fsm_post_event event: NM_EV_FRAME_RECEIVED state: NM_IDLE
10139154 NetworkManagementCommandHandler 34 1
10139158 nm_fsm_post_event event: NM_EV_NODE_ADD_S2 state: NM_IDLE
10139166 nm_fsm_post_event event: NM_EV_ADD_LEARN_READY state: NM_WAITING_FOR_ADD
10144444 nm_fsm_post_event event: NM_EV_ADD_NODE_FOUND state: NM_WAITING_FOR_ADD
10144635 nm_fsm_post_event event: NM_EV_ADD_SLAVE state: NM_NODE_FOUND
10145153 nm_fsm_post_event event: NM_EV_ADD_PROTOCOL_DONE state: NM_WIAT_FOR_PROTOCOL
10145209 nm_fsm_post_event event: NM_EV_ADD_NODE_STATUS_DONE state: NM_WIAT_FOR_PROTOCOL
10145221 nodeid=72 1
10145224 Checking for new sessions
10145225 start discover :72
10145231 probe machine is locked
10145232 ApplicationControllerUpdate: status=0x40 node=72 NIF len=0
10145233 nm_fsm_post_event event: NM_EV_SECURITY_DONE state: NM_WAIT_FOR_SECURE_ADD
10145234 rd_node_probe_update state STATUS_CREATED node =72
10145234 rd_node_probe_update state STATUS_PROBE_NODE_INFO node =72
10145247 Sending DISCOVER
10145292 ApplicationControllerUpdate: status=0x84 node=72 NIF len=18
10145293 EP probe nd=72 ep =0 state=EP_STATE_PROBE_SEC2_C2_INFO
10145293 EP probe nd=72 ep =0 state=EP_STATE_PROBE_SEC0_INFO
10145293 EP probe nd=72 ep =0 state=EP_STATE_PROBE_ZWAVE_PLUS
10145293 Sending 1->72, class: 0x5e, cmd: 0x1
10145293 nm_fsm_post_event event: NM_EV_NODE_INFO state: NM_WAIT_FOR_PROBE_AFTER_ADD
10145294 Sending with scheme 255
10145347 EP probe nd=72 ep =0 state=EP_STATE_MDNS_PROBE
10146975 Name probing done and no duplicates found
10146975 EP probe nd=72 ep =0 state=EP_STATE_PROBE_DONE
10146975 rd_node_probe_update state STATUS_PROBE_NODE_INFO node =72
10146975 rd_node_probe_update state STATUS_MDNS_PROBE node =72
10147248 DHCP Timeout
10147248 Sending DISCOVER
10147248 DHCP pass completed
10147248 update flag 1 129
10147758 Node 72 has ipv4 address 192.168.119.220
10147758 update_current_dhcp_session. check for new sessions
10147759 Checking for new sessions
10147759 New IPv4 assigned for node 72
10147759 nm_fsm_post_event event: NM_EV_DHCP_DONE state: NM_WAIT_FOR_PROBE_AFTER_ADD
10147774 DHCP pass completed
10147775 update flag 1 129
PING 192.168.119.219 (192.168.119.219): 56 data bytes
64 bytes from 192.168.119.219: seq=0 ttl=64 time=1.127 ms

— 192.168.119.219 ping statistics —
1 packets transmitted, 1 packets received, 0% packet loss
round-trip min/avg/max = 1.127/1.127/1.127 ms
10148556 Name probing done and no duplicates found
10148556 rd_node_name_probe_done status: 1
10148556 rd_node_probe_update state STATUS_MDNS_EP_PROBE node =72
10148556 rd_node_probe_update state STATUS_DONE node =72
10148557 Probe of node 72 is done
10148584 nm_fsm_post_event event: NM_EV_NODE_PROBE_DONE state: NM_WAIT_FOR_PROBE_AFTER_ADD
10148586 Sending network management reply
10148701 Sending network management reply
10148702 Sending node list to Unsolicited Destination 1
10148702 All nodes have been probed
10148702 update flag 2 131
10148703 ND for 4to6 mapped address
10148708 nm_fsm_post_event event: NM_EV_FRAME_RECEIVED state: NM_IDLE
10148708 NetworkManagementCommandHandler 4d 8
dynamic
ECDH Public key is
52938-26772-53591-63596-
42247-16425-12976-24698-
35414-08057-12158-35945-
32398-36196-48932-06430-
10148914 Sending network management reply
10149410 nm_fsm_post_event event: NM_EV_FRAME_RECEIVED state: NM_IDLE
10149410 NetworkManagementCommandHandler 52 3
10149411 Age is seconds 1
10149416 Sending network management reply
10149422 nm_fsm_post_event event: NM_EV_FRAME_RECEIVED state: NM_IDLE
10149423 NetworkManagementCommandHandler 34 d
10149589 Sending network management reply
10149596 Sending long attempt
10149596 skip to create new server session cause Only accept create new session if content type is Handshake
10149597 ((u8_t*)uip_appdata)[17]
session_done_for_uipbuf
10149598 DTLS Classic node session package
10149599 queue_send_done to node 72 queue 2
10152011 Sending long attempt
10152011 skip to create new server session cause Only accept create new session if content type is Handshake
10152011 ((u8_t*)uip_appdata)[17]
10152011 DTLS Classic node session package
10152011 queue_send_done to node 72 queue 2
10155124 Sending long attempt
10155125 skip to create new server session cause Only accept create new session if content type is Handshake
10155125 ((u8_t*)uip_appdata)[17]
10155125 DTLS Classic node session package
10155125 queue_send_done to node 72 queue 2
10157640 Sending long attempt
10157641 skip to create new server session cause Only accept create new session if content type is Handshake
10157641 ((u8_t*)uip_appdata)[17]
10157641 DTLS Classic node session package
10157641 queue_send_done to node 72 queue 2
10160735 Sending long attempt
10160736 skip to create new server session cause Only accept create new session if content type is Handshake
10160736 ((u8_t*)uip_appdata)[17]
10160736 DTLS Classic node session package
10160736 queue_send_done to node 72 queue 2

If I look at the difference between successful log and unsuccessful log, I always get “create new server session” when I succeed. And I always get “skip to create new server session cause Only accept create new session if content type is Handshake” when I failed.

I found that after deleting and registering the device after 20 seconds, it succeeds. But when deleting the device and registering the device within 5 seconds, the above log was always taken.
What is the problem with zip gateway?
Why creating new server session fail when I try to register device within 5 seconds?
and how can I fix it?


#2

zipgateway is limited in the number of DTLS sessions it can keep open at any given time. in your example, the HC API from Z-Ware seems to have used all them up. Furthermore, it seems that it’s either holding on to the connections cause it’s still using them for something, or it’s not closing them when it no longer needs them, and just leaving them hanging around until zipgateway closes them after an inactivity timeout.

As far as I can see, this doesn’t seem to be something you can fix yourself, but I’m also not familiar enough with the HC API to know if there is a way to manually close a DTLS connection. If you have a Z-Wave Developer account, I suggest you bring the issue up with Z-Wave Support.


#3

Dear hanskroner,
thanks for your reply.
I don’t think that HC API from Z-Ware used all dtls session cause I only register one device.
By the way, I did not even think about inquiring to Z-Wave Support.
Thanks for the advice :slight_smile: