How to panic a guest domain in Solaris

I recently came across a Solaris 10 guest domain in a hung state.
I accessed its console from the primary domain but I was not able to see a login prompt or anything for that matter.

I was able to ping the server but unable to login to it via ssh.

Hence we decided to reboot the guest domain but we wanted to make sure that a crash dump was generated which could be shared with Oracle support for further analysis.

We decided to induce a kernel panic in the guest domain to ensure the generation of a crash dump on system restart.

The command used to accomplish this is ldm panic-domain.

[sahil@primary-domain-p:~] $ sudo ldm panic-domain test-domain-g
[sahil@primary-domain-p:~] $ sudo ldm list test-domain-g
NAME             STATE      FLAGS   CONS    VCPU  MEMORY   UTIL  NORM  UPTIME
test-domain-g active     -t----  5002    64    158G     100%  100%  157d 1h
[sahil@primary-domain-p:~] $ sudo console test-domain-g
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.

Connecting to console "test-domain-g" in group "test-domain-g" ....
Press ~? for control options ..
 6:21 100% done
100% done: 1523171 pages dumped, dump succeeded
rebooting...
Resetting...
NOTICE: Entering OpenBoot.
NOTICE: Fetching Guest MD from HV.
NOTICE: Starting additional cpus.
NOTICE: Initializing LDC services.
NOTICE: Probing PCI devices.
NOTICE: Finished PCI probing.

The ldm panic-domain command ensured that a crash dump was generated when the guest domain underwent a reboot.

I hope this quick tip was helpful.

Shutdown a zone stuck in down state

While working on a patching activity I came across an issue wherein the swap file system temporarily mounted for a zone did not get unmounted properly during the installpatchset phase.

swap                   295G     8K   295G     1%    /zones/lab-zone/lu

From the zoneadm list output, I observed that the zone to which the above file system belonged to was somehow stuck in down state.

usport-lab-g# zoneadm list -icv

  ID NAME             STATUS     PATH                           BRAND    IP

   0 global           running    /                              native   shared

   7 lab-zone       down       /zones/lab-zone              native   shared

Further investigation revealed that the zoneadmd process for the zone was still active.

usport-lab-g# ps -ef | grep zoneadmd

    root  6962  6863   0 06:31:49 pts/1       0:00 grep zoneadmd

    root 21890     1   0 06:12:45 ?           0:01 zoneadmd -z lab-zone

I forcefully terminated this process with the kill command.

usport-lab-g# kill -9 21890

usport-lab-g# ps -ef | grep zoneadmd

    root  7025  6863   0 06:32:00 pts/1       0:00 grep zoneadmd

This fixed the problem and the zone was now in the installed state as I anticipated.

[ssuri@usport-lab-g:~] $ sudo zoneadm list -icv

  ID NAME             STATUS     PATH                           BRAND    IP

   0 global           running    /                              native   shared

   - lab-zone       installed  /zones/lab-zone              native   shared

I hope this quick tip was helpful for you and I thank you for reading.

Changing a Solaris 10 zone's ip type from shared to exclusive

Zones in Solaris 10 are configured with IP type as shared by default whereas in case of Solaris 11 the default IP type is exclusive but that's a completely different story.

In Solaris 10 zones can have one of two IP types:

Shared-ip:
In this type of network setup the zone shares a network interface or data link with the global zone. When the zone boots a logical interface is created on top of the physical interface with the IP address we specify in the zonecfg configuration for the net resource. This logical interface stays as long as the zone is running and is removed once the zone halts and is re-created at next boot and so forth. In this way the zone itself doesn't really control it's networking stack.


Exclusive-ip:
In this setup the zone is given dedicated control of a physical network interface. We set the IP address and default route from within the zone and not through the zone's configuration done via zonecfg.
Here are some of the features bestowed upon the non-global zone through this method of zone networking:

• DHCPv4 and IPv6 stateless address autoconfiguration
• IP Filter, including network address translation (NAT) functionality
• IP Network Multipathing (IPMP)
• IP routing
• ndd for setting TCP/UDP/SCTP as well as IP/ARP-level knobs
• IP security (IPsec) 

Now getting to the actual purpose of the article. The conversion of a zone network configuration from shared-ip to exclusive-ip.

So, here we have a zone configured with shared-ip networking:

root@sandbox:/# zonecfg -z auto-zone info
zonename: auto-zone
zonepath: /zones/auto-zone
brand: native
autoboot: false
bootargs:
pool:
limitpriv:
scheduling-class:
ip-type: shared
inherit-pkg-dir:
        dir: /lib
inherit-pkg-dir:
        dir: /platform
inherit-pkg-dir:
        dir: /sbin
inherit-pkg-dir:
        dir: /usr
net:
        address: 192.168.87.144/24
        physical: e1000g0
        defrouter: 192.168.87.2

To modiy the IP type, enter the configuration menu/setup by typing zonecfg -z <zone_name> and type:

zonecfg:auto-zone> set ip-type=exclusive

I tried to modify the existing net resource to make it exclusive-ip but it didn't work.

zonecfg:auto-zone> select net address=192.168.87.144/24

zonecfg:auto-zone:net> info

net:

        address: 192.168.87.144/24

        physical: e1000g0

        defrouter: 192.168.87.2

zonecfg:auto-zone:net> remove defrouter 192.168.87.2

zonecfg:auto-zone:net> set physical=e1000g1

I couldn't get rid of the address property therefore I removed the net resource and added it again.

zonecfg:auto-zone> remove net address=192.168.87.144/24

zonecfg:auto-zone> info ip-type

ip-type: exclusive

zonecfg:auto-zone> add net

zonecfg:auto-zone:net> set physical=e1000g1

zonecfg:auto-zone:net> end

zonecfg:auto-zone> info

zonename: auto-zone

zonepath: /zones/auto-zone

brand: native

autoboot: false

bootargs:

pool:

limitpriv:

scheduling-class:

ip-type: exclusive

inherit-pkg-dir:

        dir: /lib

inherit-pkg-dir:

        dir: /platform

inherit-pkg-dir:

        dir: /sbin

inherit-pkg-dir:

        dir: /usr

net:

        address not specified

        physical: e1000g1

        defrouter not specified

zonecfg:auto-zone> verify

zonecfg:auto-zone> commit

zonecfg:auto-zone> exit

to verify that the NIC e1000g1 is indeed exclusively assigned to the zone we can use the following command to verify:

oot@sandbox:/# dladm show-linkprop

LINK         PROPERTY        VALUE          DEFAULT        POSSIBLE

e1000g0      zone            --             --             --

e1000g0      tagmode         vlanonly       vlanonly       vlanonly,normal

e1000g1      zone            auto-zone      --             --

e1000g1      tagmode         vlanonly       vlanonly       vlanonly,normal

e1000g2      zone            --             --             --

e1000g2      tagmode         vlanonly       vlanonly       vlanonly,normal

root@sandbox:/#

Next we login to the zone and configure the IP address on the interface:

bash-3.00# ifconfig e1000g1 plumb

bash-3.00# ifconfig e1000g1 192.168.87.144 netmask 255.255.255.0 up

bash-3.00# ifconfig -a

lo0: flags=2001000849<UP,LOOPBACK,RUNNING,MULTICAST,IPv4,VIRTUAL> mtu 8232 index 1

        inet 127.0.0.1 netmask ff000000

e1000g1: flags=1000843<UP,BROADCAST,RUNNING,MULTICAST,IPv4> mtu 1500 index 2

        inet 192.168.87.144 netmask ffffff00 broadcast 192.168.87.255

        ether 0:c:29:59:30:ba

bash-3.00# route -p add default 192.168.87.2

add net default: gateway 192.168.87.2

add persistent net default: gateway 192.168.87.2

bash-3.00# netstat -rn

Routing Table: IPv4

  Destination           Gateway           Flags  Ref     Use     Interface

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

default              192.168.87.2         UG        1          0

192.168.87.0         192.168.87.144       U         1          0 e1000g1

127.0.0.1            127.0.0.1            UH        5        126 lo0

bash-3.00#

Let's verify the correctness of our setup by attempting to get a successful ping off the default route:

bash-3.00# ping 192.168.87.2

192.168.87.2 is alive

Everything appears to be in order.

Let's try to connect to the zones' IP from outside the zone.

[user.DESKTOP-4NUE93O] ➤ ssh 192.168.87.144

Warning: Permanently added '192.168.87.144' (RSA) to the list of known hosts.

user@192.168.87.144's password:

Looks good. Now let's make the IP address configuration persistent followed by a reboot and verification.

bash-3.00# echo "192.168.87.144" > /etc/hostname.e1000g1

bash-3.00# cat /etc/hostname.e1000g1

192.168.87.144

bash-3.00# init 6

bash-3.00#

[Connection to zone 'auto-zone' pts/4 closed]

root@sandbox:/# zlogin auto-zone

[Connected to zone 'auto-zone' pts/4]

Last login: Fri Oct  6 22:11:27 on pts/4

Sun Microsystems Inc.   SunOS 5.10      Generic January 2005

# bash

bash-3.00# ifconfig -a

lo0: flags=2001000849<UP,LOOPBACK,RUNNING,MULTICAST,IPv4,VIRTUAL> mtu 8232 index 1

        inet 127.0.0.1 netmask ff000000

e1000g1: flags=1000843<UP,BROADCAST,RUNNING,MULTICAST,IPv4> mtu 1500 index 2

        inet 192.168.87.144 netmask ffffff00 broadcast 192.168.87.255

        ether 0:c:29:59:30:ba

bash-3.00#

Using sysidcfg file to perform initial zone configuration

In this article I'll demonstrate how we can use a sysidcfg file to perform initial configuration of a solaris 10 zone after it has just been installed. Note that we need to do this before the zones' first boot.

To avoid creating the entire zone configuration from scratch I'll export a running zones' configuration, modify it and use it.

root@sandbox:/# zonecfg -z test-zone export -f auto-zone.cfg

This exported the zone test-zone's configuration to a file named auto-zone.cfg.

Now let's configure our new zone auto-cfg using this file.

root@sandbox:/# zonecfg -z auto-zone -f auto-zone.cfg

I modified the file with vi to update the IP address information, zonepath and zonename properties.

root@sandbox:/# zonecfg -z auto-zone info net

net:

        address: 192.168.87.144/24

        physical: e1000g0

        defrouter: 192.168.87.2

root@sandbox:/# zonecfg -z auto-zone info zonepath

zonepath: /zones/auto-zone

root@sandbox:/# zonecfg -z auto-zone info zonename

zonename: auto-zone

I also removed a loopback file system by invoking the remove sub-command with the fs property.

zonecfg:auto-zone> remove fs

I then installed the zone. This is a sparse root zone so the installation was quick.

root@sandbox:/# zoneadm list -icv

  ID NAME             STATUS     PATH                           BRAND    IP

   0 global           running    /                              native   shared

   3 test-zone        running    /zones/test-zone               native   shared

   - auto-zone        configured /zones/auto-zone               native   shared

root@sandbox:/# zoneadm -z auto-zone install

A ZFS file system has been created for this zone.

Preparing to install zone <auto-zone>.

Creating list of files to copy from the global zone.

Copying <7503> files to the zone.

Initializing zone product registry.

Determining zone package initialization order.

Preparing to initialize <1098> packages on the zone.

Initialized <1098> packages on zone.

Zone <auto-zone> is initialized.

The file </zones/auto-zone/root/var/sadm/system/logs/install_log> contains a log of the zone installation.

root@sandbox:/#  zoneadm list -icv

  ID NAME             STATUS     PATH                           BRAND    IP

   0 global           running    /                              native   shared

   3 test-zone        running    /zones/test-zone               native   shared

   - auto-zone        installed  /zones/auto-zone               native   shared

Now with that done go the /zones/auto-zone/root/etc/ directory.

root@sandbox:/# cd /zones/auto-zone/root/etc/

This will serve as the /etc directory for the zone and here we create our sysidcfg file and populate it.

root@sandbox:/zones/auto-zone/root/etc# vi sysidcfg

root@sandbox:/zones/auto-zone/root/etc# cat sysidcfg

system_locale=C

keyboard=US-English

terminal=xterms

network_interface=primary {

                hostname=auto-zone

}

security_policy=NONE

name_service=NONE

nfs4_domain=dynamic

timezone=Asia/Calcutta

root_password=Spectre_007

root@sandbox:/zones/auto-zone/root/etc# cd

Once done, change to a global zone directory and boot the zone.

root@sandbox:/# zoneadm -z auto-zone boot

The zone will now be in running state.

root@sandbox:/#  zoneadm list -icv

  ID NAME             STATUS     PATH                           BRAND    IP

   0 global           running    /                              native   shared

   3 test-zone        running    /zones/test-zone               native   shared

   4 auto-zone        running    /zones/auto-zone               native   shared

root@sandbox:/#

We need to give a minute or two to the system to apply the settings mentioned in the sysidcfg file. I waited for 2 minutes and then logged in to do a couple of snaity checks.

root@sandbox:/# zlogin auto-zone

[Connected to zone 'auto-zone' pts/4]

Last login: Mon Oct  2 22:32:10 on pts/4

Sun Microsystems Inc.   SunOS 5.10      Generic January 2005

# echo $TERM

xterm

# svcs -xv

svc:/application/print/server:default (LP print server)

 State: disabled since Mon Oct 02 22:23:08 2017

Reason: Disabled by an administrator.

   See: http://sun.com/msg/SMF-8000-05

   See: man -M /usr/share/man -s 1M lpsched

Impact: 2 dependent services are not running:

        svc:/application/print/rfc1179:default

        svc:/application/print/ipp-listener:default

# who -r

   .       run-level 3  Oct  2 22:23     3      0  S

# ifconfig -a

lo0:2: flags=2001000849<UP,LOOPBACK,RUNNING,MULTICAST,IPv4,VIRTUAL> mtu 8232 index 1

        inet 127.0.0.1 netmask ff000000

e1000g0:3: flags=1000843<UP,BROADCAST,RUNNING,MULTICAST,IPv4> mtu 1500 index 2

        inet 192.168.87.144 netmask ffffff00 broadcast 192.168.87.255

#

# date

Mon Oct  2 22:35:15 IST 2017

#

As expected the system was functional and accessible from the network.

Here are two more useful sample sysidcfg files for consideration:

Sysidcfg file for SPARC systems:

keyboard=US-English

system_locale=en_US

timezone=US/Central

terminal=sun-cmd

timeserver=localhost

name_service=NIS {domain_name=marquee.central.example.com

                  name_server=nmsvr2(172.31.112.3)}

nfs4_domain=dynamic

root_password=m4QPOWNY

network_interface=hme0 {hostname=host1 

                       default_route=172.31.88.1 

                       ip_address=172.31.88.210 

                       netmask=255.255.0.0 

                       protocol_ipv6=no}

security_policy=kerberos {default_realm=example.com 

                          admin_server=krbadmin.example.com 

                          kdc=kdc1.example.com, 

                          kdc2.example.com}

  

  

Sysidcfg file for zones with multiple interfaces:

  

timezone=US/Pacific

system_locale=C

terminal=xterms

timeserver=localhost

network_interface=eri0 {primary

                        hostname=host1

                        ip_address=192.168.2.7

                        netmask=255.255.255.0

                        protocol_ipv6=no

                        default_route=192.168.2.1}

network_interface=eri1 {hostname=host1-b

                        ip_address=192.168.3.8

                        netmask=255.255.255.0

                        protocol_ipv6=no

                        default_route=NONE}

root_password=JE2C35JGZi4B2

security_policy=none

name_service=NIS {domain_name=domain.example.com

                  name_server=nis-server(192.168.2.200)}

nfs4_domain=dynamic

Renaming a LOFS type file system assigned to a Solaris 10 zone

In this quick article I'll demonstrate how we can easily rename a loopback file system mounted from a global zone to a local zone and also change the zone's configuration to make the changes persistent.

The concerned mount point is /data_new on a zone named test-zone.

root@test-zone:/# df -h /data_new
Filesystem             size   used  avail capacity  Mounted on
/data_new              500M    21K   500M     1%    /data_new
root@test-zone:/#

From the global zone we can view the loopback mount point:

root@sandbox:/# mount -v | grep data

/zonefs on /zones/test-zone/root/data_new type lofs read/write/setuid/devices/dev=2d50007 on Mon Oct  2 19:59:16 2017

Let's unmount the file system from the globasl zone and remount it as /data.

Note: If you are about to do this in a production environment then make sure that no process is currently accessing the concerned file system.

root@sandbox:/# umount /zones/test-zone/root/data_new

root@sandbox:/# mkdir /zones/test-zone/root/data

root@sandbox:/# mount -F lofs /zonefs /zones/test-zone/root/data

Now if we take a look at the mount -v output we can notice that the /zonefs file system is now mounted as /data on the zone.

root@sandbox:/# mount -v | grep data

/zonefs on /zones/test-zone/root/data type lofs read/write/setuid/devices/dev=2d50007 on Mon Oct  2 21:17:58 2017

root@sandbox:/#

Let's take a look inside the zone as well.

root@test-zone:/# df -h /data

Filesystem             size   used  avail capacity  Mounted on

/data                  500M    21K   500M     1%    /data

root@test-zone:/#

This is fine but the zone configuration still has the old mount point entry.

root@sandbox:/# zonecfg -z test-zone info fs

fs:

        dir: /data_new

        special: /zonefs

        raw not specified

        type: lofs

        options: []

So whenever the zone reboots it will mount /zonefs as /data_new. So let's correct it:

root@sandbox:/# zonecfg -z test-zone

zonecfg:test-zone> select fs dir=/data_new

zonecfg:test-zone:fs> set dir=/data

zonecfg:test-zone:fs> set special=/zonefs

zonecfg:test-zone:fs> set type=lofs

zonecfg:test-zone:fs> end

zonecfg:test-zone> verify

zonecfg:test-zone> commit

zonecfg:test-zone> exit

root@sandbox:/#

Now if we view the fs info via zonecfg we observe that the modifications have been updated.

root@sandbox:/# zonecfg -z test-zone info fs

fs:

        dir: /data

        special: /zonefs

        raw not specified

        type: lofs

        options: []

root@sandbox:/#

The /zonefs file system itself is of type zfs.

root@sandbox:/# mount -v | grep zonefs | grep zfs

rpool/zonefs on /zonefs type zfs read/write/setuid/devices/nonbmand/exec/xattr/atime/dev=2d50007 on Mon Oct  2 19:35:10 2017

root@sandbox:/# df -h /zonefs

Filesystem             size   used  avail capacity  Mounted on

rpool/zonefs           500M    21K   500M     1%    /zonefs

root@sandbox:/#

Using truss to track system callls in Solaris

The truss command in Solaris is used to trace system/library calls made by new or existing processes. A system call is a C library that requests and interacts with kernel services.

The truss command is very helpful in debugging process hung and core dump issues. It can also be used to view which processes are taking more time and what parameters are being passed for each system call.

To demonstrate the usage I've written a small script which runs for five iterations, prints something to stdout, runs the date command and sleeps for 5 seconds.

root@sandbox:/# cat hup.bash
#!/bin/bash

i=0
while [ $i -le 5 ]

do
echo "printting endlessly"
date
sleep 5
i=$[$i+1]
done


When I ran the script here's what I got on the terminal:

root@sandbox:/# ./hup.bash
printting endlessly
Mon Oct  2 12:56:46 IST 2017
printting endlessly
Mon Oct  2 12:56:51 IST 2017
printting endlessly
Mon Oct  2 12:56:56 IST 2017
printting endlessly
Mon Oct  2 12:57:01 IST 2017
printting endlessly
Mon Oct  2 12:57:06 IST 2017
printting endlessly
Mon Oct  2 12:57:11 IST 2017


On another terminal I did a pgrep for the process id (PID) of the script and ran truss over it.

root@sandbox:/# pgrep hup
1446
root@sandbox:/# truss -p 1446
waitid(P_ALL, 0, 0x08047A70, WEXITED|WTRAPPED) (sleeping...)
waitid(P_ALL, 0, 0x08047A70, WEXITED|WTRAPPED)  = 0
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
sigaction(SIGINT, 0x08047AA0, 0x08047B10)       = 0
setcontext(0x080479B0)
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
write(1, " p r i n t t i n g   e n".., 20)      = 20
lwp_sigmask(SIG_SETMASK, 0x00020002, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
fork1()                                         = 1453
lwp_sigmask(SIG_SETMASK, 0x00020002, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
    Received signal #18, SIGCLD [caught]
      siginfo: SIGCLD CLD_EXITED pid=1453 status=0x0000
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
waitid(P_ALL, 0, 0x08047630, WEXITED|WTRAPPED|WNOHANG) = 0
waitid(P_ALL, 0, 0x08047630, WEXITED|WTRAPPED|WNOHANG) Err#10 ECHILD
setcontext(0x08047530)
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
sigaction(SIGINT, 0x08047A20, 0x08047A90)       = 0
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
sigaction(SIGINT, 0x08047A10, 0x08047A80)       = 0
lwp_sigmask(SIG_SETMASK, 0x00020002, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
fork1()                                         = 1454
lwp_sigmask(SIG_SETMASK, 0x00020002, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
sigaction(SIGINT, 0x08047AB0, 0x08047B20)       = 0
waitid(P_ALL, 0, 0x08047A70, WEXITED|WTRAPPED) (sleeping...)
waitid(P_ALL, 0, 0x08047A70, WEXITED|WTRAPPED)  = 0
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
sigaction(SIGINT, 0x08047AA0, 0x08047B10)       = 0
setcontext(0x080479B0)
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
write(1, " p r i n t t i n g   e n".., 20)      = 20
lwp_sigmask(SIG_SETMASK, 0x00020002, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
fork1()                                         = 1457
lwp_sigmask(SIG_SETMASK, 0x00020002, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
    Received signal #18, SIGCLD [caught]
      siginfo: SIGCLD CLD_EXITED pid=1457 status=0x0000
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
waitid(P_ALL, 0, 0x08047630, WEXITED|WTRAPPED|WNOHANG) = 0
waitid(P_ALL, 0, 0x08047630, WEXITED|WTRAPPED|WNOHANG) Err#10 ECHILD
setcontext(0x08047530)
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
sigaction(SIGINT, 0x08047A20, 0x08047A90)       = 0
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
sigaction(SIGINT, 0x08047A10, 0x08047A80)       = 0
lwp_sigmask(SIG_SETMASK, 0x00020002, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
fork1()                                         = 1458
lwp_sigmask(SIG_SETMASK, 0x00020002, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
sigaction(SIGINT, 0x08047AB0, 0x08047B20)       = 0
waitid(P_ALL, 0, 0x08047A70, WEXITED|WTRAPPED) (sleeping...)
waitid(P_ALL, 0, 0x08047A70, WEXITED|WTRAPPED)  = 0
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
sigaction(SIGINT, 0x08047AA0, 0x08047B10)       = 0
setcontext(0x080479B0)
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
write(1, " p r i n t t i n g   e n".., 20)      = 20
lwp_sigmask(SIG_SETMASK, 0x00020002, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
fork1()                                         = 1461
lwp_sigmask(SIG_SETMASK, 0x00020002, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
    Received signal #18, SIGCLD [caught]
      siginfo: SIGCLD CLD_EXITED pid=1461 status=0x0000
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
waitid(P_ALL, 0, 0x08047630, WEXITED|WTRAPPED|WNOHANG) = 0
waitid(P_ALL, 0, 0x08047630, WEXITED|WTRAPPED|WNOHANG) Err#10 ECHILD
setcontext(0x08047530)
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
sigaction(SIGINT, 0x08047A20, 0x08047A90)       = 0
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
sigaction(SIGINT, 0x08047A10, 0x08047A80)       = 0
lwp_sigmask(SIG_SETMASK, 0x00020002, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
fork1()                                         = 1462
lwp_sigmask(SIG_SETMASK, 0x00020002, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
sigaction(SIGINT, 0x08047AB0, 0x08047B20)       = 0
waitid(P_ALL, 0, 0x08047A70, WEXITED|WTRAPPED) (sleeping...)
waitid(P_ALL, 0, 0x08047A70, WEXITED|WTRAPPED)  = 0
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
sigaction(SIGINT, 0x08047AA0, 0x08047B10)       = 0
setcontext(0x080479B0)
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
write(1, " p r i n t t i n g   e n".., 20)      = 20
lwp_sigmask(SIG_SETMASK, 0x00020002, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
fork1()                                         = 1467
lwp_sigmask(SIG_SETMASK, 0x00020002, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
sigaction(SIGINT, 0x08047A20, 0x08047A90)       = 0
waitid(P_ALL, 0, 0x080479E0, WEXITED|WTRAPPED)  = 0
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
sigaction(SIGINT, 0x08047A10, 0x08047A80)       = 0
lwp_sigmask(SIG_SETMASK, 0x00020002, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
fork1()                                         = 1468
lwp_sigmask(SIG_SETMASK, 0x00020002, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
sigaction(SIGINT, 0x08047AB0, 0x08047B20)       = 0
waitid(P_ALL, 0, 0x08047A70, WEXITED|WTRAPPED) (sleeping...)
waitid(P_ALL, 0, 0x08047A70, WEXITED|WTRAPPED)  = 0
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
sigaction(SIGINT, 0x08047AA0, 0x08047B10)       = 0
setcontext(0x080479B0)
lwp_sigmask(SIG_SETMASK, 0x00020000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
lwp_sigmask(SIG_SETMASK, 0x00000000, 0x00000000) = 0xFFBFFEFF [0x0000FFFF]
read(255, 0x080FCA08, 95)                       = 0
_exit(0)


While the truss command was tracing my script I also ran ptree on the script to view the PIDs of the sub shells it was creating just to have a more thorough picture of what was going on.

I looped that over while to view the ptree output continously throughout the lifetime of the script execution.

root@sandbox:/# while true ; do ptree 1446 ;sleep 4; done
565   /usr/lib/ssh/sshd
  804   /usr/lib/ssh/sshd
    805   /usr/lib/ssh/sshd
      838   -bash
        1446  /bin/bash ./hup.bash
          1454  sleep 5
565   /usr/lib/ssh/sshd
  804   /usr/lib/ssh/sshd
    805   /usr/lib/ssh/sshd
      838   -bash
        1446  /bin/bash ./hup.bash
          1458  sleep 5
565   /usr/lib/ssh/sshd
  804   /usr/lib/ssh/sshd
    805   /usr/lib/ssh/sshd
      838   -bash
        1446  /bin/bash ./hup.bash
          1462  sleep 5
565   /usr/lib/ssh/sshd
  804   /usr/lib/ssh/sshd
    805   /usr/lib/ssh/sshd
      838   -bash
        1446  /bin/bash ./hup.bash
          1462  sleep 5
565   /usr/lib/ssh/sshd
  804   /usr/lib/ssh/sshd
    805   /usr/lib/ssh/sshd
      838   -bash
        1446  /bin/bash ./hup.bash
          1468  sleep 5



Now let's try to briefly understand and interpret the truss output in the next few lines:

The sigaction() function allows the calling process to examine or specify the action to be taken on delivery of a specific signal.

The setcontext() function restores the user context pointed to by ucp. A successful call to setcontext() does not return; program execution resumes at the point specified by the ucp argument passed to setcontext().

The write() function will write from the buffer to the file associated with the open file descriptor. For our example the write function will write the strings "printing endlessly" to the terminal.

The programmer can control which signals will be blocked by the running application process by setting a signal mask which is a bit array. SIG_SETMASK specifies that the new mask should replace the old mask. Signals are blocked if the  corresponding  bit in mask is a 1; the macro sigmask is provided to construct the mask for a given signum.

The fork() function create a new process. The address space of the new process (child process) is an exact copy of the address space of the calling process (parent process). In our example the first fork() function creates a child process for executing the date command.
This child process receives the SIGCLD signal immediately after execution implying that the child process status has changed as it exited after completing execution.

The waitid() function suspends the calling/parent process until one of its child processes changes state. It records the current state of a child in the structure pointed to by infop. It returns immediately if a child process changed state prior to the call.
Once the chiild process termination is acknowledged by the parent process and it's entry removed from the process table, the parent process continues it's execution run.

Next we see another call to the fork() function this time executing the 5 second sleep mentioned in the script.

Notice that the signal mask is set after each fork() system call.

This continues for five iterations specified in the script.

The read() function here towards the end of the truss output indicates an end of file since no process has the pipe or file descriptor open for writting.
Finally we exit after the completion of the fifth iteration of the script using the _exit() function to terminate the process.

I kept the ptree command running continously because I wanted to demonstrate how the new PIDs for the sleep child process are being generated by the fork() system call being executed. In the truss output, the fork() function gives the process id of the child process everytime it creates one.
Ptree did not show the child process for the date command being run as perhaps the context switch was too fast. I am open to other justifications though.


In the above scenario we executed the truss command on a script but we can do the same for a operating system command as well to better understand its behavior or perform some troubleshooting if the command is not generating the intented results.

Here is an example of using truss on the date command:

root@sandbox:/# truss -d date
Base time stamp:  1506928158.6656  [ Mon Oct  2 12:39:18 IST 2017 ]
 0.0000 execve("/usr/bin/date", 0x08047DE8, 0x08047DF0)  argc = 1
 0.0183 mmap(0x00000000, 4096, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_ANON, -1, 0) = 0xFEFF0000
 0.0184 resolvepath("/usr/lib/ld.so.1", "/lib/ld.so.1", 1023) = 12
 0.0186 resolvepath("/usr/bin/date", "/usr/bin/date", 1023) = 13
 0.0186 sysconfig(_CONFIG_PAGESIZE)                     = 4096
 0.0188 stat64("/usr/bin/date", 0x08047B80)             = 0
 0.0189 open("/var/ld/ld.config", O_RDONLY)             Err#2 ENOENT
 0.0190 stat64("/lib/libc.so.1", 0x08047420)            = 0
 0.0191 resolvepath("/lib/libc.so.1", "/lib/libc.so.1", 1023) = 14
 0.0192 open("/lib/libc.so.1", O_RDONLY)                = 3
 0.0193 mmap(0x00010000, 32768, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_ALIGN, 3, 0) = 0xFEFB0000
 0.0195 mmap(0x00010000, 1212416, PROT_NONE, MAP_PRIVATE|MAP_NORESERVE|MAP_ANON|MAP_ALIGN, -1, 0) = 0xFEE80000
 0.0196 mmap(0xFEE80000, 1102437, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_TEXT, 3, 0) = 0xFEE80000
 0.0196 mmap(0xFEF9E000, 30183, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_INITDATA, 3, 1105920) = 0xFEF9E000
 0.0198 mmap(0xFEFA6000, 4240, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANON, -1, 0) = 0xFEFA6000
 0.0198 munmap(0xFEF8E000, 65536)                       = 0
 0.0200 memcntl(0xFEE80000, 124080, MC_ADVISE, MADV_WILLNEED, 0, 0) = 0
 0.0201 close(3)                                        = 0
 0.0204 mmap(0x00010000, 24576, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_ANON|MAP_ALIGN, -1, 0) = 0xFEF90000
 0.0205 munmap(0xFEFB0000, 32768)                       = 0
 0.0206 getcontext(0x080479F0)
 0.0207 getrlimit(RLIMIT_STACK, 0x080479E8)             = 0
 0.0208 getpid()                                        = 1052 [1051]
 0.0209 lwp_private(0, 1, 0xFEF92A00)                   = 0x000001C3
 0.0210 setustack(0xFEF92A60)
 0.0211 sysi86(SI86FPSTART, 0xFEFA6740, 0x0000133F, 0x00001F80) = 0x00000001
 0.0212 brk(0x08062ED0)                                 = 0
 0.0213 brk(0x08064ED0)                                 = 0
 0.0214 time()                                          = 1506928158
 0.0215 brk(0x08064ED0)                                 = 0
 0.0216 brk(0x08066ED0)                                 = 0
 0.0217 open("/usr/share/lib/zoneinfo/Asia/Calcutta", O_RDONLY) = 3
 0.0218 fstat64(3, 0x08047C30)                          = 0
 0.0219 read(3, " T Z i f\0\0\0\0\0\0\0\0".., 109)      = 109
 0.0220 close(3)                                        = 0
 0.0221 sysconfig(_CONFIG_PAGESIZE)                     = 4096
 0.0222 ioctl(1, TCGETA, 0x08047C54)                    = 0
 0.0223 fstat64(1, 0x08047BC0)                          = 0
Mon Oct  2 12:39:18 IST 2017
 0.0224 write(1, " M o n   O c t     2   1".., 29)      = 29
 0.0225 _exit(0)
root@sandbox:/#

The -d option prints a timestamp along side each operation being performed.

if we are interested in viewing only the number, names and time duration of the various system calls being executed while a command is run then we may use the -c option with truss as shown below:

root@sandbox:/# truss -c -d date

Mon Oct  2 12:43:24 IST 2017

syscall               seconds   calls  errors

_exit                    .000       1

read                     .000       1

write                    .000       1

open                     .000       3       1

close                    .000       2

time                     .000       1

brk                      .000       4

getpid                   .000       1

sysi86                   .000       1

ioctl                    .000       1

execve                   .000       1

getcontext               .000       1

setustack                .000       1

mmap                     .000       7

munmap                   .000       2

getrlimit                .000       1

memcntl                  .000       1

sysconfig                .000       2

lwp_private              .000       1

resolvepath              .000       3

stat64                   .000       2

fstat64                  .000       2

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

sys totals:              .000      40      1

usr time:                .000

elapsed:                 .020

I hope this article was helpful to you and I thank you for reading.