Re: explain these replication logs?

2017-12-13 Thread Mohit Jaggi 
If that is the case won't the "learned notice" message be missing in the
first attempt?

On Wed, Dec 13, 2017 at 9:30 AM, Jie Yu <yujie@gmail.com> wrote:

> Nov  8 00:12:37 host2091 aurora-scheduler[80146]: I1108 00:12:37.005336 80278
> replica.cpp:710] Persisted action APPEND at position 67516183
> Nov  8 00:00:32 host1162 aurora-scheduler[14638]: I1108 00:00:32.736395 14772
> coordinator.cpp:348] Coordinator attempting to write APPEND action at
> position 67516183
>
> Looks like this is for the same position. So your disk might be slow (or
> having some issues) during that time?
>
> On Wed, Dec 13, 2017 at 9:27 AM, Mohit Jaggi <mohit.ja...@uber.com> wrote:
>
>> Folks,
>> Can you help please?
>>
>> Mohit.
>> -- Forwarded message --
>> From: Bill Farner <wfar...@apache.org>
>> Date: Wed, Dec 13, 2017 at 9:06 AM
>> Subject: Re: explain these replication logs?
>> To: u...@aurora.apache.org
>>
>>
>> I'm unfamiliar.  The mesos dev list may be able to give more insight.
>> I'd be interested in your findings!
>>
>> On Tue, Dec 12, 2017 at 4:32 PM, Mohit Jaggi <mohit.ja...@uber.com>
>> wrote:
>>
>>> For the same position I see two bursts of writes, one around 00:12:36
>>> and another 12 min earlier. Any idea what this means?
>>>
>>> ~/a/a/aurora-outage ❯❯❯ grep 67516183 cpp-repl-logs
>>> Nov  8 00:12:36 host1161 aurora-scheduler[112446]: I1108 00:12:36.979269
>>> 112579 replica.cpp:390] Replica received explicit promise request from
>>> __req_res__(7)@172.0.6.42.2:8083 for position 67516183 with proposal
>>> 33898
>>> Nov  8 00:12:36 host1161 aurora-scheduler[112446]: I1108 00:12:36.982532
>>> 112579 replica.cpp:710] Persisted action NOP at position 67516183
>>> Nov  8 00:12:36 host1161 aurora-scheduler[112446]: I1108 00:12:36.990187
>>> 112580 replica.cpp:693] Replica received learned notice for position
>>> 67516183 from @0.0.0.0:0
>>> Nov  8 00:12:36 host1161 aurora-scheduler[112446]: I1108 00:12:36.994510
>>> 112580 replica.cpp:710] Persisted action APPEND at position 67516183
>>> Nov  8 00:12:36 host2091 aurora-scheduler[80146]: I1108 00:12:36.978763
>>> 80281 replica.cpp:390] Replica received explicit promise request from
>>> __req_res__(6)@172.0.6.42.2:8083 for position 67516183 with proposal
>>> 33898
>>> Nov  8 00:12:36 host2091 aurora-scheduler[80146]: I1108 00:12:36.989364
>>> 80281 replica.cpp:710] Persisted action NOP at position 67516183
>>> Nov  8 00:12:36 host2091 aurora-scheduler[80146]: I1108 00:12:36.989794
>>> 80278 replica.cpp:693] Replica received learned notice for position
>>> 67516183 from @0.0.0.0:0
>>> Nov  8 00:12:37 host2091 aurora-scheduler[80146]: I1108 00:12:37.005336
>>> 80278 replica.cpp:710] Persisted action APPEND at position 67516183
>>> Nov  8 00:00:32 host1162 aurora-scheduler[14638]: I1108 00:00:32.736395
>>> 14772 coordinator.cpp:348] Coordinator attempting to write APPEND action at
>>> position 67516183
>>> Nov  8 00:00:32 host1162 aurora-scheduler[14638]: I1108 00:00:32.736794
>>> 14756 replica.cpp:539] Replica received write request for position 67516183
>>> from __req_res__(4)@172.0.8.42.11:8083
>>> Nov  8 00:00:32 host1162 aurora-scheduler[14638]: I1108 00:00:32.740519
>>> 14756 replica.cpp:710] Persisted action APPEND at position 67516183
>>> Nov  8 00:00:32 host1162 aurora-scheduler[14638]: I1108 00:00:32.749094
>>> 14764 replica.cpp:693] Replica received learned notice for position
>>> 67516183 from @0.0.0.0:0
>>> Nov  8 00:00:32 host1162 aurora-scheduler[14638]: I1108 00:00:32.749300
>>> 14764 replica.cpp:710] Persisted action APPEND at position 67516183
>>> Nov  8 00:12:36 host1162 aurora-scheduler[46132]: I1108 00:12:36.992617
>>> 46463 replica.cpp:390] Replica received explicit promise request from
>>> __req_res__(8)@172.0.6.42.2:8083 for position 67516183 with proposal
>>> 33898
>>> Nov  8 00:12:36 host1162 aurora-scheduler[46132]: I1108 00:12:36.993018
>>> 46463 replica.cpp:710] Persisted action APPEND at position 67516183
>>> Nov  8 00:12:36 host1162 aurora-scheduler[46132]: I1108 00:12:36.993108
>>> 46463 replica.cpp:693] Replica received learned notice for position
>>> 67516183 from @0.0.0.0:0
>>> Nov  8 00:12:36 host1162 aurora-scheduler[46132]: I1108 00:12:36.993345
>>> 46463 replica.cpp:710] Persisted action APPEND at position 67516183
>>> Nov  8 00:12:37 host1159 aurora-scheduler[37324]: I1108 00:12:36.978830
&g

Re: explain these replication logs?

2017-12-13 Thread Jie Yu 
Nov  8 00:12:37 host2091 aurora-scheduler[80146]: I1108 00:12:37.005336 80278
replica.cpp:710] Persisted action APPEND at position 67516183
Nov  8 00:00:32 host1162 aurora-scheduler[14638]: I1108 00:00:32.736395 14772
coordinator.cpp:348] Coordinator attempting to write APPEND action at
position 67516183

Looks like this is for the same position. So your disk might be slow (or
having some issues) during that time?

On Wed, Dec 13, 2017 at 9:27 AM, Mohit Jaggi <mohit.ja...@uber.com> wrote:

> Folks,
> Can you help please?
>
> Mohit.
> -- Forwarded message --
> From: Bill Farner <wfar...@apache.org>
> Date: Wed, Dec 13, 2017 at 9:06 AM
> Subject: Re: explain these replication logs?
> To: u...@aurora.apache.org
>
>
> I'm unfamiliar.  The mesos dev list may be able to give more insight.  I'd
> be interested in your findings!
>
> On Tue, Dec 12, 2017 at 4:32 PM, Mohit Jaggi <mohit.ja...@uber.com> wrote:
>
>> For the same position I see two bursts of writes, one around 00:12:36 and
>> another 12 min earlier. Any idea what this means?
>>
>> ~/a/a/aurora-outage ❯❯❯ grep 67516183 cpp-repl-logs
>> Nov  8 00:12:36 host1161 aurora-scheduler[112446]: I1108 00:12:36.979269
>> 112579 replica.cpp:390] Replica received explicit promise request from
>> __req_res__(7)@172.0.6.42.2:8083 for position 67516183 with proposal
>> 33898
>> Nov  8 00:12:36 host1161 aurora-scheduler[112446]: I1108 00:12:36.982532
>> 112579 replica.cpp:710] Persisted action NOP at position 67516183
>> Nov  8 00:12:36 host1161 aurora-scheduler[112446]: I1108 00:12:36.990187
>> 112580 replica.cpp:693] Replica received learned notice for position
>> 67516183 from @0.0.0.0:0
>> Nov  8 00:12:36 host1161 aurora-scheduler[112446]: I1108 00:12:36.994510
>> 112580 replica.cpp:710] Persisted action APPEND at position 67516183
>> Nov  8 00:12:36 host2091 aurora-scheduler[80146]: I1108 00:12:36.978763
>> 80281 replica.cpp:390] Replica received explicit promise request from
>> __req_res__(6)@172.0.6.42.2:8083 for position 67516183 with proposal
>> 33898
>> Nov  8 00:12:36 host2091 aurora-scheduler[80146]: I1108 00:12:36.989364
>> 80281 replica.cpp:710] Persisted action NOP at position 67516183
>> Nov  8 00:12:36 host2091 aurora-scheduler[80146]: I1108 00:12:36.989794
>> 80278 replica.cpp:693] Replica received learned notice for position
>> 67516183 from @0.0.0.0:0
>> Nov  8 00:12:37 host2091 aurora-scheduler[80146]: I1108 00:12:37.005336
>> 80278 replica.cpp:710] Persisted action APPEND at position 67516183
>> Nov  8 00:00:32 host1162 aurora-scheduler[14638]: I1108 00:00:32.736395
>> 14772 coordinator.cpp:348] Coordinator attempting to write APPEND action at
>> position 67516183
>> Nov  8 00:00:32 host1162 aurora-scheduler[14638]: I1108 00:00:32.736794
>> 14756 replica.cpp:539] Replica received write request for position 67516183
>> from __req_res__(4)@172.0.8.42.11:8083
>> Nov  8 00:00:32 host1162 aurora-scheduler[14638]: I1108 00:00:32.740519
>> 14756 replica.cpp:710] Persisted action APPEND at position 67516183
>> Nov  8 00:00:32 host1162 aurora-scheduler[14638]: I1108 00:00:32.749094
>> 14764 replica.cpp:693] Replica received learned notice for position
>> 67516183 from @0.0.0.0:0
>> Nov  8 00:00:32 host1162 aurora-scheduler[14638]: I1108 00:00:32.749300
>> 14764 replica.cpp:710] Persisted action APPEND at position 67516183
>> Nov  8 00:12:36 host1162 aurora-scheduler[46132]: I1108 00:12:36.992617
>> 46463 replica.cpp:390] Replica received explicit promise request from
>> __req_res__(8)@172.0.6.42.2:8083 for position 67516183 with proposal
>> 33898
>> Nov  8 00:12:36 host1162 aurora-scheduler[46132]: I1108 00:12:36.993018
>> 46463 replica.cpp:710] Persisted action APPEND at position 67516183
>> Nov  8 00:12:36 host1162 aurora-scheduler[46132]: I1108 00:12:36.993108
>> 46463 replica.cpp:693] Replica received learned notice for position
>> 67516183 from @0.0.0.0:0
>> Nov  8 00:12:36 host1162 aurora-scheduler[46132]: I1108 00:12:36.993345
>> 46463 replica.cpp:710] Persisted action APPEND at position 67516183
>> Nov  8 00:12:37 host1159 aurora-scheduler[37324]: I1108 00:12:36.978830
>> 37443 replica.cpp:390] Replica received explicit promise request from
>> __req_res__(10)@172.0.6.42.2:8083 for position 67516183 with proposal
>> 33898
>> Nov  8 00:12:37 host1159 aurora-scheduler[37324]: I1108 00:12:36.988788
>> 37443 replica.cpp:710] Persisted action APPEND at position 67516183
>> Nov  8 00:12:37 host1159 aurora-scheduler[37324]: I1108 00:12:36.989609
>> 37444 replica.cpp:693] Replica received learned notice for position
>> 67516183 fr

Fwd: explain these replication logs?

2017-12-13 Thread Mohit Jaggi 
Folks,
Can you help please?

Mohit.
-- Forwarded message --
From: Bill Farner <wfar...@apache.org>
Date: Wed, Dec 13, 2017 at 9:06 AM
Subject: Re: explain these replication logs?
To: u...@aurora.apache.org


I'm unfamiliar.  The mesos dev list may be able to give more insight.  I'd
be interested in your findings!

On Tue, Dec 12, 2017 at 4:32 PM, Mohit Jaggi <mohit.ja...@uber.com> wrote:

> For the same position I see two bursts of writes, one around 00:12:36 and
> another 12 min earlier. Any idea what this means?
>
> ~/a/a/aurora-outage ❯❯❯ grep 67516183 cpp-repl-logs
> Nov  8 00:12:36 host1161 aurora-scheduler[112446]: I1108 00:12:36.979269
> 112579 replica.cpp:390] Replica received explicit promise request from
> __req_res__(7)@172.0.6.42.2:8083 for position 67516183 with proposal 33898
> Nov  8 00:12:36 host1161 aurora-scheduler[112446]: I1108 00:12:36.982532
> 112579 replica.cpp:710] Persisted action NOP at position 67516183
> Nov  8 00:12:36 host1161 aurora-scheduler[112446]: I1108 00:12:36.990187
> 112580 replica.cpp:693] Replica received learned notice for position
> 67516183 from @0.0.0.0:0
> Nov  8 00:12:36 host1161 aurora-scheduler[112446]: I1108 00:12:36.994510
> 112580 replica.cpp:710] Persisted action APPEND at position 67516183
> Nov  8 00:12:36 host2091 aurora-scheduler[80146]: I1108 00:12:36.978763
> 80281 replica.cpp:390] Replica received explicit promise request from
> __req_res__(6)@172.0.6.42.2:8083 for position 67516183 with proposal 33898
> Nov  8 00:12:36 host2091 aurora-scheduler[80146]: I1108 00:12:36.989364
> 80281 replica.cpp:710] Persisted action NOP at position 67516183
> Nov  8 00:12:36 host2091 aurora-scheduler[80146]: I1108 00:12:36.989794
> 80278 replica.cpp:693] Replica received learned notice for position
> 67516183 from @0.0.0.0:0
> Nov  8 00:12:37 host2091 aurora-scheduler[80146]: I1108 00:12:37.005336
> 80278 replica.cpp:710] Persisted action APPEND at position 67516183
> Nov  8 00:00:32 host1162 aurora-scheduler[14638]: I1108 00:00:32.736395
> 14772 coordinator.cpp:348] Coordinator attempting to write APPEND action at
> position 67516183
> Nov  8 00:00:32 host1162 aurora-scheduler[14638]: I1108 00:00:32.736794
> 14756 replica.cpp:539] Replica received write request for position 67516183
> from __req_res__(4)@172.0.8.42.11:8083
> Nov  8 00:00:32 host1162 aurora-scheduler[14638]: I1108 00:00:32.740519
> 14756 replica.cpp:710] Persisted action APPEND at position 67516183
> Nov  8 00:00:32 host1162 aurora-scheduler[14638]: I1108 00:00:32.749094
> 14764 replica.cpp:693] Replica received learned notice for position
> 67516183 from @0.0.0.0:0
> Nov  8 00:00:32 host1162 aurora-scheduler[14638]: I1108 00:00:32.749300
> 14764 replica.cpp:710] Persisted action APPEND at position 67516183
> Nov  8 00:12:36 host1162 aurora-scheduler[46132]: I1108 00:12:36.992617
> 46463 replica.cpp:390] Replica received explicit promise request from
> __req_res__(8)@172.0.6.42.2:8083 for position 67516183 with proposal 33898
> Nov  8 00:12:36 host1162 aurora-scheduler[46132]: I1108 00:12:36.993018
> 46463 replica.cpp:710] Persisted action APPEND at position 67516183
> Nov  8 00:12:36 host1162 aurora-scheduler[46132]: I1108 00:12:36.993108
> 46463 replica.cpp:693] Replica received learned notice for position
> 67516183 from @0.0.0.0:0
> Nov  8 00:12:36 host1162 aurora-scheduler[46132]: I1108 00:12:36.993345
> 46463 replica.cpp:710] Persisted action APPEND at position 67516183
> Nov  8 00:12:37 host1159 aurora-scheduler[37324]: I1108 00:12:36.978830
> 37443 replica.cpp:390] Replica received explicit promise request from
> __req_res__(10)@172.0.6.42.2:8083 for position 67516183 with proposal
> 33898
> Nov  8 00:12:37 host1159 aurora-scheduler[37324]: I1108 00:12:36.988788
> 37443 replica.cpp:710] Persisted action APPEND at position 67516183
> Nov  8 00:12:37 host1159 aurora-scheduler[37324]: I1108 00:12:36.989609
> 37444 replica.cpp:693] Replica received learned notice for position
> 67516183 from @0.0.0.0:0
> Nov  8 00:12:37 host1159 aurora-scheduler[37324]: I1108 00:12:36.989812
> 37444 replica.cpp:710] Persisted action APPEND at position 67516183
> Nov  8 00:00:32 host1159 aurora-scheduler[37324]: I1108 00:00:32.737551
> 37453 replica.cpp:539] Replica received write request for position 67516183
> from __req_res__(6)@172.0.8.42.11:8083
> Nov  8 00:00:32 host1159 aurora-scheduler[37324]: I1108 00:00:32.748847
> 37453 replica.cpp:710] Persisted action APPEND at position 67516183
> Nov  8 00:00:32 host1159 aurora-scheduler[37324]: I1108 00:00:32.749682
> 37447 replica.cpp:693] Replica received learned notice for position
> 67516183 from @0.0.0.0:0
> Nov  8 00:00:32 host1159 aurora-scheduler[37324]: I1108 00:00:32.764811
> 37447 replica.cpp:710] Persisted action APPEN