<div dir="ltr">Dear all,<div><br></div><div>As I was playing around with Squid and e-cap, I decided to shutdown squid, clear the cache and the log files.</div><div><br></div><div>Now, when I start it, it seems to create both the access.log and cache.log files, but it only writes to the cache.log file:</div><div><div>root@appliance:/var/log/squid3# ls -al</div><div>total 16</div><div>drwxr-xr-x  2 proxy proxy 4096 Feb 15 23:12 .</div><div>drwxr-xr-x 11 root  root  4096 Feb 15 06:25 ..</div><div>-rw-r--r--  1 proxy proxy    0 Feb 15 23:12 access.log</div><div>-rw-r--r--  1 proxy proxy 8046 Feb 15 23:13 cache.log</div><div>root@appliance:/var/log/squid3#</div></div><div><br></div><div>As far as I know, I've reverted ALL my changes to a known working state (e.g. disabled e-cap altogether, the debug_options and the request_header_access directives I had turned on earlier today), but I just can't get squid to write to access.log.</div><div><br></div><div>Here's what I'm getting (this time with debug_options ALL, 2 , so we can see a little more info on what is going on):</div><div><br></div><div><div>root@appliance:/var/log/squid3# rm *</div><div>root@appliance:/var/log/squid3# /etc/init.d/squid3 start</div><div>[ ok ] Starting Squid HTTP Proxy 3.x: squid3.</div><div>root@appliance:/var/log/squid3# ls -l</div><div>total 12</div><div>-rw-r----- 1 proxy proxy    0 Feb 15 23:25 access.log</div><div>-rw-r----- 1 proxy proxy 9002 Feb 15 23:25 cache.log</div><div>root@appliance:/var/log/squid3# cat cache.log</div><div>2015/02/15 23:25:39.890| main.cc(1424) SquidMain: Doing post-config initialization</div><div><br></div><div>2015/02/15 23:25:39.890| main.cc(1426) SquidMain: running RegisteredRunner::finalizeConfig</div><div>2015/02/15 23:25:39.891| main.cc(1427) SquidMain: running RegisteredRunner::claimMemoryNeeds</div><div>2015/02/15 23:25:39.891| main.cc(1428) SquidMain: running RegisteredRunner::useConfig</div><div>2015/02/15 23:25:39.930 kid1| main.cc(1424) SquidMain: Doing post-config initialization</div><div><br></div><div>2015/02/15 23:25:39.930 kid1| main.cc(1426) SquidMain: running RegisteredRunner::finalizeConfig</div><div>2015/02/15 23:25:39.930 kid1| main.cc(1427) SquidMain: running RegisteredRunner::claimMemoryNeeds</div><div>2015/02/15 23:25:39.930 kid1| main.cc(1428) SquidMain: running RegisteredRunner::useConfig</div><div>2015/02/15 23:25:39.930 kid1| Current Directory is /</div><div>2015/02/15 23:25:39.930 kid1| Starting Squid Cache version 3.5.1 for x86_64-unknown-linux-gnu...</div><div>2015/02/15 23:25:39.930 kid1| Service Name: squid</div><div>2015/02/15 23:25:39.930 kid1| Process ID 11312</div><div>2015/02/15 23:25:39.930 kid1| Process Roles: worker</div><div>2015/02/15 23:25:39.930 kid1| With 65535 file descriptors available</div><div>2015/02/15 23:25:39.930 kid1| Initializing IP Cache...</div><div>2015/02/15 23:25:39.941 kid1| dns_internal.cc(1529) dnsInit: idnsInit: attempt open DNS socket to: [::]</div><div>2015/02/15 23:25:39.941 kid1| dns_internal.cc(1538) dnsInit: idnsInit: attempt open DNS socket to: 0.0.0.0</div><div>2015/02/15 23:25:39.941 kid1| DNS Socket created at [::], FD 6</div><div>2015/02/15 23:25:39.941 kid1| DNS Socket created at 0.0.0.0, FD 7</div><div>2015/02/15 23:25:39.941 kid1| Adding nameserver 8.8.8.8 from squid.conf</div><div>2015/02/15 23:25:39.941 kid1| helperOpenServers: Starting 5/5 'ssl_crtd' processes</div><div>2015/02/15 23:25:39.963 kid1| Format.cc(64) parse: got definition '%>a/%>A %un %>rm myip=%la myport=%lp'</div><div>2015/02/15 23:25:39.963 kid1| Format.cc(64) parse: got definition '%>a/%>A %un %>rm myip=%la myport=%lp'</div><div>2015/02/15 23:25:39.963 kid1| Logfile: opening log daemon:/var/log/squid3/access.log</div><div>2015/02/15 23:25:39.963 kid1| Logfile Daemon: opening log /var/log/squid3/access.log</div><div>2015/02/15 23:25:40 kid1| Unlinkd pipe opened on FD 25</div><div>2015/02/15 23:25:40.227 kid1| store_digest.cc(490) storeDigestCalcCap: storeDigestCalcCap: have: 0, want 161319 entries; limits: [1, 161319]</div><div>2015/02/15 23:25:40.227 kid1| CacheDigest.cc(49) cacheDigestInit: cacheDigestInit: capacity: 161319 entries, bpe: 5; size: 100825 bytes</div><div>2015/02/15 23:25:40.227 kid1| Local cache digest enabled; rebuild/rewrite every 3600/3600 sec</div><div>2015/02/15 23:25:40.227 kid1| Store logging disabled</div><div>2015/02/15 23:25:40.227 kid1| Swap maxSize 2097152 + 1048576 KB, estimated 241979 objects</div><div>2015/02/15 23:25:40.227 kid1| Target number of buckets: 12098</div><div>2015/02/15 23:25:40.227 kid1| Using 16384 Store buckets</div><div>2015/02/15 23:25:40.227 kid1| Max Mem  size: 1048576 KB</div><div>2015/02/15 23:25:40.227 kid1| Max Swap size: 2097152 KB</div><div>2015/02/15 23:25:40.228 kid1| ufs/UFSSwapLogParser.cc(96) GetUFSSwapLogParser: Swap file version: 2</div><div>2015/02/15 23:25:40.228 kid1| Rebuilding storage in /var/spool/squid3 (clean log)</div><div>2015/02/15 23:25:40.228 kid1| Using Least Load store dir selection</div><div>2015/02/15 23:25:40.228 kid1| Current Directory is /</div><div>2015/02/15 23:25:40.228 kid1| Finished loading MIME types and icons.</div><div>2015/02/15 23:25:40.259 kid1| wccp.cc(112) wccpConnectionOpen: WCCPv1 disabled.</div><div>2015/02/15 23:25:40.259 kid1| wccp2.cc(960) wccp2ConnectionOpen: WCCPv2 Disabled. No IPv4 Router(s) configured.</div><div>2015/02/15 23:25:40.259 kid1| AsyncCall.cc(26) AsyncCall: The AsyncCall clientListenerConnectionOpened constructed, this=0x30a4470 [call20]</div><div>2015/02/15 23:25:40.259 kid1| AsyncCall.cc(93) ScheduleCall: StartListening.cc(59) will call clientListenerConnectionOpened(local=[::]:3128 remote=[::] FD 28 flags=9, err=0, HTTP Socket port=0x30a44d0) [call20]</div><div>2015/02/15 23:25:40.259 kid1| AsyncCall.cc(26) AsyncCall: The AsyncCall clientListenerConnectionOpened constructed, this=0x30a47f0 [call22]</div><div>2015/02/15 23:25:40.260 kid1| AsyncCall.cc(93) ScheduleCall: StartListening.cc(59) will call clientListenerConnectionOpened(local=[::]:3129 remote=[::] FD 29 flags=41, err=0, HTTP Socket port=0x30a4850) [call22]</div><div>2015/02/15 23:25:40.260 kid1| AsyncCall.cc(26) AsyncCall: The AsyncCall clientListenerConnectionOpened constructed, this=0x30a4980 [call24]</div><div>2015/02/15 23:25:40.260 kid1| AsyncCall.cc(93) ScheduleCall: StartListening.cc(59) will call clientListenerConnectionOpened(local=[::]:3130 remote=[::] FD 30 flags=41, err=0, HTTPS Socket port=0x30a49e0) [call24]</div><div>2015/02/15 23:25:40.260 kid1| HTCP Disabled.</div><div>2015/02/15 23:25:40.260 kid1| Squid plugin modules loaded: 0</div><div>2015/02/15 23:25:40.260 kid1| Adaptation support is on</div><div>2015/02/15 23:25:40.260 kid1| Config.cc(211) FinalizeEach: Initialized 1 message adaptation services</div><div>2015/02/15 23:25:40.260 kid1| Config.cc(211) FinalizeEach: Initialized 0 message adaptation service groups</div><div>2015/02/15 23:25:40.260 kid1| Config.cc(211) FinalizeEach: Initialized 1 message adaptation access rules</div><div>2015/02/15 23:25:40.260 kid1| AsyncCallQueue.cc(55) fireNext: entering clientListenerConnectionOpened(local=[::]:3128 remote=[::] FD 28 flags=9, err=0, HTTP Socket port=0x30a44d0)</div><div>2015/02/15 23:25:40.260 kid1| AsyncCall.cc(38) make: make call clientListenerConnectionOpened [call20]</div><div>2015/02/15 23:25:40.260 kid1| Accepting HTTP Socket connections at local=[::]:3128 remote=[::] FD 28 flags=9</div><div>2015/02/15 23:25:40.260 kid1| AsyncCallQueue.cc(57) fireNext: leaving clientListenerConnectionOpened(local=[::]:3128 remote=[::] FD 28 flags=9, err=0, HTTP Socket port=0x30a44d0)</div><div>2015/02/15 23:25:40.260 kid1| AsyncCallQueue.cc(55) fireNext: entering clientListenerConnectionOpened(local=[::]:3129 remote=[::] FD 29 flags=41, err=0, HTTP Socket port=0x30a4850)</div><div>2015/02/15 23:25:40.260 kid1| AsyncCall.cc(38) make: make call clientListenerConnectionOpened [call22]</div><div>2015/02/15 23:25:40.260 kid1| Accepting NAT intercepted HTTP Socket connections at local=[::]:3129 remote=[::] FD 29 flags=41</div><div>2015/02/15 23:25:40.260 kid1| AsyncCallQueue.cc(57) fireNext: leaving clientListenerConnectionOpened(local=[::]:3129 remote=[::] FD 29 flags=41, err=0, HTTP Socket port=0x30a4850)</div><div>2015/02/15 23:25:40.261 kid1| AsyncCallQueue.cc(55) fireNext: entering clientListenerConnectionOpened(local=[::]:3130 remote=[::] FD 30 flags=41, err=0, HTTPS Socket port=0x30a49e0)</div><div>2015/02/15 23:25:40.261 kid1| AsyncCall.cc(38) make: make call clientListenerConnectionOpened [call24]</div><div>2015/02/15 23:25:40.261 kid1| Accepting NAT intercepted SSL bumped HTTPS Socket connections at local=[::]:3130 remote=[::] FD 30 flags=41</div><div>2015/02/15 23:25:40.261 kid1| AsyncCallQueue.cc(57) fireNext: leaving clientListenerConnectionOpened(local=[::]:3130 remote=[::] FD 30 flags=41, err=0, HTTPS Socket port=0x30a49e0)</div><div>2015/02/15 23:25:40.261 kid1| Done reading /var/spool/squid3 swaplog (0 entries)</div><div>2015/02/15 23:25:40.261 kid1| Store rebuilding is 0.00% complete</div><div>2015/02/15 23:25:40.261 kid1| Finished rebuilding storage from disk.</div><div>2015/02/15 23:25:40.261 kid1|         0 Entries scanned</div><div>2015/02/15 23:25:40.261 kid1|         0 Invalid entries.</div><div>2015/02/15 23:25:40.261 kid1|         0 With invalid flags.</div><div>2015/02/15 23:25:40.261 kid1|         0 Objects loaded.</div><div>2015/02/15 23:25:40.261 kid1|         0 Objects expired.</div><div>2015/02/15 23:25:40.261 kid1|         0 Objects cancelled.</div><div>2015/02/15 23:25:40.261 kid1|         0 Duplicate URLs purged.</div><div>2015/02/15 23:25:40.261 kid1|         0 Swapfile clashes avoided.</div><div>2015/02/15 23:25:40.261 kid1|   Took 0.03 seconds (  0.00 objects/sec).</div><div>2015/02/15 23:25:40.261 kid1| Beginning Validation Procedure</div><div>2015/02/15 23:25:40.261 kid1| disk.cc(503) xrename: xrename: renaming /var/spool/squid3/swap.state.new to /var/spool/squid3/swap.state</div><div>2015/02/15 23:25:40.261 kid1| store_rebuild.cc(96) storeCleanup: Seen: 51 entries</div><div>2015/02/15 23:25:40.261 kid1|   Completed Validation Procedure</div><div>2015/02/15 23:25:40.261 kid1|   Validated 0 Entries</div><div>2015/02/15 23:25:40.261 kid1|   store_swap_size = 0.00 KB</div><div>2015/02/15 23:25:40.261 kid1| store_digest.cc(283) storeDigestRebuildStart: storeDigestRebuildStart: rebuild #1</div><div>2015/02/15 23:25:40.261 kid1| store_digest.cc(490) storeDigestCalcCap: storeDigestCalcCap: have: 51, want 51 entries; limits: [1, 161319]</div><div>2015/02/15 23:25:40.261 kid1| store_digest.cc(512) storeDigestResize: storeDigestResize: 161319 -> 51; change: 161268 (100%)</div><div>2015/02/15 23:25:40.261 kid1| store_digest.cc(519) storeDigestResize: storeDigestResize: big change, resizing.</div><div>2015/02/15 23:25:40.262 kid1| CacheDigest.cc(49) cacheDigestInit: cacheDigestInit: capacity: 51 entries, bpe: 5; size: 32 bytes</div><div>2015/02/15 23:25:40.262 kid1| store_digest.cc(363) storeDigestRewriteStart: storeDigestRewrite: start rewrite #1</div><div>2015/02/15 23:25:40.262 kid1| store_digest.cc(377) storeDigestRewriteStart: storeDigestRewriteStart: waiting for rebuild to finish.</div><div>2015/02/15 23:25:40.262 kid1| store_digest.cc(317) storeDigestRebuildFinish: storeDigestRebuildFinish: done.</div><div>2015/02/15 23:25:40.262 kid1| store_digest.cc(418) storeDigestRewriteFinish: storeDigestRewriteFinish: digest expires at 1424071540 (+3600)</div><div>2015/02/15 23:25:41 kid1| storeLateRelease: released 0 objects</div><div>root@appliance:/var/log/squid3# cat cache.log  | grep -i access</div><div>2015/02/15 23:25:39.963 kid1| Logfile: opening log daemon:/var/log/squid3/access.log</div><div>2015/02/15 23:25:39.963 kid1| Logfile Daemon: opening log /var/log/squid3/access.log</div><div>2015/02/15 23:25:40.260 kid1| Config.cc(211) FinalizeEach: Initialized 1 message adaptation access rules</div><div>root@appliance:/var/log/squid3# ls -al</div><div>total 20</div><div>drwxr-xr-x  2 proxy proxy 4096 Feb 15 23:25 .</div><div>drwxr-xr-x 11 root  root  4096 Feb 15 06:25 ..</div><div>-rw-r-----  1 proxy proxy    0 Feb 15 23:25 access.log</div><div>-rw-r-----  1 proxy proxy 9065 Feb 15 23:25 cache.log</div><div>root@appliance:/var/log/squid3#</div></div><div><br></div><div>Everything seems to be working fine, and traffic IS being routed through squid. Its just that nothing gets logged to access.log...</div><div><br></div><div>Any idea on what might be causing this?</div><div><br></div><div>Thank you,</div><div>Luis</div></div>