Testing
Installation | Top | The ZeptoOS V2.0 Kernel
Early testing and troubleshooting
Once ZeptoOS is configured and installed, it is time to test it. Here are a few trivial tests to verify that the environment is working:
The /bin/sleep binary
If you are using Cobalt, submit using either of the commands below:
cqsub -k <profile-name> -t <time> -n 1 /bin/sleep 3600 qsub --kernel <profile-name> -t <time> -n 1 /bin/sleep 3600
If you are using mpirun directly, submit as follows:
mpirun -verbose 1 -partition <partition-name> -np 1 -timeout <time> \ -cwd $PWD -exe /bin/sleep 3600
This test, if successful, will verify that the ZeptoOS compute and I/O node environments are booting correctly. We deliberately chose a system binary such as /bin/sleep instead of something from a network filesystem so that even if the network filesystem does not come up for some reason, the test can still succeed.
If everything works out fine, messages such as the following will be found in the error stream (jobid.error file if using Cobalt):
FE_MPI (Info) : initialize() - using jobname '' provided by scheduler interface
FE_MPI (Info) : Invoking mpirun backend
FE_MPI (Info) : connectToServer() - Handshake successful
BRIDGE (Info) : rm_set_serial() - The machine serial number (alias) is BGP
FE_MPI (Info) : Preparing partition
BE_MPI (Info) : Examining specified partition
BE_MPI (Info) : Checking partition ANL-R00-M1-N12-64 initial state ...
BE_MPI (Info) : Partition ANL-R00-M1-N12-64 initial state = FREE ('F')
BE_MPI (Info) : Checking partition owner...
BE_MPI (Info) : Setting new owner
BE_MPI (Info) : Initiating boot of the partition
BE_MPI (Info) : Waiting for partition ANL-R00-M1-N12-64 to boot...
BE_MPI (Info) : Partition is ready
BE_MPI (Info) : Done preparing partition
FE_MPI (Info) : Adding job
BE_MPI (Info) : Adding job to database...
FE_MPI (Info) : Job added with the following id: 98461
FE_MPI (Info) : Starting job 98461
FE_MPI (Info) : Waiting for job to terminate
BE_MPI (Info) : IO - Threads initialized
BE_MPI (Info) : I/O input runner thread terminated
(we stripped the timestamp prefixes to make the lines shorter)
If these messages are immediately followed by other, error messages, then there is a problem. One common instance would be:
BE_MPI (Info) : I/O output runner thread terminated
BE_MPI (Info) : Job 98463 switched to state ERROR ('E')
BE_MPI (ERROR): Job execution failed
[...]
BE_MPI (ERROR): The error message in the job record is as follows:
BE_MPI (ERROR): "Load failed on 172.16.3.11: Program segment is not 1MB aligned"
This error indicates that the job was submitted to the default software environment, not to ZeptoOS (at the very least, the default I/O node ramdisk was used). You need to go back to the Kernel Profile section to fix the problem. Information from the system log files can be useful to diagnose the problem.
I/O node log files
Every I/O node has its own log file located in /bgsys/logs/BGP/, with a name such as R*-M*-N*-J*.log. This name will generally correspond to the name of the partition where the job was running. Above, our job ran on ANL-R00-M1-N12-64; a corresponding I/O node log file on Argonne machines will be R00-M1-N12-J00.log. This is how a log file from a successful ZeptoOS boot looks like:
Linux version 2.6.16.46-297 (geeko@buildhost) (gcc version 4.1.2 (BGP)) #1 SMP Wed Apr 22 15:04:42 CDT 2009
Kernel command line: console=bgcons root=/dev/ram0 lpj=8500000
init started: BusyBox v1.4.2 (2008-04-10 05:20:01 UTC) multi-call binary
Starting RPC portmap daemon..done
eth0: Link status [RX+,TX+]
mount server reported tcp not available, falling back to udp
mount: RPC: Remote system error - No route to host
Zepto ION startup-00
eth0 Link encap:Ethernet HWaddr 00:14:5E:7D:0C:57
inet addr:172.16.3.15 Bcast:172.31.255.255 Mask:255.240.0.0
UP BROADCAST RUNNING MULTICAST MTU:9000 Metric:1
RX packets:880 errors:0 dropped:0 overruns:0 frame:0
TX packets:1009 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:3878545 (3.6 Mb) TX bytes:151458 (147.9 Kb)
Interrupt:32
Zepto ION startup-00 done
done
Starting syslog servicesDec 31 18:00:36 ion-15 syslogd 1.4.1: restart.
done
Starting network time protocol daemon (NTPD) using 172.17.3.1May 1 12:57:11 ion-15 ntpdate[642]: step time server 172.17.3.1 offset 1241200617.470271 sec
May 1 12:57:11 ion-15 ntpd[653]: ntpd [email protected] Sat Oct 4 00:01:53 UTC 2008 (1)
May 1 12:57:11 ion-15 ntpd[653]: precision = 1.000 usec
May 1 12:57:11 ion-15 ntpd[653]: Listening on interface wildcard, 0.0.0.0#123
May 1 12:57:11 ion-15 ntpd[653]: Listening on interface eth0, 172.16.3.15#123
May 1 12:57:11 ion-15 ntpd[653]: Listening on interface lo, 127.0.0.1#123
May 1 12:57:11 ion-15 ntpd[653]: kernel time sync status 0040
done
Enabling ssh
Mounting site filesystems
done
Loading PVFS2 kernel module done
Sleeping 0 seconds before starting PVFS done
Starting PVFS2 client done
Sleeping 10 seconds before mounting PVFS
done
Mounting PVFS2 filesystems done
Starting SSH daemonMay 1 12:57:21 ion-15 sshd[833]: Server listening on 0.0.0.0 port 22.
done
Zepto ION startup-12
Zepto ION startup-12 done
Starting GPFS
May 1 12:57:26 ion-15 syslogd 1.4.1: restart.
/etc/init.d/rc3.d/S40gpfs: GPFS is ready on I/O node ion-15 : 172.16.3.15 : R00-M1-N12-J00
ln: creating symbolic link `/home/acherryl/acherryl' to `/gpfs/home/acherryl': File exists
ln: creating symbolic link `/home/bgpadmin/bgpadmin' to `/gpfs/home/bgpadmin': File exists
ln: creating symbolic link `/home/davidr/davidr' to `/gpfs/home/davidr': File exists
ln: creating symbolic link `/home/scullinl/scullinl' to `/gpfs/home/scullinl': File exists
Starting ZOID...
done
Zepto ION startup-99
Zepto ION startup-99 done
May 1 17:57:59 ion-15 init: Starting pid 2823, console /dev/console: '/bin/sh'
BusyBox v1.4.2 (2008-10-04 00:02:35 UTC) Built-in shell (ash)
Enter 'help' for a list of built-in commands.
/bin/sh: can't access tty; job control turned off
~ #
(again, we stripped the prefixes to make the lines shorter)
Messages such as Zepto ION startup or Starting ZOID clearly indicate that a ZeptoOS I/O node ramdisk is being used. If one instead mistakenly booted with the default ramdisk, this could be recognized by messages such as:
Starting CIO services [ciod:initialized] done
(ciod is never started when using Zepto Compute Node Linux)
In addition to verifying the ramdisk, the correct I/O node kernel can also be verified using the I/O node logfile by checking the kernel build timestamp in the first line of the boot log. As of this writing the default kernel on the Argonne machines has a timestamp of Wed Oct 29 18:51:19 UTC 2008; as can be seen above, the ZeptoOS kernel was built more recently.
Compute node log file
All the compute nodes on the machine share the same log file, located in /bgsys/logs/BGP/. The name of the log file is not fixed (it contains a timestamp), but sn1-bgdb0-mmcs_db_server-current.log always links to the current file. Because the file is shared with other jobs, we recommed to grep it for user name, partition name, or both.
A correct boot log when when booting ZeptoOS will look something like this:
iskra:ANL-R00-M1-N12-64 {20}.0: Common Node Services V1R3M0 (efix:0)
iskra:ANL-R00-M1-N12-64 {20}.0: Licensed Machine Code - Property of IBM.
iskra:ANL-R00-M1-N12-64 {20}.0: Blue Gene/P Licensed Machine Code.
iskra:ANL-R00-M1-N12-64 {20}.0: Copyright IBM Corp., 2006, 2007 All Rights Reserved.
iskra:ANL-R00-M1-N12-64 {20}.0: Z: Zepto Linux Kernel relocating CNS... dst=80280000 src=fff40000 size=262144
iskra:ANL-R00-M1-N12-64 {20}.0: Z: CNS is successfully relocated to 00280000 in physical memory
iskra:ANL-R00-M1-N12-64 {20}.0: Linux version 2.6.19.2-g66cbca2d (kazutomo@login1) (gcc version 4.1.2 (BGP)) #12 SMP Tue Apr 21 12:58:11 CDT 2009
iskra:ANL-R00-M1-N12-64 {20}.0: Zone PFN ranges:
iskra:ANL-R00-M1-N12-64 {20}.0: DMA 0 -> 28672
iskra:ANL-R00-M1-N12-64 {20}.0: Normal 28672 -> 28672
iskra:ANL-R00-M1-N12-64 {20}.0: early_node_map[1] active PFN ranges
iskra:ANL-R00-M1-N12-64 {20}.1: 0: 0 -> 28672
iskra:ANL-R00-M1-N12-64 {20}.1: Built 1 zonelists. Total pages: 28658
iskra:ANL-R00-M1-N12-64 {20}.1: Kernel command line: console=bgcons root=/dev/ram0 lpj=8500000
iskra:ANL-R00-M1-N12-64 {20}.1: PID hash table entries: 4096 (order: 12, 16384 bytes)
iskra:ANL-R00-M1-N12-64 {20}.0: Dentry cache hash table entries: 262144 (order: 4, 1048576 bytes)
iskra:ANL-R00-M1-N12-64 {20}.0: Inode-cache hash table entries: 131072 (order: 3, 524288 bytes)
iskra:ANL-R00-M1-N12-64 {20}.0: Memory: 1826560k available (1408k kernel code, 832k data, 192k init, 0k highmem)
iskra:ANL-R00-M1-N12-64 {20}.0: Calibrating delay loop (skipped)... 1700.00 BogoMIPS preset
iskra:ANL-R00-M1-N12-64 {20}.0: Mount-cache hash table entries: 8192
iskra:ANL-R00-M1-N12-64 {20}.0: CPU 1 done callin...
iskra:ANL-R00-M1-N12-64 {20}.0: CPU 1 done setup...
iskra:ANL-R00-M1-N12-64 {20}.0: CPU 1 done timebase take...
iskra:ANL-R00-M1-N12-64 {20}.0: Processor 1 found.
iskra:ANL-R00-M1-N12-64 {20}.0: CPU 2 done callin...
iskra:ANL-R00-M1-N12-64 {20}.0: CPU 2 done setup...
iskra:ANL-R00-M1-N12-64 {20}.0: CPU 2 done timebase take...
iskra:ANL-R00-M1-N12-64 {20}.0: Processor 2 found.
iskra:ANL-R00-M1-N12-64 {20}.0: CPU 3 done callin...
iskra:ANL-R00-M1-N12-64 {20}.0: CPU 3 done setup...
iskra:ANL-R00-M1-N12-64 {20}.0: CPU 3 done timebase take...
iskra:ANL-R00-M1-N12-64 {20}.0: Processor 3 found.
iskra:ANL-R00-M1-N12-64 {20}.0: Brought up 4 CPUs
iskra:ANL-R00-M1-N12-64 {20}.0: migration_cost=0
iskra:ANL-R00-M1-N12-64 {20}.0: checking if image is initramfs... it is
iskra:ANL-R00-M1-N12-64 {20}.0: Freeing initrd memory: 2575k freed
iskra:ANL-R00-M1-N12-64 {20}.0: NET: Registered protocol family 16
iskra:ANL-R00-M1-N12-64 {20}.0: NET: Registered protocol family 2
iskra:ANL-R00-M1-N12-64 {20}.0: IP route cache hash table entries: 16384 (order: 0, 65536 bytes)
iskra:ANL-R00-M1-N12-64 {20}.0: TCP established hash table entries: 65536 (order: 3, 524288 bytes)
iskra:ANL-R00-M1-N12-64 {20}.0: TCP bind hash table entries: 32768 (order: 2, 262144 bytes)
iskra:ANL-R00-M1-N12-64 {20}.0: TCP: Hash tables configured (established 65536 bind 32768)
iskra:ANL-R00-M1-N12-64 {20}.0: TCP reno registered
iskra:ANL-R00-M1-N12-64 {20}.0: fuse init (API version 7.7)
iskra:ANL-R00-M1-N12-64 {20}.0: io scheduler noop registered (default)
iskra:ANL-R00-M1-N12-64 {20}.0: RAMDISK driver initialized: 16 RAM disks of 32768K size 1024 blocksize
iskra:ANL-R00-M1-N12-64 {20}.0: tun: Universal TUN/TAP device driver, 1.6
iskra:ANL-R00-M1-N12-64 {20}.0: tun: (C) 1999-2004 Max Krasnyansky <[email protected]>
iskra:ANL-R00-M1-N12-64 {20}.0: TCP cubic registered
iskra:ANL-R00-M1-N12-64 {20}.0: NET: Registered protocol family 1
iskra:ANL-R00-M1-N12-64 {20}.0: NET: Registered protocol family 17
iskra:ANL-R00-M1-N12-64 {20}.0: NET: Registered protocol family 15
iskra:ANL-R00-M1-N12-64 {20}.0: Freeing unused kernel memory: 192k init
iskra:ANL-R00-M1-N12-64 {20}.0: init started: BusyBox(for ZeptoOS Compute Node) v1.12.1 (2009-04-21 16:08:55 CDT)
This is very easy to tell from a boot log of the default light-weight kernel, which will consist of the first four lines only.
This log file contains other useful information besides the boot log of the compute nodes. Before the kernel starts booting, the following messages related to the newly submitted job can be found there:
DBBlockCmd DatabaseBlockCommandThread started: block ANL-R00-M1-N12-64, user iskra, action 1
DBBlockCmd setusername iskra
iskra db_allocate ANL-R00-M1-N12-64
iskra DBConsoleController::setAllocating() ANL-R00-M1-N12-64
iskra block state C
iskra DBConsoleController::addBlock(ANL-R00-M1-N12-64)
iskra:ANL-R00-M1-N12-64 BlockController::connect()
iskra:ANL-R00-M1-N12-64 connecting to mcServer at 127.0.0.1:1206
Connected to MCServer as iskra@sn1. Client version 3. Server version 3 on fd 101
iskra:ANL-R00-M1-N12-64 connected to mcServer
iskra:ANL-R00-M1-N12-64 mcServer target set ANL-R00-M1-N12-64 created
iskra:ANL-R00-M1-N12-64 mcServer target set ANL-R00-M1-N12-64 opened
iskra:ANL-R00-M1-N12-64 {0} I/O log file: /bgsys/logs/BGP/R00-M1-N12-J00.log
iskra:ANL-R00-M1-N12-64 MailboxListener starting
iskra:ANL-R00-M1-N12-64 DBConsoleController::doneAllocating() ANL-R00-M1-N12-64
iskra:ANL-R00-M1-N12-64 BlockController::boot_block uloader=/bgsys/argonne-utils/partitions/ANL-R00-M1-N12-64/uloader cnload=/bgsys/argonne-utils/partitions/ANL-R00-M1-N12-64/CNS,/bgsys/argonne-utils/partitions/ANL-R00-M1-N12-64/CNK ioload=/bgsys/argonne-utils/partitions/ANL-R00-M1-N12-64/CNS,/bgsys/argonne-utils/partitions/ANL-R00-M1-N12-64/INK,/bgsys/argonne-utils/partitions/ANL-R00-M1-N12-64/ramdisk
iskra:ANL-R00-M1-N12-64 boot_block cookie: 587867023 compute_nodes: 64 io_nodes: 1
Of particular relevance are the pathnames to the I/O node log files (if they cannot be easily guessed from partition names) and the pathnames to the kernels and ramdisks used to boot the partition.
After the kernel boot log, the log file will also contain information about subsequent phases of starting a job:
iskra:ANL-R00-M1-N12-64 I/O node initialized: R00-M1-N12-J00
iskra:ANL-R00-M1-N12-64 DBBlockController::waitBoot(ANL-R00-M1-N12-64) block initialization successful
iskra DatabaseBlockCommandThread stopped
DBJobCmd DatabaseJobCommandThread started: job 98461, user iskra, action 1
DBJobCmd setusername iskra
iskra Starting Job 98461
New thread 4398305505840, for jobid 98461
selectBlock(): ANL-R00-M1-N12-64 iskra(1) connected state: I owner: iskra
ANL-R00-M1-N12-64 Jobid is 98461, homedir is /gpfs/home/iskra
ANL-R00-M1-N12-64 persist: 1
ANL-R00-M1-N12-64 connecting to mpirun...
ANL-R00-M1-N12-64 setting mpirun stream, fd=386
ANL-R00-M1-N12-64 contacting control node 0 at 172.16.3.15:7000
ANL-R00-M1-N12-64 connected to control node 0 at 172.16.3.15:7000
ANL-R00-M1-N12-64 Job::load() /bin/sleep
ANL-R00-M1-N12-64 Job loaded: 98461
ANL-R00-M1-N12-64 About to start /bin/sleep
ANL-R00-M1-N12-64 Job 98461 set to RUNNING
iskra:ANL-R00-M1-N12-64 {20}.0: floating point used in kernel (task=8080cfe0, pc=80017064)
Interactive login
Using Testcode
Once the files installations have been done and the profiles defined by creating symbolic links to the images in the top-level directory, it is time to submit a test job. Use the test program provided with the distribution. From the top level directory:
$ cd comm/testcodes
Compiling
The program can be compiled on the login node using:
$ /path/to/install/bin/zmpicc -o mpi-test-linux mpi-test.c $ /path/to/install/bin/zmpixlc_r -openmp -o omp-test-linux omp-test.c
Submitting Job
(For ANL Users) The job needs to be submitted using the cobalt resource manager. For the mpi-test program use the following command:
cqsub -n <number-of-processes> -t <time> -k <profile-name> mpi-test-linux cqsub -n <number-of-processes> -t <time> -k <profile-name> -e OMP_NUM_THREADS=<num> omp-test-linux
