Writing scripts for execution in a preboot can be challenging, oftentimes because it is difficult to get immediate and effective feedback from script execution. Deployment Solution for Dell Servers version 3.1 SP1 introduced a new multi-level logging mechanism that makes the work of writing your own custom scripts much easier. It allows you to write more robust scripts with greater feedback to the user. In addition, it provides a quick path to diagnosing problems by allowing the user the freedom of adjusting the logging verbosity as needed. These logging levels are controlled through the Configuration Utility UI, making it easy for anyone to control the logging behavior.

This article contains some sample scripts, but when writing your own scripts, many lessons can be learned by combing through the scripts that come bundled with Deployment Solution for Dell Servers. While I don't recommend changing these scripts in any way, they are very useful as a learning tool. If you want to augment the functionality of a script that comes with Deployment Solution for Dell Servers, make a copy of the job, then insert a new runscript task at the stage you want to perform an extra task.

So let's get started.

Script Prerequisites:

In order for your runscript task to take advantage of the advanced logging mechanism of Deployment Solution for Dell Servers, you obviously need to have Deployment Solution with the Dell Add-on installed, and the version must be at least 3.1 SP1. In the scripts, the logging mechanism is utilized by calling the logevent script and there is a corresponding logevent script for both Linux and WinPE. To use this logevent script, a small header needs to be added to each runscript task you wish to call logevent.

This header sets variables, pulls out the logging level from the database, and in the case of linux, copies the logevent script locally and converts it to UNIX formatted text in preparation for being called.

Here is an example of the header needed for scripts that will be run in the Linux Preboot:

#Setup of advanced logging capabilities
declare -x DELL_DRIVE="$SHARE"
declare -x DELL_PATH="$DELL_DRIVE/Dell"
declare -x JOB_DEBUG_LEVEL="%#*"select data from dbo.dell_settings where name='JobDebugLevel'"%"
declare -x DFN_LOG_FILE="$DELL_PATH/alogs/%ID%.log"
declare -x LOGEVENT="/tmp/logevent.sh"
dos2unix "$DELL_PATH/ascripts/linux/logevent.sh" > $LOGEVENT
chmod 700 $LOGEVENT

#The Script....
$LOGEVENT 2 0 INFO "This is my test script"

And here is the same script for scripts that will be run in the WinPE Preboot:

::Set up advanced scripting capabilities
set SCRIPT="MyTestScrit"
set DELL_DRIVE=%share%
set DELL_PATH=%DELL_DRIVE%\Dell
set JOB_DEBUG_LEVEL=%#*"select data from dbo.dell_settings where name='JobDebugLevel'"%
set DFN_LOG_FILE=%DELL_PATH%\alogs\%ID%.log
set LOGEVENT=cscript %DELL_PATH%\ascripts\winpe\logevent.vbs //Nologo

::The Script...
call %LOGEVENT% 2 0 INFO "This is my test script"

The "Script" variable is available for convenience and identifies the script that is logging the event in the log file. This is useful in sorting out which script logged what when you have several scripts utilizing advanced logging.

Log Events Explained:

A logging event occurs whenever the logevent script is called. Each event within the scripts is assigned a importance level, and the level visibility can be adjusted in the Configuration Utility. Click on Tools->Dell Tools->Configuration Utility->Options (in the lower right hand corner).

Click to view.

This allows you to decide how much information you want to be logged at any given time. The logging levels are additive, meaning that as you increase the level (for instance from 1 to 2), you never lose any messages, but each level adds additional messages to all those logged by the lesser levels. This is particularly useful when troubleshooting a problem; you can select "4 - All", and get a very clear picture of the context of the problem because everything is logged, and often you can discover the source of the problem immediately.

It is important to understand that logging events do not only write information to the log file, but they also log a message to the Deployment Console, visible under the status detail.

Click to view.

There is a subtle difference between these messages however. Messages logged to the log file are dependent on the logging level set. The logging level however does not affect the messages logged to the Deployment Console. All message of level 1 (errors or warnings) or 2 (information) are logged to the console irregardless of the log level selected in the Configuration Utility UI.

To learn how to make logevent calls, let's first pull out a logging event from a script and take it apart. Here is the event that is within the gcf_firmware script, the script that captures configuration files:

In WinPE:

call %LOGEVENT% 2 0 INFO "Getting %FIRMWARE_TYPE% configuration file..."

In Linux:

$LOGEVENT 2 0 INFO "Getting $FIRMWARE_TYPE configuration file..."

As you can see the syntax is mostly the same, except for the differences inherent to gnu bash, versus windows batch scripting. The general syntax is as follows:

LOGEVENT { 1-4 severity level} { status code } { WARN, INFO, ERROR (message type) } and "Message" [ID]

The severity level corresponds to the logging level adjustable in the Configuration Utility. For example, if this message is is of level 2 importance, pass in a 2 as the severity level. This message will then be logged if the logging level is set to 2, 3 or 4. The status code is merely passed back to DS to appear in the Deployment Console. The message type describes the nature of the event, and directly corresponds to the icon displayed in the Deployment Console. INFO corresponds to the blue "i" icon, WARN corresponds to the yellow triangle, and ERROR corresponds to the red "x". The message field is simply the message that you want to appear. There is one catch however, and that is Deployment Solution for security purposes will truncate a message if it detects a word that may be interpreted as SQL. For instance any message that contains the word SELECT, DELETE, DROP, etc will be cut off. So if you find your messages are being cut off, reword your message.

The last field "[ID]" is only necessary when the script is running server side. Since it is run on the DS server, there is no context as to what machine the message corresponds to, so the machine ID is passed in most easily with the built-in %ID% DS token. This allows DS to assign the message to the appropriate queue.

In our example above, we are calling LOGEVENT, with a 2 because this is normal, "Top priority" information. If it were details that I normally would not be interested in, I would log it as a 3 or a 4. The status code is usually only useful in an error state, so I pass in a 0. This message should be reported to DS as information only, thus I pass in INFO as the message type. The message itself can contain variables from the script, in this case the %FIRMWARE_TYPE% variable is usually "SYSTEM", "DRAC" or "RAID".

After running this script, I can take a look at the log, under Dell\alogs, and see the following entry:

------------------------- INFO ---------------------------
SCRIPT:gcf_firmware.sh - Tue Dec 9 22:22:14 MST 2008
Getting DRAC configuration file...
----------------------------------------------------------

I can also take a look at the status detail and see the exact same message logged. This is because the logging level was set to 2.

Up until now in our example we have been using the LOGEVENT script in event mode, but there is another type of logevent call that is worth mentioning- Pipe Mode. Pipe mode allows you to pass in the stdout of a process to the logging mechanism. This is useful for verbosely logging the output of an executable, or logging the contents of a file. Let's take another example from the gcf_firmware script.

In WinPE:

type %DFN_TEMP_FILE% | %LOGEVENT% 3 "Standard out from:\n%DELL_TK_TOOLS%\%CFG_UTIL%.exe %CMD_OPTNS%%DFN_INI%" -

In Linux:

cat $DFN_TEMP_FILE | $LOGEVENT 3 "Standard out from $CFG_UTIL. Return Code=$RETURN_CODE" -

This pipes the contents of a temporary file where the stdout from the execution of the utility was written to the log. Since the entire output from a utility is usually not needed, it is logged as level 3, meaning that in order for users see this event in the log, they would have had to change the default logging level from 2, to 3 or 4.

The syntax for using the LOGEVENT script in pipe mode is as follows:

LOGEVENT { 1-4 severity level } "Message" -

Remember to always pipe a stream into logevent when using this mode using the | operator. Since events that are logged in PIPE mode are only written to the log file and not to the console, the information associated with the console is not needed, such as the status code and the message type.

The result of this logging event is as follows:

------------------------- INFO ---------------------------
SCRIPT:gcf_firmware.sh - Tue Dec 16 16:47:17 MST 2008
Standard out from racadm. Return Code=0
----------------------------------------------------------
 [idRacInfo]
 [cfgLanNetworking]
 [cfgNicTeaming]
  . . . . 
 [cfgIpmiPet]
 
 RAC configuration saved to file successfully
----------------------------------------------------------

Conclusion:

By using a healthy combination of Logevent calls, you can paint a very clear picture of what's going on in your script. It also allows you to easily see where your script is failing. I often make it a habit of always logging any variable's value after it as set (at level 4 of course). That way I can merely take a log file, with the script that generated it, and follow the logic line by line. Using advanced logging also produces much cleaner scripts because each call only takes one line, and logging to the Deployment Console is taken care of automatically without any extra work.

Happy scripting!