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

Panic triggered when sending file to Wormhole William #136

Closed
Alch-Emi opened this issue Nov 21, 2021 · 7 comments
Closed

Panic triggered when sending file to Wormhole William #136

Alch-Emi opened this issue Nov 21, 2021 · 7 comments

Comments

@Alch-Emi
Copy link

Alch-Emi commented Nov 21, 2021 •
edited
Loading

When sending any file to the Wormhole William app (android), magic-wormhole.rs panics before the transfer is complete.

Running magic-wormhole installed from source on commit 166d434 (latest), and Wormhole William version 1.0.4 (latest fdroid). Running wormhole send <filename> on sending device, and entering the code in WW initially produces an accept/deny prompt, as expected. However, selecting "accept" causes wormhole.rs to panic with the error appended to the bottom of this post.

This error does not occur with standard python wormhole, nor with the reverse configuration (ww -> wrs). The error on WW's side is simply "Receive file error: failed to establish connection".

I'm running magic-wormhole.rs on Fedora 35 (although I had this problem on 34 as well), built locally with cargo 1.56.0 (4ed5d137b 2021-10-04)

Please let me know if there is any other information I can help provide, or if I should move this over to WW's issue tracker instead. I figured I ought to post it here, since panics are rarely expected behavior, even with a misbehaving remote, but I'm happy to move it if it's their client acting up.

Thanks so much for your help and for the awesome app!

[2021-11-21T06:39:19Z DEBUG wormhole] Logging enabled.
[2021-11-21T06:39:19Z DEBUG tungstenite::handshake::client] Client handshake done.
[2021-11-21T06:39:19Z DEBUG magic_wormhole::core::rendezvous] Received Welcome(WelcomeMessage { .. })
[2021-11-21T06:39:19Z DEBUG magic_wormhole::core::rendezvous] Sending Bind { appid: lothar.com/wormhole/text-or-file-xfer, side: MySide(79db9246c0) }
[2021-11-21T06:39:19Z DEBUG magic_wormhole::core::rendezvous] Received Ack
[2021-11-21T06:39:19Z INFO  magic_wormhole::core::rendezvous] Connected to server
[2021-11-21T06:39:19Z DEBUG magic_wormhole::core::rendezvous] Sending Allocate
[2021-11-21T06:39:19Z DEBUG magic_wormhole::core::rendezvous] Received Ack
[2021-11-21T06:39:19Z DEBUG magic_wormhole::core::rendezvous] Received Allocated(4)
[2021-11-21T06:39:19Z DEBUG magic_wormhole::core::rendezvous] Sending Claim(4)
[2021-11-21T06:39:19Z DEBUG magic_wormhole::core::rendezvous] Received Ack
[2021-11-21T06:39:19Z DEBUG magic_wormhole::core::rendezvous] Received Claimed(53ibosonhxwes)
[2021-11-21T06:39:19Z DEBUG magic_wormhole::core::rendezvous] Sending Open(53ibosonhxwes)
[2021-11-21T06:39:19Z DEBUG magic_wormhole::core::rendezvous] Received Ack
[2021-11-21T06:39:19Z DEBUG magic_wormhole::core] Connected to mailbox 53ibosonhxwes
This wormhole's code is: 4-atmosphere-edict
On the other computer, please run:

wormhole receive 4-atmosphere-edict

[2021-11-21T06:39:19Z DEBUG magic_wormhole::core::rendezvous] Sending Add { phase: pake, body: <JSON dict with key 'pake_v1'> }
[2021-11-21T06:39:19Z DEBUG magic_wormhole::core::rendezvous] Received Ack
[2021-11-21T06:39:19Z DEBUG magic_wormhole::core::rendezvous] Received EncryptedMessage { side: TheirSide(79db9246c0), phase: pake, body: <JSON dict with key 'pake_v1'>
[2021-11-21T06:39:45Z DEBUG magic_wormhole::core::rendezvous] Received EncryptedMessage { side: TheirSide(7a43000d89), phase: pake, body: <JSON dict with key 'pake_v1'>
[2021-11-21T06:39:45Z DEBUG magic_wormhole::core::rendezvous] Sending Add { phase: version, body: <74 bytes> }
[2021-11-21T06:39:45Z DEBUG magic_wormhole::core::rendezvous] Received Ack
[2021-11-21T06:39:45Z DEBUG magic_wormhole::core::rendezvous] Received EncryptedMessage { side: TheirSide(79db9246c0), phase: version, body: <74 bytes>
[2021-11-21T06:39:45Z DEBUG magic_wormhole::core::rendezvous] Received EncryptedMessage { side: TheirSide(7a43000d89), phase: version, body: <59 bytes>
[2021-11-21T06:39:45Z DEBUG magic_wormhole::core::rendezvous] Sending Release(4)
[2021-11-21T06:39:45Z DEBUG magic_wormhole::core::rendezvous] Received Ack
[2021-11-21T06:39:45Z DEBUG magic_wormhole::core::rendezvous] Received Released
[2021-11-21T06:39:45Z INFO  magic_wormhole::core] Connected to peer (PAKE successful)
Successfully connected to peer.
Decoded message: Message { class: SuccessResponse, method: Method(1), transaction_id: TransactionId(0xE721CEDB0DEDB64B511B98D0), attributes: [Known { inner: XorMappedAddress(XorMappedAddress(REDACTED)), padding: Some(Padding([])) }, Known { inner: MappedAddress(MappedAddress(REDACTED)), padding: Some(Padding([])) }, Unknown { inner: RawAttribute { attr_type: AttributeType(32811), value: [0, 1, 13, 150, 188, 34, 185, 244] }, padding: Some(Padding([])) }, Unknown { inner: RawAttribute { attr_type: AttributeType(32812), value: [0, 1, 13, 151, 188, 34, 185, 244] }, padding: Some(Padding([])) }, Known { inner: Software(Software { description: "Coturn-4.5.2 'dan Eider'" }), padding: Some(Padding([])) }] }
[2021-11-21T06:39:45Z DEBUG magic_wormhole::transit] Our external IP address is REDACTED
[2021-11-21T06:39:45Z DEBUG magic_wormhole::transfer] Sending transit message 'Hints { direct_tcp: {DirectHint { hostname: "REDACTED", port: 33595 }, DirectHint { hostname: "172.17.0.1", port: 36637 }, DirectHint { hostname: "192.168.122.1", port: 33595 }, DirectHint { hostname: "192.168.122.1", port: 36637 }, DirectHint { hostname: "fc00:bbbb:bbbb:bb01::9:c600", port: 36637 }, DirectHint { hostname: "172.23.0.1", port: 36637 }, DirectHint { hostname: "fc00:bbbb:bbbb:bb01::9:c600", port: 33595 }, DirectHint { hostname: "172.18.0.1", port: 33595 }, DirectHint { hostname: "REDACTED", port: 36637 }, DirectHint { hostname: "172.24.0.1", port: 36637 }, DirectHint { hostname: "REDACTED", port: 33595 }, DirectHint { hostname: "10.72.198.1", port: 36637 }, DirectHint { hostname: "172.20.0.1", port: 33595 }, DirectHint { hostname: "172.21.0.1", port: 33595 }, DirectHint { hostname: "REDACTED", port: 36637 }, DirectHint { hostname: "172.19.0.1", port: 36637 }, DirectHint { hostname: "172.22.0.1", port: 33595 }, DirectHint { hostname: "172.20.0.1", port: 36637 }, DirectHint { hostname: "172.24.0.1", port: 33595 }, DirectHint { hostname: "172.19.0.1", port: 33595 }, DirectHint { hostname: "REDACTED", port: 36637 }, DirectHint { hostname: "2620:8d:8000:1058:5972:1086:1aa4:50d7", port: 33595 }, DirectHint { hostname: "172.23.0.1", port: 33595 }, DirectHint { hostname: "172.17.0.1", port: 33595 }, DirectHint { hostname: "172.21.0.1", port: 36637 }, DirectHint { hostname: "172.18.0.1", port: 36637 }, DirectHint { hostname: "172.22.0.1", port: 36637 }}, relay: {DirectHint { hostname: "transit.magic-wormhole.io", port: 4001 }} }
[2021-11-21T06:39:45Z DEBUG magic_wormhole::core::rendezvous] Sending Add { phase: 0, body: <2015 bytes> }
[2021-11-21T06:39:45Z DEBUG magic_wormhole::core::rendezvous] Received Ack
[2021-11-21T06:39:45Z DEBUG magic_wormhole::transfer] Sending file offer
[2021-11-21T06:39:45Z DEBUG magic_wormhole::core::rendezvous] Sending Add { phase: 1, body: <101 bytes> }
[2021-11-21T06:39:45Z DEBUG magic_wormhole::core::rendezvous] Received EncryptedMessage { side: TheirSide(79db9246c0), phase: 0, body: <2015 bytes>
[2021-11-21T06:39:45Z DEBUG magic_wormhole::core::rendezvous] Received Ack
[2021-11-21T06:39:45Z DEBUG magic_wormhole::core::rendezvous] Received EncryptedMessage { side: TheirSide(79db9246c0), phase: 1, body: <101 bytes>
[2021-11-21T06:39:45Z DEBUG magic_wormhole::core::rendezvous] Received EncryptedMessage { side: TheirSide(7a43000d89), phase: 0, body: <129 bytes>
[2021-11-21T06:39:45Z DEBUG magic_wormhole::transfer] received transit message: TransitType { abilities_v1: [DirectTcpV1, RelayV1], hints_v1: [] }
[2021-11-21T06:39:48Z DEBUG magic_wormhole::core::rendezvous] Received EncryptedMessage { side: TheirSide(7a43000d89), phase: 1, body: <85 bytes>
Error: 
   0: Corrupt message received
   1: expected value at line 1 column 27

Location:
   /rustc/09c42c45858d5f3aedfa670698275303a3d19afa/library/core/src/result.rs:1915

  ━━━━━ BACKTRACE ━━━━━
                                ⋮ 2 frames hidden ⋮                               
   3: wormhole::main::main::{{closure}}::h9121550176b57768
      at <unknown source file>:<unknown line>
   4: <core::future::from_generator::GenFuture<T> as core::future::future::Future>::poll::h5f387e8fbe28d045
      at <unknown source file>:<unknown line>
   5: std::thread::local::LocalKey<T>::with::hc15afc704873b524
      at <unknown source file>:<unknown line>
   6: <core::future::from_generator::GenFuture<T> as core::future::future::Future>::poll::h89f3aeb70f9e2bf8
      at <unknown source file>:<unknown line>
   7: async_io::driver::block_on::h7a022a2b2d808d18
      at <unknown source file>:<unknown line>
   8: std::thread::local::LocalKey<T>::with::h6b86ee74d8cf517b
      at <unknown source file>:<unknown line>
   9: std::thread::local::LocalKey<T>::with::hffb8b80ae70ec532
      at <unknown source file>:<unknown line>
  10: async_std::task::builder::Builder::blocking::h098be1146fe1805f
      at <unknown source file>:<unknown line>
  11: wormhole::main::h1421189923cc326a
      at <unknown source file>:<unknown line>
  12: std::sys_common::backtrace::__rust_begin_short_backtrace::h71285ddb4bbe8d1e
      at <unknown source file>:<unknown line>
  13: std::rt::lang_start::{{closure}}::hebb6c8292cee4dd8
      at <unknown source file>:<unknown line>
  14: core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once::h97e9d5f21cbee92f
      at /rustc/09c42c45858d5f3aedfa670698275303a3d19afa/library/core/src/ops/function.rs:259
  15: std::panicking::try::do_call::hdfecd950eba8f698
      at /rustc/09c42c45858d5f3aedfa670698275303a3d19afa/library/std/src/panicking.rs:403
  16: std::panicking::try::h3c77c8ba3eb0735c
      at /rustc/09c42c45858d5f3aedfa670698275303a3d19afa/library/std/src/panicking.rs:367
  17: std::panic::catch_unwind::h8e0d62076d8d837e
      at /rustc/09c42c45858d5f3aedfa670698275303a3d19afa/library/std/src/panic.rs:129
  18: std::rt::lang_start_internal::{{closure}}::h647045b4c6a22e67
      at /rustc/09c42c45858d5f3aedfa670698275303a3d19afa/library/std/src/rt.rs:45
  19: std::panicking::try::do_call::h905d96e4a757647e
      at /rustc/09c42c45858d5f3aedfa670698275303a3d19afa/library/std/src/panicking.rs:403
  20: std::panicking::try::hc113426beb3c908b
      at /rustc/09c42c45858d5f3aedfa670698275303a3d19afa/library/std/src/panicking.rs:367
  21: std::panic::catch_unwind::h74f684ea7038ea12
      at /rustc/09c42c45858d5f3aedfa670698275303a3d19afa/library/std/src/panic.rs:129
  22: std::rt::lang_start_internal::h5ba185919d396c97
      at /rustc/09c42c45858d5f3aedfa670698275303a3d19afa/library/std/src/rt.rs:45
  23: main<unknown>
      at <unknown source file>:<unknown line>
  24: __libc_start_call_main<unknown>
      at <unknown source file>:<unknown line>
  25: __libc_start_main@@GLIBC_2.34<unknown>
      at <unknown source file>:<unknown line>
  26: _start<unknown>
      at <unknown source file>:<unknown line>

(output from running wormhole --log send <filename> with RUST_BACKTRACE=1)
@piegamesde
Copy link
Member

And of course, my overly verbose logging still doesn't include the relevant information :( I was in the process of improving things on the logging side anyways, so I'll finish them first before I start investigating this issue.

Generally, it looks like the Go side is sending a message that the Rust side is not happy with. Without knowing the specific message that caused the error, either side may be at fault so it was the right thing to post the bug report here. Especially as the Rust code currently may be overly strict in some cases.

@piegamesde
Copy link
Member

I finally came back to this, and to me this is a bug in the Go implementation. The message they send is:

{"answer":{"message_ack":"","file_ack":"ok"}}

This is an enum, and as such the fields message_ack and file_ack are mutually exclusive. I suppose that Go does not distinguish between "empty string" and "no string", where as Rust does. I also assume that this problem will appear on every enum message type (with that encoding), and that it is not specific to this one.

@Alch-Emi
Copy link
Author

Thank you so much for investigating! Should I pass this off to the developers of Wormhole William then?

@piegamesde
Copy link
Member

Yes, please. You can link this issue there for further context.

@psanford psanford mentioned this issue Nov 30, 2021
Closed
@psanford
Copy link

I will update wormhole-william to not send the additional fields in this message.

However, I'm not sure this strict protocol handling in the rust code is ideal. If the rust implementation panics on any unexpected fields in messages that will make it very difficult to add backwards compatible extensions to the protocol in the future. Just something to consider.

I've opened psanford/wormhole-william#59 to track the Go change.

@piegamesde
Copy link
Member

I'm not sure this strict protocol handling in the rust code is ideal. If the rust implementation panics on any unexpected fields in messages that will make it very difficult to add backwards compatible extensions to the protocol in the future.

Yes, you are totally right on that. This is tracked in #27. For future proofing, this means that we shall accept additional fields in structs (automatically done by serde) and unknown enum variants (partially implemented).

This message is different in the fact that it kind of represents an enum with two variants, and I'd say it is fine to consider this as illegal. But how should we deal with messages like: {"answer":{"message_ack": null,"file_ack":"ok"}} (i.e. only one non-null field)? I'd say it is reasonable to accept this as valid (as long as the field of the variant itself may never be null), but I'm not sure if our code currently accepts that.

@Alch-Emi Alch-Emi closed this as completed Dec 7, 2021
@psanford
Copy link

The latest version of Wormhole William on the Google Play store now has this fix.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@psanford @piegamesde @Alch-Emi