Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Pihole v6 takes more than 4 minutes to start on raspberry pi 3b #1622

Open
6 tasks done
rohitagre opened this issue Aug 7, 2024 · 9 comments
Open
6 tasks done

Pihole v6 takes more than 4 minutes to start on raspberry pi 3b #1622

rohitagre opened this issue Aug 7, 2024 · 9 comments
Labels
never-stale Use this label to ensure the stale action does not close this issue

Comments

@rohitagre
Copy link

This is a: Bug

Details

On restart of docker container, pihole loads queries from the long term database and it takes too long to finish this process. DNS resolution is unavailable during this time.

Related Issues

  • I have searched this repository/Pi-hole forums for existing issues and pull requests that look similar

How to reproduce the issue

  1. Environment data
  • Operating System: Rasbian
  • Hardware: RasPi 3B
  • Kernel Architecture: aarch64
  • Docker Install Info and version:
    • Software source: Official Docker version 27.1.1, build 6312585
    • Supplimentary Software:
  • Hardware architecture:
  1. docker-compose.yml contents, docker run shell command, or paste a screenshot of any UI based configuration of containers here
# More info at https://github.com/pi-hole/docker-pi-hole/ and https://docs.pi-hole.net/
services:
  pihole:
    image: pihole/pihole:development-v6
    container_name: pihole-v6
    environment:
      # Change the Web UI Password:
      - FTLCONF_webserver_api_password=password
      - TZ=Asia/Kolkata
      - FTLCONF_dns_listeningMode=all
      - VIRTUAL_HOST=pihole.lan
      - VIRTUAL_PORT=80
    dns:
      - 127.0.0.1
    volumes:
      - "/home/pi/portainer/pihole6/etc-pihole:/etc/pihole"
      - "/home/pi/portainer/pihole6/etc-dnsmasq.d:/etc/dnsmasq.d"
    ports:
      - "53:53/tcp"
      - "53:53/udp"
    restart: unless-stopped
    networks:
      work:
        ipv4_address: 10.10.20.3

networks:
  work:
    name: work
    external: true
  1. any additional info to help reproduce
2024-08-07 10:54:57.725 IST [148M] INFO: ########## FTL started on 0022a4f6082d! ##########
2024-08-07 10:54:57.725 IST [148M] INFO: FTL branch: development-v6
2024-08-07 10:54:57.726 IST [148M] INFO: FTL version: vDev-7c00ea3
2024-08-07 10:54:57.726 IST [148M] INFO: FTL commit: 7c00ea38
2024-08-07 10:54:57.726 IST [148M] INFO: FTL date: 2024-07-29 18:17:47 +0200
2024-08-07 10:54:57.726 IST [148M] INFO: FTL user: pihole
2024-08-07 10:54:57.726 IST [148M] INFO: Compiled for linux/arm64/v8 (compiled on CI) using cc (Alpine 13.2.1_git20240309) 13.2.1 20240309
2024-08-07 10:54:59.036 IST [148M] INFO: 2 FTLCONF environment variables found (2 used, 0 invalid, 0 ignored)
2024-08-07 10:54:59.037 IST [148M] INFO:    [✓] FTLCONF_dns_listeningMode is used
2024-08-07 10:54:59.037 IST [148M] INFO:    [✓] FTLCONF_webserver_api_password is used
2024-08-07 10:54:59.043 IST [148M] INFO: Wrote config file:
2024-08-07 10:54:59.044 IST [148M] INFO:  - 148 total entries
2024-08-07 10:54:59.044 IST [148M] INFO:  - 134 entries are default
2024-08-07 10:54:59.044 IST [148M] INFO:  - 14 entries are modified
2024-08-07 10:54:59.044 IST [148M] INFO:  - 1 entry is forced through environment
2024-08-07 10:54:59.052 IST [148M] INFO: Parsed config file /etc/pihole/pihole.toml successfully
2024-08-07 10:54:59.053 IST [148M] WARNING: Insufficient permissions to set process priority to -10 (CAP_SYS_NICE required), process priority remains at 0
2024-08-07 10:54:59.060 IST [148M] INFO: PID of FTL process: 148
2024-08-07 10:54:59.063 IST [148M] INFO: listening on 0.0.0.0 port 53
2024-08-07 10:54:59.063 IST [148M] INFO: listening on :: port 53
2024-08-07 10:54:59.069 IST [148M] INFO: PID of FTL process: 148
2024-08-07 10:54:59.073 IST [148M] INFO: Database version is 19
2024-08-07 10:54:59.076 IST [148M] INFO: Database successfully initialized

<!-- import starts here -->
2024-08-07 10:55:50.360 IST [148M] INFO: Imported 351284 queries from the on-disk database (it has 1374429 rows)
2024-08-07 10:55:50.360 IST [148M] INFO: Parsing queries in database
2024-08-07 10:55:51.877 IST [148M] INFO:   10000 queries parsed...
2024-08-07 10:55:54.079 IST [148M] INFO:   20000 queries parsed...
2024-08-07 10:55:57.003 IST [148M] INFO:   30000 queries parsed...
2024-08-07 10:56:00.652 IST [148M] INFO:   40000 queries parsed...
2024-08-07 10:56:04.362 IST [148M] INFO:   50000 queries parsed...
2024-08-07 10:56:09.718 IST [148M] INFO:   60000 queries parsed...
2024-08-07 10:56:15.251 IST [148M] INFO:   70000 queries parsed...
2024-08-07 10:56:20.512 IST [148M] INFO:   80000 queries parsed...
2024-08-07 10:56:26.032 IST [148M] INFO:   90000 queries parsed...
2024-08-07 10:56:31.627 IST [148M] INFO:   100000 queries parsed...
2024-08-07 10:56:38.287 IST [148M] INFO:   110000 queries parsed...
2024-08-07 10:56:44.929 IST [148M] INFO:   120000 queries parsed...
2024-08-07 10:56:51.075 IST [148M] INFO:   130000 queries parsed...
2024-08-07 10:56:57.060 IST [148M] INFO:   140000 queries parsed...
2024-08-07 10:57:02.521 IST [148M] INFO:   150000 queries parsed...
2024-08-07 10:57:08.473 IST [148M] INFO:   160000 queries parsed...
2024-08-07 10:57:15.285 IST [148M] INFO:   170000 queries parsed...
2024-08-07 10:57:22.252 IST [148M] INFO:   180000 queries parsed...
2024-08-07 10:57:29.829 IST [148M] INFO:   190000 queries parsed...
2024-08-07 10:57:36.276 IST [148M] INFO:   200000 queries parsed...
2024-08-07 10:57:43.524 IST [148M] INFO:   210000 queries parsed...
2024-08-07 10:57:49.280 IST [148M] INFO:   220000 queries parsed...
2024-08-07 10:57:57.731 IST [148M] INFO:   230000 queries parsed...
2024-08-07 10:58:05.275 IST [148M] INFO:   240000 queries parsed...
2024-08-07 10:58:13.886 IST [148M] INFO:   250000 queries parsed...
2024-08-07 10:58:22.101 IST [148M] INFO:   260000 queries parsed...
2024-08-07 10:58:29.510 IST [148M] INFO:   270000 queries parsed...
2024-08-07 10:58:39.272 IST [148M] INFO:   280000 queries parsed...
2024-08-07 10:58:48.068 IST [148M] INFO:   290000 queries parsed...
2024-08-07 10:58:55.903 IST [148M] INFO:   300000 queries parsed...
2024-08-07 10:59:03.794 IST [148M] INFO:   310000 queries parsed...
2024-08-07 10:59:12.703 IST [148M] INFO:   320000 queries parsed...
2024-08-07 10:59:19.649 IST [148M] INFO:   330000 queries parsed...
2024-08-07 10:59:31.265 IST [148M] INFO:   340000 queries parsed...
2024-08-07 10:59:42.556 IST [148M] INFO:   350000 queries parsed...
2024-08-07 10:59:42.821 IST [148M] INFO: Imported 350224 queries from the long-term database
<!-- import ends here after almost 5 mins -->

2024-08-07 10:59:42.821 IST [148M] INFO:  -> Total DNS queries: 350224
2024-08-07 10:59:42.822 IST [148M] INFO:  -> Cached DNS queries: 129862
2024-08-07 10:59:42.822 IST [148M] INFO:  -> Forwarded DNS queries: 51045
2024-08-07 10:59:42.822 IST [148M] INFO:  -> Blocked DNS queries: 165277
2024-08-07 10:59:42.822 IST [148M] INFO:  -> Unknown DNS queries: 11
2024-08-07 10:59:42.822 IST [148M] INFO:  -> Unique domains: 5788
2024-08-07 10:59:42.822 IST [148M] INFO:  -> Unique clients: 56
2024-08-07 10:59:42.822 IST [148M] INFO:  -> DNS cache records: 24458
2024-08-07 10:59:42.823 IST [148M] INFO:  -> Known forward destinations: 2
2024-08-07 10:59:42.847 IST [148M] WARNING: Insufficient permissions to set system time (CAP_SYS_TIME required), NTP client not available
2024-08-07 10:59:42.847 IST [148/T718] INFO: NTP server listening on 0.0.0.0:123 (IPv4)
2024-08-07 10:59:42.847 IST [148/T719] INFO: NTP server listening on :::123 (IPv6)
2024-08-07 10:59:42.848 IST [148M] INFO: FTL is running as user pihole (UID 100)
2024-08-07 10:59:42.849 IST [148M] INFO: Reading certificate from /etc/pihole/tls.pem ...
2024-08-07 10:59:42.850 IST [148M] INFO: Using SSL/TLS certificate file /etc/pihole/tls.pem
2024-08-07 10:59:43.446 IST [148M] INFO: Restored 1 API session from the database
2024-08-07 10:59:43.518 IST [148M] INFO: Blocking status is enabled
2024-08-07 10:59:43.565 IST [148/T720] INFO: Compiled 0 allow and 0 deny regex for 56 clients in 1.5 msec

I just hope i am not missing any configuration parameters which is causing this.

Screenshot 2024-08-07 at 11 50 14 AM

These common fixes didn't work for my issue

  • I have tried removing/destroying my container, and re-creating a new container
  • I have tried fresh volume data by backing up and moving/removing the old volume data
  • I have tried running the stock docker run example(s) in the readme (removing any customizations I added)
  • I have tried a newer or older version of Docker Pi-hole (depending what version the issue started in for me)
  • I have tried running without my volume data mounts to eliminate volumes as the cause

If the above debugging / fixes revealed any new information note it here.
Add any other debugging steps you've taken or theories on root cause that may help.
@rdwebdesign
Copy link
Member

[x] I have tried running without my volume data mounts to eliminate volumes as the cause

Do you see the same 4 minutes even without the volumes?

@rohitagre
Copy link
Author

I have removed the volumes and i am now waiting for the database to populate. i will report back in 1 day

@rohitagre
Copy link
Author

rohitagre commented Aug 8, 2024 •
edited
Loading

Does not make any difference if i remove the Volumes. but i lose all customisations :(
With Volumes : Time taken to load 60,000 queries : ~18 seconds
Without Volumes : Time taken to load 60,000 queries : ~15 seconds

2024-08-08 17:58:39.417 IST [148M] INFO: Imported 69246 queries from the on-disk database (it has 69246 rows)
2024-08-08 17:58:39.417 IST [148M] INFO: Parsing queries in database
2024-08-08 17:58:40.164 IST [148M] INFO:   10000 queries parsed...
2024-08-08 17:58:41.918 IST [148M] INFO:   20000 queries parsed...
2024-08-08 17:58:44.137 IST [148M] INFO:   30000 queries parsed...
2024-08-08 17:58:46.744 IST [148M] INFO:   40000 queries parsed...
2024-08-08 17:58:49.189 IST [148M] INFO:   50000 queries parsed...
2024-08-08 17:58:52.047 IST [148M] INFO:   60000 queries parsed...
2024-08-08 17:58:54.955 IST [148M] INFO: Imported 69246 queries from the long-term database
2024-08-08 17:58:54.955 IST [148M] INFO:  -> Total DNS queries: 69246

I would also like to emphasise that pihole is running on a raspberry pi and it has only one SD card for all data, its not like docker volumes are on a different storage, so i don't think it should make any difference.

@PromoFaux
Copy link
Member

Nothing to do with the slow loading, but these are not valid env vars:

      - VIRTUAL_HOST=pihole.lan
      - VIRTUAL_PORT=80

Two thoughts come to mind:

  • What class of SD card are you using?
  • Are you using an appropriate power supply for the Raspberry Pi?

@rohitagre
Copy link
Author

rohitagre commented Aug 8, 2024 •
edited
Loading

The env vars are for nginx proxy that I use for the web UI.

The SD card is class 10 and I am using official power supply for the pi.

$ sudo mmc csd read /sys/block/mmcblk0/device
type: 'SD'
card classes: 10 switch, 8 application specific, 7 lock card, 5 erase, 4 block write, 2 block read, 0 basic, 
capacity: 29.28Gbyte (31439454208 bytes, 61405184 sectors, 512 bytes each)

Speed test on SD card shows following

Write test

$ sudo dd if=/dev/zero of=./TestingFile bs=100M count=5 oflag=direct
5+0 records in
5+0 records out
524288000 bytes (524 MB, 500 MiB) copied, 40.99 s, 12.8 MB/s

Read test

$ sudo dd if=./TestingFile of=/dev/zero bs=100M count=5 oflag=dsync
5+0 records in
5+0 records out
524288000 bytes (524 MB, 500 MiB) copied, 23.0098 s, 22.8 MB/s

@PromoFaux
Copy link
Member

Sorry, I mean to say they're not valid for v6. There is nothing inside the v6 container looking for those variables. I think there are equivalent proxy settings in FTL, though I do not have the documentation to hand right now.

I'll see if I can dig a 3b and a class 10 SD card out of my box of things and try to reproduce at some point - I have so far not experienced any such slow startup time, but then I am testing v6 on an x86 machine

@rohitagre
Copy link
Author

Sorry I don't think I was clear in my previous reply.

Those environment variables are used by another container running nginx-proxy which helps me in assigning local DNS domains to my containers so I don't have to use multiple ports
https://github.com/nginx-proxy/nginx-proxy

@github-actions GitHub Actions
Copy link

github-actions bot commented Sep 8, 2024

This issue is stale because it has been open 30 days with no activity. Please comment or update this issue or it will be closed in 5 days.

@github-actions github-actions bot added the stale label Sep 8, 2024
@github-actions github-actions bot closed this as not planned Won't fix, can't repro, duplicate, stale Sep 13, 2024
@rohitagre
Copy link
Author

@github-actions bot please reopen this issue  😉

@github-actions github-actions bot removed the stale label Sep 13, 2024
@yubiuser yubiuser reopened this Sep 13, 2024
@PromoFaux PromoFaux added the never-stale Use this label to ensure the stale action does not close this issue label Sep 13, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
never-stale Use this label to ensure the stale action does not close this issue
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@rdwebdesign @PromoFaux @rohitagre @yubiuser