Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[ESP8266HTTPClient] Updates from HTTPS servers fail before transferring new binary begins #8079

Closed
pacau999 opened this issue May 24, 2021 · 19 comments · Fixed by #8136
Closed
Labels
waiting for feedback Waiting on additional info. If it's not received, the issue may be closed.

Comments

@pacau999
Copy link

pacau999 commented May 24, 2021

http update not working on this arduino-core version

HTTP_UPDATE_FAILD Error (-106): Verify Bin Header Failed;
I just instaled arduino core 2.7.4 and it worked.

NodeMCU 1.0, Arduino 1.8.15, code

httpUpdateSecure

@earlephilhower
Copy link
Collaborator

Please run with full debugging enabled and attach the logs. That can make pinpointing things much simpler for everyone.

@earlephilhower earlephilhower added the waiting for feedback Waiting on additional info. If it's not received, the issue may be closed. label May 24, 2021
@frankygoop
Copy link

I got the same error with Core 3.0.0. With Core 2.7.4 works fine.

@d-a-v
Copy link
Collaborator

d-a-v commented May 28, 2021

You will help us if you consider the previous message:

Please run with full debugging enabled and attach the logs. That can make pinpointing things much simpler for everyone.

@frankygoop
Copy link

I will be glad to help. Would you indicate how to get the log?

@d-a-v
Copy link
Collaborator

d-a-v commented May 28, 2021

Thanks !
In the arduino IDE, it's tools>Debug Port and tools>Debug Level

@frankygoop
Copy link

Hello, What level of debug do you require?

@d-a-v
Copy link
Collaborator

d-a-v commented May 28, 2021

I think the one before the last would give all details.

@frankygoop
Copy link

frankygoop commented May 29, 2021

This is all I could catch. I had to reduce the level of debug because it was scrolling too fast.
I am downloading the bin file from a private Github. I had to add Bearer header into the library to make it work. I dont know any method to add custom headers to the HttpUpdate.

[HTTP-Client][begin] url: https://api.github.com/repos/...............bin
[HTTP-Client][begin] host: api.github.com port: 443 url: /repos/............bin
[HTTP-Client][sendRequest] type: 'GET' redirCount: 0
BSSL:_connectSSL: start connection
BSSL:CERT: 30 82 05 05 30 82 04 ab a0 03 02 01 02 02 10 01 68 d5 75 f1 ce 87 28 ad 95 a8 f1 1e f1 59 8b 30 0a 06 08 2a 86 48 ce 3d 04 03 02 30 67 31 0b 30 09 06 03 55 04 06 13 02 55 53 31 17 30 15 06 03 55 04 0a 13 0e 44 69 67 69 43 65 72 74 2c 20 49 6e 63 2e 31 3f 30 3d 06 03 55 04 03 13 36 44 69 67 69 43 65 72 74 20 48 69 67 68 20 41 73 73 75 72 61 6e 63 65 20 54 4c 53 20 48 79 62 72 69 64 20 45 43 43 20 53 48 41 32 35 36 20 32 30 32 30 20 43 41 31 30 1e 17 0d 32 31 30 33 32 35 30 30 30 30 30 30 5a 17 0d 32 32 30 33 33 30 32 33 35 39 35 39 5a 30 68 31 0b 30 09 06 03 55 04 06 13 02 55 53 31 13 30 11 06 03 55 04 08 13 0a 43 61 6c 69 66 6f 72 6e 69 61 31 16 30 14 06 03 55 04 07 13 0d 53 61 6e 20 46 72 61 6e 63 69 73 63 6f 31 15 30 13 06 03 55 04 0a 13 0c 47 69 74 48 75 
BSSL:CERT: 62 2c 20 49 6e 63 2e 31 15 30 13 06 03 55 04 03 0c 0c 2a 2e 67 69 74 68 75 62 2e 63 6f 6d 30 59 30 13 06 07 2a 86 48 ce 3d 02 01 06 08 2a 86 48 ce 3d 03 01 07 03 42 00 04 94 bf 7f fb 44 e2 75 32 00 2c f7 d4 fe d8 92 ea 92 3c cc 02 24 ad 4e 29 a2 15 25 75 57 34 6d be 8e dc 50 11 97 77 27 a8 80 ca f5 2a 05 eb 9c f7 c6 24 7a 5e c9 c5 4b c1 74 3b 2f dc 85 74 7f 91 a3 82 03 36 30 82 03 32 30 1f 06 03 55 1d 23 04 18 30 16 80 14 50 61 a6 a0 d2 35 c4 11 2a 20 8d 1f 0f ac 42 f0 cd 29 cf 4b 30 1d 06 03 55 1d 0e 04 16 04 14 cf cb 0c eb ee 3d 71 24 f8 7e 96 5a 71 a6 4a 9b d5 dc c6 ce 30 23 06 03 55 1d 11 04 1c 30 1a 82 0c 2a 2e 67 69 74 68 75 62 2e 63 6f 6d 82 0a 67 69 74 68 75 62 2e 63 6f 6d 30 0e 06 03 55 1d 0f 01 01 ff 04 04 03 02 07 80 30 1d 06 03 55 1d 25 04 16 30 
BSSL:CERT: 14 06 08 2b 06 01 05 05 07 03 01 06 08 2b 06 01 05 05 07 03 02 30 81 b1 06 03 55 1d 1f 04 81 a9 30 81 a6 30 51 a0 4f a0 4d 86 4b 68 74 74 70 3a 2f 2f 63 72 6c 33 2e 64 69 67 69 63 65 72 74 2e 63 6f 6d 2f 44 69 67 69 43 65 72 74 48 69 67 68 41 73 73 75 72 61 6e 63 65 54 4c 53 48 79 62 72 69 64 45 43 43 53 48 41 32 35 36 32 30 32 30 43 41 31 2e 63 72 6c 30 51 a0 4f a0 4d 86 4b 68 74 74 70 3a 2f 2f 63 72 6c 34 2e 64 69 67 69 63 65 72 74 2e 63 6f 6d 2f 44 69 67 69 43 65 72 74 48 69 67 68 41 73 73 75 72 61 6e 63 65 54 4c 53 48 79 62 72 69 64 45 43 43 53 48 41 32 35 36 32 30 32 30 43 41 31 2e 63 72 6c 30 3e 06 03 55 1d 20 04 37 30 35 30 33 06 06 67 81 0c 01 02 02 30 29 30 27 06 08 2b 06 01 05 05 07 02 01 16 1b 68 74 74 70 3a 2f 2f 77 77 77 2e 64 69 67 69 63 65 72 
BSSL:CERT: 74 2e 63 6f 6d 2f 43 50 53 30 81 92 06 08 2b 06 01 05 05 07 01 01 04 81 85 30 81 82 30 24 06 08 2b 06 01 05 05 07 30 01 86 18 68 74 74 70 3a 2f 2f 6f 63 73 70 2e 64 69 67 69 63 65 72 74 2e 63 6f 6d 30 5a 06 08 2b 06 01 05 05 07 30 02 86 4e 68 74 74 70 3a 2f 2f 63 61 63 65 72 74 73 2e 64 69 67 69 63 65 72 74 2e 63 6f 6d 2f 44 69 67 69 43 65 72 74 48 69 67 68 41 73 73 75 72 61 6e 63 65 54 4c 53 48 79 62 72 69 64 45 43 43 53 48 41 32 35 36 32 30 32 30 43 41 31 2e 63 72 74 30 0c 06 03 55 1d 13 01 01 ff 04 02 30 00 30 82 01 03 06 0a 2b 06 01 04 01 d6 79 02 04 02 04 81 f4 04 81 f1 00 ef 00 76 00 29 79 be f0 9e 39 39 21 f0 56 73 9f 63 a5 77 e5 be 57 7d 9c 60 0a f8 f9 4d 5d 26 5c 25 5d c7 84 00 00 01 78 6a bd f9 54 00 00 04 03 00 47 30 45 02 20 04 c9 f0 35 07 92 20 
BSSL:CERT: 80 05 4a ea 86 c0 5c ff 58 ac 53 cd c3 a5 16 03 47 20 e7 e6 49 78 d1 d7 fa 02 21 00 81 fa c9 e9 a9 88 a2 8c 25 0a 68 04 d8 1a 5c e9 1e 0f 73 b9 e4 88 61 66 16 da b7 f6 81 d5 5e 84 00 75 00 22 45 45 07 59 55 24 56 96 3f a1 2f f1 f7 6d 86 e0 23 26 63 ad c0 4b 7f 5d c6 83 5c 6e e2 0f 02 00 00 01 78 6a bd f9 ad 00 00 04 03 00 46 30 44 02 20 5b 0d 6a 85 67 0b 5b 32 38 e2 46 de a3 2b 15 50 ed 0c 82 19 bb 25 92 92 35 55 29 e5 ab 59 56 60 02 20 41 e3 db ac bb 6c 55 cf df fb b5 2a 8d 73 ed f0 18 60 c6 d7 6f 9b f4 f3 f4 7c 44 a8 b6 ec a5 d7 30 0a 06 08 2a 86 48 ce 3d 04 03 02 03 48 00 30 45 02 21 00 b9 a1 93 26 e3 64 bb b2 c7 c4 0a 22 81 63 88 6f 0d e4 3b 34 da 67 1a 14 67 ef cd 6d 59 a2 85 cb 02 20 22 f3 f9 2b 24 ab fa 84 e6 e8 f2 96 7b 81 e0 3b b6 86 f0 ba ee 51 57 
BSSL:CERT: de ca c1 08 93 c3 f0 f5 f6 
BSSL:Connected!
[HTTP-Client] connected to api.github.com:443
[HTTP-Client] sending request header
-----
GET /repos/.................bin HTTP/1.0
Host: api.github.com
User-Agent: ESP8266-http-Update
Connection: close
x-ESP8266-Chip-ID: 7904961
x-ESP8266-STA-MAC: DC:4F:22:78:9E:C1
x-ESP8266-AP-MAC: DE:4F:22:78:9E:C1
x-ESP8266-free-space: 2641920
x-ESP8266-sketch-size: 500768
x-ESP8266-sketch-md5: c27965.............26992
x-ESP8266-chip-size: 4194304
x-ESP8266-sdk-version: 2.2.2-dev(38a443e)
Accept: application/vnd.github.v3.raw
authorization: Bearer gh.......................HH
x-ESP8266-mode: sketch
Content-Length: 0

-----
[HTTP-Client][handleHeaderResponse] RX: 'HTTP/1.1 200 OK
'
[HTTP-Client][handleHeaderResponse] RX: 'Server: GitHub.com
'
[HTTP-Client][handleHeaderResponse] RX: 'Date: Sat, 29 May 2021 00:48:09 GMT
'
[HTTP-Client][handleHeaderResponse] RX: 'Content-Type: application/vnd.github.v3.raw; charset=utf-8
'
[HTTP-Client][handleHeaderResponse] RX: 'Content-Length: 483232
'
[HTTP-Client][handleHeaderResponse] RX: 'Cache-Control: private, max-age=60, s-maxage=60
'
[HTTP-Client][handleHeaderResponse] RX: 'Vary: Accept, Authorization, Cookie, X-GitHub-OTP
'
[HTTP-Client][handleHeaderResponse] RX: 'ETag: "932df99358f7ff14ef80902e39234b700e76c77f"
'
[HTTP-Client][handleHeaderResponse] RX: 'Last-Modified: Fri, 28 May 2021 21:45:58 GMT
'
[HTTP-Client][handleHeaderResponse] RX: 'X-OAuth-Scopes: read:org, repo
'
[HTTP-Client][handleHeaderResponse] RX: 'X-Accepted-OAuth-Scopes: 
'
[HTTP-Client][handleHeaderResponse] RX: 'X-GitHub-Media-Type: github.v3; param=raw
'
[HTTP-Client][handleHeaderResponse] RX: 'X-RateLimit-Limit: 5000
'
[HTTP-Client][handleHeaderResponse] RX: 'X-RateLimit-Remaining: 4996
'
[HTTP-Client][handleHeaderResponse] RX: 'X-RateLimit-Reset: 1622252269
'
[HTTP-Client][handleHeaderResponse] RX: 'X-RateLimit-Used: 4
'
[HTTP-Client][handleHeaderResponse] RX: 'X-RateLimit-Resource: core
'
[HTTP-Client][handleHeaderResponse] RX: 'Access-Control-Expose-Headers: ETag, Link, Location, Retry-After, X-GitHub-OTP, X-RateLimit-Limit, X-RateLimit-Remaining, X-RateLimit-Used, X-RateLimit-Resource, X-RateLimit-Reset, X-OAuth-Scopes, X-Accepted-OAuth-Scopes, X-Poll-Interval, X-GitHub-Media-Type, Deprecation, Sunset
'
[HTTP-Client][handleHeaderResponse] RX: 'Access-Control-Allow-Origin: *
'
[HTTP-Client][handleHeaderResponse] RX: 'Strict-Transport-Security: max-age=31536000; includeSubdomains; preload
'
[HTTP-Client][handleHeaderResponse] RX: 'X-Frame-Options: deny
'
[HTTP-Client][handleHeaderResponse] RX: 'X-Content-Type-Options: nosniff
'
[HTTP-Client][handleHeaderResponse] RX: 'X-XSS-Protection: 0
'
[HTTP-Client][handleHeaderResponse] RX: 'Referrer-Policy: origin-when-cross-origin, strict-origin-when-cross-origin
'
[HTTP-Client][handleHeaderResponse] RX: 'Content-Security-Policy: default-src 'none'
'
[HTTP-Client][handleHeaderResponse] RX: 'Vary: Accept-Encoding, Accept, X-Requested-With
'
[HTTP-Client][handleHeaderResponse] RX: 'X-GitHub-Request-Id: CE7D:3158:C4F842:17C37CE:60B18F47
'
[HTTP-Client][handleHeaderResponse] RX: 'connection: close
'
[HTTP-Client][handleHeaderResponse] RX: '
'
[HTTP-Client][handleHeaderResponse] code: 200
[HTTP-Client][handleHeaderResponse] size: 483232
BSSL:peekBytes: Not connected
[HTTP-Client][end] tcp is closed
HTTP_UPDATE_FAILD Error (-106): Verify Bin Header Failed

@earlephilhower
Copy link
Collaborator

I just ran a test of the httpUpdate example against my local server and found no issue. This may be related to the actual binary you're trying to download. Can someone please post a public link we can run against? Right now, I'm unable to repro anything:

10:42:02.509 -> [SETUP] WAIT 2...
10:42:03.503 -> [SETUP] WAIT 1...
10:42:05.856 -> CALLBACK:  HTTP update process started
10:42:05.956 -> CALLBACK:  HTTP update process at 0 of 270576 bytes...
10:42:05.989 -> CALLBACK:  HTTP update process at 0 of 270576 bytes...
10:42:06.022 -> CALLBACK:  HTTP update process at 4096 of 270576 bytes...
10:42:06.088 -> CALLBACK:  HTTP update process at 8192 of 270576 bytes...
10:42:06.187 -> CALLBACK:  HTTP update process at 12288 of 270576 bytes...
...
10:42:10.462 -> CALLBACK:  HTTP update process at 270576 of 270576 bytes...
10:42:10.462 -> CALLBACK:  HTTP update process at 270576 of 270576 bytes...
10:42:10.462 -> CALLBACK:  HTTP update process finished
10:42:10.561 -> 
10:42:10.561 ->  ets Jan  8 2013,rst cause:2, boot mode:(3,6)
10:42:10.561 -> 
10:42:10.561 -> load 0x4010f000, len 3460, room 16 
10:42:10.561 -> tail 4
10:42:10.561 -> chksum 0xcc
10:42:10.561 -> load 0x3fff20b8, len 40, room 4 
10:42:10.561 -> tail 4
10:42:10.561 -> chksum 0xc9
10:42:10.561 -> csum 0xc9
10:42:10.561 -> v0004b1e0
10:42:10.561 -> @cp:B0
10:42:13.975 -> ld
10:42:14.008 -> 
10:42:14.008 -> 
10:42:14.008 -> ** pgm_read_float_unaligned() test **
10:42:14.008 -> specimen: 3.141593
10:42:14.008 -> readout:  3.141593

@frankygoop
Copy link

I suggest to try to do the test from a private github repository. The bin file I am downloading is the same that works fine with core 2.7.4.

@earlephilhower
Copy link
Collaborator

@frankygoop sorry, but I don't have any private repos as the maintainers don't use GH professionally.

If you or someone else has, say, a public blink.binthat you could repro the failure on that would be fine. Especially if the bin is an older one and was built in some way different than we're using locally (since it's reporting a format error).

@zhfei1979
Copy link

Got the same issue with 3.0.0, works fine with 2.7.4.
Issue can be reproduced with:
BearSSL::WiFiClientSecure client;
client.setFingerprint(cfgFP);
ESPhttpUpdate.update(client, urlHTTPS);

=============== ESP8266httpUpdate.cpp handleUpdate==========
WiFiClient * tcp = http.getStreamPtr();

....
uint8_t buf[4];
uint8_t x = tcp->peekBytes(&buf[0], 4);
DEBUG_HTTP_UPDATE("[httpUpdate] peekBytes x:%d\n", x);
if(x != 4) {
DEBUG_HTTP_UPDATE("[httpUpdate] peekBytes magic header failed\n");
_setLastError(HTTP_UE_BIN_VERIFY_HEADER_FAILED);
http.end();
return HTTP_UPDATE_FAILED;
}

The above codes prints x=0 causes the "Verify Bin Header Failed" error:

[httpUpdate] Header read fin.
[httpUpdate] Server header:
[httpUpdate] - code: 200
[httpUpdate] - len: 466352
[httpUpdate] ESP8266 info:
[httpUpdate] - free Space: 581632
[httpUpdate] - current Sketch Size: 466352
[httpUpdate] runUpdate flash...
[httpUpdate] peekBytes x:0
[httpUpdate] peekBytes magic header failed
UpdateByOTA: Verify Bin Header Failed!, 8261
state: 5 -> 0 (0)
rm 0
del if0
usl

@earlephilhower
Copy link
Collaborator

Again, folks, we need a public example that fails w/3.0 but passes w/the prior release. I've tried my own way several times and things "just work" so there's nothing we can do w/o a failing public example.

If it's failing but you've got some proprietary code that you don't want others to download, why not build a blink.ino update and see if that fails? You can point us at it to look at things without exposing your own stuff. OTW there's nothing the maintainers can do...

@zhfei1979
Copy link

zhfei1979 commented Jun 15, 2021

I modified httpUpdate as following and reproduced it, you can try run the sketch with core 3.0.0, see if it happens.
The file "https://apps.95wd.com.cn/httpUpdate.ino.generic.bin" was generated with the following sketch codes too.

/**
   httpUpdate.ino

    Created on: 27.11.2015

*/

#include <Arduino.h>

#include <ESP8266WiFi.h>
#include <ESP8266WiFiMulti.h>

#include <ESP8266HTTPClient.h>
#include <ESP8266httpUpdate.h>

#ifndef APSSID
#define APSSID "GL-H6-2"
#define APPSK  "GlH62401"
#endif

ESP8266WiFiMulti WiFiMulti;

void setup() {

  Serial.begin(74880);
  Serial.setDebugOutput(true);

  Serial.println();
  Serial.println();
  Serial.println();

  for (uint8_t t = 4; t > 0; t--) {
    Serial.printf("[SETUP] WAIT %d...\n", t);
    Serial.flush();
    delay(1000);
  }

  WiFi.mode(WIFI_STA);
  WiFiMulti.addAP(APSSID, APPSK);


}

void update_started() {
  Serial.println("CALLBACK:  HTTP update process started");
}

void update_finished() {
  Serial.println("CALLBACK:  HTTP update process finished");
}

void update_progress(int cur, int total) {
  Serial.printf("CALLBACK:  HTTP update process at %d of %d bytes...\n", cur, total);
}

void update_error(int err) {
  Serial.printf("CALLBACK:  HTTP update fatal error code %d\n", err);
}


void loop() {
  // wait for WiFi connection
  if ((WiFiMulti.run() == WL_CONNECTED)) {

    BearSSL::WiFiClientSecure client;//WiFiClient client;
    client.setFingerprint("36AC62F2D4A1BC79C417E2986DFA8E85FF024DCC");

    // The line below is optional. It can be used to blink the LED on the board during flashing
    // The LED will be on during download of one buffer of data from the network. The LED will
    // be off during writing that buffer to flash
    // On a good connection the LED should flash regularly. On a bad connection the LED will be
    // on much longer than it will be off. Other pins than LED_BUILTIN may be used. The second
    // value is used to put the LED on. If the LED is on with HIGH, that value should be passed
    ESPhttpUpdate.setLedPin(LED_BUILTIN, LOW);

    // Add optional callback notifiers
    ESPhttpUpdate.onStart(update_started);
    ESPhttpUpdate.onEnd(update_finished);
    ESPhttpUpdate.onProgress(update_progress);
    ESPhttpUpdate.onError(update_error);

    t_httpUpdate_return ret = ESPhttpUpdate.update(client, "https://apps.95wd.com.cn/httpUpdate.ino.generic.bin");
    // Or:
    //t_httpUpdate_return ret = ESPhttpUpdate.update(client, "server", 80, "file.bin");

    switch (ret) {
      case HTTP_UPDATE_FAILED:
        Serial.printf("HTTP_UPDATE_FAILD Error (%d): %s\n", ESPhttpUpdate.getLastError(), ESPhttpUpdate.getLastErrorString().c_str());
        break;

      case HTTP_UPDATE_NO_UPDATES:
        Serial.println("HTTP_UPDATE_NO_UPDATES");
        break;

      case HTTP_UPDATE_OK:
        Serial.println("HTTP_UPDATE_OK");
        break;
    }
  }
}

@earlephilhower
Copy link
Collaborator

Using the example posted and the remote server I am able to see the TCP connection hanging up on the ESP8266 before sending out any data:

12:43:23.635 -> [HTTP-Client] sending request header
12:43:23.635 -> -----
12:43:23.635 -> GET /httpUpdate.ino.generic.bin HTTP/1.0
12:43:23.635 -> Host: apps.95wd.com.cn
12:43:23.635 -> User-Agent: ESP8266-http-Update
12:43:23.635 -> Connection: close
12:43:23.635 -> x-ESP8266-Chip-ID: 2340006
12:43:23.635 -> x-ESP8266-STA-MAC: 60:01:94:23:B4:A6
12:43:23.635 -> x-ESP8266-AP-MAC: 62:01:94:23:B4:A6
12:43:23.668 -> x-ESP8266-free-space: 1662976
12:43:23.668 -> x-ESP8266-sketch-size: 431296
12:43:23.668 -> x-ESP8266-sketch-md5: 66ff0fbd78b2a795d52085d6b1b8bda3
12:43:23.668 -> x-ESP8266-chip-size: 4194304
12:43:23.668 -> x-ESP8266-sdk-version: 2.2.2-dev(38a443e)
12:43:23.668 -> x-ESP8266-mode: sketch
12:43:23.668 -> Content-Length: 0
12:43:23.668 -> 
12:43:23.668 -> -----
12:43:23.668 -> :wr 478 0
12:43:23.668 -> :wrc 478 478 0
12:43:23.867 -> :ack 478
12:43:23.867 -> :rn 258
12:43:23.867 -> :rch 258, 536
12:43:23.867 -> :rch 794, 536
12:43:23.867 -> :rd 5, 1330, 0
12:43:23.867 -> :rdi 258, 5
12:43:23.867 -> :rd 253, 1330, 5
12:43:23.867 -> :rdi 253, 253
12:43:23.867 -> :c 253, 258, 1330
12:43:23.867 -> [HTTP-Client][handleHeaderResponse] RX: 'HTTP/1.1 200 '
12:43:23.867 -> [HTTP-Client][handleHeaderResponse] RX: 'Accept-Ranges: bytes'
12:43:23.867 -> [HTTP-Client][handleHeaderResponse] RX: 'ETag: W/"414272-1623745148729"'
12:43:23.867 -> [HTTP-Client][handleHeaderResponse] RX: 'Last-Modified: Tue, 15 Jun 2021 08:19:08 GMT'
12:43:23.900 -> [HTTP-Client][handleHeaderResponse] RX: 'Content-Type: application/octet-stream'
12:43:23.900 -> [HTTP-Client][handleHeaderResponse] RX: 'Content-Length: 414272'
12:43:23.900 -> [HTTP-Client][handleHeaderResponse] RX: 'Date: Wed, 16 Jun 2021 19:43:00 GMT'
12:43:23.900 -> [HTTP-Client][handleHeaderResponse] RX: 'Connection: close'
12:43:23.900 -> [HTTP-Client][handleHeaderResponse] RX: ''
12:43:23.900 -> [HTTP-Client][handleHeaderResponse] code: 200
12:43:23.933 -> [HTTP-Client][handleHeaderResponse] size: 414272
12:43:23.933 -> [httpUpdate] Header read fin.
12:43:23.933 -> [httpUpdate] Server header:
12:43:23.933 -> [httpUpdate]  - code: 200
12:43:23.933 -> [httpUpdate]  - len: 414272
12:43:23.933 -> [httpUpdate] ESP8266 info:
12:43:23.933 -> [httpUpdate]  - free Space: 1662976
12:43:23.933 -> [httpUpdate]  - current Sketch Size: 431296
12:43:23.933 -> CALLBACK:  HTTP update process started
12:43:23.933 -> :rd 5, 1072, 0
12:43:23.933 -> :rdi 536, 5
12:43:23.933 -> :rd 528, 1072, 5
12:43:23.933 -> :rdi 531, 528
12:43:23.966 -> :close
12:43:24.065 -> [httpUpdate] runUpdate flash...
12:43:24.065 -> BSSL:peekBytes: Not connected
12:43:24.065 -> [httpUpdate] peekBytes magic header failed
12:43:24.065 -> CALLBACK:  HTTP update fatal error code -106
12:43:24.065 -> [HTTP-Client][end] tcp is closed

The same happens on my local Apache HTTPS server.

Switching to HTTP, the update passes:

12:53:02.473 -> [HTTP-Client] sending request header
12:53:02.473 -> -----
12:53:02.473 -> GET /httpUpdate.ino.generic.bin HTTP/1.0
12:53:02.473 -> Host: 192.168.1.8
12:53:02.473 -> User-Agent: ESP8266-http-Update
12:53:02.473 -> Connection: close
12:53:02.473 -> x-ESP8266-Chip-ID: 2340006
12:53:02.473 -> x-ESP8266-STA-MAC: 60:01:94:23:B4:A6
12:53:02.473 -> x-ESP8266-AP-MAC: 62:01:94:23:B4:A6
12:53:02.473 -> x-ESP8266-free-space: 1773568
12:53:02.473 -> x-ESP8266-sketch-size: 320320
12:53:02.473 -> x-ESP8266-sketch-md5: c2f1e4afdbb3a81b5bb966adc3874237
12:53:02.504 -> x-ESP8266-chip-size: 4194304
12:53:02.504 -> x-ESP8266-sdk-version: 2.2.2-dev(38a443e)
12:53:02.504 -> x-ESP8266-mode: sketch
12:53:02.504 -> Content-Length: 0
12:53:02.504 -> 
12:53:02.504 -> -----
12:53:02.504 -> :wr 452 0
12:53:02.504 -> :wrc 452 452 0
12:53:02.504 -> :ack 452
12:53:02.504 -> :rn 536
12:53:02.504 -> :rch 536, 536
12:53:02.504 -> [HTTP-Client][handleHeaderResponse] RX: 'HTTP/1.1 200 OK
'
12:53:02.504 -> [HTTP-Client][handleHeaderResponse] RX: 'Date: Wed, 16 Jun 2021 19:53:02 GMT
'
12:53:02.537 -> [HTTP-Client][handleHeaderResponse] RX: 'Server: Apache/2.4.29 (Ubuntu)
'
12:53:02.537 -> [HTTP-Client][handleHeaderR:rch 1072, 536
12:53:02.537 -> :rch 1608, 536
12:53:02.537 -> esponse] RX: 'Last-Modified: Wed, 16 Jun 2021 19:46:27 GMT
'
12:53:02.537 -> [HTTP-Client][handleHeaderResponse] RX: 'ETag: "65240-5c4e758a38553"
'
12:53:02.537 -> [HTTP-Client][handleHeaderResponse] RX: 'Accept-Ranges: bytes
'
12:53:02.537 -> [HTTP-Client][handleHeaderResponse] RX: 'Content-Length: 414272
'
12:53:02.571 -> [HTTP-Client][handleHeaderResponse] RX: 'Connection: close
'
12:53:02.571 -> [HTTP-Client][handleHeaderResponse] RX: 'Content-Type: application/octet-stream
'
12:53:02.571 -> [HTTP-Client][handleHeaderResponse] RX: '
'
12:53:02.571 -> [HTTP-Client][handleHeaderResponse] code: 200
12:53:02.571 -> [HTTP-Client][handleHeaderResponse] size: 414272
12:53:02.571 -> [httpUpdate] Header read fin.
12:53:02.571 -> [httpUpdate] Server header:
12:53:02.604 -> [httpUpdate]  - code: 200
12:53:02.604 -> [httpUpdate]  - len: 414272
12:53:02.604 -> [httpUpdate] ESP8266 info:
12:53:02.604 -> [httpUpdate]  - free Space: 1773568
12:53:02.604 -> [httpUpdate]  - current Sketch Size: 320320
12:53:02.604 -> CALLBACK:  HTTP update process started
12:53:02.706 -> [httpUpdate] runUpdate flash...
12:53:02.706 -> :pd 4, 2144, 268
12:53:02.706 -> :rpi 268, 4
12:53:02.706 -> sleep disable
12:53:02.706 -> [begin] roundedSize:       0x00066000 (417792)
12:53:02.706 -> [begin] updateEndAddress:  0x00200000 (2097152)
12:53:02.706 -> [begin] currentSketchSize: 0x0004F000 (323584)
12:53:02.706 -> [begin] _startAddress:     0x0019A000 (1679360)
12:53:02.706 -> [begin] _currentAddress:   0x0019A000 (1679360)
12:53:02.739 -> [begin] _size:             0x00065240 (414272)
12:53:02.739 -> CALLBACK:  HTTP update process at 0 of 414272 bytes...
12:53:02.739 -> CALLBACK:  HTTP update process at 0 of 414272 bytes...
12:53:02.739 -> readBytes should be overridden for better efficiency
12:53:02.739 -> :c 1, 536, 2144
12:53:02.739 -> :c 1, 536, 1608
12:53:02.739 -> :c 1, 536, 1072
12:53:02.739 -> :c0 1, 536
12:53:02.772 -> :rn 536
12:53:02.772 -> :rch 536, 536
12:53:02.772 -> :rch 1072, 536
12:53:02.772 -> :rch 1608, 536
12:53:02.772 -> :c 1, 536, 2144
12:53:02.772 -> :c 1, 536, 1608
12:53:02.772 -> :c 1, 536, 1072
12:53:02.772 -> :c0 1, 536
12:53:02.772 -> :rn 536
12:53:02.772 -> :rch 536, 536
12:53:02.772 -> :rch 1072, 536
12:53:02.772 -> :rch 1608, 536
12:53:02.805 -> Header: 0xE9 2 3 30
12:53:02.805 -> Set flash mode from 0x3 to 0x2
12:53:02.805 -> CALLBACK:  HTTP update process at 4096 of 414272 bytes...
....

So, it looks like Updater and the HTTPS connection are the root of the issue. Plain HTTP updates are 100%, HTTPS ones drop at the time when the raw bytes would be coming back. This isn't speed related (80/160) because that would affect the initial handshake, not the transfers.

@earlephilhower earlephilhower changed the title [ESP8266HTTPClient] HTTP_UPDATE_FAILD Error (-106): Verify Bin Header Failed [ESP8266HTTPClient] Updates from HTTPS servers fail before transferring new binary begins Jun 16, 2021
@earlephilhower
Copy link
Collaborator

The conversion of the WiFiClientSecure object to a ctx+wrapper looks to be the root cause here.

ESP8266httpUpdate is calling WiFiClinet::stopAllExcept(this-conn) which ends up closing the underlying TCP connection for the WiFiClientSecure object before it actually transfers any data:

if (_closeConnectionsOnUpdate) {
WiFiUDP::stopAll();
WiFiClient::stopAllExcept(tcp);
}

So, basically, with HTTPS the HTTP update object shoots itself in the foot every time. :(

earlephilhower added a commit to earlephilhower/Arduino that referenced this issue Jun 17, 2021
Fixes esp8266#8079

Because WiFiClientSecure inherits WiFiClient, and WiFiClientSecureCtx also
inherits WiFiClient, they both end up in the list of TCP connections that
are used for WiFiClient::stopAllExcept().  This would cause the underlying
SSL connection to be closed whenever you attempted to
stopAllExcept(WiFiClientSecure)

Fix by adding a "_owner" pointer in the WiFiClient object which points to
nullptr (default case) or to the associated upper-layer connection.
When stopping all connections except one, only look at the uppermost
connections.
@earlephilhower
Copy link
Collaborator

Folks, please give #8136 a try and report back.

@d-a-v
Copy link
Collaborator

d-a-v commented Jun 17, 2021

Alpha release 0.0.2 integrates #8032 if anyone without git is willing to test.

@d-a-v d-a-v added waiting for feedback Waiting on additional info. If it's not received, the issue may be closed. and removed waiting for feedback Waiting on additional info. If it's not received, the issue may be closed. labels Jun 17, 2021
earlephilhower added a commit that referenced this issue Jun 20, 2021
Fixes #8079

Because WiFiClientSecure inherits WiFiClient, and WiFiClientSecureCtx also
inherits WiFiClient, they both end up in the list of TCP connections that
are used for WiFiClient::stopAllExcept().  This would cause the underlying
SSL connection to be closed whenever you attempted to
stopAllExcept(WiFiClientSecure)

Fix by adding a "_owned"(by) pointer in the WiFiClient object which points to
nullptr (default case) or to the associated lower-layer connection.
When stopping all connections except one, only look at the lowermost
connections.
@frankygoop
Copy link

Sorry to ask again, maybe was not related to this but still, to be able to update from a private repository in Github, I need to add two headers to the Esp8266HttpUpdate.cpp

http.addHeader(F("Accept"), "application/vnd.github.v3.raw");
http.addHeader(F("authorization"), "Bearer ghp_........");

Thanks

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
waiting for feedback Waiting on additional info. If it's not received, the issue may be closed.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants