Thanks Shaheed for the update on the failover issue..I will go through the
logs and share the observation further..

Thanks,
Reka

On Tue, Jul 14, 2015 at 2:39 PM, Shaheedur Haque (shahhaqu) <
shahh...@cisco.com> wrote:

>  This thread breaks out the failover issue previously reported in the
> thread below.
>
>
>
> *Scenario*
>
>
>
> 1.      Start 2 orchestration controllers, octl-01 and octl-02. At this
> stage, Stratos comes up on octl-01.
>
> 2.      Shortly later, launch two single VM applications (cisco-sample
> and cartridge-proxy)
>
> 3.      Some time later, launch three more single VM applications
> (di-000-001 to di-000-003)
>
> 4.      Some time later, kill octl-01
>
> 5.      Wait
>
> 6.      About 60 seconds later or so, DNS switched to point Cartridge
> Agents to octl-02 and then Stratos comes up on octl-02.
>
>
>
> *Expected result*
>
>
>
> ·        New Stratos instance picks up the old cartridges and carries on
>
>
>
> *Actual results*
>
>
>
> ·        The new Startos instance seems to think the old cartridges are
> dead or something, and spins up new VMs.
>
> ·        All sorts of exceptions are being thrown.
>
>
>
> *Supporting info*
>
>
>
> Two tarballs attached. The “before”  set was taken before step 4, the
> “after” set was taken after step 6. Each contains tarballs for octl-01 and
> octl-02. Thus, in the first, the wso2logs are at
>
>
>
> ·        tech-support-octl-01.tar, under /var/log/apache-stratos
>
>
>
> and in the second, they are at
>
>
>
> ·        tech-support-octl-02.tar, under /var/log/apache-stratos
>
>
>
>
>
>
>
> *From:* Shaheedur Haque (shahhaqu)
> *Sent:* 07 July 2015 12:10
> *To:* dev@stratos.apache.org
> *Subject:* Problem with Stratos 4.1 autohealing (was RE: Problems with
> Stratos 4.1 failover and autohealing)
>
>
>
> I met with several of the wso2 team, and we agreed the following next
> steps:
>
>
>
> 1.      Treat the “Stratos failover” issue as separate from the
> “duplicate instances” issue, and use a new thread for the former, keeping
> this thread for the latter.
>
> 2.      The lack of synchronisation between the cleanup of the faulty VMs
> and the startup of the replacement VMs was noted.
>
> a.      It was mentioned that the period of overlap should be seconds,
> perhaps upto 60s.
>
> b.      I noted that for many of our scenarios, where the hardware is 1:1
> mapped to VMs (i.e. neither over-subscribed nor under-subscribed), the
> overlap may be a problem. I will consult with others and confirm. Imesh
> ack’d this point.
>
> c.      I will provide the wso2 logs for my test case (summarised below).
>
> d.      I will check with the test team where the problem was originally
> detected if this is a transient  (upto 60s) or long-lived, and gather logs
> as needed.
>
>
>
> *From:* Imesh Gunaratne [mailto:im...@apache.org]
> *Sent:* 06 July 2015 17:11
> *To:* dev
> *Subject:* Re: Problems with Stratos 4.1 failover and autohealing
>
>
>
> On Mon, Jul 6, 2015 at 8:13 PM, Akila Ravihansa Perera <raviha...@wso2.com
> > wrote:
>
>
>
>  If it detects that cartridge agent has not published any health event
> within the given time window (60mins), it will publish the MemberFault
> event.
>
>
>
>  This should be 60 seconds.
>
>
>
> On Mon, Jul 6, 2015 at 8:13 PM, Akila Ravihansa Perera <raviha...@wso2.com>
> wrote:
>
> Hi Shaheed,
>
>
> Regarding Stratos fail-over scenario, by looking at the logs it seems that
> there are multiple member fault cases detected by CEP. This
> FaultHandlingWindowProcessor [1] running inside CEP is implemented to check
> for health stats published by cartridge agents. It does not check whether
> actual VM or processes running inside the VM is active or not. If it
> detects that cartridge agent has not published any health event within the
> given time window (60mins), it will publish the MemberFault event.
>
> Ideally this should not happen regardless of whether the deployment is HA
> or not. Because FaultHandlingWindowProcessor will count the 60mins interval
> from the point Stratos server started. Only reason I could think of which
> may have caused these faulty member logs is Stratos (or external CEP) did
> not receive health stats published by cartridge agents on time.
>
>
>
> Are you running Stratos in single-JVM mode? If so, I'd highly recommend
> that you deploy the CEP profile separately. Please refer to [2] for
> reference deployment architecture of Stratos HA setup.
>
>
>
> Regarding your second concern; Kill multiple Cartridges, I believe your
> concern is that the first message relating to recovery of the CPS came
> 66s after faulty member detection and recovery of other VMs started before
> that. I'd like to summarize few points regarding Stratos recovery process
> which I think will explain that behavior.
>
>
>
>  - Stratos detects faulty members only by checking the health stats
> published by cartridge agent and not by checking the existence of the
> actual VM.
>
>  - Upon detecting such faulty member, CEP will publish a faulty member
> event and after receiving such event AS will move that instance to obsolete
> list. AS will iterate over this obsolete list and try to terminate those
> instances via CC. When the termination is complete, CC will publish member
> terminated event, upon receiving that AS will remove that member from
> obsolete list.
>
>  - If CC fails to terminate the instance, it will keep retrying until a
> obsolete member timeout interval has passed. When the timeout expires, AS
> will forcefully remove that member from obsolete list.
>
>  - Stratos will not try to re-spawn the faulty instance right after
> detecting it. This recovery process is triggered by the Cluster monitor
> object. There is a Drools logic which gets executed periodically (monitor
> interval is configurable, default is 90s) which will execute the min-check
> rule, scale-up rule and scale-down rule and decide whether to spawn new
> instances. So this recovery process could take some time depending on your
> monitor interval.
>
>
>
>
>
> So in retrospect;
>
> - There is no way to control which cluster monitor gets executed first, so
> therefore it is possible that CPS recovery takes place after other VMs.
>
> - The reason for seeing lot of termination logs is because
> Stratos continuously tries to terminate those faulty members until obsolete
> member timeout has expired. This could occur if the actual VM was killed
> manually or by other means.
>
>
>
> However, we need to figure out why you got these faulty member events.
> Could you send us the CEP trace log for further analysis? Also you can
> enable debug logs for FaultHandlingWindowProcessor class to get more
> insights as to what's going on.
>
>
>
> I hope this would explain your concerns. We can have a Hangout session to
> discuss this further.
>
>
>
> [1]
> https://cwiki.apache.org/confluence/display/STRATOS/4.1.0+Configuring+HA+in+Single+JVM+Mode+on+EC2
>
> [2]
> https://github.com/apache/stratos/blob/master/extensions/cep/stratos-cep-extension/src/main/java/org/apache/stratos/cep/extension/FaultHandlingWindowProcessor.java
>
>
>
> Thanks.
>
>
>
> On Mon, Jul 6, 2015 at 5:00 PM, Shaheedur Haque (shahhaqu) <
> shahh...@cisco.com> wrote:
>
> Hi,
>
>
>
> I am seeing some issues around Stratos 4.1 around failover on the one hand
> (i.e. stop one running instance of Startos, start another as a
> replacement), and autohealing (i.e. a Cartridge dies and need to be
> replaced by Stratos) which feel as though they might have a common cause,
> so I am lumping them together for now. I’ll explain the two scenarios as I
> can…and the attach some logs explaining one scenario in detail.
>
>
>
> *Failover of Stratos*
>
>
>
> The situation here is that I have 3 servers, all running MySQL in
> active-active mode, and Stratos running on at most one of them under
> Pacemaker control. The test case is that I kill the server (actually a VM)
> running Stratos, and Pacemaker responds by starting Stratos on one of the
> remaining servers. Around the time of the action, there is no ongoing REST
> activity in terms of defining new Cartridges, or Applications or anything
> like that.
>
>
>
> ·        Expected result: the replacement Stratos instance “acquires” the
> running Cartridges, and the system continues without killing/replacing any
> Cartridges.
>
> ·        Actual result: all Cartridges are kill and restarted.
>
>
>
> *Kill multiple Cartridges*
>
>
>
> I have a test where several Cartridges are killed at the same time as
> follows. We have a Cartridge Proxy Server (CPS) that hosts the (Java)
> Cartridge agent for VMs which cannot run one natively. The CPS therefore
> runs N+1 JCAs, one for itself plus N for the Cartridges it is proxying.
> Killing the CPS therefore causes all N+1 JCAs to disappear, and from a
> Startos point of view, all N+1 VMs need to be restarted.
>
>
>
> ·        Expected result: each Cartridges is replaced by Stratos.
>
> ·        Actual result: looking at the Stratos logs, it seems that there
> is a race between the termination logic which cleans up as old cluster
> members dies against the startup logic which is spinning up replacement VMs
> for the terminated ones.
>
>
>
> Both cases previously seemed to work fine, where we **think** previously
> means versions of Stratos 4.1 dating back ~3 weeks or so. I attach a series
> of log extracts for the second scenario; I suspect this also covers the
> first, even if not, at least we can start here.
>
>
>
> 1.      Original spin up of CPS is at 2015-06-11 19:50:20,585. CPS fault
> seen around 2015-06-12 18:54:51, contemporaneously, all the other faults
> are seen:
>
>
>
> ID: [0] [STRATOS] [2015-06-12 18:54:51,788]  INFO
> {org.apache.stratos.cep.extension.FaultHandlingWindowProcessor} -  Faulty
> member detected [member-id]
> di-000-007.di-000-007.cisco-qvpc-sf-0.domain88ef85b5-5ec6-4d4e-b7b2-1ab9d3f7b160
> with [last time-stamp] 1434135185318 [time-out] 60000 milliseconds
>
> ...
>
> TID: [0] [STRATOS] [2015-06-12 18:54:51,803]  INFO
> {org.apache.stratos.cep.extension.FaultHandlingWindowProcessor} -  Faulty
> member detected [member-id]
> di-000-005.di-000-005.cisco-qvpc-sf-0.domain4bcdd49a-985f-4247-a70b-31c8d65153d8
> with [last time-stamp] 1434135192556 [time-out] 60000 milliseconds
>
> ...
>
> TID: [0] [STRATOS] [2015-06-12 18:54:51,837]  INFO
> {org.apache.stratos.cep.extension.FaultHandlingWindowProcessor} -  Faulty
> member detected [member-id]
> cartridge-proxy.cartridge-proxy.cartridge-proxy.domain95a58a3e-e7a9-4071-b42b-3551bad25e6a
> with [last time-stamp] 1434135189149 [time-out] 60000 milliseconds
>
> ...
>
> etc
>
> ...
>
> TID: [0] [STRATOS] [2015-06-12 18:54:51,862]  INFO
> {org.apache.stratos.cep.extension.FaultHandlingWindowProcessor} -  Faulty
> member detected [member-id]
> di-000-010.di-000-010.cisco-qvpc-sf-0.domain2ab24c1d-53cb-452e-8aa2-f02eecf2db78
> with [last time-stamp] 1434135193054 [time-out] 60000 milliseconds
>
> ...
>
> etc
>
> ...
>
>
>
> 2.      The last message relating to the CPS failure is at 18:54:52. The
> first message relating to recovery of the CPS is some 66 seconds later:
>
>
>
> TID: [0] [STRATOS] [2015-06-12 18:55:58,516]  INFO
> {org.apache.stratos.autoscaler.rule.RuleLog} -  [min-check] Partition
> available, hence trying to spawn an instance to fulfil minimum count!
> [cluster] cartridge-proxy.cartridge-proxy.cartridge-proxy.domain
>
>
>
> 3.      However, recovery of other VMs started as much as 54 seconds
> before this point to as much as 26 seconds after:
>
>
>
> TID: [0] [STRATOS] [2015-06-12 18:55:04,564]  INFO
> {org.apache.stratos.autoscaler.client.CloudControllerClient} -  Trying to
> spawn an instance via cloud controller: [cluster]
> di-000-008.di-000-008.cisco-qvpc-sf-0.domain [partition] whole-region
> [network-partition-id] RegionOne
>
> ...
>
> TID: [0] [STRATOS] [2015-06-12 18:56:20,603]  INFO
> {org.apache.stratos.autoscaler.client.CloudControllerClient} -  Trying to
> spawn an instance via cloud controller: [cluster]
> di-000-007.di-000-007.cisco-qvpc-sf-0.domain [partition] whole-region
> [network-partition-id] RegionOne
>
>
>
> 4.      Between point 2 and 3 (with fuzz for the races), I see Stratos
> cleaning the old VMs. For example:
>
>
>
> TID: [0] [STRATOS] [2015-06-12 18:55:04,580]  INFO
> {org.apache.stratos.cloud.controller.iaases.JcloudsIaas} -  Starting to
> terminate member: [cartridge-type] cisco-qvpc-sf-0 [member-id]
> di-000-008.di-000-008.cisco-qvpc-sf-0.domaina0f15eed-9599-4f3e-a70a-93ddd02ccf5f
>
>
>
> 5.      However, around that point, look at this:
>
>
>
> TID: [0] [STRATOS] [2015-06-12 18:55:12,835]  INFO
> {org.apache.stratos.autoscaler.rule.RuleLog} -  [scale-up] Trying to scale
> up over max, hence not scaling up cluster itself and
>
>                         notifying to parent for possible group scaling or
> app bursting.
>
>                         [cluster]
> di-000-005.di-000-005.cisco-qvpc-sf-0.domain [instance id]di-000-005-1
> [max] 1
>
>
>
>
>
> 6.      Is it possible that there is a race between the terminates and
> restarts? It certainly seems so, though a detailed knowledge of Startos is
> needed to confirm it:
>
>
>
> TID: [0] [STRATOS] [2015-06-12 18:55:12,798]  INFO
> {org.apache.stratos.autoscaler.rule.RuleLog} -  [min-check] Partition
> available, hence trying to spawn an instance to fulfil minimum count!
> [cluster] di-000-005.di-000-005.cisco-qvpc-sf-0.domain
>
> TID: [0] [STRATOS] [2015-06-12 18:55:12,798]  INFO
> {org.apache.stratos.autoscaler.client.CloudControllerClient} -  Trying to
> spawn an instance via cloud controller: [cluster]
> di-000-005.di-000-005.cisco-qvpc-sf-0.domain [partition] whole-region
> [network-partition-id] RegionOne
>
> TID: [0] [STRATOS] [2015-06-12 18:55:12,799]  INFO
> {org.apache.stratos.common.client.CloudControllerServiceClient} -
> Terminating instance via cloud controller: [member]
> di-000-005.di-000-005.cisco-qvpc-sf-0.domain4bcdd49a-985f-4247-a70b-31c8d65153d8
>
> TID: [0] [STRATOS] [2015-06-12 18:55:12,812]  INFO
> {org.apache.stratos.cloud.controller.messaging.publisher.TopologyEventPublisher}
> -  Publishing member created event: [service-name] cisco-qvpc-sf-0
> [cluster-id] di-000-005.di-000-005.cisco-qvpc-sf-0.domain
> [cluster-instance-id] di-000-005-1 [member-id]
> di-000-005.di-000-005.cisco-qvpc-sf-0.domaine9e4111c-abba-4979-af07-d13d90bbd84d
> [instance-id] null [network-partition-id] RegionOne [partition-id]
> whole-region [lb-cluster-id] null
>
> TID: [0] [STRATOS] [2015-06-12 18:55:12,817]  INFO
> {org.apache.stratos.messaging.message.processor.topology.MemberCreatedMessageProcessor}
> -  Member created: [service-name] cisco-qvpc-sf-0 [cluster-id]
> di-000-005.di-000-005.cisco-qvpc-sf-0.domain [member-id]
> di-000-005.di-000-005.cisco-qvpc-sf-0.domaine9e4111c-abba-4979-af07-d13d90bbd84d
> [cluster-instance-id] di-000-005-1
>
> TID: [0] [STRATOS] [2015-06-12 18:55:12,834] ERROR
> {org.apache.stratos.autoscaler.rule.RuleTasksDelegator} -  Request in
> flight threshold is Zero
>
> TID: [0] [STRATOS] [2015-06-12 18:55:12,835]  INFO
> {org.apache.stratos.autoscaler.rule.RuleLog} -  [scale-up] Trying to scale
> up over max, hence not scaling up cluster itself and
>
>                         notifying to parent for possible group scaling or
> app bursting.
>
>                         [cluster]
> di-000-005.di-000-005.cisco-qvpc-sf-0.domain [instance id]di-000-005-1
> [max] 1
>
>
>
> (I tried to file a JIRA on this, but I’m having a bit of trouble, hence
> posting here to get the ball rolling).
>
>
>
> Thanks, Shaheed
>
>
>
>
>
>
>
>
>
> --
>
> Akila Ravihansa Perera
> Software Engineer, WSO2
>
> Blog: http://ravihansa3000.blogspot.com
>
>
>
>
>
> --
>
> Imesh Gunaratne
>
>
>
> Senior Technical Lead, WSO2
>
> Committer & PMC Member, Apache Stratos
>



-- 
Reka Thirunavukkarasu
Senior Software Engineer,
WSO2, Inc.:http://wso2.com,
Mobile: +94776442007

Reply via email to