Hi,
I just tested Appia 3.1 with the sequoia nightly build release
downloaded yesterday (2.8).
The demo that is included in the sequoia release works fine.
The controllers log the following output:
Controller #1 (after started):
14:42:00,159 DEBUG continuent.hedera.gms Appia reported new view:
version: 1
group: [Group:myDB]
id: [ViewID:1;[EMAIL PROTECTED]:49561]]
previous: [[ViewID:0;[EMAIL PROTECTED]:49561]],
[ViewID:0;[EMAIL PROTECTED]:49576]],]
view: [EMAIL PROTECTED]:49561],
[EMAIL PROTECTED]:49576],]
addresses: [yttrium.lasige.di.fc.ul.pt:
49561,yttrium.lasige.di.fc.ul.pt:49576,]
14:42:00,171 DEBUG continuent.hedera.gms Member
(address=yttrium.lasige.di.fc.ul.pt/10.10.1.8:49576,
uid=yttrium.lasige.di.fc.ul.pt/10.10.1.8:49576) joins Group(gid=myDB).
14:42:00,598 DEBUG continuent.hedera.channel Received Message
14:42:00,599 DEBUG continuent.hedera.channel received message NOT
fragmented
14:42:00,733 INFO controller.virtualdatabase.myDB Checking virtual
database configuration from 127.0.0.1:25323
14:42:00,750 DEBUG continuent.hedera.appia Sending message
[EMAIL PROTECTED] to the Appia Channel
14:42:00,750 DEBUG continuent.hedera.appia Sending message
[EMAIL PROTECTED] to the Appia Channel
14:42:00,758 DEBUG continuent.hedera.appia Message
[EMAIL PROTECTED] Sent
14:42:00,758 DEBUG continuent.hedera.appia Message
[EMAIL PROTECTED] Sent
14:42:00,775 DEBUG continuent.hedera.channel Received Message
14:42:00,778 DEBUG continuent.hedera.channel received message NOT
fragmented
14:42:00,875 DEBUG continuent.hedera.channel Received Message
14:42:00,877 DEBUG continuent.hedera.channel received message NOT
fragmented
14:42:00,893 DEBUG continuent.hedera.appia Sending message
[EMAIL PROTECTED] to the Appia Channel
14:42:00,893 DEBUG continuent.hedera.appia Sending message
[EMAIL PROTECTED] to the Appia Channel
14:42:00,894 DEBUG continuent.hedera.appia Message
[EMAIL PROTECTED] Sent
14:42:00,894 DEBUG continuent.hedera.appia Message
[EMAIL PROTECTED] Sent
14:42:00,898 DEBUG continuent.hedera.channel Received Message
14:42:00,898 DEBUG continuent.hedera.channel received message NOT
fragmented
14:42:00,935 DEBUG continuent.hedera.channel Received Message
14:42:00,939 DEBUG continuent.hedera.channel received message NOT
fragmented
14:42:00,944 INFO controller.virtualdatabase.myDB Controller
127.0.0.1:25323 is compatible with the local configuration
14:42:00,995 DEBUG continuent.hedera.appia Sending message
[EMAIL PROTECTED] to the Appia Channel
14:42:00,995 DEBUG continuent.hedera.appia Sending message
[EMAIL PROTECTED] to the Appia Channel
14:42:01,006 DEBUG continuent.hedera.appia Message
[EMAIL PROTECTED] Sent
14:42:01,006 DEBUG continuent.hedera.appia Message
[EMAIL PROTECTED] Sent
14:42:01,010 DEBUG continuent.hedera.channel Received Message
14:42:01,012 DEBUG continuent.hedera.channel received message NOT
fragmented
14:42:01,154 DEBUG continuent.hedera.channel Received Message
14:42:01,155 DEBUG continuent.hedera.channel received message NOT
fragmented
14:42:01,162 INFO controller.virtualdatabase.myDB Updating backend
list for controller Member(address=yttrium.lasige.di.fc.ul.pt/
10.10.1.8:49576, uid=yttrium.lasige.di.fc.ul.pt/10.10.1.8:49576)
14:42:01,164 DEBUG continuent.hedera.appia Sending message
[EMAIL PROTECTED] to the Appia Channel
14:42:01,164 DEBUG continuent.hedera.appia Sending message
[EMAIL PROTECTED] to the Appia Channel
14:42:01,170 DEBUG continuent.hedera.appia Message
[EMAIL PROTECTED] Sent
14:42:01,170 DEBUG continuent.hedera.appia Message
[EMAIL PROTECTED] Sent
14:42:01,176 DEBUG continuent.hedera.channel Received Message
14:42:01,177 DEBUG continuent.hedera.channel received message NOT
fragmented
Controller #2:
14:42:00,087 DEBUG continuent.hedera.gms Appia reported new view:
version: 1
group: [Group:myDB]
id: [ViewID:1;[EMAIL PROTECTED]:49561]]
previous: [[ViewID:0;[EMAIL PROTECTED]:49561]],
[ViewID:0;[EMAIL PROTECTED]:49576]],]
view: [EMAIL PROTECTED]:49561],
[EMAIL PROTECTED]:49576],]
addresses: [yttrium.lasige.di.fc.ul.pt:
49561,yttrium.lasige.di.fc.ul.pt:49576,]
14:42:00,088 DEBUG continuent.hedera.gms Member
(address=yttrium.lasige.di.fc.ul.pt/10.10.1.8:49561,
uid=yttrium.lasige.di.fc.ul.pt/10.10.1.8:49561) joins Group(gid=myDB).
14:42:00,469 INFO controller.virtualdatabase.myDB Group myDB
connected to Member(address=yttrium.lasige.di.fc.ul.pt/
10.10.1.8:49576, uid=yttrium.lasige.di.fc.ul.pt/10.10.1.8:49576)
14:42:00,471 INFO controller.virtualdatabase.myDB Group now contains
2 controllers.
14:42:00,472 INFO controller.virtualdatabase.myDB Checking virtual
database configuration with remote controllers.
14:42:00,577 DEBUG continuent.hedera.appia Sending message
[EMAIL PROTECTED] to the Appia Channel
14:42:00,577 DEBUG continuent.hedera.appia Sending message
[EMAIL PROTECTED] to the Appia Channel
14:42:00,579 DEBUG continuent.hedera.appia Message
[EMAIL PROTECTED] Sent
14:42:00,579 DEBUG continuent.hedera.appia Message
[EMAIL PROTECTED] Sent
14:42:00,584 DEBUG continuent.hedera.channel Received Message
14:42:00,585 DEBUG continuent.hedera.channel received message NOT
fragmented
14:42:00,782 DEBUG continuent.hedera.channel Received Message
14:42:00,783 DEBUG continuent.hedera.channel received message NOT
fragmented
14:42:00,830 DEBUG continuent.hedera.appia Sending message
[EMAIL PROTECTED] to the Appia Channel
14:42:00,830 DEBUG continuent.hedera.appia Sending message
[EMAIL PROTECTED] to the Appia Channel
14:42:00,831 DEBUG continuent.hedera.appia Message
[EMAIL PROTECTED] Sent
14:42:00,831 DEBUG continuent.hedera.appia Message
[EMAIL PROTECTED] Sent
14:42:00,867 DEBUG continuent.hedera.channel Received Message
14:42:00,868 DEBUG continuent.hedera.channel received message NOT
fragmented
14:42:00,903 DEBUG continuent.hedera.channel Received Message
14:42:00,911 DEBUG continuent.hedera.channel received message NOT
fragmented
14:42:00,919 INFO controller.virtualdatabase.myDB Updating backend
list for controller Member(address=yttrium.lasige.di.fc.ul.pt/
10.10.1.8:49561, uid=yttrium.lasige.di.fc.ul.pt/10.10.1.8:49561)
14:42:00,922 DEBUG continuent.hedera.appia Sending message
[EMAIL PROTECTED] to the Appia Channel
14:42:00,922 DEBUG continuent.hedera.appia Sending message
[EMAIL PROTECTED] to the Appia Channel
14:42:00,924 DEBUG continuent.hedera.appia Message
[EMAIL PROTECTED] Sent
14:42:00,924 DEBUG continuent.hedera.appia Message
[EMAIL PROTECTED] Sent
14:42:00,930 DEBUG continuent.hedera.channel Received Message
14:42:00,931 DEBUG continuent.hedera.channel received message NOT
fragmented
14:42:01,029 DEBUG continuent.hedera.channel Received Message
14:42:01,030 DEBUG continuent.hedera.channel received message NOT
fragmented
14:42:01,041 WARN controller.virtualdatabase.myDB Some virtual
database users are missing from this configuration, trying to create
them transparently...
14:42:01,044 INFO controller.virtualdatabase.myDB Virtual database
configuration is compatible with other controllers.
14:42:01,045 INFO controller.virtualdatabase.myDB Controller
identifier is set to: 2
14:42:01,052 DEBUG continuent.hedera.appia Sending message
[EMAIL PROTECTED] to the Appia Channel
14:42:01,052 DEBUG continuent.hedera.appia Sending message
[EMAIL PROTECTED] to the Appia Channel
14:42:01,072 DEBUG continuent.hedera.appia Message
[EMAIL PROTECTED] Sent
14:42:01,072 DEBUG continuent.hedera.appia Message
[EMAIL PROTECTED] Sent
14:42:01,079 DEBUG continuent.hedera.channel Received Message
14:42:01,080 DEBUG continuent.hedera.channel received message NOT
fragmented
14:42:01,189 DEBUG continuent.hedera.channel Received Message
14:42:01,190 DEBUG continuent.hedera.channel received message NOT
fragmented
14:42:01,225 INFO controller.virtualdatabase.myDB Resyncing recovery
log ...
14:42:01,229 INFO controller.virtualdatabase.myDB No shutdown
checkpoint found in recovery log. Clearing recovery log (dirty).
14:42:01,230 INFO controller.virtualdatabase.myDB Please resync
manually using 'recover log'.
14:42:01,253 INFO controller.virtualdatabase.myDB Resyncing recovery
log done
14:42:01,255 DEBUG controller.core.Controller The database backends
are auto-enabled in mode 0.
14:42:01,259 INFO controller.virtualdatabase.myDB Unknown last state
for backend localhost3. Leaving node in disabled state.
14:42:01,265 INFO controller.virtualdatabase.myDB Unknown last state
for backend localhost4. Leaving node in disabled state.
14:42:01,266 INFO controller.core.Controller Adding VirtualDatabase
myDB
14:42:01,267 DEBUG controller.core.Controller Autoload for config
file: /Users/nuno/tmp/sequoia-2.8-bin/config/virtualdatabase/hsqldb-
raidb1-distribution-2.xml has been set to: 0
14:42:01,294 INFO controller.core.Controller Waiting for connections
on 127.0.0.1:25323
14:42:01,294 DEBUG controller.core.Controller Backlog size is 10
connections.
14:42:01,337 INFO controller.core.Controller Controller started on
2006.05.04 18 at 02:42:01 PM WEST
14:42:01,338 INFO controller.core.Controller Controller
127.0.0.1:25323 ready, listening to requests ...
On these logs, we can see that they connect, join and exchange some
messages using group communication. Your logs indicate that the 2
members also join and try to check the configurations using the group
communication. I see that the message arrives to the other member,
but after this something strange happens.
What I don't understand is the following:
My first controller, after receiving the first message (configuration
of the controller that just arrived), logs the following:
14:42:00,171 DEBUG continuent.hedera.gms Member
(address=yttrium.lasige.di.fc.ul.pt/10.10.1.8:49576,
uid=yttrium.lasige.di.fc.ul.pt/10.10.1.8:49576) joins Group(gid=myDB).
14:42:00,598 DEBUG continuent.hedera.channel Received Message
14:42:00,599 DEBUG continuent.hedera.channel received message NOT
fragmented
14:42:00,733 INFO controller.virtualdatabase.myDB Checking virtual
database configuration from 127.0.0.1:25323
I don't see one log message like this in your output. Instead, I see
the following:
2006-05-03 17:09:39,385 DEBUG continuent.hedera.gms Member
(address=192.168.10.94/192.168.10.94:32808,
uid=192.168.10.94/192.168.10.94:32808) joins Group(gid=qualiproof).
2006-05-03 17:09:39,860 DEBUG continuent.hedera.channel Received Message
2006-05-03 17:09:39,860 DEBUG continuent.hedera.channel received
message NOT fragmented
2006-05-03 17:10:16,935 INFO controller.virtualdatabase.qualiproof
Member(address=test92.dresden.local/192.168.10.92:32799,
uid=test92.dresden.local/192.168.10.92:32799) see members:[Member
(address=192.168.10.94/192.168.10.94:32808,
uid=192.168.10.94/192.168.10.94:32808), Member
(address=test92.dresden.local/192.168.10.92:32799,
uid=test92.dresden.local/192.168.10.92:32799)] and has mapping:{Member
(address=test92.dresden.local/192.168.10.92:32799,
uid=test92.dresden.local/192.168.10.92:32799)=192.168.10.92:1090}
So, it seems that the message arrives to the other Appia member, but
after this it is NOT delivered to the Controller.
The Hedera messages include a list of receivers of the message and
hedera only delivers the message to the controller if the controller
belongs to that receiver list. But the list seems to be correct.
But this is just an ideia, I don't really understand what is that
last message from the controller: Member X see members Y,X and has
mapping {X=Z}
Maybe the sequoia people could help here?
I added debug information about message delivery in the
AppiaReliableGroupChannel.java file and commited it in the CVS.
Can you please update hedera from CVS and checkout if the messages
are being delivered to the controller?
Thanks for your feedback,
Nuno Carvalho
On May 4, 2006, at 7:56 AM, Schnabl, Sebastian wrote:
Does the 1st controller also outputs the token messages?
Yes. The first controller has the same token messages.
Is the virtual database configuration compatible with the
other controller?
Yes. The vdb-configuration(s) are compatible and running fine with
jGroups.
I'll give you some feedback as soon as I test Appia with 2.8.
Thank you ;-)
_______________________________________________
Hedera mailing list
[email protected]
https://forge.continuent.org/mailman/listinfo/hedera
_______________________________________________
Hedera mailing list
[email protected]
https://forge.continuent.org/mailman/listinfo/hedera