Pair “Listen queue overflow” FreeBSD errors with pcb

Just yesterday, after an upgrade to MySQL 5.7.12, saw plenty of errors were being logged in the system:

sonewconn: pcb 0xfffff8006311c870: Listen queue overflow: 151 already in queue awaiting acceptance (1 occurrences)
sonewconn: pcb 0xfffff8006311c870: Listen queue overflow: 151 already in queue awaiting acceptance (1 occurrences)
sonewconn: pcb 0xfffff8006311c870: Listen queue overflow: 151 already in queue awaiting acceptance (1 occurrences)
sonewconn: pcb 0xfffff8006311c870: Listen queue overflow: 151 already in queue awaiting acceptance (1 occurrences)

There is a great post that explains how to find the culprit. In a nutshell, there are two quick options:

  1. Use “lsof -itcp -stcp:listen -P” and grep for pcb.
  2. Or since “the overflow happens when the queue is at about 150% capacity” (as mentioned in the original post), it’s possible to match the number from the error (151 in my case) with an output from “netstat -an -p tcp -L”.

In my case that was trivial as both Postfix and Dovecot complained about missing libmysqlclient.so.18 shared library which was replaced with libmysqlclient.so.20 after the upgrade. Rebuilding from ports and restarting both of them fixed the issue and no hassling with kern.ipc.somaxconn was needed.

Have stalled snmpd in recvfrom()? Check Recv-Q

Not so while ago I had an issue with a monitoring system that paged about SNMP checks failing on a number of servers. Quick checking here and there (logs, strace, tcpdump, etc.) revealed that snmpd had stalled in recvfrom() without sending a single packet out in response to the constant queries from our monitoring system. Everything seemed to be ok except “netstat -s” that showed a steady increase in “Udp: packet receive errors” counter. Summon ss to the rescue:

# ss -ianump \( sport = *:161 \)
State      Recv-Q Send-Q                                                                                       Local Address:Port                                                                                         Peer Address:Port
UNCONN     262680 0                                                                                                        *:161                                                                                                     *:*      users:(("snmpd",52984,7))

Matching 262680 with “sysctl net.core.rmem_default” suggested that the receiving buffers (Recv-Q) were filling up but why Taking a close look at the logs returned the following segfault:

cmanicd[55673]: segfault at 0 ip 00007f041e721081 sp 00007f040e16c700 error 4 in libnetsnmp.so.20.0.0[7f041e6a1000+a0000]

It turned out to be a well known issue with NIC Agent (CMANICD):
http://h20564.www2.hpe.com/hpsc/doc/public/display?docId=emr_na-c04912220&sp4ts.oid=316583

So it looked to be our guy. Starting cmanicd back immediately solved the problem:

[root@slon02db12 ~]# ss -ianump \( sport = *:161 \)
State      Recv-Q Send-Q                                                                                       Local Address:Port                                                                                         Peer Address:Port
UNCONN     0      0                                                                                                        *:161                                                                                                     *:*      users:(("snmpd",52984,7))

Recv-Q was dropped to zero and a server became green in the monitoring dashboard. Bingo. Problem solved so now it’s time for the upgrade.

Btw, If you don’t know how to read Linux segfault message (I didn’t know that myself before this issue) then the following note could fix that:

Nov 27 15:26:19 machine kernel: fmg[6335]: segfault at 00000000ffffd2dc rip 00000000ffffd2dc rsp 00000000ffffd1bc error 15

What does the kernel message mean, in detail?

  • The rip value is the instruction pointer register value, the rsp is the stack pointer register value.
  • The error value is a bit mask of page fault error code bits (from arch/x86/mm/fault.c):
  • Raw
     *   bit 0 ==    0: no page found       1: protection fault
     *   bit 1 ==    0: read access         1: write access
     *   bit 2 ==    0: kernel-mode access  1: user-mode access
     *   bit 3 ==                           1: use of reserved bit detected
     *   bit 4 ==                           1: fault was an instruction fetch
  • Here’s error bit definition:
  • Raw
    enum x86_pf_error_code {
      PF_PROT   =       1 << 0,
      PF_WRITE  =       1 << 1,
      PF_USER   =       1 << 2,
      PF_RSVD   =       1 << 3,
      PF_INSTR  =       1 << 4,
    };

In my case error code was 4 which means cmanicd tried to access address zero from the user space which reeks a NULL pointer dereference.

Do initrd dance before turning Linux physical server into VM

If one day you decide to convert your physical server to a VM, which could be easily achieved if all its disks are presented from SAN, then don’t forget to rebuild initrd beforehand. Otherwise you would see something similar to this:

No device found
Scanning and configuring dmraid supported devices
Scanning logical volumes
  Reading all physical volumes. This may take a while...
  No volume groups found
Activating logical volumes
  Volume group "VolGroup00" not found
Trying to resume from /dev/VolGroup00/LogVol01
Unable to access resume device (/dev/VolGroup00/LogVol01)
Creating root device.
Mounting root filesystem.
mount: could not find filesystem '/dev/root'
Setting up other filesystems.
Setting up new root fs
setuproot: moving /dev failed: No such file or directory
no fstab.sys, mounting internal defaults
setuproot: error mounting /proc: No such file or directory
setuproot: error mounting /sys: No such file or directory
Switching to new root and running init
unmount old /dev
unmount old /proc
unmount old /sys
switchroot: mount failed: No such file or directory 
Kernel panic - not syncing: Attempted to kill init! 

Also, if your SAN disks are multipathed, which is an obvious and the only correct choice, then you must (according to RedHat note) to disable multipath by editing /etc/sysconfig/mkinitrd/multipath, otherwise the system won’t boot:

# vi /etc/sysconfig/mkinitrd/multipath MULTIPATH=no

Root Cause
The multipath option should only be set to YES if you your root volume (/) is on a multipathed device
If multipath is enabled with root (/) on a local device, multipathing will enable at boot time and lock down the device
If the device is locked down, fsck will be unable to open it for checking

There are two options to rebuild initrd:

  1. Use mkinitrd or dracut, depending on the OS version you’re currently on, and pre-build a new initrd before detaching the disks from the old system.
  2. If the system has been already converted to a VM, .i.e. all disks from the old system have been detached and presented as RDMs to a new VM, then boot from a rescue disk, and chroot to /mnt/sysimage (if you are running RedHat or CentOS) and run mkinitrd or dracut from their. Keep in mind that /boot partition as well as /sys must be mounted in the chrooted environment or, again, your system will not fly.
  3. mount --bind /proc /mnt/sysimage/proc
    mount --bind /dev /mnt/sysimage/dev
    mount --bind /sys /mnt/sysimage/sys

Good luck.

Workaround for Tomcat7 on Linux, JDBC and javax.naming.NamingException

A few days ago I was dabbling with JDBC and Tomcat7 and the configuration that seemingly had no issues resulted in the following error in the log file:

org.apache.catalina.core.NamingContextListener addResource
WARNING: Failed to register in JMX: javax.naming.NamingException: Could not create resource factory instance
[Root exception is java.lang.ClassNotFoundException: org.apache.tomcat.dbcp.dbcp.BasicDataSourceFactory]

Thankfully, Google pointed me to this post at stackoverflow.com which had both the solution and the link to the details behind this behaviour.

In the nutshell, the workaround looks like the following:

  1. Grab tomcat-dbcp-version.jar from Maven that
    matches the version of Tomcat you are running and place it in $CATALINA_HOME/lib. Copying it somewhere else and creating a link also works.
  2. Update <Resource/> section in context.xml file by adding the following line:
    factory="org.apache.commons.dbcp.BasicDataSourceFactory"
  3. Restart Tomcat

Peace.

P.S. Did a quick test and it looks like that FreeBSD distributes tomcat-dbcp.jar as part of its tomcat package:

# pkg query %Fp tomcat7 | grep dbcp
/usr/local/apache-tomcat-7.0/lib/tomcat-dbcp.jar

“Change master” to the rescue or how to revive MySQL replication

Sometime ago had an issue with MySQL replication that consecutively faulted with two different errors. Initially with this one:

Last_Error: Relay log read failure: Could not parse relay log event entry. The possible reasons are: the master’s binary log is corrupted (you can check this by running ‘mysqlbinlog’ on the binary log), the slave’s relay log is corrupted (you can check this by running ‘mysqlbinlog’ on the relay log), a network problem, or a bug in the master’s or slave’s MySQL code. If you want to check the master’s binary log or slave’s relay log, you will be able to know their names by issuing ‘SHOW SLAVE STATUS’ on this slave.

Thankfully, this error was easy to fix with the help of change master SQL statement:

change master to master_log_file='mysql-bin.000047', master_log_pos=152667618;

However, the second error kicked in immediately right after that:

Got fatal error 1236 from master when reading data from binary log: ‘Client requested master to start replication from impossible position; the first event ‘mysql-bin.000048’ at 223481321, the last event read from ‘/var/log/mysql/mysql-bin.000048’ at 4, the last byte read from ‘/var/log/mysql/mysql-bin.000048′ at 4.’

This one was also a no-brainer if you know how to fix them

Armed with mysqlbinlog it was easy to verify that there were no logs past 223481321 position:

mysqlbinlog --base64-output=decode-rows --verbose --start-position=223481321 ./mysql-bin.000048 
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;

Thus the proper solution in that case was to manually point the slave to the next available bin log:

change master to master_log_file='mysql-bin.000049', master_log_pos=4;

DTrace is limping when rootless is enabled

Just learnt that DTrace can’t be run at full pelt when rootless Mac OS X feature is enabled. For example, iotop ends like this:

: probe description io:::start does not match any probes

And it seems that the only way out is to boot into a rescue mode and run csrutil disable to turn off the protection mode. Only after that you could call your best friends like iotop, iosnoop and many others which are published at DTrace Book page.
Btw, if you haven’t bought it yet I highly recommend to do so.

Interview fizzle as a chance to get better

Not a long ago I had one of those humiliating moments when a simple question makes you numb a or even worse – you begin to mumble an absolute rubbish. That what exactly what has happened to me recently and being an afterthought person (which, of course, doesn’t give me any advantage) I decided to do some homework/recap o the questions I’ve failed misarebly.

  • Linux PIPE
  • – Read “man 2 pipe” as it basically says it all in a single sentene:

    pipe() creates a pair of file descriptors, pointing to a pipe inode, and places them in the array pointed to by filedes. filedes[0] is for reading, filedes[1] is for writing.

    – Want to go deeper then the source code is the best place to start:

  • Linux VM overcommit
  • – Again, start from reading the documentation.
    – Take a look at the code to figure out how the heuristic overcommit handling works. Especially, __vm_enough_memory() which is run by security_vm_enough_memory_mm(), which in turn could be called from different places, e.g. mmap_region(), acct_stack_growth(), do_brk(), insert_vm_struct(), dup_mmap().

  • MALLOC
  • – “man 3 malloc”, “man 2 mallopt”
    – Go through do_brk() code.

  • Swappiness
    – Read vm sysctl documentation about the swappiness parameter.
    – swappiness comes into play in get_scan_count() which is called from shrink_lruvec().
    – If the code looks murky, take a look at the answer published at unix.stackexchange.com which goes in a greater details about vm.swappiness.
    – Read about Split LRU

And of course, buy, read and re-read Understanding the Linux Kernel even if it’s a bit dated.