search

NICMx / FORT-validator

RPKI cache validator
MIT License
47 stars 23 forks source link

Fort does not initialize #62

Closed cli0 closed 1 year ago

cli0 commented 2 years ago

Trying to start fort version 1.5.1 on an Ubuntu 18.04 machine. I followed the installation tutorial from APNIC https://www.youtube.com/watch?v=nbVR9399z18 . The following is my config.json file:

{
        "tal": "/etc/fort/tal/",
        "server": {
                "address": ["127.0.0.1"],
                "port": "8323",
                "interval": {
                        "validation": 3600,
                        "refresh": 3600,
                        "retry": 600,
                        "expire": 7200
                }
        },
        "validation-log": {
                "enabled": true
        }
}

I run fort using

sudo service fort start

and the result I get is:

● fort.service - FORT RPKI validator
   Loaded: loaded (/lib/systemd/system/fort.service; enabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Tue 2021-10-19 02:53:02 CEST; 1s ago
     Docs: man:fort(8)
           https://nicmx.github.io/FORT-validator/
  Process: 21311 ExecStart=/usr/bin/fort --configuration-file /etc/fort/config.json (code=exited, status=127)
 Main PID: 21311 (code=exited, status=127)

Okt 19 02:53:02 trantor systemd[1]: Started FORT RPKI validator.
Okt 19 02:53:02 trantor systemd[1]: fort.service: Main process exited, code=exited, status=127/n/a
Okt 19 02:53:02 trantor systemd[1]: fort.service: Failed with result 'exit-code'.

I tried to run fort alternatively not using systemd. Same setup, same config file and the result is

$ fort --configuration-file config.json
Oct 19 03:01:28 INF: Console log output configured; disabling validation logging on syslog.
Oct 19 03:01:28 INF: (Validation Logs will be sent to the standard streams only.)
Oct 19 03:01:28 INF: Console log output configured; disabling operation logging on syslog.
Oct 19 03:01:28 INF: (Operation Logs will be sent to the standard streams only.)
Oct 19 03:01:28 WRN: First validation cycle has begun, wait until the next notification to connect your router(s)
Oct 19 03:01:28 ERR: /etc/fort/tal/lacnic.tal: Error while making directory '/var/lib/fort/rrdp.lacnic.net': Permission denied
Oct 19 03:01:28 WRN [Validation]: /etc/fort/tal/lacnic.tal: TAL URI 'https://rrdp.lacnic.net/ta/rta-lacnic-rpki.cer' could not be downloaded.
Oct 19 03:01:28 ERR: /etc/fort/tal/lacnic.tal: Error while making directory '/var/lib/fort/repository.lacnic.net': Permission denied
Oct 19 03:01:28 WRN [Validation]: /etc/fort/tal/lacnic.tal: TAL URI 'rsync://repository.lacnic.net/rpki/lacnic/rta-lacnic-rpki.cer' could not be downloaded.
Oct 19 03:01:28 ERR: /etc/fort/tal/ripe-ncc.tal: Error while making directory '/var/lib/fort/rpki.ripe.net': Permission denied
Oct 19 03:01:28 WRN [Validation]: /etc/fort/tal/ripe-ncc.tal: TAL URI 'https://rpki.ripe.net/ta/ripe-ncc-ta.cer' could not be downloaded.
Oct 19 03:01:28 ERR: /etc/fort/tal/arin.tal: Error while making directory '/var/lib/fort/rrdp.arin.net': Permission denied
Oct 19 03:01:28 WRN [Validation]: /etc/fort/tal/arin.tal: TAL URI 'https://rrdp.arin.net/arin-rpki-ta.cer' could not be downloaded.
Oct 19 03:01:28 WRN [Validation]: /etc/fort/tal/lacnic.tal: Looking for the TA certificate at the local files.
Oct 19 03:01:28 ERR [Validation]: /etc/fort/tal/lacnic.tal: stat(/var/lib/fort/rrdp.lacnic.net/ta/rta-lacnic-rpki.cer) failed
Oct 19 03:01:28 ERR [Validation]: /etc/fort/tal/lacnic.tal: stat(/var/lib/fort/repository.lacnic.net/rpki/lacnic/rta-lacnic-rpki.cer) failed
Oct 19 03:01:28 ERR: /etc/fort/tal/lacnic.tal: None of the URIs of the TAL '/etc/fort/tal/lacnic.tal' yielded a successful traversal.
Oct 19 03:01:28 ERR: /etc/fort/tal/ripe-ncc.tal: Error while making directory '/var/lib/fort/rpki.ripe.net': Permission denied
Oct 19 03:01:28 ERR: /etc/fort/tal/afrinic.tal: Error while making directory '/var/lib/fort/rpki.afrinic.net': Permission denied
Oct 19 03:01:28 WRN [Validation]: /etc/fort/tal/afrinic.tal: TAL URI 'https://rpki.afrinic.net/repository/AfriNIC.cer' could not be downloaded.
Oct 19 03:01:28 ERR: /etc/fort/tal/afrinic.tal: Error while making directory '/var/lib/fort/rpki.afrinic.net': Permission denied
Oct 19 03:01:28 WRN [Validation]: /etc/fort/tal/afrinic.tal: TAL URI 'rsync://rpki.afrinic.net/repository/AfriNIC.cer' could not be downloaded.
Oct 19 03:01:28 WRN [Validation]: /etc/fort/tal/afrinic.tal: Looking for the TA certificate at the local files.
Oct 19 03:01:28 ERR [Validation]: /etc/fort/tal/afrinic.tal: stat(/var/lib/fort/rpki.afrinic.net/repository/AfriNIC.cer) failed
Oct 19 03:01:28 ERR [Validation]: /etc/fort/tal/afrinic.tal: stat(/var/lib/fort/rpki.afrinic.net/repository/AfriNIC.cer) failed
Oct 19 03:01:28 ERR: /etc/fort/tal/afrinic.tal: None of the URIs of the TAL '/etc/fort/tal/afrinic.tal' yielded a successful traversal.
Oct 19 03:01:28 ERR: /etc/fort/tal/arin.tal: Error while making directory '/var/lib/fort/rpki.arin.net': Permission denied
Oct 19 03:01:28 ERR: /etc/fort/tal/apnic.tal: Error while making directory '/var/lib/fort/rpki.apnic.net': Permission denied
Oct 19 03:01:28 WRN [Validation]: /etc/fort/tal/apnic.tal: TAL URI 'rsync://rpki.apnic.net/repository/apnic-rpki-root-iana-origin.cer' could not be downloaded.
Oct 19 03:01:28 WRN [Validation]: /etc/fort/tal/apnic.tal: Looking for the TA certificate at the local files.
Oct 19 03:01:28 WRN [Validation]: /etc/fort/tal/ripe-ncc.tal: TAL URI 'rsync://rpki.ripe.net/ta/ripe-ncc-ta.cer' could not be downloaded.
Oct 19 03:01:28 WRN [Validation]: /etc/fort/tal/ripe-ncc.tal: Looking for the TA certificate at the local files.
Oct 19 03:01:28 ERR [Validation]: /etc/fort/tal/apnic.tal: stat(/var/lib/fort/rpki.apnic.net/repository/apnic-rpki-root-iana-origin.cer) failed
Oct 19 03:01:28 ERR: /etc/fort/tal/apnic.tal: None of the URIs of the TAL '/etc/fort/tal/apnic.tal' yielded a successful traversal.
Oct 19 03:01:28 ERR [Validation]: /etc/fort/tal/ripe-ncc.tal: stat(/var/lib/fort/rpki.ripe.net/ta/ripe-ncc-ta.cer) failed
Oct 19 03:01:28 WRN [Validation]: /etc/fort/tal/arin.tal: TAL URI 'rsync://rpki.arin.net/repository/arin-rpki-ta.cer' could not be downloaded.
Oct 19 03:01:28 WRN [Validation]: /etc/fort/tal/arin.tal: Looking for the TA certificate at the local files.
Oct 19 03:01:28 ERR [Validation]: /etc/fort/tal/ripe-ncc.tal: stat(/var/lib/fort/rpki.ripe.net/ta/ripe-ncc-ta.cer) failed
Oct 19 03:01:28 ERR: /etc/fort/tal/ripe-ncc.tal: None of the URIs of the TAL '/etc/fort/tal/ripe-ncc.tal' yielded a successful traversal.
Oct 19 03:01:28 ERR [Validation]: /etc/fort/tal/arin.tal: stat(/var/lib/fort/rrdp.arin.net/arin-rpki-ta.cer) failed
Oct 19 03:01:28 ERR [Validation]: /etc/fort/tal/arin.tal: stat(/var/lib/fort/rpki.arin.net/repository/arin-rpki-ta.cer) failed
Oct 19 03:01:28 ERR: /etc/fort/tal/arin.tal: None of the URIs of the TAL '/etc/fort/tal/arin.tal' yielded a successful traversal.
Oct 19 03:01:28 WRN: Validation from TAL '/etc/fort/tal/ripe-ncc.tal' yielded error, discarding any other validation results.
Oct 19 03:01:28 WRN: Validation from TAL '/etc/fort/tal/afrinic.tal' yielded error, discarding any other validation results.
Oct 19 03:01:28 WRN: Validation from TAL '/etc/fort/tal/arin.tal' yielded error, discarding any other validation results.
Oct 19 03:01:28 WRN: Validation from TAL '/etc/fort/tal/apnic.tal' yielded error, discarding any other validation results.
Oct 19 03:01:28 WRN: Validation from TAL '/etc/fort/tal/lacnic.tal' yielded error, discarding any other validation results.
Oct 19 03:01:28 ERR: First validation wasn't successful.

Can someone help me troubleshoot what is going on here? For reference, I managed to run routinator and octorpki on the same machine without issues.

ydahhrk commented 2 years ago

Oct 19 03:01:28 ERR: /etc/fort/tal/lacnic.tal: Error while making directory '/var/lib/fort/rrdp.lacnic.net': Permission denied

You're using the default cache directory (/var/lib/fort), but your user doesn't have write permissions on it.

The systemd service runs with user fort. If you run the command directly (fort --configuration-file config.json), then you're a different user. Therefore, the systemd error is not necessarily the same as the command error.

To find the systemd error, you'll have to search in /var/log. One way to fix the command error is to override the default cache directory:

mkdir potato/
fort --configuration-file config.json --local-repository potato/
cli0 commented 2 years ago

I checked the syslogs with regards to the systemd service and I get similar logs to this

Started FORT RPKI validator.
fort.service: Main process exited, code=exited, status=127/n/a
fort.service: Failed with result 'exit-code'.

no additional error information why that happens. I installed fort using deb and did not make any changes to the setup, all according to the tutorial.

By the way is there a way to save logs from fort, for example validation logs, in a persistent file and not on syslog?

ydahhrk commented 2 years ago

Curious. Systemd is killing Fort before it even has a chance to log anything.

In the /lib/systemd/system/fort.service file, remove this line:

SystemCallFilter=@system-service

Then run

sudo systemctl daemon-reload

Then try sudo service fort start again.

ydahhrk commented 2 years ago

This bug triggers in Ubuntu 18.08, but not in Ubuntu 20.04.

ydahhrk commented 2 years ago

By the way is there a way to save logs from fort, for example validation logs, in a persistent file and not on syslog?

What's wrong with syslog? It can write that file for you: https://askubuntu.com/questions/186592

# nano /etc/rsyslog.d/00-fort.conf # if $programname == 'fort' then /var/log/fort.log
# service syslog restart
# service fort start
# cat /var/log/fort.log
Oct 20 17:07:54 ubuntu18 fort[4990]: Oct 20 17:07:54 INF: Syslog log output configured; disabling validation logging on standard streams.
Oct 20 17:07:54 ubuntu18 fort: INF: (Validation Logs will be sent to syslog only.)
Oct 20 17:07:54 ubuntu18 fort[4990]: Oct 20 17:07:54 INF: (Validation Logs will be sent to syslog only.)
Oct 20 17:07:54 ubuntu18 fort: INF: Syslog log output configured; disabling operation logging on standard streams.
Oct 20 17:07:54 ubuntu18 fort[4990]: Oct 20 17:07:54 INF: Syslog log output configured; disabling operation logging on standard streams.
Oct 20 17:07:54 ubuntu18 fort: INF: (Operation Logs will be sent to syslog only.)
Oct 20 17:07:54 ubuntu18 fort[4990]: Oct 20 17:07:54 INF: (Operation Logs will be sent to syslog only.)
Oct 20 17:07:54 ubuntu18 fort: WRN [O]: The validation has begun.
ydahhrk commented 2 years ago

I just released 1.5.2. This version ships without SystemCallFilter, so the problem should be gone.

cli0 commented 2 years ago

Hello, your suggestion fixed the first problem. Thank you very much!

Unfortunately this issue was followed with another one. 

$ sudo service fort status
● fort.service - FORT RPKI validator
   Loaded: loaded (/lib/systemd/system/fort.service; enabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Fri 2021-10-22 23:00:45 CEST; 1s ago
     Docs: man:fort(8)
           https://nicmx.github.io/FORT-validator/
  Process: 13218 ExecStart=/usr/bin/fort --configuration-file /etc/fort/config.json (code=exited, status=22)
 Main PID: 13218 (code=exited, status=22)

Okt 22 23:00:44 trantor fort[13218]: ERR [Validation]: /var/cache/fort/tal/lacnic.tal: stat(/var/cache/fort/repository/repository.lacnic.net/rpki/lacnic/rta-lacnic-rpki.cer) failed
Okt 22 23:00:44 trantor fort[13218]: ERR: /var/cache/fort/tal/lacnic.tal: None of the URIs of the TAL '/var/cache/fort/tal/lacnic.tal' yielded a successful traversal.
Okt 22 23:00:44 trantor fort[13218]: WRN: Validation from TAL '/var/cache/fort/tal/ripe-ncc.tal' yielded error, discarding any other validation results.
Okt 22 23:00:44 trantor fort[13218]: WRN: Validation from TAL '/var/cache/fort/tal/afrinic.tal' yielded error, discarding any other validation results.
Okt 22 23:00:44 trantor fort[13218]: WRN: Validation from TAL '/var/cache/fort/tal/arin.tal' yielded error, discarding any other validation results.
Okt 22 23:00:44 trantor fort[13218]: WRN: Validation from TAL '/var/cache/fort/tal/apnic.tal' yielded error, discarding any other validation results.
Okt 22 23:00:44 trantor fort[13218]: WRN: Validation from TAL '/var/cache/fort/tal/lacnic.tal' yielded error, discarding any other validation results.
Okt 22 23:00:44 trantor fort[13218]: ERR: First validation wasn't successful.
Okt 22 23:00:45 trantor systemd[1]: fort.service: Main process exited, code=exited, status=22/n/a
Okt 22 23:00:45 trantor systemd[1]: fort.service: Failed with result 'exit-code'.

My config file /etc/fort/config.json

{
        "tal": "/var/cache/fort/tal",
        "local-repository": "/var/cache/fort/repository",
        "server": {
                "address": ["127.0.0.1"],
                "port": "8323",
                "interval": {
                        "validation": 3600,
                        "refresh": 3600,
                        "retry": 600,
                        "expire": 7200
                }
        },
        "validation-log": {
                "enabled": true,
                "output": "syslog",
                "facility": "daemon"
        },
        "log": {
                "enabled": true,
                "output": "syslog",
                "facility": "daemon"
        },
        "output": {
                "roas": "/var/cache/fort/roas.csv"
        }
}

I downloaded the TALs per the initialization script (and even checked the content to make sure that it is up to date) but somehow fort cant make the initial validation happen.

ydahhrk commented 2 years ago

Ok, new plan: Open /lib/systemd/system/fort.service again, and delete everything between User=fort and [Install]. The file should look like this:

# This is a systemd unit configuration file.
# As of now, it is the only file needed to connect Fort and systemd.
# Turns Fort into a service.

[Unit]
Description=FORT RPKI validator
Documentation=man:fort(8)
Documentation=https://nicmx.github.io/FORT-validator/
After=network.target

[Service]
ExecStart=/usr/bin/fort --configuration-file /etc/fort/config.json
Type=simple
# This user is created during postinst.
User=fort

[Install]
WantedBy=multi-user.target

And just to be sure, check the directory /var/cache/fort contains both repository and tal, and that they're all owned by the user "fort":

$ sudo chown -R fort:fort /var/cache/fort
$ sudo chmod -R u+rwx /var/cache/fort
$ ls -lash /var/cache/fort
total 16K
4.0K drwxr-xr-x  4 fort fort 4.0K Oct 23 00:27 .
4.0K drwxr-xr-x 11 root root 4.0K Oct 23 00:26 ..
4.0K drwxr-xr-x 12 fort fort 4.0K Oct 23 00:40 repository
4.0K drwxr-xr-x  2 fort fort 4.0K Oct 23 00:26 tal

Reload the configuration again:

sudo systemctl daemon-reload

Then start Fort:

sudo service fort restart
cli0 commented 2 years ago

The current setup completely solved the systemd starting issue. Thank you! :)

I have one more question in relation to the logs I am seeing. As a reference, I changed the validation/log level in the configuration file to INF and made sure /var/cache/fort and everything inside is owned by fort.

I am seeing a lot of logs about errors, missing folders, stale data, inability to setup an rrdp connection etc but nothing referencing the moment when the RP initiates contact with specific publication points or any successful attempt (at syncing, downloading etc). Do these logs suggest to you that something is not working correctly or does the code not provide a breakdown of contact with PPs (unless an error occurs) in INFO mode? I appended a snippet of the logs.

I checked debug mode for a few runs and the logs there include information about the begin of the RP <-> PP connection during validation refresh intervals. However the log files exploded to 1.6GB per single validation run. Thats a lot. It makes exploring these specific logs and interactions prohibitively expensive. Is there a way to get that data in INFO mode as well?

Oct 24 18:41:35 trantor fort: INF: Starting validation.
Oct 24 18:41:35 trantor fort: INF: - Serial before validation: 8
Oct 24 18:41:37 trantor fort: ERR [Validation]: rsync://rpki.afrinic.net/repository/member_repository/F3646C24/1C86B7862B5B11EC8EBEF540D8A014CE/_r9_454NpaYN1sjcZoHO9aJGKC4.mft: Could not open file '/var/cache/fort/repository/7F4F16BA/rpki.afrinic.net/repository/member_repository/F3646C24/1C86B7862B5B11EC8EBEF540D8A014CE/_r9_454NpaYN1sjcZoHO9aJGKC4.mft': No such file or directory
Oct 24 18:41:37 trantor fort: ERR [Validation]: rsync://rpki.afrinic.net/repository/member_repository/F362C7E9/08F07C14E8D911E98515C740F8AEA228/8A9DED60330411ECB9F7B454D8A014CE.roa: Certificate validation failed: certificate is not yet valid
Oct 24 18:41:46 trantor fort: ERR [Validation]: rsync://rpki.ripe.net/repository/DEFAULT/31ox5UkV6xDrAV7Y8EdtjD9k__E.cer: Error requesting URL https://rpki1.rpki-test.sit.fraunhofer.de/rrdp/notification.xml: SSL certificate problem: unable to get issuer certificate
Oct 24 18:41:46 trantor fort: WRN [Validation]: rsync://rpki.ripe.net/repository/DEFAULT/31ox5UkV6xDrAV7Y8EdtjD9k__E.cer: Retrying HTTP request 'https://rpki1.rpki-test.sit.fraunhofer.de/rrdp/notification.xml' in 5 seconds, 2 attempts remaining.
Oct 24 18:41:46 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/13u2dWsG36Qbx3u8tYMaD2k7HpL7CvExbMyLg6FXm3Hw/0/92707970D9A36CB4BBB7C0CED7E733E8F481BF39.mft: CRL is stale/expired
Oct 24 18:41:46 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/6nNZbA2YbBn1p39HAhdNUAxW9byqL7qVTnVP8sxH4C29/0/A460D6EC9284548B5BEE4E7828FAD27CB57753BF.mft: CRL is stale/expired
Oct 24 18:41:46 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/8cfqrtAEooPgbwLeyGP2mZF7xtVWgWZk1MaxHA3nGp8a/0/EB78B9C40B36B86ECE478846D7F4C9611D26D768.mft: CRL is stale/expired
Oct 24 18:41:46 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/4Bx88FXe8n5R749pWgrkAS3deyr5mdyyfxBNiWz5yvvM/0/615E06B249FD712C336D6DBD87713D5A2B7D4C44.mft: CRL is stale/expired
Oct 24 18:41:47 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/9VLetgpnRJaTw7ibQ3yZfmEU6xss93RN9DLBReE4oN5Y/0/729B4CD9A37F20431C93A42826003C836E39EB20.mft: CRL is stale/expired
Oct 24 18:41:47 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/8ednu8UmH5sZfAn9E1pEx2D3NH4YC5JwRttFi2tiTDDV/0/3423C3B06968E7B10D91873EA508D448D7FE4230.mft: CRL is stale/expired
Oct 24 18:41:47 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/WMHJfnYE8NUC9RUbAsx363tYt5U4gN6UpB6umWUffbG/0/4A00AF1325B5DBF0EA04C441E5B9FB9ABD85F2C1.mft: CRL is stale/expired
Oct 24 18:41:48 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/5M8ukuVpcnk9LWJQr7Y9ZiiFChbYK7h3pcqjYJ29gZvg/0/C6BD52DC079825A702D874B54502AD138171621D.mft: CRL is stale/expired
Oct 24 18:41:48 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/BadD4W2AyonpD4FMVoxCECfvseg7xDHikaAjsdtXAcEu/0/30112158BCF8C7DEE7645D440A41992FBF4B6D45.mft: CRL is stale/expired
Oct 24 18:41:48 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/ETm9SHjuk1Y4e78y5pPtETXRECkjNRi7FB5zX5cv6uNs/0/5BC9A4A76F3F26D6308F7923AE9CF7E1008962D2.mft: CRL is stale/expired
Oct 24 18:41:48 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/GvcMk3Ww6Jc2LqhbNfnjnV1ZwZbDymg3FyxUoJNQRHAt/0/8C6EA674D5B6AA958BC9F7C34AF1B69F8E9D79EB.mft: CRL is stale/expired
Oct 24 18:41:49 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/3ggwCtEcgn2A9CoDUkYHTrTAPnULgPo8jg9zpEq7JThA/0/61E2D2B53D81871EEFCB177DBA0D5F4ED947B790.mft: CRL is stale/expired
Oct 24 18:41:49 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/HwFn7q56b8g8wHPZP6eGpKoQMu1nbWhVvdyN7Ckicxw3/0/5F2C428A9AA6A79D1173E8C2A73422D261F0C6E0.mft: CRL is stale/expired
Oct 24 18:41:49 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/3HvHSSpFhi8owr3AZJgQf1nZZF8nWW2ArYXafwkfxLTU/0/362D99968B66668125E3238E9EB1585A84D71CC5.mft: CRL is stale/expired
Oct 24 18:41:49 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/7KtJRYiAJwFKxaDZQTQgPN1dwkbkjxRWynozFerU7aMH/0/5C908AE2A50DFF743C0A2B041FD20DD3BC047668.mft: CRL is stale/expired
Oct 24 18:41:49 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/Asj7c85UngufZWUW1ALuvuzjepvNwQpB7JbbfyjQu5kq/0/AF8669C40A1705DDF9FF8B1C94EE047AB500F37E.mft: CRL is stale/expired
Oct 24 18:41:50 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/HdoHKou8jAw1N458ZhsPPidp8wsYUtWg8ohy6PizqnLi/0/BA657BA9E7EF447FE8515348926AE1FE539F0EA5.mft: CRL is stale/expired
Oct 24 18:41:50 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/6BKKT3FEsg5U6fAzTTDWMmffQpbXpPnzhKJhUmyhieBp/0/035FFFD8EAD1B9CBA2633D8CBE3310AC4E8D3371.mft: CRL is stale/expired
Oct 24 18:41:50 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/8Dd2yafQEDRyLSnEhXwh6CmSYwBuJE5q35zKDVBmY5xw/0/9723508999E6E6042E07B57FC49918FDD5C8CDDC.mft: CRL is stale/expired
Oct 24 18:41:50 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/WSxxAn3UtmrYsXRXmUnPj6ZjioavzKUqkWzvnNrBGyw/0/6A954DCA8F132488386154F00954CB12AE07DEF6.mft: CRL is stale/expired
Oct 24 18:41:50 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/Em8u3mjx6DGFMbj5nsHkYs3vkzDhuSAai1UdSxFDuAdE/0/772D2DA99452DDF39D69460E60393F2ADBA0CB21.mft: CRL is stale/expired
Oct 24 18:41:50 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/GvfhAciEXy2cQjTUjcXgMzoVpnf3AdscpYYhxuh2rwfT/0/D81239EF18FC1CFB2464AA9558AFB602681FD610.mft: CRL is stale/expired
Oct 24 18:41:51 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/GkeUxS8eYM4x4iEiLVNBdh8YVUoh2CpKM1VsiveZ1Pde/0/1B7E5F56163E3F2FC1B0452A93C5F9613099DB45.mft: CRL is stale/expired
Oct 24 18:41:51 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/Aa7hski1fSwkVpgDcjyZBPsA5NYgYGLn8W9skyC5w5iB/0/AD05E228B65028B8C82DF22A9BBCCB80F9F47C3A.mft: CRL is stale/expired
Oct 24 18:41:51 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/AP5EwRomHw8FXhG5cm8ed4yvb2eVepqqBVy7hayG6bG1/0/B10A8598B44772B93158A2AC959BE76B0DF306DF.mft: CRL is stale/expired
Oct 24 18:41:51 trantor fort: ERR [Validation]: rsync://rpki.ripe.net/repository/DEFAULT/31ox5UkV6xDrAV7Y8EdtjD9k__E.cer: Error requesting URL https://rpki1.rpki-test.sit.fraunhofer.de/rrdp/notification.xml: SSL certificate problem: unable to get issuer certificate
Oct 24 18:41:51 trantor fort: WRN [Validation]: rsync://rpki.ripe.net/repository/DEFAULT/31ox5UkV6xDrAV7Y8EdtjD9k__E.cer: Retrying HTTP request 'https://rpki1.rpki-test.sit.fraunhofer.de/rrdp/notification.xml' in 5 seconds, 1 attempts remaining.
Oct 24 18:41:51 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/8pva4tQzH36bLQmausbgvvMoVnkKQGsdtBPxuPgUadGF/0/3DD549F23D2BB009A1484217ADA075AADCB1028D.mft: CRL is stale/expired
Oct 24 18:41:51 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/AkoiudMWC9CHUx4WTAQKU56CJvGPW9G2Jy4ASQHD93MJ/0/82EF1B25F4061414C0B4238012C01785D62865C7.mft: CRL is stale/expired
Oct 24 18:41:51 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/3db7SahZtRVC8PuMcgyzbAmeUfVwyRcsxWmHCGFvpcyF/0/DB85262D118B08D63F7DAED3E4A17DAC17432A79.mft: CRL is stale/expired
Oct 24 18:41:52 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/HqfTtKwd1YHMHUpF5w28Bsi8bgCDPsyKHNPb9y16HQqd/0/F9680273CF04CAC413057E6B2B2465CAD46BA4A2.mft: CRL is stale/expired
Oct 24 18:41:52 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/DVt42ktqv2gnJ8LamcyfyGihosiogj9nmwUnSd3SH522/0/07C1E5D4D7A2FEF7ABC380980024FA8E5F3667F7.mft: CRL is stale/expired
Oct 24 18:41:52 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/4TSmZvKRh7C5i7Qa5JmucSocd533Z9uHmccUpDsbRVw6/0/BC6552FEAE387B527DBA080AC5A9F268E628D723.mft: CRL is stale/expired
Oct 24 18:41:53 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/Ea1T4Yn9kYebJmSgF6uTnMwQ9kGNgfPXRqbESgr6Div6/0/7D1E177DABCB1F039743F730A41204DB06B8D471.mft: CRL is stale/expired
Oct 24 18:41:53 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/6aFyUzsQv515RBuYaapg7ot8v2yBWytcpfn57shREgHY/0/696C7FDBC89501359968A6737BF462C540AA5CFE.mft: CRL is stale/expired
Oct 24 18:41:53 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/7puFsVY7zRYcpJ4cPyKkCa9kFs4G1xcJ93mZteW1Rr6e/0/2751E298F97576E706E42DF61117E22126F17DB5.mft: CRL is stale/expired
Oct 24 18:41:53 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/4XQQYnh6XRWxjGSrTgHTeArXmZe9YLudY4M6DG6gdSUN/0/D345EB7198D1D6F10204B388FAC99014B8298C08.mft: CRL is stale/expired
Oct 24 18:41:53 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/xG3mTU3WZrM58jBuTKbJrxk8iqceuzBXZ63EVMM9ZrK/0/5CFD4BD8357F505D6CB1A47E9C153D57129592B6.mft: CRL is stale/expired
Oct 24 18:41:54 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/8SHMmdWSmKcuybksu3ErYWNvQbbq5KJpqsa9iAADH7La/0/E27B080DBCB3C8A6F1E1ACAE6239FBAAB8D051B5.mft: CRL is stale/expired
Oct 24 18:41:54 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/BQgAd2e6J4fmuWFhX7mUYwwhs1cGx5X3QoWFawBEeU4Z/0/AEEB7B0368F7E2A658EC4E02740A7CB24CBDA6E1.mft: CRL is stale/expired
Oct 24 18:41:54 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/BuKiLExJDfzSpp2UcUBZsSx2FkHuburd45jSGakkjKb4/0/328AA38E163EEBE8441252AEA3C2B4B6FF738DA3.mft: CRL is stale/expired
Oct 24 18:41:54 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/CuXCcyMYHNfxHqB8KSLUynYrzajv2UTwjpC5hU8P6Mtn/0/350ADE4FB142FFDB23B548A959DEE079D8AD9AB8.mft: CRL is stale/expired
Oct 24 18:41:54 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/FKZQynmNiWqJKBPrM51UMyBfWpCz2qAAMSUmyMUqAFMc/0/C5413045E00558EB22334E83D6DB67E3FADECDFA.mft: CRL is stale/expired
Oct 24 18:41:54 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/BKmFDnF6bXvEYbLpbnhZEWEkxjGrZRQppXQK4FnUTNVZ/0/F1CA11701480AFA714542D6F661F153EE56E9403.mft: CRL is stale/expired
Oct 24 18:41:54 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/4soZytyXuSQpLSJXeqEjPA5iFUQW4aQVKVhFJ9g2oVZn/0/5FE811DE36B4F9CC446D3A204D0F739A65A5EF36.mft: CRL is stale/expired
Oct 24 18:41:55 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/4QEdUwLT41Yu64VZWZGyYwekhFbm5cUrKC6QZhkreEgp/0/5DD67EDB0CBA6C222F193D244301CEDA035DB765.mft: CRL is stale/expired
Oct 24 18:41:55 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/B4iM1e3ZN7ampov324uiUEt3bnygYTo4UhB54PkhoKQ6/0/B961AD590C8A0651EBFEE46F007C9219D59270C9.mft: CRL is stale/expired
Oct 24 18:41:55 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/CNpBkius7r6N5WS1XXbUVMdyBxkVcja1Hz6nBjMJnGbM/0/4400296416BB5FE1B6E540C3273ADBF56ACD2119.mft: CRL is stale/expired
Oct 24 18:41:55 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/5N8ABw29qTBm55JUg93JsL6T1aq9RLDKhwBMwyykndAN/0/932FD06E95E9079EDF40C5BB219C0F5BBA3791B3.mft: CRL is stale/expired
Oct 24 18:41:56 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/GjfAKQd5YBhYAMm3bNmcAPUwSMPsZqS6PyJF3mpAckrU/0/741AA7E03C555D7D026B9883CDFDCDBCBE2FB819.mft: CRL is stale/expired
Oct 24 18:41:56 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/HLx9sJ9FQnk2bVmevSRFxPaaJX8TQLTC7d63UmWHwKxo/0/BC07094343B21CDB967FB8B26A88D14C2D3B7C62.mft: CRL is stale/expired
Oct 24 18:41:56 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/E9vFSeKTPq17PZQ4HmBQRUFsgXuLP26TXx514wnFxGs1/0/CEA18BE7E56B5BF4C23355D07180FFABCC52E18F.mft: CRL is stale/expired
Oct 24 18:41:56 trantor fort: ERR [Validation]: rsync://rpki-repo.registro.br/repo/DV4QR1rboQjucbuLzDBEZKWLZrnjtPyYzM9kFc6mWcHU/0/C0B102878E6E3362B6C8761382E427E0B4EA5A67.mft: CRL is stale/expired
Oct 24 18:41:56 trantor fort: ERR [Validation]: rsync://rpki.ripe.net/repository/DEFAULT/31ox5UkV6xDrAV7Y8EdtjD9k__E.cer: Error requesting URL https://rpki1.rpki-test.sit.fraunhofer.de/rrdp/notification.xml: SSL certificate problem: unable to get issuer certificate
Oct 24 18:41:56 trantor fort: WRN [Validation]: rsync://rpki.ripe.net/repository/DEFAULT/31ox5UkV6xDrAV7Y8EdtjD9k__E.cer: Max HTTP retries (2) reached requesting for 'https://rpki1.rpki-test.sit.fraunhofer.de/rrdp/notification.xml', won't retry again.
Oct 24 18:41:56 trantor fort: INF [Validation]: rsync://rpki.ripe.net/repository/DEFAULT/31ox5UkV6xDrAV7Y8EdtjD9k__E.cer: Couldn't fetch data from RRDP repository 'https://rpki1.rpki-test.sit.fraunhofer.de/rrdp/notification.xml', trying to fetch data now from 'rsync://rpki1.rpki-test.sit.fraunhofer.de/repo/rpki1_fraunhofer/0/'.
Oct 24 18:41:56 trantor fort: ERR [Validation]: rsync://krill-eval-ctec.charter.com/repo/Charter_CTEC_Lab/3/47CA36B68F7EBB87A8E744A7072F9E3D860263A1.mft: CRL is stale/expired
Oct 24 18:41:59 trantor fort: ERR [Validation]: rsync://rpki1.terratransit.de/repo/TerraTransit/79/EF6D5C4FF0D822C54B3BB2000663091CBC4F41E6.mft: Could not open file '/var/cache/fort/repository/552AF26C/rpki1.terratransit.de/repo/TerraTransit/79/EF6D5C4FF0D822C54B3BB2000663091CBC4F41E6.mft': No such file or directory
Oct 24 18:42:03 trantor fort: ERR [Validation]: rsync://rpki1.terratransit.de/repo/TerraTransit/87/07B1A2CB9D13D3AE494D675F20F04AC17F7F5DCB.mft: Could not open file '/var/cache/fort/repository/552AF26C/rpki1.terratransit.de/repo/TerraTransit/87/07B1A2CB9D13D3AE494D675F20F04AC17F7F5DCB.mft': No such file or directory
Oct 24 18:42:10 trantor fort: ERR [Validation]: rsync://rpki.ripe.net/repository/DEFAULT/IBfMWA0nPFS6MGTNLNavObgEuIc.cer: Error requesting URL https://chloe.sobornost.net/rpki/news-public.xml (received HTTP code 404): The requested URL returned error: 404 Not Found
Oct 24 18:42:10 trantor fort: INF [Validation]: rsync://rpki.ripe.net/repository/DEFAULT/IBfMWA0nPFS6MGTNLNavObgEuIc.cer: Couldn't fetch data from RRDP repository 'https://chloe.sobornost.net/rpki/news-public.xml', trying to fetch data now from 'rsync://chloe.sobornost.net/rpki/uplift/'.
Oct 24 18:42:12 trantor fort: ERR [Validation]: rsync://rpkica.mckay.com/rpki/MCnet/Jp4Tjp_GB5I1RfeaOGhKZNlDmAQ.mft: CRL is stale/expired
Oct 24 18:42:17 trantor fort: ERR [Validation]: rsync://rpki.ripe.net/repository/DEFAULT/OOFPkv3HzPv8GCNhUjrifWl-lS8.cer: Error requesting URL https://chloe.sobornost.net/rpki/news.xml (received HTTP code 404): The requested URL returned error: 404 Not Found
Oct 24 18:42:17 trantor fort: INF [Validation]: rsync://rpki.ripe.net/repository/DEFAULT/OOFPkv3HzPv8GCNhUjrifWl-lS8.cer: Couldn't fetch data from RRDP repository 'https://chloe.sobornost.net/rpki/news.xml', trying to fetch data now from 'rsync://chloe.sobornost.net/rpki/RIPE-nljobsnijders/'.
Oct 24 18:42:22 trantor fort: ERR [Validation]: rsync://rpkica.mckay.com/rpki/MCnet/UEh2SAvdIgPsUFdv92RSSaNqBnY.mft: Could not open file '/var/cache/fort/repository/552AF26C/rpkica.mckay.com/rpki/MCnet/UEh2SAvdIgPsUFdv92RSSaNqBnY.mft': No such file or directory
Oct 24 18:42:32 trantor fort: ERR [Validation]: rsync://rpki.ripe.net/repository/DEFAULT/bW-_qXU9uNhGQz21NR2ansB8lr0.cer: Error requesting URL https://ca.rg.net/rrdp/notify.xml (received HTTP code 404): The requested URL returned error: 404 NOT FOUND
Oct 24 18:42:32 trantor fort: INF [Validation]: rsync://rpki.ripe.net/repository/DEFAULT/bW-_qXU9uNhGQz21NR2ansB8lr0.cer: Couldn't fetch data from RRDP repository 'https://ca.rg.net/rrdp/notify.xml', trying to fetch data now from 'rsync://ca.rg.net/rpki/RGnet-OU/'.
Oct 24 18:42:34 trantor fort: ERR [Validation]: rsync://ca.rg.net/rpki/RGnet-OU/nElaCP4tstyWtV1tLP5tmOMnBXY.gbr: Expected vCard property 'VERSION:4.0', got 'VERSION:3.0'.
Oct 24 18:42:35 trantor fort: INF [Validation]: rsync://ca.rg.net/rpki/RGnet-OU/IOUcOeBGM_Tb4dwfvswY4bnNZYY.cer: RRDP repository 'https://ca.rg.net/rrdp/notify.xml' download/processing returned error previously, now I will try to fetch data from 'rsync://ca.rg.net/rpki/RGnet-OU/ovsCA/'.
Oct 24 18:42:35 trantor fort: ERR [Validation]: rsync://ca.rg.net/rpki/RGnet-OU/IOUcOeBGM_Tb4dwfvswY4bnNZYY.cer: stat(/var/cache/fort/repository/ca.rg.net/rpki/RGnet-OU/ovsCA/IOUcOeBGM_Tb4dwfvswY4bnNZYY.mft) failed
Oct 24 18:42:35 trantor fort: INF [Validation]: rsync://ca.rg.net/rpki/RGnet-OU/WMf3kmevdLp9L8wlYmUsNbXhPrE.cer: RRDP repository 'https://ca.rg.net/rrdp/notify.xml' download/processing returned error previously, now I will try to fetch data from 'rsync://ca.rg.net/rpki/RGnet-OU/ovsCA/'.
Oct 24 18:42:42 trantor fort: INF [Validation]: rsync://rpki.ripe.net/repository/DEFAULT/gqGyfHTn9dwDDkAcU0phsbw8pRI.cer: RRDP repository 'https://chloe.sobornost.net/rpki/news-public.xml' download/processing returned error previously, now I will try to fetch data from 'rsync://chloe.sobornost.net/rpki/Sobornost-RIPE/'.
Oct 24 18:46:25 trantor fort: ERR [Validation]: https://repo-rpki.idnic.net/rrdp/d0b0cc6f-23d0-4f4f-ad5b-adbca8dbf698/261275/delta.xml: Expecting an element , got nothing (at line 1)
Oct 24 18:46:25 trantor fort: ERR [Validation]: https://repo-rpki.idnic.net/rrdp/d0b0cc6f-23d0-4f4f-ad5b-adbca8dbf698/261275/delta.xml: XML document isn't valid.
Oct 24 18:46:25 trantor fort: INF [Validation]: https://repo-rpki.idnic.net/rrdp/notification.xml: There was an error processing RRDP deltas, using the snapshot instead.
Oct 24 18:48:26 trantor fort: WRN [Validation]: rsync://rpki.cnnic.cn/rpki/A9162E3D0000/1584/BZNipAPhpKf9fMAkWueHCjH_mGc.roa: Serial number '6FF' is not unique. (Also found in 'rsync://rpki.cnnic.cn/rpki/A9162E3D0000/1584/762Tkq8nSOXAR_OPz9s_RqNcXgY.roa'.)
Oct 24 18:48:26 trantor fort: WRN [Validation]: rsync://rpki.cnnic.cn/rpki/A9162E3D0000/1030/_0ZMv-nXMfHD2UeNhWHgEKSX7XE.roa: Serial number '6F8' is not unique. (Also found in 'rsync://rpki.cnnic.cn/rpki/A9162E3D0000/1030/P9IcEFxx8rbS2gm13GeV2psTmEs.roa'.)
Oct 24 18:48:26 trantor fort: WRN [Validation]: rsync://rpki.cnnic.cn/rpki/A9162E3D0000/1030/q7HhNkd-enW0u2mv3zNj-zhV5EM.roa: Serial number '6F8' is not unique. (Also found in 'rsync://rpki.cnnic.cn/rpki/A9162E3D0000/1030/P9IcEFxx8rbS2gm13GeV2psTmEs.roa'.)
Oct 24 18:48:26 trantor fort: WRN [Validation]: rsync://rpki.cnnic.cn/rpki/A9162E3D0000/2988/bDYshM_JkVOGvyLw1zmhP2UJ4bk.roa: Serial number '6C9' is not unique. (Also found in 'rsync://rpki.cnnic.cn/rpki/A9162E3D0000/2988/GCdYmYr5cs00v0nv9lrxeXx_9h0.roa'.)
Oct 24 18:48:26 trantor fort: WRN [Validation]: rsync://rpki.cnnic.cn/rpki/A9162E3D0000/2988/dZlv20oaEwbJEq0dFcm80DFnNJM.roa: Serial number '6C9' is not unique. (Also found in 'rsync://rpki.cnnic.cn/rpki/A9162E3D0000/2988/GCdYmYr5cs00v0nv9lrxeXx_9h0.roa'.)
Oct 24 18:48:26 trantor fort: WRN [Validation]: rsync://rpki.cnnic.cn/rpki/A9162E3D0000/2988/suKIkebH_oWVIpCkYYlIX0gyD8k.roa: Serial number '6C9' is not unique. (Also found in 'rsync://rpki.cnnic.cn/rpki/A9162E3D0000/2988/GCdYmYr5cs00v0nv9lrxeXx_9h0.roa'.)
Oct 24 18:48:26 trantor fort: WRN [Validation]: rsync://rpki.cnnic.cn/rpki/A9162E3D0000/332/duxjTORrmTPKBF1l0BfjK-wTXjQ.roa: Serial number '6EC' is not unique. (Also found in 'rsync://rpki.cnnic.cn/rpki/A9162E3D0000/332/8OVjT2xkaxXlZXhT3GNcTurGIIw.roa'.)
Oct 24 18:48:31 trantor fort: WRN [Validation]: rsync://rpkica.twnic.tw/rpki/TWNICCA/ULC/F79LZLC6hqMDDYzbebV8qM25_9s.roa: Serial number '1B0' is not unique. (Also found in 'rsync://rpkica.twnic.tw/rpki/TWNICCA/ULC/-rDysy1NBdX_GxSCYSCkMCVmp1k.roa'.)
Oct 24 18:48:31 trantor fort: WRN [Validation]: rsync://rpkica.twnic.tw/rpki/TWNICCA/ULC/RzOfDV8VdKD9hIIyYY-RYTkuOwk.roa: Serial number '1B0' is not unique. (Also found in 'rsync://rpkica.twnic.tw/rpki/TWNICCA/ULC/-rDysy1NBdX_GxSCYSCkMCVmp1k.roa'.)
Oct 24 18:48:31 trantor fort: WRN [Validation]: rsync://rpkica.twnic.tw/rpki/TWNICCA/ULC/gD_BzzwZY7VXFasWgcNVegD6XkY.roa: Serial number '1B0' is not unique. (Also found in 'rsync://rpkica.twnic.tw/rpki/TWNICCA/ULC/-rDysy1NBdX_GxSCYSCkMCVmp1k.roa'.)
Oct 24 18:48:31 trantor fort: WRN [Validation]: rsync://rpkica.twnic.tw/rpki/TWNICCA/ULC/gc5Z9kPagihaOnsIfqA715gvvyo.roa: Serial number '1B0' is not unique. (Also found in 'rsync://rpkica.twnic.tw/rpki/TWNICCA/ULC/-rDysy1NBdX_GxSCYSCkMCVmp1k.roa'.)
Oct 24 18:48:31 trantor fort: WRN [Validation]: rsync://rpkica.twnic.tw/rpki/TWNICCA/ULC/yTMQdgDvjHCCXlAD0CYdiZFwSGA.roa: Serial number '1B0' is not unique. (Also found in 'rsync://rpkica.twnic.tw/rpki/TWNICCA/ULC/-rDysy1NBdX_GxSCYSCkMCVmp1k.roa'.)
Oct 24 18:48:38 trantor fort: ERR [Validation]: rsync://rpki-repository.nic.ad.jp/ap/A91A73810000/699/bkqeJzVTPVpOXDMPDUQnaPOy7iw.roa: Certificate validation failed: RFC 3779 resource not subset of parent's resources
Oct 24 18:48:44 trantor fort: INF: Validation finished:
Oct 24 18:48:44 trantor fort: INF: - Valid Prefixes: 285591
Oct 24 18:48:44 trantor fort: INF: - Valid Router Keys: 0
Oct 24 18:48:44 trantor fort: INF: - Serial: 9
Oct 24 18:48:44 trantor fort: INF: - Real execution time: 429 secs.
ydahhrk commented 2 years ago

Do these logs suggest to you that something is not working correctly

No. The repositories always contain at least some bugged out objects.

does the code not provide a breakdown of contact with PPs (unless an error occurs) in INFO mode? I appended a snippet of the logs.

No, but I could add it. Why do you need it?

cli0 commented 2 years ago

I am analyzing my RP traffic and I need to know what domains the RP tries to connect with, successfully or not, and when in INFO mode. Debug mode has way too much overhead. I can get anywhere from 500MB to 1.5G of logs per hour.

ydahhrk commented 2 years ago

Ok.

Are you married to the logs?

Tentatively, it sounds like this information would be better off available in the Prometheus endpoint (#50) instead.

cli0 commented 2 years ago

They are necessary in my local deployment to oversee how the RP is working, who it is contacting and when. I think this information should qualify in the INFO log level anyway, regardless if it is added later to a future Prometheus endpoint. It's what one expects when setting log levels to INFO.

ydahhrk commented 2 years ago

Is this what you asked for?

Sample output:

Nov 16 14:45:33 INF [V]: notification.xml: HTTP GET: https://rrdp.arin.net/notification.xml
Nov 16 14:45:33 INF [V]: notification.xml: HTTP GET: https://rrdp.lacnic.net/rrdp/notification.xml
Nov 16 14:45:33 INF [V]: snapshot.xml: HTTP GET: https://rrdp.arin.net/8fe05c2e-047d-49e7-8398-cd4250a572b1/50847/snapshot.xml
Nov 16 14:45:34 INF [V]: notification.xml: HTTP GET: https://rrdp.afrinic.net/notification.xml
Nov 16 14:45:34 INF [V]: snapshot.xml: HTTP GET: https://rrdp.lacnic.net/rrdp/26afc8dd-3e3b-4b31-8ff1-710d8e944320/8794/snapshot.xml
Nov 16 14:45:34 INF [V]: notification.xml: HTTP GET: https://rrdp.apnic.net/notification.xml
Nov 16 14:45:36 INF [V]: snapshot.xml: HTTP GET: https://rrdp.afrinic.net/11218e02-4ae9-4c95-a8fa-49df27f15272/27337/snapshot.xml
...
Nov 16 14:50:27 INF [V]: uo930h5Y_pyTmmtw4lhWF-GDN2s.cer: rsync: rsync://repo-rpki.idnic.net/repo
Nov 16 14:50:30 INF [V]: IBfMWA0nPFS6MGTNLNavObgEuIc.cer: rsync: rsync://chloe.sobornost.net/rpki

A full validation cycle generated 848 kilobytes worth of logging output. (Although my --validation-log.file-name-format is set to file-name.)

cli0 commented 2 years ago

Yes, that looks great. I can tell when PPs are being contacted. Thank you!

ydahhrk commented 1 year ago

1.5.4 released; closing.