set default request timeout of 60 seconds, configurable

CHANGELOG.md

@@ -2,6 +2,7 @@
 
 ## 0.15.1-dev
  - [#374](https://github.com/tag1consulting/goose/pull/374) renamed `simple-with-session.rs` to `session.rs` and `simple-closure.rs` to `closure.rs` to avoid confusion with the `simple.rs` example as they all do different things
+ - [#382](https://github.com/tag1consulting/goose/pull/382) set client timeout to 60 seconds by default, used for all requests made; introduce `--timeout VALUE` where VALUE is seconds as integer or a float; timeout can be configured programatically using `GooseDefault::Timeout`
 
 ## 0.15.0 November 2, 2021
  - [#372](https://github.com/tag1consulting/goose/pull/372) de-deduplicate documentation, favoring [The Goose Book](https://book.goose.rs)

src/config.rs

@@ -78,6 +78,7 @@ const DEFAULT_PORT: &str = "5115";
 /// --websocket-port PORT      Sets WebSocket Controller TCP port (default: 5117)
 /// --no-autostart             Doesn't automatically start load test
 /// --no-gzip                  Doesn't set the gzip Accept-Encoding header
+/// --timeout VALUE            Sets per-request timeout, in seconds (default: 60)
 /// --co-mitigation STRATEGY   Sets coordinated omission mitigation strategy
 /// --throttle-requests VALUE  Sets maximum requests per second
 /// --sticky-follow            Follows base_url redirect with subsequent requests
@@ -215,6 +216,9 @@ pub struct GooseConfiguration {
     /// Doesn't set the gzip Accept-Encoding header
     #[options(no_short)]
     pub no_gzip: bool,
+    /// Sets per-request timeout, in seconds (default: 60)
+    #[options(no_short, meta = "VALUE")]
+    pub timeout: Option<String>,
     /// Sets coordinated omission mitigation strategy
     #[options(no_short, meta = "STRATEGY")]
     pub co_mitigation: Option<GooseCoordinatedOmissionMitigation>,
@@ -315,6 +319,8 @@ pub(crate) struct GooseDefaults {
     pub no_autostart: Option<bool>,
     /// An optional default for not setting the gzip Accept-Encoding header.
     pub no_gzip: Option<bool>,
+    /// An optional default number of seconds to timeout requests.
+    pub timeout: Option<String>,
     /// An optional default for coordinated omission mitigation.
     pub co_mitigation: Option<GooseCoordinatedOmissionMitigation>,
     /// An optional default to track additional status code metrics.
@@ -411,6 +417,8 @@ pub enum GooseDefault {
     CoordinatedOmissionMitigation,
     /// An optional default for not automatically starting load test.
     NoAutoStart,
+    /// An optional default timeout for all requests, in seconds.
+    Timeout,
     /// An optional default for not setting the gzip Accept-Encoding header.
     NoGzip,
     /// An optional default to track additional status code metrics.
@@ -559,6 +567,7 @@ impl GooseDefaultType<&str> for GooseAttack {
         match key {
             // Set valid defaults.
             GooseDefault::HatchRate => self.defaults.hatch_rate = Some(value.to_string()),
+            GooseDefault::Timeout => self.defaults.timeout = Some(value.to_string()),
             GooseDefault::Host => self.defaults.host = Some(value.to_string()),
             GooseDefault::GooseLog => self.defaults.goose_log = Some(value.to_string()),
             GooseDefault::ReportFile => self.defaults.report_file = Some(value.to_string()),
@@ -664,6 +673,7 @@ impl GooseDefaultType<usize> for GooseAttack {
             // Otherwise display a helpful and explicit error.
             GooseDefault::Host
             | GooseDefault::HatchRate
+            | GooseDefault::Timeout
             | GooseDefault::GooseLog
             | GooseDefault::ReportFile
             | GooseDefault::RequestLog
@@ -777,6 +787,7 @@ impl GooseDefaultType<bool> for GooseAttack {
             }
             GooseDefault::Users
             | GooseDefault::HatchRate
+            | GooseDefault::Timeout
             | GooseDefault::StartupTime
             | GooseDefault::RunTime
             | GooseDefault::LogLevel
@@ -880,6 +891,7 @@ impl GooseDefaultType<GooseCoordinatedOmissionMitigation> for GooseAttack {
             }
             GooseDefault::Users
             | GooseDefault::HatchRate
+            | GooseDefault::Timeout
             | GooseDefault::StartupTime
             | GooseDefault::RunTime
             | GooseDefault::LogLevel
@@ -976,6 +988,7 @@ impl GooseDefaultType<GooseLogFormat> for GooseAttack {
             }
             GooseDefault::Users
             | GooseDefault::HatchRate
+            | GooseDefault::Timeout
             | GooseDefault::StartupTime
             | GooseDefault::RunTime
             | GooseDefault::LogLevel
@@ -1352,6 +1365,24 @@ impl GooseConfiguration {
             ])
             .map(|v| v.to_string());
 
+        // Configure `timeout`.
+        self.timeout = self
+            .get_value(vec![
+                // Use --timeout if set.
+                GooseValue {
+                    value: util::get_float_from_string(self.timeout.clone()),
+                    filter: self.timeout.is_none(),
+                    message: "timeout",
+                },
+                // Otherwise use GooseDefault if set and not on Worker.
+                GooseValue {
+                    value: util::get_float_from_string(defaults.timeout.clone()),
+                    filter: defaults.timeout.is_none() || self.worker,
+                    message: "timeout",
+                },
+            ])
+            .map(|v| v.to_string());
+
         // Configure `running_metrics`.
         self.running_metrics = self.get_value(vec![
             // Use --running-metrics if set.
@@ -1910,6 +1941,13 @@ impl GooseConfiguration {
                     value: self.hatch_rate.as_ref().unwrap().to_string(),
                     detail: "`configuration.hatch_rate` can not be set in Worker mode.".to_string(),
                 });
+            // Can't set `timeout` on Worker.
+            } else if self.timeout.is_some() {
+                return Err(GooseError::InvalidOption {
+                    option: "`configuration.timeout`".to_string(),
+                    value: self.timeout.as_ref().unwrap().to_string(),
+                    detail: "`configuration.timeout` can not be set in Worker mode.".to_string(),
+                });
             // Can't set `running_metrics` on Worker.
             } else if self.running_metrics.is_some() {
                 return Err(GooseError::InvalidOption {
@@ -2046,6 +2084,20 @@ impl GooseConfiguration {
             }
         }
 
+        // If set, timeout must be greater than zero.
+        if let Some(timeout) = self.timeout.as_ref() {
+            if crate::util::get_float_from_string(self.timeout.clone())
+                .expect("failed to re-convert string to float")
+                <= 0.0
+            {
+                return Err(GooseError::InvalidOption {
+                    option: "`configuration.timeout`".to_string(),
+                    value: timeout.to_string(),
+                    detail: "`configuration.timeout` must be greater than 0.".to_string(),
+                });
+            }
+        }
+
         // Validate `users`.
         if let Some(users) = self.users.as_ref() {
             if users == &0 {
@@ -2251,6 +2303,7 @@ mod test {
         let users: usize = 10;
         let run_time: usize = 10;
         let hatch_rate = "2".to_string();
+        let timeout = "45".to_string();
         let log_level: usize = 1;
         let goose_log = "custom-goose.log".to_string();
         let verbose: usize = 0;
@@ -2282,6 +2335,8 @@ mod test {
             .unwrap()
             .set_default(GooseDefault::Verbose, verbose)
             .unwrap()
+            .set_default(GooseDefault::Timeout, timeout.as_str())
+            .unwrap()
             .set_default(GooseDefault::RunningMetrics, 15)
             .unwrap()
             .set_default(GooseDefault::NoResetMetrics, true)
@@ -2367,6 +2422,7 @@ mod test {
         assert!(goose_attack.defaults.no_telnet == Some(true));
         assert!(goose_attack.defaults.no_websocket == Some(true));
         assert!(goose_attack.defaults.no_autostart == Some(true));
+        assert!(goose_attack.defaults.timeout == Some(timeout));
         assert!(goose_attack.defaults.no_gzip == Some(true));
         assert!(goose_attack.defaults.report_file == Some(report_file));
         assert!(goose_attack.defaults.request_log == Some(request_log));

src/docs/goose-book/src/getting-started/runtime-options.md

@@ -49,6 +49,8 @@ Advanced:
   --websocket-host HOST      Sets WebSocket Controller host (default: 0.0.0.0)
   --websocket-port PORT      Sets WebSocket Controller TCP port (default: 5117)
   --no-autostart             Doesn't automatically start load test
+  --no-gzip                  Doesn't set the gzip Accept-Encoding header
+  --timeout VALUE            Sets per-request timeout, in seconds (default: 60)
   --co-mitigation STRATEGY   Sets coordinated omission mitigation strategy
   --throttle-requests VALUE  Sets maximum requests per second
   --sticky-follow            Follows base_url redirect with subsequent requests

src/docs/goose-book/src/getting-started/tips.md

@@ -1,4 +1,30 @@
 # Tips
 
+## Best Practices
+
 * When writing load tests, avoid [`unwrap()`](https://doc.rust-lang.org/std/option/enum.Option.html#method.unwrap) (and variations) in your task functions -- Goose generates a lot of load, and this tends to trigger errors. Embrace Rust's warnings and properly handle all possible errors, this will save you time debugging later.
 * When running your load test, use the cargo `--release` flag to generate optimized code. This can generate considerably more load test traffic. Learn more about this and other optimizations in ["The golden Goose egg, a compile-time adventure"](https://www.tag1consulting.com/blog/golden-goose-egg-compile-time-adventure).
+
+## Errors
+
+### Timeouts
+
+By default, Goose will time out requests that take longer than 60 seconds to return, and display a `WARN` level message saying, "operation timed out". For example:
+
+```
+11:52:17 [WARN] "/node/3672": error sending request for url (http://apache/node/3672): operation timed out
+```
+
+These will also show up in the error summary displayed with the final metrics. For example:
+
+```
+ === ERRORS ===
+ ------------------------------------------------------------------------------
+ Count       | Error
+ ------------------------------------------------------------------------------
+ 51            GET (Auth) comment form: error sending request (Auth) comment form: operation timed out
+```
+
+To change how long before requests time out, use `--timeout VALUE` when starting a load test, for example `--timeout 30` will time out requests that take longer than 30 seconds to return. To configure the timeout programatically, use [`.set_default()`](https://docs.rs/goose/*/goose/config/trait.GooseDefaultType.html#tymethod.set_default) to set [GooseDefault::Timeout](https://docs.rs/goose/*/goose/config/enum.GooseDefault.html#variant.Timeout).
+
+To completely disable timeouts, you must build a custom Reqwest Client with [`GooseUser::set_client_builder`](https://docs.rs/goose/*/goose/goose/struct.GooseUser.html#method.set_client_builder). Alternatively, you can just set a very high timeout, for example `--timeout 86400` will let a request take up to 24 hours.

src/goose.rs

@@ -308,6 +308,9 @@ use crate::{GooseConfiguration, GooseError, WeightedGooseTasks};
 /// By default Goose sets the following User-Agent header when making requests.
 static APP_USER_AGENT: &str = concat!(env!("CARGO_PKG_NAME"), "/", env!("CARGO_PKG_VERSION"));
 
+/// By default Goose times out requests after 60,000 milliseconds.
+static GOOSE_REQUEST_TIMEOUT: u64 = 60_000;
+
 /// `task!(foo)` expands to `GooseTask::new(foo)`, but also does some boxing to work around a limitation in the compiler.
 #[macro_export]
 macro_rules! task {
@@ -879,9 +882,21 @@ impl GooseUser {
         load_test_hash: u64,
     ) -> Result<Self, GooseError> {
         trace!("new GooseUser");
+
+        // Either use manually configured timeout, or default.
+        let timeout = if configuration.timeout.is_some() {
+            match crate::util::get_float_from_string(configuration.timeout.clone()) {
+                Some(f) => f as u64 * 1_000,
+                None => GOOSE_REQUEST_TIMEOUT,
+            }
+        } else {
+            GOOSE_REQUEST_TIMEOUT
+        };
+
         let client = Client::builder()
             .user_agent(APP_USER_AGENT)
             .cookie_store(true)
+            .timeout(Duration::from_millis(timeout))
             // Enable gzip unless `--no-gzip` flag is enabled.
             .gzip(!configuration.no_gzip)
             .build()?;
@@ -2020,26 +2035,31 @@ impl GooseUser {
     /// Manually build a
     /// [`reqwest::Client`](https://docs.rs/reqwest/*/reqwest/struct.Client.html).
     ///
-    /// By default, Goose configures two options when building a
-    /// [`reqwest::Client`](https://docs.rs/reqwest/*/reqwest/struct.Client.html). The first
-    /// configures Goose to report itself as the
-    /// [`user_agent`](https://docs.rs/reqwest/*/reqwest/struct.ClientBuilder.html#method.user_agent)
-    /// requesting web pages (ie `goose/0.11.2`). The second option configures
-    /// [`reqwest`](https://docs.rs/reqwest/) to
-    /// [store cookies](https://docs.rs/reqwest/*/reqwest/struct.ClientBuilder.html#method.cookie_store),
-    /// which is generally necessary if you aim to simulate logged in users.
+    /// By default, Goose configures the following options when building a
+    /// [`reqwest::Client`](https://docs.rs/reqwest/*/reqwest/struct.Client.html):
+    ///  - reports itself as the
+    ///    [`user_agent`](https://docs.rs/reqwest/*/reqwest/struct.ClientBuilder.html#method.user_agent)
+    ///    requesting web pages (ie `goose/0.15.0`);
+    ///  - [stores cookies](https://docs.rs/reqwest/*/reqwest/struct.ClientBuilder.html#method.cookie_store),
+    ///    generally necessary if you aim to simulate logged in users;
+    ///  - enables
+    ///    [`gzip`](https://docs.rs/reqwest/*/reqwest/struct.ClientBuilder.html#method.gzip) compression;
+    ///  - sets a 60 second [`timeout`](https://docs.rs/reqwest/*/reqwest/struct.ClientBuilder.html#method.timeout) all
+    ///    on all requests.
     ///
     /// # Default configuration:
     ///
     /// ```rust
     /// use reqwest::Client;
+    /// use core::time::Duration;
     ///
     /// static APP_USER_AGENT: &str = concat!(env!("CARGO_PKG_NAME"), "/", env!("CARGO_PKG_VERSION"));
     ///
     /// let builder = Client::builder()
     ///   .user_agent(APP_USER_AGENT)
     ///   .cookie_store(true)
-    ///   .gzip(true);
+    ///   .gzip(true)
+    ///   .timeout(Duration::from_secs(60));
     /// ```
     ///
     /// Alternatively, you can use this function to manually build a
@@ -2068,11 +2088,13 @@ impl GooseUser {
     ///    [`.cookie_store(true)`](https://docs.rs/reqwest/*/reqwest/struct.ClientBuilder.html#method.cookie_store).
     ///
     /// In the following example, the Goose client is configured with a different user agent,
-    /// sets a default header on every request, stores cookies, and supports gzip compression.
+    /// sets a default header on every request, stores cookies, supports gzip compression, and
+    /// times out requests after 30 seconds.
     ///
     /// ## Example
     /// ```rust
     /// use goose::prelude::*;
+    /// use core::time::Duration;
     ///
     /// task!(setup_custom_client).set_on_start();
     ///
@@ -2088,7 +2110,8 @@ impl GooseUser {
     ///         .default_headers(headers)
     ///         .user_agent("custom user agent")
     ///         .cookie_store(true)
-    ///         .gzip(true);
+    ///         .gzip(true)
+    ///         .timeout(Duration::from_secs(30));
     ///
     ///     // Assign the custom client to this GooseUser.
     ///     user.set_client_builder(builder).await?;

src/util.rs

@@ -355,18 +355,44 @@ pub fn ms_timer_expired(started: time::Instant, elapsed: usize) -> bool {
 /// assert_eq!(util::get_hatch_rate(None), 1.0);
 /// ```
 pub fn get_hatch_rate(hatch_rate: Option<String>) -> f32 {
-    match hatch_rate {
-        Some(h) => match h.parse::<f32>() {
-            Ok(rate) => rate,
+    if let Some(value) = get_float_from_string(hatch_rate) {
+        value
+    } else {
+        1.0
+    }
+}
+
+/// Convert optional string to f32, otherwise return None.
+///
+/// # Example
+/// ```rust
+/// use goose::util;
+///
+/// // No decimal returns a proper float.
+/// assert_eq!(util::get_float_from_string(Some("1".to_string())), Some(1.0));
+///
+/// // Leading decimal returns a proper float.
+/// assert_eq!(util::get_float_from_string(Some(".1".to_string())), Some(0.1));
+///
+/// // Valid float string returns a proper float.
+/// assert_eq!(util::get_float_from_string(Some("1.1".to_string())), Some(1.1));
+///
+/// // Invalid number with too many decimals returns None.
+/// assert_eq!(util::get_float_from_string(Some("1.1.1".to_string())), None);
+///
+/// // No number returns None.
+/// assert_eq!(util::get_float_from_string(None), None);
+/// ```
+pub fn get_float_from_string(string: Option<String>) -> Option<f32> {
+    match string {
+        Some(s) => match s.parse::<f32>() {
+            Ok(value) => Some(value),
             Err(e) => {
-                warn!(
-                    "failed to convert hatch rate {} to float: {}, defaulting to 1.0",
-                    h, e
-                );
-                1.0
+                warn!("failed to convert {} to float: {}", s, e);
+                None
             }
         },
-        None => 1.0,
+        None => None,
     }
 }