From mboxrd@z Thu Jan 1 00:00:00 1970 From: Michael Tremer To: development@lists.ipfire.org Subject: Re: problems with squid 3.5.17 Date: Fri, 29 Apr 2016 18:07:25 +0100 Message-ID: <1461949645.10266.305.camel@ipfire.org> In-Reply-To: <1461949269.10266.304.camel@ipfire.org> MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="===============0187540733483096697==" List-Id: --===============0187540733483096697== Content-Type: text/plain; charset="utf-8" Content-Transfer-Encoding: quoted-printable The async-io switch does not seem to be supported since squid 3.2 and after a= ny more and should not change anything at all. -Michael On Fri, 2016-04-29 at 18:01 +0100, Michael Tremer wrote: > Hi, >=20 > thanks for looking into that. I tried to contact you today to ask for a sta= tus > update about this. >=20 > I have not been able to get in touch with any of the other people that had > proxy > woes so I guess we are on our own. On one hand this makes me want to give t= his > a > very low priority. On the other hand I think we should target Core Update 1= 03 > with this. The update should actually not be that severe. >=20 > On Fri, 2016-04-29 at 18:14 +0200, Matthias Fischer wrote: > >=20 > > Hi, > >=20 > > As always: "I'd like to have a problem" - perhaps somone else here has > > some clues or better ideas: > >=20 > > I had not much luck during my tests with 'squid 3.5.17'. > >=20 > > In the last week I tested several compilations with the following > > modifications compared with '3.4.14'. Configuration included 'squid > > 3.5.17', squidguard 1.5-beta', 'squidclamav 5.11' and 'privoxy 3.0.24'. > >=20 > > I changed and tested with various configure-options: > >=20 > > 'squid': > > ipv6 disabled / enabled > > enable-async-io=3D8 / 16 / 32 > I had a look what the IPv6 switch actually changes. And that is not really > much. > Essentially nothing. It just probes if the system supports IPv6 and if not = it > disables it internally. >=20 > http://git.ipfire.org/?p=3Dthirdparty%2Fsquid.git&a=3Dsearch&h=3Drefs%2Fhea= ds%2Ftrun > k&st=3Dgrep&s=3DUSE_IPV6 >=20 > I think we can as well enable this. >=20 > >=20 > >=20 > > 'privoxy': > > ipv6-support enabled / disabled > >=20 > > After installing each new 'squid' version I deleted 'swap.state' and > > the whole cache dir structure - that means, everything below > > '/var/log/cache/' - and let 'squid' rebuild everything from scratch with > > 'squid -z'. > > No problems with that. > >=20 > > At first, 'squid' always seemed to run fine, 'squid.conf' and 'squid -k > > parse' showed no problems. Ok, without 'ipv6' I got a warning during > > start, but this seemed to have no further effect. > >=20 > > But after a few hours - sometimes it took a day - errors came up in the > > logs. > > These didn't noticably showed up during browsing. I had to search for > > them in the logs. > >=20 > > One error that ALWAYS occured - 'squid' tried to load a file from cache > > that wasn't there. In this case, 'squid' logged 'No such file or director= y'. > > Furthermore 'swapin MD5 mismatches' came up. It looked like 'swap.state' > > had been corrupted(?). > I guess it might be a good idea to wipe the cache when changing anything he= re. > Although none of these issues should happen and I have no idea what you are > trying to tell me here ;) Is this a big issue or just updating woes? >=20 > Should we merge 3.5.x for next and then see what this gets us? >=20 > >=20 > > 2016/04/25 04:41:09 kid1| WARNING: 1 swapin MD5 mismatches > > 2016/04/25 04:41:09 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 04:41:09 kid1|=C2=A0 /var/log/cache/00/00/00000008 > > 2016/04/25 04:41:09 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 04:41:09 kid1|=C2=A0 /var/log/cache/00/00/00000009 > > 2016/04/25 04:41:09 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 04:41:09 kid1|=C2=A0 /var/log/cache/00/00/0000000A > > 2016/04/25 04:41:09 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 04:41:09 kid1|=C2=A0 /var/log/cache/00/00/0000000B > > 2016/04/25 04:41:10 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 04:41:10 kid1|=C2=A0 /var/log/cache/00/00/0000000C > > 2016/04/25 04:41:10 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 04:41:10 kid1|=C2=A0 /var/log/cache/00/00/0000000D > > 2016/04/25 04:41:10 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 04:41:10 kid1|=C2=A0 /var/log/cache/00/00/0000000E > > ... > >=20 > > ... > > 2016/04/25 05:17:21 kid1| Starting new redirector helpers... > > 2016/04/25 05:17:21 kid1| helperOpenServers: Starting 1/30 > > 'redirect_wrapper' processes > > 2016/04/25 05:17:21 kid1| Starting new redirector helpers... > > 2016/04/25 05:17:21 kid1| helperOpenServers: Starting 1/30 > > 'redirect_wrapper' processes > > 2016/04/25 05:17:45 kid1| WARNING: 1 swapin MD5 mismatches > > 2016/04/25 14:05:08 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 14:05:08 kid1|=C2=A0 /var/log/cache/00/00/00000073 > > 2016/04/25 14:05:08 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 14:05:08 kid1|=C2=A0 /var/log/cache/00/00/00000075 > > 2016/04/25 14:05:09 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 14:05:09 kid1|=C2=A0 /var/log/cache/00/00/00000008 > > 2016/04/25 14:05:09 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 14:05:09 kid1|=C2=A0 /var/log/cache/00/00/00000009 > > 2016/04/25 14:05:09 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 14:05:09 kid1|=C2=A0 /var/log/cache/00/00/0000000A > > 2016/04/25 14:05:09 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 14:05:09 kid1|=C2=A0 /var/log/cache/00/00/0000000B > > 2016/04/25 14:05:09 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 14:05:09 kid1|=C2=A0 /var/log/cache/00/00/0000000C > > 2016/04/25 14:05:09 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 14:05:09 kid1|=C2=A0 /var/log/cache/00/00/0000000D > > 2016/04/25 14:05:09 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 14:05:09 kid1|=C2=A0 /var/log/cache/00/00/0000000E > > 2016/04/25 14:05:09 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 14:05:09 kid1|=C2=A0 /var/log/cache/00/00/0000000F > > 2016/04/25 14:05:09 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 14:05:09 kid1|=C2=A0 /var/log/cache/00/00/00000010 > > 2016/04/25 14:05:09 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 14:05:09 kid1|=C2=A0 /var/log/cache/00/00/00000011 > > 2016/04/25 14:05:10 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 14:05:10 kid1|=C2=A0 /var/log/cache/00/00/00000012 > > 2016/04/25 14:05:10 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 14:05:10 kid1|=C2=A0 /var/log/cache/00/00/00000013 > > 2016/04/25 14:05:10 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 14:05:10 kid1|=C2=A0 /var/log/cache/00/00/00000085 > > 2016/04/25 14:05:10 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 14:05:10 kid1|=C2=A0 /var/log/cache/00/00/00000087 > > 2016/04/25 14:05:10 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 14:05:10 kid1|=C2=A0 /var/log/cache/00/07/00000766 > > 2016/04/25 14:05:10 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 14:05:10 kid1|=C2=A0 /var/log/cache/00/07/00000767 > > 2016/04/25 14:05:11 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 14:05:11 kid1|=C2=A0 /var/log/cache/00/00/00000014 > > 2016/04/25 14:05:11 kid1| DiskThreadsDiskFile::openDone: (2) No such > > file or directory > > 2016/04/25 14:05:11 kid1|=C2=A0 /var/log/cache/00/00/00000015 > > 2016/04/25 14:10:16 kid1| Starting new redirector helpers... > > ... > >=20 > > With the last '3.5.17', 'squid' reported a totally wrong > > 'store_swap_size' plus some weird queue errors: > >=20 > > ... > > 2016/04/26 01:27:44 kid1| Beginning Validation Procedure > > 2016/04/26 01:27:44 kid1|=C2=A0=C2=A0=C2=A0Completed Validation Procedure > > 2016/04/26 01:27:44 kid1|=C2=A0=C2=A0=C2=A0Validated 9126 Entries > > 2016/04/26 01:27:44 kid1|=C2=A0=C2=A0=C2=A0store_swap_size =3D 2226220.00= KB <--- Wrong > > size! WHY!? System was nearly IDLE! > > 2016/04/26 01:27:44 kid1| storeLateRelease: released 0 objects > > 2016/04/26 01:27:45 kid1| squidaio_queue_request: Async request queue > > growing uncontrollably! > > 2016/04/26 01:27:45 kid1| squidaio_queue_request: Syncing pending I/O > > operations.. (blocking) > > 2016/04/26 01:27:45 kid1| squidaio_queue_request: Synced > > 2016/04/26 01:27:45 kid1| squidaio_queue_request: Async request queue > > growing uncontrollably! > > 2016/04/26 01:27:45 kid1| squidaio_queue_request: Syncing pending I/O > > operations.. (blocking) > > 2016/04/26 01:27:45 kid1| squidaio_queue_request: Synced > > ... > >=20 > > Even during restart, 'cache_log' reports a wrong 'store_swap_size': > >=20 > > ... > > 2016/04/29 17:16:33 kid1| Beginning Validation Procedure > > 2016/04/29 17:16:33 kid1| Completed Validation Procedure > > 2016/04/29 17:16:33 kid1| Validated 3541 Entries > > 2016/04/29 17:16:33 kid1| store_swap_size =3D 389420.00 KB <----! > > ... > >=20 > > But in reality its only 117351 KB! 'squid' was ALWAYS started with > > ... > > cache_mem 32 MB > > cache_dir aufs /var/log/cache 128 16 256 > > ... > >=20 > > So what!? > >=20 > > At this point, I'm giving up (again), to think things over and to ask if > > anyone got an idea. > >=20 > > During building everythings OK, but it looks like I can't get that > > version to work without errors. > >=20 > > Test versions are available here: > > http://people.ipfire.org/~mfischer/squid/3.5.17 > >=20 > > The same configuration is running right now with '3.4.14' (ipv6 disabled > > / enable-async-io=3D16). > > No errors in the logs, reported 'store_swap_size' is OK, no problems. > >=20 > > Any ideas? > >=20 > > Best, > > Matthias > -Michael --===============0187540733483096697== Content-Type: application/pgp-signature Content-Transfer-Encoding: base64 Content-Disposition: attachment; filename="signature.asc" MIME-Version: 1.0 LS0tLS1CRUdJTiBQR1AgU0lHTkFUVVJFLS0tLS0KVmVyc2lvbjogR251UEcgdjIKCmlRSWNCQUFC Q2dBR0JRSlhJNVROQUFvSkVJQjU4UDl2a0FrSE93a1FBS1haaXBRTGMxb05MNS9kWVpFTWU4MXcK TnlyWVB2enlad2lhZU0vemFORVg2SDRnWXY1NmpLM1pwN3cxMVI3eTRUa0g2Y0QwbmZYSk5HMjNT T2VIa0RWegp0ZEk2dlNMQjNLeWNiSW5ycmFHQTYvS2JHbTFzWDFwV0UxNm00NHd0dFNOR01Lc0ZE RGdKK05kMVk5WVlYQkdLCk52WWdqV1dPSDF1NklYcHNSYXBYN2k5bTBBR2JEV3lCY3dKeTRQeVBY aGNkY0syYTYwc2RLRVVPUm5NdllxSU4KclU1NHlBQy91bkJ2NWdVd3Y5UEhMK0dTcVl0c2tYWlg0 blNFMVN1MmNoaXhCMkcrYXZWZEl5ZFExL2VkOWhvVQpydGlweU1ROTRpbHpZNXdqTzlqSU10WitP eHNvM3lZME9YZ0ZLalp2Lytja21MUjNsRVF1M1I2OVF1Mm00ZzVlCmYrWnhvQVlGVHM5c2liUGpx OWtWQ2UzanMxRm1kZm1wZ1VKSi9xYStCRnpES2ZVUXR6Z3ZteDNkY1FQYWpybVIKb1QycUdOVEJF YkJESCt5eHNHN0Fnc1pVUGhaMTUyNUJjUEtORTJLeG01MVpKa0RXWlgrUWt3VlN5VUUyL2FhSQpq UW52MWV2ZUdCcXpRLytkSmNaMmhPR2JucGxhaUd6ek53MEVJUUV5ZVp1VzY1L0xZcUsybjNYeG5Y V0pmZitGCk1jaDBXNGtzVkxFOS91QUtkUEhDM1FncUpBYjhiSFovOUpCMUYzdk1URzVJakJaVXpB WW1KZnpDTHA2eEVHaEMKZE02dFMxZ1UzYyt2OXhRUmdEdXBaR1Y0NmFDckRNSFBsWTQ1TjlLdEg5 VTRZZmg3UnpiRlIxRCs5WWhaQkNIdgo4WUtUVnRjWnh0K0Y5ais1Z0lydwo9aTdvbgotLS0tLUVO RCBQR1AgU0lHTkFUVVJFLS0tLS0K --===============0187540733483096697==--