ipptool: Unable to connect to localhost on port 631 - Transport endpoint is not connected

[tylerecouture]

Given Ubuntu 16.04 with Puppet 4.10.9cups and CUPS 2.1.3-4.

When I apply the manifest with puppet agent -t on a node

class profile::config_printers {
include '::cups'

  # Using a suitable model from the output of the command lpinfo -m on the node
  cups_queue { 'Hackerspace_BW_Printer_LexmarkT644':
    ensure => 'printer',
    model  => 'foomatic-db-compressed-ppds:0/ppd/foomatic-ppd/Lexmark-T644-Postscript.ppd',
    uri    => 'socket://192.168.43.101', # Replace with your printer's URI
    accepting => true,
    enabled   => true,
    options => {
      'Duplex'   => 'DuplexNoTumble',
    }
  }

Then I get the error message, but only the first time it runs. The next time it runs fine.

Notice: /Stage[main]/Cups::Packages/Package[cups-ipp-utils]/ensure: created
Notice: /Stage[main]/Cups::Server::Config/File[/etc/cups/cupsd.conf]/content: 
--- /etc/cups/cupsd.conf	2018-01-28 18:34:17.929267910 -0800
+++ /tmp/puppet-file20180206-20699-yiavls	2018-02-06 14:46:11.991882507 -080

... etc...

Notice: /Stage[main]/Cups::Server::Config/File[/etc/cups/cupsd.conf]/content: content changed '{md5}32590abea589afef53ecf6c9ba672a6f' to '{md5}7e38c409f60039663ffbc3560cb1fb87'
Notice: /Stage[main]/Cups::Server::Config/File[/etc/cups/cupsd.conf]/group: group changed 'root' to 'lp'
Notice: /Stage[main]/Cups::Server::Config/File[/etc/cups/cupsd.conf]/mode: mode changed '0644' to '0640'
Info: Class[Cups::Server::Config]: Scheduling refresh of Class[Cups::Server::Services]
Info: Class[Cups::Server::Services]: Scheduling refresh of Service[cups]
Notice: /Stage[main]/Cups::Server::Services/Service[cups]: Triggered 'refresh' from 1 events
Error: Failed to apply catalog: IPP query 'ipptool -c ipp://localhost/ /dev/stdin' failed.
EXITCODE: 1
STDIN:
          {
            OPERATION CUPS-Get-Classes
            GROUP operation
            ATTR charset attributes-charset utf-8
            ATTR language attributes-natural-language en
            DISPLAY printer-name
            DISPLAY member-names
          }

STDOUT:

STDERR:
ipptool: Unable to connect to localhost on port 631 - Transport endpoint is not connected

[leoarnold]

This is a known misbehavior of Ubuntu 16.04 LTS: The CUPS service dies at random.

A Ubuntu 16.04 LTS vagrant box is the default SUT (system under test) for all integration tests of this module. The box also used to have the problem you describe, but it does not occur with contemporary versions of the vagrant box.

I don't know if someone ever found the reason for this, nor can I promise that a clean install of Ubuntu 16.04 LTS could fix it.

There is however a known workaround with a custom systemd unit. See the code in the initial post of #12. If that works for you, I might add the workaround to the module.

[jhowe-uw]

I have also seen this behaviour if you have set a default printer from the command line that writes to the /etc/cups/lpoptions file. The agent seems to nuke /etc/cups/lpoptions at the cost of crashing the cups services. Then cups service has respawned on the next agent run.

[leoarnold]

@jhowe-uw This module deletes /etc/cups/lpoptions before managing the CUPS service.

[tequeter]

I can reproduce this reliably on a CentOS 7.6 desktop just by causing a refresh of the service:

# : >/etc/cups/cupsd.conf
# puppet agent -t
...
Info: Applying configuration version 'aefe72aebd930a3d12a2fc7042dae5de51aa705a'
Notice: /Stage[main]/Cups::Server::Config/File[/etc/cups/cupsd.conf]/content: content changed '{md5}d41d8cd98f00b204e9800998ecf8427e' to '{md5}c8e7845da91c181942e83e45e
5c73e8f'
Info: Class[Cups::Server::Config]: Scheduling refresh of Class[Cups::Server::Services]
Info: Class[Cups::Server::Services]: Scheduling refresh of Service[cups]
Notice: /Stage[main]/Cups::Server::Services/Service[cups]: Triggered 'refresh' from 1 event
Error: Failed to apply catalog: IPP query 'ipptool -c ipp://localhost/ /dev/stdin' failed.
...
ipptool: Unable to connect to localhost on port 631 - Transport endpoint is not connected

journalctl -u cups shows just Stopping/Stopped/Started entries caused by the refresh, no crashes.

It seems that the service refresh returns control to Puppet before CUPS is actually listening on the ipp port.

Adding a systemd drop-in (inspired by #12) seems to work around the issue, by making systemd accept the connection on behalf of the starting CUPS:

systemd::dropin_file { 'workaround-puppet-cups-35.conf':
  unit    => 'cups.socket',
  content => @(END),
    [Socket]
    ListenStream=[::1]:631
    |END
}
~> service { 'cups.socket':
  ensure  => running,
  # Both units listen to port 631, however cups.service will play nice if
  # cups.socket is started first. See sd_listen_fds(3).
  start   => 'systemctl stop cups.service && systemctl start cups.socket',
  require => Package['cups'],
  before  => Service['cups'],
}

The service start hack is a pity, though. CentOS 8 will probably include a better fix, but it's unlikely to make it in CentOS 7.

[leoarnold]

Sadly, I was not able to reproduce this with a CentOS 7.6 VirtualBox.

[tequeter]

@leoarnold, what did you try exactly? I can assure you, it happens in real life :)

Also, at some point I'll clean up my patch and submit it as a PR.

[leoarnold]

@tequeter The acceptance tests
https://github.com/leoarnold/puppet-cups/blob/2f3b75f7f4b7be589dbb35799393957fe526505f/spec/acceptance/classes/init_spec.rb
pass with the CentOS 7.6 SUT
https://github.com/leoarnold/puppet-cups/blob/2f3b75f7f4b7be589dbb35799393957fe526505f/spec/acceptance/nodesets/centos-7.6-x64.yml

A pull request will only be accepted if it contains an acceptance test which will actually fail without the proposed changes.

[tequeter]

I do plan to provide the corresponding test, so that will work for me.

It's a bit harsh for less technically-advanced users, though. Does that mean they have to figure out how to write a failing test to submit a bug report?

[leoarnold]

@tequeter Everyone is always welcome to report issues. This is not the same as a pull request: As in any other open source project, pull requests are expected to be written in the style of the project and maintaining or raising its quality standards.

In your case, we are talking about a problem which only some people report on some computers, but it has not yet been describe in a way that everyone can reproduce on any computer. Without a test that actually demonstrates which problem is solved here, it is unclear whether the patch actually solves a problem at all. Even worse: Without the test we cannot be sure that future manipulations of the code will not break your fix.

That said, nobody has to really learn how to write those tests or use the dev environment of this module. I can write the tests myself, but therefore I need a reproducible way to cause the problem first. And then we could also see whether your proposed changes work on every operating system equally or maybe introduce problems for other platforms.

[tequeter]

This is not about me (well, I think?). As I wrote, you'll get a test with my PR, we both agree to this.

Your first two comments today read as if bugs don't exist if they can't be reproduced with the current testsuite, though. That's... peculiar :)

I do agree however that the issue is not well-defined. The CUPS service can be down for a lot of reasons (crashed, not yet started, ...) that are specific to the user's environment and hard to solve generically.

Would you recommend that users affected by this class of bugs reopen issues specific to their environment?

[leoarnold]

@tequeter This is a general purpose module, so all bugs that affect the general public will be fixed once understood. In the case of this issue I feel that it has not attracted huge attention per se, so only a minority seems to be affected, and we still seem to be at the stage of "Well, this seems to happen and then that, and I know how to fix that, but I can't really pinpoint why my setup is affected and others aren't."

At that level of understanding, we have a trade-off: Your proposed way introduces a dependency (the systemd module) and tampers with another service (SystemD). This opens a lot of doors for additional maintenance, side effects, differences of how systemd is used in different operating systems. It could potentially break or impede other people's setups in ways we do not foresee yet. New features always introduce new liabilities.

So, when a problem only affects a few setups and is not really thoroughly understood, it is more advisable that those affected fix their setups with a workaround of their choosing, rather than to add complexity to the general module.

I am tempted though to add your workaround to the known issues section of the README.

[tequeter]

About the inline patch above: IIRC, there was some ordering issue (too strict? too loose? I forgot) with the service. My PR-in-the-works is better.

About my PR-in-the-works, the branch @ 8884b1c :

• el7 marks the cups.service started before it actually listens on ipp, that OS bug breaks your module.
• This can be reliably reproduced on el7 if you have a few printers defined (see the comments in the acceptance test).
• I work around it by altering how CUPS is managed inside systemd on el7. Adding the .socket unit makes systemd accept the connections for CUPS until it's ready.
• I do not touch the general configuration of systemd.
• I do not apply the workaround anywhere but on el7 systems.
• Deploying this .socket unit still presents a slight risk (as would any change!), but provided it's introduced in a major version and users can disable it, the pro/con seems good to me.

But!

• This is for a customer project, and according to the project plan there may be some 2-3 more months before I can return to this and provide a PR.
• From the commit message, I intended to run the acceptance test suite on all supported OSes, but there was too much broken stuff outside of my code and/or I ran out of time. There may be more TODOs left, I don't have that laptop around.
• It looks like wiene had to further modify my code, I did not look into it yet.

[leoarnold]

Ah, see, there's our user story:

Given a system with CUPS already running
And a lot of queues present
And the file /etc/cups/lpoptions present (which triggers the restart of the CUPS server)
When I apply the manifest include '::cups'
Then the manifest applies without error

On distros with systemd, this is not the case. On distros without systemd, this passes nicely. So now we seem to have isolated the problem.

[leoarnold]

@tequeter I took the liberty of rephrasing your suggestions in the general style of the module and set you as the author of that commit:

https://github.com/leoarnold/puppet-cups/tree/leoarnold/fix/systemd_distros

I have already verified that the test fails without and passes with the patch on CentOS and Ubuntu. I'll publish the fix as v2.1.1 as soon as I have added the corresponding unit tests.

[tequeter]

A few comments:

1. I wouldn't just apply the .socket workaround on every systemd OS. RHEL8 probably comes with a better fix, other recent distros may have something similar.
2. Even though it is designed as a bugfix, this change increases the scope of the managed configuration and might even break users' setup in ways I can't foretell. I'd say this warrants more than a patch version bump?
3. I'm surprised that you managed to simplify the acceptance test by that much. I'll just trust you on it though.
4. I'm not sure why you need to ship KOC759UX.ppd. The builtin drv:///sample.drv/generic.ppd seemed enough for acceptance testing.
5. systemd::dropin_file was introduced in camptocamp-systemd version 1.1.0.

I rebased my commit as 1570be5 for easier diffing. It's a rough job, some of the spec_helper scaffolding has diverged.

[PhilippvK]

I have a problem integrating the systemd fix in my setup.

@leoarnold

When I use include '::cups::workarounds::systemd_service_restart' I get Errors due to a duplicate resource declaration as we already use the following statements to pass parameters to the CUPS module like this:

  class { '::cups':
    package_names          => $cups_pkgs,
    purge_unmanaged_queues => ...
    ...
  }

Wouldn’t it be easier to support such configuration when a if !defined(Class['cups']) statement surounds the include '::cups' line?

[leoarnold]

@PhilippvK Good catch. I think in Puppet 4 the include statement was like Ruby's require in that it loaded the class manifest if and only if the class had not been loaded before.

Or maybe it is just about which is defined first and you were the first to use a different order than anybody else.

I will keep this in mind when I find the time to review #250 which promises to ease the interaction with systemd.

[PhilippvK]

@leoarnold Thank you for your quick answer. You were right!

I was not aware of the fact, that the order of resource declaration on in puppet manifest does matter unless if explicitly defined using require/subscribe/->/~>.