Preparing statements without socket connection is very slow

[jonhoo]

Consider the following program which just prepares a lot of queries in a loop (the statement cache is turned off to force the prepare so we can benchmark it):

extern crate mysql;
fn main() {
    let mut opts = mysql::OptsBuilder::from_opts("mysql://localhost");
    opts.stmt_cache_size(0);
    opts.prefer_socket(false);
    let mut conn = mysql::Conn::new(opts).unwrap();

    loop {
        let start = ::std::time::Instant::now();
        conn.prepare("SELECT 1").unwrap();
        println!("{:?}", start.elapsed());
    }
}

The prepare seems to always take about 40ms, while the CPU of both the server and the client sits idle. The client is usually waiting in:

(gdb) bt
#0  0x00007f87a6372dbd in recv () from /usr/lib/libpthread.so.0
#1  0x000056109e547821 in std::sys::imp::net::Socket::recv_with_flags () at /checkout/src/libstd/sys/unix/net.rs:231
#2  std::sys::imp::net::Socket::read () at /checkout/src/libstd/sys/unix/net.rs:240
#3  std::sys_common::net::TcpStream::read () at /checkout/src/libstd/sys_common/net.rs:248
#4  std::net::tcp::{{impl}}::read () at /checkout/src/libstd/net/tcp.rs:549
#5  0x000056109e4ca27a in <bufstream::BufStream<S> as std::io::Read>::read ()
#6  0x000056109e4c6175 in std::io::Read::read_exact ()
#7  0x000056109e4d21c0 in mysql::conn::Conn::read_packet ()
#8  0x000056109e4d4aed in mysql::conn::Conn::_prepare ()
#9  0x000056109e4c46d9 in mysql_rs_issue::main ()

In contrast, using query (instead of prepare) takes ~30µs. That's a three orders of magnitude difference. Surely that isn't expected behavior?

This issue mirrors that exhibited in amphp/mysql#55, so this may be a MySQL/MariaDB server issue, not a client issue, but it is not yet clear. It could also be some kind of subtle protocol mismatch that causes the server to wait for more bytes from the client?

[blackbeam]

Hi!
That's quite interesting.

I'm on mysql Ver 14.14 Distrib 5.7.17, for macos10.12 (x86_64) and can't reproduce this issue using your code. query is strictly under 1ms for me and prepare some times takes over 1ms but no more than 2ms.

However it is reproducable on my linux box with mysql Ver 15.1 Distrib 10.1.30-MariaDB, for Linux (x86_64). First prepare takes ~300µs and all subsequent is near 40ms.

I'll investigate further.

[jonhoo]

Oh, that's interesting! Can you reproduce with MySQL (i.e., not MariaDB) on Linux, if you have access to that? What about MariaDB on macOS?

[iamacarpet]

I can reproduce with Cloud SQL on GCP, running fairly stock MySQL 5.7

[jonhoo]

I've done some more digging on this in a slightly different context, and found that this kind of 40ms delay can generally be directly attributed to Nagle's algorithm (the TCP_NODELAY option), and particularly comes to bite you when requests or responses are small. There's a more elaborate explanation of exactly why this happens in mit-pdos/noria@be9d5ab, but suffice to say that Nagle's algorithm on Linux will generally add exactly 40ms of delay. So it seems like this might be the culprit.

The way to fix this would likely be to always set TCP_NODELAY in the library, which should work well if you are using a BufWriter or generally avoid doing many small writes to the socket. If you don't, then you could make it optional by adding is an an option to Opts.

I haven't yet had a chance to test out whether this fixes the issue outlined above, but will give it a shot once I have the time.

[jonhoo]

I can confirm that the following diff reduces the latency of the original code from 40ms per prepare to 20µs per prepare:

diff --git a/src/io/tcp.rs b/src/io/tcp.rs
index a33ceef..19f264b 100644
--- a/src/io/tcp.rs
+++ b/src/io/tcp.rs
@@ -115,6 +115,7 @@ impl<T: ToSocketAddrs> MyTcpBuilder<T> {
                 stream.set_read_timeout(read_timeout)?;
                 stream.set_write_timeout(write_timeout)?;
                 stream.set_keepalive_ms(keepalive_time_ms)?;
+                stream.set_nodelay(true)?;
                 Ok(stream)
             })
     }

[jonhoo]

See #134 for a proposed fix.