Browse Source

Clean shutdown on /quit

tags/v0.5.0-beta.1
Danilo Bargen 1 year ago
parent
commit
35be904c63
5 changed files with 116 additions and 60 deletions
  1. 1
    0
      .gitignore
  2. 1
    3
      Cargo.toml
  3. 2
    12
      README.md
  4. 89
    35
      examples/chat/main.rs
  5. 23
    10
      src/lib.rs

+ 1
- 0
.gitignore View File

@@ -3,6 +3,7 @@
3 3
 **/*.rs.bk
4 4
 Cargo.lock
5 5
 .env
6
+*.log
6 7
 
7 8
 # Certificates
8 9
 *.pem

+ 1
- 3
Cargo.toml View File

@@ -22,11 +22,9 @@ tokio-core = "0.1.9"
22 22
 websocket = "0.20.2"
23 23
 
24 24
 [dev-dependencies]
25
-chrono = "0.4"
26 25
 clap = "2.27"
27 26
 cursive = "0.7"
28
-dotenv = "0.10"
29
-env_logger = "0.5.0-rc.1"
27
+log4rs = "0.8"
30 28
 
31 29
 [features]
32 30
 default = []

+ 2
- 12
README.md View File

@@ -74,22 +74,12 @@ to connect to the initiator with a responder.
74 74
 To see all options, use `cargo run --example chat -- initiator --help` and
75 75
 `cargo run --example chat -- responder --help`.
76 76
 
77
+The chat example will log to a file called `chat.log`.
78
+
77 79
 **Note:** The example chat currently expects a [SaltyRTC
78 80
 Server](https://github.com/saltyrtc/saltyrtc-server-python/) instance to run on
79 81
 `localhost:6699`.
80 82
 
81
-## Logging
82
-
83
-The examples use [`env_logger`](https://doc.rust-lang.org/log/env_logger/index.html).
84
-To see the logs, export an env variable:
85
-
86
-    export RUST_LOG=saltyrtc_client=TRACE
87
-
88
-The examples initialize the [`dotenv`](https://crates.io/crates/dotenv) crate,
89
-so you can also store this setting in an `.env` file:
90
-
91
-    echo "RUST_LOG=saltyrtc_client=DEBUG" >> .env
92
-
93 83
 
94 84
 ## Msgpack Debugging
95 85
 

+ 89
- 35
examples/chat/main.rs View File

@@ -1,24 +1,21 @@
1 1
 //! Connect to a server as initiator and print the connection info.
2 2
 
3
-extern crate chrono;
4 3
 extern crate clap;
5 4
 extern crate cursive;
6 5
 extern crate data_encoding;
7
-extern crate dotenv;
8
-extern crate env_logger;
9 6
 #[macro_use] extern crate failure;
10 7
 extern crate futures;
11 8
 #[macro_use] extern crate log;
12 9
 extern crate native_tls;
13 10
 extern crate saltyrtc_client;
11
+extern crate log4rs;
14 12
 extern crate tokio_core;
15 13
 
16 14
 mod chat_task;
17 15
 
18 16
 use std::cell::RefCell;
19
-use std::env;
20 17
 use std::fs::File;
21
-use std::io::{Read, Write};
18
+use std::io::Read;
22 19
 use std::path::Path;
23 20
 use std::process;
24 21
 use std::rc::Rc;
@@ -26,18 +23,23 @@ use std::sync::mpsc;
26 23
 use std::thread;
27 24
 use std::time::Duration;
28 25
 
29
-use chrono::Local;
30 26
 use clap::{Arg, App, SubCommand};
31 27
 use cursive::{Cursive};
32 28
 use cursive::traits::{Identifiable};
33 29
 use cursive::views::{TextView, EditView, BoxView, LinearLayout};
34 30
 use data_encoding::{HEXLOWER};
35
-use env_logger::{Builder};
36 31
 use futures::{Sink, Stream, future};
37
-use futures::future::{Future};
38
-use futures::sync::mpsc::{channel};
32
+use futures::future::Future;
33
+use futures::sync::mpsc::channel;
34
+use log::LevelFilter;
35
+use log4rs::Handle;
36
+use log4rs::append::console::ConsoleAppender;
37
+use log4rs::append::file::FileAppender;
38
+use log4rs::encode::pattern::PatternEncoder;
39
+use log4rs::config::{Appender, Config, Logger, Root};
40
+use log4rs::filter::threshold::ThresholdFilter;
39 41
 use native_tls::{TlsConnector, Certificate, Protocol};
40
-use saltyrtc_client::{SaltyClientBuilder, Role, WsClient, Task, BoxedFuture};
42
+use saltyrtc_client::{SaltyClientBuilder, Role, WsClient, Task, BoxedFuture, CloseCode};
41 43
 use saltyrtc_client::crypto::{KeyPair, AuthToken, public_key_from_hex_str};
42 44
 use saltyrtc_client::errors::{SaltyError};
43 45
 use tokio_core::reactor::{Core};
@@ -60,19 +62,6 @@ macro_rules! boxed {
60 62
 
61 63
 
62 64
 fn main() {
63
-    dotenv::dotenv().ok();
64
-    Builder::new()
65
-        .format(|buf, record| {
66
-            writeln!(buf, "{} [{:<5}] {} ({}:{})",
67
-                     Local::now().format("%Y-%m-%dT%H:%M:%S%.3f"),
68
-                     record.level(),
69
-                     record.args(),
70
-                     record.file().unwrap_or("?"),
71
-                     record.line().map(|num| num.to_string()).unwrap_or("?".to_string()))
72
-        })
73
-        .parse(&env::var("RUST_LOG").unwrap_or_default())
74
-        .init();
75
-
76 65
     const ARG_PATH: &'static str = "path";
77 66
     const ARG_AUTHTOKEN: &'static str = "authtoken";
78 67
     const ARG_PING_INTERVAL: &'static str = "ping_interval";
@@ -83,7 +72,7 @@ fn main() {
83 72
         .takes_value(true)
84 73
         .value_name("SECONDS")
85 74
         .required(false)
86
-        .default_value("30")
75
+        .default_value("60")
87 76
         .help("The WebSocket ping interval (set to 0 to disable pings)");
88 77
     let app = App::new("SaltyRTC Test Client")
89 78
         .version(VERSION)
@@ -128,6 +117,9 @@ fn main() {
128 117
         },
129 118
     };
130 119
 
120
+    // Set up logging
121
+    setup_logging(role);
122
+
131 123
     // Tokio reactor core
132 124
     let mut core = Core::new().unwrap();
133 125
 
@@ -252,13 +244,13 @@ fn main() {
252 244
     let (cb_sink_tx, cb_sink_rx) = mpsc::sync_channel(1);
253 245
     let (chat_msg_tx, chat_msg_rx) = channel::<String>(TUI_CHANNEL_BUFFER_SIZE);
254 246
     let remote = core.remote();
255
-    thread::spawn(move || {
247
+    let tui_thread = thread::spawn(move || {
256 248
         // Launch TUI
257 249
         let mut tui = Cursive::new();
258 250
         tui.set_fps(10);
259 251
 
260 252
         // Create text view (for displaying messages)
261
-        let text_view = TextView::new("=== Welcome to SaltyChat! ===\nPress Ctrl+C to exit.\nType /help to list available commands.\n\n")
253
+        let text_view = TextView::new("=== Welcome to SaltyChat! ===\nType /quit to exit.\nType /help to list available commands.\n\n")
262 254
             .scrollable(true)
263 255
             .with_id(VIEW_TEXT_ID);
264 256
 
@@ -347,6 +339,9 @@ fn main() {
347 339
                             tui.quit();
348 340
                         })).unwrap();
349 341
 
342
+                        // Disconnect
343
+                        chat_task.close(CloseCode::WsGoingAway);
344
+
350 345
                         boxed!(future::err(Ok(())))
351 346
                     }
352 347
                     "/nick" => {
@@ -378,13 +373,19 @@ fn main() {
378 373
             }
379 374
         })
380 375
         .or_else(|res| match res {
381
-            Ok(_) => future::ok(()),
376
+            Ok(_) => future::ok(debug!("† Send loop future done")),
382 377
             Err(_) => future::err(SaltyError::Crash("Something went wrong when forwarding messages to task".into()))
383 378
         });
384 379
 
385 380
     // Chat message receive loop
386
-    // TODO: Sanitize incoming messages
381
+    //
382
+    // The closure passed to `for_each` must return:
383
+    //
384
+    // * `future::ok(())` to continue listening for incoming messages
385
+    // * `future::err(Ok(()))` to stop the loop without an error
386
+    // * `future::err(Err(_))` to stop the loop with an error
387 387
     let receive_loop = incoming_rx
388
+        .map_err(|_| Err(()))
388 389
         .for_each({
389 390
             |msg: ChatMessage| {
390 391
                 match msg {
@@ -394,26 +395,79 @@ fn main() {
394 395
                             .ok()
395 396
                             .and_then(|p| p.clone())
396 397
                             .unwrap_or("?".to_string());
397
-                        log_line!("{}> {}", pn, text)
398
+                        log_line!("{}> {}", pn, text);
399
+                        future::ok(())
398 400
                     },
399 401
                     ChatMessage::NickChange(new_nick) => {
400
-                        log_line!("*** Partner nick changed to {}", new_nick)
402
+                        log_line!("*** Partner nick changed to {}", new_nick);
403
+                        future::ok(())
401 404
                     },
402 405
                     ChatMessage::Disconnect(reason) => {
403
-                        log_line!("*** Connection closed, reason: {}", reason)
406
+                        log_line!("*** Connection closed, reason: {}", reason);
407
+                        future::err(Ok(()))
404 408
                     }
405
-                };
406
-                future::ok(())
409
+                }
407 410
             }
408 411
         })
409
-        .map_err(|_| SaltyError::Crash("Something went wrong in message receive loop".into()));
412
+        .or_else(|res| match res {
413
+            Ok(_) => future::ok(debug!("† Receive loop future done")),
414
+            Err(_) => future::err(SaltyError::Crash("Something went wrong in message receive loop".into())),
415
+        });
416
+
417
+    // Main future
418
+    let main_loop = task_loop
419
+        .join(
420
+            send_loop
421
+                .select(receive_loop)
422
+                .map_err(|(e, ..)| e)
423
+        );
410 424
 
411 425
     // Run future in reactor
412
-    match core.run(task_loop.join(send_loop).join(receive_loop)) {
426
+    match core.run(main_loop) {
413 427
         Ok(_) => println!("Success."),
414 428
         Err(e) => {
415 429
             println!("{}", e);
416 430
             process::exit(1);
417 431
         },
418 432
     };
433
+
434
+    // Wait for TUI thread to exit
435
+    tui_thread.join().unwrap();
436
+
437
+    info!("Goodbye!");
438
+}
439
+
440
+fn setup_logging(role: Role) -> Handle {
441
+    // Log format
442
+    let format = "{d(%Y-%m-%dT%H:%M:%S%.3f)} [{l:<5}] {m} (({f}:{L})){n}";
443
+
444
+    // Instantiate appenders
445
+    let stdout = ConsoleAppender::builder()
446
+        .encoder(Box::new(PatternEncoder::new(format)))
447
+        .build();
448
+    let file = FileAppender::builder()
449
+        .encoder(Box::new(PatternEncoder::new(format)))
450
+        .build(match role {
451
+            Role::Initiator => "chat.initiator.log",
452
+            Role::Responder => "chat.responder.log",
453
+        })
454
+        .unwrap();
455
+
456
+    // Instantiate filters
457
+    let info_filter = ThresholdFilter::new(LevelFilter::Info);
458
+
459
+    let config = Config::builder()
460
+        // Appenders
461
+        .appender(Appender::builder().filter(Box::new(info_filter)).build("stdout", Box::new(stdout)))
462
+        .appender(Appender::builder().build("file", Box::new(file)))
463
+
464
+        // Loggers
465
+        .logger(Logger::builder().build("saltyrtc_client", LevelFilter::Debug))
466
+        .logger(Logger::builder().build("chat", LevelFilter::Debug))
467
+
468
+        // Root logger
469
+        .build(Root::builder().appender("stdout").appender("file").build(LevelFilter::Info))
470
+        .unwrap();
471
+
472
+    log4rs::init_config(config).unwrap()
419 473
 }

+ 23
- 10
src/lib.rs View File

@@ -379,7 +379,7 @@ pub fn connect(
379 379
 fn decode_ws_message(msg: OwnedMessage) -> SaltyResult<WsMessageDecoded> {
380 380
     let decoded = match msg {
381 381
         OwnedMessage::Binary(bytes) => {
382
-            debug!("Incoming binary message ({} bytes)", bytes.len());
382
+            debug!("--> Incoming binary message ({} bytes)", bytes.len());
383 383
 
384 384
             // Parse into ByteBox
385 385
             let bbox = ByteBox::from_slice(&bytes)
@@ -389,10 +389,11 @@ fn decode_ws_message(msg: OwnedMessage) -> SaltyResult<WsMessageDecoded> {
389 389
             WsMessageDecoded::ByteBox(bbox)
390 390
         },
391 391
         OwnedMessage::Ping(payload) => {
392
-            debug!("Incoming ping message");
392
+            debug!("--> Incoming ping message");
393 393
             WsMessageDecoded::Ping(payload)
394 394
         },
395 395
         OwnedMessage::Close(close_data) => {
396
+            debug!("--> Incoming close message");
396 397
             match close_data {
397 398
                 Some(data) => {
398 399
                     let close_code = CloseCode::from_number(data.status_code);
@@ -568,7 +569,7 @@ pub fn do_handshake(
568 569
 pub fn task_loop(
569 570
     client: WsClient,
570 571
     salty: Rc<RefCell<SaltyClient>>,
571
-) -> Result<(Arc<Mutex<BoxedTask>>, BoxedFuture<(((), ()), ()), SaltyError>), SaltyError> {
572
+) -> Result<(Arc<Mutex<BoxedTask>>, BoxedFuture<(), SaltyError>), SaltyError> {
572 573
     let task_name = salty
573 574
         .deref()
574 575
         .try_borrow()
@@ -704,7 +705,7 @@ pub fn task_loop(
704 705
                         let pong = OwnedMessage::Pong(payload);
705 706
                         let future = raw_outgoing_tx
706 707
                             .send(pong)
707
-                            .map(|_| debug!("Enqueued pong message"))
708
+                            .map(|_| debug!("<-- Enqueuing pong message"))
708 709
                             .map_err(|e| Err(SaltyError::Network(format!("Could not enqueue pong message: {}", e))));
709 710
                         boxed!(future)
710 711
                     },
@@ -729,7 +730,7 @@ pub fn task_loop(
729 730
                         }));
730 731
                         raw_outgoing_tx
731 732
                             .send(close)
732
-                            .map(|_| debug!("Sent close message"))
733
+                            .map(|_| debug!("<-- Enqueuing close message to peer"))
733 734
                             .or_else(|e| {
734 735
                                 warn!("Could not enqueue close message: {}", e);
735 736
                                 future::ok(())
@@ -742,7 +743,7 @@ pub fn task_loop(
742 743
                 })
743 744
         )
744 745
 
745
-        .map(|_| ())
746
+        .map(|_| debug!("† Reader future done"))
746 747
         .map_err(|(e, _next)| e);
747 748
 
748 749
     // Transform future that sends values from the outgoing channel to the raw outgoing channel
@@ -756,7 +757,10 @@ pub fn task_loop(
756 757
                 // TODO: Can we do something about the errors here?
757 758
                 match salty.deref().try_borrow_mut() {
758 759
                     Ok(mut s) => match s.encrypt_task_message(val) {
759
-                        Ok(bytes) => future::ok(OwnedMessage::Binary(bytes)),
760
+                        Ok(bytes) => {
761
+                            debug!("<-- Enqueuing task message to peer");
762
+                            future::ok(OwnedMessage::Binary(bytes))
763
+                        },
760 764
                         Err(_) => future::err(())
761 765
                     },
762 766
                     Err(_) => future::err(()),
@@ -768,7 +772,7 @@ pub fn task_loop(
768 772
         .forward(raw_outgoing_tx.sink_map_err(|_| ()))
769 773
 
770 774
         // Ignore stream/sink
771
-        .map(|(_, _)| ())
775
+        .map(|(_, _)| debug!("† Transformer future done"))
772 776
 
773 777
         // Map error types
774 778
         .map_err(|_| SaltyError::Crash("TODO: read error".into()));
@@ -786,10 +790,19 @@ pub fn task_loop(
786 790
         )
787 791
 
788 792
         // Ignore sink
789
-        .map(|_| ());
793
+        .map(|_| debug!("† Writer future done"));
790 794
 
791 795
     // The task loop is finished when all futures are resolved.
792
-    let task_loop = boxed!(reader.join(transformer).join(writer));
796
+    let task_loop = boxed!(
797
+        future::ok(info!("Starting task loop future"))
798
+        .and_then(|_| future::select_all(vec![
799
+            boxed!(reader),
800
+            boxed!(transformer),
801
+            boxed!(writer),
802
+        ]))
803
+        .and_then(|_| future::ok(info!("† Task loop future done")))
804
+        .map_err(|(e, _, _)| e)
805
+    );
793 806
 
794 807
     // Get reference to task
795 808
     let task = match salty.try_borrow_mut() {

Loading…
Cancel
Save