Getting Incorrect length (0) error #3
Description
I'm attempting to make use of your project and I've followed your README to start a copy of a server. Unfortunately I'm getting an error on my Instant AP (ArubaOS Version 8.10.0.12 LSR):
# show ap debug ble-relay iot-profile
---------------------------Profile[IoT-Utilities-Server]---------------------------
Identifier : 1722014359
authenticationURL : http://192.168.1.147:15444/auth
serverURL : ws://192.168.1.147:15443/telemetry
serverType : Telemetry Websocket
deviceClassFilter : Google,iBeacon,Unclassified,Aruba Beacons,EnOcean Sensors,Exposure Notification,WiFi RTLS Tags,WiFi Associated Stations,WiFi Unassociated Stations,Eddystone,Ability Smart Sensors,DirAct,Aruba Tags,EnOcean Switches,Aruba Sensors,sBeacon
reportingInterval : 10 second
authentication-mode : password
clientID : aruba-iot
username : USERNAME_HERE
password : *****
rssiReporting : Average
environmentType : office
bleDataForwarding : TRUE
Server Connection State
--------------------------
TransportContext : Connection Terminating
Fail Reason : Incorrect length (0)
Last Data Update : 2024-07-26 17:11:41
Last Send Time : 2024-07-26 17:11:16
TransType : Websocket
with the following log on the AP side:
# show ap debug ble-relay ws-log IoT-Utilities-Server
...
LWS0: 2024-07-26 16:50:31: br_wss_start:871 retries exhausted... restarting connection attempts from the beginning
LWS0: 2024-07-26 16:50:31: br_wss_start:784 profile:IoT-Utilities-Server type:2 mode:1
LWS0: 2024-07-26 16:50:31: br_wss_start:787 handshake attempt:0 connection_status:5 ws_state_nbf:0
LWS0: 2024-07-26 16:50:31: handshake: [http://192.168.1.147:15444/auth] send handshake using curl with proxy:n/a, username:n/a, password:n/a
LWS0: 2024-07-26 16:50:31: send request
POST /auth HTTP/1.0
HOST: 192.168.1.147:15444
Content-Type: application/json
Accept: application/json
Content-Length: 133
{"password":"PASSWORD_HERE","grant_type":"password","client_id":"aruba-iot","username":"USERNAME_HERE","scope":"Aruba_IoT_Framework"}
LWS0: 2024-07-26 16:50:31: ath_atw_auth_jwt: profile(IoT-Utilities-Server) http send ok, request <http://192.168.1.147:15444/auth>
LWS0: 2024-07-26 16:50:31: ath_atw_auth_jwt: profile(IoT-Utilities-Server) response <HTTP/1.0 200 OK
Server: BaseHTTP/0.6 Python/3.11.2
Date: Fri, 26 Jul 2024 20:50:29 GMT
Content-Type: application/json
{"access_token": "eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJzY29wZSI6InRlbGVtZXRyeSIsImlzcyI6IklvVC1VdGlsaXRpZXMgUHl0aG9uIERlbW8gU2VydmVyIiwiaWF0IjoxNzIyMDI3MDI5LCJuYmYiOjE3MjIwMjY5NjksImV4cCI6MTcyMjAyNzYyOX0.hYY0LNvZJPEb7K-IbV-fErLFS41m0sTQWAaN3liuKQw", "refresh_token": "eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJzY29wZSI6InJlZnJlc2giLCJpc3MiOiJJb1QtVXRpbGl0aWVzIFB5dGhvbiBEZW1vIFNlcnZlciIsImlhdCI6MTcyMjAyNzAyOSwibmJmIjoxNzIyMDI2OTY5LCJleHAiOjE3MjIxMTM0Mjl9.3NBTODIGxZNaOEbvTXPmKBR5LNv5mrv9KsauQIzwGiY", "api_url": "", "token_type": "bearer", "expires_in": "600s", "scope": "Aruba_IoT_Framework"}>
LWS0: 2024-07-26 16:50:31: parser_ath_atw_handsahke_json:268 token_type present: bearer
LWS0: 2024-07-26 16:50:31: parser_ath_atw_handsahke_json:277 api_url present:
LWS0: 2024-07-26 16:50:31: parser_ath_atw_handsahke_json:285 url:, host:, path:
LWS0: 2024-07-26 16:50:31: Successful save refresh_token(eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJzY29wZSI6InJlZnJlc2giLCJpc3MiOiJJb1QtVXRpbGl0aWVzIFB5dGhvbiBEZW1vIFNlcnZlciIsImlhdCI6MTcyMjAyNzAyOSwibmJmIjoxNzIyMDI2OTY5LCJleHAiOjE3MjIxMTM0Mjl9.3NBTODIGxZNaOEbvTXPmKBR5LNv5mrv9KsauQIzwGiY) to flash
LWS0: 2024-07-26 16:50:31: parser_ath_atw_handsahke_json:324 parser exp: 0, iat: 1722027031, nbf: 0
LWS0: 2024-07-26 16:50:31: 127.0.0.1 auth: login: ret: 0 req: 133 rsp: 719 idx: 0 dur: 0
LWS0: 2024-07-26 16:50:31: br_wss_start:794 handshake success ws_state_nbf:1
LWS0: 2024-07-26 16:50:36: br_wss_start:787 handshake attempt:0 connection_status:5 ws_state_nbf:1
LWS0: 2024-07-26 16:50:36: br_wss_start:806 handshake done .. ws_state_nbf:1... waiting till elappsed:5 > wait:2572940265
LWS0: 2024-07-26 16:50:36: br_wss_start:809 waited till url/token is valid... proceed to websocket connection attempt
LWS0: 2024-07-26 16:50:36: br_wss_start:826 profile:IoT-Utilities-Server... handshake phase completed; start websocket connection attempt
LWS0: 2024-07-26 16:50:36: br_wss_start:840 websocket connection attempt:0 auth_mode:1
LWS0: 2024-07-26 16:50:41: Creating Vhost 'default' (serving disabled), 1 protocols, IPv6 off
LWS0: 2024-07-26 16:50:41: lws_protocol_init
LWS0: 2024-07-26 16:50:41: br_wss_loop:596 host:. port:80 ssl:0 path:/ token:eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJzY29wZSI6InRlbGVtZXRyeSIsImlzcyI6IklvVC1VdGlsaXRpZXMgUHl0aG9uIERlbW8gU2VydmVyIiwiaWF0IjoxNzIyMDI3MDI5LCJuYmYiOjE3MjIwMjY5NjksImV4cCI6MTcyMjAyNzYyOX0.hYY0LNvZJPEb7K-IbV-fErLFS41m0sTQWAaN3liuKQw
LWS0: 2024-07-26 16:50:41: br_wss_loop:612 lws_client_connect_info host:.
LWS0: 2024-07-26 16:50:41: lws_client_connect_via_info: role binding to h1
LWS0: 2024-07-26 16:50:41: lws_client_connect_via_info: protocol binding to http-only
LWS0: 2024-07-26 16:50:41: lws_client_connect_via_info: wsi 0x65033c: h1 http-only entry
LWS0: 2024-07-26 16:50:41: lws_header_table_attach: wsi 0x65033c: ah (nil) (tsi 1, count = 0) in
LWS0: 2024-07-26 16:50:41: _lws_create_ah: created ah 0x64fedc (size 4096): pool length 1
LWS0: 2024-07-26 16:50:41: lws_header_table_attach: did attach wsi 0x65033c: ah 0x64fedc: count 1 (on exit)
LWS0: 2024-07-26 16:50:41: lws_client_connect_2_dnsreq: 0x65033c: lookup :80
LWS0: 2024-07-26 16:50:41: lws_getaddrinfo46: getaddrinfo '' says -2
LWS0: 2024-07-26 16:50:41: lws_client_connect_3_connect: lws_getaddrinfo46 failed -2
LWS0: 2024-07-26 16:50:41: callback_ws_all: LWS_CALLBACK_CLIENT_CONNECTION_ERROR
LWS0: 2024-07-26 16:50:41: rops_destroy_role_h1: ah det due to close
LWS0: 2024-07-26 16:50:41: __lws_header_table_detach: wsi 0x65033c: ah 0x64fedc (tsi=1, count = 1)
LWS0: 2024-07-26 16:50:41: __lws_header_table_detach: nobody usable waiting
LWS0: 2024-07-26 16:50:41: _lws_destroy_ah: freed ah 0x64fedc : pool length 0
LWS0: 2024-07-26 16:50:41: __lws_header_table_detach: wsi 0x65033c: ah 0x64fedc (tsi=1, count = 0)
LWS0: 2024-07-26 16:50:41: lws_vhost_destroy1
LWS0: 2024-07-26 16:50:41: __lws_vhost_destroy2: 0x637974
LWS0: 2024-07-26 16:50:41: __lws_vhost_destroy2: Freeing vhost 0x637974
LWS0: 2024-07-26 16:50:41: br_wss_start:864 attempt:0 ended.
...
Any ideas on what am I doing wrong? I've even tried re-compiling protobuf specs for my exact version of AOS 8.10 (aruba-8.10-iot-protobuf-spec-AP.zip) but that does not appear to make a differrence.
On the python server side all I'm getting is:
2024-07-26 17:07:09 172.17.0.1 - - [26/Jul/2024 21:07:09] "POST /auth HTTP/1.0" 200 -
2024-07-26 17:07:30 172.17.0.1 - - [26/Jul/2024 21:07:30] "POST /auth HTTP/1.0" 200 -
2024-07-26 17:07:30 172.17.0.1 - - [26/Jul/2024 21:07:30] "POST /auth HTTP/1.0" 200 -
2024-07-26 17:07:31 172.17.0.1 - - [26/Jul/2024 21:07:31] "POST /auth HTTP/1.0" 200 -
2024-07-26 17:11:24 172.17.0.1 - - [26/Jul/2024 21:11:24] "POST /auth HTTP/1.0" 200 -
2024-07-26 17:11:45 172.17.0.1 - - [26/Jul/2024 21:11:45] "POST /auth HTTP/1.0" 200 -
2024-07-26 17:11:46 172.17.0.1 - - [26/Jul/2024 21:11:46] "POST /auth HTTP/1.0" 200 -
2024-07-26 17:11:46 172.17.0.1 - - [26/Jul/2024 21:11:46] "POST /auth HTTP/1.0" 200 -
2024-07-26 17:15:39 172.17.0.1 - - [26/Jul/2024 21:15:39] "POST /auth HTTP/1.0" 200 -
I don't understand why would AP try to establish connection to host . on port 80...