SerenityOS / serenity

The Serenity Operating System 🐞
https://serenityos.org
BSD 2-Clause "Simplified" License
30.68k stars 3.19k forks source link

LibHTTP: HttpsJob will randomy call `on_finish` multiple times #8211

Closed drunderscore closed 3 years ago

drunderscore commented 3 years ago

With the following code, on_finish will trigger multiple times, very randomly, but usually only ever when hit with a non-successful response code:

#include <LibHTTP/HttpsJob.h>
#include <LibHTTP/HttpRequest.h>
#include <LibCore/EventLoop.h>
#include <AK/MemoryStream.h>

int main()
{
    Core::EventLoop event_loop;

    static Vector<Certificate> certs;

    auto now = Core::DateTime::now();
    auto last_year = Core::DateTime::create(now.year() - 1);
    auto next_year = Core::DateTime::create(now.year() + 1);

    Certificate cert;
    cert.subject.subject = "CyberTrust";
    cert.issuer.subject = "CyberTrust";
    cert.subject.country = "IE";
    cert.not_before = last_year;
    cert.not_after = next_year;
    certs.append(move(cert));

    HTTP::HttpRequest request;
    request.set_url("https://discord.com/api/v9/users/@me");
    request.set_method(HTTP::HttpRequest::GET);

    AK::DuplexMemoryStream stream;

    auto job = HTTP::HttpsJob::construct(request, stream, &certs);
    job->on_finish = [job](bool success)
    {
        outln("Success: {}, response code: {}", success, job->response()->code());
    };
    job->start();

    return event_loop.exec();
}

This is being built on Lagom:

$ uname -a
Linux JAMES-DESKTOP 5.10.41-1-MANJARO #1 SMP PREEMPT Fri May 28 19:10:32 UTC 2021 x86_64 GNU/Linux

Here's what the bug being triggered looks like: https://user-images.githubusercontent.com/15949431/122999893-d0f42a00-d37c-11eb-99c7-16c63ac4bd10.mp4

drunderscore commented 3 years ago

With all the debug macros,

This is what it looks like when it is triggered multiple times (incorrect)

Long output ``` 21851 Core::EventLoop constructed :) URLParser::parse: Parsing 'https://discord.com/api/v9/users/@me' URLParser::parse: SchemeStart state with code point U+0068 (h). URLParser::parse: Scheme state with code point U+0074 (t). URLParser::parse: Scheme state with code point U+0074 (t). URLParser::parse: Scheme state with code point U+0070 (p). URLParser::parse: Scheme state with code point U+0073 (s). URLParser::parse: Scheme state with code point U+003A (:). URLParser::parse: SpecialAuthoritySlashes state with code point U+002F (/). URLParser::parse: SpecialAuthorityIgnoreSlashes state with code point U+0064 (d). URLParser::parse: Authority state with code point U+0064 (d). URLParser::parse: Authority state with code point U+0069 (i). URLParser::parse: Authority state with code point U+0073 (s). URLParser::parse: Authority state with code point U+0063 (c). URLParser::parse: Authority state with code point U+006F (o). URLParser::parse: Authority state with code point U+0072 (r). URLParser::parse: Authority state with code point U+0064 (d). URLParser::parse: Authority state with code point U+002E (.). URLParser::parse: Authority state with code point U+0063 (c). URLParser::parse: Authority state with code point U+006F (o). URLParser::parse: Authority state with code point U+006D (m). URLParser::parse: Authority state with code point U+002F (/). URLParser::parse: Host state with code point U+0064 (d). URLParser::parse: Host state with code point U+0069 (i). URLParser::parse: Host state with code point U+0073 (s). URLParser::parse: Host state with code point U+0063 (c). URLParser::parse: Host state with code point U+006F (o). URLParser::parse: Host state with code point U+0072 (r). URLParser::parse: Host state with code point U+0064 (d). URLParser::parse: Host state with code point U+002E (.). URLParser::parse: Host state with code point U+0063 (c). URLParser::parse: Host state with code point U+006F (o). URLParser::parse: Host state with code point U+006D (m). URLParser::parse: Host state with code point U+002F (/). URLParser::parse: Port state with code point U+002F (/). URLParser::parse: PathStart state with code point U+002F (/). URLParser::parse: Path state with code point U+0061 (a). URLParser::parse: Path state with code point U+0070 (p). URLParser::parse: Path state with code point U+0069 (i). URLParser::parse: Path state with code point U+002F (/). URLParser::parse: Path state with code point U+0076 (v). URLParser::parse: Path state with code point U+0039 (9). URLParser::parse: Path state with code point U+002F (/). URLParser::parse: Path state with code point U+0075 (u). URLParser::parse: Path state with code point U+0073 (s). URLParser::parse: Path state with code point U+0065 (e). URLParser::parse: Path state with code point U+0072 (r). URLParser::parse: Path state with code point U+0073 (s). URLParser::parse: Path state with code point U+002F (/). URLParser::parse: Path state with code point U+0040 (@). URLParser::parse: Path state with code point U+006D (m). URLParser::parse: Path state with code point U+0065 (e). URLParser::parse: Path state with EOF. URLParser::parse: Parsed URL to be 'https://discord.com/api/v9/users/@me'. URL constructor: Parsed URL to be 'https://discord.com/api/v9/users/@me'. Socket::connect: Resolved 'discord.com' to 162.159.135.232 TLSv12(0x000055e344033800) connecting to 162.159.135.232:0... TLSv12(0x000055e344033800) connection in progress (EINPROGRESS) Core::EventLoop::post_event: (0) << receivier=Notifier(0x000055e34403a940), event=0x000055e34403ae00 Core::EventLoop: Notifier(0x000055e34403a940) event 4 TLSv12(0x000055e344033800) connected! Update hash with message of size 96 Core::EventLoop::post_event: (0) << receivier=TLSv12(0x000055e344033800), event=0x000055e34403a900 HttpsJob: on_connected callback Core::EventLoop: TLSv12(0x000055e344033800) event 5 DeferredInvoke: receiver = TLSv12(0x000055e344033800) Flushing cached records: 96 established? false SENDING... 16 03 03 00 5b 01 00 00 57 03 03 96 51 f6 25 77 c9 91 be 4f 54 46 28 c6 4c fb 4e 4f 70 bb c3 60 6d 19 5a 69 0b 22 36 a4 2c a2 39 00 00 0c 00 2f 00 35 00 3c 00 3d 00 9c 00 9d 01 00 00 22 00 00 00 10 00 0e 00 00 0b 64 69 73 63 6f 72 64 2e 63 6f 6d 00 0d 00 0a 00 08 06 01 05 01 04 01 02 01 Core::EventLoop::post_event: (0) << receivier=Notifier(0x000055e34403ae20), event=0x000055e34403ae00 Core::EventLoop: Notifier(0x000055e34403ae20) event 3 Consuming 1460 bytes message buffer length 1460 buffer size: 85 type=22, version=771 record length: 80 at offset: 3 message type: 22, length: 80 tls handshake message payload size: 79 buffer length: 80 server hello Remote session ID: 5f e2 8d c3 f9 7d 74 c5 c4 59 6a 79 b6 a7 f8 a7 61 ac 8d 20 2b 0c 86 b7 a8 ce b2 e4 ea 50 12 2f Cipher: 156 Extensions bytes total: 0 Extension 0 with length 0 Update hash with message of size 80 consumed 85 bytes Need more data: 2801 > 1375 Core::EventLoop::post_event: (0) << receivier=Notifier(0x000055e34403ae20), event=0x000055e34403ae00 Core::EventLoop: Notifier(0x000055e34403ae20) event 3 Consuming 1435 bytes message buffer length 2810 buffer size: 2801 type=22, version=771 record length: 2796 at offset: 3 message type: 22, length: 2796 tls handshake message payload size: 2795 buffer length: 2796 certificate total length: 2792 RSA PKCS#8 public key parse failed: Expected a Sequence but got Integer Certificate issued for sni.cloudflaressl.com by Cloudflare Inc RSA CA-2 RSA PKCS#8 public key parse failed: Expected a Sequence but got Integer Certificate issued for Cloudflare Inc RSA CA-2 by Baltimore CyberTrust Root Update hash with message of size 2796 consumed 2801 bytes buffer size: 9 type=22, version=771 record length: 4 at offset: 3 message type: 22, length: 4 tls handshake message payload size: 3 buffer length: 4 server hello done Update hash with message of size 4 > Key exchange PreMaster secret 03 03 ce e8 34 e6 d0 f8 02 9b 75 0d d8 19 90 04 15 37 9a 61 09 16 1d c1 1d 88 f1 2a 35 6c 2b 3f 95 df cc 88 c9 b5 8e c1 3c bb 04 9a 92 d0 35 87 key size: 256 padded output size: 256 buffer size: 256 in size: 256 Encrypted: 3d 97 b4 0a 69 fa e8 f4 c7 a8 05 dc fd a2 fc bc bb aa 9a 50 23 49 ce d6 7f ab 3a 7b 6e ca b0 de 4c d3 0e f6 a6 57 da bb 38 2c 3f 20 bd 2a ac e9 c0 74 7d e2 09 19 a6 c1 dc 3f ea b1 14 be a3 1d ed 11 98 c4 fa d9 0a 5a 44 91 c9 9a 61 76 9e 73 c7 16 0a d9 ae 81 7f 3d 24 1a a0 02 ac e3 ef f2 4c 0a 9c c6 ab f7 27 d6 00 38 69 ee 83 b8 71 69 8e 50 4f 34 65 78 f0 4d 16 73 d9 92 6a 9d 82 d8 4d b7 bd bb 40 90 76 6f 3f 22 d5 04 46 47 96 16 9c 27 9e ed 47 58 ed 1e 80 ce 30 90 62 04 3a 29 e3 b6 12 00 b2 f7 32 98 b5 09 eb ec 18 75 06 97 ed 85 2b de 32 6f e8 f0 e8 8d 3a 71 b2 ed 84 14 7a 22 15 dd 95 e7 c4 5c 43 cd 63 0c a5 6d df 3f 40 41 52 1b e7 1f 25 dd f9 de d4 d5 e2 2f 5d 14 ca 76 94 eb ac 29 f1 93 8e e5 b1 15 e6 ca 19 09 2a 96 31 3e 6a 8f 23 87 15 51 cb a0 93 5c f2 70 master key: c6 9f 93 b5 d2 f1 5a 65 f8 f5 ce 79 93 d7 0b b9 81 ef 2d b0 b9 d2 13 f5 17 bc ac 60 dd db ae dd dd fa 5d f5 b4 ec 5b 83 0e e6 dd 5a 57 83 da d6 client key 23 3d da 27 1b 02 a7 ac b6 49 74 a0 84 76 d1 06 server key 06 ae 1d 82 c9 bc 4e 2b 92 ba f1 e4 d5 a0 dc cb client iv 4d 61 a6 4e server iv 11 d4 2a 4e Update hash with message of size 267 Scheduling write of 267 Core::EventLoop::post_event: (0) << receivier=TLSv12(0x000055e344033800), event=0x000055e34403c270 > change cipher spec Flushing scheduled write of 273 Flushing cached records: 273 established? false SENDING... 16 03 03 01 06 10 00 01 02 01 00 3d 97 b4 0a 69 fa e8 f4 c7 a8 05 dc fd a2 fc bc bb aa 9a 50 23 49 ce d6 7f ab 3a 7b 6e ca b0 de 4c d3 0e f6 a6 57 da bb 38 2c 3f 20 bd 2a ac e9 c0 74 7d e2 09 19 a6 c1 dc 3f ea b1 14 be a3 1d ed 11 98 c4 fa d9 0a 5a 44 91 c9 9a 61 76 9e 73 c7 16 0a d9 ae 81 7f 3d 24 1a a0 02 ac e3 ef f2 4c 0a 9c c6 ab f7 27 d6 00 38 69 ee 83 b8 71 69 8e 50 4f 34 65 78 f0 4d 16 73 d9 92 6a 9d 82 d8 4d b7 bd bb 40 90 76 6f 3f 22 d5 04 46 47 96 16 9c 27 9e ed 47 58 ed 1e 80 ce 30 90 62 04 3a 29 e3 b6 12 00 b2 f7 32 98 b5 09 eb ec 18 75 06 97 ed 85 2b de 32 6f e8 f0 e8 8d 3a 71 b2 ed 84 14 7a 22 15 dd 95 e7 c4 5c 43 cd 63 0c a5 6d df 3f 40 41 52 1b e7 1f 25 dd f9 de d4 d5 e2 2f 5d 14 ca 76 94 eb ac 29 f1 93 8e e5 b1 15 e6 ca 19 09 2a 96 31 3e 6a 8f 23 87 15 51 cb a0 93 5c f2 70 14 03 03 00 01 01 > client finished Update hash with message of size 21 AAD bits: 0 : 104 Cipher bits: 0 : 128 Tag bits: 2355668958 : 3791070044 : 470084821 : 3353422154 Tag bits: 2355668958 : 3791070004 : 470084821 : 3353422282 Flushing scheduled write of 45 Flushing cached records: 45 established? false SENDING... 16 03 03 00 28 c6 4f 63 4f 3e ca 05 17 19 d6 cb fb 5f a9 53 70 fc db c0 e1 50 56 ed c5 17 e4 14 fb c5 64 3e ca e9 33 b0 0f 89 30 d4 be consumed 9 bytes Core::EventLoop: TLSv12(0x000055e344033800) event 5 DeferredInvoke: receiver = TLSv12(0x000055e344033800) Flushing cached records: 0 established? false Core::EventLoop::post_event: (0) << receivier=Notifier(0x000055e34403ae20), event=0x000055e34403ae00 Core::EventLoop: Notifier(0x000055e34403ae20) event 3 Consuming 51 bytes message buffer length 51 buffer size: 6 type=20, version=771 record length: 1 at offset: 3 message type: 20, length: 1 change cipher spec message consumed 6 bytes buffer size: 45 type=22, version=771 record length: 40 at offset: 3 message type: 22, length: 40 Encrypted: 00 00 00 00 00 00 00 00 ca 28 2b 37 36 c7 f6 d9 58 9e 28 99 2d 98 25 21 1e 77 a3 b4 74 28 15 3b de 12 cf 4d 12 6e d9 a6 AAD bits: 0 : 104 Cipher bits: 0 : 128 Tag bits: 1959949149 : 653119955 : 253387748 : 1469105675 Tag bits: 1959949149 : 653119931 : 253387748 : 1469105803 tls handshake message payload size: 15 buffer length: 16 finished FIXME: handle_handshake_finished :: Check message validity Job: raw_request: GET /api/v9/users/@me HTTP/1.1 Host: discord.com Connection: close AAD bits: 0 : 104 Cipher bits: 0 : 576 Tag bits: 3201074329 : 210668595 : 4066390161 : 1300892757 Tag bits: 3201074329 : 210668635 : 4066390161 : 1300893205 Scheduling write of 101 Core::EventLoop::post_event: (0) << receivier=TLSv12(0x000055e344033800), event=0x000055e344041090 Update hash with message of size 16 consumed 45 bytes Core::EventLoop: TLSv12(0x000055e344033800) event 5 DeferredInvoke: receiver = TLSv12(0x000055e344033800) Flushing cached records: 101 established? true SENDING... 17 03 03 00 60 73 b3 32 18 0a 93 e8 bb 42 cd fe 2b bf fa 5b 75 59 b1 63 45 20 b5 90 d4 bc 63 e8 48 37 3a 90 93 03 91 d6 85 62 f1 49 b7 36 82 f8 8d 7c 80 af 51 fa 65 dd b7 17 25 ff 9d 92 0f 64 75 92 66 0c 57 38 31 f5 bf 27 d4 f0 6e fb 78 9e 15 19 06 cf 2a f5 09 fb 13 1f 7b 20 54 59 15 bb 4d 39 3a 5e a8 Core::EventLoop::post_event: (0) << receivier=Notifier(0x000055e34403ae20), event=0x000055e34403ae00 Core::EventLoop: Notifier(0x000055e34403ae20) event 3 Consuming 1125 bytes message buffer length 1125 buffer size: 1125 type=23, version=771 record length: 1120 at offset: 3 message type: 23, length: 1120 Encrypted: 00 00 00 00 00 00 00 01 ef 6c 58 29 7c 81 79 10 b8 18 bd e1 32 d9 6f fb 32 8b d8 b9 c7 c7 48 2f cf 30 57 08 a6 0d 96 fc 0c 5d 14 e0 2f 46 35 9b fe e8 32 b4 d4 12 5e 53 2c 05 a7 4e 4c 49 12 62 d7 67 1f 42 97 05 ef 0f 89 c6 76 76 3f 48 0e 90 d0 2b 99 64 6a 49 44 f0 e6 2e fe b1 11 72 fe 20 06 37 90 ac fc ff 92 18 b5 37 ca ac db 60 7e df 37 36 fc d2 a9 aa 86 64 e3 36 05 79 be 62 50 30 4f b1 7a 27 7c e2 de 57 bd 9d 38 e1 70 f4 75 77 14 4a 5c c7 0b 4f 5f 55 34 f7 0d 6f 23 f2 4b a6 9f 66 62 51 0f d6 55 0f ef 1a c6 65 9f 6f 74 00 31 a8 8b 33 76 fc df 29 36 13 d5 62 a2 83 ac f6 9a 43 41 2a f6 5d 00 28 0f b1 7a c6 c4 04 7f 67 d6 1e 94 ec 07 d4 86 6c 37 e1 a3 cc 6e 18 43 66 b2 c6 09 01 d0 b5 6f bd 43 d1 3c 76 14 f1 ac 94 12 c1 c4 64 55 de af 3f 6b 57 50 8b 68 72 20 f4 73 0a da 70 50 5d 89 76 a1 ae 78 28 cb 28 a3 33 cc 91 e2 31 01 91 5d 3a e8 fc de 67 f2 c5 5c bc e0 50 ba 77 34 27 67 12 79 5a f6 73 c8 94 50 16 e4 da 76 b7 e5 ab ad c9 cc 87 1c 53 31 7a be 63 fd a1 0a 3f ee a7 28 a4 d1 cf 5d 15 83 ba 50 17 84 b1 d3 a4 48 59 68 a2 f0 3e c9 4d f8 38 88 9c 77 01 cd 71 94 0d 1a dd 4d 43 94 20 9f 57 29 8d fc f8 cf b7 8d d3 e6 6c 25 c6 74 eb 6e 1b 4c 6c 24 fc 78 92 c2 2c c5 80 5f 1a 8d 16 43 c6 7c f9 0a 04 df ca fa 5d 58 e1 15 a4 7f 9c fd f9 8f 5e 1e c4 7a 2c 69 05 2c 1f 2d 9b 13 43 bb 9c da fc f7 fb 4c f4 92 f7 8b 71 89 f6 f8 c8 6e 29 7e 8b 3c c8 2e 5d 17 b8 0a 6b 82 e6 60 5a e7 58 5b e6 58 59 ba e4 51 64 df 45 28 7d 1e fe 91 5a b5 4f 4c 6b 71 c4 51 ed 6c c8 77 95 79 c9 a3 f2 10 4e c8 1d c6 71 a9 5b f6 a5 79 d0 bb 10 df 79 1c 31 e7 13 95 54 f7 0f 24 63 11 f1 99 67 3d f0 62 44 d1 b2 ea 89 c3 d1 f2 89 61 c3 71 c9 cc 17 56 74 48 14 a0 c5 4f 52 29 5e 87 9a c9 54 15 26 a1 6a 1a 45 8a e7 2d c5 bf 90 b1 23 63 19 e1 25 7b c5 1e 20 12 7b a4 52 68 09 0c 9a 4d a0 90 ab fa e7 36 ff bb 5b 3d 65 90 f6 b4 c5 fa 70 ca a6 00 f6 fc a1 c6 28 79 3f 7e 36 d8 bf ab d3 03 52 92 71 b1 30 6b 30 f7 ad 02 69 7f 2b a6 a7 7f c0 a3 1d be a4 99 0a af 58 25 1b f3 db 19 7b 5c 7f 5f 20 b7 60 94 d8 7c 33 dd 19 62 9c cd c4 ad 6d 32 b5 69 bc 58 b4 6f 22 72 9d 2e 2a 68 27 04 bc d5 a9 52 a0 d8 87 c6 de 05 85 b8 cc aa 3f 90 c5 69 de f7 1b d2 3b f2 3b 37 75 a5 43 16 b6 a7 7f 75 53 bb df 49 c7 b7 f0 43 b9 1d 41 5e a0 88 50 eb ee 88 ab 39 b2 4c c6 10 38 41 17 e5 af e3 2f 46 f0 0d 0d 09 e0 29 92 98 b9 50 5f 1b 28 49 31 f0 e6 50 48 cd 62 2c ee a0 db e1 f8 7b c7 9f 58 cd 7b d8 41 a3 9a 4e 3b ce c1 93 ea b2 57 7c 48 ba 89 f7 31 33 06 9a 98 e1 95 2c b6 30 e6 f5 2d d2 4e 44 c6 66 c4 3e 53 b9 b7 0a 1e 6f eb c9 fd c1 ef 06 03 53 38 8f f1 89 6f 63 e9 6e d8 05 da 61 c0 ba 97 5d 53 57 20 8f 8b 3f c0 55 34 70 56 ff 7c 83 3b 0e 36 c0 93 1d 82 d5 16 05 01 16 e3 7f a6 a9 79 d1 85 45 f4 84 8c e7 4d 9e e0 bb 67 42 c5 27 cb a3 f7 bd 69 e6 c3 3a 8b 8a 0d 93 7a fc f9 1f 2b 26 89 83 b7 8a 09 ef 21 e0 7c 94 1a ab 95 f7 ce 0c ec b7 f7 2c 39 21 23 39 12 20 c8 71 5c ca c3 f0 b2 d1 f0 e3 7d d0 e6 0f 39 b5 a6 f3 de 94 47 96 78 18 64 f8 96 b4 7c b6 04 64 87 9e aa 89 c3 04 87 b3 fe 4a 67 b8 a9 64 8f c8 92 d6 50 24 49 2b 6e 67 ad 90 f3 57 1a 4f 5e 2c c2 a2 00 48 06 6c 38 26 34 f8 99 fb c2 08 de c9 8d f1 7f 1a db 4b 8d 89 87 bf 6b ee d0 e5 b2 c7 ac 55 fc 0a 83 90 b2 61 b5 65 aa 84 70 6c d3 d7 3f 64 08 cf 2f 81 9f 35 68 75 bb 4e 8d 33 f1 52 f9 d5 2f 77 99 81 b1 f8 40 a8 41 4b ee 8f 11 86 4a b3 1d 97 b5 21 5a a8 30 be cb 3b 04 da b5 88 00 d4 2f 26 ee 24 40 f3 19 fa e9 a2 41 53 07 39 77 6a b5 AAD bits: 0 : 104 Cipher bits: 0 : 8768 Tag bits: 1497825720 : 2743081304 : 92235841 : 2873995368 Tag bits: 1497825720 : 2743081264 : 92235841 : 2873987624 application data message of size 1096 consumed 1125 bytes Core::EventLoop::post_event: (0) << receivier=TLSv12(0x000055e344033800), event=0x000055e344041090 Core::EventLoop::post_event: (1) << receivier=Notifier(0x000055e34403ae20), event=0x000055e34403ae00 Core::EventLoop: TLSv12(0x000055e344033800) event 5 DeferredInvoke: receiver = TLSv12(0x000055e344033800) Core::EventLoop::post_event: (0) << receivier=TLSv12(0x000055e344033800), event=0x000055e34403c270 Job: [Date] = 'Tue, 22 Jun 2021 21:32:09 GMT' Job: [Content-Type] = 'application/json' Core::EventLoop: Notifier(0x000055e34403ae20) event 3 Core::EventLoop::post_event: (1) << receivier=TLSv12(0x000055e344033800), event=0x000055e3440410d0 Job: [Content-Length] = '43' Socket not open, assuming abrupt closure Job: [Connection] = 'close' Core::EventLoop::post_event: (2) << receivier=Notifier(0x000055e34403ae20), event=0x000055e34403ae00 Core::EventLoop: TLSv12(0x000055e344033800) event 5 DeferredInvoke: receiver = TLSv12(0x000055e344033800) Core::EventLoop::post_event: (0) << receivier=TLSv12(0x000055e344033800), event=0x000055e344041090 Job: [CF-Ray] = '6638966d684a17fd-EWR' Socket not open, assuming abrupt closure Job: [Set-Cookie] = '__dcfduid=1488ed8002a947c088dfc070400e9aa3; Expires=Sun, 21-Jun-2026 21:32:09 GMT; Max-Age=157680000; Secure; HttpOnly; Path=/' Core::EventLoop: TLSv12(0x000055e344033800) event 5 DeferredInvoke: receiver = TLSv12(0x000055e344033800) Core::EventLoop::post_event: (1) << receivier=TLSv12(0x000055e344033800), event=0x000055e344040040 Job: [Strict-Transport-Security] = 'max-age=31536000; includeSubDomains; preload' Socket not open, assuming abrupt closure Job: [Via] = '1.1 google' Core::EventLoop: Notifier(0x000055e34403ae20) event 3 Core::EventLoop::post_event: (2) << receivier=TLSv12(0x000055e344033800), event=0x000055e34403d0c0 Job: [CF-Cache-Status] = 'DYNAMIC' Socket not open, assuming abrupt closure Job: [Alt-Svc] = 'h3-27=":443"; ma=86400, h3-28=":443"; ma=86400, h3-29=":443"; ma=86400, h3=":443"; ma=86400' Core::EventLoop::post_event: (3) << receivier=Notifier(0x000055e34403ae20), event=0x000055e34403ae00 Core::EventLoop: TLSv12(0x000055e344033800) event 5 DeferredInvoke: receiver = TLSv12(0x000055e344033800) Core::EventLoop::post_event: (0) << receivier=TLSv12(0x000055e344033800), event=0x000055e3440410d0 Job: [cf-request-id] = '0ad73c5863000017fdf0a34000000001' Socket not open, assuming abrupt closure Job: [Expect-CT] = 'max-age=604800, report-uri="https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct"' Core::EventLoop: TLSv12(0x000055e344033800) event 5 DeferredInvoke: receiver = TLSv12(0x000055e344033800) Core::EventLoop::post_event: (1) << receivier=TLSv12(0x000055e344033800), event=0x000055e34403c270 Job: [X-Content-Type-Options] = 'nosniff' Socket not open, assuming abrupt closure Job: [x-envoy-upstream-service-time] = '4' Core::EventLoop: TLSv12(0x000055e344033800) event 5 DeferredInvoke: receiver = TLSv12(0x000055e344033800) Core::EventLoop::post_event: (2) << receivier=TLSv12(0x000055e344033800), event=0x000055e34403dbe0 Job: [Report-To] = '{"endpoints":[{"url":"https:\/\/a.nel.cloudflare.com\/report\/v2?s=qTV3wiCRevq8I7Ly6cMld701h6Yeu0RizMJ3XNqUAC%2F7BOi922JS6kZM89Xmu8iFPrCmcCengIzur2eyur2D6pmiI4sZkF3xig54P%2BJZnjQDKpdn8tCemA%3D%3D"}],"group":"cf-nel","max_age":604800}' Socket not open, assuming abrupt closure Job: [NEL] = '{"report_to":"cf-nel","max_age":604800}' Core::EventLoop: Notifier(0x000055e34403ae20) event 3 Core::EventLoop::post_event: (3) << receivier=TLSv12(0x000055e344033800), event=0x000055e34403dd90 Job: [Server] = 'cloudflare' Socket not open, assuming abrupt closure Core::EventLoop::post_event: (4) << receivier=Notifier(0x000055e34403ae20), event=0x000055e34403ae00 Core::EventLoop: TLSv12(0x000055e344033800) event 5 DeferredInvoke: receiver = TLSv12(0x000055e344033800) Core::EventLoop::post_event: (0) << receivier=TLSv12(0x000055e344033800), event=0x000055e34403d0c0 Job: Flushing received buffers: have 43 bytes in 1 buffers Job: Flushing received buffers done: have 0 bytes in 0 buffers Core::EventLoop::post_event: (1) << receivier=HttpsJob(0x000055e344030480), event=0x000055e344043350 Core::EventLoop::post_event: (2) << receivier=HttpsJob(0x000055e344030480), event=0x000055e344041220 Socket not open, assuming abrupt closure Core::EventLoop::post_event: (3) << receivier=HttpsJob(0x000055e344030480), event=0x000055e344044530 FINISHED Core::EventLoop: TLSv12(0x000055e344033800) event 5 DeferredInvoke: receiver = TLSv12(0x000055e344033800) Socket not open, assuming abrupt closure Core::EventLoop::post_event: (4) << receivier=HttpsJob(0x000055e344030480), event=0x000055e3440445b0 FINISHED Core::EventLoop: TLSv12(0x000055e344033800) event 5 DeferredInvoke: receiver = TLSv12(0x000055e344033800) Socket not open, assuming abrupt closure Core::EventLoop::post_event: (5) << receivier=HttpsJob(0x000055e344030480), event=0x000055e344044630 FINISHED Core::EventLoop: TLSv12(0x000055e344033800) event 5 DeferredInvoke: receiver = TLSv12(0x000055e344033800) Socket not open, assuming abrupt closure Core::EventLoop::post_event: (6) << receivier=HttpsJob(0x000055e344030480), event=0x000055e3440446b0 FINISHED Core::EventLoop: Notifier(0x000055e34403ae20) event 3 Socket not open, assuming abrupt closure Core::EventLoop::post_event: (7) << receivier=HttpsJob(0x000055e344030480), event=0x000055e344044730 FINISHED Core::EventLoop::post_event: (8) << receivier=Notifier(0x000055e34403ae20), event=0x000055e34403ae00 Core::EventLoop: TLSv12(0x000055e344033800) event 5 DeferredInvoke: receiver = TLSv12(0x000055e344033800) Socket not open, assuming abrupt closure Core::EventLoop::post_event: (0) << receivier=HttpsJob(0x000055e344030480), event=0x000055e34403dbe0 FINISHED Core::EventLoop: HttpsJob(0x000055e344030480) event 5 DeferredInvoke: receiver = HttpsJob(0x000055e344030480) Core::EventLoop: HttpsJob(0x000055e344030480) event 5 DeferredInvoke: receiver = HttpsJob(0x000055e344030480) HttpsJob(0x000055e344030480) job did_finish Success: true, response code: 401 Core::EventLoop: HttpsJob(0x000055e344030480) event 5 DeferredInvoke: receiver = HttpsJob(0x000055e344030480) HttpsJob(0x000055e344030480) job did_finish Success: true, response code: 401 Core::EventLoop: HttpsJob(0x000055e344030480) event 5 DeferredInvoke: receiver = HttpsJob(0x000055e344030480) HttpsJob(0x000055e344030480) job did_finish Success: true, response code: 401 Core::EventLoop: HttpsJob(0x000055e344030480) event 5 DeferredInvoke: receiver = HttpsJob(0x000055e344030480) HttpsJob(0x000055e344030480) job did_finish Success: true, response code: 401 Core::EventLoop: HttpsJob(0x000055e344030480) event 5 DeferredInvoke: receiver = HttpsJob(0x000055e344030480) HttpsJob(0x000055e344030480) job did_finish Success: true, response code: 401 Core::EventLoop: HttpsJob(0x000055e344030480) event 5 DeferredInvoke: receiver = HttpsJob(0x000055e344030480) HttpsJob(0x000055e344030480) job did_finish Success: true, response code: 401 Event type 3 with no receiver :( Core::EventLoop: HttpsJob(0x000055e344030480) event 5 DeferredInvoke: receiver = HttpsJob(0x000055e344030480) HttpsJob(0x000055e344030480) job did_finish Success: true, response code: 401 ```

What it looks like when triggered once (correct):

Long output ``` 21871 Core::EventLoop constructed :) URLParser::parse: Parsing 'https://discord.com/api/v9/users/@me' URLParser::parse: SchemeStart state with code point U+0068 (h). URLParser::parse: Scheme state with code point U+0074 (t). URLParser::parse: Scheme state with code point U+0074 (t). URLParser::parse: Scheme state with code point U+0070 (p). URLParser::parse: Scheme state with code point U+0073 (s). URLParser::parse: Scheme state with code point U+003A (:). URLParser::parse: SpecialAuthoritySlashes state with code point U+002F (/). URLParser::parse: SpecialAuthorityIgnoreSlashes state with code point U+0064 (d). URLParser::parse: Authority state with code point U+0064 (d). URLParser::parse: Authority state with code point U+0069 (i). URLParser::parse: Authority state with code point U+0073 (s). URLParser::parse: Authority state with code point U+0063 (c). URLParser::parse: Authority state with code point U+006F (o). URLParser::parse: Authority state with code point U+0072 (r). URLParser::parse: Authority state with code point U+0064 (d). URLParser::parse: Authority state with code point U+002E (.). URLParser::parse: Authority state with code point U+0063 (c). URLParser::parse: Authority state with code point U+006F (o). URLParser::parse: Authority state with code point U+006D (m). URLParser::parse: Authority state with code point U+002F (/). URLParser::parse: Host state with code point U+0064 (d). URLParser::parse: Host state with code point U+0069 (i). URLParser::parse: Host state with code point U+0073 (s). URLParser::parse: Host state with code point U+0063 (c). URLParser::parse: Host state with code point U+006F (o). URLParser::parse: Host state with code point U+0072 (r). URLParser::parse: Host state with code point U+0064 (d). URLParser::parse: Host state with code point U+002E (.). URLParser::parse: Host state with code point U+0063 (c). URLParser::parse: Host state with code point U+006F (o). URLParser::parse: Host state with code point U+006D (m). URLParser::parse: Host state with code point U+002F (/). URLParser::parse: Port state with code point U+002F (/). URLParser::parse: PathStart state with code point U+002F (/). URLParser::parse: Path state with code point U+0061 (a). URLParser::parse: Path state with code point U+0070 (p). URLParser::parse: Path state with code point U+0069 (i). URLParser::parse: Path state with code point U+002F (/). URLParser::parse: Path state with code point U+0076 (v). URLParser::parse: Path state with code point U+0039 (9). URLParser::parse: Path state with code point U+002F (/). URLParser::parse: Path state with code point U+0075 (u). URLParser::parse: Path state with code point U+0073 (s). URLParser::parse: Path state with code point U+0065 (e). URLParser::parse: Path state with code point U+0072 (r). URLParser::parse: Path state with code point U+0073 (s). URLParser::parse: Path state with code point U+002F (/). URLParser::parse: Path state with code point U+0040 (@). URLParser::parse: Path state with code point U+006D (m). URLParser::parse: Path state with code point U+0065 (e). URLParser::parse: Path state with EOF. URLParser::parse: Parsed URL to be 'https://discord.com/api/v9/users/@me'. URL constructor: Parsed URL to be 'https://discord.com/api/v9/users/@me'. Socket::connect: Resolved 'discord.com' to 162.159.136.232 TLSv12(0x000055696e4e1800) connecting to 162.159.136.232:0... TLSv12(0x000055696e4e1800) connection in progress (EINPROGRESS) Core::EventLoop::post_event: (0) << receivier=Notifier(0x000055696e4e8940), event=0x000055696e4e8e00 Core::EventLoop: Notifier(0x000055696e4e8940) event 4 TLSv12(0x000055696e4e1800) connected! Update hash with message of size 96 Core::EventLoop::post_event: (0) << receivier=TLSv12(0x000055696e4e1800), event=0x000055696e4e8900 HttpsJob: on_connected callback Core::EventLoop: TLSv12(0x000055696e4e1800) event 5 DeferredInvoke: receiver = TLSv12(0x000055696e4e1800) Flushing cached records: 96 established? false SENDING... 16 03 03 00 5b 01 00 00 57 03 03 50 ce 17 29 a9 3e 33 3e 07 67 f0 4a a2 70 27 50 bf fa 43 43 7f 5a ab 42 f3 66 2d 45 d4 f5 8b d4 00 00 0c 00 2f 00 35 00 3c 00 3d 00 9c 00 9d 01 00 00 22 00 00 00 10 00 0e 00 00 0b 64 69 73 63 6f 72 64 2e 63 6f 6d 00 0d 00 0a 00 08 06 01 05 01 04 01 02 01 Core::EventLoop::post_event: (0) << receivier=Notifier(0x000055696e4e8e20), event=0x000055696e4e8e00 Core::EventLoop: Notifier(0x000055696e4e8e20) event 3 Consuming 1460 bytes message buffer length 1460 buffer size: 85 type=22, version=771 record length: 80 at offset: 3 message type: 22, length: 80 tls handshake message payload size: 79 buffer length: 80 server hello Remote session ID: 55 bf 33 2b f5 46 dc 35 c3 47 7e a7 7b 8a 17 d1 60 3a 37 f8 b2 bc a7 1c 4d f3 88 de 4d 2d 0f 96 Cipher: 156 Extensions bytes total: 0 Extension 0 with length 0 Update hash with message of size 80 consumed 85 bytes Need more data: 2801 > 1375 Core::EventLoop::post_event: (0) << receivier=Notifier(0x000055696e4e8e20), event=0x000055696e4e8e00 Core::EventLoop: Notifier(0x000055696e4e8e20) event 3 Consuming 1435 bytes message buffer length 2810 buffer size: 2801 type=22, version=771 record length: 2796 at offset: 3 message type: 22, length: 2796 tls handshake message payload size: 2795 buffer length: 2796 certificate total length: 2792 RSA PKCS#8 public key parse failed: Expected a Sequence but got Integer Certificate issued for sni.cloudflaressl.com by Cloudflare Inc RSA CA-2 RSA PKCS#8 public key parse failed: Expected a Sequence but got Integer Certificate issued for Cloudflare Inc RSA CA-2 by Baltimore CyberTrust Root Update hash with message of size 2796 consumed 2801 bytes buffer size: 9 type=22, version=771 record length: 4 at offset: 3 message type: 22, length: 4 tls handshake message payload size: 3 buffer length: 4 server hello done Update hash with message of size 4 > Key exchange PreMaster secret 03 03 0b 96 79 88 bc 79 30 54 52 df b8 07 20 c8 14 9c 14 d0 73 52 44 7c c9 33 e6 3c e3 95 68 2d 55 c8 71 b4 14 1d b5 7f 22 fc ff 0a aa d0 d8 01 key size: 256 padded output size: 256 buffer size: 256 in size: 256 Encrypted: af 1a 68 e1 e4 8e 45 fa 26 c5 10 4a 86 4c d4 41 43 d9 72 61 b9 b0 ab 20 ef d4 b7 ba 21 b6 53 90 68 16 bc 0f 8a eb dd a9 88 d8 fd 02 56 d8 c7 40 8f 41 26 a9 85 22 ae d9 40 fe 15 d8 cc 1e 66 0a 1d b8 ef cd 51 21 76 35 88 da f0 13 53 49 74 0b c8 03 83 0b e8 4f d1 d7 c4 4a 9a e2 bc 14 51 05 4a b5 f4 54 09 13 8a 34 06 2d 6f 9d be 68 46 d4 cb fd 2e 1a f3 7b 4d 3f 14 5c 20 06 5f fe 55 fa 50 69 58 3e 4e ca b8 80 36 a8 5b 60 39 7a af a1 ad 17 fa 9d 66 f3 09 47 20 e0 f0 81 51 ac 06 9b 08 b7 e7 e4 73 d4 25 a8 bd a7 19 24 64 46 25 eb e5 db 5a af 7e 2e 99 1f 9c ba 23 bd bc 0c 32 9a 0a cb 72 8e 33 ae 89 a0 5b db 15 f8 f1 5a 69 fe 40 d4 4b 2b 22 2b 27 0c 9d 2e 16 3f d7 e0 12 b2 fc b9 6f 2f c1 1e ce d7 38 90 43 d1 63 46 45 e8 52 c8 02 73 f8 93 7d 5a fa d9 57 f0 96 c7 0c 8c master key: 7d fd d4 e0 1f c2 25 6f 80 79 8d d4 fa d4 da b5 6e b5 46 e4 dc a8 63 75 83 14 60 83 f0 c5 a6 ce dd 72 65 2a 46 97 09 49 fc 96 68 68 ae 3f a2 a0 client key f4 c3 2e c8 f9 29 a3 33 8e 66 8b f2 1d 45 ed d6 server key 6c 47 a7 d6 a3 dd 4b 31 6f 40 12 55 0a 95 c6 fe client iv 17 1c fd b1 server iv cc e1 ac 65 Update hash with message of size 267 Scheduling write of 267 Core::EventLoop::post_event: (0) << receivier=TLSv12(0x000055696e4e1800), event=0x000055696e4ea270 > change cipher spec Flushing scheduled write of 273 Flushing cached records: 273 established? false SENDING... 16 03 03 01 06 10 00 01 02 01 00 af 1a 68 e1 e4 8e 45 fa 26 c5 10 4a 86 4c d4 41 43 d9 72 61 b9 b0 ab 20 ef d4 b7 ba 21 b6 53 90 68 16 bc 0f 8a eb dd a9 88 d8 fd 02 56 d8 c7 40 8f 41 26 a9 85 22 ae d9 40 fe 15 d8 cc 1e 66 0a 1d b8 ef cd 51 21 76 35 88 da f0 13 53 49 74 0b c8 03 83 0b e8 4f d1 d7 c4 4a 9a e2 bc 14 51 05 4a b5 f4 54 09 13 8a 34 06 2d 6f 9d be 68 46 d4 cb fd 2e 1a f3 7b 4d 3f 14 5c 20 06 5f fe 55 fa 50 69 58 3e 4e ca b8 80 36 a8 5b 60 39 7a af a1 ad 17 fa 9d 66 f3 09 47 20 e0 f0 81 51 ac 06 9b 08 b7 e7 e4 73 d4 25 a8 bd a7 19 24 64 46 25 eb e5 db 5a af 7e 2e 99 1f 9c ba 23 bd bc 0c 32 9a 0a cb 72 8e 33 ae 89 a0 5b db 15 f8 f1 5a 69 fe 40 d4 4b 2b 22 2b 27 0c 9d 2e 16 3f d7 e0 12 b2 fc b9 6f 2f c1 1e ce d7 38 90 43 d1 63 46 45 e8 52 c8 02 73 f8 93 7d 5a fa d9 57 f0 96 c7 0c 8c 14 03 03 00 01 01 > client finished Update hash with message of size 21 AAD bits: 0 : 104 Cipher bits: 0 : 128 Tag bits: 2629870613 : 3580865094 : 1512834230 : 48989103 Tag bits: 2629870613 : 3580865070 : 1512834230 : 48988975 Flushing scheduled write of 45 Flushing cached records: 45 established? false SENDING... 16 03 03 00 28 4a 3d b7 7e 64 79 ee c1 d9 21 05 70 f7 23 25 5c ab dc 68 57 20 01 93 b4 58 e7 eb b0 61 a2 0f 9d 38 09 0e d8 22 ec e9 5c consumed 9 bytes Core::EventLoop: TLSv12(0x000055696e4e1800) event 5 DeferredInvoke: receiver = TLSv12(0x000055696e4e1800) Flushing cached records: 0 established? false Core::EventLoop::post_event: (0) << receivier=Notifier(0x000055696e4e8e20), event=0x000055696e4e8e00 Core::EventLoop: Notifier(0x000055696e4e8e20) event 3 Consuming 51 bytes message buffer length 51 buffer size: 6 type=20, version=771 record length: 1 at offset: 3 message type: 20, length: 1 change cipher spec message consumed 6 bytes buffer size: 45 type=22, version=771 record length: 40 at offset: 3 message type: 22, length: 40 Encrypted: 00 00 00 00 00 00 00 00 1c 8c a8 79 8f b1 f5 9a e6 e6 55 c1 da 02 95 44 cd eb a7 09 a9 93 bb 6c c9 46 39 2b 16 1b 69 23 AAD bits: 0 : 104 Cipher bits: 0 : 128 Tag bits: 2291755386 : 970765263 : 1549081769 : 2959051364 Tag bits: 2291755386 : 970765223 : 1549081769 : 2959051492 tls handshake message payload size: 15 buffer length: 16 finished FIXME: handle_handshake_finished :: Check message validity Job: raw_request: GET /api/v9/users/@me HTTP/1.1 Host: discord.com Connection: close AAD bits: 0 : 104 Cipher bits: 0 : 576 Tag bits: 2390845415 : 778875917 : 908701313 : 3226234173 Tag bits: 2390845415 : 778876005 : 908701313 : 3226234749 Scheduling write of 101 Core::EventLoop::post_event: (0) << receivier=TLSv12(0x000055696e4e1800), event=0x000055696e4ef090 Update hash with message of size 16 consumed 45 bytes Core::EventLoop: TLSv12(0x000055696e4e1800) event 5 DeferredInvoke: receiver = TLSv12(0x000055696e4e1800) Flushing cached records: 101 established? true SENDING... 17 03 03 00 60 8f f8 07 d5 06 6c ed c6 22 66 f1 24 b2 a5 e0 3f 9e d5 d1 ab b3 cd f7 32 7e 02 47 df 83 40 e0 e8 41 92 e3 ef fc 63 50 ce cb 2f e7 fc 94 0b 9b 83 3b 83 62 04 85 ee a1 a7 26 57 23 2a dc bf 57 e1 20 6d 07 7f ba 4d 41 85 c9 e2 d6 f3 ce 20 0e 43 98 3c 85 22 9c a6 c0 ce c4 7a bb 7d 7e b8 05 b8 Core::EventLoop::post_event: (0) << receivier=Notifier(0x000055696e4e8e20), event=0x000055696e4e8e00 Core::EventLoop: Notifier(0x000055696e4e8e20) event 3 Consuming 1126 bytes message buffer length 1126 buffer size: 1126 type=23, version=771 record length: 1121 at offset: 3 message type: 23, length: 1121 Encrypted: 00 00 00 00 00 00 00 01 b6 23 a1 b4 7c 46 a3 a8 f2 df 07 8f 39 72 9a 79 92 1c c0 4e 57 6c 29 d6 20 52 70 ac 99 7d 4c d4 c6 d2 bd aa 2f e9 ab 77 44 b7 20 7a 49 22 cd be d9 af f4 5c 71 a8 13 cd 97 e0 61 3d b0 72 54 9b 12 19 18 3c 14 be 91 0d 40 04 19 ba e6 0b 05 19 c9 31 c5 64 8b 9b e1 18 34 05 54 f6 f0 38 21 e4 fd 06 a1 0e 1d 65 df 59 ff e6 59 87 6f b2 83 b5 01 c2 9a b7 51 3a b0 60 95 08 72 94 61 73 59 10 da fe 4b 2e d8 32 bc 76 e5 8b e8 f3 b4 f3 b6 4e 52 04 1d 25 88 d4 19 20 26 25 b1 a2 7c 83 d9 84 ab 83 d7 81 b7 93 24 c4 00 19 60 34 b5 29 fc 14 6a 39 12 bb 00 a7 fc 4e 71 32 b7 ff 75 14 e7 f2 38 e1 76 d4 6d cd 5b d2 7a ae c2 1f c5 e7 bb 89 b4 12 1b 6f 19 dc e1 a6 50 ee ab 16 75 85 46 42 d6 70 f6 65 cb 83 c4 98 65 94 80 af a1 9e 16 79 17 4c 71 99 bc 47 35 92 c7 c4 d5 ff 81 14 9f bb 2a 93 43 73 c5 57 59 d0 df c0 7a 26 c4 aa 6b a2 9a b5 24 16 ff dd 3b 87 67 78 12 49 83 09 e2 52 13 83 3f cc 18 69 3d ff 4b bd 5a 88 02 93 37 ae a2 3f 48 21 da e6 aa 08 c3 97 d3 b6 04 7e a0 b5 59 bb 29 cc d4 01 b3 4d 0a cc 8f 6a fd 59 ce f8 31 fc 96 6e 18 51 3d 59 4f a8 0c 8f 45 ec e1 ea e9 05 81 b1 1b f0 bf 75 54 f7 9b a7 aa ac 8f b5 08 09 34 50 10 79 f0 cf 28 2c 33 47 e8 ca 1a 05 d4 a4 ab c7 85 bd 1d 0e d9 67 55 ae a2 3f 4e d5 73 f9 75 59 e5 2d cf 42 85 69 dd eb b8 72 b0 c1 bb c1 b8 16 a1 61 d5 b7 64 4d 0d 56 04 2d b8 48 b7 b6 0d 24 2a f0 5a 4c 9f 5e 90 67 84 09 91 b9 55 54 1d ca 96 b5 a0 cd 0d 11 fc aa 31 1d 2f 65 36 db 81 88 81 44 c3 b5 5b 20 b5 49 ea a7 05 51 ee ef 2d 27 ad f4 f6 3c 3a 67 ec 96 ac b9 0f 96 d5 37 03 3d a5 d7 43 da ca cb 9b d7 4e 2f 9f e7 df 10 19 59 11 f5 93 ff 67 64 85 16 27 74 a2 c7 38 ea 0a 1f 95 2a 88 34 7b f1 d7 d4 8d fa 12 1e 17 6e 23 a6 4f 51 14 ed ce a1 06 f4 6d 36 98 46 43 d7 47 fa 69 d2 b4 0c 96 d2 7e 7d a5 2d 92 ce ff d4 b9 2c f4 10 d0 46 44 23 0c 99 3b ae b3 64 71 6e 4e b4 c1 9e 10 c7 3f 1b 00 d6 99 0d 2e 60 2a 68 94 62 7c 00 be 0f cd 9b d6 ae c4 ec 8f 51 0f e0 bd 9c 51 1b 92 f0 e0 1e 3e 39 d4 78 b2 ad 47 53 f9 6a c5 33 76 1f 10 c3 7b b9 b0 f7 77 d9 cf e2 26 9b fe 23 ec b3 ec 01 73 c9 69 19 2c 08 7e d2 64 70 ff 55 fa 55 4f 31 a6 91 aa a0 7b 07 e3 33 95 ef 73 29 7a 6e 03 1d 78 42 9e 53 9c 9c 86 2c 25 a9 33 1b 9a f0 a1 34 ee 97 fe 63 d6 af 32 a6 18 d8 81 b1 45 11 7a 9c 8a b0 e3 79 bb 8c 24 41 be 23 56 f7 a1 fb 3b fa 0b f0 3b ae 6f 92 c4 26 73 c2 12 b8 26 32 b0 59 5f 4e ed 74 5c 52 eb b9 1e b7 cc e9 32 2d c1 0c 21 68 dc b1 07 75 f6 86 8f c4 51 b0 9c 0b 30 37 c5 37 50 42 66 3a f8 7a 28 09 d2 7e 68 33 e9 60 a3 45 c8 3f 7a 6f fc 80 ca e3 7e 4e bb 98 41 1c 86 03 a2 eb 3b 39 bb 22 40 21 8f 5a c1 fd 84 d5 f0 3e 0b b8 e0 f0 75 18 e8 da 53 c6 e4 90 b5 ef da 51 23 62 a8 62 80 ef 0c 80 d3 ce fa 1d b1 51 53 93 cf ff 4e 78 02 fd cc 91 9a 19 5e 36 cf 3b 4d d6 45 f7 75 40 41 3f d4 34 02 dc 36 df ba 50 f7 1c b9 1b 73 01 f4 1c c8 d2 4e c6 9e c1 a6 4f db 43 46 c9 0c f7 6f f6 e5 56 3d 0f b9 99 d1 da 04 84 f1 c1 54 a7 37 58 ae 05 83 68 87 3d 7b a2 30 13 7b 8d 19 b1 f6 a4 51 95 49 ac bf c3 63 52 a4 25 70 af ee 91 68 8f 2b d5 e6 80 0e 83 aa 53 a4 6c 2e 43 05 82 62 02 92 d5 52 75 cd a0 30 ca e5 03 f6 19 03 35 29 80 8f 9f 21 cb a2 d6 77 32 08 65 9a 18 dc 4c 16 04 03 92 b4 a0 1e 30 71 af 96 19 74 bf b9 62 be 87 d2 5d 85 0b 20 17 8d ac 45 5c 24 0c 25 8b dc 5b 64 c8 d6 f0 ff 05 b5 95 fc db d4 2a 84 84 3b bb 2d 17 5b 74 6c c6 2c 86 70 df 38 5d 13 3e 10 7e 6b 48 24 78 dd 70 65 15 74 4d c1 1c b8 c0 4f ca 18 40 9b b2 54 3f 36 AAD bits: 0 : 104 Cipher bits: 0 : 8776 Tag bits: 1214317529 : 1378970420 : 2182510434 : 304609266 Tag bits: 1214317529 : 1378970460 : 2182510434 : 304600506 application data message of size 1097 consumed 1126 bytes Core::EventLoop::post_event: (0) << receivier=TLSv12(0x000055696e4e1800), event=0x000055696e4ef090 Core::EventLoop: TLSv12(0x000055696e4e1800) event 5 DeferredInvoke: receiver = TLSv12(0x000055696e4e1800) Core::EventLoop::post_event: (0) << receivier=TLSv12(0x000055696e4e1800), event=0x000055696e4ea270 Job: [Date] = 'Tue, 22 Jun 2021 21:33:13 GMT' Job: [Content-Type] = 'application/json' Core::EventLoop: TLSv12(0x000055696e4e1800) event 5 DeferredInvoke: receiver = TLSv12(0x000055696e4e1800) Core::EventLoop::post_event: (0) << receivier=TLSv12(0x000055696e4e1800), event=0x000055696e4ef090 Job: [Content-Length] = '43' Job: [Connection] = 'close' Core::EventLoop: TLSv12(0x000055696e4e1800) event 5 DeferredInvoke: receiver = TLSv12(0x000055696e4e1800) Core::EventLoop::post_event: (0) << receivier=TLSv12(0x000055696e4e1800), event=0x000055696e4ea270 Job: [CF-Ray] = '663898006c88e6e0-EWR' Job: [Set-Cookie] = '__dcfduid=f93526c4c5c14bf7bce927ae28e6fd1e; Expires=Sun, 21-Jun-2026 21:33:13 GMT; Max-Age=157680000; Secure; HttpOnly; Path=/' Core::EventLoop: TLSv12(0x000055696e4e1800) event 5 DeferredInvoke: receiver = TLSv12(0x000055696e4e1800) Core::EventLoop::post_event: (0) << receivier=TLSv12(0x000055696e4e1800), event=0x000055696e4ef090 Job: [Strict-Transport-Security] = 'max-age=31536000; includeSubDomains; preload' Job: [Via] = '1.1 google' Core::EventLoop: TLSv12(0x000055696e4e1800) event 5 DeferredInvoke: receiver = TLSv12(0x000055696e4e1800) Core::EventLoop::post_event: (0) << receivier=TLSv12(0x000055696e4e1800), event=0x000055696e4ea270 Job: [CF-Cache-Status] = 'DYNAMIC' Job: [Alt-Svc] = 'h3-27=":443"; ma=86400, h3-28=":443"; ma=86400, h3-29=":443"; ma=86400, h3=":443"; ma=86400' Core::EventLoop: TLSv12(0x000055696e4e1800) event 5 DeferredInvoke: receiver = TLSv12(0x000055696e4e1800) Core::EventLoop::post_event: (0) << receivier=TLSv12(0x000055696e4e1800), event=0x000055696e4ef090 Job: [cf-request-id] = '0ad73d54440000e6e03f18d000000001' Job: [Expect-CT] = 'max-age=604800, report-uri="https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct"' Core::EventLoop: TLSv12(0x000055696e4e1800) event 5 DeferredInvoke: receiver = TLSv12(0x000055696e4e1800) Core::EventLoop::post_event: (0) << receivier=TLSv12(0x000055696e4e1800), event=0x000055696e4ea270 Job: [X-Content-Type-Options] = 'nosniff' Job: [x-envoy-upstream-service-time] = '22' Core::EventLoop: TLSv12(0x000055696e4e1800) event 5 DeferredInvoke: receiver = TLSv12(0x000055696e4e1800) Core::EventLoop::post_event: (0) << receivier=TLSv12(0x000055696e4e1800), event=0x000055696e4ef090 Job: [Report-To] = '{"endpoints":[{"url":"https:\/\/a.nel.cloudflare.com\/report\/v2?s=8ZWhm0XPd8VeEa4UvV3BapkO9WchfoX4TvdKRwqVcOkF75iNSZdRR15PDcpxWBfuev5FbaqRon886wmxS%2FyWom4t3kytISlc1Shg0x%2FZGhGftgDK9aGpxA%3D%3D"}],"group":"cf-nel","max_age":604800}' Job: [NEL] = '{"report_to":"cf-nel","max_age":604800}' Core::EventLoop: TLSv12(0x000055696e4e1800) event 5 DeferredInvoke: receiver = TLSv12(0x000055696e4e1800) Core::EventLoop::post_event: (0) << receivier=TLSv12(0x000055696e4e1800), event=0x000055696e4ea270 Job: [Server] = 'cloudflare' Core::EventLoop: TLSv12(0x000055696e4e1800) event 5 DeferredInvoke: receiver = TLSv12(0x000055696e4e1800) Core::EventLoop::post_event: (0) << receivier=TLSv12(0x000055696e4e1800), event=0x000055696e4ef090 Job: Flushing received buffers: have 43 bytes in 1 buffers Job: Flushing received buffers done: have 0 bytes in 0 buffers Core::EventLoop::post_event: (1) << receivier=HttpsJob(0x000055696e4de480), event=0x000055696e4ef220 Core::EventLoop::post_event: (2) << receivier=HttpsJob(0x000055696e4de480), event=0x000055696e4f2430 Core::EventLoop: TLSv12(0x000055696e4e1800) event 5 DeferredInvoke: receiver = TLSv12(0x000055696e4e1800) Core::EventLoop: HttpsJob(0x000055696e4de480) event 5 DeferredInvoke: receiver = HttpsJob(0x000055696e4de480) Core::EventLoop: HttpsJob(0x000055696e4de480) event 5 DeferredInvoke: receiver = HttpsJob(0x000055696e4de480) HttpsJob(0x000055696e4de480) job did_finish Success: true, response code: 401 ```
drunderscore commented 3 years ago

I believe the following patch would be a correct solution:

diff --git a/Userland/Libraries/LibTLS/Socket.cpp b/Userland/Libraries/LibTLS/Socket.cpp
index 92c7afe1e..041eb1f8d 100644
--- a/Userland/Libraries/LibTLS/Socket.cpp
+++ b/Userland/Libraries/LibTLS/Socket.cpp
@@ -186,6 +186,7 @@ bool TLSv12::check_connection_state(bool read)
         // an abrupt closure (the server is a jerk)
         dbgln_if(TLS_DEBUG, "Socket not open, assuming abrupt closure");
         m_context.connection_finished = true;
+        return false;
     }
     if (m_context.critical_error) {
         dbgln_if(TLS_DEBUG, "CRITICAL ERROR {} :(", m_context.critical_error);
alimpfard commented 3 years ago

it's pretty odd for that to call finished multiple times, since this bit should guard that:

    // Next iteration: m_context.connection_finished is false, so we don't even go in here...?
    if (((read && m_context.application_buffer.size() == 0) || !read) && m_context.connection_finished) {
        /// m_context.connection_finished must be true here
        if (m_context.application_buffer.size() == 0) {
            // m_context.application_buffer.size() must be zero here
            if (on_tls_finished)
                on_tls_finished();
        }
        if (m_context.tls_buffer.size()) {
            dbgln_if(TLS_DEBUG, "connection closed without finishing data transfer, {} bytes still in buffer and {} bytes in application buffer",
                m_context.tls_buffer.size(),
                m_context.application_buffer.size());
        } else {
            // m_context.application_buffer.size() must be zero here
            // This is likely the bug:      vvvvv
            m_context.connection_finished = false;
            dbgln_if(TLS_DEBUG, "FINISHED");
        }
        if (!m_context.application_buffer.size()) {
            // m_context.application_buffer.size() must be zero here
            // m_context.connection_finished is set to zero by the branch above
            m_context.connection_status = ConnectionStatus::Disconnected;
            return false;
        }
    }

But if your patch fixes the weirdness, just set m_context.connection_status and return false :shrug:

Try setting the false marked by vvvvv to true, that might be the problem...

alimpfard commented 3 years ago

Oh... That should set connection_finished to true, not false...

drunderscore commented 3 years ago

no, it does, that's the original code, no?

drunderscore commented 3 years ago

Oh I see what you mean,

m_context.connection_finished = false;
dbgln_if(TLS_DEBUG, "FINISHED");

thats an oopsie!

alimpfard commented 3 years ago

Or...hmmm That has to be false for us not to enter this whole if 🤔

3am logic isn't good, sorry

drunderscore commented 3 years ago

When just setting the above mistake to true doesn't fix this issue's problem, but it's still wrong so :^)