cc @stephdl
normal use journalctl -f
or find it
journalctl -f _UID=$(id -u backuppc1)
Doesn’t really give much information as to what’s wrong:
Oct 09 10:00:39 ns8 systemd[1507]: Starting Podman backuppc.service...
Oct 09 10:00:39 ns8 systemd[1507]: Created slice cgroup user-libpod_pod_5a08feb8b3d5c87b29aa8f109fdef0f724b3624356a8fbfe6fdd930f6507864f.slice.
Oct 09 10:00:39 ns8 podman[4557]: 5a08feb8b3d5c87b29aa8f109fdef0f724b3624356a8fbfe6fdd930f6507864f
Oct 09 10:00:40 ns8 systemd[1507]: Started libcrun container.
Oct 09 10:00:40 ns8 podman[4565]: 5a08feb8b3d5c87b29aa8f109fdef0f724b3624356a8fbfe6fdd930f6507864f
Oct 09 10:00:40 ns8 systemd[1507]: Started Podman backuppc.service.
Oct 09 10:00:40 ns8 systemd[1507]: Starting Podman backuppc-app.service...
Oct 09 10:02:13 ns8 systemd[1507]: backuppc-app.service: start operation timed out. Terminating.
Oct 09 10:02:15 ns8 backuppc1[4644]: a971617430dabe96423521a41a9d970ca23670c3e8ccf91be4cb69a1e0ee961e
Oct 09 10:02:15 ns8 systemd[1507]: backuppc-app.service: Failed with result 'timeout'.
Oct 09 10:02:15 ns8 systemd[1507]: Failed to start Podman backuppc-app.service.
Oct 09 10:02:15 ns8 systemd[1507]: backuppc-app.service: Consumed 11.336s CPU time.
Oct 09 10:02:15 ns8 systemd[1507]: backuppc-app.service: Scheduled restart job, restart counter is at 6.
Oct 09 10:02:15 ns8 systemd[1507]: Stopped Podman backuppc-app.service.
Oct 09 10:02:15 ns8 systemd[1507]: backuppc-app.service: Consumed 11.336s CPU time.
Oct 09 10:02:15 ns8 systemd[1507]: Stopping Podman backuppc.service...
Oct 09 10:02:17 ns8 systemd[1507]: Removed slice cgroup user-libpod_pod_5a08feb8b3d5c87b29aa8f109fdef0f724b3624356a8fbfe6fdd930f6507864f.slice.
Oct 09 10:02:17 ns8 podman[4665]: 5a08feb8b3d5c87b29aa8f109fdef0f724b3624356a8fbfe6fdd930f6507864f
Oct 09 10:02:18 ns8 podman[4771]: 5a08feb8b3d5c87b29aa8f109fdef0f724b3624356a8fbfe6fdd930f6507864f
Oct 09 10:02:18 ns8 systemd[1507]: Stopped Podman backuppc.service.
And this sequence repeats, and repeats, and repeats, and …
Cheers.
Oct 09 10:12:51 ns8 systemd[1507]: Started Podman backuppc.service.
Oct 09 10:12:51 ns8 systemd[1507]: Starting Podman backuppc-app.service...
Oct 09 10:12:52 ns8 systemd[1505]: Started Samba AD Domain Controller.
Oct 09 10:12:54 ns8 samba-dc[6592]: /usr/sbin/samba_dnsupdate: ; TSIG error with server: tsig verify failure
Oct 09 10:12:58 ns8 crowdsec2[1829]: time="2024-10-09T17:12:58Z" level=info msg="127.0.0.1 - [Wed, 09 Oct 2024 17:12:58 UTC] \"GET /v1/decisions/stream HTTP/1.1 200 1.365099443s \"crowdsec-firewall-bouncer/v0.0.28-debian-pragmatic-af6e7e25822c2b1a02168b99ebbf8458bc6728e5\" \""
Oct 09 10:13:02 ns8 sftpgo[2481]: {"level":"debug","time":"2024-10-09T17:13:02.003","sender":"eventmanager","message":"loading updated rules"}
Oct 09 10:13:02 ns8 sftpgo[2481]: {"level":"debug","time":"2024-10-09T17:13:02.003","sender":"dataprovider_sqlite","message":"start user cache check, update time 2024-10-09 17:03:02.004 +0000 UTC"}
Oct 09 10:13:02 ns8 sftpgo[2481]: {"level":"debug","time":"2024-10-09T17:13:02.006","sender":"eventmanager","message":"recently updated event rules loaded: 0"}
Oct 09 10:13:02 ns8 sftpgo[2481]: {"level":"debug","time":"2024-10-09T17:13:02.006","sender":"eventmanager","message":"event rules updated, fs events: 0, provider events: 0, schedules: 0, ip blocked events: 0, certificate events: 0, IDP login events: 0"}
Oct 09 10:13:02 ns8 sftpgo[2481]: {"level":"debug","time":"2024-10-09T17:13:02.006","sender":"dataprovider_sqlite","message":"end user cache check, new update time 2024-10-09 17:13:02.004 +0000 UTC"}
Oct 09 10:13:08 ns8 samba-dc[6592]: dnsupdate_nameupdate_done: Failed DNS update with exit code 110
Oct 09 10:13:08 ns8 loki-server[2234]: level=warn ts=2024-10-09T17:13:08.56176945Z caller=logging.go:123 traceID=72dc45c5f42ccbcd orgID=fake msg="POST /loki/api/v1/push (500) 5.000890328s Response: \"rpc error: code = DeadlineExceeded desc = context deadline exceeded\\n\" ws: false; Accept-Encoding: gzip; Content-Length: 2381; Content-Type: application/x-protobuf; User-Agent: promtail/2.9.2; X-Forwarded-For: 10.0.2.100; X-Forwarded-Host: 10.5.4.1:20009; X-Forwarded-Port: 20009; X-Forwarded-Proto: http; X-Forwarded-Server: loki; X-Real-Ip: 10.0.2.100; "
Oct 09 10:13:08 ns8 promtail[1712]: level=warn ts=2024-10-09T17:13:08.56267921Z caller=client.go:419 component=client host=10.5.4.1:20009 msg="error sending batch, will retry" status=500 tenant= error="server returned HTTP status 500 Internal Server Error (500): rpc error: code = DeadlineExceeded desc = context deadline exceeded"
Oct 09 10:13:14 ns8 loki-server[2234]: level=warn ts=2024-10-09T17:13:14.220884168Z caller=logging.go:123 traceID=6b4639318af54803 orgID=fake msg="POST /loki/api/v1/push (500) 5.002068908s Response: \"rpc error: code = DeadlineExceeded desc = context deadline exceeded\\n\" ws: false; Accept-Encoding: gzip; Content-Length: 2381; Content-Type: application/x-protobuf; User-Agent: promtail/2.9.2; X-Forwarded-For: 10.0.2.100; X-Forwarded-Host: 10.5.4.1:20009; X-Forwarded-Port: 20009; X-Forwarded-Proto: http; X-Forwarded-Server: loki; X-Real-Ip: 10.0.2.100; "
Oct 09 10:13:14 ns8 promtail[1712]: level=warn ts=2024-10-09T17:13:14.221740262Z caller=client.go:419 component=client host=10.5.4.1:20009 msg="error sending batch, will retry" status=500 tenant= error="server returned HTTP status 500 Internal Server Error (500): rpc error: code = DeadlineExceeded desc = context deadline exceeded"
Oct 09 10:13:19 ns8 crowdsec2[1829]: time="2024-10-09T17:13:19Z" level=info msg="127.0.0.1 - [Wed, 09 Oct 2024 17:13:19 UTC] \"GET /v1/decisions/stream HTTP/1.1 200 12.645182704s \"crowdsec-firewall-bouncer/v0.0.28-debian-pragmatic-af6e7e25822c2b1a02168b99ebbf8458bc6728e5\" \""
Oct 09 10:13:19 ns8 samba-dc[6592]: Doing a full scan on DC=ForestDnsZones,DC=bogolinux,DC=net and looking for deleted objects
Oct 09 10:13:19 ns8 samba-dc[6592]: Doing a full scan on DC=DomainDnsZones,DC=bogolinux,DC=net and looking for deleted objects
Oct 09 10:13:19 ns8 samba-dc[6592]: Doing a full scan on CN=Configuration,DC=bogolinux,DC=net and looking for deleted objects
Oct 09 10:13:19 ns8 samba-dc[6592]: Doing a full scan on DC=bogolinux,DC=net and looking for deleted objects
Oct 09 10:13:20 ns8 rspamd[3322]: (controller) <1u5hdp>; map; http_map_finish: data is not modified for server maps.rspamd.com, next check at Wed, 09 Oct 2024 21:13:20 GMT (http cache based: Wed, 09 Oct 2024 21:13:20 GMT)
Oct 09 10:13:21 ns8 crowdsec2[1829]: time="2024-10-09T17:13:21Z" level=info msg="127.0.0.1 - [Wed, 09 Oct 2024 17:13:21 UTC] \"GET /v1/decisions/stream HTTP/1.1 200 1.691664018s \"crowdsec-firewall-bouncer/v0.0.28-debian-pragmatic-af6e7e25822c2b1a02168b99ebbf8458bc6728e5\" \""
Oct 09 10:13:21 ns8 rspamd[3322]: (controller) <u9r7uu>; map; http_map_finish: need to reread map from https://maps.rspamd.com/rspamd/redirectors.inc.zst
Oct 09 10:13:21 ns8 rspamd[3322]: (controller) <u9r7uu>; map; http_map_finish: stored map data in a shared memory cache: /rhm.effc6795c606010ae56f
Oct 09 10:13:21 ns8 rspamd[3322]: (controller) <u9r7uu>; map; http_map_finish: https://maps.rspamd.com/rspamd/redirectors.inc.zst(151.115.41.123:443): read map data 5202 bytes compressed, 12310 uncompressed, next check at Wed, 09 Oct 2024 21:11:37 GMT
Oct 09 10:13:22 ns8 rspamd[3322]: (controller) <u9r7uu>; map; rspamd_map_save_http_cached_file: saved data from https://maps.rspamd.com/rspamd/redirectors.inc.zst in /var/lib/rspamd/f3933e67d5f9574a9eaf78cd0a8e99140ecc502e.map, 12350 bytes
Oct 09 10:13:22 ns8 rspamd[3322]: (controller) <u9r7uu>; map; rspamd_kv_list_fin: read hash of 1196 elements from https://maps.rspamd.com/rspamd/redirectors.inc.zst
Oct 09 10:13:45 ns8 crowdsec2[1829]: time="2024-10-09T17:13:45Z" level=info msg="127.0.0.1 - [Wed, 09 Oct 2024 17:13:45 UTC] \"GET /v1/decisions/stream HTTP/1.1 200 18.844304947s \"crowdsec-firewall-bouncer/v0.0.28-debian-pragmatic-af6e7e25822c2b1a02168b99ebbf8458bc6728e5\" \""
Oct 09 10:13:45 ns8 crowdsec2[1829]: time="2024-10-09T17:13:45Z" level=info msg="127.0.0.1 - [Wed, 09 Oct 2024 17:13:45 UTC] \"GET /v1/heartbeat HTTP/1.1 200 6.941257509s \"crowdsec/v1.6.3-4851945a-docker\" \""
Oct 09 10:13:45 ns8 crowdsec2[1829]: time="2024-10-09T17:13:45Z" level=info msg="127.0.0.1 - [Wed, 09 Oct 2024 17:13:45 UTC] \"GET /v1/decisions/stream HTTP/1.1 200 78.74518ms \"crowdsec-firewall-bouncer/v0.0.28-debian-pragmatic-af6e7e25822c2b1a02168b99ebbf8458bc6728e5\" \""
Oct 09 10:13:46 ns8 crowdsec2[1829]: time="2024-10-09T17:13:46Z" level=info msg="127.0.0.1 - [Wed, 09 Oct 2024 17:13:46 UTC] \"GET /v1/decisions/stream HTTP/1.1 200 93.446494ms \"crowdsec-firewall-bouncer/v0.0.28-debian-pragmatic-af6e7e25822c2b1a02168b99ebbf8458bc6728e5\" \""
Oct 09 10:13:59 ns8 crowdsec2[1829]: time="2024-10-09T17:13:59Z" level=info msg="127.0.0.1 - [Wed, 09 Oct 2024 17:13:59 UTC] \"GET /v1/decisions/stream HTTP/1.1 200 3.090530988s \"crowdsec-firewall-bouncer/v0.0.28-debian-pragmatic-af6e7e25822c2b1a02168b99ebbf8458bc6728e5\" \""
Oct 09 10:14:06 ns8 loki-server[2234]: level=warn ts=2024-10-09T17:14:06.262404963Z caller=logging.go:123 traceID=4b9fac3aed1cce78 orgID=fake msg="POST /loki/api/v1/push (500) 5.000795394s Response: \"rpc error: code = DeadlineExceeded desc = context deadline exceeded\\n\" ws: false; Accept-Encoding: gzip; Content-Length: 1595; Content-Type: application/x-protobuf; User-Agent: promtail/2.9.2; X-Forwarded-For: 10.0.2.100; X-Forwarded-Host: 10.5.4.1:20009; X-Forwarded-Port: 20009; X-Forwarded-Proto: http; X-Forwarded-Server: loki; X-Real-Ip: 10.0.2.100; "
Oct 09 10:14:06 ns8 promtail[1712]: level=warn ts=2024-10-09T17:14:06.263373479Z caller=client.go:419 component=client host=10.5.4.1:20009 msg="error sending batch, will retry" status=500 tenant= error="server returned HTTP status 500 Internal Server Error (500): rpc error: code = DeadlineExceeded desc = context deadline exceeded"
Oct 09 10:14:12 ns8 loki-server[2234]: level=warn ts=2024-10-09T17:14:12.86273558Z caller=logging.go:123 traceID=0215f752f49bbbeb orgID=fake msg="POST /loki/api/v1/push (500) 5.001639589s Response: \"rpc error: code = DeadlineExceeded desc = context deadline exceeded\\n\" ws: false; Accept-Encoding: gzip; Content-Length: 2524; Content-Type: application/x-protobuf; User-Agent: promtail/2.9.2; X-Forwarded-For: 10.0.2.100; X-Forwarded-Host: 10.5.4.1:20009; X-Forwarded-Port: 20009; X-Forwarded-Proto: http; X-Forwarded-Server: loki; X-Real-Ip: 10.0.2.100; "
Oct 09 10:14:12 ns8 promtail[1712]: level=warn ts=2024-10-09T17:14:12.863427768Z caller=client.go:419 component=client host=10.5.4.1:20009 msg="error sending batch, will retry" status=500 tenant= error="server returned HTTP status 500 Internal Server Error (500): rpc error: code = DeadlineExceeded desc = context deadline exceeded"
Oct 09 10:14:19 ns8 loki-server[2234]: level=warn ts=2024-10-09T17:14:19.761740214Z caller=logging.go:123 traceID=4517b59af7eccf24 orgID=fake msg="POST /loki/api/v1/push (500) 5.000626827s Response: \"rpc error: code = DeadlineExceeded desc = context deadline exceeded\\n\" ws: false; Accept-Encoding: gzip; Content-Length: 2574; Content-Type: application/x-protobuf; User-Agent: promtail/2.9.2; X-Forwarded-For: 10.0.2.100; X-Forwarded-Host: 10.5.4.1:20009; X-Forwarded-Port: 20009; X-Forwarded-Proto: http; X-Forwarded-Server: loki; X-Real-Ip: 10.0.2.100; "
Oct 09 10:14:19 ns8 promtail[1712]: level=warn ts=2024-10-09T17:14:19.762535894Z caller=client.go:419 component=client host=10.5.4.1:20009 msg="error sending batch, will retry" status=500 tenant= error="server returned HTTP status 500 Internal Server Error (500): rpc error: code = DeadlineExceeded desc = context deadline exceeded"
Oct 09 10:14:23 ns8 systemd[1507]: backuppc-app.service: start operation timed out. Terminating.
Oct 09 10:14:26 ns8 loki-server[2234]: level=warn ts=2024-10-09T17:14:26.362107352Z caller=logging.go:123 traceID=7c480509c2a9f19b orgID=fake msg="POST /loki/api/v1/push (500) 5.001452275s Response: \"rpc error: code = DeadlineExceeded desc = context deadline exceeded\\n\" ws: false; Accept-Encoding: gzip; Content-Length: 2515; Content-Type: application/x-protobuf; User-Agent: promtail/2.9.2; X-Forwarded-For: 10.0.2.100; X-Forwarded-Host: 10.5.4.1:20009; X-Forwarded-Port: 20009; X-Forwarded-Proto: http; X-Forwarded-Server: loki; X-Real-Ip: 10.0.2.100; "
Oct 09 10:14:26 ns8 promtail[1712]: level=warn ts=2024-10-09T17:14:26.363097804Z caller=client.go:419 component=client host=10.5.4.1:20009 msg="error sending batch, will retry" status=500 tenant= error="server returned HTTP status 500 Internal Server Error (500): rpc error: code = DeadlineExceeded desc = context deadline exceeded"
Oct 09 10:14:27 ns8 rspamd[3322]: (main) <3a80d9>; main; rspamd_main_heartbeat_cb: lost heartbeat from worker type controller with pid 27, last beat on: 2024-10-09 17:14:05.63207 (1 beats received previously)
Oct 09 10:14:29 ns8 crowdsec2[1829]: time="2024-10-09T17:14:29Z" level=info msg="127.0.0.1 - [Wed, 09 Oct 2024 17:14:29 UTC] \"GET /v1/decisions/stream HTTP/1.1 200 22.641820726s \"crowdsec-firewall-bouncer/v0.0.28-debian-pragmatic-af6e7e25822c2b1a02168b99ebbf8458bc6728e5\" \""
Oct 09 10:14:29 ns8 crowdsec2[1829]: time="2024-10-09T17:14:29Z" level=info msg="127.0.0.1 - [Wed, 09 Oct 2024 17:14:29 UTC] \"GET /v1/decisions/stream HTTP/1.1 200 40.27558ms \"crowdsec-firewall-bouncer/v0.0.28-debian-pragmatic-af6e7e25822c2b1a02168b99ebbf8458bc6728e5\" \""
Oct 09 10:14:32 ns8 backuppc1[6751]: a9d68014de16c5a728c0d9b3471dd5f54f5bf4b208609d7d1b450f19e97f0e59
Oct 09 10:14:32 ns8 systemd[1507]: backuppc-app.service: Failed with result 'timeout'.
Oct 09 10:14:32 ns8 systemd[1507]: Failed to start Podman backuppc-app.service.
Oct 09 10:14:32 ns8 systemd[1507]: backuppc-app.service: Consumed 8.995s CPU time.
Oct 09 10:14:33 ns8 systemd[1507]: backuppc-app.service: Scheduled restart job, restart counter is at 13.
Oct 09 10:14:33 ns8 systemd[1507]: Stopped Podman backuppc-app.service.
Oct 09 10:14:33 ns8 systemd[1507]: backuppc-app.service: Consumed 8.995s CPU time.
Oct 09 10:14:33 ns8 systemd[1507]: Stopping Podman backuppc.service...
Oct 09 10:14:34 ns8 systemd[1507]: Removed slice cgroup user-libpod_pod_a105bb74f26f83fae91252bdd90e947e192552e2f924db12490542c4ed7938a1.slice.
Oct 09 10:14:34 ns8 podman[6759]: a105bb74f26f83fae91252bdd90e947e192552e2f924db12490542c4ed7938a1
Oct 09 10:14:34 ns8 podman[6778]: a105bb74f26f83fae91252bdd90e947e192552e2f924db12490542c4ed7938a1
Oct 09 10:14:34 ns8 systemd[1507]: Stopped Podman backuppc.service.
Oct 09 10:14:34 ns8 systemd[1507]: Starting Podman backuppc.service...
Oct 09 10:14:34 ns8 systemd[1507]: Created slice cgroup user-libpod_pod_d7fb8849a10347491e1fae485b77ce82a623760bf2f51adafb56b873982c1633.slice.
Oct 09 10:14:35 ns8 podman[6788]: d7fb8849a10347491e1fae485b77ce82a623760bf2f51adafb56b873982c1633
Oct 09 10:14:36 ns8 systemd[1507]: Started libcrun container.
Oct 09 10:14:36 ns8 podman[6796]: d7fb8849a10347491e1fae485b77ce82a623760bf2f51adafb56b873982c1633
Cheers.
Clear but I do not know why
Is there a log for the podman process, or can one be activated.
Cheers.
maybe you can try to remove the images and start again
if you have never configured backuppc the best thing could be to clean everything images + volumes
if you have data
runagent -m backuppc1
systemctl --user stop backuppc
podman ps # verify no container is still runnning
podman image ls
podman image rm -f <ID>
then you can restart backuppc
if you have no data, add at the end before to restart
runagent -m backuppc1
systemctl --user stop backuppc
podman ps # verify no container is still runnning
podman image ls
podman image rm -f <ID>
podman volume ls
podman volume rm -f <NAME>
restart the service backuppc
I’m guessing that this is to be performed on the source before the copy/move to cleanse the image.
Which ones. I’m guessing just ghcr…backuppc.
[backuppc1@ns8 state]$ podman image ls
REPOSITORY TAG IMAGE ID CREATED SIZE
ghcr.io/stephdl/backuppc 1.0.1 d5a83f0509d4 31 hours ago 8.54 MB
ghcr.io/nethserver/restic 3.0.0 d71585df829f 7 days ago 122 MB
ghcr.io/nethserver/restic 2.9.4 3648eced4852 2 weeks ago 89.4 MB
localhost/podman-pause 4.9.4-rhel-1725442483 a68a8647cf42 2 weeks ago 814 kB
docker.io/tiredofit/backuppc 6.0.4 06bdf6929703 4 months ago 270 MB
[backuppc1@ns8 state]$
I’m guessing that’s:
systemctl --user start backuppc
If I already have data, but don’t care about it, I can use the second set of instructions to wipe that out. If so, again, which NAMEs:
[backuppc1@ns8 state]$ podman volume ls
DRIVER VOLUME NAME
local data
local conf
local home
local logs
local restic-cache
[backuppc1@ns8 state]$
Cheers.
Yep if you do not care of data and configuration you can remove all volumes
Else the simplest way is to remove the module backuppc
Thanks.
But Which ID(s) to remove.
Cheers.
See the id of images
More information for you.
On my Proxmox image I did this:
runagent -m backuppc1
systemctl --user stop backuppc
podman ps # verify no container is still runnning
podman image ls
podman image rm -f <ID>
Then also ran:
systemctl --user disable backuppc
which stops the pod starting automatically on boot over at ESXi.
This image was then copied/converted to my ESXi system and a snapshot taken (isn’t this a wonderful feature) before starting.
The first test was just a start of the pod, to see if rebuilding the pod helps. But nope, still drops into the timeout loop.
The next tests was deleting these volumes, one per restart attempt, (except home, as I think that being missing would cause other issues) to see if any are the culprit:
[backuppc1@ns8 state]$ podman volume ls
DRIVER VOLUME NAME
local data
local conf
local home
local logs
local restic-cache
[backuppc1@ns8 state]$
The only deletion where the pod didn’t drop into the timeout loop, was when I deleted data, which took 45 minutes. Following this the pod was able to start normally. Checking in the UI, obviously there were no old backups to be seen, but curiously there were also no logs either, despite not removing the logs volume. But all my configurations were still intact, which is a “good thing”.
Based on this I’m guessing (Note: My opinion only) that when the pod starts, it somehow knows it’s been moved, and is re-scanning all the volumes (for whatever reason) which is taking longer than the timeout.
Maybe yet another reason to get an answer here.
Cheers.
Just as an FYI, this action also happens if backuppc is restored from a backup.
Cheers.
I am still thinking that backup should be removed, do you think it is something important ?
backup the backup of backup … feed for thoughts
at least I have no rooms for that on my disks
This leads back to a previous suggestion. The ability to include/exclude the DATA container.
Now I’ve successfully been able to point DATA at a remote iSCSI target, I don’t need that backed up by NS8. But, I WOULD like the rest of the BackupPC app backed up, so if I need to restore, I still have all the configuration information along with any settings that aren’t in the DATA.
Cheers.
AFAIK i can exclude a container of backup but I cannot pickup for example only the volume of config because I think it is what you have in head
Yeah, exclude DATA, keep the rest.
Cheers.
@stephdl Any further thoughts (ETA) on implementing this.
Cheers.
try this please the only changes is that the backup does not take the data volume
api-cli run update-module --data '{"module_url":"ghcr.io/stephdl/backuppc:no_data_backup","instances":["backuppc1"],"force":true}'
please test and report
released