Note: This is a public test instance of Red Hat Bugzilla. The data contained within is a snapshot of the live data so any changes you make will not be reflected in the production Bugzilla. Email is disabled so feel free to test any aspect of the site that you want. File any problems you find or give feedback at bugzilla.redhat.com.

Bug 1478278

Summary: Error messages about invalid argument during start.
Product: [Fedora] Fedora EPEL Reporter: Frank Büttner <bugzilla>
Component: varnishAssignee: Ingvar Hagelund <ingvar>
Status: NEW --- QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: epel7CC: ingvar
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Frank Büttner 2017-08-04 07:51:03 UTC
Description of problem:
When start the 3 services (varnish,varnishlog and varnishncsa) an error message will be reported.

Version-Release number of selected component (if applicable):
varnish-4.0.4-3.el7.x86_64

How reproducible:
Every time

Steps to Reproduce:
1. yum install varnish
2. systemctl start varnish
3. systemctl start varnishncsa
4. systemctl start varnishlog

Actual results:
Error's in the service status
systemctl status varnish
● varnish.service - Varnish Cache, a high-performance HTTP accelerator
   Loaded: loaded (/usr/lib/systemd/system/varnish.service; disabled; vendor preset: disabled)
   Active: active (running) since Fr 2017-08-04 09:03:12 CEST; 45min ago
  Process: 1348 ExecStart=/usr/sbin/varnishd -P /var/run/varnish.pid -f $VARNISH_VCL_CONF -a ${VARNISH_LISTEN_ADDRESS}:${VARNISH_LISTEN_PORT} -T ${VARNISH_ADMIN_LISTEN_ADDRESS}:${VARNISH_ADMIN_LISTEN_PORT} -S $VARNISH_SECRET_FILE -s $VARNISH_STORAGE $DAEMON_OPTS (code=exited, status=0/SUCCESS)
 Main PID: 1358 (varnishd)
   CGroup: /system.slice/varnish.service
           ├─1358 /usr/sbin/varnishd -P /var/run/varnish.pid -f /etc/varnish/default.vcl -a :6081 -T 127.0.0.1:6082 -S /etc/varnish/secret -s malloc,256M
           └─1359 /usr/sbin/varnishd -P /var/run/varnish.pid -f /etc/varnish/default.vcl -a :6081 -T 127.0.0.1:6082 -S /etc/varnish/secret -s malloc,256M

Aug 04 09:03:12 localhost.localdomain systemd[1]: Starting Varnish Cache, a high-performance HTTP accelerator...
Aug 04 09:03:12 localhost.localdomain systemd[1]: Failed to read PID from file /var/run/varnish.pid: Invalid argument
Aug 04 09:03:12 localhost.localdomain varnishd[1358]: Platform: Linux,3.10.0-514.26.2.el7.x86_64,x86_64,-smalloc,-smalloc,-hcritbit
Aug 04 09:03:12 localhost.localdomain systemd[1]: Started Varnish Cache, a high-performance HTTP accelerator.
Aug 04 09:03:12 localhost.localdomain varnishd[1358]: child (1359) Started
Aug 04 09:03:12 localhost.localdomain varnishd[1358]: Child (1359) said Child starts

Aug 04 09:03:12 localhost.localdomain systemd[1]: Failed to read PID from file /var/run/varnish.pid: Invalid argument



systemctl status varnishlog
● varnishlog.service - Varnish Cache HTTP accelerator logging daemon
   Loaded: loaded (/usr/lib/systemd/system/varnishlog.service; disabled; vendor preset: disabled)
   Active: active (running) since Fr 2017-08-04 09:03:15 CEST; 46min ago
  Process: 1582 ExecStart=/usr/bin/varnishlog -a -w /var/log/varnish/varnish.log -D -P /run/varnishlog/varnishlog.pid (code=exited, status=0/SUCCESS)
 Main PID: 1583 (varnishlog)
   CGroup: /system.slice/varnishlog.service
           └─1583 /usr/bin/varnishlog -a -w /var/log/varnish/varnish.log -D -P /run/varnishlog/varnishlog.pid

Aug 04 09:03:15 localhost.localdomain systemd[1]: Starting Varnish Cache HTTP accelerator logging daemon...
Aug 04 09:03:15 localhost.localdomain systemd[1]: Failed to read PID from file /run/varnishlog/varnishlog.pid: Invalid argument
Aug 04 09:03:15 localhost.localdomain systemd[1]: Started Varnish Cache HTTP accelerator logging daemon.

Aug 04 09:03:15 localhost.localdomain systemd[1]: Failed to read PID from file /run/varnishlog/varnishlog.pid: Invalid argument


systemctl status varnishncsa
● varnishncsa.service - Varnish Cache HTTP accelerator NCSA logging daemon
   Loaded: loaded (/usr/lib/systemd/system/varnishncsa.service; disabled; vendor preset: disabled)
   Active: active (running) since Fr 2017-08-04 09:03:18 CEST; 46min ago
  Process: 1590 ExecStart=/usr/bin/varnishncsa -a -w /var/log/varnish/varnishncsa.log -D -P /run/varnishncsa/varnishncsa.pid (code=exited, status=0/SUCCESS)
 Main PID: 1591 (varnishncsa)
   CGroup: /system.slice/varnishncsa.service
           └─1591 /usr/bin/varnishncsa -a -w /var/log/varnish/varnishncsa.log -D -P /run/varnishncsa/varnishncsa.pid

Aug 04 09:03:18 localhost.localdomain systemd[1]: Starting Varnish Cache HTTP accelerator NCSA logging daemon...
Aug 04 09:03:18 localhost.localdomain systemd[1]: Failed to read PID from file /run/varnishncsa/varnishncsa.pid: Invalid argument
Aug 04 09:03:18 localhost.localdomain systemd[1]: Started Varnish Cache HTTP accelerator NCSA logging daemon.

Aug 04 09:03:18 localhost.localdomain systemd[1]: Failed to read PID from file /run/varnishncsa/varnishncsa.pid: Invalid argument



Expected results:
No errors about Invalid argument.

Comment 1 Ingvar Hagelund 2017-08-04 08:56:07 UTC
This is a simple race between the varnish daemons and systemd. systemd is not patient enough waiting for the daemon to open its pidfile, and gives up.

Workaround: Add 

ExecStartPost=/bin/sleep 0.5

to the varnish*.service files and it should work.


I'll try to figure out how to deal with this most correctly.

Ingvar

Comment 2 Ingvar Hagelund 2017-08-04 09:47:16 UTC
Reproduced with newer versions of varnish (5.1.3) on epel7.

Seems this is not a problem with newer versions of systemd. Fedora 25 and 26 does not have this problem.

So this means that this is a problem with systemd, not with varnish. I'll leave it with the workaround, and add that to the next update of varnish for epel7.

Ingvar

Comment 3 Frank Büttner 2017-08-07 04:44:00 UTC
Hi Ingvar,
I have try it, and it will solve it.