Init script fails test on reload/restart because of faulty regex

[Tommy Nevtelen]

[Impact]
The squid initscript has a guard against configuration mistakes that prevents the service from being disrupted if the current config has an invalid setting.

This guard relies on the "squid -k parse" command which analyzes the configuration and, in the case of a fatal problem, outputs the string "FATAL: <reason>". The initscript parses that output to catch such errors before further action is taken.

There is a mistake in the expression that is looked for, though: instead of "FATAL: ", the initscript is looking for "FATAL " (i.e., no ":"). The consequence is that actions that would reload or restart the service end up shutting the service down in the case of a configuration error.

The change fixes the expression that is looked for, restoring the functionality of the guard.

[Test Case]
* install squid:
sudo apt update && sudo apt install squid -y

* confirm the reload action is quick to return and doesn't change the pid of squid, i.e., it's not restarted:
ubuntu@xenial-squid-reload-syntax:~$ pidof squid
2684
ubuntu@xenial-squid-reload-syntax:~$ sudo service squid reload
ubuntu@xenial-squid-reload-syntax:~$ pidof squid
2684
ubuntu@xenial-squid-reload-syntax:~$

* add an invalid setting to the config file:
echo "acl nonsense nonsense nonsense" | sudo tee -a /etc/squid/squid.conf

* reload squid one more time:
sudo service squid reload

* After about 30s, squid should be dead and service squid status should show errors:
ubuntu@xenial-squid-reload-syntax:~$ pidof squid
ubuntu@xenial-squid-reload-syntax:~$

ubuntu@xenial-squid-reload-syntax:~$ sudo service squid status
● squid.service - LSB: Squid HTTP Proxy version 3.x
(...)
Oct 29 19:56:26 xenial-squid-reload-syntax squid[2684]: Squid Parent: (squid-1) process 2881 started
Oct 29 19:56:26 xenial-squid-reload-syntax squid[2684]: Squid Parent: (squid-1) process 2881 exited with status 1
Oct 29 19:56:26 xenial-squid-reload-syntax squid[2684]: Squid Parent: (squid-1) process 2881 will not be restarted due to repeated, frequent failures
Oct 29 19:56:26 xenial-squid-reload-syntax squid[2684]: Exiting due to repeated, frequent failures

With the fixed package, a reload action (for example) will flag the error, and keep the service running:

ubuntu@xenial-squid-reload-syntax:~$ pidof squid
3801

ubuntu@xenial-squid-reload-syntax:~$ sudo service squid reload
Job for squid.service failed because the control process exited with error code. See "systemctl status squid.service" and "journalctl -xe" for details.

ubuntu@xenial-squid-reload-syntax:~$ echo $?
1

ubuntu@xenial-squid-reload-syntax:~$ pidof squid
3801

And the status message will be much clearer:
ubuntu@xenial-squid-reload-syntax:~$ sudo service squid status
● squid.service - LSB: Squid HTTP Proxy version 3.x
...
Oct 29 20:13:26 xenial-squid-reload-syntax systemd[1]: Reloading LSB: Squid HTTP Proxy version 3.x.
Oct 29 20:13:26 xenial-squid-reload-syntax squid[3920]: * FATAL: Invalid ACL type 'nonsense'
Oct 29 20:13:26 xenial-squid-reload-syntax squid[3920]: FATAL: Bungled /etc/squid/squid.conf line 7897: acl nonsense nonsense nonsense
Oct 29 20:13:26 xenial-squid-reload-syntax systemd[1]: squid.service: Control process exited, code=exited status=3
Oct 29 20:13:26 xenial-squid-reload-syntax systemd[1]: Reload failed for LSB: Squid HTTP Proxy version 3.x.

[Regression Potential]
This changes not only the reload action, but also start and consequently restart. The fix makes an existing safety net around those actions actually work, instead of being ignored.
Due to the lack of an explicit restart action in systemd, however, the restart guard in the SysV initscript doesn't take effect. If there is a bad config, and squid is restarted, the service will be in a stopped state at the end:
- stop will succeed
- start will fail: service remains stopped

There is an upstream bug about it: https://github.com/systemd/systemd/issues/2175

This is not a regression, however, as it's the same behavior as before, but it will have an interesting consequence in package upgrades.

With the old package, admins upgrading squid to a newer version while having a syntax error in their configs will end up with a stopped service, but no notification of that, since the restart postinst action will exit 0.

With the new package, the same scenario will trigger an upgrade failure like this:
dpkg: error processing package squid (--configure):
 subprocess installed post-installation script returned error exit status 1
Processing triggers for systemd (229-4ubuntu21.5) ...
Processing triggers for ureadahead (0.100.0-19) ...
Errors were encountered while processing:
 squid
E: Sub-process /usr/bin/dpkg returned an error code (1)

So the end result is the same as before, in the sense that squid won't be running after the upgrade, but now it will be clear. I expect this can trigger some apport bug reports, though.

[Other Info]
Not at this time.

[Original Description]

This is a very serious issue that got fixed upstream in:
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=800341

It is also logged in the Ubuntu changelog as fixed in:

squid3 (3.5.12-1) unstable; urgency=medium
  [ Mathieu Parent ]
  * Fix FATAL parsing before start/reload/restart (Closes: #800341)

But is in fact not fixed.
When I look in the source package I find two init scripts:
squid3.rc and squid.rc. squid3.rc has the patch while squid.rc does not.

The one being included in the package and deployed is the one that does not have the fix.

I'm including a patch to fix this issue.
Please push this out ASAP.

[Ubuntu Foundations Team Bug Bot (crichton)]

The attachment "Fixing it" seems to be a patch. If it isn't, please remove the "patch" flag from the attachment, remove the "patch" tag, and if you are a member of the ~ubuntu-reviewers, unsubscribe the team.

[This is an automated message performed by a Launchpad user owned by ~brian-murray, for any issues please contact him.]

[Tommy Nevtelen (dal)]

This appears to be fixed in artful+

[ Christian Ehrhardt  (paelzer)]

I can confirm that this is missing in Xenial&Zesty but Fixed in Artful+ as mentioned in comment #3.

The fix came in by:
https://anonscm.debian.org/cgit/pkg-squid/pkg-squid.git/commit/?id=444a7fb4df59a76e6aa2741eb7a245587ccce4b3

That is in 3.15.12 and Xenial has 3.5.12-1ubuntu7.
But due to the different times the renaming squid3/squid happened Xenial and Zesty are affected.

One would need to apply above linked patch to debian/squid.rc (without the 3).

@Rbasak - you might have some extra context on that renaming history, I'm subscribing you and Ubuntu-server would you mind to take a look?

[ Christian Ehrhardt  (paelzer)]

Note: the attached patch is incomplete, but the linked change should be good.

[Robie Basak (racb)]

Tommy, thank you for bringing our attention to this.

It looks like this issue *is* fixed in the current stable Ubuntu release. Perhaps you were looking at the changelog against a newer release of Ubuntu than the one you are using?

> This is a very serious issue...

Why is this "a very serious issue"? It seems to me that it only affects invalid configurations so should only affect development and testing of deployments rather than in production? The workaround (if it can be called that) is to fix the invalid configuration.

The fix does look reasonable to SRU though. I wonder if https://anonscm.debian.org/cgit/pkg-squid/pkg-squid.git/commit/?id=6ac65f75a971a4a is also relevant? That may be a separate bug though, or we may need an additional test case for it.

[Tommy Nevtelen (dal)]

On 2018-01-02 15:38, Robie Basak wrote:
> Tommy, thank you for bringing our attention to this.
>
> It looks like this issue *is* fixed in the current stable Ubuntu
> release. Perhaps you were looking at the changelog against a newer
> release of Ubuntu than the one you are using?
>> This is a very serious issue...
> Why is this "a very serious issue"? It seems to me that it only affects
> invalid configurations so should only affect development and testing of
> deployments rather than in production? The workaround (if it can be
> called that) is to fix the invalid configuration.
I kind of hope that this is a joke :)
You know sometimes things don't go as intended, that's why the check is
there.
> The fix does look reasonable to SRU though. I wonder if
> https://anonscm.debian.org/cgit/pkg-squid/pkg-
> squid.git/commit/?id=6ac65f75a971a4a is also relevant? That may be a
> separate bug though, or we may need an additional test case for it.
So it has been a while now. What's the next step to get this in?
The fix is really trivial. Can I help with something to get it rolling?

--
TN

[Robie Basak (racb)]

On Thu, Mar 15, 2018 at 11:42:49PM -0000, Tommy Nevtelen wrote:
> On 2018-01-02 15:38, Robie Basak wrote:
> >> This is a very serious issue...
> > Why is this "a very serious issue"? It seems to me that it only affects
> > invalid configurations so should only affect development and testing of
> > deployments rather than in production? The workaround (if it can be
> > called that) is to fix the invalid configuration.
> I kind of hope that this is a joke :)

Sorry, no, it wasn't a joke.

> You know sometimes things don't go as intended, that's why the check is
> there.

I don't disagree. It is a bug and as I said I have no objection to
getting it fixed in older stable releases if somebody wants to drive
that. But I maintain it is not a serious issue, because as I explained
it only causes some inconvenience to users during development and
testing and does not affect production systems. Claiming it is a serious
issue dilutes attention from issues that really are serious, which is
why I objected to that statement in this case.

> So it has been a while now. What's the next step to get this in?
> The fix is really trivial. Can I help with something to get it rolling?

Please see https://wiki.ubuntu.com/StableReleaseUpdates#Procedure. The
fix may be trivial, but unfortunately updating the stable release is
not. The risk of regressing users who expect stability means that we
have to take considerable care. For example, an unrelated latent bug
could be exposed by a rebuild. See
https://wiki.ubuntu.com/StableReleaseUpdates#Why for details.

[Andreas Hasenack (ahasenack)]

Zesty is EOL.

[Robie Basak (racb)]

Hello Tommy, or anyone else affected,

Accepted squid3 into xenial-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/squid3/3.5.12-1ubuntu7.6 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation on how to enable and use -proposed.Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested and change the tag from verification-needed-xenial to verification-done-xenial. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed-xenial. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

[Andreas Hasenack (ahasenack)]

The DEP8 tests in http://people.canonical.com/~ubuntu-archive/proposed-migration/xenial/update_excuses.html are failing for squid3 but for a different reason. Before (http://autopkgtest.ubuntu.com/packages/squid3/xenial/amd64) they wouldn't even start.

For example, see https://objectstorage.prodstack4-5.canonical.com/v1/AUTH_77e2ada1e7a84929a74ba3b87153c0ac/autopkgtest-xenial/xenial/amd64/s/squid3/20181029_225503_190aa@/log.gz which ends with:

badpkg: Test dependencies are unsatisfiable. A common reason is that your testbed is out of date with respect to the archive, and you need to use a current testbed or run apt-get update or use -U.

That and a few other things is what was fixed. The tests now run locally at least, with autopkgtest. The current failure in the autopkgtest infrastructure from Ubuntu is firewall related, as some tests try to reach out to public facing websites like www.ubuntu.com:
FAIL: test_http_proxy (__main__.BasicTest)
Test http
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/tmp/autopkgtest.OnM2uO/build.TgJ/src/debian/tests/test-squid.py", line 124, in test_http_proxy
    self._test_url_proxy("http://www.ubuntu.com/", "Canonical", "http://localhost:3128/")
  File "/tmp/autopkgtest.OnM2uO/build.TgJ/src/debian/tests/testlib_httpd.py", line 233, in _test_url_proxy
    self._word_find(report, content)
  File "/tmp/autopkgtest.OnM2uO/build.TgJ/src/debian/tests/testlib.py", line 982, in _word_find
    self.assertTrue(content in report, warning + report)
AssertionError: Could not find "Canonical"
                                     ERROR

The requested URL could not be retrieved

   --------------------------------------------------------------------------

   The following error was encountered while trying to retrieve the URL:
   [1]http://www.ubuntu.com/

     Connection to 91.189.89.118 failed.

   The system returned: (110) Connection timed out

   The remote host or network may be down. Please try the request again.

   Your cache administrator is [2]webmaster.

   --------------------------------------------------------------------------

   Generated Wed, 31 Oct 2018 19:09:52 GMT by autopkgtest (squid/3.5.12)

I don't think the above is worth fixing at the moment, because:
a) it's a long process: reject package from proposed, prepare new one, upload, get sru team to approve, then let it lose in the autopkgtest infrastructure to see if it works
b) bileto isn't working for this for some reason, I can't get test results from it. It just says "test running (always failed)", and no logs.
c) package that is currently in proposed is already an improvement, as the test now can be run locally (and pass).

[Andreas Hasenack (ahasenack)]

xenial verification

confirming the bug:
root@xenia-squid-restart-1738412:~# apt-cache policy squid
squid:
  Installed: 3.5.12-1ubuntu7.5
  Candidate: 3.5.12-1ubuntu7.5
  Version table:
 *** 3.5.12-1ubuntu7.5 500
        500 http://br.archive.ubuntu.com/ubuntu xenial-updates/main amd64 Packages

# confirming reload doesn't restart or kill the service
ubuntu@xenia-squid-restart-1738412:~$ pidof squid
4280
ubuntu@xenia-squid-restart-1738412:~$ sudo service squid reload
ubuntu@xenia-squid-restart-1738412:~$ pidof squid
4280

# corrupting the config file and trying one more time
ubuntu@xenia-squid-restart-1738412:~$ echo "acl nonsense nonsense nonsense" | sudo tee -a /etc/squid/squid.conf
acl nonsense nonsense nonsense
ubuntu@xenia-squid-restart-1738412:~$ sudo service squid reload
ubuntu@xenia-squid-restart-1738412:~$
ubuntu@xenia-squid-restart-1738412:~$ pidof squid
4280
ubuntu@xenia-squid-restart-1738412:~$ pidof squid
ubuntu@xenia-squid-restart-1738412:~$

Indeed after a while squid isn't running anymore.

Status shows it failed:
ubuntu@xenia-squid-restart-1738412:~$ sudo service squid status
● squid.service - LSB: Squid HTTP Proxy version 3.x
   Loaded: loaded (/etc/init.d/squid; bad; vendor preset: enabled)
   Active: active (exited) since Mon 2018-11-12 18:49:18 UTC; 13min ago
...
Nov 12 18:51:56 xenia-squid-restart-1738412 squid[4280]: Squid Parent: (squid-1) process 4505 will not be restarted due to repeated, frequent failures
Nov 12 18:51:56 xenia-squid-restart-1738412 squid[4280]: Exiting due to repeated, frequent failures

Now retrying with the new package from proposed:
ubuntu@xenia-squid-restart-1738412:~$ apt-cache policy squid
squid:
  Installed: 3.5.12-1ubuntu7.6
  Candidate: 3.5.12-1ubuntu7.6
  Version table:
 *** 3.5.12-1ubuntu7.6 500
        500 http://br.archive.ubuntu.com/ubuntu xenial-proposed/main amd64 Packages

The upgrade failed as expected, because the config file is corrupted and now it's properly detected and it shows in the output:
Setting up squid-common (3.5.12-1ubuntu7.6) ...
Setting up squid (3.5.12-1ubuntu7.6) ...
Installing new version of config file /etc/init.d/squid ...
Job for squid.service failed because the control process exited with error code. See "systemctl status squid.service" and "journalctl -xe" for details.
invoke-rc.d: initscript squid, action "restart" failed.
● squid.service - LSB: Squid HTTP Proxy version 3.x
   Loaded: loaded (/etc/init.d/squid; bad; vendor preset: enabled)
   Active: failed (Result: exit-code) since Mon 2018-11-12 19:04:20 UTC; 4ms ago
     Docs: man:systemd-sysv-generator(8)
  Process: 5293 ExecStop=/etc/init.d/squid stop (code=exited, status=0/SUCCESS)
  Process: 5306 ExecStart=/etc/init.d/squid start (code=exited, status=3)

Nov 12 19:04:20 xenia-squid-restart-1738412 systemd[1]: Starting LSB: Squid HTTP Proxy version 3.x...
Nov 12 19:04:20 xenia-squid-restart-1738412 squid[5306]: * FATAL: Invalid ACL type 'nonsense'
Nov 12 19:04:20 xenia-squid-restart-1738412 squid[5306]: FATAL: Bungled /etc/squid/squid.conf line 7897: acl nonsense nonsense nonsense
(...)

Retrying the original test steps, starting with a fixed config file and then mangling it:
ubuntu@xenia-squid-...

[Brian Murray (brian-murray)]

The verification of the Stable Release Update for squid3 has completed successfully and the package has now been released to -updates. Subsequently, the Ubuntu Stable Release Updates Team is being unsubscribed and will not receive messages about this bug report. In the event that you encounter a regression using the package from -updates please report a new bug using ubuntu-bug and tag the bug report regression-update so we can easily find any regressions.

[Launchpad Janitor (janitor)]

This bug was fixed in the package squid3 - 3.5.12-1ubuntu7.6

---------------
squid3 (3.5.12-1ubuntu7.6) xenial; urgency=medium

  * d/squid.rc: fix regexp for catching FATAL errors (LP: #1738412)
  * d/t/test-squid.py: in xenial, initscript, apparmor profile, pidfile and
    process are named squid, not squid3. Get rid of the multiple distro
    logic since these tests will be only run on xenial.
  * d/t/control: drop uneeded dependency on python-unit.
  * d/t/squid: use a shorter shutdown timeout for the tests, so they
    run faster

 -- Andreas Hasenack <email address hidden> Wed, 31 Oct 2018 09:22:14 -0300