logstash-plugins / logstash-input-s3

Apache License 2.0
57 stars 150 forks source link

Slow process Cloudtrail log from S3 #75

Closed thinhluu closed 2 years ago

thinhluu commented 8 years ago

input { s3 { bucket => "BUCKETNAME" delete => true interval => 60 prefix => "AWSLogs/" region => "us-west-2" codec => "cloudtrail" type => "cloudtrail" } }

output { stdout { codec => rubydebug } }

{:timestamp=>"2016-02-26T19:26:17.580000+0000", :message=>"S3 input: Download remote file", :remote_key=>"AWSLogs/AWSAccountID/CloudTrail/us-west-2/2016/02/26/AWSAccountID_CloudTrail_us-west-2_20160226T0800Z_g8AAxJTg73yheICE.json.gz", :local_filename=>"/tmp/logstash/AWSAccountID_CloudTrail_us-west-2_20160226T0800Z_g8AAxJTg73yheICE.json.gz", :level=>:debug, :file=>"logstash/inputs/s3.rb", :line=>"344", :method=>"download_remote_file"} {:timestamp=>"2016-02-26T19:26:19.262000+0000", :message=>"Pushing flush onto pipeline", :level=>:debug, :file=>"logstash/pipeline.rb", :line=>"450", :method=>"flush"} {:timestamp=>"2016-02-26T19:26:24.266000+0000", :message=>"Pushing flush onto pipeline", :level=>:debug, :file=>"logstash/pipeline.rb", :line=>"450", :method=>"flush"} {:timestamp=>"2016-02-26T19:26:29.267000+0000", :message=>"Pushing flush onto pipeline", :level=>:debug, :file=>"logstash/pipeline.rb", :line=>"450", :method=>"flush"} {:timestamp=>"2016-02-26T19:26:34.270000+0000", :message=>"Pushing flush onto pipeline", :level=>:debug, :file=>"logstash/pipeline.rb", :line=>"450", :method=>"flush"} {:timestamp=>"2016-02-26T19:26:39.271000+0000", :message=>"Pushing flush onto pipeline", :level=>:debug, :file=>"logstash/pipeline.rb", :line=>"450", :method=>"flush"} {:timestamp=>"2016-02-26T19:26:44.271000+0000", :message=>"Pushing flush onto pipeline", :level=>:debug, :file=>"logstash/pipeline.rb", :line=>"450", :method=>"flush"} {:timestamp=>"2016-02-26T19:26:49.272000+0000", :message=>"Pushing flush onto pipeline", :level=>:debug, :file=>"logstash/pipeline.rb", :line=>"450", :method=>"flush"} {:timestamp=>"2016-02-26T19:26:54.272000+0000", :message=>"Pushing flush onto pipeline", :level=>:debug, :file=>"logstash/pipeline.rb", :line=>"450", :method=>"flush"} {:timestamp=>"2016-02-26T19:26:59.272000+0000", :message=>"Pushing flush onto pipeline", :level=>:debug, :file=>"logstash/pipeline.rb", :line=>"450", :method=>"flush"}

strace -p 3203 Process 3203 attached futex(0x7fc50e1bd9d0, FUTEX_WAIT, 3218, NULL^CProcess 3203 detached <detached ...>

strace -p 3218 futex(0x7fc50800b354, FUTEX_WAIT_BITSET_PRIVATE, 1, {5392, 782048749}, ffffffff) = -1 ETIMEDOUT (Connection timed out) futex(0x7fc50800b328, FUTEX_WAKE_PRIVATE, 1) = 0 gettimeofday({1456515307, 329336}, NULL) = 0 gettimeofday({1456515307, 329479}, NULL) = 0 gettimeofday({1456515307, 329604}, NULL) = 0 clock_gettime(CLOCK_MONOTONIC, {5392, 782924458}) = 0 futex(0x7fc50800b354, FUTEX_WAIT_BITSET_PRIVATE, 1, {5392, 982924458}, ffffffff) = -1 ETIMEDOUT (Connection timed out) futex(0x7fc50800b328, FUTEX_WAKE_PRIVATE, 1) = 0 gettimeofday({1456515307, 530201}, NULL) = 0 gettimeofday({1456515307, 530347}, NULL) = 0 gettimeofday({1456515307, 530478}, NULL) = 0 clock_gettime(CLOCK_MONOTONIC, {5392, 983801768}) = 0 futex(0x7fc50800b354, FUTEX_WAIT_BITSET_PRIVATE, 1, {5393, 183801768}, ffffffff) = -1 ETIMEDOUT (Connection timed out) futex(0x7fc50800b328, FUTEX_WAKE_PRIVATE, 1) = 0 gettimeofday({1456515307, 731088}, NULL) = 0 gettimeofday({1456515307, 731234}, NULL) = 0 gettimeofday({1456515307, 731363}, NULL) = 0 clock_gettime(CLOCK_MONOTONIC, {5393, 184683466}) = 0

ph commented 8 years ago

@thinhluu can we get a bit of details about the environment?

Logstash version? S3 input version (You can get that by running this command bin/plugin --verbose input-s3) The size of the AWSLogs/AWSAccountID/CloudTrail/us-west-2/2016/02/26/AWSAccountID_CloudTrail_us-west-2_20160226T0800Z_g8AAxJTg73yheICE.json.gz Number of files in the bucket?

ph commented 8 years ago

Not sure if the download timeout and the exception is not correctly raised?

Is the machine processing the logs is also on AWS?

thinhluu commented 8 years ago

/opt/logstash/bin/logstash --version logstash 2.2.2

/opt/logstash/bin/plugin list --verbose | grep s3 logstash-input-s3 (2.0.4)

There are about 10 files, around 200 KB each.

Standard Ubuntu Server 14.04 LTS (HVM), running in AWS, same region. File was downloaded quickly but keeps looping for a long time.

{:timestamp=>"2016-02-26T20:19:53.383000+0000", :message=>"S3 input: Download remote file"... {:timestamp=>"2016-02-26T20:19:58.316000+0000", :message=>"Pushing flush onto pipeline", :level=>:debug, :file=>"logstash/pipeline.rb", :line=>"450", :method=>"flush"}

...

{:timestamp=>"2016-02-26T20:42:13.662000+0000", :message=>"Pushing flush onto pipeline", :level=>:debug, :file=>"logstash/pipeline.rb", :line=>"450", :method=>"flush" {:timestamp=>"2016-02-26T20:42:22.807000+0000", --- start processing the file

strace -fp 4162 Process 4162 attached with 23 threads [pid 4196] futex(0x7f0a04003bf4, FUTEX_WAIT_PRIVATE, 1, NULL <unfinished ...> [pid 4211] restart_syscall(<... resuming interrupted call ...> <unfinished ...> [pid 4197] futex(0x7f0a0401c1c4, FUTEX_WAIT_PRIVATE, 1, NULL <unfinished ...> [pid 4195] restart_syscall(<... resuming interrupted call ...> <unfinished ...> [pid 4194] futex(0x19207a4, FUTEX_WAIT_PRIVATE, 107, NULL <unfinished ...> [pid 4193] futex(0x19d61a4, FUTEX_WAIT_PRIVATE, 101, NULL <unfinished ...> [pid 4191] restart_syscall(<... resuming interrupted call ...> <unfinished ...> [pid 4190] futex(0x7f0a544e0154, FUTEX_WAIT_PRIVATE, 7, NULL <unfinished ...> [pid 4188] restart_syscall(<... resuming interrupted call ...> <unfinished ...> [pid 4187] futex(0x7f0a54119e54, FUTEX_WAIT_PRIVATE, 1, NULL <unfinished ...> [pid 4186] restart_syscall(<... resuming interrupted call ...> <unfinished ...> [pid 4185] restart_syscall(<... resuming interrupted call ...> <unfinished ...> [pid 4184] futex(0x7f0a5cead8a0, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...> [pid 4183] futex(0x7f0a54110c54, FUTEX_WAIT_PRIVATE, 9, NULL <unfinished ...> [pid 4182] futex(0x7f0a540de554, FUTEX_WAIT_PRIVATE, 39, NULL <unfinished ...> [pid 4181] futex(0x7f0a540d9c54, FUTEX_WAIT_PRIVATE, 139, NULL <unfinished ...> [pid 4180] restart_syscall(<... resuming interrupted call ...> <unfinished ...> [pid 4179] restart_syscall(<... resuming interrupted call ...> <unfinished ...> [pid 4178] futex(0x7f0a5401e754, FUTEX_WAIT_PRIVATE, 42641, NULL <unfinished ...> [pid 4177] futex(0x7f0a5401cb54, FUTEX_WAIT_PRIVATE, 42563, NULL <unfinished ...> [pid 4176] restart_syscall(<... resuming interrupted call ...> <unfinished ...> [pid 4162] futex(0x7f0a5bbf49d0, FUTEX_WAIT, 4176, NULL <unfinished ...> [pid 4192] gettimeofday({1456522162, 892113}, NULL) = 0 [pid 4192] futex(0x7f0a540d2054, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a540d2050, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...> [pid 4180] <... restart_syscall resumed> ) = 0 [pid 4180] futex(0x7f0a540d2028, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...> [pid 4192] <... futex resumed> ) = 1 [pid 4192] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4180] <... futex resumed> ) = 0 [pid 4180] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 345646215}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 345712077}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 345763019}) = 0 [pid 4180] mprotect(0x7f0a5daf6000, 4096, PROT_READ) = 0 [pid 4180] mprotect(0x7f0a5daf6000, 4096, PROT_READ|PROT_WRITE) = 0 [pid 4180] mprotect(0x7f0a5daf7000, 4096, PROT_NONE) = 0 [pid 4180] futex(0x7f0a540d2054, FUTEX_WAIT_PRIVATE, 148483, NULL <unfinished ...> [pid 4192] <... futex resumed> ) = 1 [pid 4192] futex(0x7f0a540d2054, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a540d2050, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...> [pid 4180] <... futex resumed> ) = 0 [pid 4180] futex(0x7f0a540d2028, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...> [pid 4192] <... futex resumed> ) = 1 [pid 4192] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4180] <... futex resumed> ) = 0 [pid 4180] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 346193206}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 346400406}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 346474056}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 346578836}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 346655383}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 346736128}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 346800725}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 346863673}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 346929863}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 346999858}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 347067358}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 347133162}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 347180892}) = 0 [pid 4180] futex(0x7f0a5401cb54, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a5401cb50, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 [pid 4177] <... futex resumed> ) = 0 [pid 4177] futex(0x7f0a5401cb28, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...> [pid 4180] futex(0x7f0a5401cb28, FUTEX_WAKE_PRIVATE, 1) = 1 [pid 4177] <... futex resumed> ) = 0 [pid 4177] futex(0x7f0a5401cb28, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4177] futex(0x7f0a5401e754, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a5401e750, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 [pid 4178] <... futex resumed> ) = 0 [pid 4178] futex(0x7f0a5401e728, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...> [pid 4177] futex(0x7f0a5401e728, FUTEX_WAKE_PRIVATE, 1) = 1 [pid 4178] <... futex resumed> ) = 0 [pid 4178] futex(0x7f0a5401e728, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4178] clock_gettime(CLOCK_MONOTONIC, {12248, 347763774}) = 0 [pid 4177] clock_gettime(CLOCK_MONOTONIC, {12248, 348107281}) = 0 [pid 4177] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4178] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4180] futex(0x7f0a540d2054, FUTEX_WAIT_PRIVATE, 148485, NULL <unfinished ...> [pid 4178] <... clock_gettime resumed> {12248, 351697708}) = 0 [pid 4178] clock_gettime(CLOCK_MONOTONIC, {12248, 351811190}) = 0 [pid 4178] sched_yield( <unfinished ...> [pid 4177] <... clock_gettime resumed> {12248, 352020290}) = 0 [pid 4177] clock_gettime(CLOCK_MONOTONIC, {12248, 352130318}) = 0 [pid 4177] clock_gettime(CLOCK_MONOTONIC, {12248, 352225870}) = 0 [pid 4177] futex(0x7f0a540d2054, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a540d2050, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...> [pid 4180] <... futex resumed> ) = 0 [pid 4180] futex(0x7f0a540d2028, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...> [pid 4177] <... futex resumed> ) = 1 [pid 4177] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4180] <... futex resumed> ) = 0 [pid 4180] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4180] futex(0x7f0a540d2054, FUTEX_WAIT_PRIVATE, 148487, NULL <unfinished ...> [pid 4177] <... futex resumed> ) = 1 [pid 4177] futex(0x7f0a5401cb54, FUTEX_WAIT_PRIVATE, 42565, NULL <unfinished ...> [pid 4178] <... sched_yield resumed> ) = 0 [pid 4178] clock_gettime(CLOCK_MONOTONIC, {12248, 352920580}) = 0 [pid 4178] futex(0x7f0a540d2054, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a540d2050, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 [pid 4180] <... futex resumed> ) = 0 [pid 4180] futex(0x7f0a540d2028, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...> [pid 4178] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1) = 1 [pid 4180] <... futex resumed> ) = 0 [pid 4180] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4180] futex(0x7f0a5401cb54, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a5401cb50, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 353620394}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 353719128}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 353806995}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 353899522}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 353997768}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 354091782}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 354187737}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 354277619}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 354364913}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 354458426}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 354573347}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 354667394}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 354760249}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 354847678}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 354942662}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 355037045}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 355136390}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 355230280}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 355320158}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 355435882}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 355558431}) = 0 [pid 4180] mprotect(0x7f0a5daf7000, 4096, PROT_READ) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 355759528}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 355843892}) = 0 [pid 4180] futex(0x7f0a5404bf54, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a5404bf50, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 [pid 4179] <... restart_syscall resumed> ) = 0 [pid 4179] futex(0x7f0a5404bf28, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...> [pid 4180] futex(0x7f0a5404bf28, FUTEX_WAKE_PRIVATE, 1) = 1 [pid 4179] <... futex resumed> ) = 0 [pid 4179] futex(0x7f0a5404bf28, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4179] clock_gettime(CLOCK_MONOTONIC, {12248, 356362623}) = 0 [pid 4179] futex(0x7f0a5404bf54, FUTEX_WAIT_PRIVATE, 57961, NULL <unfinished ...> [pid 4180] gettimeofday({1456522162, 903313}, NULL) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 356610923}) = 0 [pid 4180] futex(0x7f0a540d2054, FUTEX_WAIT_PRIVATE, 148489, NULL <unfinished ...> [pid 4178] futex(0x7f0a5401e754, FUTEX_WAIT_PRIVATE, 42643, NULL <unfinished ...> [pid 4177] <... futex resumed> ) = 0 [pid 4177] futex(0x7f0a5401cb28, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4177] futex(0x7f0a5401cb54, FUTEX_WAIT_PRIVATE, 42567, NULL <unfinished ...> [pid 4192] <... futex resumed> ) = 1 [pid 4192] futex(0x7f0a540d2054, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a540d2050, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...> [pid 4180] <... futex resumed> ) = 0 [pid 4180] futex(0x7f0a540d2028, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...> [pid 4192] <... futex resumed> ) = 1 [pid 4192] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4180] <... futex resumed> ) = 0 [pid 4180] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 357418701}) = 0 [pid 4180] futex(0x7f0a540d2054, FUTEX_WAIT_BITSET_PRIVATE, 148491, {12249, 357418701}, ffffffff <unfinished ...> [pid 4192] <... futex resumed> ) = 1 [pid 4192] futex(0x7f0a5404bf54, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a5404bf50, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...> [pid 4179] <... futex resumed> ) = 0 [pid 4179] futex(0x7f0a5404bf28, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...> [pid 4192] <... futex resumed> ) = 1 [pid 4192] futex(0x7f0a5404bf28, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4179] <... futex resumed> ) = 0 [pid 4179] futex(0x7f0a5404bf28, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4179] clock_gettime(CLOCK_MONOTONIC, {12248, 357998115}) = 0 [pid 4179] clock_gettime(CLOCK_MONOTONIC, {12248, 358090802}) = 0 [pid 4179] clock_gettime(CLOCK_MONOTONIC, {12248, 358183819}) = 0 [pid 4179] futex(0x7f0a5404bf54, FUTEX_WAIT_BITSET_PRIVATE, 57963, {12250, 357183819}, ffffffff <unfinished ...> [pid 4192] <... futex resumed> ) = 1 [pid 4188] <... restart_syscall resumed> ) = -1 ETIMEDOUT (Connection timed out) [pid 4192] gettimeofday( <unfinished ...> [pid 4188] futex(0x7f0a5411d228, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4192] <... gettimeofday resumed> {1456522162, 918970}, NULL) = 0 [pid 4192] futex(0x7f0a540d2054, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a540d2050, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...> [pid 4180] <... futex resumed> ) = 0 [pid 4180] futex(0x7f0a540d2028, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...> [pid 4192] <... futex resumed> ) = 1 [pid 4192] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4180] <... futex resumed> ) = 0 [pid 4180] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 372636213}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 372735607}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 372826864}) = 0 [pid 4180] mprotect(0x7f0a5daf6000, 4096, PROT_READ) = 0 [pid 4180] mprotect(0x7f0a5daf6000, 4096, PROT_READ|PROT_WRITE) = 0 [pid 4180] mprotect(0x7f0a5daf7000, 4096, PROT_NONE) = 0 [pid 4180] futex(0x7f0a540d2054, FUTEX_WAIT_PRIVATE, 148493, NULL <unfinished ...> [pid 4192] <... futex resumed> ) = 1 [pid 4192] futex(0x7f0a540d2054, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a540d2050, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...> [pid 4180] <... futex resumed> ) = 0 [pid 4180] futex(0x7f0a540d2028, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...> [pid 4192] <... futex resumed> ) = 1 [pid 4192] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4180] <... futex resumed> ) = 0 [pid 4180] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 373717373}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 374002225}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 374092427}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 374218514}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 374312174}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 374408207}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 374504789}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 374596103}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 374684812}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 374776741}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 374880273}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 375006323}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 375092368}) = 0 [pid 4180] futex(0x7f0a5401e754, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a5401e750, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 [pid 4178] <... futex resumed> ) = 0 [pid 4178] futex(0x7f0a5401e728, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...> [pid 4180] futex(0x7f0a5401e728, FUTEX_WAKE_PRIVATE, 1) = 1 [pid 4178] <... futex resumed> ) = 0 [pid 4178] futex(0x7f0a5401e728, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4178] futex(0x7f0a5401cb54, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a5401cb50, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 [pid 4177] <... futex resumed> ) = 0 [pid 4177] futex(0x7f0a5401cb28, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...> [pid 4178] futex(0x7f0a5401cb28, FUTEX_WAKE_PRIVATE, 1) = 1 [pid 4177] <... futex resumed> ) = 0 [pid 4177] futex(0x7f0a5401cb28, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4177] clock_gettime(CLOCK_MONOTONIC, {12248, 376019063}) = 0 [pid 4188] <... futex resumed> ) = 0 [pid 4178] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4188] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4178] <... clock_gettime resumed> {12248, 376228336}) = 0 [pid 4188] <... clock_gettime resumed> {12248, 376276555}) = 0 [pid 4188] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4178] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4188] <... clock_gettime resumed> {12248, 379622760}) = 0 [pid 4188] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4180] futex(0x7f0a540d2054, FUTEX_WAIT_PRIVATE, 148495, NULL <unfinished ...> [pid 4188] <... clock_gettime resumed> {12248, 380105251}) = 0 [pid 4192] <... futex resumed> ) = 1 [pid 4188] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4178] <... clock_gettime resumed> {12248, 380955668}) = 0 [pid 4188] <... clock_gettime resumed> {12248, 380994269}) = 0 [pid 4192] futex(0x1901954, FUTEX_WAIT_PRIVATE, 14629, NULL <unfinished ...> [pid 4188] futex(0x7f0a5411d254, FUTEX_WAIT_BITSET_PRIVATE, 1, {12248, 430994269}, ffffffff <unfinished ...> [pid 4178] clock_gettime(CLOCK_MONOTONIC, {12248, 381186358}) = 0 [pid 4177] clock_gettime(CLOCK_MONOTONIC, {12248, 381243016}) = 0 [pid 4177] clock_gettime(CLOCK_MONOTONIC, {12248, 381359004}) = 0 [pid 4177] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4178] clock_gettime(CLOCK_MONOTONIC, {12248, 381478019}) = 0 [pid 4177] <... clock_gettime resumed> {12248, 381468731}) = 0 [pid 4178] futex(0x7f0a5401e754, FUTEX_WAIT_PRIVATE, 42645, NULL <unfinished ...> [pid 4177] futex(0x7f0a540d2054, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a540d2050, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 [pid 4180] <... futex resumed> ) = 0 [pid 4177] futex(0x7f0a5401cb54, FUTEX_WAIT_PRIVATE, 42569, NULL <unfinished ...> [pid 4180] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 385977348}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 386035079}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 386061993}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 386086862}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 386112789}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 386137358}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 386163244}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 386187971}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 386216199}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 386241993}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 388278399}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 388339722}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 388401169}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 388458251}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 388515441}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 388571988}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 388617194}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 388690711}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 388753051}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 388835210}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 392144682}) = 0 [pid 4180] mprotect(0x7f0a5daf7000, 4096, PROT_READ) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 392337854}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 392426023}) = 0 [pid 4180] futex(0x1901954, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x1901950, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...> [pid 4192] <... futex resumed> ) = 0 [pid 4180] <... futex resumed> ) = 1 [pid 4192] futex(0x1901928, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4180] futex(0x7f0a5404bf54, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a5404bf50, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...> [pid 4192] <... futex resumed> ) = 0 [pid 4180] <... futex resumed> ) = 1 [pid 4192] futex(0x1901954, FUTEX_WAIT_PRIVATE, 14631, NULL <unfinished ...> [pid 4180] gettimeofday( <unfinished ...> [pid 4179] <... futex resumed> ) = 0 [pid 4180] <... gettimeofday resumed> {1456522162, 939591}, NULL) = 0 [pid 4179] futex(0x7f0a5404bf28, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4180] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4179] <... futex resumed> ) = 0 [pid 4180] <... clock_gettime resumed> {12248, 392881363}) = 0 [pid 4179] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4180] futex(0x1901954, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x1901950, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...> [pid 4179] <... clock_gettime resumed> {12248, 392924802}) = 0 [pid 4192] <... futex resumed> ) = 0 [pid 4180] <... futex resumed> ) = 1 [pid 4192] futex(0x1901928, FUTEX_WAIT_PRIVATE, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable) [pid 4180] futex(0x1901928, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4192] futex(0x1901928, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4179] futex(0x7f0a5404bf54, FUTEX_WAIT_PRIVATE, 57965, NULL <unfinished ...> [pid 4192] <... futex resumed> ) = 0 [pid 4180] <... futex resumed> ) = 0 [pid 4192] futex(0x7f0a5404bf54, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a5404bf50, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...> [pid 4180] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4192] <... futex resumed> ) = 1 [pid 4180] <... clock_gettime resumed> {12248, 393268398}) = 0 [pid 4179] <... futex resumed> ) = 0 [pid 4180] futex(0x7f0a540d2054, FUTEX_WAIT_BITSET_PRIVATE, 148497, {12249, 393268398}, ffffffff <unfinished ...> [pid 4179] futex(0x7f0a5404bf28, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4179] clock_gettime(CLOCK_MONOTONIC, {12248, 393541286}) = 0 [pid 4179] clock_gettime(CLOCK_MONOTONIC, {12248, 393616997}) = 0 [pid 4179] clock_gettime(CLOCK_MONOTONIC, {12248, 393704946}) = 0 [pid 4179] futex(0x7f0a5404bf54, FUTEX_WAIT_BITSET_PRIVATE, 57967, {12250, 392704946}, ffffffff <unfinished ...> [pid 4176] <... restart_syscall resumed> ) = -1 ETIMEDOUT (Connection timed out) [pid 4176] futex(0x7f0a5400b328, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4176] gettimeofday({1456522162, 950758}, NULL) = 0 [pid 4176] gettimeofday({1456522162, 950922}, NULL) = 0 [pid 4176] gettimeofday({1456522162, 951049}, NULL) = 0 [pid 4176] clock_gettime(CLOCK_MONOTONIC, {12248, 404375722}) = 0 [pid 4176] futex(0x7f0a5400b354, FUTEX_WAIT_BITSET_PRIVATE, 1, {12248, 604375722}, ffffffff <unfinished ...> [pid 4192] gettimeofday({1456522162, 953410}, NULL) = 0 [pid 4192] futex(0x7f0a540d2054, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a540d2050, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 [pid 4180] <... futex resumed> ) = 0 [pid 4192] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4180] futex(0x7f0a540d2028, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...> [pid 4192] <... futex resumed> ) = 0 [pid 4180] <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable) [pid 4192] futex(0x1901954, FUTEX_WAIT_PRIVATE, 14633, NULL <unfinished ...> [pid 4180] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 407163239}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 407304782}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 407445030}) = 0 [pid 4180] mprotect(0x7f0a5daf6000, 4096, PROT_READ) = 0 [pid 4180] mprotect(0x7f0a5daf6000, 4096, PROT_READ|PROT_WRITE) = 0 [pid 4180] mprotect(0x7f0a5daf7000, 4096, PROT_NONE) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 407995113}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 408284357}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 408424291}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 408583887}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 410717823}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 410820182}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 410894683}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 410967941}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 411047030}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 411126662}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 411208728}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 411304451}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 412184790}) = 0 [pid 4180] futex(0x7f0a5401e754, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a5401e750, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 [pid 4178] <... futex resumed> ) = 0 [pid 4180] futex(0x7f0a5401e728, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4178] futex(0x7f0a5401e728, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...> [pid 4180] <... futex resumed> ) = 0 [pid 4180] futex(0x7f0a540d2054, FUTEX_WAIT_PRIVATE, 148499, NULL <unfinished ...> [pid 4178] <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable) [pid 4178] futex(0x7f0a5401e728, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4178] futex(0x7f0a5401cb54, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a5401cb50, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 [pid 4177] <... futex resumed> ) = 0 [pid 4178] futex(0x7f0a5401cb28, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4177] futex(0x7f0a5401cb28, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...> [pid 4178] <... futex resumed> ) = 0 [pid 4177] <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable) [pid 4178] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4177] futex(0x7f0a5401cb28, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4178] <... clock_gettime resumed> {12248, 412852425}) = 0 [pid 4177] <... futex resumed> ) = 0 [pid 4177] futex(0x7f0a540d2054, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a540d2050, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...> [pid 4180] <... futex resumed> ) = 0 [pid 4177] <... futex resumed> ) = 1 [pid 4180] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4177] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4180] <... futex resumed> ) = 0 [pid 4177] <... clock_gettime resumed> {12248, 416344506}) = 0 [pid 4180] futex(0x7f0a540d2054, FUTEX_WAIT_PRIVATE, 148501, NULL <unfinished ...> [pid 4177] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4178] clock_gettime(CLOCK_MONOTONIC, {12248, 417852713}) = 0 [pid 4177] <... clock_gettime resumed> {12248, 417843989}) = 0 [pid 4178] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4177] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4178] <... clock_gettime resumed> {12248, 417990018}) = 0 [pid 4177] <... clock_gettime resumed> {12248, 417982408}) = 0 [pid 4178] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4177] sched_yield( <unfinished ...> [pid 4178] <... clock_gettime resumed> {12248, 418219105}) = 0 [pid 4177] <... sched_yield resumed> ) = 0 [pid 4177] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4178] futex(0x7f0a540d2054, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a540d2050, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...> [pid 4180] <... futex resumed> ) = 0 [pid 4178] <... futex resumed> ) = 1 [pid 4177] <... clock_gettime resumed> {12248, 418360365}) = 0 [pid 4180] futex(0x7f0a540d2028, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...> [pid 4178] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4177] futex(0x7f0a5401cb54, FUTEX_WAIT_PRIVATE, 42571, NULL <unfinished ...> [pid 4180] <... futex resumed> ) = 0 [pid 4178] <... futex resumed> ) = 1 [pid 4180] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4178] futex(0x7f0a5401e754, FUTEX_WAIT_PRIVATE, 42647, NULL <unfinished ...> [pid 4180] <... futex resumed> ) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 418915769}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 419058450}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 419193500}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 419355163}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 419511417}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 419665449}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 419818259}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 419946894}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 420088660}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 420225203}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 420370778}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 420504189}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 420670293}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 420812599}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 420986672}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 421132194}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 421288909}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 421431610}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 421579382}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 421740387}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 421909641}) = 0 [pid 4180] mprotect(0x7f0a5daf7000, 4096, PROT_READ) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 422193705}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 422338534}) = 0 [pid 4180] futex(0x7f0a5404bf54, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a5404bf50, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 [pid 4179] <... futex resumed> ) = 0 [pid 4180] futex(0x7f0a5404bf28, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4179] futex(0x7f0a5404bf28, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...> [pid 4180] <... futex resumed> ) = 0 [pid 4179] <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable) [pid 4180] gettimeofday( <unfinished ...> [pid 4179] futex(0x7f0a5404bf28, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4180] <... gettimeofday resumed> {1456522162, 969610}, NULL) = 0 [pid 4179] <... futex resumed> ) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4179] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4180] <... clock_gettime resumed> {12248, 422962779}) = 0 [pid 4179] <... clock_gettime resumed> {12248, 422955152}) = 0 [pid 4180] futex(0x1901954, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x1901950, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...> [pid 4179] futex(0x7f0a5404bf54, FUTEX_WAIT_PRIVATE, 57969, NULL <unfinished ...> [pid 4192] <... futex resumed> ) = 0 [pid 4180] <... futex resumed> ) = 1 [pid 4192] futex(0x1901928, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4180] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4192] <... futex resumed> ) = 0 [pid 4180] <... clock_gettime resumed> {12248, 423254276}) = 0 [pid 4192] futex(0x7f0a5404bf54, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a5404bf50, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...> [pid 4180] futex(0x7f0a540d2054, FUTEX_WAIT_BITSET_PRIVATE, 148503, {12249, 423254276}, ffffffff <unfinished ...> [pid 4192] <... futex resumed> ) = 1 [pid 4179] <... futex resumed> ) = 0 [pid 4179] futex(0x7f0a5404bf28, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4179] clock_gettime(CLOCK_MONOTONIC, {12248, 423737450}) = 0 [pid 4179] clock_gettime(CLOCK_MONOTONIC, {12248, 423868259}) = 0 [pid 4179] clock_gettime(CLOCK_MONOTONIC, {12248, 424009505}) = 0 [pid 4179] futex(0x7f0a5404bf54, FUTEX_WAIT_BITSET_PRIVATE, 57971, {12250, 423009505}, ffffffff <unfinished ...> [pid 4192] gettimeofday( <unfinished ...> [pid 4188] <... futex resumed> ) = -1 ETIMEDOUT (Connection timed out) [pid 4188] futex(0x7f0a5411d228, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4188] clock_gettime(CLOCK_MONOTONIC, {12248, 435212012}) = 0 [pid 4192] <... gettimeofday resumed> {1456522162, 982046}, NULL) = 0 [pid 4188] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4192] futex(0x7f0a540d2054, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a540d2050, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...> [pid 4188] <... clock_gettime resumed> {12248, 435351287}) = 0 [pid 4192] <... futex resumed> ) = 1 [pid 4188] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4192] futex(0x1901954, FUTEX_WAIT_PRIVATE, 14635, NULL <unfinished ...> [pid 4188] <... clock_gettime resumed> {12248, 435493766}) = 0 [pid 4180] <... futex resumed> ) = 0 [pid 4188] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4180] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4188] <... clock_gettime resumed> {12248, 435657196}) = 0 [pid 4180] <... futex resumed> ) = 0 [pid 4188] futex(0x7f0a5411d254, FUTEX_WAIT_BITSET_PRIVATE, 1, {12248, 485657196}, ffffffff <unfinished ...> [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 435793634}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 435912864}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 436077800}) = 0 [pid 4180] mprotect(0x7f0a5daf6000, 4096, PROT_READ) = 0 [pid 4180] mprotect(0x7f0a5daf6000, 4096, PROT_READ|PROT_WRITE) = 0 [pid 4180] mprotect(0x7f0a5daf7000, 4096, PROT_NONE) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 440661309}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 440920010}) = 0 [pid 4195] <... restart_syscall resumed> ) = -1 ETIMEDOUT (Connection timed out) [pid 4195] futex(0x19dae28, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4180] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4195] <... futex resumed> ) = 0 [pid 4180] <... clock_gettime resumed> {12248, 441088853}) = 0 [pid 4195] futex(0x19db254, FUTEX_WAIT_PRIVATE, 1331, NULL <unfinished ...> [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 441334886}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 441559841}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 441753979}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 441906571}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 442121305}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 442390316}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 442607247}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 442780144}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 442989587}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 443192854}) = 0 [pid 4180] futex(0x7f0a5401cb54, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a5401cb50, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 [pid 4177] <... futex resumed> ) = 0 [pid 4180] futex(0x7f0a5401cb28, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4177] futex(0x7f0a5401cb28, FUTEX_WAIT_PRIVATE, 2, NULL) = -1 EAGAIN (Resource temporarily unavailable) [pid 4180] <... futex resumed> ) = 0 [pid 4177] futex(0x7f0a5401cb28, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4180] futex(0x7f0a540d2054, FUTEX_WAIT_PRIVATE, 148505, NULL <unfinished ...> [pid 4177] <... futex resumed> ) = 0 [pid 4177] futex(0x7f0a5401e754, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a5401e750, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...> [pid 4178] <... futex resumed> ) = 0 [pid 4177] <... futex resumed> ) = 1 [pid 4178] futex(0x7f0a5401e728, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...> [pid 4177] futex(0x7f0a5401e728, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4178] <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable) [pid 4178] futex(0x7f0a5401e728, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4178] futex(0x7f0a540d2054, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a540d2050, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 [pid 4180] <... futex resumed> ) = 0 [pid 4178] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4180] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4178] <... clock_gettime resumed> {12248, 444308407}) = 0 [pid 4180] <... futex resumed> ) = 0 [pid 4177] <... futex resumed> ) = 0 [pid 4177] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4180] futex(0x7f0a540d2054, FUTEX_WAIT_PRIVATE, 148507, NULL <unfinished ...> [pid 4177] <... clock_gettime resumed> {12248, 448208377}) = 0 [pid 4177] clock_gettime(CLOCK_MONOTONIC, {12248, 449539628}) = 0 [pid 4177] clock_gettime(CLOCK_MONOTONIC, {12248, 449573396}) = 0 [pid 4177] sched_yield() = 0 [pid 4177] sched_yield() = 0 [pid 4177] sched_yield() = 0 [pid 4177] sched_yield( <unfinished ...> [pid 4178] clock_gettime(CLOCK_MONOTONIC, {12248, 450182874}) = 0 [pid 4178] clock_gettime(CLOCK_MONOTONIC, {12248, 450235834}) = 0 [pid 4178] clock_gettime(CLOCK_MONOTONIC, {12248, 450289560}) = 0 [pid 4178] futex(0x7f0a540d2054, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a540d2050, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 [pid 4178] futex(0x7f0a5401e754, FUTEX_WAIT_PRIVATE, 42649, NULL <unfinished ...> [pid 4180] <... futex resumed> ) = 0 [pid 4180] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4177] <... sched_yield resumed> ) = 0 [pid 4180] <... futex resumed> ) = 0 [pid 4180] futex(0x7f0a540d2054, FUTEX_WAIT_PRIVATE, 148509, NULL <unfinished ...> [pid 4177] clock_gettime(CLOCK_MONOTONIC, {12248, 450508904}) = 0 [pid 4177] futex(0x7f0a5401e754, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a5401e750, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 [pid 4177] futex(0x7f0a5401cb54, FUTEX_WAIT_PRIVATE, 42573, NULL <unfinished ...> [pid 4178] <... futex resumed> ) = 0 [pid 4178] futex(0x7f0a5401e728, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 4178] futex(0x7f0a540d2054, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a540d2050, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1}) = 1 [pid 4180] <... futex resumed> ) = 0 [pid 4180] futex(0x7f0a540d2028, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...> [pid 4178] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4180] <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable) [pid 4180] futex(0x7f0a540d2028, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4178] <... futex resumed> ) = 0 [pid 4180] <... futex resumed> ) = 0 [pid 4178] futex(0x7f0a5401e754, FUTEX_WAIT_PRIVATE, 42651, NULL <unfinished ...> [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 451008789}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 451076562}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 451121814}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 451218667}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 451304314}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 451400534}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 451484867}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 451569410}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 451675140}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 451767823}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 451860951}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 451917080}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 452016984}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 452129691}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 452175072}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 452253150}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 452322899}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 452411298}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 452489207}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 452574164}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 452663397}) = 0 [pid 4180] mprotect(0x7f0a5daf7000, 4096, PROT_READ) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 452792257}) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, {12248, 452891079}) = 0 [pid 4180] futex(0x19db254, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x19db250, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...> [pid 4195] <... futex resumed> ) = 0 [pid 4180] <... futex resumed> ) = 1 [pid 4195] futex(0x19db228, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...> [pid 4180] futex(0x19db228, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4195] <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable) [pid 4195] futex(0x19db228, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4180] <... futex resumed> ) = 0 [pid 4195] <... futex resumed> ) = 0 [pid 4180] futex(0x7f0a5404bf54, FUTEX_WAKE_OP_PRIVATE, 1, 1, 0x7f0a5404bf50, {FUTEX_OP_SET, 0, FUTEX_OP_CMP_GT, 1} <unfinished ...> [pid 4195] gettimeofday( <unfinished ...> [pid 4180] <... futex resumed> ) = 1 [pid 4179] <... futex resumed> ) = 0 [pid 4195] <... gettimeofday resumed> {1456522162, 999961}, NULL) = 0 [pid 4180] futex(0x7f0a5404bf28, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4195] gettimeofday( <unfinished ...> [pid 4180] <... futex resumed> ) = 0 [pid 4195] <... gettimeofday resumed> {1456522163, 32}, NULL) = 0 [pid 4180] gettimeofday( <unfinished ...> [pid 4179] futex(0x7f0a5404bf28, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...> [pid 4195] gettimeofday( <unfinished ...> [pid 4180] <... gettimeofday resumed> {1456522163, 106}, NULL) = 0 [pid 4179] <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable) [pid 4195] <... gettimeofday resumed> {1456522163, 132}, NULL) = 0 [pid 4180] clock_gettime(CLOCK_MONOTONIC, <unfinished ...> [pid 4179] futex(0x7f0a5404bf28, FUTEX_WAKE_PRIVATE, 1 <unfinished ...> [pid 4195] gettimeofday( <unfinished ...> [pid 4180] <... clock_gettime resumed> {12248, 453408299}) = 0 [pid 4195] <... gettimeofday resumed> {1456522163, 238}, NULL) = 0 ^CProcess 4162 detached Process 4176 detached Process 4177 detached Process 4178 detached Process 4179 detached Process 4180 detached Process 4181 detached Process 4182 detached Process 4183 detached Process 4184 detached Process 4185 detached Process 4186 detached Process 4187 detached Process 4188 detached Process 4190 detached Process 4191 detached Process 4192 detached Process 4193 detached Process 4194 detached Process 4195 detached Process 4196 detached Process 4197 detached Process 4211 detached

Thanks, Thinh