Thursday, January 24, 2008

Server Manager Logging - Part 1

Server Manager has log files. A lot of 'em in fact. There, I said it.

So where do you go when something in SM isn't working just right? We spent considerable time attempting to log often and use meaningful messages within SM. That said it is a distributed architecture with components contained on the console machine, agents installed on remote machines, and more agents built into the E1 products themselves. This post will help you identify which logs you should be looking at, where they are, how to configure them, and what to look for. For the sake of being able to finish the article eventually I'll just focus on the SM logs.

Throughout this post I'll be referring to some common paths.
<console_install> - Refers to the location supplied during the installation of the management console.

Installation Logs - Management Console

We begin with looking at the log files generated during the installation of the management console. These can be helpful if there are problems installing the management console application. Once the console is successfully installed and you are able to sign-in to the web application these logs are no longer relevant for any purpose and may be removed, if desired.

The management console is installed using an InstallShield based installer. This installer is responsible for creating the <console_install> directory, extracting all the component files that make up SM, configuring the integrated J2EE server, and deploying the management console web application.

The primary log created by the installer is located in <console_install>logssmmc_install.log. This is the first place you should look if you are having problems installing the management console. This log will probably go down as the most cryptic of the log files to analyze but somewhere in there is good information. One thing to note is if something goes wrong during the installation the installer will roll back the changes already made. This may result in error messages and other possibly confusing messages in the log file. In the case of a failed installation you want to find the first thing that went wrong in the log file before it started rolling back the installation.

The bulk of the messages in the smmc_install.log file will detail the extraction of files from the installer application to the <console_install> location. Near the end the installer performs the configuration of the J2EE container and deploys the management console application. The first task is to configure the administrative user for the J2EE container using the credentials provided during the installer wizard. The smmc_install.log will contain the following lines:

(Jul 31, 2007 12:40:14 PM), Install, com.installshield.wizard.platform.win32.Win32ProductServiceImpl, dbg.install, JVM memory before installing Exec Action (execJaznJar): free=9241864 total=23748608
(Jul 31, 2007 12:40:14 PM), Install, com.installshield.wizard.platform.win32.Win32ProductServiceImpl, msg1, installing Exec Action (execJaznJar)
(Jul 31, 2007 12:40:16 PM), Install, com.installshield.wizard.platform.win32.Win32ProductServiceImpl, dbg.install, JVM memory after installing Exec Action (execJaznJar): free=9833152 total=23748608

At the same time two new log files will appear in <console_install>logs: jazn_stdout.log and jazn_stderr.log. These are the stdout and stderr output from running commands contained in the jazn.jar java application delivered with the J2EE container. The stderr file should be empty. Any content in the file is indicative of an error and will cause the installation to fail. If the jazn_stderr.log file is not empty you should investigate the cause of any errors detailed within.

The next step performed is to install the Windows service used to start and stop the management console. This is performed by running the delivered script <console_install>bininstallManagementConsoleService.bat. The following lines in the smmc_install.log file indicate when this batch file is called:

(Jul 31, 2007 12:40:16 PM), Install, com.installshield.wizard.platform.win32.Win32ProductServiceImpl, dbg.install, JVM memory before installing Exec Action (execInstService): free=9809880 total=23748608
(Jul 31, 2007 12:40:16 PM), Install, com.installshield.wizard.platform.win32.Win32ProductServiceImpl, msg1, installing Exec Action (execInstService)
(Jul 31, 2007 12:40:17 PM), Install, com.installshield.wizard.platform.win32.Win32ProductServiceImpl, dbg.install, JVM memory after installing Exec Action (execInstService): free=9552496 total=23748608
(Jul 31, 2007 12:40:17 PM), Install, com.installshield.scfmc.event.InstallScript, msg1, Beginning the onInstalledOc4jExecComp method.

The installManagementConsoleService.bat creates a log file named <console_install>logsinstallManagementConsole.log. The contents will look something like:

[2008-01-24 14:50:41] [1206 prunsrv.c] [debug] Procrun log initialized
[2008-01-24 14:50:41] [496 prunsrv.c] [debug] Installing service...
[2008-01-24 14:50:41] [info] Service SCFMngmtConsole3 name SCF Management Console [D:servermanagerdemosystem] - SCFMngmtConsole3
[2008-01-24 14:50:42] [538 prunsrv.c] [debug] Setting service description SCF Management Console
[2008-01-24 14:50:42] [info] Service SCFMngmtConsole3 installed
[2008-01-24 14:50:42] [info] Procrun finished.

Now that the J2EE server has been configured with the administrative password and the Windows service created its time to start the container. The batch file <console_install>binstartManagementConsole.bat is invoked and you will see lines along the lines of:

(Jul 31, 2007 12:40:17 PM), Install, com.installshield.scfmc.event.InstallScript, msg1, Command to run is: d:servermanagerdemosystem/bin/startManagementConsole.bat
(Jul 31, 2007 12:40:20 PM), Install, com.installshield.scfmc.event.InstallScript, msg1, Return code is: 0

The output of the startManagementConsole.bat is written to the log file <console_install>logsMCDeploy_stdout.log. The first two lines of the file will contain something like:

The SM Management Console [D:servermanagerdemosystem] - SCFMngmtConsole4 service is starting.
The SM Management Console [D:servermanagerdemosystem] - SCFMngmtConsole4 service was started successfully.

It may take a while for the J2EE container to fully start up. To ensure the container is actually running before the management console application is deployed the installer will repeatedly run a command line program that will check if the server is actually running. You will see this in the log file:

(Jul 31, 2007 12:40:30 PM), Install, com.installshield.scfmc.event.InstallScript, msg1, Command to run is: d:servermanagerdemosystem/jdk/bin/java.exe -jar d:servermanagerdemosystem/targets/oc4j/j2ee/home/admin_client.jar deployer:oc4j:localhost:24795 oc4jadmin ******** -validateURI
(Jul 31, 2007 12:41:24 PM), Install, com.installshield.scfmc.event.InstallScript, msg1, Return code is: 0

The installer will be looking for a success message emitted by the program run. If not found it will wait a bit and re-run the command, eventually giving up. The responses are appended to the MCDeploy_stdout.log. The success message looks like

URI deployer:oc4j:localhost:24795 is valid and connected

Once the J2EE container is validated as running the management console application is deployed to it. The deployment is performed through a command line program, the running of which is shown below:


(Jul 31, 2007 12:41:24 PM), Install, com.installshield.scfmc.event.InstallScript, msg1, Command to run is: d:servermanagerdemosystem/jdk/bin/java.exe -jar d:servermanagerdemosystem/targets/oc4j/j2ee/home/admin_client.jar deployer:oc4j:localhost:24795 oc4jadmin ******** -deploy -file d:servermanagerdemosystem/_stage/ManagementConsole_WAR.ear -deploymentName ManagementConsole -bindAllWebApps
(Jul 31, 2007 12:42:00 PM), Install, com.installshield.scfmc.event.InstallScript, msg1, Return code is: 0
(Jul 31, 2007 12:42:00 PM), Install, com.installshield.scfmc.event.InstallScript, msg1, Deployment succeeded for MC.

The output of the deployment operations are also appended to MCDeploy_stdout.log and should look something like:


07/07/31 12:41:26 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:26 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:27 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:27 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:27 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:27 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:28 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:28 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:28 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:29 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:29 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:29 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:29 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:30 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:30 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:30 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:30 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:31 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:31 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:31 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:31 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:32 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:32 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:32 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:33 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:33 Notification ==>Uploading file ManagementConsole.ear ...
07/07/31 12:41:33 Notification ==>Application Deployer for ManagementConsole STARTS.
07/07/31 12:41:33 Notification ==>Copy the archive to D:servermanagerdemosystemtargetsoc4jj2eehomeapplicationsManagementConsole.ear
07/07/31 12:41:33 Notification ==>Initialize D:servermanagerdemosystemtargetsoc4jj2eehomeapplicationsManagementConsole.ear begins...
07/07/31 12:41:33 Notification ==>Unpacking ManagementConsole.ear
07/07/31 12:41:34 Notification ==>Done unpacking ManagementConsole.ear
07/07/31 12:41:35 Notification ==>Unpacking ManagementConsole_WAR.war
07/07/31 12:41:44 Notification ==>Done unpacking ManagementConsole_WAR.war
07/07/31 12:41:44 Notification ==>Initialize D:servermanagerdemosystemtargetsoc4jj2eehomeapplicationsManagementConsole.ear ends...
07/07/31 12:41:44 Notification ==>Starting application : ManagementConsole
07/07/31 12:41:44 Notification ==>Initializing ClassLoader(s)
07/07/31 12:41:44 Notification ==>Initializing EJB container
07/07/31 12:41:44 Notification ==>Loading connector(s)
07/07/31 12:41:44 Notification ==>Starting up resource adapters
07/07/31 12:41:44 Notification ==>Initializing EJB sessions
07/07/31 12:41:44 Notification ==>Committing ClassLoader(s)
07/07/31 12:41:44 Notification ==>Initialize ManagementConsole_WAR begins...
07/07/31 12:41:44 Notification ==>Initialize ManagementConsole_WAR ends...
07/07/31 12:41:44 Notification ==>Started application : ManagementConsole
07/07/31 12:41:44 Notification ==>Binding web application(s) to site default-web-site begins...
07/07/31 12:41:44 Notification ==>Binding ManagementConsole_WAR web-module for application ManagementConsole to site default-web-site under context root /manage
07/07/31 12:41:45 Notification ==>Initializing Servlet: com.jdedwards.mgmt.web.ConsoleInit for web application ManagementConsole_WAR
07/07/31 12:41:58 Notification ==>Initializing Servlet: oracle.cabo.servlet.UIXServlet for web application ManagementConsole_WAR
07/07/31 12:41:59 Notification ==>Binding web application(s) to site default-web-site ends...
07/07/31 12:41:59 Notification ==>Application Deployer for ManagementConsole COMPLETES. Operation time: 25813 msecs

Any errors or problems that occur during the startup, running validation, and deployment will appear in the log file <console_install>logsMCDeploy_stderr.log. The installer will check if there are any errors contained within this file and if so terminate and rollback the installation, as shown below:


(Jul 31, 2007 12:42:00 PM), Install, com.installshield.wizard.platform.win32.Win32ProductServiceImpl, msg1, installing Log File Error Check (logFileErrCheck)
(Jul 31, 2007 12:42:00 PM), Install, com.oracle.e1.install.common.ISMP.product.LogFileErrorCheck, msg1, Beginning stderr log checks.
(Jul 31, 2007 12:42:00 PM), Install, com.oracle.e1.install.common.ISMP.product.LogFileErrorCheck, msg1, Checking for errors in: D:servermanagerdemosystemlogsMCDeploy_stderr.log
(Jul 31, 2007 12:42:00 PM), Install, com.oracle.e1.install.common.ISMP.product.LogFileErrorCheck, msg1, No errors in the stderr logs, continuing the installation.


In case you forgot the information you entered, such as the HTTP port to use for the management console, a readme.txt file is created in the <console_install> directory. After creating the readme.txt file the installation is essentially complete.

Next Time

Now that we have the management console installed it's time to start installing some management agents, and looking at their log files.