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.

Sign up for GitHub

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

Jump to bottom

electrum_client: disrepancies w/ certificate verification between use-rustls & use-openssl #1598

Open
pythcoiner opened this issue Sep 9, 2024 · 2 comments
Open

electrum_client: disrepancies w/ certificate verification between use-rustls & use-openssl #1598

pythcoiner opened this issue Sep 9, 2024 · 2 comments
Labels
bug Something isn't working
Milestone
1.0.0-beta

Comments

@pythcoiner
Copy link

Describe the bug
trying to connect to an electrum server w/ a self-signed certificate using use-rustls fails but succeed w/ use-openssl

To Reproduce
code snippet:

use electrum_client::{ConfigBuilder, ElectrumApi};

fn main() {
    let config = ConfigBuilder::new()
        .retry(1)
        .timeout(Some(1))
        .validate_domain(false)
        .socks5(None)
        .build();
    let client =
        electrum_client::Client::from_config("ssl://testnet.aranguren.org:51002", config).unwrap();

    match client.ping() {
        Ok(_) => println!("Pong"),
        Err(e) => {
            println!("{:?}", e);
        }
    }
}

Expected behavior
should succeed w/ both features, use-rusttls fails w/:

AllAttemptsErrored([IOError(Kind(UnexpectedEof))])

trying w/ a local electrs + nginx + self-sign certificate i got this in nginx error log w/ use-rustls:

2024/09/09 10:31:50 [info] 493372#493372: *16 client 192.168.1.6:56774 connected to 0.0.0.0:60002
2024/09/09 10:31:50 [debug] 493372#493372: *16 posix_memalign: 00005583228C41D0:256 @16
2024/09/09 10:31:50 [debug] 493372#493372: *16 posix_memalign: 00005583227FA5D0:256 @16
2024/09/09 10:31:50 [debug] 493372#493372: *16 generic phase: 0
2024/09/09 10:31:50 [debug] 493372#493372: *16 generic phase: 1
2024/09/09 10:31:50 [debug] 493372#493372: *16 generic phase: 2
2024/09/09 10:31:50 [debug] 493372#493372: *16 generic phase: 3
2024/09/09 10:31:50 [debug] 493372#493372: *16 generic phase: 4
2024/09/09 10:31:50 [debug] 493372#493372: *16 tcp_nodelay
2024/09/09 10:31:50 [debug] 493372#493372: *16 posix_memalign: 00005583227FAC90:256 @16
2024/09/09 10:31:50 [debug] 493372#493372: *16 SSL_do_handshake: -1
2024/09/09 10:31:50 [debug] 493372#493372: *16 SSL_get_error: 1
2024/09/09 10:31:50 [crit] 493372#493372: *16 SSL_do_handshake() failed (SSL: error:0A00006E:SSL routines::bad extension) while SSL handshaking, client: 192.168.1.6, server: 0.0.0.0:60002
2024/09/09 10:31:50 [debug] 493372#493372: *16 finalize stream session: 500
2024/09/09 10:31:50 [debug] 493372#493372: *16 stream log handler
2024/09/09 10:31:50 [debug] 493372#493372: *16 geoip2 stream log handler
2024/09/09 10:31:50 [debug] 493372#493372: *16 close stream connection: 18
2024/09/09 10:31:50 [debug] 493372#493372: *16 reusable connection: 0
2024/09/09 10:31:50 [debug] 493372#493372: *16 free: 00005583228C3B50, unused: 19
2024/09/09 10:31:50 [debug] 493372#493372: *16 free: 00005583228C43F0, unused: 16
2024/09/09 10:31:50 [debug] 493372#493372: *16 free: 00005583228C41D0, unused: 64
2024/09/09 10:31:50 [debug] 493372#493372: *16 free: 00005583227FA5D0, unused: 48
2024/09/09 10:31:50 [debug] 493372#493372: *16 free: 00005583227FAC90, unused: 53

and this w/ use-openssl:

2024/09/09 10:34:20 [debug] 493372#493372: *17 accept: 192.168.1.6:60776 fd:18
2024/09/09 10:34:20 [debug] 493372#493372: posix_memalign: 00005583227FA5D0:256 @16
2024/09/09 10:34:20 [info] 493372#493372: *17 client 192.168.1.6:60776 connected to 0.0.0.0:60002
2024/09/09 10:34:20 [debug] 493372#493372: *17 posix_memalign: 00005583228C41D0:256 @16
2024/09/09 10:34:20 [debug] 493372#493372: *17 posix_memalign: 00005583228C43F0:256 @16
2024/09/09 10:34:20 [debug] 493372#493372: *17 generic phase: 0
2024/09/09 10:34:20 [debug] 493372#493372: *17 generic phase: 1
2024/09/09 10:34:20 [debug] 493372#493372: *17 generic phase: 2
2024/09/09 10:34:20 [debug] 493372#493372: *17 generic phase: 3
2024/09/09 10:34:20 [debug] 493372#493372: *17 generic phase: 4
2024/09/09 10:34:20 [debug] 493372#493372: *17 tcp_nodelay
2024/09/09 10:34:20 [debug] 493372#493372: *17 posix_memalign: 00005583228C3B50:256 @16
2024/09/09 10:34:20 [debug] 493372#493372: *17 SSL_do_handshake: -1
2024/09/09 10:34:20 [debug] 493372#493372: *17 SSL_get_error: 2
2024/09/09 10:34:20 [debug] 493372#493372: *17 epoll add event: fd:18 op:1 ev:80002001
2024/09/09 10:34:20 [debug] 493372#493372: *17 event timer add: 18: 60000:439665879
2024/09/09 10:34:20 [debug] 493372#493372: *17 SSL handshake handler: 0
2024/09/09 10:34:20 [debug] 493372#493372: *17 SSL_do_handshake: -1
2024/09/09 10:34:20 [debug] 493372#493372: *17 SSL_get_error: 2
2024/09/09 10:34:20 [debug] 493372#493372: *17 SSL handshake handler: 0
2024/09/09 10:34:20 [debug] 493372#493372: *17 ssl new session: 101DC0F1:32:149
2024/09/09 10:34:20 [debug] 493372#493372: *17 ssl new session: 4BBE0F2A:32:150
2024/09/09 10:34:20 [debug] 493372#493372: *17 SSL_do_handshake: 1
2024/09/09 10:34:20 [debug] 493372#493372: *17 SSL: TLSv1.3, cipher: "TLS_AES_256_GCM_SHA384 TLSv1.3 Kx=any Au=any Enc=AESGCM(256) Mac=AEAD"
2024/09/09 10:34:20 [debug] 493372#493372: *17 event timer del: 18: 439665879
2024/09/09 10:34:20 [debug] 493372#493372: *17 generic phase: 4
2024/09/09 10:34:20 [debug] 493372#493372: *17 ssl preread handler
2024/09/09 10:34:20 [debug] 493372#493372: *17 proxy connection handler
2024/09/09 10:34:20 [debug] 493372#493372: *17 malloc: 00005583228C4BB0:448
2024/09/09 10:34:20 [debug] 493372#493372: *17 malloc: 00005583228BAC70:16384
2024/09/09 10:34:20 [debug] 493372#493372: *17 post event 0000558322896D10
2024/09/09 10:34:20 [debug] 493372#493372: *17 get rr peer, try: 1
2024/09/09 10:34:20 [debug] 493372#493372: *17 stream socket 19
2024/09/09 10:34:20 [debug] 493372#493372: *17 epoll add connection: fd:19 ev:80002005
2024/09/09 10:34:20 [debug] 493372#493372: *17 connect to 192.168.1.21:50003, fd:19 #18
2024/09/09 10:34:20 [debug] 493372#493372: *17 proxy connect: -2
2024/09/09 10:34:20 [debug] 493372#493372: *17 event timer add: 19: 60000:439665925
2024/09/09 10:34:20 [debug] 493372#493372: *17 delete posted event 0000558322896D10
2024/09/09 10:34:20 [debug] 493372#493372: *17 SSL_read: -1
2024/09/09 10:34:20 [debug] 493372#493372: *17 SSL_get_error: 2
2024/09/09 10:34:20 [debug] 493372#493372: *17 event timer del: 19: 439665925
2024/09/09 10:34:20 [debug] 493372#493372: *17 stream proxy connect upstream
2024/09/09 10:34:20 [debug] 493372#493372: *17 tcp_nodelay
2024/09/09 10:34:20 [info] 493372#493372: *17 proxy 192.168.1.21:57420 connected to 192.168.1.21:50003
2024/09/09 10:34:20 [debug] 493372#493372: *17 malloc: 00005583228C5030:16384
2024/09/09 10:34:20 [debug] 493372#493372: *17 event timer add: 18: 600000:440205926
2024/09/09 10:34:20 [debug] 493372#493372: *17 SSL_read: 60
2024/09/09 10:34:20 [debug] 493372#493372: *17 SSL_read: -1
2024/09/09 10:34:20 [debug] 493372#493372: *17 SSL_get_error: 2
2024/09/09 10:34:20 [debug] 493372#493372: *17 write new buf t:1 f:0 0000000000000000, pos 00005583228BAC70, size: 60 file: 0, size: 0
2024/09/09 10:34:20 [debug] 493372#493372: *17 stream write filter: l:0 f:1 s:60
2024/09/09 10:34:20 [debug] 493372#493372: *17 writev: 60 of 60
2024/09/09 10:34:20 [debug] 493372#493372: *17 stream write filter 0000000000000000
2024/09/09 10:34:20 [debug] 493372#493372: *17 event timer: 18, old: 440205926, new: 440205931
2024/09/09 10:34:20 [debug] 493372#493372: *17 recv: eof:0, avail:-1
2024/09/09 10:34:20 [debug] 493372#493372: *17 recv: fd:19 39 of 16384
2024/09/09 10:34:20 [debug] 493372#493372: *17 write new buf t:1 f:0 0000000000000000, pos 00005583228C5030, size: 39 file: 0, size: 0
2024/09/09 10:34:20 [debug] 493372#493372: *17 stream write filter: l:0 f:1 s:39
2024/09/09 10:34:20 [debug] 493372#493372: *17 SSL to write: 39
2024/09/09 10:34:20 [debug] 493372#493372: *17 SSL_write: 39
2024/09/09 10:34:20 [debug] 493372#493372: *17 stream write filter 0000000000000000
2024/09/09 10:34:20 [debug] 493372#493372: *17 event timer: 18, old: 440205926, new: 440205931
2024/09/09 10:34:20 [debug] 493372#493372: *17 event timer: 18, old: 440205926, new: 440205931
2024/09/09 10:34:20 [debug] 493372#493372: *17 SSL_read: 0
2024/09/09 10:34:20 [debug] 493372#493372: *17 SSL_get_error: 6
2024/09/09 10:34:20 [debug] 493372#493372: *17 peer shutdown SSL cleanly
2024/09/09 10:34:20 [debug] 493372#493372: *17 write new buf t:0 f:0 0000000000000000, pos 00005583228BAC70, size: 0 file: 0, size: 0
2024/09/09 10:34:20 [debug] 493372#493372: *17 stream write filter: l:1 f:1 s:0
2024/09/09 10:34:20 [info] 493372#493372: *17 client disconnected, bytes from/to client:60/39, bytes from/to upstream:39/60
2024/09/09 10:34:20 [debug] 493372#493372: *17 finalize stream proxy: 200
2024/09/09 10:34:20 [debug] 493372#493372: *17 free rr peer 1 0
2024/09/09 10:34:20 [debug] 493372#493372: *17 close stream proxy upstream connection: 19
2024/09/09 10:34:20 [debug] 493372#493372: *17 reusable connection: 0
2024/09/09 10:34:20 [debug] 493372#493372: *17 finalize stream session: 200
2024/09/09 10:34:20 [debug] 493372#493372: *17 stream log handler
2024/09/09 10:34:20 [debug] 493372#493372: *17 posix_memalign: 00005583228C35A0:256 @16
2024/09/09 10:34:20 [debug] 493372#493372: *17 posix_memalign: 00005583228C3820:256 @16
2024/09/09 10:34:20 [debug] 493372#493372: *17 geoip2 stream log handler
2024/09/09 10:34:20 [debug] 493372#493372: *17 close stream connection: 18
2024/09/09 10:34:20 [debug] 493372#493372: *17 SSL_shutdown: 1
2024/09/09 10:34:20 [debug] 493372#493372: *17 event timer del: 18: 440205926
2024/09/09 10:34:20 [debug] 493372#493372: *17 reusable connection: 0
2024/09/09 10:34:20 [debug] 493372#493372: *17 free: 00005583228C5030
2024/09/09 10:34:20 [debug] 493372#493372: *17 free: 00005583228BAC70
2024/09/09 10:34:20 [debug] 493372#493372: *17 free: 00005583228C4BB0
2024/09/09 10:34:20 [debug] 493372#493372: *17 free: 00005583227FAC90, unused: 8
2024/09/09 10:34:20 [debug] 493372#493372: *17 free: 00005583227FA5D0, unused: 0
2024/09/09 10:34:20 [debug] 493372#493372: *17 free: 00005583228C41D0, unused: 8
2024/09/09 10:34:20 [debug] 493372#493372: *17 free: 00005583228C43F0, unused: 0
2024/09/09 10:34:20 [debug] 493372#493372: *17 free: 00005583228C3B50, unused: 2
2024/09/09 10:34:20 [debug] 493372#493372: *17 free: 00005583228C35A0, unused: 70
2024/09/09 10:34:20 [debug] 493372#493372: *17 free: 00005583228C3820, unused: 124

Build environment

  • BDK tag/commit: 0.21.0
  • OS+version: arch linux
  • Rust/Cargo version: cargo 1.78.0 (54d8815d0 2024-03-26)
  • Rust/Cargo target: x86_64-unknown-linux-gnu
@pythcoiner pythcoiner added the bug Something isn't working label Sep 9, 2024
@pythcoiner pythcoiner mentioned this issue Sep 9, 2024
Open
@oleonardolima
Copy link
Contributor

oleonardolima commented Sep 9, 2024 •
edited
Loading

Thanks for debugging and collecting the related info. Although I didn't delve into this yet and reproduced the problem, I think it's somewhat related to a problem I faced in the past with LND, reference: lightningnetwork/lnd#5450.

It requires further investigation, but if it's not a problem downstream with how rustls and how webpki handle self-signed certificates, it's related to how we are building the client here.

There's also the issue that we don't expose the use-openssl feature on bdk_electrum, right ?

@notmandatory @thunderbiscuit, have there been any previous discussions on why it's not exposed ?

@pythcoiner
Copy link
Author

pythcoiner commented Sep 9, 2024 •
edited
Loading

Thanks for debugging and collecting the related info. Although I didn't delve into this yet and reproduced the problem, I think it's somewhat related to a problem I faced in the past with LND, reference: lightningnetwork/lnd#5450.

looks have the same root cause

It requires further investigation, but if it's not a problem downstream with how rustls and how webpki handle self-signed certificates, it's related to how we are building the client here.

Yes, it looks to me the intended logic is to NOT check the certificate if validate_domain = false :

but ends up not as intended for rustls

There's also the issue that we don't expose the use-openssl feature on bdk_electrum, right ?

right this make it uneasy to fallback to openssl

@notmandatory @thunderbiscuit, have there been any previous discussions on why it's not exposed ?

@notmandatory notmandatory added this to the 1.0.0-beta milestone Sep 17, 2024
@oleonardolima oleonardolima mentioned this issue Sep 20, 2024
Draft
8 tasks
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
BDK
Status: Discussion
Milestone
1.0.0-beta
Development

No branches or pull requests
3 participants
@notmandatory @oleonardolima @pythcoiner