Unrecoverable crash every few days: context deadline exceeded

[nathang21]

• [x ] I have checked the existing issues to avoid duplicates
• [x ] I have redacted any info hashes and content metadata from any logs or screenshots attached to this issue

Describe the bug

Bitmagnet container crashes after some delay, about every ~1-3 days from what I can tell. It does not restart/recover automatically, seemingly because the exit code is 1 (docker is weird about restarting only for certain exit codes). I have been having some intermittent network stability issues with my ISP, and it seems loosely correlated with that, although it has happened even when I didn't notice any other problems on my network, so i'm not fully convinced that is the trigger/root cause.

I've attached the raw debug logs from a recent failover, AFAICT there isn't anything sensitive in them as it's mostly errors but apologize if I missed anything, happy to edit/redact if needed.
bitmagnet.log

To Reproduce

Steps to reproduce the behavior:

1. Boot Bitmagnet
2. Wait for issue to re-occur
3. View stopped container and inspect logs

Expected behavior

Bitmagnet to remain stable and not crash, however if it does crash ideally it would self-recover better as well.

Environment Information (Required)

• Bitmagnet version: v0.9.5
• OS and version: macOS 15.1.1 (24B2091)
• Browser and version (if issue is with WebUI): Version 131.0.6778.70 (Official Build) (arm64) (not WebUI related)
• Please specify any config values for which you have overridden the defaults: See docker compose below

Additional context

Bitmagnet was super heavy on Disk I/O, and I have plenty of RAM so I made some tweaks to the Postgres config to prefer RAM over Disk I/O in some cases, which has helped a lot with the performance of my Synology NAS DS423+.

Docker Compose:

bitmagnet:
    container_name: bitmagnet
    image: ghcr.io/bitmagnet-io/bitmagnet:latest
    volumes:
      - /volume2/docker/starr-trash/bitmagnet:/root/.local/share/bitmagnet
    restart: always
    environment:
      - LOG_FILE_ROTATOR_ENABLED=true
      - POSTGRES_HOST=bitmagnet-postgres
      - POSTGRES_PASSWORD=<REDACTED>
      - TMDB_API_KEY=<REDACTED>
      - CLASSIFIER_DELETE_XXX=true
      - DHT_CRAWLER.SCAILING_FACTOR=5
      - LOG_LEVEL=debug
    labels:
      - autoheal=true
    shm_size: 1g
    logging:
      driver: json-file
      options:
        max-file: ${DOCKERLOGGING_MAXFILE}
        max-size: ${DOCKERLOGGING_MAXSIZE}
    # logging:
    #   driver: none
    # Ports mapped via VPN
    # ports:
    #   - 3333:3333 # Bitmagnet - API and WebUI
    #   - 3334:3334/tcp # Bitmagnet - BitTorrent
    #   - 3334:3334/udp # Bitmagnet - BitTorrent
    network_mode: service:gluetun
    depends_on:
      gluetun:
        condition: service_healthy # Used by gluetun-healthcheck.sh script.
        restart: true
      bitmagnet-postgres:
        condition: service_healthy
        restart: true
    healthcheck:
      test: "nc -z localhost 9999 || kill 1"
      interval: 1m
      timeout: 1m
      start_period: 300s
    command:
      - worker
      - run
      # Run all workers:
      - --all
      # Or enable individual workers:
      # - --keys=http_server
      # - --keys=queue_server
      # - --keys=dht_crawler

  bitmagnet-postgres:
    image: postgres:16-alpine
    container_name: bitmagnet-postgres
    volumes:
      - /volume2/docker/starr-trash/bitmagnet/postgres:/var/lib/postgresql/data
    ports:
      - "6432:5432"
    shm_size: 3g
    restart: always
    command:
      -c shared_buffers=3GB
      -c work_mem=256MB
      -c maintenance_work_mem=512MB
      -c checkpoint_timeout=30min
      -c checkpoint_completion_target=0.9
      -c wal_buffers=128MB
      -c effective_cache_size=6GB
      -c synchronous_commit=off
      -c autovacuum_vacuum_cost_limit=2000
      -c autovacuum_vacuum_cost_delay=10ms
      -c autovacuum_max_workers=3
      -c autovacuum_naptime=20s
      -c autovacuum_vacuum_scale_factor=0.05
      -c autovacuum_analyze_scale_factor=0.02
      -c temp_file_limit=5GB
      # Risk data loss
      # -c fsync=off
      # -c full_page_writes=off
    # logging:
    #   driver: none
    environment:
      - POSTGRES_PASSWORD=<REDACTED>
      - POSTGRES_DB=bitmagnet
      - PGUSER=postgres
    healthcheck:
      test: ["CMD-SHELL", "pg_isready"]
      interval: 10s
      start_period: 60s
    networks:
      syno-bridge:
        # https://github.com/qdm12/gluetun-wiki/blob/main/setup/inter-containers-networking.md#between-a-gluetun-connected-container-and-another-container
        # Required until fixed: https://github.com/qdm12/gluetun/issues/281
        ipv4_address: <REDACTED>

[rraymondgh]

I found running bitmagnet on macOS Catalina and an old version of docker problematic. I could not update macOS or docker due Mac being a 2012 Mac mini. Split Fusion Drive and created partitions of ssd and hdd. Then dual booted to Ubuntu 24.10 and latest version of docker. Bitmagnet is now very stable - no crashes of docker daemon. Hence I suspect docker version and host os version are important for stable networking with bitmagnet crawling network loads

[DerBunteBall]

There are various problem reports about Bitmagnet in connection with Docker on Windows or macOS hosts.

The following should always be borne in mind:
Bitmagnet is an app with high I/O requirements in terms of both storage and network.

On Windows and macOS, it must always be borne in mind that the usual Docker stacks are mostly a virtualization solution. Probably Hyper-V on Windows today and Hyperkit on macOS.

These are already highly optimized hypervisors for the platforms. The small Linux running in them is also highly optimized. However, both the hypervisor and the device model of the VM (emulated network card, etc.) or some setting in the parts of the stack (be it a kernel option in the kernel of the small Linux system) can lead to problems.
Bitmagnet lives best on physical hardware, a system isolated for operation, which is best equipped with HVMe storage. CPUs of older generations, the middle class and also mobile processors are perfectly adequate. Just add 16-32GB of RAM and you're good to go.

[nathang21]

Thanks for chiming in folks. To be clear for this issue, I am running docker natively on linux not via any hypervisor. I am using a Synology DS423+ NAS (which unfortunately still uses an older Docker Daemon - v24.0.2), paired with a modern M.2 NVME 1TB SSD and 18 GB of RAM.

This wasn't a problem previously but i have been running Bitmagnet for almost 6 months so maybe the increased size of the DB is putting more pressure?. It is intermittent, I haven't had a crash in about a week.

Honestly, an occasional crash isn't a big deal to me, but I'd like to debug why it was unable to recover on its own, and required my manually intervention.

[DerBunteBall]

I was assuming macOS as it was in the first post above.

NAS devices are also extremely unsuitable for software like Bitmagnet.
On the one hand, the underlying Linux distributions are highly optimized. Possibly even so that it is problematic for Bitmagnet. In addition, the Docker versions are often very old.
The hardware can also still cause problems here. Even with an SSD cache. There are two main reasons for this. The I/O level that NAS devices often have and the fact that there is a high CPU base load (especially with smaller devices).

At first glance, I would assume from the debug log that the restart does not succeed at all because “not the container” is terminated but because “the process is shot down” and Docker then stops the container. It could also be that it is simply getting tangled up.

For me, the reason could be that there are situations in which files can no longer be opened. I would suspect this because of the “bad file descriptor” errors. It looks like it can't write to the socket, which causes it to crash at some point.

That wouldn't surprise me with a NAS either. On the one hand, they already have a lot of files open, and on the other, a lot of small network connections open and therefore a lot of sockets open. It should be borne in mind that sockets in Unix are also files according to the “everything is a file” principle.
I think that somewhere there lies the problem. Possibly also kernel options that influence socket sizes or other socket options. Possibly other limitations are also relevant that often want to keep processes in check on NAS devices.

[nathang21]

Ah apologies, I thought that was for debugging the web app (which I am using macOS in this case).

Regarding NAS devices in general, that is an interesting perspective, and that does make some sense, although i'm not certain it's what i'm experiencing based on a few things:

• To be clear, i'm not using an "SSD Cache", but a full SSD volume, where docker and all the relevant containers and their state live. This is technically the same system as the rest of my NAS with HDD's but the SSD is only used for containers and other applications, which allows for a very performant operation.
• Regarding socket sizes / file limits, I have run into that issue before with Plex, and I did have to increase the default limits, which has worked well for me. I previously changed my system config to the following fs.inotify.max_user_watches=524288 and fs.inotify.max_user_instances=1024, perhaps i could continue scaling up if i'm reaching these limits again, but will need to determine if thats what is actually happening.
• I haven't had any other issues running numerous other containers on this device, with varying levels of load across CPU/RAM/DISK/NET. Overall my system runs quite smooth, with occasional bursts of activity due to scheduled tasks or general use, but i've never had this interrupt bitmagnet previously.
• Interestingly, it hasn't crashed in about a week (since posting this issue) so that is good news, and my network has been stable so it seems correlated to that.

[BattouSaeen]

Heya, I'm completely noob when it comes to Docker et al but I at least managed to set it up and run it. However, the crashes for me happen every few minutes rather than days. I'm running on Windows 10, latest Docker, using SSD. I don't know if it's an actual crash or not, but I am always getting

"bitmagnet | WARN dht_crawler dhtcrawler/bootstrap.go:20 failed to resolve bootstrap node address: lookup router.bittorrent.cloud on 127.0.0.11:53: server misbehaving"

Even while it's crawling, so I can't tell if this is a result of crawling stopping, or there is some delay, because this error increases and correlates with zero crawling being done. There is no exit, database reports checkpoints as healthy and all is well in that regard.

In the beginning, it wasn't crawling at all, so I thought maybe my VPN setup was blocking something. I have no idea, but I setup split tunnelling anyway and it seemed to get things started (and I believe there was a separate error that doesn't show up now). Just some extra info.

But yeah anyway, any ideas why this warning shows up and the crawling ends in a few minutes? I have to keep restarting the container or docker itself for it to resume and then few minutes later, it's rinse and repeat.

[PaddyPang]

@BattouSaeen same issue😂

2025-02-07 22:34:10 INFO        migrator        migrations/migrator.go:68       checking and applying migrations...
2025-02-07 22:34:10 INFO        migrator        migrations/logger.go:33 goose: no migrations to run. current version: 18
2025-02-07 22:34:11 INFO        worker/worker.go:195    started worker  {"key": "http_server"}
2025-02-07 22:34:11 INFO        worker/worker.go:195    started worker  {"key": "queue_server"}
2025-02-07 22:34:11 INFO        worker/worker.go:195    started worker  {"key": "dht_crawler"}
2025-02-07 22:34:11 WARN        dht_crawler     dhtcrawler/bootstrap.go:20      failed to resolve bootstrap node address: lookup dht.anacrolix.link on 127.0.0.11:53: no such host
2025-02-07 22:34:11 WARN        dht_crawler     dhtcrawler/bootstrap.go:20      failed to resolve bootstrap node address: lookup router.bittorrent.cloud on 127.0.0.11:53: no such host
2025-02-07 22:39:11 WARN        tmdb/requester_lazy.go:40       you are using the default TMDB api key; TMDB requests will be limited to 1 per second; to remove this warning please configure a personal TMDB api key

[mgdigital]

At the moment I don't have much insight on the container crash, however I can say that the warning failed to resolve bootstrap node address is not an error, and unrelated to any container crashes.

We cannot control if any given bootstrap node is online at any given moment; the warning indicates a node is currently unreachable and should not affect functionality (as long as we can connect to at least one of the nodes).

[PaddyPang]

At the moment I don't have much insight on the container crash, however I can say that the warning failed to resolve bootstrap node address is not an error, and unrelated to any container crashes.

We cannot control if any given bootstrap node is online at any given moment; the warning indicates a node is currently unreachable and should not affect functionality (as long as we can connect to at least one of the nodes).

Yeah.This issue does not affect usage, I think this issue can be closed.

[issuefiler]

I guess it’s a Windows thing. I have run it both with and without Docker (containerized or native) on Windows and in both cases, I noticed network utilization occasionally dropping down to zero with context deadline exceeded. All requests it made timed out and failed and the only way to recover was restarting it. It took minutes or days since launching to encounter this.

[issuefiler]

{"severity":"DEBUG","timestamp":"2025-04-17T17:50:22.172916+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"ping failed","addr":"67.150.1.151:40980","duration":4.000226,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:22.172916+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"ping failed","addr":"116.126.112.125:8187","duration":4.000226,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:24.1661892+09:00","logger":"dht_client","caller":"client/logger.go:68","message":"find_node","addr":"133.32.232.7:6785","duration":0.0538282}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:24.5282118+09:00","logger":"gin","caller":"ginzap/ginzap.go:93","message":"/graphql","status":200,"method":"POST","path":"/graphql","query":"","ip":"::1","user-agent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Edg/135.0.0.0","latency":0,"time"
:"2025-04-17T08:50:24Z"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:28.1737012+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"ping failed","addr":"191.84.21.162:50433","duration":4.0004674,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:28.1737012+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"ping failed","addr":"117.215.54.160:4000","duration":4.0004674,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:30.1678963+09:00","logger":"dht_client","caller":"client/logger.go:68","message":"find_node","addr":"133.32.232.7:6785","duration":0.0535582}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:34.1740702+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"ping failed","addr":"175.182.31.57:26900","duration":4.0003066,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:34.1740702+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"ping failed","addr":"191.84.21.162:50433","duration":4.0003066,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:34.1740702+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"find_node failed","addr":"122.5.99.56:57256","duration":4.0003066,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:34.1740702+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"find_node failed","addr":"117.215.54.160:4000","duration":4.0003066,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:34.1740702+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"ping failed","addr":"73.248.180.243:56314","duration":4.0003066,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:34.1740702+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"ping failed","addr":"115.55.138.64:23460","duration":4.0003066,"er
ror":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:35.5262841+09:00","logger":"gin","caller":"ginzap/ginzap.go:93","message":"/graphql","status":200,"method":"POST","path":"/graphql","query":"","ip":"::1","user-agent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Edg/135.0.0.0","latency":0,"time":"202
5-04-17T08:50:35Z"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:36.1693595+09:00","logger":"dht_client","caller":"client/logger.go:68","message":"find_node","addr":"133.32.232.7:6785","duration":0.0531712}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:40.1747305+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"sample_infohashes failed","addr":"61.84.64.70:40926","duration":4.000407,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:40.1747305+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"find_node failed","addr":"46.188.41.173:51413","duration":4.000407,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:40.1747305+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"sample_infohashes failed","addr":"163.53.207.140:1474","duration":4.000407,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:42.1719208+09:00","logger":"dht_client",
"caller":"client/logger.go:68","message":"find_node","addr":"133.32.232.7:6785","duration":0.0541948}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:46.1753624+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"sample_infohashes failed","addr":"221.163.21.37:40984","duration":4.0005053,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:46.1753624+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"sample_infohashes failed","addr":"125.31.103.194:51413","duration":4.0005053,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:46.1753624+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"sample_infohashes failed","addr":"213.251.229.162:35915","duration":4.0005053,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:46.1753624+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"find_node failed","addr":"106.5.200.72:26583","durat
ion":4.0005053,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:46.1753624+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"sample_infohashes failed","addr":"102.157.90.98:57536","duration":4.0005053,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:46.1753624+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"find_node failed","addr":"86.166.10.111:6881","duration":4.0005053,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:46.5263881+09:00","logger":"gin","caller":"ginzap/ginzap.go:93","message":"/graphql","status":200,"method":"POST","path":"/graphql","query":"","ip":"::1","user-agent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Edg/135.0.0.0","latency":0,"time":"2025-04-17T08:50:46Z"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:48.1730627+09:00","logger":"dht_client","caller":"cli
ent/logger.go:68","message":"find_node","addr":"133.32.232.7:6785","duration":0.0522076}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:52.1755188+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"find_node failed","addr":"102.157.90.98:57536","duration":4.0002923,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:52.1755188+09:00","logger":"dht_
client","caller":"client/logger.go:70","message":"find_node failed","addr":"221.163.21.37:40984","duration":4.0002923,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:52.1755188+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"sample_infohashes failed","addr":"125.31.103.194:51413","duration":4.0002923,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:52.1755188+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"find_node failed","addr":"86.166.10.111:6881","duration":4.0002923,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:54.1772652+09:00","logger":"dht_client","caller":"client/logger.go:68","message":"find_node","addr":"133.32.232.7:6785","duration":0.0543263}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:57.5250796+09:00","logger":"gin","caller":"ginzap/ginzap.go:93","message":"/graphql","status":200,"method":"POST","path":"/graphql","query":"","i
p":"::1","user-agent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Edg/135.0.0.0","latency":0,"time":"2025-04-17T08:50:57Z"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:58.1860162+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"sample_infohashes failed","addr":"46.146.33.67:51413","duration":4.0003883,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:58.1860162+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"find_node failed","addr":"67.220.85.98:6961","duration":4.0003883,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:58.1860162+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"find_node failed","addr":"92.221.93.160:64207","duration":4.0003883,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:58.1860162+09:00","logger":"dht_client","caller":"client/logger.g
o:70","message":"sample_infohashes failed","addr":"91.240.103.138:8268","duration":4.0003883,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:50:58.1860162+09:00","logger":"dht_client","caller":"client/logger.go:70","message":"sample_infohashes failed","addr":"59.15.86.21:7553","duration":4.0003883,"error":"context deadline exceeded"}
{"severity":"DEBUG","timestamp":"2025-04-17T17:51:00.1786931+09:00","logger":"dht_client","caller":"client/logger.go:68","message":"find_node","addr":"133.32.232.7:6785","duration":0.0533562}

[648480505]

I guess it’s a Windows thing. I have run it both with and without Docker (containerized or native) on Windows and in both cases, I noticed network utilization occasionally dropping down to zero with context deadline exceeded. All requests it made timed out and failed and the only way to recover was restarting it. It took minutes or days since launching to encounter this.

There are definitely issues when running with Docker Desktop on the Windows system. When not using Docker for running, no component anomalies have been encountered (perhaps due to the short running time?).

[mgdigital]

Is anyone having issues on windows running Bitmagnet through gluetun VPN? If not, this may fix any issues. See the docker compose example in this repo.