OTA failure: GET request ignored

[rith87]

Thank you for the awesome library!

Unfortunately, I haven't managed to get fota to work with the ubisen server that is running locally and the fota module from this repo. On the ESP side:

FOTA client: Connect to ip 192.168.30.134:80
FOTA Client: Sent request
FOTA Client: Request timeout, close connection
FOTA Client: Disconnect
Final response: {"application":"otaupdate","last":{"version":"0.0.2","created":"2015-11-19T14:03:34.027Z","protocol":"http:","host":"192.168.30.134","path":"/firmwares/564dd6b6cc2a19680ca603f0/download"}}
    Version 0.0.2
    Host 192.168.30.134
    Path /firmwares/564dd6b6cc2a19680ca603f0/download
    Protocol http:
FOTA Client: Preparing to get firmware
Firmware client: Connect to 192.168.30.134:80
Firmware client: Connected
system_upgrade_start
upgrade_connect
upgrade_connect_cb
GET /firmwares/564dd6b6cc2a19680ca603f0/download HTTP/1.1
Host: 192.168.30.134
Connection: keep-alive
Cache-Control: no-cache
User-Agent: ESP8266
Accept: */*
Content-Type: application/json

HEAD /firmwares/564dd6b6cc2a19680ca603f0/download HTTP/1.1
Host: 192.168.30.134
Connection: close
Cache-Control: no-cache
User-Agent: ESP8266
Accept: */*
Content-Type: application/json

Firmware client: Disconnect
upgrade_check
Firmware upgrade fail

On the server side,

GET /api/otaupdate/versions/image2 200 4.599 ms - 188
HEAD /firmwares/564dd6b6cc2a19680ca603f0/download - - ms - -

So, somehow, the GET request for /firmwares/564dd6b6cc2a19680ca603f0/download is never received but the HEAD request is. Any ideas why this is the case?

[rith87]

Also, I haven't been able to access http://103.253.146.183/. Is it up and running?

[nqd]

Yes, the http://103.253.146.183/ is down, my digitalocean run out of credit ;).

Its quite strange that ESP request GET (which is fail) then HEAD. I will need to look into the problem at this weekend. Of course if you find any problem, plz submit solution.

[rith87]

I've posted a question on the Espressif forums: http://bbs.espressif.com/viewtopic.php?f=7&t=1408&p=4696#p4696, since it is some weird behavior in the firmware upgrade function (which to me seems like a huge black box).

It seems like the GET request is just a printout and the HEAD request is sent first. Anyway, I'll update as soon as I get more information from Espressif.

[rith87]

Another strange observation:

HEAD /firmwares/5651c5ffbcd1c23416107ba9/download - - ms - -

There's no return code for HEAD request from the server. Any chance you can get http://103.253.146.183/ up and running again? Or do you know of anyone else I can hit up?

[rith87]

Another interesting observation:

curl -X HEAD -i http://localhost/firmwares/5651c5ffbcd1c23416107ba9/download
HTTP/1.1 302 Moved Temporarily
X-Powered-By: Express
Location: /login
Vary: Accept, Accept-Encoding
Content-Type: text/plain; charset=utf-8
Content-Length: 40
Set-Cookie: express:sess=eyJwYXNzcG9ydCI6e30sImZsYXNoIjp7fX0=; path=/; httponly
Set-Cookie: express:sess.sig=XGtahmr2ydmPUKdcJHretZ8sOY0; path=/; httponly
Date: Sun, 22 Nov 2015 14:53:20 GMT
Connection: keep-alive

It returns a 302, so this definitely seems like unexpected behavior from the server side (ESPs have problems dealing with a 302, don't they?).

[rith87]

Well, I figured that the 302 was due to authentication and disabled that temporarily. My curl requests return a 200 but still no return code on the ESP side...

curl -X HEAD -H "Connection: close" -i http://localhost/firmwares/5651c5ffbcd1c23416107ba9/download
HTTP/1.1 200 OK
X-Powered-By: Express
Content-disposition: attachment; filename=4096_user2.bin
Content-type: application/octet-stream
Content-Length: 275428
ETag: W/"8AdilsMPY5qihgLN03z9mQ=="
Set-Cookie: express:sess=eyJwYXNzcG9ydCI6e30sImZsYXNoIjp7fX0=; path=/; httponly
Set-Cookie: express:sess.sig=XGtahmr2ydmPUKdcJHretZ8sOY0; path=/; httponly
Date: Mon, 23 Nov 2015 05:48:17 GMT
Connection: close

Logs from the server side:

GET /api/otaupdate/versions/image2 200 8.284 ms - 188
HEAD /firmwares/5651c5ffbcd1c23416107ba9/download - - ms - -

[rith87]

This is actually really strange. All I get from the HTTP request is an ACK (233 is the ESP, 134 is the server):

43  20.146158000    192.168.30.233  192.168.30.134  HTTP    54  HEAD /firmwares/5651c5ffbcd1c23416107ba9/download HTTP/1.1 Continuation or non-HTTP traffic
44  20.146195000    192.168.30.134  192.168.30.233  TCP 54  http > 42112 [ACK] Seq=2 Ack=200 Win=30016 Len=0
48  36.781921000    192.168.30.134  192.168.30.233  TCP 54  http > 20294 [FIN, ACK] Seq=1 Ack=1 Win=29200 Len=0

Any chance you can get http://103.253.146.183/ up and running again?

[nqd]

• Did you run the commit 4519a9499ab66dcae87d0f5ac599063fa29d7e81 of https://github.com/ubisen/ota-update? We was going to implement some sort of security in downloading firmware, but later decide to leave that to developer.
• If strange things happend, check commit 76b1fc5e8032210bc771b76324ebec582e5ea412 of https://github.com/nqd/esp8266-sdk/, this one is well tested.

If the error still persist, please run your code somewhere so that I could have a chance to test this.

Hope that help you @rith87

[rith87]

Without the security fixes,

9   0.062260000 192.168.30.233  192.168.30.134  TCP 252 [TCP segment of a reassembled PDU]
12  0.064925000 192.168.30.233  192.168.30.134  HTTP    54  HEAD /firmwares/5651c5ffbcd1c23416107ba9/download HTTP/1.1 Continuation or non-HTTP traffic
13  0.064951000 192.168.30.134  192.168.30.233  TCP 54  http > 37967 [ACK] Seq=2 Ack=200 Win=30016 Len=0

It seems like the HTTP HEAD request is broken into two parts and then the server just responds with an ACK but no HTTP response. Could this be caused by a change in the 1.4 SDK? I haven't tried downgrading to 1.3 yet...