Possible regression: vm-to-vm RPC calls stopped working

[Elias Mårtenson]

After doing the most recent qubes-dom0-update from the testing repository, all RPC calls from one VM to another stopped working. Calls from dom0 still works fine.

By "not working" I mean that the call to qrexec-client-vm gives me a "Request refused".

This includes calls to qvm-copy as well, since it uses the qubes.Filecopy RPC call.

Is this a known problem?

Regards,
Elias

[Yuraeitha]

I can semi-reproduce it yes, I was not aware of it before seeing your post though.


-- Tested --
qvm-move-to-vm (worked fine)
qvm-open-in-dvm (worked fine)
qvm-copy-to-vm (failed with a freeze)


-- Behaviour --
The File manager (Nautilus) froze when it failed. Nothing else stopped working in the AppVM, it was only Nautilus that frooze. I could stop the pending sending window, not a problem, but it probably kept pending since Nautilus frooze? Essentially it seems like this *bug* is causing Nautilus to freeze up. The target AppVM had no issues, it remained stable.


-- Environment --
Target and receiving AppVM's had same template, Fedora-26.
Updates on current-testing (both dom0 and template).
Tested with GUI right clicking, did not verify with the terminal counterparts.


Do you see the Nautilus freezing too Elias? or is this just my machine doing that?
It seems qvm-copy-to-vm in Fedora is broken at least, since we both had issues with that one.

[Elias Mårtenson]

I'm away from my computer at the moment so I can't try to reproduce all your tests, but I did try to use copy-to-vm from Nautilus on a fedora-26 template-based vm and it didn't seem to do anything. The menu just closed.

I can't say if anything else in the Nautilus instance worked after that, as I closed the window after that.

[Yuraeitha]

On Tuesday, February 20, 2018 at 3:37:54 PM UTC+1, Elias Mårtenson wrote:
> I'm away from my computer at the moment so I can't try to reproduce all your tests, but I did try to use copy-to-vm from Nautilus on a fedora-26 template-based vm and it didn't seem to do anything. The menu just closed.
>
> I can't say if anything else in the Nautilus instance worked after that, as I closed the window after that.

It seems we both have the same, it would seem? It seems to behave slightly different, but the same bug by the looks of it.

I found more odd behaviour after I decided to test a bit more.
Used 2 different AppVM's, same template again.
This time I used the terminal instead of the GUI, so nautilus was excluded in the equation.

I did not know qvm-copy-to-vm/qvm-move-to-vm had been deprecated, the terminal told me just now. But funnily enough, the old deprecated qvm-copy-to-vm command worked just fine, while the new qvm-copy failed.

I suppose the old deprecated qvm-copy-to-vm can be a short-term temporary solution if it's needed? If it's still there and not removed despite being deprecated, then I suppose it's still safe to use the deprecated version?

- - - - - -

Also, before I did any of the above, between my two posts here, I encountered a 10-12 seconds or so long system wide freeze, entire screen, all VM's, dom0, mouse, everything frooze. I've never had this before on this machine, and I've never seen it in Qubes 4. This was something very new, or so it seems at least.

My laptop only has 8GB ram, so I guess it could be something related to RAM. But whether these two issues are related or not? I don't know. But it had never happened before today, and I've used this computer everyday for months, running Qubes 4 since RC-2.

Could the RAM balancing between the AppVM's have been affected too, perhaps?

[Yuraeitha]

[user@Study ~]$ qvm-copy Stream ~/LanguageTool.log
qfile-agent: Fatal error: stat Stream (error type: No such file or directory)
Gtk-Message: GtkDialog mapped without a transient parent. This is discouraged.
EOF
[user@Study ~]$

Not the kind of error message I was expecting, but it does look like it can't find the files. Since it was $ that was removed in the update today, which with my poor understanding of code, seems to be location related?
Perhaps it's not a coincidence that qvm-copy can't find the location, a typo in the code perhaps?

[Marek Marczykowski-Górecki]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

On Tue, Feb 20, 2018 at 02:24:22AM -0800, Elias Mårtenson wrote:
> After doing the most recent qubes-dom0-update from the testing repository, all RPC calls from one VM to another stopped working. Calls from dom0 still works fine.
>
> By "not working" I mean that the call to qrexec-client-vm gives me a "Request refused".

Have you updated also templates? If not, install updates also there and
restart all the VMs. Details here:
https://github.com/QubesOS/qubes-secpack/blob/master/QSBs/qsb-038-2018.txt

- --
Best Regards,
Marek Marczykowski-Górecki
Invisible Things Lab
A: Because it messes up the order in which people normally read text.
Q: Why is top-posting such a bad thing?
-----BEGIN PGP SIGNATURE-----

iQEzBAEBCAAdFiEEhrpukzGPukRmQqkK24/THMrX1ywFAlqMOWIACgkQ24/THMrX
1ywCxAf/ad8xHLawtWPnwZxoBvc/ZT7PdfhOQjexUwcy03fRVDdvHUpSlAekfQ/2
mhdzxSyqYvZveeZkO3prKsEmYeNpG4bhOMXbh3cPqrcDS6jv7CAuQieaUlk1neyD
T7P/3nSNU+Q/+eokXf40qg8rZhdHzz6JvY04lEg9kwkMD+jAHDZlzIJdeMb7ZJ6U
6ot9XUcYk+WC0a5FjzMHqRtDI9cTwzqqrgPMhp5bRANvLnyCdo7wL/m6C6s+yWKr
Ny+p/18IoySwIz1+j6FMMRDU60YmFqKZlfqteHCIvxqwBdp+nSonQ6+SzehUF4bS
xSU0Ff9LL6VOFLfjDdkz93gvRVY1Yw==
=57Zw
-----END PGP SIGNATURE-----

[Yuraeitha]

I can verify that the computer on my end had the template updated yes, also full system restart by shutting down the computer, then starting again. Everything was updated before restart.

Commands that was used, checked by opening terminal and arrow up in history:
dom0: sudo qubes-dom0-update --enablerepo=qubes-dom0-current-testing
fedora-26: sudo dnf update --enablerepo=qubes-vm-*-current-testing


It's not the issue this time, however I've experienced some issues with the update not going through properly where I had to run 'sudo dnf clean all' first before I could update. The first update today was like that too, but I believe I caught all of situations it happened in the different templates? I've seen it both in dom0 and in the fedora template. Upstream fedora dnf bug maybe? Time-span was last 14 days or so, but I'm not sure if it could have occurred longer back.

I just did a clean all now again, no new updates was available afterwards. So I guess it isn't this cache issue.

[Elias Mårtenson]

I did update, and I am reasonably sure that everything was restarted after that.

However, I will try again in the morning and report back.

[Yuraeitha]

On Tuesday, February 20, 2018 at 4:06:58 PM UTC+1, Marek Marczykowski-Górecki wrote:

Just tested qvm-copy (terminal) on both debian-9 and another fedora-9 clone I've got. I've also tried debian-9 to debian-9 only. Same error message across the board, in all 3 different templates.

[Yuraeitha]

Apologies, fedora-26* not fedora-9.

[Marek Marczykowski-Górecki]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

On Tue, Feb 20, 2018 at 07:40:15AM -0800, Yuraeitha wrote:
> On Tuesday, February 20, 2018 at 4:38:26 PM UTC+1, Yuraeitha wrote:
> > On Tuesday, February 20, 2018 at 4:06:58 PM UTC+1, Marek Marczykowski-Górecki wrote:
> > > -----BEGIN PGP SIGNED MESSAGE-----
> > > Hash: SHA256
> > >
> > > On Tue, Feb 20, 2018 at 02:24:22AM -0800, Elias Mårtenson wrote:
> > > > After doing the most recent qubes-dom0-update from the testing repository, all RPC calls from one VM to another stopped working. Calls from dom0 still works fine.
> > > >
> > > > By "not working" I mean that the call to qrexec-client-vm gives me a "Request refused".
> > >
> > > Have you updated also templates? If not, install updates also there and
> > > restart all the VMs. Details here:
> > > https://github.com/QubesOS/qubes-secpack/blob/master/QSBs/qsb-038-2018.txt
> >

> > Just tested qvm-copy (terminal) on both debian-9 and another fedora-9 clone I've got. I've also tried debian-9 to debian-9 only. Same error message across the board, in all 3 different templates.
>
> Apologies, fedora-26* not fedora-9.

Looks like one more thing needs to be restarted: the tool handling
RPC calls confirmations:

In dom0, as normal user:

killall qrexec-policy-agent
qrexec-policy-agent >>~/.xsession-errors 2>&1 &

- --
Best Regards,
Marek Marczykowski-Górecki
Invisible Things Lab
A: Because it messes up the order in which people normally read text.
Q: Why is top-posting such a bad thing?
-----BEGIN PGP SIGNATURE-----

iQEzBAEBCAAdFiEEhrpukzGPukRmQqkK24/THMrX1ywFAlqMQ+4ACgkQ24/THMrX
1ywD6QgAg5XOhohAUNjHlAzL3Ua4jqaBG+5JsIyGkbmwiPYL928E+COvYG8WRf02
7v1oJZIxGo+cN6SehM7psg8xkAx/XLVBOgjF2dBz2dLfhg+JihX6s1qHeGDLnHwi
4RSV8iHyqGp38S+ujcx6yuY2+ufNbNBR3WHg9pA+cufBUsHDTp+xm9ZY4e2KB4P9
RQ9TufAE9W3511poSRXejtjKY+qKqIzWY5S2mGpe2wnUWma5Ps4lLmMaDezewoh6
+TVY+vcolKh9ZbDGzhKNSon4FygvSB190OQjYa+i3MmK1tCtqSDm4vONKDABLqAA
gDUz/H0mF6AXd/JrwBMtVP8pjZAjDg==
=s3Eo
-----END PGP SIGNATURE-----

[Yuraeitha]

It seems writing these commands solved half the problem? I now get the same error that Elias was talking about "Request refused" instead of the issue that it can't find the location. It's a pretty short message, just an outright permission denial.

I got an odd feedback from the second command in dom0 though, maybe it's not normal?

$ killall qrexec-policy-agent
$ qrexec-policy-agent >>~/.xsession-errors 2>$1 &
[1] 16771
bash: $1: ambiguous redirect
[1]+ Exit 1 qrexec-policy-agent >> ~/.xsession-errors 2> $1


Written over exactly as it looks in the dom0, I'm not sure if it's meant to give this reply back or if this is normal.

I'll do a new restart and more testing once I get off the road.

[Marek Marczykowski-Górecki]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

On Tue, Feb 20, 2018 at 08:08:54AM -0800, Yuraeitha wrote:
> On Tuesday, February 20, 2018 at 4:52:00 PM UTC+1, Marek Marczykowski-Górecki wrote:
> > -----BEGIN PGP SIGNED MESSAGE-----
> > Hash: SHA256
> >
> > On Tue, Feb 20, 2018 at 07:40:15AM -0800, Yuraeitha wrote:
> > > On Tuesday, February 20, 2018 at 4:38:26 PM UTC+1, Yuraeitha wrote:
> > > > On Tuesday, February 20, 2018 at 4:06:58 PM UTC+1, Marek Marczykowski-Górecki wrote:
> > > > > -----BEGIN PGP SIGNED MESSAGE-----
> > > > > Hash: SHA256
> > > > >
> > > > > On Tue, Feb 20, 2018 at 02:24:22AM -0800, Elias Mårtenson wrote:
> > > > > > After doing the most recent qubes-dom0-update from the testing repository, all RPC calls from one VM to another stopped working. Calls from dom0 still works fine.
> > > > > >
> > > > > > By "not working" I mean that the call to qrexec-client-vm gives me a "Request refused".
> > > > >
> > > > > Have you updated also templates? If not, install updates also there and
> > > > > restart all the VMs. Details here:
> > > > > https://github.com/QubesOS/qubes-secpack/blob/master/QSBs/qsb-038-2018.txt
> > > >
> > > > Just tested qvm-copy (terminal) on both debian-9 and another fedora-9 clone I've got. I've also tried debian-9 to debian-9 only. Same error message across the board, in all 3 different templates.
> > >
> > > Apologies, fedora-26* not fedora-9.
> >
> > Looks like one more thing needs to be restarted: the tool handling
> > RPC calls confirmations:
> >
> > In dom0, as normal user:
> >
> > killall qrexec-policy-agent
> > qrexec-policy-agent >>~/.xsession-errors 2>&1 &
>

> It seems writing these commands solved half the problem? I now get the same error that Elias was talking about "Request refused" instead of the issue that it can't find the location. It's a pretty short message, just an outright permission denial.
>
> I got an odd feedback from the second command in dom0 though, maybe it's not normal?
>
> $ killall qrexec-policy-agent
> $ qrexec-policy-agent >>~/.xsession-errors 2>$1 &

& not $

> [1] 16771
> bash: $1: ambiguous redirect
> [1]+ Exit 1 qrexec-policy-agent >> ~/.xsession-errors 2> $1

- --
Best Regards,
Marek Marczykowski-Górecki
Invisible Things Lab
A: Because it messes up the order in which people normally read text.
Q: Why is top-posting such a bad thing?
-----BEGIN PGP SIGNATURE-----

iQEzBAEBCAAdFiEEhrpukzGPukRmQqkK24/THMrX1ywFAlqMSVsACgkQ24/THMrX
1yyZigf+I/of4t9uufxPJd2bIe9GZB+B+U0GHaM7lsxXTe4ZUE+B8aw2kORpeB9K
JW2Yymvhwy1aT1xerfy0CZgk7pCCwddD9QUks+uapaxZ6gDi9eKu8FYN38W2nxu+
ofLkmjOnMwXxs8rPTjjjZ9HKRScdBxHjDqUyiR7Vy4yYvYrIk3t+UvHYhYEBZ0VS
k9ly3yKSN3KombvPLtkUHzXHmsY0PW+CPlsmZ0Wv+K6b8EJEypshTtdbN0v1Ho1W
7AwPwyS/a/SroGU6i1tCr7vR3CKb/FkyGjJm8MU0mcRUc57oGH+H1dic+tF3qPDg
eq1Wzmcdd0KUw1hGoHQAE7X2hQhWCg==
=QPhx
-----END PGP SIGNATURE-----

[Yuraeitha]

Sorry about that.

- I corrected my typo and ran both commands again, it now gives back a normal feedback in dom0.

- The GUI copy to VM now works, but the terminal qvm-copy still doesn't work.

- I did a full shutdown, then a start again. No changes, the GUI right click on file to copy to VM still works, but the terminal does not.

- I attached a screenshot of how it looks when the terminal gives the error. It's the same error that came from before typing the 2 commands you gave. Correcting my typo returned the error message instead of the mentioned permission request.

- I made sure to put the address correct, the one you can see in the screenshot, by drag and dropping the file, so that the path was auto-generated. There should therefore presumably be no typo's in the path address. It's also the same error from all the previous issues.

[MirrorWay]

I also had qvm-copy and other rpc requests fail after yesterday's updates with "Request refused". I restarted and everything seems okay now.
​

-------- Original Message --------

>You received this message because you are subscribed to the Google Groups "qubes-devel" group.
> To unsubscribe from this group and stop receiving emails from it, send an email to qubes-devel...@googlegroups.com.
> To post to this group, send email to qubes...@googlegroups.com.
> To view this discussion on the web visit https://groups.google.com/d/msgid/qubes-devel/9606becc-5c00-46c6-bb06-28ae90624a18%40googlegroups.com.
> For more options, visit https://groups.google.com/d/optout.
>

[Marek Marczykowski-Górecki]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

On Tue, Feb 20, 2018 at 09:07:34AM -0800, Yuraeitha wrote:
> - The GUI copy to VM now works, but the terminal qvm-copy still doesn't work.

qvm-copy command takes only filename, the VM name you give in qrexec
confirmation prompt.

- --
Best Regards,
Marek Marczykowski-Górecki
Invisible Things Lab
A: Because it messes up the order in which people normally read text.
Q: Why is top-posting such a bad thing?
-----BEGIN PGP SIGNATURE-----

iQEzBAEBCAAdFiEEhrpukzGPukRmQqkK24/THMrX1ywFAlqMaBcACgkQ24/THMrX
1yxRQgf/YtF1OCeg/iwryngYe+4PI0tv6x9h+ZZISzL1ppVCTEyWa2PJouDZ9GeB
OVZSlGnu/0hmEd4CsXzGsu011PHRYK5dPeQFMq3EmywJQy9gXQh72ifkqZbYscO3
WuXYHf8NK/OzxlUZHCKrpurjFtOLZpZTXa79UMd1lkscmnpS0PAI72Nqi0xd6mJf
DQ81u0tzh57QQmM3qJJSFBMMac6TR9i0zSvEWVacYVuzdIeFSMEf1v4GqPRG2lsQ
3xNQvm76JQ/WU0s886qNCl0Q3M7kZ41OlH7gy1PhG9QINBUW1aacnxLXrKP3zNu6
psvUm9UaEu2cFpLLRF5FV2FBE0xHNA==
=/if3
-----END PGP SIGNATURE-----

[Yuraeitha]

ah I see, that really simplifies the command compared to the old, or maybe it was always like that in VM's and I didn't realize.

Either way though, the issue is still there without putting the VM name in the command, but now the "Request refused." is back in the place of the error. It strikes me as a little odd that it changed on its own this time without me doing anything new (I did nothing special except restarting the VM in question, perhaps it was that). It's the same changed feedback (from error to missing permission) if applying the VM name in the command.

This is a peculiar oddball error. Multiple of full system restarts, and it just won't go away despite careful maintenance procedures, or so I would like to think anyway. (i.e. I don't just recklessly update with wrong repositories between dom0/templates, plug the power, etc.).

This is not a personal issue for me though, not yet at least. I'll wait and see if something new happens, right now I don't think I can add anything new.

Now that full 10-12 second long system-wide freeze that happened earlier today after the update, worries me a bit more. But it hasn't happened since then though. It wasn't too long after returning from suspend, and occurred immediately after starting a another VM. I had little spare RAM left at the time (8GB total) and more VM's running than normal, so maybe that's part of the issue, but normally it would just not start if not enough RAM is left and not cause a freeze like that. I don't expect a personal followup on this, I'm only mentioning this one time incident for awareness. At the time of the system-wide freeze, it had only been restarted once after the update. If a second restart could fix something like that, then maybe it's gone now *shrug*

[Elias Mårtenson]

On Wednesday, 21 February 2018 02:26:16 UTC+8, Marek Marczykowski-Górecki wrote:

> qvm-copy command takes only filename, the VM name you give in qrexec
> confirmation prompt.

After doing a full reboot of the system, and making sure that everything is updated, qvm-copy-to-vm now works, but qvm-copy still gives me the permission error.

As the Nautilus integration uses qvm-copy (rather than qvm-copy-to-vm) it too fails, in the same way as before.

A colleague of mine who installed rc3 (and has updated everything from testing since) just did a full update and he's not seeing the same problem.

Regards,
Elias

[Yuraeitha]

@Elias
I got mine resolved, I'm not sure exactly how as it doesn't make sense, but the new updates that arrived (which seems to have nothing to do with this bug) somehow fixed this bug for me. It went like this.

I tested if the bug was still there in these steps:
- Rebooting multiple of times again, nothing helped, it didn't go away.
- Testing if the bug was there right before new update today, it was still there.
- Testing if the bug was there right after new update today, it was still there.
- Rebooted after the above update and testing, and now it's "magically" gone.

On another bright side or bonus, Qubes even seem more smooth now. It's like old creeky wheels has gotten some oil and it's running more smooth. It can definitely be felt, at least on my system. For example one noticeable difference is how fast VM's shutdown after use.

Can you reproduce this fix Elias?

[Elias Mårtenson]

On Wednesday, 21 February 2018 23:42:18 UTC+8, Yuraeitha wrote:

> On another bright side or bonus, Qubes
> even seem more smooth now. It's like old
> creeky wheels has gotten some oil and
> it's running more smooth. It can
> definitely be felt, at least on my
> system. For example one noticeable

> difference is how fast VM's shutdown is

> after use.
>
> Can you reproduce this fix Elias?

I did try to update and reboot today, but
the problem remained.

I also noted that "open in dispvm" doesn't
work, but I presume that's a consequence
of qvm-copy not working.

It is funny that qvm-copy-to-vm works. I
wonder what the difference is between
these.

[Yuraeitha]

This is really weird indeed... there somehow seems to be a time or random factor involved? I believe there were a few before us too, who also had problems for a while even after a restart, but it was resolved eventually on its own? (At least that's the impression I got from reading those posts). Now the same happened to me, it just went away on its own. Then the question is, what is triggering this "delay"?

Could it be some system cache of sorts? also did you install current-testing? That's the one I used today. I also sometimes have to do 'clean all' or restart sys-net and sys-firewall, for the updater to work properly, which either can't find the updates or return PGP check errors. Sometimes I need to do both, but typically the VM restart is just needed when PGP errors come up during downloads. if I don't do that once in a while, especially if the system has been running for a while, then I've frequently run into these issues the last 14 days or so. It may be a long shot, but you can try these things out too. For example I use qubes-dom0-update --action='clean all' and then clean all in the respective template too.

Usually if the updater pulls down repository updates, and it returns no PGP errors during the update downloads, then there is no cache issue. Or so I believe, I can't tell the difference otherwise.

[Elias Mårtenson]

On Thursday, 22 February 2018 00:52:03 UTC+8, Yuraeitha wrote:

> This is really weird indeed... there somehow seems to be a time or random
> factor involved? I believe there were a few before us too, who also had
> problems for a while even after a restart, but it was resolved eventually on
> its own? (At least that's the impression I got from reading those posts). Now
> the same happened to me, it just went away on its own. Then the question is,
> what is triggering this "delay"?
>
> Could it be some system cache of sorts? also did you install current-testing?
> That's the one I used today. I also sometimes have to do 'clean all' or
> restart sys-net and sys-firewall, for the updater to work properly, which
> either can't find the updates or return PGP check errors. Sometimes I need to
> do both, but typically the VM restart is just needed when PGP errors come up
> during downloads. if I don't do that once in a while, especially if the
> system has been running for a while, then I've frequently run into these
> issues the last 14 days or so. It may be a long shot, but you can try these
> things out too. For example I use qubes-dom0-update --action='clean all' and
> then clean all in the respective template too.

I figured it out.

The problem was indeed that the template had not been updated to testing. This was caused by the repositories file being reverted back to its original (non-testing) state. I believe this was caused by me executing the wrong Salt state when I was experimenting with that previously.

Thanks a lot for the help, both you and Marek.

[Yuraeitha]

Good you got it working (:

It's still frustrating me a bit though, I never found out what triggered the fix for me, besides the extra update that had no qubes-tools in it like the first one had. Either something is wrong with my system, or I did a user mistake. Guess I'll draw the long straw, and just get rid of RC-3 and install RC-4 without confirmation whether it'd any good to do so. I'll probably never find out the reason, but it's starting to make me a bit uneasy whether it could have been due to Qubes RC-3 or not. Either way, it may still have been a user mistake, but at least it wasn't the update command (I use arrow up to get the command from last time I updated, and when checking the last commands, it's still correct) or the lack of restarts (which I tried). I've verified both of these multiple of times over before the fix kicked in. This weird behavior makes me a bit uneasy, I wonder if RC-3 could have explained it or not. In the end it may just have been that I missed something and did a mistake, but not having an answer to this weird issue bugs me. But I probably won't be able to find answers though, so maybe it's best to just forget about it and move on (after I get rid of RC-3, just to be on the safe side, and maybe it fixes those annoying update cache issues I've experiencing recently).

[Elias Mårtenson]

On 22 Feb 2018 4:24 pm, "Yuraeitha" <yura...@gmail.com> wrote:

Guess I'll draw the long straw, and just get rid of RC-3 and install RC-4 without confirmation whether it'd any good to do so. I'll probably never find out the reason, but it's starting to make me a bit uneasy whether it could have been due to Qubes RC-3 or not.

I wouldn't bet on it. My system is based on rc4. My colleague who installed rc3 did not have the problem. 

Regards,

Elias 

[Yuraeitha]

While my qvm-copy issue is gone, what triggered the issue for me isn't, and by the looks of it, it looks like it could happen for another future update again, if it hasn't already happened in the past without showing signs of it. I believe this may be the reason the qvm-copy issue happend to me, although I can't be sure yet. There is also a chance it was the same that happened to you? But either way, this is what frequently happens on my setup, I started noticing it the last 14 days or so.

Below is a recent example of the template's terminal output when it happens. I did the update after work followed up with sleeping, so I'm sure it was well beyond the default 6 hours for saving cache on repository updates.

This also happened on the second template (fedora-26-apps), and not on the first template I ran the update (fedora-26). Could this be because the updates are handled in the same place and the cache wasn't cleared? It seems likely to be a legit explanation, although remains to be confirmed.

There is also the issue I have with PGP checks, where I have to restart sys-net/sys-firewall to get proper PGP checks on updates.

All these seem to be connected to each others. Cache doesn't seem to be cleared properly where Qubes handles the updates. I'm not sure if that is actually the explanation for the behavior though. It looks like this.

This is from the latest update, the cache issue happens quite frequently despite the 6 hour window.


[user@fedora-26-apps ~]$ sudo dnf update --enablerepo=qubes-vm-*-current-testing
Fedora 26 - x86_64 - Updates 2.3 MB/s | 20 MB 00:08
Last metadata expiration check: 0:00:12 ago on Feb
Dependencies resolved.
Nothing to do.
Complete!
[user@fedora-26-apps ~]$ sudo dnf clean all
44 files removed
[user@fedora-26-apps ~]$ sudo dnf update --enablerepo=qubes-vm-*-current-testing
Fedora 26 - x86_64 - Updates 2.2 MB/s | 20 MB 00:09
Fedora 26 - x86_64 2.5 MB/s | 53 MB 00:21
Qubes OS Repository for VM (updates) 106 kB/s | 55 kB 00:00
Qubes OS Repository for VM (updates-testing) 291 kB/s | 182 kB 00:00
RPM Fusion for Fedora 26 - Free 1.0 MB/s | 519 kB 00:00
RPM Fusion for Fedora 26 - Nonfree 322 kB/s | 158 kB 00:00
Last metadata expiration check: 0:00:00 ago on Feb
Dependencies resolved.
================================================================================
Package Arch Version Repository Size
================================================================================
Upgrading:
python3-dnf-plugins-qubes-hooks
x86_64 4.0.23-1.fc26 qubes-vm-r4.0-current-testing 8.9 k
qubes-core-agent x86_64 4.0.23-1.fc26 qubes-vm-r4.0-current-testing 107 k
qubes-core-agent-dom0-updates
x86_64 4.0.23-1.fc26 qubes-vm-r4.0-current-testing 8.3 k
qubes-core-agent-nautilus
x86_64 4.0.23-1.fc26 qubes-vm-r4.0-current-testing 11 k
qubes-core-agent-network-manager
x86_64 4.0.23-1.fc26 qubes-vm-r4.0-current-testing 9.3 k
qubes-core-agent-networking
x86_64 4.0.23-1.fc26 qubes-vm-r4.0-current-testing 17 k
qubes-core-agent-passwordless-root
x86_64 4.0.23-1.fc26 qubes-vm-r4.0-current-testing 8.5 k
qubes-core-agent-qrexec
x86_64 4.0.23-1.fc26 qubes-vm-r4.0-current-testing 30 k
qubes-core-agent-systemd
x86_64 4.0.23-1.fc26 qubes-vm-r4.0-current-testing 22 k

Transaction Summary
================================================================================
Upgrade 9 Packages

Total download size: 222 k
Is this ok [y/N]:


As it can be seen, in the first update it only checks the fedora repository, and no other repositories.
I haven't observed the details yet, for example I'm not sure if it sometimes includes Qubes repository, but not the Qubes current-testing repository. I'm not sure if it's a all or nothing situation, or if it can be "mixed", for example if current-testing isn't included despite the --enablerepo=qubes-vm-*-current-testing flag. For now though, I just know it's at least an all or nothing issue, whether it can be mixed is too early to tell.

At this point I might just re-install, unless it can be fixed. But it seems something is fundamentally broken, it seems safer to get a clean re-install. But I wonder if this could have explained the qvm-copy issue.

[Yuraeitha]

GPG*, I mixed that acronym up with PGP in the above post.

It should also be noted that fedora-26-apps is the only AppVM I have

RPM Fusion for Fedora 26 - Free

RPM Fusion for Fedora 26 - Nonfree

enabled, which further deepens the mystery. If the cache isn't cleared from the earlier fedora-26 update just before updating fedora-26-apps, then why wasn't RPM Fusion repositories checked on the first update run in fedora-26-apps?

It still seems to be a cache issue in the shared Qubes template update mechanism (and it also sometimes affects dom0 update as well). But it may be important to include that that RPM Fusion did not update, despite no other RPM update had been run within the 6 hour window, although fedora/qubes updates had been run minutes before the issue.

Also this only happens to fedora, I've never encountered the issue on the debian template. I also only have one debian template, not 3 (dom0, fedora-26, and fedora-26-apps).

Putting it short, it seems whenever recent version of Qubes 4 update with multiple of the same architectures (fedora-26), it has cache issues. At the very least this happens on my Qubes system, I've not yet seen others report this. Could it be a unique issue?

[Marek Marczykowski-Górecki]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

On Fri, Feb 23, 2018 at 01:27:41PM -0800, Yuraeitha wrote:
> On Thursday, February 22, 2018 at 9:26:42 AM UTC+1, Elias Mårtenson wrote:
> > On 22 Feb 2018 4:24 pm, "Yuraeitha" <yura...@gmail.com> wrote:
> >
> > Guess I'll draw the long straw, and just get rid of RC-3 and install RC-4 without confirmation whether it'd any good to do so. I'll probably never find out the reason, but it's starting to make me a bit uneasy whether it could have been due to Qubes RC-3 or not.
> >
> >
> > I wouldn't bet on it. My system is based on rc4. My colleague who installed rc3 did not have the problem. 
> >
> >
> > Regards,
> > Elias 
>
>
> While my qvm-copy issue is gone, what triggered the issue for me isn't, and by the looks of it, it looks like it could happen for another future update again, if it hasn't already happened in the past without showing signs of it. I believe this may be the reason the qvm-copy issue happend to me, although I can't be sure yet. There is also a chance it was the same that happened to you? But either way, this is what frequently happens on my setup, I started noticing it the last 14 days or so.
>
> Below is a recent example of the template's terminal output when it happens. I did the update after work followed up with sleeping, so I'm sure it was well beyond the default 6 hours for saving cache on repository updates.

According to dnf.conf manual, "The default corresponds to 48 hours".

Does it explains anything?

> This also happened on the second template (fedora-26-apps), and not on the first template I ran the update (fedora-26). Could this be because the updates are handled in the same place and the cache wasn't cleared? It seems likely to be a legit explanation, although remains to be confirmed.
>
> There is also the issue I have with PGP checks, where I have to restart sys-net/sys-firewall to get proper PGP checks on updates.
>
> All these seem to be connected to each others. Cache doesn't seem to be cleared properly where Qubes handles the updates. I'm not sure if that is actually the explanation for the behavior though. It looks like this.
>
> This is from the latest update, the cache issue happens quite frequently despite the 6 hour window.
>
>
> [user@fedora-26-apps ~]$ sudo dnf update --enablerepo=qubes-vm-*-current-testing

I'd recommend --refresh option, instead of separate "dnf clean all"
call. This will cause dnf to check if metadata on the server have
updated, and do not download (50+ MB) again if not.

(...)

> As it can be seen, in the first update it only checks the fedora repository, and no other repositories.
> I haven't observed the details yet, for example I'm not sure if it sometimes includes Qubes repository, but not the Qubes current-testing repository. I'm not sure if it's a all or nothing situation, or if it can be "mixed", for example if current-testing isn't included despite the --enablerepo=qubes-vm-*-current-testing flag. For now though, I just know it's at least an all or nothing issue, whether it can be mixed is too early to tell.
>
> At this point I might just re-install, unless it can be fixed. But it seems something is fundamentally broken, it seems safer to get a clean re-install. But I wonder if this could have explained the qvm-copy issue.

Have you installed those updates now? The not-checking-updates issue
seems separate and in fact working as documented (but maybe not as
expected). Other issues, should be fixed in the update.

- --
Best Regards,
Marek Marczykowski-Górecki
Invisible Things Lab
A: Because it messes up the order in which people normally read text.
Q: Why is top-posting such a bad thing?
-----BEGIN PGP SIGNATURE-----

iQEzBAEBCAAdFiEEhrpukzGPukRmQqkK24/THMrX1ywFAlqQjoEACgkQ24/THMrX
1yxKAQf8DZYI17fmswIFANu8osyFKhcV3JYVRVUcDbI68HN1r/bQHAdkx+Y68pep
1oycNtiFYOGrPpzcWlbAVAMNdb/GJYhH/GxQSCRTuufxOFPljvNQtf7pMleeNh21
dbfNsE8xZpbPTZ35j+baxjsb5jzLCcypUxzjU/1I3WfY9gmjQbXSoIvHacffGBex
nz+6rkFGMLDTULLvQWRkbwLM53oInkWxtU0BpAh6ZW2OyV4SMzFu+NkWnxve3Kw6
Qx6wEPADErR+k3mVEVwEq0FNsS8CMFiO8JUypbep5N38dBs71ZjVAl1TW6SvuvIH
4lw96WYVUo1QKcgAAhS4AQiaAdqcjA==
=R+3Z
-----END PGP SIGNATURE-----

[Yuraeitha]

If cache last 48 hours and not 6 hours, that certainly could explain it. I'll write down when I do future updates to see if it is gone when beyond 48 hours or if using --refresh within 48 hours.

Duly noted on the --refresh option. I've been worried if checking updates more frequently would stress the servers (considering when many people do it), so --refresh seems like a much, much better option. I'll definitely use this from now on.

I have indeed installed the listed updates. I think I understand what you mean, it's a little complex to rephrase it all in full words, but if I understood what you meant right I essentially I created these update holes on my own, which caused out-of-sync dom0/template updates when only "sometimes" using 'clean all' within 48 hours instead of the thought 6 hours, (or --refresh, which I'll use from now on). So if I got this down right, if I properly and systematically use --refresh for both dom0/template in sync when it's within 48 hours, then I won't risk out of sync updates again. I lack the technical insight, but with the little knowledge I have it does indeed seem pretty likely to explain the cache issue I experience, and the solution seems pretty good. It also removes the worries I had, I want to thank you for that too.

I'll give this adjusted user approach to updates a spin for a while before reporting back whether the cache update issue is fully gone.