Difference between revisions of "Doc:latest/evalguide/csa104m"

(Putting it all Together)
(How to Run csa103 and What to Observe)
Line 338: Line 338:
 
|}
 
|}
  
===How to Run csa103 and What to Observe===
+
===How to Run csa104 and What to Observe===
  
This sample application can run on all Runtime Hardware Setups. The following, lists which node <code>csa103compI*</code> runs on.
+
This sample application runs 2 processes on SCNodeI0 (first system controller) in all the hardware setups described at the beginning of this eval guide. While it is certainly possible to run messaging across multiple nodes, this single node configuration makes evaluation simpler.
<ul>
+
 
<li>'''Runtime Hardware Setup 1.1 and 2.1'''
+
csa104 is "enabled" by default when SAFplus is started so there is no need to enter the SAFplus Debug Console and change its program state.
<br>csa103compI0 and csa103compI1 will run upon the single node.
+
<li>'''Runtime Hardware Setup 1.2 and 2.2'''
+
<br>csa103compI0 runs on PayloadNodeI0 and csa103compI1 runs on PayloadNodeI1
+
<li>'''Runtime Hardware Setup 1.3 and 2.3'''
+
<br>csa103compI2 and csa103compI3 run on SCNodeI0 and SCNodeI1 respectively. csa103compI0 and csa103compI1 run on PayloadNodeI0 and PayloadNodeI1 respectively.
+
<br><br>In the four node set up SCNodeI0 and SCNodeI1 output data via <code>/root/asp/var/log/csa103CompI2</code> and <code>/root/asp/var/log/csa103CompI3</code> respectively. Therefore in this case follow the below instructions replacing csa103CompI0 and csa103compI1 with csa103compI2 and csa103compI3 respectively.
+
</ul>
+
  
We run csa103 very much the same way we run any of the rest of the sample applications: with the SAFplus Platform Console.
 
 
 
<ol>
 
<li>First, on the active System Controller move it to state LockAssignment with (Unlock csa203SGI0 instead of csa103SGI0 to run csa203)
 
<code><pre>
 
cli[Test]-> setc 1
 
cli[Test:SCNodeI0]-> setc cpm
 
cli[Test:SCNodeI0:CPM]-> amsLockAssignment sg csa103SGI0
 
</pre></code>
 
  
The following output is given when you run <code>tail -f</code> on the csa103 log files. For example:
+
The following output is given when you run <code>tail -f</code> on the csa104 log files. For example:
 
<code><pre>
 
<code><pre>
# tail -f /root/asp/var/log/csa103CompI0.log
+
# ./eval start
 +
# tail -f var/log/csa104CompI?Log.latest
 
</pre></code>
 
</pre></code>
  
 
{| cellspacing="0" cellpadding = "0" border="0" align = "center" width="680"
 
{| cellspacing="0" cellpadding = "0" border="0" align = "center" width="680"
  ! style="color:black;background-color:#ffffaa;" align="center"| /root/asp/var/log/csa103CompI0Log.latest
+
  ! style="color:black;background-color:#ffffaa;" align="center"| /root/asp/var/log/csa103CompI?Log.latest
 
  |-  
 
  |-  
 
  |<code><pre>
 
  |<code><pre>
Mon Jul 14 00:01:09 2008  (SCNodeI0.15238 : csa103CompEO.---.---.00030 :  INFO)
+
==> var/log/csa104CompI0Log.latest <==
Component [csa103CompI0] : PID [15238]. Initializing
+
Fri Jan 11 14:38:45.215 2013 (SCNodeI0.3301 : csa104Comp.---.---.00009 :  INFO) Name value pairs :
Mon Jul 14 00:01:09 2008  (SCNodeI0.15238 : csa103CompEO.---.---.00031 :  INFO)
+
Fri Jan 11 14:38:45.215 2013 (SCNodeI0.3301 : csa104Comp.---.---.00010 :  INFO) HA state : [Active]
    IOC Address            : 0x1
+
Fri Jan 11 14:38:45.215 2013 (SCNodeI0.3301 : csa104Comp.---.---.00011 :  INFO) Active Descriptor :
Mon Jul 14 00:01:09 2008  (SCNodeI0.15238 : csa103CompEO.---.---.00032 :  INFO)
+
Fri Jan 11 14:38:45.215 2013 (SCNodeI0.3301 : csa104Comp.---.---.00012 :  INFO) Transition Descriptor : [1]
    IOC Port                : 0x81
+
Fri Jan 11 14:38:45.215 2013 (SCNodeI0.3301 : csa104Comp.---.---.00013 :  INFO) Active Component : [csa104CompI0]
Mon Jul 14 00:01:09 2008  (SCNodeI0.15238 : csa103CompEO.---.---.00033 :  INFO)
+
Fri Jan 11 14:38:45.215 2013 (SCNodeI0.3301 : csa104Comp.---.---.00014 :  INFO) csa104: ACTIVE state requested; activating message queue receiver service
csa103: Instantiated as component instance csa103CompI0.
+
Fri Jan 11 14:38:45.250 2013 (SCNodeI0.3301 : csa104Comp.---.---.00015 :  INFO) Received Message : Msg    1 from csa104CompI1
Mon Jul 14 00:01:09 2008  (SCNodeI0.15238 : csa103CompEO.---.---.00034 :  INFO)
+
csa103CompI0: Waiting for CSI assignment...
+
Mon Jul 14 00:01:09 2008  (SCNodeI0.15238 : csa103CompEO.---.---.00035 :  INFO)
+
csa103CompI0: Waiting for CSI assignment...
+
Mon Jul 14 00:01:09 2008  (SCNodeI0.15238 : csa103CompEO.---.---.00036 :  INFO)
+
csa103CompI0: checkpoint_initialize
+
Mon Jul 14 00:01:10 2008  (SCNodeI0.15238 : csa103CompEO.---.---.00043 :  INFO)
+
csa103CompI0: Checkpoint service initialized (handle=0x1)
+
Mon Jul 14 00:01:10 2008  (SCNodeI0.15238 : csa103CompEO.---.---.00045 :  INFO)
+
  csa103CompI0: Checkpoint opened (handle=0x2)
+
  </pre></code>
+
|}
+
  
<code><pre>
+
Fri Jan 11 14:38:47.251 2013 (SCNodeI0.3301 : csa104Comp.---.---.00016 :  INFO) Received Message  : Msg    2 from csa104CompI1
# tail -f /root/asp/var/log/csa103CompI1.log
+
</pre></code>
+
  
{| cellspacing="0" cellpadding = "0" border="0" align = "center" width="680"
 
! style="color:black;background-color:#ffffaa;" align="center"| /root/asp/var/log/csa103CompI1Log.latest
 
|-
 
|<code><pre>
 
Mon Jul 14 00:01:09 2008  (SCNodeI0.15234 : csa103CompEO.---.---.00030 :  INFO)
 
Component [csa103CompI1] : PID [15234]. Initializing
 
Mon Jul 14 00:01:09 2008  (SCNodeI0.15234 : csa103CompEO.---.---.00031 :  INFO)
 
    IOC Address            : 0x1
 
Mon Jul 14 00:01:09 2008  (SCNodeI0.15234 : csa103CompEO.---.---.00032 :  INFO)
 
    IOC Port                : 0x80
 
Mon Jul 14 00:01:09 2008  (SCNodeI0.15234 : csa103CompEO.---.---.00033 :  INFO)
 
csa103: Instantiated as component instance csa103CompI1.
 
Mon Jul 14 00:01:09 2008  (SCNodeI0.15234 : csa103CompEO.---.---.00034 :  INFO)
 
csa103CompI1: Waiting for CSI assignment...
 
Mon Jul 14 00:01:09 2008  (SCNodeI0.15234 : csa103CompEO.---.---.00035 :  INFO)
 
csa103CompI1: Waiting for CSI assignment...
 
Mon Jul 14 00:01:09 2008  (SCNodeI0.15234 : csa103CompEO.---.---.00036 :  INFO)
 
csa103CompI1: checkpoint_initialize
 
Mon Jul 14 00:01:09 2008  (SCNodeI0.15234 : csa103CompEO.---.---.00043 :  INFO)
 
csa103CompI1: Checkpoint service initialized (handle=0x1)
 
Mon Jul 14 00:01:09 2008  (SCNodeI0.15234 : csa103CompEO.---.---.00045 :  INFO)
 
csa103CompI1: Checkpoint opened (handle=0x2)
 
Mon Jul 14 00:01:09 2008  (SCNodeI0.15234 : csa103CompEO.---.---.00053 :  INFO)
 
csa103CompI1: Section created
 
  </pre></code>
 
|}
 
  
<li>Then, unlock the application by running
+
==> var/log/csa104CompI1Log.latest <==
<code><pre>
+
Fri Jan 11 14:38:45.250 2013 (SCNodeI0.3302 : csa104Comp.---.---.00007 :  INFO) CSI Flags : [Add One]
cli[Test:SCNodeI0:CPM]-> amsUnlock sg csa103SGI0
+
Fri Jan 11 14:38:45.250 2013 (SCNodeI0.3302 : csa104Comp.---.---.00008 :  INFO) CSI Name : [csa104CSII]
</pre></code>
+
Fri Jan 11 14:38:45.250 2013 (SCNodeI0.3302 : csa104Comp.---.---.00009 :  INFO) Name value pairs :
 +
Fri Jan 11 14:38:45.250 2013 (SCNodeI0.3302 : csa104Comp.---.---.00010 :  INFO) HA state : [Standby]
 +
Fri Jan 11 14:38:45.250 2013 (SCNodeI0.3302 : csa104Comp.---.---.00011 :  INFO) Standby Descriptor :
 +
Fri Jan 11 14:38:45.250 2013 (SCNodeI0.3302 : csa104Comp.---.---.00012 :  INFO) Standby Rank : [1]
 +
Fri Jan 11 14:38:45.250 2013 (SCNodeI0.3302 : csa104Comp.---.---.00013 :  INFO) Active Component : [csa104CompI0]
 +
Fri Jan 11 14:38:45.250 2013 (SCNodeI0.3302 : csa104Comp.---.---.00014 :  INFO) csa104: Standby state requested
 +
Fri Jan 11 14:38:45.250 2013 (SCNodeI0.3302 : csa104Comp.---.---.00015 :  INFO) csa104: Sending Message: Msg    1 from csa104CompI1
 +
Fri Jan 11 14:38:47.251 2013 (SCNodeI0.3302 : csa104Comp.---.---.00016 :  INFO) csa104: Sending Message: Msg    2 from csa104CompI1
  
In the application log files, you should see
+
==> var/log/csa104CompI0Log.latest <==
 +
Fri Jan 11 14:38:49.252 2013 (SCNodeI0.3301 : csa104Comp.---.---.00017 :  INFO) Received Message  : Msg    3 from csa104CompI1
  
{| cellspacing="0" cellpadding = "0" border="0" align = "center" width="680"
 
! style="color:black;background-color:#ffffaa;" align="center"| /root/asp/var/log/csa103CompI0Log.latest
 
|-
 
|<code><pre>
 
Mon Jul 14 00:09:08 2008  (SCNodeI0.15238 : csa103CompEO.---.---.00058 :  INFO)
 
  Standby state requested from state 0
 
  </pre></code>
 
|}
 
  
{| cellspacing="0" cellpadding = "0" border="0" align = "center" width="680"
+
==> var/log/csa104CompI1Log.latest <==
! style="color:black;background-color:#ffffaa;" align="center"| /root/asp/var/log/csa103CompI1Log.latest
+
Fri Jan 11 14:38:49.252 2013 (SCNodeI0.3302 : csa104Comp.---.---.00017 :  INFO) csa104: Sending Message: Msg    3 from csa104CompI1
|-
+
Fri Jan 11 14:38:51.253 2013 (SCNodeI0.3302 : csa104Comp.---.---.00018 :  INFO) csa104: Sending Message: Msg    4 from csa104CompI1
|<code><pre>
+
 
Mon Jul 14 00:09:08 2008  (SCNodeI0.15234 : csa103CompEO.---.---.00064 :  INFO)
+
==> var/log/csa104CompI0Log.latest <==
csa103CompI1: Active state requested from state 0
+
Fri Jan 11 14:38:51.253 2013 (SCNodeI0.3301 : csa104Comp.---.---.00018 :  INFO) Received Message : Msg    4 from csa104CompI1
Mon Jul 14 00:09:09 2008  (SCNodeI0.15234 : csa103CompEO.---.---.00065 :  INFO)
+
 
csa103CompI1: Hello World! (seq=0)
+
 
Mon Jul 14 00:09:10 2008  (SCNodeI0.15234 : csa103CompEO.---.---.00066 :  INFO)
+
==> var/log/csa104CompI1Log.latest <==
  csa103CompI1: Hello World! (seq=1)
+
Fri Jan 11 14:38:53.253 2013 (SCNodeI0.3302 : csa104Comp.---.---.00019 :  INFO) csa104: Sending Message: Msg    5 from csa104CompI1
Mon Jul 14 00:09:11 2008  (SCNodeI0.15234 : csa103CompEO.---.---.00067 :  INFO)
+
 
csa103CompI1: Hello World! (seq=2)
+
==> var/log/csa104CompI0Log.latest <==
Mon Jul 14 00:09:12 2008  (SCNodeI0.15234 : csa103CompEO.---.---.00068 :  INFO)
+
Fri Jan 11 14:38:53.254 2013 (SCNodeI0.3301 : csa104Comp.---.---.00019 :  INFO) Received Message : Msg    5 from csa104CompI1
  csa103CompI1: Hello World! (seq=3)
+
 
Mon Jul 14 00:09:13 2008  (SCNodeI0.15234 : csa103CompEO.---.---.00069 :  INFO)
+
 
csa103CompI1: Hello World! (seq=4)
+
==> var/log/csa104CompI1Log.latest <==
 +
Fri Jan 11 14:38:55.254 2013 (SCNodeI0.3302 : csa104Comp.---.---.00020 :  INFO) csa104: Sending Message: Msg    6 from csa104CompI1
 +
 
 +
==> var/log/csa104CompI0Log.latest <==
 +
Fri Jan 11 14:38:55.255 2013 (SCNodeI0.3301 : csa104Comp.---.---.00020 :  INFO) Received Message  : Msg    6 from csa104CompI1
 
   </pre></code>
 
   </pre></code>
 
|}  
 
|}  
  
<li>Next, find the active csa103 process, the one that's printing the Hello World lines and kill itTo find the process ID issue the following command from a bash shell.
+
The logs show the work assignment occurring with csa104CompI0 as ACTIVE and csa104CompI1 as STANDBY.  This causes the csa104CompI1 (standby) component to start sending messages and the csa104CompI0 (active) component to begin receiving them.
 +
 
 +
[[File:OpenClovis_Note.png]]Sometimes the output shows a double send, double receive or even a receive before a send!  This is an effect of the tail program polling the logs and not an actual issue.
 +
 
 +
Next, find the active csa104 process and kill it.  In this case, its the one that's receiving the messagesThe process ID is available in the log which is formmated as follows:
 +
date                        (Node    .PID  : compname.---.---.logCount : SEVERITY) Message
 +
Fri Jan 11 14:38:55.255 2013 (SCNodeI0.3301 : csa104Comp.---.---.00020 :  INFO) Received Message  : Msg    6 from csa104CompI1
 +
 
 +
So in the log above the active process is pid 3301.
 +
 
 +
While keeping the tail running, open a new window and run the kill command:
 +
 
 
<code><pre>
 
<code><pre>
# ps -eaf | grep csa103
+
# kill 3301
 
</pre></code>
 
</pre></code>
This should produce an output that looks similar to the following.
 
root    17830 15663  0 14:21 ?        00:00:00 csa103Comp -p
 
root    17839 15663  0 14:21 ?        00:00:00 csa103Comp -p
 
root    18558 16145  0 14:32 pts/4    00:00:00 grep csa103
 
Notice the two entries that end with csa103Comp -p. These are our two component processes. The first one is usually the active process. This is the one that we will kill. In this case the process ID is 17830. So to kill the active component you issue the command:
 
 
# kill -9 17830
 
  
 
[[File:OpenClovis_Note.png]]If this step does not result in the active component being killed then it is likely that the standby component was killed. In this case simply try killing the other process.  
 
[[File:OpenClovis_Note.png]]If this step does not result in the active component being killed then it is likely that the standby component was killed. In this case simply try killing the other process.  
Line 477: Line 430:
 
  |-  
 
  |-  
 
  |<code><pre>
 
  |<code><pre>
Mon Jul 14 00:16:43 2008  (SCNodeI0.15234 : csa103CompEO.---.---.00515 :  INFO)
+
root@gh-lubuntu1204:~/eval# tail -f var/log/csa104CompI?Log.latest
csa103CompI1: Hello World! (seq=452)
+
==> var/log/csa104CompI1Log.latest <==
Mon Jul 14 00:16:44 2008  (SCNodeI0.15234 : csa103CompEO.---.---.00516 :  INFO)
+
Fri Jan 11 14:43:19.398 2013 (SCNodeI0.3302 : csa104Comp.---.---.00152 :  INFO) csa104: Sending Message: Msg 138 from csa104CompI1
  csa103CompI1: Hello World! (seq=453)
+
Fri Jan 11 14:43:21.399 2013 (SCNodeI0.3302 : csa104Comp.---.---.00153 :  INFO) csa104: Sending Message: Msg 139 from csa104CompI1
Mon Jul 14 00:16:45 2008  (SCNodeI0.15234 : csa103CompEO.---.---.00517 :  INFO)
+
csa103CompI1: Hello World! (seq=454)
+
Mon Jul 14 00:16:46 2008  (SCNodeI0.15234 : csa103CompEO.---.---.00518 :  INFO)
+
  csa103CompI1: Hello World! (seq=455)
+
  </pre></code>
+
|}
+
  
{| cellspacing="0" cellpadding = "0" border="0" align = "center" width="680"
+
==> var/log/csa104CompI0Log.latest <==
! style="color:black;background-color:#ffffaa;" align="center"| /var/log/csa103CompI0Log.latest
+
Fri Jan 11 14:43:21.400 2013 (SCNodeI0.3301 : csa104Comp.---.---.00153 :  INFO) Received Message : Msg 139 from csa104CompI1
|-
+
|<code><pre>
+
Mon Jul 14 00:16:48 2008  (SCNodeI0.15238 : csa103CompEO.---.---.00065 :  INFO)
+
csa103CompI0: Active state requested from state 2
+
Mon Jul 14 00:16:48 2008  (SCNodeI0.15238 : csa103CompEO.---.---.00066 :  INFO)
+
csa103CompI0 reading checkpoint
+
Mon Jul 14 00:16:48 2008  (SCNodeI0.15238 : csa103CompEO.---.---.00067 :  INFO)
+
csa103CompI0 read checkpoint: seq = 456
+
Mon Jul 14 00:16:49 2008  (SCNodeI0.15238 : csa103CompEO.---.---.00068 :  INFO)
+
csa103CompI0: Hello World! (seq=456)
+
Mon Jul 14 00:16:50 2008  (SCNodeI0.15238 : csa103CompEO.---.---.00069 :  INFO)
+
  csa103CompI0: Hello World! (seq=457)
+
Mon Jul 14 00:16:51 2008  (SCNodeI0.15238 : csa103CompEO.---.---.00070 :  INFO)
+
  csa103CompI0: Hello World! (seq=458)
+
  </pre></code>
+
|}
+
  
Where we can see CompI1 printing 455 and then dieing, where upon CompI0 gets the notice to take over processing, reads the checkpoint and then takes over with seq=456 and so on.
 
  
Then, in the CompI1 log file we see:
+
==> var/log/csa104CompI1Log.latest <==
 +
Fri Jan 11 14:43:23.400 2013 (SCNodeI0.3302 : csa104Comp.---.---.00154 :  INFO) csa104: Sending Message: Msg  140 from csa104CompI1
  
{| cellspacing="0" cellpadding = "0" border="0" align = "center" width="680"
+
==> var/log/csa104CompI0Log.latest <==
! style="color:black;background-color:#ffffaa;" align="center"| /root/asp/var/log/csa103CompI1Log.latest
+
Fri Jan 11 14:43:23.401 2013 (SCNodeI0.3301 : csa104Comp.---.---.00154 :  INFO) Received Message : Msg 140 from csa104CompI1
|-
+
|<code><pre>
+
Mon Jul 14 00:16:49 2008  (SCNodeI0.15553 : csa103CompEO.---.---.00044 :  INFO)
+
csa103: Instantiated as component instance csa103CompI1.
+
Mon Jul 14 00:16:49 2008  (SCNodeI0.15553 : csa103CompEO.---.---.00045 :  INFO)
+
  csa103CompI1: Waiting for CSI assignment...
+
Mon Jul 14 00:16:49 2008  (SCNodeI0.15553 : csa103CompEO.---.---.00046 :  INFO)
+
  csa103CompI1: Waiting for CSI assignment...
+
Mon Jul 14 00:16:49 2008  (SCNodeI0.15553 : csa103CompEO.---.---.00047 :  INFO)
+
csa103CompI1: checkpoint_initialize
+
Mon Jul 14 00:16:50 2008  (SCNodeI0.15553 : csa103CompEO.---.---.00054 :  INFO)
+
csa103CompI1: Checkpoint service initialized (handle=0x1)
+
Mon Jul 14 00:16:50 2008  (SCNodeI0.15553 : csa103CompEO.---.---.00056 :  INFO)
+
csa103CompI1: Checkpoint opened (handle=0x2)
+
  </pre></code>
+
|}
+
  
That is the component that had been killed being restarted.
+
Fri Jan 11 14:43:25.158 2013 (SCNodeI0.4069 : csa104Comp.---.---.00001 :  INFO) Component [csa104CompI0] : PID [4069]. Initializing
  
CompI0 is moving along just fine, and we see CompI1 come back up. If we then kill CompI0 we see:
+
Fri Jan 11 14:43:25.158 2013 (SCNodeI0.4069 : csa104Comp.---.---.00002 :  INFO)    IOC Address            : 0x1
  
{| cellspacing="0" cellpadding = "0" border="0" align = "center" width="680"
+
Fri Jan 11 14:43:25.158 2013 (SCNodeI0.4069 : csa104Comp.---.---.00003 :  INFO)   IOC Port                : 0x89
! style="color:black;background-color:#ffffaa;" align="center"| /root/asp/var/log/csa103CompI1Log.latest
+
|-
+
|<code><pre>
+
Mon Jul 14 00:29:44 2008  (SCNodeI0.15553 : csa103CompEO.---.---.00065 :  INFO)
+
csa103CompI1: Active state requested from state 2
+
Mon Jul 14 00:29:44 2008  (SCNodeI0.15553 : csa103CompEO.---.---.00066 :  INFO)
+
csa103CompI1 reading checkpoint
+
Mon Jul 14 00:29:44 2008  (SCNodeI0.15553 : csa103CompEO.---.---.00067 :  INFO)
+
csa103CompI1 read checkpoint: seq = 1225
+
Mon Jul 14 00:29:45 2008  (SCNodeI0.15553 : csa103CompEO.---.---.00068 :  INFO)
+
csa103CompI1: Hello World! (seq=1225)
+
Mon Jul 14 00:29:46 2008  (SCNodeI0.15553 : csa103CompEO.---.---.00069 :  INFO)
+
csa103CompI1: Hello World! (seq=1226)
+
  </pre></code>
+
|}
+
  
Where we can see the CompI0 process die, and CompI1 process read the sequence number from the checkpoint and then take over from where CompI0 left off.
+
Fri Jan 11 14:43:25.159 2013 (SCNodeI0.4069 : csa104Comp.---.---.00004 :  INFO) csa102: Instantiated as component instance csa104CompI0.
 +
Fri Jan 11 14:43:25.159 2013 (SCNodeI0.4069 : csa104Comp.---.---.00005 :  INFO) csa104CompI0: Waiting for CSI assignment...
 +
Fri Jan 11 14:43:25.159 2013 (SCNodeI0.4069 : csa104Comp.---.---.00006 :  INFO) Component [csa104CompI0] : PID [4069]. CSI Set Received
  
<li>To stop csa103 use the following SAFplus Platform Console command.
+
Fri Jan 11 14:43:25.159 2013 (SCNodeI0.4069 : csa104Comp.---.---.00007 :  INFO) CSI Flags : [Add One]
<code><pre>
+
Fri Jan 11 14:43:25.159 2013 (SCNodeI0.4069 : csa104Comp.---.---.00008 :  INFO) CSI Name : [csa104CSII]
cli[Test:SCNodeI0:CPM]-> amsLockAssignment sg csa103SGI0
+
Fri Jan 11 14:43:25.159 2013 (SCNodeI0.4069 : csa104Comp.---.---.00009 :  INFO) HA state : [Active]
</pre></code>
+
Fri Jan 11 14:43:25.159 2013 (SCNodeI0.4069 : csa104Comp.---.---.00010 :  INFO) Active Descriptor :
 +
Fri Jan 11 14:43:25.159 2013 (SCNodeI0.4069 : csa104Comp.---.---.00011 :  INFO) Transition Descriptor : [1]
 +
Fri Jan 11 14:43:25.159 2013 (SCNodeI0.4069 : csa104Comp.---.---.00012 :  INFO) Active Component : [csa104CompI0]
 +
Fri Jan 11 14:43:25.159 2013 (SCNodeI0.4069 : csa104Comp.---.---.00013 :  INFO) csa104: ACTIVE state requested; activating message queue receiver service
  
<li>Now change the state of csa103SGI0 to LockInstantiation and close the SAFplus Platform Console.
+
==> var/log/csa104CompI1Log.latest <==
<code><pre>
+
Fri Jan 11 14:43:25.401 2013 (SCNodeI0.3302 : csa104Comp.---.---.00155 :  INFO) csa104: Sending Message: Msg  141 from csa104CompI1
cli[Test:SCNodeI0:CPM]-> amsLockInstantiation sg csa103SGI0
+
 
cli[Test:SCNodeI0:CPM] -> end
+
==> var/log/csa104CompI0Log.latest <==
cli[Test:SCNodeI0] -> end
+
Fri Jan 11 14:43:25.401 2013 (SCNodeI0.4069 : csa104Comp.---.---.00014 :  INFO) Received Message  : Msg  141 from csa104CompI1
cli[Test] -> bye
+
 
</pre></code>
+
Fri Jan 11 14:43:27.403 2013 (SCNodeI0.4069 : csa104Comp.---.---.00015 :  INFO) Received Message  : Msg  142 from csa104CompI1
</ol>
+
 
 +
 
 +
==> var/log/csa104CompI1Log.latest <==
 +
Fri Jan 11 14:43:27.403 2013 (SCNodeI0.3302 : csa104Comp.---.---.00156 :  INFO) csa104: Sending Message: Msg  142 from csa104CompI1
 +
 
 +
 
 +
  </pre></code>
 +
|}
  
 
===csa203===
 
===csa203===

Revision as of 19:49, 11 January 2013

Contents

csa104 Messaging

Messaging refers to communications between components within the cluster. SAFplus provides a SA-Forum compliant implementation of the messaging service. In one sentence, the messaging service is a reliable packet based communications mechanism which stores and addresses endpoints via cluster-wide message queues that are identified by a well-known name and can be bound to any running process. For more details and API reference please see the SA-Forum spec SA-AIS-MSG-B*.pdf.

Objective

csa104 demonstrates the use of the SAFplus Messaging service to provide basic communications during process and node failure.

What Will You Learn

  • how to initialize the messaging client library,
  • how to create a message queue.
  • how to send messages to the queue.
  • how to receive messages from the queue.
  • how to take over the message queue after process failure.

The Code

The code can be found within the following directory:

<SAFplus_installation_dir>/src/examples/eval/src/app/csa104Comp

All messaging code has been isolated into a single module that consists of 2 files: msgFns.c and msgFns.h to increase readability. These files provide the following APIs.


msgFns.h
void        msgInitialize(void);
SaAisErrorT msgOpen(const char* queuename,int bytesPerPriority);
SaAisErrorT msgSend(const char* queuename, void* buffer, int length);
void*       msgReceiverLoop(void * notused);
  

These APIs constitute the basic operations of any messaging library; initialize, open, send and receive.

The following constants are also defined:


msgFns.h
#define ACTIVE_COMP_QUEUE "csa104msgqueue"
#define QUEUE_LENGTH 2048
  

The ACTIVE_COMP_QUEUE defines the well-known name of the messaging queue which will be used in this example. The QUEUE_LENGTH defines the maximum size of the buffer allocated for each priority within a particular queue. There are 4 possible message priorities and the maximum buffer size can be set on a per priority basis.


Initialization

Initialization follows the standard SA Forum library lifecycle pattern:

msgFns.c
void msgInitialize(void)
{
    SaAisErrorT             Rc;
    SaMsgCallbacksT         MsgCallbacks = {
                                .saMsgQueueOpenCallback           = (SaMsgQueueOpenCallbackT) 0,
                                .saMsgQueueGroupTrackCallback     = (SaMsgQueueGroupTrackCallbackT) 0,
                                .saMsgMessageDeliveredCallback    = (SaMsgMessageDeliveredCallbackT) 0,
                                .saMsgMessageReceivedCallback     = (SaMsgMessageReceivedCallbackT) 0,
                            };
    SaVersionT              Version = {
                                .majorVersion = 1,
                                .minorVersion = 1,
                                .releaseCode  = 'B',
                            };

	Rc = saMsgInitialize (&msgLibraryHandle, &MsgCallbacks, &Version);
	if ( SA_AIS_OK != Rc)
    {
		clprintf ( CL_LOG_SEV_ERROR, "Init failed [0x%X]", Rc);
        assert(0);
    }
}
  

The messaging library supports either a callback or threaded paradigm. In this example, we will use threading so no callbacks are installed and therefore it is not necessary to periodically call saMsgDispatch(...).

To receive messages from the queue, the application must first open it. The open essentially binds the well-known name to the application process so that senders know where to direct messages. By providing an explicit bind operation (rather then folding it into the library initialize) the API allows the application to choose when it takes ownership of the queue; this could be when it becomes active (or standby) for example, allowing senders to address messages to a single well-known queue name if they need to communicate with the active component.

Designing addresses that represent a concept such as "The currently active transaction server" rather then a physical entity is an extremely powerful design pattern used throughout highly available applications because it means that the sender does not need to access the real-time cluster state to determine this mapping and does not need to handle errors caused by application failure (except perhaps with a simple retry-on-error loop).

msgFns.c
SaAisErrorT msgOpen(const char* queuename,int bytesPerPriority)
{
    SaAisErrorT             rc;
    SaNameT                 saQueueName;
    SaMsgQueueCreationAttributesT   CreationAttributes;
    
    saQueueName.length=strlen(queuename);
    memcpy(saQueueName.value,queuename,saQueueName.length+1);

    SaMsgQueueOpenFlagsT    OpenFlags = SA_MSG_QUEUE_CREATE;
    
    CreationAttributes.creationFlags = 0;
    for (int i=0;i<SA_MSG_MESSAGE_LOWEST_PRIORITY;i++)
        CreationAttributes.size[i] = bytesPerPriority;
    CreationAttributes.retentionTime = 0;

    rc = saMsgQueueOpen (msgLibraryHandle, &saQueueName, & CreationAttributes, OpenFlags, SA_TIME_MAX, &msgQueueHandle);
    if (SA_AIS_OK != rc)
    {
		clprintf ( CL_LOG_SEV_ERROR, "Msg QueueOpen failed [0x%X]\n\r", rc);
    }
    return rc;
 }
  


Transmission

Message transmission uses the saMsgMessageSend API which allows the application to pass a message buffer and a bunch of meta-data (such as message version, sender's name, etc) that will be sent to the receiver:

msgFns.c
SaAisErrorT msgSend(const char* queuename, void* buffer, int length)
{
    SaAisErrorT             rc;
    SaNameT                 saQueueName;
    SaMsgMessageT           message;

    /* Load the SAF string */
    saQueueName.length=strlen(queuename);
    memcpy(saQueueName.value,queuename,saQueueName.length+1);

    /* Load the SAF message structure */
    message.type = 0;
    message.version.releaseCode = 0;
    message.version.majorVersion=0;
    message.version.minorVersion=0;
    message.senderName = 0;  /* You could put a SaNameT* in here if you wanted to pass a reply queue (for example) */
    message.size = length;
    message.data = buffer;
    message.priority = SA_MSG_MESSAGE_HIGHEST_PRIORITY;
    rc = saMsgMessageSend (msgLibraryHandle, &saQueueName, &message, SA_TIME_MAX);
    if (SA_AIS_OK != rc)
    {
        /* Error 0xC here means that the queue has not yet been created.
         That is, the receiver is not yet listening. */
		clprintf ( CL_LOG_SEV_ERROR, "Msg saMsgMessageSend to queue [%s] failed [0x%X]", saQueueName.value,rc );
    }
    return rc;
}
 

For simplicity, this example creates the destination SaNameT and the SaMsgMessageT structures each time a message is sent. However, for efficiency when sending multiple messages to the same destination it is preferred to pre-create and reuse these objects.

Receipt

This example will create a dedicated message receiver thread and run the following code within that thread:

msgFns.c
void* msgReceiverLoop(void * notused)
{
    SaAisErrorT             rc;
    SaNameT                 SenderName;
    char                    Data[1024];
    SaMsgSenderIdT          SenderId;
    SaTimeT                 SendTime;
    
    while(1)
    {
        
        SaMsgMessageT           message = {
            .size       = 1024,
            .senderName = &SenderName,
            .data       = Data,
        };
    
        rc = saMsgMessageGet (msgQueueHandle, &message, & SendTime, & SenderId, SA_TIME_MAX);
        if (SA_AIS_OK != rc)
        {
            clprintf ( CL_LOG_SEV_ERROR, "Msg saMsgMessageGet failed [0x%X]\n\r", rc );
            break;
        }
        
        if (message.senderName->length)
        {
            clprintf ( CL_LOG_SEV_INFO, "Sender Name   : %s\n", message.senderName->value);
        }
        clprintf ( CL_LOG_SEV_INFO, "Received Message  : %s\n", (char *)message.data);
        
    }
    
    rc = saMsgQueueClose (msgQueueHandle);
    if (SA_AIS_OK != rc)
    {
		clprintf ( CL_LOG_SEV_ERROR, "Msg Queue Close failed [0x%X]\n\r", rc );
    }
    return 0;
 
}

This code simply loops "forever" receiving messages and printing the contents of the message. If anything goes wrong it kicks itself out of the message processing loop and closes the message queue. Closing the queue will allow some other application to open it, in effect "taking over" the queue. If an application is killed or disappears due to node death (or other events) the AMF will close all queues opened by the application. This allow the new active application to take control of the queue.


Putting it all Together

These functions are called from the application's clCompAppMain.c file to implement an application that periodically sends a message from the standby to the active application. First we define a helper function that will repeatedly send messages. This function will loop so long as the application is standby, as indicated by a global variable "standby" that is set in the work assignment callback.

clCompAppMain.c
void* senderLoop(void* p)
{
    int count =0;
    char msg[100];
    while (standby)
    {
        count++;
        snprintf(msg,99,"Msg %4d from %.*s",count,appName.length,appName.value);
        
        clprintf(CL_LOG_SEV_INFO,"csa104: Sending Message: %s",msg);
        msgSend(ACTIVE_COMP_QUEUE,msg,strlen(msg)+1);
        sleep(2);
    }
    return NULL;
}
  

Next, we initialize the messaging library from main():

clCompAppMain.c
...
    /*
     * Now register the component with AMF. At this point it is
     * ready to provide service, i.e. take work assignments.
     */

    if ( (rc = saAmfComponentNameGet(amfHandle, &appName)) != SA_AIS_OK) 
        goto errorexit;
    if ( (rc = saAmfComponentRegister(amfHandle, &appName, NULL)) != SA_AIS_OK) 
        goto errorexit;

    /*
     * Initialize the log stream
     */
    clEvalAppLogStreamOpen((ClCharT*)appName.value, &gEvalLogStream);

    msgInitialize();
    
    /*
     * Print out standard information for this component.
     */

    clEoMyEoIocPortGet(&iocPort);
...
  


In the work assignment callback, we open the queue and spawn the message receiver thread when an active assignment is received, and spawn a message sender thread when a standby assignment is received.

clCompAppMain.c
void clCompAppAMFCSISet(SaInvocationT       invocation,
                        const SaNameT       *compName,
                        SaAmfHAStateT       haState,
                        SaAmfCSIDescriptorT csiDescriptor)
{
    /*
     * Print information about the CSI Set
     */

    clprintf (CL_LOG_SEV_INFO, "Component [%.*s] : PID [%d]. CSI Set Received\n", 
              compName->length, compName->value, mypid);

    clCompAppAMFPrintCSI(csiDescriptor, haState);

    /*
     * Take appropriate action based on state
     */

    switch ( haState )
    {
        case SA_AMF_HA_ACTIVE:
        {
            /*
             * AMF has requested application to take the active HA state 
             * for the CSI.
             */
            pthread_t thr;
            
            clprintf(CL_LOG_SEV_INFO,"csa104: ACTIVE state requested; activating message queue receiver service");
            running = 1;
            msgOpen(ACTIVE_COMP_QUEUE,QUEUE_LENGTH);
            pthread_create(&thr,NULL,msgReceiverLoop,NULL);
            
            saAmfResponse(amfHandle, invocation, SA_AIS_OK);
            break;
        }

        case SA_AMF_HA_STANDBY:
        {
            /*
             * AMF has requested application to take the standby HA state 
             * for this CSI.
             */
            pthread_t thr;
            clprintf(CL_LOG_SEV_INFO,"csa104: Standby state requested");
            running = 0;
            standby = 1;
            pthread_create(&thr,NULL,senderLoop,NULL);

            saAmfResponse(amfHandle, invocation, SA_AIS_OK);
            break;
        }
...
  

How to Run csa104 and What to Observe

This sample application runs 2 processes on SCNodeI0 (first system controller) in all the hardware setups described at the beginning of this eval guide. While it is certainly possible to run messaging across multiple nodes, this single node configuration makes evaluation simpler.

csa104 is "enabled" by default when SAFplus is started so there is no need to enter the SAFplus Debug Console and change its program state.


The following output is given when you run tail -f on the csa104 log files. For example:

# ./eval start
# tail -f var/log/csa104CompI?Log.latest
/root/asp/var/log/csa103CompI?Log.latest
==> var/log/csa104CompI0Log.latest <==
Fri Jan 11 14:38:45.215 2013 (SCNodeI0.3301 : csa104Comp.---.---.00009 :   INFO) Name value pairs :
Fri Jan 11 14:38:45.215 2013 (SCNodeI0.3301 : csa104Comp.---.---.00010 :   INFO) HA state : [Active]
Fri Jan 11 14:38:45.215 2013 (SCNodeI0.3301 : csa104Comp.---.---.00011 :   INFO) Active Descriptor :
Fri Jan 11 14:38:45.215 2013 (SCNodeI0.3301 : csa104Comp.---.---.00012 :   INFO) Transition Descriptor : [1]
Fri Jan 11 14:38:45.215 2013 (SCNodeI0.3301 : csa104Comp.---.---.00013 :   INFO) Active Component : [csa104CompI0]
Fri Jan 11 14:38:45.215 2013 (SCNodeI0.3301 : csa104Comp.---.---.00014 :   INFO) csa104: ACTIVE state requested; activating message queue receiver service
Fri Jan 11 14:38:45.250 2013 (SCNodeI0.3301 : csa104Comp.---.---.00015 :   INFO) Received Message  : Msg    1 from csa104CompI1

Fri Jan 11 14:38:47.251 2013 (SCNodeI0.3301 : csa104Comp.---.---.00016 :   INFO) Received Message  : Msg    2 from csa104CompI1


==> var/log/csa104CompI1Log.latest <==
Fri Jan 11 14:38:45.250 2013 (SCNodeI0.3302 : csa104Comp.---.---.00007 :   INFO) CSI Flags : [Add One]
Fri Jan 11 14:38:45.250 2013 (SCNodeI0.3302 : csa104Comp.---.---.00008 :   INFO) CSI Name : [csa104CSII]
Fri Jan 11 14:38:45.250 2013 (SCNodeI0.3302 : csa104Comp.---.---.00009 :   INFO) Name value pairs :
Fri Jan 11 14:38:45.250 2013 (SCNodeI0.3302 : csa104Comp.---.---.00010 :   INFO) HA state : [Standby]
Fri Jan 11 14:38:45.250 2013 (SCNodeI0.3302 : csa104Comp.---.---.00011 :   INFO) Standby Descriptor :
Fri Jan 11 14:38:45.250 2013 (SCNodeI0.3302 : csa104Comp.---.---.00012 :   INFO) Standby Rank : [1]
Fri Jan 11 14:38:45.250 2013 (SCNodeI0.3302 : csa104Comp.---.---.00013 :   INFO) Active Component : [csa104CompI0]
Fri Jan 11 14:38:45.250 2013 (SCNodeI0.3302 : csa104Comp.---.---.00014 :   INFO) csa104: Standby state requested
Fri Jan 11 14:38:45.250 2013 (SCNodeI0.3302 : csa104Comp.---.---.00015 :   INFO) csa104: Sending Message: Msg    1 from csa104CompI1
Fri Jan 11 14:38:47.251 2013 (SCNodeI0.3302 : csa104Comp.---.---.00016 :   INFO) csa104: Sending Message: Msg    2 from csa104CompI1

==> var/log/csa104CompI0Log.latest <==
Fri Jan 11 14:38:49.252 2013 (SCNodeI0.3301 : csa104Comp.---.---.00017 :   INFO) Received Message  : Msg    3 from csa104CompI1


==> var/log/csa104CompI1Log.latest <==
Fri Jan 11 14:38:49.252 2013 (SCNodeI0.3302 : csa104Comp.---.---.00017 :   INFO) csa104: Sending Message: Msg    3 from csa104CompI1
Fri Jan 11 14:38:51.253 2013 (SCNodeI0.3302 : csa104Comp.---.---.00018 :   INFO) csa104: Sending Message: Msg    4 from csa104CompI1

==> var/log/csa104CompI0Log.latest <==
Fri Jan 11 14:38:51.253 2013 (SCNodeI0.3301 : csa104Comp.---.---.00018 :   INFO) Received Message  : Msg    4 from csa104CompI1


==> var/log/csa104CompI1Log.latest <==
Fri Jan 11 14:38:53.253 2013 (SCNodeI0.3302 : csa104Comp.---.---.00019 :   INFO) csa104: Sending Message: Msg    5 from csa104CompI1

==> var/log/csa104CompI0Log.latest <==
Fri Jan 11 14:38:53.254 2013 (SCNodeI0.3301 : csa104Comp.---.---.00019 :   INFO) Received Message  : Msg    5 from csa104CompI1


==> var/log/csa104CompI1Log.latest <==
Fri Jan 11 14:38:55.254 2013 (SCNodeI0.3302 : csa104Comp.---.---.00020 :   INFO) csa104: Sending Message: Msg    6 from csa104CompI1

==> var/log/csa104CompI0Log.latest <==
Fri Jan 11 14:38:55.255 2013 (SCNodeI0.3301 : csa104Comp.---.---.00020 :   INFO) Received Message  : Msg    6 from csa104CompI1
  

The logs show the work assignment occurring with csa104CompI0 as ACTIVE and csa104CompI1 as STANDBY. This causes the csa104CompI1 (standby) component to start sending messages and the csa104CompI0 (active) component to begin receiving them.

OpenClovis Note.pngSometimes the output shows a double send, double receive or even a receive before a send! This is an effect of the tail program polling the logs and not an actual issue.

Next, find the active csa104 process and kill it. In this case, its the one that's receiving the messages. The process ID is available in the log which is formmated as follows:

date                         (Node    .PID  : compname.---.---.logCount : SEVERITY) Message
Fri Jan 11 14:38:55.255 2013 (SCNodeI0.3301 : csa104Comp.---.---.00020 :   INFO) Received Message  : Msg    6 from csa104CompI1

So in the log above the active process is pid 3301.

While keeping the tail running, open a new window and run the kill command:

# kill 3301

OpenClovis Note.pngIf this step does not result in the active component being killed then it is likely that the standby component was killed. In this case simply try killing the other process.

After killing the active component you should see lines in the log files like the following:

/root/asp/var/log/csa103CompI1Log.latest
root@gh-lubuntu1204:~/eval# tail -f var/log/csa104CompI?Log.latest
==> var/log/csa104CompI1Log.latest <==
Fri Jan 11 14:43:19.398 2013 (SCNodeI0.3302 : csa104Comp.---.---.00152 :   INFO) csa104: Sending Message: Msg  138 from csa104CompI1
Fri Jan 11 14:43:21.399 2013 (SCNodeI0.3302 : csa104Comp.---.---.00153 :   INFO) csa104: Sending Message: Msg  139 from csa104CompI1

==> var/log/csa104CompI0Log.latest <==
Fri Jan 11 14:43:21.400 2013 (SCNodeI0.3301 : csa104Comp.---.---.00153 :   INFO) Received Message  : Msg  139 from csa104CompI1


==> var/log/csa104CompI1Log.latest <==
Fri Jan 11 14:43:23.400 2013 (SCNodeI0.3302 : csa104Comp.---.---.00154 :   INFO) csa104: Sending Message: Msg  140 from csa104CompI1

==> var/log/csa104CompI0Log.latest <==
Fri Jan 11 14:43:23.401 2013 (SCNodeI0.3301 : csa104Comp.---.---.00154 :   INFO) Received Message  : Msg  140 from csa104CompI1

Fri Jan 11 14:43:25.158 2013 (SCNodeI0.4069 : csa104Comp.---.---.00001 :   INFO) Component [csa104CompI0] : PID [4069]. Initializing

Fri Jan 11 14:43:25.158 2013 (SCNodeI0.4069 : csa104Comp.---.---.00002 :   INFO)    IOC Address             : 0x1

Fri Jan 11 14:43:25.158 2013 (SCNodeI0.4069 : csa104Comp.---.---.00003 :   INFO)    IOC Port                : 0x89

Fri Jan 11 14:43:25.159 2013 (SCNodeI0.4069 : csa104Comp.---.---.00004 :   INFO) csa102: Instantiated as component instance csa104CompI0.
Fri Jan 11 14:43:25.159 2013 (SCNodeI0.4069 : csa104Comp.---.---.00005 :   INFO) csa104CompI0: Waiting for CSI assignment...
Fri Jan 11 14:43:25.159 2013 (SCNodeI0.4069 : csa104Comp.---.---.00006 :   INFO) Component [csa104CompI0] : PID [4069]. CSI Set Received

Fri Jan 11 14:43:25.159 2013 (SCNodeI0.4069 : csa104Comp.---.---.00007 :   INFO) CSI Flags : [Add One]
Fri Jan 11 14:43:25.159 2013 (SCNodeI0.4069 : csa104Comp.---.---.00008 :   INFO) CSI Name : [csa104CSII]
Fri Jan 11 14:43:25.159 2013 (SCNodeI0.4069 : csa104Comp.---.---.00009 :   INFO) HA state : [Active]
Fri Jan 11 14:43:25.159 2013 (SCNodeI0.4069 : csa104Comp.---.---.00010 :   INFO) Active Descriptor :
Fri Jan 11 14:43:25.159 2013 (SCNodeI0.4069 : csa104Comp.---.---.00011 :   INFO) Transition Descriptor : [1]
Fri Jan 11 14:43:25.159 2013 (SCNodeI0.4069 : csa104Comp.---.---.00012 :   INFO) Active Component : [csa104CompI0]
Fri Jan 11 14:43:25.159 2013 (SCNodeI0.4069 : csa104Comp.---.---.00013 :   INFO) csa104: ACTIVE state requested; activating message queue receiver service

==> var/log/csa104CompI1Log.latest <==
Fri Jan 11 14:43:25.401 2013 (SCNodeI0.3302 : csa104Comp.---.---.00155 :   INFO) csa104: Sending Message: Msg  141 from csa104CompI1

==> var/log/csa104CompI0Log.latest <==
Fri Jan 11 14:43:25.401 2013 (SCNodeI0.4069 : csa104Comp.---.---.00014 :   INFO) Received Message  : Msg  141 from csa104CompI1

Fri Jan 11 14:43:27.403 2013 (SCNodeI0.4069 : csa104Comp.---.---.00015 :   INFO) Received Message  : Msg  142 from csa104CompI1


==> var/log/csa104CompI1Log.latest <==
Fri Jan 11 14:43:27.403 2013 (SCNodeI0.3302 : csa104Comp.---.---.00156 :   INFO) csa104: Sending Message: Msg  142 from csa104CompI1


  

csa203

csa203 demonstrates the usage of SA Forum's Checkpointing service. This sample application does not deviate functionally from csa103. The code differences are due to using SA Forum data types (structures) and APIs , as presented in the following two tables. (Note we have not repeated data types and APIs covered previously.)

SA Forum Data Types with the SAFplus Platform equivalent
SA Forum Data Types OpenClovis Data Types
SaCkptHandleT ClCkptSvcHdlT
SaCkptHandleT ClCkptHdlT
SaCkptSectionIdT ClCkptSectionIdT
SaCkptCheckpointCreationAttributesT ClCkptCheckpointCreationAttributesT
SaCkptSectionCreationAttributesT ClCkptSectionCreationAttributesT
SaCkptIOVectorElementT ClCkptIOVectorElementT



SA Forum APIs with the SAFplus Platform equivalent
SA Forum APIs OpenClovis APIs
saCkptInitialize clCkptInitialize
saCkptCheckpointOpen clCkptCheckpointOpen
saCkptSectionCreate clCkptSectionCreate
saCkptCheckpointClose clCkptCheckpointClose
saCkptFinalize clCkptFinalize
saCkptSectionOverwrite clCkptSectionOverwrite
saCkptCheckpointSynchronize clCkptCheckpointSynchronize
saCkptCheckpointRead clCkptCheckpointRead


How to Run csa103 and What to Observe

This sample application can run on all Runtime Hardware Setups. The following, lists which node csa103compI* runs on.

  • Runtime Hardware Setup 1.1 and 2.1
    csa103compI0 and csa103compI1 will run upon the single node.
  • Runtime Hardware Setup 1.2 and 2.2
    csa103compI0 runs on PayloadNodeI0 and csa103compI1 runs on PayloadNodeI1
  • Runtime Hardware Setup 1.3 and 2.3
    csa103compI2 and csa103compI3 run on SCNodeI0 and SCNodeI1 respectively. csa103compI0 and csa103compI1 run on PayloadNodeI0 and PayloadNodeI1 respectively.

    In the four node set up SCNodeI0 and SCNodeI1 output data via /root/asp/var/log/csa103CompI2 and /root/asp/var/log/csa103CompI3 respectively. Therefore in this case follow the below instructions replacing csa103CompI0 and csa103compI1 with csa103compI2 and csa103compI3 respectively.

We run csa103 very much the same way we run any of the rest of the sample applications: with the SAFplus Platform Console.

  1. First, on the active System Controller move it to state LockAssignment with (Unlock csa203SGI0 instead of csa103SGI0 to run csa203)
    cli[Test]-> setc 1
    cli[Test:SCNodeI0]-> setc cpm
    cli[Test:SCNodeI0:CPM]-> amsLockAssignment sg csa103SGI0
    

    The following output is given when you run tail -f on the csa103 log files. For example:

    # tail -f /root/asp/var/log/csa103CompI0.log
    
    /root/asp/var/log/csa103CompI0Log.latest
    Mon Jul 14 00:01:09 2008   (SCNodeI0.15238 : csa103CompEO.---.---.00030 :   INFO)
     Component [csa103CompI0] : PID [15238]. Initializing
    Mon Jul 14 00:01:09 2008   (SCNodeI0.15238 : csa103CompEO.---.---.00031 :   INFO)
        IOC Address             : 0x1
    Mon Jul 14 00:01:09 2008   (SCNodeI0.15238 : csa103CompEO.---.---.00032 :   INFO)
        IOC Port                : 0x81
    Mon Jul 14 00:01:09 2008   (SCNodeI0.15238 : csa103CompEO.---.---.00033 :   INFO)
     csa103: Instantiated as component instance csa103CompI0.
    Mon Jul 14 00:01:09 2008   (SCNodeI0.15238 : csa103CompEO.---.---.00034 :   INFO)
     csa103CompI0: Waiting for CSI assignment...
    Mon Jul 14 00:01:09 2008   (SCNodeI0.15238 : csa103CompEO.---.---.00035 :   INFO)
     csa103CompI0: Waiting for CSI assignment...
    Mon Jul 14 00:01:09 2008   (SCNodeI0.15238 : csa103CompEO.---.---.00036 :   INFO)
     csa103CompI0: checkpoint_initialize
    Mon Jul 14 00:01:10 2008   (SCNodeI0.15238 : csa103CompEO.---.---.00043 :   INFO)
     csa103CompI0: Checkpoint service initialized (handle=0x1)
    Mon Jul 14 00:01:10 2008   (SCNodeI0.15238 : csa103CompEO.---.---.00045 :   INFO)
     csa103CompI0: Checkpoint opened (handle=0x2)
      
    # tail -f /root/asp/var/log/csa103CompI1.log
    
    /root/asp/var/log/csa103CompI1Log.latest
    Mon Jul 14 00:01:09 2008   (SCNodeI0.15234 : csa103CompEO.---.---.00030 :   INFO)
     Component [csa103CompI1] : PID [15234]. Initializing
    Mon Jul 14 00:01:09 2008   (SCNodeI0.15234 : csa103CompEO.---.---.00031 :   INFO)
        IOC Address             : 0x1
    Mon Jul 14 00:01:09 2008   (SCNodeI0.15234 : csa103CompEO.---.---.00032 :   INFO)
        IOC Port                : 0x80
    Mon Jul 14 00:01:09 2008   (SCNodeI0.15234 : csa103CompEO.---.---.00033 :   INFO)
     csa103: Instantiated as component instance csa103CompI1.
    Mon Jul 14 00:01:09 2008   (SCNodeI0.15234 : csa103CompEO.---.---.00034 :   INFO)
     csa103CompI1: Waiting for CSI assignment...
    Mon Jul 14 00:01:09 2008   (SCNodeI0.15234 : csa103CompEO.---.---.00035 :   INFO)
     csa103CompI1: Waiting for CSI assignment...
    Mon Jul 14 00:01:09 2008   (SCNodeI0.15234 : csa103CompEO.---.---.00036 :   INFO)
     csa103CompI1: checkpoint_initialize
    Mon Jul 14 00:01:09 2008   (SCNodeI0.15234 : csa103CompEO.---.---.00043 :   INFO)
     csa103CompI1: Checkpoint service initialized (handle=0x1)
    Mon Jul 14 00:01:09 2008   (SCNodeI0.15234 : csa103CompEO.---.---.00045 :   INFO)
     csa103CompI1: Checkpoint opened (handle=0x2)
    Mon Jul 14 00:01:09 2008   (SCNodeI0.15234 : csa103CompEO.---.---.00053 :   INFO)
     csa103CompI1: Section created
      
  2. Then, unlock the application by running
    cli[Test:SCNodeI0:CPM]-> amsUnlock sg csa103SGI0
    

    In the application log files, you should see

    /root/asp/var/log/csa103CompI0Log.latest
    Mon Jul 14 00:09:08 2008   (SCNodeI0.15238 : csa103CompEO.---.---.00058 :   INFO)
      Standby state requested from state 0
      
    /root/asp/var/log/csa103CompI1Log.latest
    Mon Jul 14 00:09:08 2008   (SCNodeI0.15234 : csa103CompEO.---.---.00064 :   INFO)
     csa103CompI1: Active state requested from state 0
    Mon Jul 14 00:09:09 2008   (SCNodeI0.15234 : csa103CompEO.---.---.00065 :   INFO)
     csa103CompI1: Hello World! (seq=0)
    Mon Jul 14 00:09:10 2008   (SCNodeI0.15234 : csa103CompEO.---.---.00066 :   INFO)
     csa103CompI1: Hello World! (seq=1)
    Mon Jul 14 00:09:11 2008   (SCNodeI0.15234 : csa103CompEO.---.---.00067 :   INFO)
     csa103CompI1: Hello World! (seq=2)
    Mon Jul 14 00:09:12 2008   (SCNodeI0.15234 : csa103CompEO.---.---.00068 :   INFO)
     csa103CompI1: Hello World! (seq=3)
    Mon Jul 14 00:09:13 2008   (SCNodeI0.15234 : csa103CompEO.---.---.00069 :   INFO)
     csa103CompI1: Hello World! (seq=4)
      
  3. Next, find the active csa103 process, the one that's printing the Hello World lines and kill it. To find the process ID issue the following command from a bash shell.
     # ps -eaf | grep csa103
    

    This should produce an output that looks similar to the following.

    root     17830 15663  0 14:21 ?        00:00:00 csa103Comp -p
    root     17839 15663  0 14:21 ?        00:00:00 csa103Comp -p
    root     18558 16145  0 14:32 pts/4    00:00:00 grep csa103
    

    Notice the two entries that end with csa103Comp -p. These are our two component processes. The first one is usually the active process. This is the one that we will kill. In this case the process ID is 17830. So to kill the active component you issue the command:

    # kill -9 17830
    

    OpenClovis Note.pngIf this step does not result in the active component being killed then it is likely that the standby component was killed. In this case simply try killing the other process.

    After killing the active component you should see lines in the log files like the following:

    /root/asp/var/log/csa103CompI1Log.latest
    Mon Jul 14 00:16:43 2008   (SCNodeI0.15234 : csa103CompEO.---.---.00515 :   INFO)
     csa103CompI1: Hello World! (seq=452)
    Mon Jul 14 00:16:44 2008   (SCNodeI0.15234 : csa103CompEO.---.---.00516 :   INFO)
     csa103CompI1: Hello World! (seq=453)
    Mon Jul 14 00:16:45 2008   (SCNodeI0.15234 : csa103CompEO.---.---.00517 :   INFO)
     csa103CompI1: Hello World! (seq=454)
    Mon Jul 14 00:16:46 2008   (SCNodeI0.15234 : csa103CompEO.---.---.00518 :   INFO)
     csa103CompI1: Hello World! (seq=455)
      
    /var/log/csa103CompI0Log.latest
    Mon Jul 14 00:16:48 2008   (SCNodeI0.15238 : csa103CompEO.---.---.00065 :   INFO)
     csa103CompI0: Active state requested from state 2
    Mon Jul 14 00:16:48 2008   (SCNodeI0.15238 : csa103CompEO.---.---.00066 :   INFO)
     csa103CompI0 reading checkpoint
    Mon Jul 14 00:16:48 2008   (SCNodeI0.15238 : csa103CompEO.---.---.00067 :   INFO)
     csa103CompI0 read checkpoint: seq = 456
    Mon Jul 14 00:16:49 2008   (SCNodeI0.15238 : csa103CompEO.---.---.00068 :   INFO)
     csa103CompI0: Hello World! (seq=456)
    Mon Jul 14 00:16:50 2008   (SCNodeI0.15238 : csa103CompEO.---.---.00069 :   INFO)
     csa103CompI0: Hello World! (seq=457)
    Mon Jul 14 00:16:51 2008   (SCNodeI0.15238 : csa103CompEO.---.---.00070 :   INFO)
     csa103CompI0: Hello World! (seq=458)
      

    Where we can see CompI1 printing 455 and then dieing, where upon CompI0 gets the notice to take over processing, reads the checkpoint and then takes over with seq=456 and so on.

    Then, in the CompI1 log file we see:

    /root/asp/var/log/csa103CompI1Log.latest
    Mon Jul 14 00:16:49 2008   (SCNodeI0.15553 : csa103CompEO.---.---.00044 :   INFO)
     csa103: Instantiated as component instance csa103CompI1.
    Mon Jul 14 00:16:49 2008   (SCNodeI0.15553 : csa103CompEO.---.---.00045 :   INFO)
     csa103CompI1: Waiting for CSI assignment...
    Mon Jul 14 00:16:49 2008   (SCNodeI0.15553 : csa103CompEO.---.---.00046 :   INFO)
     csa103CompI1: Waiting for CSI assignment...
    Mon Jul 14 00:16:49 2008   (SCNodeI0.15553 : csa103CompEO.---.---.00047 :   INFO)
     csa103CompI1: checkpoint_initialize
    Mon Jul 14 00:16:50 2008   (SCNodeI0.15553 : csa103CompEO.---.---.00054 :   INFO)
     csa103CompI1: Checkpoint service initialized (handle=0x1)
    Mon Jul 14 00:16:50 2008   (SCNodeI0.15553 : csa103CompEO.---.---.00056 :   INFO)
     csa103CompI1: Checkpoint opened (handle=0x2)
      

    That is the component that had been killed being restarted.

    CompI0 is moving along just fine, and we see CompI1 come back up. If we then kill CompI0 we see:

    /root/asp/var/log/csa103CompI1Log.latest
    Mon Jul 14 00:29:44 2008   (SCNodeI0.15553 : csa103CompEO.---.---.00065 :   INFO)
     csa103CompI1: Active state requested from state 2
    Mon Jul 14 00:29:44 2008   (SCNodeI0.15553 : csa103CompEO.---.---.00066 :   INFO)
     csa103CompI1 reading checkpoint
    Mon Jul 14 00:29:44 2008   (SCNodeI0.15553 : csa103CompEO.---.---.00067 :   INFO)
     csa103CompI1 read checkpoint: seq = 1225
    Mon Jul 14 00:29:45 2008   (SCNodeI0.15553 : csa103CompEO.---.---.00068 :   INFO)
     csa103CompI1: Hello World! (seq=1225)
    Mon Jul 14 00:29:46 2008   (SCNodeI0.15553 : csa103CompEO.---.---.00069 :   INFO)
     csa103CompI1: Hello World! (seq=1226)
      

    Where we can see the CompI0 process die, and CompI1 process read the sequence number from the checkpoint and then take over from where CompI0 left off.

  4. To stop csa103 use the following SAFplus Platform Console command.
    cli[Test:SCNodeI0:CPM]-> amsLockAssignment sg csa103SGI0
    
  5. Now change the state of csa103SGI0 to LockInstantiation and close the SAFplus Platform Console.
    cli[Test:SCNodeI0:CPM]-> amsLockInstantiation sg csa103SGI0
    cli[Test:SCNodeI0:CPM] -> end
    cli[Test:SCNodeI0] -> end
    cli[Test] -> bye
    

Additional Tests for Runtime Hardware Setup 1.3 and 2.3

Now repeat the experiment till the stage before we kill the active process and follow these steps.

Step A

  1. Stop SAFplus Platform on SCNodeI0 using /etc/init.d/asp stop. Observer the logs /root/asp/var/log/csa103CompI3Log.latest on SCNodeI1. This will become active and start printing the hello world logs as above. Note in this case active System Controller SCNode1 is still aware of PayloadNodeI0 and PayloadNodeI1.
  2. Start looking at the logs for /root/asp/var/log/csa103CompI0Log.latest in PayloadNodeI0. This will print the standby logs as above.
  3. Stop SAFplus Platform on PayloadNodeI0 and start observing the logs on PayloadNodeI1 in /root/asp/var/log/csa103CompI1Log.latest for standby. In this case, you can see, via the active System Controller logs that PayloadNodeI0 is not active whilst PayloadNodeI1 is.

Step B For Hardware Setup 1.3 only

  1. Repeat A with the slight exception that the blade running SCNodeI0 is yanked out(/etc/init.d/asp zap) instead of gracefully shutting down SAFplus Platform in step 1.

Summary and References

We've seen :

  • How to use SAFplus Messaging to communicate between any 2 processes
  • How to take over a communications channel after a failover

Further information can be found within the following: SA-AIS-MSG-B* (SA-Forum Messaging Specification), 'OpenClovis API Reference Guide.