I recently faced a problem where an application stop working after
transferring a system from an old Sun E450 running Solaris 8 to a more recent
Sun Fire V490 running Solaris 10 10/09 with the Solaris 8 Container software
stack. Although all went smooth during the P2V, and most of all applications
runs pretty well in the non-global zone, we encounter a problem where the
Courier SMTP product didn't answer anymore to remote connections, such as:
# telnet localhost 25
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
Connection closed by foreign host.
The fact is, the couriertcpd program is running, and listening
to the TCP port number 25.
# pfiles `pgrep couriertcpd | head -1`
5691: /usr/lib/courier/sbin/couriertcpd
Current rlimit: 1024 file descriptors
[...]
5: S_IFSOCK mode:0666 dev:366,0 ino:62871 uid:0 gid:0 size:0
O_RDWR|O_NONBLOCK FD_CLOEXEC
sockname: AF_INET 0.0.0.0 port: 25
[...]
Interestingly, here is what is logged by the Courier application:
# grep mail.info /path/to/Courier.log
XXX courieresmtpd: [ID 702911 mail.info] gdbm fatal: couldn't init cache
The problem seems located around the gdbm library which is a dependency of
Courier. So, what happened when we try to initiate a direct connection using
telnet on port 25:
# truss -alef -rall -wall -p 5691
[...]
5691/1: fork() = 245
245/1: fork() (returning as child ...) = 5691
[...]
245/1: brk(0x004136D8) = 0
245/1: brk(0x004136D8) = 0
245/1: brk(0x004336D8) Err#12 ENOMEM
245/1: write(2, " g d b m f a t a l : ", 12) = 12
245/1: write(2, 0xFF2D4D28, 19) = 19
245/1: c o u l d n ' t i n i t c a c h e
245/1: write(2, "\n", 1) = 1
245/1: llseek(0, 0, SEEK_CUR) = 0
245/1: _exit(-1)
5691/1: Received signal #18, SIGCLD, in poll() [caught]
[...]
# echo "ibase=16; `echo 004136D8 | tr [:lower:] [:upper:]`" | bc
4273880
# echo "ibase=16; `echo 004336D8 | tr [:lower:] [:upper:]`" | bc
4404952
Ok. The brk(2) function is used to change dynamically the
amount of space allocated for the calling process's data segment. So, the
process which PID is 245, forked from couriertcpd, can not
allocate more than 4273880 bytes since a try to allocate 4404952 bytes return
an error. When the brk(2) function fails, it is generally due to
one of these two major cases:
- Insufficient space exists in the swap area to support the expansion.
- The data segment size limit as set by
setrlimit(2) would be
exceeded.
At first, we decided to grow the size of the swap space in the global zone
from 4GB to 8GB (since there is no resource control on memory for this
non-global zone). As it is a full-ZFS Solaris 10 system, here are the steps to
do so:
# swap -d /dev/zvol/dsk/rpool/swap
# zfs set volsize=8G rpool/swap
# /sbin/swapadd
# swap -l
swapfile dev swaplo blocks free
/dev/zvol/dsk/rpool/swap 256,2 16 16777200 16777200
But nothing change from the couriertcpd point of view, as we
may have thought since we were able to deallocate the entire swap device from
the global zone. So, we shrink it back using the same steps as for growing it.
Then, is it possible we have reached an upper resource limitation?
The couriertcpd is executed under the daemon
identity: what are the maximum size of data segment (or heap) for the
daemon account:
# su - daemon -c "ulimit -Sd; ulimit -Hd"
unlimited
unlimited
This seems more than sufficient, not to say more. But what are the real
current limitation for the running process?
# plimit -k 5691
5691: /usr/lib/courier/sbin/couriertcpd
resource current maximum
time(seconds) unlimited unlimited
file(kbytes) unlimited unlimited
data(kbytes) 4096 4096
stack(kbytes) 8192 unlimited
coredump(kbytes) unlimited unlimited
nofiles(descriptors) 1024 1024
vmemory(kbytes) unlimited unlimited
Ok. One can argue that the 4404952 bytes size is very close to the 4096KB
(4194304 bytes) data size limitation... and yes, it is. The two points here are
the fact that the limitation is close to memory allocation size for sure, and
that there must be some settings somewhere which sets this resource limitation
since we verified it is not a the account level (the current hard limit is set
to 4096KB, thus not very unlimited). So, we tried to set the resource
limit for the running process to much higher value, and voila:
# plimit -d 65536,65536 5691
# telnet localhost 25
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
220 S0003010 ESMTP
quit
221 Bye.
Connection closed by foreign host.
Well, all seems far better this time:
# truss -alef -rall -wall -p 5691
[...]
5691/1: fork() = 4861
4861/1: fork() (returning as child ...) = 5691
[...]
4861/1: brk(0x00CF36D8) = 0
4861/1: lseek(6, 262144, SEEK_SET) = 262144
4861/1: read(6, 0x00071730, 131072) = 131072
[...]
# echo "ibase=16; `echo 00CF36D8 | tr [:lower:] [:upper:]`" | bc
13579992
So, now the memory allocation succeed at changing the space allocated up to
13579992 bytes (13262KB). We decided to set the data segment size up to 16MB,
which seems to be sufficient in our case.
We now need to find the configuration responsible for setting the size of
the data segment size to 4096KB. Looking at the courier documentation, and and
after a bit of digging on the system itself we found the responsible
configuration file, and adapt it as follow:
# grep ULIMIT= /usr/lib/courier/etc/esmtpd
#ULIMIT=4096
ULIMIT=16384
As a last validation, we made a complete reboot of the non-global zone to
verify the overall behavior, which is OK right now. As a last word, it was very
interesting problem to fight with, but I didn't understand until now why 4MB
was sufficient on an old Sun E450, and why it is not in a branded Solaris 8
non-global zone... comments welcome.
Oracle ACE