Pi-hole issues after 5.10 update

I just started noticing issues with 5.10, though I update a couple of weeks ago. I have not made any config file changes in the last 3 or 4 months, just some blacklist, whitelist, and adlist changes before the update. I just tried to add a new domain from the web interface and I received the following error:

While executing: attempt to write a readonly database
Added 0 out of 1 domains

When investigating, I found the following new error in /var/log/pihole-FTL.log which keeps occurring over and over:

[2022-05-11 19:11:49.519 1757M] ERR: Port mismatch for 127.1.1.1: we derived 5353, dnsmasq told us 43

The error log has a strange output after startup:

   2022-05-11 18:25:08: (server.c.1464) server started (lighttpd/1.4.53) 
   2022-05-11 18:25:08: (server.c.1493) WARNING: unknown config-key: alias.url (
ignored) 
   2022-05-11 18:31:07: (mod_fastcgi.c.421) FastCGI-stderr: PHP Warning:  SQLite3Stmt::execute(): Unable to execute statement: attempt to write a readonly database in /var/www/html/admin/scripts/pi-hole/php/groups.php on line 708
   2022-05-11 18:37:18: (mod_fastcgi.c.421) FastCGI-stderr: PHP Warning:  SQLite3Stmt::execute(): Unable to execute statement: attempt to write a readonly database in /var/www/html/admin/scripts/pi-hole/php/groups.php on line 708
   2022-05-11 18:37:36: (mod_fastcgi.c.421) FastCGI-stderr: PHP Warning:  SQLite3Stmt::execute(): Unable to execute statement: attempt to write a readonly database in /var/www/html/admin/scripts/pi-hole/php/groups.php on line 708
   2022-05-11 18:39:10: (mod_fastcgi.c.421) FastCGI-stderr: PHP Warning:  SQLite3Stmt::execute(): Unable to execute statement: attempt to write a readonly database in /var/www/html/admin/scripts/pi-hole/php/groups.php on line 708
   2022-05-11 18:46:28: (mod_fastcgi.c.421) FastCGI-stderr: PHP Warning:  SQLite3Stmt::execute(): Unable to execute statement: attempt to write a readonly database in /var/www/html/admin/scripts/pi-hole/php/groups.php on line 723
   2022-05-11 18:50:21: (mod_fastcgi.c.421) FastCGI-stderr: PHP Warning:  SQLite3Stmt::execute(): Unable to execute statement: attempt to write a readonly database in /var/www/html/admin/scripts/pi-hole/php/groups.php on line 723

I am not using port 43 for anything: 'netstat -an | grep 43' shows no address tied to port 43, and a 'grep 43 /etc/pihole/*.conf' shows nothing.

None of my filesystems are full, and I have disabled log2ram to help with diagnoses. I have wireguard installed but not configured. I have checked all of my file ownerships and permissions in /etc/pihole and they seem to be correct. I use stubby for my DNS backend, but I am not having issues with DNS lookups... as everything is working except for the errors above.

I am running a standard pihole configuration installed on my Rpi-3B on a 64GB SDXC card on Raspbian Buster. As previously noted, I have changed some configration files on install and issues, but I had no problems before 5.10. I will check the updated version at my other house again next week, but that one uses NGINX and an external HDD for storage, so it is non-standard.

Does anyone know the fix for these issues on a standard installation running directlly on a dedicated Rpi-3B?

Thanks... -James

Sometimes the SD card writers involved with a kernel upgrade (and other larger package upgrades) cause I/O and/or filesystem errors and the root filesystem may then be automatically remounted in read-only mode. You can check this via:

mount | grep ro
dmesg -l emerg,alert,crit,err

The first command to check for read-only mounts, the second to check for kernel errors. The invalid config key and port 43 may be due to rated filesystem corruption, but of course I hope that is not the case.

This is a known upstream dnsmasq issue.

One of our developers send a patch to dnsmasq and it was accepted.

The next version of dnsmasq (and thereafter Pi-hole) will include the patch

Hi Michael,

No issues with my filesystems... I checked your command output, and also validate my filesystems. Any other ideas?

Thanks again,
James

Permissions of /etc/pihole, especially the contained databases are definitely correct, there is no read-only or noexec mount involved? Then I can only suggest a pihole -r. You may also check journalctl for other system/service errors.

Hi Michal,

I ran a 'sudo pihole -r' and I still get the error when trying to add a blacklist entry from the web interface. 'journalctl' did not show me anything out of the ordinary. This seems to be some type of permission issue... I have an idea and I will post back in a bit.

Thanks,
James

OK... I think I have found a possible issue.

I was able to add a domain from the cli and it worked, though still not from the webpage. So, it seemed that the issue had something to due with webpage connectivity.

I used the logout webpage link... and then logged in again and the issue is gone temporarily. Unfortunately, the webpage interface no longer notifies me when my login has expired, nor does it sign me out. I tend to use the "remember me for 7 days" check box if that makes any difference... and my web browser is FireFox.

Thanks for all of the troubleshooting assistance. It is unfortunate that this seems to be a new problem as the interface used to just notify me and log me out... now I can see all of the settings and logs, but I just cannot update the database from the web interface. I did not think to check if I could update the settings page information. Please advise if this is the new expected interface experience.

Thanks again.
James

Please upload a debug log and post just the token URL that is generated after the log is uploaded by running the following command from the Pi-hole host terminal:

pihole -d

or do it through the Web interface:

Tools > Generate Debug Log

My debug log is:

https://tricorder.pi-hole.net/42Q7dQzu/

I looked at your debug log but there are no issues related to not being able to write to the gravity.db. You configured individual clients, groups, domains and adlists

*** [ DIAGNOSING ]: Disk usage
   Filesystem      Size  Used Avail Use% Mounted on
   /dev/root        57G  5.9G   49G  11% /
   devtmpfs        454M     0  454M   0% /dev
   tmpfs           487M  9.3M  478M   2% /dev/shm
   tmpfs           487M   31M  456M   7% /run
   tmpfs           5.0M  4.0K  5.0M   1% /run/lock
   tmpfs           487M     0  487M   0% /sys/fs/cgroup
   /dev/mmcblk0p1  253M   49M  204M  20% /boot
   log2ram         128M   54M   75M  43% /var/log
   tmpfs            98M     0   98M   0% /run/user/1000
   tmpfs            98M     0   98M   0% /run/user/999

*** [ DIAGNOSING ]: Gravity Database
-rw-rw-r-- 1 pihole pihole 80M May 16 23:41 /etc/pihole/gravity.db

*** [ DIAGNOSING ]: Info table
   property              value                                   
   --------------------  ----------------------------------------
   version               15                                      
   updated               1652601291                              
   gravity_count         1089379                                 
   Last gravity run finished at: Sun 15 May 2022 03:54:51 AM EDT

*** [ DIAGNOSING ]: contents of /var/log/lighttpd

-rw-r--r-- 1 www-data www-data 74 May 15 00:00 /var/log/lighttpd/error.log
   -----head of error.log------
   2022-05-15 00:00:25: (server.c.1759) logfiles cycled UID = 0 PID = 18464 

   -----tail of error.log------
   2022-05-15 00:00:25: (server.c.1759) logfiles cycled UID = 0 PID = 18464 

   -----tail of pihole-FTL.log------
   [2022-05-21 00:50:11.579 9260M] ERR: Port mismatch for 127.1.1.1: we derived 5353, dnsmasq told us 43
   [2022-05-21 01:47:47.665 9260M] Resizing "FTL-queries" from 7929856 to (184320 * 44) == 8110080 (/dev/shm: 9.2MB used, 510.0MB total, FTL uses 9.2MB)
   [2022-05-21 02:11:28.783 9260M] ERR: Port mismatch for 127.1.1.1: we derived 5353, dnsmasq told us 43
   [2022-05-21 03:49:12.447 9260M] ERR: Port mismatch for 127.1.1.1: we derived 5353, dnsmasq told us 43
   [2022-05-21 03:50:45.188 9260M] ERR: Port mismatch for 127.1.1.1: we derived 5353, dnsmasq told us 43
   [2022-05-21 03:53:37.606 9260M] Resizing "FTL-queries" from 8110080 to (188416 * 44) == 8290304 (/dev/shm: 9.4MB used, 510.0MB total, FTL uses 9.4MB)
   [2022-05-21 03:58:51.785 9260M] ERR: Port mismatch for 127.1.1.1: we derived 5353, dnsmasq told us 43
   [2022-05-21 04:26:01.039 9260M] ERR: Port mismatch for 127.1.1.1: we derived 5353, dnsmasq told us 43
   [2022-05-21 05:21:03.806 9260M] ERR: Port mismatch for 127.1.1.1: we derived 5353, dnsmasq told us 43
   [2022-05-21 06:06:49.655 9260M] ERR: Port mismatch for 127.1.1.1: we derived 5353, dnsmasq told us 43
   [2022-05-21 06:53:28.055 9260M] Resizing "FTL-queries" from 8290304 to (192512 * 44) == 8470528 (/dev/shm: 9.5MB used, 510.0MB total, FTL uses 9.5MB)
   [2022-05-21 07:24:25.911 9260M] Resizing "FTL-domains" from 81920 to (5120 * 20) == 102400 (/dev/shm: 9.7MB used, 510.0MB total, FTL uses 9.7MB)
   [2022-05-21 08:22:49.760 9260M] ERR: Port mismatch for 127.1.1.1: we derived 5353, dnsmasq told us 43
   [2022-05-21 08:30:33.118 9260M] ERR: Port mismatch for 127.1.1.1: we derived 5353, dnsmasq told us 43
   [2022-05-21 09:09:41.520 9260M] ERR: Port mismatch for 127.1.1.1: we derived 5353, dnsmasq told us 43
   [2022-05-21 09:53:01.628 9260M] ERR: Port mismatch for 127.1.1.1: we derived 5353, dnsmasq told us 43
   [2022-05-21 12:09:39.532 9260M] ERR: Port mismatch for 127.1.1.1: we derived 5353, dnsmasq told us 43
   [2022-05-21 12:31:47.728 9260M] ERR: Port mismatch for 127.1.1.1: we derived 5353, dnsmasq told us 48
   [2022-05-21 13:00:47.075 9260M] ERR: Port mismatch for 127.1.1.1: we derived 5353, dnsmasq told us 43
   [2022-05-21 14:17:57.516 9260M] ERR: Port mismatch for 127.1.1.1: we derived 5353, dnsmasq told us 43

The only thing I've not seen before is a file in /dev/shm by mono using the same user/group as lighttpd

*** [ DIAGNOSING ]: contents of /dev/shm

-rw-r----- 1 www-data www-data 4.0K May 11 18:24 /dev/shm/mono.462

 tcp:0.0.0.0:8084 is in use by mono

But I don't know if this can cause the issue you have seen...

Thanks for that. I disabled the 'mono-xsp4' service, as I was not sure what started this in raspbian buster. I know that I did not add the repository on any of my boxes, but it seems to be included on this pihole box... so I will check the other one at my permanent address. My understanding is that this is not installed by in raspbian buster default and I missed it in the apt-get update outputs, as the list was last updated on May 5.

Upon trying to remove it, I get the following:
pi@pi3:~ $ sudo apt remove mono-xsp4
Reading package lists... Done
Building dependency tree
Reading state information... Done
The following additional packages will be installed:
mono-apache-server4
The following packages will be REMOVED:
mono-xsp4
The following NEW packages will be installed:
mono-apache-server4
0 upgraded, 1 newly installed, 1 to remove and 0 not upgraded.
Need to get 84.0 kB of archives.
After this operation, 25.6 kB disk space will be freed.
Do you want to continue? [Y/n] ^C

I am not sure how it was installed, and why is wants to install something else when I try to remove it. I know basic Linux Administration but I come from a Solaris and BSD background... so please advise.

Thanks,
James

I don't know why mono was installed on your device - I don't think it is installed as a default in raspbian buster. Are you running any other software on this device?
It looks like it is going to install mono-apache instead. You need to figure out why it is there in the first place.
As I said above:

You could try to uninstall it and see if your issues persist. If so, you can install it any time later again.

No... my RPi is a dedicated pihole server. The only software I have added is wireguard, though it is not currently configured. I removed the repository, and then the mono-xsp4 package... it still found and installed the corresponding mono-apache package. Even though it is not running, I assume that this is a raspbian default... as if I remove the mono-apache package, it puts the mono-xsp4 package back.

I do not understand the purpose of this package if there is no dependencies for it... so why I cannot remove mono entirely is still a mystery? How can I track this down?

There seems to be no aftereffects from disabling it previously... everything still works. I am starting to wonder if it can with either a raspbian or pihole update? I tried removing wireguard, but that seemed to have not bearing... so I put it back.

Something seems afoul here... any thoughts?

Sorry, no idea here. If nothing else is installed at the device you could try to set it up again from scratch. Make sure you take a teleporter backup first.