[Bug 1815852] Re: squid FATAL: check failed: ios[0].iov_len == sizeof(data)#012 exception location: TypedMsgHdr.cc(70) sync#012

Thu Feb 28 17:43:02 UTC 2019

** Description changed:

  [Impact]
  Squid doesn't work if "workers" is set in squid.conf.

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

  * apply workaround for #1816006
  sudo mkdir -p /var/run/squid
  sudo chown proxy:proxy /var/run/squid

  * confirm no FATAL errors in logs so far
  sudo grep FATAL /var/log/squid/cache.log
  (empty)

  * confirm squid working:
  http_proxy=http://localhost:3128/ wget http://www.ubuntu.com -O /dev/null
  echo $?
  0

  * add workers config
  echo "workers 5" | sudo tee -a /etc/squid/squid.conf

  * to speed the test up a bit, reduce the shutdown timeout
  echo "shutdown_lifetime 5 seconds" | sudo tee -a /etc/squid/squid.conf

  * restart squid
  sudo systemctl restart squid

  * verify new FATAL error in logs
  sudo grep FATAL /var/log/squid/cache.log
  2019/02/28 17:05:04 kid2| FATAL: check failed: ios[0].iov_len == sizeof(data)
  2019/02/28 17:05:04 kid4| FATAL: check failed: ios[0].iov_len == sizeof(data)
  (...)

  * verify squid not working
  $ http_proxy=http://localhost:3128/ wget http://www.ubuntu.com -O /dev/null
  (...)
  Connecting to localhost (localhost)|127.0.0.1|:3128... failed: Connection refused.
  $ echo $?
  4

  With the updated packages, there is (new) FATAL error in the logs, and
  wget works just fine with the workers setting.

  [Regression Potential]
  The fix applies on top of another fix that was used to fix a FTBFS with gcc-8. The full gcc-8 set of fixes is quite big and some are still open, like https://github.com/squid-cache/squid/pull/270, and triggered some refactoring upstream. That being said, this particular change was committed many months ago (July 2018) and is already included in Disco in the newer upstream release we ship there.

  [Other Info]
  The fix applies on top of another patch from Debian. I chose to use a new patch instead of changing the existing one in order to simplify things, keep a clear dep3 header, and ease maintenance.

  There is another pending SRU for squid in bug #1816006, and the test
  instructions above include a workaround to not hit that bug, otherwise
  we wouldn't even hit the condition where this bug here occurs. Both will
- be fixed with one upload, but for now I'll leave the workaround
- instructions in place until I have the other fix done.
+ be fixed with one upload,

  [Original Description]
  Hi,

  It seems squid fails when configured with SMP. Steps I took to
  reproduce:

    * spin up a fresh cosmic instance

    * add 'workers 5' to /etc/squid/squid.conf

    * sudo service squid restart

  Logging shows this:

  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: Starting Squid Cache version 4.1 for x86_64-pc-linux-gnu...
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: Service Name: squid
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: Process ID 10728
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: Process Roles: worker
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: With 1024 file descriptors available
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: Initializing IP Cache...
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: DNS Socket created at [::], FD 5
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: DNS Socket created at 0.0.0.0, FD 13
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: Adding nameserver 127.0.0.53 from /etc/resolv.conf
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: Adding domain lcy02.canonistack from /etc/resolv.conf
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10726]: Local cache digest enabled; rebuild/rewrite every 3600/3600 sec
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10726]: Store logging disabled
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10726]: Swap maxSize 0 + 262144 KB, estimated 20164 objects
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10726]: Target number of buckets: 1008
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10726]: Using 8192 Store buckets
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10726]: Max Mem  size: 262144 KB [shared]
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10726]: Max Swap size: 0 KB
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10726]: Using Least Load store dir selection
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10726]: Set Current Directory to /var/spool/squid
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: Logfile: opening log daemon:/var/log/squid/access.log
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: Logfile Daemon: opening log /var/log/squid/access.log
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10723]: Finished loading MIME types and icons.
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10723]: FATAL: check failed: ios[0].iov_len == sizeof(data)#012    exception location: TypedMsgHdr.cc(70) sync#012
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10657]: Squid Parent: squid-1 process 10723 exited with status 255
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10657]: Squid Parent: squid-1 process 10723 will not be restarted for 3600 seconds due to repeated, frequent failures
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: Local cache digest enabled; rebuild/rewrite every 3600/3600 sec
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10726]: Finished loading MIME types and icons.
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: Store logging disabled
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10726]: FATAL: check failed: ios[0].iov_len == sizeof(data)#012    exception location: TypedMsgHdr.cc(70) sync#012
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: Swap maxSize 0 + 262144 KB, estimated 20164 objects
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: Target number of buckets: 1008
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: Using 8192 Store buckets
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: Max Mem  size: 262144 KB [shared]
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: Max Swap size: 0 KB
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: Using Least Load store dir selection
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: Set Current Directory to /var/spool/squid
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10657]: Squid Parent: squid-4 process 10726 exited with status 255
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10657]: Squid Parent: squid-4 process 10726 will not be restarted for 3600 seconds due to repeated, frequent failures
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: Finished loading MIME types and icons.
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10728]: FATAL: check failed: ios[0].iov_len == sizeof(data)#012    exception location: TypedMsgHdr.cc(70) sync#012
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10657]: Squid Parent: squid-3 process 10728 exited with status 255
  | Feb 14 03:39:56 juju-be3f45-default-20 squid[10657]: Squid Parent: squid-3 process 10728 will not be restarted for 3600 seconds due to repeated, frequent failures
  | Feb 14 03:39:57 juju-be3f45-default-20 squid[10659]: storeLateRelease: released 0 objects

  | ubuntu at juju-be3f45-default-20:~$ apt-cache policy squid
  | squid:
  |   Installed: 4.1-1ubuntu3
  |   Candidate: 4.1-1ubuntu3
  |   Version table:
  |  *** 4.1-1ubuntu3 500
  |         500 http://nova.clouds.archive.ubuntu.com/ubuntu cosmic/main amd64 Packages
  |         100 /var/lib/dpkg/status

-- 
You received this bug notification because you are a member of Ubuntu
Server, which is subscribed to the bug report.
https://bugs.launchpad.net/bugs/1815852

Title:
  squid FATAL: check failed: ios[0].iov_len == sizeof(data)#012
  exception location: TypedMsgHdr.cc(70) sync#012

To manage notifications about this bug go to:
https://bugs.launchpad.net/squid/+bug/1815852/+subscriptions