Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

qubes-updates-proxy: Start request repeated too quickly #9110

Closed
kaie opened this issue Apr 12, 2024 · 24 comments · Fixed by QubesOS/qubes-core-agent-linux#531
Closed

qubes-updates-proxy: Start request repeated too quickly #9110

kaie opened this issue Apr 12, 2024 · 24 comments · Fixed by QubesOS/qubes-core-agent-linux#531
Labels
affects-4.2 This issue affects Qubes OS 4.2. C: networking C: updates diagnosed Technical diagnosis has been performed (see issue comments). P: default Priority: default. Default priority for new issues, to be replaced given sufficient information. pr submitted A pull request has been submitted for this issue. r4.2-vm-bookworm-stable r4.2-vm-fc39-stable r4.2-vm-fc40-stable r4.2-vm-fc41-stable r4.2-vm-trixie-stable r4.3-vm-bookworm-cur-test r4.3-vm-fc39-cur-test r4.3-vm-fc40-cur-test r4.3-vm-fc41-cur-test r4.3-vm-trixie-cur-test T: bug Type: bug report. A problem or defect resulting in unintended behavior in something that exists.

Comments

@kaie
Copy link

kaie commented Apr 12, 2024

How to file a helpful issue

Qubes OS release

4.2

Brief summary

qubes-updates-proxy fails to start in sys-net.

systemctl status qubes-updates-proxy
reports:

sys-net systemd[1]: qubes-updates-proxy.service: Start request repeated too quickly.
sys-net systemd[1]: qubes-updates-proxy.service: Failed with result 'start-limit-hit'.
sys-net systemd[1]: Failed to start qubes-updates-proxy.service - Qubes updates proxy (tinyproxy).

Steps to reproduce

Shut down all VMs.
Start up sys-net, either directly or indirectly.
Try to update a qube, which fails.
Open a terminal in sys-net and check systemctl, the above service has failed to start.

I can manually work around the issue, after sys-net has started, by running this command:
systemctl start qubes-updates-proxy

Additional notes

I originally mentioned my update problems in issue #9025 and claimed it had to with the template that sys-net was based on.
That was an incorrect statement, I had incorrectly concluded that, I got misled during my various attempts to resolve that issue on my system.

The new issue I'm reporting happens regardless of the template used for sys-net, I tried both debian-12-xfce and fedora-39-xfce.

@kaie kaie added P: default Priority: default. Default priority for new issues, to be replaced given sufficient information. T: bug Type: bug report. A problem or defect resulting in unintended behavior in something that exists. labels Apr 12, 2024
@marmarek
Copy link
Member

Can you check earlier logs why it failed initially? You can get it with sudo journalctl b -u qubes-updates-proxy in sys-net.

@andrewdavidwong andrewdavidwong added needs diagnosis Requires technical diagnosis from developer. Replace with "diagnosed" or remove if otherwise closed. C: updates affects-4.2 This issue affects Qubes OS 4.2. labels Apr 13, 2024
@kaie
Copy link
Author

kaie commented Apr 13, 2024

I guess you meant "-b -u" (not "b -u")

Apr 12 16:26:23 sys-net systemd[1]: Started qubes-updates-proxy.service - Qubes updates proxy (tinyproxy).
Apr 12 16:26:23 sys-net tinyproxy-wrapper[680]: Found tinyproxy at /usr/bin/tinyproxy
Apr 12 16:26:23 sys-net tinyproxy[680]: Initializing tinyproxy ...
Apr 12 16:26:23 sys-net tinyproxy-wrapper[680]: WARNING: obsolete config item on line 14
Apr 12 16:26:23 sys-net tinyproxy-wrapper[680]: WARNING: obsolete config item on line 15
Apr 12 16:26:23 sys-net tinyproxy-wrapper[680]: WARNING: obsolete config item on line 16
Apr 12 16:26:23 sys-net tinyproxy-wrapper[680]: WARNING: obsolete config item on line 17
Apr 12 16:26:23 sys-net tinyproxy[680]: Reloading config file
Apr 12 16:26:23 sys-net tinyproxy[680]: Reloading config file finished
Apr 12 16:26:25 sys-net tinyproxy[680]: Shutting down.
Apr 12 16:26:25 sys-net tinyproxy-wrapper[885]: Found tinyproxy at /usr/bin/tinyproxy
Apr 12 16:26:25 sys-net tinyproxy-wrapper[885]: WARNING: obsolete config item on line 14
Apr 12 16:26:25 sys-net tinyproxy-wrapper[885]: WARNING: obsolete config item on line 15
Apr 12 16:26:25 sys-net tinyproxy-wrapper[885]: WARNING: obsolete config item on line 16
Apr 12 16:26:25 sys-net tinyproxy-wrapper[885]: WARNING: obsolete config item on line 17
Apr 12 16:26:25 sys-net tinyproxy[885]: Initializing tinyproxy ...
Apr 12 16:26:25 sys-net tinyproxy[885]: Reloading config file
Apr 12 16:26:25 sys-net tinyproxy[885]: Reloading config file finished
Apr 12 16:26:25 sys-net systemd[1]: Stopping qubes-updates-proxy.service - Qubes updates proxy (tinyproxy)...
Apr 12 16:26:25 sys-net systemd[1]: qubes-updates-proxy.service: Deactivated successfully.
Apr 12 16:26:25 sys-net systemd[1]: Stopped qubes-updates-proxy.service - Qubes updates proxy (tinyproxy).
Apr 12 16:26:25 sys-net systemd[1]: Started qubes-updates-proxy.service - Qubes updates proxy (tinyproxy).
Apr 12 16:26:27 sys-net systemd[1]: Stopping qubes-updates-proxy.service - Qubes updates proxy (tinyproxy)...
Apr 12 16:26:27 sys-net tinyproxy[885]: Shutting down.
Apr 12 16:26:27 sys-net systemd[1]: qubes-updates-proxy.service: Deactivated successfully.
Apr 12 16:26:27 sys-net systemd[1]: Stopped qubes-updates-proxy.service - Qubes updates proxy (tinyproxy).
Apr 12 16:26:27 sys-net systemd[1]: Started qubes-updates-proxy.service - Qubes updates proxy (tinyproxy).
Apr 12 16:26:27 sys-net tinyproxy-wrapper[1146]: Found tinyproxy at /usr/bin/tinyproxy
Apr 12 16:26:27 sys-net tinyproxy-wrapper[1146]: WARNING: obsolete config item on line 14
Apr 12 16:26:27 sys-net tinyproxy-wrapper[1146]: WARNING: obsolete config item on line 15
Apr 12 16:26:27 sys-net tinyproxy-wrapper[1146]: WARNING: obsolete config item on line 16
Apr 12 16:26:27 sys-net tinyproxy-wrapper[1146]: WARNING: obsolete config item on line 17
Apr 12 16:26:27 sys-net tinyproxy[1146]: Initializing tinyproxy ...
Apr 12 16:26:27 sys-net tinyproxy[1146]: Reloading config file
Apr 12 16:26:27 sys-net tinyproxy[1146]: Reloading config file finished
Apr 12 16:26:27 sys-net tinyproxy[1146]: Shutting down.
Apr 12 16:26:27 sys-net systemd[1]: Stopping qubes-updates-proxy.service - Qubes updates proxy (tinyproxy)...
Apr 12 16:26:27 sys-net systemd[1]: qubes-updates-proxy.service: Deactivated successfully.
Apr 12 16:26:27 sys-net systemd[1]: Stopped qubes-updates-proxy.service - Qubes updates proxy (tinyproxy).
Apr 12 16:26:27 sys-net systemd[1]: Started qubes-updates-proxy.service - Qubes updates proxy (tinyproxy).
Apr 12 16:26:27 sys-net tinyproxy-wrapper[1222]: Found tinyproxy at /usr/bin/tinyproxy
Apr 12 16:26:27 sys-net tinyproxy-wrapper[1222]: WARNING: obsolete config item on line 14
Apr 12 16:26:27 sys-net tinyproxy-wrapper[1222]: WARNING: obsolete config item on line 15
Apr 12 16:26:27 sys-net tinyproxy-wrapper[1222]: WARNING: obsolete config item on line 16
Apr 12 16:26:27 sys-net tinyproxy-wrapper[1222]: WARNING: obsolete config item on line 17
Apr 12 16:26:27 sys-net tinyproxy[1222]: Initializing tinyproxy ...
Apr 12 16:26:27 sys-net tinyproxy[1222]: Reloading config file
Apr 12 16:26:27 sys-net tinyproxy[1222]: Reloading config file finished
Apr 12 16:26:29 sys-net systemd[1]: Stopping qubes-updates-proxy.service - Qubes updates proxy (tinyproxy)...
Apr 12 16:26:29 sys-net tinyproxy[1222]: Shutting down.
Apr 12 16:26:29 sys-net systemd[1]: qubes-updates-proxy.service: Deactivated successfully.
Apr 12 16:26:29 sys-net systemd[1]: Stopped qubes-updates-proxy.service - Qubes updates proxy (tinyproxy).
Apr 12 16:26:29 sys-net systemd[1]: Started qubes-updates-proxy.service - Qubes updates proxy (tinyproxy).
Apr 12 16:26:29 sys-net tinyproxy-wrapper[1282]: Found tinyproxy at /usr/bin/tinyproxy
Apr 12 16:26:29 sys-net tinyproxy-wrapper[1282]: WARNING: obsolete config item on line 14
Apr 12 16:26:29 sys-net tinyproxy-wrapper[1282]: WARNING: obsolete config item on line 15
Apr 12 16:26:29 sys-net tinyproxy-wrapper[1282]: WARNING: obsolete config item on line 16
Apr 12 16:26:29 sys-net tinyproxy-wrapper[1282]: WARNING: obsolete config item on line 17
Apr 12 16:26:29 sys-net tinyproxy[1282]: Initializing tinyproxy ...
Apr 12 16:26:29 sys-net tinyproxy[1282]: Reloading config file
Apr 12 16:26:29 sys-net tinyproxy[1282]: Reloading config file finished
Apr 12 16:26:29 sys-net tinyproxy[1282]: Shutting down.
Apr 12 16:26:29 sys-net systemd[1]: Stopping qubes-updates-proxy.service - Qubes updates proxy (tinyproxy)...
Apr 12 16:26:29 sys-net systemd[1]: qubes-updates-proxy.service: Deactivated successfully.
Apr 12 16:26:29 sys-net systemd[1]: Stopped qubes-updates-proxy.service - Qubes updates proxy (tinyproxy).
Apr 12 16:26:29 sys-net systemd[1]: qubes-updates-proxy.service: Start request repeated too quickly.
Apr 12 16:26:29 sys-net systemd[1]: qubes-updates-proxy.service: Failed with result 'start-limit-hit'.
Apr 12 16:26:29 sys-net systemd[1]: Failed to start qubes-updates-proxy.service - Qubes updates proxy (tinyproxy).

@kaie
Copy link
Author

kaie commented Apr 13, 2024

I think the lines 14-17 it complains about are:

MinSpareServers 2
MaxSpareServers 10
StartServers 2
MaxRequestsPerChild 0

@kaie
Copy link
Author

kaie commented Apr 13, 2024

I think the above log isn't helpful to understand the reason for the restart.
Looking at other log items I see:

Apr 12 16:26:24 sys-net systemd[1]: tinyproxy.service - Tinyproxy lightweight HTTP Proxy was skipped because of an unmet condition check (ConditionPathExists=/var/run/qubes-service/tinyproxy).

Should that maybe check for tinyproxy.pid ?
I'll try to change file /usr/lib/systemd/system/tinyproxy.service.d/30_not_needed_in_qubes_by_default.conf
which contains that condition

@kaie
Copy link
Author

kaie commented Apr 13, 2024

Hmm, not sure my theory is right.

The existing script looks for something in /var/run/qubes-service/
I don't have any entries named tinyproxy in that directory.

The pid file I had suggested to check for is in
/var/run/tinyproxy-updates/tinyproxy.pid
(and this was just a wild guess, I'm just reporting what file with a name containing the word "tinyproxy" I can find in /var/run

@marmarek
Copy link
Member

tinyproxy.service is a different thing than qubes-updates-proxy.service. Do you see any other log entries? Maybe NetworkManager is quickly changing settings (updates proxy is reloaded on each IP change)

@kaie
Copy link
Author

kaie commented Apr 14, 2024

Your theory that it has to do with IP addresses and network manager was correct.

My laptop was connected to the network with an ethernet cable, and in addition it was in reach of a wifi network that was configured for automaatic connection. At startup, network manager reports that it connected to both.

With ethernet disconnected, the updates-proxy stay up, no error.
With disabled automatic wifi connection and ethernet cable connected, it also works fine.

The problem happens for me if network manager is able to connect using two different methods at the same time.

@doublehelix24
Copy link

doublehelix24 commented Aug 3, 2024

I can confirm @kaie's findings: When my laptop is connected to LAN and Wifi at the same time then the updates proxy is down.
Restarting qubes-updates-proxy in sys-net fixes it.
Running Qubes 4.2.2

@bzcanli
Copy link

bzcanli commented Oct 2, 2024

I have too many vlans connected via ethernet. I can confirm that is the reason "start-limit-hit" on qubes-updates-proxy.service . I modified sys-net (where my qubes-updates-proxy.service is running) /lib/systemd/system/qubes-updates-proxy.service file. Added StartLimitBurst=0 under [Service]. It solved for me. Ref: https://www.suse.com/support/kb/doc/?id=000019750

marmarek added a commit to marmarek/qubes-core-agent-linux that referenced this issue Nov 1, 2024
NetworkManager will call the hook when anything about the connection
changes. In some cases (like multiple connections) this can be quite
often and restarting tinyproxy each time will eventually trigger restart
rate limit and keep the service down. But even if not hitting this
limit, restart interrupts any download in progress.

Add a check if DNS addresses actually changed since the las hook call,
and restart the service only when necessary.
As a side effect, this will also avoid restarting the service on DHCP
lease renew.

Fixes QubesOS/qubes-issues#9110
@qubesos-bot
Copy link

Automated announcement from builder-github

The component core-agent-linux (including package core-agent-linux) has been pushed to the r4.3 testing repository for the Fedora template.
To test this update, please install it with the following command:

sudo dnf update --enablerepo=qubes-vm-r4.3-current-testing

Changes included in this update

@qubesos-bot
Copy link

Automated announcement from builder-github

The component core-agent-linux (including package core-agent-linux) has been pushed to the r4.3 testing repository for the Fedora template.
To test this update, please install it with the following command:

sudo dnf update --enablerepo=qubes-vm-r4.3-current-testing

Changes included in this update

@qubesos-bot
Copy link

Automated announcement from builder-github

The component core-agent-linux (including package core-agent-linux) has been pushed to the r4.3 testing repository for the Fedora template.
To test this update, please install it with the following command:

sudo dnf update --enablerepo=qubes-vm-r4.3-current-testing

Changes included in this update

@qubesos-bot
Copy link

Automated announcement from builder-github

The package core-agent-linux has been pushed to the r4.3 testing repository for the Debian template.
To test this update, first enable the testing repository in /etc/apt/sources.list.d/qubes-*.list by uncommenting the line containing bookworm-testing (or appropriate equivalent for your template version), then use the standard update command:

sudo apt-get update && sudo apt-get dist-upgrade

Changes included in this update

@qubesos-bot
Copy link

Automated announcement from builder-github

The package core-agent-linux has been pushed to the r4.3 testing repository for the Debian template.
To test this update, first enable the testing repository in /etc/apt/sources.list.d/qubes-*.list by uncommenting the line containing trixie-testing (or appropriate equivalent for your template version), then use the standard update command:

sudo apt-get update && sudo apt-get dist-upgrade

Changes included in this update

@andrewdavidwong andrewdavidwong added diagnosed Technical diagnosis has been performed (see issue comments). pr submitted A pull request has been submitted for this issue. labels Nov 5, 2024
marmarek added a commit to QubesOS/qubes-core-agent-linux that referenced this issue Nov 5, 2024
NetworkManager will call the hook when anything about the connection
changes. In some cases (like multiple connections) this can be quite
often and restarting tinyproxy each time will eventually trigger restart
rate limit and keep the service down. But even if not hitting this
limit, restart interrupts any download in progress.

Add a check if DNS addresses actually changed since the las hook call,
and restart the service only when necessary.
As a side effect, this will also avoid restarting the service on DHCP
lease renew.

Fixes QubesOS/qubes-issues#9110

(cherry picked from commit 01aa298)
@qubesos-bot
Copy link

Automated announcement from builder-github

The package core-agent-linux has been pushed to the r4.2 testing repository for the Debian template.
To test this update, first enable the testing repository in /etc/apt/sources.list.d/qubes-*.list by uncommenting the line containing trixie-testing (or appropriate equivalent for your template version), then use the standard update command:

sudo apt-get update && sudo apt-get dist-upgrade

Changes included in this update

@qubesos-bot
Copy link

Automated announcement from builder-github

The component core-agent-linux (including package core-agent-linux) has been pushed to the r4.2 testing repository for the Fedora template.
To test this update, please install it with the following command:

sudo dnf update --enablerepo=qubes-vm-r4.2-current-testing

Changes included in this update

@qubesos-bot
Copy link

Automated announcement from builder-github

The component core-agent-linux (including package core-agent-linux) has been pushed to the r4.2 testing repository for the Fedora template.
To test this update, please install it with the following command:

sudo dnf update --enablerepo=qubes-vm-r4.2-current-testing

Changes included in this update

@qubesos-bot
Copy link

Automated announcement from builder-github

The package core-agent-linux has been pushed to the r4.2 testing repository for the Debian template.
To test this update, first enable the testing repository in /etc/apt/sources.list.d/qubes-*.list by uncommenting the line containing bookworm-testing (or appropriate equivalent for your template version), then use the standard update command:

sudo apt-get update && sudo apt-get dist-upgrade

Changes included in this update

@qubesos-bot
Copy link

Automated announcement from builder-github

The component core-agent-linux (including package core-agent-linux) has been pushed to the r4.2 testing repository for the Fedora template.
To test this update, please install it with the following command:

sudo dnf update --enablerepo=qubes-vm-r4.2-current-testing

Changes included in this update

@qubesos-bot
Copy link

Automated announcement from builder-github

The package core-agent-linux has been pushed to the r4.2 stable repository for the Debian template.
To install this update, please use the standard update command:

sudo apt-get update && sudo apt-get dist-upgrade

Changes included in this update

@qubesos-bot
Copy link

Automated announcement from builder-github

The component core-agent-linux (including package core-agent-linux) has been pushed to the r4.2 stable repository for the Fedora template.
To install this update, please use the standard update command:

sudo dnf update

Changes included in this update

@qubesos-bot
Copy link

Automated announcement from builder-github

The package core-agent-linux has been pushed to the r4.2 stable repository for the Debian template.
To install this update, please use the standard update command:

sudo apt-get update && sudo apt-get dist-upgrade

Changes included in this update

@qubesos-bot
Copy link

Automated announcement from builder-github

The component core-agent-linux (including package core-agent-linux) has been pushed to the r4.2 stable repository for the Fedora template.
To install this update, please use the standard update command:

sudo dnf update

Changes included in this update

@qubesos-bot
Copy link

Automated announcement from builder-github

The component core-agent-linux (including package core-agent-linux) has been pushed to the r4.2 stable repository for the Fedora template.
To install this update, please use the standard update command:

sudo dnf update

Changes included in this update

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
affects-4.2 This issue affects Qubes OS 4.2. C: networking C: updates diagnosed Technical diagnosis has been performed (see issue comments). P: default Priority: default. Default priority for new issues, to be replaced given sufficient information. pr submitted A pull request has been submitted for this issue. r4.2-vm-bookworm-stable r4.2-vm-fc39-stable r4.2-vm-fc40-stable r4.2-vm-fc41-stable r4.2-vm-trixie-stable r4.3-vm-bookworm-cur-test r4.3-vm-fc39-cur-test r4.3-vm-fc40-cur-test r4.3-vm-fc41-cur-test r4.3-vm-trixie-cur-test T: bug Type: bug report. A problem or defect resulting in unintended behavior in something that exists.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

6 participants