Re: [qubes-users] Systemd terminating qubesd during backup?

2021-10-12 Thread Andrew David Wong

On 10/12/21 12:31 PM, Marek Marczykowski-Górecki wrote:

On Mon, Oct 11, 2021 at 11:52:59AM -0400, Steve Coleman wrote:

I seem to have an intermittent problem when my backup scripts are running
late at night.



My qubesd is apparently being shutdown (sent a sigterm signal) by systemd
during my long running backup sessions which then causes an eof pipe close
exception and qvm-backup then receives a socket exception and immediately
receives a second exception while still handling the first exception, thus
the qvm-backup process gets forcibly terminated mid stream. Just prior to
the qubesd shutdown I can clearly see that systemd had also
shutdown/restarted the qubes memory manager (qubes-qmemman) too.



Q: What kind of background maintenance processing would actually require
qubesd or the memory manager to be restarted?


I guess that's logrorate (but it isn't clear to me why qubesd too, not
just qubes-qmemman service...).


Q: Could this processing be put on hold during backups?



Q: Or, how could I at least know when this maintenance is scheduled to
happen so I could defer my own processing?


If that's indeed logrotate, see `systemctl status logrotate.timer`


My scripts can certainly trap this error, erase the incomplete backup file,
then loop and check for qubesd to complete its restart, and then finally
restart my own backup processing, but why should this even be necessary?



When this happens its almost always during the backup of my largest VM which
can take well over 90 minutes to complete.  If I can somehow block/defer
this kind of system maintenance until after my backups are complete that
would be better than having to deal with trapping random restarts.


Again, if that's logrotate, you can stop the timer before, and restart it
afterwards.



This sounds like:

https://github.com/QubesOS/qubes-issues/issues/5004

I agree that it's a serious bug. It makes no sense for logrotate to 
interrupt backups. Backups completing successfully and reliably is 
infinitely more important than rotating log files.


It looks like the issue has been fixed in 4.1, but I'm still 
experiencing on 4.0, as well. I've just gotten in the habit of trying 
not to let my backups run between ~1-6am. :\


--
Andrew David Wong
Community Manager
The Qubes OS Project
https://www.qubes-os.org

--
You received this message because you are subscribed to the Google Groups 
"qubes-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to qubes-users+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/qubes-users/748d50de-9c67-ab38-bd46-d2810f5c024d%40qubes-os.org.


OpenPGP_signature
Description: OpenPGP digital signature


Re: [qubes-users] Systemd terminating qubesd during backup?

2021-10-12 Thread Marek Marczykowski-Górecki
-BEGIN PGP SIGNED MESSAGE-
Hash: SHA256

On Mon, Oct 11, 2021 at 11:52:59AM -0400, Steve Coleman wrote:
> I seem to have an intermittent problem when my backup scripts are running
> late at night.
> 
> My qubesd is apparently being shutdown (sent a sigterm signal) by systemd
> during my long running backup sessions which then causes an eof pipe close
> exception and qvm-backup then receives a socket exception and immediately
> receives a second exception while still handling the first exception, thus
> the qvm-backup process gets forcibly terminated mid stream. Just prior to
> the qubesd shutdown I can clearly see that systemd had also
> shutdown/restarted the qubes memory manager (qubes-qmemman) too.
> 
> Q: What kind of background maintenance processing would actually require
> qubesd or the memory manager to be restarted?

I guess that's logrorate (but it isn't clear to me why qubesd too, not
just qubes-qmemman service...).

> Q: Could this processing be put on hold during backups?
> 
> Q: Or, how could I at least know when this maintenance is scheduled to
> happen so I could defer my own processing?

If that's indeed logrotate, see `systemctl status logrotate.timer`

> My scripts can certainly trap this error, erase the incomplete backup file,
> then loop and check for qubesd to complete its restart, and then finally
> restart my own backup processing, but why should this even be necessary?
> 
> When this happens its almost always during the backup of my largest VM which
> can take well over 90 minutes to complete.  If I can somehow block/defer
> this kind of system maintenance until after my backups are complete that
> would be better than having to deal with trapping random restarts.

Again, if that's logrotate, you can stop the timer before, and restart it
afterwards.

- -- 
Best Regards,
Marek Marczykowski-Górecki
Invisible Things Lab
-BEGIN PGP SIGNATURE-

iQEzBAEBCAAdFiEEhrpukzGPukRmQqkK24/THMrX1ywFAmFl4ocACgkQ24/THMrX
1ywC1gf8ChUCgVxe/SIHnVF8+hoA8/JoKlQTyddVGfjf5qp3a49vMtUbvMJ0hqWH
C5Ejz5dF+UxkqEkcXS1/oKlgnBIwal+GYEe1u2VwZyLmB9WV725ukzi8MYCOVKvM
amJuLGcD7vT2T6akTxnOLta+ofByJhSWgup7eEnXYfuOQ3hp8fKVWJ451QWbOafV
oY1TPJ/ptfl2ynUePyX8R990RnHS6V7LoBShbI5CB4e4g+6ogm9ibVC94nk9d+pD
PcIF9c+iC8jhVXMzkoP73KR7WEJ74WmrcefigoffwDLIjXwNPiQqwC4kGmq32rfG
7TVjl9Rv8DpUNfVTtDq+8xjOx3Ck3Q==
=6Alm
-END PGP SIGNATURE-

-- 
You received this message because you are subscribed to the Google Groups 
"qubes-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to qubes-users+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/qubes-users/YWXih4xG5dAuGaKS%40mail-itl.


Re: [qubes-users] Systemd terminating qubesd during backup?

2021-10-11 Thread Steve Coleman

On 10/11/21 14:07, Rusty Bird wrote:

Steve Coleman:
> I seem to have an intermittent problem when my backup scripts are 
running

> late at night.

> My qubesd is apparently being shutdown (sent a sigterm signal) by 
systemd
> during my long running backup sessions which then causes an eof pipe 
close
> exception and qvm-backup then receives a socket exception and 
immediately
> receives a second exception while still handling the first 
exception, thus
> the qvm-backup process gets forcibly terminated mid stream. Just 
prior to

> the qubesd shutdown I can clearly see that systemd had also
> shutdown/restarted the qubes memory manager (qubes-qmemman) too.

> Q: What kind of background maintenance processing would actually require
> qubesd or the memory manager to be restarted?

It's crond running logrotate. Fixed in R4.1 but not yet in R4.0:
https://github.com/QubesOS/qubes-issues/issues/5004

> Q: Could this processing be put on hold during backups?

I always sandwich backup runs between 'systemctl stop crond' and
'systemctl start crond'.


Great!

I was hoping for an answer like that. In my case the system will be 
shutting down after the unattended backup completes, so this is actually 
twice as easy!


thanks!


Rusty

>


--
You received this message because you are subscribed to the Google Groups 
"qubes-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to qubes-users+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/qubes-users/d1528316-5e0e-9052-2f43-952c91559fcb%40gmail.com.


Re: [qubes-users] Systemd terminating qubesd during backup?

2021-10-11 Thread Rusty Bird
-BEGIN PGP SIGNED MESSAGE-
Hash: SHA512

Steve Coleman:
> I seem to have an intermittent problem when my backup scripts are running
> late at night.
> 
> My qubesd is apparently being shutdown (sent a sigterm signal) by systemd
> during my long running backup sessions which then causes an eof pipe close
> exception and qvm-backup then receives a socket exception and immediately
> receives a second exception while still handling the first exception, thus
> the qvm-backup process gets forcibly terminated mid stream. Just prior to
> the qubesd shutdown I can clearly see that systemd had also
> shutdown/restarted the qubes memory manager (qubes-qmemman) too.
> 
> Q: What kind of background maintenance processing would actually require
> qubesd or the memory manager to be restarted?

It's crond running logrotate. Fixed in R4.1 but not yet in R4.0:
https://github.com/QubesOS/qubes-issues/issues/5004

> Q: Could this processing be put on hold during backups?

I always sandwich backup runs between 'systemctl stop crond' and
'systemctl start crond'.

Rusty
-BEGIN PGP SIGNATURE-

iQKTBAEBCgB9FiEEhLWbz8YrEp/hsG0ERp149HqvKt8FAmFkfVZfFIAALgAo
aXNzdWVyLWZwckBub3RhdGlvbnMub3BlbnBncC5maWZ0aGhvcnNlbWFuLm5ldDg0
QjU5QkNGQzYyQjEyOUZFMUIwNkQwNDQ2OUQ3OEY0N0FBRjJBREYACgkQRp149Hqv
Kt/dHQ/+LXkv+7GT64IgMXpwQjKMuDMswRPsEvXpGihJYohSioeGm6HvUNQ1uh99
zwih5PqT1OnJrIfgzRvqLPfTbTpO3YrkQZi32TY848M14rg1A5NtTHIzOthJP2+x
puZy7hMcFvZR4awv3g/4WVLRsMrUVuQ5x3n/xzId5MAycWrsQtt8bRH+kc3VHgMn
Jul0TPzD1jnmN36Ngpgr5UGe4LrNfR4IcRaG5mzoI/4tIA4mtkcmm1AwqBnR3KrQ
0Gclbk/F5ud/Nj4EwIQDFWnrBa70Hru7HZ+wj7V7shJD2fMuQVsBcys8EVJjpGQp
qFzy6AfvdIHJ1BmtoJM+v8cqo2AU+kVdRx0n2cTXCkHM5eN1nCpc6EO81HoB6ypE
8773aw8l/Y5fCowT0p/y4c8jTUd3/YiNFpJSPiRfLJDAk4PunnynM9IPVY+GnJUX
6HB8tXDn6vx5Gq90f0UjNkcWonJ/bt5GMYGpWBtHGQyQ0dh+mxhmwnT5hYnfNMW+
+pAcBB4fRclebEroW1RcLqe7FVZ1dldNqZQIL6WlQgU8/I06/JNNZkhjmlpdBDX5
FwNGFw7b2ss+4A+LdC6Q4IJ1S2LyOeIQtCCX3UIffhcvOEMmJSxkHBb65e1kGAxe
5Lsfcjmq6rK1jCYMC5or177Mo9u+PPxWxvr5p4zocBu7VyUUCdM=
=zaUv
-END PGP SIGNATURE-

-- 
You received this message because you are subscribed to the Google Groups 
"qubes-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to qubes-users+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/qubes-users/YWR9VrcVsYS/1FC8%40mutt.


[qubes-users] Systemd terminating qubesd during backup?

2021-10-11 Thread Steve Coleman
I seem to have an intermittent problem when my backup scripts are 
running late at night.


My qubesd is apparently being shutdown (sent a sigterm signal) by 
systemd during my long running backup sessions which then causes an eof 
pipe close exception and qvm-backup then receives a socket exception and 
immediately receives a second exception while still handling the first 
exception, thus the qvm-backup process gets forcibly terminated mid 
stream. Just prior to the qubesd shutdown I can clearly see that systemd 
had also shutdown/restarted the qubes memory manager (qubes-qmemman) too.


Q: What kind of background maintenance processing would actually require 
qubesd or the memory manager to be restarted?


Q: Could this processing be put on hold during backups?

Q: Or, how could I at least know when this maintenance is scheduled to 
happen so I could defer my own processing?


My scripts can certainly trap this error, erase the incomplete backup 
file, then loop and check for qubesd to complete its restart, and then 
finally restart my own backup processing, but why should this even be 
necessary?


When this happens its almost always during the backup of my largest VM 
which can take well over 90 minutes to complete.  If I can somehow 
block/defer this kind of system maintenance until after my backups are 
complete that would be better than having to deal with trapping random 
restarts.


thanks,

Steve

Sorry for the amount of text below but googlegroups would not let me 
send this as *.txt attachments:


qvm-backup error:

Making a backup... 56.28%
Connection to qubesd terminated, reconnecting in 1.0 seconds

Backup error: Got empty response from qubesd. See journalctl in dom0 for 
details.


Traceback (most recent call last):
  File "/usr/lib/python3.5/site-packages/qubesadmin/app.py", line 580, 
in qubesd_call

    client_socket.connect(qubesadmin.config.QUBESD_SOCKET)
FileNotFoundError: [Errno 2] No such file or directory

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/bin/qvm-run", line 5, in 
    sys.exit(main())
  File "/usr/lib/python3.5/site-packages/qubesadmin/tools/qvm_run.py", 
line 199, in main

    args = parser.parse_args(args, app=app)
  File "/usr/lib/python3.5/site-packages/qubesadmin/tools/__init__.py", 
line 384, in parse_args

    action.parse_qubes_app(self, namespace)
  File "/usr/lib/python3.5/site-packages/qubesadmin/tools/__init__.py", 
line 170, in parse_qubes_app

    namespace.domains += [app.domains[vm_name]]
  File "/usr/lib/python3.5/site-packages/qubesadmin/app.py", line 91, 
in __getitem__

    if not self.app.blind_mode and item not in self:
  File "/usr/lib/python3.5/site-packages/qubesadmin/app.py", line 114, 
in __contains__

    self.refresh_cache()
  File "/usr/lib/python3.5/site-packages/qubesadmin/app.py", line 63, 
in refresh_cache

    'admin.vm.List'
  File "/usr/lib/python3.5/site-packages/qubesadmin/app.py", line 583, 
in qubesd_call

    'Failed to connect to qubesd service: %s', str(e))
qubesadmin.exc.QubesDaemonCommunicationError: Failed to connect to 
qubesd service: [Errno 2] No such file or directory



journalctl output:
Oct 11 03:15:02 dom0 systemd[1]: Stopping Qubes memory management daemon...
Oct 11 03:15:02 dom0 systemd[1]: Stopped Qubes memory management daemon.
Oct 11 03:15:02 dom0 audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 
ses=4294967295 msg='unit=qubes-qmemman comm="systemd" 
exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Oct 11 03:15:02 dom0 kernel: audit: type=1131 audit(1633936502.556:250): 
pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=qubes-qmemman 
comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? 
terminal=? res=success'

Oct 11 03:15:02 dom0 systemd[1]: Starting Qubes memory management daemon...
Oct 11 03:15:07 dom0 qmemman.daemon[18836]: MIN_PREFMEM=199229440 
DOM0_MEM_BOOST=349175808 CACHE_FACTOR=1.3

Oct 11 03:15:07 dom0 systemd[1]: Started Qubes memory management daemon.
Oct 11 03:15:07 dom0 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 
ses=4294967295 msg='unit=qubes-qmemman comm="systemd" 
exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Oct 11 03:15:07 dom0 kernel: audit: type=1130 audit(1633936507.784:251): 
pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=qubes-qmemman 
comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? 
terminal=? res=success'
Oct 11 03:15:07 dom0 qmemman.daemon.algo[18836]: 
balance_when_enough_memory(xen_free_memory=53353416961, 
total_mem_pref=0, total_available_memory=53353416961)
Oct 11 03:15:07 dom0 qmemman.systemstate[18836]: stat: 
xenfree=53405845761 memset_reqs=[]
Oct 11 03:15:07 dom0 qmemman.daemon.algo[18836]: 
balance_when_enough_memory(xen_free_memory=53353416961, 
total_mem_pref=0, total_available_memory=53353416961)
Oct 11 03:15:07 dom0 qmemman.systemstate[18836]: stat: 
xenfree=53405845761 memset_reqs=[]
Oct 11 

[qubes-users] Systemd terminating qubesd during backup?

2021-10-11 Thread Steve Coleman
I seem to have an intermittent problem when my backup scripts are 
running late at night.


My qubesd is apparently being shutdown (sent a sigterm signal) by 
systemd during my long running backup sessions which then causes an eof 
pipe close exception and qvm-backup then receives a socket exception and 
immediately receives a second exception while still handling the first 
exception, thus the qvm-backup process gets forcibly terminated mid 
stream. Just prior to the qubesd shutdown I can clearly see that systemd 
had also shutdown/restarted the qubes memory manager (qubes-qmemman) too.


Q: What kind of background maintenance processing would actually require 
qubesd or the memory manager to be restarted?


Q: Could this processing be put on hold during backups?

Q: Or, how could I at least know when this maintenance is scheduled to 
happen so I could defer my own processing?


My scripts can certainly trap this error, erase the incomplete backup 
file, then loop and check for qubesd to complete its restart, and then 
finally restart my own backup processing, but why should this even be 
necessary?


When this happens its almost always during the backup of my largest VM 
which can take well over 90 minutes to complete.  If I can somehow 
block/defer this kind of system maintenance until after my backups are 
complete that would be better than having to deal with trapping random 
restarts.


thanks,

Steve

--
You received this message because you are subscribed to the Google Groups 
"qubes-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email 
to qubes-users+unsubscr...@googlegroups.com.
To view this discussion on the web visit 
https://groups.google.com/d/msgid/qubes-users/4fb6c085-4491-c67a-a940-98cca1f89c7c%40gmail.com.
Making a backup... 56.28%
Connection to qubesd terminated, reconnecting in 1.0 seconds

Backup error: Got empty response from qubesd. See journalctl in dom0 for 
details.

Traceback (most recent call last):
  File "/usr/lib/python3.5/site-packages/qubesadmin/app.py", line 580, in 
qubesd_call
client_socket.connect(qubesadmin.config.QUBESD_SOCKET)
FileNotFoundError: [Errno 2] No such file or directory

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/bin/qvm-run", line 5, in 
sys.exit(main())
  File "/usr/lib/python3.5/site-packages/qubesadmin/tools/qvm_run.py", line 
199, in main
args = parser.parse_args(args, app=app)
  File "/usr/lib/python3.5/site-packages/qubesadmin/tools/__init__.py", line 
384, in parse_args
action.parse_qubes_app(self, namespace)
  File "/usr/lib/python3.5/site-packages/qubesadmin/tools/__init__.py", line 
170, in parse_qubes_app
namespace.domains += [app.domains[vm_name]]
  File "/usr/lib/python3.5/site-packages/qubesadmin/app.py", line 91, in 
__getitem__
if not self.app.blind_mode and item not in self:
  File "/usr/lib/python3.5/site-packages/qubesadmin/app.py", line 114, in 
__contains__
self.refresh_cache()
  File "/usr/lib/python3.5/site-packages/qubesadmin/app.py", line 63, in 
refresh_cache
'admin.vm.List'
  File "/usr/lib/python3.5/site-packages/qubesadmin/app.py", line 583, in 
qubesd_call
'Failed to connect to qubesd service: %s', str(e))
qubesadmin.exc.QubesDaemonCommunicationError: Failed to connect to qubesd 
service: [Errno 2] No such file or directory





Oct 11 03:15:02 dom0 systemd[1]: Stopping Qubes memory management daemon...
Oct 11 03:15:02 dom0 systemd[1]: Stopped Qubes memory management daemon.
Oct 11 03:15:02 dom0 audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 
ses=4294967295 msg='unit=qubes-qmemman comm="systemd" 
exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Oct 11 03:15:02 dom0 kernel: audit: type=1131 audit(1633936502.556:250): pid=1 
uid=0 auid=4294967295 ses=4294967295 msg='unit=qubes-qmemman comm="systemd" 
exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Oct 11 03:15:02 dom0 systemd[1]: Starting Qubes memory management daemon...
Oct 11 03:15:07 dom0 qmemman.daemon[18836]: MIN_PREFMEM=199229440 
DOM0_MEM_BOOST=349175808 CACHE_FACTOR=1.3
Oct 11 03:15:07 dom0 systemd[1]: Started Qubes memory management daemon.
Oct 11 03:15:07 dom0 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 
ses=4294967295 msg='unit=qubes-qmemman comm="systemd" 
exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Oct 11 03:15:07 dom0 kernel: audit: type=1130 audit(1633936507.784:251): pid=1 
uid=0 auid=4294967295 ses=4294967295 msg='unit=qubes-qmemman comm="systemd" 
exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Oct 11 03:15:07 dom0 qmemman.daemon.algo[18836]: 
balance_when_enough_memory(xen_free_memory=53353416961, total_mem_pref=0, 
total_available_memory=53353416961)
Oct 11 03:15:07 dom0 qmemman.systemstate[18836]: stat: xenfree=53405845761 
memset_reqs=[]
Oct 11 03:15:07 dom0 qmemman.daemon.algo[18836]: