Skip to content

Instantly share code, notes, and snippets.

@allquixotic
Created January 18, 2023 13:56
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save allquixotic/f1b02d7e674cdd4abd72b46cb9ff2d57 to your computer and use it in GitHub Desktop.
Save allquixotic/f1b02d7e674cdd4abd72b46cb9ff2d57 to your computer and use it in GitHub Desktop.
jsonrpsee logging issue
use jsonrpsee::{http_client::HttpClientBuilder};
use dotenvy::var;
use jsonrpsee::{core::{Error}, proc_macros::rpc};
#[rpc(client)]
pub trait User
{
#[method(name = "User.login", param_kind = map, blocking)]
fn login(&self, email: String, password: String) -> Result<String, Error>;
}
#[tokio::main]
async fn main() -> anyhow::Result<()> {
tracing_subscriber::FmtSubscriber::builder()
.with_env_filter(tracing_subscriber::EnvFilter::from_default_env())
.try_init()
.expect("setting default subscriber failed");
let email = var("email").expect("Required .env variable missing: email");
let password = var("password").expect("Required .env variable missing: password");
let website = var("website").expect("Required .env variable missing: website");
let client = HttpClientBuilder::default().set_max_logging_length(99999999).build(format!("https://{}:443/api/v1/api.php", website)).unwrap();
let session_id = client.login(email, password).await;
match session_id {
Ok(sess) => println!("Session ID: {}", sess),
Err(e) => {
println!("Error: {}", e.to_string());
}
}
Ok(())
}
user@system project-client % export RUST_LOG=trace
user@system project-client % export email="redacted@example.com"
user@system project-client % export password="redacted"
user@system project-client % export website="www.enjin.com"
user@system project-client % cargo run
Finished dev [unoptimized + debuginfo] target(s) in 0.08s
Running `target/debug/project-client`
2023-01-18T13:51:07.121235Z DEBUG hyper_rustls::config: with_native_roots processed 165 valid and 0 invalid certs
2023-01-18T13:51:07.122064Z TRACE method_call{method="User.login"}: jsonrpsee_core::tracing: send="{\"jsonrpc\":\"2.0\",\"id\":0,\"method\":\"User.login\",\"params\":{\"email\":\"redacted@example.com\",\"password\":\"redacted\"}}"
2023-01-18T13:51:07.122585Z TRACE method_call{method="User.login"}: hyper::client::pool: checkout waiting for idle connection: ("https", www.enjin.com:443)
2023-01-18T13:51:07.122854Z TRACE method_call{method="User.login"}: hyper::client::connect::http: Http::connect; scheme=Some("https"), host=Some("www.enjin.com"), port=Some(Port(443))
2023-01-18T13:51:07.122965Z DEBUG hyper::client::connect::dns: resolving host="www.enjin.com"
2023-01-18T13:51:07.276290Z DEBUG method_call{method="User.login"}: hyper::client::connect::http: connecting to 104.19.252.34:443
2023-01-18T13:51:07.276642Z TRACE method_call{method="User.login"}: mio::poll: registering event source with poller: token=Token(0), interests=READABLE | WRITABLE
2023-01-18T13:51:07.290856Z DEBUG method_call{method="User.login"}: hyper::client::connect::http: connected to 104.19.252.34:443
2023-01-18T13:51:07.291113Z DEBUG method_call{method="User.login"}: rustls::client::hs: No cached session for DnsName(DnsName(DnsName("www.enjin.com")))
2023-01-18T13:51:07.291544Z DEBUG method_call{method="User.login"}: rustls::client::hs: Not resuming any session
2023-01-18T13:51:07.291907Z TRACE method_call{method="User.login"}: rustls::client::hs: Sending ClientHello Message {
version: TLSv1_0,
payload: Handshake {
parsed: HandshakeMessagePayload {
typ: ClientHello,
payload: ClientHello(
ClientHelloPayload {
client_version: TLSv1_2,
random: redacted,
session_id: redacted,
cipher_suites: [
TLS13_AES_256_GCM_SHA384,
TLS13_AES_128_GCM_SHA256,
TLS13_CHACHA20_POLY1305_SHA256,
TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384,
TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256,
TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305_SHA256,
TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384,
TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256,
TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305_SHA256,
TLS_EMPTY_RENEGOTIATION_INFO_SCSV,
],
compression_methods: [
Null,
],
extensions: [
SupportedVersions(
[
TLSv1_3,
TLSv1_2,
],
),
ECPointFormats(
[
Uncompressed,
],
),
NamedGroups(
[
X25519,
secp256r1,
secp384r1,
],
),
SignatureAlgorithms(
[
ECDSA_NISTP384_SHA384,
ECDSA_NISTP256_SHA256,
ED25519,
RSA_PSS_SHA512,
RSA_PSS_SHA384,
RSA_PSS_SHA256,
RSA_PKCS1_SHA512,
RSA_PKCS1_SHA384,
RSA_PKCS1_SHA256,
],
),
ExtendedMasterSecretRequest,
CertificateStatusRequest(
OCSP(
OCSPCertificateStatusRequest {
responder_ids: [],
extensions: ,
},
),
),
ServerName(
[
ServerName {
typ: HostName,
payload: HostName(
(
redacted,
DnsName(
"www.enjin.com",
),
),
),
},
],
),
SignedCertificateTimestampRequest,
KeyShare(
[
KeyShareEntry {
group: X25519,
payload: redacted,
},
],
),
PresharedKeyModes(
[
PSK_DHE_KE,
],
),
SessionTicket(
Request,
),
],
},
),
},
encoded: redacted,
},
}
2023-01-18T13:51:07.324344Z TRACE method_call{method="User.login"}: rustls::client::hs: We got ServerHello ServerHelloPayload {
legacy_version: TLSv1_2,
random: redacted,
session_id: redacted,
cipher_suite: TLS13_AES_256_GCM_SHA384,
compression_method: Null,
extensions: [
KeyShare(
KeyShareEntry {
group: X25519,
payload: redacted,
},
),
SupportedVersions(
TLSv1_3,
),
],
}
2023-01-18T13:51:07.324501Z DEBUG method_call{method="User.login"}: rustls::client::hs: Using ciphersuite TLS13_AES_256_GCM_SHA384
2023-01-18T13:51:07.324551Z DEBUG method_call{method="User.login"}: rustls::client::tls13: Not resuming
2023-01-18T13:51:07.324572Z TRACE method_call{method="User.login"}: rustls::client::client_conn: EarlyData rejected
2023-01-18T13:51:07.325213Z TRACE method_call{method="User.login"}: rustls::conn: Dropping CCS
2023-01-18T13:51:07.325307Z DEBUG method_call{method="User.login"}: rustls::client::tls13: TLS1.3 encrypted extensions: [ServerNameAck]
2023-01-18T13:51:07.325347Z DEBUG method_call{method="User.login"}: rustls::client::hs: ALPN protocol is None
2023-01-18T13:51:07.325438Z TRACE method_call{method="User.login"}: rustls::client::tls13: Server cert is [Certificate(b"0redacted")]
2023-01-18T13:51:07.326684Z TRACE method_call{method="User.login"}: rustls::verify: Unvalidated OCSP response: [1, 2, 3, redacted]
2023-01-18T13:51:07.327456Z TRACE method_call{method="User.login"}: hyper::client::conn: client handshake Http1
2023-01-18T13:51:07.327595Z TRACE method_call{method="User.login"}: hyper::client::client: handshake complete, spawning background dispatcher task
2023-01-18T13:51:07.328100Z TRACE want: signal: Want
2023-01-18T13:51:07.328129Z TRACE want: signal found waiting giver, notifying
2023-01-18T13:51:07.328175Z TRACE hyper::proto::h1::conn: flushed({role=client}): State { reading: Init, writing: Init, keep_alive: Busy }
2023-01-18T13:51:07.328171Z TRACE method_call{method="User.login"}: want: poll_want: taker wants!
2023-01-18T13:51:07.328216Z TRACE method_call{method="User.login"}: hyper::client::pool: checkout dropped for ("https", www.enjin.com:443)
2023-01-18T13:51:07.328555Z TRACE encode_headers: hyper::proto::h1::role: Client::encode method=POST, body=Some(Known(121))
2023-01-18T13:51:07.328690Z TRACE hyper::proto::h1::io: buffer.flatten self.len=139 buf.len=121
2023-01-18T13:51:07.328738Z DEBUG hyper::proto::h1::io: flushed 260 bytes
2023-01-18T13:51:07.328748Z TRACE hyper::proto::h1::conn: flushed({role=client}): State { reading: Init, writing: KeepAlive, keep_alive: Busy }
2023-01-18T13:51:07.425366Z TRACE hyper::proto::h1::conn: Conn::read_head
2023-01-18T13:51:07.425619Z DEBUG rustls::client::tls13: Ticket saved
2023-01-18T13:51:07.425689Z DEBUG rustls::client::tls13: Ticket saved
2023-01-18T13:51:07.425722Z TRACE hyper::proto::h1::io: received 745 bytes
2023-01-18T13:51:07.425829Z TRACE parse_headers: hyper::proto::h1::role: Response.parse bytes=745
2023-01-18T13:51:07.425922Z TRACE parse_headers: hyper::proto::h1::role: Response.parse Complete(729)
2023-01-18T13:51:07.426079Z DEBUG hyper::proto::h1::io: parsed 12 headers
2023-01-18T13:51:07.426097Z DEBUG hyper::proto::h1::conn: incoming body is content-length (16 bytes)
2023-01-18T13:51:07.426250Z TRACE hyper::proto::h1::decode: decode; state=Length(16)
2023-01-18T13:51:07.426290Z DEBUG hyper::proto::h1::conn: incoming body completed
Error: Networking or low-level protocol error: Server returned an error status code: 403
2023-01-18T13:51:07.426330Z TRACE hyper::proto::h1::conn: maybe_notify; read_from_io blocked
2023-01-18T13:51:07.426383Z TRACE want: signal: Want
2023-01-18T13:51:07.426407Z TRACE want: signal found waiting giver, notifying
2023-01-18T13:51:07.426429Z TRACE hyper::proto::h1::conn: flushed({role=client}): State { reading: Init, writing: Init, keep_alive: Idle }
2023-01-18T13:51:07.426455Z TRACE want: signal: Want
2023-01-18T13:51:07.426471Z TRACE hyper::proto::h1::conn: flushed({role=client}): State { reading: Init, writing: Init, keep_alive: Idle }
2023-01-18T13:51:07.426627Z TRACE mio::poll: deregistering event source from poller
2023-01-18T13:51:07.426685Z TRACE hyper::client::pool: pool dropped, dropping pooled (("https", www.enjin.com:443))
2023-01-18T13:51:07.426767Z TRACE want: signal: Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment