ablog

不器用で落着きのない技術者のメモ

YCSB から Amazon KeySpaces に接続エラーになるのでトラブルシューティング

cqlsh、Java アプリからは接続して CQL の発行に成功するので、strace を取って比較してみた。

事象

  • YCSB で Amazon KeySpaces にデータをロードしようとすると "NoHostAvailableException: All host(s) tried for query failed" と怒られる。
$ ./bin/ycsb load cassandra-cql -p hosts=cassandra.ap-northeast-1.amazonaws.com -p port=9142 -P ./workloads/workloada -s -threads 2 -p recordcount=100  -p cassandra.writeconsistencylevel=LOCAL_QUORUM -p cassandra.ssl=true -jvm-args="-Djavax.net.ssl.trustStore=/home/ec2-user/.cassandra/cassandra_truststore.jks -Djavax.net.ssl.trustStorePassword=********"
[WARN]  Running against a source checkout. In order to get our runtime dependencies we'll have to invoke Maven. Depending on the state of your system, this may take ~30-45 seconds
[DEBUG]  Running 'mvn -pl site.ycsb:cassandra-binding -am package -DskipTests dependency:build-classpath -DincludeScope=compile -Dmdep.outputFilterFile=true'
/usr/lib/jvm/java-1.8.0-amazon-corretto.x86_64/bin/java -Djavax.net.ssl.trustStore=/home/ec2-user/.cassandra/cassandra_truststore.jks -Djavax.net.ssl.trustStorePassword=******** -cp /home/ec2-user/YCSB/cassandra/conf:/home/ec2-user/YCSB/cassandra/target/cassandra-binding-0.18.0-SNAPSHOT.jar:/home/ec2-user/.m2/repository/org/apache/htrace/htrace-core4/4.1.0-incubating/htrace-core4-4.1.0-incubating.jar:/home/ec2-user/.m2/repository/org/hdrhistogram/HdrHistogram/2.1.4/HdrHistogram-2.1.4.jar:/home/ec2-user/.m2/repository/io/dropwizard/metrics/metrics-core/3.1.2/metrics-core-3.1.2.jar:/home/ec2-user/.m2/repository/com/datastax/cassandra/cassandra-driver-core/3.0.0/cassandra-driver-core-3.0.0.jar:/home/ec2-user/.m2/repository/io/netty/netty-handler/4.0.33.Final/netty-handler-4.0.33.Final.jar:/home/ec2-user/.m2/repository/org/codehaus/jackson/jackson-core-asl/1.9.4/jackson-core-asl-1.9.4.jar:/home/ec2-user/YCSB/core/target/core-0.18.0-SNAPSHOT.jar:/home/ec2-user/.m2/repository/org/slf4j/slf4j-api/1.7.25/slf4j-api-1.7.25.jar:/home/ec2-user/.m2/repository/io/netty/netty-transport/4.0.33.Final/netty-transport-4.0.33.Final.jar:/home/ec2-user/.m2/repository/io/netty/netty-codec/4.0.33.Final/netty-codec-4.0.33.Final.jar:/home/ec2-user/.m2/repository/com/google/guava/guava/16.0.1/guava-16.0.1.jar:/home/ec2-user/.m2/repository/org/codehaus/jackson/jackson-mapper-asl/1.9.4/jackson-mapper-asl-1.9.4.jar:/home/ec2-user/.m2/repository/io/netty/netty-buffer/4.0.33.Final/netty-buffer-4.0.33.Final.jar:/home/ec2-user/.m2/repository/io/netty/netty-common/4.0.33.Final/netty-common-4.0.33.Final.jar site.ycsb.Client -db site.ycsb.db.CassandraCQLClient -p hosts=cassandra.ap-northeast-1.amazonaws.com -p port=9142 -P ./workloads/workloada -s -threads 2 -p recordcount=100 -p cassandra.writeconsistencylevel=LOCAL_QUORUM -p cassandra.ssl=true -load
Command line: -db site.ycsb.db.CassandraCQLClient -p hosts=cassandra.ap-northeast-1.amazonaws.com -p port=9142 -P ./workloads/workloada -s -threads 2 -p recordcount=100 -p cassandra.writeconsistencylevel=LOCAL_QUORUM -p cassandra.ssl=true -load
YCSB Client 0.18.0-SNAPSHOT

Loading workload...
Starting test.
SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
SLF4J: Defaulting to no-operation (NOP) logger implementation
SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
2023-09-19 13:09:47:013 0 sec: 0 operations; est completion in 0 second
2023-09-19 13:09:56:993 10 sec: 0 operations; est completion in 106751991167300 days 15 hours
site.ycsb.DBException: com.datastax.driver.core.exceptions.NoHostAvailableException: All host(s) tried for query failed (tried: cassandra.ap-northeast-1.amazonaws.com/18.177.156.231:9142 (com.datastax.driver.core.exceptions.OperationTimedOutException: [cassandra.ap-northeast-1.amazonaws.com/18.177.156.231] Operation timed out))
	at site.ycsb.db.CassandraCQLClient.init(CassandraCQLClient.java:235)
	at site.ycsb.DBWrapper.init(DBWrapper.java:90)
	at site.ycsb.ClientThread.run(ClientThread.java:91)
	at java.lang.Thread.run(Thread.java:750)
Caused by: com.datastax.driver.core.exceptions.NoHostAvailableException: All host(s) tried for query failed (tried: cassandra.ap-northeast-1.amazonaws.com/18.177.156.231:9142 (com.datastax.driver.core.exceptions.OperationTimedOutException: [cassandra.ap-northeast-1.amazonaws.com/18.177.156.231] Operation timed out))
	at com.datastax.driver.core.ControlConnection.reconnectInternal(ControlConnection.java:231)
	at com.datastax.driver.core.ControlConnection.connect(ControlConnection.java:77)
	at com.datastax.driver.core.Cluster$Manager.init(Cluster.java:1414)
	at com.datastax.driver.core.Cluster.getMetadata(Cluster.java:393)
	at site.ycsb.db.CassandraCQLClient.init(CassandraCQLClient.java:222)
	... 3 more
site.ycsb.DBException: com.datastax.driver.core.exceptions.NoHostAvailableException: All host(s) tried for query failed (tried: cassandra.ap-northeast-1.amazonaws.com/18.177.156.231:9142 (com.datastax.driver.core.exceptions.OperationTimedOutException: [cassandra.ap-northeast-1.amazonaws.com/18.177.156.231] Operation timed out))DBWrapper: report latency for each error is false and specific error codes to track for latency are: []

	at site.ycsb.db.CassandraCQLClient.init(CassandraCQLClient.java:235)
	at site.ycsb.DBWrapper.init(DBWrapper.java:90)
	at site.ycsb.ClientThread.run(ClientThread.java:91)
	at java.lang.Thread.run(Thread.java:750)
Caused by: com.datastax.driver.core.exceptions.NoHostAvailableException: All host(s) tried for query failed (tried: cassandra.ap-northeast-1.amazonaws.com/18.177.156.231:9142 (com.datastax.driver.core.exceptions.OperationTimedOutException: [cassandra.ap-northeast-1.amazonaws.com/18.177.156.231] Operation timed out))
	at com.datastax.driver.core.ControlConnection.reconnectInternal(ControlConnection.java:231)
	at com.datastax.driver.core.ControlConnection.connect(ControlConnection.java:77)
	at com.datastax.driver.core.Cluster$Manager.init(Cluster.java:1414)
	at com.datastax.driver.core.Cluster.getMetadata(Cluster.java:393)
	at site.ycsb.db.CassandraCQLClient.init(CassandraCQLClient.java:222)
	... 3 more
Error inserting, not retrying any more. number of attempts: 1Insertion Retry Limit: 0
2023-09-19 13:09:59:595 12 sec: 0 operations; est completion in 106751991167300 days 15 hours [CLEANUP: Count=1, Max=6, Min=6, Avg=6, 90=6, 99=6, 99.9=6, 99.99=6] [INSERT: Count=0, Max=0, Min=9223372036854775807, Avg=�, 90=0, 99=0, 99.9=0, 99.99=0] [INSERT-FAILED: Count=1, Max=15215, Min=15208, Avg=15212, 90=15215, 99=15215, 99.9=15215, 99.99=15215]
[OVERALL], RunTime(ms), 12602
[OVERALL], Throughput(ops/sec), 0.0
[TOTAL_GCS_PS_Scavenge], Count, 1
[TOTAL_GC_TIME_PS_Scavenge], Time(ms), 10
[TOTAL_GC_TIME_%_PS_Scavenge], Time(%), 0.07935248373274084
[TOTAL_GCS_PS_MarkSweep], Count, 0
[TOTAL_GC_TIME_PS_MarkSweep], Time(ms), 0
[TOTAL_GC_TIME_%_PS_MarkSweep], Time(%), 0.0
[TOTAL_GCs], Count, 1
[TOTAL_GC_TIME], Time(ms), 10
[TOTAL_GC_TIME_%], Time(%), 0.07935248373274084
[CLEANUP], Operations, 1
[CLEANUP], AverageLatency(us), 6.0
[CLEANUP], MinLatency(us), 6
[CLEANUP], MaxLatency(us), 6
[CLEANUP], 95thPercentileLatency(us), 6
[CLEANUP], 99thPercentileLatency(us), 6
[INSERT], Operations, 0
[INSERT], AverageLatency(us), NaN
[INSERT], MinLatency(us), 9223372036854775807
[INSERT], MaxLatency(us), 0
[INSERT], 95thPercentileLatency(us), 0
[INSERT], 99thPercentileLatency(us), 0
[INSERT], Return=ERROR, 1
[INSERT-FAILED], Operations, 1
[INSERT-FAILED], AverageLatency(us), 15212.0
[INSERT-FAILED], MinLatency(us), 15208
[INSERT-FAILED], MaxLatency(us), 15215
[INSERT-FAILED], 95thPercentileLatency(us), 15215
[INSERT-FAILED], 99thPercentileLatency(us), 15215

システムコールトレースの比較

YCSB
[ec2-user@ip-172-31-17-86 YCSB]$ strace -Ttt -ff -yy -s 100 -o log/strace_ycsb_log ./bin/ycsb load cassandra-cql -p hosts=cassandra.ap-northeast-1.amazonaws.com -p port=9142 -P ./workloads/workloada -s -threads 2 -p recordcount=100  -p cassandra.writeconsistencylevel=LOCAL_QUORUM -p cassandra.ssl=true -jvm-args="-Djavax.net.ssl.trustStore=/home/ec2-user/.cassandra/cassandra_truststore.jks -Djavax.net.ssl.trustStorePassword=********"
  • システムコールトレースの確認
    • connect で接続できているが、SIGSEGV が発生している模様。ネットワークではなく、クライアント側のソフトウェア的な問題?
# strace_ycsb_log.236108 より抜粋
13:17:10.246966 connect(35<TCPv6:[1105410]>, {sa_family=AF_INET6, sin6_port=htons(9142), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "::ffff:18.177.156.213", &sin6_addr), sin6_scope_id=0}, 28) = -1 EINPROGRESS (Operation now in progress) <0.000040>

...

13:17:10.249738 epoll_ctl(25<anon_inode:[eventpoll]>, EPOLL_CTL_ADD, 35<TCPv6:[[::ffff:172.31.17.86]:38562->[::ffff:18.177.156.213]:9142]>, {events=EPOLLOUT, data={u32=35, u64=140393890971683}}) = 0 <0.000015>
13:17:10.250076 epoll_ctl(25<anon_inode:[eventpoll]>, EPOLL_CTL_MOD, 35<TCPv6:[[::ffff:172.31.17.86]:38562->[::ffff:18.177.156.213]:9142]>, {events=EPOLLOUT, data={u32=35, u64=140393890971683}}) = 0 <0.000007>
13:17:10.250124 epoll_wait(25<anon_inode:[eventpoll]>, [{events=EPOLLOUT, data={u32=35, u64=140393890971683}}], 8192, 4998) = 1 <0.000007>
13:17:10.250246 getsockopt(35<TCPv6:[[::ffff:172.31.17.86]:38562->[::ffff:18.177.156.213]:9142]>, SOL_SOCKET, SO_ERROR, [0], [4]) = 0 <0.000008>
13:17:10.250296 getsockname(35<TCPv6:[[::ffff:172.31.17.86]:38562->[::ffff:18.177.156.213]:9142]>, {sa_family=AF_INET6, sin6_port=htons(38562), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "::ffff:172.31.17.86", &sin6_addr), sin6_scope_id=0}, [28]) = 0 <0.000007>
13:17:10.250351 getsockname(35<TCPv6:[[::ffff:172.31.17.86]:38562->[::ffff:18.177.156.213]:9142]>, {sa_family=AF_INET6, sin6_port=htons(38562), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "::ffff:172.31.17.86", &sin6_addr), sin6_scope_id=0}, [28]) = 0 <0.000007>

...

13:17:10.332030 writev(35<TCPv6:[[::ffff:172.31.17.86]:38562->[::ffff:18.177.156.213]:9142]>, [{iov_base="\4\0\0\0\1\0\0\0\26", iov_len=9}, {iov_base="\0\1\0\vCQL_VERSION\0\0053.0.0", iov_len=22}], 2) = 31 <0.000038>
13:17:10.332285 lseek(21</home/ec2-user/.m2/repository/io/netty/netty-buffer/4.0.33.Final/netty-buffer-4.0.33.Final.jar>, 45654, SEEK_SET) = 45654 <0.000012>
13:17:10.332352 read(21</home/ec2-user/.m2/repository/io/netty/netty-buffer/4.0.33.Final/netty-buffer-4.0.33.Final.jar>, "PK\3\4\24\0\10\0\10\0)ucG\0\0\0\0\0\0\0\0\0\0\0\0'\0\0\0", 30) = 30 <0.000011>
13:17:10.332401 lseek(21</home/ec2-user/.m2/repository/io/netty/netty-buffer/4.0.33.Final/netty-buffer-4.0.33.Final.jar>, 45723, SEEK_SET) = 45723 <0.000010>
13:17:10.332441 read(21</home/ec2-user/.m2/repository/io/netty/netty-buffer/4.0.33.Final/netty-buffer-4.0.33.Final.jar>, "\215R\335N\23A\24\376\246\335v\333\272H-U\v\376 v\201\26\265kH\214\27\32\243i !\266\205d\33\274\340j\272\35\350\3002c\246[\f>\200\257\342\265\232\30c\f\17\340\3\3708\3063\253\21\343O$\331\363\363\2359\3379;s\316\347\257\37O\0\254\342n\t\227Q+\242\200\331\"ys\26^q"..., 501) = 501 <0.000010>
13:17:10.332726 lseek(21</home/ec2-user/.m2/repository/io/netty/netty-buffer/4.0.33.Final/netty-buffer-4.0.33.Final.jar>, 46240, SEEK_SET) = 46240 <0.000012>
13:17:10.332782 read(21</home/ec2-user/.m2/repository/io/netty/netty-buffer/4.0.33.Final/netty-buffer-4.0.33.Final.jar>, "PK\3\4\24\0\10\0\10\0)ucG\0\0\0\0\0\0\0\0\0\0\0\0=\0\0\0", 30) = 30 <0.000012>
13:17:10.332830 lseek(21</home/ec2-user/.m2/repository/io/netty/netty-buffer/4.0.33.Final/netty-buffer-4.0.33.Final.jar>, 46331, SEEK_SET) = 46331 <0.000010>
13:17:10.332869 read(21</home/ec2-user/.m2/repository/io/netty/netty-buffer/4.0.33.Final/netty-buffer-4.0.33.Final.jar>, "\235TmO\23A\20~\6\332\236=Nh\21\221\27\221\267\252\345P\256 \212\n\351\227F\243\246\276\4\32L\374\266=\226\366\360\2703\327\253I\177\226\211U\343\7?\0305\21\375M\352\354\365\210\201\202D\366\303\356\354\314<\363\314\316\316\356\336\257\217\237\0,\341\266\16\35W\223\277\343\221F\32y5\315\251\311\324q"..., 597) = 597 <0.000010>
13:17:10.333306 epoll_ctl(25<anon_inode:[eventpoll]>, EPOLL_CTL_MOD, 35<TCPv6:[[::ffff:172.31.17.86]:38562->[::ffff:18.177.156.213]:9142]>, {events=EPOLLIN, data={u32=35, u64=140393890971683}}) = 0 <0.000015>
13:17:10.333389 epoll_ctl(25<anon_inode:[eventpoll]>, EPOLL_CTL_MOD, 35<TCPv6:[[::ffff:172.31.17.86]:38562->[::ffff:18.177.156.213]:9142]>, {events=EPOLLIN, data={u32=35, u64=140393890971683}}) = 0 <0.000010>
13:17:10.333437 epoll_wait(25<anon_inode:[eventpoll]>, [], 8192, 0) = 0 <0.000011>
13:17:10.333563 epoll_wait(25<anon_inode:[eventpoll]>, [], 8192, 0) = 0 <0.000010>
13:17:10.333633 epoll_wait(25<anon_inode:[eventpoll]>, [], 8192, 0) = 0 <0.000010>
13:17:10.333698 epoll_wait(25<anon_inode:[eventpoll]>, [], 8192, 0) = 0 <0.000011>
13:17:10.333799 epoll_wait(25<anon_inode:[eventpoll]>, [], 8192, 0) = 0 <0.000010>
13:17:10.333865 epoll_wait(25<anon_inode:[eventpoll]>, [], 8192, 0) = 0 <0.000010>
13:17:10.333935 epoll_wait(25<anon_inode:[eventpoll]>, [{events=EPOLLIN, data={u32=23, u64=140393890971671}}], 8192, 29932) = 1 <12.033226>
13:17:22.367329 read(23<pipe:[1105394]>, "\1", 128) = 1 <0.000023>
13:17:22.367409 write(24<pipe:[1105394]>, "\1", 1) = 1 <0.000025>
13:17:22.367752 getsockopt(35<TCPv6:[[::ffff:172.31.17.86]:38562->[::ffff:18.177.156.213]:9142]>, SOL_SOCKET, SO_LINGER, {l_onoff=0, l_linger=0}, [8]) = 0 <0.000033>
13:17:22.367922 dup2(36<UNIX-STREAM:[1105400->1105401]>, 35<TCPv6:[[::ffff:172.31.17.86]:38562->[::ffff:18.177.156.213]:9142]>) = 35<UNIX-STREAM:[1105400->1105401]> <0.000065>
13:17:22.368039 --- SIGSEGV {si_signo=SIGSEGV, si_code=SEGV_ACCERR, si_addr=0x7fb09abeb980} ---
cqlsh
[ec2-user@ip-172-31-17-86 cqlsh]$ pwd
/home/ec2-user/cqlsh
[ec2-user@ip-172-31-17-86 cqlsh]$ strace -Ttt -ff -yy -s 100 -o log/strace_cqlsh_log cqlsh cassandra.ap-northeast-1.amazonaws.com 9142 --ssl
Connected to Amazon Keyspaces at cassandra.ap-northeast-1.amazonaws.com:9142
[cqlsh 6.1.0 | Cassandra 3.11.2 | CQL spec 3.4.4 | Native protocol v4]
Use HELP for help.
cqlsh> exit
  • システムコールトレースの確認
    • connect で接続してソケットに対して read/write できている。
13:04:35.572485 connect(6<TCP:[1101165]>, {sa_family=AF_INET, sin_port=htons(9142), sin_addr=inet_addr("18.177.156.206")}, 16) = -1 EINPROGRESS (Operation now in progress) <0.000031>
13:04:35.572802 poll([{fd=6<TCP:[172.31.17.86:56216->18.177.156.206:9142]>, events=POLLOUT|POLLERR}], 1, 5000) = 1 ([{fd=6, revents=POLLOUT}]) <0.001987>
13:04:35.575079 getsockopt(6<TCP:[172.31.17.86:56216->18.177.156.206:9142]>, SOL_SOCKET, SO_ERROR, [0], [4]) = 0 <0.000015>

13:04:35.575374 write(6<TCP:[172.31.17.86:56216->18.177.156.206:9142]>, "\26\3\1\2\0\1\0\1\374\3\3\265\224k\331\366[\334\332\2'\376:F\235Uc:\2728\377k\332}\200~\25L\223\17`'\253 \6O0\236\f\236\335\t\207\35L\211\301\345\343\3325A\340R4:,ZL\242\375\32\207\211'\220\0&\23\2\23\3\23\1\23\4\300,\3000\300+\300/\314\251\314\250\300$"..., 517) = 517 <0.000024>
13:04:35.575433 read(6<TCP:[172.31.17.86:56216->18.177.156.206:9142]>, 0x7f22ac013fc3, 5) = -1 EAGAIN (Resource temporarily unavailable) <0.000015>
13:04:35.575483 poll([{fd=6<TCP:[172.31.17.86:56216->18.177.156.206:9142]>, events=POLLIN}], 1, 5000) = 1 ([{fd=6, revents=POLLIN}]) <0.001619>
13:04:35.577140 read(6<TCP:[172.31.17.86:56216->18.177.156.206:9142]>, "\26\3\3\0z", 5) = 5 <0.000016>
Java アプリ
[ec2-user@ip-172-17-3-232 keySpacesTest]$ pwd
/home/ec2-user/keySpacesTest
[ec2-user@ip-172-17-3-232 keySpacesTest]$ strace -Ttt -ff -yy -s 100 -o log/strace_java-app_log java -jar target/keySpacesTest-1.0-SNAPSHOT.jar
  • システムコールトレースの確認
    • connect で接続してソケットに対して read/write できている。
#log/strace_java-app_log.193991 より抜粋
12:51:25.469820 connect(53<TCPv6:[1036610]>, {sa_family=AF_INET6, sin6_port=htons(9142), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "::ffff:18.177.156.253", &sin6_addr), sin6_scope_id=0}, 28) = -1 EINPROGRESS (Operation now in progress) <0.000056>
12:51:25.471685 epoll_ctl(33<anon_inode:[eventpoll]>, EPOLL_CTL_ADD, 53<TCPv6:[[::ffff:172.17.3.232]:37008->[::ffff:18.177.156.253]:9142]>, {events=EPOLLOUT, data={u32=53, u64=139964394242101}}) = 0 <0.000067>
12:51:25.473605 epoll_wait(33<anon_inode:[eventpoll]>, [{events=EPOLLOUT, data={u32=53, u64=139964394242101}}], 1024, 5000) = 1 <0.000062>
12:51:25.473760 poll([{fd=53<TCPv6:[[::ffff:172.17.3.232]:37008->[::ffff:18.177.156.253]:9142]>, events=POLLOUT}], 1, 0) = 1 ([{fd=53, revents=POLLOUT}]) <0.000078>
12:51:25.473931 getsockopt(53<TCPv6:[[::ffff:172.17.3.232]:37008->[::ffff:18.177.156.253]:9142]>, SOL_SOCKET, SO_ERROR, [0], [4]) = 0 <0.000061>
12:51:25.474070 getsockname(53<TCPv6:[[::ffff:172.17.3.232]:37008->[::ffff:18.177.156.253]:9142]>, {sa_family=AF_INET6, sin6_port=htons(37008), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "::ffff:172.17.3.232", &sin6_addr), sin6_scope_id=0}, [28]) = 0 <0.000047>
12:51:25.474192 getsockname(53<TCPv6:[[::ffff:172.17.3.232]:37008->[::ffff:18.177.156.253]:9142]>, {sa_family=AF_INET6, sin6_port=htons(37008), sin6_flowinfo=htonl(0), inet_pton(AF_INET6, "::ffff:172.17.3.232", &sin6_addr), sin6_scope_id=0}, [28]) = 0 <0.000043>
12:51:25.474578 mmap(NULL, 4198400, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f4cc29fb000 <0.000038>

...

12:51:25.493470 write(53<TCPv6:[[::ffff:172.17.3.232]:37008->[::ffff:18.177.156.253]:9142]>, "\26\3\3\1\313\1\0\1\307\3\3\1\352\377\247u\345m\322\23\3522\10\241[\205a\246\371\356\311\321X?2\35\223|~\342\352\320\376 q\203\325\316\335`\365]\177\313\217\25\337\10\316\354\266\207\233\345E\356%L\317\26\237\215\306\245\37\367\0b\23\2\23\1\23\3\300,\300+\314\251\3000\314\250\300/\0\237\314\252"..., 464) = 464 <0.000027>
12:51:25.493647 epoll_ctl(33<anon_inode:[eventpoll]>, EPOLL_CTL_MOD, 53<TCPv6:[[::ffff:172.17.3.232]:37008->[::ffff:18.177.156.253]:9142]>, {events=EPOLLIN, data={u32=53, u64=139964394242101}}) = 0 <0.000013>
12:51:25.493712 epoll_wait(33<anon_inode:[eventpoll]>, [{events=EPOLLIN, data={u32=53, u64=139964394242101}}], 1024, 10000) = 1 <0.000856>
12:51:25.494720 read(53<TCPv6:[[::ffff:172.17.3.232]:37008->[::ffff:18.177.156.253]:9142]>, "\26\3\3\0z\2\0\0v\3\3\271\311}\30~KT\254&\3346Z\337\345\7\304\207\333\227\33\30\245Nk\2537@\254\24aY\3 q\203\325\316\335`\365]\177\313\217\25\337\10\316\354\266\207\233\345E\356%L\317\26\237\215\306\245\37\367\23\1\0\0.\0+\0\2\3\4\0003\0$\0\35\0 \317\2136\342\354"..., 2048) = 2048 <0.000018>
12:51:25.494847 futex(0x7f4da8011138, FUTEX_WAIT_PRIVATE, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable) <0.000021>
12:51:25.494915 futex(0x7f4da8011138, FUTEX_WAKE_PRIVATE, 1) = 0 <0.000015>
12:51:25.496771 read(53<TCPv6:[[::ffff:172.17.3.232]:37008->[::ffff:18.177.156.253]:9142]>, "\234d$\216Yi\37\10Q\300Q\tV\35\245!=\371\372C\311\266\302\277*\212\210\224\301\327,c\313\24\201\2210-O\7g\r\246\210\232\7\341\247\270\344\302J\25\307/\317xz\242A\200\215\17\22/\236fh\32\360m\223$\3\334`\"\224\310L6\321\360\232Y7\32\212\205\313\5\233Oc%\303\223$\257*"..., 32768) = 3527 <0.000027>