You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@qpid.apache.org by Pavel Moravec <pm...@redhat.com> on 2014/05/25 22:51:08 UTC

Re: [HA] debug Backup Rejected connection - problem with setting up qpid HA

Hi Radek,
did you promote either of brokers to be a primary? See qpid-ha promote command.

Kind regards,
Pavel


----- Original Message -----
> From: "Radek Smigielski" <ra...@ymail.com>
> To: users@qpid.apache.org
> Sent: Friday, May 23, 2014 6:14:45 PM
> Subject: [HA] debug Backup Rejected connection - problem with setting up qpid HA
> 
> Hi,
>    I'm tryin to make pair of qpids (qpid0.26) working as a HA pair.
> 
> Here is my very simplistic config, identical for both nodes:
> worker-threads=10
> mgmt-qmf2=yes
> mgmt-qmf1=yes
> enable-timestamp=yes
> log-enable=info+
> log-time=yes
> log-category=yes
> ha-queue-replication=yes
> ha-replicate=all
> ha-cluster=yes
> ha-brokers-url=amqp:qpid1,qpid2
> link-maintenance-interval=1
> link-heartbeat-interval=3
> 
> 
> I am using examples/messaging/hello_world to check if I can connect to any of
> the nodes and getting the same error on both nodes:
> 
> [radek@qpid1 ~]$
> /home/radek/src/qpid-cpp-0.26/build/examples/messaging/hello_world
> 2014-05-23 11:35:02 [Client] warning Connection
> [127.0.0.1:42581-localhost:5672] closed
> Failed to connect (reconnect disabled)
> 
> 
> This is what I see on the servers, the same when I am trying connect to any
> of nodes:
> 
> [HA] debug Backup: Rejected connection qpid.127.0.0.1:5672-127.0.0.1:42556
> 
> 
> And this is the full qpidd trace output
> 
> 2014-05-23 11:28:05 [Network] info Set TCP_NODELAY on connection to
> 127.0.0.1:42556
> 2014-05-23 11:28:05 [System] debug RECV
> [qpid.127.0.0.1:5672-127.0.0.1:42556]: INIT(0-10)
> 2014-05-23 11:28:05 [Security] debug External ssf=0 and auth=
> 2014-05-23 11:28:05 [Security] debug min_ssf: 0, max_ssf: 256, external_ssf:
> 0
> 2014-05-23 11:28:05 [Security] info SASL: Mechanism list: ANONYMOUS
> 2014-05-23 11:28:05 [Broker] debug LinkRegistry::notifyConnection();
> key=qpid.127.0.0.1:5672-127.0.0.1:42556
> 2014-05-23 11:28:05 [Model] trace Mgmt create connection.
> id:qpid.127.0.0.1:5672-127.0.0.1:42556
> 2014-05-23 11:28:05 [Management] debug Management object (V1) added:
> org.apache.qpid.broker:connection:qpid.127.0.0.1:5672-127.0.0.1:42556
> 2014-05-23 11:28:05 [Protocol] trace SENT
> [qpid.127.0.0.1:5672-127.0.0.1:42556]: INIT(0-10)
> 2014-05-23 11:28:05 [Protocol] trace SENT
> [qpid.127.0.0.1:5672-127.0.0.1:42556]: Frame[BEbe; channel=0;
> {ConnectionStartBody:
> server-properties={qpid.federation_tag:V2:36:str16(48096762-a992-4f4d-9836-b9895965c499)};
> mechanisms=str16{V2:9:str16(ANONYMOUS)}; locales=str16{V2:5:str16(en_US)};
> }]
> 2014-05-23 11:28:05 [Protocol] trace RECV
> [qpid.127.0.0.1:5672-127.0.0.1:42556]: Frame[BEbe; channel=0;
> {ConnectionStartOkBody:
> client-properties={qpid.client_pid:F4:int32(456),qpid.client_ppid:F4:int32(342),qpid.client_process:V2:11:str16(hello_world),qpid.session_flow:F4:int32(1)};
> mechanism=ANONYMOUS; response=xxxxxx; locale=en_US; }]
> 2014-05-23 11:28:05 [Security] info SASL: Starting authentication with
> mechanism: ANONYMOUS
> 2014-05-23 11:28:05 [Management] debug SEND raiseEvent (v1)
> class=org.apache.qpid.broker.clientConnect
> 2014-05-23 11:28:05 [Management] debug SEND raiseEvent (v2)
> class=org.apache.qpid.broker.clientConnect
> 2014-05-23 11:28:05 [Model] debug Create connection. user:anonymous@QPID
> rhost:qpid.127.0.0.1:5672-127.0.0.1:42556
> 2014-05-23 11:28:05 [Security] info qpid.127.0.0.1:5672-127.0.0.1:42556 SASL:
> Authentication succeeded for: anonymous@QPID
> 2014-05-23 11:28:05 [Protocol] trace SENT
> [qpid.127.0.0.1:5672-127.0.0.1:42556]: Frame[BEbe; channel=0;
> {ConnectionTuneBody: channel-max=32767; max-frame-size=65535;
> heartbeat-min=0; heartbeat-max=120; }]
> 2014-05-23 11:28:05 [Protocol] trace RECV
> [qpid.127.0.0.1:5672-127.0.0.1:42556]: Frame[BEbe; channel=0;
> {ConnectionTuneOkBody: channel-max=32767; max-frame-size=65535; heartbeat=0;
> }]
> 2014-05-23 11:28:05 [Protocol] trace RECV
> [qpid.127.0.0.1:5672-127.0.0.1:42556]: Frame[BEbe; channel=0;
> {ConnectionOpenBody: virtual-host=; capabilities=void{}; insist=1; }]
> 2014-05-23 11:28:05 [HA] debug Backup: Rejected connection
> qpid.127.0.0.1:5672-127.0.0.1:42556
> 2014-05-23 11:28:05 [System] debug DISCONNECTED
> [qpid.127.0.0.1:5672-127.0.0.1:42556]
> 2014-05-23 11:28:05 [Model] trace Mgmt destroying connection.
> id:qpid.127.0.0.1:5672-127.0.0.1:42556 Statistics: {bytesFromClient:226,
> bytesToClient:49, closing:False, framesFromClient:3, framesToClient:2,
> msgsFromClient:0, msgsToClient:0}
> 2014-05-23 11:28:05 [Management] debug SEND raiseEvent (v1)
> class=org.apache.qpid.broker.clientDisconnect
> 2014-05-23 11:28:05 [Management] debug SEND raiseEvent (v2)
> class=org.apache.qpid.broker.clientDisconnect
> 2014-05-23 11:28:05 [Model] debug Delete connection. user:anonymous@QPID
> rhost:qpid.127.0.0.1:5672-127.0.0.1:42556
> 
> 
> 
> Thanks for advice,
> - Radoslaw Smigielski
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
> For additional commands, e-mail: users-help@qpid.apache.org
> 
> 

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
For additional commands, e-mail: users-help@qpid.apache.org


Re: [HA] debug Backup Rejected connection - problem with setting up qpid HA

Posted by Radek Smigielski <ra...@ymail.com>.

> On Tuesday, 27 May 2014, 22:55:47, Radek Smigielski <ra...@ymail.com> wrote:

> > 
> 
>  
>>  That is odd. It shows the new backup actually becomes ready, but then
>>  disconnects for some reason - and then appears to disconnect _again_,
>>  which is why it is reported as unknown, because as far as the primary is
>>  concerned it is not connected at that point. Hmm. Can you send me the
>>  full logs from primary & backup please?  Use these flags:
>>    --log-enable=debug+:HA --log-enable=info+
> 
> Alan, sent you the logs directly.


Alan, have you had chance to look on the logs I sent you? 


Radek.

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
For additional commands, e-mail: users-help@qpid.apache.org


Re: [HA] debug Backup Rejected connection - problem with setting up qpid HA

Posted by Radek Smigielski <ra...@ymail.com>.

 
> That is odd. It shows the new backup actually becomes ready, but then
> disconnects for some reason - and then appears to disconnect _again_,
> which is why it is reported as unknown, because as far as the primary is
> concerned it is not connected at that point. Hmm. Can you send me the
> full logs from primary & backup please?  Use these flags:
>   --log-enable=debug+:HA --log-enable=info+

Alan, sent you the logs directly.

Thanks!
Radek.

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
For additional commands, e-mail: users-help@qpid.apache.org


Re: [HA] debug Backup Rejected connection - problem with setting up qpid HA

Posted by Alan Conway <ac...@redhat.com>.
On Tue, 2014-05-27 at 18:51 +0100, Radek Smigielski wrote:
> > On Tuesday, 27 May 2014, 15:53:50, Alan Conway <ac...@redhat.com> wrote:
> > > On Sun, 2014-05-25 at 23:33 +0100, Radek Smigielski wrote:
> >> 
> >>  > On Sunday, 25 May 2014, 21:51:39, Pavel Moravec 
> > <pm...@redhat.com> wrote:
> >>  > > Hi Radek,
> >>  > did you promote either of brokers to be a primary? See qpid-ha promote 
> > command.
> >>  > 
> >>  > Kind regards,
> >>  > Pavel
> >> 
> >> 
> >>  Thanks Pavel, it does the trick, almost. Now one of my nodes becomes active 
> > but the backup
> >>  one stays in "joining" state, never exits it. 
> >> 
> >>  This is what I see on master: 
> >>  [radek@qpid1 /]$ qpid-ha query
> >>  Status:              active
> >>  Brokers URL:         amqp:tcp:qpid2:5672
> >>  Public URL:
> >>  Expected Backups:    None
> >>  Replicate:           all
> >> 
> >>  And on master:
> >>  [HA] info Primary: Disconnect from unknown backup 66f38d8c(joining)
> >>             
> >> 
> >> 
> >>  And this is a backup node:
> >>  [radek@qpid2 ~]$ qpid-ha query
> >>  Status:              joining
> >>  Brokers URL:         amqp:tcp:qpid1:5672
> >>  Public URL:
> >>  Expected Backups:    None
> >>  Replicate:           all
> > 
> > Your brokers-url should be the same for all brokers, and should contain
> > a list of all the brokers in your cluster i.e: 
> > 
> > brokers-url: amqp:tcp:qpid1:5672,tcp:qpid2:5672
> > 
> 
> 
> I beleive you mean ha-broker-url option. I set it on both brokers to:
> 
> ha-brokers-url=amqp:tcp:qpid1:5672,tcp:qpid2:5672
> 
> 
> But still the backup broker stays in joining state:
> [radek@qpid1 ~]$  qpid-ha status --all
> qpid1:5672 active
> qpid2:5672 joining
> 
> 
> 
> I don't know if this matters but the master broker show this: 
> 
> 2014-05-27 13:49:03 [HA] info Primary: New backup connection: 3bc70754(joining)
> 2014-05-27 13:49:03 [HA] info Membership: 6732b428@tcp:qpid1:5672(active) 3bc70754(catchup) 
> 2014-05-27 13:49:03 [HA] info Membership: 6732b428@tcp:qpid1:5672(active) 3bc70754(ready) 
> 2014-05-27 13:49:03 [HA] info Primary: New backup is ready: 3bc70754(ready)
> 2014-05-27 13:49:03 [HA] info Primary: Disconnect from backup 3bc70754(joining)
> 2014-05-27 13:49:03 [HA] info Membership: 6732b428@tcp:qpid1:5672(active) 
> 2014-05-27 13:49:03 [HA] info Primary: Disconnect from unknown backup 3bc70754(joining)
> 
> 
> And the last line indicates that master broker still doesn't know the backup broker for some reason?

That is odd. It shows the new backup actually becomes ready, but then
disconnects for some reason - and then appears to disconnect _again_,
which is why it is reported as unknown, because as far as the primary is
concerned it is not connected at that point. Hmm. Can you send me the
full logs from primary & backup please?  Use these flags:
  --log-enable=debug+:HA --log-enable=info+

Cheers,
Alan.


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
For additional commands, e-mail: users-help@qpid.apache.org


Re: [HA] debug Backup Rejected connection - problem with setting up qpid HA

Posted by Radek Smigielski <ra...@ymail.com>.
> On Tuesday, 27 May 2014, 15:53:50, Alan Conway <ac...@redhat.com> wrote:
> > On Sun, 2014-05-25 at 23:33 +0100, Radek Smigielski wrote:
>> 
>>  > On Sunday, 25 May 2014, 21:51:39, Pavel Moravec 
> <pm...@redhat.com> wrote:
>>  > > Hi Radek,
>>  > did you promote either of brokers to be a primary? See qpid-ha promote 
> command.
>>  > 
>>  > Kind regards,
>>  > Pavel
>> 
>> 
>>  Thanks Pavel, it does the trick, almost. Now one of my nodes becomes active 
> but the backup
>>  one stays in "joining" state, never exits it. 
>> 
>>  This is what I see on master: 
>>  [radek@qpid1 /]$ qpid-ha query
>>  Status:              active
>>  Brokers URL:         amqp:tcp:qpid2:5672
>>  Public URL:
>>  Expected Backups:    None
>>  Replicate:           all
>> 
>>  And on master:
>>  [HA] info Primary: Disconnect from unknown backup 66f38d8c(joining)
>>             
>> 
>> 
>>  And this is a backup node:
>>  [radek@qpid2 ~]$ qpid-ha query
>>  Status:              joining
>>  Brokers URL:         amqp:tcp:qpid1:5672
>>  Public URL:
>>  Expected Backups:    None
>>  Replicate:           all
> 
> Your brokers-url should be the same for all brokers, and should contain
> a list of all the brokers in your cluster i.e: 
> 
> brokers-url: amqp:tcp:qpid1:5672,tcp:qpid2:5672
> 


I beleive you mean ha-broker-url option. I set it on both brokers to:

ha-brokers-url=amqp:tcp:qpid1:5672,tcp:qpid2:5672


But still the backup broker stays in joining state:
[radek@qpid1 ~]$  qpid-ha status --all
qpid1:5672 active
qpid2:5672 joining



I don't know if this matters but the master broker show this: 

2014-05-27 13:49:03 [HA] info Primary: New backup connection: 3bc70754(joining)
2014-05-27 13:49:03 [HA] info Membership: 6732b428@tcp:qpid1:5672(active) 3bc70754(catchup) 
2014-05-27 13:49:03 [HA] info Membership: 6732b428@tcp:qpid1:5672(active) 3bc70754(ready) 
2014-05-27 13:49:03 [HA] info Primary: New backup is ready: 3bc70754(ready)
2014-05-27 13:49:03 [HA] info Primary: Disconnect from backup 3bc70754(joining)
2014-05-27 13:49:03 [HA] info Membership: 6732b428@tcp:qpid1:5672(active) 
2014-05-27 13:49:03 [HA] info Primary: Disconnect from unknown backup 3bc70754(joining)


And the last line indicates that master broker still doesn't know the backup broker for some reason?

Cheers,
Radek.


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
For additional commands, e-mail: users-help@qpid.apache.org


Re: [HA] debug Backup Rejected connection - problem with setting up qpid HA

Posted by Alan Conway <ac...@redhat.com>.
On Sun, 2014-05-25 at 23:33 +0100, Radek Smigielski wrote:
> 
> > On Sunday, 25 May 2014, 21:51:39, Pavel Moravec <pm...@redhat.com> wrote:
> > > Hi Radek,
> > did you promote either of brokers to be a primary? See qpid-ha promote command.
> > 
> > Kind regards,
> > Pavel
> 
> 
> Thanks Pavel, it does the trick, almost. Now one of my nodes becomes active but the backup
> one stays in "joining" state, never exits it. 
> 
> This is what I see on master: 
> [radek@qpid1 /]$ qpid-ha query
> Status:              active
> Brokers URL:         amqp:tcp:qpid2:5672
> Public URL:
> Expected Backups:    None
> Replicate:           all
> 
> And on master:
> [HA] info Primary: Disconnect from unknown backup 66f38d8c(joining)
>             
> 
> 
> And this is a backup node:
> [radek@qpid2 ~]$ qpid-ha query
> Status:              joining
> Brokers URL:         amqp:tcp:qpid1:5672
> Public URL:
> Expected Backups:    None
> Replicate:           all

Your brokers-url should be the same for all brokers, and should contain
a list of all the brokers in your cluster i.e: 

brokers-url: amqp:tcp:qpid1:5672,tcp:qpid2:5672

> 
> And the logs on backup server:
> 2014-05-25 18:19:54 [HA] debug amq.failover created.
> 2014-05-25 18:19:54 [HA] debug Backup starting, rejecting client connections.
> 2014-05-25 18:19:54 [HA] info Membership: 66f38d8c(joining) 
> 2014-05-25 18:19:54 [HA] info Status change: standalone -> joining
> 2014-05-25 18:19:54 [HA] notice Initializing HA broker: 66f38d8c(joining)
> 2014-05-25 18:19:54 [HA] info Membership: 66f38d8c(joining) 
> 2014-05-25 18:19:54 [HA] info Backup: Brokers URL set to: amqp:tcp:qpid1:5672
> 2014-05-25 18:19:54 [HA] info Backup: Connecting to cluster, broker URL: amqp:tcp:qpid1:5672
> 2014-05-25 18:19:54 [HA] debug Status check amqp:tcp:qpid1:5672: active
> 2014-05-25 18:19:54 [HA] info Status check amqp:tcp:qpid1:5672: Joining established cluster
> 2014-05-25 18:19:56 [HA] debug Backup: Accepted admin connection: qpid.127.0.0.1:5672-127.0.0.1:44233
> 2014-05-25 18:20:00 [HA] debug Backup: Accepted admin connection: qpid.127.0.0.1:5672-127.0.0.1:44234
> 2014-05-25 18:20:01 [HA] debug Backup: Accepted admin connection: qpid.127.0.0.1:5672-127.0.0.1:44235
> 2014-05-25 18:20:02 [HA] debug Backup: Accepted admin connection: qpid.127.0.0.1:5672-127.0.0.1:44236
> 2014-05-25 18:20:14 [HA] debug Backup: Accepted admin connection: qpid.127.0.0.1:5672-127.0.0.1:44237
> 2014-05-25 18:20:15 [HA] info Backup: Brokers URL set to: amqp:tcp:qpid1:5672
> 2014-05-25 18:20:15 [HA] debug Status check amqp:tcp:qpid1:5672: active
> 2014-05-25 18:20:15 [HA] info Status check amqp:tcp:qpid1:5672: Joining established cluster
> 
> 
> 
> Why the backup host is unknow for master?
> Am I missing something obvius again?
> What is the Primary::closed state mean in qpid/ha/Primary.cpp?
> 
> 
> Thanks,
> Radek
> 
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
> For additional commands, e-mail: users-help@qpid.apache.org
> 



---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
For additional commands, e-mail: users-help@qpid.apache.org


Re: [HA] debug Backup Rejected connection - problem with setting up qpid HA

Posted by Radek Smigielski <ra...@ymail.com>.

> On Sunday, 25 May 2014, 21:51:39, Pavel Moravec <pm...@redhat.com> wrote:
> > Hi Radek,
> did you promote either of brokers to be a primary? See qpid-ha promote command.
> 
> Kind regards,
> Pavel


Thanks Pavel, it does the trick, almost. Now one of my nodes becomes active but the backup
one stays in "joining" state, never exits it. 

This is what I see on master: 
[radek@qpid1 /]$ qpid-ha query
Status:              active
Brokers URL:         amqp:tcp:qpid2:5672
Public URL:
Expected Backups:    None
Replicate:           all

And on master:
[HA] info Primary: Disconnect from unknown backup 66f38d8c(joining)
            


And this is a backup node:
[radek@qpid2 ~]$ qpid-ha query
Status:              joining
Brokers URL:         amqp:tcp:qpid1:5672
Public URL:
Expected Backups:    None
Replicate:           all

And the logs on backup server:
2014-05-25 18:19:54 [HA] debug amq.failover created.
2014-05-25 18:19:54 [HA] debug Backup starting, rejecting client connections.
2014-05-25 18:19:54 [HA] info Membership: 66f38d8c(joining) 
2014-05-25 18:19:54 [HA] info Status change: standalone -> joining
2014-05-25 18:19:54 [HA] notice Initializing HA broker: 66f38d8c(joining)
2014-05-25 18:19:54 [HA] info Membership: 66f38d8c(joining) 
2014-05-25 18:19:54 [HA] info Backup: Brokers URL set to: amqp:tcp:qpid1:5672
2014-05-25 18:19:54 [HA] info Backup: Connecting to cluster, broker URL: amqp:tcp:qpid1:5672
2014-05-25 18:19:54 [HA] debug Status check amqp:tcp:qpid1:5672: active
2014-05-25 18:19:54 [HA] info Status check amqp:tcp:qpid1:5672: Joining established cluster
2014-05-25 18:19:56 [HA] debug Backup: Accepted admin connection: qpid.127.0.0.1:5672-127.0.0.1:44233
2014-05-25 18:20:00 [HA] debug Backup: Accepted admin connection: qpid.127.0.0.1:5672-127.0.0.1:44234
2014-05-25 18:20:01 [HA] debug Backup: Accepted admin connection: qpid.127.0.0.1:5672-127.0.0.1:44235
2014-05-25 18:20:02 [HA] debug Backup: Accepted admin connection: qpid.127.0.0.1:5672-127.0.0.1:44236
2014-05-25 18:20:14 [HA] debug Backup: Accepted admin connection: qpid.127.0.0.1:5672-127.0.0.1:44237
2014-05-25 18:20:15 [HA] info Backup: Brokers URL set to: amqp:tcp:qpid1:5672
2014-05-25 18:20:15 [HA] debug Status check amqp:tcp:qpid1:5672: active
2014-05-25 18:20:15 [HA] info Status check amqp:tcp:qpid1:5672: Joining established cluster



Why the backup host is unknow for master?
Am I missing something obvius again?
What is the Primary::closed state mean in qpid/ha/Primary.cpp?


Thanks,
Radek


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
For additional commands, e-mail: users-help@qpid.apache.org