WebLogic ClusterMessaging

We occasionally see these messages in an instance of a WLS cluster:

####<Mar 8, 2017 10:21:43 AM CET> <Info> <WorkManager> <myhost> <myserver> <[ACTIVE] ExecuteThread: '13' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1488964903589> <BEA-002939> <The maximum thread constraint ClusterMessaging has been reached 2 times for the last 237 seconds.>

What is that constraint ClusterMessaging ? It's set internally by WLS on a WorkManager, it allows max 8 threads to handle the internal cluster messaging and this parameter can't be changed.

If you want to detect what is wrong, take a few thread dumps at interval of 3-5 seconds. Most likely you have some huge object in the JNDI tree being serialized/deserialized. Another possibility is that you have a non serializable object in the JNDI tree. If this is not the case, try analyzing your network traffic (the procedure could be very differend depending if you are using Multicast of Unicast)

In our case, we had this message which could be a hint that serialization is wrong:

<Mar 14, 2017 10:30:19 AM CET> <Error> <Cluster> <BEA-000123> <Conflict start: You tried to bind an object under the name jdbc.workflow.HibernateSessionFactory in the JNDI tree. The object from -2132852355821393490S:169.56.179.213:[-1,-1,32275,32275,-1,-1,-1]:mydomain:myserver01 is non-clusterable, and you have tried to bind more than once from two or more servers. Such objects can only be deployed from one server.>

WebLogic: all MS in a cluster hang while starting up.... weblogic.cluster.MemberManager.getJNDIStateDump issue

in the thread dump of both MS I see several blocked threads:

weblogic.cluster.MemberManager.getRemoteMembers
weblogic.iiop.ClusterServices.getMembers
weblogic.cluster.ClusterRuntime.clusterMembersChanged
weblogic.cluster.MemberManager.findOrCreate
plus some 150 DynamicJSSEListenThread threads....
In particular all BLOCKED threads are waiting for lock 0x000000060276f168 who is held by this getJNDIStateDump:

"[STANDBY] ExecuteThread: '2' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=10 tid=0x00007f6a800024c0 nid=0x74bd runnable [0x00007f6b1f7e6000]
   java.lang.Thread.State: RUNNABLE
               at java.net.SocketInputStream.socketRead0(Native Method)
               at java.net.SocketInputStream.read(SocketInputStream.java:152)
               at java.net.SocketInputStream.read(SocketInputStream.java:122)
               at sun.security.ssl.InputRecord.readFully(InputRecord.java:442)
               at sun.security.ssl.InputRecord.read(InputRecord.java:480)
               at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:946)
               - locked <0x000000060bcf5160> (a java.lang.Object)
               at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:903)
               at sun.security.ssl.AppInputStream.read(AppInputStream.java:102)
               - locked <0x000000060bd2a9b0> (a sun.security.ssl.AppInputStream)
               at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
               at java.io.BufferedInputStream.read1(BufferedInputStream.java:275)
               at java.io.BufferedInputStream.read(BufferedInputStream.java:334)
               - locked <0x000000060bd2a988> (a java.io.BufferedInputStream)
               at sun.net.www.http.HttpClient.parseHTTPHeader(HttpClient.java:690)
               at sun.net.www.http.HttpClient.parseHTTP(HttpClient.java:633)
               at sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1325)
               - locked <0x000000060c29d3c8> (a sun.net.www.protocol.https.DelegateHttpsURLConnection)
               at sun.net.www.protocol.https.HttpsURLConnectionImpl.getInputStream(HttpsURLConnectionImpl.java:254)
               - locked <0x000000060c29d4a8> (a sun.net.www.protocol.https.HttpsURLConnectionImpl)
               at weblogic.cluster.MemberManager.getJNDIStateDump(MemberManager.java:244)
               at weblogic.cluster.MemberManager.waitForSync(MemberManager.java:222)
               at weblogic.cluster.MemberManager.waitToSyncWithCurrentMembers(MemberManager.java:182)
               - locked <0x000000060276f168> (a weblogic.cluster.MemberManager)
               at weblogic.cluster.InboundService.start(InboundService.java:52)
               at weblogic.server.AbstractServerService.postConstruct(AbstractServerService.java:78)
               at sun.reflect.GeneratedMethodAccessor6.invoke(Unknown Source)
               at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
               at java.lang.reflect.Method.invoke(Method.java:606)
               at org.glassfish.hk2.utilities.reflection.ReflectionHelper.invoke(ReflectionHelper.java:1017)
               at org.jvnet.hk2.internal.ClazzCreator.postConstructMe(ClazzCreator.java:388)
               at org.jvnet.hk2.internal.ClazzCreator.create(ClazzCreator.java:430)
               at org.jvnet.hk2.internal.SystemDescriptor.create(SystemDescriptor.java:456)
               at org.glassfish.hk2.runlevel.internal.AsyncRunLevelContext.findOrCreate(AsyncRunLevelContext.java:225)
               at org.glassfish.hk2.runlevel.RunLevelContext.findOrCreate(RunLevelContext.java:82)
               at org.jvnet.hk2.internal.Utilities.createService(Utilities.java:2488)
               at org.jvnet.hk2.internal.ServiceHandleImpl.getService(ServiceHandleImpl.java:98)
               - locked <0x000000060acd0028> (a java.lang.Object)
               at org.jvnet.hk2.internal.ServiceHandleImpl.getService(ServiceHandleImpl.java:87)
               at org.glassfish.hk2.runlevel.internal.CurrentTaskFuture$QueueRunner.oneJob(CurrentTaskFuture.java:1162)
               at org.glassfish.hk2.runlevel.internal.CurrentTaskFuture$QueueRunner.run(CurrentTaskFuture.java:1147)
               at weblogic.work.SelfTuningWorkManagerImpl$WorkAdapterImpl.run(SelfTuningWorkManagerImpl.java:553)
               at weblogic.work.ExecuteThread.execute(ExecuteThread.java:311)
               at weblogic.work.ExecuteThread.run(ExecuteThread.java:263)

It turned out that the SAME domain was running before on a different set of servers, and while migrating them the operator forgot to shut down the previous instances. How this could interfere with the current domain, it's still a mystery

WebLogic cluster: "Failed to deserialize statedump from server "

If you have an error "Failed to deserialize statedump from server " "java.lang.ClassNotFoundException"
you should read Oracle Document:

"How To Avoid De-Serialize Statedump Errors While Starting Manage Servers in Cluster Environment (java.lang.ClassNotFoundException) (Doc ID 796357.1)"

The solution is to start first the Admin, and only when this is running you should start the managed servers one by one, and not in parallel (the Oracle doc says the opposite). Don't ask me questions, I have no clue.

The other possible root cause could be an invalid EAR, try rebuilding it and redeploying it.

http://oraclefmwadmins.blogspot.ch/2014/07/bea-000140-failed-to-deserialize.html

Reason:
 Corrupted EJB files due to temporary communication failure between WebLogic admin and managed server instances

Solution:
 1. Stop Weblogic Managed/Admin Server
 2.Delete the directory under $DOMAIN_HOME/servers//tmp/_WL_user/
 3.Restart Admin/Managed servers. The file will create automatically.

See also http://www.ateam-oracle.com/weblogic-server-cluster-messaging-protocols/ "When a server (re)joins the cluster, that server will ask another server in the cluster to provide the current view of its JNDI tree (known as a JNDI state dump) to initialize its view and then rely on JNDI replication messages to maintain it. This JNDI state dump does not use the cluster messaging protocol and relies on a point-to-point connection with the other server."

 <BEA-000140> <Failed to deserialize statedump from server 8572742343661541822S:169.13.12.236:[-1,-1,31623,31623,-1,-1,-1]:pipposerver_cluster2:pippovaimsi0_chlp2520199_server with java.lang.ClassNotFoundException: com.pippo.Pluto.
java.lang.ClassNotFoundException: com.pippo.Pluto
                at weblogic.application.internal.AppClassLoaderManagerImpl.loadApplicationClass(AppClassLoaderManagerImpl.java:164)
                at weblogic.common.internal.ProxyClassResolver.resolveProxyClass(ProxyClassResolver.java:68)
                at weblogic.common.internal.WLObjectInputStream.resolveProxyClass(WLObjectInputStream.java:76)
                at java.io.ObjectInputStream.readProxyDesc(ObjectInputStream.java:1537)
                at java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1493)
                at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1750)
                at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1329)
                at java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:1977)
                at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1901)
                at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1777)
                at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1329)
                at java.io.ObjectInputStream.readObject(ObjectInputStream.java:349)
                at weblogic.common.internal.WLObjectInputStream.readObjectWL(WLObjectInputStream.java:98)
                at weblogic.cluster.BasicServiceOffer.readExternal(BasicServiceOffer.java:172)
                at java.io.ObjectInputStream.readExternalData(ObjectInputStream.java:1818)
                at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1775)
                at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1329)
                at java.io.ObjectInputStream.readObject(ObjectInputStream.java:349)
                at java.util.ArrayList.readObject(ArrayList.java:593)
                at sun.reflect.GeneratedMethodAccessor3.invoke(Unknown Source)
                at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
                at java.lang.reflect.Method.invoke(Method.java:597)
                at java.io.ObjectStreamClass.invokeReadObject(ObjectStreamClass.java:1019)
                at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1877)
                at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1777)
                at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1329)
                at java.io.ObjectInputStream.readObject(ObjectInputStream.java:349)
                at weblogic.common.internal.WLObjectInputStream.readArrayList(WLObjectInputStream.java:116)
                at weblogic.cluster.StateDumpMessage.readExternal(StateDumpMessage.java:53)
                at java.io.ObjectInputStream.readExternalData(ObjectInputStream.java:1818)
                at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1775)
                at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1329)
                at java.io.ObjectInputStream.readObject(ObjectInputStream.java:349)
                at weblogic.cluster.HTTPExecuteRequest.run(HTTPExecuteRequest.java:90)
                at weblogic.work.ExecuteThread.execute(ExecuteThread.java:256)
                at weblogic.work.ExecuteThread.run(ExecuteThread.java:221)

One should assign a warmup period https://docs.oracle.com/cd/E13222_01/wls/docs100/schemaref/config/http.www.bea.com.ns.weblogic.920.domain/types/clustertype.member-warmup-timeout-seconds.html and make sure you use default protocol t3s

Singleton Timer in WebLogic

If you have a JEE EJB Timer in a Cluster, maybe you want only 1 instance to be active. In this case you should implement a Cluster Aware Singleton Component :
https://blogs.oracle.com/muraliveligeti/entry/ejb_timer_ejb

- create table WEBLOGIC_TIMERS

configure a Datasource and set it in "cluster-Scheduling":

OSB Cluster

Create a new Domain, using the "OSB Production" template
Create it in "Production" mode
Create MS osb_server1 and osb_server2 and put them into a cluster.

You will notice that this deployment:

"ALSB Cluster Singleton Marker Application" is targeted to osb_server1

wlsbJMSServer_auto_1 and 2 are targeted to osb_server1 and 2

WseeJmsServer_auto_1 and 2 are targeted to osb_server1 and 2

wli.reporting.purge.queue is deployed to wlsbJMSServer_auto_1

all the reporting, email file ftp sftp transport JMS queues are created as Distributed Destinations and targeted to the cluster
(wlsb.internal.transport.task.queue.ftp_auto_1, wlsb.internal.transport.task.queue.sftp_auto_1, wlsb.internal.transport.task.queue.email_auto_1, wlsb.internal.transport.task.queue.file_auto_1, QueueIn_auto_1, wli.reporting.jmsprovider.queue_auto_1, wli.reporting.jmsprovider_error.queue_auto_1)


DefaultCallbackQueue-WseeJmsServer_auto_1/2 and DefaultQueue-WseeJmsServer_auto_1/2 are deployed to either server



see here


for File, FTP, email:
"the poller on only one managed server will poll for a given proxy service"

Waiting to synchronize with other running members of mycluster

If using unicast cluster and WebLogic Servers take a long time to startup, you can check for the message "Waiting to synchronize with other running members of " and see if it corresponds to a silence of 30 seconds.
If this is the case, you can change at cluster level the "Member Warmup Timeout":

"Maximum number of seconds that a cluster member will wait to discover and synchronize with other servers in the cluster. Normally, the member will be able to sync in 30 seconds. If the value of this attribute is higher, that does not necessarily mean that it will take longer for the member to warmup. Instead it defines an upper bound on the time that a server will wait to sync with the servers that it has discovered. If the value is set 0, servers will not attempt to discover other running server in the cluster during server initialization"

WebLogic 11 Whole Server Migration

previous notes here

Here the doc:
http://docs.oracle.com/cd/E14571_01/web.1111/e13709/migration.htm

Here an excellent crash course.

To provoke a server migration:
kill -9 PID
when NodeManager restarts the MS, kill again!

The second time, the NodeManager will not try to restart the MS locally, and will let che ClusterMaster decide another machine on which to start the MS

This is what is traced in the nodemanager.log

Successfully removed 10.56.5.183 from bond0:4.
Server failed so attempting to restart (restart count = 1)
Sleeping for 30 seconds before attempting to restart server
Starting WebLogic server with command line: /opt/oracle/domains/osbpp1do/bin/startWebLogic.sh
Working directory is '/opt/oracle/domains/osbpp1do'
Rotated server output log to "/opt/oracle/domains/osbpp1do/servers/osbpp1ms1/logs/osbpp1ms1.out00132"
Server error log also redirected to server log
Server output log file is '/opt/oracle/domains/osbpp1do/servers/osbpp1ms1/logs/osbpp1ms1.out'
Successfully brought 10.56.5.183 with netmask 255.255.255.0 online on bond0:4
Successfully removed 10.56.5.183 from bond0:4.
Server failed during startup so will not be restarted

Server tribes migrating in the desert.

To discover on which machine it was started: open the console, MS, Control, Migration, "Current Machine:".

Now, I think something is weird.... let's say I have a cluster with
4 machines: m1, m2, m3 and m4,
4 managed servers: ms1, ms2, ms3, ms4


I kill ms1 on m1 and make it migrate to m2.
Now, I expect to be able to "fallback" from m2 to m1. I go to server/control/migration and, lo and behold, in the list "migrate to machine" I have only m2, m3, m4 (no m1)... incidentally, since m2 is the current machine, it makes no sense to migrate to m2...

Also, if you click on "Migratable Targets", the column "Current Hosting Server" reports the wrong information, m1 instead of m2.... but at least here, if you take the lock, select the ms1 and do "migrate", it gives you the option to migrate ms1 (migratable) back to hosting server ms1 (what does it mean "hosting server ms1"? even if I request migration, it fails with a

weblogic.management.runtime.MigrationException: Cannot migrate - destination server must not be the currently activate server - services are already deployed on that server.

...)

How can I migrate a server with WLST?

Here the doc

SQLIntegrityConstraintViolationException while the LeaseManager updates the ACTIVE table

####<May 31, 2012 11:14:06 AM CEST> <Debug> <ServerMigration> <hqchacme105> <osbpp1ms1> <[ACTIVE] ExecuteThread: '32' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <553e43a3c186ec6d:58114d2:1379f528b89:-7ffd-0000000000008622> <1338455646674> <BEA-000000> <Query: UPDATE ACTIVE SET TIMEOUT = ( (SYSDATE + (30/86400))) WHERE SERVER IN ('wlsserver.osbpp1ms1') AND INSTANCE ='-5605988896686436333/osbpp1ms1' AND DOMAINNAME='osbpp1do' AND CLUSTERNAME='osbpp1cl'>

####<May 31, 2012 11:14:07 AM CEST> <Debug> <ServerMigration> <hqchacme105> <osbpp1ms1> <[ACTIVE] ExecuteThread: '23' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <553e43a3c186ec6d:58114d2:1379f528b89:-7ffd-0000000000008626> <1338455647328> <BEA-000000> <<DatabaseLeasingBasis>: tryAcquire(service.SINGLETON_MASTER, 30000)>

####<May 31, 2012 11:14:07 AM CEST> <Debug> <ServerMigration> <hqchacme105> <osbpp1ms1> <[ACTIVE] ExecuteThread: '23' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <553e43a3c186ec6d:58114d2:1379f528b89:-7ffd-0000000000008626> <1338455647329> <BEA-000000> <Query: DELETE FROM ACTIVE WHERE (SYSDATE > TIMEOUT) AND SERVER = 'service.SINGLETON_MASTER' AND DOMAINNAME='osbpp1do' AND CLUSTERNAME='osbpp1cl'>

####<May 31, 2012 11:14:07 AM CEST> <Debug> <ServerMigration> <hqchacme105> <osbpp1ms1> <[ACTIVE] ExecuteThread: '23' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <553e43a3c186ec6d:58114d2:1379f528b89:-7ffd-0000000000008626> <1338455647331> <BEA-000000> <Query: INSERT INTO ACTIVE ( SERVER, INSTANCE, DOMAINNAME, CLUSTERNAME, TIMEOUT ) VALUES ( 'service.SINGLETON_MASTER' , '-5605988896686436333/osbpp1ms1' , 'osbpp1do' , 'osbpp1cl' , (SYSDATE + (30/86400)) )>

####<May 31, 2012 11:14:07 AM CEST> <Debug> <ServerMigration> <hqchacme105> <osbpp1ms1> <[ACTIVE] ExecuteThread: '23' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <553e43a3c186ec6d:58114d2:1379f528b89:-7ffd-0000000000008626> <1338455647333> <BEA-000000> <Attempted Query: INSERT INTO ACTIVE ( SERVER, INSTANCE, DOMAINNAME, CLUSTERNAME, TIMEOUT ) VALUES ( 'service.SINGLETON_MASTER' , '-5605988896686436333/osbpp1ms1' , 'osbpp1do' , 'osbpp1cl' , (SYSDATE + (30/86400)) )>

####<May 31, 2012 11:14:07 AM CEST> <Debug> <ServerMigration> <hqchacme105> <osbpp1ms1> <[ACTIVE] ExecuteThread: '23' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <553e43a3c186ec6d:58114d2:1379f528b89:-7ffd-0000000000008626> <1338455647334> <BEA-000000> <Unexpected exception

java.sql.SQLIntegrityConstraintViolationException: ORA-00001: unique constraint (PP1_SOAINFRA.SYS_C0013550) violated
at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:457)
at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:405)
at oracle.jdbc.driver.T4C8Oall.processError(T4C8Oall.java:889)
at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:476)
at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:204)
at oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:540)
at oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:217)
at oracle.jdbc.driver.T4CPreparedStatement.executeForRows(T4CPreparedStatement.java:1079)
at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1466)
at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3752)
at oracle.jdbc.driver.OraclePreparedStatement.executeUpdate(OraclePreparedStatement.java:3887)
at oracle.jdbc.driver.OraclePreparedStatementWrapper.executeUpdate(OraclePreparedStatementWrapper.java:1508)
at weblogic.jdbc.wrapper.PreparedStatement.executeUpdate(PreparedStatement.java:172)
at weblogic.cluster.singleton.DatabaseLeasingBasis.assumeLease(DatabaseLeasingBasis.java:253)
at weblogic.cluster.singleton.DatabaseLeasingBasis.acquire(DatabaseLeasingBasis.java:88)
at weblogic.cluster.singleton.LeaseManager.timerExpired(LeaseManager.java:408)
at weblogic.timers.internal.TimerImpl.run(TimerImpl.java:273)
at weblogic.work.SelfTuningWorkManagerImpl$WorkAdapterImpl.run(SelfTuningWorkManagerImpl.java:528)
at weblogic.work.ExecuteThread.execute(ExecuteThread.java:209)
at weblogic.work.ExecuteThread.run(ExecuteThread.java:178)




this is the content of the ACTIVE table




"SERVER" "INSTANCE" "DOMAINNAME" "CLUSTERNAME" "TIMEOUT"

"service.SINGLETON_MASTER" "2372471525479840300/osbpp1ms2" "osbpp1do" "osbpp1cl" 31-MAY-12

"wlsserver.osbpp1ms1" "-5605988896686436333/osbpp1ms1" "osbpp1do" "osbpp1cl" 31-MAY-12

"service.CLUSTER_MASTER" "2372471525479840300/osbpp1ms2" "osbpp1do" "osbpp1cl" 31-MAY-12

"wlsserver.osbpp1ms4" "2967680027205630303/osbpp1ms4" "osbpp1do" "osbpp1cl" 31-MAY-12

"wlsserver.osbpp1ms2" "2372471525479840300/osbpp1ms2" "osbpp1do" "osbpp1cl" 31-MAY-12

"wlsserver.osbpp1ms3" "1002143801186479830/osbpp1ms3" "osbpp1do" "osbpp1cl" 31-MAY-12





and the constraint is:



"CONSTRAINT_NAME" "CONSTRAINT_TYPE" "SEARCH_CONDITION" "R_OWNER" "R_TABLE_NAME" "R_CONSTRAINT_NAME" "DELETE_RULE" "STATUS" "DEFERRABLE" "VALIDATED" "GENERATED" "BAD" "RELY" "LAST_CHANGE" "INDEX_OWNER" "INDEX_NAME" "INVALID" "VIEW_RELATED"


"SYS_C0013550" "Primary_Key" "" "" "" "" "" "ENABLED" "NOT DEFERRABLE" "VALIDATED" "GENERATED NAME" "" "" 26-APR-12 "PP1_SOAINFRA" "SYS_C0013550" "" ""





and the DDL is:



--------------------------------------------------------

-- DDL for Table ACTIVE

--------------------------------------------------------



CREATE TABLE "PP1_SOAINFRA"."ACTIVE"

( "SERVER" VARCHAR2(150 BYTE),

"INSTANCE" VARCHAR2(100 BYTE),

"DOMAINNAME" VARCHAR2(50 BYTE),

"CLUSTERNAME" VARCHAR2(50 BYTE),

"TIMEOUT" DATE

)


CREATE UNIQUE INDEX "PP1_SOAINFRA"."SYS_C0013550" ON "PP1_SOAINFRA"."ACTIVE" ("SERVER", "DOMAINNAME", "CLUSTERNAME")



ALTER TABLE "PP1_SOAINFRA"."ACTIVE" ADD PRIMARY KEY ("SERVER", "DOMAINNAME", "CLUSTERNAME");



probably the DELETE doesn’t delete the row....


This is what the official documentation says:


http://docs.oracle.com/cd/E23549_01/relnotes.1111/e10133/ha.htm#CIHEJAHC




6.1.14 Harmless SQLIntegrityConstraintViolationException Can be Received in a SOA Cluster

The following SQLIntegrityConstraintViolationException can be received in a SOA cluster:

[TopLink Warning]: 2010.04.11 14:26:53.941--UnitOfWork(275924841)--Exception

[TOPLINK-4002] (Oracle TopLink - 11g Release 1 (11.1.1.3.0):

Internal Exception: java.sql.SQLIntegrityConstraintViolationException:

ORA-00001: unique constraint (JYIPS2RC4B49_SOAINFRA.SYS_C0035333) violated

.

.

.

This is not a bug. In a cluster environment, when the messages for the same group arrive on both the nodes, one node is bound to experience this exception for the first message. The application is aware of this exception and handles it properly. It does not break any functionality.

This exception can also come on a single node after you restart the server and send the message for the existing group. Again, this exception will be experienced on the very first message.

In summary, this exception is within the application design and does not impact any functionality. It is for this reason that you do not see this exception logged as severe in the soa-diagnostic logs.

Toplink does, however, log it in its server logs.



I hope this is our case... harmless....

SOAPUI, OSB, WSDL and FrontEnd address and port

(guest post, thanks Luis Verge (vergegon pisellon!) Gonzales for this)

Yesterday while using SOAPUI for defining some projects for testing I saw that if I try to use the dynamic?WSDL address I got an error as described below:


1st. Open the Internet explorer and type the address of your WSDL:

http://10.56.5.192:8105/SSS_GetUsers/ProxyServices/GetUsers_PS?wsdl

Then you will see the wsdl and the soap address (HINT: where does that 9980 port come from???):

If you create a SOAPUI project and you use the dynamic address:

(notice: port is 8105, not 9980!)

Your process will  remain  running trying to solve the address:

(notice again the 9980!)

If you see the previous image you will notice something estrange, the port you were using 8105 is now 9980. Your first question is why?



The response is given in the weblogic configuration, in the cluster configuration and to be more precise: in the HTTP cluster configuration (see image below)

it't the FRONTEND HTTP PORT!!!


If you read the explanation in oracle documentation:



http://docs.oracle.com/cd/E12840_01/wls/docs103/webserv/setenv.html#wp220521



and in middleware magic:

http://middlewaremagic.com/weblogic/?p=1938



You will understand how it works.

Apparently, in our current configuration (with network proxies) when we try to use a dynamic address , we don’t get it because is redirecting it to the frontend port and address defined in the cluster.

Normally in that part of the weblogic configuration we should have the loadbalancer address, but unfortunately we have none in dev.

I was wondering on using as the default port in the frontend configuration in the cluster the port 8105, so every request not solved will be redirected to 8105.

That change will require a restart.

ClusterTimer, Updated time skew

I have seen in the logs this Info:

ClusterTimer, Updated time skew. New skew is -3 Old skew was 3 and Urzeit is 1334181600000

Since I am as curious as a cat, I have searched and found out that this is logged by com.bea.wli.timer.TimeSkewSynchronizer,

running a TimeSkewSynchronizerTask which in turn uses a ClusterTimerService which uses a ClusterTimerPersistenceStore to persist the Urzeit (apart from being a mythological archetype, it's also a universal time reference).

more to come...

Cluster Master, Singleton Master....

taking sparse notes here...

Cluster Master:

http://docs.oracle.com/cd/E21764_01/web.1111/e13709/migration.htm#i1034621
"Its role is to orchestrate the server migration process"
Reading this doc is like pure poetry.



Singleton Master:

http://docs.oracle.com/cd/E21764_01/web.1111/e13709/service_migration.htm#i1051470

"The singleton master is a lightweight singleton service that monitors other services that can be migrated automatically."

These services use the ACTIVE Database table to keep renewed the lease:

CREATE TABLE ACTIVE (
SERVER VARCHAR2(150) NOT NULL,
INSTANCE VARCHAR2(100) NOT NULL,
DOMAINNAME VARCHAR2(50) NOT NULL,
CLUSTERNAME VARCHAR2(50) NOT NULL,
TIMEOUT DATE,
PRIMARY KEY (SERVER, DOMAINNAME, CLUSTERNAME)
);


see /opt/oracle/fmw11_1_1_5/wlserver_10.3/server/db/oracle/920/leasing.ddl

and the content of the table looks like:

"SERVER"                      "INSTANCE"                    "DOMAINNAME"                  "CLUSTERNAME"                 "TIMEOUT"                    

"service.SINGLETON_MASTER"    "2756549746869550668/osbpp1ms1""osbpp1do"                    "osbpp1cl"                    "06-MAY-12"                  

"wlsserver.osbpp1ms4"         "-5012701700773599167/osbpp1ms4""osbpp1do"                    "osbpp1cl"                    "06-MAY-12"                  

"service.CLUSTER_MASTER"      "2756549746869550668/osbpp1ms1""osbpp1do"                    "osbpp1cl"                    "06-MAY-12"                  

"wlsserver.osbpp1ms2"         "1291378860276628438/osbpp1ms2""osbpp1do"                    "osbpp1cl"                    "06-MAY-12"                  

"wlsserver.osbpp1ms1"         "2756549746869550668/osbpp1ms1""osbpp1do"                    "osbpp1cl"                    "06-MAY-12"                  

"wlsserver.osbpp1ms3"         "-2011604050071714597/osbpp1ms3""osbpp1do"                    "osbpp1cl"                    "06-MAY-12"               


that is, one row per managed server in the cluster, plus a row for service.SINGLETON_MASTER and one for service.CLUSTER_MASTER (this is also telling us that both SINGLETON_MASTER and CLUSTER_MASTER are osbpp1ms1 in this case.

WebLogic cluster monitor script

#Script to monitor running cluster
#will write thread dumps and other cluster diagnostic info to a file, at regular intervals

#Vernetto 2011-11-11

from java.io import File
from java.io import FileOutputStream
from java.io import FileInputStream
from java.util import HashMap
from java.util import HashSet
from java.util import ArrayList
from time import sleep

import datetime

import zlib
import zipfile
from os import *

configFileProperties = None
isConnected = false
previousStdout = None

#=======================================================================================
# Utility function to load properties from a config file
#=======================================================================================

def loadProps(configPropFile):
    global configFileProperties
    propInputStream = FileInputStream(configPropFile)
    configFileProperties = Properties()
    configFileProperties.load(propInputStream)
    

def appendToAlarmLog(alarmmessage):
    alarmsfile = configFileProperties.get('alarmsfile')
    alarmFile = open(alarmsfile, 'a')
    alarmFile.write(getNowTimestamp() + ' ' + alarmmessage + '\n')
    alarmFile.close()


def getNowTimestamp():
 now = datetime.datetime.now()
 nowtimestamp = now.strftime("%Y%m%dT%H%M%S")
 return nowtimestamp
 
def monitorServer():
    global isConnected
    fos = None    
    previousStdout = theInterpreter.getOut()
    try:
  #initialize variables
  serverURL=configFileProperties.get('serverURL')
  serverName=configFileProperties.get('serverName')
  username=configFileProperties.get('username')
  password=configFileProperties.get('password')
  logFile=configFileProperties.get('logFile')
  aliveServerCountExpected=configFileProperties.get('aliveServerCountExpected')
  interval=configFileProperties.get('interval')

  #initialize timestamp to append to log filename
  nowtimestamp = getNowTimestamp()


  #save stdout handle 
  logFileNameWithTimestamp = logFile + '.' + nowtimestamp

  #set new stdout

  print "start the script"
  #easeSyntax()

  if (not isConnected) :
      connect(username, password, serverURL)
      isConnected = true

  serverRuntime()
  
  #redirect output to log file
  f = File(logFileNameWithTimestamp)
  fos = FileOutputStream(f)
  theInterpreter.setOut(fos)

  cd('/')
  print 'Health', cmo.getHealthState()

  cd('/ClusterRuntime/myCluster/')
  print 'AliveServerCount=', cmo.getAliveServerCount(), ' ServerNames', cmo.getServerNames()

  if (aliveServerCountExpected != cmo.getAliveServerCount()) :
     alarmmessage = 'MONITORALARM, we were expecting AliveServerCount ' + aliveServerCountExpected + ' and we have instead %d , see file %s' % (cmo.getAliveServerCount() , logFileNameWithTimestamp, )
     print alarmmessage 
     appendToAlarmLog(alarmmessage)
     
     
  cd('/ClusterRuntime/myCluster/UnicastMessaging/UnicastMessagingRuntime')

  print 'DiscoveredGroupLeaders=',  cmo.getDiscoveredGroupLeaders(), ' Groups=', cmo.getGroups(), ' LocalGroupLeaderName=',  cmo.getLocalGroupLeaderName(), ' RemoteGroupsDiscoveredCount=',  cmo.getRemoteGroupsDiscoveredCount(), ' TotalGroupsCount=', cmo.getTotalGroupsCount()

  cd('/ServerChannelRuntimes/unicastChannel')
  print 'AcceptCount=' , cmo.getAcceptCount() , ' MessagesReceivedCount=' , cmo.getMessagesReceivedCount() , ' MessagesSentCount=' , cmo.getMessagesSentCount()
  scr = cmo.getServerConnectionRuntimes()
  #scr is an array of weblogic.server.channels.ServerConnectionRuntimeImpl$SerializableConnectionRuntime
  for myscr in scr:
   print "BytesReceivedCount=", myscr.getBytesReceivedCount(), " BytesSentCount=", myscr.getBytesSentCount(), " ConnectTime=", myscr.getConnectTime()," MessagesReceivedCount=",  myscr.getMessagesReceivedCount(), " MessagesSentCount=", myscr.getMessagesSentCount()

  print ""

  threadDump()


  cd('/JVMRuntime/' + serverName)
  #this is valid for JRockit
  #print "HeapFreeCurrent=", cmo.getHeapFreeCurrent(), " TotalGarbageCollectionTime", cmo.getTotalGarbageCollectionTime(), " TotalNumberOfThreads=", cmo.getTotalNumberOfThreads()
  #this is valid for JRockit
  print "HeapFreeCurrent=", cmo.getHeapFreeCurrent(), ' HeapSizeCurrent=', cmo.getHeapSizeCurrent()

  cd('/ThreadPoolRuntime/ThreadPoolRuntime')

  print 'HoggingThreadCount=', cmo.getHoggingThreadCount(), ' PendingUserRequestCount', cmo.getPendingUserRequestCount(), ' StandbyThreadCount' , cmo.getStandbyThreadCount()
  print 'CompletedRequestCount=', cmo.getCompletedRequestCount(), ' ExecuteThreadIdleCount=', cmo.getExecuteThreadIdleCount(), ' ExecuteThreadTotalCount=', cmo.getExecuteThreadTotalCount()

  #restore stdout
  theInterpreter.setOut(previousStdout)

  fos.close()
  #now zip the report
  zipfileLog = zipfile.ZipFile(logFileNameWithTimestamp + '.zip', 'w')
  zipfileLog.write(logFileNameWithTimestamp, compress_type=zipfile.ZIP_DEFLATED)
  zipfileLog.close()
  os.remove(logFileNameWithTimestamp)

  
    except:
        isConnected = false
        theInterpreter.setOut(previousStdout)
        if (fos != None) :
            fos.close()
        print "Unexpected error:", sys.exc_info()[0]
        raise
  

  
  

# monitor script init
try:
    # sys.argv[1] is the config properties file
 configFile = sys.argv[1]
 print 'Loading config from :', configFile
 loadProps(configFile)
 interval = configFileProperties.getProperty('interval')

 while True:
  try:
   sleep(float(interval))
   monitorServer()
  except:
   errorMessage = "ERROR_QUERYING_SERVER %s - %s - %s"% (sys.exc_info()[0], sys.exc_info()[1], sys.exc_info()[2], )
   appendToAlarmLog(errorMessage)
   dumpStack()


except:
    print "Unexpected error: ", sys.exc_info()[0]
    dumpStack()
    raise
 

and the property file contains:


serverURL=t3://pierrepc:7031
serverName=ms3
username=weblogic
password=welcome1
logFile=C:/pierre/clustermonitor/clustermonitorinfo3.log
alarmsfile=C:/pierre/clustermonitor/clustermonitoralarms3.log
aliveServerCountExpected=3
interval=10

OSB Cluster

Create a new Domain, using the "OSB Production" template
Create it in "Production" mode
Create MS osb_server1 and osb_server2 and put them into a cluster.

You will notice that this deployment:

"ALSB Cluster Singleton Marker Application" is targeted to osb_server1

wlsbJMSServer_auto_1 and 2 are targeted to osb_server1 and 2

WseeJmsServer_auto_1 and 2 are targeted to osb_server1 and 2

wli.reporting.purge.queue is deployed to wlsbJMSServer_auto_1

all the reporting, email file ftp sftp transport JMS queues are created as Distributed Destinations and targeted to the cluster
(wlsb.internal.transport.task.queue.ftp_auto_1, wlsb.internal.transport.task.queue.sftp_auto_1, wlsb.internal.transport.task.queue.email_auto_1, wlsb.internal.transport.task.queue.file_auto_1, QueueIn_auto_1, wli.reporting.jmsprovider.queue_auto_1, wli.reporting.jmsprovider_error.queue_auto_1)


DefaultCallbackQueue-WseeJmsServer_auto_1/2 and DefaultQueue-WseeJmsServer_auto_1/2 are deployed to either server



see here


for File, FTP, email:
"the poller on only one managed server will poll for a given proxy service"


(more to come...)

Unicast Cluster, reconnecting servers

Create a cluster myCluster with 3 MS: ms1, ms2, ms3
Create a unicastChannel on the 3 MS to dedicate for the unicast communication.

#connect to NodeManager
nmConnect('weblogic', 'welcome1', 'localhost', '5556', 'osb_domain', 'C:/Oracle2/Middleware/user_projects/domains/osb_domain')

#start ms1
nmStart('ms1')
#connect to ms1
connect('weblogic', 'welcome1', 't3://localhost:7011')

cd('/ClusterRuntime/myCluster/')
ls()


you should get:
AliveServerCount=1
ServerNames=java.lang.String[ms1]

Start ms2:
nmStart('ms2')

ls()

you should get:
AliveServerCount=2
ServerNames=java.lang.String[ms2,ms1]


nmKill('ms2')

Successfully killed server ms2 ...

ls

AMAZING:
AliveServerCount=2
ServerNames=java.lang.String[ms2,ms1]


how can it be... we have just killed ms2!

In fact, it takes some time for ms1 to notice that ms2 is dead. After some more seconds, you get
AliveServerCount=1
ServerNames=java.lang.String[ms1]
as it should be.