Force the allocation of an elasticsearch index on restore

Today, I had occasion to delete an elasticsearch index and restore it from a snapshot. Normally this is a straightforward process, but this particular cluster has been in a yellow state for a while because all of its nodes are up against the low-disk watermark and many of its replica shards are thus sitting unallocated. We’re working on a fix for that, but in the meantime I needed to restore a small index urgently.

I only discovered this would be a problem after I tried and failed to restore the snapshot. I figured that a small index should be able to slip between the cracks, especially if I had deleted something of a similar size immediately beforehand. But the shard allocator had other ideas, and all the restored shards (both primary and replica) went straight into an unallocated state and sat there unblinking.

I found some old indexes that I could safely delete to free up a little space, but the shard allocator started work on the long-pending replica shards rather than the (surely more important!) primaries of my fresh restore. Even after setting the index priority to 1000 on the restored index, it still preferred to allocate old replicas.

I ended up forcing the allocation by hand, after combining the techniques here, here and here. The trick is to get a list of the shard numbers for the offending index and call the command “allocate_empty_primary” on each, which forces them into an allocated (but empty) state. Once they are allocated, we can then retry the restore from snapshot.

Defining BAD_INDEX and TARGET_NODE appropriately, we incant:

curl -q -s "http://localhost:9200/_cat/shards" | egrep "$BAD_INDEX" | \
  while read index shard type state; do
    if [ $type = "p" ]; then
      curl -X POST "http://localhost:9200/_cluster/reroute" -d "{commands\" : [ { \"allocate_empty_primary\": { \"index\": \"$index\", \"shard\": $shard, \"node\": \"$TARGET_NODE\", \"accept_data_loss\": true } } ] }"
    fi
  done

 

This produced an ungodly amount of output, as the shard allocator proceeded to restructure its entire work queue. But the offending index had indeed been allocated with a higher priority than the old replicas, and a repeat attempt at restoring from snapshot worked.

/var/log/ksymoops modprobe error flood with a Xen kernel

I have a small virtual server in Linode that I use for various public-facing things such as serving web pages, a small Debian repository, email etc. Unfortunately it has a bad habit of filling up /var/log – I did say it was small.

I noticed today a lot of space being used up in `/var/log/ksymoops`, every few seconds and all of the form:

xen:~# tail -f /var/log/ksymoops/20180502.log
20180502 183837 start /sbin/modprobe -q -- net-pf-0 safemode=1
20180502 183837 probe ended
20180502 183842 start /sbin/modprobe -q -- net-pf-0 safemode=1
20180502 183842 probe ended
20180502 183842 start /sbin/modprobe -q -- net-pf-0 safemode=1
20180502 183842 probe ended
20180502 183842 start /sbin/modprobe -q -- net-pf-0 safemode=1
20180502 183842 probe ended
20180502 183842 start /sbin/modprobe -q -- net-pf-0 safemode=1
20180502 183842 probe ended
20180502 183847 start /sbin/modprobe -q -- net-pf-0 safemode=1
20180502 183847 probe ended
20180502 183847 start /sbin/modprobe -q -- net-pf-0 safemode=1
20180502 183847 probe ended
20180502 183847 start /sbin/modprobe -q -- net-pf-0 safemode=1
20180502 183847 probe ended
20180502 183847 start /sbin/modprobe -q -- net-pf-0 safemode=1
20180502 183847 probe ended

What’s more, these log files are not subject to logrotate by default, so I have them going back years, for as long as the VM has existed. While this is somewhat concerning, it does allow me to work out what happened.

The ksymoops logfiles are relatively sparse (a few lines every month or so) up until the date last year that I dist-upgraded the server from Debian 8 to 9. Then the dam broke and it has been throwing a batch of four errors like the above every five seconds since, day and night. Something somewhere is calling modprobe in a very tight loop, and it appears to be related to a package upgrade.

I managed to track down the offending process by replacing /sbin/modprobe with a script that called `sleep 100000` and running `ps axf`. It turns out that it had been called directly from one of the kworkers. If all four kworkers (2xHT) are doing the same thing, that would explain the pattern of errors.

Remember that this is in Linode – their VMs run under Xen paravirtualisation with non-modular kernels. Which means that modprobe, lsmod etc. have no effect – they crash out with the following error if you try to use them:

xen:~# lsmod
Module Size Used by Not tainted
lsmod: QM_MODULES: Function not implemented

This is only to be expected, as the VM’s modutils won’t talk to the Xen para-v kernel. But why is a para-v kernel worker triggering modprobe, when failure is guaranteed?

Luckily, I don’t have to care.

ksymoops is non-optional, but it can only write its logfiles if `/var/log/ksymoops` exists. The solution is simple.

rm -rf /var/log/ksymoops

Peace and quiet.

warning: connect to Milter service unix:/var/run/opendkim/opendkim.sock: No such file or directory

I currently run a postfix mailserver and have souped it up to use all the latest security features (see Hamzah Khan’s blog for a good tutorial). One thing that had been bothering me though was the appearance of the above milter connection failures in the logs – even though these seemed to fail gracefully it was a worrying sign that something was Just Not Right.

After a lot of trial and error, it seems that the culprit is my postfix chroot jail. I had originally attempted to compensate for this by defining “Socket /var/spool/postfix/var/run/opendkim/opendkim.sock” in /etc/opendkim.conf, but even so, postfix was throwing errors (and no, putting the socket in the standard location doesn’t work – I tried that!). It turns out that postfix sometimes attempts to connect to the socket from inside the jail, and sometimes from outside. The solution is to create a soft link in the standard location pointing to the real socket inside the jail.

Of course I could have reconfigured it to bind to a localhost port instead, but the soft link was less work.

Openvpn “WARNING: Bad encapsulated packet length from peer”

xkcd979

I run a VPN from my Linode VM for various reasons, the most important of which is so that I and other family members can submit email over SMTP without having to worry about braindead networks that block outgoing port 587 for makey-uppey “security” reasons. Since my brother and I both have jobs that entail connecting to random corporate wireless networks, this is critical.

The problem was that I was running openvpn over the standard port 1194, which is also blocked by many networks – including my own employer’s. Openvpn uses a mock-HTTP protocol that will work over HTTP proxies, so I configured squid on the server’s port 8080 to forward packets to localhost:1194 and told the laptop openvpn client to use myserver:8080 as a proxy.

This worked well for my employer’s network, but did not agree with the guest wireless network of one of my clients, which had absolutely no problem with port 1194, but uses its own transparent proxy that doesn’t play nice with daisychained proxies. I kept having to comment and uncomment the proxy directive in my laptop’s openvpn.conf and restart, depending on location.

So I decided to do it the proper way, by connecting directly to openvpn on port 8080. My employer’s network would allow this through directly, and the client’s network should route through its transparent proxy without complaint. I don’t want to turn off port 1194 though, as this would rudely nobble all my brother’s devices, so I configured the server’s iptables to masquerade 8080->1194. I could then remove the proxy config from the laptop, change its connecting port to 8080 and restart the vpn client.

Problem solved! Except then I started getting the following error in my server logs:

Apr 28 13:02:43 xxx ovpn-server[13110]: xxx.xxx.xxx.xxx:57458 WARNING: Bad encapsulated packet length from peer (17231), which must be > 0 and <= 1560 -- please ensure that --tun-mtu or --link-mtu is equal on both peers -- this condition could also indicate a possible active attack on the TCP link -- [Attempting restart...]

It turned out this was being generated by another client which had also been configured to use the proxy, but which had slipped my mind. The error stems from the client connecting to an openvpn port directly but sending requests formatted for a web proxy. Not sure why it shows up as an MTU error, but changing the other client config to match the laptop solved it.

Windows Script Host error 800c0019 (VBScript)

Came across this gem today on a machine that had recently been upgraded to Server 2008:

Error: System error: -2146697191
Code: 800C0019
Source: msxml3.dll

Turns out that a custom VBScript was sending a form to one of our secure web servers and the certificate chain couldn’t be verified up to the root (even though we bought it from a reputable source). Adding the offending root certificate to the trusted root certificate authorities database fixed the problem.

This does not seem to be documented anywhere on the internet yet, so here it is.