Pest_Json_Decode: Decoding error: Malformed UTF-8 characters after PDNS Upgrade

[Napsty]

Hello!

After upgrading PowerDNS from 4.2 to 4.5, I suddenly am unable to view the zones in DNS UI (current master version).

/zones and /users/username shows:

Oops! Something went wrong!

Sorry, but it looks like something needs fixing on the system. The problem has been automatically reported to the administrators, but if you wish, you can also provide additional information about what you were doing that may have triggered the error.

The apache error logs shows:

[Mon Mar 07 15:35:11.920993 2022] [php7:notice] [pid 12503] [client 10.162.210.49:65133] 1646663711: Pest_Json_Decode: Decoding error: Malformed UTF-8 characters, possibly incorrectly encoded in /var/dns-ui/PestJSON.php:110
[Mon Mar 07 15:35:11.921038 2022] [php7:notice] [pid 12503] [client 10.162.210.49:65133] 1646663711: Stack trace:
[Mon Mar 07 15:35:11.921044 2022] [php7:notice] [pid 12503] [client 10.162.210.49:65133] 1646663711: #0 /var/dns-ui/PestJSON.php(199): PestJSON->jsonDecode('[{"account": "N...')
[Mon Mar 07 15:35:11.921048 2022] [php7:notice] [pid 12503] [client 10.162.210.49:65133] 1646663711: #1 /var/dns-ui/Pest.php(155): PestJSON->processBody('[{"account": "N...')
[Mon Mar 07 15:35:11.921052 2022] [php7:notice] [pid 12503] [client 10.162.210.49:65133] 1646663711: #2 /var/dns-ui/powerdns.php(30): Pest->get('zones', Array, Array)
[Mon Mar 07 15:35:11.921056 2022] [php7:notice] [pid 12503] [client 10.162.210.49:65133] 1646663711: #3 /var/dns-ui/model/zonedirectory.php(146): PowerDNS->get('zones')
[Mon Mar 07 15:35:11.921060 2022] [php7:notice] [pid 12503] [client 10.162.210.49:65133] 1646663711: #4 /var/dns-ui/model/user.php(221): ZoneDirectory->list_zones(Array)
[Mon Mar 07 15:35:11.921064 2022] [php7:notice] [pid 12503] [client 10.162.210.49:65133] 1646663711: #5 /var/dns-ui/views/zones.php(18): User->list_accessible_zones(Array)
[Mon Mar 07 15:35:11.921068 2022] [php7:notice] [pid 12503] [client 10.162.210.49:65133] 1646663711: #6 /var/dns-ui/requesthandler.php(62): require('/var/dns-ui/vie...')
[Mon Mar 07 15:35:11.921072 2022] [php7:notice] [pid 12503] [client 10.162.210.49:65133] 1646663711: #7 /var/dns-ui/public_html/init.php(18): require('/var/dns-ui/req...')
[Mon Mar 07 15:35:11.921076 2022] [php7:notice] [pid 12503] [client 10.162.210.49:65133] 1646663711: #8 {main}

When trying to view a user in the UI, the following queries happen on the dnsui database in PostgreSQL:

2022-03-07 16:03:59.755 CET [9943] dnsui@dnsui LOG:  execute pdo_stmt_00000001: SELECT MAX(id) FROM migration
2022-03-07 16:03:59.755 CET [9943] dnsui@dnsui LOG:  statement: DEALLOCATE pdo_stmt_00000001
2022-03-07 16:03:59.756 CET [9943] dnsui@dnsui LOG:  execute pdo_stmt_00000002: SELECT * FROM "user" WHERE uid = $1
2022-03-07 16:03:59.756 CET [9943] dnsui@dnsui DETAIL:  parameters: $1 = 'user1'
2022-03-07 16:03:59.757 CET [9943] dnsui@dnsui LOG:  statement: DEALLOCATE pdo_stmt_00000002
2022-03-07 16:03:59.757 CET [9943] dnsui@dnsui LOG:  execute pdo_stmt_00000003: SELECT * FROM "user" WHERE uid = $1
2022-03-07 16:03:59.757 CET [9943] dnsui@dnsui DETAIL:  parameters: $1 = 'user2'
2022-03-07 16:03:59.757 CET [9943] dnsui@dnsui LOG:  statement: DEALLOCATE pdo_stmt_00000003
2022-03-07 16:03:59.758 CET [9943] dnsui@dnsui LOG:  execute pdo_stmt_00000004: 
            SELECT changeset.*, zone.pdns_id, zone.name, zone.serial, zone.account, zone.active
            FROM changeset
            INNER JOIN zone ON zone.id = changeset.zone_id
            WHERE author_id = $1
            ORDER BY id DESC

2022-03-07 16:03:59.758 CET [9943] dnsui@dnsui DETAIL:  parameters: $1 = '3'
2022-03-07 16:03:59.761 CET [9943] dnsui@dnsui LOG:  statement: DEALLOCATE pdo_stmt_00000004
2022-03-07 16:03:59.761 CET [9943] dnsui@dnsui LOG:  execute pdo_stmt_00000005: BEGIN WORK
2022-03-07 16:03:59.761 CET [9943] dnsui@dnsui LOG:  statement: DEALLOCATE pdo_stmt_00000005
2022-03-07 16:03:59.762 CET [9943] dnsui@dnsui LOG:  execute pdo_stmt_00000006: LOCK TABLE zone
2022-03-07 16:03:59.762 CET [9943] dnsui@dnsui LOG:  statement: DEALLOCATE pdo_stmt_00000006
2022-03-07 16:03:59.763 CET [9943] dnsui@dnsui LOG:  execute pdo_stmt_00000007: 
                SELECT zone.*
                FROM zone 
                GROUP BY zone.id
                ORDER BY zone.name

2022-03-07 16:03:59.949 CET [9943] dnsui@dnsui LOG:  statement: DEALLOCATE pdo_stmt_00000007

Maybe this helps to rule out some parts already.

My current idea is that something in the database might have some characters which cannot be decoded properly by the JSON Decoder and then throws the error. Or is the JSON Decoder failing on data from the PDNS API?

Any ideas?

[Napsty]

Reverted back to PowerDNS 4.3 and with the following config changes from the default in /etc/powerdns/pdns.conf:

allow-axfr-ips=ip.of.slave.1,ip.of.slave.2

api=yes

api-key=secret

default-soa-edit=INCEPTION-INCREMENT

default-soa-mail=dnsadmin.example.com

default-soa-name=ns1.example.com

master=yes

overload-queue-length=4000

webserver=yes

Now DNS UI works again - but with older PowerDNS version. So I guess the problem is not in the DNSUI database?

Update: I'm able to reproduce this in a TEST environment with:

• PowerDNS 4.5.3
• Latest DNS UI (master branch)

As soon as I import the powerdns database from PROD to TEST, the same errors appear in DNS UI. So the source of the problem is definitely in the PowerDNS database.

[Napsty]

Was able to find the issue.

There were indeed some malformed characters returned from the API (/api/v1/servers/localhost/zones). The reason for it was that the database content was saved in latin1:

mysql> SELECT DISTINCT table_name,table_collation FROM information_schema.tables WHERE table_schema = "powerdns" LIMIT 0,15;
+----------------+-------------------+
| table_name     | table_collation   |
+----------------+-------------------+
| comments       | latin1_swedish_ci |
| cryptokeys     | latin1_swedish_ci |
| domainmetadata | latin1_swedish_ci |
| domains        | latin1_swedish_ci |
| records        | latin1_swedish_ci |
| supermasters   | latin1_swedish_ci |
| tsigkeys       | latin1_swedish_ci |
+----------------+-------------------+
7 rows in set (0.00 sec)

After converting to UTF8:

mysqldump --add-drop-table powerdns | replace CHARSET=latin1 CHARSET=utf8 | iconv -f latin1 -t utf8 | mysql powerdns

... it works again!

[thomas-pike]

Glad you managed to get it sorted out!