Administration

These are the pages for all my system administration woes. I rarely post happy things in this section. You have been warned.

2019-11-16 Pleroma

OK, so I tried Epicyon and it used a lot of CPU cycles doing not much. Would Pleroma fare any better?

I am ready to give it a try: Installing on Debian Based Distributions.

apt install postgresql postgresql-contrib elixir erlang erlang-dev erlang-tools erlang-parsetools erlang-ssh erlang-xmerl

Well, I was following the instructions until I got to this step:

root@sibirocobombus:/opt/pleroma# sudo -Hu pleroma mix deps.get
!!! RUNNING IN LOCALHOST DEV MODE! !!!
FEDERATION WON'T WORK UNTIL YOU CONFIGURE A dev.secret.exs
Could not find Hex, which is needed to build dependency :phoenix
Shall I install Hex? (if running non-interactively, use "mix local.hex --force") [Yn] 
** (UndefinedFunctionError) function :inets.stop/2 is undefined (module :inets is not available)
    :inets.stop(:httpc, :mix)
    (mix) lib/mix/utils.ex:560: Mix.Utils.read_httpc/1
    (mix) lib/mix/utils.ex:501: Mix.Utils.read_path/2
    (mix) lib/mix/local.ex:149: Mix.Local.read_path!/2
    (mix) lib/mix/local.ex:126: Mix.Local.find_matching_versions_from_signed_csv!/2
    (mix) lib/mix/tasks/local.hex.ex:56: Mix.Tasks.Local.Hex.run_install/1
    (mix) lib/mix/dep/loader.ex:168: Mix.Dep.Loader.with_scm_and_app/4
    (mix) lib/mix/dep/loader.ex:121: Mix.Dep.Loader.to_dep/3

This helped:

apt install erlang-inets

🙂

I also changed registrations_open to false in config/prod.secret.exs.

Tags:

Comments on 2019-11-16 Pleroma

And I wrote my first Elixir code with the help of @wim_v12e:

diff --git a/lib/mix/tasks/pleroma/user.ex b/lib/mix/tasks/pleroma/user.ex
index a3f8bc945..964209c96 100644
--- a/lib/mix/tasks/pleroma/user.ex
+++ b/lib/mix/tasks/pleroma/user.ex
@@ -442,6 +442,20 @@ defmodule Mix.Tasks.Pleroma.User do
     end
   end
 
+  def run(["list"]) do
+    start_pleroma()
+
+    Pleroma.User.Query.build(%{local: true})
+    |> Pleroma.RepoStreamer.chunk_stream(500)
+    |> Stream.each(fn users ->
+      users
+      |> Enum.each(fn user ->
+        shell_info("#{user.nickname} moderator: #{user.info.is_moderator}, admin: #{user.info.is_admin}, locked: #{user.info.locked}, deactivated: #{user.info.deactivated}")
+      end)
+    end)
+    |> Stream.run()
+  end
+
   defp set_moderator(user, value) do
     info_cng = User.Info.admin_api_update(user.info, %{is_moderator: value})

This allows me to run:

root@sibirocobombus:/opt/pleroma# sudo -Hu pleroma MIX_ENV=prod mix pleroma.user list
Compiling 1 file (.ex)
internal.fetch moderator: false, admin: false, locked: false, deactivated: false
alex moderator: false, admin: true, locked: false, deactivated: false
admin moderator: false, admin: true, locked: false, deactivated: false
kensanata moderator: false, admin: false, locked: false, deactivated: false

– Alex Schroeder 2019-11-17 13:29 UTC


For now I’m happy with Pleroma. Notice how load came back down again after switching from Epicyon to Pleroma and PostgreSQL. I wasn’t running a database before the Pleroma installation.

Load

– Alex Schroeder 2019-11-17 21:11 UTC

Add Comment

2019-11-09 Upgrading Debian from Stretch to Buster

I did it! I upgrade the server. No restart required. I was a bit intimidated by the extensive documentation. But I was fine.

First, I improved my backup. I currently use the following:

#!/bin/bash

# Using sudo rsync --archive to preserve ownership.
# Using --fake-super to avoid changes to groups and owners

echo Backing up Sibirocobombus
echo home directory
rsync --archive --fake-super --verbose --compress --delete --delete-excluded \
      --itemize-changes \
      --exclude '/home/alex/logs' \
      --exclude '/home/alex/alexschroeder.ch/share' \
      --exclude '/home/alex/planet/osr/' \
      --exclude '/home/alex/planet/indie/' \
      --exclude '.cpan/build' \
      --exclude '.cpan/sources' \
      --exclude '.cpanplus' \
      --exclude '.cpanm' \
      --exclude '.cache' \
      --exclude '.Trash' \
      --exclude '.local/share/Trash' \
      --exclude 'temp/' \
      --exclude 'pids/' \
      --exclude 'visitors.log' \
      --exclude 'referer/' \
      --exclude '.git/' \
      --rsh="ssh -p 882" \
      root@alexschroeder.ch:/home \
      /home/alex/Documents/Sibirocobombus

# https://www.debian.org/releases/buster/amd64/release-notes/ch-upgrading.en.html#data-backup
echo etc directory
rsync --archive --fake-super --verbose --compress --delete --delete-excluded \
      --itemize-changes \
      --rsh="ssh -p 882" \
      root@alexschroeder.ch:/etc \
      root@alexschroeder.ch:/var/lib/dpkg \
      root@alexschroeder.ch:/var/lib/apt/extended_states \
      root@alexschroeder.ch:/var/lib/dehydrated \
      root@alexschroeder.ch:/usr/lib/cgit/filters \
      /home/alex/Documents/Sibirocobombus

I also installed and ran apt-forktracer:

apt install apt-forktracer
apt-forktracer | sort > packages-not-from-debian

I also checked my system using dpkg --audit.

I ran everything inside script -t 2>~/upgrade-busterstep.time -a ~/upgrade-busterstep.script.

I was very afraid!

But eventually I just changed my /etc/apt/sources.list to the following:

deb http://deb.debian.org/debian buster main non-free contrib
deb http://security.debian.org/debian-security buster/updates main contrib non-free

# deb  http://ftp.debian.org/debian stretch main non-free contrib
# deb-src  http://ftp.debian.org/debian stretch main non-free contrib

# deb  http://ftp.debian.org/debian stretch-updates main non-free contrib
# deb-src  http://ftp.debian.org/debian stretch-updates main non-free contrib

# deb http://security.debian.org/ stretch/updates main non-free contrib
# deb-src http://security.debian.org/ stretch/updates main non-free contrib

I guess I should think about updates and security? Or perhaps they aren’t used anymore? I have no idea. I’ll look at this some other time.

Finally I ran the upgrade itself:

apt update
apt upgrade
apt dist-upgrade

I had two changes to system config files:

  1. in /etc/logrotate.conf I changed weeklydaily (keeping 4 days worth of logs instead of 4 weeks)
  2. in /etc/ssh/sshd_config I merged my changes with what upstream had provided

I am amazed to see that the server is still up. It didn’t even reboot. Let me sing the praise of Debian and all the things it includes and all the volunteers and maintainers and testers—thank you all. ❤️

I think I’m going to be fine. 😃

I noticed that I had to reinstall all my pip3 stuff.

For the Mastodon bots:

pip3 install Mastodon.py cairosvg html2text

For Epicyon:

pip3 install requests commentjson beautifulsoup4 pycryptodome

My monitoring also broke down.

Monit stopped monitoring a bunch of stuff because the checksums failed.

Munin isn’t running at all...

Well, time to look at this tomorrow!

Tags:

Comments on 2019-11-09 Upgrading Debian from Stretch to Buster

Cleaning up non-default config files... I installed debsums and use debsums -ce to find config files that I have changed.

Then I use a little script I got from StackExchange to find the diff.

#!/bin/bash

# Usage: debdiffconf.sh FILE
# Produce on stdout diff of FILE against the first installed Debian package
# found that provides it.
# Returns the exit code of diff if everything worked, 3 or 4 otherwise.

command -v apt-get >/dev/null 2>&1 || {
  echo "apt-get not found, this is probably not a Debian system. Aborting." >&2;
  exit 4; }
command -v apt-file >/dev/null 2>&1 || {
  echo "Please install apt-file: sudo apt-get install apt-file. Aborting." >&2;
  exit 4; }

FILE=$(readlink -f "$1")
while read PACKAGE
do
  # verify from first installed package
  if dpkg-query -W --showformat='${Status}\n' | grep installed > /dev/null
  then
    DIR=$(mktemp -d)
    cd "$DIR"
    echo "Trying $PACKAGE..." >&2
    apt-get download "$PACKAGE" >&2
    # downloaded archive is the only file present...
    ARCHIVE=$(ls)
    mkdir contents
    # extract entire archive
    dpkg-deb -x "$ARCHIVE" contents/ >&2
    if [ -f "contents$FILE" ]
    then
      # package contained required file
      diff "contents$FILE" "$FILE"
      RET=$?
      # cleanup
      cd
      rm -Rf "$DIR"
      # exit entire script as this is the main shell
      # with the return code from diff
      exit $RET
    else
      # cleanup
      cd
      rm -Rf "$DIR"
    fi
  fi
done < <(apt-file -l search "$FILE")
# if we are here, it means we have found no suitable package
echo "Could not find original package for $FILE" >&2
exit 3

And if I think the changes I made could be reverted, I run patch --reverse $FILE on the file and paste the diff seen above to revert it.

– Alex Schroeder 2019-11-10 11:38 UTC


The problem I had seems to due to changes I made to the Apache configuration. Apparently I created a special account with password to allow access to Munin from remote systems. This makes sense since I’m running Munin on the server...

*** apache24.conf~	2019-05-16 01:21:08.000000000 +0200
--- apache24.conf	2019-11-10 12:47:00.533056622 +0100
***************
*** 14,25 ****
  Alias /munin/static/ /var/cache/munin/www/static/
  
  <Directory /var/cache/munin/www>
!     Require local
      Options None
  </Directory>
  
  <Directory /usr/lib/munin/cgi>
!     Require local
      <IfModule mod_fcgid.c>
          SetHandler fcgid-script
      </IfModule>
--- 14,36 ----
  Alias /munin/static/ /var/cache/munin/www/static/
  
  <Directory /var/cache/munin/www>
!     Order allow,deny
!     Allow from all
      Options None
+     AuthUserFile /etc/munin/munin-htpasswd
+     AuthName "Munin"
+     AuthType Basic
+     require valid-user
  </Directory>
  
  <Directory /usr/lib/munin/cgi>
!     Order allow,deny
!     Allow from all
!     Options None
!     AuthUserFile /etc/munin/munin-htpasswd
!     AuthName "Munin"
!     AuthType Basic
!     require valid-user
      <IfModule mod_fcgid.c>
          SetHandler fcgid-script
      </IfModule>

– Alex Schroeder 2019-11-10 11:51 UTC

Add Comment

2019-11-09 Epicyon needs Python 3.6 which needs a Debian upgrade

I’ve tried to install Epicyon on my server but I’m running into a Python problem. I think I have everything set up correctly (my notes below) but I’m getting a syntax error in webfinger.py:

python3 webfinger.py 
  File "webfinger.py", line 81
    return f"data:application/magic-public-key,RSA.{mod}.{pubexp}"
                                                                 ^
SyntaxError: invalid syntax

I’m using Debian stable (9.11) on my server which means I have Python 3.5.3 installed. f-strings joined Python in 3.6, apparently.

So... Upgrade my server? Make Epicyon work with Python 3.5? Postpone the entire thing?

I don’t know...

Epicyon

I was more or less following the official installation instructions.

Some decisions:

  • I’m not using certbot because I am using dehydrated.
  • I don’t want to install in /etc/epicyon. Let me use /home/epicyon instead.

Install the code as root:

apt-get -y install tor python3-pip python3-socks imagemagick python3-numpy python3-setuptools python3-crypto python3-dateutil python3-pil.imagetk
pip3 install commentjson beautifulsoup4 pycryptodome
adduser --system --home=/home/epicyon --group epicyon
cd /home
git clone https://gitlab.com/bashrc2/epicyon
cd epicyon
./theme purple
chown -R epicyon:epicyon /home/epicyon

Create the demon by creating the file /etc/systemd/system/epicyon.service as follows:

[Unit]
Description=epicyon
After=syslog.target
After=network.target

[Service]
Type=simple
User=epicyon
Group=epicyon
WorkingDirectory=/home/epicyon
ExecStart=/usr/bin/python3 /home/epicyon/epicyon.py --port 443 --proxy 7156 --domain fedi.alexschroeder.ch --registration open --debug
Environment=USER=epicyon
Restart=always
StandardError=syslog
CPUQuota=30%

[Install]
WantedBy=multi-user.target

Activate the demon:

systemctl enable epicyon
systemctl start epicyon

Check how it is doing:

journalctl -u epicyon

On my first attempt I had forgotten to install the Python modules using pip3 and saw the error messages in the journal alerting me to the fact.

As for the website, I’m using Apache. I’m on my own, now. I edited /etc/apache2/sites-enabled/100-alexschroeder.ch.conf because that’s where my site is configured and added the following:

  • a redirect from HTTP on port 80 to HTTPS on port 443
  • the right server name
  • SSL files generated by dehydrated
  • proxying to port 7156

I’m basically trusting my remaining SSL and security settings.

Here’s what I added to the site configuration:

<VirtualHost *:80>
    ServerName fedi.alexschroeder.ch
    Redirect permanent / https://fedi.alexschroeder.ch/
</VirtualHost>
<VirtualHost *:443>
    ServerName fedi.alexschroeder.ch
    SSLEngine on
    SSLCertificateFile      /var/lib/dehydrated/certs/alexschroeder.ch/cert.pem
    SSLCertificateKeyFile   /var/lib/dehydrated/certs/alexschroeder.ch/privkey.pem
    SSLCertificateChainFile /var/lib/dehydrated/certs/alexschroeder.ch/chain.pem
    SSLVerifyClient None
    ProxyPass /             http://alexschroeder.ch:7156/
</VirtualHost>

Next I had to tell my domain name service provider (Gandi) about the new subdomain. In the DNS zone file, I had to add a line for IPv4 and IPv6:

fedi 10800 IN A 178.209.50.237
fedi 10800 IN AAAA 2a02:418:6a04:178:209:50:237:1

Then I had to tell dehydrated about the new subdomain by editing /etc/dehydrated/domains.txt and changing the line for my site to:

alexschroeder.ch www.alexschroeder.ch fedi.alexschroeder.ch

With that, I was ready to regenerate the certificates (still doing everything as root). The version of dehydrated in Debian isn’t working for me so I have to use a copy of the master branch I checked out.

/home/alex/src/dehydrated/dehydrated -c

And now I should be ready!

  • the domain name server points to the right machine
  • on that machine, the web server knows how to redirect from HTTP to HTTPS for this domain
  • the web server also knows how to proxy HTTPS to port 7156 locally
  • the application is running and listening on the port

Or is it? I’m getting an error! journalctl -u epicyon shows the following:

Nov 09 14:56:01 sibirocobombus python3[27300]: Traceback (most recent call last):
Nov 09 14:56:01 sibirocobombus python3[27300]:   File "/home/epicyon/epicyon.py", line 9, in <module>
Nov 09 14:56:01 sibirocobombus python3[27300]:     from person import createPerson
Nov 09 14:56:01 sibirocobombus python3[27300]:   File "/home/epicyon/person.py", line 19, in <module>
Nov 09 14:56:01 sibirocobombus python3[27300]:     from webfinger import createWebfingerEndpoint
Nov 09 14:56:01 sibirocobombus python3[27300]:   File "/home/epicyon/webfinger.py", line 81
Nov 09 14:56:01 sibirocobombus python3[27300]:     return f"data:application/magic-public-key,RSA.{mod}.{pubexp}"
Nov 09 14:56:01 sibirocobombus python3[27300]:                                                                  ^
Nov 09 14:56:01 sibirocobombus python3[27300]: SyntaxError: invalid syntax

Tags:

Comments on 2019-11-09 Epicyon needs Python 3.6 which needs a Debian upgrade

I decided to stop Epicyon for now. It was basically using up all the CPU resources I had granted it via systemd. With no actual activity, I find that unacceptable.

Load goes up

Sometime between November 10 and 11 I managed to get it up and running and load goes up, and stays up.

– Alex Schroeder 2019-11-14 21:30 UTC


A lot of back and forth on this issue. Increase the CPU quota? Work on debugging this? What’s the problem?

Or should I just try Pleroma instead?

– Alex Schroeder 2019-11-16 22:09


I think I’ll give Pleroma a try...

systemctl stop epicyon
systemctl disable epicyon
apt remove tor python3-socks python3-numpy python3-setuptools \
  python3-crypto python3-dateutil python3-pil.imagetk

– Alex Schroeder 2019-11-17 11:09

Add Comment

2019-09-25 RAM doubled on this VM

A few days ago I received an email: if I power cycled the VM all my sites are running on, I’d get my RAM doubled for no reason. Ohhhh, cool! But...

Power cycling my server always scares me – but they promised to double my RAM if I did it… What to do! What to do? What to do‽ 😨

I did it.

Monit shows all the processes restarting

Well, actually I did a soft reset first and I think that didn’t do it! They really want me to power cycle the thing. So here we go, again! 😱

Or did it? Anyway, I did it again, but this time I really did a power toggle.

And it seems to have worked.

Munin shows RAM going from 3GB to 6GB

I don't understand all the lines on that graph, to be honest. What’s that green “committed” line doing, for example? On ServerFault somebody wrote:

Committed memory is, essentially, all the memory which has been allocated by applications, whether it’s used or not. In contrast, the “apps” is memory that is allocated AND used.

OK! Lots of unused memory allocated to apps... Looks like I have a ton of dead apps hanging around or something?

The price we pay is always interesting, of course. I’m paying 15€/month for this kernel-based virtual machine (KVM). And apparently that now gets me one core at 2.3GHz, 6GB RAM and around 75GB of disk space.

alex@sibirocobombus:~$ df -h
Filesystem      Size  Used Avail Use% Mounted on
udev            3.0G     0  3.0G   0% /dev
tmpfs           598M  7.9M  590M   2% /run
/dev/vda1        73G   32G   39G  46% /
tmpfs           3.0G     0  3.0G   0% /dev/shm
tmpfs           5.0M     0  5.0M   0% /run/lock
tmpfs           3.0G     0  3.0G   0% /sys/fs/cgroup
tmpfs           598M     0  598M   0% /run/user/1000

No idea how that compares to others.

Tags:

Add Comment

2019-07-24 Alternative multips plugins for Munin

I learned about multips and multips_memory today but found that I couldn’t use them for my purposes.

The main problem is that both of them depend on the process name. Let me illustrate the problem:

# ps -eo rss,comm
...
29908 /home/alex/farm
30836 /home/alex/farm
 7596 /home/alex/farm
24156 /home/alex/farm
...

But I want to match on the command name:

# ps -eo rss,command
...
29908 /home/alex/farm/communitywiki2.pl
30836 /home/alex/farm/campaignwiki2.pl
 7596 /home/alex/farm/emacswiki2.pl
24156 /home/alex/farm/oddmuse2.pl

Furthermore, I can’t rely on awk splitting and looking at $2 because I want to match on the arguments as well. These three processes are distinct:

# ps -eo rss,command|grep gopher|grep -v grep
 4008 /home/alex/perl5/perlbrew/perls/perl-5.26.1/bin/perl /home/alex/farm/gopher-server.pl --setsid --user=alex --group=alex --host=alexschroeder.ch --port=79 --log_level=3 --log_file=/home/alex/farm/finger-server.log --pid_file=/home/alex/farm/finger-server.pid --wiki=/home/alex/farm/wiki.pl --wiki_dir=/home/alex/alexschroeder --wiki_pages=alex --wiki_pages=About --wiki_pages=Contact
26240 /home/alex/perl5/perlbrew/perls/perl-5.26.1/bin/perl /home/alex/farm/gopher-server.pl --setsid --user=alex --group=alex --host=alexschroeder.ch --port=7443 --log_level=3 --log_file=/home/alex/farm/gopher-server-ssl.log --pid_file=/home/alex/farm/gopher-server-ssl.pid --wiki=/home/alex/farm/wiki.pl --wiki_dir=/home/alex/alexschroeder --wiki_pages=SiteMap --wiki_pages=About --wiki_pages=Gopher --menu=Moku_Pona_Updates --menu_file=/home/alex/.moku-pona/updates.txt --menu=Moku_Pona_Sites --menu_file=/home/alex/.moku-pona/sites.txt --wiki_cert_file=/var/lib/dehydrated/certs/alexschroeder.ch/fullchain.pem --wiki_key_file=/var/lib/dehydrated/certs/alexschroeder.ch/privkey.pem
19776 /home/alex/perl5/perlbrew/perls/perl-5.26.1/bin/perl /home/alex/farm/gopher-server.pl --setsid --user=alex --group=alex --host=alexschroeder.ch --port=70 --log_level=3 --log_file=/home/alex/farm/gopher-server.log --pid_file=/home/alex/farm/gopher-server.pid --wiki=/home/alex/farm/wiki.pl --wiki_dir=/home/alex/alexschroeder --wiki_pages=SiteMap --wiki_pages=About --wiki_pages=Gopher --menu=Moku_Pona_Updates --menu_file=/home/alex/.moku-pona/updates.txt --menu=Moku_Pona_Sites --menu_file=/home/alex/.moku-pona/sites.txt

That’s a Gopher server listening on ports 70 (Gohper), 79 (Finger), and 7443 (TLS Gopher).

Anyway, I made some changes.

For multips I got rid of the overly restricted regular expressions:

# diff /usr/share/munin/plugins/multips /etc/munin/plugins/alex_multips
8,9c8,9
< multips - Munin plugin to monitor number of processes. Which processes
< are configured in client-conf.d
---
> alex_multips - Munin plugin to monitor number of processes. Which
> processes are configured in client-conf.d
19,25c19,20
<   [multips]
<      env.names pop3d imapd sslwrap
<      env.regex_imapd ^[0-9]* imapd:
<      env.regex_pop3d ^[0-9]* pop3d:
< 
< The regex parts are not needed if the name given in "names" can be
< used to grep with directly.
---
>   [alex_multips]
>      env.names perl6
26a22,23
> The regexp environment variables have been removed.
>      
30,31c27
< configured regular expressions.  The regular expressions are
< interpreted by "grep" (and not egrep or perl).
---
> command name.
80d75
< 		eval REGEX='"${regex_'$name'-\<'$name'\>}"'
84c79
< 		echo "$fieldname.info Processes matching this regular expression: /$REGEX/"
---
> 		echo "$fieldname.info Processes matching $name"
95d89
< 	eval REGEX='"${regex_'$name'-\<'$name'\>}"'
98c92
< 		$PGREP -f -l "$name" | grep "$REGEX" | wc -l
---
> 		$PGREP -f -l "$name" | wc -l
101c95
< 		/usr/ucb/ps auxwww | grep "$REGEX" | grep -v grep | wc -l
---
> 		/usr/ucb/ps auxwww | grep -v grep | wc -l
103c97
< 		ps auxwww | grep "$REGEX" | grep -v grep | wc -l
---
> 		ps auxwww | grep -v grep | wc -l

For multips_memory I got rid of the overly restricted regular expressions, but this time in the awk script at the end, and I use command instead of comm in the ps format.

# diff /usr/share/munin/plugins/multips_memory /etc/munin/plugins/alex_multips_memory
8c8
< multips_memory - Munin plugin to monitor memory usage of processes. Which
---
> alex_multips_memory - Munin plugin to monitor memory usage of processes. Which
15c15
<   ps -eo rss,comm
---
>   ps -eo rss,command
19c19
< You must specify what process names to monitor:
---
> You must specify what commands to monitor:
21c21
<   [multips_memory]
---
>   [alex_multips_memory]
28d27
< 
42,43c41,43
< /etc/munin/plugins or /etc/opt/munin/plugins), eg. multips_memory_rss and
< multips_memory_vsize as symlinks to multips_memory and configure them thus:
---
> /etc/munin/plugins or /etc/opt/munin/plugins), eg. multips_memory_rss
> and multips_memory_vsize as symlinks to alex_multips_memory and
> configure them thus:
58d57
< 
77,81d75
< Only the executable name is matched against (ps -eo comm)1, and it must
< be a full string match to the executable base name, not substring,
< unless you enter a name such as ".*apache" since RE meta characters in
< the names are active.
< 
95a90,91
> Switching from comm to command by Alex Schroeder <alex@gnu.org>
> 
129,130d124
< 		eval REGEX='^$name$';
< 
132c126
< 		echo "$fieldname.info For /$REGEX/"
---
> 		echo "$fieldname.info For /$name/"
140c134
< 	ps -eo $monitor,comm | gawk '
---
> 	ps -eo $monitor,command | gawk '
143c137
< $2 ~ /^'"$name"'$/ { total = total + ($1*1024); }
---
> '"/$name/"'        { total = total + ($1*1024); }

For configuration, I use the same regular expressions for both plugins:

[alex_multips*]
env.names gridmapper-server alexschroeder campaignwiki communitywiki emacswiki face food halberdsnhelmets helmut hex-describe hug linearb mark megadungeon monones names oddmuse paper small-sites software soweli-lukin tarballs text-mapper traveller trunk gopher-server.*port=79 gopher-server.*port=70 gopher-server.*port=7443 perl6

Tags:

Add Comment

2019-07-21 PureOS, Debian, and updates

I use PureOS, which is derived from Debian. Debian recently had a new release, so I was interested in learning how they handled it. Apparently not too well.

I had already added the following line to my /etc/apt/sources.list because I needed the GNU manuals:

deb http://http.us.debian.org/debian testing non-free

That’s why I wasn’t surprised when apt told me that something or other had changed from testing to something else. Whatever, I accept. For the purposes of this blog post I commented that line.

But something still isn’t right:

$ sudo apt update
Hit:1 https://repo.puri.sm/pureos green InRelease
Reading package lists... Done                               
Building dependency tree       
Reading state information... Done
All packages are up to date.
N: Skipping acquire of configured file 'main/binary-i386/Packages' as repository 'https://repo.puri.sm/pureos green InRelease' doesn't support architecture 'i386'

I wonder what that means.

Tags:

Comments on 2019-07-21 PureOS, Debian, and updates

The problem remains unsolved. I deleted /etc/apt/sources.list and recreated it using Software & Updates.

Software & Updates

New content:

deb https://repo.pureos.net/pureos/ green main

I used to have a line saying puri.sm instead of pureos.net but it appears to make no difference:

$ sudo apt update
Hit:1 https://repo.pureos.net/pureos green InRelease
Reading package lists... Done
Building dependency tree       
Reading state information... Done
All packages are up to date.
N: Skipping acquire of configured file 'main/binary-i386/Packages' as repository 'https://repo.pureos.net/pureos green InRelease' doesn't support architecture 'i386'

– Alex Schroeder 2019-07-27 20:53 UTC


What architecture am I using?

$ dpkg --print-architecture
amd64
$ dpkg --print-foreign-architectures
i386

Perhaps that is the problem? I think I don’t have any i386 stuff installed:

$ dpkg --get-selections | grep :i386

No output.

Let’s remove it!

$ sudo dpkg --remove-architecture i386

Problem solved!

$ sudo apt update
Hit:1 https://repo.pureos.net/pureos green InRelease
Reading package lists... Done
Building dependency tree       
Reading state information... Done
All packages are up to date.

– Alex Schroeder 2019-07-27 20:59 UTC


Add this to the Purism forum, just in case you find more info in the replies over there.

– Alex Schroeder 2019-07-27 21:05 UTC


For future reference, you shouldn’t have a line like

deb http://http.us.debian.org/debian testing non-free

because you might accidently upgrade to the next testing release when you don’t want to. Instead you should refer to the releases by codename, ie:

deb http://http.us.debian.org/debian buster non-free

That way, you can upgrade to the next release at your own discretion.

– matthew 2019-07-30 05:38 UTC


Thanks!

– Alex Schroeder 2019-07-30 06:02 UTC

Add Comment

2019-07-21 Not trusting a Mac

Here I am, sitting next to my wife’s unattended Mac. Suddenly the Mac’s fan is spinning up. What the hell?

I open a terminal and run top. Apparently load was up to 6, slowly going down but still around 3. How strange. I use the o key to change the sort order and use cpu as the primary key. The process using about 50% of the CPU is photoanalys. It’s shortened. I assume it’s photoanalysisid. Other people have reported something like it back in 2016.

Today, I had loaded some pictures onto the external disk. That would explain it? So I’m trying to eject the external disk, but that doesn’t work because it’s “being used by another process”. I still have top running. So now I’m force-ejecting the external drive. In the top window I see ReportCrash for a moment. What the hell is it doing?

This blog post says “it’s designed to saves the application state to aid developers in working out why the app crashed” (ReportCrash High CPU & How to Disable reportcrash in Mac OSX). OK, I guess?

But I think my main problem is I don’t trust systems that have a ton of processes starting up and doing stuff and shutting down and maybe all of that is required, and perhaps it’s “modular design”, but I also get a vague feeling of dread as the design of our machines complicates.

Tags:

Comments on 2019-07-21 Not trusting a Mac

Just so you know I dislike this complexity in all systems, here’s what happened to me today with my GNU/Linux laptop: I pulled out the SD card including the adapter from my camera, marvelled at it, pulled the micro (?) card out of the adapter, showed it to my wife, put it back, and plugged it into my laptop. I heard the typical beep-bop sound, but the drive didn’t mount. I removed the card and heard the typical bop-beep sound. Repeated it a few times, but it didn’t mount. I asked for help on Mastodon, got some good replies, with ideas ranging from lsblk to mount to fdisk. But the thing that fixed it was trying the same thing on the Mac, seeing that it failed, pulling the micro card out of the adapter and inserting it again, and then trying it all over again. And then it worked.

So, the problem was that something about the contacts in the card adapter was good enough for the laptop to recognize a card but not good enough to recognize a filesystem on it? Or something? And the suggestions revealed the abyss of layers upon layers of architecture required to make external drives and plug-and-play and USB all work. And for a short moment, I wanted it all to just go away. What have we done?

– Alex Schroeder 2019-07-21 21:22 UTC


Every problem in computing can be solved by adding another layer of indirection, except the problem of having too many layers of indirection.

Ed Davies 2019-07-22 10:49 UTC


Hahaha!

– Alex Schroeder 2019-07-22 14:10 UTC

Add Comment

2019-07-09 Web Requests

I have dozens of little scripts, bash functions and aliases...

This one, for example, shows me the distribution of HTTP codes Apache is returning. These are the codes you’re going to see in the list below:

codemessage
200OK, page was served
301redirect (permanent, this should go down)
302redirect (temporary, this might change in the future)
304not modified (no need to serve page, this is the best)
404forbidden (this is a suspected bot or spammer)
404not found (should be changed into a redirect)
408timeout (this is a problem)
502bad gateway (this is a problem)
root@sibirocobombus:~# time-grouping 
   09/Jul/2019:12:40        524     5%  403 (41%), 200 (40%), 301 (7%), 404 (4%), 304 (3%), 408 (1%), 302 (0%), 400 (0%)
   09/Jul/2019:12:30        677     6%  200 (69%), 301 (14%), 408 (4%), 404 (4%), 304 (3%), 403 (2%), 302 (0%)
   09/Jul/2019:12:20        628     6%  200 (69%), 301 (10%), 304 (5%), 408 (4%), 302 (3%), 404 (3%), 403 (2%)
   09/Jul/2019:12:10        860     8%  200 (57%), 403 (17%), 301 (13%), 304 (3%), 408 (3%), 404 (3%), 400 (0%), 302 (0%)
   09/Jul/2019:12:00        936     9%  403 (42%), 200 (40%), 301 (8%), 408 (3%), 304 (2%), 404 (1%), 302 (0%)
   09/Jul/2019:11:50        578     5%  200 (69%), 301 (12%), 304 (7%), 408 (3%), 403 (2%), 302 (1%), 404 (1%)
   09/Jul/2019:11:40        705     7%  200 (65%), 301 (10%), 503 (9%), 304 (4%), 408 (3%), 404 (2%), 403 (2%), 502 (1%), 302 (0%)
   09/Jul/2019:11:30        719     7%  200 (72%), 301 (9%), 304 (6%), 408 (5%), 404 (3%), 403 (1%), 302 (0%)
   09/Jul/2019:11:20        740     7%  200 (71%), 301 (10%), 304 (6%), 403 (4%), 408 (4%), 404 (1%), 302 (0%)
   09/Jul/2019:11:10        673     6%  200 (68%), 301 (13%), 408 (6%), 404 (4%), 304 (3%), 403 (2%), 302 (0%)
   09/Jul/2019:11:00        694     6%  200 (70%), 301 (12%), 304 (6%), 408 (4%), 404 (3%), 403 (1%), 302 (0%), 502 (0%)
   09/Jul/2019:10:50        580     5%  200 (72%), 301 (14%), 304 (5%), 404 (3%), 408 (2%), 403 (1%), 302 (0%), 400 (0%)
   09/Jul/2019:10:40        707     7%  200 (76%), 301 (9%), 304 (4%), 408 (3%), 404 (3%), 403 (1%), 302 (1%)
   09/Jul/2019:10:30        805     8%  200 (71%), 301 (14%), 408 (4%), 403 (3%), 404 (2%), 304 (2%), 302 (0%)
   09/Jul/2019:10:20        174     1%  200 (70%), 301 (12%), 304 (6%), 408 (6%), 404 (1%), 403 (1%), 302 (0%)

The time-grouping is an alias for:

tail -n 10000 /var/log/apache2/access.log | /home/alex/bin/time-grouping 10

And /home/alex/bin/time-grouping is a Perl script to parse access.log:

#!/usr/bin/env perl
use Modern::Perl;
use Time::ParseDate;

die "Argument '10min' to use smaller bucket size\n" if grep { $_ eq '--help' } @ARGV;

my $bucket = '1h';
$bucket = '10min' if grep { $_ eq '10' } @ARGV;

my $ESC = "\x1b";

sub red {
  my $text = shift;
  return '' unless $text;
  return "$ESC\[31m$text$ESC\[0m";
}

sub bold_red {
  my $text = shift;
  return '' unless $text;
  return "$ESC\[1;31m$text$ESC\[0m";
}

sub green {
  my $text = shift;
  return '' unless $text;
  return "$ESC\[32m$text$ESC\[0m";
}

sub yellow {
  my $text = shift;
  return '' unless $text;
  return "$ESC\[33m$text$ESC\[0m";
}

sub color_code {
  my $code = shift;
  return '' unless $code;
  return green($code) if substr($code,0,1) eq '2' or $code eq '304'; # or not modified
  return red($code) if substr($code,0,1) eq '5' or $code eq '408'; # server errors or timeout
  # return yellow($code) if substr($code,0,1) eq '3'; # redirects
  return yellow($code) if substr($code,0,1) eq '4'; # error messages
  return $code;
}

my %latest;
my %status;
my %count;
my $total;
while (<STDIN>) {
  m/^(?:(\S+):\S+ )?(\S+) \S+ \S+ \[(.*?)\] "(.*?)" (\d+)/ or die "Cannot parse:\n$_";
  my $host = $1;
  my $ip = $2;
  my $ts = $3;
  my $url = $4;
  my $code = $5;
  my $time = parsedate($ts);
  my $label;
  $label = substr($ts,0,14) if $bucket eq '1h';
  $label = substr($ts,0,16) . '0' if $bucket eq '10min';
  $total++;
  $latest{$label}=$time;
  $status{$label} = () unless exists $status{$label};
  $status{$label}{$code}++;
  $count{$label}++;
}
my @result = sort {$latest{$b} <=> $latest{$a}} keys %count;
foreach my $label (@result) {
  printf "%20s %10d   %3d%%  %s\n", $label, $count{$label}, 100* $count{$label} / $total,
      join(', ', map { sprintf("%3s (%d%%)",
			       color_code($_),
			       100 * $status{$label}{$_} / $count{$label})
	   } sort { $status{$label}{$b} <=> $status{$label}{$a} } keys %{$status{$label}});
}

Tags:

Add Comment

2019-07-04 Lost contact with the machine

A few minutes ago I noticed that I couldn’t reach my website. I tried to connect via SSH but got a timeout. I tried to start a VNC server via the admin console but got an error. I figured it must have gone totally bonkers and rebooted it, after more than 450 days of uptime. Now that it’s back up, I’m checking stuff but it looks like that wasn’t the problem. Time to look at the log files…

CPU looks OK Load looks OK

Time to figure out when this happened! Let’s zoom into the very end, when Apache reports no more hits:

Apache logs showing a drop to zero after 9:00

Let’s look at the time between 9:00 and 9:10 in the logfile!

Jul  4 09:00:01 sibirocobombus CRON[13112]: (alex) CMD (/home/alex/bin/trunk-bot)
Jul  4 09:00:01 sibirocobombus CRON[13113]: (munin) CMD (if [ -x /usr/bin/munin-cron ]; then /usr/bin/munin-cron; fi)
Jul  4 09:00:01 sibirocobombus CRON[13114]: (root) CMD (if [ -x /etc/munin/plugins/apt_all ]; then /etc/munin/plugins/apt_all update 7200 12 >/dev/
null; elif [ -x /etc/munin/plugins/apt ]; then /etc/munin/plugins/apt update 7200 12 >/dev/null; fi)
Jul  4 09:00:01 sibirocobombus CRON[13115]: (root) CMD (   test -x /usr/sbin/tigercron && { [ -r "$DEFAULT" ] && . "$DEFAULT" ; nice -n$NICETIGER /
usr/sbin/tigercron -q ; })
Jul  4 09:02:01 sibirocobombus CRON[13592]: (logcheck) CMD (   if [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck; fi)
Jul  4 09:05:01 sibirocobombus CRON[13627]: (munin) CMD (if [ -x /usr/bin/munin-cron ]; then /usr/bin/munin-cron; fi)
Jul  4 09:05:01 sibirocobombus CRON[13628]: (root) CMD (if [ -x /etc/munin/plugins/apt_all ]; then /etc/munin/plugins/apt_all update 7200 12 >/dev/
null; elif [ -x /etc/munin/plugins/apt ]; then /etc/munin/plugins/apt update 7200 12 >/dev/null; fi)
Jul  4 09:06:01 sibirocobombus CRON[13938]: (alex) CMD (/home/alex/bin/trunk-bot)
Jul  4 09:07:01 sibirocobombus CRON[13940]: (alex) CMD (/home/alex/bin/planet-indie)
Jul  4 09:10:01 sibirocobombus CRON[13961]: (munin) CMD (if [ -x /usr/bin/munin-cron ]; then /usr/bin/munin-cron; fi)
Jul  4 09:10:01 sibirocobombus CRON[13962]: (root) CMD (if [ -x /etc/munin/plugins/apt_all ]; then /etc/munin/plugins/apt_all update 7200 12 >/dev/null; elif [ -x /etc/munin/plugins/apt ]; then /etc/munin/plugins/apt update 7200 12 >/dev/null; fi)

This is extremely and reassuringly boring. Nothing at all seems to have happened. Happy cron jobs!

I rebooted about ten minutes later:

Jul  4 09:18:49 sibirocobombus kernel: [    0.000000] ...

@fitheach asked about that spike around midnight. I remember seeing those on a regular basis and never bothered to look into it. Let’s check now!

Jul  3 23:55:01 sibirocobombus CRON[24281]: (root) CMD (if [ -x /etc/munin/plugins/apt_all ]; then /etc/munin/plugins/apt_all update 7200 12 >/dev/
null; elif [ -x /etc/munin/plugins/apt ]; then /etc/munin/plugins/apt update 7200 12 >/dev/null; fi)
Jul  3 23:55:01 sibirocobombus CRON[24282]: (munin) CMD (if [ -x /usr/bin/munin-cron ]; then /usr/bin/munin-cron; fi)
Jul  3 23:57:25 sibirocobombus systemd[1]: Created slice User Slice of git.
Jul  3 23:57:25 sibirocobombus systemd[1]: Starting User Manager for UID 1001...
Jul  3 23:57:25 sibirocobombus systemd[1]: Started Session 394503 of user git.
Jul  3 23:57:25 sibirocobombus systemd[24851]: Reached target Timers.
Jul  3 23:57:25 sibirocobombus systemd[24851]: Reached target Paths.
Jul  3 23:57:25 sibirocobombus systemd[24851]: Listening on GnuPG cryptographic agent (access for web browsers).
Jul  3 23:57:25 sibirocobombus systemd[24851]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Jul  3 23:57:25 sibirocobombus systemd[24851]: Listening on GnuPG cryptographic agent and passphrase cache.
Jul  3 23:57:25 sibirocobombus systemd[24851]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Jul  3 23:57:25 sibirocobombus systemd[24851]: Listening on GnuPG network certificate management daemon.
Jul  3 23:57:25 sibirocobombus systemd[24851]: Reached target Sockets.
Jul  3 23:57:25 sibirocobombus systemd[24851]: Reached target Basic System.
Jul  3 23:57:25 sibirocobombus systemd[24851]: Reached target Default.
Jul  3 23:57:25 sibirocobombus systemd[24851]: Startup finished in 50ms.
Jul  3 23:57:25 sibirocobombus systemd[1]: Started User Manager for UID 1001.
Jul  3 23:57:25 sibirocobombus systemd[1]: Stopping User Manager for UID 1001...
Jul  3 23:57:25 sibirocobombus systemd[24851]: Stopped target Default.
Jul  3 23:57:25 sibirocobombus systemd[24851]: Stopped target Basic System.
Jul  3 23:57:25 sibirocobombus systemd[24851]: Stopped target Timers.
Jul  3 23:57:25 sibirocobombus systemd[24851]: Stopped target Paths.
Jul  3 23:57:25 sibirocobombus systemd[24851]: Stopped target Sockets.
Jul  3 23:57:25 sibirocobombus systemd[24851]: Closed GnuPG cryptographic agent and passphrase cache.
Jul  3 23:57:25 sibirocobombus systemd[24851]: Closed GnuPG cryptographic agent (ssh-agent emulation).
Jul  3 23:57:25 sibirocobombus systemd[24851]: Closed GnuPG cryptographic agent and passphrase cache (restricted).
Jul  3 23:57:25 sibirocobombus systemd[24851]: Closed GnuPG cryptographic agent (access for web browsers).
Jul  3 23:57:25 sibirocobombus systemd[24851]: Closed GnuPG network certificate management daemon.
Jul  3 23:57:25 sibirocobombus systemd[24851]: Reached target Shutdown.
Jul  3 23:57:25 sibirocobombus systemd[24851]: Starting Exit the Session...
Jul  3 23:57:25 sibirocobombus systemd[24851]: Received SIGRTMIN+24 from PID 24867 (kill).
Jul  3 23:57:25 sibirocobombus systemd[1]: Stopped User Manager for UID 1001.
Jul  3 23:57:25 sibirocobombus systemd[1]: Removed slice User Slice of git.
Jul  3 23:57:51 sibirocobombus systemd[1]: Started Session 394505 of user alex.
Jul  3 23:57:59 sibirocobombus systemd[1]: Created slice User Slice of git.
Jul  3 23:57:59 sibirocobombus systemd[1]: Starting User Manager for UID 1001...
Jul  3 23:57:59 sibirocobombus systemd[24942]: Listening on GnuPG cryptographic agent and passphrase cache.
Jul  3 23:57:59 sibirocobombus systemd[24942]: Listening on GnuPG network certificate management daemon.
Jul  3 23:57:59 sibirocobombus systemd[24942]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
Jul  3 23:57:59 sibirocobombus systemd[24942]: Reached target Timers.
Jul  3 23:57:59 sibirocobombus systemd[24942]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
Jul  3 23:57:59 sibirocobombus systemd[24942]: Listening on GnuPG cryptographic agent (access for web browsers).
Jul  3 23:57:59 sibirocobombus systemd[24942]: Reached target Sockets.
Jul  3 23:57:59 sibirocobombus systemd[24942]: Reached target Paths.
Jul  3 23:57:59 sibirocobombus systemd[24942]: Reached target Basic System.
Jul  3 23:57:59 sibirocobombus systemd[24942]: Reached target Default.
Jul  3 23:57:59 sibirocobombus systemd[24942]: Startup finished in 25ms.
Jul  3 23:57:59 sibirocobombus systemd[1]: Started User Manager for UID 1001.
Jul  3 23:57:59 sibirocobombus systemd[1]: Started Session 394506 of user git.
Jul  3 23:58:00 sibirocobombus systemd[1]: Stopping User Manager for UID 1001...
Jul  3 23:58:00 sibirocobombus systemd[24942]: Stopped target Default.
Jul  3 23:58:00 sibirocobombus systemd[24942]: Stopped target Basic System.
Jul  3 23:58:00 sibirocobombus systemd[24942]: Stopped target Timers.
Jul  3 23:58:00 sibirocobombus systemd[24942]: Stopped target Paths.
Jul  3 23:58:00 sibirocobombus systemd[24942]: Stopped target Sockets.
Jul  3 23:58:00 sibirocobombus systemd[24942]: Closed GnuPG cryptographic agent and passphrase cache.
Jul  3 23:58:00 sibirocobombus systemd[24942]: Closed GnuPG cryptographic agent (access for web browsers).
Jul  3 23:58:00 sibirocobombus systemd[24942]: Closed GnuPG cryptographic agent (ssh-agent emulation).
Jul  3 23:58:00 sibirocobombus systemd[24942]: Closed GnuPG network certificate management daemon.
Jul  3 23:58:00 sibirocobombus systemd[24942]: Closed GnuPG cryptographic agent and passphrase cache (restricted).
Jul  3 23:58:00 sibirocobombus systemd[24942]: Reached target Shutdown.
Jul  3 23:58:00 sibirocobombus systemd[24942]: Starting Exit the Session...
Jul  3 23:58:00 sibirocobombus systemd[24942]: Received SIGRTMIN+24 from PID 24957 (kill).
Jul  3 23:58:00 sibirocobombus systemd[1]: Stopped User Manager for UID 1001.
Jul  3 23:58:00 sibirocobombus systemd[1]: Removed slice User Slice of git.
Jul  4 00:00:01 sibirocobombus CRON[25130]: (root) CMD (if [ -x /etc/munin/plugins/apt_all ]; then /etc/munin/plugins/apt_all update 7200 12 >/dev/null; elif [ -x /etc/munin/plugins/apt ]; then /etc/munin/plugins/apt update 7200 12 >/dev/null; fi)
Jul  4 00:00:01 sibirocobombus CRON[25131]: (alex) CMD (/home/alex/bin/trunk-bot)
Jul  4 00:00:01 sibirocobombus CRON[25133]: (munin) CMD (if [ -x /usr/bin/munin-cron ]; then /usr/bin/munin-cron; fi)
Jul  4 00:00:01 sibirocobombus CRON[25132]: (root) CMD (   test -x /usr/sbin/tigercron && { [ -r "$DEFAULT" ] && . "$DEFAULT" ; nice -n$NICETIGER /usr/sbin/tigercron -q ; })
Jul  4 00:00:08 sibirocobombus crontab[26499]: (root) LIST (nobody)
Jul  4 00:02:01 sibirocobombus CRON[29160]: (logcheck) CMD (   if [ -x /usr/sbin/logcheck ]; then nice -n10 /usr/sbin/logcheck; fi)
Jul  4 00:05:01 sibirocobombus CRON[29266]: (root) CMD (if [ -x /etc/munin/plugins/apt_all ]; then /etc/munin/plugins/apt_all update 7200 12 >/dev/null; elif [ -x /etc/munin/plugins/apt ]; then /etc/munin/plugins/apt update 7200 12 >/dev/null; fi)
Jul  4 00:05:01 sibirocobombus CRON[29267]: (munin) CMD (if [ -x /usr/bin/munin-cron ]; then /usr/bin/munin-cron; fi)
Jul  4 00:06:01 sibirocobombus CRON[29598]: (alex) CMD (/home/alex/bin/trunk-bot)
Jul  4 00:07:01 sibirocobombus CRON[29644]: (alex) CMD (/home/alex/bin/planet-osr)

OK, so shortly before midnight, there’s some systemd activity, but nothing stands out, I think?

For the moment, there doesn’t seem to be anything I can learn from the experience.

  1. Apache was unreachable
  2. SSH daemon was unreachable

I didn’t check ping, nor the Gopher services. Perhaps I should have, before rebooting.

Log files are looking good. Monitoring seems to have worked just fine.

I have no idea what happened.

As you can see in the logs above I have some bots running via cron jobs. Both of them mailed me error messages.

At 09:08 and at 09:14, when the system was unreachable, I got the error “socket.gaierror: [Errno -3] Temporary failure in name resolution.”

At 10:00, after the reboot, I got a message from Tiger:

# Checking listening processes 
OLD: --WARN-- [lin003w] The process `systemd-resolve' is listening on socket 53 (UDP on 127.0.0.53 interface) is run by systemd-resolve. 
OLD: --WARN-- [lin003w] The process `systemd-resolve' is listening on socket 5355 (TCP on every interface) is run by systemd-resolve. 
OLD: --WARN-- [lin003w] The process `systemd-resolve' is listening on socket 5355 (UDP on every interface) is run by systemd-resolve. 

So... what happened? I’m skimming journalctl -r but that just starts with the boot and journalctl --list-boots shows I have just this one to go by. Sad! I guess we’ll never know...

Tags:

Comments on 2019-07-04 Lost contact with the machine

I’m not sure we’re done, here. I just tried contacting websites and was getting proxy errors: Apache was unable to contact the Hypnotoad services!

Monit reported all of them up and running. Munin reported load average around 0.6. What the hell?

  1. I added a ton of IP numbers with suspicious activity in my access log to the black list
  2. I restarted all the Hypnotoads

Let’s see what happens.

– Alex Schroeder 2019-07-07 14:14 UTC


Same thing, today! I just had to reload all the Hypnotoads. When it’s happening, I’m getting 502 Proxy errors and cannot connect to my sites via Apache, and I can’t connect to the same sites directly via HTTP. This includes the Mojolicious::Plugin::Status page. Thus, the plugin is currently useless for debugging this.

  1. CPU% is not suspicious
  2. Load is not suspicious
  3. Apache hits are not suspicious

Let’s take a look at the Apache result codes in 10min time groupings:

tail -n 10000 /var/log/apache2/access.log | /home/alex/bin/time-grouping 10 | cut -c 1-80
   08/Jul/2019:11:30        581     5%  200 (62%), 403 (21%), 301 (6%), 408 (3%)
   08/Jul/2019:11:20        885     8%  200 (67%), 301 (16%), 304 (6%), 404 (5%)
   08/Jul/2019:11:10       1265    12%  200 (36%), 502 (29%), 403 (19%), 301 (8%
   08/Jul/2019:11:00        721     7%  200 (75%), 301 (11%), 408 (3%), 304 (3%)
   08/Jul/2019:10:50        798     7%  200 (79%), 301 (11%), 304 (3%), 404 (2%)
   08/Jul/2019:10:40        780     7%  200 (74%), 301 (15%), 404 (3%), 304 (2%)
   08/Jul/2019:10:30        701     7%  200 (72%), 301 (13%), 408 (5%), 304 (3%)
   08/Jul/2019:10:20        757     7%  200 (72%), 301 (16%), 304 (4%), 408 (3%)
   08/Jul/2019:10:10        622     6%  200 (68%), 301 (17%), 408 (4%), 404 (4%)
   08/Jul/2019:10:00        876     8%  200 (75%), 301 (9%), 403 (5%), 408 (4%),
   08/Jul/2019:09:50        701     7%  200 (76%), 301 (11%), 404 (3%), 304 (3%)
   08/Jul/2019:09:40        790     7%  200 (76%), 301 (10%), 408 (4%), 304 (4%)
   08/Jul/2019:09:30        523     5%  200 (78%), 301 (10%), 408 (4%), 404 (3%)

Clearly, at 11:10 the requests nearly double and about a third (29%) result in 502 (proxy error) codes. But there are also 19% resulting in 403 (forbidden). The typical 200 (ok) results drop significantly.

New approach!

I’m going to use the rules listed in Stop fake and bad user agents with htaccess. Let’s hope this works! 🙂

– Alex Schroeder 2019-07-08 10:28 UTC


And it just happened again:

time-grouping | cut -c 1-80
   08/Jul/2019:13:20        122     1%  200 (60%), 403 (18%), 301 (13%), 404 (3%
   08/Jul/2019:13:10        737     7%  200 (75%), 301 (12%), 403 (4%), 404 (3%)
→  08/Jul/2019:13:00        615     6%  502 (44%), 200 (29%), 301 (16%), 403 (3%
→  08/Jul/2019:12:50        642     6%  200 (37%), 502 (34%), 301 (15%), 403 (5%
   08/Jul/2019:12:40        719     7%  200 (68%), 301 (14%), 403 (5%), 408 (4%)
   08/Jul/2019:12:30        774     7%  200 (70%), 301 (13%), 403 (6%), 408 (3%)
   08/Jul/2019:12:20        665     6%  200 (70%), 301 (12%), 304 (7%), 404 (3%)
   08/Jul/2019:12:10        763     7%  200 (73%), 301 (12%), 304 (6%), 404 (3%)
   08/Jul/2019:12:00        848     8%  200 (76%), 301 (12%), 304 (4%), 404 (2%)
   08/Jul/2019:11:50        887     8%  200 (75%), 301 (6%), 304 (6%), 404 (3%),
   08/Jul/2019:11:40        862     8%  200 (78%), 301 (8%), 304 (6%), 408 (3%),
   08/Jul/2019:11:30        809     8%  200 (66%), 403 (15%), 301 (7%), 304 (4%)
   08/Jul/2019:11:20        885     8%  200 (67%), 301 (16%), 304 (6%), 404 (5%)
   08/Jul/2019:11:10        672     6%  200 (41%), 403 (22%), 502 (21%), 301 (8%

I’m out of ideas... I’ll try changing all the Hypnotoad configurations and increase the number of workers per application from 1 to 2.

– Alex Schroeder 2019-07-08 11:20 UTC

Add Comment

2019-06-26 Privacy vs. fail2ban

I’m using fail2ban to watch over my sites. Or at least I thought I did!

CPU went up Load went up

Apparently, fail2ban didn’t notice a thing.

fail2ban is not busy

But zoom out and you’ll notice that the rules for Apache and Gopher aren’t seeing any matches.

fail2ban used to be busy

What happened? I don’t know. But I suspect this is due to me removing IP numbers from the web server logs. This meant that the fail2ban rules no longer matched. Not once. Somebody started unleashing another bot and here we are, once again fighting the leeches.

Well, I enabled the logging of IP numbers again and I see fail2ban has started banning some IP numbers again. But unfortunately, load remains an issue.

So now I’ve started the process of tearing the farm apart.

Toadfarm is a single Mojolicious application which mounted all of the 27 Mojolicious applications I had as one “farm”. This resulted in two problems:

  1. the processes were all named farm so I couldn’t tell them apart
  2. Mojolicious offers a status plugin which doesn’t work with Toadfarm

Now now I’m removing the applications one by one from Toadfarm, using Hypnotoad to run them.

  1. uncomment the application in the Toadfarm script
  2. assign them a separate port in the Apache config
  3. create a separate Monit config for each application
  4. create a separate Hypnotoad wrapper script for each application

See if it works.

Current status: 4/27 done. I have a bad feeling about this.

Tags:

Comments on 2019-06-26 Privacy vs. fail2ban

Status: still fucked.

CPU at 100% for 100% of the time

– Alex Schroeder 2019-06-27 07:02 UTC


Migrated more applications from Toadfarm to Hypnotoad. Looked at the log files and banned a bot via UserAgent because their webpage said they only looked at the directives for all bots. Witnessed a dozens of requests for the same page in a short time, from different IP numbers, with different user agents, checked it, and saw that it was spammed. They had made 307 edits in four days, starting June 23. Hm. Look at the graph above... Perhaps they are the problem?

log file matches
access.log 125
access.log.1 584
access.log.2.gz 726
access.log.3.gz 870
access.log.4.gz 556

My wikis don’t react well when lots of hits arrive in bursts, sadly. That’s what fail2ban is supposed to stop. We’ll see how it goes. I’m not too hopeful because I don’t think these are actually a lot of hits.

Looking at the current log file:

hour hits rel.
27/Jun/2019:13 17 13%
27/Jun/2019:12 21 16%
27/Jun/2019:11 18 14%
27/Jun/2019:10 15 11%
27/Jun/2019:09 17 13%
27/Jun/2019:08 16 12%
27/Jun/2019:07 11 8%
27/Jun/2019:06 13 10%

The data for Apache accesses also makes me think that the number of hits isn’t the problem, here.

Hits don't grow like CPU% does

As for the conversion from Toadfarm to Hypnotoad: just four applications left to do! 🙂

– Alex Schroeder 2019-06-27 11:24 UTC


Also reducing the number of preforked worked threads to 1 for almost all apps. The only exceptions are Emacs Wiki (3) and Campaign Wiki (2), as these seem to be the most popular ones, based on domain names.

domain hits rel.
www.emacswiki.org 17831 51%
campaignwiki.org 6424 18%
alexschroeder.ch 5969 17%
communitywiki.org 2069 6%

I think that helps? That was also a benefit of the Toadfarm. You didn’t have workers sleeping for every app! Now I do. Can’t go below zero, though. 🙂

Number of processes going down

– Alex Schroeder 2019-06-27 11:37 UTC


Well, right now it doesn’t look so bad!

Load dropped below 2

– Alex Schroeder 2019-06-27 11:59 UTC


Yes, looks like I’m back from the brink.

Load is back under control

But to be honest I’m not sure what did it. Perhaps moving from Toadfarm to Hypnotoad allowed me to see that a lot of processes were serving the Food wiki even though it wasn’t getting a lot of hits? Or perhaps that was simply half the story and the other half was fail2ban not working? I’m not sure. Nothing helps against distributed denial of service attacks, basically.

I think I’d need a “shields up” mode. Something that I could trigger from a job when load reaches goes over twenty or thirty? Perhaps there’s a way to write a job that just runs once a day and starts all the Monit services that are no longer running as currently I only attempt to restart them a handful of times.

check process alexschroeder with pidfile ...
    start program = "..." as uid alex gid alex
    stop program = "..." as uid alex gid alex
    if failed host ... port ... type tcp protocol http
      and request "..." for 5 cycles then restart
    if totalmem > 500 MB for 5 cycles then restart
    if 3 restarts within 15 cycles then timeout

I’ve just set set daemon 300 (up from 120) so now it checks services every five minutes.

If it can’t reach the site five times, i.e. 25min (up from 10m) it restarts the services and if there were already 3 restarts in 75min (up from 30min) the service goes down and I have to restart it manually after investigating.

Sadly my impression is that “timeout” doesn’t actually stop services. It’s just Monit that goes stops monitoring them. The website continues to struggle and eat up resources. I think that’s what I would need: I should use stop instead of timeout/unmonitor.

– Alex Schroeder 2019-06-27 14:47 UTC


At least fail2ban seems to be working again:

one or two IP numbers banned

– Alex Schroeder 2019-07-04 08:18 UTC


Ok, I decided to look at the /var/log/fail2ban.log file.

2019-07-04 09:37:41,759 fail2ban.actions        [459]: NOTICE  [alex-apache] Ban 64.62.202.71
2019-07-04 09:40:39,990 fail2ban.actions        [459]: NOTICE  [alex-apache] Ban 62.210.139.12
2019-07-04 09:47:42,540 fail2ban.actions        [459]: NOTICE  [alex-apache] Unban 64.62.202.71
2019-07-04 09:50:40,779 fail2ban.actions        [459]: NOTICE  [alex-apache] Unban 62.210.139.12

Hm... Let’s see who offends the most. Let’s write fail2ban-report.pl.

#!/usr/bin/env perl
use Time::ParseDate;

while (<STDIN>) {
  next if /Unban|already banned/;
  m/^([0-9: -]+).*Ban (\S+)$/ or warn "Cannot parse:\n$_" and next;
  my ($date, $ip) = ($1, $2);
  $time = parsedate($date);
  $count{$ip}++;
  $first{$ip} = $time unless $first{$ip};
  $last{$ip} = $time;
  $total++;
}
@result = sort {$count{$b} <=> $count{$a}} keys %count;
print "                                      ip      #bans bans% interval\n";
foreach my $ip (@result) {
  $avg = 0;
  if ($first{$ip} and $last{$ip} and $count{$ip} > 1) {
    $avg = ($last{$ip} - $first{$ip}) / ($count{$ip} -1) / 3600;
  }
  printf ("% 40s %10d %3d%% %7s\n",
	  $ip,
	  $count{$ip},
	  100 * $count{$ip} / $total,
	  $avg ? sprintf('%3.2fh', $avg) : '');
}

And call it:

/home/alex/bin/fail2ban-report.pl < /var/log/fail2ban.log | head
                                      ip      #bans bans% interval
                          62.210.180.146         69  10%   1.04h
                                     ***         60   8%   1.68h
                           62.210.139.12         54   7%   1.33h
                          62.210.180.164         52   7%   1.18h
                           62.210.83.206         47   6%   1.54h
                           62.210.177.44         32   4%   2.22h
                                     ***         28   4%   2.61h
                                     ***         23   3%   2.53h
                                     ***         16   2%   4.56h

This 62.210.*.* number sure shows up a lot! whois 62.210.180.146 tells me that 62.210.128.0 - 62.210.255.255 is owned by a French hosting and services provider. Oh well.

Let’s see what they do:

alexschroeder.ch:443 62.210.180.146 - - [04/Jul/2019:08:07:22 +0200] "POST /software HTTP/1.0" 403 5976 "https://alexschroeder.ch/software/Comments_on_Merge_Venus_dev_branch" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.87 Safari/537.36"

That’s right, they’re trying to spam my wiki! They’re already getting a 403 response, but I really hate those spammers.

I recently rebooted the server so all my blacklists are gone. But we can get them back. Let’s start with the following:

ipset create blacklist hash:ip hashsize 4096
iptables -I INPUT -m set --match-set blacklist src -j DROP
iptables -I FORWARD -m set --match-set blacklist src -j DROP
ipset add blacklist 62.210.180.146
ipset add blacklist 62.210.180.164
ipset add blacklist 62.210.177.44
ipset add blacklist 62.210.139.12
ipset add blacklist 62.210.83.206

That’s right, I added the last one as well. I checked and the 62.210.0.0 - 62.210.127.255 range belongs to the same provider.

Check the setup:

iptables -L
ipset list blacklist

– Alex Schroeder 2019-07-04 09:03 UTC


I also checked #2 in the list above. I checked the logs and noticed that they make two HEAD and a GET request for all of the new page on my site. Looks like they’re checking all the links in the RSS feed, perhaps?

grep *** /var/log/apache2/access.log | /home/alex/bin/leech-detector
 ip       hits bandw. hits% interv. status code distrib.
***         43     9K 100%  128.8s  200 (93%), 503 (6%)

43 hits doesn’t look like much for today, but they did get banned 60 times by fail2ban. Remember the data up there? Once every 2h at least! That must be the 503 result. Let’s look at these patterns.

grep *** /var/log/apache2/access.log | cut -c 50-69,77,79- | sed -e 's/Friendica.*/Friendica.../' -e 's/".*"/ /' -e 's/HTTP\/1.1 //'
04/Jul/2019:07:05:03 GET /wiki/feed/full/ Friendica...
04/Jul/2019:07:05:04 HEAD /wiki/2019-06-25_Reflowing_arbitrary_text Friendica...
04/Jul/2019:07:05:04 HEAD /wiki/2019-06-25_Reflowing_arbitrary_text Friendica...
04/Jul/2019:07:05:04 GET /wiki/2019-06-25_Reflowing_arbitrary_text Friendica...
04/Jul/2019:07:05:05 HEAD /wiki/2019-06-26_Gopher_to_HTTP_and_HTML_Proxy Friendica...
04/Jul/2019:07:05:05 HEAD /wiki/2019-06-26_Gopher_to_HTTP_and_HTML_Proxy Friendica...
04/Jul/2019:07:05:06 GET /wiki/2019-06-26_Gopher_to_HTTP_and_HTML_Proxy Friendica...
04/Jul/2019:07:05:06 HEAD /wiki/2019-06-26_Hiding_your_address Friendica...
04/Jul/2019:07:05:07 HEAD /wiki/2019-06-26_Hiding_your_address Friendica...
04/Jul/2019:07:05:07 GET /wiki/2019-06-26_Hiding_your_address Friendica...
04/Jul/2019:07:05:08 HEAD /wiki/2019-06-26_Privacy_vs._fail2ban Friendica...
04/Jul/2019:07:05:08 HEAD /wiki/2019-06-26_Privacy_vs._fail2ban Friendica...
04/Jul/2019:07:05:09 GET /wiki/2019-06-26_Privacy_vs._fail2ban Friendica...
04/Jul/2019:07:05:09 HEAD /wiki/2019-06-29_Microsoft_illustrates_why_DRM_is_shit Friendica...
04/Jul/2019:07:05:10 HEAD /wiki/2019-06-29_Microsoft_illustrates_why_DRM_is_shit Friendica...
04/Jul/2019:07:05:11 GET /wiki/2019-06-29_Microsoft_illustrates_why_DRM_is_shit Friendica...
04/Jul/2019:07:05:11 HEAD /wiki/2019-06-29_Property Friendica...
04/Jul/2019:07:05:12 HEAD /wiki/2019-06-29_Property Friendica...
04/Jul/2019:07:05:12 GET /wiki/2019-06-29_Property Friendica...
04/Jul/2019:07:05:12 HEAD /wiki/2019-07-01_Orcs Friendica...
04/Jul/2019:07:05:13 HEAD /wiki/2019-07-01_Orcs Friendica...
04/Jul/2019:08:35:03 GET /wiki/feed/full/ Friendica...
04/Jul/2019:08:35:03 HEAD /wiki/2019-06-25_Reflowing_arbitrary_text Friendica...
04/Jul/2019:08:35:04 HEAD /wiki/2019-06-25_Reflowing_arbitrary_text Friendica...
04/Jul/2019:08:35:04 GET /wiki/2019-06-25_Reflowing_arbitrary_text Friendica...
04/Jul/2019:08:35:04 HEAD /wiki/2019-06-26_Gopher_to_HTTP_and_HTML_Proxy Friendica...
04/Jul/2019:08:35:05 HEAD /wiki/2019-06-26_Gopher_to_HTTP_and_HTML_Proxy Friendica...
04/Jul/2019:08:35:05 GET /wiki/2019-06-26_Gopher_to_HTTP_and_HTML_Proxy Friendica...
04/Jul/2019:08:35:06 HEAD /wiki/2019-06-26_Hiding_your_address Friendica...
04/Jul/2019:08:35:06 HEAD /wiki/2019-06-26_Hiding_your_address Friendica...
04/Jul/2019:08:35:06 GET /wiki/2019-06-26_Hiding_your_address Friendica...
04/Jul/2019:08:35:07 HEAD /wiki/2019-06-26_Privacy_vs._fail2ban Friendica...
04/Jul/2019:08:35:07 HEAD /wiki/2019-06-26_Privacy_vs._fail2ban Friendica...
04/Jul/2019:08:35:07 GET /wiki/2019-06-26_Privacy_vs._fail2ban Friendica...
04/Jul/2019:08:35:08 HEAD /wiki/2019-06-29_Microsoft_illustrates_why_DRM_is_shit Friendica...
04/Jul/2019:08:35:08 HEAD /wiki/2019-06-29_Microsoft_illustrates_why_DRM_is_shit Friendica...
04/Jul/2019:08:35:09 GET /wiki/2019-06-29_Microsoft_illustrates_why_DRM_is_shit Friendica...
04/Jul/2019:08:35:09 HEAD /wiki/2019-06-29_Property Friendica...
04/Jul/2019:08:35:09 HEAD /wiki/2019-06-29_Property Friendica...
04/Jul/2019:08:35:10 GET /wiki/2019-06-29_Property Friendica...
04/Jul/2019:08:35:10 HEAD /wiki/2019-07-01_Orcs Friendica...
04/Jul/2019:08:35:10 HEAD /wiki/2019-07-01_Orcs Friendica...
04/Jul/2019:08:35:11 GET /wiki/2019-07-01_Orcs Friendica...

Let’s list the things I am unhappy with:

  1. two HEAD requests when one would have done
  2. it sends all the requests until it gets a 503
  3. the next time it shows up, it hasn’t slowed down

So what I think I’m going to do is simply add them to the User Agent based rules in my Apache site configuration:

RewriteEngine on
RewriteCond "%{HTTP_USER_AGENT}" "Mastodon|Pcore|MegaIndex|Friendica"
RewriteRule ".*" "-" [redirect=403,last]

There you go. Sorry, Friendica! I’m suspecting somebody has added my blog’s RSS feed to their Friendica instance, and that’s a very flattering thing, but I don’t think this is how feed aggregators ought to work.

– Alex Schroeder 2019-07-04 09:22 UTC

Add Comment

More...

Comments


Please make sure you contribute only your own work, or work licensed under the GNU Free Documentation License. Note: in order to facilitate peer review and fight vandalism, we will store your IP number for a number of days. See Privacy Policy for more information. See Info for text formatting rules. You can edit the comment page if you need to fix typos. You can subscribe to new comments by email without leaving a comment.

To save this page you must answer this question:

Please say HELLO.